Re: [RFC PATCH 1/1] tracefs: add TP_printk_no_nl - RFC

From: jim . cromie
Date: Mon Jul 31 2023 - 17:02:02 EST


On Mon, Jul 31, 2023 at 9:21 AM Steven Rostedt <rostedt@xxxxxxxxxxx> wrote:
>
> On Mon, 31 Jul 2023 12:21:29 +0200
> Petr Mladek <pmladek@xxxxxxxx> wrote:
>
> > > Grepping through the kernel, I am surprised how many messages are
> > > missing the trailing newline when it is obvious they are not intended to
> > > be extended. I consider these bugs.
> >
> > I consider this bug as well.
> >

agreed.
I blame pr_cont() at least in part.

Note - I have submitted
drm_dbg: add trailing newlines where missing
https://patchwork.freedesktop.org/series/121583/

it appears to have failed - on what look like unrelated failures - pipe etc


> > My understanding is that this patch affects only messages printed to
> > the ftrace buffer so that it does not affect printk() directly.
> >
> > But still. It creates a habit that is bad for printk(). Also relies
> > on the fact that people are aware of this macro and use it. IMHO,
> > it will not work in practice. Or do I miss something?

something like (opposite of) this, used inside pr_debug, would force
all callers to add \n.
#include <assert.h>
#define FAIL_IF_TRAILING_NEWLINE(str) \
_Static_assert((str[sizeof(str) - 2] != '\n'), "String literal has a
trailing newline")

obviously, Inverted, gentler versions are perhaps better.

>
> I believe that the problem Jim is addressing is that there's printk()
> messages that also go to a tracepoint() function. The tracepoint function
> will add its own '\n' to the message, and now we have two '\n's and this
> causes extra spaces in the output of the ftrace ring buffer.

Yes. only quibble - there arent yet, there could be.
Vincents patch didnt go in, Im trying to get it ready for another submit.

I uncovered this bit on the way,
figured I could turn it into a question, and maybe a little conceptual buy-in.

This is a 0 or 1 "\n" problem,
quietly accepting 25 in a row could paper over another problem.
maybe complain-once after 2-3 ?

TP_printk_no_nl doesnt solve all problems -
it could work for adding DRM.debug trace-events,
cuz the callsites have few of the bad-habits noted above,
*very* few drm_dbg()s without trailing \n. - presuming theyre fixable.

fixing the larger body of pr_debug()s is quite a nuisance,
and if dyndbg -T flag sends them, you'd get the larger varying
population of \n's
So some real-time stripping /adding is needed for some populations of pr_debugs

the no_nl macro would at least allow event-definers
to assert that theyre sending their own.


>
> Perhaps what we should do is to make sure that the output doesn't add more
> newlines than just one.
>
> Something like this: (totally untested)
>
> diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c
> index db575094c498..a1b73ffa1552 100644
> --- a/kernel/trace/trace_output.c
> +++ b/kernel/trace/trace_output.c
> @@ -333,6 +333,8 @@ int trace_output_raw(struct trace_iterator *iter, char *name,
>
> trace_seq_printf(s, "%s: ", name);
> trace_seq_vprintf(s, trace_event_format(iter, fmt), ap);
> + trace_seq_trim_newlines(s);
> + trace_seq_putc(s, '\n');
>
> return trace_handle_return(s);
> }
> diff --git a/kernel/trace/trace_seq.c b/kernel/trace/trace_seq.c
> index bac06ee3b98b..d4e2049809e3 100644
> --- a/kernel/trace/trace_seq.c
> +++ b/kernel/trace/trace_seq.c
> @@ -221,6 +221,22 @@ void trace_seq_puts(struct trace_seq *s, const char *str)
> }
> EXPORT_SYMBOL_GPL(trace_seq_puts);
>
> +/**
> + * trace_seq_trim_newlines - remove ending newlines
> + * @s: trace sequence descriptor
> + *
> + * Remove ending newlines from the buffer.
> + */
> +void trace_seq_trim_newlines(struct trace_seq *s)
> +{
> + if (unlikely(!s->seq.size || !s->seq.len))
> + return;
> +
> + while (s->seq.len && s->buffer[s->seq.len - 1] == '\n') {
> + s->seq.len--;
> + }
> +}
> +
> /**
> * trace_seq_putc - trace sequence printing of simple character
> * @s: trace sequence descriptor
>
>
>
> A similar thing would need to go into libtraceevent.
>
> -- Steve