Degraded throughput due to interrupt storm throttling

[demco]

Anyone seeing poor network performance under heavy traffic for the recent 2.2 snapshots?

Snapshot (20141129, 20141204) are generating warnings - interrupt storm detected on "irq270:"; throttling interrupt source.

This caused the CPU usage to stay around 97% and having poor network throughput.

Compare to 2.1.5 and older 2.2 snapshot (20140919), the same box is passing near 900+mbps traffic without issue or warnings (CPU under 10%).

Anyway to improve the performance?

Details

• Box is an i5 with Intel 82574L nic, 4GB RAM, running 64-bit nanobsd images on CF card.

• pfsense configuration
    - NAT disabled
    - All pass rules on WAN, LAN
    - No packages, no traffic shapers
    - sysctl
        hw.em.tx_int_delay: 66
        hw.em.rx_int_delay: 0
        hw.em.tx_abs_int_delay: 66
        hw.em.rx_abs_int_delay: 66
        hw.em.rxd: 4096
        hw.em.txd: 4096
        hw.em.smart_pwr_down: 0
        hw.em.sbp: 0
        hw.em.enable_msix: 1
        hw.em.rx_process_limit: 100
        hw.em.eee_setting: 1

• Test setup, concurrent client connections to web server up to 1000, with pfsense in between as router and firewall. All physical boxes, no VM.

• Interrupt storm throttling seem to start around 600+ concurrent connections.

• No issue when doing simple iperf test between the server and client.

1. For recent 2.2 snapshots

• Traffic from web server into pfsense,
    netstat -nI em2 1

input            em2          output
  packets  errs idrops      bytes    packets  errs      bytes colls
    41922  1330    0  61497812      34615    0    2433832    0
    41561  723    0  61183086      33979    0    2384516    0
    43855  1123    0  64352120      34663    0    2435020    0
    40410    0    0  59474947      34556    0    2420231    0
    40282  2531    0  57048771      39191    0    2832258    0
    46541  1523    0  68680197      32910    0    2308428    0
    46293    0    0  68489656      32672    0    2283879    0
    46680    0    0  68816340      33387    0    2345346    0
    45718    0    0  67235892      33308    0    2327113    0
    45657    0    0  66864013      32736    0    2301972    0
    45147    0    0  66209712      32260    0    2265602    0
    46687    0    0  68342960      33765    0    2375869    0
    48460    0    0  71058875      35266    0    2473635    0
    48110    0    0  70738064      34524    0    2422508    0
    46613    0    0  68264042      32181    0    2419998    0
    50495  2672    0  72226424      53466    0    3703409    0
    31466  3123    0  45934835      28704    0    2069234    0
    41080  2937    0  60452355      36361    0    2771632    0
    36885  3519    0  54510486      39587    0    2660647    0
    41503  3513    0  61372788      39089    0    2789832    0
    41522  3749    0  61447560      39103    0    2790018    0

• vmstat -i

interrupt                          total      rate
irq4: uart0                          620          0
irq16: ehci0                        4745          1
irq23: ehci1                        7115          1
cpu0:timer                      5319037      1127
irq264: em0:rx 0                  17839          3
irq265: em0:tx 0                    1429          0
irq266: em0:link                      2          0
irq270: em2:rx 0                  633881        134
irq271: em2:tx 0                  645456        136
irq272: em2:link                  42815          9
irq276: em4:rx 0                  624352        132
irq277: em4:tx 0                  641515        135
irq278: em4:link                  26399          5
irq282: ahci0                      2743          0
cpu2:timer                        110432        23
cpu1:timer                        110089        23
cpu3:timer                        114447        24
Total                            8302916      1759

2. Older 2.2 snapshot (20140919)

netstat -nI em2 1

input            em2          output
  packets  errs idrops      bytes    packets  errs      bytes colls
    81580    0    0  122601603      35142    0    2437730    0
    81503    0    0  122512940      35607    0    2464214    0
    81607    0    0  122714085      35389    0    2447989    0
    81514    0    0  122612193      35521    0    2449642    0
    81557    0    0  122671122      35068    0    2429027    0
    81604    0    0  122748284      35100    0    2425902    0
    81516    0    0  122614208      35825    0    2478457    0
    81580    0    0  122710044      35396    0    2451409    0
    81413    0    0  122506987      35693    0    2467824    0
    81460    0    0  122536780      34706    0    2408373    0
    81439    0    0  122543600      35257    0    2440134    0
    81681    0    0  122876198      35590    0    2471851    0
    81365    0    0  122404607      35601    0    2464459    0
    81512    0    0  122647849      35808    0    2478354    0
    81372    0    0  122463423      35755    0    2472559    0
    81637    0    0  122865426      35357    0    2443842    0
    81183    0    0  122158613      34626    0    2392547    0
    81576    0    0  122763709      35548    0    2457471    0
    81511    0    0  122642309      35810    0    2474260    0
    81460    0    0  122637148      35836    0    2468833    0
    81428    0    0  122588928      35380    0    2439441    0

• vmstat -i

interrupt                          total      rate
irq4: uart0                        3265        10
irq16: ehci0                        345          1
irq23: ehci1                        514          1
cpu0:timer                        359402      1123
irq264: em0:rx 0                    1138          3
irq265: em0:tx 0                    174          0
irq266: em0:link                      2          0
irq270: em2:rx 0                  866450      2707
irq271: em2:tx 0                  786135      2456
irq272: em2:link                      1          0
irq276: em4:rx 0                  776769      2427
irq277: em4:tx 0                  866653      2708
irq278: em4:link                      1          0
irq282: ahci0                      3104          9
cpu1:timer                        131978        412
cpu2:timer                        123993        387
cpu3:timer                        132347        413
Total                            4052271      12663

3. Version 2.1.5

netstat -nI em2 1

input          (em2)          output
  packets  errs idrops      bytes    packets  errs      bytes colls
    81445    0    0  122465467      35098    0    4837936    0
    81450    0    0  122432070      35283    0    4880932    0
    81502    0    0  122544587      35875    0    4954440    0
    81375    0    0  122366699      34946    0    4834210    0
    81499    0    0  122534890      35477    0    4906938    0
    81284    0    0  122215008      35405    0    4906668    0
    81404    0    0  122464929      35363    0    4892856    0
    81364    0    0  122419545      35331    0    4893078    0
    81462    0    0  122572226      35721    0    4934358    0
    81209    0    0  122194846      35451    0    4907820    0
    81295    0    0  122294846      36019    0    4977534    0
    81224    0    0  122224062      35578    0    4910052    0
    81319    0    0  122430646      36035    0    4964622    0
    81266    0    0  122319826      35776    0    4945454    0
    81254    0    0  122236376      35919    0    4974384    0
    81373    0    0  122423862      35218    0    4876918    0
    81427    0    0  122530893      35263    0    4890102    0
    81176    0    0  122138073      35940    0    4970200    0
    81152    0    0  122160659      35532    0    4903262    0
    81238    0    0  122200615      36090    0    4994622    0
    81267    0    0  122258881      35727    0    4947498    0

• vmstat -i

interrupt                          total      rate
irq4: uart0                          326          1
irq16: ehci0                        221          1
irq19: atapci0                      1837          9
irq23: ehci1                        329          1
cpu0: timer                      392065      1990
irq256: em0:rx 0                    822          4
irq257: em0:tx 0                    290          1
irq258: em0:link                      2          0
irq262: em2:rx 0                  734327      3727
irq263: em2:tx 0                  667692      3389
irq264: em2:link                      1          0
irq268: em4:rx 0                  659987      3350
irq269: em4:tx 0                  734599      3728
irq270: em4:link                      1          0
cpu1: timer                      391509      1987
cpu3: timer                      391932      1989
cpu2: timer                      391813      1988
Total                            4367753      22171

[cmb]

Haven't seen anything like that. Things at the OS level haven't changed much since mid September. The errors you're racking up should show in the dev.em sysctls, what are those showing?

[demco]

@cmb:

Haven't seen anything like that. Things at the OS level haven't changed much since mid September. The errors you're racking up should show in the dev.em sysctls, what are those showing?

*** Snapshot 20141204 sysctl dev.em.2 output ***

dev.em.2.%desc: Intel(R) PRO/1000 Network Connection 7.4.2
dev.em.2.%driver: em
dev.em.2.%location: slot=0 function=0 handle=_SB_.PCI0.RP03.PXSX
dev.em.2.%pnpinfo: vendor=0x8086 device=0x10d3 subvendor=0x8086 subdevice=0x0000 class=0x020000
dev.em.2.%parent: pci4
dev.em.2.nvm: -1
dev.em.2.debug: -1
dev.em.2.fc: 3
dev.em.2.rx_int_delay: 0
dev.em.2.tx_int_delay: 66
dev.em.2.rx_abs_int_delay: 66
dev.em.2.tx_abs_int_delay: 66
dev.em.2.itr: 488
dev.em.2.rx_processing_limit: 100
dev.em.2.eee_control: 1
dev.em.2.link_irq: 5607
dev.em.2.mbuf_alloc_fail: 0
dev.em.2.cluster_alloc_fail: 0
dev.em.2.dropped: 0
dev.em.2.tx_dma_fail: 0
dev.em.2.rx_overruns: 0
dev.em.2.watchdog_timeouts: 0
dev.em.2.device_control: 1074790984
dev.em.2.rx_control: 67141634
dev.em.2.fc_high_water: 18432
dev.em.2.fc_low_water: 16932
dev.em.2.queue0.txd_head: 1086
dev.em.2.queue0.txd_tail: 1086
dev.em.2.queue0.tx_irq: 285309
dev.em.2.queue0.no_desc_avail: 0
dev.em.2.queue0.rxd_head: 797
dev.em.2.queue0.rxd_tail: 796
dev.em.2.queue0.rx_irq: 86721
dev.em.2.mac_stats.excess_coll: 0
dev.em.2.mac_stats.single_coll: 0
dev.em.2.mac_stats.multiple_coll: 0
dev.em.2.mac_stats.late_coll: 0
dev.em.2.mac_stats.collision_count: 0
dev.em.2.mac_stats.symbol_errors: 0
dev.em.2.mac_stats.sequence_errors: 0
dev.em.2.mac_stats.defer_count: 0
dev.em.2.mac_stats.missed_packets: 129070
dev.em.2.mac_stats.recv_no_buff: 101260
dev.em.2.mac_stats.recv_undersize: 0
dev.em.2.mac_stats.recv_fragmented: 0
dev.em.2.mac_stats.recv_oversize: 0
dev.em.2.mac_stats.recv_jabber: 0
dev.em.2.mac_stats.recv_errs: 0
dev.em.2.mac_stats.crc_errs: 0
dev.em.2.mac_stats.alignment_errs: 0
dev.em.2.mac_stats.coll_ext_errs: 0
dev.em.2.mac_stats.xon_recvd: 0
dev.em.2.mac_stats.xon_txd: 0
dev.em.2.mac_stats.xoff_recvd: 0
dev.em.2.mac_stats.xoff_txd: 0
dev.em.2.mac_stats.total_pkts_recvd: 7818058
dev.em.2.mac_stats.good_pkts_recvd: 7688988
dev.em.2.mac_stats.bcast_pkts_recvd: 52
dev.em.2.mac_stats.mcast_pkts_recvd: 0
dev.em.2.mac_stats.rx_frames_64: 32
dev.em.2.mac_stats.rx_frames_65_127: 177145
dev.em.2.mac_stats.rx_frames_128_255: 16042
dev.em.2.mac_stats.rx_frames_256_511: 26136
dev.em.2.mac_stats.rx_frames_512_1023: 40015
dev.em.2.mac_stats.rx_frames_1024_1522: 7429618
dev.em.2.mac_stats.good_octets_recvd: 11319521774
dev.em.2.mac_stats.good_octets_txd: 438056220
dev.em.2.mac_stats.total_pkts_txd: 5895218
dev.em.2.mac_stats.good_pkts_txd: 5895218
dev.em.2.mac_stats.bcast_pkts_txd: 2
dev.em.2.mac_stats.mcast_pkts_txd: 4
dev.em.2.mac_stats.tx_frames_64: 8329
dev.em.2.mac_stats.tx_frames_65_127: 5802307
dev.em.2.mac_stats.tx_frames_128_255: 84582
dev.em.2.mac_stats.tx_frames_256_511: 0
dev.em.2.mac_stats.tx_frames_512_1023: 0
dev.em.2.mac_stats.tx_frames_1024_1522: 0
dev.em.2.mac_stats.tso_txd: 0
dev.em.2.mac_stats.tso_ctx_fail: 0
dev.em.2.interrupts.asserts: 5385
dev.em.2.interrupts.rx_pkt_timer: 3
dev.em.2.interrupts.rx_abs_timer: 0
dev.em.2.interrupts.tx_pkt_timer: 0
dev.em.2.interrupts.tx_abs_timer: 0
dev.em.2.interrupts.tx_queue_empty: 0
dev.em.2.interrupts.tx_queue_min_thresh: 0
dev.em.2.interrupts.rx_desc_min_thresh: 0
dev.em.2.interrupts.rx_overrun: 1
dev.em.2.wake: 0

*** Older snapshot 20140919 sysctl dev.em.2 output ***

dev.em.2.%desc: Intel(R) PRO/1000 Network Connection 7.4.2
dev.em.2.%driver: em
dev.em.2.%location: slot=0 function=0 handle=_SB_.PCI0.RP03.PXSX
dev.em.2.%pnpinfo: vendor=0x8086 device=0x10d3 subvendor=0x8086 subdevice=0x0000 class=0x020000
dev.em.2.%parent: pci4
dev.em.2.nvm: -1
dev.em.2.debug: -1
dev.em.2.fc: 3
dev.em.2.rx_int_delay: 0
dev.em.2.tx_int_delay: 66
dev.em.2.rx_abs_int_delay: 66
dev.em.2.tx_abs_int_delay: 66
dev.em.2.itr: 488
dev.em.2.rx_processing_limit: 100
dev.em.2.eee_control: 1
dev.em.2.link_irq: 1
dev.em.2.mbuf_alloc_fail: 0
dev.em.2.cluster_alloc_fail: 0
dev.em.2.dropped: 0
dev.em.2.tx_dma_fail: 0
dev.em.2.rx_overruns: 0
dev.em.2.watchdog_timeouts: 0
dev.em.2.device_control: 1074790984
dev.em.2.rx_control: 67141634
dev.em.2.fc_high_water: 18432
dev.em.2.fc_low_water: 16932
dev.em.2.queue0.txd_head: 2254
dev.em.2.queue0.txd_tail: 2254
dev.em.2.queue0.tx_irq: 1110342
dev.em.2.queue0.no_desc_avail: 0
dev.em.2.queue0.rxd_head: 3277
dev.em.2.queue0.rxd_tail: 3276
dev.em.2.queue0.rx_irq: 1233944
dev.em.2.mac_stats.excess_coll: 0
dev.em.2.mac_stats.single_coll: 0
dev.em.2.mac_stats.multiple_coll: 0
dev.em.2.mac_stats.late_coll: 0
dev.em.2.mac_stats.collision_count: 0
dev.em.2.mac_stats.symbol_errors: 0
dev.em.2.mac_stats.sequence_errors: 0
dev.em.2.mac_stats.defer_count: 0
dev.em.2.mac_stats.missed_packets: 0
dev.em.2.mac_stats.recv_no_buff: 0
dev.em.2.mac_stats.recv_undersize: 0
dev.em.2.mac_stats.recv_fragmented: 0
dev.em.2.mac_stats.recv_oversize: 0
dev.em.2.mac_stats.recv_jabber: 0
dev.em.2.mac_stats.recv_errs: 0
dev.em.2.mac_stats.crc_errs: 0
dev.em.2.mac_stats.alignment_errs: 0
dev.em.2.mac_stats.coll_ext_errs: 0
dev.em.2.mac_stats.xon_recvd: 0
dev.em.2.mac_stats.xon_txd: 0
dev.em.2.mac_stats.xoff_recvd: 0
dev.em.2.mac_stats.xoff_txd: 0
dev.em.2.mac_stats.total_pkts_recvd: 12606668
dev.em.2.mac_stats.good_pkts_recvd: 12606668
dev.em.2.mac_stats.bcast_pkts_recvd: 493
dev.em.2.mac_stats.mcast_pkts_recvd: 0
dev.em.2.mac_stats.rx_frames_64: 267
dev.em.2.mac_stats.rx_frames_65_127: 10502
dev.em.2.mac_stats.rx_frames_128_255: 18802
dev.em.2.mac_stats.rx_frames_256_511: 35809
dev.em.2.mac_stats.rx_frames_512_1023: 43431
dev.em.2.mac_stats.rx_frames_1024_1522: 12497857
dev.em.2.mac_stats.good_octets_recvd: 19003788762
dev.em.2.mac_stats.good_octets_txd: 395260642
dev.em.2.mac_stats.total_pkts_txd: 5404868
dev.em.2.mac_stats.good_pkts_txd: 5404868
dev.em.2.mac_stats.bcast_pkts_txd: 2
dev.em.2.mac_stats.mcast_pkts_txd: 3
dev.em.2.mac_stats.tx_frames_64: 87626
dev.em.2.mac_stats.tx_frames_65_127: 5175706
dev.em.2.mac_stats.tx_frames_128_255: 141536
dev.em.2.mac_stats.tx_frames_256_511: 0
dev.em.2.mac_stats.tx_frames_512_1023: 0
dev.em.2.mac_stats.tx_frames_1024_1522: 0
dev.em.2.mac_stats.tso_txd: 0
dev.em.2.mac_stats.tso_ctx_fail: 0
dev.em.2.interrupts.asserts: 1
dev.em.2.interrupts.rx_pkt_timer: 0
dev.em.2.interrupts.rx_abs_timer: 0
dev.em.2.interrupts.tx_pkt_timer: 0
dev.em.2.interrupts.tx_abs_timer: 0
dev.em.2.interrupts.tx_queue_empty: 0
dev.em.2.interrupts.tx_queue_min_thresh: 0
dev.em.2.interrupts.rx_desc_min_thresh: 0
dev.em.2.interrupts.rx_overrun: 0
dev.em.2.wake: 0