Merge patch series "Tidy up console recording in tests"

Simon Glass <[email protected]> says:

This series started as a small fix for checking for an empty line,
but in the process several other problems were found and fixed:

- fix tests which use console recording but don't set the flag
- drop unnecessary resetting of the console in tests
- drop unnecessary blank line before MMC output
- update the docs a little
- fix buildman test failure on newer Pythons
- a few other minor things

This series also renames the confusing flag names, so that they are
easier to remember - just a UTF_ (unit-test flags) prefix.

6 files changed, 31 insertions, 64 deletions

diff --git a/test/log/cont_test.c b/test/log/cont_test.c
index 036d44b9d73..32b1c792367 100644
--- a/test/log/cont_test.c
+++ b/test/log/cont_test.c
@@ -25,7 +25,6 @@ static int log_test_cont(struct unit_test_state *uts)
 	/* Write two messages, the second continuing the first */
 	gd->log_fmt = (1 << LOGF_CAT) | (1 << LOGF_LEVEL) | (1 << LOGF_MSG);
 	gd->default_log_level = LOGL_INFO;
-	console_record_reset_enable();
 	log(LOGC_ARCH, LOGL_ERR, "ea%d\n", 1);
 	log(LOGC_CONT, LOGL_CONT, "cc%d\n", 2);
 	gd->default_log_level = log_level;
@@ -33,7 +32,7 @@ static int log_test_cont(struct unit_test_state *uts)
 	gd->flags &= ~GD_FLG_RECORD;
 	ut_assertok(ut_check_console_line(uts, "ERR.arch, ea1"));
 	ut_assertok(ut_check_console_line(uts, "ERR.arch, cc2"));
-	ut_assertok(ut_check_console_end(uts));
+	ut_assert_console_end();
 
 	/* Write a third message which is not a continuation */
 	gd->log_fmt = (1 << LOGF_CAT) | (1 << LOGF_LEVEL) | (1 << LOGF_MSG);
@@ -44,7 +43,7 @@ static int log_test_cont(struct unit_test_state *uts)
 	gd->log_fmt = log_fmt;
 	gd->flags &= ~GD_FLG_RECORD;
 	ut_assertok(ut_check_console_line(uts, "INFO.efi, ie3"));
-	ut_assertok(ut_check_console_end(uts));
+	ut_assert_console_end();
 
 	/* Write two messages without a newline between them */
 	gd->log_fmt = (1 << LOGF_CAT) | (1 << LOGF_LEVEL) | (1 << LOGF_MSG);
@@ -56,7 +55,7 @@ static int log_test_cont(struct unit_test_state *uts)
 	gd->log_fmt = log_fmt;
 	gd->flags &= ~GD_FLG_RECORD;
 	ut_assertok(ut_check_console_line(uts, "ERR.arch, ea1 cc2"));
-	ut_assertok(ut_check_console_end(uts));
+	ut_assert_console_end();
 
 	return 0;
 }
diff --git a/test/log/log_filter.c b/test/log/log_filter.c
index 9cc891dc48c..d36e9d9714e 100644
--- a/test/log/log_filter.c
+++ b/test/log/log_filter.c
@@ -24,7 +24,7 @@ static int log_test_filter_invalid(struct unit_test_state *uts)
 
 	return 0;
 }
-LOG_TEST_FLAGS(log_test_filter_invalid, UT_TESTF_CONSOLE_REC);
+LOG_TEST_FLAGS(log_test_filter_invalid, UTF_CONSOLE);
 
 /* Test adding and removing filters */
 static int log_test_filter(struct unit_test_state *uts)
@@ -38,7 +38,6 @@ static int log_test_filter(struct unit_test_state *uts)
 	ulong filt1, filt2;
 
 #define create_filter(args, filter_num) do {\
-	ut_assertok(console_record_reset_enable()); \
 	ut_assertok(run_command("log filter-add -p " args, 0)); \
 	ut_assert_skipline(); \
 	ut_assertok(strict_strtoul(uts->actual_str, 10, &(filter_num))); \
@@ -72,7 +71,6 @@ static int log_test_filter(struct unit_test_state *uts)
 	ut_asserteq(true, filt2_found);
 
 #define remove_filter(filter_num) do { \
-	ut_assertok(console_record_reset_enable()); \
 	snprintf(cmd, sizeof(cmd), "log filter-remove %lu", filter_num); \
 	ut_assertok(run_command(cmd, 0)); \
 	ut_assert_console_end(); \
@@ -95,7 +93,6 @@ static int log_test_filter(struct unit_test_state *uts)
 	create_filter("", filt1);
 	create_filter("", filt2);
 
-	ut_assertok(console_record_reset_enable());
 	ut_assertok(run_command("log filter-remove -a", 0));
 	ut_assert_console_end();
 
@@ -105,4 +102,4 @@ static int log_test_filter(struct unit_test_state *uts)
 
 	return 0;
 }
-LOG_TEST_FLAGS(log_test_filter, UT_TESTF_CONSOLE_REC);
+LOG_TEST_FLAGS(log_test_filter, UTF_CONSOLE);
diff --git a/test/log/log_test.c b/test/log/log_test.c
index 18f8a2d9391..1c89df4ef18 100644
--- a/test/log/log_test.c
+++ b/test/log/log_test.c
@@ -110,18 +110,16 @@ int log_test_cat_allow(struct unit_test_state *uts)
 	filt = log_add_filter("console", cat_list, LOGL_MAX, NULL);
 	ut_assert(filt >= 0);
 
-	ut_assertok(console_record_reset_enable());
 	log_run_cat(UCLASS_MMC);
 	check_log_entries_extra();
 
-	ut_assertok(console_record_reset_enable());
 	log_run_cat(UCLASS_SPI);
 	check_log_entries_extra();
 
 	ut_assertok(log_remove_filter("console", filt));
 	return 0;
 }
-LOG_TEST_FLAGS(log_test_cat_allow, UT_TESTF_CONSOLE_REC);
+LOG_TEST_FLAGS(log_test_cat_allow, UTF_CONSOLE);
 
 /* Check a category filter that should block log entries */
 int log_test_cat_deny_implicit(struct unit_test_state *uts)
@@ -134,14 +132,13 @@ int log_test_cat_deny_implicit(struct unit_test_state *uts)
 	filt = log_add_filter("console", cat_list, LOGL_MAX, NULL);
 	ut_assert(filt >= 0);
 
-	ut_assertok(console_record_reset_enable());
 	log_run_cat(UCLASS_SPI);
 	check_log_entries_none();
 
 	ut_assertok(log_remove_filter("console", filt));
 	return 0;
 }
-LOG_TEST_FLAGS(log_test_cat_deny_implicit, UT_TESTF_CONSOLE_REC);
+LOG_TEST_FLAGS(log_test_cat_deny_implicit, UTF_CONSOLE);
 
 /* Check passing and failing file filters */
 int log_test_file(struct unit_test_state *uts)
@@ -151,18 +148,16 @@ int log_test_file(struct unit_test_state *uts)
 	filt = log_add_filter("console", NULL, LOGL_MAX, "file");
 	ut_assert(filt >= 0);
 
-	ut_assertok(console_record_reset_enable());
 	log_run_file("file");
 	check_log_entries_flags(EXPECT_DIRECT | EXPECT_EXTRA | EXPECT_FORCE);
 
-	ut_assertok(console_record_reset_enable());
 	log_run_file("file2");
 	check_log_entries_none();
 
 	ut_assertok(log_remove_filter("console", filt));
 	return 0;
 }
-LOG_TEST_FLAGS(log_test_file, UT_TESTF_CONSOLE_REC);
+LOG_TEST_FLAGS(log_test_file, UTF_CONSOLE);
 
 /* Check a passing file filter (second in list) */
 int log_test_file_second(struct unit_test_state *uts)
@@ -172,14 +167,13 @@ int log_test_file_second(struct unit_test_state *uts)
 	filt = log_add_filter("console", NULL, LOGL_MAX, "file,file2");
 	ut_assert(filt >= 0);
 
-	ut_assertok(console_record_reset_enable());
 	log_run_file("file2");
 	check_log_entries_flags(EXPECT_DIRECT | EXPECT_EXTRA | EXPECT_FORCE);
 
 	ut_assertok(log_remove_filter("console", filt));
 	return 0;
 }
-LOG_TEST_FLAGS(log_test_file_second, UT_TESTF_CONSOLE_REC);
+LOG_TEST_FLAGS(log_test_file_second, UTF_CONSOLE);
 
 /* Check a passing file filter (middle of list) */
 int log_test_file_mid(struct unit_test_state *uts)
@@ -190,14 +184,13 @@ int log_test_file_mid(struct unit_test_state *uts)
 			      "file,file2,log/log_test.c");
 	ut_assert(filt >= 0);
 
-	ut_assertok(console_record_reset_enable());
 	log_run_file("file2");
 	check_log_entries_extra();
 
 	ut_assertok(log_remove_filter("console", filt));
 	return 0;
 }
-LOG_TEST_FLAGS(log_test_file_mid, UT_TESTF_CONSOLE_REC);
+LOG_TEST_FLAGS(log_test_file_mid, UTF_CONSOLE);
 
 /* Check a log level filter */
 int log_test_level(struct unit_test_state *uts)
@@ -207,7 +200,6 @@ int log_test_level(struct unit_test_state *uts)
 	filt = log_add_filter("console", NULL, LOGL_WARNING, NULL);
 	ut_assert(filt >= 0);
 
-	ut_assertok(console_record_reset_enable());
 	log_run();
 	check_log_entries_flags_levels(EXPECT_LOG | EXPECT_DIRECT | EXPECT_FORCE,
 				       LOGL_FIRST, LOGL_WARNING);
@@ -215,7 +207,7 @@ int log_test_level(struct unit_test_state *uts)
 	ut_assertok(log_remove_filter("console", filt));
 	return 0;
 }
-LOG_TEST_FLAGS(log_test_level, UT_TESTF_CONSOLE_REC);
+LOG_TEST_FLAGS(log_test_level, UTF_CONSOLE);
 
 /* Check two filters, one of which passes everything */
 int log_test_double(struct unit_test_state *uts)
@@ -227,7 +219,6 @@ int log_test_double(struct unit_test_state *uts)
 	filt2 = log_add_filter("console", NULL, LOGL_MAX, NULL);
 	ut_assert(filt2 >= 0);
 
-	ut_assertok(console_record_reset_enable());
 	log_run();
 	check_log_entries_extra();
 
@@ -235,7 +226,7 @@ int log_test_double(struct unit_test_state *uts)
 	ut_assertok(log_remove_filter("console", filt2));
 	return 0;
 }
-LOG_TEST_FLAGS(log_test_double, UT_TESTF_CONSOLE_REC);
+LOG_TEST_FLAGS(log_test_double, UTF_CONSOLE);
 
 /* Check three filters, which together pass everything */
 int log_test_triple(struct unit_test_state *uts)
@@ -249,7 +240,6 @@ int log_test_triple(struct unit_test_state *uts)
 	filt3 = log_add_filter("console", NULL, LOGL_MAX, "log/log_test.c");
 	ut_assert(filt3 >= 0);
 
-	ut_assertok(console_record_reset_enable());
 	log_run_file("file2");
 	check_log_entries_extra();
 
@@ -258,13 +248,12 @@ int log_test_triple(struct unit_test_state *uts)
 	ut_assertok(log_remove_filter("console", filt3));
 	return 0;
 }
-LOG_TEST_FLAGS(log_test_triple, UT_TESTF_CONSOLE_REC);
+LOG_TEST_FLAGS(log_test_triple, UTF_CONSOLE);
 
 int do_log_test_helpers(struct unit_test_state *uts)
 {
 	int i;
 
-	ut_assertok(console_record_reset_enable());
 	log_err("level %d\n", LOGL_EMERG);
 	log_err("level %d\n", LOGL_ALERT);
 	log_err("level %d\n", LOGL_CRIT);
@@ -292,11 +281,10 @@ int log_test_helpers(struct unit_test_state *uts)
 	gd->log_fmt = log_get_default_format();
 	return ret;
 }
-LOG_TEST_FLAGS(log_test_helpers, UT_TESTF_CONSOLE_REC);
+LOG_TEST_FLAGS(log_test_helpers, UTF_CONSOLE);
 
 int do_log_test_disable(struct unit_test_state *uts)
 {
-	ut_assertok(console_record_reset_enable());
 	log_err("default\n");
 	ut_assert_nextline("%*s() default", CONFIG_LOGF_FUNC_PAD, __func__);
 
@@ -319,7 +307,7 @@ int log_test_disable(struct unit_test_state *uts)
 	gd->log_fmt = log_get_default_format();
 	return ret;
 }
-LOG_TEST_FLAGS(log_test_disable, UT_TESTF_CONSOLE_REC);
+LOG_TEST_FLAGS(log_test_disable, UTF_CONSOLE);
 
 /* Check denying based on category */
 int log_test_cat_deny(struct unit_test_state *uts)
@@ -335,7 +323,6 @@ int log_test_cat_deny(struct unit_test_state *uts)
 				     LOGFF_DENY);
 	ut_assert(filt2 >= 0);
 
-	ut_assertok(console_record_reset_enable());
 	log_run_cat(UCLASS_SPI);
 	check_log_entries_none();
 
@@ -343,7 +330,7 @@ int log_test_cat_deny(struct unit_test_state *uts)
 	ut_assertok(log_remove_filter("console", filt2));
 	return 0;
 }
-LOG_TEST_FLAGS(log_test_cat_deny, UT_TESTF_CONSOLE_REC);
+LOG_TEST_FLAGS(log_test_cat_deny, UTF_CONSOLE);
 
 /* Check denying based on file */
 int log_test_file_deny(struct unit_test_state *uts)
@@ -356,7 +343,6 @@ int log_test_file_deny(struct unit_test_state *uts)
 				     LOGFF_DENY);
 	ut_assert(filt2 >= 0);
 
-	ut_assertok(console_record_reset_enable());
 	log_run_file("file");
 	check_log_entries_none();
 
@@ -364,7 +350,7 @@ int log_test_file_deny(struct unit_test_state *uts)
 	ut_assertok(log_remove_filter("console", filt2));
 	return 0;
 }
-LOG_TEST_FLAGS(log_test_file_deny, UT_TESTF_CONSOLE_REC);
+LOG_TEST_FLAGS(log_test_file_deny, UTF_CONSOLE);
 
 /* Check denying based on level */
 int log_test_level_deny(struct unit_test_state *uts)
@@ -377,7 +363,6 @@ int log_test_level_deny(struct unit_test_state *uts)
 				     LOGFF_DENY);
 	ut_assert(filt2 >= 0);
 
-	ut_assertok(console_record_reset_enable());
 	log_run();
 	check_log_entries_flags_levels(
 		EXPECT_LOG | EXPECT_DIRECT | EXPECT_FORCE,
@@ -387,7 +372,7 @@ int log_test_level_deny(struct unit_test_state *uts)
 	ut_assertok(log_remove_filter("console", filt2));
 	return 0;
 }
-LOG_TEST_FLAGS(log_test_level_deny, UT_TESTF_CONSOLE_REC);
+LOG_TEST_FLAGS(log_test_level_deny, UTF_CONSOLE);
 
 /* Check matching based on minimum level */
 int log_test_min(struct unit_test_state *uts)
@@ -401,7 +386,6 @@ int log_test_min(struct unit_test_state *uts)
 				     LOGFF_DENY | LOGFF_LEVEL_MIN);
 	ut_assert(filt2 >= 0);
 
-	ut_assertok(console_record_reset_enable());
 	log_run();
 	check_log_entries_flags_levels(EXPECT_LOG | EXPECT_DIRECT | EXPECT_FORCE,
 				       LOGL_WARNING, LOGL_INFO - 1);
@@ -410,7 +394,7 @@ int log_test_min(struct unit_test_state *uts)
 	ut_assertok(log_remove_filter("console", filt2));
 	return 0;
 }
-LOG_TEST_FLAGS(log_test_min, UT_TESTF_CONSOLE_REC);
+LOG_TEST_FLAGS(log_test_min, UTF_CONSOLE);
 
 /* Check dropped traces */
 int log_test_dropped(struct unit_test_state *uts)
@@ -419,8 +403,6 @@ int log_test_dropped(struct unit_test_state *uts)
 	gd->flags &= ~(GD_FLG_LOG_READY);
 	gd->log_drop_count = 0;
 
-	ut_assertok(console_record_reset_enable());
-
 	log_run();
 	ut_asserteq(2 * (LOGL_COUNT - LOGL_FIRST) +
 		    _LOG_MAX_LEVEL - LOGL_FIRST + 1,
@@ -432,7 +414,7 @@ int log_test_dropped(struct unit_test_state *uts)
 
 	return 0;
 }
-LOG_TEST_FLAGS(log_test_dropped, UT_TESTF_CONSOLE_REC);
+LOG_TEST_FLAGS(log_test_dropped, UTF_CONSOLE);
 
 /* Check log_buffer() */
 int log_test_buffer(struct unit_test_state *uts)
@@ -446,7 +428,6 @@ int log_test_buffer(struct unit_test_state *uts)
 	for (i = 0; i < 0x11; i++)
 		buf[i] = i * 0x11;
 
-	ut_assertok(console_record_reset_enable());
 	log_buffer(LOGC_BOOT, LOGL_INFO, 0, buf, 1, 0x12, 0);
 
 	/* This one should product no output due to the debug level */
@@ -461,4 +442,4 @@ int log_test_buffer(struct unit_test_state *uts)
 
 	return 0;
 }
-LOG_TEST_FLAGS(log_test_buffer, UT_TESTF_CONSOLE_REC);
+LOG_TEST_FLAGS(log_test_buffer, UTF_CONSOLE);
diff --git a/test/log/nolog_ndebug.c b/test/log/nolog_ndebug.c
index b714a16d2e7..4dc0f2d3a33 100644
--- a/test/log/nolog_ndebug.c
+++ b/test/log/nolog_ndebug.c
@@ -21,7 +21,6 @@ static int log_test_log_disabled_ndebug(struct unit_test_state *uts)
 	int i;
 
 	memset(buf, 0, BUFFSIZE);
-	console_record_reset_enable();
 
 	/* Output a log record at every level */
 	for (i = LOGL_EMERG; i < LOGL_COUNT; i++)
@@ -31,7 +30,7 @@ static int log_test_log_disabled_ndebug(struct unit_test_state *uts)
 	/* Since DEBUG is not defined, we expect to not get debug output */
 	for (i = LOGL_EMERG; i < LOGL_DEBUG; i++)
 		ut_assertok(ut_check_console_line(uts, "testing level %d", i));
-	ut_assertok(ut_check_console_end(uts));
+	ut_assert_console_end();
 
 	return 0;
 }
diff --git a/test/log/nolog_test.c b/test/log/nolog_test.c
index c4c0fa6cf81..341dbfc9310 100644
--- a/test/log/nolog_test.c
+++ b/test/log/nolog_test.c
@@ -25,11 +25,10 @@ static int log_test_nolog_err(struct unit_test_state *uts)
 	char buf[BUFFSIZE];
 
 	memset(buf, 0, BUFFSIZE);
-	console_record_reset_enable();
 	log_err("testing %s\n", "log_err");
 	gd->flags &= ~GD_FLG_RECORD;
 	ut_assertok(ut_check_console_line(uts, "testing log_err"));
-	ut_assertok(ut_check_console_end(uts));
+	ut_assert_console_end();
 	return 0;
 }
 LOG_TEST(log_test_nolog_err);
@@ -39,11 +38,10 @@ static int log_test_nolog_warning(struct unit_test_state *uts)
 	char buf[BUFFSIZE];
 
 	memset(buf, 0, BUFFSIZE);
-	console_record_reset_enable();
 	log_warning("testing %s\n", "log_warning");
 	gd->flags &= ~GD_FLG_RECORD;
 	ut_assertok(ut_check_console_line(uts, "testing log_warning"));
-	ut_assertok(ut_check_console_end(uts));
+	ut_assert_console_end();
 	return 0;
 }
 LOG_TEST(log_test_nolog_warning);
@@ -53,11 +51,10 @@ static int log_test_nolog_notice(struct unit_test_state *uts)
 	char buf[BUFFSIZE];
 
 	memset(buf, 0, BUFFSIZE);
-	console_record_reset_enable();
 	log_notice("testing %s\n", "log_notice");
 	gd->flags &= ~GD_FLG_RECORD;
 	ut_assertok(ut_check_console_line(uts, "testing log_notice"));
-	ut_assertok(ut_check_console_end(uts));
+	ut_assert_console_end();
 	return 0;
 }
 LOG_TEST(log_test_nolog_notice);
@@ -67,11 +64,10 @@ static int log_test_nolog_info(struct unit_test_state *uts)
 	char buf[BUFFSIZE];
 
 	memset(buf, 0, BUFFSIZE);
-	console_record_reset_enable();
 	log_err("testing %s\n", "log_info");
 	gd->flags &= ~GD_FLG_RECORD;
 	ut_assertok(ut_check_console_line(uts, "testing log_info"));
-	ut_assertok(ut_check_console_end(uts));
+	ut_assert_console_end();
 	return 0;
 }
 LOG_TEST(log_test_nolog_info);
@@ -83,10 +79,9 @@ static int nolog_test_nodebug(struct unit_test_state *uts)
 	char buf[BUFFSIZE];
 
 	memset(buf, 0, BUFFSIZE);
-	console_record_reset_enable();
 	debug("testing %s\n", "debug");
 	gd->flags &= ~GD_FLG_RECORD;
-	ut_assertok(ut_check_console_end(uts));
+	ut_assert_console_end();
 	return 0;
 }
 LOG_TEST(nolog_test_nodebug);
@@ -96,11 +91,10 @@ static int log_test_nolog_nodebug(struct unit_test_state *uts)
 	char buf[BUFFSIZE];
 
 	memset(buf, 0, BUFFSIZE);
-	console_record_reset_enable();
 	log_debug("testing %s\n", "log_debug");
 	gd->flags &= ~GD_FLG_RECORD;
 	ut_assert(!strcmp(buf, ""));
-	ut_assertok(ut_check_console_end(uts));
+	ut_assert_console_end();
 	return 0;
 }
 LOG_TEST(log_test_nolog_nodebug);
@@ -112,11 +106,10 @@ static int nolog_test_debug(struct unit_test_state *uts)
 	char buf[BUFFSIZE];
 
 	memset(buf, 0, BUFFSIZE);
-	console_record_reset_enable();
 	debug("testing %s\n", "debug");
 	gd->flags &= ~GD_FLG_RECORD;
 	ut_assertok(ut_check_console_line(uts, "testing debug"));
-	ut_assertok(ut_check_console_end(uts));
+	ut_assert_console_end();
 	return 0;
 }
 LOG_TEST(nolog_test_debug);
@@ -126,13 +119,12 @@ static int log_test_nolog_debug(struct unit_test_state *uts)
 	char buf[BUFFSIZE];
 
 	memset(buf, 0, BUFFSIZE);
-	console_record_reset_enable();
 	log_debug("testing %s\n", "log_debug");
 	log(LOGC_NONE, LOGL_DEBUG, "more %s\n", "log_debug");
 	gd->flags &= ~GD_FLG_RECORD;
 	ut_assertok(ut_check_console_line(uts, "testing log_debug"));
 	ut_assertok(ut_check_console_line(uts, "more log_debug"));
-	ut_assertok(ut_check_console_end(uts));
+	ut_assert_console_end();
 	return 0;
 }
 LOG_TEST(log_test_nolog_debug);
diff --git a/test/log/pr_cont_test.c b/test/log/pr_cont_test.c
index 30f30d98fe1..7734e927f98 100644
--- a/test/log/pr_cont_test.c
+++ b/test/log/pr_cont_test.c
@@ -28,14 +28,13 @@ static int log_test_pr_cont(struct unit_test_state *uts)
 	/* Write two messages, the second continuing the first */
 	gd->log_fmt = BIT(LOGF_MSG);
 	gd->default_log_level = LOGL_INFO;
-	console_record_reset_enable();
 	pr_err("ea%d ", 1);
 	pr_cont("cc%d\n", 2);
 	gd->default_log_level = log_level;
 	gd->log_fmt = log_fmt;
 	gd->flags &= ~GD_FLG_RECORD;
 	ut_assertok(ut_check_console_line(uts, "ea1 cc2"));
-	ut_assertok(ut_check_console_end(uts));
+	ut_assert_console_end();
 
 	return 0;
 }