search

khoih-prog / NTPClient_Generic

Library for NTPClient to connect to an NTP time-server. Get time from a NTP time-server and keep it in sync. For ESP8266/ESP32, nRF52, SAMD21/SAMD51, STM32F/L/H/G/WB/MP1, Teensy, etc. besides AVR, using ESP WiFi, WiFiNINA, Ethernet W5x00, ENC28J60, LAN8742A, ESP8266/ESP32 AT-command WiFi.
MIT License
28 stars 12 forks source link

Time jumping back 9 minutes #1

Closed DrTron closed 3 years ago

DrTron commented 3 years ago

I experienced a rather strange bug:

After 10 minutes or running a simple clock with the library, the time is set back 9 minutes. That difference stays and is not reverted back when the ntpserver is polled again.

This is with a loop time of 1 minute:

10:01:53.112 -> 10:00:52
10:02:53.102 -> 10:01:52
10:03:53.112 -> 10:02:52
10:04:53.123 -> 10:03:52
10:05:53.107 -> 10:04:52
10:06:53.096 -> 10:05:52
10:07:53.088 -> 10:06:52
10:08:53.098 -> 10:07:52
10:09:53.106 -> 10:08:52
10:10:53.096 -> 10:09:52
10:11:53.098 -> 10:01:53
10:12:53.111 -> 10:02:53
10:13:53.108 -> 10:03:53
10:14:53.102 -> 10:04:53

Clock is started at 10:00 and 10 minutes later it jumps back The "original" NTPClient.h library does not show this behavior.

khoih-prog commented 3 years ago

Thanks for using the library. Hope this is a good bug to catch.

Can you provide some more info, such as

  1. the examples you're using,
  2. how to duplicate the issue by following How to create a Minimal, Reproducible Example
  3. Boards, shield, etc.
  4. IDE version, core version
  5. Library Version
  6. Any info necessary to duplicate
DrTron commented 3 years ago

See minimal example at the bottom. It seems to correlate with the frequency the ntp server is contacted. In this example the standard 60 seconds is used, and the time jump is one minute. In my code I only poll the server every 10 minutes, and that correlates with the jump. The jump seems to happen only once, but the time stays wrong after that and is not corrected by ntp.

12:20:49.309 -> 18:20:48
12:20:50.303 -> 18:20:49
12:20:51.297 -> 18:19:51
12:20:52.324 -> 18:19:52

Board: ESP-32 no-name, VID: 10C4, PID: EA60 IDE 1.8.13 on Linux Library 3.2.2

#include <WiFi.h>
#include <NTPClient_Generic.h>
#include <WiFiUdp.h>

const char* ssid       = "ssid";
const char* password   = "password";

WiFiUDP ntpUDP;

NTPClient timeClient(ntpUDP);

void setup()
{
  Serial.begin(115200);

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

timeClient.begin();
}

void loop()
{
timeClient.update();
Serial.println(timeClient.getFormattedTime());
delay(1000);
}
khoih-prog commented 3 years ago

Thanks for the code. I couldn't duplicate the issue after several runs, I suggest to check your full code to see what can cause the issue. It's possible that the memory location to store NTP data has been accidentally overwritten as there is no way the NTP server can provide wrong time like that.

You can also use the ESP_NTPClient_Basic example to be sure.

Using different library and the elusive problem appears does not assure 100% that the different library causes the problem. The somewhere-somehow corrupted pointer can cause lot of headaches by pointing us to the wrong direction.

This is the code I use to test (even with the original code you posted) I still haven't seen any issue yet

#include <WiFi.h>

#define _NTP_LOGLEVEL_       4

#define USING_NTPCLIENT_GENERIC     true

#if USING_NTPCLIENT_GENERIC
  #include <NTPClient_Generic.h>
#else
  #include <NTPClient.h>
#endif

#include <WiFiUdp.h>

const char* ssid       = "ssid";
const char* password   = "password";

WiFiUDP ntpUDP;

NTPClient timeClient(ntpUDP);

void setup()
{
  Serial.begin(115200);
  while (!Serial);

  delay(200);

#if USING_NTPCLIENT_GENERIC
  Serial.println("\nStarting NTPClient_Generic_Issue using NTPClient_Generic");
#else
  Serial.println("\nStarting NTPClient_Generic_Issue using NTPClient");
#endif

  WiFi.begin(ssid, password);

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

  Serial.println();

  timeClient.begin();
}

void loop()
{
  timeClient.update();
  Serial.println(timeClient.getFormattedTime());
  delay(60000);
}

and the library added code to print more debug info in NTPClient_Generic_Impl.h#L175-L187

String NTPClient::createFormattedTime(unsigned long rawTime) const 
{
  unsigned long tempo   = hour(rawTime);
  String hoursStr       = tempo < 10 ? "0" + String(tempo) : String(tempo);

  tempo   = minute(rawTime);
  String minuteStr      = tempo < 10 ? "0" + String(tempo) : String(tempo);

  tempo   = second(rawTime);
  String secondStr      = tempo < 10 ? "0" + String(tempo) : String(tempo);

  NTP_LOGDEBUG3("rawTime =", rawTime, ", hour =", hoursStr);
  NTP_LOGDEBUG3("min =", minuteStr, ", second =", secondStr);

  return hoursStr + ":" + minuteStr + ":" + secondStr;
}

The Debug terminal output

Starting NTPClient_Generic_Issue using NTPClient_Generic
..00:00:01
20:57:21
20:58:21
20:59:21
21:00:21
21:01:21
21:02:21
21:03:21
21:04:21
21:05:21
21:06:21
21:07:21
21:08:21
Starting NTPClient_Generic_Issue using NTPClient_Generic
..
00:00:01
21:11:34
21:12:34
21:13:34
21:14:34
21:15:34
21:16:34
21:17:34
21:18:34
21:19:34
21:20:33
21:21:33
21:22:33

With #define _NTP_LOGLEVEL_ 4


Starting NTPClient_Generic_Issue using NTPClient_Generic
..
[NTP] rawTime = 1 , hour = 00
[NTP] min = 00 , second = 01
00:00:01
[NTP] rawTime = 1610313900 , hour = 21
[NTP] min = 25 , second = 00
21:25:00
[NTP] rawTime = 1610313960 , hour = 21
[NTP] min = 26 , second = 00
21:26:00
[NTP] rawTime = 1610314020 , hour = 21
[NTP] min = 27 , second = 00
21:27:00
[NTP] rawTime = 1610314080 , hour = 21
[NTP] min = 28 , second = 00
21:28:00
[NTP] rawTime = 1610314140 , hour = 21
[NTP] min = 29 , second = 00
21:29:00
[NTP] rawTime = 1610314200 , hour = 21
[NTP] min = 30 , second = 00
21:30:00
[NTP] rawTime = 1610314260 , hour = 21
[NTP] min = 31 , second = 00
21:31:00
[NTP] rawTime = 1610314320 , hour = 21
[NTP] min = 32 , second = 00
21:32:00
[NTP] rawTime = 1610314380 , hour = 21
[NTP] min = 33 , second = 00
21:33:00
[NTP] rawTime = 1610314440 , hour = 21
[NTP] min = 34 , second = 00
21:34:00
[NTP] rawTime = 1610314500 , hour = 21
[NTP] min = 35 , second = 00
21:35:00
[NTP] rawTime = 1610314560 , hour = 21
[NTP] min = 36 , second = 00
21:36:00
[NTP] rawTime = 1610314620 , hour = 21
[NTP] min = 37 , second = 00
21:37:00
[NTP] rawTime = 1610314680 , hour = 21
[NTP] min = 38 , second = 00
21:38:00
[NTP] rawTime = 1610314740 , hour = 21
[NTP] min = 39 , second = 00
21:39:00
[NTP] rawTime = 1610314800 , hour = 21
[NTP] min = 40 , second = 00
21:40:00

I'm closing this issue now as I don't think this issue has anything to do with the library, until you prove otherwise.

Good Luck with your project,

DrTron commented 3 years ago

Strange, it doesn't happen with your example, although I fail to see significant differences to my example. Thanks anyway!

iBuilderBY commented 1 year ago

Hello! I've got the same isue and I know when it appears. It's happend when the connection disappears - time jump back on NTP_UPDATE_INTERVAL_MS. When connection is up - time jump forward.

khoih-prog commented 1 year ago

Hi @iBuilderBY and @DrTron

The new NTPClient_Generic v3.7.5 has just been released.

Please have more tests to see if there is still any bug.

Best Regards,

Releases v3.7.5

  1. Fix bug causing time jumping back or forth when network has problem. Check Time jumping back when connection is lost and forward when up #9 and Time jumping back 9 minutes #1
  2. Modify example ESP_NTPClient_Advanced to demo the better way to use the library, without using long delay()
  3. Add support to RP2040W boards using CYW43439 WiFi
  4. Optimize and clean up
  5. Modify platformio.ini and library.json to reduce error with PIO
  6. Update Packages' Patches