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

2023-12-11 Thread Google 
On Sun, 10 Dec 2023 10:34:15 -0500
Steven Rostedt  wrote:

> On Sun, 10 Dec 2023 09:11:40 -0500
> Mathieu Desnoyers  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  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) 

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)

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

2023-12-10 Thread Steven Rostedt 
On Sun, 10 Dec 2023 09:11:40 -0500
Mathieu Desnoyers  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  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

2023-12-10 Thread 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  tag.

Thanks,

Mathieu

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

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

2023-12-09 Thread Steven Rostedt 
From: "Steven Rostedt (Google)" 

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) 
---
 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(>seq, "[LINE TOO BIG]\n");
+   }
ret = trace_print_seq(m, >seq);
/*
 * If we overflow the seq_file buffer, then it will
-- 
2.42.0