Mwan3 confusing on interface status

jhadipak · October 1, 2021, 2:43pm

Guys,

I have an OpenWrt 21.02.0 installation on a raspberry pi 4B model. This set up has LAN on eth0, a broadband on eth1 and a LTE (4G) on eth2. The wan interfaces eth1 and eth2 are based on USB3 to ethernet adapters and I have configured a mwan3 module to failover from broadband (eth1) to LTE (eth2) only when the broadband becomes unavailable. Both members of mwan3 havd 8.8.4.4 and 8.8.4.4 as their tracking IPs. My broadband (eth1) goes into cable modem supplied by my ISP.

When I pull out the ethernet cable between the broadband modem and the pi, failover works fine and 100% of the outbound traffic is directed to LTE (eth2). Also when I restore the ethernet connection, outbound traffic is reliably redirected back to the broadband interface, so no issues there.

However my problems begin when I disconnect the coaxial cable that feeds into the broadband modem. Failover to LTE happens as expected but within a few minutes of the failover, the system somehow thinks that the broadband link is back up and tries to redirect outbound traffic to it. Obviously, since the coaxial cable is still disconnected, I lose internet connectivity completely. My only option then, is to disable the broadband interface manually and re-force a failover to LTE.

Logs from my router clearly showing how the system thinks the eth1 link is back up (look at timestamp Fri Oct 1 14:38:04 2021) are reproduced below. I am also reproducing my mwan3 configuration below for quick and easy reference

Any insights into what could be causing this problem will be most appreciated.

LOGS

Fri Oct  1 14:33:33 2021 user.info mwan3track[1038]: Check (ping) failed for target "8.8.4.4" on interface bband (eth1). Current score: 8
Fri Oct  1 14:33:36 2021 user.info mwan3track[1038]: Check (ping) failed for target "8.8.8.8" on interface bband (eth1). Current score: 8
Fri Oct  1 14:33:36 2021 user.notice mwan3track[1038]: Interface bband (eth1) is disconnecting
Fri Oct  1 14:33:42 2021 user.info mwan3track[1038]: Check (ping) failed for target "8.8.4.4" on interface bband (eth1). Current score: 7
Fri Oct  1 14:33:45 2021 user.info mwan3track[1038]: Check (ping) failed for target "8.8.8.8" on interface bband (eth1). Current score: 7
Fri Oct  1 14:33:51 2021 user.info mwan3track[1038]: Check (ping) failed for target "8.8.4.4" on interface bband (eth1). Current score: 6
Fri Oct  1 14:33:54 2021 user.info mwan3track[1038]: Check (ping) failed for target "8.8.8.8" on interface bband (eth1). Current score: 6
Fri Oct  1 14:34:00 2021 user.info mwan3track[1038]: Check (ping) failed for target "8.8.4.4" on interface bband (eth1). Current score: 5
Fri Oct  1 14:34:03 2021 user.info mwan3track[1038]: Check (ping) failed for target "8.8.8.8" on interface bband (eth1). Current score: 5
Fri Oct  1 14:34:09 2021 user.info mwan3track[1038]: Check (ping) failed for target "8.8.4.4" on interface bband (eth1). Current score: 4
Fri Oct  1 14:34:12 2021 user.info mwan3track[1038]: Check (ping) failed for target "8.8.8.8" on interface bband (eth1). Current score: 4
Fri Oct  1 14:34:12 2021 user.notice mwan3track[1038]: Interface bband (eth1) is offline
Fri Oct  1 14:34:13 2021 user.notice mwan3-hotplug[14144]: Execute disconnected event on interface bband (eth1)
Fri Oct  1 14:36:45 2021 daemon.warn odhcpd[1309]: A default route is present but there is no public prefix on lan thus we don't announce a default route!
Fri Oct  1 14:37:35 2021 daemon.notice netifd: Network device 'eth1' link is down
Fri Oct  1 14:37:35 2021 daemon.notice netifd: Interface 'bband' has link connectivity loss
Fri Oct  1 14:37:35 2021 kern.info kernel: [22091.036112] r8152 2-2.2:1.0 eth1: carrier off
Fri Oct  1 14:37:35 2021 daemon.notice netifd: bband (22948): udhcpc: received SIGTERM
Fri Oct  1 14:37:35 2021 daemon.notice netifd: bband (22948): udhcpc: unicasting a release of 81.99.236.200 to 80.1.17.189
Fri Oct  1 14:37:35 2021 daemon.notice netifd: bband (22948): udhcpc: sending release
Fri Oct  1 14:37:35 2021 daemon.notice netifd: bband (22948): udhcpc: entering released state
Fri Oct  1 14:37:35 2021 daemon.notice netifd: bband (22948): Command failed: Permission denied
Fri Oct  1 14:37:35 2021 daemon.notice netifd: Interface 'bband' is now down
Fri Oct  1 14:37:35 2021 daemon.notice netifd: Interface 'bband' is disabled
Fri Oct  1 14:37:35 2021 daemon.notice netifd: Interface 'bband' is enabled
Fri Oct  1 14:37:35 2021 daemon.info dnsmasq[3688]: reading /tmp/resolv.conf.d/resolv.conf.auto
Fri Oct  1 14:37:35 2021 daemon.info dnsmasq[3688]: using only locally-known addresses for domain test
Fri Oct  1 14:37:35 2021 daemon.info dnsmasq[3688]: using only locally-known addresses for domain onion
Fri Oct  1 14:37:35 2021 daemon.info dnsmasq[3688]: using only locally-known addresses for domain localhost
Fri Oct  1 14:37:35 2021 daemon.info dnsmasq[3688]: using only locally-known addresses for domain local
Fri Oct  1 14:37:35 2021 daemon.info dnsmasq[3688]: using only locally-known addresses for domain invalid
Fri Oct  1 14:37:35 2021 daemon.info dnsmasq[3688]: using only locally-known addresses for domain bind
Fri Oct  1 14:37:35 2021 daemon.info dnsmasq[3688]: using only locally-known addresses for domain lan
Fri Oct  1 14:37:35 2021 daemon.info dnsmasq[3688]: using nameserver 8.8.4.4#53
Fri Oct  1 14:37:35 2021 daemon.info dnsmasq[3688]: using nameserver 8.8.8.8#53
Fri Oct  1 14:37:36 2021 user.notice mwan3-hotplug[19125]: Execute ifdown event on interface bband (unknown)
Fri Oct  1 14:37:36 2021 user.info mwan3track[1038]: Detect ifdown event on interface bband (eth1)
Fri Oct  1 14:37:36 2021 user.notice mwan3track[1038]: Interface bband (eth1) is offline
Fri Oct  1 14:37:36 2021 user.notice mwan3-hotplug[19270]: Execute disconnected event on interface bband (eth1)
Fri Oct  1 14:37:45 2021 daemon.notice netifd: Network device 'eth1' link is up
Fri Oct  1 14:37:45 2021 daemon.notice netifd: Interface 'bband' has link connectivity
Fri Oct  1 14:37:45 2021 daemon.notice netifd: Interface 'bband' is setting up now
Fri Oct  1 14:37:45 2021 kern.info kernel: [22100.749375] IPv6: ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
Fri Oct  1 14:37:45 2021 kern.info kernel: [22100.756295] r8152 2-2.2:1.0 eth1: carrier on
Fri Oct  1 14:37:45 2021 daemon.notice netifd: bband (19802): udhcpc: started, v1.33.1
Fri Oct  1 14:37:45 2021 daemon.notice netifd: bband (19802): udhcpc: sending discover
Fri Oct  1 14:37:48 2021 daemon.notice netifd: bband (19802): udhcpc: sending discover
Fri Oct  1 14:37:51 2021 daemon.notice netifd: bband (19802): udhcpc: sending discover
Fri Oct  1 14:37:55 2021 daemon.notice netifd: Network device 'eth1' link is down
Fri Oct  1 14:37:55 2021 daemon.notice netifd: Interface 'bband' has link connectivity loss
Fri Oct  1 14:37:55 2021 kern.info kernel: [22111.076414] r8152 2-2.2:1.0 eth1: carrier off
Fri Oct  1 14:37:55 2021 daemon.notice netifd: bband (19802): udhcpc: received SIGTERM
Fri Oct  1 14:37:55 2021 daemon.notice netifd: bband (19802): udhcpc: entering released state
Fri Oct  1 14:37:55 2021 daemon.notice netifd: bband (19802): Command failed: Permission denied
Fri Oct  1 14:37:56 2021 daemon.notice netifd: Interface 'bband' is now down
Fri Oct  1 14:37:56 2021 daemon.notice netifd: Interface 'bband' is disabled
Fri Oct  1 14:37:56 2021 daemon.notice netifd: Interface 'bband' is enabled
Fri Oct  1 14:37:56 2021 user.notice mwan3-hotplug[20046]: Execute ifdown event on interface bband (unknown)
Fri Oct  1 14:37:56 2021 user.info mwan3track[1038]: Detect ifdown event on interface bband (eth1)
Fri Oct  1 14:37:56 2021 user.notice mwan3track[1038]: Interface bband (eth1) is offline
Fri Oct  1 14:37:56 2021 user.notice mwan3-hotplug[20147]: Execute disconnected event on interface bband (eth1)
Fri Oct  1 14:38:04 2021 daemon.notice netifd: Network device 'eth1' link is up
Fri Oct  1 14:38:04 2021 daemon.notice netifd: Interface 'bband' has link connectivity
Fri Oct  1 14:38:04 2021 daemon.notice netifd: Interface 'bband' is setting up now
Fri Oct  1 14:38:04 2021 kern.info kernel: [22119.145024] IPv6: ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
Fri Oct  1 14:38:04 2021 kern.info kernel: [22119.152192] r8152 2-2.2:1.0 eth1: carrier on
Fri Oct  1 14:38:04 2021 daemon.notice netifd: bband (20637): udhcpc: started, v1.33.1
Fri Oct  1 14:38:04 2021 daemon.notice netifd: bband (20637): udhcpc: sending discover
Fri Oct  1 14:38:07 2021 daemon.notice netifd: bband (20637): udhcpc: sending discover
Fri Oct  1 14:38:10 2021 daemon.notice netifd: bband (20637): udhcpc: sending discover
Fri Oct  1 14:38:22 2021 daemon.notice netifd: bband (20637): udhcpc: sending select for 192.168.100.20
Fri Oct  1 14:38:22 2021 daemon.notice netifd: bband (20637): udhcpc: lease of 192.168.100.20 obtained, lease time 122
Fri Oct  1 14:38:22 2021 daemon.notice netifd: Interface 'bband' is now up
Fri Oct  1 14:38:22 2021 user.notice mwan3-hotplug[21000]: Execute ifup event on interface bband (eth1)
Fri Oct  1 14:38:22 2021 user.info mwan3track[1038]: Detect ifup event on interface bband (eth1)
Fri Oct  1 14:38:22 2021 user.notice mwan3track[1038]: Interface bband (eth1) is online
Fri Oct  1 14:38:22 2021 user.notice firewall: Reloading firewall due to ifup of bband (eth1)

MWAN3 CONFIG

config member 'bband_mem'
	option interface 'bband'
	option metric '1'
	option weight '2'

config member 'lte_mem'
	option interface 'lte'
	option weight '1'
	option metric '2'

config interface 'lte'
	option enabled '1'
	list track_ip '8.8.4.4'
	list track_ip '8.8.8.8'
	option reliability '1'
	option count '1'
	option timeout '3'
	option interval '3'
	option down '5'
	option up '3'	

config interface 'bband'
	option enabled '1'
	list track_ip '8.8.4.4'
	list track_ip '8.8.8.8'
	option reliability '1'
	option count '1'
	option timeout '3'
	option interval '3'
	option down '5'
	option up '3'

config policy 'failover'
	list use_member 'bband_mem'
	list use_member 'lte_mem'
	option last_resort 'unreachable'

config rule 'default_rule'
	option dest_ip '0.0.0.0/0'
	option use_policy 'failover'

trendy · October 2, 2021, 9:15pm

In line 72 you can see that the ISP modem responded to the dhcp discovery from OpenWrt. So the switch to the bband from lte is justified. What you can try to avoid such situation is to use the option initial_state 'offline' for bband. This way even if it comes up without actually being connected to the internet, it will have to pass the connectivity test before actually being used.

jhadipak · October 3, 2021, 12:30pm

Hi trendy

Before you replied and based on come comments I found in other discussions on mwan3, I tried the following option for my bband and lte interfaces in /etc/config/network

option force_link '1'

This seems to have fully solved my problem. I have tested several times and can confirm both failover and fail back now seem to be working as expected.

I haven't tried your suggestion yet but have made note and will go for it should my own change lead to any odd behaviour I haven't noticed so far.

But many thanks for your response, much appreciated.

Regards,

Dipak Jha

trendy · October 3, 2021, 7:24pm

Does it detect the ethernet cable unplugging too correctly?

jhadipak · October 4, 2021, 2:54pm

Hi,

Yes it does. I can confirm it (option force_link '1') works for all of the following scenarios:

Cable modem coaxial cable pulled out and reconnected after about 20 mins
Ethernet cable between modem and my pi pulled out and reconnected after about 20 mins
Cable modem powered off and powered back up after about 20 mins

Regards

Dipak Jha

trendy · October 4, 2021, 5:22pm

If your problem is solved, please consider marking this topic as [Solved]. See How to mark a topic as [Solved] for a short how-to.

system · October 14, 2021, 5:22pm

This topic was automatically closed 10 days after the last reply. New replies are no longer allowed.