Bug#1003225: on resume, tries to openat() mountpoint of remote nfs mounts that are not yet available, thus delaying network configuration
On Wed, 13 Jul 2022 18:17:51 +0200 Andras Korn wrote: > On Mon, Jul 11, 2022 at 10:47:26AM +0300, Martin-Éric Racine wrote: > > > On Thu, 6 Jan 2022 18:38:47 +0100 Michael Biebl wrote: > > > On 06.01.22 17:26, Andras Korn wrote: > > > > Package: systemd-timesyncd > > > > Version: 249.7-1 > > > > Severity: normal > > > > Tags: upstream > > > > > > > > Hi, > > > > > > > > I noticed that it took a while for the network to become available > > > > after my > > > > laptop wakes up from suspend. > > > > > > > > I traced the problem to systemd-timesyncd. > > > > > > > > I use dhcpcd5, which ships /lib/dhcpcd/dhcpcd-hooks/64-timesyncd.conf, > > which > > > > contains the line "systemctl try-restart systemd-timesyncd.service || > > > > :". > > > > > > That file is not shipped by systemd. Why does it restart timesyncd? > > > Why does it so blockingly? Why does it restart timesyncd when the > > > network is still down? > > > > This is dhcpcd's attempt at adding the NTP servers received via DHCP > > options to > > timesyncd's configuration and restarting timesyncd to use them. This should > > only happen once the network has been raised, though, since this is an exit > > hook. > > Is there any particular reason you can't invoke systemctl with --no-block > here? Good point. Added in Debian Git. Please note that I will be dropping Debian's own deprecated NTP hooks when the next upstream is released, since upstream now includes hooks for timesyncd, in addition to its existing hooks for NTP, OpenNTP and Chrony. Martin-Éric
Bug#1003225: on resume, tries to openat() mountpoint of remote nfs mounts that are not yet available, thus delaying network configuration
On Mon, Jul 11, 2022 at 10:47:26AM +0300, Martin-Éric Racine wrote: > On Thu, 6 Jan 2022 18:38:47 +0100 Michael Biebl wrote: > > On 06.01.22 17:26, Andras Korn wrote: > > > Package: systemd-timesyncd > > > Version: 249.7-1 > > > Severity: normal > > > Tags: upstream > > > > > > Hi, > > > > > > I noticed that it took a while for the network to become available after > > > my > > > laptop wakes up from suspend. > > > > > > I traced the problem to systemd-timesyncd. > > > > > > I use dhcpcd5, which ships /lib/dhcpcd/dhcpcd-hooks/64-timesyncd.conf, > which > > > contains the line "systemctl try-restart systemd-timesyncd.service || :". > > > > That file is not shipped by systemd. Why does it restart timesyncd? > > Why does it so blockingly? Why does it restart timesyncd when the > > network is still down? > > This is dhcpcd's attempt at adding the NTP servers received via DHCP options > to > timesyncd's configuration and restarting timesyncd to use them. This should > only happen once the network has been raised, though, since this is an exit > hook. Is there any particular reason you can't invoke systemctl with --no-block here? András -- Buy an atlas and see the world.
Bug#1003225: on resume, tries to openat() mountpoint of remote nfs mounts that are not yet available, thus delaying network configuration
On Thu, 6 Jan 2022 18:38:47 +0100 Michael Biebl wrote: > On 06.01.22 17:26, Andras Korn wrote: > > Package: systemd-timesyncd > > Version: 249.7-1 > > Severity: normal > > Tags: upstream > > > > Hi, > > > > I noticed that it took a while for the network to become available after my > > laptop wakes up from suspend. > > > > I traced the problem to systemd-timesyncd. > > > > I use dhcpcd5, which ships /lib/dhcpcd/dhcpcd-hooks/64-timesyncd.conf, which > > contains the line "systemctl try-restart systemd-timesyncd.service || :". > > That file is not shipped by systemd. Why does it restart timesyncd? > Why does it so blockingly? Why does it restart timesyncd when the > network is still down? This is dhcpcd's attempt at adding the NTP servers received via DHCP options to timesyncd's configuration and restarting timesyncd to use them. This should only happen once the network has been raised, though, since this is an exit hook. Martin-Éric
Bug#1003225: on resume, tries to openat() mountpoint of remote nfs mounts that are not yet available, thus delaying network configuration
Does the issue still apply to dhcpcd5 version 9.4.1-1 or newer? Martin-Éric
Bug#1003225: on resume, tries to openat() mountpoint of remote nfs mounts that are not yet available, thus delaying network configuration
On 06.01.22 17:26, Andras Korn wrote: Package: systemd-timesyncd Version: 249.7-1 Severity: normal Tags: upstream Hi, I noticed that it took a while for the network to become available after my laptop wakes up from suspend. I traced the problem to systemd-timesyncd. I use dhcpcd5, which ships /lib/dhcpcd/dhcpcd-hooks/64-timesyncd.conf, which contains the line "systemctl try-restart systemd-timesyncd.service || :". That file is not shipped by systemd. Why does it restart timesyncd? Why does it so blockingly? Why does it restart timesyncd when the network is still down? OpenPGP_signature Description: OpenPGP digital signature
Bug#1003225: on resume, tries to openat() mountpoint of remote nfs mounts that are not yet available, thus delaying network configuration
Package: systemd-timesyncd
Version: 249.7-1
Severity: normal
Tags: upstream
Hi,
I noticed that it took a while for the network to become available after my
laptop wakes up from suspend.
I traced the problem to systemd-timesyncd.
I use dhcpcd5, which ships /lib/dhcpcd/dhcpcd-hooks/64-timesyncd.conf, which
contains the line "systemctl try-restart systemd-timesyncd.service || :".
During this try-restart operation, a timesyncd process is started and hangs
for several seconds in D state for each nfs mountpoint that is unreachable.
(I'm attaching an strace log; the nfs server also exports
nfs-mountpoint-2/subdir to this client separately, so technically that's
nfs-mountpoint-3.)
dhcpcd5 doesn't continue setting up the network before the hook script
returns, but without the network, the hook script takes a long time to
finish.
I don't see why timesyncd has to try to openat() a directory on every
mountpoint. I assume this is due to some generic code it pulls in from maybe
libsystemd; if it can't be avoided, perhaps timesyncd should be started in a
restricted mount namespace that doesn't contain anything but the (local)
mountpoints it absolutely needs to function. (This would be desirable anyway
from a security perspective.) I'm not sure if this can also be done for
try-restart, though.
András
-- System Information:
Debian Release: bookworm/sid
APT prefers stable-security
APT policy: (500, 'stable-security'), (500, 'unstable'), (1, 'experimental')
Architecture: amd64 (x86_64)
Foreign Architectures: i386
Kernel: Linux 5.14.15-pf8-luna (SMP w/8 CPU threads; PREEMPT)
Kernel taint flags: TAINT_PROPRIETARY_MODULE, TAINT_WARN, TAINT_OOT_MODULE,
TAINT_UNSIGNED_MODULE
Locale: LANG=en_US.UTF-8, LC_CTYPE=hu_HU.UTF-8 (charmap=UTF-8),
LANGUAGE=en_US.UTF-8
Shell: /bin/sh linked to /usr/bin/bash
Init: systemd (via /run/systemd/system)
LSM: AppArmor: enabled
--
Good documentation is not written to satisfy a quota specified in cubic feet.
read(3, "REDACTED"..., 1024) = 1024 <0.20>
read(3, "REDACTED"..., 1024) = 1024 <0.22>
read(3, "REDACTED", 1024) = 18 <0.06>
read(3, "REDACTED", 1024) = 0 <0.06>
openat(AT_FDCWD, "/run/systemd/unit-root/run/credentials",
O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) =
4 <0.18>
mount(NULL, "/proc/self/fd/4", NULL,
MS_RDONLY|MS_NOSUID|MS_NODEV|MS_NOEXEC|MS_REMOUNT|MS_BIND, NULL) = 0 <0.11>
close(4) = 0 <0.08>
lseek(3, 0, SEEK_SET) = 0 <0.06>
read(3, "REDACTED"..., 1024) = 1024 <0.29>
lstat("/proc", {st_mode=S_IFDIR|0555, st_size=0, ...}) = 0 <0.08>
lstat("/proc/self", {st_mode=S_IFLNK|0777, st_size=0, ...}) = 0 <0.06>
readlink("/proc/self", "63713", 4095) = 5 <0.06>
lstat("/proc/63713", {st_mode=S_IFDIR|0555, st_size=0, ...}) = 0 <0.06>
lstat("/proc/63713/mountinfo", {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
<0.05>
read(3, "REDACTED"..., 1024) = 1024 <0.17>
read(3, "REDACTED"..., 1024) = 1024 <0.17>
read(3, "REDACTED"..., 1024) = 1024 <0.23>
read(3, "REDACTED"..., 1024) = 1024 <0.25>
read(3, "REDACTED"..., 1024) = 1024 <0.17>
read(3, "REDACTED"..., 1024) = 1024 <0.18>
read(3, "REDACTED"..., 1024) = 1024 <0.14>
read(3, "REDACTED"..., 1024) = 1024 <0.15>
read(3, "REDACTED"..., 1024) = 1024 <0.16>
read(3, "REDACTED"..., 1024) = 1024 <0.12>
read(3, "REDACTED"..., 1024) = 1024 <0.15>
read(3, "REDACTED"..., 1024) = 1024 <0.13>
read(3, "REDACTED"..., 1024) = 1024 <0.12>
read(3, "REDACTED"..., 1024) = 1024 <0.14>
read(3, "REDACTED", 1024) = 18 <0.05>
read(3, "REDACTED", 1024) = 0 <0.05>
lseek(3, 0, SEEK_SET) = 0 <0.05>
read(3, "REDACTED"..., 1024) = 1024 <0.18>
lstat("/proc", {st_mode=S_IFDIR|0555, st_size=0, ...}) = 0 <0.06>
lstat("/proc/self", {st_mode=S_IFLNK|0777, st_size=0, ...}) = 0 <0.05>
readlink("/proc/self", "63713", 4095) = 5 <0.06>
lstat("/proc/63713", {st_mode=S_IFDIR|0555, st_size=0, ...}) = 0 <0.06>
lstat("/proc/63713/mountinfo", {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
<0.05>
read(3, "REDACTED"..., 1024) = 1024 <0.20>
read(3, "REDACTED"..., 1024) = 1024 <0.15>
read(3, "REDACTED"..., 1024) = 1024 <0.16>
read(3, "REDACTED"..., 1024) = 1024 <0.17>
read(3, "REDACTED"..., 1024) = 1024 <0.13>
read(3, "REDACTED"..., 1024) = 1024 <0.15>
read(3, "REDACTED"..., 1024) = 1024 <0.14>
read(3, "REDACTED"..., 1024) = 1024 <0.15>
read(3, "REDACTED"..., 1024) = 1024 <0.16>
read(3, "REDACTED"..., 1024) = 1024 <0.11>
read(3, "REDACTED"..., 1024) = 1024 <0.14>
read(3, "REDACTED"..., 1024) = 1024 <0.12>
read(3, "REDACTED"..., 1024) = 1024 <0.12>
read(3, "REDACTED"..., 1024) = 1024 <0.14>
read(3, "REDACTED", 1024) = 18 <0.05>
read(3, "REDACTED", 1024) = 0 <0.05>
openat(AT_FDCWD, "/run/systemd/unit-root/run/systemd/incoming",
O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) =
4 <0.08>
mount(NULL, "/proc/self/fd/4", NULL,
MS_RDONLY|MS_NOSUID|MS_NODEV|MS_NOEXEC|MS_REMOUNT|MS_BIND, NULL)
