selftests: rtc: fix flaky date_read_loop test
Subsystems (2)
PATCH RESEND 1/1 selftests: rtc: fix flaky date_read_loop test
The test case rtc.date_read_loop in rtctest.c fails intermittently because it checks that the RTC time does not advance by more than 1 second per loop iteration. However, the loop sleeps for 11ms via nanosleep(), and if the test thread is descheduled by the OS scheduler (e.g., under heavy system load in a VM), more than 1 second can elapse between consecutive RTC reads. This causes the next RTC time read to be 2 or more seconds ahead of the previous read, triggering a test assertion failure.
To make the test more resilient against OS scheduling delays, measure the real elapsed time between iterations using a monotonic clock (clock_gettime(CLOCK_MONOTONIC)), and compute the actual number of seconds elapsed (delta_s) between consecutive RTC reads. Then dynamically adjust the assertion to:ASSERT_GE(prev_rtc_read + delta_s + 1, rtc_read);
---
Hi Shuah, Alexandre,
This is a resend of a patch that has been Acked by the RTC maintainer but does not seem to have been picked up by either tree yet:
https://lore.kernel.org/all/[email protected]/
It applies cleanly on top of current mainline. No code changes since the original posting; I have only folded in Alexandre's Acked-by.
Since tools/testing/selftests/rtc/ is listed under both the RTC subsystem and the kselftest framework in MAINTAINERS, could either Shuah (via the kselftest tree) or Alexandre (via the rtc tree) please pick it up? I'm happy to go with whichever tree you both prefer.
We are still seeing this test fail intermittently in Android VTS (about 15-18% of runs on some devices), so it would be great to get this merged.
Thanks,
Wake
tools/testing/selftests/rtc/rtctest.c | 11 +++++++++-- 1 file changed, 9 insertions(+), 2 deletions(-)
tools/testing/selftests/rtc/rtctest.c +9 -2
@@ -116,6 +116,7 @@ TEST_F_TIMEOUT(rtc, date_read_loop, READ_LOOP_DURATION_SEC + 2) {long iter_count =0 ;struct rtc_time rtc_tm;time_t start_rtc_read, prev_rtc_read; +struct timespec prev_mono, cur_mono;if (self->fd ==-1 && errno ==ENOENT )SKIP (return,"Skipping test since %s does not exist" , rtc_file);
@@ -126,25 +127,31 @@ TEST_F_TIMEOUT(rtc, date_read_loop, READ_LOOP_DURATION_SEC + 2) { rc =ioctl (self->fd,RTC_RD_TIME , &rtc_tm);ASSERT_NE (-1 , rc); +clock_gettime (CLOCK_MONOTONIC , &prev_mono); start_rtc_read =rtc_time_to_timestamp (&rtc_tm); prev_rtc_read = start_rtc_read;do {time_t rtc_read; +time_t delta_s =0 ; rc =ioctl (self->fd,RTC_RD_TIME , &rtc_tm);ASSERT_NE (-1 , rc); +clock_gettime (CLOCK_MONOTONIC , &cur_mono); rtc_read =rtc_time_to_timestamp (&rtc_tm); + delta_s = cur_mono.tv_sec - prev_mono.tv_sec; +/* Time should not go backwards */ ASSERT_LE (prev_rtc_read, rtc_read); -/* Time should not increase more then 1s at a time */ -ASSERT_GE (prev_rtc_read +1 , rtc_read); +/* Time should not increase more then elapsed time + 1s */ +ASSERT_GE (prev_rtc_read + delta_s +1 , rtc_read);/* Sleep 11ms to avoid killing / overheating the RTC */ nanosleep_with_retries (READ_LOOP_SLEEP_MS *1000000 ); prev_rtc_read = rtc_read; + prev_mono = cur_mono; iter_count++; }while (prev_rtc_read <= start_rtc_read +READ_LOOP_DURATION_SEC );
Signature · 1 line
2.56.0.rc1.315.gc6ed9934b7-goog
[email protected]
AI reviewThank you for your contribution! Sashiko AI review found 2 potential issue(s) to consider: - [Medium] selftests: rtc: preemption race between ioctl and clock_gettime - [Medium] selftests: rtc…
Thank you for your contribution! Sashiko AI review found 2 potential issue(s) to consider:
- [Medium] selftests: rtc: preemption race between ioctl and clock_gettime
- [Medium] selftests: rtc: CLOCK_MONOTONIC does not account for system suspend --
commit 470d20b138e75cc7483b890fe5b4c4fbcf96a62c
Author: Wake Liu <[email protected]>
selftests: rtc: fix flaky date_read_loop test
This commit modifies the rtc.date_read_loop test to measure real elapsed time between iterations using CLOCK_MONOTONIC. It then dynamically adjusts the test assertion to make the test more resilient against OS scheduling delays.
Quoted 4 lines
tools/testing/selftests/rtc/rtctest.c +0
-0
[ ... ]
tools/testing/selftests/rtc/rtctest.c TEST_F_TIMEOUT(rtc, date_read_loop, READ_LOOP_DURATION_SEC + 2) { · line 130
Quoted 5 lines
tools/testing/selftests/rtc/rtctest.c +1
-0@@ -126,25 +127,31 @@ TEST_F_TIMEOUT(rtc, date_read_loop, READ_LOOP_DURATION_SEC + 2) { rc =ioctl (self->fd,RTC_RD_TIME , &rtc_tm);ASSERT_NE (-1 , rc); +clock_gettime (CLOCK_MONOTONIC , &prev_mono);
[Severity: Medium]
Does CLOCK_MONOTONIC adequately account for system suspend in this test?
Since CLOCK_MONOTONIC stops incrementing during suspend while the hardware RTC continues ticking, if the system suspends during the sleep loop, could the RTC advance significantly without delta_s reflecting it?
Would using CLOCK_BOOTTIME avoid this regression and correctly track elapsed time across suspends?
tools/testing/selftests/rtc/rtctest.c TEST_F_TIMEOUT(rtc, date_read_loop, READ_LOOP_DURATION_SEC + 2) { · line 140
Quoted 10 lines
tools/testing/selftests/rtc/rtctest.c +2
-0start_rtc_read =rtc_time_to_timestamp (&rtc_tm); prev_rtc_read = start_rtc_read; do { time_t rtc_read; + time_t delta_s = 0; rc = ioctl(self->fd, RTC_RD_TIME, &rtc_tm); ASSERT_NE(-1, rc); + clock_gettime(CLOCK_MONOTONIC, &cur_mono);
[Severity: Medium]
Could a preemption between the ioctl() and clock_gettime() calls cause spurious assertion failures?
If the thread is preempted immediately after ioctl(RTC_RD_TIME) in iteration N, cur_mono will be delayed. When this delayed cur_mono is assigned to prev_mono for iteration N+1, it artificially shrinks the measured delta_s for the next iteration.
Could this make delta_s smaller than the actual elapsed RTC time, causing the assertion below to fail?
Quoted 19 lines
tools/testing/selftests/rtc/rtctest.c +5
-2rtc_read =rtc_time_to_timestamp (&rtc_tm); + delta_s = cur_mono.tv_sec - prev_mono.tv_sec; +/* Time should not go backwards */ ASSERT_LE (prev_rtc_read, rtc_read); -/* Time should not increase more then 1s at a time */ -ASSERT_GE (prev_rtc_read +1 , rtc_read); +/* Time should not increase more then elapsed time + 1s */ +ASSERT_GE (prev_rtc_read + delta_s +1 , rtc_read);/* Sleep 11ms to avoid killing / overheating the RTC */ nanosleep_with_retries (READ_LOOP_SLEEP_MS *1000000 ); prev_rtc_read = rtc_read; + prev_mono = cur_mono; iter_count++; }while (prev_rtc_read <= start_rtc_read +READ_LOOP_DURATION_SEC );
Signature · 1 line
Sashiko AI review · https://sashiko.dev/#/patchset/[email protected]?part=1
Quoted 9 lines · Wake Liu
The test case rtc.date_read_loop in
rtctest.cfails intermittently because it checks that the RTC time does not advance by more than 1 second per loop iteration. However, the loop sleeps for 11ms viananosleep(), and if the test thread is descheduled by the OS scheduler (e.g., under heavy system load in a VM), more than 1 second can elapse between consecutive RTC reads. This causes the next RTC time read to be 2 or more seconds ahead of the previous read, triggering a test assertion failure.[...]
Applied, thanks!
[1/1] selftests: rtc: fix flaky date_read_loop test
https://git.kernel.org/abelloni/c/82e7babfb39f
Best regards,
Signature · 3 lines
Alexandre Belloni, co-owner and COO, Bootlin Embedded Linux and Kernel engineering https://bootlin.com