top incorrectly reporting process time
Ott Köstner
OttK at zzz.ee
Fri Nov 28 00:44:28 PST 2008
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
>> --------------------------------------------------------------------------------------------------------------
>> # ps -aHx|grep 1079
>> 1079 con- S 1:58.71 [mysqld]
>> 1079 con- I 0:00.00 [mysqld]
>> 1079 con- S 0:01.30 [mysqld]
>> 1079 con- I 0:46.72 [mysqld]
>> 1079 con- S 0:03.51 [mysqld]
>> 1079 con- S 0:26.05 [mysqld]
>> 1079 con- S 3:11.80 [mysqld]
>> 1079 con- S 4:09.88 [mysqld]
>> 1079 con- S 0:03.67 [mysqld]
>>
>>
>> Strange?
>>
>> Greetings,
>> O.K.
>>
>> _______________________________________________
>> freebsd-questions at freebsd.org mailing list
>> http://lists.freebsd.org/mailman/listinfo/freebsd-questions
>> To unsubscribe, send any mail to
>> "freebsd-questions-unsubscribe at freebsd.org"
>>
>>
>
> _______________________________________________
> freebsd-questions at freebsd.org mailing list
> http://lists.freebsd.org/mailman/listinfo/freebsd-questions
> To unsubscribe, send any mail to
> "freebsd-questions-unsubscribe at freebsd.org"
>
More information about the freebsd-questions
mailing list