Re: [PATCH] tracing: Fix race when concurrently splice_read trace_pipe
From: Zheng Yejian
Date: Fri Aug 11 2023 - 22:22:49 EST
On 2023/8/12 03:24, Steven Rostedt wrote:
On Fri, 11 Aug 2023 20:37:07 +0800
Zheng Yejian <zhengyejian1@xxxxxxxxxx> wrote:
On 2023/8/11 19:42, Masami Hiramatsu (Google) wrote:
On Thu, 10 Aug 2023 20:39:05 +0800
Zheng Yejian <zhengyejian1@xxxxxxxxxx> wrote:
When concurrently splice_read file trace_pipe and per_cpu/cpu*/trace_pipe,
there are more data being read out than expected.
The root cause is that in tracing_splice_read_pipe(), an entry is found
outside locks, it may be read by multiple readers or consumed by other
reader as starting printing it.
To fix it, change to find entry after holding locks.
Fixes: 7e53bd42d14c ("tracing: Consolidate protection of reader access to the ring buffer")
Signed-off-by: Zheng Yejian <zhengyejian1@xxxxxxxxxx>
---
kernel/trace/trace.c | 10 ++++++----
1 file changed, 6 insertions(+), 4 deletions(-)
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index b8870078ef58..f169d33b948f 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -7054,14 +7054,16 @@ static ssize_t tracing_splice_read_pipe(struct file *filp,
if (ret <= 0)
goto out_err;
- if (!iter->ent && !trace_find_next_entry_inc(iter)) {
+ trace_event_read_lock();
+ trace_access_lock(iter->cpu_file);
+
+ if (!trace_find_next_entry_inc(iter)) {
It seems you skips '!iter->ent' check. Is there any reason for this change?
IIUC, 'iter->ent' may be the entry that was found but not consumed
in last call tracing_splice_read_pipe(), and in this call, 'iter->ent'
may have being consumed, so we may should find a new 'iter->ent' before
printing it in tracing_fill_pipe_page(), see following reduced codes:
And if it wasn't consumed? We just lost it?
If 'iter->ent' was not consumed, trace_find_next_entry_inc() will find
it again, will it?
-- Zheng Yejian
tracing_splice_read_pipe() {
if (!iter->ent && !trace_find_next_entry_inc(iter)) { // 1. find
entry here
... ...
}
tracing_fill_pipe_page() {
for (;;) {
... ...
ret = print_trace_line(iter); // 2. print entry
... ...
You missed:
count = trace_seq_used(&iter->seq) - save_len;
if (rem < count) {
rem = 0;
iter->seq.seq.len = save_len;
Where the above just threw away what was printed in the above
"print_trace_line()", and it never went to console.
break;
}
Thanks for pointing this out!
-- Zheng Yejian
-- Steve
if (!trace_find_next_entry_inc()) { // 3. find next entry
... ...
break;
}
}
--
Thanks,
Zheng Yejian
Thank you,
+ trace_access_unlock(iter->cpu_file);
+ trace_event_read_unlock();
ret = -EFAULT;
goto out_err;
}
- trace_event_read_lock();
- trace_access_lock(iter->cpu_file);
-
/* Fill as many pages as possible. */
for (i = 0, rem = len; i < spd.nr_pages_max && rem; i++) {
spd.pages[i] = alloc_page(GFP_KERNEL);
--
2.25.1