Add tracepoints for reconnecting an smb3 session
Example output (from trace-cmd) with the patch
(showing the session marked for reconnect, the stat failing, and then
the subsequent SMB3 commands after the server comes back up).
The "smb3_reconnect" event is the new one.
cifsd-25993 [000] .... 29635.368265: smb3_reconnect: server=localhost current_mid=0x1e
stat-26200 [001] .... 29638.516403: smb3_enter: cifs_revalidate_dentry_attr: xid=22
stat-26200 [001] .... 29648.723296: smb3_exit_err: cifs_revalidate_dentry_attr: xid=22 rc=-112
kworker/0:1-22830 [000] .... 29653.850947: smb3_cmd_done: sid=0x0 tid=0x0 cmd=0 mid=0
kworker/0:1-22830 [000] .... 29653.851191: smb3_cmd_err: sid=0x8ae4683c tid=0x0 cmd=1 mid=1 status=0xc0000016 rc=-5
kworker/0:1-22830 [000] .... 29653.855254: smb3_cmd_done: sid=0x8ae4683c tid=0x0 cmd=1 mid=2
kworker/0:1-22830 [000] .... 29653.855482: smb3_cmd_done: sid=0x8ae4683c tid=0x8084f30d cmd=3 mid=3
--
Example output (from trace-cmd) with the patch
(showing the session marked for reconnect, the stat failing, and then
the subsequent SMB3 commands after the server comes back up).
The "smb3_reconnect" event is the new one.
cifsd-25993 [000] .... 29635.368265: smb3_reconnect: server=localhost current_mid=0x1e
stat-26200 [001] .... 29638.516403: smb3_enter: cifs_revalidate_dentry_attr: xid=22
stat-26200 [001] .... 29648.723296: smb3_exit_err: cifs_revalidate_dentry_attr: xid=22 rc=-112
kworker/0:1-22830 [000] .... 29653.850947: smb3_cmd_done: sid=0x0 tid=0x0 cmd=0 mid=0
kworker/0:1-22830 [000] .... 29653.851191: smb3_cmd_err: sid=0x8ae4683c tid=0x0 cmd=1 mid=1 status=0xc0000016 rc=-5
kworker/0:1-22830 [000] .... 29653.855254: smb3_cmd_done: sid=0x8ae4683c tid=0x0 cmd=1 mid=2
kworker/0:1-22830 [000] .... 29653.855482: smb3_cmd_done: sid=0x8ae4683c tid=0x8084f30d cmd=3 mid=3
--
Thanks,
Steve
Steve
From 745929a07ac8b076d139f4479cb16b2b460cd335 Mon Sep 17 00:00:00 2001 From: Steve French <stfrench@xxxxxxxxxxxxx> Date: Mon, 30 Jul 2018 19:23:09 -0500 Subject: [PATCH] smb3: add reconnect tracepoints Add tracepoints for reconnecting an smb3 session Example output (from trace-cmd) with the patch (showing the session marked for reconnect, the stat failing, and then the subsequent SMB3 commands after the server comes back up). The "smb3_reconnect" event is the new one. cifsd-25993 [000] .... 29635.368265: smb3_reconnect: server=localhost current_mid=0x1e stat-26200 [001] .... 29638.516403: smb3_enter: cifs_revalidate_dentry_attr: xid=22 stat-26200 [001] .... 29648.723296: smb3_exit_err: cifs_revalidate_dentry_attr: xid=22 rc=-112 kworker/0:1-22830 [000] .... 29653.850947: smb3_cmd_done: sid=0x0 tid=0x0 cmd=0 mid=0 kworker/0:1-22830 [000] .... 29653.851191: smb3_cmd_err: sid=0x8ae4683c tid=0x0 cmd=1 mid=1 status=0xc0000016 rc=-5 kworker/0:1-22830 [000] .... 29653.855254: smb3_cmd_done: sid=0x8ae4683c tid=0x0 cmd=1 mid=2 kworker/0:1-22830 [000] .... 29653.855482: smb3_cmd_done: sid=0x8ae4683c tid=0x8084f30d cmd=3 mid=3 Signed-off-by: Steve French <stfrench@xxxxxxxxxxxxx> --- fs/cifs/connect.c | 1 + fs/cifs/trace.h | 26 ++++++++++++++++++++++++++ fs/cifs/transport.c | 2 ++ 3 files changed, 29 insertions(+) diff --git a/fs/cifs/connect.c b/fs/cifs/connect.c index 67f91a6313a0..d9bd10d295a9 100644 --- a/fs/cifs/connect.c +++ b/fs/cifs/connect.c @@ -348,6 +348,7 @@ cifs_reconnect(struct TCP_Server_Info *server) server->max_read = 0; cifs_dbg(FYI, "Reconnecting tcp session\n"); + trace_smb3_reconnect(server->CurrentMid, server->hostname); /* before reconnecting the tcp session, mark the smb session (uid) and the tid bad so they are not used until reconnected */ diff --git a/fs/cifs/trace.h b/fs/cifs/trace.h index 0fdf2f5c07ba..6b50b57e2416 100644 --- a/fs/cifs/trace.h +++ b/fs/cifs/trace.h @@ -423,6 +423,32 @@ DEFINE_EVENT(smb3_open_done_class, smb3_##name, \ DEFINE_SMB3_OPEN_DONE_EVENT(open_done); DEFINE_SMB3_OPEN_DONE_EVENT(posix_mkdir_done); +DECLARE_EVENT_CLASS(smb3_reconnect_class, + TP_PROTO(__u64 currmid, + char *hostname), + TP_ARGS(currmid, hostname), + TP_STRUCT__entry( + __field(__u64, currmid) + __field(char *, hostname) + ), + TP_fast_assign( + __entry->currmid = currmid; + __entry->hostname = hostname; + ), + TP_printk("server=%s current_mid=0x%llx", + __entry->hostname, + __entry->currmid) +) + +#define DEFINE_SMB3_RECONNECT_EVENT(name) \ +DEFINE_EVENT(smb3_reconnect_class, smb3_##name, \ + TP_PROTO(__u64 currmid, \ + char *hostname), \ + TP_ARGS(currmid, hostname)) + +DEFINE_SMB3_RECONNECT_EVENT(reconnect); +DEFINE_SMB3_RECONNECT_EVENT(partial_send_reconnect); + #endif /* _CIFS_TRACE_H */ #undef TRACE_INCLUDE_PATH diff --git a/fs/cifs/transport.c b/fs/cifs/transport.c index 0f9156af5eb0..357d25351ffa 100644 --- a/fs/cifs/transport.c +++ b/fs/cifs/transport.c @@ -361,6 +361,8 @@ __smb_send_rqst(struct TCP_Server_Info *server, int num_rqst, * socket so the server throws away the partial SMB */ server->tcpStatus = CifsNeedReconnect; + trace_smb3_partial_send_reconnect(server->CurrentMid, + server->hostname); } smbd_done: if (rc < 0 && rc != -EINTR) -- 2.17.1