System time corrupted across reboots

[cruvus]

Hi,

my plan is to "rescue" the system time across a reboot (crash, firmware update, etc.). I know I could rely on NTP, but I'd like to have this feature as a fall back solution anyways.
My understanding is that there is an RTC running and that the RTC memory survives a reboot. In theory. However I noticed (looking at the log time stamps) that after the reboot, the system time is awfully wrong. It jumped several minutes or hours into the future. After the NTP event it is corrected.
Now the question: What causes this behavior and how do I keep the time accurate across a reboot?

[gtjoseph]

I think it depends on what kind of reset is performed and whether the clocks were stopped. For instance, if you toggle the EN/CHIP_PU line, that's a power cycle of the chip.

I think the only real way to recover the time locally would be to include an I2C RTC with a battery backup.

[cruvus]

https://docs.espressif.com/projects/esp ... ght=across

In menuconfig I chose the option "RTC and high-resolution timer (default)", so time should persist. But it doesn't. I wonder if others have more experience. This is my second week with the ESP32.

[cruvus]

I tried calling esp_sync_counters_rtc_and_frc() just before esp_restart(), but that didn't help.

[cruvus]

I found the very old thread
https://www.esp32.com/viewtopic.php?t=7544
indicating the same problem.

There's the recommendation to change CONFIG_NEWLIB_TIME_SYSCALL to only rtc as the Timer for gettimeofday. But that does not help either.

I wonder why the behavior differs from the documentation here. Is it a bug? Or is time simply not defined before NTP? Then why not initialize it to zero like after poweron?

Maybe Espressif can clear this up.

[ESP_igrr]

Hi cruvus,

I tried but couldn't reproduce the problem based on your description. Could you please open an issue in ESP-IDF Github project, attaching the code to reproduce this behavior?

[cruvus]

I am willing to provide a minimum code example, but I didn't have success in doing so yet...
It might be another mechanism in my application which causes this, but I have no idea which one, despite commenting out almost everything one by one.
I am redirecting the log into a (noinit) buffer which I access via the http server. This is how I can easily see what the system time was just before and after esp_restart(). Restart/OTA is also done using the http server.
A side effect of this is that I do not need any serial connection and the board rarely is hardware-reset. At the moment esp_rtc_get_time_us() is ~3 days.

I get the impression the phenomenon gets worse the more time passes since poweron (== hardware reset). I also noticed the value of esp_rtc_get_time_us() jumping. Whether it gets changed just after esp_restart() or just before the user code runs I don't know.

[cruvus]

That is another topic about the same problem:
viewtopic.php?t=19504

It seems that on "freshly powered on" (<1 day) devices the issue is indeed not very obvious.

Edit: I'll try to whip up a very simple example which automatically reboots once per hour or so. The main problem is, my serial connection is not stable enough to leave this running for like 3 days. Remember that in order to demonstrate the issue, a hardware reboot must not happen during the test.

[cruvus]

Example code. Run it and leave it for 1-3 days. It will (soft-)restart automatically every hour. Use PuTTY or a similar terminal and do not hardware reset the chip during the test. The problem will only manifest after several hours or days. Typical output see below.

Code: [Select all] [Expand/Collapse]

1. #include "esp_log.h"
2. #include "esp_sntp.h"
3. #include "esp_wifi.h"
4. #include "nvs_flash.h"
5. #include "esp32/rtc.h"
6.  
7. static const char *TAG = "main";
8.  
9. void time_sync_notification_cb(struct timeval *tv) {
10.     ESP_LOGI(TAG, "time_sync_notification_cb");
11. }
12.  
13. void log_rtc(void) {
14.     int u = esp_rtc_get_time_us() / 1000000;
15.     ESP_LOGI(TAG, "rtc=%d seconds (%d days %02d:%02d:%02d)", u, u / (24*3600), (u % (24*3600)) / 3600, (u % 3600) / 60, u % 60);
16. }
17.  
18. void app_main(void) {
19.     log_rtc();
20.     ESP_LOGI(TAG, "start");
21.  
22.     ESP_ERROR_CHECK(nvs_flash_init());
23.     ESP_ERROR_CHECK(esp_netif_init());
24.     ESP_ERROR_CHECK(esp_event_loop_create_default());
25.     esp_netif_create_default_wifi_sta();
26.     wifi_init_config_t wifi_init_config = WIFI_INIT_CONFIG_DEFAULT();
27.     ESP_ERROR_CHECK(esp_wifi_init(&wifi_init_config));
28.  
29.     wifi_config_t conf_sta = {
30.         .sta.ssid = "xxxxx",
31.     };
32.     esp_wifi_set_config(WIFI_IF_STA, &conf_sta);
33.  
34.     ESP_ERROR_CHECK(esp_wifi_start());
35.     esp_wifi_connect();
36.  
37.     sntp_setoperatingmode(SNTP_OPMODE_POLL);
38.     sntp_setservername(0, "pool.ntp.org");
39.     sntp_set_time_sync_notification_cb(time_sync_notification_cb);
40.     sntp_init();
41.  
42.     // Wait an hour
43.     for (int i = 0; i < 60; i++) {
44.         ESP_LOGI(TAG, "%d", i);
45.         vTaskDelay(60000 / portTICK_PERIOD_MS);
46.     }
47.  
48.     ESP_LOGI(TAG, "end");
49.     log_rtc();
50.  
51.     esp_restart();
52. //  esp_abort(); // TODO: Try the other "restart methods" and see if there is a difference
53. //  esp_deep_sleep(1000000);
54. }

GeSHi © Codebox Plus Extension

I (08:07:52.302) main: 58
I (08:08:52.302) main: 59
I (08:09:52.302) main: end
I (08:09:52.303) main: rtc=32399 seconds (0 days 08:59:59)
[...]
ets Jun 8 2016 00:22:57
rst:0xc (SW_CPU_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
[...]
I (08:09:15.296) main: rtc=32362 seconds (0 days 08:59:22)
I (08:09:15.301) main: start

Here you can see the log just before and after a reboot. Look at the time stamp. Restarting takes maybe ~1 second, but instead time and rtc jumped backwards more than half a minute.

[LuccasCircuits]

Hi there! Any updates on that? I'm facing the same problem with NTC, after some resets it jumps to the future...