[RFC][PATCH] Track time spent in each command

[Steve French]

I created a small experimental patch (leveraging the existing code for
the slow command check we already have in mid processing) to track the
total time per SMB2/SMB3 command.   Seems like it could be useful -
here is sample output (see below) from running seven xfstests to
generate the stats (these stats require CONFIG_CIFS_STATS2 to be
compiled as do the slow command counters).   I wanted to keep the
patch small and low risk so this seemed like the best place to capture
it.    This could be helpful in calculating average time per command
(and perhaps help isolate performance problems, and isolate what is
really causing slowdowns).   As with other counters: "echo 0 >
/proc/fs/cifs/Stats" resets them.   The new stats counters start at
the line "Total time spent processing each command"

Thoughts?

$ cat /proc/fs/cifs/Stats
Resources in use
CIFS Session: 1
Share (unique mount targets): 3
SMB Request/Response Buffer: 1 Pool size: 5
SMB Small Req/Resp Buffer: 2 Pool size: 30
Total Large 60864 Small 1165977 Allocations
Operations (MIDs): 1

0 session 0 share reconnects
Total vfs operations: 280236 maximum at one time: 3
Total time spent processing each command
cmd: 0 jiffies: 0 seconds 0
cmd: 1 jiffies: 2 seconds 0
cmd: 2 jiffies: 0 seconds 0
cmd: 3 jiffies: 1 seconds 0
cmd: 4 jiffies: 1 seconds 0
cmd: 5 jiffies: 6212 seconds 24
cmd: 6 jiffies: 3993 seconds 15
cmd: 7 jiffies: 135 seconds 0
cmd: 8 jiffies: 83 seconds 0
cmd: 9 jiffies: 44 seconds 0
cmd: 10 jiffies: 0 seconds 0
cmd: 11 jiffies: 1 seconds 0
cmd: 12 jiffies: 0 seconds 0
cmd: 13 jiffies: 0 seconds 0
cmd: 14 jiffies: 47 seconds 0
cmd: 15 jiffies: 0 seconds 0
cmd: 16 jiffies: 1890 seconds 7
cmd: 17 jiffies: 1368 seconds 5
cmd: 18 jiffies: 0 seconds 0

1) \\localhost\btrfs-scratch
SMBs: 42255
Bytes read: 25379425  Bytes written: 53689661
Open files: 1 total (local), 1 open on server
TreeConnects: 1 total 0 failed
TreeDisconnects: 0 total 0 failed
Creates: 14012 total 0 failed
Closes: 14009 total 0 failed
Flushes: 27 total 0 failed
Reads: 41 total 0 failed
Writes: 112 total 0 failed
Locks: 0 total 0 failed
IOCTLs: 2 total 1 failed
QueryDirectories: 28 total 0 failed
ChangeNotifies: 0 total 0 failed
QueryInfos: 11312 total 0 failed
SetInfos: 2711 total 0 failed
OplockBreaks: 0 sent 0 failed
2) \\localhost\btrfs
SMBs: 77
Bytes read: 282  Bytes written: 94
Open files: 0 total (local), 0 open on server
TreeConnects: 1 total 0 failed
TreeDisconnects: 0 total 0 failed
Creates: 23 total 0 failed
Closes: 21 total 0 failed
Flushes: 0 total 0 failed
Reads: 3 total 0 failed
Writes: 1 total 0 failed
Locks: 0 total 0 failed

-- 
Thanks,

Steve
-------------- next part --------------
A non-text attachment was scrubbed...
Name: 0001-SMB3-track-total-time-spent-per-command.patch
Type: text/x-patch
Size: 3121 bytes
Desc: not available
URL: <http://lists.samba.org/pipermail/samba-technical/attachments/20190326/8796764d/0001-SMB3-track-total-time-spent-per-command.bin>