I have an ESP32 project that needs to know the current datetime. I noticed an odd issue where the time was sometimes wroing.
After lots of testing, I have now narrowed the issue down to something specific and I’m baffled as to why it’s happening.
For the purposes of demonstrating the issue, I have a function that sets a fixed datetime (midnight on Saturday 26th September 2020) and then prints that datetime.
This function is called from my main loop.
I have also copy-pasted the code from that function into the main loop directly.
Here is the code (this is the entirety of it, nothing omitted):
#include <Esp.h>
#include <esp_system.h>
#include <sys/time.h>
void setup()
{
Serial.begin(115200);
Serial.setDebugOutput(true);
esp_log_level_set("*", ESP_LOG_VERBOSE);
}
void time_sync_loop()
{
struct tm timeinfo;
timeval tv;
timezone tz;
timezone tz_utc = {0,0};
// Set a fixed time of 2020-09-26 00:00:00, UTC
tv.tv_sec = time_t(1601078400);
tz.tz_minuteswest = 0;
tz.tz_dsttime = 0;
settimeofday(&tv, &tz_utc);
// Get the time and print it
time_t now = time(nullptr);
gmtime_r(&now, &timeinfo);
Serial.print("Function: ");
Serial.println(&timeinfo, "%A, %B %d %Y %H:%M:%S");
}
void loop()
{
// Runs the function (prints a time that is behind)
time_sync_loop();
delay(1000);
// Run the same code directly (prints a time that is 2m14s fast)
struct tm timeinfo;
timeval tv;
timezone tz;
timezone tz_utc = {0,0};
tv.tv_sec = time_t(1601078400);
tz.tz_minuteswest = 0;
tz.tz_dsttime = 0;
settimeofday(&tv, &tz_utc);
time_t now = time(nullptr);
gmtime_r(&now, &timeinfo);
Serial.print("Main: ");
Serial.println(&timeinfo, "%A, %B %d %Y %H:%M:%S");
delay(1000);
}
Here is the serial output:
Function: Friday, September 25 2020 23:34:44
Main: Saturday, September 26 2020 00:02:14
Function: Friday, September 25 2020 23:24:13
Main: Saturday, September 26 2020 00:02:14
Function: Friday, September 25 2020 23:24:13
Main: Saturday, September 26 2020 00:02:14
Function: Friday, September 25 2020 23:24:13
Main: Saturday, September 26 2020 00:02:14
Function: Friday, September 25 2020 23:24:13
Main: Saturday, September 26 2020 00:02:14
The function prints a time that is 35m47s behind ahead of the set time (except for the first call, where it is 25m16s ahead). The code in the main loop prints the a time that is 2m14s shead of the set time.
This behaviour is consistent across resets of the ESP32.
I have no idea why this would be happening. The code in the function and the loop are identical, they do not share any variables.
Can anyone shed any light on this?