Re: [GIT PULL] tracing: histogram fix and take 2 on the __string_len() marcros

[Chuck Lever III]

> On Jul 16, 2021, at 5:18 PM, Steven Rostedt <rostedt@xxxxxxxxxxx> wrote:
> 
> On Fri, 16 Jul 2021 11:45:57 -0700
> Linus Torvalds <torvalds@xxxxxxxxxxxxxxxxxxxx> wrote:
> 
>> On Fri, Jul 16, 2021 at 11:37 AM Steven Rostedt <rostedt@xxxxxxxxxxx> wrote:
>>> 
>>> 
>>> So how do you want this implemented?
>>> 
>>> #define __assign_str_len(dst, src, len)                                 \
>>>        do {                                                            \
>>>                strscpy(__get_str(dst), (src) ? (const char *)(src) : "(null)", len); \
>>>                __get_str(dst)[len] = '\0';
>> 
>> What? That "__get_str(dst)[len] = '\0';" is pointless and wrong.
> 
> I wrote up explanations to all this, and when I finally went to show an
> example of where this would be used, I found a major bug, that
> questions whether this is needed or not.
> 
> Chuck, WTH!
> 
> This feature was going to be used by Chuck, because he said he had strings
> that had to be saved that did not have terminating nul bytes.
> 
> For example, he has:
> 
> fs/nfsd/trace.h:
> 
>> DECLARE_EVENT_CLASS(nfsd_clid_class,
>> 	TP_PROTO(const struct nfsd_net *nn,
>> 		 unsigned int namelen,
>> 		 const unsigned char *namedata),
>> 	TP_ARGS(nn, namelen, namedata),
> 
> Above, namedata supposedly has no terminating '\0' byte,
> and namelen is the number of characters in namedata.
> 
>> 	TP_STRUCT__entry(
>> 		__field(unsigned long long, boot_time)
>> 		__field(unsigned int, namelen)
>> 		__dynamic_array(unsigned char,  name, namelen)
> 
> __dynamic_array() allocates __entry->name on the ring buffer of namelen
> bytes.
> 
> Where my patch would add instead:
> 
> 		__string(name, namelen)

You mean

                 __string_len(name, namelen)


> Which would allocate __entry->name on the ring buffer with "namelen" + 1
> bytes.
> 
> 
>> 	),
>> 	TP_fast_assign(
>> 		__entry->boot_time = nn->boot_time;
>> 		__entry->namelen = namelen;
>> 		memcpy(__get_dynamic_array(name), namedata, namelen);
> 
> The above is basically the open coded version of my __assign_str_len(),
> where we could use.
> 
> 		__assign_str_len(name, namedata, namelen);
> 
> instead.
> 
>> 	),
>> 	TP_printk("boot_time=%16llx nfs4_clientid=%.*s",
>> 		__entry->boot_time, __entry->namelen, __get_str(name))
>> )
> 
> 
> With my helpers, Chuck would no longer need this "%.*s", and pass in
> __entry->namelen, because, the __assign_str_len() would have added the
> '\0' terminating byte,  and "%s" would be sufficient.

Exactly, I would still like to do this. I've been waiting
for two months for the __string_len() macros to land.


> But this isn't the example I original used. The example I was going to
> use questions Chuck's use case, and was this:
> 
>> TRACE_EVENT(nfsd_dirent,
>> 	TP_PROTO(struct svc_fh *fhp,
>> 		 u64 ino,
>> 		 const char *name,
>> 		 int namlen),
>> 	TP_ARGS(fhp, ino, name, namlen),
>> 	TP_STRUCT__entry(
>> 		__field(u32, fh_hash)
>> 		__field(u64, ino)
>> 		__field(int, len)
>> 		__dynamic_array(unsigned char, name, namlen)
>> 	),
>> 	TP_fast_assign(
>> 		__entry->fh_hash = fhp ? knfsd_fh_hash(&fhp->fh_handle) : 0;
>> 		__entry->ino = ino;
>> 		__entry->len = namlen;
>> 		memcpy(__get_str(name), name, namlen);
> 
> Everything up to here is the same as above, but then there's ...
> 
>> 		__assign_str(name, name);
> 
> WTH! Chuck, do you know the above expands to:
> 
> 	strcpy(__get_str(name), (name) ? (const char *)(name) : "(null)");
> 
> If "name" does not have a terminating '\0' byte, this would crash hard.

Yes, it does crash hard. That's why I sent this fix:

7b08cf62b123 ("NFSD: Prevent a possible oops in the nfs_dirent() tracepoint")

Which is now in v5.14-rc1 (and should be picked soon up by
automation for backport). I intended to fix nfs_dirent to use
__string_len() and friends, but you decided to delay adding
these new macros, and I had to send the above fix instead.


> Even if it did have that byte, the __dynamic_array() above only
> allocated "namelen" bytes, and that did not include the terminating
> byte, which means you are guaranteed to overflow.
> 
> It may not have crashed for you if name is nul terminated, because the
> ring buffer rounds up to 4 byte alignment,  and you may have had some
> extra bytes to use at the end of the event allocation.
> 
> But this makes me question if name is really not terminated, and is
> this patch actually necessary.

Yes, it is necessary to finish this work.


>> 	),
>> 	TP_printk("fh_hash=0x%08x ino=%llu name=%.*s",
>> 		__entry->fh_hash, __entry->ino,
>> 		__entry->len, __get_str(name))
>> )
> 
> I'm dropping this patch for now,

Please don't drop it. I'm sure these two are not the only uses
for a proper __string_len(). The point of this exercise is to
provide helpers that do all of this manipulation correctly so
that others don't have to take the chance of getting it wrong.


> and will send another pull request with just the histogram bug fix.
> 
> Thanks,
> 
> -- Steve

--
Chuck Lever