Thank you for your contribution! Sashiko AI review found 2 potential
issues to consider:
- [Low] tracing/remotes: selftests: dmesg.tc fails when
CONFIG_PRINTK_CALLER=y
- [Low] tracing/remotes: selftests: unpinned writes in test_dmesg() race
with poll
--
commit 3fde60957549859280fe5d4a8fc22ed359270e5c
Author: Vincent Donnefort [off-list ref]
tracing/remotes: selftests: Add a test for the dmesg tracefs file
This commit adds ftrace selftests for the trace remote dmesg tracefs file
to verify dmesg redirection on both the test remote and hypervisor remote.
quoted hunk ↗ jump to hunk
diff --git a/tools/testing/selftests/ftrace/test.d/remotes/dmesg.tc b/tools/testing/selftests/ftrace/test.d/remotes/dmesg.tc
new file mode 100644
index 0000000000000..a5dcdd91e516b
--- /dev/null
+++ b/tools/testing/selftests/ftrace/test.d/remotes/dmesg.tc
[ ... ]
quoted hunk ↗ jump to hunk
+ nr_events=128
+ for i in $(seq 1 $nr_events); do
+ echo $i > write_event
+ done
[Severity: Low]
Can unpinned writes to write_event here race with the periodic dmesg poller
and log events out of order?
Enabling dmesg starts the 100 ms periodic poll_work, and each write_event
records into the current CPU's ring buffer. If this loop migrates from a
CPU that was already polled or drained in the current cycle to a CPU that
is drained later in the same cycle, newer events on the second CPU are
printed to dmesg before earlier events on the first CPU, which remain unseen
until the next poll cycle and cause check_trace() to fail its monotonic
timestamp and sequential ID checks. Pinning the writer loop to a single
CPU with taskset, as trace_pipe.tc does when writing concurrently with a
reader, would avoid this.
quoted hunk ↗ jump to hunk
+ sleep 1
+ output=$(mktemp $TMPDIR/remote_test.XXXXXX)
+ dmesg | awk -v ts=$last_ts '
+ /^\[ *[0-9]+\.[0-9]+\]/ {
+ t=$0; sub(/^[[ \t]*/, "", t); sub(/].*/, "", t);
+ if (t+0 > ts+0) print $0
+ }' | grep "selftest id=" | sed 's/^[^]]*] //'> $output
+
+ check_trace 1 $nr_events $output
[Severity: Low]
Does this sed expression fail to strip the printk prefix when
CONFIG_PRINTK_CALLER=y is enabled?
With CONFIG_PRINTK_CALLER=y, dmesg prefixes each line with a second
bracketed caller ID field such as "[ 12.345678][ T42] " or
"[ 12.345678] [ T42] ". Because sed 's/^[^]]*] //' only strips a
single bracketed field followed by a space, the caller ID (or the entire
prefix) remains at the start of each line in $output.
tools/testing/selftests/ftrace/test.d/remotes/functions:check_trace() {
...
sed -e 's/\[[0-9]*\]\s*\([0-9]*.[0-9]*\): [a-z]* id=\([0-9]*\)/\1 \2/' $file > $tmp
}
Because check_trace() does not strip characters preceding the numeric CPU
field, cut extracts parts of the remaining printk prefix instead of the
event timestamp and ID, causing the test to fail.
--
Sashiko AI review · https://sashiko.dev/#/patchset/20261106180657.2460376-1-vdonnefort@google.com?part=9