RP2: Pico W hangs shortly after start of main.py when connected to USB host

[lowfatcode]

We had reports on our repo that users were having issues with their Pico W locking up: pimoroni/pimoroni-pico#392

I can recreate this issue (using an M1 Macbook Air) with a very simple script:

import time
from machine import Pin

onboard = Pin("LED", Pin.OUT, value=0)

for i in range(0, 40000):
  onboard.on()
  time.sleep(0.025)
  onboard.off()
  time.sleep(0.025)

If that is saved as main.py then when the Pico starts up it will run for perhaps 20-30 iterations of the loop and then lock up hard every single time. Weirdly if I remotely execute the script using the mpremote tool then it runs flawlessly every time.

• occurs both with the official MicroPython build (currently rp2-pico-w-20220712-unstable-v1.19.1-127-g74794d42b.uf2) and also our build (pimoroni-picow-v1.19.2-micropython.uf2)
• definitely happens with MacOS (M1 specifically perhaps? not sure) but we think it may affect other platforms with less consistency
• does not occur on a Pico (sans wireless)
• does not occur if the device is plugged into a microB AC adaptor

I'm pretty sure something is causing the USB stack to fall over on the Pico W which is then causing it to hang completely.

[Gadgetoid]

I see this same issue with Ubuntu, albeit it requires a more complicated main.py to trigger the crash, at which point it happens most of the time with the occasional lucky break where it'll enumerate correctly over USB and not hardlock.

The above code seems to work fine for me, but if I run any code that does something useful then it seems to lock up on reset and dmesg shows me:

[523818.376246] usb 1-4: New USB device found, idVendor=2e8a, idProduct=0005, bcdDevice= 1.00
[523818.376255] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[523818.376257] usb 1-4: Product: Board in FS mode
[523818.376259] usb 1-4: Manufacturer: MicroPython
[523818.376261] usb 1-4: SerialNumber: e6614c311b472731
[523818.378014] cdc_acm 1-4:1.0: ttyACM0: USB ACM device
[524445.718118] audit: type=1326 audit(1657700540.439:4674771): auid=1001 uid=1001 gid=1001 ses=3 subj=? pid=414724 comm="slack" exe="/snap/slack/64/usr/lib/slack/slack" sig=0 arch=c000003e syscall=92 compat=0 ip=0x7fbf5629d3b7 code=0x50000
[524611.331091] usb 1-4: USB disconnect, device number 77
[524611.932995] usb 1-4: new full-speed USB device number 78 using xhci_hcd
[524612.413339] usb 1-4: device descriptor read/all, error -71
[524612.545089] usb 1-4: new full-speed USB device number 79 using xhci_hcd
[524617.121167] usb 1-4: device descriptor read/64, error -71
[524617.533235] usb 1-4: Device not responding to setup address.
[524617.741194] usb 1-4: Device not responding to setup address.
[524617.949033] usb 1-4: device not accepting address 79, error -71
[524617.949235] usb usb1-port4: attempt power cycle
[524618.601077] usb 1-4: new full-speed USB device number 80 using xhci_hcd
[524618.601267] usb 1-4: Device not responding to setup address.
[524618.809200] usb 1-4: Device not responding to setup address.
[524619.017034] usb 1-4: device not accepting address 80, error -71
[524619.144762] usb 1-4: new full-speed USB device number 81 using xhci_hcd
[524619.144938] usb 1-4: Device not responding to setup address.
[524619.353238] usb 1-4: Device not responding to setup address.
[524619.560948] usb 1-4: device not accepting address 81, error -71
[524619.561165] usb usb1-port4: unable to enumerate USB device

If I connect this same board running the same, failing, code to a dumb microUSB power supply it works 100% of the time.

If I run the same code via Thonny it also works 100% of the time.

I had dismissed this as a bad USB cable or voltage drop, but testing with multiple boards and USB cables gets the same result.

[nkotilainen]

I tested the proof of concept script with the latest v1.19.1-129-g5bf376563 (2022-07-13).uf2 on a M1 Macbook Pro with OS X 11.6.6 and the Pico W locked up 17 times out of 20 resets. On the 3 successful tries it seems to keep running long-term with no issues and the board shows up in the USB System Information list correctly.

[liamfraser]

@Gadgetoid can you share your main.py please? I see this on my M1 Mac and we also see it on an Intel Mac.

[aallan]

So from internal testing, it looks like the wireless firmware is being loaded during USB device enumeration. We're seeing problems primarily on Apple hardware as it looks like the Mac is being a bit fussier about timings than other platforms.

Since the wireless stack is loaded on demand, adding a few seconds of delay before pulling it in — in this case to talk to the LED via the 43439 — means it all "just works",

import time
from machine import Pin

time.sleep(5)

onboard = Pin("LED", Pin.OUT, value=0)

for i in range(0, 40000):
  onboard.on()
  time.sleep(0.025)
  onboard.off()
  time.sleep(0.025)

this isn't a solution, but at least we (think) we know what's going on.

[Gadgetoid]

Does import network also load the wireless stack? That might explain why a delay did not work for me when I was battling this issue from a Linux host.

[peterharperuk]

No, import network doesn't load the wifi stack.

It looks like it might be firmware loading being slow and taking time from the usb stack. I can't repro the problem on ubuntu so can't say if it will fix your problem.

[aallan]

@Gadgetoid can you share your main.py please so we can try and replicate on Ubuntu. I've also tried and can't get it to fall over.

[Gadgetoid]

I don't have a minimal test case, the full blown example code I had encountered as failing on Ubuntu was tied to our baked-in libraries. I'll see if I can pare it back.

[peterharperuk]

I don't suppose anyone could test these two changes? You'll have to build the code yourself. I don't have one of these mac things to test at the moment.

georgerobotics/cyw43-driver#12
#8911

[jimmo]

I don't suppose anyone could test these two changes? You'll have to build the code yourself. I don't have one of these mac things to test at the moment.

I have access to one. Will test today. Thanks for the quick fix @peterharperuk !

[Gadgetoid]

Some experimentation suggests that what I'm seeing might be a different but related issue, where USB, Network and our own libraries are contesting for (outside of gc_heap) RAM.

I can't reproduce with any kind of reliability, but I definitely manage to break things if I get beyond a certain complexity. I think the extra RAM pressure is the culprit in my cases, but I will test the fixes nonetheless.

[Gadgetoid]

For @lowfatcode @nkotilainen - upstream with these patches compiled in.

firmware-wifi-fw-load-fix.zip

[Gadgetoid]

The .uf2 in the above .zip seems to be corrupted, but I supplied a fresh build to @nkotilainen and he reports 10/10 success rate.

I didn't want to muddy the waters here, but my own tests built with our modules seemed to be more stable, too.

Hopefully this build will work, should anyone wish to test it but not have the time to compile from source:

firmware-picow-wifi-race-fix.zip

[sammachin]

I had a PicoW with what looks to be this issue, and something in my application was triggering it, just tried with @Gadgetoid's fix above and it seems to be happy now. Thanks, hopefully that patch can get merged in ASAP

[SebasZH]

Hopefully this build will work, should anyone wish to test it but not have the time to compile from source:

firmware-picow-wifi-race-fix.zip

Works great, not only the sample code above but also with my code mentioned here

Looks like a good fix to me.

[dpgeorge]

Should be fixed by 33d6994

[peterharperuk]

Can someone confirm if this build fixes the issue? https://micropython.org/resources/firmware/rp2-pico-w-20220725-unstable-v1.19.1-209-g0c45a28d2.uf2

[mattytrentini]

@peterharperuk yes, it should. @dpgeorge merged this at rev 33d6994 which was (two commits) before that build at 0c45a28. See the commit history on master for more details.

[peterharperuk]

I'd like someone to test it.

[SebasZH]

I am sorry to inform that this build (rp2-pico-w-20220725-unstable-v1.19.1-209-g0c45a28d2.uf2) doesn't work for me on MacOS. However, the build provided by @Gadgetoid (firmware-picow-wifi-race-fix.zip) does work.

Edit/Addition:
The sample code provided by @lowfatcode at the topic start (which does not use networking/WiFi) works now on MacOS. My sample code creating a webserver still locks up the rp2040:

# https://gist.github.com/aallan/3d45a062f26bc425b22a17ec9c81e3b6

import network
import socket
import time

from machine import Pin
import uasyncio as asyncio

led = Pin(15, Pin.OUT)
onboard = Pin("LED", Pin.OUT, value=0)

ssid = 'ssid'
password = 'password'

html = """<!DOCTYPE html>
<html>
    <head> <title>Pico W</title> </head>
    <body> <h1>Pico W</h1>
        <p>%s</p>
    </body>
</html>
"""

wlan = network.WLAN(network.STA_IF)

def connect_to_network():
    wlan.active(True)
    wlan.config(pm = 0xa11140)  # Disable power-save mode
    wlan.connect(ssid, password)

    max_wait = 10
    while max_wait > 0:
        if wlan.status() < 0 or wlan.status() >= 3:
            break
        max_wait -= 1
        print('waiting for connection...')
        onboard.on()
        time.sleep(.1)
        onboard.off()
        time.sleep(1)

    if wlan.status() != 3:
        raise RuntimeError('network connection failed')
    else:
        print('connected')
        status = wlan.ifconfig()
        print('ip = ' + status[0])

async def serve_client(reader, writer):
    print("Client connected")
    request_line = await reader.readline()
    print("Request:", request_line)
    # We are not interested in HTTP request headers, skip them
    while await reader.readline() != b"\r\n":
        pass

    request = str(request_line)
    led_on = request.find('/light/on')
    led_off = request.find('/light/off')
    print( 'led on = ' + str(led_on))
    print( 'led off = ' + str(led_off))

    stateis = ""
    if led_on == 6:
        print("led on")
        led.value(1)
        stateis = "LED is ON"
    
    if led_off == 6:
        print("led off")
        led.value(0)
        stateis = "LED is OFF"
        
    response = html % stateis
    writer.write('HTTP/1.0 200 OK\r\nContent-type: text/html\r\n\r\n')
    writer.write(response)

    await writer.drain()
    await writer.wait_closed()
    print("Client disconnected")

async def main():
    print('Connecting to Network...')
    connect_to_network()

    print('Setting up webserver...')
    asyncio.create_task(asyncio.start_server(serve_client, "0.0.0.0", 80))
    while True:
        print("heartbeat")
        
        onboard.on()
        await asyncio.sleep(0.1)
        onboard.off()
        await asyncio.sleep(0.2)
        onboard.on()
        await asyncio.sleep(0.1)
        onboard.off()
        await asyncio.sleep(5)
        
try:
    asyncio.run(main())
finally:
    asyncio.new_event_loop()

[peterharperuk]

ok - I have access to a mac now and I can repro your issue.

[peterharperuk]

To avoid confusion (maybe) I raised a new issue #8963

[peterharperuk]

@SebasZH Can you test the latest nightly? I tested your script on a mac and it worked. https://micropython.org/resources/firmware/rp2-pico-w-20220727-unstable-v1.19.1-216-g45ab801c3.uf2

[SebasZH]

@peterharperuk I can confirm the webserver script now works on MacOS. Thanks!