On Wed, 18 Dec 2024 09:32:45 -0800
Linus Torvalds <torvalds@xxxxxxxxxxxxxxxxxxxx> wrote:
> As you also point out with your tracing test:
>
> > modprobe-905 [003] ..... 113.624842: bprint: [FAILED TO PARSE] ip=0xffffffffc060e045 fmt=0xffff8c05c338e760 buf=ARRAY[]
> > modprobe-905 [003] ..... 113.624843: bprint: [FAILED TO PARSE] ip=0xffffffffc060e045 fmt=0xffff8c05c338ec40 buf=ARRAY[]
> > modprobe-905 [003] ..... 113.624843: bprint: [FAILED TO PARSE] ip=0xffffffffc060e045 fmt=0xffff8c05c338e280 buf=ARRAY[]
> >
> > Those "[FAILED TO PARSE]" messages have nothing to do with your code, but
> > it means that it doesn't handle 'h' at all. Even the "unsigned short"
> > printed but still failed to parse properly.
>
> Yeah, %h{d,u} and %hh{d,u} are not hugely common, and apparently it's
> not just your tracing tools that don't understand them: Alexei
> reported that the bpf binary printk code also refused them.
>
> That said, they *do* exist in the kernel, including in tracing:
>
> git grep 'TP_printk.*".*%hh*[ud].*"'
>
> doesn't return lots of hits, but does report a handful.
Those are not processed by vbin_printf() or bstr_printf() the TP_printk()
of the event is a simple vsnprintf() and is executed on the read side.
The TP_printk() macro is basically translated into:
trace_event_printf(iter, print);
Where that "print" is the TP_printk() passed to TRACE_EVENT(). And that's
the function that I was fixing:
void trace_event_printf(struct trace_iterator *iter, const char *fmt, ...)
{
va_list ap;
va_start(ap, fmt);
trace_check_vprintf(iter, trace_event_format(iter, fmt), ap);
va_end(ap);
}
So, if vsnprintf() handles anything, so does TP_printk(). Nothing to do
with the binary formatting.
>
> > This is because libtraceevent appears to not support "%h" in print formats.
> > That at least means there would be no breakage if they are modified in any
> > way.
>
> Oh, %hd is not getting modified (and if I did, that would be a major bug).
>
> It's very much a part of the standard printf format, and is very much
> inherent to the whole varargs and C integer promotion rules (ie you
> literally *cannot* pass an actual 'char' value to a varargs function -
> the normal C integer type extension rules apply).
>
> So this is not really some odd kernel extension, and while there are
> only a handful of users in tracing (that apparently trace-cmd cannot
> deal with), it's not even _that_ uncommon in general:
trace-cmd (and libtraceevent for that matter) does handle "%h" and "%hh"
as well.
But the vbin_printf() which trace_printk() uses is a different beast, and
requires rebuilding the arguments so that it can be parsed, and there "%h"
isn't supported.
-- Steve
