agherzan / meta-raspberrypi

Yocto/OE BSP layer for the Raspberry Pi boards
https://www.yoctoproject.org/
MIT License
520 stars 407 forks source link

[raspberrypi4-64][honister] timedatectl timesync not working #1113

Open bojidartonchev opened 1 year ago

bojidartonchev commented 1 year ago

Hello,

After migrating from dunfell to honister, time synchronization stopped working for raspberrypi4-64. On dunfell, it takes about 3 seconds after connecting to Wifi to sync the time. On honister it never does.

I have the following patch for systemd's timesyncd.conf:

[Time]
NTP=0.europe.pool.ntp.org
FallbackNTP=1.europe.pool.ntp.org 2.europe.pool.ntp.org 3.europe.pool.ntp.org
RootDistanceMaxSec=30
ConnectionRetrySec=5

This is the timedatectl output:

root@raspberrypi4-64:~# timedatectl
               Local time: Fri 2021-11-19 17:20:49 UTC
           Universal time: Fri 2021-11-19 17:20:49 UTC
                 RTC time: n/a
                Time zone: Universal (UTC, +0000)
System clock synchronized: no
              NTP service: active
          RTC in local TZ: no

The output for timedatectl timesync-status. Obviously it didn't read the timesyncd.conf

root@raspberrypi4-64:/etc/systemd/network# timedatectl timesync-status
       Server: n/a (n/a)
Poll interval: 0 (min: 32s; max 34min 8s)
 Packet count: 0

Manually running /lib/systemd/systemd-timesyncd stucks at resolving servers:

root@raspberrypi4-64:~# SYSTEMD_LOG_LEVEL=debug /lib/systemd/systemd-timesyncd
Bus bus-api-timesync: changing state UNSET → OPENING
sd-bus: starting bus bus-api-timesync by connecting to /run/dbus/system_bus_socket...
Bus bus-api-timesync: changing state OPENING → AUTHENTICATING
Registering bus object implementation for path=/org/freedesktop/LogControl1 iface=org.freedesktop.LogControl1
Added new server 0.europe.pool.ntp.org.
Added new server 1.europe.pool.ntp.org.
Added new server 2.europe.pool.ntp.org.
Added new server 3.europe.pool.ntp.org.
systemd-timesyncd running as pid 280
Bus bus-api-timesync: changing state AUTHENTICATING → HELLO
Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=Hello cookie=1 reply_cookie=0 signature=n/a error-name=n/a error-message=n/a
Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=RequestName cookie=2 reply_cookie=0 signature=su error-name=n/a error-message=n/a
Got message type=method_return sender=org.freedesktop.DBus destination=:1.21 path=n/a interface=n/a member=n/a cookie=1 reply_cookie=1 signature=s error-name=n/a error-message=n/a
Bus bus-api-timesync: changing state HELLO → RUNNING
Got message type=signal sender=org.freedesktop.DBus.Local destination=n/a path=/org/freedesktop/DBus/Local interface=org.freedesktop.DBus.Local member=Connected cookie=4294967295 reply_cookie=0 signature=n/a error-name=n/a error-message=n/a
Got message type=signal sender=org.freedesktop.DBus destination=:1.21 path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=NameAcquired cookie=2 reply_cookie=0 signature=s error-name=n/a error-message=n/a
Got message type=signal sender=org.freedesktop.DBus destination=:1.21 path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=NameAcquired cookie=3 reply_cookie=0 signature=s error-name=n/a error-message=n/a
Got message type=method_return sender=org.freedesktop.DBus destination=:1.21 path=n/a interface=n/a member=n/a cookie=4 reply_cookie=2 signature=u error-name=n/a error-message=n/a
Successfully acquired requested service name.

But systemd resolvectl has no problems resolving the above server:

root@raspberrypi4-64:~# resolvectl query 0.europe.pool.ntp.org
0.europe.pool.ntp.org: 88.209.121.106          -- link: wlan0
                       91.235.212.22           -- link: wlan0
                       185.32.222.237          -- link: wlan0
                       193.52.136.2            -- link: wlan0

-- Information acquired via protocol DNS in 45.1ms.
-- Data is authenticated: no; Data was acquired via local or encrypted transport: no
-- Data from: network

Any help would be appreciated!

P.S Tested with the same configuration on kirkstone and everything seems fine there.

Best regards.

agherzan commented 1 year ago

Is the network interface up?

Piocky commented 1 year ago

It works well for you on kirkstone? I've got kind of the same result on my side (switching from dunfell to kirkstone), except that it takes approximately 3-4 minutes to get timesync. The only solution I found to reduce this time is to add:

ExecStartPre=/usr/sbin/ntpd -g -q
ExecStart=/usr/sbin/ntpd -u ntp:ntp -p /run/ntpd.pid -g

in /lib/systemd/system/ntpd.service

From what I understand, it seems that systemd-timesyncd.service is used on dunfell:

root@raspberrypi4:~# journalctl -u  systemd-timesyncd
Jan 01 01:00:04 localhost systemd[1]: Starting Network Time Synchronization...
Jan 01 01:00:04 localhost systemd[1]: Started Network Time Synchronization.
Jan 01 01:00:10 Piccolo-Noire systemd-timesyncd[208]: Network configuration changed, trying to establish connection.
Jan 06 12:42:25 Piccolo-Noire systemd-timesyncd[208]: Initial synchronization to time server 216.239.35.0:123 (time1.google.com).

On kirkstone i've got nothing:

root@raspberrypi4:~# journalctl -u  systemd-timesyncd
Jan 01 01:00:05 localhost systemd[1]: Starting Network Time Synchronization...
Jan 01 01:00:05 localhost systemd[1]: Started Network Time Synchronization.

But I do see stuff with ntpd.service:

root@raspberrypi4:~# journalctl -u ntpd
Jan 01 01:00:06 raspberrypi4 systemd[1]: Starting Network Time Service...
Jan 01 01:00:06 raspberrypi4 ntpd[293]:  1 Jan 01:00:06 ntpd[293]: ntpd 4.2.8p15@1.3728-o Tue 23 Jun 2020 09:22:22 AM UTC (1): Starting
Jan 01 01:00:06 raspberrypi4 ntpd[293]:  1 Jan 01:00:06 ntpd[293]: Command line: /usr/sbin/ntpd -g -q
Jan 01 01:00:06 raspberrypi4 ntpd[293]:  1 Jan 01:00:06 ntpd[293]: ----------------------------------------------------
Jan 01 01:00:06 raspberrypi4 ntpd[293]:  1 Jan 01:00:06 ntpd[293]: ntp-4 is maintained by Network Time Foundation,
Jan 01 01:00:06 raspberrypi4 ntpd[293]:  1 Jan 01:00:06 ntpd[293]: Inc. (NTF), a non-profit 501(c)(3) public-benefit
Jan 01 01:00:06 raspberrypi4 ntpd[293]:  1 Jan 01:00:06 ntpd[293]: corporation.  Support and training for ntp-4 are
Jan 01 01:00:06 raspberrypi4 ntpd[293]:  1 Jan 01:00:06 ntpd[293]: available at https://www.nwtime.org/support
Jan 01 01:00:06 raspberrypi4 ntpd[293]:  1 Jan 01:00:06 ntpd[293]: ----------------------------------------------------
Jan 01 01:00:06 raspberrypi4 ntpd[293]:  1 Jan 01:00:06 ntpd[293]: proto: precision = 6.926 usec (-17)
Jan 01 01:00:06 raspberrypi4 ntpd[293]:  1 Jan 01:00:06 ntpd[293]: basedate set to 2020-06-11
Jan 01 01:00:06 raspberrypi4 ntpd[293]:  1 Jan 01:00:06 ntpd[293]: gps base set to 2020-06-14 (week 2110)
Jan 01 01:00:06 raspberrypi4 ntpd[293]:  1 Jan 01:00:06 ntpd[293]: Listen and drop on 0 v6wildcard [::]:123
Jan 01 01:00:06 raspberrypi4 ntpd[293]:  1 Jan 01:00:06 ntpd[293]: Listen and drop on 1 v4wildcard 0.0.0.0:123
Jan 01 01:00:06 raspberrypi4 ntpd[293]:  1 Jan 01:00:06 ntpd[293]: Listen normally on 2 lo 127.0.0.1:123
Jan 01 01:00:06 raspberrypi4 ntpd[293]:  1 Jan 01:00:06 ntpd[293]: Listen normally on 3 lo [::1]:123
Jan 01 01:00:06 raspberrypi4 ntpd[293]:  1 Jan 01:00:06 ntpd[293]: Listening on routing socket on fd #20 for interface updates
Jan 01 01:00:14 raspberrypi4 ntpd[293]:  1 Jan 01:00:14 ntpd[293]: Listen normally on 4 wlan0 [fe80::da5b:a660:4196:a985%3]:123
Jan 01 01:00:14 raspberrypi4 ntpd[293]:  1 Jan 01:00:14 ntpd[293]: new interface(s) found: waking up resolver
Jan 01 01:00:21 raspberrypi4 ntpd[293]:  1 Jan 01:00:21 ntpd[293]: Listen normally on 5 wlan0 192.168.0.101:123
Jan 01 01:00:21 raspberrypi4 ntpd[293]:  1 Jan 01:00:21 ntpd[293]: new interface(s) found: waking up resolver
Jan 06 16:13:10 raspberrypi4 ntpd[293]:  6 Jan 16:13:10 ntpd[293]: ntpd: time set +1673017958.292877 s
Jan 06 16:13:10 raspberrypi4 ntpd[293]: ntpd: time set +1673017958.292877s
Jan 06 16:13:10 raspberrypi4 systemd[1]: Started Network Time Service.

Is there a reason for systemd-timesyncd not being used anymore? The service is still up and running though.