Interface Down/Up and CARP failover when adding VLANs normal?

[tt-ah]

Hi everyone!

Just caused a couple unintended failovers on our CARP-Cluster on a client site. Has been running rock solid for a good 500 days. CARP worked fine so the client did not notice the failover at all. Nevertheless I would like to clear up this issue, since I have to do further configurations.

Setup is as follows:

• 2x OPNsense 20.7.8_4-amd64 (I know)
• 4 NICS
• 3 VLANs on LAN (igb0)
• CARP on all VLANs and WAN-Port (igb1)

Scenario:
Client site gets a new wifi setup which requires 4 more VLANs on the LAN interface (igb0). After adding every VLAN I got "logged out" from the webinterface, had to relog and got Cookie related errors. On the fourth occurrence I noticed, that the cluster was actually failing over every time I added a VLAN since I relogged to the secondary node.

Upon checking the logs, I saw that the Interface goes down for about 5 seconds after adding a VLAN to it.

I am not used to anything of the sort on other network hardware when making such changes. I did not find any known issue/bugs/reports of this effect.

I am now hesitant to configure the cluster further (VLANs on Backup-Node, IPs on those new VLANs, CARP on those new VLANs, DHCP on those new VLANs).

Logs (after adding VLAN 903 on LAN (igb0) ):

Code Select Expand

Jun 30 08:53:08 sws-tue-gw1 devd[98176]: Processing event '!system=IFNET subsystem=vlan4 type=ATTACH'
Jun 30 08:53:08 sws-tue-gw1 devd[98176]: Processing event '!system=ETHERNET subsystem=vlan4 type=IFATTACH'
Jun 30 08:53:08 sws-tue-gw1 devd[98176]: Executing '/usr/libexec/hyperv/hyperv_vfattach $'vlan4' 0'
Jun 30 08:53:08 sws-tue-gw1 dhcpd[62818]: failover peer dhcp_opt2: network down
Jun 30 08:53:08 sws-tue-gw1 devd[98176]: Processing event '!system=IFNET subsystem=igb0 type=LINK_DOWN'
Jun 30 08:53:08 sws-tue-gw1 charon[37623]: 15[KNL] interface igb0_vlan903 appeared
Jun 30 08:53:08 sws-tue-gw1 charon[37623]: 15[KNL] xxx.xxx.xxx.xxx disappeared from igb1
Jun 30 08:53:08 sws-tue-gw1 devd[98176]: Executing '/usr/local/opnsense/service/configd_ctl.py interface linkup stop $'igb0''
Jun 30 08:53:08 sws-tue-gw1 charon[37623]: 15[KNL] interface igb0_vlan903 activated
Jun 30 08:53:08 sws-tue-gw1 configd.py[96964]: [14c7ff7b-1237-4d5f-ac39-021f62c205ba] Linkup stopping igb0
Jun 30 08:53:09 sws-tue-gw1 opnsense[36836]: /usr/local/etc/rc.linkup: Hotplug event detected for LAN(lan) but ignoring since interface is configured with static IP (0.0.0.0 ::)
Jun 30 08:53:09 sws-tue-gw1 devd[98176]: Processing event '!system=CARP subsystem=4@igb0_vlan990 type=INIT'
Jun 30 08:53:09 sws-tue-gw1 devd[98176]: Processing event '!system=IFNET subsystem=igb0_vlan990 type=LINK_DOWN'
Jun 30 08:53:09 sws-tue-gw1 devd[98176]: Executing '/usr/local/opnsense/service/configd_ctl.py interface linkup stop $'igb0_vlan990''
Jun 30 08:53:09 sws-tue-gw1 configd.py[96964]: [09c46065-3f53-4592-a74f-aa78cc4eac34] Linkup stopping igb0_vlan990
Jun 30 08:53:09 sws-tue-gw1 configctl[28232]: event @ 1656571988.80 msg: Jun 30 08:53:08 sws-tue-gw1.xxxxxxxxxx.xx config[53108]: config-event: new_config /conf/backup/config-1656571988.7957.xml
Jun 30 08:53:09 sws-tue-gw1 configctl[28232]: event @ 1656571988.80 exec: system event config_changed
Jun 30 08:53:09 sws-tue-gw1 configd.py[96964]: [5a25d4db-8863-4201-89a2-14bf1a5d8614] trigger config changed event
Jun 30 08:53:09 sws-tue-gw1 opnsense[17071]: /usr/local/etc/rc.linkup: Hotplug event detected for LAN_990_mgmt(opt6) but ignoring since interface is configured with static IP (10.199.90.252 ::)
Jun 30 08:53:09 sws-tue-gw1 devd[98176]: Processing event '!system=IFNET subsystem=igb0_vlan903 type=LINK_DOWN'
Jun 30 08:53:09 sws-tue-gw1 devd[98176]: Executing '/usr/local/opnsense/service/configd_ctl.py interface linkup stop $'igb0_vlan903''
Jun 30 08:53:09 sws-tue-gw1 configd.py[96964]: [d15cb733-9914-4d71-8b08-9ddc3b7d4ae7] Linkup stopping igb0_vlan903
Jun 30 08:53:09 sws-tue-gw1 devd[98176]: Processing event '!system=CARP subsystem=3@igb0_vlan902 type=INIT'
Jun 30 08:53:09 sws-tue-gw1 devd[98176]: Processing event '!system=IFNET subsystem=igb0_vlan902 type=LINK_DOWN'
Jun 30 08:53:09 sws-tue-gw1 devd[98176]: Executing '/usr/local/opnsense/service/configd_ctl.py interface linkup stop $'igb0_vlan902''
Jun 30 08:53:09 sws-tue-gw1 configd.py[96964]: [d081e87b-e10b-4f6b-9ae3-2680b0b43e4d] Linkup stopping igb0_vlan902
Jun 30 08:53:09 sws-tue-gw1 filterlog[96237]: 81,,,0,igb0_vlan903,match,pass,out,6,0x00,0x00000,1,ip,0,36,::,ff02::16,HBH,PADN,RTALERT,0x0000,
Jun 30 08:53:09 sws-tue-gw1 filterlog[96237]: 81,,,0,igb0_vlan903,match,pass,out,6,0x00,0x00000,255,ipv6-icmp,58,32,::,ff02::1:ff00:346d,
Jun 30 08:53:09 sws-tue-gw1 opnsense[43024]: /usr/local/etc/rc.linkup: Hotplug event detected for LAN_902_printers(opt4) but ignoring since interface is configured with static IP (10.200.28.252 ::)
Jun 30 08:53:10 sws-tue-gw1 devd[98176]: Processing event '!system=CARP subsystem=1@igb0_vlan901 type=INIT'
Jun 30 08:53:10 sws-tue-gw1 devd[98176]: Processing event '!system=IFNET subsystem=igb0_vlan901 type=LINK_DOWN'
Jun 30 08:53:10 sws-tue-gw1 devd[98176]: Executing '/usr/local/opnsense/service/configd_ctl.py interface linkup stop $'igb0_vlan901''
Jun 30 08:53:10 sws-tue-gw1 configd.py[96964]: [76e761f3-41d9-4be1-afff-7ad5e66f82d3] Linkup stopping igb0_vlan901
Jun 30 08:53:10 sws-tue-gw1 opnsense[52486]: /usr/local/etc/rc.linkup: Hotplug event detected for LAN_901_intra(opt2) but ignoring since interface is configured with static IP (10.200.32.252 ::)
Jun 30 08:53:10 sws-tue-gw1 devd[98176]: Processing event '!system=CARP subsystem=2@igb1 type=BACKUP'
Jun 30 08:53:10 sws-tue-gw1 devd[98176]: Executing '/usr/local/opnsense/service/configd_ctl.py interface carp $'2@igb1' $'BACKUP''
Jun 30 08:53:10 sws-tue-gw1 configd.py[96964]: [ce3a5ff4-b1a0-423e-b5c3-6e28c29d5021] Carp event on subsystem 2@igb1 for type BACKUP
Jun 30 08:53:10 sws-tue-gw1 opnsense[50023]: /usr/local/etc/rc.syshook.d/carp/20-openvpn: Carp cluster member "xxx.xxx.xxx.xxx - VIP_WAN (2@igb1)" has resumed the state "BACKUP" for vhid 2
Jun 30 08:53:13 sws-tue-gw1 devd[98176]: Processing event '!system=IFNET subsystem=igb0 type=LINK_UP'
Jun 30 08:53:13 sws-tue-gw1 devd[98176]: Executing '/usr/local/opnsense/service/configd_ctl.py interface linkup start $'igb0''
Jun 30 08:53:13 sws-tue-gw1 configd.py[96964]: [3dfd282b-bf24-4d4d-80d0-46a82d86a05f] Linkup starting igb0
Jun 30 08:53:13 sws-tue-gw1 opnsense[5859]: /usr/local/etc/rc.linkup: Hotplug event detected for LAN(lan) but ignoring since interface is configured with static IP (0.0.0.0 ::)
Jun 30 08:53:13 sws-tue-gw1 configd.py[96964]: [2c62e4a1-2680-43be-8746-1f9d64434060] New IPv4 on igb0
Jun 30 08:53:13 sws-tue-gw1 opnsense[51169]: /usr/local/etc/rc.newwanip: IPv4 renewal is starting on 'igb0'
Jun 30 08:53:13 sws-tue-gw1 opnsense[51169]: /usr/local/etc/rc.newwanip: On (IP address: ) (interface: LAN[lan]) (real interface: igb0).
Jun 30 08:53:13 sws-tue-gw1 opnsense[51169]: /usr/local/etc/rc.newwanip: Failed to detect IP for LAN[lan]
Jun 30 08:53:13 sws-tue-gw1 devd[98176]: Processing event '!system=CARP subsystem=4@igb0_vlan990 type=BACKUP'
Jun 30 08:53:13 sws-tue-gw1 devd[98176]: Executing '/usr/local/opnsense/service/configd_ctl.py interface carp $'4@igb0_vlan990' $'BACKUP''