[Bug] Primehub "hangs" in mid program run on Pybricks beta.12 and firmware 3.0.0b4

BertLindeman commented 3 years ago

Describe the bug Sometimes (unpredictable for me at the moment) a running program hangs

To reproduce Steps to reproduce the behavior (NO fixed scenario, just sometimes) Describing the last situation I had:

Go to code.pybricks.com
loaded and ran all tests in pybricks-micropython\tests\pup\sensors (a few times even) except ultrasonic_presence.py
After starting ultrasonic_presence.py the situation occurred. It is such a small program, I do not understand what's wrong.

Expected behavior The test to run successfully

Screenshots Stationery so no animation, display looks like:

versions

Hub firmware: 'primehub', '3.0.0b4', 'b4b450d3 on 2021-04-10'
Pybricks protocol version: 1.0.0
Pybricks Code v1.0.0-beta.12
Win10
Microsoft Edge Versie 89.0.774.75 (Officiële build) (64-bits)

additional info

Stop button on the code webpage does "nothing"
attempt to stop the hub by holding the middle button, no success have to take the battery out to get it back to normal.
No errors are seen on the developers' info page
There is a color sensor connected to the hardware module (1) during the hang the color sensor's lights blink altogether. looks like "half a second" OFF and "2 or 3 seconds" ON. The color sensor is not instantiated in the program.

The program

# SPDX-License-Identifier: MIT
# Copyright (c) 2020 The Pybricks Authors

"""
Hardware Module: 1

Description: Verifies that the Ultrasonic Sensor does not sense ultrasonic
interference by default.
"""
from pybricks.pupdevices import UltrasonicSensor
from pybricks.parameters import Port

# Initialize devices.
ultrasonic_sensor = UltrasonicSensor(Port.C)

# Assert that there are no ultrasonic devices nearby.
assert not ultrasonic_sensor.presence(), "Unexpected interference detected."

[EDIT] added precise firmware level

BertLindeman commented 3 years ago

Was busy on coverage test for Spike ColorSensor

BertLindeman commented 3 years ago

After a reboot of the primehub, and ctrl-F5 on the code webpage: ran ultrasonic_presence.py 93 times (counted on the log) and then got:

Running downloaded program...

...done.
ValueError: incompatible .mpy file
ValueError: incompatible .mpy file
ValueError: incompatible .mpy file
ValueError: incompatible .mpy file
ValueError: incompatible .mpy file
ValueError: incompatible .mpy file

BertLindeman commented 3 years ago

Once more same hang; running: pybricks-api\examples\pup\sensor_ultrasonic\basics.py

Same hardware / software / environment. Same blinking color sensor

[EDIT]: Does not seem to be memory-related. Added to the loop:

    print('-----------------------------')
    micropython.mem_info()
    print('-----------------------------')

Log at the start shows:

-----------------------------
stack: 356 out of 38944
GC: total: 258048, used: 1072, free: 256976
 No. of 1-blocks: 14, 2-blocks: 5, max blk sz: 16, max free sz: 16050
-----------------------------
2000

Log at the end shows:

-----------------------------
stack: 356 out of 38944
GC: total: 258048, used: 1072, free: 256976
 No. of 1-blocks: 14, 2-blocks: 5, max blk sz: 16, max free sz: 16050
-----------------------------
40
-----------------------------
stack: 356 out of 38944
GC: total: 258048, used: 1072, free: 256976
 No. of 1-blocks: 14, 2-blocks: 5, max blk sz: 16, max free sz: 16050
-----------------------------
40
-----------------------------
stack: 356 out of 38944
GC: total: 258048, used: 1072, free: 256976
 No. of 1-blocks: 14, 2-blocks: 5, max blk sz: 16, max free sz: 16050
-----------------------------
40
-----------------------------
stack: 356 out of 38944
GC: total: 258048, used: 1072, free: 256976
 No. of 1-blocks: 14, 2-blocks: 5, max blk sz: 16, max free sz: 16050
-----------------------------
40
-----------------------------
stack: 356 out of 38944
GC: total: 258048, used: 1072, free: 256976
 No. of 1-blocks: 14, 2-blocks: 5, max blk sz: 16, max free sz: 16050
-----------------------------
40
-----------------------------
stack: 356 out of 38944
GC: total: 258048, used: 1072, free: 256976
 No. of 1-blocks: 14, 2-blocks: 5, max blk sz: 16, max free sz: 16050
-----------------------------
40

BertLindeman commented 3 years ago

The same happened on Linux Google Chrome and Chromium after some more time. After win10 reboot it takes a lot more time. (Not happened yet after 17,030,000 times taking sensor.distance()

dlech commented 3 years ago

Does this happen on other hubs?

BertLindeman commented 3 years ago

Did not (yet) try. And at the moment on Win10 (after reboot) no problem after 91,155,000 times taking the distance. Might be "reboot" a first response?

Will try a technic hub now.

[EDIT] added program used:

from pybricks.pupdevices import UltrasonicSensor
from pybricks.parameters import Port
from pybricks.tools import wait

# Initialize the sensor.
eyes = UltrasonicSensor(Port.C)
counter = 0
max = 0
min = 9999
while True:
    counter += 1
    # Print the measured distance.
    dist = eyes.distance()
    if dist > max:
        max = dist
    if dist < min:
        min = dist
    if counter % 5000 == 0:
        print("%12d Distance:%5d Min:%5d Max:%5d" % (counter, dist, min, max))
        max = 0
        min = 9999
    # # If an object is detected closer than 500mm:
    # if eyes.distance() < 500:
    #     # Turn the lights on.
    #     eyes.lights.on(100)
    # else:
    #     # Turn the lights off.
    #     eyes.lights.off()

    # Wait some time so we can read what is printed.
    # wait(100)

dlech commented 3 years ago

There have been quite a few times recently where I had to reboot Windows because it seems that the Bluetooth stack got in a bad state (i.e. restarting the web browser was not enough).

BertLindeman commented 3 years ago

My feeling is that it is more than the Bluetooth stack. It's confusing to me anyway. The blinking colorsensor and no responsive middle button might not be caused by a Bluetooth stack on windows.

Win10 - MS EDGE test on TechnicHub is running - just passed the 10.000.000 mark. Stopped the run on win10 at 54,060,000 Now back to linux mint.

BertLindeman commented 3 years ago

got a "hang" after reboot win10 using MS EDGE on a Spike hub with firmware ('primehub', '3.0.0b5', 'e5858276 on 2021-04-12') and Pybricks Code v1.0.0-beta.14

Maybe it's getting reproducible. Run these test in pybricks-micropython\tests\pup\sensors THREE times in this order:

color_color.py
color_mode.py
color_reflection.py
ultrasonic_distance.py

Then running ultrasonic_lights.py causes the "hang". This is the second time this occurred, now.

Will try the same on Linux Mint tomorrow.

dlech commented 3 years ago

Since Pybricks Code v1.0.0-beta.14, if the hub hangs, can you reboot the hub and still use Pybricks Code without restarting Pybricks Code?

BertLindeman commented 3 years ago

Since Pybricks Code v1.0.0-beta.14, if the hub hangs, can you reboot the hub and still use Pybricks Code without restarting Pybricks Code?

Could not reboot by long-press the middle button. (did I forget a reboot button combination?) Did:

Bluetooth disconnect on "code"
Battery out of the Spike hub . . .
Battery in again and boot
run ultrasonic_lights.py 5 times no problem so far

Was that what you asked @dlech ?.

Could recreate the freeze on beta-14 on:

Linux mint
Google chrome 89.0.4389.114

The scenario from above : Run these test in pybricks-micropython\tests\pup\sensors THREE times in this order:

color_color.py
color_mode.py
color_reflection.py
ultrasonic_distance.py

Then running ultrasonic_lights.py causes the "hang".

Could be that there is a shorter recreate scenario, but this scenario now worked a number of times. Will try to get it shorter and still produce the freeze each time.

BertLindeman commented 3 years ago

Adapted ultrasonic_lights.py to run 'forever" like this:

# SPDX-License-Identifier: MIT
# Copyright (c) 2020 The Pybricks Authors

"""
Hardware Module: 1

Description: This tests the lights on the Ultrasonic Sensor. No external
sensors are used to verify that it works.
"""

from pybricks.pupdevices import UltrasonicSensor
from pybricks.parameters import Port
from pybricks.tools import wait
from urandom import randint

# Initialize devices.
lights = UltrasonicSensor(Port.C).lights
count = 0
while True:
    count += 1
    print("Start iteration", count)
    # Turn on all lights at full brightness.
    lights.on()
    wait(500)

    # Turn on all lights.
    for i in range(-50, 150, 2):
        lights.on(i)
        wait(20)

    # Turn of all lights.
    lights.off()
    wait(500)

    # Turn on all lights.
    for i in range(50):
        lights.on([randint(0, 100) for j in range(4)])
        wait(50)

Ran a three times with this as result:

Start iteration 1
Start iteration 2
Start iteration 3
Start iteration 4
Start iteration 1
Start iteration 2
Start iteration 3
Start iteration 4
Start iteration 5
Start iteration 6
Start iteration 7
Start iteration 1
Start iteration 2
Start iteration 3
Start iteration 4
Start iteration 5
Start iteration 6
Start iteration 7
Start iteration 8
Start iteration 9
Start iteration 10
Start iteration 11
Start iteration 12
Start iteration 13
Start iteration 14
Start iteration 15
Start iteration 16

Each time eventually a freeze occurred. So in iteration 4, 7 and 16 Not very stable though.

laurensvalk commented 3 years ago

Thanks a lot for your detailed investigation!

ultrasonic_distance.py Then running ultrasonic_lights.py causes the "hang".

I have a hunch that switching modes and writing to the sensor (for the lights) is wreaking havoc here.

BertLindeman commented 3 years ago

@laurensvalk

I have a hunch that switching modes and writing to the sensor (for the lights) is wreaking havoc here.

A shorter script also does the freeze, but not as fast:

while True:
    count += 1
    print("Start iteration", count, end="")
    # Turn on all lights.
    for i in range(50):
        lights.on([randint(0, 100) for j in range(4)])
        # wait(50)
    print("; ended")

This does no mode switching, just write light values to the sensor. Hang at:

Start iteration 405; ended
Start iteration 406

Start iteration 167; ended
Start iteration 168

Start iteration 83; ended
Start iteration 84

Note that I removed the wait after the lights switch for speed sake

laurensvalk commented 3 years ago

This does no mode switching, just write light values to the sensor.

Indeed, both can be an issue, separately and combined. I'll add a test that does this specifically, thanks.

And just to confirm, you no longer see this, right?

ValueError: incompatible .mpy file

BertLindeman commented 3 years ago

And just to confirm, you no longer see this, right?

ValueError: incompatible .mpy file

Well . . . If I do no funny things. Example: stopped a program and then press UP or DOWN button, shows:

SystemExit: stop button pressed
ValueError: incompatible .mpy file
ValueError: incompatible .mpy file
ValueError: incompatible .mpy file
ValueError: incompatible .mpy file
ValueError: incompatible .mpy file

No idea why I would want to press UP or DOWN though 😃 And do not know what the cursor keys are supposed to do. Most browsing keys act the same.

laurensvalk commented 3 years ago

Ah, yes, good one. That reminds me of a separate issue 😄

laurensvalk commented 3 years ago

I've split the remaining open problems in this thread into separate issues. Thanks for reporting!

dlech commented 3 years ago

Was that what you asked @dlech ?

Yes thanks. Just wanted to verify that even if the hub has problems that Pybricks Code can recover without having to be restarted.

pybricks / support

[Bug] Primehub "hangs" in mid program run on Pybricks beta.12 and firmware 3.0.0b4 #297