High CPU-load

[EricPerl]

If you have not done so yet, 'vmstat -i' and 'systat -vmstat' seem to be the next step wrt finding the device triggering the interrupts.

[ThomasE]

If you have not done so yet, 'vmstat -i' and 'systat -vmstat' seem to be the next step wrt finding the device triggering the interrupts.

Ok, so here we go...

Code Select Expand

vmstat -i
interrupt                          total       rate
cpu0:timer                     346081709        999
cpu1:timer                       5389274         16
cpu2:timer                       5441949         16
cpu3:timer                       5441140         16
cpu4:timer                       5466498         16
cpu5:timer                       5543676         16
cpu6:timer                       5480325         16
cpu7:timer                       5598821         16
cpu8:timer                       5212744         15
cpu9:timer                       5198477         15
cpu10:timer                      5221979         15
cpu11:timer                      5162333         15
cpu12:timer                      5261906         15
cpu13:timer                      5317179         15
cpu14:timer                      5368505         15
cpu15:timer                      7457476         22
cpu16:timer                      5158599         15
cpu17:timer                      5146936         15
cpu18:timer                      5188516         15
cpu19:timer                      5163081         15
cpu20:timer                      5173798         15
cpu21:timer                      5262110         15
cpu22:timer                      5264156         15
cpu23:timer                      5328887         15
cpu24:timer                      5351694         15
cpu25:timer                      5328853         15
cpu26:timer                      5348923         15
cpu27:timer                      5352703         15
cpu28:timer                      5390198         16
cpu29:timer                      5447410         16
cpu30:timer                      5463452         16
cpu31:timer                      7490578         22
irq112: ahci0                         52          0
irq113: xhci0                    5394722         16
irq115: igb0:rxq0                  89822          0
irq116: igb0:rxq1                 278626          1
irq117: igb0:rxq2                   3747          0
irq118: igb0:rxq3                   1343          0
irq119: igb0:rxq4                   9842          0
irq120: igb0:rxq5                    228          0
irq121: igb0:rxq6                    543          0
irq122: igb0:rxq7                    711          0
irq123: igb0:aq                        2          0
irq331: bxe0:sp                   346413          1
irq332: bxe0:fp00               18789253         54
irq333: bxe0:fp01               18676967         54
irq334: bxe0:fp02               17816764         51
irq335: bxe0:fp03               17740225         51
irq336: bxe1:sp                   347275          1
irq337: bxe1:fp00               21428716         62
irq338: bxe1:fp01               21227816         61
irq339: bxe1:fp02               20153853         58
irq340: bxe1:fp03               20304599         59
Total                          678115404       1957

And this is the systat under load.

Code Select Expand

    4 users    Load 26.02 17.48  8.97                  Jan 14 09:48:32
   Mem usage:   2%Phy  2%Kmem                           VN PAGER   SWAP PAGER
Mem:      REAL           VIRTUAL                        in   out     in   out
       Tot   Share     Tot    Share     Free   count
Act  2180M  98768K    518G     148M     364G   pages
All  2198M    113M    518G     262M                       ioflt  Interrupts
Proc:                                                 207 cow    272k total
  r   p   d    s   w   Csw  Trp  Sys  Int  Sof  Flt   465 zfod   1126 cpu0:timer
             170      651K   1K   2K 232K  53K   1K       ozfod  1127 cpu1:timer
                                                         %ozfod  1127 cpu2:timer
 0.8%Sys  77.6%Intr  0.1%User  0.0%Nice 21.5%Idle         daefr  1127 cpu3:timer
|    |    |    |    |    |    |    |    |    |    |   241 prcfr  1067 cpu4:timer
+++++++++++++++++++++++++++++++++++++++               855 totfr  1048 cpu5:timer
                                           dtbuf          react  1045 cpu6:timer
Namei     Name-cache   Dir-cache   6280561 maxvn          pdwak  1073 cpu7:timer
   Calls    hits   %    hits   %    441406 numvn       50 pdpgs  1083 cpu8:timer
    2847    2843 100                357588 frevn          intrn  1077 cpu9:timer
                                                    6438M wire   1103 cpu10:time
Disks   da0   cd0 pass0 pass1 pass2 pass3            134M act    1025 cpu11:time
KB/t  40.74  0.00  0.00  0.00  0.00  0.00           2251M inact  1104 cpu12:time
tps      21     0     0     0     0     0               0 laund  1086 cpu13:time
MB/s   0.82  0.00  0.00  0.00  0.00  0.00            364G free   1077 cpu14:time
%busy    59     0     0     0     0     0             57K buf    1075 cpu15:time
                                                                 1110 cpu16:time
                                                                 1081 cpu17:time
                                                                 1080 cpu18:time
                                                                 1092 cpu19:time
                                                                 1075 cpu20:time
                                                                 1062 cpu21:time
                                                                 1037 cpu22:time
                                                                 1085 cpu23:time
                                                                 1101 cpu24:time
                                                                 1072 cpu25:time
                                                                 1072 cpu26:time
                                                                 1074 cpu27:time
                                                                 1070 cpu28:time
                                                                 1115 cpu29:time
                                                                 1077 cpu30:time
                                                                 1085 cpu31:time
                                                                      ahci0 112
                                                                   68 xhci0 113
                                                                      igb0:rxq0
                                                                   28 igb0:rxq1
                                                                      igb0:rxq2
                                                                      igb0:rxq3
                                                                      igb0:rxq4
                                                                      igb0:rxq5
                                                                      igb0:rxq6
                                                                      igb0:rxq7
                                                                      igb0:aq
                                                                    1 bxe0:sp
                                                                28378 bxe0:fp00
                                                                22496 bxe0:fp01
                                                                24798 bxe0:fp02
                                                                35004 bxe0:fp03
                                                                    1 bxe1:sp
                                                                29363 bxe1:fp00
                                                                29687 bxe1:fp01
                                                                29310 bxe1:fp02
                                                                38388 bxe1:fp03


[pfry]

Cute! I have to note those...

Are you logging to a USB flash device? Or am I misreading that? If so, might be worth reducing storage chatter and see what happens.

[EricPerl]

I'm quite outside of my area of expertise here but:

vmstat -i is cumulative since the system is up.
Yes it looks like some USB controller got busy but it's not during systat.
In this output, what strikes me is the uneven cpu0:timer compared to the other.

The 2nd output is live (refreshed every X secs).
The 2 BXE devices seem pretty busy. Broadcom NICs?
Some level of busy should be expected under load but that much?

Some of the optimization work might have been counterproductive....

Also, it might be worth looking at the details of the slots used on the MB: PCI gen, lanes, exclusions...
I don't have OPN on bare metal and these low-level tools tend to be pretty distro specific...

[ThomasE]

Cute! I have to note those...

Are you logging to a USB flash device? Or am I misreading that? If so, might be worth reducing storage chatter and see what happens.

There's no USB device attached and we're only logging critical errors as everything above that is guaranteed to severely overload the system. ;-)

I'm quite outside of my area of expertise here but:

So am I so welcome to the club. ;-)

vmstat -i is cumulative since the system is up.
Yes it looks like some USB controller got busy but it's not during systat.
In this output, what strikes me is the uneven cpu0:timer compared to the other.

I must admit that I didn't even notice that. Maybe the system defaults to cpu:0 and only if that one is busy does round robin or whatever on the other cores?

The 2nd output is live (refreshed every X secs).
The 2 BXE devices seem pretty busy. Broadcom NICs?
Some level of busy should be expected under load but that much?

Yes, Broadcom NICs. Intel NICs behave pretty much the same. At that time I was using

Code Select Expand

iperf3 -c 10.199.0.150 -p 5201 -P 128 -t 120
to push around 8Gbit/s of traffic through those interfaces, so yes, that is quite a bit. However, and that is where we get to the original question, I think this machine should be able to handle this with ease - especially, if it's the only thing going on there...

Some of the optimization work might have been counterproductive....

Acknowledged, though as far as I can tell, none of it seemed to have any noticeable effect at all.

Also, it might be worth looking at the details of the slots used on the MB: PCI gen, lanes, exclusions...

I will have a look though I admit that I don't have a clue what exactly to look for. Maybe - though not very likely - I will know once I see it. :)