[PATCH 0/5] rtc: Work around race conditions
This series includes some patches to work around race conditions in the rtc tests, as well as a mechanism to run unit tests more than once.
With 1000 runs I normally see three failures in the tests addressed here. With this series no failures are seen.
This also includes a work-around for the daylight-saving changeover.
Simon Glass (5): dm: rtc: Make use of ut_assertnonnull() test: Allow running tests multiple times dm: rtc: Avoid a race in the rtc_reset test dm: rtc: Try to avoid a race in rtc_set_get test dm: rtc: Try to handle the localtime() race
arch/sandbox/cpu/spl.c | 2 +- doc/develop/tests_sandbox.rst | 24 ++++++++++++++++ include/test/test.h | 2 ++ include/test/ut.h | 3 +- test/cmd_ut.c | 12 ++++++-- test/dm/rtc.c | 53 +++++++++++++++++++++++++---------- test/dm/test-dm.c | 13 +++++++-- test/test-main.c | 14 +++++++-- 8 files changed, 98 insertions(+), 25 deletions(-)
Use this (newish) macro since it is designed for the purpose of making sure things are non-NULL.
Signed-off-by: Simon Glass sjg@chromium.org ---
test/dm/rtc.c | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-)
diff --git a/test/dm/rtc.c b/test/dm/rtc.c index c7f9f8f0ce7..a8349756c18 100644 --- a/test/dm/rtc.c +++ b/test/dm/rtc.c @@ -66,7 +66,7 @@ static int dm_test_rtc_set_get(struct unit_test_state *uts) ut_assertok(dm_rtc_get(dev, &now));
ut_assertok(i2c_emul_find(dev, &emul)); - ut_assert(emul != NULL); + ut_assertnonnull(emul);
/* Tell the RTC to go into manual mode */ old_offset = sandbox_i2c_rtc_set_offset(emul, false, 0); @@ -161,7 +161,7 @@ static int dm_test_rtc_read_write(struct unit_test_state *uts) ut_asserteq(memcmp(buf, "at", 3), 0);
ut_assertok(i2c_emul_find(dev, &emul)); - ut_assert(emul != NULL); + ut_assertnonnull(emul);
old_offset = sandbox_i2c_rtc_set_offset(emul, false, 0); ut_assertok(dm_rtc_get(dev, &time)); @@ -245,7 +245,7 @@ static int dm_test_rtc_reset(struct unit_test_state *uts) ut_assertok(dm_rtc_get(dev, &now));
ut_assertok(i2c_emul_find(dev, &emul)); - ut_assert(emul != NULL); + ut_assertnonnull(emul);
old_base_time = sandbox_i2c_rtc_get_set_base_time(emul, 0);
@@ -274,9 +274,9 @@ static int dm_test_rtc_dual(struct unit_test_state *uts) ut_assertok(dm_rtc_get(dev2, &now2));
ut_assertok(i2c_emul_find(dev1, &emul1)); - ut_assert(emul1 != NULL); + ut_assertnonnull(emul1); ut_assertok(i2c_emul_find(dev2, &emul2)); - ut_assert(emul2 != NULL); + ut_assertnonnull(emul2);
offset = sandbox_i2c_rtc_set_offset(emul1, false, -1); sandbox_i2c_rtc_set_offset(emul2, false, offset + 1);
On Mon, Aug 01, 2022 at 07:58:44AM -0600, Simon Glass wrote:
Use this (newish) macro since it is designed for the purpose of making sure things are non-NULL.
Signed-off-by: Simon Glass sjg@chromium.org
For the series, applied to u-boot/next, thanks!
Some tests can have race conditions which are hard to detect on a single one. Add a way to run tests more than once, to help with this.
Each individual test is run the requested number of times before moving to the next test. If any runs failed, a message is shown.
This is most useful when running a single test, since running all tests multiple times can take a while.
Signed-off-by: Simon Glass sjg@chromium.org ---
arch/sandbox/cpu/spl.c | 2 +- doc/develop/tests_sandbox.rst | 24 ++++++++++++++++++++++++ include/test/test.h | 2 ++ include/test/ut.h | 3 ++- test/cmd_ut.c | 12 ++++++++++-- test/dm/test-dm.c | 13 ++++++++++--- test/test-main.c | 14 +++++++++++--- 7 files changed, 60 insertions(+), 10 deletions(-)
diff --git a/arch/sandbox/cpu/spl.c b/arch/sandbox/cpu/spl.c index fe5d44d36ed..1d49a9bd102 100644 --- a/arch/sandbox/cpu/spl.c +++ b/arch/sandbox/cpu/spl.c @@ -89,7 +89,7 @@ void spl_board_init(void) int ret;
ret = ut_run_list("spl", NULL, tests, count, - state->select_unittests); + state->select_unittests, 1); /* continue execution into U-Boot */ } } diff --git a/doc/develop/tests_sandbox.rst b/doc/develop/tests_sandbox.rst index 40cf8ecdd7f..8e42a32afb9 100644 --- a/doc/develop/tests_sandbox.rst +++ b/doc/develop/tests_sandbox.rst @@ -119,6 +119,30 @@ You can easily use gdb on these tests, without needing --gdbserver:: You can then single-step and look at variables as needed.
+Running tests multiple times +---------------------------- + +Some tests can have race conditions which are hard to detect on a single +one. It is possible to run each individual test multiple times, before moving +to the next test, with the '-r' flag. + +This is most useful when running a single test, since running all tests +multiple times can take a while. + +For example:: + + => ut dm -r1000 dm_test_rtc_set_get + ... + Test: dm_test_rtc_set_get: rtc.c (flat tree) + Test: dm_test_rtc_set_get: rtc.c + test/dm/rtc.c:257, dm_test_rtc_reset(): old_base_time == base_time: Expected 0x62e7453c (1659323708), got 0x62e7453d (1659323709) + Test: dm_test_rtc_set_get: rtc.c (flat tree) + Test: dm_test_rtc_set_get: rtc.c + Test: dm_test_rtc_set_get: rtc.c (flat tree) + ... + Test dm_test_rtc_reset failed 3 times + + Running sandbox_spl tests directly ----------------------------------
diff --git a/include/test/test.h b/include/test/test.h index 0104e189f63..66fece48b2a 100644 --- a/include/test/test.h +++ b/include/test/test.h @@ -20,6 +20,7 @@ * @testdev: Test device * @force_fail_alloc: Force all memory allocs to fail * @skip_post_probe: Skip uclass post-probe processing + * @runs_per_test: Number of times to run each test (typically 1) * @expect_str: Temporary string used to hold expected string value * @actual_str: Temporary string used to hold actual string value */ @@ -32,6 +33,7 @@ struct unit_test_state { struct udevice *testdev; int force_fail_alloc; int skip_post_probe; + int runs_per_test; char expect_str[512]; char actual_str[512]; }; diff --git a/include/test/ut.h b/include/test/ut.h index 18740f5807c..f7d1d18f7c1 100644 --- a/include/test/ut.h +++ b/include/test/ut.h @@ -403,9 +403,10 @@ void test_set_state(struct unit_test_state *uts); * @count: Number of tests to run * @select_name: Name of a single test to run (from the list provided). If NULL * then all tests are run + * @runs_per_test: Number of times to run each test (typically 1) * Return: 0 if all tests passed, -1 if any failed */ int ut_run_list(const char *name, const char *prefix, struct unit_test *tests, - int count, const char *select_name); + int count, const char *select_name, int runs_per_test);
#endif diff --git a/test/cmd_ut.c b/test/cmd_ut.c index 3789c6b784c..11c219b48ac 100644 --- a/test/cmd_ut.c +++ b/test/cmd_ut.c @@ -18,10 +18,17 @@ int cmd_ut_category(const char *name, const char *prefix, struct unit_test *tests, int n_ents, int argc, char *const argv[]) { + int runs_per_text = 1; int ret;
+ if (argc > 1 && !strncmp("-r", argv[1], 2)) { + runs_per_text = dectoul(argv[1] + 2, NULL); + argv++; + argc++; + } + ret = ut_run_list(name, prefix, tests, n_ents, - argc > 1 ? argv[1] : NULL); + argc > 1 ? argv[1] : NULL, runs_per_text);
return ret ? CMD_RET_FAILURE : 0; } @@ -168,7 +175,8 @@ static char ut_help_text[] = #ifdef CONFIG_CMD_LOADM "ut loadm [test-name]- test of parameters and load memory blob\n" #endif - ; + "All commands accept an optional [-r<runs>] flag before [test-name], to\n" + "run each test multiple times (<runs> is in decimal)"; #endif /* CONFIG_SYS_LONGHELP */
U_BOOT_CMD( diff --git a/test/dm/test-dm.c b/test/dm/test-dm.c index f5cda81bbfc..eb3581333b9 100644 --- a/test/dm/test-dm.c +++ b/test/dm/test-dm.c @@ -29,13 +29,14 @@ DECLARE_GLOBAL_DATA_PTR; * "fdt_pre_reloc"), or NULL to run all * Return: 0 if all tests passed, 1 if not */ -static int dm_test_run(const char *test_name) +static int dm_test_run(const char *test_name, int runs_per_text) { struct unit_test *tests = UNIT_TEST_SUITE_START(dm_test); const int n_ents = UNIT_TEST_SUITE_COUNT(dm_test); int ret;
- ret = ut_run_list("driver model", "dm_test_", tests, n_ents, test_name); + ret = ut_run_list("driver model", "dm_test_", tests, n_ents, test_name, + runs_per_text);
return ret ? CMD_RET_FAILURE : 0; } @@ -43,9 +44,15 @@ static int dm_test_run(const char *test_name) int do_ut_dm(struct cmd_tbl *cmdtp, int flag, int argc, char *const argv[]) { const char *test_name = NULL; + int runs_per_text = 1;
+ if (argc > 1 && !strncmp("-r", argv[1], 2)) { + runs_per_text = dectoul(argv[1] + 2, NULL); + argv++; + argc++; + } if (argc > 1) test_name = argv[1];
- return dm_test_run(test_name); + return dm_test_run(test_name, runs_per_text); } diff --git a/test/test-main.c b/test/test-main.c index ee38d1faea8..9b19f967499 100644 --- a/test/test-main.c +++ b/test/test-main.c @@ -387,11 +387,17 @@ static int ut_run_tests(struct unit_test_state *uts, const char *prefix,
for (test = tests; test < tests + count; test++) { const char *test_name = test->name; - int ret; + int ret, i, old_fail_count;
if (!test_matches(prefix, test_name, select_name)) continue; - ret = ut_run_test_live_flat(uts, test, select_name); + old_fail_count = uts->fail_count; + for (i = 0; i < uts->runs_per_test; i++) + ret = ut_run_test_live_flat(uts, test, select_name); + if (uts->fail_count != old_fail_count) { + printf("Test %s failed %d times\n", select_name, + uts->fail_count - old_fail_count); + } found++; if (ret == -EAGAIN) continue; @@ -405,7 +411,8 @@ static int ut_run_tests(struct unit_test_state *uts, const char *prefix, }
int ut_run_list(const char *category, const char *prefix, - struct unit_test *tests, int count, const char *select_name) + struct unit_test *tests, int count, const char *select_name, + int runs_per_test) { struct unit_test_state uts = { .fail_count = 0 }; bool has_dm_tests = false; @@ -429,6 +436,7 @@ int ut_run_list(const char *category, const char *prefix, printf("Running %d %s tests\n", count, category);
uts.of_root = gd_of_root(); + uts.runs_per_test = runs_per_test; ret = ut_run_tests(&uts, prefix, tests, count, select_name);
if (ret == -ENOENT)
Since resetting the RTC on sandbox causes it to read the base time from the system, we cannot rely on this being unchanged since it was last read. Allow for a one-second delay.
Reviewed-by: Heinrich Schuchardt heinrich.schuchardt@canonical.com Fixes: https://source.denx.de/u-boot/u-boot/-/issues/4 Reported-by: Bin Meng bmeng.cn@gmail.com Reported-by: Tom Rini trini@konsulko.com Suggested-by: Rasmus Villemoes rasmus.villemoes@prevas.dk Signed-off-by: Simon Glass sjg@chromium.org ---
test/dm/rtc.c | 9 +++++++-- 1 file changed, 7 insertions(+), 2 deletions(-)
diff --git a/test/dm/rtc.c b/test/dm/rtc.c index a8349756c18..e23905b3e2e 100644 --- a/test/dm/rtc.c +++ b/test/dm/rtc.c @@ -251,10 +251,15 @@ static int dm_test_rtc_reset(struct unit_test_state *uts)
ut_asserteq(0, sandbox_i2c_rtc_get_set_base_time(emul, -1));
- /* Resetting the RTC should put he base time back to normal */ + /* + * Resetting the RTC should put the base time back to normal. Allow for + * a one-second adjustment in case the time flips over while this + * test process is pre-empted, since reset_time() in i2c_rtc_emul.c + * reads the time from the OS. + */ ut_assertok(dm_rtc_reset(dev)); base_time = sandbox_i2c_rtc_get_set_base_time(emul, -1); - ut_asserteq(old_base_time, base_time); + ut_assert(base_time - old_base_time <= 1);
return 0; }
It seems that the time can change in between getting it and reading the offset. Check for this and try again if this happens.
Signed-off-by: Simon Glass sjg@chromium.org ---
test/dm/rtc.c | 22 +++++++++++++++++----- 1 file changed, 17 insertions(+), 5 deletions(-)
diff --git a/test/dm/rtc.c b/test/dm/rtc.c index e23905b3e2e..50086ffcf36 100644 --- a/test/dm/rtc.c +++ b/test/dm/rtc.c @@ -60,16 +60,27 @@ static int dm_test_rtc_set_get(struct unit_test_state *uts) { struct rtc_time now, time, cmp; struct udevice *dev, *emul; - long offset, old_offset, old_base_time; + long offset, check_offset, old_offset, old_base_time; + int i;
ut_assertok(uclass_get_device(UCLASS_RTC, 0, &dev)); - ut_assertok(dm_rtc_get(dev, &now));
ut_assertok(i2c_emul_find(dev, &emul)); ut_assertnonnull(emul);
- /* Tell the RTC to go into manual mode */ - old_offset = sandbox_i2c_rtc_set_offset(emul, false, 0); + /* Get the offset, putting the RTC into manual mode */ + i = 0; + do { + check_offset = sandbox_i2c_rtc_set_offset(emul, false, 0); + ut_assertok(dm_rtc_get(dev, &now)); + + /* Tell the RTC to go into manual mode */ + old_offset = sandbox_i2c_rtc_set_offset(emul, false, 0); + + /* If the times changed in that period, read it again */ + } while (++i < 2 && check_offset != old_offset); + ut_asserteq(check_offset, old_offset); + old_base_time = sandbox_i2c_rtc_get_set_base_time(emul, -1);
memset(&time, '\0', sizeof(time)); @@ -127,7 +138,8 @@ static int dm_test_rtc_set_get(struct unit_test_state *uts) ut_asserteq(now.tm_sec + 1, cmp.tm_sec); }
- old_offset = sandbox_i2c_rtc_set_offset(emul, true, 0); + /* return RTC to normal mode */ + sandbox_i2c_rtc_set_offset(emul, true, 0);
return 0; }
At present the sandbox timer uses localtime() which can jump around twice a year when daylight-saving time changes.
It would be tricky to make use of gmtime() since we still need to present the time in local time, as seems to be required by U-Boot's RTC interface.
The problem can only happen once, so use a loop to detect it and try again. This should be sufficient to detect either a change in the 'second' value, or a daylight-saving change. We can assume that the latter also incorporates a 'second' change, so there is no need to loop more than twice.
Signed-off-by: Simon Glass sjg@chromium.org ---
test/dm/rtc.c | 32 +++++++++++++++++++------------- 1 file changed, 19 insertions(+), 13 deletions(-)
diff --git a/test/dm/rtc.c b/test/dm/rtc.c index 50086ffcf36..bf97dbbd2f9 100644 --- a/test/dm/rtc.c +++ b/test/dm/rtc.c @@ -252,6 +252,7 @@ static int dm_test_rtc_reset(struct unit_test_state *uts) struct rtc_time now; struct udevice *dev, *emul; long old_base_time, base_time; + int i;
ut_assertok(uclass_get_device(UCLASS_RTC, 0, &dev)); ut_assertok(dm_rtc_get(dev, &now)); @@ -259,19 +260,24 @@ static int dm_test_rtc_reset(struct unit_test_state *uts) ut_assertok(i2c_emul_find(dev, &emul)); ut_assertnonnull(emul);
- old_base_time = sandbox_i2c_rtc_get_set_base_time(emul, 0); - - ut_asserteq(0, sandbox_i2c_rtc_get_set_base_time(emul, -1)); - - /* - * Resetting the RTC should put the base time back to normal. Allow for - * a one-second adjustment in case the time flips over while this - * test process is pre-empted, since reset_time() in i2c_rtc_emul.c - * reads the time from the OS. - */ - ut_assertok(dm_rtc_reset(dev)); - base_time = sandbox_i2c_rtc_get_set_base_time(emul, -1); - ut_assert(base_time - old_base_time <= 1); + i = 0; + do { + old_base_time = sandbox_i2c_rtc_get_set_base_time(emul, 0); + + ut_asserteq(0, sandbox_i2c_rtc_get_set_base_time(emul, -1)); + + ut_assertok(dm_rtc_reset(dev)); + base_time = sandbox_i2c_rtc_get_set_base_time(emul, -1); + + /* + * Resetting the RTC should put the base time back to normal. + * Allow for a one-timeadjustment in case the time flips over + * while this test process is pre-empted (either by a second + * or a daylight-saving change), since reset_time() in + * i2c_rtc_emul.c reads the time from the OS. + */ + } while (++i < 2 && base_time != old_base_time); + ut_asserteq(old_base_time, base_time);
return 0; }
On 8/1/22 15:58, Simon Glass wrote:
At present the sandbox timer uses localtime() which can jump around twice a year when daylight-saving time changes.
It would be tricky to make use of gmtime() since we still need to present the time in local time, as seems to be required by U-Boot's RTC interface.
The problem can only happen once, so use a loop to detect it and try again. This should be sufficient to detect either a change in the 'second' value, or a daylight-saving change. We can assume that the latter also incorporates a 'second' change, so there is no need to loop more than twice.
Signed-off-by: Simon Glass sjg@chromium.org
Linux systems tend to use UTC on the RTC. There is no reason for sandbox_defconfig to deviate. Please, avoid all this complication by reading the time with gmtime() instead of localtime().
Best regards
Heinrich
test/dm/rtc.c | 32 +++++++++++++++++++------------- 1 file changed, 19 insertions(+), 13 deletions(-)
diff --git a/test/dm/rtc.c b/test/dm/rtc.c index 50086ffcf36..bf97dbbd2f9 100644 --- a/test/dm/rtc.c +++ b/test/dm/rtc.c @@ -252,6 +252,7 @@ static int dm_test_rtc_reset(struct unit_test_state *uts) struct rtc_time now; struct udevice *dev, *emul; long old_base_time, base_time;
int i;
ut_assertok(uclass_get_device(UCLASS_RTC, 0, &dev)); ut_assertok(dm_rtc_get(dev, &now));
@@ -259,19 +260,24 @@ static int dm_test_rtc_reset(struct unit_test_state *uts) ut_assertok(i2c_emul_find(dev, &emul)); ut_assertnonnull(emul);
- old_base_time = sandbox_i2c_rtc_get_set_base_time(emul, 0);
- ut_asserteq(0, sandbox_i2c_rtc_get_set_base_time(emul, -1));
- /*
* Resetting the RTC should put the base time back to normal. Allow for* a one-second adjustment in case the time flips over while this* test process is pre-empted, since reset_time() in i2c_rtc_emul.c* reads the time from the OS.*/- ut_assertok(dm_rtc_reset(dev));
- base_time = sandbox_i2c_rtc_get_set_base_time(emul, -1);
- ut_assert(base_time - old_base_time <= 1);
i = 0;
do {
old_base_time = sandbox_i2c_rtc_get_set_base_time(emul, 0);ut_asserteq(0, sandbox_i2c_rtc_get_set_base_time(emul, -1));ut_assertok(dm_rtc_reset(dev));base_time = sandbox_i2c_rtc_get_set_base_time(emul, -1);/** Resetting the RTC should put the base time back to normal.* Allow for a one-timeadjustment in case the time flips over* while this test process is pre-empted (either by a second* or a daylight-saving change), since reset_time() in* i2c_rtc_emul.c reads the time from the OS.*/} while (++i < 2 && base_time != old_base_time);
ut_asserteq(old_base_time, base_time);
return 0; }
Hi Heinrich,
On Mon, 1 Aug 2022 at 09:00, Heinrich Schuchardt xypron.glpk@gmx.de wrote:
On 8/1/22 15:58, Simon Glass wrote:
At present the sandbox timer uses localtime() which can jump around twice a year when daylight-saving time changes.
It would be tricky to make use of gmtime() since we still need to present the time in local time, as seems to be required by U-Boot's RTC interface.
The problem can only happen once, so use a loop to detect it and try again. This should be sufficient to detect either a change in the 'second' value, or a daylight-saving change. We can assume that the latter also incorporates a 'second' change, so there is no need to loop more than twice.
Signed-off-by: Simon Glass sjg@chromium.org
Linux systems tend to use UTC on the RTC. There is no reason for sandbox_defconfig to deviate. Please, avoid all this complication by reading the time with gmtime() instead of localtime().
That is an API change...how will we show the local time in that case? I suppose we need to add this concept to rtc.h ?
Regards, Simon
participants (3)
-
Heinrich Schuchardt -
Simon Glass -
Tom Rini