Bug 480128 - mpstat shows invalid statistics
Summary: mpstat shows invalid statistics
Keywords:
Status: CLOSED WONTFIX
Alias: None
Product: Red Hat Enterprise Linux 5
Classification: Red Hat
Component: sysstat
Version: 5.3
Hardware: All
OS: Linux
low
medium
Target Milestone: rc
: ---
Assignee: Ivana Varekova
QA Contact: BaseOS QE
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2009-01-15 09:37 UTC by Karel Volný
Modified: 2009-01-28 11:40 UTC (History)
0 users

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2009-01-28 11:40:20 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)

Description Karel Volný 2009-01-15 09:37:34 UTC
Description of problem:
during testing of bug #451119 I have found that mpstat does not show correct results - see the bug #480124 - and I have found that there is a problem in RHEL 5 too

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

How reproducible:
always

Steps to Reproduce:
1. run some cpu intensive task, e.g. cat /dev/urandom > /dev/null
2. watch mpstat with some short interval, not from the system boot (watch
mpstat -P ALL 1 1)
  
Actual results:
Every 2.0s: mpstat -P ALL 1 1                                                                                                       Thu Jan 15 04:14:28 2009

Linux 2.6.18-92.1.22.el5xen (x86-64-5s-m1.lab.bos.redhat.com)   01/15/2009

04:14:28 AM  CPU   %user   %nice    %sys %iowait    %irq   %soft  %steal   %idle    intr/s
04:14:29 AM  all    0.00    0.00   25.38    0.00    0.00    0.00    0.00   74.62    256.00
04:14:29 AM    0    0.00    0.00  100.00    0.00    0.00    0.00    0.00    0.00    108.00
04:14:29 AM    1    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     65.00
04:14:29 AM    2    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     31.00
04:14:29 AM    3    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     52.00

Average:     CPU   %user   %nice    %sys %iowait    %irq   %soft  %steal   %idle    intr/s
Average:     all    0.00    0.00   25.38    0.00    0.00    0.00    0.00   74.62    256.00
Average:       0    0.00    0.00  100.00    0.00    0.00    0.00    0.00    0.00    108.00
Average:       1    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     65.00
Average:       2    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     31.00
Average:       3    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     52.00


Expected results:
the "all" sum corresponds to sum of the individual CPUs divided by their number, i.e. (100+0+0+0)/4=25.00 and (0+100+100+100)/4=75.00 within the columns sys and idle in this example; the difference 0.38 is far beyond any rounding error due to using just two places after the point

Additional info:
I've been testing using the machine x86-64-5s-m1.lab.bos.redhat.com

Comment 1 Ivana Varekova 2009-01-16 12:31:46 UTC
Hello, 
please could you rebuild and run a version which produces more verbose output:
http://people.redhat.com/varekova/sysstat-7.0.2-3.TEST.el5.src.rpm
and attach the output here.
Thanks a lot.

Comment 2 Karel Volný 2009-01-27 11:07:30 UTC
here are some samples:

.qa.[root@x86-64-5s-m1 tmp]# mpstat -P ALL 1 3
Linux 2.6.18-92.1.22.el5xen (x86-64-5s-m1.lab.bos.redhat.com)   01/27/2009

06:07:34 AM  CPU   %user   %nice    %sys %iowait    %irq   %soft  %steal   %idle    intr/s
06:07:35 AM  all    0.00    0.00   25.84    0.00    0.00    0.00    0.00   74.16    221.00
    2003566       87444      639665     1232451         428        2890        7558   313293904 ||        100
    2003566       87444      639665     1232451         428        2890        7558   313293904 ||        100
06:07:35 AM    0    0.00    0.00  100.00    0.00    0.00    0.00    0.00    0.00    108.00
     795117       43668      202498     1124325         428        2404        3301    77145232 ||        100
     795117       43668      202598     1124325         428        2404        3301    77145232 ||        100
06:07:35 AM    1    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     62.00
     362980       13848      144649       38823           0         178        2122    78754374 ||        100
     362980       13848      144649       38823           0         178        2122    78754474 ||        100
06:07:35 AM    2    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     27.00
     435130       17604      158653       49143           0         162        1272    78655010 ||        100
     435130       17604      158653       49143           0         162        1272    78655106 ||        100
06:07:35 AM    3    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     23.00
     410338       12323      133865       20157           0         144         861    78739286 ||        100
     410338       12323      133865       20157           0         144         861    78739378 ||        100

06:07:35 AM  CPU   %user   %nice    %sys %iowait    %irq   %soft  %steal   %idle    intr/s
06:07:36 AM  all    0.49    0.00   24.21    0.00    0.00    0.00    0.00   75.31    191.00
    2003566       87444      639765     1232451         428        2890        7558   313294191 ||        100
    2003566       87444      639765     1232451         428        2890        7558   313294191 ||        100
06:07:36 AM    0    1.00    0.00   99.00    0.00    0.00    0.00    0.00    0.00    120.00
     795117       43668      202598     1124325         428        2404        3301    77145232 ||        100
     795118       43668      202697     1124325         428        2404        3301    77145232 ||        100
06:07:36 AM    1    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     37.00
     362980       13848      144649       38823           0         178        2122    78754474 ||        100
     362980       13848      144649       38823           0         178        2122    78754574 ||        100
06:07:36 AM    2    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     18.00
     435130       17604      158653       49143           0         162        1272    78655106 ||        100
     435130       17604      158653       49143           0         162        1272    78655206 ||        100
06:07:36 AM    3    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     16.00
     410338       12323      133865       20157           0         144         861    78739378 ||        100
     410338       12323      133865       20157           0         144         861    78739486 ||        100

06:07:36 AM  CPU   %user   %nice    %sys %iowait    %irq   %soft  %steal   %idle    intr/s
06:07:37 AM  all    0.00    0.00   25.45    0.00    0.00    0.00    0.00   74.55    192.00
    2003568       87444      639864     1232451         428        2890        7558   313294499 ||        100
    2003568       87444      639864     1232451         428        2890        7558   313294499 ||        100
06:07:37 AM    0    0.00    0.00  100.00    0.00    0.00    0.00    0.00    0.00    113.00
     795118       43668      202697     1124325         428        2404        3301    77145232 ||        100
     795118       43668      202797     1124325         428        2404        3301    77145232 ||        100
06:07:37 AM    1    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     42.00
     362980       13848      144649       38823           0         178        2122    78754574 ||        100
     362980       13848      144649       38823           0         178        2122    78754674 ||        100
06:07:37 AM    2    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     18.00
     435130       17604      158653       49143           0         162        1272    78655206 ||        100
     435130       17604      158653       49143           0         162        1272    78655306 ||        100
06:07:37 AM    3    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     19.00
     410338       12323      133865       20157           0         144         861    78739486 ||        100
     410338       12323      133865       20157           0         144         861    78739578 ||        100

Average:     CPU   %user   %nice    %sys %iowait    %irq   %soft  %steal   %idle    intr/s
Average:     all    0.17    0.00   25.15    0.00    0.00    0.00    0.00   74.68    201.33
    2003566       87444      639665     1232451         428        2890        7558   313293904 ||        300
    2003566       87444      639665     1232451         428        2890        7558   313293904 ||        300
Average:       0    0.33    0.00   99.67    0.00    0.00    0.00    0.00    0.00    113.67
     795117       43668      202498     1124325         428        2404        3301    77145232 ||        300
     795118       43668      202797     1124325         428        2404        3301    77145232 ||        300
Average:       1    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     47.00
     362980       13848      144649       38823           0         178        2122    78754374 ||        300
     362980       13848      144649       38823           0         178        2122    78754674 ||        300
Average:       2    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     21.00
     435130       17604      158653       49143           0         162        1272    78655010 ||        300
     435130       17604      158653       49143           0         162        1272    78655306 ||        300
Average:       3    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     19.33
     410338       12323      133865       20157           0         144         861    78739286 ||        300
     410338       12323      133865       20157           0         144         861    78739578 ||        300

Comment 3 Karel Volný 2009-01-27 14:19:34 UTC
another test run:

.qa.[root@x86-64-5s-m1 tmp]# mpstat -P ALL 1 3
Linux 2.6.18-92.1.22.el5xen (x86-64-5s-m1.lab.bos.redhat.com)   01/27/2009

09:19:48 AM  CPU   %user   %nice    %sys %iowait    %irq   %soft  %steal   %idle    intr/s
09:19:49 AM  all    0.00    0.00   25.57    0.00    0.00    0.00    0.00   74.43    250.50
    2016906       87444     1795282     1237358         428        2911        7701   316733323 ||        101
    2016906       87444     1795383     1237358         428        2911        7701   316733617 ||        101
09:19:49 AM    0    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     64.36
     799628       43668      206682     1128873         428        2421        3367    78285267 ||        101
     799628       43668      206682     1128873         428        2421        3367    78285368 ||        101
09:19:49 AM    1    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     76.24
     365892       13848      145767       38970           0         181        2178    79903500 ||        101
     365892       13848      145767       38970           0         181        2178    79903599 ||        101
09:19:49 AM    2    0.00    0.00  100.00    0.00    0.00    0.00    0.00    0.00    100.00
     436623       17604     1307808       49149           0         162        1272    78657717 ||        101
     436623       17604     1307909       49149           0         162        1272    78657717 ||        101
09:19:49 AM    3    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00      9.90
     414761       12323      135023       20365           0         145         882    79886838 ||        101
     414761       12323      135023       20365           0         145         882    79886933 ||        101

09:19:49 AM  CPU   %user   %nice    %sys %iowait    %irq   %soft  %steal   %idle    intr/s
09:19:50 AM  all    0.25    0.00   24.56    0.00    0.00    0.00    0.00   75.19    280.81
    2016906       87444     1795383     1237358         428        2911        7701   316733617 ||         99
    2016907       87444     1795481     1237358         428        2911        7701   316733917 ||         99
09:19:50 AM    0    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     90.91
     799628       43668      206682     1128873         428        2421        3367    78285368 ||         99
     799628       43668      206682     1128873         428        2421        3367    78285467 ||         99
09:19:50 AM    1    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     78.79
     365892       13848      145767       38970           0         181        2178    79903599 ||         99
     365892       13848      145767       38970           0         181        2178    79903700 ||         99
09:19:50 AM    2    1.01    0.00   98.99    0.00    0.00    0.00    0.00    0.00    101.01
     436623       17604     1307909       49149           0         162        1272    78657717 ||         99
     436624       17604     1308007       49149           0         162        1272    78657717 ||         99
09:19:50 AM    3    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     11.11
     414761       12323      135023       20365           0         145         882    79886933 ||         99
     414761       12323      135023       20365           0         145         882    79887032 ||         99

09:19:50 AM  CPU   %user   %nice    %sys %iowait    %irq   %soft  %steal   %idle    intr/s
09:19:51 AM  all    0.00    0.00   25.00    0.00    0.00    0.00    0.00   75.00    250.00
    2016907       87444     1795481     1237358         428        2911        7701   316733917 ||        100
    2016907       87444     1795581     1237358         428        2911        7701   316734217 ||        100
09:19:51 AM    0    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     65.00
     799628       43668      206682     1128873         428        2421        3367    78285467 ||        100
     799628       43668      206682     1128873         428        2421        3367    78285567 ||        100
09:19:51 AM    1    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     76.00
     365892       13848      145767       38970           0         181        2178    79903700 ||        100
     365892       13848      145767       38970           0         181        2178    79903799 ||        100
09:19:51 AM    2    0.00    0.00  100.00    0.00    0.00    0.00    0.00    0.00     99.00
     436624       17604     1308007       49149           0         162        1272    78657717 ||        100
     436624       17604     1308107       49149           0         162        1272    78657717 ||        100
09:19:51 AM    3    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00      9.00
     414761       12323      135023       20365           0         145         882    79887032 ||        100
     414761       12323      135023       20365           0         145         882    79887132 ||        100

Average:     CPU   %user   %nice    %sys %iowait    %irq   %soft  %steal   %idle    intr/s
Average:     all    0.08    0.00   25.04    0.00    0.00    0.00    0.00   74.87    260.33
    2016906       87444     1795282     1237358         428        2911        7701   316733323 ||        300
    2016907       87444     1795581     1237358         428        2911        7701   316734217 ||        300
Average:       0    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     73.33
     799628       43668      206682     1128873         428        2421        3367    78285267 ||        300
     799628       43668      206682     1128873         428        2421        3367    78285567 ||        300
Average:       1    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     77.00
     365892       13848      145767       38970           0         181        2178    79903500 ||        300
     365892       13848      145767       38970           0         181        2178    79903799 ||        300
Average:       2    0.33    0.00   99.67    0.00    0.00    0.00    0.00    0.00    100.00
     436623       17604     1307808       49149           0         162        1272    78657717 ||        300
     436624       17604     1308107       49149           0         162        1272    78657717 ||        300
Average:       3    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00     10.00
     414761       12323      135023       20365           0         145         882    79886838 ||        300
     414761       12323      135023       20365           0         145         882    79887132 ||        300

Comment 4 Ivana Varekova 2009-01-28 11:40:20 UTC
Hello, the problem is analogical to 480124 - now the bug is caused by different sources for time for one cpu and time for all cpus. (the difference is maximally 0.01*number of proc) - so there should be a small mistake  like this.


Note You need to log in before you can comment on or make changes to this bug.