Re: [RFC PATCH bpf-next 0/6] bpf, printk: add BTF-based type printing

[Joe Perches <joe@perches.com>]

On Mon, 2020-04-20 at 16:29 +0100, Alan Maguire wrote:
> On Sat, 18 Apr 2020, Alexei Starovoitov wrote:
> 
> > On Fri, Apr 17, 2020 at 11:42:34AM +0100, Alan Maguire wrote:
> > > The printk family of functions support printing specific pointer types
> > > using %p format specifiers (MAC addresses, IP addresses, etc).  For
> > > full details see Documentation/core-api/printk-formats.rst.
> > > 
> > > This RFC patchset proposes introducing a "print typed pointer" format
> > > specifier "%pT<type>"; the type specified is then looked up in the BPF
> > > Type Format (BTF) information provided for vmlinux to support display.
> > 
> > This is great idea! Love it.
> > 
> 
> Thanks for taking a look!
>  
> > > The above potential use cases hint at a potential reply to
> > > a reasonable objection that such typed display should be
> > > solved by tracing programs, where the in kernel tracing records
> > > data and the userspace program prints it out.  While this
> > > is certainly the recommended approach for most cases, I
> > > believe having an in-kernel mechanism would be valuable
> > > also.
> > 
> > yep. This is useful for general purpose printk.
> > The only piece that must be highlighted in the printk documentation
> > that unlike the rest of BPF there are zero safety guarantees here.
> > The programmer can pass wrong pointer to printk() and the kernel _will_ crash.
> > 
> 
> Good point; I'll highlight the fact that we aren't
> executing in BPF context, no verifier etc.
> 
> > >   struct sk_buff *skb = alloc_skb(64, GFP_KERNEL);
> > > 
> > >   pr_info("%pTN<struct sk_buff>", skb);
> > 
> > why follow "TN" convention?
> > I think "%p<struct sk_buff>" is much more obvious, unambiguous, and
> > equally easy to parse.
> > 
> 
> That was my first choice, but the first character
> after the 'p' in the '%p' specifier signifies the
> pointer format specifier. If we use '<', and have
> '%p<', where do we put the modifiers? '%p<xYz struct foo>'
> seems clunky to me.

While I don't really like the %p<struct type> block,
it's at least obvious what's being attempted.

Modifiers could easily go after the <struct type> block.

It appears a %p<struct type> output might be a lot of
total characters so another potential issue might be
the maximum length of each individual printk.

> > I like the choice of C style output, but please format it similar to drgn. Like:
> > *(struct task_struct *)0xffff889ff8a08000 = {
> > 	.thread_info = (struct thread_info){
> > 		.flags = (unsigned long)0,
> > 		.status = (u32)0,
> > 	},
> > 	.state = (volatile long)1,
> > 	.stack = (void *)0xffffc9000c4dc000,
> > 	.usage = (refcount_t){
> > 		.refs = (atomic_t){
> > 			.counter = (int)2,
> > 		},
> > 	},
> > 	.flags = (unsigned int)4194560,
> > 	.ptrace = (unsigned int)0,

And here, the issue might be duplicating the log level
for each line of output and/or prefixing each line with
whatever struct type is being dumped as interleaving
with other concurrent logging is possible.

Here as well the individual field types don't contain
enough information to determine if a field should be
output as %x or %u.