I'm running custom build of OpenWRT 19.07 on x86, i3-8100 CPU. I have a problem with udhcpc choking when there's "full load" (download ongoing at max speed) on wan/tun0 interface. I'm also using VPN which get disconnected in this case and only comes back up with /etc/init.d/openvpn restart
Here's log
Mon Apr 5 20:21:03 2021 daemon.notice netifd: wan (5210): udhcpc: sending renew to a.a.a.a
Mon Apr 5 20:36:03 2021 daemon.notice netifd: wan (5210): udhcpc: sending renew to a.a.a.a
Mon Apr 5 20:43:33 2021 daemon.notice netifd: wan (5210): udhcpc: sending renew to a.a.a.a
Mon Apr 5 20:47:18 2021 daemon.notice netifd: wan (5210): udhcpc: sending renew to a.a.a.a
Mon Apr 5 20:49:10 2021 daemon.notice netifd: wan (5210): udhcpc: sending renew to a.a.a.a
Mon Apr 5 20:50:06 2021 daemon.notice netifd: wan (5210): udhcpc: sending renew to 0.0.0.0
Mon Apr 5 20:50:36 2021 daemon.notice netifd: wan (5210): udhcpc: sending renew to 0.0.0.0
Mon Apr 5 20:50:51 2021 daemon.notice netifd: wan (5210): udhcpc: sending renew to 0.0.0.0
Mon Apr 5 20:50:58 2021 daemon.notice netifd: wan (5210): udhcpc: sending renew to 0.0.0.0
Mon Apr 5 20:51:01 2021 daemon.notice netifd: wan (5210): udhcpc: sending renew to 0.0.0.0
Mon Apr 5 20:51:02 2021 daemon.notice netifd: wan (5210): udhcpc: sending renew to 0.0.0.0
Mon Apr 5 20:51:02 2021 daemon.notice netifd: wan (5210): udhcpc: lease lost, entering init state
Mon Apr 5 20:51:02 2021 daemon.notice netifd: Interface 'wan' has lost the connection
Mon Apr 5 20:51:02 2021 daemon.notice netifd: wan (5210): udhcpc: sending discover
Mon Apr 5 20:51:05 2021 daemon.notice netifd: wan (5210): udhcpc: sending discover
Mon Apr 5 20:51:05 2021 daemon.notice netifd: wan (5210): udhcpc: sending select for b.b.b.b
Mon Apr 5 20:51:05 2021 daemon.notice netifd: wan (5210): udhcpc: lease of b.b.b.b obtained, lease time 7200
Mon Apr 5 20:51:05 2021 daemon.notice netifd: Interface 'wan' is now up
Mon Apr 5 20:51:05 2021 user.notice firewall: Reloading firewall due to ifup of wan (eth1)
Mon Apr 5 20:53:44 2021 daemon.notice openvpn(vpnclient)[5517]: TLS: tls_process: killed expiring key
Mon Apr 5 20:54:02 2021 daemon.notice openvpn(vpnclient)[5517]: [vpnprovider.com] Inactivity timeout (--ping-restart), restarting
Mon Apr 5 20:54:02 2021 daemon.notice openvpn(vpnclient)[5517]: SIGUSR1[soft,ping-restart] received, process restarting
Mon Apr 5 20:54:02 2021 daemon.notice openvpn(vpnclient)[5517]: Restart pause, 5 second(s)
Mon Apr 5 20:54:07 2021 daemon.notice openvpn(vpnclient)[5517]: TCP/UDP: Preserving recently used remote address: [AF_INET]z.z.z.z.132:1194
Mon Apr 5 20:54:07 2021 daemon.notice openvpn(vpnclient)[5517]: Socket Buffers: R=[212992->425984] S=[212992->425984]
Mon Apr 5 20:54:07 2021 daemon.notice openvpn(vpnclient)[5517]: UDP link local: (not bound)
Mon Apr 5 20:54:07 2021 daemon.notice openvpn(vpnclient)[5517]: UDP link remote: [AF_INET]z.z.z.z.132:1194
Mon Apr 5 20:55:07 2021 daemon.err openvpn(vpnclient)[5517]: TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Mon Apr 5 20:55:07 2021 daemon.err openvpn(vpnclient)[5517]: TLS Error: TLS handshake failed
Mon Apr 5 20:55:07 2021 daemon.notice openvpn(vpnclient)[5517]: SIGUSR1[soft,tls-error] received, process restarting
... TLS Error: TLS handshake failed repeated until OpenVPN restarted manually ...
I've tried SQM and software flow offload without SQM which do not help in this case, I believe they have no effect on DHCP requests that go straight to VPN tunnel. I'm running out of ideas what to try next so maybe someone can give some ideas. Also I'm puzzled why OpenVPN requires restart in this case.
I have also tried to get rid of "sending renew to a.a.a.a" by using "Use broadcast flag: true" but for some reason this option does not change what happens in logs in any way.
When there is no load on wan/tun0 DHCP renew always succeeds
Mon Apr 5 16:22:56 2021 daemon.notice netifd: wan (5210): udhcpc: sending renew to a.a.a.a
Mon Apr 5 16:37:56 2021 daemon.notice netifd: wan (5210): udhcpc: sending renew to a.a.a.a
Mon Apr 5 16:45:26 2021 daemon.notice netifd: wan (5210): udhcpc: sending renew to a.a.a.a
Mon Apr 5 16:49:11 2021 daemon.notice netifd: wan (5210): udhcpc: sending renew to a.a.a.a
Mon Apr 5 16:51:03 2021 daemon.notice netifd: wan (5210): udhcpc: sending renew to a.a.a.a
Mon Apr 5 16:51:59 2021 daemon.notice netifd: wan (5210): udhcpc: sending renew to 0.0.0.0
Mon Apr 5 16:51:59 2021 daemon.notice netifd: wan (5210): udhcpc: lease of b.b.b.b obtained, lease time 7200
Mon Apr 5 16:53:44 2021 daemon.notice openvpn(vpnclient)[5517]: TLS: tls_process: killed expiring key
Mon Apr 5 16:53:44 2021 daemon.notice openvpn(vpnclient)[5517]: VERIFY OK: depth=2, C=PA, O=VPNProvider, CN=VPNProvider Root CA
Mon Apr 5 16:53:44 2021 daemon.notice openvpn(vpnclient)[5517]: VERIFY OK: depth=1, C=PA, O=VPNProvider, CN=VPNProvider CA5
Mon Apr 5 16:53:44 2021 daemon.notice openvpn(vpnclient)[5517]: VERIFY KU OK
Mon Apr 5 16:53:44 2021 daemon.notice openvpn(vpnclient)[5517]: Validating certificate extended key usage
Thanks, I wonder which tcpdump spell I could use to check if these DHCP UDP packets are actually dropped in this scenario.
Also I would like to understand "sending renew to a.a.a.a" requests although those are not probably related to this problem. It feels that my ISP does not respond to these requests but udhcpc still sends those anyway. And should the configuration flag "Use broadcast flag" on wan interface change this behavior some way because it doesn't seem to do anything?
If I understand correct dhclient which I could try is an alternative to udhcpc but can I use it instead on OpenWRT or am I stuck with udhcpc?
Probably none, if we assume the packets are dropped between you and the ISP - after they've passed tcpdump.
You can see they're going out, but there's no reply.
No banIP (don't even know what it is). Should I use wan interface for tcpdump or tun0 instead? But I'm pretty sure what I see in my current dump is correct.
Also I'm thinking could this be firewall problem since I don't have "default setup", but then again this does not happen when there's no full download.
I tested tcpdump for wan interface but can't spot any differences or problems. What puzzles me is that why so many broadcasts even if each one gets reply properly
Most likely it doesn't get the reply, hence the continuous retries. You'd have to disable one thing at a time, like vpn, firewall, downloads, until you find the culprit.
Check whether the issue persists if you disable the default gateway redirection.
Instead, route the LAN client traffic to the VPN tunnel using the PBR app.
But there is no reply visible for this request in tcpdump, maybe because of firewall rules? Should there be reply and should I make some rule to allow this somehow?
"udhcpc: sending renew to 0.0.0.0" is visible only for tcpdump -i eth1 not for -i tun0 and reply is visible, maybe because reply is allowed as firewall rule?
Also fo tcpdump -evn -i eth1 udp port 67 or 68 I get
2 packets captured
150 packets received by filter
44 packets dropped by kernel