[PATCH] tracing: Have large events show up as '[LINE TOO BIG]' instead of nothing

[PATCH] tracing: Have large events show up as '[LINE TOO BIG]' instead of nothing

[Steven Rostedt]

From: "Steven Rostedt (Google)" <rostedt@goodmis.org>

If a large event was added to the ring buffer that is larger than what the
trace_seq can handle, it just drops the output:

 ~# cat /sys/kernel/tracing/trace
 # tracer: nop
 #
 # entries-in-buffer/entries-written: 2/2   #P:8
 #
 #                                _-----=> irqs-off/BH-disabled
 #                               / _----=> need-resched
 #                              | / _---=> hardirq/softirq
 #                              || / _--=> preempt-depth
 #                              ||| / _-=> migrate-disable
 #                              |||| /     delay
 #           TASK-PID     CPU#  |||||  TIMESTAMP  FUNCTION
 #              | |         |   |||||     |         |
            <...>-859     [001] .....   141.118951: tracing_mark_write           <...>-859     [001] .....   141.148201: tracing_mark_write: 78901234

Instead, catch this case and add some context:

 ~# cat /sys/kernel/tracing/trace
 # tracer: nop
 #
 # entries-in-buffer/entries-written: 2/2   #P:8
 #
 #                                _-----=> irqs-off/BH-disabled
 #                               / _----=> need-resched
 #                              | / _---=> hardirq/softirq
 #                              || / _--=> preempt-depth
 #                              ||| / _-=> migrate-disable
 #                              |||| /     delay
 #           TASK-PID     CPU#  |||||  TIMESTAMP  FUNCTION
 #              | |         |   |||||     |         |
            <...>-852     [001] .....   121.550551: tracing_mark_write[LINE TOO BIG]
            <...>-852     [001] .....   121.550581: tracing_mark_write: 78901234

This now emulates the same output as trace_pipe.

Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
---
 kernel/trace/trace.c | 6 +++++-
 1 file changed, 5 insertions(+), 1 deletion(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index fbcd3bafb93e..aa8f99f3e5de 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -4722,7 +4722,11 @@ static int s_show(struct seq_file *m, void *v)
 		iter->leftover = ret;
 
 	} else {
-		print_trace_line(iter);
+		ret = print_trace_line(iter);
+		if (ret == TRACE_TYPE_PARTIAL_LINE) {
+			iter->seq.full = 0;
+			trace_seq_puts(&iter->seq, "[LINE TOO BIG]\n");
+		}
 		ret = trace_print_seq(m, &iter->seq);
 		/*
 		 * If we overflow the seq_file buffer, then it will
-- 
2.42.0

Re: [PATCH] tracing: Have large events show up as '[LINE TOO BIG]' instead of nothing

[Mathieu Desnoyers]

On 2023-12-09 17:10, Steven Rostedt wrote:
[...]
>              <...>-852     [001] .....   121.550551: tracing_mark_write[LINE TOO BIG]
>              <...>-852     [001] .....   121.550581: tracing_mark_write: 78901234

Failing to print an entire message because it does not fit in the
buffer size is rather inconvenient.

It would be better to print the partial line, and end the line with
a <TRUNCATED LINE> tag.

Thanks,

Mathieu

-- 
Mathieu Desnoyers
EfficiOS Inc.
https://www.efficios.com

Re: [PATCH] tracing: Have large events show up as '[LINE TOO BIG]' instead of nothing

[Steven Rostedt]

On Sun, 10 Dec 2023 09:11:40 -0500
Mathieu Desnoyers <mathieu.desnoyers@efficios.com> wrote:

> On 2023-12-09 17:10, Steven Rostedt wrote:
> [...]
> >              <...>-852     [001] .....   121.550551: tracing_mark_write[LINE TOO BIG]
> >              <...>-852     [001] .....   121.550581: tracing_mark_write: 78901234  
> 
> Failing to print an entire message because it does not fit in the
> buffer size is rather inconvenient.

Yes I agree, and luckily it hasn't been called out as an issue. Note, I hit
this because I extended the trace_marker buffer before increasing the
trace_seq size. Otherwise, the trace_marker just breaks it up. This can now
only be triggered by internal changes.

> 
> It would be better to print the partial line, and end the line with
> a <TRUNCATED LINE> tag.

Agreed, but I don't have time to do that (I already spent way too much time
on this than I had allocated). I decided to just do what the trace_pipe
currently does, and leave "print partial line" to another day when I can
allocate time on this.

Hmm, this could be added to the "TODO" list that was talked about in
ksummit-discuss.

-- Steve

Re: [PATCH] tracing: Have large events show up as '[LINE TOO BIG]' instead of nothing

[Masami Hiramatsu]

On Sun, 10 Dec 2023 10:34:15 -0500
Steven Rostedt <rostedt@goodmis.org> wrote:

> On Sun, 10 Dec 2023 09:11:40 -0500
> Mathieu Desnoyers <mathieu.desnoyers@efficios.com> wrote:
> 
> > On 2023-12-09 17:10, Steven Rostedt wrote:
> > [...]
> > >              <...>-852     [001] .....   121.550551: tracing_mark_write[LINE TOO BIG]
> > >              <...>-852     [001] .....   121.550581: tracing_mark_write: 78901234  
> > 
> > Failing to print an entire message because it does not fit in the
> > buffer size is rather inconvenient.
> 
> Yes I agree, and luckily it hasn't been called out as an issue. Note, I hit
> this because I extended the trace_marker buffer before increasing the
> trace_seq size. Otherwise, the trace_marker just breaks it up. This can now
> only be triggered by internal changes.

Rather than the broken output, I would perfer this output.

> 
> > 
> > It would be better to print the partial line, and end the line with
> > a <TRUNCATED LINE> tag.

But how long the partial line length is good enough? I think that big (and long)
user marker maybe not for human, so we don't need to care about readability.
I think current one is one of better solutions.

So I'll give my Reviewed-by. :)

Reviewed-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>

Thank you,

> 
> Agreed, but I don't have time to do that (I already spent way too much time
> on this than I had allocated). I decided to just do what the trace_pipe
> currently does, and leave "print partial line" to another day when I can
> allocate time on this.
> 
> Hmm, this could be added to the "TODO" list that was talked about in
> ksummit-discuss.
> 
> -- Steve
> 


-- 
Masami Hiramatsu (Google) <mhiramat@kernel.org>