4100 ix2 interface failures only recoverable by disabling or rebooting

[Gertjan]

@arri

I propose one more test: console or GUI, chose 'reboot' but use the 'reroot' instead of the 'reboot' option instead.

Thanks for writing up all the test you've done so far.
I've a 4100 myself, and had this weird observation about both (or one of ?) the ix, the two on the left, looking at the back.
I'm using one right now, the ix3 port, for 3+ years now. It's the WAN to my ISP router.
This ISP router has 3 1 Gbit/sec ports and one 2,5 Gbit/sec. If I use this 2.5 port with the pfSense ix3, 'all hell breaks lose'. ix3 setting is :

but this probably says more about the 2,5 Gbit port on the ISP router as the ix3 of the 4100's, which has a max speed of 1 Gbit anyway.
I know the 4 igc's can do 2,5 Gbit.

Where you, imho, nailed it : when fiddling with ix ports, they (or just one of them ?) can get like, let me call it 'stuck' and only a reset, a power reset, or a complete ix driver re init, done while the OS boots, loads the driver etc can bring it back in a working state.
Again, my is theory of what is happing.

As I'm not changing anything right now, and both pfSense as the ISP fiber router are UPS fed, the connection is stable.

I'll remap the ix3 to the right now not used ix2 this weekend as my WAN, to see if its all 'ix' based issue, or, let's give the issue a name : I have, like you, a flaky ix port ? We'll see, I report back.

[stephenw10]

I would check ifconfig -vvm ix2 at the CLI. Compare the output before and during the failure.

I would also try ifconfig ix2 down; ifconfig ix2 up to see if that restores it.

[arri]

@Gertjan I did use the reroot option, as well as changing the State Killing on Gateway Failure to Flush All before the current run yesterday to see if it that would aid the interface recovery but it seems like this issue is only recoverable by bouncing (or power cycling) the interface. Unfortunately, in my case these appliances are deployed remotely.

@stephenw10
It was in the unresponsive state this morning when I read these messages so I can confirm that bouncing the interfaces with ifconfig from a prompt does bring it back online. I think I probably had confirmed that before by using the checkbox for enable in the interrfaces gui.

I ran the double verbose and media flags while it was still locked up as follows:

ix2: flags=1008843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST,LOWER_UP> metric 0 mtu 1500
	description: WAN2
	options=4e138bb<RXCSUM,TXCSUM,VLAN_MTU,VLAN_HWTAGGING,JUMBO_MTU,VLAN_HWCSUM,WOL_UCAST,WOL_MCAST,WOL_MAGIC,VLAN_HWFILTER,RXCSUM_IPV6,TXCSUM_IPV6,HWSTATS,MEXTPG>
	capabilities=4f53fbb<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,HWSTATS,MEXTPG>
	ether 90:ec:77:32:ad:6d
	inet 10.14.55.172 netmask 0xfffffe00 broadcast 10.14.55.255
	inet6 fe80::92ec:77ff:fe32:ad6d%ix2 prefixlen 64 scopeid 0x7
	media: Ethernet autoselect (1000baseT <full-duplex,rxpause,txpause>)
	status: active
	supported media:
		media autoselect
		media 10baseT/UTP
		media 100baseTX
		media 1000baseT
	nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL>
	drivername: ix2

And again, after bouncing the interface back to operational:

ix2: flags=1008843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST,LOWER_UP> metric 0 mtu 1500
	description: WAN2
	options=4e138bb<RXCSUM,TXCSUM,VLAN_MTU,VLAN_HWTAGGING,JUMBO_MTU,VLAN_HWCSUM,WOL_UCAST,WOL_MCAST,WOL_MAGIC,VLAN_HWFILTER,RXCSUM_IPV6,TXCSUM_IPV6,HWSTATS,MEXTPG>
	capabilities=4f53fbb<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,HWSTATS,MEXTPG>
	ether 90:ec:77:32:ad:6d
	inet 10.14.55.172 netmask 0xfffffe00 broadcast 10.14.55.255
	inet6 fe80::92ec:77ff:fe32:ad6d%ix2 prefixlen 64 scopeid 0x7
	media: Ethernet autoselect (1000baseT <full-duplex,rxpause,txpause>)
	status: active
	supported media:
		media autoselect
		media 10baseT/UTP
		media 100baseTX
		media 1000baseT
	nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL>
	drivername: ix2

Finally, I pulled the hardware stats after it locked up as follows, for reference, while I don't have a copy of the before stats, I do recall particularly the local_faults: 10 is the same as before (probably the result of my testing pulling the ethernet cable to see how it recovered from that). Whereas the byte_errs and rx_errs both read 1 when I left it running iperf last night but now rx_errs reads 90.

Spoiler

Shell Output - sysctl dev.ix.2.mac_stats
dev.ix.2.mac_stats.tx_frames_1024_1522: 2910606237
dev.ix.2.mac_stats.tx_frames_512_1023: 4133
dev.ix.2.mac_stats.tx_frames_256_511: 1909
dev.ix.2.mac_stats.tx_frames_128_255: 2967
dev.ix.2.mac_stats.tx_frames_65_127: 4390591417
dev.ix.2.mac_stats.tx_frames_64: 131276
dev.ix.2.mac_stats.management_pkts_txd: 0
dev.ix.2.mac_stats.mcast_pkts_txd: 9
dev.ix.2.mac_stats.bcast_pkts_txd: 168
dev.ix.2.mac_stats.good_pkts_txd: 7301337939
dev.ix.2.mac_stats.total_pkts_txd: 7301337944
dev.ix.2.mac_stats.good_octets_txd: 4726457951908
dev.ix.2.mac_stats.checksum_errs: 0
dev.ix.2.mac_stats.management_pkts_drpd: 0
dev.ix.2.mac_stats.management_pkts_rcvd: 0
dev.ix.2.mac_stats.recv_jabberd: 1
dev.ix.2.mac_stats.recv_oversized: 0
dev.ix.2.mac_stats.recv_fragmented: 0
dev.ix.2.mac_stats.recv_undersized: 0
dev.ix.2.mac_stats.rx_frames_1024_1522: 4389524471
dev.ix.2.mac_stats.rx_frames_512_1023: 72703
dev.ix.2.mac_stats.rx_frames_256_511: 61172
dev.ix.2.mac_stats.rx_frames_128_255: 65485
dev.ix.2.mac_stats.rx_frames_65_127: 107596989
dev.ix.2.mac_stats.rx_frames_64: 1138580
dev.ix.2.mac_stats.bcast_pkts_rcvd: 1250388
dev.ix.2.mac_stats.mcast_pkts_rcvd: 125164
dev.ix.2.mac_stats.good_pkts_rcvd: 4498459400
dev.ix.2.mac_stats.total_pkts_rcvd: 4502238514
dev.ix.2.mac_stats.good_octets_rcvd: 6671024103714
dev.ix.2.mac_stats.total_octets_rcvd: 6671789047115
dev.ix.2.mac_stats.xoff_recvd: 0
dev.ix.2.mac_stats.xoff_txd: 4
dev.ix.2.mac_stats.xon_recvd: 0
dev.ix.2.mac_stats.xon_txd: 1
dev.ix.2.mac_stats.rx_missed_packets: 89
dev.ix.2.mac_stats.rec_len_errs: 0
dev.ix.2.mac_stats.remote_faults: 0
dev.ix.2.mac_stats.local_faults: 10
dev.ix.2.mac_stats.short_discards: 0
dev.ix.2.mac_stats.byte_errs: 1
dev.ix.2.mac_stats.ill_errs: 0
dev.ix.2.mac_stats.crc_errs: 0
dev.ix.2.mac_stats.rx_errs: 90

I should also note the last few entries in the gateway log were as following continuous stream of the sendto errors:

Aug 21 15:45:52	dpinger	4092	WAN2_DHCP 10.14.54.1: sendto error: 50
Aug 21 15:45:53	dpinger	4092	WAN2_DHCP 10.14.54.1: sendto error: 50
Aug 21 15:45:53	dpinger	4092	exiting on signal 15
Aug 21 15:47:13	dpinger	59430	send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 1 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% alarm_hold 10000ms dest_addr 10.14.54.1 bind_addr 10.14.55.172 identifier "WAN2_DHCP "

An unrelated observation: Despite choosing the gui's factory default reset before testing the interface the logs after last night's lockup show the vnstat daemon is still concerning itself with vlan interfaces not showing in the present gui from prior configurations by disabling them.

The only halfway rational suggestion I'm getting from Google's AI given the existing evidence is to disable EEE (Energy Efficient Ethernet) with the following rational: "Energy Efficient Ethernet forces the Intel SoC port into low-power states during minor millisecond lulls in traffic. On combo-ports, this feature often triggers the exact singular, false link state changed message you are seeing. Setting this to 0 forces the RJ-45 side to stay powered at 100%." However, it links to a product brief from Intel's I350 server adapters so I'm not sure how likely this "solution" is.

[arri]

Just lost the interface again during an iperf that was only loading the cpu to around 60%. Still no change visible to the interface configuration but a jump up in dev.ix.2.mac_stats.local_faults: 14 from 10 was not from me pulling the ethernet this time.

Spoiler

dev.ix.2.mac_stats.tx_frames_1024_1522: 2937921879
dev.ix.2.mac_stats.tx_frames_512_1023: 181875
dev.ix.2.mac_stats.tx_frames_256_511: 3804
dev.ix.2.mac_stats.tx_frames_128_255: 4149
dev.ix.2.mac_stats.tx_frames_65_127: 4418149011
dev.ix.2.mac_stats.tx_frames_64: 141316
dev.ix.2.mac_stats.management_pkts_txd: 0
dev.ix.2.mac_stats.mcast_pkts_txd: 10
dev.ix.2.mac_stats.bcast_pkts_txd: 175
dev.ix.2.mac_stats.good_pkts_txd: 7356402034
dev.ix.2.mac_stats.total_pkts_txd: 7356402039
dev.ix.2.mac_stats.good_octets_txd: 4770002606445
dev.ix.2.mac_stats.checksum_errs: 0
dev.ix.2.mac_stats.management_pkts_drpd: 0
dev.ix.2.mac_stats.management_pkts_rcvd: 0
dev.ix.2.mac_stats.recv_jabberd: 1
dev.ix.2.mac_stats.recv_oversized: 0
dev.ix.2.mac_stats.recv_fragmented: 0
dev.ix.2.mac_stats.recv_undersized: 0
dev.ix.2.mac_stats.rx_frames_1024_1522: 4416806934
dev.ix.2.mac_stats.rx_frames_512_1023: 305300
dev.ix.2.mac_stats.rx_frames_256_511: 63443
dev.ix.2.mac_stats.rx_frames_128_255: 68431
dev.ix.2.mac_stats.rx_frames_65_127: 108887684
dev.ix.2.mac_stats.rx_frames_64: 1188214
dev.ix.2.mac_stats.bcast_pkts_rcvd: 1298503
dev.ix.2.mac_stats.mcast_pkts_rcvd: 130029
dev.ix.2.mac_stats.good_pkts_rcvd: 4527320006
dev.ix.2.mac_stats.total_pkts_rcvd: 4531244943
dev.ix.2.mac_stats.good_octets_rcvd: 6712726134283
dev.ix.2.mac_stats.total_octets_rcvd: 6713520438972
dev.ix.2.mac_stats.xoff_recvd: 0
dev.ix.2.mac_stats.xoff_txd: 4
dev.ix.2.mac_stats.xon_recvd: 0
dev.ix.2.mac_stats.xon_txd: 1
dev.ix.2.mac_stats.rx_missed_packets: 89
dev.ix.2.mac_stats.rec_len_errs: 0
dev.ix.2.mac_stats.remote_faults: 0
dev.ix.2.mac_stats.local_faults: 14
dev.ix.2.mac_stats.short_discards: 0
dev.ix.2.mac_stats.byte_errs: 1
dev.ix.2.mac_stats.ill_errs: 0
dev.ix.2.mac_stats.crc_errs: 0
dev.ix.2.mac_stats.rx_errs: 90

[stephenw10]

Hmm, what is ix2 actually linked to?

Do you have more than one gateways defined?

[arri]

@stephenw10
When I first started experiencing these issues ix2 was the sole gateway connected by a short cat 6 cable to a Casa Systems NDD-0305. The issue did not exist for well over a year, it started happening in the last few months sometime with increasing frequency starting around bi weekly and eventually every few days. I finally replaced the unit a week ago with another 4100 that has not experienced the issue yet.

Presently the 4100 expressing this issue is on my lab bench with ix2 connected via a different, short cat 6 cable to a Unifi USW Flex 2.5G. There is a single allow all ipv4 firewall rule for WAN and WAN2.

Short answer is there are four gateways defined in this lab test.

I am conducting the iPerf testing from a Linux box on the same subnet. I factory reset the appliance using the gui and subsequently configured ix2 as a gateway while leaving ix3 also configured as a gateway with no connection. I have left the default gateway set to automatic during testing. However, when it was in service the default gateway was set to WAN2 which was technically ix2.201 due to the fiber requirments while there was also still a defined dhcpv4 gateway for WAN. In service, there was no physical cable connected to the WAN (ix3) normally; however, I left it this way because in the event of catastrophic failure with the fiber ISP I could talk someone through connecting a cable modem to that interface without having administrative access to the software.

[stephenw10]

And you have replicated it in the bench test correct?

Can you still replicate it if you just re-assign the WAN to ix3? If not it sure looks like a hardware issue.

[arri]

@stephenw10
I replicated the environment where two dhcp v4 gateways were defined on the two ix interfaces with only ix2 connected to a cat6 with similar failure within a few hours of iperf testing with under 70% cpu usage on the 4100. I did not replicate the vlan used by the fiber ISP.

I am currently running iPerf again with a single gateway defined on ix2 to see if it fails in that configuration. If it does, I will redefine a single gateway on ix3 and test that interface as well to verify whether this is isolated to ix2 or is more reflective of both ix RJ45 combo ports.

In any case, I will probably relegate this specific device to applications where the four igc ports are sufficient as long as it's not a software issue.

[arri]

@stephenw10
I reset the device back to factory defaults using the gui again, this time it actully removed the packages which had not been removed by previous factory resting strangely although logs and vnstat's ghosts of vlans past remain. On this series of tests, I utilized the interface assignments gui to redefine the single WAN gateway for targeted hardware port tests.
Both of the ix ports failed with just an hour or two of bidirectional iperf loading both the cpu and the port's bandwidth around 60%.
Out of curiosity I remapped the igc3 port to the WAN gateway which has been running for a few hours now without any issues. However, the 4100's average system utilization using the same iperf flags from the client is running almost 10% lower with the 2.5g port. Good to know!
Thanks for your help, I'm just going to plug the combo ports and put a label on the appliance blocking their use. Hope this doesn't happen to any of my other 4100s. Would a few months of running low system utilization at temperatures between 50 and 60C possibly contribute to the combo port degradation?

[stephenw10]

I'm not aware of any other cases with ports presenting like that. So I doubt it's a temperature/time issue. There are a lot of 4100s out there that will have seen many more hours at higher temps.