Roberthh wrote: ↑Tue May 21, 2019 5:23 am
I had an event with @pythoncoder's simple test code this night. I used the settings for COUNT, MAX, MIN = 10000, 38, 34.
There was a fail with a time gap of 4295005 ms, which is 1h 11m 35s 5 ms, or about 2^32 µs. A single pass runs ~35ms, which is the deviation to 2^32.
Thank you @Roberthh for testing this!
This brings us on the right track. Apparently there is a case where "time.ticks_diff" returns 1h 11min.
The code in uasyncio responsible for the delay until the next coroutine is this:
Code: Select all
delay = 0
if not self.runq:
delay = -1
if self.waitq:
tnow = self.time()
t = self.waitq.peektime()
delay = time.ticks_diff(t, tnow)
if delay < 0:
delay = 0
self.wait(delay)
So if there is a case where time.ticks_diff() returns 1h 11 min, it blocks all executions for this duration (unless there were some pollers registered, which was never the case in my applications).
This means we now have to find out the reason why time.ticks_diff can return a 1h 11 min/2^32 offset.
The function in extmod/utime_mphal.c:
Code: Select all
STATIC mp_obj_t time_ticks_diff(mp_obj_t end_in, mp_obj_t start_in) {
// we assume that the arguments come from ticks_xx so are small ints
mp_uint_t start = MP_OBJ_SMALL_INT_VALUE(start_in);
mp_uint_t end = MP_OBJ_SMALL_INT_VALUE(end_in);
// Optimized formula avoiding if conditions. We adjust difference "forward",
// wrap it around and adjust back.
mp_int_t diff = ((end - start + MICROPY_PY_UTIME_TICKS_PERIOD / 2) & (MICROPY_PY_UTIME_TICKS_PERIOD - 1))
- MICROPY_PY_UTIME_TICKS_PERIOD / 2;
return MP_OBJ_NEW_SMALL_INT(diff);
}
My C is a bit too rusty to fully understand what is done here and I don't know where MICROPY_PY_UTIME_TICKS_PERIOD is updated.
But considering that this is an extmod used by all ports and the problem being specific to the esp8266, I'd assume that his function works correctly.
This leads us back to to esp_mphal.c: If the high_word is indeed truncated by the compiler anyway, wouldn't that mean that the returned value would overflow and be back at 0 at one point? However ticks_diff() would then return a negative number and there would be no delay in uasyncio.
So from my knowledge without fully understanding ticks_diff I'm stuck here but at least we got prove that this is a problem within the timing modules on the esp8266.