USB CDC not flashing RP2040 reliably #3012

kenbell · 2022-07-22T13:02:59Z

It seems like tinygo flash only works immediately after a hardware reset and not after a soft reset.

OS:

$ lsb_release -a
No LSB modules are available.
Distributor ID:	Ubuntu
Description:	Ubuntu 22.04 LTS
Release:	22.04
Codename:	jammy

TinyGo:
tinygo version 0.25.0-dev-3047d8f3 linux/amd64 (using go version go1.18.3 and LLVM version 14.0.0)

Connections:

RP2040 board (challenger RP2040) attached to USB (CDC maps to /dev/ttyACM0)

Scenario:

Plug-in board to USB (observe /dev/ttyACM0 present)
Run tinygo flash -target challenger-rp2040 ./src/examples/serial/ (observe flash succeeds)
Run tinygo flash -target challenger-rp2040 ./src/examples/serial/ (observe error error: unable to locate a serial port)

The text was updated successfully, but these errors were encountered:

kenbell · 2022-07-22T13:07:51Z

(I have reproduced this issue on a vanilla Pico)

sago35 · 2022-07-22T13:26:46Z

@kenbell
I'll try it later.
Could you also try the following PR code?

#2991

kenbell · 2022-07-22T14:33:16Z

Thanks @sago35 - I've just tried that PR. It's not helping with my scenario unfortunately.

kenbell · 2022-07-22T15:33:13Z

It might be related to that errata. I've been having the rp2040 boards plugged into a USB hub with some other devices. Using a USB port directly on my PC it's a lot more reliable.

sago35 · 2022-07-22T16:02:43Z

#2991 code may not be well implemented yet.
Because RP2040-E5 is not reproduced in my environment.

deadprogram · 2022-07-22T16:05:04Z

Perhaps related to same issue as micropython/micropython#8904

sago35 · 2022-07-22T16:30:16Z

tinygo flash failed when USB-CDC exchange was executed from another microcontroller with the same USB-HUB.
To be clear, USB Enumeration has failed.

#2991 source will allow successful USB Enumeration.
Perhaps a workaround for errata is done.

However, USB enumeration of rp2040-bootloader almost always fails after portReset.
This is the same thing that happens when resetting while holding down Bootsel.
I think the bootloader on my B1 chip is not able to handle the RP2040-E5.

my feather-rp2040:

UF2 Bootloader v2.0
Model: Raspberry Pi RP2
Board-ID: RPI-RP2

kenbell · 2022-07-22T16:32:05Z

This is a dmesg from my system...

[45572.317953] usb 1-1.1: new full-speed USB device number 100 using xhci_hcd
[45572.423816] usb 1-1.1: New USB device found, idVendor=2e8a, idProduct=1023, bcdDevice= 1.00
[45572.423820] usb 1-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[45572.423822] usb 1-1.1: Product: Challenger 2040 LoRa
[45572.423823] usb 1-1.1: Manufacturer: iLabs
[45572.431808] cdc_acm 1-1.1:1.0: ttyACM0: USB ACM device
[45592.425940] usb 1-1.1: USB disconnect, device number 100
[45592.677650] usb 1-1.1: new full-speed USB device number 101 using xhci_hcd
[45592.778795] usb 1-1.1: New USB device found, idVendor=2e8a, idProduct=0003, bcdDevice= 1.00
[45592.778799] usb 1-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[45592.778801] usb 1-1.1: Product: RP2 Boot
[45592.778802] usb 1-1.1: Manufacturer: Raspberry Pi
[45592.778803] usb 1-1.1: SerialNumber: E0C9125B0D9B
[45592.788593] usb-storage 1-1.1:1.0: USB Mass Storage device detected
[45592.788695] scsi host0: usb-storage 1-1.1:1.0
[45593.801949] scsi 0:0:0:0: Direct-Access     RPI      RP2              3    PQ: 0 ANSI: 2
[45593.802140] sd 0:0:0:0: Attached scsi generic sg0 type 0
[45593.802482] sd 0:0:0:0: [sda] 262144 512-byte logical blocks: (134 MB/128 MiB)
[45593.803082] sd 0:0:0:0: [sda] Write Protect is off
[45593.803084] sd 0:0:0:0: [sda] Mode Sense: 03 00 00 00
[45593.803522] sd 0:0:0:0: [sda] No Caching mode page found
[45593.803525] sd 0:0:0:0: [sda] Assuming drive cache: write through
[45593.810076]  sda: sda1
[45593.812077] sd 0:0:0:0: [sda] Attached SCSI removable disk
[45597.005730] usb 1-1.1: reset full-speed USB device number 101 using xhci_hcd
[45597.105653] usb 1-1.1: device firmware changed
[45597.105735] sd 0:0:0:0: [sda] Unaligned partial completion (resid=67264, sector_sz=512)
[45597.105738] sd 0:0:0:0: [sda] tag#0 CDB: Read(10) 28 00 00 03 fb 01 00 00 f0 00
[45597.105742] sd 0:0:0:0: [sda] tag#0 FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK cmd_age=0s
[45597.105743] sd 0:0:0:0: [sda] tag#0 CDB: Read(10) 28 00 00 03 fb 01 00 00 f0 00
[45597.105744] blk_update_request: I/O error, dev sda, sector 260865 op 0x0:(READ) flags 0x84700 phys_seg 30 prio class 0
[45597.105774] sd 0:0:0:0: [sda] tag#0 FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK cmd_age=0s
[45597.105777] sd 0:0:0:0: [sda] tag#0 CDB: Read(10) 28 00 00 03 fb f1 00 00 10 00
[45597.105778] blk_update_request: I/O error, dev sda, sector 261105 op 0x0:(READ) flags 0x80700 phys_seg 2 prio class 0
[45597.106485] usb 1-1.1: USB disconnect, device number 101
[45597.113519] blk_update_request: I/O error, dev sda, sector 260865 op 0x0:(READ) flags 0x0 phys_seg 8 prio class 0
[45597.113525] Buffer I/O error on dev sda1, logical block 260864, async page read
[45597.113528] Buffer I/O error on dev sda1, logical block 260865, async page read
[45597.113530] Buffer I/O error on dev sda1, logical block 260866, async page read
[45597.113531] Buffer I/O error on dev sda1, logical block 260867, async page read
[45597.113532] Buffer I/O error on dev sda1, logical block 260868, async page read
[45597.113533] Buffer I/O error on dev sda1, logical block 260869, async page read
[45597.113535] Buffer I/O error on dev sda1, logical block 260870, async page read
[45597.113536] Buffer I/O error on dev sda1, logical block 260871, async page read
[45597.113576] Buffer I/O error on dev sda1, logical block 4096, async page read
[45597.113580] Buffer I/O error on dev sda1, logical block 4097, async page read
[45597.121642] FAT-fs (sda1): unable to read boot sector to mark fs as dirty
[45597.265571] usb 1-1.1: new full-speed USB device number 102 using xhci_hcd
[45597.349567] usb 1-1.1: device descriptor read/64, error -32
[45597.537562] usb 1-1.1: device descriptor read/64, error -32
[45597.733527] usb 1-1.1: new full-speed USB device number 103 using xhci_hcd
[45597.813513] usb 1-1.1: device descriptor read/64, error -32
[45598.001590] usb 1-1.1: device descriptor read/64, error -32
[45598.109603] usb 1-1-port1: attempt power cycle
[45598.713489] usb 1-1.1: new full-speed USB device number 104 using xhci_hcd
[45598.713569] usb 1-1.1: Device not responding to setup address.
[45598.921570] usb 1-1.1: Device not responding to setup address.
[45599.129503] usb 1-1.1: device not accepting address 104, error -71
[45599.213484] usb 1-1.1: new full-speed USB device number 105 using xhci_hcd
[45599.213545] usb 1-1.1: Device not responding to setup address.
[45599.425550] usb 1-1.1: Device not responding to setup address.
[45599.633494] usb 1-1.1: device not accepting address 105, error -71
[45599.633584] usb 1-1-port1: unable to enumerate USB device

That sequence is:

hardware reset
tinygo flash (succeeds)
flash-initiated reset (USB fails)

sago35 · 2022-07-22T16:38:52Z

The INFO.txt for my pico is as follows
Please check the Version. @kenbell

UF2 Bootloader v1.0
Model: Raspberry Pi RP2
Board-ID: RPI-RP2

kenbell · 2022-07-22T18:02:07Z

The Challenger RP2040 (the dmesg above is from this board):

UF2 Bootloader v3.0
Model: Raspberry Pi RP2
Board-ID: RPI-RP2

kenbell · 2022-07-22T18:21:36Z

I've put some simple println debug lines in the interrupt handler that are being pushed to (tinygo flash -target challenger-rp2040 -serial uart ./src/examples/serial/).

Here's one observation (not sure if useful). When I use the 'serial' example the trace output from a hard reset (button) is:

bus reset
standard setup
bus reset
standard setup
standard setup
standard setup
standard setup
standard setup
standard setup
standard setup
standard setup
standard setup
standard setup
standard setup
standard setup
standard setup
standard setup
standard setup
standard setup
standard setup
class if requests
hello world!
hello world!
hello world!
hello world!
hello world!
hello world!

I.e. the main app isn't sending any output until USB is initialized.

After flashing with TinyGo, the bus reset output is much slower and some app output is interspersed.

bus reset
standard setup
bus reset
standard setup
standard setup
bus reset
bus reset
bus reset
bus reset
bus reset
hello world!
bus reset
bus reset
bus reset
hello world!
bus reset
hello world!
hello world!
hello world!
hello world!
hello world!
hello world!
hello world!
hello world!
hello world!
hello world!
hello world!
hello world!
hello world!
hello world!
hello world!
hello world!

I'll keep digging to see if any other differences pop up

kenbell · 2022-07-22T19:37:55Z

I've confirmed by looking at the chip - the RP2040 I have on the board is a B2, so should already have the hardware fix. At least as far as my case goes, I don't think it's related to the Errata as such - it's something more subtle... Maybe something not being fully reset after flashing or a clock / timing subtlety.

kenbell · 2022-07-22T21:52:35Z

I've found a hacky solution - by forcing a delay into USBDevice.Configure flashing is working reliably. I've also added a USB device block reset, per the examples. The delay appears to be the thing that matters. Now, why this works, I've no idea...

// Configure the USB peripheral. The config is here for compatibility with the UART interface.
func (dev *USBDevice) Configure(config UARTConfig) {
	rp.RESETS.SetRESET_USBCTRL(1)
	rp.RESETS.SetRESET_USBCTRL(0)
	for rp.RESETS.GetRESET_DONE_USBCTRL() == 0 {
		println("w")
	}

	//// Clear any previous state in dpram just in case
	usbDPSRAM.clear()

	hardSleep(1000000)

	//// Enable USB interrupt at processor
	rp.USBCTRL_REGS.INTE.Set(0)
	intr := interrupt.New(rp.IRQ_USBCTRL_IRQ, handleUSBIRQ)
	intr.SetPriority(0x00)
	intr.Enable()
	irqSet(rp.IRQ_USBCTRL_IRQ, true)

The definition of hardSleep is:

func hardSleep(ticks uint64) {
	end := timer.timeElapsed() + ticks
	for timer.timeElapsed() < end {
	}
}

sago35 · 2022-07-22T23:33:43Z

RESET_USBCTRL

https://github.com/raspberrypi/pico-examples/blob/a7ad17156bf60842ee55c8f86cd39e9cd7427c1d/usb/device/dev_lowlevel/dev_lowlevel.c#L184-L186

I mistakenly thought that resetBlock was running.
In machineInit(), USBCTRL is not resetting.

https://github.com/tinygo-org/tinygo/blob/dev/src/machine/machine_rp2040.go#L58-L64

It needs to be added.
Perhaps the following would be a good code.

	resetBlock(rp.RESETS_RESET_USBCTRL)
	unresetBlockWait(rp.RESETS_RESET_USBCTRL)

hardSleep(1000000)

So you don't know why, but it improves.
There appears to be no change in my environment.
Block for 1 second with hardSleep(1000000).
It seems a little too long, but if you shorten it, it won't be stable, right? @kenbell

kenbell · 2022-07-23T11:36:22Z

I can get down to 700ms delay and it works, at 600ms it doesn't work. I've abused a USB cable to hook up my logic analyzer. I'm going to see if that can shed any light on what's happening between the hub and the board.

kenbell · 2022-07-23T17:17:28Z

I think I may be hitting some kind of 'design choice' (bug?) in my USB hub. The only factor that seems to make a difference between success and failure is how long the USB DP pin is 'floating' (pulled down by Hub, indicating no device connected) and 'high' (pulled up by device, indicating high-speed device present). This is in effect what my delay loop is causing - extending the period the USB DP pin is floating.

This is a table of me trying various values for the delay in USB initialization, triggered by different scenarios. 'Soft Reset' is when the boot ROM triggers the reset after flashing the UF2.

Case	DP Low Duration (device disconnected)	DP High Duration (full-speed device presence indicated)	Outcome
Hard Reset, 0ms Delay	227.6ms	255.9ms	PASS
Hard Reset, 600ms Delay	954.9ms	310.9ms	PASS
Soft Reset, 700ms Delay	735.1ms	173.9ms	PASS
Soft Reset, 600ms Delay	635.1ms	50.9ms	FAIL
Soft Reset, 0ms Delay	35.1ms	9.25ms	FAIL
Cold Plug, 0ms Delay	inf	287ms	PASS

Bizarrely, the longer the DP line is floating, the longer it takes for the hub/host to issue a USB reset and query the device descriptor. I'm not sure why that is.

I don't think there's any specification for how long the DP line should be left floating (or even, to be honest if this is the real root cause), or that it's even necessary. However, we don't have the option of leaving the DP line high because the boot rom lets it float...

The boot rom appears to trigger a watchdog reboot that resets the USB controller (causing the DP line to float in the first place):
https://github.com/raspberrypi/pico-bootrom/blob/master/bootrom/virtual_disk.c#L161
https://github.com/raspberrypi/pico-bootrom/blob/master/bootrom/usb_boot_device.c#L499
https://github.com/raspberrypi/pico-bootrom/blob/master/usb_device_tiny/runtime.c#L70

kenbell · 2022-07-23T21:39:58Z

Another observation. When the USB handshake fails, there's a lot more NAK packets - it seems like the RP2040 is much slower to reply to USB requests in the failing case. Why adding a delay would cause subsequent USB processing to be faster is not clear.

First image is a successful case (700ms delay before starting USB), second image is a failed case (600ms delay applied):

kenbell · 2022-07-24T15:38:57Z

(removed - was a red herring caused by debug logic)

kenbell · 2022-07-25T16:26:06Z

After much head-scratching, I think i finally found the issue :)

kenbell added the rp2040 RP2040 (Pi Pico, RP2040 Feather, etc) label Jul 22, 2022

sago35 mentioned this issue Jul 25, 2022

rp2040: add resetBlock for USBCTRL #3015

Merged

kenbell mentioned this issue Jul 25, 2022

RP2040 fix USB device reset #3016

Merged

deadprogram added the next-release Will be part of next release label Jul 26, 2022

sago35 mentioned this issue Jul 28, 2022

rp2040: fix errata RP2040-E5 issue #2991

Merged

deadprogram removed the next-release Will be part of next release label Aug 4, 2022

deadprogram closed this as completed Aug 4, 2022

Elara6331 mentioned this issue Sep 3, 2022

Unable to get output from Raspberry Pi Pico on 0.25.0 #3126

Closed

tuffrabit mentioned this issue Feb 19, 2024

rp2040: failed enumeration #4137

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

USB CDC not flashing RP2040 reliably #3012

USB CDC not flashing RP2040 reliably #3012

kenbell commented Jul 22, 2022

kenbell commented Jul 22, 2022

sago35 commented Jul 22, 2022

kenbell commented Jul 22, 2022

kenbell commented Jul 22, 2022

sago35 commented Jul 22, 2022

deadprogram commented Jul 22, 2022

sago35 commented Jul 22, 2022 •

edited

Loading

kenbell commented Jul 22, 2022

sago35 commented Jul 22, 2022

kenbell commented Jul 22, 2022

kenbell commented Jul 22, 2022

kenbell commented Jul 22, 2022

kenbell commented Jul 22, 2022

sago35 commented Jul 22, 2022

kenbell commented Jul 23, 2022

kenbell commented Jul 23, 2022

kenbell commented Jul 23, 2022

kenbell commented Jul 24, 2022 •

edited

Loading

kenbell commented Jul 25, 2022

USB CDC not flashing RP2040 reliably #3012

USB CDC not flashing RP2040 reliably #3012

Comments

kenbell commented Jul 22, 2022

kenbell commented Jul 22, 2022

sago35 commented Jul 22, 2022

kenbell commented Jul 22, 2022

kenbell commented Jul 22, 2022

sago35 commented Jul 22, 2022

deadprogram commented Jul 22, 2022

sago35 commented Jul 22, 2022 • edited Loading

kenbell commented Jul 22, 2022

sago35 commented Jul 22, 2022

kenbell commented Jul 22, 2022

kenbell commented Jul 22, 2022

kenbell commented Jul 22, 2022

kenbell commented Jul 22, 2022

sago35 commented Jul 22, 2022

kenbell commented Jul 23, 2022

kenbell commented Jul 23, 2022

kenbell commented Jul 23, 2022

kenbell commented Jul 24, 2022 • edited Loading

kenbell commented Jul 25, 2022

sago35 commented Jul 22, 2022 •

edited

Loading

kenbell commented Jul 24, 2022 •

edited

Loading