High INTERRUPT rate on CPU 0

fs0 · Nov 17, 2009

Hello,

Yesterday I get a fresh install of FreeBSD 8.0 RC3 Current. However just some hours after the installation the machine began very slow/laggy.

Code:

$ top -P CC
(...)
last pid:  1460;  load averages:  0.01,  0.08,  0.07                                             up 0+00:11:00  08:28:59
100 processes: 1 running, 99 sleeping
CPU 0:  0.0% user,  0.0% nice,  0.0% system, 81.9% interrupt, 18.1% idle
CPU 1:  1.1% user,  0.0% nice,  3.2% system,  0.0% interrupt, 95.7% idle
Mem: 160M Active, 141M Inact, 143M Wired, 1512K Cache, 112M Buf, 2525M Free
Swap: 4096M Total, 4096M Free

Code:

$ top -S

last pid:  1457;  load averages:  0.08,  0.13,  0.08                                             up 0+00:07:59  08:25:58
177 processes: 4 running, 157 sleeping, 16 waiting
CPU:  0.8% user,  0.0% nice,  1.2% system, 37.8% interrupt, 60.2% idle
Mem: 158M Active, 127M Inact, 149M Wired, 1484K Cache, 112M Buf, 2534M Free
Swap: 4096M Total, 4096M Free

  PID USERNAME    THR PRI NICE   SIZE    RES STATE   C   TIME   WCPU COMMAND
   11 root          2 171 ki31     0K    16K RUN     0   8:38 112.16% idle
   12 root         17 -64    -     0K   136K WAIT    0   5:39 77.29% intr
 1405 hender       11  44    0   116M 86380K ucond   1   0:11  1.86% firefox-bin
 1259 root          1  44    0   322M   316M select  1   0:10  0.00% Xorg
    3 root          1  -8    -     0K     8K -       1   0:02  0.00% g_up
    4 root          1  -8    -     0K     8K -       1   0:01  0.00% g_down
 1440 hender        1  44    0   136M 14468K select  1   0:01  0.00% npviewer.bin
   13 root          1  44    -     0K     8K -       1   0:01  0.00% yarrow
 1432 hender        2  44    0 37584K 19268K piperd  1   0:01  0.00% gnome-terminal
 1345 hender        1  44    0 19712K 14204K select  1   0:01  0.00% metacity
 1348 hender        1  44    0 49048K 25112K select  1   0:01  0.00% nautilus
 1390 root          1  48    4  3300K  1084K biord   1   0:01  0.00% fsck_ufs
 1347 hender        1  44    0 34164K 20608K select  1   0:00  0.00% gnome-panel
 1370 hender        1  44    0 33148K 18024K select  1   0:00  0.00% wnck-applet
 1331 hender        1  44    0  8588K  5552K select  1   0:00  0.00% gconfd-2
 1337 hender        2  44    0 94612K 15776K piperd  1   0:00  0.00% gnome-settings-daem
 1201 haldaemon     1  44    0  7236K  4920K select  1   0:00  0.00% hald
 1380 hender        1  44    0 32300K 22552K select  1   0:00  0.00% clock-applet
 1342 hender        1  44    0  6308K  3236K select  1   0:00  0.00% gam_server
  575 root          1  44    0  3448K  1136K select  1   0:00  0.00% moused
   17 root          1  44    -     0K     8K syncer  1   0:00  0.00% syncer
 1352 hender        1  44    0 26804K 18844K select  1   0:00  0.00% gnome-power-manager
   19 root          1  44    -     0K     8K biord   1   0:00  0.00% softdepflush
 1308 hender        2  52    0 21768K 11932K piperd  1   0:00  0.00% gnome-session
  958 messagebus    1  44    0  3500K  2176K select  1   0:00  0.00% dbus-daemon
 1350 hender        2  46    0 19240K  6896K select  1   0:00  0.00% bonobo-activation-s
 1247 root          1  44    0  3804K  1700K ATA re  0   0:00  0.00% hald-addon-storage
   14 root         32 -64    -     0K   256K -       0   0:00  0.00% usb
 1381 hender        1  44    0 22044K 14568K select  1   0:00  0.00% notification-area-a
 1354 hender        1  44    0 87032K 14120K select  1   0:00  0.00% gnome-volume-contro
    0 root          9 -68    0     0K    64K -       1   0:00  0.00% kernel
 1318 hender        1  44    0  3500K  2056K select  1   0:00  0.00% dbus-daemon
   16 root          1  44    -     0K     8K psleep  1   0:00  0.00% bufdaemon
 1328 hender        1  44    0 19320K 12456K select  1   0:00  0.00% seahorse-agent
 1087 avahi         1  44    0  5092K  2536K select  1   0:00  0.00% avahi-daemon
 1258 root          1  45    0  7588K  4312K select  1   0:00  0.00% gdm-simple-slave
 1372 hender        2  44    0  7764K  4116K piperd  0   0:00  0.00% gvfs-hal-volume-mon
 1368 hender        1  44    0  6688K  4000K select  1   0:00  0.00% gvfsd-trash
 1204 root         17  44    0 14532K  4668K waitvt  1   0:00  0.00% console-kit-daemon
 1205 root          1  44    0  5928K  2752K select  1   0:00  0.00% hald-runner
 1297 root          1  44    0  7696K  3804K select  1   0:00  0.00% gdm-session-worker
 1073 root          1  44    0  7504K  3688K select  1   0:00  0.00% gdm-binary
    2 root          1  -8    -     0K     8K GEOM t  1   0:00  0.00% g_event
 1333 hender        1  44    0  6468K  3268K select  1   0:00  0.00% gvfsd
 1374 hender        1  44    0  7304K  3944K select  1   0:00  0.00% gvfs-gphoto2-volume
  779 root          1  44    0  3344K  1312K select  1   0:00  0.00% syslogd

And I really don't know wt*f...

Thanks in advance.

fs0-

ps : sorry for my quiet bad english

vermaden · Nov 17, 2009

Add vmstat -i output here, it will show what generates so high interrupt rate.

SirDice · Nov 17, 2009

Try # systat -vmstat

You will notice that irq0 is connected to the clock, hence the high interrupt count.

fs0 · Nov 17, 2009

Code:

$ systat -vmstat

    2 users    Load  0.15  0.22  0.10                  Nov 17 18:16

Mem:KB    REAL            VIRTUAL                       VN PAGER   SWAP PAGER
        Tot   Share      Tot    Share    Free           in   out     in   out
Act  182280   25972   743712    36292 2679304  count
All  232564   40544  3238872    56908          pages
Proc:                                                            Interrupts
  r   p   d   s   w   Csw  Trp  Sys  Int  Sof  Flt        cow   93416 total
             94      180k  197 1509  89k  205   19     12 zfod        atkbd0 1
                                                          ozfod       psm0 irq12
 0.2%Sys  40.3%Intr  0.5%User  0.0%Nice 58.9%Idle        %ozfod       fwohci0+ 1
|    |    |    |    |    |    |    |    |    |    |       daefr 89400 uhci2 ehci
++++++++++++++++++++>                                     prcfr    20 uhci3 ehci
                                       919 dtbuf      292 totfr  1998 cpu0: time
Namei     Name-cache   Dir-cache    100000 desvn          react       mskc0 256
   Calls    hits   %    hits   %      8091 numvn          pdwak  1998 cpu1: time
    1221    1221 100                  1082 frevn          pdpgs
                                                          intrn
Disks   ad4   ad8                                  146440 wire
KB/t   0.00 15.96                                  135892 act
tps       0   141                                   79928 inact
MB/s   0.00  2.21                                    1988 cache
%busy     0   100                                 2677300 free

    2 users    Load  0.12  0.21  0.10                  Nov 17 18:16

Mem:KB    REAL            VIRTUAL                       VN PAGER   SWAP PAGER
        Tot   Share      Tot    Share    Free           in   out     in   out
Act  183688   25972   746272    36292 2680552  count
All  233988   40544  3241432    56908          pages
Proc:                                                            Interrupts
  r   p   d   s   w   Csw  Trp  Sys  Int  Sof  Flt        cow   92797 total
             94      179k 2877 4010  88k  202 2292   2291 zfod        atkbd0 1
                                                          ozfod       psm0 irq12
 1.7%Sys  40.5%Intr  3.7%User  0.0%Nice 54.2%Idle        %ozfod       fwohci0+ 1
|    |    |    |    |    |    |    |    |    |    |       daefr 88736 uhci2 ehci
=++++++++++++++++++++>>                                   prcfr    63 uhci3 ehci
                                        72 dtbuf     3268 totfr  1999 cpu0: time
Namei     Name-cache   Dir-cache    100000 desvn          react       mskc0 256
   Calls    hits   %    hits   %      8091 numvn          pdwak  1999 cpu1: time
     793     793 100                  1083 frevn          pdpgs
                                                          intrn
Disks   ad4   ad8                                  139872 wire
KB/t   0.00 15.98                                  137304 act
tps       0   142                                   83820 inact
MB/s   0.00  2.22                                    1592 cache
%busy     0    99                                 2678960 free

Code:

$ vmstat -i
interrupt                          total       rate
irq1: atkbd0                         201          0
irq12: psm0                            9          0
irq16: fwohci0+                        2          0
irq19: uhci2 ehci*              25229879      89151
irq23: uhci3 ehci1                  4852         17
cpu0: timer                       565386       1997
irq256: mskc0                        389          1
cpu1: timer                       562755       1988
Total                           26363473      93157
$

Don't understand ...

fs0 · Nov 17, 2009

As we can't edit our post, I'm obliged to double-post (sorry) :

http://pastebin.com/m6d13967b
http://pastebin.com/m16ccc3

Better to check output.

Thanks.

DutchDaemon · Nov 17, 2009

You should use

Code:

 tags, not [quote] tags, for this type of output.

SirDice · Nov 17, 2009

There's a relatively high number of interrupts on uhci2. What's attached to your USB?

fs0 · Nov 17, 2009

SirDice said:
There's a relatively high number of interrupts on uhci2. What's attached to your USB?

Code:

$ dmesg | grep uhci2
uhci2: <Intel 82801I (ICH9) U$ dmesg | grep uhci2
uhci2: <Intel 82801I (ICH9) USB controller> port 0x1840-0x185f irq 19 at device 26.2 on pci0
uhci2: [ITHREAD]
uhci2: LegSup = 0x0010
usbus2: <Intel 82801I (ICH9) USB controller> on uhci2
SB controller> port 0x1840-0x185f irq 19 at device 26.2 on pci0
uhci2: [ITHREAD]
uhci2: LegSup = 0x0010
usbus2: <Intel 82801I (ICH9) USB controller> on uhci2

I've nothing special on USB, only the mouse. However during first boots I didnt have such problems :s. I tried to remove that only one usb device, nothing changed.

But, before the installation I had to disable the acpi to get msk driver working as expected...dunno if all of this is linked..

thanks for your help

vermaden · Nov 17, 2009

IMHO submit a BUG here:
http://freebsd.org/send-pr.html

... and add all that info also to freebsd-current@freebsd.org and cooperate to fix the problem.

High INTERRUPT rate on CPU 0

fs0

vermaden

SirDice

Administrator

fs0

fs0

DutchDaemon

Administrator

SirDice

Administrator

fs0

vermaden