LXR uboot/test/log/log

   1// SPDX-License-Identifier: GPL-2.0+
   2/*
   3 * Logging support test program
   4 *
   5 * Copyright (c) 2017 Google, Inc
   6 * Written by Simon Glass <sjg@chromium.org>
   7 */
   8
   9#include <common.h>
  10#include <command.h>
  11#include <log.h>
  12#include <asm/global_data.h>
  13#include <test/log.h>
  14#include <test/ut.h>
  15
  16DECLARE_GLOBAL_DATA_PTR;
  17
  18/* emit some sample log records in different ways, for testing */
  19static int do_log_run(struct unit_test_state *uts, int cat, const char *file)
  20{
  21        int i;
  22        int ret, expected_ret;
  23
  24        if (gd->flags & GD_FLG_LOG_READY)
  25                expected_ret = 0;
  26        else
  27                expected_ret = -ENOSYS;
  28
  29        gd->log_fmt = LOGF_TEST;
  30        debug("debug\n");
  31        for (i = LOGL_FIRST; i < LOGL_COUNT; i++) {
  32                log(cat, i, "log %d\n", i);
  33                ret = _log(log_uc_cat(cat), i, file, 100 + i,
  34                           "func", "_log %d\n", i);
  35                ut_asserteq(ret, expected_ret);
  36        }
  37        /* test with LOGL_COUNT flag */
  38        for (i = LOGL_FIRST; i < LOGL_COUNT; i++) {
  39                ret = _log(log_uc_cat(cat), i | LOGL_FORCE_DEBUG, file, 100 + i,
  40                           "func", "_log force %d\n", i);
  41                ut_asserteq(ret, expected_ret);
  42        }
  43
  44        gd->log_fmt = log_get_default_format();
  45        return 0;
  46}
  47
  48#define log_run_cat(cat) do_log_run(uts, cat, "file")
  49#define log_run_file(file) do_log_run(uts, UCLASS_SPI, file)
  50#define log_run() do_log_run(uts, UCLASS_SPI, "file")
  51
  52#define EXPECT_LOG BIT(0)
  53#define EXPECT_DIRECT BIT(1)
  54#define EXPECT_EXTRA BIT(2)
  55#define EXPECT_FORCE BIT(3)
  56#define EXPECT_DEBUG BIT(4)
  57
  58static int do_check_log_entries(struct unit_test_state *uts, int flags, int min,
  59                                int max)
  60{
  61        int i;
  62
  63        for (i = min; i <= max; i++) {
  64                if (flags & EXPECT_LOG)
  65                        ut_assert_nextline("          do_log_run() log %d", i);
  66                if (flags & EXPECT_DIRECT)
  67                        ut_assert_nextline("                func() _log %d", i);
  68                if (flags & EXPECT_DEBUG) {
  69                        ut_assert_nextline("log %d", i);
  70                        ut_assert_nextline("_log %d", i);
  71                }
  72        }
  73        if (flags & EXPECT_EXTRA)
  74                for (; i <= LOGL_MAX ; i++)
  75                        ut_assert_nextline("                func() _log %d", i);
  76
  77        for (i = LOGL_FIRST; i < LOGL_COUNT; i++) {
  78                if (flags & EXPECT_FORCE)
  79                        ut_assert_nextline("                func() _log force %d",
  80                                           i);
  81                if (flags & EXPECT_DEBUG)
  82                        ut_assert_nextline("_log force %d", i);
  83        }
  84
  85        ut_assert_console_end();
  86        return 0;
  87}
  88
  89#define check_log_entries_flags_levels(flags, min, max) do {\
  90        int ret = do_check_log_entries(uts, flags, min, max); \
  91        if (ret) \
  92                return ret; \
  93} while (0)
  94
  95#define check_log_entries_flags(flags) \
  96        check_log_entries_flags_levels(flags, LOGL_FIRST, _LOG_MAX_LEVEL)
  97#define check_log_entries() check_log_entries_flags(EXPECT_LOG | EXPECT_DIRECT | EXPECT_FORCE)
  98#define check_log_entries_extra() \
  99        check_log_entries_flags(EXPECT_LOG | EXPECT_DIRECT | EXPECT_EXTRA | EXPECT_FORCE)
 100#define check_log_entries_none() check_log_entries_flags(EXPECT_FORCE)
 101
 102/* Check a category filter using the first category */
 103int log_test_cat_allow(struct unit_test_state *uts)
 104{
 105        enum log_category_t cat_list[] = {
 106                log_uc_cat(UCLASS_MMC), log_uc_cat(UCLASS_SPI),
 107                LOGC_NONE, LOGC_END
 108        };
 109        int filt;
 110
 111        filt = log_add_filter("console", cat_list, LOGL_MAX, NULL);
 112        ut_assert(filt >= 0);
 113
 114        ut_assertok(console_record_reset_enable());
 115        log_run_cat(UCLASS_MMC);
 116        check_log_entries_extra();
 117
 118        ut_assertok(console_record_reset_enable());
 119        log_run_cat(UCLASS_SPI);
 120        check_log_entries_extra();
 121
 122        ut_assertok(log_remove_filter("console", filt));
 123        return 0;
 124}
 125LOG_TEST_FLAGS(log_test_cat_allow, UT_TESTF_CONSOLE_REC);
 126
 127/* Check a category filter that should block log entries */
 128int log_test_cat_deny_implicit(struct unit_test_state *uts)
 129{
 130        enum log_category_t cat_list[] = {
 131                log_uc_cat(UCLASS_MMC),  LOGC_NONE, LOGC_END
 132        };
 133        int filt;
 134
 135        filt = log_add_filter("console", cat_list, LOGL_MAX, NULL);
 136        ut_assert(filt >= 0);
 137
 138        ut_assertok(console_record_reset_enable());
 139        log_run_cat(UCLASS_SPI);
 140        check_log_entries_none();
 141
 142        ut_assertok(log_remove_filter("console", filt));
 143        return 0;
 144}
 145LOG_TEST_FLAGS(log_test_cat_deny_implicit, UT_TESTF_CONSOLE_REC);
 146
 147/* Check passing and failing file filters */
 148int log_test_file(struct unit_test_state *uts)
 149{
 150        int filt;
 151
 152        filt = log_add_filter("console", NULL, LOGL_MAX, "file");
 153        ut_assert(filt >= 0);
 154
 155        ut_assertok(console_record_reset_enable());
 156        log_run_file("file");
 157        check_log_entries_flags(EXPECT_DIRECT | EXPECT_EXTRA | EXPECT_FORCE);
 158
 159        ut_assertok(console_record_reset_enable());
 160        log_run_file("file2");
 161        check_log_entries_none();
 162
 163        ut_assertok(log_remove_filter("console", filt));
 164        return 0;
 165}
 166LOG_TEST_FLAGS(log_test_file, UT_TESTF_CONSOLE_REC);
 167
 168/* Check a passing file filter (second in list) */
 169int log_test_file_second(struct unit_test_state *uts)
 170{
 171        int filt;
 172
 173        filt = log_add_filter("console", NULL, LOGL_MAX, "file,file2");
 174        ut_assert(filt >= 0);
 175
 176        ut_assertok(console_record_reset_enable());
 177        log_run_file("file2");
 178        check_log_entries_flags(EXPECT_DIRECT | EXPECT_EXTRA | EXPECT_FORCE);
 179
 180        ut_assertok(log_remove_filter("console", filt));
 181        return 0;
 182}
 183LOG_TEST_FLAGS(log_test_file_second, UT_TESTF_CONSOLE_REC);
 184
 185/* Check a passing file filter (middle of list) */
 186int log_test_file_mid(struct unit_test_state *uts)
 187{
 188        int filt;
 189
 190        filt = log_add_filter("console", NULL, LOGL_MAX,
 191                              "file,file2,log/log_test.c");
 192        ut_assert(filt >= 0);
 193
 194        ut_assertok(console_record_reset_enable());
 195        log_run_file("file2");
 196        check_log_entries_extra();
 197
 198        ut_assertok(log_remove_filter("console", filt));
 199        return 0;
 200}
 201LOG_TEST_FLAGS(log_test_file_mid, UT_TESTF_CONSOLE_REC);
 202
 203/* Check a log level filter */
 204int log_test_level(struct unit_test_state *uts)
 205{
 206        int filt;
 207
 208        filt = log_add_filter("console", NULL, LOGL_WARNING, NULL);
 209        ut_assert(filt >= 0);
 210
 211        ut_assertok(console_record_reset_enable());
 212        log_run();
 213        check_log_entries_flags_levels(EXPECT_LOG | EXPECT_DIRECT | EXPECT_FORCE,
 214                                       LOGL_FIRST, LOGL_WARNING);
 215
 216        ut_assertok(log_remove_filter("console", filt));
 217        return 0;
 218}
 219LOG_TEST_FLAGS(log_test_level, UT_TESTF_CONSOLE_REC);
 220
 221/* Check two filters, one of which passes everything */
 222int log_test_double(struct unit_test_state *uts)
 223{
 224        int filt1, filt2;
 225
 226        filt1 = log_add_filter("console", NULL, LOGL_WARNING, NULL);
 227        ut_assert(filt1 >= 0);
 228        filt2 = log_add_filter("console", NULL, LOGL_MAX, NULL);
 229        ut_assert(filt2 >= 0);
 230
 231        ut_assertok(console_record_reset_enable());
 232        log_run();
 233        check_log_entries_extra();
 234
 235        ut_assertok(log_remove_filter("console", filt1));
 236        ut_assertok(log_remove_filter("console", filt2));
 237        return 0;
 238}
 239LOG_TEST_FLAGS(log_test_double, UT_TESTF_CONSOLE_REC);
 240
 241/* Check three filters, which together pass everything */
 242int log_test_triple(struct unit_test_state *uts)
 243{
 244        int filt1, filt2, filt3;
 245
 246        filt1 = log_add_filter("console", NULL, LOGL_MAX, "file)");
 247        ut_assert(filt1 >= 0);
 248        filt2 = log_add_filter("console", NULL, LOGL_MAX, "file2");
 249        ut_assert(filt2 >= 0);
 250        filt3 = log_add_filter("console", NULL, LOGL_MAX, "log/log_test.c");
 251        ut_assert(filt3 >= 0);
 252
 253        ut_assertok(console_record_reset_enable());
 254        log_run_file("file2");
 255        check_log_entries_extra();
 256
 257        ut_assertok(log_remove_filter("console", filt1));
 258        ut_assertok(log_remove_filter("console", filt2));
 259        ut_assertok(log_remove_filter("console", filt3));
 260        return 0;
 261}
 262LOG_TEST_FLAGS(log_test_triple, UT_TESTF_CONSOLE_REC);
 263
 264int do_log_test_helpers(struct unit_test_state *uts)
 265{
 266        int i;
 267
 268        ut_assertok(console_record_reset_enable());
 269        log_err("level %d\n", LOGL_EMERG);
 270        log_err("level %d\n", LOGL_ALERT);
 271        log_err("level %d\n", LOGL_CRIT);
 272        log_err("level %d\n", LOGL_ERR);
 273        log_warning("level %d\n", LOGL_WARNING);
 274        log_notice("level %d\n", LOGL_NOTICE);
 275        log_info("level %d\n", LOGL_INFO);
 276        log_debug("level %d\n", LOGL_DEBUG);
 277        log_content("level %d\n", LOGL_DEBUG_CONTENT);
 278        log_io("level %d\n", LOGL_DEBUG_IO);
 279
 280        for (i = LOGL_EMERG; i <= gd->default_log_level; i++)
 281                ut_assert_nextline("%*s() level %d", CONFIG_LOGF_FUNC_PAD,
 282                                   __func__, i);
 283        ut_assert_console_end();
 284        return 0;
 285}
 286
 287int log_test_helpers(struct unit_test_state *uts)
 288{
 289        int ret;
 290
 291        gd->log_fmt = LOGF_TEST;
 292        ret = do_log_test_helpers(uts);
 293        gd->log_fmt = log_get_default_format();
 294        return ret;
 295}
 296LOG_TEST_FLAGS(log_test_helpers, UT_TESTF_CONSOLE_REC);
 297
 298int do_log_test_disable(struct unit_test_state *uts)
 299{
 300        ut_assertok(console_record_reset_enable());
 301        log_err("default\n");
 302        ut_assert_nextline("%*s() default", CONFIG_LOGF_FUNC_PAD, __func__);
 303
 304        ut_assertok(log_device_set_enable(LOG_GET_DRIVER(console), false));
 305        log_err("disabled\n");
 306
 307        ut_assertok(log_device_set_enable(LOG_GET_DRIVER(console), true));
 308        log_err("enabled\n");
 309        ut_assert_nextline("%*s() enabled", CONFIG_LOGF_FUNC_PAD, __func__);
 310        ut_assert_console_end();
 311        return 0;
 312}
 313
 314int log_test_disable(struct unit_test_state *uts)
 315{
 316        int ret;
 317
 318        gd->log_fmt = LOGF_TEST;
 319        ret = do_log_test_disable(uts);
 320        gd->log_fmt = log_get_default_format();
 321        return ret;
 322}
 323LOG_TEST_FLAGS(log_test_disable, UT_TESTF_CONSOLE_REC);
 324
 325/* Check denying based on category */
 326int log_test_cat_deny(struct unit_test_state *uts)
 327{
 328        int filt1, filt2;
 329        enum log_category_t cat_list[] = {
 330                log_uc_cat(UCLASS_SPI), LOGC_END
 331        };
 332
 333        filt1 = log_add_filter("console", cat_list, LOGL_MAX, NULL);
 334        ut_assert(filt1 >= 0);
 335        filt2 = log_add_filter_flags("console", cat_list, LOGL_MAX, NULL,
 336                                     LOGFF_DENY);
 337        ut_assert(filt2 >= 0);
 338
 339        ut_assertok(console_record_reset_enable());
 340        log_run_cat(UCLASS_SPI);
 341        check_log_entries_none();
 342
 343        ut_assertok(log_remove_filter("console", filt1));
 344        ut_assertok(log_remove_filter("console", filt2));
 345        return 0;
 346}
 347LOG_TEST_FLAGS(log_test_cat_deny, UT_TESTF_CONSOLE_REC);
 348
 349/* Check denying based on file */
 350int log_test_file_deny(struct unit_test_state *uts)
 351{
 352        int filt1, filt2;
 353
 354        filt1 = log_add_filter("console", NULL, LOGL_MAX, "file");
 355        ut_assert(filt1 >= 0);
 356        filt2 = log_add_filter_flags("console", NULL, LOGL_MAX, "file",
 357                                     LOGFF_DENY);
 358        ut_assert(filt2 >= 0);
 359
 360        ut_assertok(console_record_reset_enable());
 361        log_run_file("file");
 362        check_log_entries_none();
 363
 364        ut_assertok(log_remove_filter("console", filt1));
 365        ut_assertok(log_remove_filter("console", filt2));
 366        return 0;
 367}
 368LOG_TEST_FLAGS(log_test_file_deny, UT_TESTF_CONSOLE_REC);
 369
 370/* Check denying based on level */
 371int log_test_level_deny(struct unit_test_state *uts)
 372{
 373        int filt1, filt2;
 374
 375        filt1 = log_add_filter("console", NULL, LOGL_INFO, NULL);
 376        ut_assert(filt1 >= 0);
 377        filt2 = log_add_filter_flags("console", NULL, LOGL_WARNING, NULL,
 378                                     LOGFF_DENY);
 379        ut_assert(filt2 >= 0);
 380
 381        ut_assertok(console_record_reset_enable());
 382        log_run();
 383        check_log_entries_flags_levels(EXPECT_LOG | EXPECT_DIRECT | EXPECT_FORCE,
 384                                       LOGL_WARNING + 1,
 385                                       min(gd->default_log_level, LOGL_INFO));
 386
 387        ut_assertok(log_remove_filter("console", filt1));
 388        ut_assertok(log_remove_filter("console", filt2));
 389        return 0;
 390}
 391LOG_TEST_FLAGS(log_test_level_deny, UT_TESTF_CONSOLE_REC);
 392
 393/* Check matching based on minimum level */
 394int log_test_min(struct unit_test_state *uts)
 395{
 396        int filt1, filt2;
 397
 398        filt1 = log_add_filter_flags("console", NULL, LOGL_WARNING, NULL,
 399                                     LOGFF_LEVEL_MIN);
 400        ut_assert(filt1 >= 0);
 401        filt2 = log_add_filter_flags("console", NULL, LOGL_INFO, NULL,
 402                                     LOGFF_DENY | LOGFF_LEVEL_MIN);
 403        ut_assert(filt2 >= 0);
 404
 405        ut_assertok(console_record_reset_enable());
 406        log_run();
 407        check_log_entries_flags_levels(EXPECT_LOG | EXPECT_DIRECT | EXPECT_FORCE,
 408                                       LOGL_WARNING, LOGL_INFO - 1);
 409
 410        ut_assertok(log_remove_filter("console", filt1));
 411        ut_assertok(log_remove_filter("console", filt2));
 412        return 0;
 413}
 414LOG_TEST_FLAGS(log_test_min, UT_TESTF_CONSOLE_REC);
 415
 416/* Check dropped traces */
 417int log_test_dropped(struct unit_test_state *uts)
 418{
 419        /* force LOG not ready */
 420        gd->flags &= ~(GD_FLG_LOG_READY);
 421        gd->log_drop_count = 0;
 422
 423        ut_assertok(console_record_reset_enable());
 424
 425        log_run();
 426        ut_asserteq(2 * (LOGL_COUNT - LOGL_FIRST) +
 427                    _LOG_MAX_LEVEL - LOGL_FIRST + 1,
 428                    gd->log_drop_count);
 429        check_log_entries_flags_levels(EXPECT_DEBUG, LOGL_FIRST, CONFIG_LOG_DEFAULT_LEVEL);
 430
 431        gd->flags |= GD_FLG_LOG_READY;
 432        gd->log_drop_count = 0;
 433
 434        return 0;
 435}
 436LOG_TEST_FLAGS(log_test_dropped, UT_TESTF_CONSOLE_REC);
 437
 438/* Check log_buffer() */
 439int log_test_buffer(struct unit_test_state *uts)
 440{
 441        u8 *buf;
 442        int i;
 443
 444        buf = malloc(0x20);
 445        ut_assertnonnull(buf);
 446        memset(buf, '\0', 0x20);
 447        for (i = 0; i < 0x11; i++)
 448                buf[i] = i * 0x11;
 449
 450        ut_assertok(console_record_reset_enable());
 451        log_buffer(LOGC_BOOT, LOGL_INFO, 0, buf, 1, 0x12, 0);
 452
 453        /* This one should product no output due to the debug level */
 454        log_buffer(LOGC_BOOT, LOGL_DEBUG, 0, buf, 1, 0x12, 0);
 455
 456        ut_assert_nextline("00000000: 00 11 22 33 44 55 66 77 88 99 aa bb cc dd ee ff  ..\"3DUfw........");
 457        ut_assert_nextline("00000010: 10 00                                            ..");
 458        ut_assert_console_end();
 459        free(buf);
 460
 461        return 0;
 462}
 463LOG_TEST_FLAGS(log_test_buffer, UT_TESTF_CONSOLE_REC);
 464