High CPU Usage and Delay Calling ifconfig -v ix0/ix1; Delays Dashboard Load

ltctech · Jan 25, 2023, 8:59 PM

More info about card:

sysctl dev.ix.1


dev.ix.1.fw_version: eTrack 0x80000528 PHY FW V286
dev.ix.1.advertise_speed: 7
dev.ix.1.fc: 0
dev.ix.1.mac_stats.tx_frames_1024_1522: 1206525516
dev.ix.1.mac_stats.tx_frames_512_1023: 8917549
dev.ix.1.mac_stats.tx_frames_256_511: 8111570
dev.ix.1.mac_stats.tx_frames_128_255: 79421629
dev.ix.1.mac_stats.tx_frames_65_127: 65310030
dev.ix.1.mac_stats.tx_frames_64: 265654722
dev.ix.1.mac_stats.management_pkts_txd: 0
dev.ix.1.mac_stats.mcast_pkts_txd: 3
dev.ix.1.mac_stats.bcast_pkts_txd: 50373
dev.ix.1.mac_stats.good_pkts_txd: 1633941016
dev.ix.1.mac_stats.total_pkts_txd: 1633941016
dev.ix.1.mac_stats.good_octets_txd: 1813044533668
dev.ix.1.mac_stats.checksum_errs: 0
dev.ix.1.mac_stats.management_pkts_drpd: 0
dev.ix.1.mac_stats.management_pkts_rcvd: 0
dev.ix.1.mac_stats.recv_jabberd: 0
dev.ix.1.mac_stats.recv_oversized: 0
dev.ix.1.mac_stats.recv_fragmented: 0
dev.ix.1.mac_stats.recv_undersized: 0
dev.ix.1.mac_stats.rx_frames_1024_1522: 677354061
dev.ix.1.mac_stats.rx_frames_512_1023: 9601513
dev.ix.1.mac_stats.rx_frames_256_511: 10145596
dev.ix.1.mac_stats.rx_frames_128_255: 82799180
dev.ix.1.mac_stats.rx_frames_65_127: 820440758
dev.ix.1.mac_stats.rx_frames_64: 0
dev.ix.1.mac_stats.bcast_pkts_rcvd: 608287
dev.ix.1.mac_stats.mcast_pkts_rcvd: 3
dev.ix.1.mac_stats.good_pkts_rcvd: 1600341108
dev.ix.1.mac_stats.total_pkts_rcvd: 1600598184
dev.ix.1.mac_stats.good_octets_rcvd: 1110241698944
dev.ix.1.mac_stats.total_octets_rcvd: 1110277666432
dev.ix.1.mac_stats.xoff_recvd: 0
dev.ix.1.mac_stats.xoff_txd: 0
dev.ix.1.mac_stats.xon_recvd: 0
dev.ix.1.mac_stats.xon_txd: 0
dev.ix.1.mac_stats.rx_missed_packets: 0
dev.ix.1.mac_stats.rec_len_errs: 0
dev.ix.1.mac_stats.remote_faults: 0
dev.ix.1.mac_stats.local_faults: 7
dev.ix.1.mac_stats.short_discards: 0
dev.ix.1.mac_stats.byte_errs: 0
dev.ix.1.mac_stats.ill_errs: 0
dev.ix.1.mac_stats.crc_errs: 0
dev.ix.1.mac_stats.rx_errs: 0
dev.ix.1.queue3.rx_discarded: 0
dev.ix.1.queue3.rx_copies: 0
dev.ix.1.queue3.rx_bytes: 342057574713
dev.ix.1.queue3.rx_packets: 593135439
dev.ix.1.queue3.rxd_tail: 1870
dev.ix.1.queue3.rxd_head: 1871
dev.ix.1.queue3.irqs: 499456640
dev.ix.1.queue3.interrupt_rate: 31250
dev.ix.1.queue3.tx_packets: 0
dev.ix.1.queue3.tso_tx: 0
dev.ix.1.queue3.txd_tail: 0
dev.ix.1.queue3.txd_head: 0
dev.ix.1.queue2.rx_discarded: 0
dev.ix.1.queue2.rx_copies: 0
dev.ix.1.queue2.rx_bytes: 214014283409
dev.ix.1.queue2.rx_packets: 172466257
dev.ix.1.queue2.rxd_tail: 80
dev.ix.1.queue2.rxd_head: 81
dev.ix.1.queue2.irqs: 111247329
dev.ix.1.queue2.interrupt_rate: 31250
dev.ix.1.queue2.tx_packets: 0
dev.ix.1.queue2.tso_tx: 0
dev.ix.1.queue2.txd_tail: 0
dev.ix.1.queue2.txd_head: 0
dev.ix.1.queue1.rx_discarded: 0
dev.ix.1.queue1.rx_copies: 0
dev.ix.1.queue1.rx_bytes: 265381420690
dev.ix.1.queue1.rx_packets: 230347674
dev.ix.1.queue1.rxd_tail: 921
dev.ix.1.queue1.rxd_head: 922
dev.ix.1.queue1.irqs: 156052235
dev.ix.1.queue1.interrupt_rate: 31250
dev.ix.1.queue1.tx_packets: 0
dev.ix.1.queue1.tso_tx: 0
dev.ix.1.queue1.txd_tail: 0
dev.ix.1.queue1.txd_head: 0
dev.ix.1.queue0.rx_discarded: 0
dev.ix.1.queue0.rx_copies: 0
dev.ix.1.queue0.rx_bytes: 275985711464
dev.ix.1.queue0.rx_packets: 604391817
dev.ix.1.queue0.rxd_tail: 392
dev.ix.1.queue0.rxd_head: 393
dev.ix.1.queue0.irqs: 1182566786
dev.ix.1.queue0.interrupt_rate: 31250
dev.ix.1.queue0.tx_packets: 1633941113
dev.ix.1.queue0.tso_tx: 0
dev.ix.1.queue0.txd_tail: 655
dev.ix.1.queue0.txd_head: 655
dev.ix.1.link_irq: 2
dev.ix.1.watchdog_events: 0
dev.ix.1.dropped: 0
dev.ix.1.iflib.rxq3.rxq_fl0.buf_size: 2048
dev.ix.1.iflib.rxq3.rxq_fl0.credits: 2047
dev.ix.1.iflib.rxq3.rxq_fl0.cidx: 1871
dev.ix.1.iflib.rxq3.rxq_fl0.pidx: 1870
dev.ix.1.iflib.rxq3.cpu: 3
dev.ix.1.iflib.rxq2.rxq_fl0.buf_size: 2048
dev.ix.1.iflib.rxq2.rxq_fl0.credits: 2047
dev.ix.1.iflib.rxq2.rxq_fl0.cidx: 81
dev.ix.1.iflib.rxq2.rxq_fl0.pidx: 80
dev.ix.1.iflib.rxq2.cpu: 2
dev.ix.1.iflib.rxq1.rxq_fl0.buf_size: 2048
dev.ix.1.iflib.rxq1.rxq_fl0.credits: 2047
dev.ix.1.iflib.rxq1.rxq_fl0.cidx: 923
dev.ix.1.iflib.rxq1.rxq_fl0.pidx: 922
dev.ix.1.iflib.rxq1.cpu: 1
dev.ix.1.iflib.rxq0.rxq_fl0.buf_size: 2048
dev.ix.1.iflib.rxq0.rxq_fl0.credits: 2047
dev.ix.1.iflib.rxq0.rxq_fl0.cidx: 393
dev.ix.1.iflib.rxq0.rxq_fl0.pidx: 392
dev.ix.1.iflib.rxq0.cpu: 0
dev.ix.1.iflib.txq3.r_abdications: 0
dev.ix.1.iflib.txq3.r_restarts: 0
dev.ix.1.iflib.txq3.r_stalls: 0
dev.ix.1.iflib.txq3.r_starts: 0
dev.ix.1.iflib.txq3.r_drops: 0
dev.ix.1.iflib.txq3.r_enqueues: 0
dev.ix.1.iflib.txq3.ring_state: pidx_head: 0000 pidx_tail: 0000 cidx: 0000 state: IDLE
dev.ix.1.iflib.txq3.txq_cleaned: 0
dev.ix.1.iflib.txq3.txq_processed: 0
dev.ix.1.iflib.txq3.txq_in_use: 0
dev.ix.1.iflib.txq3.txq_cidx_processed: 0
dev.ix.1.iflib.txq3.txq_cidx: 0
dev.ix.1.iflib.txq3.txq_pidx: 0
dev.ix.1.iflib.txq3.no_tx_dma_setup: 0
dev.ix.1.iflib.txq3.txd_encap_efbig: 0
dev.ix.1.iflib.txq3.tx_map_failed: 0
dev.ix.1.iflib.txq3.no_desc_avail: 0
dev.ix.1.iflib.txq3.mbuf_defrag_failed: 0
dev.ix.1.iflib.txq3.m_pullups: 0
dev.ix.1.iflib.txq3.mbuf_defrag: 0
dev.ix.1.iflib.txq3.cpu: 3
dev.ix.1.iflib.txq2.r_abdications: 0
dev.ix.1.iflib.txq2.r_restarts: 0
dev.ix.1.iflib.txq2.r_stalls: 0
dev.ix.1.iflib.txq2.r_starts: 0
dev.ix.1.iflib.txq2.r_drops: 0
dev.ix.1.iflib.txq2.r_enqueues: 0
dev.ix.1.iflib.txq2.ring_state: pidx_head: 0000 pidx_tail: 0000 cidx: 0000 state: IDLE
dev.ix.1.iflib.txq2.txq_cleaned: 0
dev.ix.1.iflib.txq2.txq_processed: 0
dev.ix.1.iflib.txq2.txq_in_use: 0
dev.ix.1.iflib.txq2.txq_cidx_processed: 0
dev.ix.1.iflib.txq2.txq_cidx: 0
dev.ix.1.iflib.txq2.txq_pidx: 0
dev.ix.1.iflib.txq2.no_tx_dma_setup: 0
dev.ix.1.iflib.txq2.txd_encap_efbig: 0
dev.ix.1.iflib.txq2.tx_map_failed: 0
dev.ix.1.iflib.txq2.no_desc_avail: 0
dev.ix.1.iflib.txq2.mbuf_defrag_failed: 0
dev.ix.1.iflib.txq2.m_pullups: 0
dev.ix.1.iflib.txq2.mbuf_defrag: 0
dev.ix.1.iflib.txq2.cpu: 2
dev.ix.1.iflib.txq1.r_abdications: 0
dev.ix.1.iflib.txq1.r_restarts: 0
dev.ix.1.iflib.txq1.r_stalls: 0
dev.ix.1.iflib.txq1.r_starts: 0
dev.ix.1.iflib.txq1.r_drops: 0
dev.ix.1.iflib.txq1.r_enqueues: 0
dev.ix.1.iflib.txq1.ring_state: pidx_head: 0000 pidx_tail: 0000 cidx: 0000 state: IDLE
dev.ix.1.iflib.txq1.txq_cleaned: 0
dev.ix.1.iflib.txq1.txq_processed: 0
dev.ix.1.iflib.txq1.txq_in_use: 0
dev.ix.1.iflib.txq1.txq_cidx_processed: 0
dev.ix.1.iflib.txq1.txq_cidx: 0
dev.ix.1.iflib.txq1.txq_pidx: 0
dev.ix.1.iflib.txq1.no_tx_dma_setup: 0
dev.ix.1.iflib.txq1.txd_encap_efbig: 0
dev.ix.1.iflib.txq1.tx_map_failed: 0
dev.ix.1.iflib.txq1.no_desc_avail: 0
dev.ix.1.iflib.txq1.mbuf_defrag_failed: 0
dev.ix.1.iflib.txq1.m_pullups: 0
dev.ix.1.iflib.txq1.mbuf_defrag: 0
dev.ix.1.iflib.txq1.cpu: 1
dev.ix.1.iflib.txq0.r_abdications: 0
dev.ix.1.iflib.txq0.r_restarts: 0
dev.ix.1.iflib.txq0.r_stalls: 0
dev.ix.1.iflib.txq0.r_starts: 1633941118
dev.ix.1.iflib.txq0.r_drops: 0
dev.ix.1.iflib.txq0.r_enqueues: 1633941121
dev.ix.1.iflib.txq0.ring_state: pidx_head: 1665 pidx_tail: 1665 cidx: 1665 state: IDLE
dev.ix.1.iflib.txq0.txq_cleaned: 3267887733
dev.ix.1.iflib.txq0.txq_processed: 3267887765
dev.ix.1.iflib.txq0.txq_in_use: 34
dev.ix.1.iflib.txq0.txq_cidx_processed: 661
dev.ix.1.iflib.txq0.txq_cidx: 629
dev.ix.1.iflib.txq0.txq_pidx: 663
dev.ix.1.iflib.txq0.no_tx_dma_setup: 0
dev.ix.1.iflib.txq0.txd_encap_efbig: 0
dev.ix.1.iflib.txq0.tx_map_failed: 0
dev.ix.1.iflib.txq0.no_desc_avail: 0
dev.ix.1.iflib.txq0.mbuf_defrag_failed: 0
dev.ix.1.iflib.txq0.m_pullups: 50
dev.ix.1.iflib.txq0.mbuf_defrag: 0
dev.ix.1.iflib.txq0.cpu: 0
dev.ix.1.iflib.override_nrxds: 0
dev.ix.1.iflib.override_ntxds: 0
dev.ix.1.iflib.use_logical_cores: 0
dev.ix.1.iflib.separate_txrx: 0
dev.ix.1.iflib.core_offset: 0
dev.ix.1.iflib.tx_abdicate: 0
dev.ix.1.iflib.rx_budget: 0
dev.ix.1.iflib.disable_msix: 0
dev.ix.1.iflib.override_qs_enable: 0
dev.ix.1.iflib.override_nrxqs: 0
dev.ix.1.iflib.override_ntxqs: 0
dev.ix.1.iflib.driver_version: 4.0.1-k
dev.ix.1.%parent: pci3
dev.ix.1.%pnpinfo: vendor=0x8086 device=0x1528 subvendor=0x1dcf subdevice=0x031b class=0x020000
dev.ix.1.%location: slot=0 function=1 dbsf=pci0:8:0:1 handle=\_SB_.PCI0.IPT1.SLT1
dev.ix.1.%driver: ix
dev.ix.1.%desc: Intel(R) X540-AT2

stephenw10 · Jan 26, 2023, 9:59 PM

Hmm, odd. I don't expect it to hit that on that NIC.
Looks like it's 1s per NIC then, which I guess is expected. Not 10x 1s which would be..painful.

I raised this internally though, I'll see what our developers think.

Steve

ltctech · Jan 26, 2023, 9:59 PM

@stephenw10

The firewall in question has TAC Pro support on it. Should we open a ticket for this?

stephenw10 · Jan 26, 2023, 10:14 PM

You can do but TAC won't be able to tell you anything further until we hear back from the developers. If you do be sure to reference this thread.

I opened a bug to track this: https://redmine.pfsense.org/issues/13911

Steve

ltctech · Jan 26, 2023, 10:18 PM

@stephenw10

Thanks, will keep checking the bug tracker.

ltctech · Apr 4, 2023, 3:18 AM

Looks like it may not be fixed anytime soon. We have moved from 22.05 to 23.01 and it's still happening. I compared the output of ifconfig with and without the verbose flag and found it to be the same for our NICs. Thus I made the following temporary patch to use with the System_Patches package. With this patch Dashboard is quick to load and no longer causes high CPU usage.

--- a/src/etc/inc/pfsense-utils.inc
+++ b/src/etc/inc/pfsense-utils.inc
@@ -1790,7 +1790,7 @@
 	if ($ifinfo['status'] == "up" && $swifinfo == NULL) {
 		/* try to determine media with ifconfig */
 		$ifconfiginfo = [];
-		exec("/sbin/ifconfig -v " . $ifinfo['if'], $ifconfiginfo);
+		exec("/sbin/ifconfig " . $ifinfo['if'], $ifconfiginfo);
 		$wifconfiginfo = [];
 		if (is_interface_wireless($ifdescr)) {
 			exec("/sbin/ifconfig {$ifinfo['if']} list sta", $wifconfiginfo);

Do you foresee any issues with this patch?

stephenw10 · Apr 4, 2023, 8:19 PM

It likely wouldn't make any difference for a NIC that doesn't have a module inserted, which is where the problem exists.
Without that though you won't get any module info in the status page etc. for an interface that is linked with SFP.

Steve

mvikman · Apr 4, 2023, 4:03 PM

I have and dual-RJ45 X540 card (ix0/ix1) that also shows same kind of delay running ifconfig -v command
On the dual-SFP+ X710 card (ixl0/ixl1), the result prints instantly.

X540 has cable plugged in the ix0 and X710 has an RJ45 SFP plugged&connected in the ixl0.
Second port on both cards is unplugged.

[23.01-RELEASE][admin@shodan.phobos.home.arpa]/root: time ifconfig -v ix0
ix0: flags=8863<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500
        description: WAN
        options=4e138bb<RXCSUM,TXCSUM,VLAN_MTU,VLAN_HWTAGGING,JUMBO_MTU,VLAN_HWCSUM,WOL_UCAST,WOL_MCAST,WOL_MAGIC,VLAN_HWFILTER,RXCSUM_IPV6,TXCSUM_IPV6,NOMAP>
        ether 48:df:37:68:54:08
        inet6 fe80::4adf:37ff:fe68:5408%ix0 prefixlen 64 scopeid 0x3
        inet [redacted] netmask 0xfffffc00 broadcast [redacted]
        media: Ethernet autoselect (1000baseT <full-duplex>)
        status: active
        nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL>
0.000u 1.314s 0:01.31 100.0%    170+206k 0+0io 0pf+0w
[23.01-RELEASE][admin@shodan.phobos.home.arpa]/root: time ifconfig -v ix1
ix1: flags=8822<BROADCAST,SIMPLEX,MULTICAST> metric 0 mtu 1500
        options=4e53fbb<RXCSUM,TXCSUM,VLAN_MTU,VLAN_HWTAGGING,JUMBO_MTU,VLAN_HWCSUM,TSO4,TSO6,LRO,WOL_UCAST,WOL_MCAST,WOL_MAGIC,VLAN_HWFILTER,VLAN_HWTSO,RXCSUM_IPV6,TXCSUM_IPV6,NOMAP>
        ether 48:df:37:68:54:09
        media: Ethernet autoselect
        status: no carrier
        nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL>
0.000u 1.291s 0:01.29 100.0%    167+203k 0+0io 0pf+0w
[23.01-RELEASE][admin@shodan.phobos.home.arpa]/root: time ifconfig -v ixl0
ixl0: flags=8863<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500
        options=4e100bb<RXCSUM,TXCSUM,VLAN_MTU,VLAN_HWTAGGING,JUMBO_MTU,VLAN_HWCSUM,VLAN_HWFILTER,RXCSUM_IPV6,TXCSUM_IPV6,NOMAP>
        ether 48:df:37:74:bb:40
        inet6 [redacted] prefixlen 64 scopeid 0x1
        media: Ethernet autoselect (1000baseT <full-duplex>)
        status: active
        nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL>
        plugged: SFP/SFP+/SFP28 1000BASE-T (RJ45)
        vendor: DELTA PN: LCP-1250RJ3SR-HV SN: CN8BKK22X0 DATE: 2018-12-07
0.000u 0.045s 0:00.04 100.0%    198+240k 0+0io 0pf+0w
[23.01-RELEASE][admin@shodan.phobos.home.arpa]/root: time ifconfig -v ixl1
ixl1: flags=8822<BROADCAST,SIMPLEX,MULTICAST> metric 0 mtu 1500
        options=4e507bb<RXCSUM,TXCSUM,VLAN_MTU,VLAN_HWTAGGING,JUMBO_MTU,VLAN_HWCSUM,TSO4,TSO6,LRO,VLAN_HWFILTER,VLAN_HWTSO,RXCSUM_IPV6,TXCSUM_IPV6,NOMAP>
        ether 48:df:37:74:bb:48
        media: Ethernet autoselect
        status: no carrier
        nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL>
0.000u 0.006s 0:00.00 0.0%      0+0k 0+0io 0pf+0w
[23.01-RELEASE][admin@shodan.phobos.home.arpa]/root:

ltctech · Apr 4, 2023, 8:19 PM

@stephenw10

We do not have a module capable card so it's not an issue at least for us.

If the underlying delay and CPU usage with module detection in the driver cannot be fixed could Netgate add a system tunable to turn off module detection on the dashboard?

stephenw10 · Apr 5, 2023, 12:15 AM

Better to add comments to the bug so all developers can see them.