print_trace_line may overflow seq_file buffer. If the event is not
consumed, the while loop keeps peeking this event, causing a infinite loop.
Signed-off-by: Yang Jihong <[email protected]>
---
kernel/trace/trace.c | 13 +++++++++++++
1 file changed, 13 insertions(+)
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 47a44b055a1d..2a8d5c68c29b 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -6788,6 +6788,19 @@ tracing_read_pipe(struct file *filp, char __user *ubuf,
if (ret == TRACE_TYPE_PARTIAL_LINE) {
/* don't print partial lines */
iter->seq.seq.len = save_len;
+
+ /*
+ * If one trace_line of the tracer overflows seq_file
+ * buffer, trace_seq_to_user returns -EBUSY because
+ * nothing in the sequence (iter->seq.seq.len = \
+ * iter->seq.seq.readpos = 0).
+ * In this case, we need to consume, otherwise,
+ * "while" will peek this event next time, resulting
+ * in an infinite loop.
+ */
+ if (trace_seq_has_overflowed(&iter->seq))
+ trace_consume(iter);
+
break;
}
if (ret != TRACE_TYPE_NO_CONSUME)
--
2.30.GIT
On Mon, 14 Nov 2022 10:29:46 +0800
Yang Jihong <[email protected]> wrote:
> print_trace_line may overflow seq_file buffer. If the event is not
> consumed, the while loop keeps peeking this event, causing a infinite loop.
>
> Signed-off-by: Yang Jihong <[email protected]>
> ---
> kernel/trace/trace.c | 13 +++++++++++++
> 1 file changed, 13 insertions(+)
>
> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> index 47a44b055a1d..2a8d5c68c29b 100644
> --- a/kernel/trace/trace.c
> +++ b/kernel/trace/trace.c
> @@ -6788,6 +6788,19 @@ tracing_read_pipe(struct file *filp, char __user *ubuf,
> if (ret == TRACE_TYPE_PARTIAL_LINE) {
> /* don't print partial lines */
> iter->seq.seq.len = save_len;
> +
> + /*
> + * If one trace_line of the tracer overflows seq_file
> + * buffer, trace_seq_to_user returns -EBUSY because
> + * nothing in the sequence (iter->seq.seq.len = \
> + * iter->seq.seq.readpos = 0).
> + * In this case, we need to consume, otherwise,
> + * "while" will peek this event next time, resulting
> + * in an infinite loop.
> + */
> + if (trace_seq_has_overflowed(&iter->seq))
> + trace_consume(iter);
Instead of consuming it, I think the right solution is to print the partial
line. Something like:
if (trace_seq_has_overflowed(&iter->seq)) {
char dots[] = "...";
iter->seq.seq.len -= sizeof(dots) + 1;
iter->seq.seq.full = 0;
trace_seq_puts(&iter->seq, dots);
trace_consume(iter);
break;
}
iter->seq.seq.len = save_len;
break;
That way we can see the broken trace event and not just silently drop it.
-- Steve
> +
> break;
> }
> if (ret != TRACE_TYPE_NO_CONSUME)
Hello,
On 2022/11/18 5:40, Steven Rostedt wrote:
> On Mon, 14 Nov 2022 10:29:46 +0800
> Yang Jihong <[email protected]> wrote:
>
>> print_trace_line may overflow seq_file buffer. If the event is not
>> consumed, the while loop keeps peeking this event, causing a infinite loop.
>>
>> Signed-off-by: Yang Jihong <[email protected]>
>> ---
>> kernel/trace/trace.c | 13 +++++++++++++
>> 1 file changed, 13 insertions(+)
>>
>> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
>> index 47a44b055a1d..2a8d5c68c29b 100644
>> --- a/kernel/trace/trace.c
>> +++ b/kernel/trace/trace.c
>> @@ -6788,6 +6788,19 @@ tracing_read_pipe(struct file *filp, char __user *ubuf,
>> if (ret == TRACE_TYPE_PARTIAL_LINE) {
>> /* don't print partial lines */
>> iter->seq.seq.len = save_len;
>> +
>> + /*
>> + * If one trace_line of the tracer overflows seq_file
>> + * buffer, trace_seq_to_user returns -EBUSY because
>> + * nothing in the sequence (iter->seq.seq.len = \
>> + * iter->seq.seq.readpos = 0).
>> + * In this case, we need to consume, otherwise,
>> + * "while" will peek this event next time, resulting
>> + * in an infinite loop.
>> + */
>> + if (trace_seq_has_overflowed(&iter->seq))
>> + trace_consume(iter);
>
> Instead of consuming it, I think the right solution is to print the partial
> line. Something like:
>
> if (trace_seq_has_overflowed(&iter->seq)) {
> char dots[] = "...";
>
> iter->seq.seq.len -= sizeof(dots) + 1;
> iter->seq.seq.full = 0;
> trace_seq_puts(&iter->seq, dots);
> trace_consume(iter);
> break;
> }
>
> iter->seq.seq.len = save_len;
> break;
>
> 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.)
Thanks,
Yang
On Fri, 18 Nov 2022 18:21:12 +0800
Yang Jihong <[email protected]> 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?
Anyway, what is triggering this?
-- Steve
Hello,
On 2022/11/21 3:49, Steven Rostedt wrote:
> On Fri, 18 Nov 2022 18:21:12 +0800
> Yang Jihong <[email protected]> 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
Hello,
On 2022/11/21 3:49, Steven Rostedt wrote:
> On Fri, 18 Nov 2022 18:21:12 +0800
> Yang Jihong <[email protected]> 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");
>
The v3 patch has been sent according to this solution.
Thanks,
Yang