github-mirror/linux
1
0
Fork 0
mirror of https://github.com/torvalds/linux.git synced 2026-11-07 06:17:02 +01:00
Code Issues Actions Packages Projects Releases Wiki Activity Graph

kcsan: test: Do not count report printing time against test duration

Browse Source 
Since commit d353934702 ("serial: 8250: Switch to nbcon console, take
2"), several KCSAN tests fail with CONFIG_KCSAN_VERBOSE=y when using the
8250 console.

With CONFIG_KCSAN_VERBOSE=y, the report prints the racing tasks' IRQ
trace events via print_irqtrace_events(), which marks its output as a
printk emergency section. Within an emergency section, printk() flushes
all pending messages to nbcon consoles synchronously. With a slow
console, the reporting thread can therefore stall for over a second
while holding report_lock, i.e. before the remaining lines of the report
are stored.

The test, however, stops checking for reports after a fixed deadline,
which is easily exceeded by a single slow report:

| [    5.360278] BUG: KCSAN: data-race in test_kernel_read / test_kernel_write
| [    5.360303] write to 0xffffffffab95a478 of 8 bytes by task 237 on cpu 7:
| ...
| [    5.360411] irq event stamp: 23
| [    6.059836]     # test_basic: EXPECTATION FAILED at kernel/kcsan/kcsan_test.c:735
| ...
| [    6.616416] read to 0xffffffffab95a478 of 8 bytes by task 238 on cpu 9:

Waiting for in-progress reports to complete is insufficient: a slow
report that does not match the expected report still uses up the time
to observe the expected report.

Fix it by pausing the test's time budget while a test-related report is
being printed, bounded by an upper limit to avoid stalling the test
forever. Once a report completes, always check it at least once.

Assisted-by: Antigravity
Signed-off-by: Marco Elver <elver@google.com>
This commit is contained in:
Marco Elver 2026-10-10 11:14:11 +00:00
parent 99b6fcce87
commit bd3cc16d1d
1 changed files with 33 additions and 1 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

34
kernel/kcsan/kcsan_test.c
View File

@ -48,6 +48,9 @@ static void (*access_kernels[2])(void);
static struct task_struct **threads; /* Lists of threads. */
static unsigned long end_time; /* End time of test. */
static unsigned long end_time_max; /* Upper bound for end time of test. */
static unsigned long report_budget; /* Time left when report printing began. */
static bool report_paused; /* Paused while a report is printing. */
/* Report as observed from console. */
static struct {
@ -69,17 +72,46 @@ begin_test_checks(void (*func1)(void), void (*func2)(void))
* least one race is reported.
*/
end_time = jiffies + msecs_to_jiffies(CONFIG_KCSAN_REPORT_ONCE_IN_MS + 500);
end_time_max = end_time + msecs_to_jiffies(10000);
report_paused = false;
/* Signal start; release potential initialization of shared data. */
smp_store_release(&access_kernels[0], func1);
smp_store_release(&access_kernels[1], func2);
}
/*
* Printing a report may take a while, e.g. if a printk emergency section (such
* as with CONFIG_KCSAN_VERBOSE) flushes a console backlog synchronously. Do not
* count the time a test-related report is being printed against the test's
* time budget, so that a slow report is neither missed, nor prevents observing
* other reports. Returns true if checking must continue.
*/
static __no_kcsan bool pause_for_report(void)
{
const int nlines = READ_ONCE(observed.nlines);
const bool in_progress = nlines == 1 || nlines == 2;
if (in_progress && !report_paused) {
report_paused = true;
report_budget = time_before(jiffies, end_time) ? end_time - jiffies : 0;
} else if (!in_progress && report_paused) {
report_paused = false;
end_time = jiffies + report_budget;
if (time_after(end_time, end_time_max))
end_time = end_time_max;
/* Check the now complete report at least once. */
return true;
}
return report_paused && time_before(jiffies, end_time_max);
}
/* End test checking loop. */
static __no_kcsan inline bool
end_test_checks(bool stop)
{
if (!stop && time_before(jiffies, end_time)) {
if (!stop && (pause_for_report() || time_before(jiffies, end_time))) {
/* Continue checking */
might_sleep();
return false;