Re: interfaces are killed after boot
Daniel Huhardeaux
Sat Nov 23 14:20:50 2019
Hi,
sorry for delay, back to this subject. I updated raspbian and dhcpcd
version is now
dhcpcd 8.1.2
Copyright (c) 2006-2019 Roy Marples
Compiled in features: INET ARP ARPing IPv4LL INET6 DHCPv6 AUTH
Le 14/11/2019 à 17:53, Roy Marples a écrit :
On 14/11/2019 15:34, Daniel Huhardeaux wrote:
Try this instead
PATHtoFW=/etc/network/if-post-up.d
if $if_up; then
case "$protocol" in
dhcp|ipv4ll) "$PATHtoFW/sfw4" "$interface";;
ra|dhcp6|static6) "$PATHtoFW/sfw6" "$interface";;
esac
fi
My script is only launched for eth0 ipv4 and what is strange, not all
the script is executed ! It's a sh script which start nftables rules.
Inside they are echo "bla bla ..." for debugging. Could this be the
problem ? I don't find those datas in syslog, even using logger "..."
dhcpcd-run-hooks provires a syslog function
syslog err "This is an error"
I put the file 00-startFW in /etc/dhcpcd.exit-hook which contain
PATHtoFW=/etc/network/if-post-up.d
syslog warn "dhcpcd-exit-hooks - if_up=$if_up protocol=$protocol
interface=$interface path=$PATHtoFW"
The script is NEVER executed on boot. I put it in
/lib/dhcpcd/dhcpcd-hooks under the name 99-start-FW and here he is
launched on boot, syslog warn as dhcpcd-hooks (see attached console file).
Another problem arised: during boot, dhdcpd timeout after 1m34s and die,
both interfaces eth0 and wlan0 having only their ipv4 IP address. See
attached syslog
[...]
After boot:
pi@raspi:~ $ ps ax|grep dhcp
2591 pts/6 S+ 0:00 grep --color=auto dhcp
pi@raspi:~ $ sudo /sbin/dhcpcd
pi@raspi:~ $ ps ax|grep dhcp
3189 ? Ss 0:00 /sbin/dhcpcd
3463 pts/6 S+ 0:00 grep --color=auto dhcp
and I see all the stuff executed on console (attached file)
dhcp server is dnsmasq who send the same IPs to eth0 and wlan0. Could
this be the problem with ipv6 on wlan0 as with ipv4 both interfaces
always gets the IP?
I generally use this command
dhcpcd -dB
That's what I put in systemd boot script
Very verbose.
Like this, you can now enable shell debugging by putting this at the top
of your exit.hook
set -x >
And boom, running dhcpcd on the console will force your hook to log each
line with variables expanded.
My problem is at boot time. I could add the scripts in rc.local but it's
not a proper manier
[...]
If someone had an idea on this problem ot any hint, welcome :)
--
Daniel
TOOTAi Networks
pi@raspi:~ $ sudo /sbin/dhcpcd
dev: loaded udev
+ PATHtoFW=/etc/network/if-post-up.d
+ PATHtoFW=/etc/network/if-post-up.d
+ [ -n warn ]
+ shift
+ [ -n dhcpcd-hooks - if_up=false protocol=link interface=eth0 path=/etc/network/if-post-up.d ]
+ echo eth0: dhcpcd-hooks - if_up=false protocol=link interface=eth0 path=/etc/network/if-post-up.d
eth0: dhcpcd-hooks - if_up=false protocol=link interface=eth0 path=/etc/network/if-post-up.d
+ [ -n dhcpcd-hooks - if_up=false protocol=link interface=wlan0 path=/etc/network/if-post-up.d ]
+ echo wlan0: dhcpcd-hooks - if_up=false protocol=link interface=wlan0 path=/etc/network/if-post-up.d
wlan0: dhcpcd-hooks - if_up=false protocol=link interface=wlan0 path=/etc/network/if-post-up.d
+ type logger
wlan0: connected to Access Point `'
+ PATHtoFW=/etc/network/if-post-up.d
+ syslog warn dhcpcd-hooks - if_up=false protocol=link interface=wlan0 path=/etc/network/if-post-up.d
+ [ -f /etc/dhcpcd.exit-hook ]
DUID 00:01:00:01:25:5e:zz:yy:xx:27:eb:89:ee:cd
eth0: IAID zz:xx:bb:98
wlan0: waiting for carrier
eth0: soliciting an IPv6 router
eth0: Router Advertisement from fe80::5054:ff:xxxx:yyyy
eth0: adding route to 2a01:xxxx:yyyy:10::/64
eth0: adding default route via fe80::5054:ff:xxxx:yyyy
+ PATHtoFW=/etc/network/if-post-up.d
+ syslog warn dhcpcd-hooks - if_up=true protocol=ra interface=eth0 path=/etc/network/if-post-up.d
+ lvl=warn
+ [ warn = debug ]
+ [ -n warn ]
+ shift
+ [ -n dhcpcd-hooks - if_up=true protocol=ra interface=eth0 path=/etc/network/if-post-up.d ]
+ echo eth0: dhcpcd-hooks - if_up=true protocol=ra interface=eth0 path=/etc/network/if-post-up.d
eth0: dhcpcd-hooks - if_up=true protocol=ra interface=eth0 path=/etc/network/if-post-up.d
+ type logger
+ logger -i -p daemon.warn -t dhcpcd-run-hooks eth0: dhcpcd-hooks - if_up=true protocol=ra interface=eth0 path=/etc/network/if-post-up.d
+ [ -f /etc/dhcpcd.exit-hook ]
eth0: confirming prior DHCPv6 lease
eth0: rebinding lease of 192.168.10.18
eth0: REPLY6 received from fe80::5054:ff:xxxx:yyyy
eth0: adding address 2a01:xxxx:yyyy:10::18/128
eth0: renew in 1296000, rebind in 2073600, expire in 2592000 seconds
wlan0: carrier acquired
wlan0: connected to Access Point `myAP'
+ PATHtoFW=/etc/network/if-post-up.d
+ syslog warn dhcpcd-hooks - if_up=false protocol=link interface=wlan0 path=/etc/network/if-post-up.d
+ lvl=warn
+ [ warn = debug ]
+ [ -n warn ]
+ shift
+ [ -n dhcpcd-hooks - if_up=false protocol=link interface=wlan0 path=/etc/network/if-post-up.d ]
+ echo wlan0: dhcpcd-hooks - if_up=false protocol=link interface=wlan0 path=/etc/network/if-post-up.d
wlan0: dhcpcd-hooks - if_up=false protocol=link interface=wlan0 path=/etc/network/if-post-up.d
+ type logger
+ logger -i -p daemon.warn -t dhcpcd-run-hooks wlan0: dhcpcd-hooks - if_up=false protocol=link interface=wlan0 path=/etc/network/if-post-up.d
+ [ -f /etc/dhcpcd.exit-hook ]
wlan0: IAID eb:89:ee:cd
wlan0: adding address fe80::17db:5df7:xxxx:yyyy
wlan0: soliciting an IPv6 router
wlan0: rebinding lease of 192.168.10.18
wlan0: leased 192.168.10.18 for 345600 seconds
wlan0: adding route to 192.168.10.0/24
wlan0: adding default route via 192.168.10.1
+ PATHtoFW=/etc/network/if-post-up.d
+ syslog warn dhcpcd-hooks - if_up=true protocol=dhcp interface=wlan0 path=/etc/network/if-post-up.d
+ lvl=warn
+ [ warn = debug ]
+ [ -n warn ]
+ shift
+ [ -n dhcpcd-hooks - if_up=true protocol=dhcp interface=wlan0 path=/etc/network/if-post-up.d ]
+ echo wlan0: dhcpcd-hooks - if_up=true protocol=dhcp interface=wlan0 path=/etc/network/if-post-up.d
wlan0: dhcpcd-hooks - if_up=true protocol=dhcp interface=wlan0 path=/etc/network/if-post-up.d
+ type logger
+ logger -i -p daemon.warn -t dhcpcd-run-hooks wlan0: dhcpcd-hooks - if_up=true protocol=dhcp interface=wlan0 path=/etc/network/if-post-up.d
+ [ -f /etc/dhcpcd.exit-hook ]
forked to background, child pid 3189
Nov 23 14:29:09 raspi rsyslogd: [origin software="rsyslogd" swVersion="8.1901.0" x-pid="327" x-info="https://www.rsyslog.com";] rsyslogd was HUPed
Nov 23 14:29:09 raspi systemd[1]: logrotate.service: Succeeded.
Nov 23 14:29:09 raspi systemd[1]: Started Rotate log files.
Nov 23 14:29:10 raspi systemd[1]: man-db.service: Succeeded.
Nov 23 14:29:10 raspi systemd[1]: Started Daily man-db regeneration.
Nov 23 14:29:13 raspi systemd[1]: systemd-hostnamed.service: Succeeded.
Nov 23 14:30:08 raspi systemd[1]: dhcpcd.service: Start operation timed out. Terminating.
Nov 23 14:30:08 raspi dhcpcd[365]: received SIGTERM, stopping
Nov 23 14:30:08 raspi dhcpcd[365]: received SIGTERM, stopping
Nov 23 14:30:08 raspi dhcpcd[365]: wlan0: removing interface
Nov 23 14:30:08 raspi dhcpcd[365]: wlan0: removing interface
Nov 23 14:30:08 raspi dhcpcd[365]: wlan0: executing `/lib/dhcpcd/dhcpcd-run-hooks' STOPPED
Nov 23 14:30:08 raspi dhcpcd[365]: wlan0: executing `/lib/dhcpcd/dhcpcd-run-hooks' STOPPED
Nov 23 14:30:08 raspi dhcpcd[365]: eth0: removing interface
Nov 23 14:30:08 raspi dhcpcd[365]: eth0: removing interface
Nov 23 14:30:08 raspi dhcpcd[365]: eth0: executing `/lib/dhcpcd/dhcpcd-run-hooks' STOPPED
Nov 23 14:30:08 raspi dhcpcd[365]: eth0: executing `/lib/dhcpcd/dhcpcd-run-hooks' STOPPED
Nov 23 14:30:08 raspi dhcpcd[365]: dev: unloaded udev
Nov 23 14:30:08 raspi dhcpcd[365]: dhcpcd exited
Nov 23 14:30:08 raspi dhcpcd[365]: dev: unloaded udev
Nov 23 14:30:08 raspi dhcpcd[365]: dhcpcd exited
Nov 23 14:30:09 raspi avahi-daemon[360]: Interface wlan0.IPv6 no longer relevant for mDNS.
Nov 23 14:30:09 raspi avahi-daemon[360]: Leaving mDNS multicast group on interface wlan0.IPv6 with address 2a01:729:16e:10::18.
Nov 23 14:30:09 raspi avahi-daemon[360]: Interface wlan0.IPv4 no longer relevant for mDNS.
Nov 23 14:30:09 raspi avahi-daemon[360]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.10.18.
Nov 23 14:30:09 raspi avahi-daemon[360]: Withdrawing address record for 2a01:729:16e:10::18 on wlan0.
Nov 23 14:30:09 raspi avahi-daemon[360]: Withdrawing address record for 192.168.10.18 on wlan0.
Nov 23 14:30:09 raspi systemd[1]: dhcpcd.service: Failed with result 'timeout'.
Nov 23 14:30:09 raspi systemd[1]: Failed to start dhcpcd on all interfaces.
Nov 23 14:30:09 raspi systemd[1]: Reached target Network.
Nov 23 14:30:09 raspi systemd[1]: Starting OpenBSD Secure Shell server...
Nov 23 14:30:09 raspi systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped.
Nov 23 14:30:09 raspi systemd[1]: Starting Permit User Sessions...
Nov 23 14:30:09 raspi systemd[1]: Reached target Network is Online.
Nov 23 14:30:09 raspi systemd[1]: Starting LSB: exim Mail Transport Agent...
Nov 23 14:30:09 raspi systemd[1]: Starting Daily apt upgrade and clean activities...
Nov 23 14:30:09 raspi systemd[1]: Starting LSB: autostarter for services in debian-8 ExaGear guest...
Nov 23 14:30:09 raspi systemd[1]: Starting /etc/rc.local Compatibility...
Nov 23 14:30:09 raspi systemd[1]: Started Permit User Sessions.
Nov 23 14:30:09 raspi systemd[1]: Started /etc/rc.local Compatibility.
Nov 23 14:30:09 raspi systemd[1]: Starting Hold until boot process finishes up...
Nov 23 14:30:09 raspi systemd[1]: Starting Light Display Manager...
Nov 23 14:30:09 raspi exagear-guest-debian-8[916]: S01dbus
Nov 23 14:30:09 raspi systemd[1]: Started OpenBSD Secure Shell server.
Nov 23 14:30:09 raspi lightdm[933]: Error getting user list from org.freedesktop.Accounts: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.Accounts was not provided by any .service files
Nov 23 14:30:09 raspi systemd[1]: Received SIGRTMIN+21 from PID 152 (plymouthd).
Nov 23 14:30:09 raspi systemd[1]: plymouth-start.service: Succeeded.
Nov 23 14:30:09 raspi systemd[1]: plymouth-quit-wait.service: Succeeded.
Nov 23 14:30:09 raspi systemd[1]: Started Hold until boot process finishes up.
Nov 23 14:30:09 raspi systemd[1]: Received SIGRTMIN+21 from PID 152 (n/a).
Nov 23 14:30:09 raspi systemd[1]: Started Light Display Manager.
Nov 23 14:30:09 raspi systemd[1]: Started Getty on tty1.
Nov 23 14:30:09 raspi systemd[1]: Started Serial Getty on ttyS0.
Nov 23 14:30:09 raspi systemd[1]: Reached target Login Prompts.
Nov 23 14:30:11 raspi exim4[914]: Starting MTA: exim4.
Nov 23 14:30:11 raspi systemd[1]: Started LSB: exim Mail Transport Agent.
Nov 23 14:30:12 raspi exagear-guest-debian-8[916]: Starting S01dbus (via systemctl): S01dbus.serviceFailed to start S01dbus.service: Unit S01dbus.service not found.
Nov 23 14:30:12 raspi exagear-guest-debian-8[916]: failed!
Nov 23 14:30:12 raspi exagear-guest-debian-8[916]: S01binfmt-support
Nov 23 14:30:13 raspi exagear-guest-debian-8[916]: Starting S01binfmt-support (via systemctl): S01binfmt-support.serviceFailed to start S01binfmt-support.service: Unit S01binfmt-support.service not found.
Nov 23 14:30:13 raspi exagear-guest-debian-8[916]: failed!
Nov 23 14:30:13 raspi exagear-guest-debian-8[916]: S02saned
Nov 23 14:30:14 raspi exagear-guest-debian-8[916]: Starting S02saned (via systemctl): S02saned.serviceFailed to start S02saned.service: Unit S02saned.service not found.
Nov 23 14:30:14 raspi systemd[1]: apt-daily-upgrade.service: Succeeded.
Nov 23 14:30:14 raspi systemd[1]: Started Daily apt upgrade and clean activities.
Nov 23 14:30:14 raspi exagear-guest-debian-8[916]: failed!
Nov 23 14:30:14 raspi exagear-guest-debian-8[916]: Exagear: forwarding crontabs...
Nov 23 14:30:14 raspi exagear-guest-debian-8[916]: Exagear: forwarding udev rules...
Nov 23 14:30:14 raspi systemd[1]: Started LSB: autostarter for services in debian-8 ExaGear guest.
Nov 23 14:30:14 raspi systemd[1]: Reached target Multi-User System.
Nov 23 14:30:14 raspi systemd[1]: Reached target Graphical Interface.
Nov 23 14:30:14 raspi systemd[1]: Starting Update UTMP about System Runlevel Changes...
Nov 23 14:30:14 raspi systemd[1]: systemd-update-utmp-runlevel.service: Succeeded.
Nov 23 14:30:14 raspi systemd[1]: Started Update UTMP about System Runlevel Changes.
Nov 23 14:30:14 raspi systemd[1]: Startup finished in 3.585s (kernel) + 1min 42.591s (userspace) = 1min 46.177s.
Nov 23 14:30:15 raspi lightdm[1287]: Error getting user list from org.freedesktop.Accounts: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.Accounts was not provided by any .service files
Nov 23 14:30:15 raspi systemd[1]: Created slice User Slice of UID 1000.
Nov 23 14:30:15 raspi systemd[1]: Starting User Runtime Directory /run/user/1000...
Nov 23 14:30:15 raspi systemd[1]: Started User Runtime Directory /run/user/1000.
Nov 23 14:30:15 raspi systemd[1]: Starting User Manager for UID 1000...
Nov 23 14:30:16 raspi systemd[1295]: Listening on Sound System.
Nov 23 14:30:16 raspi systemd[1295]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Nov 23 14:30:16 raspi systemd[1295]: Listening on GnuPG network certificate management daemon.
Nov 23 14:30:16 raspi systemd[1295]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Nov 23 14:30:16 raspi systemd[1295]: Reached target Timers.
Nov 23 14:30:16 raspi systemd[1295]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
Nov 23 14:30:16 raspi systemd[1295]: Listening on GnuPG cryptographic agent and passphrase cache.
Nov 23 14:30:16 raspi systemd[1295]: Reached target Paths.
Nov 23 14:30:16 raspi systemd[1295]: Starting D-Bus User Message Bus Socket.
Nov 23 14:30:16 raspi systemd[1295]: Listening on D-Bus User Message Bus Socket.
Nov 23 14:30:16 raspi systemd[1295]: Reached target Sockets.
Nov 23 14:30:16 raspi systemd[1295]: Reached target Basic System.
Nov 23 14:30:16 raspi systemd[1295]: Reached target Default.
Nov 23 14:30:16 raspi systemd[1295]: Startup finished in 319ms.
Nov 23 14:30:16 raspi systemd[1]: Started User Manager for UID 1000.
Nov 23 14:30:16 raspi systemd[1]: Started Session c1 of user pi.
Nov 23 14:30:16 raspi lightdm[933]: Error opening audit socket: Protocol not supported
Nov 23 14:30:16 raspi systemd[1295]: Started D-Bus User Message Bus.
Nov 23 14:30:17 raspi dbus-daemon[1318]: [session uid=1000 pid=1318] Activating via systemd: service name='org.gtk.vfs.Daemon' unit='gvfs-daemon.service' requested by ':1.3' (uid=1000 pid=1309 comm="/usr/bin/lxsession -s LXDE-pi -e LXDE ")
Nov 23 14:30:17 raspi systemd[1295]: Starting Virtual filesystem service...
Nov 23 14:30:17 raspi dbus-daemon[1318]: [session uid=1000 pid=1318] Successfully activated service 'org.gtk.vfs.Daemon'
Nov 23 14:30:17 raspi systemd[1295]: Started Virtual filesystem service.
Nov 23 14:30:18 raspi kernel: [ 109.362264] fuse init (API version 7.27)
Nov 23 14:30:18 raspi systemd[1]: Mounting FUSE Control File System...
Nov 23 14:30:18 raspi systemd[1]: Mounted FUSE Control File System.
Nov 23 14:30:18 raspi systemd[1295]: Starting Sound Service...
Nov 23 14:30:19 raspi dbus-daemon[333]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.41' (uid=1000 pid=1416 comm="/usr/bin/pulseaudio --daemonize=no ")
Nov 23 14:30:19 raspi systemd[1]: Starting RealtimeKit Scheduling Policy Service...
Nov 23 14:30:19 raspi dbus-daemon[333]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1'
Nov 23 14:30:19 raspi systemd[1]: Started RealtimeKit Scheduling Policy Service.
Nov 23 14:30:19 raspi rtkit-daemon[1432]: Successfully called chroot.
Nov 23 14:30:19 raspi rtkit-daemon[1432]: Successfully dropped privileges.
Nov 23 14:30:19 raspi rtkit-daemon[1432]: Successfully limited resources.
Nov 23 14:30:19 raspi rtkit-daemon[1432]: Running.
Nov 23 14:30:19 raspi rtkit-daemon[1432]: Canary thread running.
Nov 23 14:30:19 raspi rtkit-daemon[1432]: Watchdog thread running.
Nov 23 14:30:19 raspi rtkit-daemon[1432]: Successfully made thread 1416 of process 1416 (n/a) owned by '1000' high priority at nice level -11.
Nov 23 14:30:19 raspi rtkit-daemon[1432]: Supervising 1 threads of 1 processes of 1 users.
Nov 23 14:30:20 raspi dbus-daemon[1318]: [session uid=1000 pid=1318] Activating via systemd: service name='org.gtk.vfs.UDisks2VolumeMonitor' unit='gvfs-udisks2-volume-monitor.service' requested by ':1.7' (uid=1000 pid=1381 comm="pcmanfm --desktop --profile LXDE-pi ")
Nov 23 14:30:20 raspi systemd[1295]: Starting Virtual filesystem service - disk device monitor...
Nov 23 14:30:21 raspi dbus-daemon[1318]: [session uid=1000 pid=1318] Successfully activated service 'org.gtk.vfs.UDisks2VolumeMonitor'
Nov 23 14:30:21 raspi systemd[1295]: Started Virtual filesystem service - disk device monitor.
Nov 23 14:30:21 raspi dbus-daemon[1318]: [session uid=1000 pid=1318] Activating via systemd: service name='org.gtk.vfs.MTPVolumeMonitor' unit='gvfs-mtp-volume-monitor.service' requested by ':1.7' (uid=1000 pid=1381 comm="pcmanfm --desktop --profile LXDE-pi ")
Nov 23 14:30:21 raspi systemd[1295]: Starting Virtual filesystem service - Media Transfer Protocol monitor...
Nov 23 14:30:21 raspi dbus-daemon[1318]: [session uid=1000 pid=1318] Successfully activated service 'org.gtk.vfs.MTPVolumeMonitor'
Nov 23 14:30:21 raspi systemd[1295]: Started Virtual filesystem service - Media Transfer Protocol monitor.
Nov 23 14:30:21 raspi dbus-daemon[1318]: [session uid=1000 pid=1318] Activating via systemd: service name='org.gtk.vfs.GoaVolumeMonitor' unit='gvfs-goa-volume-monitor.service' requested by ':1.7' (uid=1000 pid=1381 comm="pcmanfm --desktop --profile LXDE-pi ")
Nov 23 14:30:21 raspi systemd[1295]: Starting Virtual filesystem service - GNOME Online Accounts monitor...
Nov 23 14:30:21 raspi dbus-daemon[1318]: [session uid=1000 pid=1318] Successfully activated service 'org.gtk.vfs.GoaVolumeMonitor'
Nov 23 14:30:21 raspi systemd[1295]: Started Virtual filesystem service - GNOME Online Accounts monitor.
Nov 23 14:30:21 raspi dbus-daemon[1318]: [session uid=1000 pid=1318] Activating via systemd: service name='org.gtk.vfs.AfcVolumeMonitor' unit='gvfs-afc-volume-monitor.service' requested by ':1.7' (uid=1000 pid=1381 comm="pcmanfm --desktop --profile LXDE-pi ")
Nov 23 14:30:21 raspi systemd[1295]: Starting Virtual filesystem service - Apple File Conduit monitor...
Nov 23 14:30:21 raspi gvfs-afc-volume-monitor[1481]: Volume monitor alive
Nov 23 14:30:21 raspi dbus-daemon[1318]: [session uid=1000 pid=1318] Successfully activated service 'org.gtk.vfs.AfcVolumeMonitor'
Nov 23 14:30:21 raspi systemd[1295]: Started Virtual filesystem service - Apple File Conduit monitor.
Nov 23 14:30:21 raspi dbus-daemon[1318]: [session uid=1000 pid=1318] Activating via systemd: service name='org.gtk.vfs.GPhoto2VolumeMonitor' unit='gvfs-gphoto2-volume-monitor.service' requested by ':1.7' (uid=1000 pid=1381 comm="pcmanfm --desktop --profile LXDE-pi ")
Nov 23 14:30:21 raspi systemd[1295]: Starting Virtual filesystem service - digital camera monitor...
Nov 23 14:30:21 raspi dbus-daemon[1318]: [session uid=1000 pid=1318] Successfully activated service 'org.gtk.vfs.GPhoto2VolumeMonitor'
Nov 23 14:30:21 raspi systemd[1295]: Started Virtual filesystem service - digital camera monitor.
Nov 23 14:30:21 raspi systemd[1295]: Started Sound Service.
Nov 23 14:30:35 raspi systemd[1]: Started Session c2 of user pi.
Nov 23 14:32:31 raspi systemd-timesyncd[278]: Timed out waiting for reply from [2a06:1480:5ec:900::123:2]:123 (2.debian.pool.ntp.org).
Nov 23 14:32:42 raspi systemd-timesyncd[278]: Timed out waiting for reply from [2600:3c00::f03c:91ff:fe91:5dd8]:123 (2.debian.pool.ntp.org).
Nov 23 14:32:52 raspi systemd-timesyncd[278]: Timed out waiting for reply from [2001:41d0:1008:1a1d::1]:123 (2.debian.pool.ntp.org).
Nov 23 14:33:02 raspi systemd-timesyncd[278]: Timed out waiting for reply from [2400:8500:1302:845:a150:95:187:1280]:123 (2.debian.pool.ntp.org).
Nov 23 14:33:02 raspi systemd-timesyncd[278]: Synchronized to time server for the first time 129.250.35.251:123 (2.debian.pool.ntp.org).
Archive administrator: postmaster@marples.name