top incorrectly reporting process time
Ott Köstner
OttK at zzz.ee
Fri Nov 28 01:44:46 PST 2008
Kris Kennaway wrote:
> Ott Köstner wrote:
>> Kris Kennaway wrote:
>>> Ott Köstner wrote:
>>>> Kris Kennaway wrote:
>>>>> Ott Köstner wrote:
>>>>>> Jeremy Chadwick wrote:
>>>>>>> On Sun, Nov 16, 2008 at 04:34:01PM +0200, Ott Köstner wrote:
>>>>>>>
>>>>>>>> On several FreeBSD machines I have the following problem:
>>>>>>>>
>>>>>>>
>>>>>>> What FreeBSD version? (It matters)
>>>>>>>
>>>>>> 7.1-PRERELEASE FreeBSD
>>>>>>
>>>>>> But I can experience it also on a 7.0 machine. Seems that top
>>>>>> reports
>>>>>> incorrectly processes with multiple threads.
>>>>>>
>>>>>> $ top -bUbind
>>>>>> last pid: 21635; load averages: 0.73, 0.46, 0.29 up 1+00:17:18
>>>>>> 16:48:10
>>>>>> 54 processes: 1 running, 53 sleeping
>>>>>>
>>>>>> Mem: 66M Active, 1174M Inact, 204M Wired, 36K Cache, 112M Buf,
>>>>>> 555M Free
>>>>>> Swap: 2048M Total, 2048M Free
>>>>>>
>>>>>> PID USERNAME THR PRI NICE SIZE RES STATE C TIME WCPU
>>>>>> COMMAND
>>>>>> 979 bind 8 44 0 40288K 32916K select 0 0:16 0.00%
>>>>>> named
>>>>>>
>>>>>> $ ps -ax|grep 979
>>>>>> 979 ?? Ss 1:11.26 /usr/sbin/named -n 5 -t /var/named -u bind
>>>>>
>>>>> Check top -H to display the statistics for individual threads.
>>>>>
>>>>> Kris
>>>> # top -bUmysql
>>>> last pid: 8336; load averages: 0.33, 0.30, 0.24 up
>>>> 13+22:36:29 08:47:07
>>>> 157 processes: 1 running, 156 sleeping
>>>>
>>>> Mem: 1163M Active, 2058M Inact, 555M Wired, 160M Cache, 214M Buf,
>>>> 22M Free
>>>> Swap: 4096M Total, 432K Used, 4095M Free
>>>>
>>>>
>>>> PID USERNAME THR PRI NICE SIZE RES STATE C TIME
>>>> WCPU COMMAND
>>>> 1079 mysql 9 20 0 92316K 70472K sigwai 1 0:04
>>>> 0.00% mysqld
>>>> 1015 mysql 1 8 0 7056K 1332K wait 1 0:00
>>>> 0.00% sh
>>>>
>>>> -------------------------------------------------------------------------------------------------------------
>>>>
>>>> # top -bHUmysql
>>>> last pid: 8497; load averages: 0.36, 0.32, 0.25 up
>>>> 13+22:37:43 08:48:21
>>>> 148 processes: 4 running, 144 sleeping
>>>>
>>>> Mem: 1147M Active, 2068M Inact, 554M Wired, 156M Cache, 214M Buf,
>>>> 32M Free
>>>> Swap: 4096M Total, 432K Used, 4095M Free
>>>>
>>>>
>>>> PID USERNAME PRI NICE SIZE RES STATE C TIME WCPU
>>>> COMMAND
>>>> 1079 mysql 44 0 92316K 70472K select 0 4:10 0.00% mysqld
>>>> 1079 mysql 44 0 92316K 70472K select 0 3:12 0.00% mysqld
>>>> 1079 mysql 44 0 92316K 70472K select 1 1:59 0.00% mysqld
>>>> 1079 mysql 44 0 92316K 70472K ucond 0 0:47 0.00% mysqld
>>>> 1079 mysql 44 0 92316K 70472K select 0 0:26 0.00% mysqld
>>>> 1079 mysql 20 0 92316K 70472K sigwai 1 0:04 0.00% mysqld
>>>> 1079 mysql 44 0 92316K 70472K ucond 0 0:04 0.00% mysqld
>>>> 1079 mysql 44 0 92316K 70472K ucond 1 0:01 0.00% mysqld
>>>> 1015 mysql 8 0 7056K 1332K wait 1 0:00 0.00% sh
>>>> 1079 mysql 44 0 92316K 70472K ucond 0 0:00 0.00% mysqld
>>>> --------------------------------------------------------------------------------------------------------------
>>>>
>>>
>>> This seems to be the only inconsistent one:
>>>
>>>> # ps -ax|grep 1079
>>>> 1079 con- S 576:13.90 [mysqld]
>>>
>>> Check that your ps binary is in sync with your kernel, i.e. rebuild
>>> world with the same sources you used to build your kernel.
>>>
>>> Kris
>>>
>> I did that. First, downloaded source with csup, built world, kernel,
>> installed kernel and world. Then rebuilt kernel once again and
>> installed it.
>>
>> On another machine (w/ 32bit kernel):
>>
>> # top -bU bind; top -bHU bind
>> last pid: 21738; load averages: 0.02, 0.20, 0.27 up
>> 12+18:08:53 10:39:45
>> 56 processes: 1 running, 55 sleeping
>>
>> Mem: 207M Active, 1494M Inact, 223M Wired, 70M Cache, 112M Buf, 4700K
>> Free
>> Swap: 2048M Total, 12K Used, 2048M Free
>>
>>
>> PID USERNAME THR PRI NICE SIZE RES STATE C TIME WCPU COMMAND
>> 979 bind 8 44 0 52576K 44652K select 1 9:42 0.00% named
======================================^^^^^^
>>
>> last pid: 21739; load averages: 0.02, 0.20, 0.27 up
>> 12+18:08:53 10:39:45
>> 56 processes: 1 running, 55 sleeping
>>
>> Mem: 207M Active, 1494M Inact, 223M Wired, 70M Cache, 112M Buf, 4712K
>> Free
>> Swap: 2048M Total, 12K Used, 2048M Free
>>
>>
>> PID USERNAME PRI NICE SIZE RES STATE C TIME WCPU COMMAND
>> 979 bind 44 0 52576K 44652K select 1 9:42 0.00% named
>> 979 bind 44 0 52576K 44652K ucond 1 5:52 0.00% named
>> 979 bind 44 0 52576K 44652K ucond 0 5:51 0.00% named
>> 979 bind 44 0 52576K 44652K ucond 0 5:50 0.00% named
>> 979 bind 44 0 52576K 44652K ucond 1 5:49 0.00% named
>> 979 bind 44 0 52576K 44652K ucond 1 5:48 0.00% named
>> 979 bind 44 0 52576K 44652K ucond 1 0:16 0.00% named
>> 979 bind 20 0 52576K 44652K sigwai 1 0:00 0.00% named
>>
>> # ps -aHx | grep 979; echo ;ps -ax | grep 979
>> 979 ?? Is 0:00.01 /usr/sbin/named -n 5 -t /var/named -u bind
>> 979 ?? Ss 5:49.41 /usr/sbin/named -n 5 -t /var/named -u bind
>> 979 ?? Ss 5:50.73 /usr/sbin/named -n 5 -t /var/named -u bind
>> 979 ?? Ss 5:50.36 /usr/sbin/named -n 5 -t /var/named -u bind
>> 979 ?? Ss 5:52.14 /usr/sbin/named -n 5 -t /var/named -u bind
>> 979 ?? Ss 5:48.15 /usr/sbin/named -n 5 -t /var/named -u bind
>> 979 ?? Ss 0:15.69 /usr/sbin/named -n 5 -t /var/named -u bind
>> 979 ?? Ss 9:41.68 /usr/sbin/named -n 5 -t /var/named -u bind
>> 21761 p0 R+ 0:00.00 grep 979
>>
>> 979 ?? Ss 39:08.18 /usr/sbin/named -n 5 -t /var/named -u bind
=============^^^^
Here is the problem. top returns only 9:42 -- the time of the first
thread. ps returns the sum of the thread times, which is correct.
Best regards,
O.K.
>>
>> 21763 p0 R+ 0:00.01 grep 979
>
> Well, that one makes sense, it's the sum of the thread run times. The
> previous one you posted wasn't though - maybe you didn't paste in all
> of the threads?
>
> Kris
>
>
>
More information about the freebsd-questions
mailing list