Broken since recent commit #357
Description
Describe the bug
We use this tool to flash our embedded CM3+ modules located on a custom carrier board as part of our CI-pipeline hardware-in-the-loop testbench.
While updating all software of our test benches to some current versions, we also updated rpiboot. Checking the commit history and a few commits, I've narrowed breakage down to commit 6866561 "bootcode: Use USB2 HS mode for loading start.elf / ramdisk".
As the bringup process is a little involved (switching power paths from the host system to get the carrier into "flashing mode"), I can with low effort provide a journal log, which does contain the output of rpiboot:
Dec 23 15:47:37 fortunit test-bench-rpcd[1131]: RPIBOOT: build-date 2025/12/23 pkg-version local 68665619
Dec 23 15:47:37 fortunit test-bench-rpcd[1131]: Please fit the EMMC_DISABLE / nRPIBOOT jumper before connecting the power and USB cables to the target device.
Dec 23 15:47:37 fortunit test-bench-rpcd[1131]: If the device fails to connect then please see https://rpltd.co/rpiboot for debugging tips.
Dec 23 15:47:37 fortunit test-bench-rpcd[1131]: Waiting for BCM2835/6/7/2711/2712...
Dec 23 15:47:43 fortunit kernel: usb 1-1.2: new high-speed USB device number 16 using dwc_otg
Dec 23 15:47:43 fortunit kernel: usb 1-1.2: config index 0 descriptor too short (expected 55, got 32)
Dec 23 15:47:43 fortunit kernel: usb 1-1.2: New USB device found, idVendor=0a5c, idProduct=2764, bcdDevice= 0.00
Dec 23 15:47:43 fortunit kernel: usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Dec 23 15:47:43 fortunit kernel: usb 1-1.2: Product: BCM2710 Boot
Dec 23 15:47:43 fortunit kernel: usb 1-1.2: Manufacturer: Broadcom
Dec 23 15:47:43 fortunit mtp-probe[1134]: checking bus 1, device 16: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2"
Dec 23 15:47:44 fortunit mtp-probe[1134]: bus: 1, device: 16 was not an MTP device
Dec 23 15:47:44 fortunit test-bench-rpcd[1131]: Loading embedded: bootcode.bin
Dec 23 15:47:44 fortunit mtp-probe[1135]: checking bus 1, device 16: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2"
Dec 23 15:47:44 fortunit mtp-probe[1135]: bus: 1, device: 16 was not an MTP device
Dec 23 15:47:45 fortunit test-bench-rpcd[1131]: Sending bootcode.bin
Dec 23 15:47:46 fortunit test-bench-rpcd[1131]: Successful read 4 bytes
Dec 23 15:47:46 fortunit kernel: usb 1-1.2: USB disconnect, device number 16
Dec 23 15:47:47 fortunit test-bench-rpcd[1131]: Waiting for BCM2835/6/7/2711/2712...
Dec 23 15:47:47 fortunit kernel: usb 1-1.2: new high-speed USB device number 17 using dwc_otg
Dec 23 15:47:47 fortunit kernel: usb 1-1.2: config 1 interface 0 altsetting 0 bulk endpoint 0x1 has invalid maxpacket 64
Dec 23 15:47:47 fortunit kernel: usb 1-1.2: config 1 interface 0 altsetting 0 bulk endpoint 0x2 has invalid maxpacket 64
Dec 23 15:47:47 fortunit kernel: usb 1-1.2: New USB device found, idVendor=0a5c, idProduct=2764, bcdDevice= 0.00
Dec 23 15:47:47 fortunit kernel: usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=1
Dec 23 15:47:47 fortunit kernel: usb 1-1.2: Product: BCM2710 Boot
Dec 23 15:47:47 fortunit kernel: usb 1-1.2: Manufacturer: Broadcom
Dec 23 15:47:47 fortunit kernel: usb 1-1.2: SerialNumber: Broadcom
Dec 23 15:47:47 fortunit mtp-probe[1136]: checking bus 1, device 17: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2"
Dec 23 15:47:47 fortunit mtp-probe[1136]: bus: 1, device: 17 was not an MTP device
Dec 23 15:47:47 fortunit test-bench-rpcd[1131]: Loading embedded: bootcode.bin
Dec 23 15:47:47 fortunit mtp-probe[1137]: checking bus 1, device 17: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2"
Dec 23 15:47:47 fortunit mtp-probe[1137]: bus: 1, device: 17 was not an MTP device
Dec 23 15:47:48 fortunit test-bench-rpcd[1131]: Second stage boot server
Dec 23 15:47:48 fortunit test-bench-rpcd[1131]: Cannot open file autoboot.txt
Dec 23 15:47:48 fortunit test-bench-rpcd[1131]: Cannot open file config.txt
Dec 23 15:47:48 fortunit test-bench-rpcd[1131]: Cannot open file recovery.elf
Dec 23 15:47:48 fortunit test-bench-rpcd[1131]: Loading embedded: start.elf
Dec 23 15:47:48 fortunit test-bench-rpcd[1131]: File read: start.elf
Dec 23 15:47:53 fortunit test-bench-rpcd[1131]: Failed to write complete file to USB device
Notes for reading:
- fortunit is the hostname of the test-bench
- test-bench-rpcd is the daemon that calls rpiboot upon receiving XML-RPC requests
To compare, this is what a good sequence looks like:
Dec 23 15:48:43 fortunit test-bench-rpcd[1185]: RPIBOOT: build-date 2025/12/23 pkg-version local d8a1f4c4
Dec 23 15:48:43 fortunit test-bench-rpcd[1185]: Please fit the EMMC_DISABLE / nRPIBOOT jumper before connecting the power and USB cables to the target device.
Dec 23 15:48:43 fortunit test-bench-rpcd[1185]: If the device fails to connect then please see https://rpltd.co/rpiboot for debugging tips.
Dec 23 15:48:43 fortunit test-bench-rpcd[1185]: Waiting for BCM2835/6/7/2711/2712...
Dec 23 15:48:49 fortunit kernel: usb 1-1.2: new high-speed USB device number 18 using dwc_otg
Dec 23 15:48:50 fortunit kernel: usb 1-1.2: config index 0 descriptor too short (expected 55, got 32)
Dec 23 15:48:50 fortunit kernel: usb 1-1.2: New USB device found, idVendor=0a5c, idProduct=2764, bcdDevice= 0.00
Dec 23 15:48:50 fortunit kernel: usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Dec 23 15:48:50 fortunit kernel: usb 1-1.2: Product: BCM2710 Boot
Dec 23 15:48:50 fortunit kernel: usb 1-1.2: Manufacturer: Broadcom
Dec 23 15:48:50 fortunit mtp-probe[1189]: checking bus 1, device 18: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2"
Dec 23 15:48:50 fortunit mtp-probe[1189]: bus: 1, device: 18 was not an MTP device
Dec 23 15:48:50 fortunit test-bench-rpcd[1185]: Loading embedded: bootcode.bin
Dec 23 15:48:50 fortunit mtp-probe[1190]: checking bus 1, device 18: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2"
Dec 23 15:48:50 fortunit mtp-probe[1190]: bus: 1, device: 18 was not an MTP device
Dec 23 15:48:51 fortunit test-bench-rpcd[1185]: Sending bootcode.bin
Dec 23 15:48:52 fortunit test-bench-rpcd[1185]: Successful read 4 bytes
Dec 23 15:48:53 fortunit test-bench-rpcd[1185]: Waiting for BCM2835/6/7/2711/2712...
Dec 23 15:48:53 fortunit test-bench-rpcd[1185]: Loading embedded: bootcode.bin
Dec 23 15:48:53 fortunit kernel: usb 1-1.2: USB disconnect, device number 18
Dec 23 15:48:53 fortunit kernel: usb 1-1.2: new full-speed USB device number 19 using dwc_otg
Dec 23 15:48:53 fortunit kernel: usb 1-1.2: not running at top speed; connect to a high speed hub
Dec 23 15:48:53 fortunit kernel: usb 1-1.2: New USB device found, idVendor=0a5c, idProduct=2764, bcdDevice= 0.00
Dec 23 15:48:53 fortunit kernel: usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=1
Dec 23 15:48:53 fortunit kernel: usb 1-1.2: Product: BCM2710 Boot
Dec 23 15:48:53 fortunit kernel: usb 1-1.2: Manufacturer: Broadcom
Dec 23 15:48:53 fortunit kernel: usb 1-1.2: SerialNumber: Broadcom
Dec 23 15:48:53 fortunit mtp-probe[1192]: checking bus 1, device 19: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2"
Dec 23 15:48:53 fortunit mtp-probe[1192]: bus: 1, device: 19 was not an MTP device
Dec 23 15:48:53 fortunit mtp-probe[1193]: checking bus 1, device 19: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2"
Dec 23 15:48:53 fortunit mtp-probe[1193]: bus: 1, device: 19 was not an MTP device
Dec 23 15:48:54 fortunit test-bench-rpcd[1185]: Loading embedded: bootcode.bin
Dec 23 15:48:55 fortunit test-bench-rpcd[1185]: Second stage boot server
Dec 23 15:48:55 fortunit test-bench-rpcd[1185]: Cannot open file autoboot.txt
Dec 23 15:48:55 fortunit test-bench-rpcd[1185]: Cannot open file config.txt
Dec 23 15:48:55 fortunit test-bench-rpcd[1185]: Cannot open file recovery.elf
Dec 23 15:48:55 fortunit test-bench-rpcd[1185]: Loading embedded: start.elf
Dec 23 15:48:55 fortunit test-bench-rpcd[1185]: File read: start.elf
Dec 23 15:48:56 fortunit test-bench-rpcd[1185]: Cannot open file fixup.dat
Dec 23 15:48:56 fortunit kernel: usb 1-1.2: USB disconnect, device number 19
Dec 23 15:48:57 fortunit test-bench-rpcd[1185]: Second stage boot server done
Dec 23 15:48:57 fortunit kernel: usb 1-1.2: new high-speed USB device number 20 using dwc_otg
Dec 23 15:48:57 fortunit kernel: usb 1-1.2: New USB device found, idVendor=0a5c, idProduct=0001, bcdDevice= 0.01
Dec 23 15:48:57 fortunit kernel: usb 1-1.2: New USB device strings: Mfr=2, Product=1, SerialNumber=3
Dec 23 15:48:57 fortunit kernel: usb 1-1.2: Product: Compute Module
Dec 23 15:48:57 fortunit kernel: usb 1-1.2: Manufacturer: Raspberry Pi
Dec 23 15:48:57 fortunit kernel: usb 1-1.2: SerialNumber: 4d80defc
Dec 23 15:48:57 fortunit kernel: usb-storage 1-1.2:1.0: USB Mass Storage device detected
Dec 23 15:48:57 fortunit kernel: scsi host0: usb-storage 1-1.2:1.0
Dec 23 15:48:57 fortunit mtp-probe[1198]: checking bus 1, device 20: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2"
Dec 23 15:48:57 fortunit mtp-probe[1198]: bus: 1, device: 20 was not an MTP device
Dec 23 15:48:57 fortunit mtp-probe[1199]: checking bus 1, device 20: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2"
Dec 23 15:48:57 fortunit mtp-probe[1199]: bus: 1, device: 20 was not an MTP device
Dec 23 15:48:58 fortunit test-bench-rpcd[1177]: result: Ok(ExitStatus(unix_wait_status(0)))
Dec 23 15:48:58 fortunit test-bench-rpcd[1177]: [src/main.rs:229:21] e = Os {
Dec 23 15:48:58 fortunit test-bench-rpcd[1177]: code: 2,
Dec 23 15:48:58 fortunit test-bench-rpcd[1177]: kind: NotFound,
Dec 23 15:48:58 fortunit test-bench-rpcd[1177]: message: "No such file or directory",
Dec 23 15:48:58 fortunit test-bench-rpcd[1177]: }
Dec 23 15:48:58 fortunit test-bench-rpcd[1177]: trying once more ...
Dec 23 15:48:58 fortunit kernel: scsi 0:0:0:0: Direct-Access RPi-MSD- 0001 PQ: 0 ANSI: 2
Dec 23 15:48:58 fortunit kernel: sd 0:0:0:0: Attached scsi generic sg0 type 0
Dec 23 15:48:58 fortunit kernel: sd 0:0:0:0: [sda] 15269888 512-byte logical blocks: (7.82 GB/7.28 GiB)
Dec 23 15:48:58 fortunit kernel: sd 0:0:0:0: [sda] Write Protect is off
Dec 23 15:48:58 fortunit kernel: sd 0:0:0:0: [sda] Mode Sense: 0f 00 00 00
Dec 23 15:48:58 fortunit kernel: sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Dec 23 15:48:58 fortunit kernel: sda: sda1 sda2
Dec 23 15:48:58 fortunit kernel: sd 0:0:0:0: [sda] Attached SCSI removable disk
Dec 23 15:48:59 fortunit test-bench-rpcd[1177]: new socket
Dec 23 15:48:59 fortunit test-bench-rpcd[1177]: listening
Dec 23 15:48:59 fortunit test-bench-rpcd[1177]: accepting
Dec 23 15:48:59 fortunit test-bench-rpcd[1177]: accepted
Dec 23 15:48:59 fortunit test-bench-rpcd[1177]: [src/main.rs:263:13] &stream = PollEvented {
Dec 23 15:48:59 fortunit test-bench-rpcd[1177]: io: Some(
Dec 23 15:48:59 fortunit test-bench-rpcd[1177]: TcpStream {
Dec 23 15:48:59 fortunit test-bench-rpcd[1177]: addr: redacted
Dec 23 15:48:59 fortunit test-bench-rpcd[1177]: },
Dec 23 15:48:59 fortunit test-bench-rpcd[1177]: ),
Dec 23 15:48:59 fortunit test-bench-rpcd[1177]: }
Dec 23 15:48:59 fortunit test-bench-rpcd[1177]: [src/main.rs:263:13] addr = redacted
Dec 23 15:49:00 fortunit test-bench-rpcd[1177]: receiving; 11.849 MB, 11.849 MB total (11.849 MB/s since 1 s)
Dec 23 15:49:01 fortunit test-bench-rpcd[1177]: receiving; 11.693 MB, 23.542 MB total (11.771 MB/s since 2 s)
Dec 23 15:49:02 fortunit test-bench-rpcd[1177]: receiving; 11.755 MB, 35.297 MB total (11.766 MB/s since 3 s)
Dec 23 15:49:03 fortunit test-bench-rpcd[1177]: receiving; 11.781 MB, 47.078 MB total (11.769 MB/s since 4 s)
...and on and on...
What other information can I provide to help debug this issue?
Steps to reproduce the behaviour
Requires our internal hardware.
Device(s)
Raspberry Pi CM3+
Compute Module IO board.
No response
RPIBOOT logs
No response
Kernel logs
No response
Device UART logs
No response