Page 1 of 1

RevPi date changes repeatedly

Posted: 13 Jul 2020, 15:01
by RMeissnerCC
Dear all,
we observed issues of our software just getting stuck or freezing without any messages. We had this repeatedly over the last few weeks and thought it to be caused by various different issues.
Now, we observed that the date of the revpi itself reset repeatedly. Here an extract from /var/log/daemon.log

"Jun 25 12:54:46 RevPi39763 systemd[1846]: Stopped target Sockets.
Jun 25 12:54:46 RevPi39763 avahi-daemon[1659]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.243.10.
Jun 25 12:54:46 RevPi39763 systemd[1846]: Closed D-Bus User Message Bus Socket.
Jun 25 12:54:46 RevPi39763 avahi-daemon[1659]: avahi-daemon 0.6.32 exiting.
Jun 25 12:54:46 RevPi39763 systemd[1846]: Closed GnuPG cryptographic agent (access for web browsers).
Jun 25 12:54:46 RevPi39763 systemd[1846]: Closed GnuPG cryptographic agent and passphrase cache (restricted).
Jun 25 12:54:46 RevPi39763 systemd[1846]: Closed GnuPG cryptographic agent (ssh-agent emulation).
Jun 25 12:54:46 RevPi39763 systemd[1846]: Closed GnuPG cryptographic agent and passphrase cache.
Jun 25 12:54:46 RevPi39763 systemd[1846]: Reached target Shutdown.
Jun 25 12:54:46 RevPi39763 systemd[1846]: Starting Exit the Session...
Jun 25 12:44:25 RevPi39763 systemd-modules-load[136]: Inserted module 'i2c_dev'
Jun 25 12:44:25 RevPi39763 systemd-fsck[143]: e2fsck 1.43.4 (31-Jan-2017)
Jun 25 12:44:25 RevPi39763 systemd-fsck[143]: Superblock last mount time (Thu Jul 2 09:47:22 2020,
Jun 25 12:44:25 RevPi39763 systemd-fsck[143]: #011now = Thu Nov 3 18:16:43 2016) is in the future.
Jun 25 12:44:25 RevPi39763 systemd-fsck[143]: Fix? yes
Jun 25 12:44:25 RevPi39763 systemd-fsck[143]: Superblock last write time (Thu Jul 2 09:47:31 2020,
Jun 25 12:44:25 RevPi39763 systemd-fsck[143]: #011now = Thu Nov 3 18:16:43 2016) is in the future.
Jun 25 12:44:25 RevPi39763 systemd-fsck[143]: Fix? yes
Jun 25 12:44:25 RevPi39763 systemd-fsck[143]: Pass 1: Checking inodes, blocks, and sizes
Jun 25 12:44:25 RevPi39763 systemd-modules-load[136]: Inserted module 'piControl'
Jun 25 12:44:25 RevPi39763 systemd[1]: Started Load Kernel Modules.
Jun 25 12:44:25 RevPi39763 systemd[1]: Started Create Static Device Nodes in /dev.
"

Please observe, how time jumped back to 12:44:25. We observed this multiple times, each one followed by the line "Inserted module 'i2c_dev'". We cannot conclude yet, that only this line appeared after the time changed. The revpi is connected to the internet. We use a RevPi Connect 3+ with 32GB and the 4.19 kernel (newest kernel, but stretch image from last year march).

Which additional data would you need to understand this issue better?
Best, Robert

Re: RevPi date changes repeatedly

Posted: 13 Jul 2020, 15:02
by RMeissnerCC
After a reboot, the clock is also resetting to a few days in the past. From just now:

pi@127.0.0.1's password:
Linux RevPi39763 4.19.95-rt38-v7+ #1 SMP PREEMPT RT Tue, 16 Jun 2020 13:25:43 +0200 armv7l

The programs included with the Debian GNU/Linux system are free software;
the exact distribution terms for each program are described in the
individual files in /usr/share/doc/*/copyright.

Debian GNU/Linux comes with ABSOLUTELY NO WARRANTY, to the extent
permitted by applicable law.
Last login: Mon Jun 29 17:57:17 2020 from ::1
pi@RevPi39763:~ $ date
Thu Jun 25 12:44:43 CEST 2020



We did not perform the revpi-factory-reset yet. Could that be resolving it and how much of our installation (software packages, users, ...) could that change and break?

Re: RevPi date changes repeatedly

Posted: 14 Jul 2020, 08:28
by RMeissnerCC
Dear all,
by applying the revpi factory reset and setting the hardware clock manually (hwclock) I got the clock to work again, even beyond a reboot.
BUT, this feels rather manually.
`timedatectl` works again and shows:

Local time: Tue 2020-07-14 08:26:10 CEST
Universal time: Tue 2020-07-14 06:26:10 UTC
RTC time: Tue 2020-07-14 06:26:10
Time zone: Europe/Berlin (CEST, +0200)
Network time on: yes
NTP synchronized: no
RTC in local TZ: no

But for some reason I cannot get NTP to sychronize automatically. Does anyone have a suggestion for this?

Best, Robert

P.S.: A side note: we have two RevPi Connects in use. Both have been flashed with the same image, one showed this clock problem, the other did not. What could be the cause for this difference?

Re: RevPi date changes repeatedly

Posted: 15 Jul 2020, 13:11
by zhan
Hello Robert,

Probability the reason of the problems is that the capacitor of one device was used up, while the other is not.
The RTC chip which holds the time is supplied by a super capacitor. When the capacitor is used up, the time of the device is unpredictable.
From the information you provided in this post, it seems that the problems are caused by a faulty time.

After the device is powering on for several hours, the capacitor should be full charged. And,
with command "sudo hwclock -s ", you should be able to save the current system time to the RTC chip again.
(this should be done after the "NTP synchronized" says "yes")

Regards,
Simon

Re: RevPi date changes repeatedly

Posted: 15 Jul 2020, 14:03
by lukas
Hi Robert,

if you haven't run revpi-factory-reset yet, then the RTC is not accessible, hence cannot be used to store or retrieve the time. Once you run revpi-factory-reset, the devicetree overlay for your product is loaded. It contains information about the devices present in the system, allowing the kernel to discover and make use of the RTC. revpi-factory-reset also adds an entry to /boot/config.txt which causes the devicetree overlay to be loaded on every future reboot.

If the machine is booted without access to the RTC and any NTP servers, the initial system time is set to the timestamp of the file /var/lib/systemd/timesync/clock. The timestamp corresponds to the build date of the systemd version on your system if no successful NTP synchronization has ever occurred. Once NTP is synchronized, the timestamp of that file is updated.

On your system, you must have had a successful NTP synchronization on June 25. Afterwards you booted the machine without access to the RTC and to NTP servers, hence the clock was initialized to June 25.

So this is perfectly normal and expected behavior.

Re: RevPi date changes repeatedly

Posted: 30 Jul 2020, 11:40
by RMeissnerCC
Dear all,
after factory reseting the devices it worked fine. I also noticed that I had to restart the service "systemd-networkd", that one had failed.
During the last two weeks, we had no more problems with the clock.
Thank you for your help :)