lkml.org 
[lkml]   [2022]   [Nov]   [21]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
SubjectRe: [PATCH] tracing: Fix infinite loop in tracing_read_pipe on overflowed print_trace_line
From
Date
Hello,

On 2022/11/21 3:49, Steven Rostedt wrote:
> On Fri, 18 Nov 2022 18:21:12 +0800
> Yang Jihong <yangjihong1@huawei.com> wrote:
>
>>> That way we can see the broken trace event and not just silently drop it.
>>>
>> Ok, will change in next version.(Because iter->seq.seq.len may be
>> smaller than strlen(dots), direct subtraction here may not be appropriate.)
>
> We should only need to do this if the len is maxed out.
>
> Hmm, len is only updated if it did actually copy it.
>
> Perhaps we could just add:
>
> trace_seq_puts(&iter->seq, "[LINE TOO BIG]\n");
>
> And perhaps that will work?
>
Yes, as you mentioned in the v2 patch:

"The case I believe you are fixing, is the case were one
print_trace_line() actually fills the entire trace_seq in one shot."
The problem I'm having is exactly that.

Just add "trace_seq_puts(&iter->seq, "[LINE TOO BIG]\n"); " can solve
this problem.

But I thought it might happen. (Not yet. Is it possible to support new
tracers in the future?)

print_one_line {
char buf[4090]; // there's some data in
the buf.
trace_seq_puts(s, buf); // trace_seq buffer write
successfully
trace_seq_puts(s, "test, test, test\n"); // trace_seq buffer overflow
}

If we want to print out the boken event (buf[4090]), we may need to
reserve space as we did before.
If we don't consider this situation, we can just add
"trace_seq_puts(&iter->seq, "[LINE TOO BIG]\n");", it's fine.

> Anyway, what is triggering this?
In my environment, this problem may be triggered in the following ways:
# echo 1 > /sys/kernel/debug/tracing/options/blk_classic
# echo 1 > /sys/kernel/debug/tracing/options/blk_cgroup
# echo 1 > /sys/kernel/debug/tracing/events/enable
# echo blk > /sys/kernel/debug/tracing/current_tracer
# cat /sys/kernel/debug/tracing/trace_pipe > /dev/null

trace_pipe enter the blk_log_dump_pdu function through the following
call stack:

tracing_read_pipe
-> print_trace_line
-> iter->trace->print_line (current_trace == blk)
-> blk_tracer_print_line
-> print_one_line
-> blk_log_generic
-> blk_log_dump_pdu

static void blk_log_dump_pdu(struct trace_seq *s,
const struct trace_entry *ent, bool has_cg)
{
...
for (i = 0; i < pdu_len; i++) {

trace_seq_printf(s, "%s%02x",
i == 0 ? "" : " ", pdu_buf[i]);

/*
* stop when the rest is just zeros and indicate so
* with a ".." appended
*/
if (i == end && end != pdu_len - 1) {
trace_seq_puts(s, " ..) ");
return;
}
}
...
}
After the blk_classic option is enabled, blktrace writes all events in
the ring buffer to the trace_seq buffer through blk_log_dump_pdu.
If the value of pdu_len is too large, the buffer overflow may occur.
(This problem may be caused by improper processing of blktrace.)

Thanks,
Yang

\
 
 \ /
  Last update: 2022-11-21 09:16    [W:1.889 / U:0.316 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site