Time going backwards: aon_timer_get_time() [SDK 2.1.1] #2374

Closed
opened 2025-03-27 00:27:36 -05:00 by tjko · 10 comments
tjko commented 2025-03-27 00:27:36 -05:00 (Migrated from github.com)

After upgrading from SDK version 2.1.0 to 2.1.1, I noticed weird behavior with aon_timer_get_time() on RP2040 (pico_w).
Time returned seems to randomly go backwards (and forwards) 1 hour.

I have a project that displays clock (among other things) on OLED panel, and after upgrading to new SDK (2.1.1), I noticed hour digit was randomly toggling back and forth.

So I added some 'debug' output in the function that gets the current (RTC) time:

time went backwards: 1743055938 -> 1743052339 (delta=3599)
time went backwards: 1743055948 -> 1743052349 (delta=3599)
time went backwards: 1743055953 -> 1743052354 (delta=3599)
time went backwards: 1743055970 -> 1743052371 (delta=3599)
time went backwards: 1743055973 -> 1743052374 (delta=3599)
time went backwards: 1743055990 -> 1743052391 (delta=3599)
time went backwards: 1743056009 -> 1743052410 (delta=3599)
time went backwards: 1743056041 -> 1743052442 (delta=3599)
time went backwards: 1743056082 -> 1743052483 (delta=3599)
time went backwards: 1743056116 -> 1743052517 (delta=3599)
time went backwards: 1743056123 -> 1743052524 (delta=3599)
time went backwards: 1743056126 -> 1743052527 (delta=3599)
time went backwards: 1743056148 -> 1743052549 (delta=3599)
time went backwards: 1743056156 -> 1743052557 (delta=3599)

This is from the function shown below (that gets called about once a second):

bool rtc_get_time(time_t *t)
{
        static time_t old_t = 0;
        struct timespec ts;
        time_t new_t;

        if (!t || !aon_timer_is_running())
                return false;

        if (!aon_timer_get_time(&ts))
                return false;
        new_t = ts.tv_sec;

        if (old_t > new_t) {
                printf("time went backwards: %lld -> %lld (delta=%lld)\n", old_t, new_t, old_t - new_t);
        }
        old_t = new_t;

        *t = new_t;

        return true;
}

(switching back to SDK 2.1.0 seems to "fix" the issue)

After upgrading from SDK version 2.1.0 to 2.1.1, I noticed weird behavior with **aon_timer_get_time()** on RP2040 (pico_w). Time returned seems to randomly go backwards (and forwards) 1 hour. I have a project that displays clock (among other things) on OLED panel, and after upgrading to new SDK (2.1.1), I noticed hour digit was randomly toggling back and forth. So I added some 'debug' output in the function that gets the current (RTC) time: ``` time went backwards: 1743055938 -> 1743052339 (delta=3599) time went backwards: 1743055948 -> 1743052349 (delta=3599) time went backwards: 1743055953 -> 1743052354 (delta=3599) time went backwards: 1743055970 -> 1743052371 (delta=3599) time went backwards: 1743055973 -> 1743052374 (delta=3599) time went backwards: 1743055990 -> 1743052391 (delta=3599) time went backwards: 1743056009 -> 1743052410 (delta=3599) time went backwards: 1743056041 -> 1743052442 (delta=3599) time went backwards: 1743056082 -> 1743052483 (delta=3599) time went backwards: 1743056116 -> 1743052517 (delta=3599) time went backwards: 1743056123 -> 1743052524 (delta=3599) time went backwards: 1743056126 -> 1743052527 (delta=3599) time went backwards: 1743056148 -> 1743052549 (delta=3599) time went backwards: 1743056156 -> 1743052557 (delta=3599) ``` This is from the function shown below (that gets called about once a second): ``` bool rtc_get_time(time_t *t) { static time_t old_t = 0; struct timespec ts; time_t new_t; if (!t || !aon_timer_is_running()) return false; if (!aon_timer_get_time(&ts)) return false; new_t = ts.tv_sec; if (old_t > new_t) { printf("time went backwards: %lld -> %lld (delta=%lld)\n", old_t, new_t, old_t - new_t); } old_t = new_t; *t = new_t; return true; } ``` (switching back to SDK 2.1.0 seems to "fix" the issue)
tjko commented 2025-03-27 09:04:49 -05:00 (Migrated from github.com)

Actually, seems like this is happening on SDK 2.1.0, but lot less frequently, it its minutes to hours between occurrences.

I left test running overnight and save couple occurrences logged:

time went backwards: 1743061269 -> 1743057670 (delta=3599)
time went backwards: 1743061703 -> 1743058104 (delta=3599)
time went backwards: 1743085016 -> 1743081417 (delta=3599)

When this happens time seems to jump forward 1 hour for about a second and then jump back....
As if this is somehow timezone (daylight savings) related, but doesn't seem aon_timer_get_time() does any timezone processing?

Actually, seems like this is happening on SDK 2.1.0, but lot less frequently, it its minutes to hours between occurrences. I left test running overnight and save couple occurrences logged: ``` time went backwards: 1743061269 -> 1743057670 (delta=3599) time went backwards: 1743061703 -> 1743058104 (delta=3599) time went backwards: 1743085016 -> 1743081417 (delta=3599) ``` When this happens time seems to jump forward 1 hour for about a second and then jump back.... As if this is somehow timezone (daylight savings) related, but doesn't seem **aon_timer_get_time()** does any timezone processing?
peterharperuk commented 2025-03-27 09:31:50 -05:00 (Migrated from github.com)

It calls mktime. I wonder if that's doing some daylight saving. It might be worth zeroing the struct timespec ts; memory which might indicate a bug in datetime_to_tm?

It calls mktime. I wonder if that's doing some daylight saving. It might be worth zeroing the struct timespec ts; memory which might indicate a bug in datetime_to_tm?
tjko commented 2025-03-27 09:57:18 -05:00 (Migrated from github.com)

I think you might be right, if I clear the timespec struct before calling aon_timer_get_time(), it would seem like issue goes away....

        memset(&ts, 0, sizeof(ts));
        if (!aon_timer_get_time(&ts))
                return false;
        new_t = ts.tv_sec;
I think you might be right, if I clear the timespec struct before calling aon_timer_get_time(), it would seem like issue goes away.... ``` memset(&ts, 0, sizeof(ts)); if (!aon_timer_get_time(&ts)) return false; new_t = ts.tv_sec; ```
peterharperuk commented 2025-03-27 10:08:17 -05:00 (Migrated from github.com)

Good find. I guess we should be setting tm_isdst to zero. Although how it determines day light saving is on is beyond me.
Actually, we should just make sure it's not -1? Or always use -1?

Good find. I guess we should be setting tm_isdst to zero. Although how it determines day light saving is on is beyond me. Actually, we should just make sure it's not -1? Or always use -1?
tjko commented 2025-03-27 11:27:05 -05:00 (Migrated from github.com)

Seems like clearing timespec before making call to aon_timer_get_time() didn't really "help", just unlucky that didn't see the issue immediately...

Looks like datetime_to_tm() leaves three fields uninitialized (tm_wday, tm_yday, tm_isdst) that likely lead to the random issues I was seeing?

This change would seem to "fix" the issue for me:

diff --git a/src/common/pico_util/datetime.c b/src/common/pico_util/datetime.c
index 130e2d5..f25bb5f 100644
--- a/src/common/pico_util/datetime.c
+++ b/src/common/pico_util/datetime.c
@@ -63,6 +63,9 @@ void datetime_to_tm(const datetime_t *dt, struct tm *tm) {
     tm->tm_hour = dt->hour;
     tm->tm_min = dt->min;
     tm->tm_sec = dt->sec;
+    tm->tm_wday = dt->dotw;
+    tm->tm_yday = -1; // FIXME
+    tm->tm_isdst = -1;
 }
 
 void tm_to_datetime(const struct tm *tm, datetime_t *dt) {
Seems like clearing timespec before making call to aon_timer_get_time() didn't really "help", just unlucky that didn't see the issue immediately... Looks like datetime_to_tm() leaves three fields uninitialized (tm_wday, tm_yday, tm_isdst) that likely lead to the random issues I was seeing? This change would seem to "fix" the issue for me: ``` diff --git a/src/common/pico_util/datetime.c b/src/common/pico_util/datetime.c index 130e2d5..f25bb5f 100644 --- a/src/common/pico_util/datetime.c +++ b/src/common/pico_util/datetime.c @@ -63,6 +63,9 @@ void datetime_to_tm(const datetime_t *dt, struct tm *tm) { tm->tm_hour = dt->hour; tm->tm_min = dt->min; tm->tm_sec = dt->sec; + tm->tm_wday = dt->dotw; + tm->tm_yday = -1; // FIXME + tm->tm_isdst = -1; } void tm_to_datetime(const struct tm *tm, datetime_t *dt) { ```
tjko commented 2025-03-27 19:39:51 -05:00 (Migrated from github.com)

Looks like workaround to the issue (that avoids having to patch the SDK) is to define following pico_mktime() function (that overrides the implementation in SDK, thanks to the __weak linker directive).

/* Workaround to issue (#2374) in datetime_to_tm() ... */
time_t pico_mktime(struct tm *tm)
{
        tm->tm_isdst = -1;
        return mktime(tm);
}

Seems like this issue is only triggered when timezone is set to a timezone that has daylight savings time.

I'm getting time from NTP, so I'm setting timezone in order to convert UTC time received from NTP server to local time
(I was using following timezone "PST8PDT7,M3.2.0/2,M11.1.0/02:00:00")

I'm setting timezone as follows:

setenv("TZ", dhcp_timezone, 1);
tzset();
Looks like workaround to the issue (that avoids having to patch the SDK) is to define following _pico_mktime()_ function (that overrides the implementation in SDK, thanks to the __weak linker directive). ``` /* Workaround to issue (#2374) in datetime_to_tm() ... */ time_t pico_mktime(struct tm *tm) { tm->tm_isdst = -1; return mktime(tm); } ``` Seems like this issue is only triggered when timezone is set to a timezone that has daylight savings time. I'm getting time from NTP, so I'm setting timezone in order to convert UTC time received from NTP server to local time (I was using following timezone **"PST8PDT7,M3.2.0/2,M11.1.0/02:00:00"**) I'm setting timezone as follows: ``` setenv("TZ", dhcp_timezone, 1); tzset(); ```
kilograham commented 2025-03-27 22:25:22 -05:00 (Migrated from github.com)

less of a workaround and more of a fix, as tm_isdst does need to be initialized, however in this case i would put it in datetime_to_tm

less of a workaround and more of a fix, as `tm_isdst` does need to be initialized, however in this case i would put it in `datetime_to_tm`
kilograham commented 2025-04-11 11:14:40 -05:00 (Migrated from github.com)

merged into develop

merged into develop
tjko commented 2025-04-11 11:35:11 -05:00 (Migrated from github.com)

Thanks!

Btw, why doesn't datetime_to_tm() still fully initialize the struct tm? It would seem there should be at least warning in the docs that it doesn't do full convesion from "datetime" to "tm", etc? (and leaves tm_wday and tm_yday fields uninitialized)

Thanks! Btw, why doesn't _datetime_to_tm()_ still fully initialize the struct tm? It would seem there should be at least warning in the docs that it doesn't do full convesion from "datetime" to "tm", etc? (and leaves tm_wday and tm_yday fields uninitialized)
lurch commented 2025-04-14 07:22:25 -05:00 (Migrated from github.com)

@tjko If there's additional functionality you'd like to see, please open a new issue (or PR) 🙂

@tjko If there's additional functionality you'd like to see, please open a new issue (or PR) 🙂
Sign in to join this conversation.
No milestone
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set

Reference
gh-raspberrypi/pico-sdk#2374
No description provided.