High CPU Usage and Delay Calling ifconfig -v ix0/ix1; Delays Dashboard Load
-
How would I check that the card is reporting it's SFP capable?
The dashboard takes roughly 7 seconds to load/refresh. That's without the widgets that take longer. It also tends to keep a core busy as its constantly trying to update.
-
Output of same command that you ran:
[22.05-RELEASE][root@redacted.redacted.com]/root: time ifconfig -vvvm ix1 ix1: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500 description: LAN options=8138b8<VLAN_MTU,VLAN_HWTAGGING,JUMBO_MTU,VLAN_HWCSUM,WOL_UCAST,WOL_MCAST,WOL_MAGIC,VLAN_HWFILTER> capabilities=f53fbb<RXCSUM,TXCSUM,VLAN_MTU,VLAN_HWTAGGING,JUMBO_MTU,VLAN_HWCSUM,TSO4,TSO6,LRO,WOL_UCAST,WOL_MCAST,WOL_MAGIC,VLAN_HWFILTER,VLAN_HWTSO,NETMAP,RXCSUM_IPV6,TXCSUM_IPV6> ether 80:61:5f:XX:XX:XX inet6 [redacted] prefixlen 64 scopeid 0x2 media: Ethernet autoselect (1000baseT <full-duplex>) status: active supported media: media autoselect media 100baseTX media 1000baseT media 10Gbase-T nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL> 0.000u 1.365s 0:01.37 99.2% 145+205k 1+0io 0pf+0w
This one shows supported media but nothing that I wouldn't expect for the card.
-
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
-
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
-
The firewall in question has TAC Pro support on it. Should we open a ticket for this?
-
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
-
Thanks, will keep checking the bug tracker.
-
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?
-
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
-
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:
-
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?
-
Better to add comments to the bug so all developers can see them.