top incorrectly reporting process time
Kris Kennaway
kris at FreeBSD.org
Fri Nov 28 00:54:28 PST 2008
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
> 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