Time is not synced when system starts before surrounding network

[t-dan]

Describe the bug

When my Raspberry 4 starts, the time is not synchronized correctly. It seems to me that it occurres when the libreElec starts before the other network infrastructure (e.g. on electricity shutdown and restart of the whole village)

To Reproduce

Steps to reproduce the behavior:

1. switch the router of the local net OFF
2. start openElec
3. switch the router ON
   Not sure, if it will work, though ...

Informations

• LE Version: 9.2.5
• Hardware Platform: RPi4.arm

Log file

network-online.service and kodi-waitonnetwork.service are in failed state while wait-time-sync.service is still running (forever). Besides that, all works without problems.
Note that the date is wrong in the long, but the message shows "1 years 7 months ago" since I have started ntpd then.

connman.service
● connman.service - Connection service
Loaded: loaded (/usr/lib/systemd/system/connman.service; enabled; vendor preset: disabled)
Active: active (running) since Thu 2019-04-11 18:28:38 CEST; 1 years 7 months ago
Main PID: 335 (connmand)
Memory: 2.2M
CGroup: /system.slice/connman.service
└─335 /usr/sbin/connmand -nr --config=/etc/connman/main.conf

Apr 11 18:29:28 libreElec connmand[335]: eth0 {add} route 0.0.0.0 gw 0.0.0.0 scope 253
Apr 11 18:31:48 libreElec connmand[335]: eth0 {del} address 169.254.249.21/16 label eth0
Apr 11 18:31:48 libreElec connmand[335]: eth0 {del} route 169.254.0.0 gw 0.0.0.0 scope 253
Apr 11 18:31:48 libreElec connmand[335]: eth0 {add} address 192.168.200.12/24 label eth0 family 2
Apr 11 18:31:48 libreElec connmand[335]: eth0 {add} route 192.168.200.0 gw 0.0.0.0 scope 253
Apr 11 18:31:48 libreElec connmand[335]: eth0 {add} route 192.168.200.1 gw 0.0.0.0 scope 253
Apr 11 18:31:48 libreElec connmand[335]: eth0 {add} route 0.0.0.0 gw 192.168.200.1 scope 0
Apr 11 18:31:48 libreElec connmand[335]: eth0 {add} route 212.227.81.55 gw 192.168.200.1 scope 0
Apr 11 18:31:48 libreElec connmand[335]: eth0 {del} route 212.227.81.55 gw 192.168.200.1 scope 0

network-online.service
● network-online.service - Wait for network to be configured by ConnMan
Loaded: loaded (/usr/lib/systemd/system/network-online.service; enabled; vendor preset: disabled)
Active: failed (Result: exit-code) since Thu 2019-04-11 18:29:08 CEST; 1 years 7 months ago
Main PID: 346 (code=exited, status=110)

Apr 11 18:28:38 libreElec systemd[1]: Starting Wait for network to be configured by ConnMan...
Apr 11 18:29:08 libreElec systemd[1]: network-online.service: Main process exited, code=exited, status=110/n/a
Apr 11 18:29:08 libreElec systemd[1]: network-online.service: Failed with result 'exit-code'.
Apr 11 18:29:08 libreElec systemd[1]: Failed to start Wait for network to be configured by ConnMan.

wait-time-sync.service
● wait-time-sync.service - Wait For Kernel Time Synchronized
Loaded: loaded (/usr/lib/systemd/system/wait-time-sync.service; disabled; vendor preset: disabled)
Active: activating (start) since Thu 2019-04-11 18:28:36 CEST; 1 years 7 months ago
Main PID: 189 (wait-time-sync)
Memory: 404.0K
CGroup: /system.slice/wait-time-sync.service
└─189 /usr/bin/wait-time-sync

kodi-waitonnetwork.service
● kodi-waitonnetwork.service - Wait on network
Loaded: loaded (/usr/lib/systemd/system/kodi-waitonnetwork.service; disabled; vendor preset: disabled)
Active: failed (Result: exit-code) since Thu 2019-04-11 18:28:48 CEST; 1 years 7 months ago
Main PID: 345 (code=exited, status=110)
Apr 11 18:28:38 libreElec systemd[1]: Starting Wait on network...
Apr 11 18:28:48 libreElec systemd[1]: kodi-waitonnetwork.service: Main process exited, code=exited, status=110/n/a
Apr 11 18:28:48 libreElec systemd[1]: kodi-waitonnetwork.service: Failed with result 'exit-code'.
Apr 11 18:28:48 libreElec systemd[1]: Failed to start Wait on network.

[chewitt]

Pi hardware has no RTC so depends on NTP, and if "other network infrastructure" is not available (internet no up yet etc.) then NTP will fail and system clock starts at the current libc elease date (April 2019). ConnMan will make repeated NTP checks with a progressively decreasing frequency, but if you leave it alone, onoce the router/internet comes up it will eventually set the clock correctly.

This is normal behaviour for Pi hardware (there is no bug) so I will be closing the ticket. If the behaviour bothers you; get an RTC chip/battery https://thepihut.com/products/mini-rtc-module-for-raspberry-pi

[t-dan]

OK, understand.
But still, is there a way of saying connmann to repeat the trial again? One can write a systemd timer to do so, for example ...

And one more think - why is the network-online.service (and possibly kodi-waitonnetwork.service) in failed state? It should not be there, if it is not a bug, should be? The address is assigned correctly after all.

This still is an issue, isn't it?

[chewitt]

https://git.kernel.org/pub/scm/network/connman/connman.git/commit/?id=bb194cf63688c74713d6fa9c64f99d5c463d1dae

^ ConnMan repeatedly makes NTP requests if the initial request fails - this commit was explicitly made to solve the issue of Pi boards with no RTC having issues (reported by me to the connman devs). If the network could not resolve ipv4.connman.net (which it would not if the internet is down) the service will remain in an offline state.

If a reboot after the rest of the infra resolved all .. "nothing to see here, move along please"

[mglae]

@t-dan If you can reproducete issue and want do some more research you can enable connman debug logging by creating /storage/.config/system.d/connman.service.d/debug.conf:

[Service]
Environment=CONNMAN_DEBUG=--debug

and reboot.

Afterwards user journalctl to see the log.

But as said: if there is no obvious configuration error this is a connman issue.