Kernel 6.6+ resets Pi4 clock to systemd creation date&time upon reboot

[by]

Describe the bug

When rebooting kernel 6.7 rc2 with RT patch rt1, time and date of PI4's internal (non-RTC) clock are reset to 20-Sep 14:15:14, the creation date of /etc/systemd/systemd.

Upon startup of ntp and/or an additional RTC during later phases of the boot process, the clock gets properly (re-)set to the current time.

This does not happen with the current distributed kernel 6.1.0-rpi6-rpi-v8.

Steps to reproduce the behaviour

Switching kernels, see above.

RT-kernel settings documented at https://github.com/by/RT-Kernel

Device (s)

Raspberry Pi 4 Mod. B

System

Linux xxx 6.7.0-rc2-rt1-v8-NTP+ #2 SMP PREEMPT_RT Fri Nov 24 21:00:40 CET 2023 aarch64 GNU/Linux

Logs

Sep 20 14:15:14 xxx kernel: Booting Linux on physical CPU 0x0000000000 [0x410fd083] Sep 20 14:15:14 xxx kernel: Linux version 6.7.0-rc2-rt1-v8-NTP+ (pi@chronos) (gcc (Debian 12.2.0-14) 12.2.0, GNU ld (GNU Binuti> Sep 20 14:15:14 xxx kernel: KASLR enabled Sep 20 14:15:14 xxx kernel: random: crng init done Sep 20 14:15:14 xxx kernel: Machine model: Raspberry Pi 4 Model B Rev 1.1 (...) Sep 20 14:15:15 xxx kernel: rtc-ds1307 1-0068: registered as rtc0 Nov 25 12:05:26 xxx kernel: rtc-ds1307 1-0068: setting system clock to 2023-11-25T11:05:26 UTC (1700910326) (...)

Additional context

No response

[by]

P.S.: Same situation with kernel 6.6 (no RT) from rpi-update rpi-6.6.y (rpi-update rpi-6.7.y fails w/ *** Invalid hash given):

Sep 20 14:15:14 xxx kernel: Booting Linux on physical CPU 0x0000000000 [0x410fd083] Sep 20 14:15:14 xxx kernel: Linux version 6.6.2-v8+ (runner@fv-az651-369) (aarch64-linux-gnu-gcc (Ubuntu 11.4.0-1ubuntu1~22.04)> Sep 20 14:15:14 xxx kernel: KASLR enabled Sep 20 14:15:14 xxx kernel: random: crng init done Sep 20 14:15:14 xxx kernel: Machine model: Raspberry Pi 4 Model B Rev 1.1

[by]

P.S.2: fakehwclock is uninstalled in all cases.

[pelwell]

I'm not seeing that on Bookworm with either 6.6 or 6.7, when testing using Pi 5 and its built-in RTC., but on a CM4+CM4IO running Bullseye with the onboard PCF85073a I do. However, reverting to a 6.1 doesn't change it.

I think you are seeing an artifact of a change in when logging messages are generated. On Bullseye (or it's version of systemd) the logging is captured earlier and therefore sees the change in clock, whereas Bookworm's systemd starts the capturing afterwards:

CM4 + Bullseye + 6.1:

pi@raspberrypi:~$ journalctl -r | grep -2 rtc0 | head -5
Dec 20 10:26:32 raspberrypi kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled
Dec 20 10:26:32 raspberrypi kernel: rtc-pcf85063 10-0051: setting system clock to 2023-12-20T10:26:32 UTC (1703067992)
Dec 20 10:26:32 raspberrypi kernel: rtc-pcf85063 10-0051: registered as rtc0
Dec 20 10:26:21 raspberrypi dhcpcd-run-hooks[454]: wlan0: starting wpa_supplicant
Dec 20 10:26:21 raspberrypi dhcpcd[435]: wlan0: starting wpa_supplicant

CM4 + Bullseye + 6.6.5-v8+:

pi@raspberrypi:~$ journalctl -r | grep -2 rtc0 | head -5
Dec 20 10:34:57 raspberrypi systemd[1]: Starting Raspberry Pi bluetooth helper...
Dec 20 10:34:57 raspberrypi kernel: rtc-pcf85063 10-0051: setting system clock to 2023-12-20T10:34:57 UTC (1703068497)
Dec 20 10:34:57 raspberrypi kernel: rtc-pcf85063 10-0051: registered as rtc0
Dec 20 10:34:57 raspberrypi dhcpcd-run-hooks[449]: wlan0: starting wpa_supplicant
Dec 20 10:34:45 raspberrypi systemd[1]: Started Configure Bluetooth Modems connected by UART.

Pi 5 + Bookworm + 6.7.0-rc6-v8-16k+:

pi@raspberrypi:~$ journalctl -r | grep -2 rtc0 | head -5
Dec 20 10:18:27 raspberrypi kernel: bcm2835-wdt bcm2835-wdt: Poweroff handler already present!
Dec 20 10:18:27 raspberrypi kernel: rpi-rtc soc:rpi_rtc: setting system clock to 2023-12-20T10:18:25 UTC (1703067505)
Dec 20 10:18:27 raspberrypi kernel: rpi-rtc soc:rpi_rtc: registered as rtc0
Dec 20 10:18:27 raspberrypi kernel: mousedev: PS/2 mouse device common for all mice
Dec 20 10:18:27 raspberrypi kernel: usbcore: registered new interface driver usb-storage

In all systems the time changes when the RTC is read. Disabling fakehwclock probably makes the change more obvious. However, the time is correct after the reading of the RTC, which happens very early. What appears to have changed is the time the logging is captured rather than the actual point where the time is corrected - look at the relationship between the timestamps in each of the captures above.

I don't consider this anything more than a curiosity.