misc/126230: weird process cpu usage stats and weird load average

[Kris Kennaway]

The following reply was made to PR misc/126230; it has been noted by GNATS.

From: Kris Kennaway <kris at FreeBSD.org>
To: Jakub Jasinski <jakub.jasinski at utoronto.ca>
Cc: freebsd-gnats-submit at FreeBSD.org
Subject: Re: misc/126230: weird process cpu usage stats and weird load average
Date: Mon, 04 Aug 2008 13:34:44 +0200

 Jakub Jasinski wrote:
 >> Number:         126230
 >> Category:       misc
 >> Synopsis:       weird process cpu usage stats and weird load average
 >> Confidential:   no
 >> Severity:       non-critical
 >> Priority:       medium
 >> Responsible:    freebsd-bugs
 >> State:          open
 >> Quarter:        
 >> Keywords:       
 >> Date-Required:
 >> Class:          sw-bug
 >> Submitter-Id:   current-users
 >> Arrival-Date:   Mon Aug 04 06:50:02 UTC 2008
 >> Closed-Date:
 >> Last-Modified:
 >> Originator:     Jakub Jasinski
 >> Release:        7.0
 >> Organization:
 >> Environment:
 > FreeBSD mail2.parkin.ca 7.0-RELEASE FreeBSD 7.0-RELEASE #0: Sun Feb 24 10:35:36 UTC 2008     root at driscoll.cse.buffalo.edu:/usr/obj/usr/src/sys/GENERIC  amd64
 >> Description:
 > This is a Proliant 380 G5, running the 64-bit FreeBSD 7.0-RELEASE.
 > 
 > Top's output seems like total nonsense.  The server is not deployed yet.  So I ran rsync to see what strangeness might occur.  Only rsync is really active.
 > 
 > Here's a snippet of top's output:
 > 
 > last pid:  7591;  load averages:  7.70,  8.78,  9.87    up 0+09:14:46  02:34:03
 > 61 processes:  1 running, 59 sleeping, 1 stopped
 > CPU states:  1.1% user,  0.0% nice, 34.4% system,  3.1% interrupt, 61.4% idle
 > Mem: 208M Active, 7031M Inact, 377M Wired, 257M Cache, 214M Buf, 40M Free
 > Swap: 8192M Total, 4K Used, 8192M Free
 > 
 >   PID USERNAME    THR PRI NICE   SIZE    RES STATE  C   TIME   WCPU COMMAND
 >  7315 root          1 102    0 17196K 11908K select 1   6:35  9.03% rsync
 >   664 root          2   4    0 15396K  2196K select 0   6:12  7.32% apcupsd
 >   745 root          1   4    0  9940K  1072K select 3   3:47  3.96% authdaemond
 >  6619 root          1   4    0 30108K  3912K select 0   2:54  3.81% sendmail
 >  7310 root          1   4    0 17196K 11620K select 2   2:22  3.76% rsync
 >  5212 root          1   4    0 10700K  2184K select 3   3:04  3.56% gam_server
 >  6534 mailnull      1   4    0  9252K  1732K select 1   2:42  3.52% mimedefang-
 >   473 root          1   4    0  5808K  1000K select 2   2:42  3.52% moused
 >   768 root          1   4    0  9940K  1204K select 2   2:23  3.47% authdaemond
 >  6551 mailnull      2  20    0  7196K  1648K sigwai 2   2:26  3.37% mimedefang
 >  7575 root          1  98    0  7656K  2016K CPU1   0   0:09  3.32% top
 >   772 root          1   4    0  9940K  1204K select 2   2:21  3.22% authdaemond
 >  5458 root          1   4    0 76168K 17452K select 3   3:53  3.17% kdeinit
 >   500 root          1   4    0  5808K  1000K select 1   2:41  3.17% moused
 >   770 root          1   4    0  9940K  1072K select 3   2:21  3.12% authdaemond
 >   811 root          1   4    0 20960K  3004K select 2   2:17  3.08% sshd
 >  7092 root          1   4    0 27300K  9668K select 2   2:25  3.03% perl
 >   771 root          1   4    0  9940K  1204K select 0   2:21  2.98% authdaemond
 >  5845 admin         1   4    0 32936K  3552K select 2   2:29  2.93% sshd
 >   769 root          1   4    0  9940K  1204K select 1   2:21  2.88% authdaemond
 >   788 root          1   4    0  3604K  1024K select 1   2:16  2.73% couriertcpd
 >   615 root          1   4    0  4684K  1172K select 0   2:28  2.69% syslogd
 >   763 root          1   4    0  3604K  1020K select 1   2:18  2.64% couriertcpd
 >   548 root          1   4    0  1616K   484K select 1   2:19  2.54% devd
 >   778 root          1   4    0  3604K  1056K select 3   2:16  2.54% couriertcpd
 >   754 root          1   4    0  3604K  1020K select 3   2:16  2.54% couriertcpd
 >   793 mailnull      1   4    0 88116K 75880K accept 1   0:08  0.00% clamd
 >  6536 mailnull      1  -8    0 44464K 22288K piperd 3   0:00  0.00% perl
 >  6556 mailnull      1  -8    0 43696K 21524K piperd 3   0:00  0.00% perl
 >  5857 root          1   8    0  8692K  2316K wait   3   0:00  0.00% bash
 >  5540 root          1   4   19 75800K 19312K STOP   0   0:00  0.00% kblankscrn.
 >   836 root          1   8    0  5736K  1208K nanslp 1   0:00  0.00% cron
 >  1003 root          1  20    0  9616K  2612K pause  1   0:00  0.00% csh
 >   954 root          1   5    0  9616K  2564K ttyin  1   0:00  0.00% csh
 >   798 mailnull      1  20    0 11976K  1796K pause  1   0:00  0.00% freshclam
 >  4013 root          1   5    0  8692K  2232K ttyin  1   0:00  0.00% bash
 >  5842 root          1   4    0 32936K  3552K sbwait 1   0:00  0.00% sshd
 >   945 root          1   8    0 19412K  1532K wait   2   0:00  0.00% login
 >  5852 root          1  20    0  9616K  2432K pause  0   0:00  0.00% csh
 >   946 root          1   8    0 19412K  1492K wait   1   0:00  0.00% login
 >  5847 admin         1   8    0  8692K  2304K wait   3   0:00  0.00% bash
 
 This shows that various processes have recently been running, explaining 
 the load average.  You can also see that the same processes that have 
 non-zero WCPU have non-zero TIME, indicating that they have accumulated 
 CPU runtime.  All of this is self-consistent and points to the fact that 
 you have processes running on your server.
 
 Kris