WAN only connecting on 80% of reboots on RT3200

Hi,
the WAN-interface of my RT3200 is not connecting on around 20% of the reboots on RC6 and latest snapshots. The router of my ISP (Kabel vodafone.de) is in bridge mode and connected to my RT3200 through wall-cables. I ruled out faulty cables by directly connecting the two. Only a reboot solves this issue. Restarting the WAN-interface is not working. If WAN is connected, the connection is stable without dropouts.

Here are the logs (with redacted IPs):

WAN is not connecting:
Thu Sep  1 10:33:18 2022 kern.info kernel: [    1.860576] mt7530 mdio-bus:00 wan (uninitialized): PHY [mt7530-0:04] driver [MediaTek MT7531 PHY] (irq=151)
Thu Sep  1 10:33:21 2022 kern.info kernel: [   15.419522] mt7530 mdio-bus:00 wan: configuring for phy/gmii link mode
Thu Sep  1 10:33:21 2022 daemon.notice netifd: Interface 'wan' is enabled
Thu Sep  1 10:33:21 2022 daemon.notice netifd: Interface 'wan6' is enabled
Thu Sep  1 10:33:21 2022 kern.info kernel: [   15.442060] mt7530 mdio-bus:00 wan: Link is Up - 1Gbps/Full - flow control rx/tx
Thu Sep  1 10:33:21 2022 kern.info kernel: [   15.449687] IPv6: ADDRCONF(NETDEV_CHANGE): wan: link becomes ready
Thu Sep  1 10:33:21 2022 daemon.notice netifd: Network device 'wan' link is up
Thu Sep  1 10:33:21 2022 daemon.notice netifd: Interface 'wan' has link connectivity
Thu Sep  1 10:33:21 2022 daemon.notice netifd: Interface 'wan' is setting up now
Thu Sep  1 10:33:21 2022 daemon.notice netifd: Interface 'wan6' has link connectivity
Thu Sep  1 10:33:21 2022 daemon.notice netifd: Interface 'wan6' is setting up now
Thu Sep  1 10:33:21 2022 daemon.notice netifd: wan (2092): udhcpc: started, v1.35.0
Thu Sep  1 10:33:22 2022 daemon.notice netifd: wan (2092): udhcpc: broadcasting discover
Thu Sep  1 10:33:22 2022 user.notice SQM: Starting SQM script: simple.qos on wan, in: 880000 Kbps, out: 47000 Kbps
Thu Sep  1 10:33:22 2022 daemon.notice procd: /etc/rc.d/S50sqm: SQM: Starting SQM script: simple.qos on wan, in: 880000 Kbps, out: 47000 Kbps
Thu Sep  1 10:33:24 2022 user.notice SQM: simple.qos was started on wan successfully
Thu Sep  1 10:33:24 2022 daemon.notice procd: /etc/rc.d/S50sqm: SQM: simple.qos was started on wan successfully
Thu Sep  1 10:33:25 2022 daemon.notice netifd: wan (2092): udhcpc: broadcasting discover
Thu Sep  1 10:33:25 2022 daemon.info avahi-daemon[3397]: Joining mDNS multicast group on interface wan.IPv6 with address XXX.
Thu Sep  1 10:33:25 2022 daemon.info avahi-daemon[3397]: New relevant interface wan.IPv6 for mDNS.
Thu Sep  1 10:33:25 2022 daemon.info avahi-daemon[3397]: Registering new address record for XXX on wan.*.
Thu Sep  1 10:33:28 2022 daemon.notice netifd: wan (2092): udhcpc: broadcasting discover


root@OpenWrt:~# dmesg | grep wan
[    1.860576] mt7530 mdio-bus:00 wan (uninitialized): PHY [mt7530-0:04] driver [MediaTek MT7531 PHY] (irq=151)
[   15.419522] mt7530 mdio-bus:00 wan: configuring for phy/gmii link mode
[   15.442060] mt7530 mdio-bus:00 wan: Link is Up - 1Gbps/Full - flow control rx/tx
[   15.449687] IPv6: ADDRCONF(NETDEV_CHANGE): wan: link becomes ready```
WAN is connected:
root@OpenWrt:~# logread | grep wan
Thu Sep  1 10:33:18 2022 kern.info kernel: [    1.860691] mt7530 mdio-bus:00 wan (uninitialized): PHY [mt7530-0:04] driver [MediaTek MT7531 PHY] (irq=151)
Thu Sep  1 10:33:21 2022 kern.info kernel: [   15.477822] mt7530 mdio-bus:00 wan: configuring for phy/gmii link mode
Thu Sep  1 10:33:21 2022 daemon.notice netifd: Interface 'wan' is enabled
Thu Sep  1 10:33:21 2022 daemon.notice netifd: Interface 'wan6' is enabled
Thu Sep  1 10:33:21 2022 kern.info kernel: [   15.500412] mt7530 mdio-bus:00 wan: Link is Up - 1Gbps/Full - flow control rx/tx
Thu Sep  1 10:33:21 2022 kern.info kernel: [   15.507933] IPv6: ADDRCONF(NETDEV_CHANGE): wan: link becomes ready
Thu Sep  1 10:33:21 2022 daemon.notice netifd: Network device 'wan' link is up
Thu Sep  1 10:33:21 2022 daemon.notice netifd: Interface 'wan' has link connectivity
Thu Sep  1 10:33:21 2022 daemon.notice netifd: Interface 'wan' is setting up now
Thu Sep  1 10:33:21 2022 daemon.notice netifd: Interface 'wan6' has link connectivity
Thu Sep  1 10:33:21 2022 daemon.notice netifd: Interface 'wan6' is setting up now
Thu Sep  1 10:33:21 2022 daemon.notice netifd: wan (2108): udhcpc: started, v1.35.0
Thu Sep  1 10:33:21 2022 user.notice SQM: Starting SQM script: simple.qos on wan, in: 880000 Kbps, out: 47000 Kbps
Thu Sep  1 10:33:21 2022 daemon.notice procd: /etc/rc.d/S50sqm: SQM: Starting SQM script: simple.qos on wan, in: 880000 Kbps, out: 47000 Kbps
Thu Sep  1 10:33:22 2022 daemon.notice netifd: wan (2108): udhcpc: broadcasting discover
Thu Sep  1 10:33:22 2022 daemon.notice netifd: wan (2108): udhcpc: broadcasting select for XXX, server XXX
Thu Sep  1 10:33:22 2022 daemon.notice netifd: wan (2108): udhcpc: lease of XXX obtained from XXX, lease time 1800
Thu Sep  1 10:33:22 2022 daemon.notice netifd: Interface 'wan' is now up
Thu Sep  1 10:33:23 2022 user.notice SQM: simple.qos was started on wan successfully
Thu Sep  1 10:33:23 2022 daemon.notice procd: /etc/rc.d/S50sqm: SQM: simple.qos was started on wan successfully
Thu Sep  1 10:33:24 2022 daemon.info avahi-daemon[3320]: Joining mDNS multicast group on interface wan.IPv6 with address XXX.
Thu Sep  1 10:33:24 2022 daemon.info avahi-daemon[3320]: New relevant interface wan.IPv6 for mDNS.
Thu Sep  1 10:33:24 2022 daemon.info avahi-daemon[3320]: Joining mDNS multicast group on interface wan.IPv4 with address XXX.
Thu Sep  1 10:33:24 2022 daemon.info avahi-daemon[3320]: New relevant interface wan.IPv4 for mDNS.
Thu Sep  1 10:33:24 2022 daemon.info avahi-daemon[3320]: Registering new address record for XXX on wan.*.
Thu Sep  1 10:33:24 2022 daemon.info avahi-daemon[3320]: Registering new address record for XXX on wan.IPv4.
Thu Sep  1 10:33:25 2022 daemon.info avahi-daemon[3320]: Leaving mDNS multicast group on interface wan.IPv6 with address XXX.
Thu Sep  1 10:33:25 2022 daemon.info avahi-daemon[3320]: Joining mDNS multicast group on interface wan.IPv6 with address XXX.
Thu Sep  1 10:33:25 2022 daemon.info avahi-daemon[3320]: Registering new address record for XXX on wan.*.
Thu Sep  1 10:33:25 2022 daemon.info avahi-daemon[3320]: Withdrawing address record for XXX on wan.
Thu Sep  1 10:33:25 2022 daemon.notice netifd: Interface 'wan6' is now up
Thu Sep  1 11:04:19 2022 user.notice SQM: Stopping SQM on wan
Thu Sep  1 11:04:20 2022 user.notice SQM: Starting SQM script: simple.qos on wan, in: 880000 Kbps, out: 47000 Kbps
Thu Sep  1 11:04:22 2022 user.notice SQM: simple.qos was started on wan successfully
Thu Sep  1 11:04:22 2022 user.notice firewall: Reloading firewall due to ifup of wan (wan)
Thu Sep  1 11:04:25 2022 user.notice SQM: Stopping SQM on wan
Thu Sep  1 11:04:26 2022 user.notice SQM: Starting SQM script: simple.qos on wan, in: 880000 Kbps, out: 47000 Kbps
Thu Sep  1 11:04:27 2022 user.notice SQM: simple.qos was started on wan successfully
Thu Sep  1 11:04:27 2022 user.notice firewall: Reloading firewall due to ifup of wan6 (wan)


root@OpenWrt:~# dmesg | grep wan
[    1.860691] mt7530 mdio-bus:00 wan (uninitialized): PHY [mt7530-0:04] driver [MediaTek MT7531 PHY] (irq=151)
[   15.477822] mt7530 mdio-bus:00 wan: configuring for phy/gmii link mode
[   15.500412] mt7530 mdio-bus:00 wan: Link is Up - 1Gbps/Full - flow control rx/tx
[   15.507933] IPv6: ADDRCONF(NETDEV_CHANGE): wan: link becomes ready
WAN in /etc/config/network
config interface 'wan'
	option device 'wan'
	option proto 'dhcp'
	option hostname '*'

config interface 'wan6'
	option device 'wan'
	option proto 'dhcpv6'
	option reqaddress 'try'
	option reqprefix '56'
	option iface_dslite '0'

Seems like it is halting after udhcpc: broadcasting discover. Does anyone have an idea on how to solve this?

what happens if you temp disable the SQM script, or delay the start up.

The issue remains, when disabling SQM.

So i did a little try and error, disabled a lot of things which run on startup (python script, VPN Server, VPN-Connection for DMZ) and changed some settings back and forth (e.g. in unbound), but nothing worked so far. I even connected my Xiaomi 4A Gigabit to see, if it has the same issue, it did not.

When i start the RT3200 with the WAN-cable to the modem disconnected, it boots just fine and it gets an IP via DHCP every time i plug the cable back in the WAN-port. I never had problems, when my ISP thought to reboot my modem, too.

Could this be some kind of connection-error during boot? It is strange that i can not get a connection by restarting the WAN-interface, only a reboot of the router works. Modem reboot does not work either.

I get the same failure to connect sometimes too, even on a base install, there was a bug a while back where wan wasn't picking up an ip at all, it got fixed but it may be related, although I really don't know.

Ok. If you have the same issue, than at least it should not be a bad config on my router.

I thought I read something about this issue in the RT3200 thread a long time ago, but I can not find it anymore. Maybe I dig into that, if I have some time.

Here's that mention, it was happening at every boot at that time.