Am 12.01.20 um 18:18 schrieb Michael Biebl: > Am 04.01.20 um 20:22 schrieb Santiago Vila: >> Hi. I managed to put the instances in a state where a reboot does not >> make the problem to go away. Please give it a try. > > I could reproduce the issue on the system provided by Santiago. > > I'm dumping the relevant parts of the log here:
From a buster system of mine which has chrony and systemd-timesyncd
installed and enabled:
> ● chrony.service - chrony, an NTP client/server
> Loaded: loaded (/lib/systemd/system/chrony.service; enabled; vendor
> preset: enabled)
> Active: active (running) since Sun 2020-01-12 19:48:09 CET; 1min 15s ago
> Docs: man:chronyd(8)
> man:chronyc(1)
> man:chrony.conf(5)
> Process: 395 ExecStart=/usr/sbin/chronyd $DAEMON_OPTS (code=exited,
> status=0/SUCCESS)
> Process: 404 ExecStartPost=/usr/lib/chrony/chrony-helper update-daemon
> (code=exited, status=0/SUCCESS)
> Main PID: 401 (chronyd)
> Tasks: 2 (limit: 1149)
> Memory: 3.3M
> CGroup: /system.slice/chrony.service
> ├─401 /usr/sbin/chronyd -F -1
> └─403 /usr/sbin/chronyd -F -1
>
> Jan 12 19:48:09 debian systemd[1]: chrony.service: Control process exited,
> code=exited, status=0/SUCCESS
> Jan 12 19:48:09 debian systemd[1]: chrony.service: Got final SIGCHLD for
> state start-post.
> Jan 12 19:48:09 debian systemd[1]: chrony.service: Changed start-post ->
> running
> Jan 12 19:48:09 debian systemd[1]: chrony.service: Job 75
> chrony.service/start finished, result=done
> Jan 12 19:48:09 debian systemd[1]: Started chrony, an NTP client/server.
> Jan 12 19:48:14 debian systemd[1]: chrony.service: chrony.service/stop would
> stop a running service.
> Jan 12 19:48:14 debian systemd[1]: chrony.service: Deleting
> chrony.service/stop to minimize impact.
> Jan 12 19:48:17 debian chronyd[401]: Selected source 162.159.200.1
> Jan 12 19:48:18 debian chronyd[401]: Selected source 173.249.58.145
> Jan 12 19:48:19 debian chronyd[401]: Source 129.70.132.37 replaced with
> 2a01:4f8:110:12c8::123
>
> ● systemd-timesyncd.service - Network Time Synchronization
> Loaded: loaded (/lib/systemd/system/systemd-timesyncd.service; enabled;
> vendor preset: enabled)
> Drop-In: /usr/lib/systemd/system/systemd-timesyncd.service.d
> └─disable-with-time-daemon.conf
> Active: inactive (dead)
> Docs: man:systemd-timesyncd.service(8)
> Jan 12 19:48:08 debian systemd-sysv-generator[232]: Native unit for
> chrony.service already exists, skipping.
> Jan 12 19:48:09 debian audit[296]: AVC apparmor="STATUS"
> operation="profile_load" profile="unconfined" name="/usr/sbin/chronyd"
> pid=296 comm="apparmor_parser"
> Jan 12 19:48:09 debian kernel: audit: type=1400 audit(1578854889.112:7):
> apparmor="STATUS" operation="profile_load" profile="unconfined"
> name="/usr/sbin/chronyd" pid=296 comm="apparmor_parser"
> Jan 12 19:48:09 debian chronyd[401]: chronyd version 3.4 starting (+CMDMON
> +NTP +REFCLOCK +RTC +PRIVDROP +SCFILTER +SIGND +ASYNCDNS +SECHASH +IPV6
> -DEBUG)
> Jan 12 19:48:09 debian chronyd[401]: Frequency 0.000 +/- 1000000.000 ppm read
> from /var/lib/chrony/chrony.drift
> Jan 12 19:48:09 debian chronyd[401]: Loaded seccomp filter
> Jan 12 19:48:09 debian systemd[1]: chrony.service:
> ConditionCapability=CAP_SYS_TIME succeeded.
> Jan 12 19:48:09 debian systemd[1]: chrony.service: Passing 0 fds to service
> Jan 12 19:48:09 debian systemd[1]: chrony.service: About to execute:
> /usr/sbin/chronyd $DAEMON_OPTS
> Jan 12 19:48:09 debian systemd[1]: chrony.service: Forked /usr/sbin/chronyd
> as 395
> Jan 12 19:48:09 debian systemd[1]: chrony.service: Changed dead -> start
> Jan 12 19:48:09 debian systemd[1]: Starting chrony, an NTP client/server...
> Jan 12 19:48:09 debian systemd[395]: Successfully mounted
> /tmp/systemd-private-c32de5dec7564bdd85daa27163fecfdb-chrony.service-2LqUhJ/tmp
> to /run/systemd/unit-root/tmp
> Jan 12 19:48:09 debian systemd[395]: Successfully mounted
> /var/tmp/systemd-private-c32de5dec7564bdd85daa27163fecfdb-chrony.service-aYqukO/tmp
> to /run/systemd/unit-root/var/tmp
> Jan 12 19:48:09 debian systemd[395]: chrony.service: Executing:
> /usr/sbin/chronyd -F -1
> Jan 12 19:48:09 debian systemd[1]: Received SIGCHLD from PID 400 (chronyd).
> Jan 12 19:48:09 debian systemd[1]: Child 395 (chronyd) died (code=exited,
> status=0/SUCCESS)
> Jan 12 19:48:09 debian systemd[1]: chrony.service: Child 395 belongs to
> chrony.service.
> Jan 12 19:48:09 debian systemd[1]: chrony.service: Control process exited,
> code=exited, status=0/SUCCESS
> Jan 12 19:48:09 debian systemd[1]: chrony.service: Got final SIGCHLD for
> state start.
> Jan 12 19:48:09 debian systemd[1]: chrony.service: New main PID 401 belongs
> to service, we are happy.
> Jan 12 19:48:09 debian systemd[1]: chrony.service: Main PID loaded: 401
> Jan 12 19:48:09 debian systemd[1]: chrony.service: About to execute:
> /usr/lib/chrony/chrony-helper update-daemon
> Jan 12 19:48:09 debian systemd[1]: chrony.service: Forked
> /usr/lib/chrony/chrony-helper as 404
> Jan 12 19:48:09 debian systemd[1]: chrony.service: Changed start -> start-post
> Jan 12 19:48:09 debian systemd[1]: Sent message type=signal sender=n/a
> destination=n/a path=/org/freedesktop/systemd1/unit/chrony_2eservice
> interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=31
> reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
> Jan 12 19:48:09 debian systemd[1]: Sent message type=signal sender=n/a
> destination=n/a path=/org/freedesktop/systemd1/unit/chrony_2eservice
> interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=32
> reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
> Jan 12 19:48:09 debian systemd[1]: Child 400 (chronyd) died (code=exited,
> status=0/SUCCESS)
> Jan 12 19:48:09 debian systemd[1]: chrony.service: Child 400 belongs to
> chrony.service.
> Jan 12 19:48:09 debian systemd-logind[380]: Got message type=signal
> sender=:1.0 destination=n/a
> path=/org/freedesktop/systemd1/unit/chrony_2eservice
> interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=31
> reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
> Jan 12 19:48:09 debian systemd-logind[380]: Got message type=signal
> sender=:1.0 destination=n/a
> path=/org/freedesktop/systemd1/unit/chrony_2eservice
> interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=32
> reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
> Jan 12 19:48:09 debian systemd[404]: Successfully mounted
> /tmp/systemd-private-c32de5dec7564bdd85daa27163fecfdb-chrony.service-2LqUhJ/tmp
> to /run/systemd/unit-root/tmp
> Jan 12 19:48:09 debian systemd[404]: Successfully mounted
> /var/tmp/systemd-private-c32de5dec7564bdd85daa27163fecfdb-chrony.service-aYqukO/tmp
> to /run/systemd/unit-root/var/tmp
> Jan 12 19:48:09 debian systemd[404]: chrony.service: Executing:
> /usr/lib/chrony/chrony-helper update-daemon
> Jan 12 19:48:09 debian systemd[1]: Received SIGCHLD from PID 404
> (chrony-helper).
> Jan 12 19:48:09 debian systemd[1]: Child 404 (chrony-helper) died
> (code=exited, status=0/SUCCESS)
> Jan 12 19:48:09 debian systemd[1]: chrony.service: Child 404 belongs to
> chrony.service.
> Jan 12 19:48:09 debian systemd[1]: chrony.service: Control process exited,
> code=exited, status=0/SUCCESS
> Jan 12 19:48:09 debian systemd[1]: chrony.service: Got final SIGCHLD for
> state start-post.
> Jan 12 19:48:09 debian systemd[1]: chrony.service: Changed start-post ->
> running
> Jan 12 19:48:09 debian systemd[1]: chrony.service: Job 75
> chrony.service/start finished, result=done
> Jan 12 19:48:09 debian systemd[1]: Started chrony, an NTP client/server.
> Jan 12 19:48:09 debian systemd[1]: Sent message type=signal sender=n/a
> destination=n/a path=/org/freedesktop/systemd1/unit/chrony_2eservice
> interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=38
> reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
> Jan 12 19:48:09 debian systemd[1]: Sent message type=signal sender=n/a
> destination=n/a path=/org/freedesktop/systemd1/unit/chrony_2eservice
> interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=39
> reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
> Jan 12 19:48:09 debian systemd[1]: Sent message type=signal sender=n/a
> destination=n/a path=/org/freedesktop/systemd1/unit/chrony_2eservice
> interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=41
> reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
> Jan 12 19:48:09 debian systemd[1]: Sent message type=signal sender=n/a
> destination=n/a path=/org/freedesktop/systemd1/unit/chrony_2eservice
> interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=42
> reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
> Jan 12 19:48:09 debian systemd-logind[380]: Got message type=signal
> sender=:1.0 destination=n/a
> path=/org/freedesktop/systemd1/unit/chrony_2eservice
> interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=38
> reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
> Jan 12 19:48:09 debian systemd-logind[380]: Got message type=signal
> sender=:1.0 destination=n/a
> path=/org/freedesktop/systemd1/unit/chrony_2eservice
> interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=39
> reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
> Jan 12 19:48:09 debian systemd-logind[380]: Got message type=signal
> sender=:1.0 destination=n/a
> path=/org/freedesktop/systemd1/unit/chrony_2eservice
> interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=41
> reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
> Jan 12 19:48:09 debian systemd-logind[380]: Got message type=signal
> sender=:1.0 destination=n/a
> path=/org/freedesktop/systemd1/unit/chrony_2eservice
> interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=42
> reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
> Jan 12 19:48:14 debian systemd[1]: Pulling in systemd-timesyncd.service/start
> from sysinit.target/start
> Jan 12 19:48:14 debian systemd[1]: Added job systemd-timesyncd.service/start
> to transaction.
> Jan 12 19:48:14 debian systemd[1]: Pulling in -.mount/start from
> systemd-timesyncd.service/start
> Jan 12 19:48:14 debian systemd[1]: Pulling in system.slice/start from
> systemd-timesyncd.service/start
> Jan 12 19:48:14 debian systemd[1]: Pulling in time-sync.target/start from
> systemd-timesyncd.service/start
> Jan 12 19:48:14 debian systemd[1]: Pulling in shutdown.target/stop from
> systemd-timesyncd.service/start
> Jan 12 19:48:14 debian systemd[1]: Pulling in chrony.service/stop from
> systemd-timesyncd.service/start
> Jan 12 19:48:14 debian systemd[1]: Added job chrony.service/stop to
> transaction.
> Jan 12 19:48:14 debian systemd[1]: Garbage collecting job
> systemd-timesyncd.service/start
> Jan 12 19:48:14 debian systemd[1]: Garbage collecting job chrony.service/stop
> Jan 12 19:48:14 debian systemd[1]: Pulling in systemd-timesyncd.service/start
> from sysinit.target/start
> Jan 12 19:48:14 debian systemd[1]: Added job systemd-timesyncd.service/start
> to transaction.
> Jan 12 19:48:14 debian systemd[1]: Pulling in -.mount/start from
> systemd-timesyncd.service/start
> Jan 12 19:48:14 debian systemd[1]: Pulling in system.slice/start from
> systemd-timesyncd.service/start
> Jan 12 19:48:14 debian systemd[1]: Pulling in time-sync.target/start from
> systemd-timesyncd.service/start
> Jan 12 19:48:14 debian systemd[1]: Pulling in shutdown.target/stop from
> systemd-timesyncd.service/start
> Jan 12 19:48:14 debian systemd[1]: Pulling in chrony.service/stop from
> systemd-timesyncd.service/start
> Jan 12 19:48:14 debian systemd[1]: Added job chrony.service/stop to
> transaction.
> Jan 12 19:48:14 debian systemd[1]: chrony.service: chrony.service/stop would
> stop a running service.
> Jan 12 19:48:14 debian systemd[1]: chrony.service: Deleting
> chrony.service/stop to minimize impact.
> Jan 12 19:48:14 debian systemd[1]: Garbage collecting job
> systemd-timesyncd.service/start
> Jan 12 19:48:17 debian chronyd[401]: Selected source 162.159.200.1
> Jan 12 19:48:18 debian chronyd[401]: Selected source 173.249.58.145
> Jan 12 19:48:19 debian chronyd[401]: Source 129.70.132.37 replaced with
> 2a01:4f8:110:12c8::123
signature.asc
Description: OpenPGP digital signature
