linux-stable/fs/smb/client/trace.h

1328 lines
35 KiB
C
Raw Permalink Normal View History

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-18 02:16:55 +00:00
/* SPDX-License-Identifier: GPL-2.0 */
/*
* Copyright (C) 2018, Microsoft Corporation.
*
* Author(s): Steve French <stfrench@microsoft.com>
*
* Please use this 3-part article as a reference for writing new tracepoints:
* https://lwn.net/Articles/379903/
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-18 02:16:55 +00:00
*/
#undef TRACE_SYSTEM
#define TRACE_SYSTEM cifs
#if !defined(_CIFS_TRACE_H) || defined(TRACE_HEADER_MULTI_READ)
#define _CIFS_TRACE_H
#include <linux/tracepoint.h>
smb3: add dynamic trace points for socket connection In debugging user problems with ip address/DNS issues with smb3 mounts, we sometimes needed additional info on the hostname and ip address. Add two tracepoints, one to show socket connection success and one for failures to connect to the socket. Sample output: mount.cifs-14551 [005] ..... 7636.547906: smb3_connect_done: conn_id=0x1 server=localhost addr=127.0.0.1:445 mount.cifs-14558 [004] ..... 7642.405413: smb3_connect_done: conn_id=0x2 server=smfrench.file.core.windows.net addr=52.239.158.232:445 mount.cifs-14741 [005] ..... 7818.490716: smb3_connect_done: conn_id=0x3 server=::1 addr=[::1]:445/0%0 mount.cifs-14810 [000] ..... 7966.380337: smb3_connect_err: rc=-101 conn_id=0x4 server=::2 addr=[::2]:445/0%0 mount.cifs-14810 [000] ..... 7966.380356: smb3_connect_err: rc=-101 conn_id=0x4 server=::2 addr=[::2]:139/0%0 mount.cifs-14818 [003] ..... 7986.771992: smb3_connect_done: conn_id=0x5 server=127.0.0.9 addr=127.0.0.9:445 mount.cifs-14825 [008] ..... 8008.178109: smb3_connect_err: rc=-115 conn_id=0x6 server=124.23.0.9 addr=124.23.0.9:445 mount.cifs-14825 [008] ..... 8013.298085: smb3_connect_err: rc=-115 conn_id=0x6 server=124.23.0.9 addr=124.23.0.9:139 cifsd-14553 [006] ..... 8036.735615: smb3_reconnect: conn_id=0x1 server=localhost current_mid=32 cifsd-14743 [010] ..... 8036.735644: smb3_reconnect: conn_id=0x3 server=::1 current_mid=29 cifsd-14743 [010] ..... 8039.921740: smb3_connect_err: rc=-111 conn_id=0x3 server=::1 addr=[::1]:445/0%0 cifsd-14553 [008] ..... 8042.993894: smb3_connect_err: rc=-111 conn_id=0x1 server=localhost addr=127.0.0.1:445 cifsd-14743 [010] ..... 8042.993894: smb3_connect_err: rc=-111 conn_id=0x3 server=::1 addr=[::1]:445/0%0 cifsd-14553 [008] ..... 8046.065824: smb3_connect_err: rc=-111 conn_id=0x1 server=localhost addr=127.0.0.1:445 cifsd-14743 [010] ..... 8046.065824: smb3_connect_err: rc=-111 conn_id=0x3 server=::1 addr=[::1]:445/0%0 cifsd-14553 [008] ..... 8049.137796: smb3_connect_done: conn_id=0x1 server=localhost addr=127.0.0.1:445 cifsd-14743 [010] ..... 8049.137796: smb3_connect_done: conn_id=0x3 server=::1 addr=[::1]:445/0%0 Reviewed-by: Paulo Alcantara (SUSE) <pc@cjr.nz> Signed-off-by: Steve French <stfrench@microsoft.com>
2021-11-04 20:56:37 +00:00
#include <linux/net.h>
#include <linux/inet.h>
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-18 02:16:55 +00:00
/*
* Specify enums for tracing information.
*/
#define smb3_tcon_ref_traces \
EM(netfs_trace_tcon_ref_dec_dfs_refer, "DEC DfsRef") \
EM(netfs_trace_tcon_ref_free, "FRE ") \
EM(netfs_trace_tcon_ref_free_fail, "FRE Fail ") \
EM(netfs_trace_tcon_ref_free_ipc, "FRE Ipc ") \
EM(netfs_trace_tcon_ref_free_ipc_fail, "FRE Ipc-F ") \
EM(netfs_trace_tcon_ref_free_reconnect_server, "FRE Reconn") \
EM(netfs_trace_tcon_ref_get_cancelled_close, "GET Cn-Cls") \
EM(netfs_trace_tcon_ref_get_dfs_refer, "GET DfsRef") \
EM(netfs_trace_tcon_ref_get_find, "GET Find ") \
EM(netfs_trace_tcon_ref_get_find_sess_tcon, "GET FndSes") \
EM(netfs_trace_tcon_ref_get_reconnect_server, "GET Reconn") \
EM(netfs_trace_tcon_ref_new, "NEW ") \
EM(netfs_trace_tcon_ref_new_ipc, "NEW Ipc ") \
EM(netfs_trace_tcon_ref_new_reconnect_server, "NEW Reconn") \
EM(netfs_trace_tcon_ref_put_cancelled_close, "PUT Cn-Cls") \
EM(netfs_trace_tcon_ref_put_cancelled_close_fid, "PUT Cn-Fid") \
EM(netfs_trace_tcon_ref_put_cancelled_mid, "PUT Cn-Mid") \
EM(netfs_trace_tcon_ref_put_mnt_ctx, "PUT MntCtx") \
EM(netfs_trace_tcon_ref_put_reconnect_server, "PUT Reconn") \
EM(netfs_trace_tcon_ref_put_tlink, "PUT Tlink ") \
EM(netfs_trace_tcon_ref_see_cancelled_close, "SEE Cn-Cls") \
EM(netfs_trace_tcon_ref_see_fscache_collision, "SEE FV-CO!") \
EM(netfs_trace_tcon_ref_see_fscache_okay, "SEE FV-Ok ") \
EM(netfs_trace_tcon_ref_see_fscache_relinq, "SEE FV-Rlq") \
E_(netfs_trace_tcon_ref_see_umount, "SEE Umount")
#undef EM
#undef E_
/*
* Define those tracing enums.
*/
#ifndef __SMB3_DECLARE_TRACE_ENUMS_ONCE_ONLY
#define __SMB3_DECLARE_TRACE_ENUMS_ONCE_ONLY
#define EM(a, b) a,
#define E_(a, b) a
enum smb3_tcon_ref_trace { smb3_tcon_ref_traces } __mode(byte);
#undef EM
#undef E_
#endif
/*
* Export enum symbols via userspace.
*/
#define EM(a, b) TRACE_DEFINE_ENUM(a);
#define E_(a, b) TRACE_DEFINE_ENUM(a);
smb3_tcon_ref_traces;
#undef EM
#undef E_
/*
* Now redefine the EM() and E_() macros to map the enums to the strings that
* will be printed in the output.
*/
#define EM(a, b) { a, b },
#define E_(a, b) { a, b }
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-18 02:16:55 +00:00
/* For logging errors in read or write */
DECLARE_EVENT_CLASS(smb3_rw_err_class,
TP_PROTO(unsigned int rreq_debug_id,
unsigned int rreq_debug_index,
unsigned int xid,
__u64 fid,
__u32 tid,
__u64 sesid,
__u64 offset,
__u32 len,
int rc),
TP_ARGS(rreq_debug_id, rreq_debug_index,
xid, fid, tid, sesid, offset, len, rc),
TP_STRUCT__entry(
__field(unsigned int, rreq_debug_id)
__field(unsigned int, rreq_debug_index)
__field(unsigned int, xid)
__field(__u64, fid)
__field(__u32, tid)
__field(__u64, sesid)
__field(__u64, offset)
__field(__u32, len)
__field(int, rc)
),
TP_fast_assign(
__entry->rreq_debug_id = rreq_debug_id;
__entry->rreq_debug_index = rreq_debug_index;
__entry->xid = xid;
__entry->fid = fid;
__entry->tid = tid;
__entry->sesid = sesid;
__entry->offset = offset;
__entry->len = len;
__entry->rc = rc;
),
TP_printk("\tR=%08x[%x] xid=%u sid=0x%llx tid=0x%x fid=0x%llx offset=0x%llx len=0x%x rc=%d",
__entry->rreq_debug_id, __entry->rreq_debug_index,
__entry->xid, __entry->sesid, __entry->tid, __entry->fid,
__entry->offset, __entry->len, __entry->rc)
)
#define DEFINE_SMB3_RW_ERR_EVENT(name) \
DEFINE_EVENT(smb3_rw_err_class, smb3_##name, \
TP_PROTO(unsigned int rreq_debug_id, \
unsigned int rreq_debug_index, \
unsigned int xid, \
__u64 fid, \
__u32 tid, \
__u64 sesid, \
__u64 offset, \
__u32 len, \
int rc), \
TP_ARGS(rreq_debug_id, rreq_debug_index, xid, fid, tid, sesid, offset, len, rc))
DEFINE_SMB3_RW_ERR_EVENT(read_err);
/* For logging errors in other file I/O ops */
DECLARE_EVENT_CLASS(smb3_other_err_class,
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-18 02:16:55 +00:00
TP_PROTO(unsigned int xid,
__u64 fid,
__u32 tid,
__u64 sesid,
__u64 offset,
__u32 len,
int rc),
TP_ARGS(xid, fid, tid, sesid, offset, len, rc),
TP_STRUCT__entry(
__field(unsigned int, xid)
__field(__u64, fid)
__field(__u32, tid)
__field(__u64, sesid)
__field(__u64, offset)
__field(__u32, len)
__field(int, rc)
),
TP_fast_assign(
__entry->xid = xid;
__entry->fid = fid;
__entry->tid = tid;
__entry->sesid = sesid;
__entry->offset = offset;
__entry->len = len;
__entry->rc = rc;
),
TP_printk("\txid=%u sid=0x%llx tid=0x%x fid=0x%llx offset=0x%llx len=0x%x rc=%d",
__entry->xid, __entry->sesid, __entry->tid, __entry->fid,
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-18 02:16:55 +00:00
__entry->offset, __entry->len, __entry->rc)
)
#define DEFINE_SMB3_OTHER_ERR_EVENT(name) \
DEFINE_EVENT(smb3_other_err_class, smb3_##name, \
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-18 02:16:55 +00:00
TP_PROTO(unsigned int xid, \
__u64 fid, \
__u32 tid, \
__u64 sesid, \
__u64 offset, \
__u32 len, \
int rc), \
TP_ARGS(xid, fid, tid, sesid, offset, len, rc))
DEFINE_SMB3_OTHER_ERR_EVENT(write_err);
DEFINE_SMB3_OTHER_ERR_EVENT(query_dir_err);
DEFINE_SMB3_OTHER_ERR_EVENT(zero_err);
DEFINE_SMB3_OTHER_ERR_EVENT(falloc_err);
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-18 02:16:55 +00:00
/* For logging successful read or write */
DECLARE_EVENT_CLASS(smb3_rw_done_class,
TP_PROTO(unsigned int rreq_debug_id,
unsigned int rreq_debug_index,
unsigned int xid,
__u64 fid,
__u32 tid,
__u64 sesid,
__u64 offset,
__u32 len),
TP_ARGS(rreq_debug_id, rreq_debug_index,
xid, fid, tid, sesid, offset, len),
TP_STRUCT__entry(
__field(unsigned int, rreq_debug_id)
__field(unsigned int, rreq_debug_index)
__field(unsigned int, xid)
__field(__u64, fid)
__field(__u32, tid)
__field(__u64, sesid)
__field(__u64, offset)
__field(__u32, len)
),
TP_fast_assign(
__entry->rreq_debug_id = rreq_debug_id;
__entry->rreq_debug_index = rreq_debug_index;
__entry->xid = xid;
__entry->fid = fid;
__entry->tid = tid;
__entry->sesid = sesid;
__entry->offset = offset;
__entry->len = len;
),
TP_printk("R=%08x[%x] xid=%u sid=0x%llx tid=0x%x fid=0x%llx offset=0x%llx len=0x%x",
__entry->rreq_debug_id, __entry->rreq_debug_index,
__entry->xid, __entry->sesid, __entry->tid, __entry->fid,
__entry->offset, __entry->len)
)
#define DEFINE_SMB3_RW_DONE_EVENT(name) \
DEFINE_EVENT(smb3_rw_done_class, smb3_##name, \
TP_PROTO(unsigned int rreq_debug_id, \
unsigned int rreq_debug_index, \
unsigned int xid, \
__u64 fid, \
__u32 tid, \
__u64 sesid, \
__u64 offset, \
__u32 len), \
TP_ARGS(rreq_debug_id, rreq_debug_index, xid, fid, tid, sesid, offset, len))
DEFINE_SMB3_RW_DONE_EVENT(read_enter);
DEFINE_SMB3_RW_DONE_EVENT(read_done);
/* For logging successful other op */
DECLARE_EVENT_CLASS(smb3_other_done_class,
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-18 02:16:55 +00:00
TP_PROTO(unsigned int xid,
__u64 fid,
__u32 tid,
__u64 sesid,
__u64 offset,
__u32 len),
TP_ARGS(xid, fid, tid, sesid, offset, len),
TP_STRUCT__entry(
__field(unsigned int, xid)
__field(__u64, fid)
__field(__u32, tid)
__field(__u64, sesid)
__field(__u64, offset)
__field(__u32, len)
),
TP_fast_assign(
__entry->xid = xid;
__entry->fid = fid;
__entry->tid = tid;
__entry->sesid = sesid;
__entry->offset = offset;
__entry->len = len;
),
TP_printk("xid=%u sid=0x%llx tid=0x%x fid=0x%llx offset=0x%llx len=0x%x",
__entry->xid, __entry->sesid, __entry->tid, __entry->fid,
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-18 02:16:55 +00:00
__entry->offset, __entry->len)
)
#define DEFINE_SMB3_OTHER_DONE_EVENT(name) \
DEFINE_EVENT(smb3_other_done_class, smb3_##name, \
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-18 02:16:55 +00:00
TP_PROTO(unsigned int xid, \
__u64 fid, \
__u32 tid, \
__u64 sesid, \
__u64 offset, \
__u32 len), \
TP_ARGS(xid, fid, tid, sesid, offset, len))
DEFINE_SMB3_OTHER_DONE_EVENT(write_enter);
DEFINE_SMB3_OTHER_DONE_EVENT(query_dir_enter);
DEFINE_SMB3_OTHER_DONE_EVENT(zero_enter);
DEFINE_SMB3_OTHER_DONE_EVENT(falloc_enter);
DEFINE_SMB3_OTHER_DONE_EVENT(write_done);
DEFINE_SMB3_OTHER_DONE_EVENT(query_dir_done);
DEFINE_SMB3_OTHER_DONE_EVENT(zero_done);
DEFINE_SMB3_OTHER_DONE_EVENT(falloc_done);
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-18 02:16:55 +00:00
/* For logging successful set EOF (truncate) */
DECLARE_EVENT_CLASS(smb3_eof_class,
TP_PROTO(unsigned int xid,
__u64 fid,
__u32 tid,
__u64 sesid,
__u64 offset),
TP_ARGS(xid, fid, tid, sesid, offset),
TP_STRUCT__entry(
__field(unsigned int, xid)
__field(__u64, fid)
__field(__u32, tid)
__field(__u64, sesid)
__field(__u64, offset)
),
TP_fast_assign(
__entry->xid = xid;
__entry->fid = fid;
__entry->tid = tid;
__entry->sesid = sesid;
__entry->offset = offset;
),
TP_printk("xid=%u sid=0x%llx tid=0x%x fid=0x%llx offset=0x%llx",
__entry->xid, __entry->sesid, __entry->tid, __entry->fid,
__entry->offset)
)
#define DEFINE_SMB3_EOF_EVENT(name) \
DEFINE_EVENT(smb3_eof_class, smb3_##name, \
TP_PROTO(unsigned int xid, \
__u64 fid, \
__u32 tid, \
__u64 sesid, \
__u64 offset), \
TP_ARGS(xid, fid, tid, sesid, offset))
DEFINE_SMB3_EOF_EVENT(set_eof);
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-18 02:16:55 +00:00
/*
* For handle based calls other than read and write, and get/set info
*/
DECLARE_EVENT_CLASS(smb3_fd_class,
TP_PROTO(unsigned int xid,
__u64 fid,
__u32 tid,
__u64 sesid),
TP_ARGS(xid, fid, tid, sesid),
TP_STRUCT__entry(
__field(unsigned int, xid)
__field(__u64, fid)
__field(__u32, tid)
__field(__u64, sesid)
),
TP_fast_assign(
__entry->xid = xid;
__entry->fid = fid;
__entry->tid = tid;
__entry->sesid = sesid;
),
TP_printk("\txid=%u sid=0x%llx tid=0x%x fid=0x%llx",
__entry->xid, __entry->sesid, __entry->tid, __entry->fid)
)
#define DEFINE_SMB3_FD_EVENT(name) \
DEFINE_EVENT(smb3_fd_class, smb3_##name, \
TP_PROTO(unsigned int xid, \
__u64 fid, \
__u32 tid, \
__u64 sesid), \
TP_ARGS(xid, fid, tid, sesid))
DEFINE_SMB3_FD_EVENT(flush_enter);
DEFINE_SMB3_FD_EVENT(flush_done);
DEFINE_SMB3_FD_EVENT(close_enter);
DEFINE_SMB3_FD_EVENT(close_done);
DEFINE_SMB3_FD_EVENT(oplock_not_found);
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-18 02:16:55 +00:00
DECLARE_EVENT_CLASS(smb3_fd_err_class,
TP_PROTO(unsigned int xid,
__u64 fid,
__u32 tid,
__u64 sesid,
int rc),
TP_ARGS(xid, fid, tid, sesid, rc),
TP_STRUCT__entry(
__field(unsigned int, xid)
__field(__u64, fid)
__field(__u32, tid)
__field(__u64, sesid)
__field(int, rc)
),
TP_fast_assign(
__entry->xid = xid;
__entry->fid = fid;
__entry->tid = tid;
__entry->sesid = sesid;
__entry->rc = rc;
),
TP_printk("\txid=%u sid=0x%llx tid=0x%x fid=0x%llx rc=%d",
__entry->xid, __entry->sesid, __entry->tid, __entry->fid,
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-18 02:16:55 +00:00
__entry->rc)
)
#define DEFINE_SMB3_FD_ERR_EVENT(name) \
DEFINE_EVENT(smb3_fd_err_class, smb3_##name, \
TP_PROTO(unsigned int xid, \
__u64 fid, \
__u32 tid, \
__u64 sesid, \
int rc), \
TP_ARGS(xid, fid, tid, sesid, rc))
DEFINE_SMB3_FD_ERR_EVENT(flush_err);
DEFINE_SMB3_FD_ERR_EVENT(lock_err);
DEFINE_SMB3_FD_ERR_EVENT(close_err);
/*
* For handle based query/set info calls
*/
DECLARE_EVENT_CLASS(smb3_inf_enter_class,
TP_PROTO(unsigned int xid,
__u64 fid,
__u32 tid,
__u64 sesid,
__u8 infclass,
__u32 type),
TP_ARGS(xid, fid, tid, sesid, infclass, type),
TP_STRUCT__entry(
__field(unsigned int, xid)
__field(__u64, fid)
__field(__u32, tid)
__field(__u64, sesid)
__field(__u8, infclass)
__field(__u32, type)
),
TP_fast_assign(
__entry->xid = xid;
__entry->fid = fid;
__entry->tid = tid;
__entry->sesid = sesid;
__entry->infclass = infclass;
__entry->type = type;
),
TP_printk("xid=%u sid=0x%llx tid=0x%x fid=0x%llx class=%u type=0x%x",
__entry->xid, __entry->sesid, __entry->tid, __entry->fid,
__entry->infclass, __entry->type)
)
#define DEFINE_SMB3_INF_ENTER_EVENT(name) \
DEFINE_EVENT(smb3_inf_enter_class, smb3_##name, \
TP_PROTO(unsigned int xid, \
__u64 fid, \
__u32 tid, \
__u64 sesid, \
__u8 infclass, \
__u32 type), \
TP_ARGS(xid, fid, tid, sesid, infclass, type))
DEFINE_SMB3_INF_ENTER_EVENT(query_info_enter);
DEFINE_SMB3_INF_ENTER_EVENT(query_info_done);
DEFINE_SMB3_INF_ENTER_EVENT(notify_enter);
DEFINE_SMB3_INF_ENTER_EVENT(notify_done);
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-18 02:16:55 +00:00
DECLARE_EVENT_CLASS(smb3_inf_err_class,
TP_PROTO(unsigned int xid,
__u64 fid,
__u32 tid,
__u64 sesid,
__u8 infclass,
__u32 type,
int rc),
TP_ARGS(xid, fid, tid, sesid, infclass, type, rc),
TP_STRUCT__entry(
__field(unsigned int, xid)
__field(__u64, fid)
__field(__u32, tid)
__field(__u64, sesid)
__field(__u8, infclass)
__field(__u32, type)
__field(int, rc)
),
TP_fast_assign(
__entry->xid = xid;
__entry->fid = fid;
__entry->tid = tid;
__entry->sesid = sesid;
__entry->infclass = infclass;
__entry->type = type;
__entry->rc = rc;
),
TP_printk("xid=%u sid=0x%llx tid=0x%x fid=0x%llx class=%u type=0x%x rc=%d",
__entry->xid, __entry->sesid, __entry->tid, __entry->fid,
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-18 02:16:55 +00:00
__entry->infclass, __entry->type, __entry->rc)
)
#define DEFINE_SMB3_INF_ERR_EVENT(name) \
DEFINE_EVENT(smb3_inf_err_class, smb3_##name, \
TP_PROTO(unsigned int xid, \
__u64 fid, \
__u32 tid, \
__u64 sesid, \
__u8 infclass, \
__u32 type, \
int rc), \
TP_ARGS(xid, fid, tid, sesid, infclass, type, rc))
DEFINE_SMB3_INF_ERR_EVENT(query_info_err);
DEFINE_SMB3_INF_ERR_EVENT(set_info_err);
DEFINE_SMB3_INF_ERR_EVENT(notify_err);
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-18 02:16:55 +00:00
DEFINE_SMB3_INF_ERR_EVENT(fsctl_err);
DECLARE_EVENT_CLASS(smb3_inf_compound_enter_class,
TP_PROTO(unsigned int xid,
__u32 tid,
__u64 sesid,
const char *full_path),
TP_ARGS(xid, tid, sesid, full_path),
TP_STRUCT__entry(
__field(unsigned int, xid)
__field(__u32, tid)
__field(__u64, sesid)
__string(path, full_path)
),
TP_fast_assign(
__entry->xid = xid;
__entry->tid = tid;
__entry->sesid = sesid;
tracing/treewide: Remove second parameter of __assign_str() With the rework of how the __string() handles dynamic strings where it saves off the source string in field in the helper structure[1], the assignment of that value to the trace event field is stored in the helper value and does not need to be passed in again. This means that with: __string(field, mystring) Which use to be assigned with __assign_str(field, mystring), no longer needs the second parameter and it is unused. With this, __assign_str() will now only get a single parameter. There's over 700 users of __assign_str() and because coccinelle does not handle the TRACE_EVENT() macro I ended up using the following sed script: git grep -l __assign_str | while read a ; do sed -e 's/\(__assign_str([^,]*[^ ,]\) *,[^;]*/\1)/' $a > /tmp/test-file; mv /tmp/test-file $a; done I then searched for __assign_str() that did not end with ';' as those were multi line assignments that the sed script above would fail to catch. Note, the same updates will need to be done for: __assign_str_len() __assign_rel_str() __assign_rel_str_len() I tested this with both an allmodconfig and an allyesconfig (build only for both). [1] https://lore.kernel.org/linux-trace-kernel/20240222211442.634192653@goodmis.org/ Link: https://lore.kernel.org/linux-trace-kernel/20240516133454.681ba6a0@rorschach.local.home Cc: Masami Hiramatsu <mhiramat@kernel.org> Cc: Mathieu Desnoyers <mathieu.desnoyers@efficios.com> Cc: Linus Torvalds <torvalds@linux-foundation.org> Cc: Julia Lawall <Julia.Lawall@inria.fr> Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org> Acked-by: Jani Nikula <jani.nikula@intel.com> Acked-by: Christian König <christian.koenig@amd.com> for the amdgpu parts. Acked-by: Thomas Hellström <thomas.hellstrom@linux.intel.com> #for Acked-by: Rafael J. Wysocki <rafael@kernel.org> # for thermal Acked-by: Takashi Iwai <tiwai@suse.de> Acked-by: Darrick J. Wong <djwong@kernel.org> # xfs Tested-by: Guenter Roeck <linux@roeck-us.net>
2024-05-16 17:34:54 +00:00
__assign_str(path);
),
TP_printk("xid=%u sid=0x%llx tid=0x%x path=%s",
__entry->xid, __entry->sesid, __entry->tid,
__get_str(path))
)
#define DEFINE_SMB3_INF_COMPOUND_ENTER_EVENT(name) \
DEFINE_EVENT(smb3_inf_compound_enter_class, smb3_##name, \
TP_PROTO(unsigned int xid, \
__u32 tid, \
__u64 sesid, \
const char *full_path), \
TP_ARGS(xid, tid, sesid, full_path))
DEFINE_SMB3_INF_COMPOUND_ENTER_EVENT(query_info_compound_enter);
DEFINE_SMB3_INF_COMPOUND_ENTER_EVENT(posix_query_info_compound_enter);
DEFINE_SMB3_INF_COMPOUND_ENTER_EVENT(hardlink_enter);
DEFINE_SMB3_INF_COMPOUND_ENTER_EVENT(rename_enter);
DEFINE_SMB3_INF_COMPOUND_ENTER_EVENT(rmdir_enter);
DEFINE_SMB3_INF_COMPOUND_ENTER_EVENT(set_eof_enter);
DEFINE_SMB3_INF_COMPOUND_ENTER_EVENT(set_info_compound_enter);
DEFINE_SMB3_INF_COMPOUND_ENTER_EVENT(set_reparse_compound_enter);
DEFINE_SMB3_INF_COMPOUND_ENTER_EVENT(get_reparse_compound_enter);
DEFINE_SMB3_INF_COMPOUND_ENTER_EVENT(delete_enter);
DEFINE_SMB3_INF_COMPOUND_ENTER_EVENT(mkdir_enter);
DEFINE_SMB3_INF_COMPOUND_ENTER_EVENT(tdis_enter);
DEFINE_SMB3_INF_COMPOUND_ENTER_EVENT(mknod_enter);
DECLARE_EVENT_CLASS(smb3_inf_compound_done_class,
TP_PROTO(unsigned int xid,
__u32 tid,
__u64 sesid),
TP_ARGS(xid, tid, sesid),
TP_STRUCT__entry(
__field(unsigned int, xid)
__field(__u32, tid)
__field(__u64, sesid)
),
TP_fast_assign(
__entry->xid = xid;
__entry->tid = tid;
__entry->sesid = sesid;
),
TP_printk("xid=%u sid=0x%llx tid=0x%x",
__entry->xid, __entry->sesid, __entry->tid)
)
#define DEFINE_SMB3_INF_COMPOUND_DONE_EVENT(name) \
DEFINE_EVENT(smb3_inf_compound_done_class, smb3_##name, \
TP_PROTO(unsigned int xid, \
__u32 tid, \
__u64 sesid), \
TP_ARGS(xid, tid, sesid))
DEFINE_SMB3_INF_COMPOUND_DONE_EVENT(query_info_compound_done);
DEFINE_SMB3_INF_COMPOUND_DONE_EVENT(posix_query_info_compound_done);
DEFINE_SMB3_INF_COMPOUND_DONE_EVENT(hardlink_done);
DEFINE_SMB3_INF_COMPOUND_DONE_EVENT(rename_done);
DEFINE_SMB3_INF_COMPOUND_DONE_EVENT(rmdir_done);
DEFINE_SMB3_INF_COMPOUND_DONE_EVENT(set_eof_done);
DEFINE_SMB3_INF_COMPOUND_DONE_EVENT(set_info_compound_done);
DEFINE_SMB3_INF_COMPOUND_DONE_EVENT(set_reparse_compound_done);
DEFINE_SMB3_INF_COMPOUND_DONE_EVENT(get_reparse_compound_done);
DEFINE_SMB3_INF_COMPOUND_DONE_EVENT(query_wsl_ea_compound_done);
DEFINE_SMB3_INF_COMPOUND_DONE_EVENT(delete_done);
DEFINE_SMB3_INF_COMPOUND_DONE_EVENT(mkdir_done);
DEFINE_SMB3_INF_COMPOUND_DONE_EVENT(tdis_done);
DEFINE_SMB3_INF_COMPOUND_DONE_EVENT(mknod_done);
DECLARE_EVENT_CLASS(smb3_inf_compound_err_class,
TP_PROTO(unsigned int xid,
__u32 tid,
__u64 sesid,
int rc),
TP_ARGS(xid, tid, sesid, rc),
TP_STRUCT__entry(
__field(unsigned int, xid)
__field(__u32, tid)
__field(__u64, sesid)
__field(int, rc)
),
TP_fast_assign(
__entry->xid = xid;
__entry->tid = tid;
__entry->sesid = sesid;
__entry->rc = rc;
),
TP_printk("xid=%u sid=0x%llx tid=0x%x rc=%d",
__entry->xid, __entry->sesid, __entry->tid,
__entry->rc)
)
#define DEFINE_SMB3_INF_COMPOUND_ERR_EVENT(name) \
DEFINE_EVENT(smb3_inf_compound_err_class, smb3_##name, \
TP_PROTO(unsigned int xid, \
__u32 tid, \
__u64 sesid, \
int rc), \
TP_ARGS(xid, tid, sesid, rc))
DEFINE_SMB3_INF_COMPOUND_ERR_EVENT(query_info_compound_err);
DEFINE_SMB3_INF_COMPOUND_ERR_EVENT(posix_query_info_compound_err);
DEFINE_SMB3_INF_COMPOUND_ERR_EVENT(hardlink_err);
DEFINE_SMB3_INF_COMPOUND_ERR_EVENT(rename_err);
DEFINE_SMB3_INF_COMPOUND_ERR_EVENT(rmdir_err);
DEFINE_SMB3_INF_COMPOUND_ERR_EVENT(set_eof_err);
DEFINE_SMB3_INF_COMPOUND_ERR_EVENT(set_info_compound_err);
DEFINE_SMB3_INF_COMPOUND_ERR_EVENT(set_reparse_compound_err);
DEFINE_SMB3_INF_COMPOUND_ERR_EVENT(get_reparse_compound_err);
DEFINE_SMB3_INF_COMPOUND_ERR_EVENT(query_wsl_ea_compound_err);
DEFINE_SMB3_INF_COMPOUND_ERR_EVENT(mkdir_err);
DEFINE_SMB3_INF_COMPOUND_ERR_EVENT(delete_err);
DEFINE_SMB3_INF_COMPOUND_ERR_EVENT(tdis_err);
DEFINE_SMB3_INF_COMPOUND_ERR_EVENT(mknod_err);
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-18 02:16:55 +00:00
/*
* For logging SMB3 Status code and Command for responses which return errors
*/
DECLARE_EVENT_CLASS(smb3_cmd_err_class,
TP_PROTO(__u32 tid,
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-18 02:16:55 +00:00
__u64 sesid,
__u16 cmd,
__u64 mid,
__u32 status,
int rc),
TP_ARGS(tid, sesid, cmd, mid, status, rc),
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-18 02:16:55 +00:00
TP_STRUCT__entry(
__field(__u32, tid)
__field(__u64, sesid)
__field(__u16, cmd)
__field(__u64, mid)
__field(__u32, status)
__field(int, rc)
),
TP_fast_assign(
__entry->tid = tid;
__entry->sesid = sesid;
__entry->cmd = cmd;
__entry->mid = mid;
__entry->status = status;
__entry->rc = rc;
),
TP_printk("\tsid=0x%llx tid=0x%x cmd=%u mid=%llu status=0x%x rc=%d",
__entry->sesid, __entry->tid, __entry->cmd, __entry->mid,
__entry->status, __entry->rc)
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-18 02:16:55 +00:00
)
#define DEFINE_SMB3_CMD_ERR_EVENT(name) \
DEFINE_EVENT(smb3_cmd_err_class, smb3_##name, \
TP_PROTO(__u32 tid, \
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-18 02:16:55 +00:00
__u64 sesid, \
__u16 cmd, \
__u64 mid, \
__u32 status, \
int rc), \
TP_ARGS(tid, sesid, cmd, mid, status, rc))
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-18 02:16:55 +00:00
DEFINE_SMB3_CMD_ERR_EVENT(cmd_err);
DECLARE_EVENT_CLASS(smb3_cmd_done_class,
TP_PROTO(__u32 tid,
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-18 02:16:55 +00:00
__u64 sesid,
__u16 cmd,
__u64 mid),
TP_ARGS(tid, sesid, cmd, mid),
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-18 02:16:55 +00:00
TP_STRUCT__entry(
__field(__u32, tid)
__field(__u64, sesid)
__field(__u16, cmd)
__field(__u64, mid)
),
TP_fast_assign(
__entry->tid = tid;
__entry->sesid = sesid;
__entry->cmd = cmd;
__entry->mid = mid;
),
TP_printk("\tsid=0x%llx tid=0x%x cmd=%u mid=%llu",
__entry->sesid, __entry->tid,
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-18 02:16:55 +00:00
__entry->cmd, __entry->mid)
)
#define DEFINE_SMB3_CMD_DONE_EVENT(name) \
DEFINE_EVENT(smb3_cmd_done_class, smb3_##name, \
TP_PROTO(__u32 tid, \
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-18 02:16:55 +00:00
__u64 sesid, \
__u16 cmd, \
__u64 mid), \
TP_ARGS(tid, sesid, cmd, mid))
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-18 02:16:55 +00:00
DEFINE_SMB3_CMD_DONE_EVENT(cmd_enter);
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-18 02:16:55 +00:00
DEFINE_SMB3_CMD_DONE_EVENT(cmd_done);
DEFINE_SMB3_CMD_DONE_EVENT(ses_expired);
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-18 02:16:55 +00:00
DECLARE_EVENT_CLASS(smb3_mid_class,
TP_PROTO(__u16 cmd,
__u64 mid,
__u32 pid,
unsigned long when_sent,
unsigned long when_received),
TP_ARGS(cmd, mid, pid, when_sent, when_received),
TP_STRUCT__entry(
__field(__u16, cmd)
__field(__u64, mid)
__field(__u32, pid)
__field(unsigned long, when_sent)
__field(unsigned long, when_received)
),
TP_fast_assign(
__entry->cmd = cmd;
__entry->mid = mid;
__entry->pid = pid;
__entry->when_sent = when_sent;
__entry->when_received = when_received;
),
TP_printk("\tcmd=%u mid=%llu pid=%u, when_sent=%lu when_rcv=%lu",
__entry->cmd, __entry->mid, __entry->pid, __entry->when_sent,
__entry->when_received)
)
#define DEFINE_SMB3_MID_EVENT(name) \
DEFINE_EVENT(smb3_mid_class, smb3_##name, \
TP_PROTO(__u16 cmd, \
__u64 mid, \
__u32 pid, \
unsigned long when_sent, \
unsigned long when_received), \
TP_ARGS(cmd, mid, pid, when_sent, when_received))
DEFINE_SMB3_MID_EVENT(slow_rsp);
DECLARE_EVENT_CLASS(smb3_exit_err_class,
TP_PROTO(unsigned int xid,
const char *func_name,
int rc),
TP_ARGS(xid, func_name, rc),
TP_STRUCT__entry(
__field(unsigned int, xid)
__string(func_name, func_name)
__field(int, rc)
),
TP_fast_assign(
__entry->xid = xid;
tracing/treewide: Remove second parameter of __assign_str() With the rework of how the __string() handles dynamic strings where it saves off the source string in field in the helper structure[1], the assignment of that value to the trace event field is stored in the helper value and does not need to be passed in again. This means that with: __string(field, mystring) Which use to be assigned with __assign_str(field, mystring), no longer needs the second parameter and it is unused. With this, __assign_str() will now only get a single parameter. There's over 700 users of __assign_str() and because coccinelle does not handle the TRACE_EVENT() macro I ended up using the following sed script: git grep -l __assign_str | while read a ; do sed -e 's/\(__assign_str([^,]*[^ ,]\) *,[^;]*/\1)/' $a > /tmp/test-file; mv /tmp/test-file $a; done I then searched for __assign_str() that did not end with ';' as those were multi line assignments that the sed script above would fail to catch. Note, the same updates will need to be done for: __assign_str_len() __assign_rel_str() __assign_rel_str_len() I tested this with both an allmodconfig and an allyesconfig (build only for both). [1] https://lore.kernel.org/linux-trace-kernel/20240222211442.634192653@goodmis.org/ Link: https://lore.kernel.org/linux-trace-kernel/20240516133454.681ba6a0@rorschach.local.home Cc: Masami Hiramatsu <mhiramat@kernel.org> Cc: Mathieu Desnoyers <mathieu.desnoyers@efficios.com> Cc: Linus Torvalds <torvalds@linux-foundation.org> Cc: Julia Lawall <Julia.Lawall@inria.fr> Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org> Acked-by: Jani Nikula <jani.nikula@intel.com> Acked-by: Christian König <christian.koenig@amd.com> for the amdgpu parts. Acked-by: Thomas Hellström <thomas.hellstrom@linux.intel.com> #for Acked-by: Rafael J. Wysocki <rafael@kernel.org> # for thermal Acked-by: Takashi Iwai <tiwai@suse.de> Acked-by: Darrick J. Wong <djwong@kernel.org> # xfs Tested-by: Guenter Roeck <linux@roeck-us.net>
2024-05-16 17:34:54 +00:00
__assign_str(func_name);
__entry->rc = rc;
),
TP_printk("\t%s: xid=%u rc=%d",
__get_str(func_name), __entry->xid, __entry->rc)
)
#define DEFINE_SMB3_EXIT_ERR_EVENT(name) \
DEFINE_EVENT(smb3_exit_err_class, smb3_##name, \
TP_PROTO(unsigned int xid, \
const char *func_name, \
int rc), \
TP_ARGS(xid, func_name, rc))
DEFINE_SMB3_EXIT_ERR_EVENT(exit_err);
DECLARE_EVENT_CLASS(smb3_sync_err_class,
TP_PROTO(unsigned long ino,
int rc),
TP_ARGS(ino, rc),
TP_STRUCT__entry(
__field(unsigned long, ino)
__field(int, rc)
),
TP_fast_assign(
__entry->ino = ino;
__entry->rc = rc;
),
TP_printk("\tino=%lu rc=%d",
__entry->ino, __entry->rc)
)
#define DEFINE_SMB3_SYNC_ERR_EVENT(name) \
DEFINE_EVENT(smb3_sync_err_class, cifs_##name, \
TP_PROTO(unsigned long ino, \
int rc), \
TP_ARGS(ino, rc))
DEFINE_SMB3_SYNC_ERR_EVENT(fsync_err);
DEFINE_SMB3_SYNC_ERR_EVENT(flush_err);
DECLARE_EVENT_CLASS(smb3_enter_exit_class,
TP_PROTO(unsigned int xid,
const char *func_name),
TP_ARGS(xid, func_name),
TP_STRUCT__entry(
__field(unsigned int, xid)
__string(func_name, func_name)
),
TP_fast_assign(
__entry->xid = xid;
tracing/treewide: Remove second parameter of __assign_str() With the rework of how the __string() handles dynamic strings where it saves off the source string in field in the helper structure[1], the assignment of that value to the trace event field is stored in the helper value and does not need to be passed in again. This means that with: __string(field, mystring) Which use to be assigned with __assign_str(field, mystring), no longer needs the second parameter and it is unused. With this, __assign_str() will now only get a single parameter. There's over 700 users of __assign_str() and because coccinelle does not handle the TRACE_EVENT() macro I ended up using the following sed script: git grep -l __assign_str | while read a ; do sed -e 's/\(__assign_str([^,]*[^ ,]\) *,[^;]*/\1)/' $a > /tmp/test-file; mv /tmp/test-file $a; done I then searched for __assign_str() that did not end with ';' as those were multi line assignments that the sed script above would fail to catch. Note, the same updates will need to be done for: __assign_str_len() __assign_rel_str() __assign_rel_str_len() I tested this with both an allmodconfig and an allyesconfig (build only for both). [1] https://lore.kernel.org/linux-trace-kernel/20240222211442.634192653@goodmis.org/ Link: https://lore.kernel.org/linux-trace-kernel/20240516133454.681ba6a0@rorschach.local.home Cc: Masami Hiramatsu <mhiramat@kernel.org> Cc: Mathieu Desnoyers <mathieu.desnoyers@efficios.com> Cc: Linus Torvalds <torvalds@linux-foundation.org> Cc: Julia Lawall <Julia.Lawall@inria.fr> Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org> Acked-by: Jani Nikula <jani.nikula@intel.com> Acked-by: Christian König <christian.koenig@amd.com> for the amdgpu parts. Acked-by: Thomas Hellström <thomas.hellstrom@linux.intel.com> #for Acked-by: Rafael J. Wysocki <rafael@kernel.org> # for thermal Acked-by: Takashi Iwai <tiwai@suse.de> Acked-by: Darrick J. Wong <djwong@kernel.org> # xfs Tested-by: Guenter Roeck <linux@roeck-us.net>
2024-05-16 17:34:54 +00:00
__assign_str(func_name);
),
TP_printk("\t%s: xid=%u",
__get_str(func_name), __entry->xid)
)
#define DEFINE_SMB3_ENTER_EXIT_EVENT(name) \
DEFINE_EVENT(smb3_enter_exit_class, smb3_##name, \
TP_PROTO(unsigned int xid, \
const char *func_name), \
TP_ARGS(xid, func_name))
DEFINE_SMB3_ENTER_EXIT_EVENT(enter);
DEFINE_SMB3_ENTER_EXIT_EVENT(exit_done);
/*
* For SMB2/SMB3 tree connect
*/
DECLARE_EVENT_CLASS(smb3_tcon_class,
TP_PROTO(unsigned int xid,
__u32 tid,
__u64 sesid,
const char *unc_name,
int rc),
TP_ARGS(xid, tid, sesid, unc_name, rc),
TP_STRUCT__entry(
__field(unsigned int, xid)
__field(__u32, tid)
__field(__u64, sesid)
cifs: Fix slab-out-of-bounds when tracing SMB tcon This patch fixes the following KASAN report: [ 779.044746] BUG: KASAN: slab-out-of-bounds in string+0xab/0x180 [ 779.044750] Read of size 1 at addr ffff88814f327968 by task trace-cmd/2812 [ 779.044756] CPU: 1 PID: 2812 Comm: trace-cmd Not tainted 5.1.0-rc1+ #62 [ 779.044760] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.12.0-0-ga698c89-prebuilt.qemu.org 04/01/2014 [ 779.044761] Call Trace: [ 779.044769] dump_stack+0x5b/0x90 [ 779.044775] ? string+0xab/0x180 [ 779.044781] print_address_description+0x6c/0x23c [ 779.044787] ? string+0xab/0x180 [ 779.044792] ? string+0xab/0x180 [ 779.044797] kasan_report.cold.3+0x1a/0x32 [ 779.044803] ? string+0xab/0x180 [ 779.044809] string+0xab/0x180 [ 779.044816] ? widen_string+0x160/0x160 [ 779.044822] ? vsnprintf+0x5bf/0x7f0 [ 779.044829] vsnprintf+0x4e7/0x7f0 [ 779.044836] ? pointer+0x4a0/0x4a0 [ 779.044841] ? seq_buf_vprintf+0x79/0xc0 [ 779.044848] seq_buf_vprintf+0x62/0xc0 [ 779.044855] trace_seq_printf+0x113/0x210 [ 779.044861] ? trace_seq_puts+0x110/0x110 [ 779.044867] ? trace_raw_output_prep+0xd8/0x110 [ 779.044876] trace_raw_output_smb3_tcon_class+0x9f/0xc0 [ 779.044882] print_trace_line+0x377/0x890 [ 779.044888] ? tracing_buffers_read+0x300/0x300 [ 779.044893] ? ring_buffer_read+0x58/0x70 [ 779.044899] s_show+0x6e/0x140 [ 779.044906] seq_read+0x505/0x6a0 [ 779.044913] vfs_read+0xaf/0x1b0 [ 779.044919] ksys_read+0xa1/0x130 [ 779.044925] ? kernel_write+0xa0/0xa0 [ 779.044931] ? __do_page_fault+0x3d5/0x620 [ 779.044938] do_syscall_64+0x63/0x150 [ 779.044944] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 779.044949] RIP: 0033:0x7f62c2c2db31 [ 779.044955] Code: fe ff ff 48 8d 3d 17 9e 09 00 48 83 ec 08 e8 96 02 02 00 66 0f 1f 44 00 00 8b 05 fa fc 2c 00 48 63 ff 85 c0 75 13 31 c0 0f 05 <48> 3d 00 f0 ff ff 77 57 f3 c3 0f 1f 44 00 00 55 53 48 89 d5 48 89 [ 779.044958] RSP: 002b:00007ffd6e116678 EFLAGS: 00000246 ORIG_RAX: 0000000000000000 [ 779.044964] RAX: ffffffffffffffda RBX: 0000560a38be9260 RCX: 00007f62c2c2db31 [ 779.044966] RDX: 0000000000002000 RSI: 00007ffd6e116710 RDI: 0000000000000003 [ 779.044966] RDX: 0000000000002000 RSI: 00007ffd6e116710 RDI: 0000000000000003 [ 779.044969] RBP: 00007f62c2ef5420 R08: 0000000000000000 R09: 0000000000000003 [ 779.044972] R10: ffffffffffffffa8 R11: 0000000000000246 R12: 00007ffd6e116710 [ 779.044975] R13: 0000000000002000 R14: 0000000000000d68 R15: 0000000000002000 [ 779.044981] Allocated by task 1257: [ 779.044987] __kasan_kmalloc.constprop.5+0xc1/0xd0 [ 779.044992] kmem_cache_alloc+0xad/0x1a0 [ 779.044997] getname_flags+0x6c/0x2a0 [ 779.045003] user_path_at_empty+0x1d/0x40 [ 779.045008] do_faccessat+0x12a/0x330 [ 779.045012] do_syscall_64+0x63/0x150 [ 779.045017] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 779.045019] Freed by task 1257: [ 779.045023] __kasan_slab_free+0x12e/0x180 [ 779.045029] kmem_cache_free+0x85/0x1b0 [ 779.045034] filename_lookup.part.70+0x176/0x250 [ 779.045039] do_faccessat+0x12a/0x330 [ 779.045043] do_syscall_64+0x63/0x150 [ 779.045048] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 779.045052] The buggy address belongs to the object at ffff88814f326600 which belongs to the cache names_cache of size 4096 [ 779.045057] The buggy address is located 872 bytes to the right of 4096-byte region [ffff88814f326600, ffff88814f327600) [ 779.045058] The buggy address belongs to the page: [ 779.045062] page:ffffea00053cc800 count:1 mapcount:0 mapping:ffff88815b191b40 index:0x0 compound_mapcount: 0 [ 779.045067] flags: 0x200000000010200(slab|head) [ 779.045075] raw: 0200000000010200 dead000000000100 dead000000000200 ffff88815b191b40 [ 779.045081] raw: 0000000000000000 0000000000070007 00000001ffffffff 0000000000000000 [ 779.045083] page dumped because: kasan: bad access detected [ 779.045085] Memory state around the buggy address: [ 779.045089] ffff88814f327800: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc [ 779.045093] ffff88814f327880: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc [ 779.045097] >ffff88814f327900: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc [ 779.045099] ^ [ 779.045103] ffff88814f327980: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc [ 779.045107] ffff88814f327a00: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc [ 779.045109] ================================================================== [ 779.045110] Disabling lock debugging due to kernel taint Correctly assign tree name str for smb3_tcon event. Signed-off-by: Paulo Alcantara (SUSE) <paulo@paulo.ac> Signed-off-by: Steve French <stfrench@microsoft.com>
2019-03-21 22:31:22 +00:00
__string(name, unc_name)
__field(int, rc)
),
TP_fast_assign(
__entry->xid = xid;
__entry->tid = tid;
__entry->sesid = sesid;
tracing/treewide: Remove second parameter of __assign_str() With the rework of how the __string() handles dynamic strings where it saves off the source string in field in the helper structure[1], the assignment of that value to the trace event field is stored in the helper value and does not need to be passed in again. This means that with: __string(field, mystring) Which use to be assigned with __assign_str(field, mystring), no longer needs the second parameter and it is unused. With this, __assign_str() will now only get a single parameter. There's over 700 users of __assign_str() and because coccinelle does not handle the TRACE_EVENT() macro I ended up using the following sed script: git grep -l __assign_str | while read a ; do sed -e 's/\(__assign_str([^,]*[^ ,]\) *,[^;]*/\1)/' $a > /tmp/test-file; mv /tmp/test-file $a; done I then searched for __assign_str() that did not end with ';' as those were multi line assignments that the sed script above would fail to catch. Note, the same updates will need to be done for: __assign_str_len() __assign_rel_str() __assign_rel_str_len() I tested this with both an allmodconfig and an allyesconfig (build only for both). [1] https://lore.kernel.org/linux-trace-kernel/20240222211442.634192653@goodmis.org/ Link: https://lore.kernel.org/linux-trace-kernel/20240516133454.681ba6a0@rorschach.local.home Cc: Masami Hiramatsu <mhiramat@kernel.org> Cc: Mathieu Desnoyers <mathieu.desnoyers@efficios.com> Cc: Linus Torvalds <torvalds@linux-foundation.org> Cc: Julia Lawall <Julia.Lawall@inria.fr> Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org> Acked-by: Jani Nikula <jani.nikula@intel.com> Acked-by: Christian König <christian.koenig@amd.com> for the amdgpu parts. Acked-by: Thomas Hellström <thomas.hellstrom@linux.intel.com> #for Acked-by: Rafael J. Wysocki <rafael@kernel.org> # for thermal Acked-by: Takashi Iwai <tiwai@suse.de> Acked-by: Darrick J. Wong <djwong@kernel.org> # xfs Tested-by: Guenter Roeck <linux@roeck-us.net>
2024-05-16 17:34:54 +00:00
__assign_str(name);
__entry->rc = rc;
),
TP_printk("xid=%u sid=0x%llx tid=0x%x unc_name=%s rc=%d",
__entry->xid, __entry->sesid, __entry->tid,
cifs: Fix slab-out-of-bounds when tracing SMB tcon This patch fixes the following KASAN report: [ 779.044746] BUG: KASAN: slab-out-of-bounds in string+0xab/0x180 [ 779.044750] Read of size 1 at addr ffff88814f327968 by task trace-cmd/2812 [ 779.044756] CPU: 1 PID: 2812 Comm: trace-cmd Not tainted 5.1.0-rc1+ #62 [ 779.044760] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.12.0-0-ga698c89-prebuilt.qemu.org 04/01/2014 [ 779.044761] Call Trace: [ 779.044769] dump_stack+0x5b/0x90 [ 779.044775] ? string+0xab/0x180 [ 779.044781] print_address_description+0x6c/0x23c [ 779.044787] ? string+0xab/0x180 [ 779.044792] ? string+0xab/0x180 [ 779.044797] kasan_report.cold.3+0x1a/0x32 [ 779.044803] ? string+0xab/0x180 [ 779.044809] string+0xab/0x180 [ 779.044816] ? widen_string+0x160/0x160 [ 779.044822] ? vsnprintf+0x5bf/0x7f0 [ 779.044829] vsnprintf+0x4e7/0x7f0 [ 779.044836] ? pointer+0x4a0/0x4a0 [ 779.044841] ? seq_buf_vprintf+0x79/0xc0 [ 779.044848] seq_buf_vprintf+0x62/0xc0 [ 779.044855] trace_seq_printf+0x113/0x210 [ 779.044861] ? trace_seq_puts+0x110/0x110 [ 779.044867] ? trace_raw_output_prep+0xd8/0x110 [ 779.044876] trace_raw_output_smb3_tcon_class+0x9f/0xc0 [ 779.044882] print_trace_line+0x377/0x890 [ 779.044888] ? tracing_buffers_read+0x300/0x300 [ 779.044893] ? ring_buffer_read+0x58/0x70 [ 779.044899] s_show+0x6e/0x140 [ 779.044906] seq_read+0x505/0x6a0 [ 779.044913] vfs_read+0xaf/0x1b0 [ 779.044919] ksys_read+0xa1/0x130 [ 779.044925] ? kernel_write+0xa0/0xa0 [ 779.044931] ? __do_page_fault+0x3d5/0x620 [ 779.044938] do_syscall_64+0x63/0x150 [ 779.044944] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 779.044949] RIP: 0033:0x7f62c2c2db31 [ 779.044955] Code: fe ff ff 48 8d 3d 17 9e 09 00 48 83 ec 08 e8 96 02 02 00 66 0f 1f 44 00 00 8b 05 fa fc 2c 00 48 63 ff 85 c0 75 13 31 c0 0f 05 <48> 3d 00 f0 ff ff 77 57 f3 c3 0f 1f 44 00 00 55 53 48 89 d5 48 89 [ 779.044958] RSP: 002b:00007ffd6e116678 EFLAGS: 00000246 ORIG_RAX: 0000000000000000 [ 779.044964] RAX: ffffffffffffffda RBX: 0000560a38be9260 RCX: 00007f62c2c2db31 [ 779.044966] RDX: 0000000000002000 RSI: 00007ffd6e116710 RDI: 0000000000000003 [ 779.044966] RDX: 0000000000002000 RSI: 00007ffd6e116710 RDI: 0000000000000003 [ 779.044969] RBP: 00007f62c2ef5420 R08: 0000000000000000 R09: 0000000000000003 [ 779.044972] R10: ffffffffffffffa8 R11: 0000000000000246 R12: 00007ffd6e116710 [ 779.044975] R13: 0000000000002000 R14: 0000000000000d68 R15: 0000000000002000 [ 779.044981] Allocated by task 1257: [ 779.044987] __kasan_kmalloc.constprop.5+0xc1/0xd0 [ 779.044992] kmem_cache_alloc+0xad/0x1a0 [ 779.044997] getname_flags+0x6c/0x2a0 [ 779.045003] user_path_at_empty+0x1d/0x40 [ 779.045008] do_faccessat+0x12a/0x330 [ 779.045012] do_syscall_64+0x63/0x150 [ 779.045017] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 779.045019] Freed by task 1257: [ 779.045023] __kasan_slab_free+0x12e/0x180 [ 779.045029] kmem_cache_free+0x85/0x1b0 [ 779.045034] filename_lookup.part.70+0x176/0x250 [ 779.045039] do_faccessat+0x12a/0x330 [ 779.045043] do_syscall_64+0x63/0x150 [ 779.045048] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 779.045052] The buggy address belongs to the object at ffff88814f326600 which belongs to the cache names_cache of size 4096 [ 779.045057] The buggy address is located 872 bytes to the right of 4096-byte region [ffff88814f326600, ffff88814f327600) [ 779.045058] The buggy address belongs to the page: [ 779.045062] page:ffffea00053cc800 count:1 mapcount:0 mapping:ffff88815b191b40 index:0x0 compound_mapcount: 0 [ 779.045067] flags: 0x200000000010200(slab|head) [ 779.045075] raw: 0200000000010200 dead000000000100 dead000000000200 ffff88815b191b40 [ 779.045081] raw: 0000000000000000 0000000000070007 00000001ffffffff 0000000000000000 [ 779.045083] page dumped because: kasan: bad access detected [ 779.045085] Memory state around the buggy address: [ 779.045089] ffff88814f327800: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc [ 779.045093] ffff88814f327880: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc [ 779.045097] >ffff88814f327900: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc [ 779.045099] ^ [ 779.045103] ffff88814f327980: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc [ 779.045107] ffff88814f327a00: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc [ 779.045109] ================================================================== [ 779.045110] Disabling lock debugging due to kernel taint Correctly assign tree name str for smb3_tcon event. Signed-off-by: Paulo Alcantara (SUSE) <paulo@paulo.ac> Signed-off-by: Steve French <stfrench@microsoft.com>
2019-03-21 22:31:22 +00:00
__get_str(name), __entry->rc)
)
#define DEFINE_SMB3_TCON_EVENT(name) \
DEFINE_EVENT(smb3_tcon_class, smb3_##name, \
TP_PROTO(unsigned int xid, \
__u32 tid, \
__u64 sesid, \
const char *unc_name, \
int rc), \
TP_ARGS(xid, tid, sesid, unc_name, rc))
DEFINE_SMB3_TCON_EVENT(tcon);
DEFINE_SMB3_TCON_EVENT(qfs_done);
/*
* For smb2/smb3 open (including create and mkdir) calls
*/
DECLARE_EVENT_CLASS(smb3_open_enter_class,
TP_PROTO(unsigned int xid,
__u32 tid,
__u64 sesid,
const char *full_path,
int create_options,
int desired_access),
TP_ARGS(xid, tid, sesid, full_path, create_options, desired_access),
TP_STRUCT__entry(
__field(unsigned int, xid)
__field(__u32, tid)
__field(__u64, sesid)
__string(path, full_path)
__field(int, create_options)
__field(int, desired_access)
),
TP_fast_assign(
__entry->xid = xid;
__entry->tid = tid;
__entry->sesid = sesid;
tracing/treewide: Remove second parameter of __assign_str() With the rework of how the __string() handles dynamic strings where it saves off the source string in field in the helper structure[1], the assignment of that value to the trace event field is stored in the helper value and does not need to be passed in again. This means that with: __string(field, mystring) Which use to be assigned with __assign_str(field, mystring), no longer needs the second parameter and it is unused. With this, __assign_str() will now only get a single parameter. There's over 700 users of __assign_str() and because coccinelle does not handle the TRACE_EVENT() macro I ended up using the following sed script: git grep -l __assign_str | while read a ; do sed -e 's/\(__assign_str([^,]*[^ ,]\) *,[^;]*/\1)/' $a > /tmp/test-file; mv /tmp/test-file $a; done I then searched for __assign_str() that did not end with ';' as those were multi line assignments that the sed script above would fail to catch. Note, the same updates will need to be done for: __assign_str_len() __assign_rel_str() __assign_rel_str_len() I tested this with both an allmodconfig and an allyesconfig (build only for both). [1] https://lore.kernel.org/linux-trace-kernel/20240222211442.634192653@goodmis.org/ Link: https://lore.kernel.org/linux-trace-kernel/20240516133454.681ba6a0@rorschach.local.home Cc: Masami Hiramatsu <mhiramat@kernel.org> Cc: Mathieu Desnoyers <mathieu.desnoyers@efficios.com> Cc: Linus Torvalds <torvalds@linux-foundation.org> Cc: Julia Lawall <Julia.Lawall@inria.fr> Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org> Acked-by: Jani Nikula <jani.nikula@intel.com> Acked-by: Christian König <christian.koenig@amd.com> for the amdgpu parts. Acked-by: Thomas Hellström <thomas.hellstrom@linux.intel.com> #for Acked-by: Rafael J. Wysocki <rafael@kernel.org> # for thermal Acked-by: Takashi Iwai <tiwai@suse.de> Acked-by: Darrick J. Wong <djwong@kernel.org> # xfs Tested-by: Guenter Roeck <linux@roeck-us.net>
2024-05-16 17:34:54 +00:00
__assign_str(path);
__entry->create_options = create_options;
__entry->desired_access = desired_access;
),
TP_printk("xid=%u sid=0x%llx tid=0x%x path=%s cr_opts=0x%x des_access=0x%x",
__entry->xid, __entry->sesid, __entry->tid, __get_str(path),
__entry->create_options, __entry->desired_access)
)
#define DEFINE_SMB3_OPEN_ENTER_EVENT(name) \
DEFINE_EVENT(smb3_open_enter_class, smb3_##name, \
TP_PROTO(unsigned int xid, \
__u32 tid, \
__u64 sesid, \
const char *full_path, \
int create_options, \
int desired_access), \
TP_ARGS(xid, tid, sesid, full_path, create_options, desired_access))
DEFINE_SMB3_OPEN_ENTER_EVENT(open_enter);
DEFINE_SMB3_OPEN_ENTER_EVENT(posix_mkdir_enter);
DECLARE_EVENT_CLASS(smb3_open_err_class,
TP_PROTO(unsigned int xid,
__u32 tid,
__u64 sesid,
int create_options,
int desired_access,
int rc),
TP_ARGS(xid, tid, sesid, create_options, desired_access, rc),
TP_STRUCT__entry(
__field(unsigned int, xid)
__field(__u32, tid)
__field(__u64, sesid)
__field(int, create_options)
__field(int, desired_access)
__field(int, rc)
),
TP_fast_assign(
__entry->xid = xid;
__entry->tid = tid;
__entry->sesid = sesid;
__entry->create_options = create_options;
__entry->desired_access = desired_access;
__entry->rc = rc;
),
TP_printk("xid=%u sid=0x%llx tid=0x%x cr_opts=0x%x des_access=0x%x rc=%d",
__entry->xid, __entry->sesid, __entry->tid,
__entry->create_options, __entry->desired_access, __entry->rc)
)
#define DEFINE_SMB3_OPEN_ERR_EVENT(name) \
DEFINE_EVENT(smb3_open_err_class, smb3_##name, \
TP_PROTO(unsigned int xid, \
__u32 tid, \
__u64 sesid, \
int create_options, \
int desired_access, \
int rc), \
TP_ARGS(xid, tid, sesid, create_options, desired_access, rc))
DEFINE_SMB3_OPEN_ERR_EVENT(open_err);
DEFINE_SMB3_OPEN_ERR_EVENT(posix_mkdir_err);
DECLARE_EVENT_CLASS(smb3_open_done_class,
TP_PROTO(unsigned int xid,
__u64 fid,
__u32 tid,
__u64 sesid,
int create_options,
int desired_access),
TP_ARGS(xid, fid, tid, sesid, create_options, desired_access),
TP_STRUCT__entry(
__field(unsigned int, xid)
__field(__u64, fid)
__field(__u32, tid)
__field(__u64, sesid)
__field(int, create_options)
__field(int, desired_access)
),
TP_fast_assign(
__entry->xid = xid;
__entry->fid = fid;
__entry->tid = tid;
__entry->sesid = sesid;
__entry->create_options = create_options;
__entry->desired_access = desired_access;
),
TP_printk("xid=%u sid=0x%llx tid=0x%x fid=0x%llx cr_opts=0x%x des_access=0x%x",
__entry->xid, __entry->sesid, __entry->tid, __entry->fid,
__entry->create_options, __entry->desired_access)
)
#define DEFINE_SMB3_OPEN_DONE_EVENT(name) \
DEFINE_EVENT(smb3_open_done_class, smb3_##name, \
TP_PROTO(unsigned int xid, \
__u64 fid, \
__u32 tid, \
__u64 sesid, \
int create_options, \
int desired_access), \
TP_ARGS(xid, fid, tid, sesid, create_options, desired_access))
DEFINE_SMB3_OPEN_DONE_EVENT(open_done);
DEFINE_SMB3_OPEN_DONE_EVENT(posix_mkdir_done);
DECLARE_EVENT_CLASS(smb3_lease_done_class,
TP_PROTO(__u32 lease_state,
__u32 tid,
__u64 sesid,
__u64 lease_key_low,
__u64 lease_key_high),
TP_ARGS(lease_state, tid, sesid, lease_key_low, lease_key_high),
TP_STRUCT__entry(
__field(__u32, lease_state)
__field(__u32, tid)
__field(__u64, sesid)
__field(__u64, lease_key_low)
__field(__u64, lease_key_high)
),
TP_fast_assign(
__entry->lease_state = lease_state;
__entry->tid = tid;
__entry->sesid = sesid;
__entry->lease_key_low = lease_key_low;
__entry->lease_key_high = lease_key_high;
),
TP_printk("sid=0x%llx tid=0x%x lease_key=0x%llx%llx lease_state=0x%x",
__entry->sesid, __entry->tid, __entry->lease_key_high,
__entry->lease_key_low, __entry->lease_state)
)
#define DEFINE_SMB3_LEASE_DONE_EVENT(name) \
DEFINE_EVENT(smb3_lease_done_class, smb3_##name, \
TP_PROTO(__u32 lease_state, \
__u32 tid, \
__u64 sesid, \
__u64 lease_key_low, \
__u64 lease_key_high), \
TP_ARGS(lease_state, tid, sesid, lease_key_low, lease_key_high))
DEFINE_SMB3_LEASE_DONE_EVENT(lease_done);
DEFINE_SMB3_LEASE_DONE_EVENT(lease_not_found);
DECLARE_EVENT_CLASS(smb3_lease_err_class,
TP_PROTO(__u32 lease_state,
__u32 tid,
__u64 sesid,
__u64 lease_key_low,
__u64 lease_key_high,
int rc),
TP_ARGS(lease_state, tid, sesid, lease_key_low, lease_key_high, rc),
TP_STRUCT__entry(
__field(__u32, lease_state)
__field(__u32, tid)
__field(__u64, sesid)
__field(__u64, lease_key_low)
__field(__u64, lease_key_high)
__field(int, rc)
),
TP_fast_assign(
__entry->lease_state = lease_state;
__entry->tid = tid;
__entry->sesid = sesid;
__entry->lease_key_low = lease_key_low;
__entry->lease_key_high = lease_key_high;
__entry->rc = rc;
),
TP_printk("sid=0x%llx tid=0x%x lease_key=0x%llx%llx lease_state=0x%x rc=%d",
__entry->sesid, __entry->tid, __entry->lease_key_high,
__entry->lease_key_low, __entry->lease_state, __entry->rc)
)
#define DEFINE_SMB3_LEASE_ERR_EVENT(name) \
DEFINE_EVENT(smb3_lease_err_class, smb3_##name, \
TP_PROTO(__u32 lease_state, \
__u32 tid, \
__u64 sesid, \
__u64 lease_key_low, \
__u64 lease_key_high, \
int rc), \
TP_ARGS(lease_state, tid, sesid, lease_key_low, lease_key_high, rc))
DEFINE_SMB3_LEASE_ERR_EVENT(lease_err);
smb3: add dynamic trace points for socket connection In debugging user problems with ip address/DNS issues with smb3 mounts, we sometimes needed additional info on the hostname and ip address. Add two tracepoints, one to show socket connection success and one for failures to connect to the socket. Sample output: mount.cifs-14551 [005] ..... 7636.547906: smb3_connect_done: conn_id=0x1 server=localhost addr=127.0.0.1:445 mount.cifs-14558 [004] ..... 7642.405413: smb3_connect_done: conn_id=0x2 server=smfrench.file.core.windows.net addr=52.239.158.232:445 mount.cifs-14741 [005] ..... 7818.490716: smb3_connect_done: conn_id=0x3 server=::1 addr=[::1]:445/0%0 mount.cifs-14810 [000] ..... 7966.380337: smb3_connect_err: rc=-101 conn_id=0x4 server=::2 addr=[::2]:445/0%0 mount.cifs-14810 [000] ..... 7966.380356: smb3_connect_err: rc=-101 conn_id=0x4 server=::2 addr=[::2]:139/0%0 mount.cifs-14818 [003] ..... 7986.771992: smb3_connect_done: conn_id=0x5 server=127.0.0.9 addr=127.0.0.9:445 mount.cifs-14825 [008] ..... 8008.178109: smb3_connect_err: rc=-115 conn_id=0x6 server=124.23.0.9 addr=124.23.0.9:445 mount.cifs-14825 [008] ..... 8013.298085: smb3_connect_err: rc=-115 conn_id=0x6 server=124.23.0.9 addr=124.23.0.9:139 cifsd-14553 [006] ..... 8036.735615: smb3_reconnect: conn_id=0x1 server=localhost current_mid=32 cifsd-14743 [010] ..... 8036.735644: smb3_reconnect: conn_id=0x3 server=::1 current_mid=29 cifsd-14743 [010] ..... 8039.921740: smb3_connect_err: rc=-111 conn_id=0x3 server=::1 addr=[::1]:445/0%0 cifsd-14553 [008] ..... 8042.993894: smb3_connect_err: rc=-111 conn_id=0x1 server=localhost addr=127.0.0.1:445 cifsd-14743 [010] ..... 8042.993894: smb3_connect_err: rc=-111 conn_id=0x3 server=::1 addr=[::1]:445/0%0 cifsd-14553 [008] ..... 8046.065824: smb3_connect_err: rc=-111 conn_id=0x1 server=localhost addr=127.0.0.1:445 cifsd-14743 [010] ..... 8046.065824: smb3_connect_err: rc=-111 conn_id=0x3 server=::1 addr=[::1]:445/0%0 cifsd-14553 [008] ..... 8049.137796: smb3_connect_done: conn_id=0x1 server=localhost addr=127.0.0.1:445 cifsd-14743 [010] ..... 8049.137796: smb3_connect_done: conn_id=0x3 server=::1 addr=[::1]:445/0%0 Reviewed-by: Paulo Alcantara (SUSE) <pc@cjr.nz> Signed-off-by: Steve French <stfrench@microsoft.com>
2021-11-04 20:56:37 +00:00
DECLARE_EVENT_CLASS(smb3_connect_class,
TP_PROTO(char *hostname,
__u64 conn_id,
const struct __kernel_sockaddr_storage *dst_addr),
TP_ARGS(hostname, conn_id, dst_addr),
TP_STRUCT__entry(
__string(hostname, hostname)
__field(__u64, conn_id)
__array(__u8, dst_addr, sizeof(struct sockaddr_storage))
),
TP_fast_assign(
struct sockaddr_storage *pss = NULL;
__entry->conn_id = conn_id;
pss = (struct sockaddr_storage *)__entry->dst_addr;
*pss = *dst_addr;
tracing/treewide: Remove second parameter of __assign_str() With the rework of how the __string() handles dynamic strings where it saves off the source string in field in the helper structure[1], the assignment of that value to the trace event field is stored in the helper value and does not need to be passed in again. This means that with: __string(field, mystring) Which use to be assigned with __assign_str(field, mystring), no longer needs the second parameter and it is unused. With this, __assign_str() will now only get a single parameter. There's over 700 users of __assign_str() and because coccinelle does not handle the TRACE_EVENT() macro I ended up using the following sed script: git grep -l __assign_str | while read a ; do sed -e 's/\(__assign_str([^,]*[^ ,]\) *,[^;]*/\1)/' $a > /tmp/test-file; mv /tmp/test-file $a; done I then searched for __assign_str() that did not end with ';' as those were multi line assignments that the sed script above would fail to catch. Note, the same updates will need to be done for: __assign_str_len() __assign_rel_str() __assign_rel_str_len() I tested this with both an allmodconfig and an allyesconfig (build only for both). [1] https://lore.kernel.org/linux-trace-kernel/20240222211442.634192653@goodmis.org/ Link: https://lore.kernel.org/linux-trace-kernel/20240516133454.681ba6a0@rorschach.local.home Cc: Masami Hiramatsu <mhiramat@kernel.org> Cc: Mathieu Desnoyers <mathieu.desnoyers@efficios.com> Cc: Linus Torvalds <torvalds@linux-foundation.org> Cc: Julia Lawall <Julia.Lawall@inria.fr> Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org> Acked-by: Jani Nikula <jani.nikula@intel.com> Acked-by: Christian König <christian.koenig@amd.com> for the amdgpu parts. Acked-by: Thomas Hellström <thomas.hellstrom@linux.intel.com> #for Acked-by: Rafael J. Wysocki <rafael@kernel.org> # for thermal Acked-by: Takashi Iwai <tiwai@suse.de> Acked-by: Darrick J. Wong <djwong@kernel.org> # xfs Tested-by: Guenter Roeck <linux@roeck-us.net>
2024-05-16 17:34:54 +00:00
__assign_str(hostname);
smb3: add dynamic trace points for socket connection In debugging user problems with ip address/DNS issues with smb3 mounts, we sometimes needed additional info on the hostname and ip address. Add two tracepoints, one to show socket connection success and one for failures to connect to the socket. Sample output: mount.cifs-14551 [005] ..... 7636.547906: smb3_connect_done: conn_id=0x1 server=localhost addr=127.0.0.1:445 mount.cifs-14558 [004] ..... 7642.405413: smb3_connect_done: conn_id=0x2 server=smfrench.file.core.windows.net addr=52.239.158.232:445 mount.cifs-14741 [005] ..... 7818.490716: smb3_connect_done: conn_id=0x3 server=::1 addr=[::1]:445/0%0 mount.cifs-14810 [000] ..... 7966.380337: smb3_connect_err: rc=-101 conn_id=0x4 server=::2 addr=[::2]:445/0%0 mount.cifs-14810 [000] ..... 7966.380356: smb3_connect_err: rc=-101 conn_id=0x4 server=::2 addr=[::2]:139/0%0 mount.cifs-14818 [003] ..... 7986.771992: smb3_connect_done: conn_id=0x5 server=127.0.0.9 addr=127.0.0.9:445 mount.cifs-14825 [008] ..... 8008.178109: smb3_connect_err: rc=-115 conn_id=0x6 server=124.23.0.9 addr=124.23.0.9:445 mount.cifs-14825 [008] ..... 8013.298085: smb3_connect_err: rc=-115 conn_id=0x6 server=124.23.0.9 addr=124.23.0.9:139 cifsd-14553 [006] ..... 8036.735615: smb3_reconnect: conn_id=0x1 server=localhost current_mid=32 cifsd-14743 [010] ..... 8036.735644: smb3_reconnect: conn_id=0x3 server=::1 current_mid=29 cifsd-14743 [010] ..... 8039.921740: smb3_connect_err: rc=-111 conn_id=0x3 server=::1 addr=[::1]:445/0%0 cifsd-14553 [008] ..... 8042.993894: smb3_connect_err: rc=-111 conn_id=0x1 server=localhost addr=127.0.0.1:445 cifsd-14743 [010] ..... 8042.993894: smb3_connect_err: rc=-111 conn_id=0x3 server=::1 addr=[::1]:445/0%0 cifsd-14553 [008] ..... 8046.065824: smb3_connect_err: rc=-111 conn_id=0x1 server=localhost addr=127.0.0.1:445 cifsd-14743 [010] ..... 8046.065824: smb3_connect_err: rc=-111 conn_id=0x3 server=::1 addr=[::1]:445/0%0 cifsd-14553 [008] ..... 8049.137796: smb3_connect_done: conn_id=0x1 server=localhost addr=127.0.0.1:445 cifsd-14743 [010] ..... 8049.137796: smb3_connect_done: conn_id=0x3 server=::1 addr=[::1]:445/0%0 Reviewed-by: Paulo Alcantara (SUSE) <pc@cjr.nz> Signed-off-by: Steve French <stfrench@microsoft.com>
2021-11-04 20:56:37 +00:00
),
TP_printk("conn_id=0x%llx server=%s addr=%pISpsfc",
__entry->conn_id,
__get_str(hostname),
__entry->dst_addr)
)
#define DEFINE_SMB3_CONNECT_EVENT(name) \
DEFINE_EVENT(smb3_connect_class, smb3_##name, \
TP_PROTO(char *hostname, \
__u64 conn_id, \
const struct __kernel_sockaddr_storage *addr), \
TP_ARGS(hostname, conn_id, addr))
DEFINE_SMB3_CONNECT_EVENT(connect_done);
DEFINE_SMB3_CONNECT_EVENT(smbd_connect_done);
DEFINE_SMB3_CONNECT_EVENT(smbd_connect_err);
smb3: add dynamic trace points for socket connection In debugging user problems with ip address/DNS issues with smb3 mounts, we sometimes needed additional info on the hostname and ip address. Add two tracepoints, one to show socket connection success and one for failures to connect to the socket. Sample output: mount.cifs-14551 [005] ..... 7636.547906: smb3_connect_done: conn_id=0x1 server=localhost addr=127.0.0.1:445 mount.cifs-14558 [004] ..... 7642.405413: smb3_connect_done: conn_id=0x2 server=smfrench.file.core.windows.net addr=52.239.158.232:445 mount.cifs-14741 [005] ..... 7818.490716: smb3_connect_done: conn_id=0x3 server=::1 addr=[::1]:445/0%0 mount.cifs-14810 [000] ..... 7966.380337: smb3_connect_err: rc=-101 conn_id=0x4 server=::2 addr=[::2]:445/0%0 mount.cifs-14810 [000] ..... 7966.380356: smb3_connect_err: rc=-101 conn_id=0x4 server=::2 addr=[::2]:139/0%0 mount.cifs-14818 [003] ..... 7986.771992: smb3_connect_done: conn_id=0x5 server=127.0.0.9 addr=127.0.0.9:445 mount.cifs-14825 [008] ..... 8008.178109: smb3_connect_err: rc=-115 conn_id=0x6 server=124.23.0.9 addr=124.23.0.9:445 mount.cifs-14825 [008] ..... 8013.298085: smb3_connect_err: rc=-115 conn_id=0x6 server=124.23.0.9 addr=124.23.0.9:139 cifsd-14553 [006] ..... 8036.735615: smb3_reconnect: conn_id=0x1 server=localhost current_mid=32 cifsd-14743 [010] ..... 8036.735644: smb3_reconnect: conn_id=0x3 server=::1 current_mid=29 cifsd-14743 [010] ..... 8039.921740: smb3_connect_err: rc=-111 conn_id=0x3 server=::1 addr=[::1]:445/0%0 cifsd-14553 [008] ..... 8042.993894: smb3_connect_err: rc=-111 conn_id=0x1 server=localhost addr=127.0.0.1:445 cifsd-14743 [010] ..... 8042.993894: smb3_connect_err: rc=-111 conn_id=0x3 server=::1 addr=[::1]:445/0%0 cifsd-14553 [008] ..... 8046.065824: smb3_connect_err: rc=-111 conn_id=0x1 server=localhost addr=127.0.0.1:445 cifsd-14743 [010] ..... 8046.065824: smb3_connect_err: rc=-111 conn_id=0x3 server=::1 addr=[::1]:445/0%0 cifsd-14553 [008] ..... 8049.137796: smb3_connect_done: conn_id=0x1 server=localhost addr=127.0.0.1:445 cifsd-14743 [010] ..... 8049.137796: smb3_connect_done: conn_id=0x3 server=::1 addr=[::1]:445/0%0 Reviewed-by: Paulo Alcantara (SUSE) <pc@cjr.nz> Signed-off-by: Steve French <stfrench@microsoft.com>
2021-11-04 20:56:37 +00:00
DECLARE_EVENT_CLASS(smb3_connect_err_class,
TP_PROTO(char *hostname, __u64 conn_id,
const struct __kernel_sockaddr_storage *dst_addr, int rc),
TP_ARGS(hostname, conn_id, dst_addr, rc),
TP_STRUCT__entry(
__string(hostname, hostname)
__field(__u64, conn_id)
__array(__u8, dst_addr, sizeof(struct sockaddr_storage))
__field(int, rc)
),
TP_fast_assign(
struct sockaddr_storage *pss = NULL;
__entry->conn_id = conn_id;
__entry->rc = rc;
pss = (struct sockaddr_storage *)__entry->dst_addr;
*pss = *dst_addr;
tracing/treewide: Remove second parameter of __assign_str() With the rework of how the __string() handles dynamic strings where it saves off the source string in field in the helper structure[1], the assignment of that value to the trace event field is stored in the helper value and does not need to be passed in again. This means that with: __string(field, mystring) Which use to be assigned with __assign_str(field, mystring), no longer needs the second parameter and it is unused. With this, __assign_str() will now only get a single parameter. There's over 700 users of __assign_str() and because coccinelle does not handle the TRACE_EVENT() macro I ended up using the following sed script: git grep -l __assign_str | while read a ; do sed -e 's/\(__assign_str([^,]*[^ ,]\) *,[^;]*/\1)/' $a > /tmp/test-file; mv /tmp/test-file $a; done I then searched for __assign_str() that did not end with ';' as those were multi line assignments that the sed script above would fail to catch. Note, the same updates will need to be done for: __assign_str_len() __assign_rel_str() __assign_rel_str_len() I tested this with both an allmodconfig and an allyesconfig (build only for both). [1] https://lore.kernel.org/linux-trace-kernel/20240222211442.634192653@goodmis.org/ Link: https://lore.kernel.org/linux-trace-kernel/20240516133454.681ba6a0@rorschach.local.home Cc: Masami Hiramatsu <mhiramat@kernel.org> Cc: Mathieu Desnoyers <mathieu.desnoyers@efficios.com> Cc: Linus Torvalds <torvalds@linux-foundation.org> Cc: Julia Lawall <Julia.Lawall@inria.fr> Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org> Acked-by: Jani Nikula <jani.nikula@intel.com> Acked-by: Christian König <christian.koenig@amd.com> for the amdgpu parts. Acked-by: Thomas Hellström <thomas.hellstrom@linux.intel.com> #for Acked-by: Rafael J. Wysocki <rafael@kernel.org> # for thermal Acked-by: Takashi Iwai <tiwai@suse.de> Acked-by: Darrick J. Wong <djwong@kernel.org> # xfs Tested-by: Guenter Roeck <linux@roeck-us.net>
2024-05-16 17:34:54 +00:00
__assign_str(hostname);
smb3: add dynamic trace points for socket connection In debugging user problems with ip address/DNS issues with smb3 mounts, we sometimes needed additional info on the hostname and ip address. Add two tracepoints, one to show socket connection success and one for failures to connect to the socket. Sample output: mount.cifs-14551 [005] ..... 7636.547906: smb3_connect_done: conn_id=0x1 server=localhost addr=127.0.0.1:445 mount.cifs-14558 [004] ..... 7642.405413: smb3_connect_done: conn_id=0x2 server=smfrench.file.core.windows.net addr=52.239.158.232:445 mount.cifs-14741 [005] ..... 7818.490716: smb3_connect_done: conn_id=0x3 server=::1 addr=[::1]:445/0%0 mount.cifs-14810 [000] ..... 7966.380337: smb3_connect_err: rc=-101 conn_id=0x4 server=::2 addr=[::2]:445/0%0 mount.cifs-14810 [000] ..... 7966.380356: smb3_connect_err: rc=-101 conn_id=0x4 server=::2 addr=[::2]:139/0%0 mount.cifs-14818 [003] ..... 7986.771992: smb3_connect_done: conn_id=0x5 server=127.0.0.9 addr=127.0.0.9:445 mount.cifs-14825 [008] ..... 8008.178109: smb3_connect_err: rc=-115 conn_id=0x6 server=124.23.0.9 addr=124.23.0.9:445 mount.cifs-14825 [008] ..... 8013.298085: smb3_connect_err: rc=-115 conn_id=0x6 server=124.23.0.9 addr=124.23.0.9:139 cifsd-14553 [006] ..... 8036.735615: smb3_reconnect: conn_id=0x1 server=localhost current_mid=32 cifsd-14743 [010] ..... 8036.735644: smb3_reconnect: conn_id=0x3 server=::1 current_mid=29 cifsd-14743 [010] ..... 8039.921740: smb3_connect_err: rc=-111 conn_id=0x3 server=::1 addr=[::1]:445/0%0 cifsd-14553 [008] ..... 8042.993894: smb3_connect_err: rc=-111 conn_id=0x1 server=localhost addr=127.0.0.1:445 cifsd-14743 [010] ..... 8042.993894: smb3_connect_err: rc=-111 conn_id=0x3 server=::1 addr=[::1]:445/0%0 cifsd-14553 [008] ..... 8046.065824: smb3_connect_err: rc=-111 conn_id=0x1 server=localhost addr=127.0.0.1:445 cifsd-14743 [010] ..... 8046.065824: smb3_connect_err: rc=-111 conn_id=0x3 server=::1 addr=[::1]:445/0%0 cifsd-14553 [008] ..... 8049.137796: smb3_connect_done: conn_id=0x1 server=localhost addr=127.0.0.1:445 cifsd-14743 [010] ..... 8049.137796: smb3_connect_done: conn_id=0x3 server=::1 addr=[::1]:445/0%0 Reviewed-by: Paulo Alcantara (SUSE) <pc@cjr.nz> Signed-off-by: Steve French <stfrench@microsoft.com>
2021-11-04 20:56:37 +00:00
),
TP_printk("rc=%d conn_id=0x%llx server=%s addr=%pISpsfc",
__entry->rc,
__entry->conn_id,
__get_str(hostname),
__entry->dst_addr)
)
#define DEFINE_SMB3_CONNECT_ERR_EVENT(name) \
DEFINE_EVENT(smb3_connect_err_class, smb3_##name, \
TP_PROTO(char *hostname, \
__u64 conn_id, \
const struct __kernel_sockaddr_storage *addr, \
int rc), \
TP_ARGS(hostname, conn_id, addr, rc))
DEFINE_SMB3_CONNECT_ERR_EVENT(connect_err);
DECLARE_EVENT_CLASS(smb3_reconnect_class,
TP_PROTO(__u64 currmid,
__u64 conn_id,
char *hostname),
TP_ARGS(currmid, conn_id, hostname),
TP_STRUCT__entry(
__field(__u64, currmid)
__field(__u64, conn_id)
__string(hostname, hostname)
),
TP_fast_assign(
__entry->currmid = currmid;
__entry->conn_id = conn_id;
tracing/treewide: Remove second parameter of __assign_str() With the rework of how the __string() handles dynamic strings where it saves off the source string in field in the helper structure[1], the assignment of that value to the trace event field is stored in the helper value and does not need to be passed in again. This means that with: __string(field, mystring) Which use to be assigned with __assign_str(field, mystring), no longer needs the second parameter and it is unused. With this, __assign_str() will now only get a single parameter. There's over 700 users of __assign_str() and because coccinelle does not handle the TRACE_EVENT() macro I ended up using the following sed script: git grep -l __assign_str | while read a ; do sed -e 's/\(__assign_str([^,]*[^ ,]\) *,[^;]*/\1)/' $a > /tmp/test-file; mv /tmp/test-file $a; done I then searched for __assign_str() that did not end with ';' as those were multi line assignments that the sed script above would fail to catch. Note, the same updates will need to be done for: __assign_str_len() __assign_rel_str() __assign_rel_str_len() I tested this with both an allmodconfig and an allyesconfig (build only for both). [1] https://lore.kernel.org/linux-trace-kernel/20240222211442.634192653@goodmis.org/ Link: https://lore.kernel.org/linux-trace-kernel/20240516133454.681ba6a0@rorschach.local.home Cc: Masami Hiramatsu <mhiramat@kernel.org> Cc: Mathieu Desnoyers <mathieu.desnoyers@efficios.com> Cc: Linus Torvalds <torvalds@linux-foundation.org> Cc: Julia Lawall <Julia.Lawall@inria.fr> Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org> Acked-by: Jani Nikula <jani.nikula@intel.com> Acked-by: Christian König <christian.koenig@amd.com> for the amdgpu parts. Acked-by: Thomas Hellström <thomas.hellstrom@linux.intel.com> #for Acked-by: Rafael J. Wysocki <rafael@kernel.org> # for thermal Acked-by: Takashi Iwai <tiwai@suse.de> Acked-by: Darrick J. Wong <djwong@kernel.org> # xfs Tested-by: Guenter Roeck <linux@roeck-us.net>
2024-05-16 17:34:54 +00:00
__assign_str(hostname);
),
TP_printk("conn_id=0x%llx server=%s current_mid=%llu",
__entry->conn_id,
__get_str(hostname),
__entry->currmid)
)
#define DEFINE_SMB3_RECONNECT_EVENT(name) \
DEFINE_EVENT(smb3_reconnect_class, smb3_##name, \
TP_PROTO(__u64 currmid, \
__u64 conn_id, \
char *hostname), \
TP_ARGS(currmid, conn_id, hostname))
DEFINE_SMB3_RECONNECT_EVENT(reconnect);
DEFINE_SMB3_RECONNECT_EVENT(partial_send_reconnect);
DECLARE_EVENT_CLASS(smb3_ses_class,
TP_PROTO(__u64 sesid),
TP_ARGS(sesid),
TP_STRUCT__entry(
__field(__u64, sesid)
),
TP_fast_assign(
__entry->sesid = sesid;
),
TP_printk("sid=0x%llx",
__entry->sesid)
)
#define DEFINE_SMB3_SES_EVENT(name) \
DEFINE_EVENT(smb3_ses_class, smb3_##name, \
TP_PROTO(__u64 sesid), \
TP_ARGS(sesid))
DEFINE_SMB3_SES_EVENT(ses_not_found);
DECLARE_EVENT_CLASS(smb3_ioctl_class,
TP_PROTO(unsigned int xid,
__u64 fid,
unsigned int command),
TP_ARGS(xid, fid, command),
TP_STRUCT__entry(
__field(unsigned int, xid)
__field(__u64, fid)
__field(unsigned int, command)
),
TP_fast_assign(
__entry->xid = xid;
__entry->fid = fid;
__entry->command = command;
),
TP_printk("xid=%u fid=0x%llx ioctl cmd=0x%x",
__entry->xid, __entry->fid, __entry->command)
)
#define DEFINE_SMB3_IOCTL_EVENT(name) \
DEFINE_EVENT(smb3_ioctl_class, smb3_##name, \
TP_PROTO(unsigned int xid, \
__u64 fid, \
unsigned int command), \
TP_ARGS(xid, fid, command))
DEFINE_SMB3_IOCTL_EVENT(ioctl);
DECLARE_EVENT_CLASS(smb3_credit_class,
TP_PROTO(__u64 currmid,
__u64 conn_id,
char *hostname,
int credits,
int credits_to_add,
int in_flight),
TP_ARGS(currmid, conn_id, hostname, credits, credits_to_add, in_flight),
TP_STRUCT__entry(
__field(__u64, currmid)
__field(__u64, conn_id)
__string(hostname, hostname)
__field(int, credits)
__field(int, credits_to_add)
__field(int, in_flight)
),
TP_fast_assign(
__entry->currmid = currmid;
__entry->conn_id = conn_id;
tracing/treewide: Remove second parameter of __assign_str() With the rework of how the __string() handles dynamic strings where it saves off the source string in field in the helper structure[1], the assignment of that value to the trace event field is stored in the helper value and does not need to be passed in again. This means that with: __string(field, mystring) Which use to be assigned with __assign_str(field, mystring), no longer needs the second parameter and it is unused. With this, __assign_str() will now only get a single parameter. There's over 700 users of __assign_str() and because coccinelle does not handle the TRACE_EVENT() macro I ended up using the following sed script: git grep -l __assign_str | while read a ; do sed -e 's/\(__assign_str([^,]*[^ ,]\) *,[^;]*/\1)/' $a > /tmp/test-file; mv /tmp/test-file $a; done I then searched for __assign_str() that did not end with ';' as those were multi line assignments that the sed script above would fail to catch. Note, the same updates will need to be done for: __assign_str_len() __assign_rel_str() __assign_rel_str_len() I tested this with both an allmodconfig and an allyesconfig (build only for both). [1] https://lore.kernel.org/linux-trace-kernel/20240222211442.634192653@goodmis.org/ Link: https://lore.kernel.org/linux-trace-kernel/20240516133454.681ba6a0@rorschach.local.home Cc: Masami Hiramatsu <mhiramat@kernel.org> Cc: Mathieu Desnoyers <mathieu.desnoyers@efficios.com> Cc: Linus Torvalds <torvalds@linux-foundation.org> Cc: Julia Lawall <Julia.Lawall@inria.fr> Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org> Acked-by: Jani Nikula <jani.nikula@intel.com> Acked-by: Christian König <christian.koenig@amd.com> for the amdgpu parts. Acked-by: Thomas Hellström <thomas.hellstrom@linux.intel.com> #for Acked-by: Rafael J. Wysocki <rafael@kernel.org> # for thermal Acked-by: Takashi Iwai <tiwai@suse.de> Acked-by: Darrick J. Wong <djwong@kernel.org> # xfs Tested-by: Guenter Roeck <linux@roeck-us.net>
2024-05-16 17:34:54 +00:00
__assign_str(hostname);
__entry->credits = credits;
__entry->credits_to_add = credits_to_add;
__entry->in_flight = in_flight;
),
TP_printk("conn_id=0x%llx server=%s current_mid=%llu "
"credits=%d credit_change=%d in_flight=%d",
__entry->conn_id,
__get_str(hostname),
__entry->currmid,
__entry->credits,
__entry->credits_to_add,
__entry->in_flight)
)
#define DEFINE_SMB3_CREDIT_EVENT(name) \
DEFINE_EVENT(smb3_credit_class, smb3_##name, \
TP_PROTO(__u64 currmid, \
__u64 conn_id, \
char *hostname, \
int credits, \
int credits_to_add, \
int in_flight), \
TP_ARGS(currmid, conn_id, hostname, credits, credits_to_add, in_flight))
DEFINE_SMB3_CREDIT_EVENT(reconnect_with_invalid_credits);
DEFINE_SMB3_CREDIT_EVENT(reconnect_detected);
DEFINE_SMB3_CREDIT_EVENT(credit_timeout);
DEFINE_SMB3_CREDIT_EVENT(insufficient_credits);
DEFINE_SMB3_CREDIT_EVENT(too_many_credits);
DEFINE_SMB3_CREDIT_EVENT(add_credits);
DEFINE_SMB3_CREDIT_EVENT(adj_credits);
DEFINE_SMB3_CREDIT_EVENT(hdr_credits);
DEFINE_SMB3_CREDIT_EVENT(nblk_credits);
DEFINE_SMB3_CREDIT_EVENT(pend_credits);
DEFINE_SMB3_CREDIT_EVENT(wait_credits);
DEFINE_SMB3_CREDIT_EVENT(waitff_credits);
DEFINE_SMB3_CREDIT_EVENT(overflow_credits);
DEFINE_SMB3_CREDIT_EVENT(set_credits);
TRACE_EVENT(smb3_tcon_ref,
TP_PROTO(unsigned int tcon_debug_id, int ref,
enum smb3_tcon_ref_trace trace),
TP_ARGS(tcon_debug_id, ref, trace),
TP_STRUCT__entry(
__field(unsigned int, tcon)
__field(int, ref)
__field(enum smb3_tcon_ref_trace, trace)
),
TP_fast_assign(
__entry->tcon = tcon_debug_id;
__entry->ref = ref;
__entry->trace = trace;
),
TP_printk("TC=%08x %s r=%u",
__entry->tcon,
__print_symbolic(__entry->trace, smb3_tcon_ref_traces),
__entry->ref)
);
#undef EM
#undef E_
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-18 02:16:55 +00:00
#endif /* _CIFS_TRACE_H */
#undef TRACE_INCLUDE_PATH
#define TRACE_INCLUDE_PATH .
#define TRACE_INCLUDE_FILE trace
#include <trace/define_trace.h>