Date: Fri, 28 Nov 2008 00:54:25 -0800 From: Kris Kennaway <kris@FreeBSD.org> To: =?ISO-8859-1?Q?Ott_K=F6stner?= <OttK@zzz.ee> Cc: freebsd-questions@freebsd.org Subject: Re: top incorrectly reporting process time Message-ID: <492FB1C1.8070808@FreeBSD.org> In-Reply-To: <492FAF64.50507@zzz.ee> References: <49202F59.7050802@zzz.ee> <20081116144057.GA3864@icarus.home.lan> <492034B8.9020903@zzz.ee> <492F4086.7040403@FreeBSD.org> <492F95B9.8050506@zzz.ee> <492F9899.9030506@FreeBSD.org> <492FAF64.50507@zzz.ee>
next in thread | previous in thread | raw e-mail | index | archive | help
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
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?492FB1C1.8070808>