Commit 020eec5f authored by Steve French's avatar Steve French
Browse files

smb3: add tracepoint for slow responses 



If responses take longer than one second from the server,
we can optionally log them to dmesg in current cifs.ko code
(CONFIG_CIFS_STATS2 must be configured and a
/proc/fs/cifs/cifsFYI flag must be set), but can be more useful
to log these via ftrace (tracepoint is smb3_slow_rsp) which
is easier and more granular (still requires CONFIG_CIFS_STATS2
to be configured in the build though).

Signed-off-by: default avatarSteve French <stfrench@microsoft.com>
Reviewed-by: default avatarPavel Shilovsky <pshilov@microsoft.com>
parent e0bba0b8

fs/cifs/trace.h

+37 −0
Original line number Diff line number Diff line
@@ -283,6 +283,43 @@ DEFINE_EVENT(smb3_cmd_done_class, smb3_##name, \ 
DEFINE_SMB3_CMD_DONE_EVENT(cmd_done);

DEFINE_SMB3_CMD_DONE_EVENT(ses_expired);



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,

fs/cifs/transport.c

+6 −2
Original line number Diff line number Diff line
@@ -115,8 +115,12 @@ DeleteMidQEntry(struct mid_q_entry *midEntry) 
	now = jiffies;

	/* commands taking longer than one second are indications that

	   something is wrong, unless it is quite a slow link or server */

	if (time_after(now, midEntry->when_alloc + HZ)) {

		if ((cifsFYI & CIFS_TIMER) && (midEntry->command != command)) {

	if (time_after(now, midEntry->when_alloc + HZ) &&

	    (midEntry->command != command)) {

		trace_smb3_slow_rsp(le16_to_cpu(midEntry->command),

			       midEntry->mid, midEntry->pid,

			       midEntry->when_sent, midEntry->when_received);

		if (cifsFYI & CIFS_TIMER) {

			pr_debug(" CIFS slow rsp: cmd %d mid %llu",

			       midEntry->command, midEntry->mid);

			pr_info(" A: 0x%lx S: 0x%lx R: 0x%lx\n",

CRA Git | Maintained and supported by SUSTech CRA and CCSE