Re: [PATCH][SMB3] Add various dynamic tracepoints for compounded operations

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Reviewed-by me.

Only issue is that it is very verbose like this :
+ if (rc)
+ trace_smb3_rmdir_err(xid,  ses->Suid, tcon->tid, rc);
+ else
+ trace_smb3_rmdir_done(xid, ses->Suid, tcon->tid);

We can do this late but this pattern can be simplified to a single
line with a macro.
It is always rc that decides which tracepoint we use, and the error
path tracepoint has a small subset of the arguments,except for rc,
than the _done tracepoint have.
So the macro could take both rc as well as all the arguments for _done as this :

TRACE_SMB3_RMDIR_END(rc, xid, suid, tid)

which then expands to the four lines of code.
We can do that later, just to reduce the amount of emacs real-estate
these lines take up.


On Wed, Mar 13, 2019 at 3:03 PM Steve French <smfrench@xxxxxxxxx> wrote:
>
> Version 3 of the patch attached.   Sample output below:
> (trace-cmd  record -e *query_info_co* -e smb3_hardlink* -e
> smb3_rename* -e smb3_set_eof* -e smb3_set_info_co* -e smb3_mkdir* -e
> smb3_delete* -e smb3_rmdir*)
>
>            mkdir-17927 [003] .... 447434.636544:
> smb3_query_info_compound_enter: xid=7 sid=0x7dc5fd6f tid=0xc7968732
> path=\newdir
>            mkdir-17927 [003] .... 447434.637240:
> smb3_query_info_compound_err: xid=7 sid=0x7dc5fd6f tid=0xc7968732
> rc=-2
>            mkdir-17942 [000] .... 447446.807606:
> smb3_query_info_compound_enter: xid=8 sid=0x7dc5fd6f tid=0xc7968732
> path=\newdir
>            mkdir-17942 [000] .... 447446.808233:
> smb3_query_info_compound_err: xid=8 sid=0x7dc5fd6f tid=0xc7968732
> rc=-2
>            mkdir-17942 [000] .... 447446.808251: smb3_mkdir_enter:
> xid=9 sid=0x7dc5fd6f tid=0xc7968732 path=\newdir
>            mkdir-17942 [000] .... 447446.809161: smb3_mkdir_done:
> xid=9 sid=0x7dc5fd6f tid=0xc7968732
>            mkdir-17942 [000] .... 447446.809178:
> smb3_query_info_compound_enter: xid=9 sid=0x7dc5fd6f tid=0xc7968732
> path=\newdir
>            mkdir-17942 [000] .... 447446.809979:
> smb3_query_info_compound_done: xid=9 sid=0x7dc5fd6f tid=0xc7968732
>            rmdir-17943 [001] .... 447451.374029:
> smb3_query_info_compound_enter: xid=10 sid=0x7dc5fd6f tid=0xc7968732
> path=\baddir
>            rmdir-17943 [001] .... 447451.379621:
> smb3_query_info_compound_err: xid=10 sid=0x7dc5fd6f tid=0xc7968732
> rc=-2
>            rmdir-17944 [001] .... 447456.088795:
> smb3_query_info_compound_enter: xid=11 sid=0x7dc5fd6f tid=0xc7968732
> path=\newdir
>            rmdir-17944 [001] .... 447456.089615:
> smb3_query_info_compound_done: xid=11 sid=0x7dc5fd6f tid=0xc7968732
>            rmdir-17944 [001] .... 447456.089640: smb3_rmdir_enter:
> xid=12 sid=0x7dc5fd6f tid=0xc7968732 path=\newdir
>            rmdir-17944 [001] .... 447456.090651: smb3_rmdir_done:
> xid=12 sid=0x7dc5fd6f tid=0xc7968732
>            touch-17945 [006] .... 447460.575789:
> smb3_set_info_compound_enter: xid=14 sid=0x7dc5fd6f tid=0xc7968732
> path=\file
>            touch-17945 [006] .... 447460.576571:
> smb3_set_info_compound_done: xid=14 sid=0x7dc5fd6f tid=0xc7968732
>               ln-17946 [001] .... 447468.254480:
> smb3_query_info_compound_enter: xid=16 sid=0x7dc5fd6f tid=0xc7968732
> path=\linkedfile
>               ln-17946 [001] .... 447468.255082:
> smb3_query_info_compound_err: xid=16 sid=0x7dc5fd6f tid=0xc7968732
> rc=-2
>               ln-17946 [001] .... 447468.255118:
> smb3_query_info_compound_enter: xid=17 sid=0x7dc5fd6f tid=0xc7968732
> path=\file
>               ln-17946 [001] .... 447468.255715:
> smb3_query_info_compound_done: xid=17 sid=0x7dc5fd6f tid=0xc7968732
>               ln-17946 [001] .... 447468.255760:
> smb3_query_info_compound_enter: xid=18 sid=0x7dc5fd6f tid=0xc7968732
> path=\linkedfile
>               ln-17946 [001] .... 447468.256254:
> smb3_query_info_compound_err: xid=18 sid=0x7dc5fd6f tid=0xc7968732
> rc=-2
>               ln-17946 [001] .... 447468.256277: smb3_hardlink_enter:
> xid=19 sid=0x7dc5fd6f tid=0xc7968732 path=\file
>               ln-17946 [001] .... 447468.256954: smb3_hardlink_done:
> xid=19 sid=0x7dc5fd6f tid=0xc7968732
>            gmain-2225  [004] .... 447468.257130:
> smb3_query_info_compound_enter: xid=20 sid=0x7dc5fd6f tid=0xc7968732
> path=\linkedfile
>            gmain-2225  [005] .... 447468.257788:
> smb3_query_info_compound_done: xid=20 sid=0x7dc5fd6f tid=0xc7968732
>
> On Tue, Mar 12, 2019 at 4:51 PM Pavel Shilovsky <piastryyy@xxxxxxxxx> wrote:
> >
> > I actually like the idea proposed in the patch: this way we will be
> > able to track logical operations better. In a case we need a deeper
> > logging we already have mid traces which contains MID, TID, SID and
> > CMD - everything you need to trace individual SMB packet regardless of
> > whether it is a part of compounding chain or not.
> >
> > Now in order to match both logical operation and SMB packets traces we
> > need something common - like XID. Currently we do not propagate XID
> > down to the transport layer, let's do that - this way we can trace
> > individual system call from the very beginning to the completeness on
> > every layer inside cifs.ko.
> >
> > вт, 12 мар. 2019 г. в 00:19, Steve French <smfrench@xxxxxxxxx>:
> > >
> > > The general feeling I am getting from tracing the compounding is that
> > > we have to have the more granular tracing available
> > > (similar to this patch), and also (with followon patch) add noisier
> > > optional trace points lower down (that are generic) that we turn on
> > > less frequently (in particular when the filename is not good enough
> > > and we must have the xid - even if it makes the trace very noisy)
> > >
> > >
> > > On Tue, Mar 12, 2019 at 1:06 AM ronnie sahlberg
> > > <ronniesahlberg@xxxxxxxxx> wrote:
> > > >
> > > > Hmm.
> > > >
> > > > I don't think this is the wrong layer to add the tracing.
> > > > Instead of adding the tracing in say smb2_compound_op(), where we
> > > > create the compound,
> > > > I think it will be better to add the tracing down in the leaf
> > > > functions, i.e. down in SMB2_open_init(), SMB2_query_info_init(), ...
> > > >
> > > > That way we know that we will always have tracing for all opens/closes/...
> > > >
> > > > But then what to do about the trace_smb3_..._err()/trace_smb3_..._done() calls ?
> > > > These I think should be moved down and handled inside compound_send_recv().
> > > > That way we can have one single place where we call the appropriate
> > > > _err()/_done() functions
> > > > and we know that we will catch every single completed function.
> > > >
> > > > I.e. just put it in a single place instead of in every single call-site.
> > > > In compound_send_recv we can just loop over all the responses, cast it
> > > > to a smb2_hdr structure, looka at both the command code as well as the
> > > > status code and call the appropriate xys_err() or xyz_done() functions
> > > > as needed.
> > > >
> > > > Let me show an example of what I mean for a open/query/close compound :
> > > >
> > > > trace_smb3_open_enter(xid=5, filename="foo", ...)   from SMB2_open_init()
> > > > trace_smb3_query_info_enter(xid=5,... ) from SMB2_query_info_init()
> > > > trace_smb3_close_enter(xid=5, ...) from SMB2_close_init()
> > > > (maybe have additional tracing in compound_send_recv() that we are
> > > > about to send xid=5 to the wire)
> > > > trace_smb3_open_done(xid=5, ...) from compound_send_recv()
> > > > trace_smb3_query_info_done(xid=5, ...) from compound_send_recv()
> > > > trace_smb3_close_done(xid=5, ...) from compound_send_recv()
> > > >
> >
> > As pointed above we already have a similar tracing inside
> > compound_send_recv and other transport layer functions - command level
> > tracing. The only problem is that we do not log failure cases when we
> > didn't send the packet - we only log server responses in
> > map_smb2_to_linux_error. This is another area of the tracing where a
> > fix is needed.
> >
> > --
> > Best regards,
> > Pavel Shilovsky
>
>
>
> --
> Thanks,
>
> Steve




[Linux USB Devel]     [Video for Linux]     [Linux Audio Users]     [Yosemite News]     [Linux Kernel]     [Linux SCSI]

  Powered by Linux