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