ESP32: Threading with 2 or 3 similar threads not properly scheduled
Platform: ESP32 Wroom
MP-Version: MicroPython v1.19.1 on 2022-06-18; ESP32 module with ESP32
I observed that the computation performance of 2 or 3 identical threads started in parallel is very unevenly distributed, the worst case being one of 3 threads getting only 1 % of computation power.
Further investigation revealed that there are very long durations during which a single thread is not activated. This may be the reason for the first observation.
A test program appended below after a few runs exhibits the following output,
Threads tmin: 0 0 ms
Threads tmax: 9981 10 ms
Iterations: 957 302461
showing that the first of 2 threads is not active in 9.98 seconds of 10 seconds total, resulting in only 957 iterations instead of about 150000 which would be expected in fair scheduling.
This problem seems to vanish if there are 4 or more similar threads active, then the tmax take quite similar values of 20-40 ms.
This is only observed on esp32. Testing of Pyboard and Unix port of MP revealed fair scheduling.
The test program:
import _thread
from time import sleep, sleep_ms
from machine import idle, Timer
flag = False
tim0 = Timer(0)
tim0.init(period=20000, mode=Timer.ONE_SHOT, callback=lambda t:print('interrupt 0'))
rmin = [0, 0]
rmax = [0, 0]
ret = [0, 0]
def th_tims(i):
global rmin, rmax, ret
while not flag:
idle()
tmin = 1_000_000; tmax = 0; n = 0
t0 = tim0.value()
t1 = tim0.value()
td = t1 - t0 # put some computation here,
t1 = min(td, tmin) # .. so we don't produce the minimum here
t1 = max(td, tmin)
t1 = min(td, tmin)
t1 = max(td, tmin)
while flag:
t1 = tim0.value() # get weird results without the lock (4, 5, 10 seconds for max)
td = t1 - t0
tmin = min(td, tmin)
tmax = max(td, tmax)
t0 = t1
n +=1
rmin[i] = tmin
rmax[i] = tmax
ret[i] = n
_thread.start_new_thread(th_tims, (0,))
_thread.start_new_thread(th_tims, (1,))
flag = True
sleep(10)
flag = False
sleep_ms(50)
print('Threads tmin: {:9d} {:9d} ms'.format(rmin[0], rmin[1]))
print('Threads tmax: {:9d} {:9d} ms'.format(rmax[0], rmax[1]))
print('Iterations: {:9d} {:9d}'.format(ret[0], ret[1]))
From an initial version with machine.ticks_us() I switched to hardware timer, suspecting that ticks_us() was not thread-safe.
This is wrong. It was discussed here.
As a partial workaround the introduction of a lock (aquired and released in the while flag: loop) could be used. The threads then have breaks of up to 0.5 seconds and overall performance is almost halved, but scheduling is quite fair.
Inconsistent thread behavior in different versions of MicroPython on ESP32
Port, board and/or hardware
ESP-WROOM-32 (chip ESP32-D0WD-V3)
MicroPython version
- [Works well] MicroPython v1.20.0 on 2023-04-26; ESP32 module with ESP32
- [Bug] MicroPython v1.22.2 on 2024-02-22; Generic ESP32 module with ESP32
- [Bug] MicroPython v1.23.0 on 2024-06-02; Generic ESP32 module with ESP32
Reproduction
import _thread
import time
def thread2task():
print("thread 2 started")
while True:
pass
if __name__ == "__main__":
_thread.start_new_thread(thread2task,())
while 1:
t = time.ticks_ms()
time.sleep(1)
print(time.ticks_ms() - t)
Expected behaviour
The main loop should consistently produce similar timing intervals regardless of the thread's state. For example, the sleep interval should be close to 1000ms as in version 1.20.
Output:
- MicroPython v1.20.0 on 2023-04-26; ESP32 module with ESP32:
MPY: soft reboot
thread 2 started
1006
1010
1010
1010
1010
1010
1010
1010
1010
1010
[...]
Observed behaviour
Creating a simple thread in versions above 1.20 causes variable time intervals, which affects the timing accuracy of the main loop, suspends the connection to the computer, and often prevents the script from being restarted.
Output:
- MicroPython v1.22.2 on 2024-02-22; Generic ESP32 module with ESP32:
MPY: soft reboot
thread 2 started
[Nothing else appears, this is where the script gets stuck]
- MicroPython v1.23.0 on 2024-06-02; Generic ESP32 module with ESP32:
Once I managed to get this result, other times nothing is printed, as in version 1.22.2
MPY: soft reboot
thread 2 started
1843
1230
1830
2060
1500
1500
2020
1980
2020
1980
[...]
Additional Information
No, I've provided everything above.
Code of Conduct
Yes, I agree