Why are if-up.d scripts running before DHCP is done?

[DanTup]

I'm using DHCP and have both IPv4 and IPv6. I want to run a script that updates an IPv6 DDNS service when my network is configured.

I created a script at /etc/network/if-up.d/update_dns however this script fails with a DNS resolution error ("curl: (6) Could not resolve host: dynv6.com"). The logs seem to show it's running before the IPv6 DHCP is finished. I think maybe this is because IPv4 is ready and the scripts fire.

Is there somewhere else I should put scripts that require IPv6? There are many answers that suggest if-up.d is the correct place?

I'm using Raspbian Jessie Lite, which already has the Slow Boot (a script at /etc/systemd/system/dhcpcd.service.d/wait.conf that waits for DHCP) which fixed similar issues previously with things running before the network was ready.

I've included logs of anything including network/dhcp/eth0 below.

Apr 6 20:49:58 raspberrypi systemd[1]: Starting LSB: Raise network interfaces....
Apr 6 20:49:58 raspberrypi networking[223]: Configuring network interfaces...* Hostname was NOT found in DNS cache
Apr 6 20:49:58 raspberrypi networking[223]: % Total % Received % Xferd Average Speed Time Time Time Current
Apr 6 20:49:58 raspberrypi networking[223]: Dload Upload Total Spent Left Speed
Apr 6 20:49:58 raspberrypi networking[223]: 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0* Could not resolve host: dynv6.com
Apr 6 20:49:58 raspberrypi networking[223]: * Closing connection 0
Apr 6 20:49:58 raspberrypi networking[223]: curl: (6) Could not resolve host: dynv6.com
Apr 6 20:49:58 raspberrypi networking[223]: done.
Apr 6 20:49:58 raspberrypi systemd[1]: Started LSB: Raise network interfaces..
Apr 6 20:49:58 raspberrypi systemd[1]: Starting dhcpcd on all interfaces...
Apr 6 20:49:58 raspberrypi dhcpcd[385]: version 6.7.1 starting
Apr 6 20:49:58 raspberrypi dhcpcd[385]: dev: loaded udev
Apr 6 20:49:58 raspberrypi dhcpcd[385]: eth0: adding address fe80::1073:c87:ef15:c4a3
Apr 6 20:49:58 raspberrypi dhcpcd[385]: eth0: waiting for carrier
Apr 6 20:49:58 raspberrypi dhcpcd[385]: wlan0: waiting for carrier
Apr 6 20:50:00 raspberrypi dhcpcd[385]: eth0: carrier acquired
Apr 6 20:50:00 raspberrypi dhcpcd[385]: DUID 00:01:00:01:1e:7e:75:f4:b8:27:eb:8c:48:b0
Apr 6 20:50:00 raspberrypi dhcpcd[385]: eth0: IAID eb:8c:48:b0
Apr 6 20:50:01 raspberrypi dhcpcd[385]: eth0: rebinding lease of 192.168.0.100
Apr 6 20:50:01 raspberrypi dhcpcd[385]: eth0: soliciting an IPv6 router
Apr 6 20:50:02 raspberrypi dhcpcd[385]: eth0: Router Advertisement from fe80::c23e:fff:fe63:5170
Apr 6 20:50:02 raspberrypi dhcpcd[385]: eth0: adding address fd41:6d80:6364:0:bcdf:ae43:354b:1e46/64
Apr 6 20:50:02 raspberrypi dhcpcd[385]: eth0: adding address 2a02:c7d:2bbb:9f00:76b3:47f9:2c11:fea4/64
Apr 6 20:50:02 raspberrypi dhcpcd[385]: eth0: adding route to fd41:6d80:6364::/64
Apr 6 20:50:02 raspberrypi dhcpcd[385]: eth0: adding route to 2a02:c7d:2bbb:9f00::/64
Apr 6 20:50:02 raspberrypi dhcpcd[385]: eth0: adding default route via fe80::c23e:fff:fe63:5170
Apr 6 20:50:02 raspberrypi dhcpcd[385]: eth0: requesting DHCPv6 information
Apr 6 20:50:06 raspberrypi dhcpcd[385]: eth0: leased 192.168.0.100 for 86400 seconds
Apr 6 20:50:06 raspberrypi dhcpcd[385]: eth0: adding route to 192.168.0.0/24
Apr 6 20:50:06 raspberrypi dhcpcd[385]: eth0: adding default route via 192.168.0.1
Apr 6 20:50:06 raspberrypi dhcpcd[385]: forked to background, child pid 716
Apr 6 20:50:06 raspberrypi systemd[1]: Started dhcpcd on all interfaces.
Apr 6 20:50:06 raspberrypi ntpd[757]: Listen normally on 3 eth0 192.168.0.100 UDP 123
Apr 6 20:50:06 raspberrypi ntpd[757]: Listen normally on 5 eth0 2a02:c7d:2bbb:9f00:76b3:47f9:2c11:fea4 UDP 123
Apr 6 20:50:06 raspberrypi ntpd[757]: Listen normally on 6 eth0 fe80::1073:c87:ef15:c4a3 UDP 123
Apr 6 20:50:06 raspberrypi ntpd[757]: Listen normally on 8 eth0 fd41:6d80:6364:0:bcdf:ae43:354b:1e46 UDP 123

[ShiftPlusOne]

Yes, ifup runs well before dhcpcd does. You'll want to use dhcpcd hooks instead.

Code: Select all

man dhcpcd-run-hooks
man dhcpcd
cat /lib/dhcpcd/dhcpcd-hooks/01-test

[DanTup]

Thanks; I tried putting a file at /lib/dhcpcd/dhcpcd-hooks/100-ddns and it runs, but the man page says:

System hook scripts are found in /lib/dhcpcd/dhcpcd-hooks and the user defined hooks are /etc/dhcpcd.enter-hook. and /etc/dhcpcd.exit-hook

However I don't have either of those files. I do have a directory at /etc/dhcp/dhclient-exit-hooks.d/ which has a bunch of stuff in, but I put something in there and it doesn't seem to fire at startup!

Where exactly should I be putting my scripts?

[ShiftPlusOne]

I'll give this a go myself and let you know if I have more luck.

[DanTup]

Ok, so I just dumped some logging in a bunch of files, including those you mentioned that didn't already exist. Full logs at end of this post

It's hard (for me!) to tell exactly when DHCPv6 is complete and the DNS would work, but I'm going to guess it's about when this line occurs:

Code: Select all

Apr  7 17:05:30 raspberrypi avahi-daemon[413]: Registering new address record

If so, that means there are 4 events in the scripts I created:

Code: Select all

Apr  7 17:05:30 raspberrypi logger: DANNY running /lib/dhcpcd/dhcpcd-hooks/100-dns (ROUTERADVERT)
Apr  7 17:05:30 raspberrypi logger: DANNY running /etc/dhcpcd.exit-hook (ROUTERADVERT)
Apr  7 17:05:37 raspberrypi logger: DANNY running /lib/dhcpcd/dhcpcd-hooks/100-dns (REBOOT)
Apr  7 17:05:37 raspberrypi logger: DANNY running /etc/dhcpcd.exit-hook (REBOOT)

It's not clear if these events are triggered by DHCPv4 or DHCPv6 (I presume they're separate?), but also neither of event (RouterAdvert and Reboot) seems like an "IP address assigned"? I was hoping for an event that I could be sure happened whenever the IP was assigned by DHCP6, including both boot, and it it gets changed/expires/renews/whatever (it's to run a dynamic dns update).

Any suggestions on the best place for it?



FULL LOGS: cat /var/log/syslog | grep 'dhcp\|DANNY\|eth0'

Code: Select all

Apr  7 17:05:25 raspberrypi systemd[1]: Starting dhcpcd on all interfaces...
Apr  7 17:05:25 raspberrypi dhcpcd[408]: version 6.7.1 starting
Apr  7 17:05:25 raspberrypi dhcpcd[408]: dev: loaded udev
Apr  7 17:05:25 raspberrypi dhcpcd[408]: eth0: adding address fe80::1073:c87:ef15:c4a3
Apr  7 17:05:25 raspberrypi logger: DANNY running /lib/dhcpcd/dhcpcd-hooks/100-dns (PREINIT)
Apr  7 17:05:25 raspberrypi logger: DANNY running /etc/dhcpcd.exit-hook (PREINIT)
Apr  7 17:05:25 raspberrypi logger: DANNY running /lib/dhcpcd/dhcpcd-hooks/100-dns (NOCARRIER)
Apr  7 17:05:25 raspberrypi logger: DANNY running /etc/dhcpcd.exit-hook (NOCARRIER)
Apr  7 17:05:25 raspberrypi logger: DANNY running /lib/dhcpcd/dhcpcd-hooks/100-dns (PREINIT)
Apr  7 17:05:25 raspberrypi logger: DANNY running /etc/dhcpcd.exit-hook (PREINIT)
Apr  7 17:05:25 raspberrypi logger: DANNY running /lib/dhcpcd/dhcpcd-hooks/100-dns (NOCARRIER)
Apr  7 17:05:25 raspberrypi logger: DANNY running /etc/dhcpcd.exit-hook (NOCARRIER)
Apr  7 17:05:25 raspberrypi avahi-daemon[413]: Joining mDNS multicast group on interface eth0.IPv6 with address fe80::1073:c87:ef15:c4a3.
Apr  7 17:05:25 raspberrypi avahi-daemon[413]: New relevant interface eth0.IPv6 for mDNS.
Apr  7 17:05:25 raspberrypi avahi-daemon[413]: Registering new address record for fe80::1073:c87:ef15:c4a3 on eth0.*.
Apr  7 17:05:25 raspberrypi dhcpcd[408]: eth0: waiting for carrier
Apr  7 17:05:25 raspberrypi dhcpcd[408]: wlan0: waiting for carrier
Apr  7 17:05:25 raspberrypi kernel: [    9.300745] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
Apr  7 17:05:25 raspberrypi kernel: [    9.301202] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
Apr  7 17:05:27 raspberrypi kernel: [   10.903449] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Apr  7 17:05:27 raspberrypi kernel: [   10.904384] smsc95xx 1-1.1:1.0 eth0: link up, 100Mbps, full-duplex, lpa 0x49E1
Apr  7 17:05:27 raspberrypi dhcpcd[408]: eth0: carrier acquired
Apr  7 17:05:27 raspberrypi logger: DANNY running /lib/dhcpcd/dhcpcd-hooks/100-dns (CARRIER)
Apr  7 17:05:27 raspberrypi logger: DANNY running /etc/dhcpcd.exit-hook (CARRIER)
Apr  7 17:05:27 raspberrypi dhcpcd[408]: DUID 00:01:00:01:1e:7e:75:f4:b8:27:eb:8c:48:b0
Apr  7 17:05:27 raspberrypi dhcpcd[408]: eth0: IAID eb:8c:48:b0
Apr  7 17:05:27 raspberrypi dhcpcd[408]: eth0: rebinding lease of 192.168.0.100
Apr  7 17:05:28 raspberrypi dhcpcd[408]: eth0: soliciting an IPv6 router
Apr  7 17:05:28 raspberrypi dhcpcd[408]: eth0: Router Advertisement from fe80::c23e:fff:fe63:5170
Apr  7 17:05:28 raspberrypi dhcpcd[408]: eth0: adding address fd41:6d80:6364:0:bcdf:ae43:354b:1e46/64
Apr  7 17:05:28 raspberrypi dhcpcd[408]: eth0: adding address 2a02:c7d:2bbb:9f00:76b3:47f9:2c11:fea4/64
Apr  7 17:05:28 raspberrypi dhcpcd[408]: eth0: adding route to fd41:6d80:6364::/64
Apr  7 17:05:28 raspberrypi dhcpcd[408]: eth0: adding route to 2a02:c7d:2bbb:9f00::/64
Apr  7 17:05:28 raspberrypi dhcpcd[408]: eth0: adding default route via fe80::c23e:fff:fe63:5170
Apr  7 17:05:28 raspberrypi dhcpcd[408]: eth0: requesting DHCPv6 information
Apr  7 17:05:30 raspberrypi avahi-daemon[413]: Leaving mDNS multicast group on interface eth0.IPv6 with address fe80::1073:c87:ef15:c4a3.
Apr  7 17:05:30 raspberrypi avahi-daemon[413]: Joining mDNS multicast group on interface eth0.IPv6 with address 2a02:c7d:2bbb:9f00:76b3:47f9:2c11:fea4.
Apr  7 17:05:30 raspberrypi avahi-daemon[413]: Registering new address record for 2a02:c7d:2bbb:9f00:76b3:47f9:2c11:fea4 on eth0.*.
Apr  7 17:05:30 raspberrypi avahi-daemon[413]: Withdrawing address record for fe80::1073:c87:ef15:c4a3 on eth0.
Apr  7 17:05:30 raspberrypi avahi-daemon[413]: Registering new address record for fd41:6d80:6364:0:bcdf:ae43:354b:1e46 on eth0.*.
Apr  7 17:05:30 raspberrypi logger: DANNY running /lib/dhcpcd/dhcpcd-hooks/100-dns (ROUTERADVERT)
Apr  7 17:05:30 raspberrypi logger: DANNY running /etc/dhcpcd.exit-hook (ROUTERADVERT)
Apr  7 17:05:37 raspberrypi dhcpcd[408]: eth0: leased 192.168.0.100 for 86400 seconds
Apr  7 17:05:37 raspberrypi avahi-daemon[413]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.0.100.
Apr  7 17:05:37 raspberrypi avahi-daemon[413]: New relevant interface eth0.IPv4 for mDNS.
Apr  7 17:05:37 raspberrypi avahi-daemon[413]: Registering new address record for 192.168.0.100 on eth0.IPv4.
Apr  7 17:05:37 raspberrypi dhcpcd[408]: eth0: adding route to 192.168.0.0/24
Apr  7 17:05:37 raspberrypi dhcpcd[408]: eth0: adding default route via 192.168.0.1
Apr  7 17:05:37 raspberrypi logger: DANNY running /lib/dhcpcd/dhcpcd-hooks/100-dns (REBOOT)
Apr  7 17:05:37 raspberrypi logger: DANNY running /etc/dhcpcd.exit-hook (REBOOT)
Apr  7 17:05:37 raspberrypi dhcpcd[408]: forked to background, child pid 715
Apr  7 17:05:37 raspberrypi systemd[1]: Started dhcpcd on all interfaces.
Apr  7 17:05:37 raspberrypi ntpd[750]: Listen normally on 3 eth0 192.168.0.100 UDP 123
Apr  7 17:05:37 raspberrypi ntpd[750]: Listen normally on 5 eth0 2a02:c7d:2bbb:9f00:76b3:47f9:2c11:fea4 UDP 123
Apr  7 17:05:37 raspberrypi ntpd[750]: Listen normally on 6 eth0 fe80::1073:c87:ef15:c4a3 UDP 123
Apr  7 17:05:37 raspberrypi ntpd[750]: Listen normally on 8 eth0 fd41:6d80:6364:0:bcdf:ae43:354b:1e46 UDP 123

[ShiftPlusOne]

DNS should work as soon as you have a lease and resolvconf has run (via 20-resolv.conf). So $reson should be BOUND|RENEW|REBIND|REBOOT|INFORM (or whatever the case may be for your particular application, each with a 6 at the end if you're really talking IPv6, I think), $if_up should be 'true' and your hook should run after 20-resolv.conf. They recommend using the /etc path for user configs, so I'd use that.

[DanTup]

None of the $reasons seem to end in 6, so I'm still a bit unsure what to hook :/

Code: Select all

Apr  8 10:09:23 raspberrypi danny: DANNY rebooting...
Apr  8 10:09:31 raspberrypi logger: DANNY running /lib/dhcpcd/dhcpcd-hooks/100-ddns (Reason: PREINIT, If_up: false, Interface: eth0)
Apr  8 10:09:31 raspberrypi logger: DANNY running /etc/dhcpcd.exit-hook (Reason: PREINIT, If_up: false, Interface: eth0)
Apr  8 10:09:32 raspberrypi logger: DANNY running /lib/dhcpcd/dhcpcd-hooks/100-ddns (Reason: NOCARRIER, If_up: false, Interface: eth0)
Apr  8 10:09:32 raspberrypi logger: DANNY running /etc/dhcpcd.exit-hook (Reason: NOCARRIER, If_up: false, Interface: eth0)
Apr  8 10:09:32 raspberrypi logger: DANNY running /lib/dhcpcd/dhcpcd-hooks/100-ddns (Reason: PREINIT, If_up: false, Interface: wlan0)
Apr  8 10:09:32 raspberrypi logger: DANNY running /etc/dhcpcd.exit-hook (Reason: PREINIT, If_up: false, Interface: wlan0)
Apr  8 10:09:32 raspberrypi logger: DANNY running /lib/dhcpcd/dhcpcd-hooks/100-ddns (Reason: NOCARRIER, If_up: false, Interface: wlan0)
Apr  8 10:09:32 raspberrypi logger: DANNY running /etc/dhcpcd.exit-hook (Reason: NOCARRIER, If_up: false, Interface: wlan0)
Apr  8 10:09:34 raspberrypi logger: DANNY running /lib/dhcpcd/dhcpcd-hooks/100-ddns (Reason: CARRIER, If_up: false, Interface: eth0)
Apr  8 10:09:34 raspberrypi logger: DANNY running /etc/dhcpcd.exit-hook (Reason: CARRIER, If_up: false, Interface: eth0)
Apr  8 10:09:35 raspberrypi logger: DANNY running /lib/dhcpcd/dhcpcd-hooks/100-ddns (Reason: INFORM6, If_up: true, Interface: eth0)
Apr  8 10:09:35 raspberrypi logger: DANNY running /etc/dhcpcd.exit-hook (Reason: INFORM6, If_up: true, Interface: eth0)
Apr  8 10:09:55 raspberrypi logger: DANNY running /lib/dhcpcd/dhcpcd-hooks/100-ddns (Reason: EXPIRE, If_up: false, Interface: eth0)
Apr  8 10:09:55 raspberrypi logger: DANNY running /etc/dhcpcd.exit-hook (Reason: EXPIRE, If_up: false, Interface: eth0)
Apr  8 10:09:56 raspberrypi logger: DANNY running /lib/dhcpcd/dhcpcd-hooks/100-ddns (Reason: ROUTERADVERT, If_up: true, Interface: eth0)
Apr  8 10:09:56 raspberrypi logger: DANNY running /etc/dhcpcd.exit-hook (Reason: ROUTERADVERT, If_up: true, Interface: eth0)
Apr  8 10:10:00 raspberrypi logger: DANNY running /lib/dhcpcd/dhcpcd-hooks/100-ddns (Reason: IPV4LL, If_up: true, Interface: eth0)
Apr  8 10:10:00 raspberrypi logger: DANNY running /etc/dhcpcd.exit-hook (Reason: IPV4LL, If_up: true, Interface: eth0)
Apr  8 10:10:01 raspberrypi logger: DANNY running /lib/dhcpcd/dhcpcd-hooks/100-ddns (Reason: BOUND, If_up: true, Interface: eth0)
Apr  8 10:10:01 raspberrypi logger: DANNY running /etc/dhcpcd.exit-hook (Reason: BOUND, If_up: true, Interface: eth0)
Apr  8 10:10:07 raspberrypi logger: DANNY running /lib/dhcpcd/dhcpcd-hooks/100-ddns (Reason: IPV4LL, If_up: false, Interface: eth0)
Apr  8 10:10:07 raspberrypi logger: DANNY running /etc/dhcpcd.exit-hook (Reason: IPV4LL, If_up: false, Interface: eth0)

[ShiftPlusOne]

None of the $reasons seem to end in 6

Code: Select all

Apr  8 10:09:35 raspberrypi logger: DANNY running /lib/dhcpcd/dhcpcd-hooks/100-ddns (Reason: INFORM6, If_up: true, Interface: eth0)
Apr  8 10:09:35 raspberrypi logger: DANNY running /etc/dhcpcd.exit-hook (Reason: INFORM6, If_up: true, Interface: eth0)

[DanTup]

lol, I saw that afterwards. But, I was exchanging some emails with Roy Marples (the developer of dhcpcd) about logging, so I sent him this link. He advised ROUTERADVERT is what I want, so I have set this up:

Code: Select all

## /etc/dhcpcd.exit-hook ##
if [ "$interface" = eth0 ] && [ "$reason" = ROUTERADVERT ] && [ "$if_up" = true ]; then
        logger 'Running DYNDNS update...'
        curl --stderr - -v "https://dynv6.com/api/update(blah)"
fi

It certainly worked at boot, though I'm slightly worried it'll run every few minutes (my router advertises a lot, which is why I was emailing him). I'll give it a few hours and see what's in the logs.

Thanks!

[DanTup]

Yep, runs way too often like this I'll see ask Roy if he has any suggestions...

[ShiftPlusOne]

Keep us posted, it would be good to know what the 'correct' solution is.

[DanTup]

Roy suggested stashing the IP and then comparing each time that event fires. It'll work, but it doesn't sound great. Not sure if that means there isn't really an appropriate thing in DHCP6 to signify what I want, or whether it's just not easily available from dhcpcd.

Logging the IP is slightly complicated by the fact that I seem to have more than one:

Code: Select all

danny@raspberrypi:~$ ifconfig
eth0      Link encap:Ethernet  HWaddr b8:27:eb:8c:48:b0  
          inet addr:192.168.0.100  Bcast:192.168.0.255  Mask:255.255.255.0
          inet6 addr: 2a02:c7d:2bbd:2f00:1b6e:102f:bf3a:90f6/64 Scope:Global
          inet6 addr: fe80::1073:c87:ef15:c4a3/64 Scope:Link
          inet6 addr: fd1b:6fb2:3cb8:0:b46d:e102:a664:7a72/64 Scope:Global

The first one (2a02) seems to be the publicly addressable one, and based on [url=https://en.wikipedia.org/wiki/Unique_local_address]this page[url], I'd guess the other is a local one, but why it's marked "Global" I don't know!

[DougieLawson]

You may want to edit your post and remove the 2a02:xxxx:xxxx:xxxx prefix as that's your public global address and publishing it gives the hackers a clue. I don't know what the fd1b:xxxx:xxxx:xxxx address is or why it's appearing.

You're OK at the moment I couldn't ssh to either of those addresses. Remember anyone hacking at IPv6 addresses isn't going to be some numpty script kiddie, if they do that they're coming in armed and dangerous.

The fe80: address is OK as that's the link-local range so is only accessible from your LAN.

Use ip -6 addr show | grep 'global' to extract the IPv6 global addresses from an ip addr show command

[DanTup]

You may want to edit your post and remove the 2a02:xxxx:xxxx:xxxx prefix as that's your public global address and publishing it gives the hackers a clue. I don't know what the fd1b:xxxx:xxxx:xxxx address is or why it's appearing.

I'm setting up dynamic DNS specifically to allow access to my Pi, so its IP is not secret My router includes IPv6 firewalling and I've tested it fairly well and I'm confident in the setup I do have SSH open, but currently only on a NATed v4 IP (while I'm trying to fix this dynamic DNS script) and on nonstandard port.

The fd1b address I'm sure is a local one (the wikipedia page suggests this), though I don't know why it's marked global; I doubt my router will route to/from that over the web. Maybe it's like a 169 address and was set up prior to DHCP completing? I can just ignore it by the prefix for now I guess and make my script email me if it ever gets more than one result after doing that.

Code: Select all

Remember anyone hacking at IPv6 addresses isn't going to be some numpty script kiddie, if they do that they're coming in armed and dangerous.

Sure; but I'm sure I've done everything right. Everything is firewalled by default, root SSH is disabled, Pi user is deleted and unattended security updates are set up with email notifications