When using platformio, earlephilhower-based firmware doesn't run after reboot-to-bootloader (but does after hard BOOTSEL+RESET)

egnor commented 3 months ago

My system

board: Adafruit Feather RFM95 (but I suspect this isn't important)
platformio version: 6.1.15 (what pip install gives me)
earlephilhower version: 3.8.0 (what I get from maxgerhardt/platform-raspberrypi.git)
OS: Ubuntu 23.10 (Mantic), Linux 6.5.0-28 (not sure this matters either)

Steps to repro (make a super trivial platformio project)

(probably setup a Python virtualenv and an empty working directory)
pip install platformio

create platformio.ini:

[env:trivial_test]
platform = https://github.com/maxgerhardt/platform-raspberrypi.git
framework = arduino
board = adafruit_feather_rfm

create src/trivial_test_main.cpp:
```
#include <Arduino.h>
```

void setup() { Serial.begin(115200); Serial.println("SETUP"); }

void loop() { Serial.println("LOOP"); delay(500); }


5. monitor kernel logs (`journalctl -fk`)
6. connect the RP2040, put it in BOOTSEL mode (hold down BOOT, press RESET), I get kernel logs like this which all looks good (the bootloader USB disk showing up):

May 09 19:19:14 skully kernel: usb 3-2.2: new full-speed USB device number 84 using xhci_hcd May 09 19:19:14 skully kernel: usb 3-2.2: New USB device found, idVendor=2e8a, idProduct=0003, bcdDevice= 1.00 May 09 19:19:14 skully kernel: usb 3-2.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3 May 09 19:19:14 skully kernel: usb 3-2.2: Product: RP2 Boot May 09 19:19:14 skully kernel: usb 3-2.2: Manufacturer: Raspberry Pi May 09 19:19:14 skully kernel: usb 3-2.2: SerialNumber: E0C9125B0D9B May 09 19:19:14 skully kernel: usb-storage 3-2.2:1.0: USB Mass Storage device detected May 09 19:19:14 skully kernel: scsi host3: usb-storage 3-2.2:1.0 May 09 19:19:15 skully kernel: scsi 3:0:0:0: Direct-Access RPI RP2 3 PQ: 0 ANSI: 2 May 09 19:19:15 skully kernel: sd 3:0:0:0: Attached scsi generic sg3 type 0 May 09 19:19:15 skully kernel: sd 3:0:0:0: [sdd] 262144 512-byte logical blocks: (134 MB/128 MiB) May 09 19:19:15 skully kernel: sd 3:0:0:0: [sdd] Write Protect is off May 09 19:19:15 skully kernel: sd 3:0:0:0: [sdd] Mode Sense: 03 00 00 00 May 09 19:19:15 skully kernel: sd 3:0:0:0: [sdd] No Caching mode page found May 09 19:19:15 skully kernel: sd 3:0:0:0: [sdd] Assuming drive cache: write through May 09 19:19:15 skully kernel: sdd: sdd1 May 09 19:19:15 skully kernel: sd 3:0:0:0: [sdd] Attached SCSI removable disk


7. run `pio run -t upload` (might need `--upload-port=/media/$USER/RPI-RP2`). for me, it works:

May 09 19:21:50 skully kernel: usb 3-2.2: USB disconnect, device number 84 May 09 19:21:50 skully kernel: usb 3-2.2: new full-speed USB device number 85 using xhci_hcd May 09 19:21:50 skully kernel: usb 3-2.2: New USB device found, idVendor=2e8a, idProduct=000a, bcdDevice= 1.00 May 09 19:21:50 skully kernel: usb 3-2.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3 May 09 19:21:50 skully kernel: usb 3-2.2: Product: Feather RP2040 RFM May 09 19:21:50 skully kernel: usb 3-2.2: Manufacturer: Adafruit May 09 19:21:50 skully kernel: usb 3-2.2: SerialNumber: DF62585783553434 May 09 19:21:50 skully kernel: cdc_acm 3-2.2:1.0: ttyACM3: USB ACM device


8. run `pio device monitor`, this should show `LOOP` printing over and over. cool cool
9. run `pio run -t upload` again. the upload seems to succeed...

[ ... ] Auto-detected: /dev/ttyACM3 Forcing reset using 1200bps open/close on port /dev/ttyACM3 Uploading .pio/build/trivial_test/firmware.elf rp2040load 1.0.1 - compiled with go1.15.8 ...Loading into Flash: [ ] 0% Loading into Flash: [= ] 5% [ ... ] Loading into Flash: [============================= ] 99% Loading into Flash: [==============================] 100%

========================= [SUCCESS] Took 5.44 seconds =========================


   in the kernel logs, we see the serial port going away and mass storage:

May 09 19:25:21 skully kernel: usb 3-2.2: USB disconnect, device number 85 May 09 19:25:21 skully kernel: usb 3-2.2: new full-speed USB device number 86 using xhci_hcd May 09 19:25:21 skully kernel: usb 3-2.2: New USB device found, idVendor=2e8a, idProduct=0003, bcdDevice= 1.00 May 09 19:25:21 skully kernel: usb 3-2.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3 May 09 19:25:21 skully kernel: usb 3-2.2: Product: RP2 Boot May 09 19:25:21 skully kernel: usb 3-2.2: Manufacturer: Raspberry Pi May 09 19:25:21 skully kernel: usb 3-2.2: SerialNumber: E0C9125B0D9B May 09 19:25:21 skully kernel: usb-storage 3-2.2:1.0: USB Mass Storage device detected May 09 19:25:21 skully kernel: scsi host3: usb-storage 3-2.2:1.0 May 09 19:25:22 skully kernel: scsi 3:0:0:0: Direct-Access RPI RP2 3 PQ: 0 ANSI: 2 May 09 19:25:22 skully kernel: sd 3:0:0:0: Attached scsi generic sg3 type 0 May 09 19:25:22 skully kernel: sd 3:0:0:0: [sdd] 262144 512-byte logical blocks: (134 MB/128 MiB) May 09 19:25:22 skully kernel: sd 3:0:0:0: [sdd] Write Protect is off May 09 19:25:22 skully kernel: sd 3:0:0:0: [sdd] Mode Sense: 03 00 00 00 May 09 19:25:22 skully kernel: sd 3:0:0:0: [sdd] No Caching mode page found May 09 19:25:22 skully kernel: sd 3:0:0:0: [sdd] Assuming drive cache: write through May 09 19:25:22 skully kernel: sdd: sdd1 May 09 19:25:22 skully kernel: sd 3:0:0:0: [sdd] Attached SCSI removable disk


   that all looks good, right? but here is where the wheels fall off. instead of the mass storage unmounting and the serial port mounting, we start getting errors from the kernel

May 09 19:25:24 skully kernel: usb 3-2.2: reset full-speed USB device number 86 using xhci_hcd May 09 19:25:35 skully kernel: xhci_hcd 0000:00:14.0: Timeout while waiting for setup device command May 09 19:25:40 skully kernel: xhci_hcd 0000:00:14.0: Timeout while waiting for setup device command May 09 19:25:40 skully kernel: usb 3-2.2: device not accepting address 86, error -62 May 09 19:25:40 skully kernel: usb 3-2.2: reset full-speed USB device number 86 using xhci_hcd May 09 19:25:56 skully kernel: usb 3-2.2: device descriptor read/64, error -110 [ ... ]


    and of course it's impossible to `pio device monitor` since no serial port has shown up. Importantly, if you change the program to blink an LED or something, you can see that it's not just a USB issue, the firmware is not actually running!

10. press RESET on the board. NOW we get our serial port

May 09 19:29:09 skully kernel: usb 3-2.2: new full-speed USB device number 91 using xhci_hcd May 09 19:29:09 skully kernel: usb 3-2.2: New USB device found, idVendor=2e8a, idProduct=000a, bcdDevice= 1.00 May 09 19:29:09 skully kernel: usb 3-2.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3 May 09 19:29:09 skully kernel: usb 3-2.2: Product: Feather RP2040 RFM May 09 19:29:09 skully kernel: usb 3-2.2: Manufacturer: Adafruit May 09 19:29:09 skully kernel: usb 3-2.2: SerialNumber: DF62585783553434 May 09 19:29:09 skully kernel: cdc_acm 3-2.2:1.0: ttyACM3: USB ACM device


and we can `pio device monitor`, etc.

## Discussion

It seems like the firmware runs fine after a hard reset, but after a soft reset-to-bootloader from platformio+earlephilhower, you can load new firmware with the USB mass storage drive, and the USB mass storage system will stop, but... you never get the expected reset into a serial port, and the firmware image doesn't actually seem to start.

For whatever reason this appears to be specific to platformio+earlephilhower! If you use the Arduino IDE with the earlephilhower core, everything is hunky dory and you can soft-reboot and reflash the device all day with no problem. Similarly if you use the basic Pico SDK and just do things by hand.

This whole thing (including platformio) used to work for me, but for some reason just started not working for me. Shades of the old RP2040-E5 errata, but that's long fixed, and also that would happen the same regardless of hard reset vs soft reboot.

earlephilhower commented 3 months ago

Looks more like a USB stack issue on the Linux machine than the Pico or platform.io. (FWIW, I too sometimes get USB issues when a Pico hangs that require a power cycle of the port of a reset of the /sys/.../xHCI devices).

The FW upload is handled in ROM on the Pico, as is the reset out of bootloader mode. Possibly the upload changes devices too fast (UF2 goes away and CDC shows up without sufficient time for the OS to do whatever cleanup it needs)?

Looks like P.IO is configures to use something called rp2040load in your config. The IDE doesn't support that, but it does handle UF2, PicoProbe, and PicoTool uploaders. Maybe you can change the configuration in the P.IO ini to use one of those instead?

egnor commented 3 months ago

The Linux USB stack definitely sucks but I don't think it's the whole story? The Pico doesn't actually run the firmware (no LED blinky) even though the upload seemingly completed. I even tried supplying external 5V and then unplugging the USB and it still didn't blink until I hit reset. So the RP2040 is in some wedged state.

Theory 1: the upload didn't actually complete??

Theory 2: the upload did complete, but early on in the boot of the uploaded firmware (with this platform) it wedged, preventing the Pico's USB stack from resetting properly??

Theory 3: the upload does complete and it does reboot into the firmware but Linux screws up and does something with USB that actually interferes with firmware boot when it wants to set up the CDC device, and it wedges?

I will mess with the upload technique and report back!

egnor commented 3 months ago

I don't know what's going on, but I don't think this is an issue with the earlephilhower Arduino layer! I'll close this out and open a new issue with the maxgerhardt platformio integration.

Gory details for the record: I confirmed that installing with

stty 1200 < /dev/ttyACM3  # reboot to ROM bootloader
cp .pio/build/trivial_test/firmware.uf2 /media/egnor/RPI-RP2

works fine, where pio run -t upload leads to the hang. (Side note: sometimes, after a minute or two, the hang ends and the board starts running. Not always?) Platformio SAYS it's using picotool, here's the full upload log (with -v):

% pio run -t upload -v
Processing trivial_test (platform: https://github.com/maxgerhardt/platform-raspberrypi.git; framework: arduino; board: adafruit_feather_rfm)
--------------------------------------------------------------------------------
CONFIGURATION: https://docs.platformio.org/page/boards/raspberrypi/adafruit_feather_rfm.html
PLATFORM: Raspberry Pi RP2040 (1.11.0+sha.60d6ae8) (git+https://github.com/maxgerhardt/platform-raspberrypi.git) > Feather RP2040 RFM
HARDWARE: RP2040 133MHz, 264KB RAM, 8MB Flash
DEBUG: Current (blackmagic) External (blackmagic, cmsis-dap, jlink, pico-debug, picoprobe, raspberrypi-swd)
PACKAGES: 
 - framework-arduinopico @ 1.30700.0+sha.88ccf0c (git+https://github.com/earlephilhower/arduino-pico.git#88ccf0c256dc717ff932adc9e2d84485214bf2e5) 
 - tool-mklittlefs-rp2040-earlephilhower @ 5.100300.230216 (10.3.0) 
 - tool-openocd-rp2040-earlephilhower @ 5.120300.240125 (12.3.0, https://github.com/earlephilhower/pico-quick-toolchain/releases/download/2.2.0/x86_64-linux-gnu.openocd-4d87f6dca.240125.tar.gz) 
 - tool-rp2040tools @ 1.0.2 
 - toolchain-rp2040-earlephilhower @ 5.120300.240125 (12.3.0, https://github.com/earlephilhower/pico-quick-toolchain/releases/download/2.2.0/x86_64-linux-gnu.arm-none-eabi-028e019.240125.tar.gz)
Flash size: 8.00MB
Sketch size: 8.00MB
Filesystem size: 0.00MB
Maximium Sketch size: 8384512 EEPROM start: 0x107ff000 Filesystem start: 0x107ff000 Filesystem end: 0x107ff000
LDF: Library Dependency Finder -> https://bit.ly/configure-pio-ldf
LDF Modes: Finder ~ chain, Compatibility ~ soft
Ignored library /home/egnor/.platformio/packages/framework-arduinopico/libraries/Adafruit_TinyUSB_Arduino
Found 52 compatible libraries
More details about "Library Compatibility Mode": https://docs.platformio.org/page/librarymanager/ldf.html#ldf-compat-mode
Scanning dependencies...
No dependencies
Building in release mode
<lambda>(["checkprogsize"], [".pio/build/trivial_test/firmware.elf"])
Flash size: 8.00MB
Sketch size: 8.00MB
Filesystem size: 0.00MB
Maximium Sketch size: 8384512 EEPROM start: 0x107ff000 Filesystem start: 0x107ff000 Filesystem end: 0x107ff000
MethodWrapper(["checkprogsize"], [".pio/build/trivial_test/firmware.elf"])
Advanced Memory Usage is available via "PlatformIO Home > Project Inspect"
RAM:   [          ]   3.8% (used 10040 bytes from 262144 bytes)
Flash: [          ]   0.7% (used 58096 bytes from 8384512 bytes)
.pio/build/trivial_test/firmware.elf  :
section               size        addr
.boot2                 256   268435456
.ota                  9444   268435712
.partition            2588   268445156
.text                49800   268447744
.rodata               2316   268497544
.ram_vector_table      192   536870912
.data                 5724   536871104
.scratch_x               0   537133056
.scratch_y               0   537137152
.bss                  4316   536876832
.heap                 2048   536881148
.stack1_dummy         2048   537133056
.stack_dummy          2048   537137152
.ARM.attributes         40           0
.comment                18           0
.debug_info         312836           0
.debug_abbrev        63387           0
.debug_loclists      99956           0
.debug_aranges        7352           0
.debug_rnglists      11697           0
.debug_line         156977           0
.debug_str           43386           0
.debug_frame         15780           0
.debug_line_str       1016           0
Total               793225
<lambda>(["upload"], [".pio/build/trivial_test/firmware.elf"])
AVAILABLE: blackmagic, cmsis-dap, jlink, pico-debug, picoprobe, picotool, raspberrypi-swd
CURRENT: upload_protocol = picotool
BeforeUpload(["upload"], [".pio/build/trivial_test/firmware.elf"])
TimeoutError: Could not automatically find serial port for the `Feather RP2040 RFM` board based on the declared HWIDs=['239A:812D', '239A:812D']
Auto-detected: /dev/ttyACM3
Forcing reset using 1200bps open/close on port /dev/ttyACM3
"/home/egnor/.platformio/packages/tool-rp2040tools/rp2040load" -v -D .pio/build/trivial_test/firmware.elf
rp2040load 1.0.1 - compiled with go1.15.8
...Loading into Flash: [                              ]  0%
Loading into Flash: [=                             ]  5%
Loading into Flash: [===                           ]  11%
Loading into Flash: [=====                         ]  17%
Loading into Flash: [======                        ]  23%
Loading into Flash: [========                      ]  29%
Loading into Flash: [==========                    ]  35%
Loading into Flash: [============                  ]  40%
Loading into Flash: [=============                 ]  46%
Loading into Flash: [===============               ]  52%
Loading into Flash: [=================             ]  58%
Loading into Flash: [===================           ]  64%
Loading into Flash: [=====================         ]  70%
Loading into Flash: [======================        ]  75%
Loading into Flash: [========================      ]  81%
Loading into Flash: [==========================    ]  87%
Loading into Flash: [===========================   ]  93%
Loading into Flash: [============================= ]  99%
Loading into Flash: [==============================]  100%

========================= [SUCCESS] Took 5.53 seconds =========================

Surprisingly, the picotool option doesn't mean to use... picotool, instead it means to use rp2040load (unless uploadfs is also wanted). This is probably because picotool doesn't know how to use 1200-baud to reboot the device into bootloader mode (instead it looks for a "reset interface" it doesn't find when running an earlephilhower image).

If I use picotool by hand, things work repeatedly:

% stty 1200 < /dev/ttyACM3
% ~/source/picotool/build/picotool load -f .pio/build/trivial_test/firmware.elf
Loading into Flash: [==============================]  100%
% ~/source/picotool/build/picotool reboot
The device was rebooted into application mode.

(light blinks, and I can repeat this all day.) If I use rp2040load, things STILL work:

% stty 1200 < /dev/ttyACM3
% /home/egnor/.platformio/packages/tool-rp2040tools/rp2040load -D .pio/build/trivial_test/firmware.elf -v
rp2040load 1.0.1 - compiled with go1.15.8
Loading into Flash: [==============================]  100%

(again, light blinks, and I can repeat this all day.) And yet, pio run -t upload causes the hang!

egnor commented 3 months ago

OK, I have gotten it to hang with picotool and also rp2040load -- see https://github.com/maxgerhardt/platform-raspberrypi/issues/65 for further details.

earlephilhower / arduino-pico

When using platformio, earlephilhower-based firmware doesn't run after reboot-to-bootloader (but does after hard BOOTSEL+RESET) #2153

My system

Steps to repro (make a super trivial platformio project)