Skip to content

Inconsistent thread behavior in different versions of MicroPython on ESP32 #15423

Description

@flis-mateusz

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

Activity

  1. dpgeorge commented on Jul 8, 2024

    @dpgeorge
    Member

    Thanks for the report and the simple reproduction.

    I can confirm the issue. I checked MicroPython v1.21.0 and it also shows the same problem.

    Note that:

    • MicroPython v1.20.0 uses IDF v4.2.4
    • MicroPython v1.21.0 uses IDF v5.0.2

    It seems that the issue was introduced when moving to ESP IDF 5.x. It could be that IDF 5 has some different settings for FreeRTOS which give this behaviour.

    It could be simply that FreeRTOS is prioritising threads that are doing a lot of work, over threads that are sleeping.

  2. flis-mateusz commented on Jul 8, 2024

    @flis-mateusz
    Author

    Thank you for the quick reply. In fact, it looks like some sort of optimization of thread tasks.
    If you change this code to the following without any intentional delays, where the same operation is performed in both threads, you will see that it still behaves unpredictably.

    import _thread
    import time
     
    def thread2task():
        print("thread 2 started")
        t = time.ticks_ms()
        while True:
            if (time.ticks_ms() - t > 1000):
                print('T2:', time.ticks_ms() - t)
                t = time.ticks_ms()
    
    
    if __name__ == "__main__":
        _thread.start_new_thread(thread2task,())
        
        t = time.ticks_ms()    
        while True:
            if (time.ticks_ms() - t > 1000):
                print('T1:', time.ticks_ms() - t)
                t = time.ticks_ms()
    
    

    Example output:

    MPY: soft reboot
    T1: 1001
    T1: 1001
    T1: 1001
    thread 2 started
    T1: 1001
    T1: 1001
    T1: 1001
    T1: 1001
    T1: 1001
    T1: 1001
    T2: 5800
    T2: 1001
    T2: 1001
    T2: 1001
    T2: 1001
    T2: 1001
    T2: 1001
    T2: 1001
    T2: 1001
    T2: 1001
    T2: 1001
    T1: 10113
    [...]
    

    It is worth mentioning that this code in version 1.20 works perfectly:

    MPY: soft reboot
    thread 2 started
    T1: 1001
    T2: 1001
    T1: 1001
    T2: 1001
    T1: 1001
    [...]
    

    Well, I think the previous way threads worked was more natural and predictable.
    I would be happy to see any updates related to this. For now, I have to stick with version 1.20 in my project.

  3. added this to the release-1.24.0 milestone on Jul 17, 2024
  4. andrewleech commented on Jul 17, 2024

    @andrewleech
    SponsorContributor

    It would be worth retrying these tests on a v1.23 built with IDF 5.2.2 to see if it's resolved already there.

  5. projectgus commented on Jul 17, 2024

    @projectgus
    Contributor

    @flis-mateusz Thanks for a very clear bug report!

    Looks like Python code such as this could trigger a pathological pattern in the FreeRTOS scheduler that meant some threads wouldn't run for an unbounded amount of time. (In my testing I sometimes ended up in a steady-state where the main thread never woke up at all!) Despite this I'm pretty certain it was a bug in MicroPython not ESP-IDF or FreeRTOS. See the linked PR for an explanation of exactly what happens.

    I think it probably did come in with ESP-IDF V5 when the FreeRTOS version was bumped and the code updated to track the upstream FreeRTOS, but I think it only happened to work as expected in the older ESP-IDF version.

    It would be worth retrying these tests on a v1.23 built with IDF 5.2.2 to see if it's resolved already there.

    I double checked this and unfortunately it behaves the same. I also took a look at the upstream "vanilla FreeRTOS" and as far as I can tell it would behave the same as ESP-IDF in this case, too.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Type

    No type

    Projects

    No projects

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions