Hotplug/iface script gets not executed on boot up

[anon50098793]

uci show system | grep ntp
netstat -lnp | grep ntp

[Michael.Uray]

root@OpenWrt-R5:~# uci show system | grep ntp
system.ntp=timeserver
system.ntp.enabled='1'
system.ntp.enable_server='0'
system.ntp.server='0.openwrt.pool.ntp.org' '1.openwrt.pool.ntp.org' '2.openwrt.pool.ntp.org' '3.openwrt.pool.ntp.org'

root@OpenWrt-R5:~# netstat -lnp | grep ntp

root@OpenWrt-R5:~# ./pstree.sh
1 /sbin/procd
|- 1811 /sbin/ubusd
|- 1812 /sbin/askfirst /usr/libexec/login.sh
|- 1813 /bin/ash --login
|- 2041 /sbin/logd -S 64
|- 2072 /sbin/rpcd -s /var/run/ubus.sock -t 30
|- 2135 /usr/sbin/dnsmasq -C /var/etc/dnsmasq.conf.cfg01411c -k -x /var/run/dnsmasq/dnsmasq.cfg01411c.pid
|- 2168 /usr/sbin/dropbear -F -P /var/run/dropbear.1.pid -p 22 -K 300 -T 3
|   |- 2599 /usr/sbin/dropbear -F -P /var/run/dropbear.1.pid -p 22 -K 300 -T 3
|   |   L- 2600 -bash
|   L- 2715 /usr/sbin/dropbear -F -P /var/run/dropbear.1.pid -p 22 -K 300 -T 3
|       L- 2716 -bash
|           L- 2913 /bin/sh ./pstree.sh
|- 2223 /sbin/netifd
|   |- 2478 /bin/sh /sbin/hotplug-call iface
|   |   L- 2518 /bin/sh /sbin/hotplug-call iface
|   |       L- 2526 /usr/sbin/ntpclient -c 1 -p 123 -i 2 -h 0.openwrt.pool.ntp.org
|   L- 2493 udhcpc -p /var/run/udhcpc-br-lan.pid -s /lib/netifd/dhcp.script -f -t 0 -i br-lan -x hostname:OpenWrt-R5 -C -O 121
|- 2260 /usr/sbin/odhcpd
|- 2320 /usr/sbin/uhttpd -f -h /www -r OpenWrt-R5 -x /cgi-bin -t 60 -T 30 -k 20 -A 1 -n 3 -N 100 -R -p 0.0.0.0:80 -p [::]:80
L- 2641 /usr/sbin/ntpd -n -N -S /usr/sbin/ntpd-hotplug -p 0.openwrt.pool.ntp.org -p 1.openwrt.pool.ntp.org -p 2.openwrt.pool.ntp.org -p 3.openwrt.pool.ntp.org

root@OpenWrt-R5:~# kill 2526
After that it did execute the firewall hotplug script,

[  249.441107] sbin-hotplugcall-122148 iface
[  249.456593] sbin-hotplugcall-122148 firewall
[  249.458356] sbin-hotplugcall-122148 firewall NODIR-/etc/hotplug.d/firewall

but this does not happen all the time I run the kill command.

root@OpenWrt-R5:~# ./pstree.sh
1 /sbin/procd
|- 1811 /sbin/ubusd
|- 1812 /sbin/askfirst /usr/libexec/login.sh
|- 1813 /bin/ash --login
|- 2041 /sbin/logd -S 64
|- 2072 /sbin/rpcd -s /var/run/ubus.sock -t 30
|- 2135 /usr/sbin/dnsmasq -C /var/etc/dnsmasq.conf.cfg01411c -k -x /var/run/dnsmasq/dnsmasq.cfg01411c.pid
|- 2168 /usr/sbin/dropbear -F -P /var/run/dropbear.1.pid -p 22 -K 300 -T 3
|   |- 2599 /usr/sbin/dropbear -F -P /var/run/dropbear.1.pid -p 22 -K 300 -T 3
|   |   L- 2600 -bash
|   L- 2715 /usr/sbin/dropbear -F -P /var/run/dropbear.1.pid -p 22 -K 300 -T 3
|       L- 2716 -bash
|           L- 3308 /bin/sh ./pstree.sh
|- 2223 /sbin/netifd
|   L- 2493 udhcpc -p /var/run/udhcpc-br-lan.pid -s /lib/netifd/dhcp.script -f -t 0 -i br-lan -x hostname:OpenWrt-R5 -C -O 121
|- 2260 /usr/sbin/odhcpd
|- 2320 /usr/sbin/uhttpd -f -h /www -r OpenWrt-R5 -x /cgi-bin -t 60 -T 30 -k 20 -A 1 -n 3 -N 100 -R -p 0.0.0.0:80 -p [::]:80
|- 2641 /usr/sbin/ntpd -n -N -S /usr/sbin/ntpd-hotplug -p 0.openwrt.pool.ntp.org -p 1.openwrt.pool.ntp.org -p 2.openwrt.pool.ntp.org -p 3.openwrt.pool.ntp.org
L- 3101 /usr/sbin/ntpclient -i 600 -s -l -D -p 123 -h 1.openwrt.pool.ntp.org

After I have killed all the ntpclients

root@OpenWrt-R5:~# netstat -lnp | grep ntp
udp        0      0 0.0.0.0:49476           0.0.0.0:*                           2640/ntpd

root@OpenWrt-R5:~# /usr/sbin/ntpclient -c 1 -p 123 -i 2 -h 0.openwrt.pool.ntp.org
44013 45069.716   11032.0     66.1    3724.2  24566.7         0

root@OpenWrt-R5:~# /usr/sbin/ntpclient -c 1 -p 123 -i 2 -h 0.openwrt.pool.ntp.org
The second call hangs, I have to cancel it via Ctl+c.
If I call it a couple times in a row, then it stucks and this is probably what happens in the hotplug script and what causes the issue.

In general, for what is the ntpclient actually required?
So far as I have seen has the OpenWRT system 19.07.3 an ntp client already included.
I did setup my router with a setup script created a couple years ago, maybe was ntp not included in older versions of OpenWRT and this is the reason why the script installs ntpclient?
It does not help to set system.ntp.enabled='0', means it is not a problem to run both at the same time. Even if I kill all ntp processes and if I start a couple ntpclient commands in a row, then it stucks.

So what is then wrong with the ntpclient command that causes it to stuck?

[fantom-x]

@Michael.Uray

So what is then wrong with the ntpclient command that causes it to stuck?

Are you using DoT or DoH for DNS?

[fantom-x]

@Michael.Uray

In general, for what is the ntpclient actually required?

I am sure you can google it, but I do not have it on my router and never needed. It is not needed to keep the router system time in sync.

[Michael.Uray]

@fantom-x

Are you using DoT or DoH for DNS?

Not that I am aware of, I just installed a fresh OpenWRT system and changed its LAN interface to DHCP. After that I installed the ntpclient and the problem occurred.

[fantom-x]

opkg list-installed | grep ntp returned nothing on my router. It is up to you to decide if you need the ntpclient, which seems to be super old.

ntpclient - 2015_365-2 - NTP client for setting system time from NTP servers

The default ntpd from busybox seems to be doing the job for me:

ls -la /usr/sbin/ntpd /usr/sbin/ntpd-hotplug
lrwxrwxrwx    1 root     root            17 Jul  1 11:07 /usr/sbin/ntpd -> ../../bin/busybox
-rwxr-xr-x    1 root     root            45 Jun 28 08:37 /usr/sbin/ntpd-hotplug

[jow]

The ntpclient hotplug script will block all subsequent scripts until the initial NTP client sync completed. Possibly there's a also a bug in this script and the ntpclient process never returns or only times out way later. Arguably that is a bug that should be adressed in the ntpclient package itself. Maybe it does not cope well with missing default routes - could be that it requires a very long time to time out.

To workaround the problem, you can prefix your 99-netmap script with something <= 20 to ensure it runs before the ntpclient hotplug. Even 20-netmap will do since 20-ne < 20-nt.

[Michael.Uray]

I will remove ntpclient on my routers since it is not required anymore to sync the time.

Just wondering if ntpclient should get removed from OpenWRT in general since it is not required and it could cause problems to other users as well.
To not run some hotplug scripts like firewall might cause security issues.

[Michael.Uray]

@jow

Even 20-netmap will do since 20-ne < 20-nt .

Shouldn't it run then also 20-firewall before 20-ntpclient?

[jow]

Yes, it should.

[Michael.Uray]

I don't think that it executes the 20-firewall script if the 20-ntpclient script stucks.

It does not create the according log entries "Reloading firewall" by 20-firewall in this situation.

Hotplug/iface script gets not executed on boot up

Thanks, I will have a look on this. Independent from that, that there is be a better solution to do my netmap, why is this iface event not called reliably? Hotplug scripts which get not executed during the boot could cause other problems as well. For example gets the firewall script also not called in this situation. root@test-r1:~# logread | grep "Reloading firewall" No log entry for the firewall (created by /etc/hotplug.d/iface/20-firewall) if this happens with the not-executed scripts d…

[jow]

My assumption would be that 20-firewall runs once only, for the first iface being started (likely loopback), then ntpclient gets stuck and is blocking all remaining scripts and all further iface hotplug events. When the ntpclient instances are killed, the next iface hotplug events continue being processed.

OpenWrt's hotplug daemon queues iface hotplug events and processes them in a single-threaded manner, one after another. The hotplug daemon eventually invokes /sbin/hotplug-call to dispatch events to user hotplug scripts which in turn sources the scripts in /etc/hotplug.d/$eventclass/ sequentially. As long as /sbin/hotplug-call does not return (due to 20-ntpclient being stuck), the hotplug service will not continue processing the next iface hotplug event for the next interface.

[Michael.Uray]

@jow

My assumption would be that 20-firewall runs once only, for the first iface being started (likely loopback), then ntpclient gets stuck and is blocking all remaining scripts and all further iface hotplug events. When the ntpclient instances are killed, the next iface hotplug events continue being processed.

That's exactly how it behaves.

[    9.192474] IPv6: ADDRCONF(NETDEV_UP): br-lan: link is not ready
[    9.200716] sbin-hotplugcall-150748 iface
[    9.206993] hotplug.d/iface/20-firewall: ifup loopback
[    9.210345] hotplug.d/iface/20-ntpclient: ifup loopback
[    9.790034] IPv6: ADDRCONF(NETDEV_CHANGE): br-lan: link becomes ready

And then it stucks until the ntpclient process gets killed.

@jow

OpenWrt's hotplug daemon queues iface hotplug events and processes them in a single-threaded manner, one after another.

Does this actually mean that hotplug scripts cannot have multiple instances called at the same time as it was mentioned above?

@fantom-x

Wrong. Your script is invoked one per each interface in the fire and forget non-blocking mode, so the kernel does not wait until scripts finish and keep on setting up interfaces. So, yes the script is absolutely running many instances.

[fantom-x]

@Michael.Uray

Does this actually mean that hotplug scripts cannot have multiple instances called at the same time as it was mentioned above?

@fantom-x

Wrong. Your script is invoked one per each interface in the fire and forget non-blocking mode, so the kernel does not wait until scripts finish and keep on setting up interfaces. So, yes the script is absolutely running many instances.

It seems I was wrong there. I observed them running concurrently, but I never looked into the code.

[jow]

@Michael.Uray

Does this actually mean that hotplug scripts cannot have multiple instances called at the same time as it was mentioned above?

It cannot be ruled out entirely, but in general, /etc/hotplug.d/XXX/ scripts are only invoked by /sbin/hotplug-call which in turn is only invoked by procd's hotplug service which in turn queues all execution events to process them linearely. However some hotplug event classes are synthesized by user space (e.g. the dhcp or neigh ones). In these cases, it is usually a daemon processes that is invoking /sbin/hotplug-call and then there is no guarantee that multiple hotplug-call processes aren't run concurrently.

[Michael.Uray]

@jow

Arguably that is a bug that should be adressed in the ntpclient package itself.

Just opened a ticket there.

ntpclient: stucks after a couple calls in a row, causes hotplug script to stuck, other hotplug scripts are not called anymore

[Michael.Uray]

@fantom-x

I observed them running concurrently

Have you actually seen this on the iface hotplug scripts, or was that on scripts from any other section?
Just curious how this all works together.

[fantom-x]

I just took a look at my scripts and they are using ( )& to do the work, which makes the commands run in the background. My script is invoked many times and it is possible that the concurrent executions that I saw was not the hotplug, but my commands running in the background and detached from the hoplug context.

[Michael.Uray]

Thank you very much guys for your help to figure this out, as well as to help me to understand how this all this works together.