ropg / ezTime

ezTime — pronounced "Easy Time" — is a very easy to use Arduino time and date library that provides NTP network time lookups, extensive timezone support, formatted time and date strings, user events, millisecond precision and more.
MIT License
327 stars 92 forks source link

Incorrect time on WiFi Loss #21

Open chinswain opened 5 years ago

chinswain commented 5 years ago

I've had a few false triggers on setEvent that appear to be due to datetime being incorrect immediately after a WiFi loss and reconnect. On the next update it's corrected (if WiFi is ok) but all of the days event's are triggered.

I'll write a simplified example (with DEBUG level) and post\test tomorrow and leaving it running. I have a timer doing the following every 10 minutes:

 Serial.print("Time: "); Serial.println(myTZ.dateTime());

Output Example 1:

Querying pool.ntp.org ... success (round trip 64 ms)
Received time: Wednesday, 02-Jan-19 18:30:25.098 UTC (internal clock was 33 ms fast)

[0] Heartbeat timeout <-- WiFi Loss and Reconnect
[148] Ready (ping: 31ms).

**Time: Thursday, 21-Feb-2019 10:22:54 GMT**

Querying pool.ntp.org ... success (round trip 55 ms)
Received time: Wednesday, 02-Jan-19 18:31:42.317 UTC (internal clock was 4294973 ms fast)

Time: Wednesday, 02-Jan-2019 18:37:39 GMT

Querying pool.ntp.org ... success (round trip 906 ms)
Received time: Wednesday, 02-Jan-19 18:41:42.331 UTC (internal clock was 425 ms fast)

Output Example 2:

Time: Wednesday, 02-Jan-2019 23:25:20 UTC

[0] Heartbeat timeout <-- WiFi Loss and Reconnect
[148] Ready (ping: 35ms).

**Time: Thursday, 21-Feb-2019 15:16:33 UTC**

Querying pool.ntp.org ... success (round trip 44 ms)
Received time: Wednesday, 02-Jan-19 23:25:21.408 UTC (internal clock was 4294953 ms fast)

Time: Wednesday, 02-Jan-2019 23:25:21 UTC
chinswain commented 5 years ago

Example Sketch:

#include <ezTime.h>
#include <WiFi.h>

unsigned long previousMillis = 0;

Timezone myTZ;

void setup() {

  Serial.begin(115200);
  WiFi.begin("xxxxx", "xxxxx");
  while (WiFi.status() != WL_CONNECTED) {
    delay(500);
    Serial.print(".");
  }

  setDebug(DEBUG);
  waitForSync();
  myTZ.setLocation(F("gb"));
  myTZ.setDefault();
}

void loop() {

  unsigned long currentMillis = millis();
  events();
  if (currentMillis - previousMillis >= 1000) {
    previousMillis = currentMillis;
    Serial.println("Time: " + myTZ.dateTime());
  }
}
ezTime debug level set to DEBUG
Waiting for time sync
Querying pool.ntp.org ... success (round trip 17 ms)
Received time: Sunday, 06-Jan-19 19:08:57.553 UTC
Set event (#1) to trigger on: Sunday, 06-Jan-2019 19:18:57 UTC
Time is in sync
Timezone lookup for: gb ... (round-trip 54 ms)  success.
  Olsen: Europe/London
  Posix: GMT0BST,M3.5.0/1,M10.5.0
Default timezone set to Europe/London  GMT0BST,M3.5.0/1,M10.5.0
Time: Sunday, 06-Jan-2019 19:08:57 GMT
Time: Sunday, 06-Jan-2019 19:08:58 GMT
Time: Sunday, 06-Jan-2019 19:08:59 GMT
.....
Time: Sunday, 06-Jan-2019 20:18:53 GMT
Time: Sunday, 06-Jan-2019 20:18:54 GMT
Time: Sunday, 06-Jan-2019 20:18:55 GMT
Running event (#1) set for Sunday, 06-Jan-2019 20:18:56 UTC
Querying pool.ntp.org ... success (round trip 55 ms)
Received time: Sunday, 06-Jan-19 20:18:55.985 UTC (internal clock was 71 ms slow)
Set event (#1) to trigger on: Sunday, 06-Jan-2019 20:28:55 UTC
Time: Sunday, 06-Jan-2019 20:18:56 GMT
Time: Sunday, 06-Jan-2019 20:18:57 GMT
Time: Sunday, 06-Jan-2019 20:18:58 GMT

All good until the clock suddenly jumps from 20:19:00 to a future time, seems to then trigger an NTP update (And all events):

Time: Sunday, 06-Jan-2019 20:18:59 GMT
Time: Sunday, 06-Jan-2019 20:19:00 GMT
Running event (#1) set for Sunday, 06-Jan-2019 20:28:55 UTC
Querying pool.ntp.org ... success (round trip 19 ms)
Received time: Sunday, 06-Jan-19 20:19:01.366 UTC (internal clock was 4294951 ms fast)
Set event (#1) to trigger on: Sunday, 06-Jan-2019 20:29:01 UTC
Time: Sunday, 06-Jan-2019 20:19:01 GMT
Time: Sunday, 06-Jan-2019 20:19:02 GMT
Time: Sunday, 06-Jan-2019 20:19:03 GMT