ESP8266/ESP32 uptime overflow

[HermannSW]

In this posting I learned that ESP32 module esp_timer_get_time() returns an int64_t and counts microseconds since system start. int64_t overflows after 292,000 years.

I looked into ESP32 MicroPython code for utime module ticks_ms() and ticks_us() and saw that uint32_t gets returned:

Code: Select all

uint32_t mp_hal_ticks_ms(void) {
    return esp_timer_get_time() / 1000;
}

uint32_t mp_hal_ticks_us(void) {
    return esp_timer_get_time();
}

That means that ESP32 MicroPython utime.ticks_us() overflows after 71 minutes, and utime.ticks_ms() overflows after 49 days:

Code: Select all

>>> 2**32/(60*60*1000000)
1.19305
>>> 2**32/(24*60*60*1000)
49.7103
>>> 

Interestingly ESP8266 MicroPython has same overflow precision for both tick() functions, although for ESP8266 system_get_time() returns an uint32_t only:

Code: Select all

uint32_t mp_hal_ticks_ms(void) {
    return ((uint64_t)system_time_high_word << 32 | (uint64_t)system_get_time()) / 1000;
}

The high 32bit of 64bit counter get handled by MicroPython in micropython/ports/unix/esp8266/ets_alt_task.c at top of ets_loop_iter():
https://github.com/micropython/micropyt ... ask.c#L114

[Roberthh]

Actuall it is less than 32 bit, AFAIK 30 bit. There is some amount of discussion around that in the documentation and in the forum. Keeping that in a 32 bit integer is intentional, because that avoids memory allocation and allows to use these calls in an interrupt context.

[HermannSW]

Which documentation/postings do you refer to?

If it really is less than 32bit, then ESP8266 implementation of time_ms() has a bug.

While overflow counting in ets_alt_task.c is correct even for less than 32 bit:

Code: Select all

...
    // handle overflow of system microsecond counter
    ets_intr_lock();
    uint32_t system_time_cur = system_get_time();
    if (system_time_cur < system_time_prev) {
        system_time_high_word += 1; // record overflow of low 32-bits
    }
    system_time_prev = system_time_cur;
    ets_intr_unlock();
...

The implementation of time_ms() assumes exactly 32bit:

Code: Select all

uint32_t mp_hal_ticks_ms(void) {
    return ((uint64_t)system_time_high_word << 32 | (uint64_t)system_get_time()) / 1000;
}

So if you are right with less than 32 bit, an issue against ESP8266 time_ms() is needed.

[Roberthh]

The documentation of MicroPython aboujt ticks_ms(), ticks_us. The code lines for ticks_us() and ticks_ms() goes like:

Code: Select all

STATIC mp_obj_t time_ticks_us(void) {
    return MP_OBJ_NEW_SMALL_INT(mp_hal_ticks_us() & (MICROPY_PY_UTIME_TICKS_PERIOD - 1));
}
MP_DEFINE_CONST_FUN_OBJ_0(mp_utime_ticks_us_obj, time_ticks_us);

with
#define MICROPY_PY_UTIME_TICKS_PERIOD (MP_SMALL_INT_POSITIVE_MASK + 1)
with
#define MP_SMALL_INT_POSITIVE_MASK ~(WORD_MSBIT_HIGH | (WORD_MSBIT_HIGH >> 1))

[HermannSW]

Thanks for correcting me

I did show the "mp_hal_ticks_ms()" overflow.
You showed that "time_ticks_us(void)" calls that function and reduces its overflow.

Before I read your answer I wrote a script that did show me experimentally where the overflow occurs. It used the method I posted yesterday allowing to execute a single MicroPython command on a ESP8266 from within a Linux command line using unix port MicroPython and mp.py:
viewtopic.php?f=15&t=233&p=31846#p31846

This is the script, it collects Linux epoch timestamps and ESP8266 utime.tick_us():

Code: Select all

#!/bin/bash
./micropython mp.py 192.168.4.1 import utime
t0=$((`date +%s`))
m0=`./micropython mp.py 192.168.4.1 utime.ticks_us'()' | sed "s/\r//"`
while true
do
  ms=`./micropython mp.py 192.168.4.1 utime.ticks_us'()' | sed "s/\r//"`
  s=$((`date +%s`))
  echo $ms $((($s - $t0)*1000000 - ($ms - $m0)))
done

I did power cycle the ESP8266 and then started the command. Each while loop roughly takes a second to run. This is initial part of output, left column showing ESP8266 ticks_us(), and right column showing difference of Linux time and ESP8266 time:

Code: Select all

$ head -7 log.us.txt 
18799977 1123105
19960828 962254
20780697 1142385
21807231 1115851
22712514 210568
23523399 399683
24673486 249596
$ 

Here is where the first overflow happened:

Code: Select all

$ head -1099 log.us.txt | tail -7
1070894263 1028819
1071673017 1250065
1072698003 1225079
1073659491 263591
806039 1074117043
1758467 1074164615
2700779 1074222303
$ 

The measured overflow corresponds to the code you did show since 1073741824 is 2**30.


So for ESP8266 as well as ESP32 ticks_us() overflows after 17 minutes, and ticks_ms() overflows after 12 days:

Code: Select all

>>> 2**30/(60*1000000)
17.8957
>>> 2**30/(24*60*60*1000)
12.4276
>>> 

P.S:
The script did well despite the fact that bash script, starting/closing unix micropython, doing websockets connection to ESP8266 all are variables. The Linux to ESP8266 time differences are in rage 0.14s .. 1.97s only:

Code: Select all

$ head -1096 log.us.txt | cut -f2 -d\  | sort -n | head -3
147436
150795
158603
$ head -1096 log.us.txt | cut -f2 -d\  | sort -n | tail -3
1423278
1811667
1964856
$