diff mbox

nfs-utils: display NFS RPC queue time for mountstats and nfs-iostat

Message ID MEXPR01MB0711C64DC23E94EE366C5455A2590@MEXPR01MB0711.ausprd01.prod.outlook.com (mailing list archive)
State New, archived
Headers show

Commit Message

Ryan Doyle Oct. 30, 2017, 3:30 a.m. UTC 
Hi there

I've got a patch to display the NFS queue statistics for mountstats and nfsiostat exported in /proc/self/mountstats. The RTT and total execution time is currently displayed but I think it's also useful displaying how long the task was queued for too. If others agree, please feel free to apply it.

Cheers,
Ryan

Comments

Steve Dickson Oct. 30, 2017, 3:29 p.m. UTC | #1 
On 10/29/2017 11:30 PM, Ryan Doyle wrote:
> Hi there
> 
> I've got a patch to display the NFS queue statistics for mountstats and nfsiostat exported in /proc/self/mountstats. The RTT and total execution time is currently displayed but I think it's also useful displaying how long the task was queued for too. If others agree, please feel free to apply it.

In the future please use the proper format for posting
a patch that is described in 
    https://www.kernel.org/doc/html/v4.12/process/submitting-patches.html

Basically, inline the patch, have a subject and description
section and a proper Signed-off-by: line. But since I 
found another bug while testing your patch and I'm about
to make a release I'll go ahead and add the Signed-off-by: line

Patch committed! 

steved.
--
To unsubscribe from this list: send the line "unsubscribe linux-nfs" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
diff mbox

Patch

diff --git a/tools/mountstats/mountstats.py b/tools/mountstats/mountstats.py
index a68d702..29b5f5a 100644
--- a/tools/mountstats/mountstats.py
+++ b/tools/mountstats/mountstats.py
@@ -587,6 +587,7 @@  class DeviceData:
         ops = float(rpc_stats[0])
         retrans = float(rpc_stats[1] - rpc_stats[0])
         kilobytes = float(rpc_stats[3] + rpc_stats[4]) / 1024
+        queued_for = float(rpc_stats[5])
         rtt = float(rpc_stats[6])
         exe = float(rpc_stats[7])
 
@@ -596,11 +597,13 @@  class DeviceData:
             retrans_percent = (retrans * 100) / ops
             rtt_per_op = rtt / ops
             exe_per_op = exe / ops
+            queued_for_per_op = queued_for / ops
         else:
             kb_per_op = 0.0
             retrans_percent = 0.0
             rtt_per_op = 0.0
             exe_per_op = 0.0
+            queued_for_per_op = 0.0
 
         op += ':'
         print(format(op.lower(), '<16s'), end='')
@@ -609,7 +612,8 @@  class DeviceData:
         print(format('kB/op', '>16s'), end='')
         print(format('retrans', '>16s'), end='')
         print(format('avg RTT (ms)', '>16s'), end='')
-        print(format('avg exe (ms)', '>16s'))
+        print(format('avg exe (ms)', '>16s'), end='')
+        print(format('avg queue (ms)', '>16s'))
 
         print(format((ops / sample_time), '>24.3f'), end='')
         print(format((kilobytes / sample_time), '>16.3f'), end='')
@@ -617,7 +621,8 @@  class DeviceData:
         retransmits = '{0:>10.0f} ({1:>3.1f}%)'.format(retrans, retrans_percent).strip()
         print(format(retransmits, '>16'), end='')
         print(format(rtt_per_op, '>16.3f'), end='')
-        print(format(exe_per_op, '>16.3f'))
+        print(format(exe_per_op, '>16.3f'), end='')
+        print(format(queued_for_per_op, '>16.3f'))
 
     def display_iostats(self, sample_time):
         """Display NFS and RPC stats in an iostat-like way
diff --git a/tools/nfs-iostat/nfs-iostat.py b/tools/nfs-iostat/nfs-iostat.py
index 577a23d..0d8b216 100644
--- a/tools/nfs-iostat/nfs-iostat.py
+++ b/tools/nfs-iostat/nfs-iostat.py
@@ -326,6 +326,7 @@  class DeviceData:
         ops = float(rpc_stats[0])
         retrans = float(rpc_stats[1] - rpc_stats[0])
         kilobytes = float(rpc_stats[3] + rpc_stats[4]) / 1024
+        queued_for = float(rpc_stats[5])
         rtt = float(rpc_stats[6])
         exe = float(rpc_stats[7])
 
@@ -335,11 +336,13 @@  class DeviceData:
             retrans_percent = (retrans * 100) / ops
             rtt_per_op = rtt / ops
             exe_per_op = exe / ops
+            queued_for_per_op = queued_for / ops
         else:
             kb_per_op = 0.0
             retrans_percent = 0.0
             rtt_per_op = 0.0
             exe_per_op = 0.0
+            queued_for_per_op = 0.0
 
         op += ':'
         print(format(op.lower(), '<16s'), end='')
@@ -348,7 +351,8 @@  class DeviceData:
         print(format('kB/op', '>16s'), end='')
         print(format('retrans', '>16s'), end='')
         print(format('avg RTT (ms)', '>16s'), end='')
-        print(format('avg exe (ms)', '>16s'))
+        print(format('avg exe (ms)', '>16s'), end='')
+        print(format('avg queue (ms)', '>16s'))
 
         print(format((ops / sample_time), '>24.3f'), end='')
         print(format((kilobytes / sample_time), '>16.3f'), end='')
@@ -356,7 +360,8 @@  class DeviceData:
         retransmits = '{0:>10.0f} ({1:>3.1f}%)'.format(retrans, retrans_percent).strip()
         print(format(retransmits, '>16'), end='')
         print(format(rtt_per_op, '>16.3f'), end='')
-        print(format(exe_per_op, '>16.3f'))
+        print(format(exe_per_op, '>16.3f'), end='')
+        print(format(queued_for_per_op, '>16.3f'))
 
     def ops(self, sample_time):
         sends = float(self.__rpc_data['rpcsends'])
diff --git a/tools/nfs-iostat/nfsiostat.man b/tools/nfs-iostat/nfsiostat.man
index b477a9a..9ae94c5 100644
--- a/tools/nfs-iostat/nfsiostat.man
+++ b/tools/nfs-iostat/nfsiostat.man
@@ -90,6 +90,13 @@  This is the duration from the time that NFS client does the RPC request to its k
 .RE
 .RE
 .RE
+.RS 8
+- \fBavg queue (ms)\fR
+.RS
+This is the duration from the time the NFS client created the RPC request task to the time the request is transmitted.
+.RE
+.RE
+.RE
 .TP
 Note that if an interval is used as argument to \fBnfsiostat\fR, then the diffrence from previous interval will be displayed, otherwise the results will be from the time that the share was mounted.