Re: [PATCH] tracing: Fix infinite loop in tracing_read_pipe on overflowed print_trace_line

From: Yang Jihong
Date: Mon Nov 21 2022 - 03:15:44 EST


Hello,

On 2022/11/21 3:49, Steven Rostedt wrote:
On Fri, 18 Nov 2022 18:21:12 +0800
Yang Jihong <yangjihong1@xxxxxxxxxx> 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