Commit Graph

3 Commits

Author SHA1 Message Date
Steve French
28d59363ae smb3: add tracepoints for smb2/smb3 open
add two tracepoints for open completion. One for error one for completion (open_done).
Sample output below

            TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
               | |       |   ||||       |         |
            bash-15348 [007] .... 42441.027492: smb3_enter: 	cifs_lookup: xid=45
            bash-15348 [007] .... 42441.028214: smb3_cmd_err: 	sid=0x6173e4ce tid=0xa05150e6 cmd=5 mid=105 status=0xc0000034 rc=-2
            bash-15348 [007] .... 42441.028219: smb3_open_err: xid=45 sid=0x6173e4ce tid=0xa05150e6 cr_opts=0x0 des_access=0x80 rc=-2
            bash-15348 [007] .... 42441.028225: smb3_exit_done: 	cifs_lookup: xid=45
          fop777-24560 [002] .... 42442.627617: smb3_enter: 	cifs_revalidate_dentry_attr: xid=46
          fop777-24560 [003] .... 42442.628301: smb3_cmd_err: 	sid=0x6173e4ce tid=0xa05150e6 cmd=5 mid=106 status=0xc0000034 rc=-2
          fop777-24560 [003] .... 42442.628319: smb3_open_err: xid=46 sid=0x6173e4ce tid=0xa05150e6 cr_opts=0x0 des_access=0x80 rc=-2
          fop777-24560 [003] .... 42442.628335: smb3_enter: 	cifs_atomic_open: xid=47
          fop777-24560 [003] .... 42442.629587: smb3_cmd_done: 	sid=0x6173e4ce tid=0xa05150e6 cmd=5 mid=107
          fop777-24560 [003] .... 42442.629592: smb3_open_done: xid=47 sid=0x6173e4ce tid=0xa05150e6 fid=0xb8a0984d cr_opts=0x40 des_access=0x40000080

Signed-off-by: Steve French <smfrench@gmail.com>
2018-05-30 21:42:34 -05:00
Steve French
d683bcd3e5 smb3: add additional ftrace entry points for entry/exit to cifs.ko
Signed-off-by: Steve French <smfrench@gmail.com>
2018-05-30 16:06:18 -05:00
Steve French
eccb4422cf smb3: Add ftrace tracepoints for improved SMB3 debugging
Although dmesg logs and wireshark network traces can be
helpful, being able to dynamically enable/disable tracepoints
(in this case via the kernel ftrace mechanism) can also be
helpful in more quickly debugging problems, and more
selectively tracing the events related to the bug report.

This patch adds 12 ftrace tracepoints to cifs.ko for SMB3 events
in some obvious locations.  Subsequent patches will add more
as needed.

Example use:
   trace-cmd record -e cifs
   <run test case>
   trace-cmd show

Various trace events can be filtered. See:
       trace-cmd list | grep cifs
for the current list of cifs tracepoints.

Sample output (from mount and writing to a file):

root@smf:/sys/kernel/debug/tracing/events/cifs# trace-cmd show
<snip>
      mount.cifs-6633  [006] ....  7246.936461: smb3_cmd_done: pid=6633 tid=0x0 sid=0x0 cmd=0 mid=0
      mount.cifs-6633  [006] ....  7246.936701: smb3_cmd_err:  pid=6633 tid=0x0 sid=0x3d9cf8e5 cmd=1 mid=1 status=0xc0000016 rc=-5
      mount.cifs-6633  [006] ....  7246.943055: smb3_cmd_done: pid=6633 tid=0x0 sid=0x3d9cf8e5 cmd=1 mid=2
      mount.cifs-6633  [006] ....  7246.943298: smb3_cmd_done: pid=6633 tid=0xf9447636 sid=0x3d9cf8e5 cmd=3 mid=3
      mount.cifs-6633  [006] ....  7246.943446: smb3_cmd_done: pid=6633 tid=0xf9447636 sid=0x3d9cf8e5 cmd=11 mid=4
      mount.cifs-6633  [006] ....  7246.943659: smb3_cmd_done: pid=6633 tid=0xe1b781a sid=0x3d9cf8e5 cmd=3 mid=5
      mount.cifs-6633  [006] ....  7246.943766: smb3_cmd_done: pid=6633 tid=0xe1b781a sid=0x3d9cf8e5 cmd=11 mid=6
      mount.cifs-6633  [006] ....  7246.943937: smb3_cmd_done: pid=6633 tid=0xe1b781a sid=0x3d9cf8e5 cmd=5 mid=7
      mount.cifs-6633  [006] ....  7246.944020: smb3_cmd_done: pid=6633 tid=0xe1b781a sid=0x3d9cf8e5 cmd=16 mid=8
      mount.cifs-6633  [006] ....  7246.944091: smb3_cmd_done: pid=6633 tid=0xe1b781a sid=0x3d9cf8e5 cmd=16 mid=9
      mount.cifs-6633  [006] ....  7246.944163: smb3_cmd_done: pid=6633 tid=0xe1b781a sid=0x3d9cf8e5 cmd=16 mid=10
      mount.cifs-6633  [006] ....  7246.944218: smb3_cmd_err:  pid=6633 tid=0xf9447636 sid=0x3d9cf8e5 cmd=11 mid=11 status=0xc0000225 rc=-2
      mount.cifs-6633  [006] ....  7246.944219: smb3_fsctl_err: xid=0 fid=0xffffffffffffffff tid=0xf9447636 sid=0x3d9cf8e5 class=0 type=393620 rc=-2
      mount.cifs-6633  [007] ....  7246.944353: smb3_cmd_done: pid=6633 tid=0xe1b781a sid=0x3d9cf8e5 cmd=16 mid=12
            bash-2071  [000] ....  7256.903844: smb3_cmd_done: pid=2071 tid=0xe1b781a sid=0x3d9cf8e5 cmd=5 mid=13
            bash-2071  [000] ....  7256.904172: smb3_cmd_done: pid=2071 tid=0xe1b781a sid=0x3d9cf8e5 cmd=16 mid=14
            bash-2071  [000] ....  7256.904471: smb3_cmd_done: pid=2071 tid=0xe1b781a sid=0x3d9cf8e5 cmd=17 mid=15
            bash-2071  [000] ....  7256.904950: smb3_cmd_done: pid=2071 tid=0xe1b781a sid=0x3d9cf8e5 cmd=5 mid=16
            bash-2071  [000] ....  7256.905305: smb3_cmd_done: pid=2071 tid=0xe1b781a sid=0x3d9cf8e5 cmd=17 mid=17
            bash-2071  [000] ....  7256.905688: smb3_cmd_done: pid=2071 tid=0xe1b781a sid=0x3d9cf8e5 cmd=6 mid=18
            bash-2071  [000] ....  7256.905809: smb3_write_done: xid=0 fid=0xd628f511 tid=0xe1b781a sid=0x3d9cf8e5 offset=0x0 len=0x1b

Signed-off-by: Steve French <stfrench@microsoft.com>
Acked-by: Ronnie Sahlberg <lsahlber@redhat.com>
2018-05-27 17:56:35 -05:00