External Time Source -DS3231 need help

[TD-er]

I just tested it on an ESP32 board I made.
Can also test it on any NodeMCU board.

[igorka]

Can also test it on any NodeMCU board.

If you don't mind, check on ESP8266.After all, I have problems with this particular controller.
Thanks!

[chemmex]

I just tried this build with DS3231 on ESP8266 (bare ESP-12F module).

The time is read correctly from DS3231 after a cold restart.

[chemmex]

A question to TD-er: are you planning to resolve the NTP/RTC priority if both time sources are enabled and available?

[TD-er]

A question to TD-er: are you planning to resolve the NTP/RTC priority if both time sources are enabled and available?

That has been resolved in the current code. (fixed it last week)

I do compute some weighted value from all time sources.
RTC is only read once at boot.
NTP is done at the same intervals as it was before (some randomness to make sure we're not DDoS-ing the time servers when all nodes boot at the same time like after a power outage)
P2P nodes check the time source reported from other nodes and pick the one which has likely the most accurate time.
This takes into account the time since last sync and the sync source.
I estimated a node would wander about 4 ppm (roughly half of the tolerance allowed by the crystal) and added some "penalty" score depending on the time source.
GPS is one of the best sources, then NTP, etc.
It also would prefer other time sources over "only p2p" as this may cause quite a significant drift over time if there is no external sync.

Also the accuracy from GPS has now improved as I try to calculate when the first bytes were received from the GPS.
Before this fix its accuracy was actually worse than NTP.

[chemmex]

So, initial NTP request is only sent if no external RTC or GPS is configured? Then next question: does a successful NTP update also update RTC?

[TD-er]

So, initial NTP request is only sent if no external RTC or GPS is configured?

Nope, NTP is done as always.
But if there's no network, NTP will fail and then you have RTC as backup.

Then next question: does a successful NTP update also update RTC?

Yep, as will GPS, or p2p time sync, or manual time sync, etc.

[chemmex]

Nope, NTP is done as always.

To be honest, this doesn't seem to happen:

Code: Select all

INIT : Booting version: ESP_Easy_mega_20221108_custom_ESP8266_4M1M, (Self built) 20221108TZ_noDebug (ESP82xx Core 2843a5ac, NONOS SDK 2.2.2-dev(c0eb301), LWIP: 2.1.2 PUYA support)
5267 : Info   : INIT : Free RAM:25688
5268 : Info   : INIT : Cold Boot - Restart Reason: Power On
5269 : Info   : FS   : Mounting...
5295 : Info   : FS   : Mount successful, used 85591 bytes of 957314
5310 : Info   : CRC  : Settings CRC           ...OK
5313 : Info   : CRC  : SecuritySettings CRC   ...OK
5316 : Info   : INIT : I2C
5318 : Info   : INIT : SPI not enabled
5319 : Error  : ExtRTC: Cannot get time from external time source
5424 : Info   : WIFI : Set WiFi to STA
7724 : Info   : WIFI : Connecting xxxx  (-55dBm) WPA2/PSK attempt #0
7907 : Info   : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 81 ms
8008 : Info   : Reset WiFi.
10209 : Info   : WIFI : Connecting xxxx (-57dBm) WPA2/PSK attempt #1
11159 : Info   : WIFI : Disconnected! Reason: '(8) Assoc leave' Connected for 81 ms
11159 : Info   : WIFI : Set WiFi to OFF
11272 : Info   : INIT : Free RAM:24136
11364 : Info   : INFO : Plugins: 14 [No Debug Log] (ESP82xx Core 2843a5ac, NONOS SDK 2.2.2-dev(c0eb301), LWIP: 2.1.2 PUYA support)
11365 : Info   : EVENT: System#Wake
11508 : Info   : Webserver: start
11509 : Info   : EVENT: System#Boot
15288 : Info   : ExtRTC: Read external time source: 1667914925
15288 : Info   : Time set to 1667914925.000
15290 : Info   : Current Time Zone: STD time start: 2022-10-30 03:00:00 offset: 180 min
15293 : Info   : Local time: 2022-11-08 16:42:05
15307 : Info   : EVENT: WiFi#Disconnected
15381 : Info   : EVENT: Clock#Time=Tue,16:42
15400 : Info   : WD   : Uptime 0 ConnectFailures 0 FreeMem 13848 WiFiStatus WL_IDLE_STATUS 0 ESPeasy internal wifi status: DISCONNECTED
15478 : Info   : EVENT: WiFi#Disconnected
15497 : Info   : EVENT: WiFi#APmodeEnabled
15538 : Info   : EVENT: Time#Initialized
20212 : Info   : WIFI : Connecting xxx (-51dBm) WPA2/PSK attempt #2
21612 : Info   : WIFI : DHCP IP: 192.168.10.229 (ESPEasy) GW: 192.168.10.129 SN: 255.255.255.128   duration: 296 ms
21614 : Info   : firstLoopConnectionsEstablished
21616 : Info   : WIFI : Connected! AP: xxxx Ch: 9 Duration: 1090 ms
21618 : Info   : EVENT: WiFi#Connected
21631 : Info   : EVENT: WiFi#ChangedAccesspoint
21641 : Info   : EVENT: WiFi#ChangedWiFichannel
21721 : Error  : MQTT : Intentional reconnect
21777 : Info   : MQTT : Connected to broker with client ID: ESPEasy
21780 : Info   : Subscribed to: ESPEasy/#
21785 : Info   : EVENT: MQTT#Connected

It only read the RTC but didn't ask for NTP

[TD-er]

Hmm I wil look into it.

Can you keep an eye on it to see if it may still call NTP in like 2 minutes or 30 or 60?
You should see the used time source both on the root page, or the sysinfo page.
N.B. those minutes I mentioned are used intervals in the code.

[chemmex]

Yes, I will check that

[Ath]

NTP is probably unchecked in Tools/Advanced settings, so it shouldn't be called, I expect (read: hope )

[chemmex]

NTP is probably unchecked in Tools/Advanced settings, so it shouldn't be called, I expect (read: hope )

Not this time, I played too much with that
I intentionally set wrong time

[chemmex]

Can you keep an eye on it to see if it may still call NTP in like 2 minutes or 30 or 60?
You should see the used time source both on the root page, or the sysinfo page.

No, nothging so far

[chemmex]

Found an NTP transaction in the log, 10 min after the previous message:

Code: Select all

3564139: EVENT: Clock#Time=Sat,4:29
3582556: WD : Uptime 60 ConnectFailures 0 FreeMem 20984 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
3612556: WD : Uptime 60 ConnectFailures 0 FreeMem 20960 WiFiStatus WL_CONNECTED 3 ESPeasy internal wifi status: Conn. IP Init
3615167: NTP : NTP replied: delay 11 mSec Accuracy increased by 0.730 seconds
3615171: ExtRTC: External time source set to: 1667912125
3615171: Time set to 1667912124.730
3615173: Current Time Zone: STD time start: 2022-10-30 03:00:00 offset: 180 min
3615177: Local time: 2022-11-08 15:55:24
3615179: EVENT: Clock#Time=Tue,15:55
3615183: EVENT: Time#Set

So, it took an hour to update

[TD-er]

With a pending fix (which is on my laptop downstairs, not yet pushed to GitHub), it will be faster.
There is a function to check running services, which is called every time there is a working network connection.
I added a check in there to see if we have a time source which is worse than NTP (and with NTP enabled in the settings of course), it will call for a forced update to NTP.

So that will be fixed before the new build (which will be in a few days)

[chemmex]

Super, ready to test before the new build is released

[chemmex]

Compiled current sources and getting strange results:

When both NTP and Ext RTC enabled, I see that NTP is called in only 1 out of 10 consequent startups. In other 9 the unit keeps wrong time read from the DS3231.
If Ext time source is set to None, the NTP is called immediately next to WiFi#Connected event.

Both NTP and DS3231 enabled:

Code: Select all

INIT : Booting version: ESP_Easy_mega_20221110_custom_ESP8266_4M1M, (Self built) 20221110TZ_noDebug (ESP82xx Core 2843a5ac, NONOS SDK 2.2.2-dev(38a443e), LWIP: 2.1.2 PUYA support)
5268 : Info   : ExtRTC: Read external time source: 1582937679
11228 : Info   : EVENT: System#Wake
11344 : Info   : Webserver: start
11356 : Info   : ExtRTC: Read external time source: 1582937685
11356 : Info   : Time set to 1582937685.000
11358 : Info   : Current Time Zone: STD time start: 2020-10-25 03:00:00 offset: 180 min
11360 : Info   : Local time: 2020-02-29 03:54:45
11362 : Info   : EVENT: System#Boot
15059 : Info   : EVENT: Clock#Time=Sat,3:54
20124 : Info   : WIFI : Connecting xxxx Ch:9 (-51dBm) WPA2/PSK attempt #2
21538 : Info   : WIFI : DHCP IP: 192.168.10.169 (ESPEasy) GW: 192.168.10.129 SN: 255.255.255.128   duration: 307 ms
21540 : Info   : firstLoopConnectionsEstablished
21542 : Info   : WIFI : Connected! AP: xxxx Ch: 9 Duration: 1095 ms
21545 : Info   : EVENT: WiFi#Connected
21549 : Info   : EVENT: WiFi#ChangedAccesspoint
21551 : Info   : EVENT: WiFi#ChangedWiFichannel
27059 : Info   : EVENT: Clock#Time=Sat,3:55

DS3231 disabled:

Code: Select all

INIT : Booting version: ESP_Easy_mega_20221110_custom_ESP8266_4M1M, (Self built) 20221110TZ_noDebug (ESP82xx Core 2843a5ac, NONOS SDK 2.2.2-dev(38a443e), LWIP: 2.1.2 PUYA support)
11178 : Info   : EVENT: System#Wake
11293 : Info   : Webserver: start
11305 : Info   : EVENT: System#Boot
21467 : Info   : firstLoopConnectionsEstablished
21468 : Info   : EVENT: WiFi#Connected
21472 : Info   : WIFI : Connected! AP: xxxx  Ch: 9 Duration: 1083 ms
21515 : Info   : NTP  : NTP replied: delay 10 mSec Accuracy increased by 0.012 seconds
21517 : Info   : Time set to 1668075353.012
21519 : Info   : Current Time Zone: STD time start: 2022-10-30 03:00:00 offset: 180 min
21522 : Info   : Local time: 2022-11-10 13:15:53
21526 : Info   : EVENT: WiFi#ChangedAccesspoint
21529 : Info   : EVENT: WiFi#ChangedWiFichannel
21532 : Info   : EVENT: Time#Initialized
22017 : Info   : EVENT: Clock#Time=Thu,13:15

From my point of view, the initial NTP request should be (if network status allows) sent regardless of external timesource setting, there's not much to save the ntp.org from flooding as 99% of units are uncapable of RTC and send this request anyway.

[TD-er]

[...]
From my point of view, the initial NTP request should be (if network status allows) sent regardless of external timesource setting, there's not much to save the ntp.org from flooding as 99% of units are uncapable of RTC and send this request anyway.

Well not only from your point of view...
That was also my point of view.

I think I need to strip the NTP call away from the now() function and just schedule it as a periodical call in ESPEasy, where I can change this period based on network connect events.
Right now it is still being called from this now() function as it has been for years. But it should actually be treated the same as the other external time sources (p2p time sync, ext. RTC, GPS).

So will dive into this again

Thanks for testing on multiple nodes.