Bug 791342

Summary: first iteration of iostat in sysstat 7.0.2 appears to report artificially low results
Product: Red Hat Enterprise Linux 5 Reporter: William Yardley <wby+redhat>
Component: sysstatAssignee: Peter Schiffer <pschiffe>
Status: CLOSED NOTABUG QA Contact: BaseOS QE - Apps <qe-baseos-apps>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 5.7CC: wby+redhat
Target Milestone: rc   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2012-02-20 10:59:56 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:

Description William Yardley 2012-02-16 19:52:04 UTC
Description of problem:
I have noticed for a while that iostat on RHEL 5 seems to show artificially low values on the first iteration if "interval is set", or, on its only iteration if invoked without the "interval" parameter. I noticed recently that on a Debian system (with sysstat v 8.1.2), the same problem doesn't seem to happen. If this is a bug that has been fixed rather than an inherent limitation of the RHEL version of sysstat, please fix it.

It's not super obvious when i/o is low, but it's very noticeable / reproducible when the system is more heavily loaded in a way that makes me suspect it's not a simple matter iowait fluctuating. For example, even when the second and later iterations of iowait report iowait % in the 40-60% range, the first reading will often be under 2%. 

Version-Release number of selected component (if applicable):
7.0.2-11.el5

How reproducible:
Very, however, it's easier to notice when the system is under heavy i/o or heavy load.

Steps to Reproduce:
1. Run iostat N
2. First %iowait (and possibly other, like %user) value will be artificially low 
  
Actual results:


Expected results:


Additional info:

Comment 1 William Yardley 2012-02-16 22:11:04 UTC
Running iostat over and over gives me the same %iowait, %user, etc. values consistently:

water-griffen:$ iostat 
Linux 2.6.18-274.7.1.el5PAE (water-griffen.caltech.edu) 	02/16/2012

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           1.28    0.00    1.43    3.55    0.00   93.74

Device:            tps   Blk_read/s   Blk_wrtn/s   Blk_read   Blk_wrtn
sda              38.47         4.20       536.10   13127193 1675426004
sda1              0.00         0.00         0.00        424          0
sda2              0.00         0.00         0.00        500          0
sda3              0.00         0.00         0.00       3282       6948
sda4              0.00         0.00         0.00          6          0
sda5             38.47         4.20       536.10   13112602 1675418496
sda6              0.00         0.00         0.00       1459        560

water-griffen:$ iostat 
Linux 2.6.18-274.7.1.el5PAE (water-griffen.caltech.edu) 	02/16/2012

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           1.28    0.00    1.43    3.55    0.00   93.74

Device:            tps   Blk_read/s   Blk_wrtn/s   Blk_read   Blk_wrtn
sda              38.47         4.20       536.10   13127193 1675426540
sda1              0.00         0.00         0.00        424          0
sda2              0.00         0.00         0.00        500          0
sda3              0.00         0.00         0.00       3282       6948
sda4              0.00         0.00         0.00          6          0
sda5             38.47         4.20       536.10   13112602 1675419032
sda6              0.00         0.00         0.00       1459        560

water-griffen:$ iostat 
Linux 2.6.18-274.7.1.el5PAE (water-griffen.caltech.edu) 	02/16/2012

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           1.28    0.00    1.43    3.55    0.00   93.74

Device:            tps   Blk_read/s   Blk_wrtn/s   Blk_read   Blk_wrtn
sda              38.47         4.20       536.10   13127193 1675426540
sda1              0.00         0.00         0.00        424          0
sda2              0.00         0.00         0.00        500          0
sda3              0.00         0.00         0.00       3282       6948
sda4              0.00         0.00         0.00          6          0
sda5             38.47         4.20       536.10   13112602 1675419032
sda6              0.00         0.00         0.00       1459        560

Comment 2 William Yardley 2012-02-16 22:11:31 UTC
And, running iostat 5 shows about that same value on the first iteration, and the (apparently) correct value on subsequent iterations:

water-griffen:$ iostat 5
Linux 2.6.18-274.7.1.el5PAE (water-griffen.caltech.edu) 	02/16/2012

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           1.27    0.00    1.43    3.55    0.00   93.74

Device:            tps   Blk_read/s   Blk_wrtn/s   Blk_read   Blk_wrtn
sda              38.46         4.19       536.06   13099411 1675095524
sda1              0.00         0.00         0.00        424          0
sda2              0.00         0.00         0.00        500          0
sda3              0.00         0.00         0.00       3276       6940
sda4              0.00         0.00         0.00          6          0
sda5             38.46         4.19       536.06   13084826 1675088024
sda6              0.00         0.00         0.00       1459        560

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           3.16    0.00    4.01   29.28    0.00   63.56

Device:            tps   Blk_read/s   Blk_wrtn/s   Blk_read   Blk_wrtn
sda              41.60        30.40       604.80        152       3024
sda1              0.00         0.00         0.00          0          0
sda2              0.00         0.00         0.00          0          0
sda3              0.00         0.00         0.00          0          0
sda4              0.00         0.00         0.00          0          0
sda5             41.60        30.40       604.80        152       3024
sda6              0.00         0.00         0.00          0          0

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           3.13    0.00    3.41   27.75    0.00   65.71

Device:            tps   Blk_read/s   Blk_wrtn/s   Blk_read   Blk_wrtn
sda              43.60         0.00       667.20          0       3336
sda1              0.00         0.00         0.00          0          0
sda2              0.00         0.00         0.00          0          0
sda3              0.00         0.00         0.00          0          0
sda4              0.00         0.00         0.00          0          0
sda5             43.60         0.00       667.20          0       3336
sda6              0.00         0.00         0.00          0          0

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           4.52    0.00    5.04   27.72    0.00   62.72

Device:            tps   Blk_read/s   Blk_wrtn/s   Blk_read   Blk_wrtn
sda              64.40         1.60       870.40          8       4352
sda1              0.00         0.00         0.00          0          0
sda2              0.00         0.00         0.00          0          0
sda3              0.00         0.00         0.00          0          0
sda4              0.00         0.00         0.00          0          0
sda5             64.40         1.60       870.40          8       4352
sda6              0.00         0.00         0.00          0          0

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           3.96    0.00    4.19   26.41    0.00   65.44

Device:            tps   Blk_read/s   Blk_wrtn/s   Blk_read   Blk_wrtn
sda             102.00         0.00      1330.14          0       6664
sda1              0.00         0.00         0.00          0          0
sda2              0.00         0.00         0.00          0          0
sda3              0.00         0.00         0.00          0          0
sda4              0.00         0.00         0.00          0          0
sda5            102.00         0.00      1330.14          0       6664
sda6              0.00         0.00         0.00          0          0

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           3.98    0.00    3.85   29.69    0.00   62.47

Device:            tps   Blk_read/s   Blk_wrtn/s   Blk_read   Blk_wrtn
sda              57.40         0.00       856.00          0       4280
sda1              0.00         0.00         0.00          0          0
sda2              0.00         0.00         0.00          0          0
sda3              0.00         0.00         0.00          0          0
sda4              0.00         0.00         0.00          0          0
sda5             57.40         0.00       856.00          0       4280
sda6              0.00         0.00         0.00          0          0

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           6.23    0.00    6.54   28.80    0.00   58.43

Device:            tps   Blk_read/s   Blk_wrtn/s   Blk_read   Blk_wrtn
sda             281.60      3249.60      3105.60      16248      15528
sda1              0.00         0.00         0.00          0          0
sda2              0.00         0.00         0.00          0          0
sda3              0.00         0.00         0.00          0          0
sda4              0.00         0.00         0.00          0          0
sda5            281.60      3249.60      3105.60      16248      15528
sda6              0.00         0.00         0.00          0          0

Comment 3 William Yardley 2012-02-16 22:57:17 UTC
I also created Red Hat case #00600185

Comment 4 William Yardley 2012-02-17 00:28:43 UTC
The behavior is actually not as different as I thought with sysstat 8 on Debian (the iostat % seems to be higher rather than lower, but the other behavior is still the same). The behavior still strikes me as unusual.

Comment 6 William Yardley 2012-02-18 01:27:56 UTC
Ahah. I looked in TFM before, but not in the right place... near the top:

 "The first report generated by the iostat command provides statistics concerning the  time  since  the  system  was booted."

You can close this.