SMB3: Track total time spent on roundtrips for each SMB3 command (433b8dd7) · Commits · EulixOS / Software / Kernel

fs/cifs/cifs_debug.c

+17 −2

Original line number	Original line	Diff line number	Diff line
	@@ -462,8 +462,13 @@ static ssize_t cifs_stats_proc_write(struct file *file,
	server = list_entry(tmp1, struct TCP_Server_Info,		server = list_entry(tmp1, struct TCP_Server_Info,
	tcp_ses_list);		tcp_ses_list);
	#ifdef CONFIG_CIFS_STATS2		#ifdef CONFIG_CIFS_STATS2
	for (i = 0; i < NUMBER_OF_SMB2_COMMANDS; i++)		for (i = 0; i < NUMBER_OF_SMB2_COMMANDS; i++) {
			atomic_set(&server->num_cmds[i], 0);
	atomic_set(&server->smb2slowcmd[i], 0);		atomic_set(&server->smb2slowcmd[i], 0);
			server->time_per_cmd[i] = 0;
			server->slowest_cmd[i] = 0;
			server->fastest_cmd[0] = 0;
			}
	#endif /* CONFIG_CIFS_STATS2 */		#endif /* CONFIG_CIFS_STATS2 */
	list_for_each(tmp2, &server->smb_ses_list) {		list_for_each(tmp2, &server->smb_ses_list) {
	ses = list_entry(tmp2, struct cifs_ses,		ses = list_entry(tmp2, struct cifs_ses,
	@@ -531,6 +536,16 @@ static int cifs_stats_proc_show(struct seq_file m, void v)
	server = list_entry(tmp1, struct TCP_Server_Info,		server = list_entry(tmp1, struct TCP_Server_Info,
	tcp_ses_list);		tcp_ses_list);
	#ifdef CONFIG_CIFS_STATS2		#ifdef CONFIG_CIFS_STATS2
			seq_puts(m, "\nTotal time spent processing by command. Time ");
			seq_printf(m, "units are jiffies (%d per second)\n", HZ);
			seq_puts(m, " SMB3 CMD\tNumber\tTotal Time\tFastest\tSlowest\n");
			seq_puts(m, " --------\t------\t----------\t-------\t-------\n");
			for (j = 0; j < NUMBER_OF_SMB2_COMMANDS; j++)
			seq_printf(m, " %d\t\t%d\t%llu\t\t%u\t%u\n", j,
			atomic_read(&server->num_cmds[j]),
			server->time_per_cmd[j],
			server->fastest_cmd[j],
			server->slowest_cmd[j]);
	for (j = 0; j < NUMBER_OF_SMB2_COMMANDS; j++)		for (j = 0; j < NUMBER_OF_SMB2_COMMANDS; j++)
	if (atomic_read(&server->smb2slowcmd[j]))		if (atomic_read(&server->smb2slowcmd[j]))
	seq_printf(m, " %d slow responses from %s for command %d\n",		seq_printf(m, " %d slow responses from %s for command %d\n",

fs/cifs/cifsglob.h

+4 −0

Original line number	Original line	Diff line number	Diff line
	@@ -714,7 +714,11 @@ struct TCP_Server_Info {
	#ifdef CONFIG_CIFS_STATS2		#ifdef CONFIG_CIFS_STATS2
	atomic_t in_send; /* requests trying to send */		atomic_t in_send; /* requests trying to send */
	atomic_t num_waiters; /* blocked waiting to get in sendrecv */		atomic_t num_waiters; /* blocked waiting to get in sendrecv */
			atomic_t num_cmds[NUMBER_OF_SMB2_COMMANDS]; /* total requests by cmd */
	atomic_t smb2slowcmd[NUMBER_OF_SMB2_COMMANDS]; /* count resps > 1 sec */		atomic_t smb2slowcmd[NUMBER_OF_SMB2_COMMANDS]; /* count resps > 1 sec */
			__u64 time_per_cmd[NUMBER_OF_SMB2_COMMANDS]; /* total time per cmd */
			__u32 slowest_cmd[NUMBER_OF_SMB2_COMMANDS];
			__u32 fastest_cmd[NUMBER_OF_SMB2_COMMANDS];
	#endif /* STATS2 */		#endif /* STATS2 */
	unsigned int max_read;		unsigned int max_read;
	unsigned int max_write;		unsigned int max_write;

fs/cifs/transport.c

+23 −4

Original line number	Original line	Diff line number	Diff line
	@@ -104,7 +104,10 @@ DeleteMidQEntry(struct mid_q_entry *midEntry)
	{		{
	#ifdef CONFIG_CIFS_STATS2		#ifdef CONFIG_CIFS_STATS2
	__le16 command = midEntry->server->vals->lock_cmd;		__le16 command = midEntry->server->vals->lock_cmd;
			__u16 smb_cmd = le16_to_cpu(midEntry->command);
	unsigned long now;		unsigned long now;
			unsigned long roundtrip_time;
			struct TCP_Server_Info *server = midEntry->server;
	#endif		#endif
	midEntry->mid_state = MID_FREE;		midEntry->mid_state = MID_FREE;
	atomic_dec(&midCount);		atomic_dec(&midCount);
	@@ -114,6 +117,23 @@ DeleteMidQEntry(struct mid_q_entry *midEntry)
	cifs_small_buf_release(midEntry->resp_buf);		cifs_small_buf_release(midEntry->resp_buf);
	#ifdef CONFIG_CIFS_STATS2		#ifdef CONFIG_CIFS_STATS2
	now = jiffies;		now = jiffies;
			if (now < midEntry->when_alloc)
			cifs_dbg(VFS, "invalid mid allocation time\n");
			roundtrip_time = now - midEntry->when_alloc;

			if (smb_cmd < NUMBER_OF_SMB2_COMMANDS) {
			if (atomic_read(&server->num_cmds[smb_cmd]) == 0) {
			server->slowest_cmd[smb_cmd] = roundtrip_time;
			server->fastest_cmd[smb_cmd] = roundtrip_time;
			} else {
			if (server->slowest_cmd[smb_cmd] < roundtrip_time)
			server->slowest_cmd[smb_cmd] = roundtrip_time;
			else if (server->fastest_cmd[smb_cmd] > roundtrip_time)
			server->fastest_cmd[smb_cmd] = roundtrip_time;
			}
			cifs_stats_inc(&server->num_cmds[smb_cmd]);
			server->time_per_cmd[smb_cmd] += roundtrip_time;
			}
	/*		/*
	* commands taking longer than one second (default) can be indications		* commands taking longer than one second (default) can be indications
	* that something is wrong, unless it is quite a slow link or a very		* that something is wrong, unless it is quite a slow link or a very
	@@ -131,11 +151,10 @@ DeleteMidQEntry(struct mid_q_entry *midEntry)
	* smb2slowcmd[NUMBER_OF_SMB2_COMMANDS] counts by command		* smb2slowcmd[NUMBER_OF_SMB2_COMMANDS] counts by command
	* NB: le16_to_cpu returns unsigned so can not be negative below		* NB: le16_to_cpu returns unsigned so can not be negative below
	*/		*/
	if (le16_to_cpu(midEntry->command) < NUMBER_OF_SMB2_COMMANDS)		if (smb_cmd < NUMBER_OF_SMB2_COMMANDS)
	cifs_stats_inc(&midEntry->server->smb2slowcmd[le16_to_cpu(midEntry->command)]);		cifs_stats_inc(&server->smb2slowcmd[smb_cmd]);

	trace_smb3_slow_rsp(le16_to_cpu(midEntry->command),		trace_smb3_slow_rsp(smb_cmd, midEntry->mid, midEntry->pid,
	midEntry->mid, midEntry->pid,
	midEntry->when_sent, midEntry->when_received);		midEntry->when_sent, midEntry->when_received);
	if (cifsFYI & CIFS_TIMER) {		if (cifsFYI & CIFS_TIMER) {
	pr_debug(" CIFS slow rsp: cmd %d mid %llu",		pr_debug(" CIFS slow rsp: cmd %d mid %llu",