steadily increasing instr/s from mpstat

[pedalpete]

Hi all,

I'm fairly new to Linux and am running CentOS on my web server.

I've been using mpstat to check out the processor utilization, and most of the numbers look good (as far as I can tell).

Here's my mpstat output

02:31:49 PM  CPU   %user   %nice    %sys %iowait    %irq   %soft  %steal   %idle    intr/s
02:31:49 PM  all    8.70    0.00    1.68    0.10    0.02    0.02    0.00   89.49    153.21

the only thing that I think I am slightly concerened about is intr/s. I'm not sure if 153 is a big number, but I started out around 50 or so about 2 weeks ago, and it seems to be steadily climbing, though I don't have any more services running now than I did then.

Could it be that some threads are not being released or something?
Is this something I should be concerned about?

[sicarie]

From an online mpstat manpage it looks like that is an aggregate number over time of the number of interrupts received, so it should be climbing the longer the box is up.

That's just my 15 seconds of Googling, though - I couldn't tell you what a good or bad level of interrupts may be - I'm guessing that would be more for application behavior, but that is just a guess.

[pedalpete]

Thanks Sicarie,

I saw that page, but took the meaning to be that is the number of interupts per second, not an aggregate of the total number of interupts as long as the machine was up.

I'm trying to figure out if an aggregate of total number per second makes sense, but you could be right.

If so, I won't worry.
Bit digging deeper, using ps -aux, it shows that mysql is using 153% of cpu. But mpstat shows very little cpu being used.
I'm gonna try to restart mysql and see what happens.

Thanks,
Pete

[sicarie]

pedalpete-

Could you post that ps? It's very interesting that over 100% could be utilized, though I don't doubt that it could show that. (I'm really just curious to see it, personally)

Thanks,

sicarie

[pedalpete]

Damn, i literally JUST restarted mysql, and it is now showing 1%.

now that I've started running a few processes, mysql has jumped to 20%

mysql    16157 20.1  0.9 137640 19660 pts/0    Sl   17:58   1:40

now 46%,
I'll post here when I get over 100%
mpstat still shows

06:10:14 PM  CPU   %user   %nice    %sys %iowait    %irq   %soft  %steal   %idle    intr/s
06:10:14 PM  all    8.88    0.00    1.71    0.10    0.02    0.02    0.00   89.28    156.41

[pedalpete]

within 20 minutes of restarting mysql, it was showing 102% cpu,
but then it dropped and it seems to be dropping albiet slowly.

currently at 96.5%

mysql    16157 96.5  1.3 139592 27440 pts/0    Sl   17:58  25:12 /usr/libexec/my

if i get a chance to see it above 100% again, i'll be sure to grab a shot and post it here.

[pedalpete]

here it is, about 1 hour after restarting and mysql is up above 100% again

mysql    16157  102  1.3 139604 27492 ?        Sl   17:58  96:45 /usr/libexec/my

here's the mpstat

07:35:20 PM  CPU   %user   %nice    %sys %iowait    %irq   %soft  %steal   %idle    intr/s
07:35:20 PM  all    8.89    0.00    1.71    0.10    0.02    0.02    0.00   89.27    156.58

here's the full output of my ps -aux

USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root         1  0.0  0.0   2032   596 ?        Ss    2007   2:34 init [3]
root         2  0.0  0.0      0     0 ?        S     2007   0:04 [migration/0]
root         3  0.0  0.0      0     0 ?        SN    2007   0:00 [ksoftirqd/0]
root         4  0.0  0.0      0     0 ?        S     2007   0:00 [watchdog/0]
root         5  0.0  0.0      0     0 ?        S     2007   0:01 [migration/1]
root         6  0.0  0.0      0     0 ?        SN    2007   0:00 [ksoftirqd/1]
root         7  0.0  0.0      0     0 ?        S     2007   0:00 [watchdog/1]
root         8  0.0  0.0      0     0 ?        S<    2007   0:00 [events/0]
root         9  0.0  0.0      0     0 ?        S<    2007   0:00 [events/1]
root        10  0.0  0.0      0     0 ?        S<    2007   0:00 [khelper]
root        11  0.0  0.0      0     0 ?        S<    2007   0:00 [kthread]
root        15  0.0  0.0      0     0 ?        S<    2007   0:03 [kblockd/0]
root        16  0.0  0.0      0     0 ?        S<    2007   0:03 [kblockd/1]
root        17  0.0  0.0      0     0 ?        S<    2007   0:00 [kacpid]
root        90  0.0  0.0      0     0 ?        S<    2007   0:00 [cqueue/0]
root        91  0.0  0.0      0     0 ?        S<    2007   0:00 [cqueue/1]
root        94  0.0  0.0      0     0 ?        S<    2007   0:00 [khubd]
root        96  0.0  0.0      0     0 ?        S<    2007   0:00 [kseriod]
root       166  0.0  0.0      0     0 ?        S<    2007   0:29 [kswapd0]
root       167  0.0  0.0      0     0 ?        S<    2007   0:00 [aio/0]
root       168  0.0  0.0      0     0 ?        S<    2007   0:00 [aio/1]
root       328  0.0  0.0      0     0 ?        S<    2007   0:00 [kpsmoused]
root       358  0.0  0.0      0     0 ?        S<    2007   0:00 [ata/0]
root       359  0.0  0.0      0     0 ?        S<    2007   0:00 [ata/1]
root       360  0.0  0.0      0     0 ?        S<    2007   0:00 [ata_aux]
root       364  0.0  0.0      0     0 ?        S<    2007   0:00 [scsi_eh_0]
root       365  0.0  0.0      0     0 ?        S<    2007   0:00 [scsi_eh_1]
root       366  0.0  0.0      0     0 ?        S<    2007  38:02 [kjournald]
root       398  0.0  0.0      0     0 ?        S<    2007   0:15 [kauditd]
root       432  0.0  0.0   2664  1136 ?        S<s   2007   0:00 /sbin/udevd -d
root      1275  0.0  0.0      0     0 ?        S<    2007   0:00 [kmirrord]
root      1296  0.0  0.0      0     0 ?        S<    2007   0:00 [kjournald]
root      1877  0.0  0.3   9672  8100 ?        Ss    2007   0:00 /usr/sbin/resto
root      1893  0.0  0.0  13088   736 ?        S<sl  2007   8:35 auditd
root      1895  0.0  0.1   9496  3856 ?        S<s   2007   6:52 python /sbin/au
root      1913  0.0  0.0   1688   580 ?        Ss    2007  12:32 syslogd -m 0
root      1916  0.0  0.0   1640   400 ?        Ss    2007   0:00 klogd -x
root      1932  0.0  0.0   1684   336 ?        Ss    2007   0:16 irqbalance
root      1952  0.0  0.0   2124   508 ?        Ss    2007   1:48 mcstransd
rpc       1974  0.0  0.0   1772   624 ?        Ss    2007   0:00 portmap
root      1991  0.0  0.7  45984 15524 ?        Ssl   2007   8:13 /usr/bin/python
root      2016  0.0  0.0   1784   728 ?        Ss    2007   0:00 rpc.statd
root      2059  0.0  0.0   4936   560 ?        Ss    2007   0:00 rpc.idmapd
dbus      2086  0.0  0.0  13076  1308 ?        Ssl   2007   0:00 dbus-daemon --s
root      2102  0.0  0.0   2120   756 ?        Ss    2007   0:00 /usr/sbin/hcid
root      2132  0.0  0.0      0     0 ?        S<    2007   0:00 [krfcommd]
root      2182  0.0  0.0  12688  1348 ?        Ssl   2007   1:05 pcscd
root      2206  0.0  0.0   1876   444 ?        Ss    2007   0:00 /usr/bin/hidd -
apache    2222  0.0  0.5  31484 11916 ?        S    Oct12   0:02 /usr/sbin/httpd
root      2227  0.1  0.0      0     0 ?        RN    2007 474:24 [kipmi0]
root      2279  0.0  0.0  12400  1116 ?        Ssl   2007   0:00 automount
root      2302  0.0  0.0   1636   528 ?        Ss    2007   0:00 /usr/sbin/acpid
root      2317  0.0  0.0   9576  2036 ?        Ss    2007   0:00 cupsd
root      2335  0.0  0.0   5172   952 ?        Ss    2007  11:38 /usr/sbin/sshd
root      2384  0.0  0.0   1868   472 ?        Ss    2007   0:00 gpm -m /dev/inp
root      2399  0.0  0.0   5220  1180 ?        Ss    2007   0:01 crond
xfs       2428  0.0  0.0   3420  1284 ?        Ss    2007   0:00 xfs -droppriv -
root      2457  0.0  0.0   2204   428 ?        Ss    2007   0:00 /usr/sbin/atd
avahi     2488  0.0  0.0   2532  1372 ?        Ss    2007   0:00 avahi-daemon: r
avahi     2489  0.0  0.0   2532   424 ?        Ss    2007   0:00 avahi-daemon: c
68        2504  0.0  0.1   5320  3644 ?        Ss    2007   0:02 hald
root      2505  0.0  0.0   3096  1092 ?        S     2007   0:00 hald-runner
68        2511  0.0  0.0   1968   816 ?        S     2007   0:00 hald-addon-acpi
root      2527  0.0  0.0   1924   656 ?        S     2007   7:26 hald-addon-stor
root      2542  0.0  0.1   7028  2320 ?        Ss    2007   0:00 /usr/bin/perl /
root      2577  0.0  0.0   1952   512 ?        S     2007   0:01 /usr/sbin/smart
root      2580  0.0  0.0   1628   468 tty1     Ss+   2007   0:00 /sbin/mingetty
root      2581  0.0  0.0   1624   464 tty2     Ss+   2007   0:00 /sbin/mingetty
root      2582  0.0  0.0   1624   464 tty3     Ss+   2007   0:00 /sbin/mingetty
root      2583  0.0  0.0   1628   468 tty4     Ss+   2007   0:00 /sbin/mingetty
root      2584  0.0  0.0   1628   468 tty5     Ss+   2007   0:00 /sbin/mingetty
root      2598  0.0  0.0   1624   464 tty6     Ss+   2007   0:00 /sbin/mingetty
root      2599  0.0  0.0   1640   512 ttyS0    Ss+   2007   0:00 /sbin/agetty -L
apache    3524  0.0  0.6  32712 12948 ?        S    Oct12   0:03 /usr/sbin/httpd
apache    3891  0.0  0.5  31756 11988 ?        S    Oct12   0:02 /usr/sbin/httpd
apache    4118  0.0  0.5  31484 11888 ?        S    Oct12   0:02 /usr/sbin/httpd
apache    8973  0.0  1.4  60528 31016 ?        S    Jan22   0:00 /usr/sbin/httpd
nobody   10964  0.0  3.3 102236 69944 ?        Ssl  Sep05   0:01 memcached -d -m
root     15027  0.0  0.6  31044 14104 ?        Ss   Oct11   0:00 /usr/sbin/httpd
root     16121  0.0  0.0   4488  1208 ?        S    17:58   0:00 /bin/sh /usr/bi
mysql    16157  102  1.3 139604 27492 ?        Sl   17:58  96:45 /usr/libexec/my
root     16437  0.0  0.0      0     0 ?        S    18:11   0:00 [pdflush]
root     16685  0.0  0.0      0     0 ?        S    18:29   0:00 [pdflush]
root     17502  0.0  0.1   8028  2448 ?        Ss   19:30   0:00 sshd: root@pts/
root     17504  0.0  0.0   4620  1448 pts/0    Ss   19:30   0:00 -bash
root     17538  0.0  0.0   4216   948 pts/0    R+   19:33   0:00 ps -aux
apache   18041  0.0  0.5  31568 12000 ?        S    Oct12   0:03 /usr/sbin/httpd
apache   18042  0.0  0.5  31484 11920 ?        S    Oct12   0:28 /usr/sbin/httpd
apache   18043  0.0  0.5  31484 11900 ?        S    Oct12   0:03 /usr/sbin/httpd
apache   18044  0.0  0.6  32352 12828 ?        S    Oct12   0:30 /usr/sbin/httpd
apache   18045  0.0  0.6  32256 13108 ?        S    Oct12   0:15 /usr/sbin/httpd
apache   18046  0.0  0.5  31976 12292 ?        S    Oct12   0:03 /usr/sbin/httpd
apache   18047  0.0  0.6  32772 13580 ?        S    Oct12   0:05 /usr/sbin/httpd
apache   18048  0.0  0.5  31868 12300 ?        S    Oct12   0:19 /usr/sbin/httpd
apache   21222  0.0  0.6  32288 13140 ?        S    Oct12   0:53 /usr/sbin/httpd
apache   21532  0.0  0.5  31896 12236 ?        S    Oct12   0:26 /usr/sbin/httpd
apache   21533  0.0  0.5  31548 12052 ?        S    Oct12   0:03 /usr/sbin/httpd
root     24631  0.0  0.0   8628  1828 ?        Ss   Mar28   0:00 sendmail: accep
smmsp    24640  0.0  0.0   7548  1460 ?        Ss   Mar28   0:00 sendmail: Queue
root     24665  0.0  0.0   4988   460 ?        Ss   Mar28   0:00 /usr/sbin/sasla
root     24666  0.0  0.0   4988   244 ?        S    Mar28   0:00 /usr/sbin/sasla
root     24667  0.0  0.0   4988   240 ?        S    Mar28   0:00 /usr/sbin/sasla
root     24668  0.0  0.0   4988   240 ?        S    Mar28   0:00 /usr/sbin/sasla
root     24669  0.0  0.0   4988   240 ?        S    Mar28   0:00 /usr/sbin/sasla
apache   28252  0.0  0.6  32240 13120 ?        S    Oct12   0:29 /usr/sbin/httpd
apache   28378  0.0  0.6  32400 12636 ?        S    Oct12   0:05 /usr/sbin/httpd
apache   28650  0.0  0.6  32668 13648 ?        S    Oct12   0:03 /usr/sbin/httpd

[pedalpete]

just checked again this am, and mysql up to 139% cpu

mysql    16157  139  1.3 141404 27944 ?        Sl   Oct14 1445:13 /usr/libexec/m

at the same time, queries are running quickly, so could be an error in ps

[sicarie]

just checked again this am, and mysql up to 139% cpu

mysql    16157  139  1.3 141404 27944 ?        Sl   Oct14 1445:13 /usr/libexec/m

at the same time, queries are running quickly, so could be an error in ps

Well, what I'm curious now is the specs on your machine - does this have more than one processor? I'm gonna have to look into ps now - it's interesting to me that a Linux/UNIX programmer would allow something to register as more than 100%.

Thanks for indulging me!

[Laharl]

I have a dual-core system and I've seen the load go over 1.0 with uptime, so this may be a symptom that it's calculating each processor separately and adding them together.

[sicarie]

I have a dual-core system and I've seen the load go over 1.0 with uptime, so this may be a symptom that it's calculating each processor separately and adding them together.

That's my guess as well, but I'm extremely curious on this one - now I just have to get some free time... :\

[pedalpete]

It is a dual core, single proc machine, as far as I can remember (it's virtual), pretty sure its a xeon 3040.

I highly doubt mysql is using that much cpu as I don't think the server is doing THAT much, but I definitely could be wrong on that.

I would think that if mysql is using that much cpu, mpstat would report it. but mpstat is low.
Something isn't adding up.
Any idea how else I can test this?