log_test.c 12 KB

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