Strange behaviour probably related to time syncing
1
vote
0
answers
205
views
I have a raspberry pi running Raspbian bullseye. On it, I have a software installed that does the following every 30 seconds:
- logs data to a mariadb database
- publishes the data via a rest api
- publishes the data via MQTT
On irregular instances (about every few days),
- the data stops being logged to mariadb and
- ssh stops working ("kex_exchange_identification: read: Connection reset by peer")
- but rest api and MQTT still work fine, so the machine is still up.
I think the problem is related to time syncing, any help to further investigate is highly appreciated.
Here is what I've got so far:
journalctl -u systemd-timesyncd --no-hostname --since "1 day ago"
-- Boot d689dc8fa3c1460a9e301ea7e3d024e4 --
Jul 06 23:17:10 systemd-timesyncd: System clock time unset or jumped backwards, restoring from recorded timestamp: Sat 2024-07-06 23:44:05 CEST
Jul 06 23:44:05 systemd: Started Network Time Synchronization.
Jul 06 23:44:45 systemd-timesyncd: Timed out waiting for reply from 144.76.43.40:123 (0.de.pool.ntp.org).
Jul 07 07:41:32 systemd-timesyncd: Initial synchronization to time server 116.202.171.176:123 (0.de.pool.ntp.org).
-- Boot 1833ccc33db04f41af2486ff4a4bc63a --
Jul 06 23:17:13 systemd-timesyncd: System clock time unset or jumped backwards, restoring from recorded timestamp: Sun 2024-07-07 07:45:17 CEST
Jul 07 07:45:17 systemd: Started Network Time Synchronization.
Jul 07 07:45:57 systemd-timesyncd: Timed out waiting for reply from 178.63.9.212:123 (0.de.pool.ntp.org).
Jul 07 07:47:07 systemd-timesyncd: Initial synchronization to time server 141.144.230.32:123 (0.de.pool.ntp.org).
systemd-analyze dot systemd-timesyncd.service
digraph systemd {
"time-set.target"->"systemd-timesyncd.service" [color="green"];
"systemd-timesyncd.service"->"systemd-tmpfiles-setup.service" [color="green"];
"systemd-timesyncd.service"->"system.slice" [color="green"];
"systemd-timesyncd.service"->"-.mount" [color="green"];
"systemd-timesyncd.service"->"systemd-remount-fs.service" [color="green"];
"systemd-timesyncd.service"->"systemd-sysusers.service" [color="green"];
"systemd-timesyncd.service"->"systemd-journald.socket" [color="green"];
"systemd-timesyncd.service"->"system.slice" [color="black"];
"systemd-timesyncd.service"->"-.mount" [color="black"];
"systemd-timesyncd.service"->"time-set.target" [color="grey66"];
"systemd-timesyncd.service"->"time-sync.target" [color="grey66"];
"systemd-timesyncd.service"->"shutdown.target" [color="red"];
"shutdown.target"->"systemd-timesyncd.service" [color="green"];
"vzlogger.service"->"systemd-timesyncd.service" [color="green"];
"sysinit.target"->"systemd-timesyncd.service" [color="green"];
"sysinit.target"->"systemd-timesyncd.service" [color="grey66"];
}
sudo systemctl status systemd-timesyncd.service
● systemd-timesyncd.service - Network Time Synchronization
Loaded: loaded (/lib/systemd/system/systemd-timesyncd.service; enabled; vendor preset: enabled)
Active: active (running) since Sun 2024-07-07 07:45:17 CEST; 6min ago
Docs: man:systemd-timesyncd.service(8)
Main PID: 369 (systemd-timesyn)
Status: "Initial synchronization to time server 141.144.230.32:123 (0.de.pool.ntp.org)."
Tasks: 2 (limit: 3932)
CPU: 292ms
CGroup: /system.slice/systemd-timesyncd.service
└─369 /lib/systemd/systemd-timesyncd
timedatectl status
Local time: So 2024-07-07 07:52:12 CEST
Universal time: So 2024-07-07 05:52:12 UTC
RTC time: n/a
Time zone: Europe/Berlin (CEST, +0200)
System clock synchronized: yes
NTP service: active
RTC in local TZ: no
cat /lib/systemd/system/systemd-timesyncd.service
# [commented out general info]
[Unit]
Description=Network Time Synchronization
Documentation=man:systemd-timesyncd.service(8)
ConditionCapability=CAP_SYS_TIME
ConditionVirtualization=!container
DefaultDependencies=no
After=systemd-sysusers.service
Before=time-set.target sysinit.target shutdown.target
Conflicts=shutdown.target
Wants=time-set.target time-sync.target
[Service]
AmbientCapabilities=CAP_SYS_TIME
BusName=org.freedesktop.timesync1
CapabilityBoundingSet=CAP_SYS_TIME
ExecStart=!!/lib/systemd/systemd-timesyncd
LockPersonality=yes
MemoryDenyWriteExecute=yes
NoNewPrivileges=yes
PrivateDevices=yes
PrivateTmp=yes
ProtectProc=invisible
ProtectControlGroups=yes
ProtectHome=yes
ProtectHostname=yes
ProtectKernelLogs=yes
ProtectKernelModules=yes
ProtectKernelTunables=yes
ProtectSystem=strict
Restart=always
RestartSec=0
RestrictAddressFamilies=AF_UNIX AF_INET AF_INET6
RestrictNamespaces=yes
RestrictRealtime=yes
RestrictSUIDSGID=yes
RuntimeDirectory=systemd/timesync
StateDirectory=systemd/timesync
SystemCallArchitectures=native
SystemCallErrorNumber=EPERM
SystemCallFilter=@system-service @clock
Type=notify
User=systemd-timesync
WatchdogSec=3min
[Install]
WantedBy=sysinit.target
cat /etc/systemd/system/systemd-timesyncd.timer
: /etc/systemd/system/systemd-timesyncd.timer: No such file or directory
cat /etc/systemd/timesyncd.conf
# [commented out general info]
[Time]
NTP=0.de.pool.ntp.org
FallbackNTP=0.debian.pool.ntp.org 1.debian.pool.ntp.org 2.debian.pool.ntp.org 3.debian.pool.ntp.org 1.de.pool.ntp.org 2.de.pool.ntp.org
#RootDistanceMaxSec=5
#PollIntervalMinSec=32
#PollIntervalMaxSec=2048
Edit: Thanks for the hints. I installed chrony and changed the NTP servers, let's see if anything changes. So far, no issue.
Second edit: problem arised today again, here is some info that might help you:
The system rebootet three times within a short timespan (from journalctl
):
-- Boot b1fe1bcf01554348828247969af37f88 --
Jul 09 12:17:01 raspberrypi kernel: Booting Linux on physical CPU 0x0000000000 [0x410fd083]
Jul 09 12:17:01 raspberrypi kernel: Linux version 6.1.21-v8+ (dom@buildbot) (aarch64-linux-gnu-gcc-8 (Ubuntu/Linaro 8.4.0-3ubuntu1) 8.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1642 SMP PREEMPT Mon Apr 3 17:24:16 BST 2023
Jul 09 12:17:01 raspberrypi kernel: random: crng init done
Jul 09 12:17:01 raspberrypi kernel: Machine model: Raspberry Pi 4 Model B Rev 1.2
-- Boot c7607911dbbe4ed7b10cf3df812b2c16 --
Jul 09 12:17:01 raspberrypi CRON: pam_unix(cron:session): session closed for user root
-- Boot b1fe1bcf01554348828247969af37f88 --
and then it showed some issues:
Jul 09 12:17:36 raspberrypi bluetoothd: profiles/sap/server.c:sap_server_register() Sap driver initialization failed.
Jul 09 12:17:36 raspberrypi bluetoothd: sap-server: Operation not permitted (1)
Jul 09 12:17:36 raspberrypi bluetoothd: Failed to set mode: Rejected (0x0b)
Jul 09 12:17:36 raspberrypi bluetoothd: Failed to set mode: Rejected (0x0b)
Jul 09 12:17:36 raspberrypi bluetoothd: Failed to set privacy: Rejected (0x0b)
Jul 09 12:17:36 raspberrypi dbus-daemon: [system] Successfully activated service 'org.freedesktop.hostname1'
Jul 09 12:17:36 raspberrypi systemd: Started Hostname Service.
Jul 09 12:17:36 raspberrypi pulseaudio: Failed to find a working profile.
Jul 09 12:17:36 raspberrypi pulseaudio: Failed to load module "module-alsa-card" (argument: "device_id="1" name="platform-fef00700.hdmi" card_name="alsa_card.platform-fef00700.hdmi" namereg_fail=false tsched=no fixed_lat>
Jul 09 12:17:36 raspberrypi pulseaudio: Failed to find a working profile.
Jul 09 12:17:36 raspberrypi pulseaudio: Failed to load module "module-alsa-card" (argument: "device_id="2" name="platform-fef05700.hdmi" card_name="alsa_card.platform-fef05700.hdmi" namereg_fail=false tsched=no fixed_lat>
Then, another reboot (no error message before that):
-- Boot b1fe1bcf01554348828247969af37f88 --
Jul 09 12:18:03 raspberrypi chronyd: Selected source 185.183.159.238 (2.debian.pool.ntp.org)
Jul 09 12:18:03 raspberrypi chronyd: System clock wrong by 6401.522525 seconds
Jul 09 14:04:45 raspberrypi chronyd: System clock was stepped by 6401.522525 seconds
Jul 09 14:04:45 raspberrypi chronyd: System clock TAI offset set to 37 seconds
Asked by ununoctium
(11 rep)
Jul 7, 2024, 12:56 PM
Last activity: Jul 9, 2024, 12:31 PM
Last activity: Jul 9, 2024, 12:31 PM