UDM-PRO 3.1.16: network-online.target and ppp interface

[fdcastel]

Anybody else having problems with ppp interfaces being up only AFTER on-boot-scripts run?

2023-09-25T07:57:06-03:00 UDM-Pro inadyn[1973]: In-a-dyn version 2.9.1 -- Dynamic DNS update client.
2023-09-25T07:57:06-03:00 UDM-Pro inadyn[1973]: Guessing DDNS plugin '[email protected]' from 'cloudflare'
2023-09-25T07:57:06-03:00 UDM-Pro inadyn[1973]: Failed connecting to 1.1.1.1: Network is unreachable
2023-09-25T07:57:06-03:00 UDM-Pro inadyn[1973]: Communication with checkip server 1.1.1.1 failed, run again with 'inadyn -l debug' if problem persists
2023-09-25T07:57:06-03:00 UDM-Pro inadyn[1973]: Retrying with built-in 'default', api.ipify.org ...
2023-09-25T07:57:06-03:00 UDM-Pro inadyn[1973]: Failed resolving hostname api.ipify.org: Temporary failure in name resolution

2023-09-25T07:57:07-03:00 UDM-Pro pppd[1307]: PPP session is 1
2023-09-25T07:57:07-03:00 UDM-Pro pppd[1307]: Connected to xx:xx:xx:xx:xx:xx via interface eth8
2023-09-25T07:57:07-03:00 UDM-Pro pppd[1307]: Using interface ppp0
2023-09-25T07:57:07-03:00 UDM-Pro pppd[1307]: Connect: ppp0 <--> eth8
2023-09-25T07:57:08-03:00 UDM-Pro ubios-udapi-server[1174]: svc-unifi-network: Failed to read status from /run/system.controller.state: Unknown status value:
2023-09-25T07:57:10-03:00 UDM-Pro pppd[1307]: Remote message: Login ok
2023-09-25T07:57:10-03:00 UDM-Pro pppd[1307]: PAP authentication succeeded
2023-09-25T07:57:10-03:00 UDM-Pro pppd[1307]: peer from calling number xx:xx:xx:xx:xx:xx authorized
2023-09-25T07:57:10-03:00 UDM-Pro pppd[1307]: Unsupported protocol 'IPv6 Control Protocol' (0x8057) received
2023-09-25T07:57:10-03:00 UDM-Pro pppd[1307]: Unsupported protocol 'IPv6 Control Protocol' (0x8057) received
2023-09-25T07:57:10-03:00 UDM-Pro pppd[1307]: local  IP address XXX.XXX.10.61
2023-09-25T07:57:10-03:00 UDM-Pro pppd[1307]: remote IP address XXX.XXX.126.59
2023-09-25T07:57:10-03:00 UDM-Pro pppd[1307]: primary   DNS address YYY.YYY.250.115
2023-09-25T07:57:10-03:00 UDM-Pro pppd[1307]: secondary DNS address YYY.YYY.250.215

2023-09-25T07:57:10-03:00 UDM-Pro ubios-udapi-server[1174]: wan-failover-interfaces: wf-interface-ppp0 (XXX.XXX.10.61) is unknown [_---___](~down~)
2023-09-25T07:57:16-03:00 UDM-Pro ubios-udapi-server[1174]: wan-failover-monitor-icmp: wf-monitor-ppp0-2-icmp (XXX.XXX.10.61->1.1.1.1) has dpinger update: 1.1.1.1 is up {"alarm":false,"id":"ppp0-mon2-1.1.1.1-ping.ui.com","latencyAverage":1120.0,"latencyStdDev":4884.0,"lossPercentage":0.0}
2023-09-25T07:57:16-03:00 UDM-Pro ubios-udapi-server[1174]: wan-failover-interfaces: wf-interface-ppp0 (XXX.XXX.10.61) is up [_U--___]
2023-09-25T07:57:16-03:00 UDM-Pro ubios-udapi-server[1174]: wan-failover-monitor-icmp: wf-monitor-ppp0-2-icmp (XXX.XXX.10.61->8.8.8.8) has dpinger update: 8.8.8.8 is up {"alarm":false,"id":"ppp0-mon2-8.8.8.8-ping.ui.com","latencyAverage":1160.0,"latencyStdDev":5056.0,"lossPercentage":0.0}
2023-09-25T07:57:17-03:00 UDM-Pro ubios-udapi-server[1174]: wan-failover-group-base: wf-group-1-single is up [u](ppp0)
2023-09-25T07:57:18-03:00 UDM-Pro linkcheck[657]: linkcheck[657]: linkcheck.update(): /etc/resolv.conf appears to have changed
2023-09-25T07:57:20-03:00 UDM-Pro ubios-udapi-server[1174]: wan-failover-monitor-dns: wf-monitor-ppp0-3-dns (XXX.XXX.10.61->1.1.1.1) has dns-monitor update: 1.1.1.1:ui.com is up
2023-09-25T07:57:20-03:00 UDM-Pro ubios-udapi-server[1174]: wan-failover-monitor-dns: wf-monitor-ppp0-4-dns (XXX.XXX.10.61->8.8.8.8) has dns-monitor update: 8.8.8.8:ui.com is up

In the above syslog, inadyn[1973] was started by a custom on-boot-script at 2023-09-25T07:57:06.

However, it also shows that ppp interface was marked up only at 2023-09-25T07:57:17

The /lib/systemd/system/udm-boot.service contains the lines

[Unit]
Description=Run On Startup UDM 3.x
Wants=network-online.target
After=network-online.target
(...)

But it appears this is not enough according to this doc.

Please note that network-online.target means that the network connectivity has been reached, not that it is currently available.

[fdcastel]

For the record: the workaround for now was (of course) to add a first script to wait 30 seconds before others.

SCRIPT_FILE=/data/on_boot.d/00-wait-for-udm-startup.sh
cat > $SCRIPT_FILE <<EOF
#!/bin/sh

# PPP interface is up ~12 seconds after on_boot_scripts run. Wait 30 seconds for safety.
sleep 30
EOF
chmod +x $SCRIPT_FILE

Not proud 🥲. But works.