Hotplug/iface script gets not executed on boot up

Michael.Uray · June 20, 2020, 1:03pm

I have a iface hotplug script running in a VMware (OpenWrt 19.07.3), which gets not triggered on a reboot when the interface comes up, but it gets triggered on a network restart.

/etc/hotplug.d/iface/99-netmap

#!/bin/sh
echo $ACTION $INTERFACE >> /tmp/if_dbg

/etc/config/network

config interface 'lan'
        option type 'bridge'
        option ifname 'eth0'
        option proto 'dhcp'
...

After a reboot br-lan is available and already got an IP address via DHCP.

root@test-r1:~# ifconfig
br-lan    Link encap:Ethernet  HWaddr 00:0C:29:3B:DE:43
          inet addr:192.168.90.157  Bcast:192.168.90.255  Mask:255.255.255.0
          inet6 addr: fe80::20c:29ff:fe3b:de43/64 Scope:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:581 errors:0 dropped:0 overruns:0 frame:0
          TX packets:121 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:228129 (222.7 KiB)  TX bytes:20981 (20.4 KiB)

eth0      Link encap:Ethernet  HWaddr 00:0C:29:3B:DE:43
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:4863 errors:0 dropped:2 overruns:0 frame:0
          TX packets:121 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:1205914 (1.1 MiB)  TX bytes:20981 (20.4 KiB)
          Interrupt:19 Base address:0x2000

lo        Link encap:Local Loopback
          inet addr:127.0.0.1  Mask:255.0.0.0
          inet6 addr: ::1/128 Scope:Host
          UP LOOPBACK RUNNING  MTU:65536  Metric:1
          RX packets:24 errors:0 dropped:0 overruns:0 frame:0
          TX packets:24 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:2112 (2.0 KiB)  TX bytes:2112 (2.0 KiB)

tun1      Link encap:UNSPEC  HWaddr 00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00
          inet addr:10.102.0.11  P-t-P:10.102.0.11  Mask:255.255.0.0
          inet6 addr: fe80::21b4:75c2:45fe:948b/64 Scope:Link
          UP POINTOPOINT RUNNING NOARP MULTICAST  MTU:1500  Metric:1
          RX packets:0 errors:0 dropped:0 overruns:0 frame:0
          TX packets:4 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:100
          RX bytes:0 (0.0 B)  TX bytes:304 (304.0 B)

But the file if_dbg from 99-netmap gets not created during the boot, means to me that the script gets not executed.

root@test-r1:~# ls /tmp/if_dbg
ls: /tmp/if_dbg: No such file or directory

If I run a network restart, then the 99-netmap iface hotplug script gets executed properly.
root@test-r1:~# /etc/init.d/network restart

Debug file exists after network restart.

root@test-r1:~# ls /tmp/if_dbg
/tmp/if_dbg

Somtimes it gets only partially called by some IFs during the boot:

root@test-r1:~# cat /tmp/if_dbg
ifup loopback
ifdown wan_3g

root@test-r1:~# /etc/init.d/network restart

root@test-r1:~# cat /tmp/if_dbg
ifup loopback
ifdown wan_3g
ifup loopback
ifdown wan_3g
ifup lan
ifup lan

Why is my hotplug script 99-netmap not called (or only partially) during the boot process when the lan interface is coming up?

anon50098793 · June 20, 2020, 1:25pm

send your output > /dev/kmesg to exclude async fs timing issue

Michael.Uray · June 20, 2020, 3:05pm

You mean change

echo $ACTION $INTERFACE >> /tmp/if_dbg

to

echo $ACTION $INTERFACE >> /dev/kmsg

in /etc/hotplug.d/iface/99-netmap ?

There is often no file created in /tmp/if_dbg after a reboot.

anon50098793 · June 20, 2020, 3:07pm

that should work... check 'dmesg' to see results... ( you can leave the other line too if you want to compare )

fantom-x · June 20, 2020, 3:21pm

@Michael.Uray I had the same issue and in the absence of docs, I am not sure if that is a bug or desired behaviour. There are two hot plug locations: iface and net. I experimentally found out that a virtual interface like PPPoE only triggers iface scripts, while wireless interfaces are triggering net scripts.
I suggest you put a script in both locations, output the invocations and env, and then decide which one works for you better.

UPDATE. Well, there are some docs (https://openwrt.org/docs/guide-user/base-system/hotplug), but the page does not explain what I saw.

Michael.Uray · June 20, 2020, 3:28pm

As soon as I add echo $ACTION $INTERFACE >> /dev/kmsg to the hotplug script the problem disapears.
I did reboot 4 times to verify, it runs every time the ifup for lan without any problems.

Michael.Uray · June 20, 2020, 4:19pm

Why does it have an influence on the ifup lan event if I write to /dev/kmsg via the hotplug script 99-netmap which gets executed by this event?

Michael.Uray · June 20, 2020, 5:06pm

It seems that the hotplug script in net gets called during the reboot without problems.

After reboot:

root@test-r1:~# cat /tmp/if_dbg
hotplug/net add gre0
hotplug/net add gretap0
hotplug/net add erspan0
hotplug/net add eth0
hotplug/net add br-lan
hotplug/net add tun1

root@test-r1:~# /etc/init.d/network restart

root@test-r1:~# cat /tmp/if_dbg
hotplug/net remove br-lan
hotplug/net add br-lan
hotplug/iface: ifup loopback
hotplug/iface: ifdown wan_3g
hotplug/iface: ifup lan
hotplug/iface: ifup loopback

It looks as if net works more reliable, but I am still wondering why this happens to iface and especially why it has an influence to write to /dev/kmsg within the houtplug script.

fantom-x · June 20, 2020, 5:18pm

My experience was consistent, so I suspect that is normal behaviour, but I could not find a good explanation that details the conditions for these two groups of scripts.

Michael.Uray · June 20, 2020, 5:18pm

Seems to me as if it is random if iface gets called during the boot.

root@test-r1:~# reboot

root@test-r1:~# cat /tmp/if_dbg
hotplug/net add gre0
hotplug/net add gretap0
hotplug/net add erspan0
hotplug/net add eth0
hotplug/net add br-lan
hotplug/iface: ifup loopback
hotplug/iface: ifdown wan_3g
hotplug/iface: ifup lan
hotplug/net add tun1

root@test-r1:~# reboot

root@test-r1:~# cat /tmp/if_dbg
hotplug/net add gre0
hotplug/net add gretap0
hotplug/net add erspan0
hotplug/net add eth0
hotplug/net add br-lan
hotplug/net add tun1

root@test-r1:~# reboot

root@test-r1:~# cat /tmp/if_dbg
hotplug/net add gre0
hotplug/net add gretap0
hotplug/net add erspan0
hotplug/net add eth0
hotplug/net add br-lan
hotplug/iface: ifup loopback
hotplug/iface: ifdown wan_3g
hotplug/net add tun1

I don't think that this behaviour is wanted. I guess the hotplug script should get executed in every situation.

fantom-x · June 20, 2020, 5:19pm

You may be seeing concurrency issues. Add locking to your scripts (make sure flock is installed) to guarantee execution of one script at a time:

exec 511>/var/lock/etc-hotplug.d-net-my-script.lock
flock 511 || (echo "Failed to obtain a lock" ; exit 1)

Add the above BEFORE the redirect to a file.

fantom-x · June 20, 2020, 5:21pm

Questionable until you figure out the differences between iface and net events. I could not find anything concrete short of having to read the code.

fantom-x · June 20, 2020, 5:30pm

By writing to that device you slow down your scripts and maybe also serializing the invocations. One more proof of concurrency issues when multiple scripts write into the same file and overwriting each other's output.

Michael.Uray · June 20, 2020, 5:33pm

It actually only can slow down the script if executes the script, but it only executes the script for sure if I add this line to the script and this is what I don't understand.

anon50098793 · June 20, 2020, 5:34pm

false assumption

Michael.Uray · June 20, 2020, 5:36pm

Please explain.

fantom-x · June 20, 2020, 5:36pm

I already explained. The hot plug scripts are non-blocking and you can have many of them writing to a file. /dev/kmsg is not a regular file, so it must not be allowing message overwrites.

fantom-x · June 20, 2020, 5:38pm

Use my flock example and write into /tmp/log.txt. You will likely see all the invocations of your scripts in a proper order there, because flock will not allow for parallel writes.

UPDATE: it is a false assumption, because you assume that a missing log entry is a sign of the scripts not being run. That is incorrect on a concurrent system.

Michael.Uray · June 20, 2020, 5:48pm

Ok, I understand if multiple writes happen to /dev/kmsg at the same time then a write could fail, but there cannot happen multiple writes to /tmp/if_dbg since I use this file only for debugging this script.

I actually started adding these debug lines because my iptables commands did not get execute during every boot process.

#!/bin/sh

echo hotplug/iface: $ACTION $INTERFACE >> /tmp/if_dbg
#echo hotplug/iface: $ACTION $INTERFACE >> /dev/kmsg

if [ "$ACTION" = "ifup" -a "$INTERFACE" = "lan" ]; then

        network0=`ubus call network.interface.lan status | grep \"address\" | grep -oE '[0-9]{1,3}\.[0-9]{1,3}\.[0-9]{1,3}\.';`
        network="$network0""0/24"

        iptables -t nat -A PREROUTING -d 10.1.223.0/24 -i tun1 -j NETMAP --to $network
        iptables -t nat -A POSTROUTING -s $network -o tun1 -j NETMAP --to 10.1.223.0/24

        echo $ACTION $INTERFACE >> /tmp/lan_up_dbg
        date +"%T" >> /tmp/lan_up_dbg
        echo iptables -t nat -A PREROUTING -d 10.1.223.0/24 -i tun1 -j NETMAP --to $network >> /tmp/lan_up_dbg
        echo iptables -t nat -A POSTROUTING -s $network -o tun1 -j NETMAP --to 10.1.223.0/24 >> /tmp/lan_up_dbg

        echo "#!/bin/sh" > /tmp/lan_down
        echo iptables -t nat -D PREROUTING -d 10.1.223.0/24 -i tun1 -j NETMAP --to $network >> /tmp/lan_down
        echo iptables -t nat -D POSTROUTING -s $network -o tun1 -j NETMAP --to 10.1.223.0/24 >> /tmp/lan_down
        chmod +x /tmp/lan_down
fi

if [ "$ACTION" = "ifdown" -a "$INTERFACE" = "lan" ]; then

        echo $ACTION $INTERFACE >> /tmp/lan_up_dbg
        date +"%T" >> /tmp/lan_up_dbg

        /tmp/lan_down
        rm /tmp/lan_down
fi

anon50098793 · June 20, 2020, 5:53pm

i would assume the opposite...

your iptables stuff is definately better in /net/...