There was no check to see if sample_time was zero before dividing by it.
This was causing ZeroDivisionError's:
Traceback (most recent call last):
File "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py", line 628, in ?
iostat_command(prog)
File "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py", line 610, in iostat_command
print_iostat_summary(old_mountstats, mountstats, devices, sample_time, options)
File "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py", line 462, in print_iostat_summary
stats[device].display_iostats(time, options.which)
File "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py", line 370, in display_iostats
backlog = (float(self.__rpc_data['backlogutil']) / sends) / sample_time
ZeroDivisionError: float division
Traceback (most recent call last):
File "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py", line 628, in ?
iostat_command(prog)
File "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py", line 610, in iostat_command
print_iostat_summary(old_mountstats, mountstats, devices, sample_time, options)
File "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py", line 462, in print_iostat_summary
stats[device].display_iostats(time, options.which)
File "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py", line 380, in display_iostats
print '%7.2f' % (sends / sample_time),
ZeroDivisionError: float division
Traceback (most recent call last):
File "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py", line 630, in ?
iostat_command(prog)
File "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py", line 612, in iostat_command
print_iostat_summary(old_mountstats, mountstats, devices, sample_time, options)
File "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py", line 464, in print_iostat_summary
stats[device].display_iostats(time, options.which)
File "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py", line 386, in display_iostats
self.__print_rpc_op_stats('READ', sample_time)
File "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py", line 350, in __print_rpc_op_stats
print '\t\t%7.3f' % (ops / sample_time),
ZeroDivisionError: float division
Signed-off-by: Kevin Constantine <kevin.constantine-FfNkGbSheRGpB8w63BLUukEOCMrvLtNR@public.gmane.org>
---
tools/nfs-iostat/nfs-iostat.py | 20 +++++++++++++++-----
1 files changed, 15 insertions(+), 5 deletions(-)
diff --git a/tools/nfs-iostat/nfs-iostat.py b/tools/nfs-iostat/nfs-iostat.py
index 2d0b143..4d6b295 100644
--- a/tools/nfs-iostat/nfs-iostat.py
+++ b/tools/nfs-iostat/nfs-iostat.py
@@ -342,13 +342,19 @@ class DeviceData:
retrans_percent = 0.0
rtt_per_op = 0.0
exe_per_op = 0.0
+ if sample_time != 0:
+ ops_per_sample_time = ops / sample_time
+ kb_per_sample_time = kilobytes / sample_time
+ else:
+ ops_per_sample_time = 0.0
+ kb_per_sample_time = 0.0
op += ':'
print '%s' % op.lower().ljust(15),
print ' ops/s\t\t kB/s\t\t kB/op\t\tretrans\t\tavg RTT (ms)\tavg exe (ms)'
- print '\t\t%7.3f' % (ops / sample_time),
- print '\t%7.3f' % (kilobytes / sample_time),
+ print '\t\t%7.3f' % (ops_per_sample_time),
+ print '\t%7.3f' % (kb_per_sample_time),
print '\t%7.3f' % kb_per_op,
print ' %7d (%3.1f%%)' % (retrans, retrans_percent),
print '\t%7.3f' % rtt_per_op,
@@ -358,7 +364,9 @@ class DeviceData:
sends = float(self.__rpc_data['rpcsends'])
if sample_time == 0:
sample_time = float(self.__nfs_data['age'])
- return (sends / sample_time)
+ return (sends / sample_time)
+ else:
+ return(0.0)
def display_iostats(self, sample_time, which):
"""Display NFS and RPC stats in an iostat-like way
@@ -366,10 +374,12 @@ class DeviceData:
sends = float(self.__rpc_data['rpcsends'])
if sample_time == 0:
sample_time = float(self.__nfs_data['age'])
- if sends != 0:
+ if sends != 0 and sample_time != 0:
backlog = (float(self.__rpc_data['backlogutil']) / sends) / sample_time
+ sends_per_sample_time = sends / sample_time
else:
backlog = 0.0
+ sends_per_sample_time = 0.0
print
print '%s mounted on %s:' % \
@@ -377,7 +387,7 @@ class DeviceData:
print
print ' op/s\t\trpc bklog'
- print '%7.2f' % (sends / sample_time),
+ print '%7.2f' % (sends_per_sample_time),
print '\t%7.2f' % backlog
if which == 0:
--
1.6.5.2
The first time through the code sample_time is set to 0.0 on line 588.
Eventually we call display_iostats() and check if sample_time == 0. It
does, so we set sample_time equal to the mount age on line 368. I'm
seeing instances where the age of a mount is 0.
cat /proc/self/mountstats | egrep "device|age"
device fashome-n1:/vol/home/fahome mounted on /home/fahome with fstype
nfs statvers=1.0
age: 0
All of our storage is automounted, so volumes are frequently getting
unmounted and remounted.
-kevin
On 05/27/2010 05:22 PM, Chuck Lever wrote:
> On 05/27/2010 07:58 PM, Kevin Constantine wrote:
>> There was no check to see if sample_time was zero before dividing by it.
>
> I haven't looked at this code in a very long time. Why was sample_time
> zero? That seems wrong.
>
>> This was causing ZeroDivisionError's:
>>
>> Traceback (most recent call last):
>> File
>> "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py",
>> line 628, in ?
>> iostat_command(prog)
>> File
>> "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py",
>> line 610, in iostat_command
>> print_iostat_summary(old_mountstats, mountstats, devices, sample_time,
>> options)
>> File
>> "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py",
>> line 462, in print_iostat_summary
>> stats[device].display_iostats(time, options.which)
>> File
>> "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py",
>> line 370, in display_iostats
>> backlog = (float(self.__rpc_data['backlogutil']) / sends) / sample_time
>> ZeroDivisionError: float division
>>
>> Traceback (most recent call last):
>> File
>> "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py",
>> line 628, in ?
>> iostat_command(prog)
>> File
>> "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py",
>> line 610, in iostat_command
>> print_iostat_summary(old_mountstats, mountstats, devices, sample_time,
>> options)
>> File
>> "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py",
>> line 462, in print_iostat_summary
>> stats[device].display_iostats(time, options.which)
>> File
>> "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py",
>> line 380, in display_iostats
>> print '%7.2f' % (sends / sample_time),
>> ZeroDivisionError: float division
>>
>> Traceback (most recent call last):
>> File
>> "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py",
>> line 630, in ?
>> iostat_command(prog)
>> File
>> "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py",
>> line 612, in iostat_command
>> print_iostat_summary(old_mountstats, mountstats, devices, sample_time,
>> options)
>> File
>> "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py",
>> line 464, in print_iostat_summary
>> stats[device].display_iostats(time, options.which)
>> File
>> "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py",
>> line 386, in display_iostats
>> self.__print_rpc_op_stats('READ', sample_time)
>> File
>> "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py",
>> line 350, in __print_rpc_op_stats
>> print '\t\t%7.3f' % (ops / sample_time),
>> ZeroDivisionError: float division
>>
>> Signed-off-by: Kevin Constantine<[email protected]>
>> ---
>> tools/nfs-iostat/nfs-iostat.py | 20 +++++++++++++++-----
>> 1 files changed, 15 insertions(+), 5 deletions(-)
>>
>> diff --git a/tools/nfs-iostat/nfs-iostat.py
>> b/tools/nfs-iostat/nfs-iostat.py
>> index 2d0b143..4d6b295 100644
>> --- a/tools/nfs-iostat/nfs-iostat.py
>> +++ b/tools/nfs-iostat/nfs-iostat.py
>> @@ -342,13 +342,19 @@ class DeviceData:
>> retrans_percent = 0.0
>> rtt_per_op = 0.0
>> exe_per_op = 0.0
>> + if sample_time != 0:
>> + ops_per_sample_time = ops / sample_time
>> + kb_per_sample_time = kilobytes / sample_time
>> + else:
>> + ops_per_sample_time = 0.0
>> + kb_per_sample_time = 0.0
>>
>> op += ':'
>> print '%s' % op.lower().ljust(15),
>> print ' ops/s\t\t kB/s\t\t kB/op\t\tretrans\t\tavg RTT (ms)\tavg exe
>> (ms)'
>>
>> - print '\t\t%7.3f' % (ops / sample_time),
>> - print '\t%7.3f' % (kilobytes / sample_time),
>> + print '\t\t%7.3f' % (ops_per_sample_time),
>> + print '\t%7.3f' % (kb_per_sample_time),
>> print '\t%7.3f' % kb_per_op,
>> print ' %7d (%3.1f%%)' % (retrans, retrans_percent),
>> print '\t%7.3f' % rtt_per_op,
>> @@ -358,7 +364,9 @@ class DeviceData:
>> sends = float(self.__rpc_data['rpcsends'])
>> if sample_time == 0:
>> sample_time = float(self.__nfs_data['age'])
>> - return (sends / sample_time)
>> + return (sends / sample_time)
>> + else:
>> + return(0.0)
>>
>> def display_iostats(self, sample_time, which):
>> """Display NFS and RPC stats in an iostat-like way
>> @@ -366,10 +374,12 @@ class DeviceData:
>> sends = float(self.__rpc_data['rpcsends'])
>> if sample_time == 0:
>> sample_time = float(self.__nfs_data['age'])
>> - if sends != 0:
>> + if sends != 0 and sample_time != 0:
>> backlog = (float(self.__rpc_data['backlogutil']) / sends) / sample_time
>> + sends_per_sample_time = sends / sample_time
>> else:
>> backlog = 0.0
>> + sends_per_sample_time = 0.0
>>
>> print
>> print '%s mounted on %s:' % \
>> @@ -377,7 +387,7 @@ class DeviceData:
>> print
>>
>> print ' op/s\t\trpc bklog'
>> - print '%7.2f' % (sends / sample_time),
>> + print '%7.2f' % (sends_per_sample_time),
>> print '\t%7.2f' % backlog
>>
>> if which == 0:
>
>
On 05/28/2010 10:00 AM, Chuck Lever wrote:
> On 05/27/10 08:50 PM, Kevin Constantine wrote:
>> The first time through the code sample_time is set to 0.0 on line 588.
>> Eventually we call display_iostats() and check if sample_time == 0. It
>> does, so we set sample_time equal to the mount age on line 368. I'm
>> seeing instances where the age of a mount is 0.
>>
>> cat /proc/self/mountstats | egrep "device|age"
>> device fashome-n1:/vol/home/fahome mounted on /home/fahome with fstype
>> nfs statvers=1.0
>> age: 0
>>
>> All of our storage is automounted, so volumes are frequently getting
>> unmounted and remounted.
>
> Makes sense. When I wrote the script, I wasn't using automounter at all.
> It might be simpler to have one check for a zero age at 368.
>
My only concern with checking and just returning (which is certainly
easier and a smaller change) is that we end up not printing anything for
a volume that is technically mounted. I figured it was better to print
the volume info and all zeroes than to not print anything.
I'll defer to your opinion on which of those two is best.
-kevin
>> On 05/27/2010 05:22 PM, Chuck Lever wrote:
>>> On 05/27/2010 07:58 PM, Kevin Constantine wrote:
>>>> There was no check to see if sample_time was zero before dividing by
>>>> it.
>>>
>>> I haven't looked at this code in a very long time. Why was sample_time
>>> zero? That seems wrong.
>>>
>>>> This was causing ZeroDivisionError's:
>>>>
On 05/27/10 08:50 PM, Kevin Constantine wrote:
> The first time through the code sample_time is set to 0.0 on line 588.
> Eventually we call display_iostats() and check if sample_time == 0. It
> does, so we set sample_time equal to the mount age on line 368. I'm
> seeing instances where the age of a mount is 0.
>
> cat /proc/self/mountstats | egrep "device|age"
> device fashome-n1:/vol/home/fahome mounted on /home/fahome with fstype
> nfs statvers=1.0
> age: 0
>
> All of our storage is automounted, so volumes are frequently getting
> unmounted and remounted.
Makes sense. When I wrote the script, I wasn't using automounter at
all. It might be simpler to have one check for a zero age at 368.
> -kevin
>
> On 05/27/2010 05:22 PM, Chuck Lever wrote:
>> On 05/27/2010 07:58 PM, Kevin Constantine wrote:
>>> There was no check to see if sample_time was zero before dividing by it.
>>
>> I haven't looked at this code in a very long time. Why was sample_time
>> zero? That seems wrong.
>>
>>> This was causing ZeroDivisionError's:
>>>
>>> Traceback (most recent call last):
>>> File
>>> "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py",
>>>
>>> line 628, in ?
>>> iostat_command(prog)
>>> File
>>> "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py",
>>>
>>> line 610, in iostat_command
>>> print_iostat_summary(old_mountstats, mountstats, devices, sample_time,
>>> options)
>>> File
>>> "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py",
>>>
>>> line 462, in print_iostat_summary
>>> stats[device].display_iostats(time, options.which)
>>> File
>>> "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py",
>>>
>>> line 370, in display_iostats
>>> backlog = (float(self.__rpc_data['backlogutil']) / sends) / sample_time
>>> ZeroDivisionError: float division
>>>
>>> Traceback (most recent call last):
>>> File
>>> "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py",
>>>
>>> line 628, in ?
>>> iostat_command(prog)
>>> File
>>> "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py",
>>>
>>> line 610, in iostat_command
>>> print_iostat_summary(old_mountstats, mountstats, devices, sample_time,
>>> options)
>>> File
>>> "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py",
>>>
>>> line 462, in print_iostat_summary
>>> stats[device].display_iostats(time, options.which)
>>> File
>>> "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py",
>>>
>>> line 380, in display_iostats
>>> print '%7.2f' % (sends / sample_time),
>>> ZeroDivisionError: float division
>>>
>>> Traceback (most recent call last):
>>> File
>>> "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py",
>>>
>>> line 630, in ?
>>> iostat_command(prog)
>>> File
>>> "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py",
>>>
>>> line 612, in iostat_command
>>> print_iostat_summary(old_mountstats, mountstats, devices, sample_time,
>>> options)
>>> File
>>> "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py",
>>>
>>> line 464, in print_iostat_summary
>>> stats[device].display_iostats(time, options.which)
>>> File
>>> "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py",
>>>
>>> line 386, in display_iostats
>>> self.__print_rpc_op_stats('READ', sample_time)
>>> File
>>> "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py",
>>>
>>> line 350, in __print_rpc_op_stats
>>> print '\t\t%7.3f' % (ops / sample_time),
>>> ZeroDivisionError: float division
>>>
>>> Signed-off-by: Kevin Constantine<[email protected]>
>>> ---
>>> tools/nfs-iostat/nfs-iostat.py | 20 +++++++++++++++-----
>>> 1 files changed, 15 insertions(+), 5 deletions(-)
>>>
>>> diff --git a/tools/nfs-iostat/nfs-iostat.py
>>> b/tools/nfs-iostat/nfs-iostat.py
>>> index 2d0b143..4d6b295 100644
>>> --- a/tools/nfs-iostat/nfs-iostat.py
>>> +++ b/tools/nfs-iostat/nfs-iostat.py
>>> @@ -342,13 +342,19 @@ class DeviceData:
>>> retrans_percent = 0.0
>>> rtt_per_op = 0.0
>>> exe_per_op = 0.0
>>> + if sample_time != 0:
>>> + ops_per_sample_time = ops / sample_time
>>> + kb_per_sample_time = kilobytes / sample_time
>>> + else:
>>> + ops_per_sample_time = 0.0
>>> + kb_per_sample_time = 0.0
>>>
>>> op += ':'
>>> print '%s' % op.lower().ljust(15),
>>> print ' ops/s\t\t kB/s\t\t kB/op\t\tretrans\t\tavg RTT (ms)\tavg exe
>>> (ms)'
>>>
>>> - print '\t\t%7.3f' % (ops / sample_time),
>>> - print '\t%7.3f' % (kilobytes / sample_time),
>>> + print '\t\t%7.3f' % (ops_per_sample_time),
>>> + print '\t%7.3f' % (kb_per_sample_time),
>>> print '\t%7.3f' % kb_per_op,
>>> print ' %7d (%3.1f%%)' % (retrans, retrans_percent),
>>> print '\t%7.3f' % rtt_per_op,
>>> @@ -358,7 +364,9 @@ class DeviceData:
>>> sends = float(self.__rpc_data['rpcsends'])
>>> if sample_time == 0:
>>> sample_time = float(self.__nfs_data['age'])
>>> - return (sends / sample_time)
>>> + return (sends / sample_time)
>>> + else:
>>> + return(0.0)
>>>
>>> def display_iostats(self, sample_time, which):
>>> """Display NFS and RPC stats in an iostat-like way
>>> @@ -366,10 +374,12 @@ class DeviceData:
>>> sends = float(self.__rpc_data['rpcsends'])
>>> if sample_time == 0:
>>> sample_time = float(self.__nfs_data['age'])
>>> - if sends != 0:
>>> + if sends != 0 and sample_time != 0:
>>> backlog = (float(self.__rpc_data['backlogutil']) / sends) / sample_time
>>> + sends_per_sample_time = sends / sample_time
>>> else:
>>> backlog = 0.0
>>> + sends_per_sample_time = 0.0
>>>
>>> print
>>> print '%s mounted on %s:' % \
>>> @@ -377,7 +387,7 @@ class DeviceData:
>>> print
>>>
>>> print ' op/s\t\trpc bklog'
>>> - print '%7.2f' % (sends / sample_time),
>>> + print '%7.2f' % (sends_per_sample_time),
>>> print '\t%7.2f' % backlog
>>>
>>> if which == 0:
>>
>>
On 05/27/2010 07:58 PM, Kevin Constantine wrote:
> There was no check to see if sample_time was zero before dividing by it.
I haven't looked at this code in a very long time. Why was sample_time
zero? That seems wrong.
> This was causing ZeroDivisionError's:
>
> Traceback (most recent call last):
> File "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py", line 628, in ?
> iostat_command(prog)
> File "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py", line 610, in iostat_command
> print_iostat_summary(old_mountstats, mountstats, devices, sample_time, options)
> File "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py", line 462, in print_iostat_summary
> stats[device].display_iostats(time, options.which)
> File "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py", line 370, in display_iostats
> backlog = (float(self.__rpc_data['backlogutil']) / sends) / sample_time
> ZeroDivisionError: float division
>
> Traceback (most recent call last):
> File "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py", line 628, in ?
> iostat_command(prog)
> File "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py", line 610, in iostat_command
> print_iostat_summary(old_mountstats, mountstats, devices, sample_time, options)
> File "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py", line 462, in print_iostat_summary
> stats[device].display_iostats(time, options.which)
> File "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py", line 380, in display_iostats
> print '%7.2f' % (sends / sample_time),
> ZeroDivisionError: float division
>
> Traceback (most recent call last):
> File "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py", line 630, in ?
> iostat_command(prog)
> File "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py", line 612, in iostat_command
> print_iostat_summary(old_mountstats, mountstats, devices, sample_time, options)
> File "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py", line 464, in print_iostat_summary
> stats[device].display_iostats(time, options.which)
> File "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py", line 386, in display_iostats
> self.__print_rpc_op_stats('READ', sample_time)
> File "/home/fahome/kconstan/repos/nfs-utils.upstream/tools/nfs-iostat/nfs-iostat.py", line 350, in __print_rpc_op_stats
> print '\t\t%7.3f' % (ops / sample_time),
> ZeroDivisionError: float division
>
> Signed-off-by: Kevin Constantine<kevin.constantine-FfNkGbSheRGpB8w63BLUukEOCMrvLtNR@public.gmane.org>
> ---
> tools/nfs-iostat/nfs-iostat.py | 20 +++++++++++++++-----
> 1 files changed, 15 insertions(+), 5 deletions(-)
>
> diff --git a/tools/nfs-iostat/nfs-iostat.py b/tools/nfs-iostat/nfs-iostat.py
> index 2d0b143..4d6b295 100644
> --- a/tools/nfs-iostat/nfs-iostat.py
> +++ b/tools/nfs-iostat/nfs-iostat.py
> @@ -342,13 +342,19 @@ class DeviceData:
> retrans_percent = 0.0
> rtt_per_op = 0.0
> exe_per_op = 0.0
> + if sample_time != 0:
> + ops_per_sample_time = ops / sample_time
> + kb_per_sample_time = kilobytes / sample_time
> + else:
> + ops_per_sample_time = 0.0
> + kb_per_sample_time = 0.0
>
> op += ':'
> print '%s' % op.lower().ljust(15),
> print ' ops/s\t\t kB/s\t\t kB/op\t\tretrans\t\tavg RTT (ms)\tavg exe (ms)'
>
> - print '\t\t%7.3f' % (ops / sample_time),
> - print '\t%7.3f' % (kilobytes / sample_time),
> + print '\t\t%7.3f' % (ops_per_sample_time),
> + print '\t%7.3f' % (kb_per_sample_time),
> print '\t%7.3f' % kb_per_op,
> print ' %7d (%3.1f%%)' % (retrans, retrans_percent),
> print '\t%7.3f' % rtt_per_op,
> @@ -358,7 +364,9 @@ class DeviceData:
> sends = float(self.__rpc_data['rpcsends'])
> if sample_time == 0:
> sample_time = float(self.__nfs_data['age'])
> - return (sends / sample_time)
> + return (sends / sample_time)
> + else:
> + return(0.0)
>
> def display_iostats(self, sample_time, which):
> """Display NFS and RPC stats in an iostat-like way
> @@ -366,10 +374,12 @@ class DeviceData:
> sends = float(self.__rpc_data['rpcsends'])
> if sample_time == 0:
> sample_time = float(self.__nfs_data['age'])
> - if sends != 0:
> + if sends != 0 and sample_time != 0:
> backlog = (float(self.__rpc_data['backlogutil']) / sends) / sample_time
> + sends_per_sample_time = sends / sample_time
> else:
> backlog = 0.0
> + sends_per_sample_time = 0.0
>
> print
> print '%s mounted on %s:' % \
> @@ -377,7 +387,7 @@ class DeviceData:
> print
>
> print ' op/s\t\trpc bklog'
> - print '%7.2f' % (sends / sample_time),
> + print '%7.2f' % (sends_per_sample_time),
> print '\t%7.2f' % backlog
>
> if which == 0:
--
chuck[dot]lever[at]oracle[dot]com
On 06/01/2010 08:37 AM, Chuck Lever wrote:
> On 05/28/10 06:51 PM, Kevin Constantine wrote:
>> On 05/28/2010 10:00 AM, Chuck Lever wrote:
>>> On 05/27/10 08:50 PM, Kevin Constantine wrote:
>>>> The first time through the code sample_time is set to 0.0 on line 588.
>>>> Eventually we call display_iostats() and check if sample_time == 0. It
>>>> does, so we set sample_time equal to the mount age on line 368. I'm
>>>> seeing instances where the age of a mount is 0.
>>>>
>>>> cat /proc/self/mountstats | egrep "device|age"
>>>> device fashome-n1:/vol/home/fahome mounted on /home/fahome with fstype
>>>> nfs statvers=1.0
>>>> age: 0
>>>>
>>>> All of our storage is automounted, so volumes are frequently getting
>>>> unmounted and remounted.
>>>
>>> Makes sense. When I wrote the script, I wasn't using automounter at all.
>>> It might be simpler to have one check for a zero age at 368.
>>>
>>
>> My only concern with checking and just returning (which is certainly
>> easier and a smaller change) is that we end up not printing anything for
>> a volume that is technically mounted. I figured it was better to print
>> the volume info and all zeroes than to not print anything.
>
> Unfortunately not printing anything in this case might be considered
> "following the precedent" of Unix tools -- don't print anything in error
> cases, or when there is nothing to show. I think that's the rule I
> followed for RPC procedures that have a zero op count. But it would
> still be useful to see other relevant information for that mount, as you
> point out.
>
> What would happen if, at line 368, you set sample_time to 1 if the
> mount's age is zero?
>
Substituting a 1 if 0 is found should cause fairly correct output.
/proc/self/mountstats does show values for the appropriate statistics
when age is 0, so setting sample_time to 1 would print those out instead
of printing zeroes.
It's a good compromise between not printing anything even though the
export is clearly mounted, and printing all zeroes which is kind of a
waste.
-kevin
>> I'll defer to your opinion on which of those two is best.
>>
>> -kevin
>>
>>>> On 05/27/2010 05:22 PM, Chuck Lever wrote:
>>>>> On 05/27/2010 07:58 PM, Kevin Constantine wrote:
>>>>>> There was no check to see if sample_time was zero before dividing by
>>>>>> it.
>>>>>
>>>>> I haven't looked at this code in a very long time. Why was sample_time
>>>>> zero? That seems wrong.
>>>>>
>>>>>> This was causing ZeroDivisionError's:
>>>>>>
On 05/28/10 06:51 PM, Kevin Constantine wrote:
> On 05/28/2010 10:00 AM, Chuck Lever wrote:
>> On 05/27/10 08:50 PM, Kevin Constantine wrote:
>>> The first time through the code sample_time is set to 0.0 on line 588.
>>> Eventually we call display_iostats() and check if sample_time == 0. It
>>> does, so we set sample_time equal to the mount age on line 368. I'm
>>> seeing instances where the age of a mount is 0.
>>>
>>> cat /proc/self/mountstats | egrep "device|age"
>>> device fashome-n1:/vol/home/fahome mounted on /home/fahome with fstype
>>> nfs statvers=1.0
>>> age: 0
>>>
>>> All of our storage is automounted, so volumes are frequently getting
>>> unmounted and remounted.
>>
>> Makes sense. When I wrote the script, I wasn't using automounter at all.
>> It might be simpler to have one check for a zero age at 368.
>>
>
> My only concern with checking and just returning (which is certainly
> easier and a smaller change) is that we end up not printing anything for
> a volume that is technically mounted. I figured it was better to print
> the volume info and all zeroes than to not print anything.
Unfortunately not printing anything in this case might be considered
"following the precedent" of Unix tools -- don't print anything in error
cases, or when there is nothing to show. I think that's the rule I
followed for RPC procedures that have a zero op count. But it would
still be useful to see other relevant information for that mount, as you
point out.
What would happen if, at line 368, you set sample_time to 1 if the
mount's age is zero?
> I'll defer to your opinion on which of those two is best.
>
> -kevin
>
>>> On 05/27/2010 05:22 PM, Chuck Lever wrote:
>>>> On 05/27/2010 07:58 PM, Kevin Constantine wrote:
>>>>> There was no check to see if sample_time was zero before dividing by
>>>>> it.
>>>>
>>>> I haven't looked at this code in a very long time. Why was sample_time
>>>> zero? That seems wrong.
>>>>
>>>>> This was causing ZeroDivisionError's:
>>>>>
When an export is freshly mounted, /proc/self/mountstats displays age = 0.
This causes nfs-iostat.py to divide by zero throwing an error. When we
have age = 0, other stats are greater than 0, so we'll set age = 1 and
print the relevant stats.
Signed-off-by: Kevin Constantine <[email protected]>
---
tools/nfs-iostat/nfs-iostat.py | 6 ++++++
1 files changed, 6 insertions(+), 0 deletions(-)
diff --git a/tools/nfs-iostat/nfs-iostat.py b/tools/nfs-iostat/nfs-iostat.py
index 2d0b143..1207674 100644
--- a/tools/nfs-iostat/nfs-iostat.py
+++ b/tools/nfs-iostat/nfs-iostat.py
@@ -366,6 +366,12 @@ class DeviceData:
sends = float(self.__rpc_data['rpcsends'])
if sample_time == 0:
sample_time = float(self.__nfs_data['age'])
+ # sample_time could still be zero if the export was just mounted.
+ # Set it to 1 to avoid divide by zero errors in this case since we'll
+ # likely still have relevant mount statistics to show.
+ #
+ if sample_time == 0:
+ sample_time = 1;
if sends != 0:
backlog = (float(self.__rpc_data['backlogutil']) / sends) / sample_time
else:
--
1.6.5.2
On 06/07/2010 06:40 PM, Kevin Constantine wrote:
> When an export is freshly mounted, /proc/self/mountstats displays age = 0.
> This causes nfs-iostat.py to divide by zero throwing an error. When we
> have age = 0, other stats are greater than 0, so we'll set age = 1 and
> print the relevant stats.
>
> Signed-off-by: Kevin Constantine <kevin.constantine-FfNkGbSheRGpB8w63BLUukEOCMrvLtNR@public.gmane.org>
> ---
> tools/nfs-iostat/nfs-iostat.py | 6 ++++++
> 1 files changed, 6 insertions(+), 0 deletions(-)
>
> diff --git a/tools/nfs-iostat/nfs-iostat.py b/tools/nfs-iostat/nfs-iostat.py
> index 2d0b143..1207674 100644
> --- a/tools/nfs-iostat/nfs-iostat.py
> +++ b/tools/nfs-iostat/nfs-iostat.py
> @@ -366,6 +366,12 @@ class DeviceData:
> sends = float(self.__rpc_data['rpcsends'])
> if sample_time == 0:
> sample_time = float(self.__nfs_data['age'])
> + # sample_time could still be zero if the export was just mounted.
> + # Set it to 1 to avoid divide by zero errors in this case since we'll
> + # likely still have relevant mount statistics to show.
> + #
> + if sample_time == 0:
> + sample_time = 1;
> if sends != 0:
> backlog = (float(self.__rpc_data['backlogutil']) / sends) / sample_time
> else:
Committed..
steved.
On 06/ 7/10 06:40 PM, Kevin Constantine wrote:
> When an export is freshly mounted, /proc/self/mountstats displays age = 0.
> This causes nfs-iostat.py to divide by zero throwing an error. When we
> have age = 0, other stats are greater than 0, so we'll set age = 1 and
> print the relevant stats.
>
> Signed-off-by: Kevin Constantine<kevin.constantine-FfNkGbSheRGpB8w63BLUukEOCMrvLtNR@public.gmane.org>
Reviewed-by: Chuck Lever <[email protected]>
> ---
> tools/nfs-iostat/nfs-iostat.py | 6 ++++++
> 1 files changed, 6 insertions(+), 0 deletions(-)
>
> diff --git a/tools/nfs-iostat/nfs-iostat.py b/tools/nfs-iostat/nfs-iostat.py
> index 2d0b143..1207674 100644
> --- a/tools/nfs-iostat/nfs-iostat.py
> +++ b/tools/nfs-iostat/nfs-iostat.py
> @@ -366,6 +366,12 @@ class DeviceData:
> sends = float(self.__rpc_data['rpcsends'])
> if sample_time == 0:
> sample_time = float(self.__nfs_data['age'])
> + # sample_time could still be zero if the export was just mounted.
> + # Set it to 1 to avoid divide by zero errors in this case since we'll
> + # likely still have relevant mount statistics to show.
> + #
> + if sample_time == 0:
> + sample_time = 1;
> if sends != 0:
> backlog = (float(self.__rpc_data['backlogutil']) / sends) / sample_time
> else: