Re: [PATCH v3 5/8] perf trace: Pretty print buffer data

[Howard Chu]

On Mon, Sep 9, 2024 at 9:45 AM Arnaldo Carvalho de Melo <acme@xxxxxxxxxx> wrote:
>
> On Mon, Sep 09, 2024 at 01:33:17PM -0300, Arnaldo Carvalho de Melo wrote:
> > >  static bool trace__filter_duration(struct trace *trace, double t)
> > >  {
> > >     return t < (trace->duration_filter * NSEC_PER_MSEC);
> > > @@ -1956,6 +1987,8 @@ syscall_arg_fmt__init_array(struct syscall_arg_fmt *arg, struct tep_format_field
> > >                 ((len >= 4 && strcmp(field->name + len - 4, "name") == 0) ||
> > >                  strstr(field->name, "path") != NULL))
> > >                     arg->scnprintf = SCA_FILENAME;
> > > +           else if (strstr(field->type, "char *") && strstr(field->name, "buf"))
> > > +                   arg->scnprintf = SCA_BUF;
> >
> > You can't really do this for things like 'read' as we would be printing
> > whatever is in the buffer when we enter the syscall, right? As we can
> > see testing after applying the following patch:
>
> This is also valid for the struct dumper, where I'll have to add some
> indication in the syscall_fmt table when the pointer should be read in
> the BPF augmenter, and thus we shouldn't bother to get it in the
> sys_enter if it is, say, fstat().

Yes you are right, problems with read buffers happen in structs too.
I'll get my read family patch out soon to ease your pain...

Thanks,
Howard
>
> - Arnaldo
>
> > root@number:~# perf trace -e read,write cat /etc/passwd > /dev/null
> >      0.000 ( 0.004 ms): cat/291442 read(fd: 3, buf: \0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0, count: 832) = 832
> >      0.231 ( 0.004 ms): cat/291442 read(fd: 3, buf: , count: 131072)                                     = 3224
> >      0.236 ( 0.001 ms): cat/291442 write(fd: 1, buf: root:x:0:0:Super User:/root:/bin, count: 3224)      = 3224
> >      0.239 ( 0.001 ms): cat/291442 read(fd: 3, buf: root:x:0:0:Super User:/root:/bin, count: 131072)     = 0
> > root@number:~#
> >
> > So we can't really do it at this point, we have to do it, for now, by
> > doing it on that syscall table initialization, for instance, for the
> > 'write' syscall:
> >
> > diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c
> > index 5f0877e891c2047d..1bcb45e737d830bf 100644
> > --- a/tools/perf/builtin-trace.c
> > +++ b/tools/perf/builtin-trace.c
> > @@ -1379,6 +1379,8 @@ static const struct syscall_fmt syscall_fmts[] = {
> >         .arg = { [2] = { .scnprintf = SCA_WAITID_OPTIONS, /* options */ }, }, },
> >       { .name     = "waitid",     .errpid = true,
> >         .arg = { [3] = { .scnprintf = SCA_WAITID_OPTIONS, /* options */ }, }, },
> > +     { .name     = "write",      .errpid = true,
> > +       .arg = { [1] = { .scnprintf = SCA_BUF, /* buf */ }, }, },
> >  };
> >
> >  static int syscall_fmt__cmp(const void *name, const void *fmtp)
> > @@ -1987,8 +1989,6 @@ syscall_arg_fmt__init_array(struct syscall_arg_fmt *arg, struct tep_format_field
> >                   ((len >= 4 && strcmp(field->name + len - 4, "name") == 0) ||
> >                    strstr(field->name, "path") != NULL))
> >                       arg->scnprintf = SCA_FILENAME;
> > -             else if (strstr(field->type, "char *") && strstr(field->name, "buf"))
> > -                     arg->scnprintf = SCA_BUF;
> >               else if ((field->flags & TEP_FIELD_IS_POINTER) || strstr(field->name, "addr"))
> >                       arg->scnprintf = SCA_PTR;
> >               else if (strcmp(field->type, "pid_t") == 0)
> >
> > With that we get:
> >
> > root@number:~# perf trace -e read,write cat /etc/passwd > /dev/null
> >      0.000 ( 0.005 ms): cat/296870 read(fd: 3, buf: 0x7ffe9cb8df98, count: 832)                          = 832
> >      0.268 ( 0.004 ms): cat/296870 read(fd: 3, buf: 0x7fa7d700a000, count: 131072)                       = 3224
> >      0.273 ( 0.002 ms): cat/296870 write(fd: 1, buf: root:x:0:0:Super User:/root:/bin, count: 3224)      =
> >      0.276 ( 0.001 ms): cat/296870 read(fd: 3, buf: 0x7fa7d700a000, count: 131072)                       = 0
> > root@number:~#
> >
> > After the following patch is applied.
> >
> > - Arnaldo