Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Stuck in loop - Failed control transfer (-7,24) #87

Open
ddibiasi opened this issue Aug 4, 2021 · 33 comments
Open

Stuck in loop - Failed control transfer (-7,24) #87

ddibiasi opened this issue Aug 4, 2021 · 33 comments

Comments

@ddibiasi
Copy link

ddibiasi commented Aug 4, 2021

Hello,

I'm trying to flash the CM4 on the official IO board.

The jumper has been set to 'Fit jumper to disable eMMC Boot' and I am using the latest usbboot.

If i try to run sudo ./rpiboot it gets stuck in this loop:

Waiting for BCM2835/6/7/2711...
Loading embedded: bootcode4.bin
Sending bootcode.bin
Successful read 4 bytes
Waiting for BCM2835/6/7/2711...
Loading embedded: bootcode4.bin
Sending bootcode.bin
Failed control transfer (-7,24)
Failed to write correct length, returned -7
Waiting for BCM2835/6/7/2711...
Loading embedded: bootcode4.bin
Sending bootcode.bin
Failed control transfer (-7,24)
Failed to write correct length, returned -7
Waiting for BCM2835/6/7/2711...
Loading embedded: bootcode4.bin
Sending bootcode.bin
Failed control transfer (-7,24)
Failed to write correct length, returned -7

This issue is probably related to #82.

Output of sudo ./rpiboot -vv

Waiting for BCM2835/6/7/2711...
Found device 1 idVendor=0x1d6b idProduct=0x0003
Bus: 8, Device: 1 Path: 8
Found device 2 idVendor=0x045e idProduct=0x0719
Bus: 7, Device: 5 Path: 7-4
Found device 3 idVendor=0x03f0 idProduct=0x094a
Bus: 7, Device: 4 Path: 7-3
Found device 4 idVendor=0x17f6 idProduct=0x0862
Bus: 7, Device: 3 Path: 7-2
Found device 5 idVendor=0x05ac idProduct=0x1301
Bus: 7, Device: 2 Path: 7-1
Found device 6 idVendor=0x1d6b idProduct=0x0002
Bus: 7, Device: 1 Path: 7
Found device 7 idVendor=0x1d6b idProduct=0x0003
Bus: 6, Device: 1 Path: 6
Found device 8 idVendor=0x1d6b idProduct=0x0002
Bus: 5, Device: 1 Path: 5
Found device 9 idVendor=0x1d6b idProduct=0x0003
Bus: 4, Device: 1 Path: 4
Found device 10 idVendor=0x1d6b idProduct=0x0002
Bus: 3, Device: 1 Path: 3
Found device 11 idVendor=0x1d6b idProduct=0x0003
Bus: 2, Device: 1 Path: 2
Found device 12 idVendor=0x0a5c idProduct=0x2711
Bus: 1, Device: 8 Path: 1-6
Found candidate Compute Module...Loading embedded: bootcode4.bin
Device located successfully
Initialised device correctly
Found serial number 3
Sending bootcode.bin
libusb_bulk_transfer sent 24 bytes; returned 0
Writing 121944 bytes
libusb_bulk_transfer sent 121944 bytes; returned 0
Successful read 4 bytes
Waiting for BCM2835/6/7/2711...
Found device 1 idVendor=0x1d6b idProduct=0x0003
Bus: 8, Device: 1 Path: 8
Found device 2 idVendor=0x045e idProduct=0x0719
Bus: 7, Device: 5 Path: 7-4
Found device 3 idVendor=0x03f0 idProduct=0x094a
Bus: 7, Device: 4 Path: 7-3
Found device 4 idVendor=0x17f6 idProduct=0x0862
Bus: 7, Device: 3 Path: 7-2
Found device 5 idVendor=0x05ac idProduct=0x1301
Bus: 7, Device: 2 Path: 7-1
Found device 6 idVendor=0x1d6b idProduct=0x0002
Bus: 7, Device: 1 Path: 7
Found device 7 idVendor=0x1d6b idProduct=0x0003
Bus: 6, Device: 1 Path: 6
Found device 8 idVendor=0x1d6b idProduct=0x0002
Bus: 5, Device: 1 Path: 5
Found device 9 idVendor=0x1d6b idProduct=0x0003
Bus: 4, Device: 1 Path: 4
Found device 10 idVendor=0x1d6b idProduct=0x0002
Bus: 3, Device: 1 Path: 3
Found device 11 idVendor=0x1d6b idProduct=0x0003
Bus: 2, Device: 1 Path: 2
Found device 12 idVendor=0x0a5c idProduct=0x2711
Bus: 1, Device: 8 Path: 1-6
Found candidate Compute Module...Loading embedded: bootcode4.bin
Device located successfully
Initialised device correctly
Found serial number 3
Sending bootcode.bin
Failed control transfer (-7,24)
Failed to write correct length, returned -7
Waiting for BCM2835/6/7/2711...
Found device 1 idVendor=0x1d6b idProduct=0x0003
Bus: 8, Device: 1 Path: 8
Found device 2 idVendor=0x045e idProduct=0x0719
Bus: 7, Device: 5 Path: 7-4
Found device 3 idVendor=0x03f0 idProduct=0x094a
Bus: 7, Device: 4 Path: 7-3
Found device 4 idVendor=0x17f6 idProduct=0x0862
Bus: 7, Device: 3 Path: 7-2
Found device 5 idVendor=0x05ac idProduct=0x1301
Bus: 7, Device: 2 Path: 7-1
Found device 6 idVendor=0x1d6b idProduct=0x0002
Bus: 7, Device: 1 Path: 7
Found device 7 idVendor=0x1d6b idProduct=0x0003
Bus: 6, Device: 1 Path: 6
Found device 8 idVendor=0x1d6b idProduct=0x0002
Bus: 5, Device: 1 Path: 5
Found device 9 idVendor=0x1d6b idProduct=0x0003
Bus: 4, Device: 1 Path: 4
Found device 10 idVendor=0x1d6b idProduct=0x0002
Bus: 3, Device: 1 Path: 3
Found device 11 idVendor=0x1d6b idProduct=0x0003
Bus: 2, Device: 1 Path: 2
Found device 12 idVendor=0x0a5c idProduct=0x2711
Bus: 1, Device: 8 Path: 1-6
Found candidate Compute Module...Loading embedded: bootcode4.bin
Device located successfully
Initialised device correctly
Found serial number 3
Sending bootcode.bin
Failed control transfer (-7,24)
Failed to write correct length, returned -7
@ddibiasi
Copy link
Author

ddibiasi commented Aug 5, 2021

I just tried flashing again with another CM4 & the same IO board and it works as it should.

The faulty CM4 has already an OS installed which boots if the jumper is removed, so I think this is some sort of software issue.

Do you have any solution for this problem?

@bhuvanchandra
Copy link

I'm trying the rpiboot for Rpi CM3 module. I see similar errors:

with sudo ./rpiboot
$ sudo ./rpiboot
Waiting for BCM2835/6/7/2711...
Loading embedded: bootcode.bin
Sending bootcode.bin
Failed to write correct length, returned 0
Waiting for BCM2835/6/7/2711...
Loading embedded: bootcode.bin
Sending bootcode.bin
Failed to write correct length, returned 0
Waiting for BCM2835/6/7/2711...
Loading embedded: bootcode.bin
Sending bootcode.bin
Failed to write correct length, returned 0
Waiting for BCM2835/6/7/2711...
Loading embedded: bootcode.bin
Sending bootcode.bin
Failed to write correct length, returned 0

and with sudo ./rpiboot -d msd
sudo ./rpiboot
Loading: msd/bootcode.bin
Loading: msd/bootcode4.bin
Waiting for BCM2835/6/7/2711...
Loading: msd/bootcode.bin
Sending bootcode.bin
Failed to read correct length, returned 0
Waiting for BCM2835/6/7/2711...
Loading: msd/bootcode.bin
Sending bootcode.bin
Failed to write correct length, returned 0
Waiting for BCM2835/6/7/2711...
Loading: msd/bootcode.bin
Sending bootcode.bin
Failed to write correct length, returned 0
Waiting for BCM2835/6/7/2711...
Loading: msd/bootcode.bin
Sending bootcode.bin
Failed to write correct length, returned 0
Waiting for BCM2835/6/7/2711...
Loading: msd/bootcode.bin
Sending bootcode.bin
Failed to write correct length, returned 0
Waiting for BCM2835/6/7/2711...
Loading: msd/bootcode.bin
Sending bootcode.bin
Failed to write correct length, returned 0
Waiting for BCM2835/6/7/2711...
Loading: msd/bootcode.bin
Sending bootcode.bin
Failed to write correct length, returned 0

@ddibiasi
Copy link
Author

Is there any progress on this issue, as this seems to affect multiple people and potentially bricks CM4s?

@Sagar73594
Copy link

Hey @ddibiasi, I have gone throw many issues like these(eg- EMMC/SD Card MSD Mouting), And I have seen 2 common solutions to all of that issues. Which are A good USB cable and A Decent Power supply. Both can solve these types of problems on many Raspberry pi hardware platforms.
And I want to add many solutions like these to the main documentation of raspberry pi.
So I just want to know, How I get started and How to do it?

@scott-williams-xentronics

I had this issue, but it was on a fresh Compute Module 4.
Tried it on another PC (which was also running an older version of rpiboot) and it worked fine.
So, in my case, it was either a (1) PC host specific issue, or (2) something wrong with a recent update of this Git repo.

@ddibiasi
Copy link
Author

This issue still exists despite having tried multiple different USB cables, as well as power supplies, as mentioned by @Sagar73594 .

I also have tried usbboot on multiple different PCs, using different operating systems (Linux, Windows) to no avail, as suggested by @scott-williams-xentronics .

As this was last tried in August, there could potentially have been a fix in the GitHub repo, so I'll need to retry usbboot with the said bricked device.

@dir-ableton
Copy link

I'm also running into this. I tried several cables, ports, hubs and no hubs in between, several CM4s and two different IO boards. The problem persists. Using a USB protocol analyzer I see nothing of significance (but I am not an expert on this at all).

However I just plugged the exact same IO board + CM4 + cable to a different computer - and there it works.

The notebook where it's not working is an DELL XPS and the XHCI controller is named

Tiger Lake-H USB 3.2 Gen 2x1 xHCI Host Controller

according to https://pci-ids.ucw.cz/read/PC/8086/43ed

The PC where it works lists the respective USB host controller as

01:00.0 USB controller: Advanced Micro Devices, Inc. [AMD] X399 Series Chipset USB 3.1 xHCI Controller (rev 02)

Probably not something anybody here could do anything about, but OTOH maybe a puzzle piece to understand the issue better.

@scott-williams-xentronics

Super interesting.
I am having the issue on a Dell XPS 17, brand new.
Must be some common issue with the USB Controller.

I wonder if there's any action we can take?

@dir-ableton
Copy link

dir-ableton commented Nov 24, 2021

I have some new information in the meantime. While it appeared to work (meaning the rpiboot was actually doing what it's supposed to do), mounting and working with the block device is fraught with errors. It produces fun error messages, see below.

Using a newer Dell XPS of a colleague with USB host controllers identifying as "something something Thunderbolt 4" (sorry, I just read the output of lsusb and recite from memory) actually did work for rpiboot, but again mounting would fail.

This whole thing is driving me nuts.

Edit The below error messages seem to be disappearing when using a better power-supply. I might have gotten sloppy there. However the exact same power supply was used for the original Dell XPS.

[  716.896000] usb 1-10: new high-speed USB device number 3 using xhci_hcd
[  717.059073] usb 1-10: config index 0 descriptor too short (expected 55, got 32)
[  717.074976] usb 1-10: New USB device found, idVendor=0a5c, idProduct=2711, bcdDevice= 0.00
[  717.074982] usb 1-10: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[  717.074985] usb 1-10: Product: BCM2711 Boot
[  717.074987] usb 1-10: Manufacturer: Broadcom
[  717.074989] usb 1-10: SerialNumber: 9c45210c
[  719.458137] usb 1-10: USB disconnect, device number 3
[  719.732014] usb 1-10: new high-speed USB device number 4 using xhci_hcd
[  719.911348] usb 1-10: New USB device found, idVendor=0a5c, idProduct=2711, bcdDevice= 0.00
[  719.911354] usb 1-10: New USB device strings: Mfr=1, Product=2, SerialNumber=4
[  719.911357] usb 1-10: Product: BCM2711 Boot
[  719.911359] usb 1-10: Manufacturer: Broadcom
[  719.911361] usb 1-10: SerialNumber: 9c45210c
[  721.511036] usb 1-10: USB disconnect, device number 4
[  723.204084] usb 1-10: new high-speed USB device number 5 using xhci_hcd
[  723.379801] usb 1-10: New USB device found, idVendor=0a5c, idProduct=0001, bcdDevice= 0.01
[  723.379807] usb 1-10: New USB device strings: Mfr=2, Product=1, SerialNumber=3
[  723.379810] usb 1-10: Product: Compute Module
[  723.379812] usb 1-10: Manufacturer: Raspberry Pi
[  723.379814] usb 1-10: SerialNumber: 9c45210c
[  723.407274] usb-storage 1-10:1.0: USB Mass Storage device detected
[  723.407523] scsi host10: usb-storage 1-10:1.0
[  723.407660] usbcore: registered new interface driver usb-storage
[  723.409912] usbcore: registered new interface driver uas
[  724.416325] scsi 10:0:0:0: Direct-Access     RPi-MSD- 0001                  PQ: 0 ANSI: 2
[  724.417080] scsi 10:0:0:0: Attached scsi generic sg0 type 0
[  724.417515] sd 10:0:0:0: [sda] 62333952 512-byte logical blocks: (31.9 GB/29.7 GiB)
[  724.417656] sd 10:0:0:0: [sda] Write Protect is off
[  724.417659] sd 10:0:0:0: [sda] Mode Sense: 0f 00 00 00
[  724.417803] sd 10:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[  724.450049]  sda: sda1 sda2 sda3 sda4
[  724.470161] sd 10:0:0:0: [sda] Attached SCSI removable disk
[  737.959173] FAT-fs (sda1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
[  740.596673] sd 10:0:0:0: [sda] tag#0 FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE cmd_age=0s
[  740.596690] sd 10:0:0:0: [sda] tag#0 Sense Key : Hardware Error [current] 
[  740.596694] sd 10:0:0:0: [sda] tag#0 Add. Sense: No additional sense information
[  740.596704] sd 10:0:0:0: [sda] tag#0 CDB: Write(10) 2a 00 00 01 42 08 00 00 18 00
[  740.596712] blk_update_request: I/O error, dev sda, sector 82440 op 0x1:(WRITE) flags 0x800 phys_seg 3 prio class 0
[  740.596721] Buffer I/O error on dev sda2, logical block 65, lost async page write
[  740.596728] Buffer I/O error on dev sda2, logical block 66, lost async page write
[  740.596732] Buffer I/O error on dev sda2, logical block 67, lost async page write
[  740.680490] sd 10:0:0:0: [sda] tag#0 FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE cmd_age=0s
[  740.680502] sd 10:0:0:0: [sda] tag#0 Sense Key : Hardware Error [current] 
[  740.680506] sd 10:0:0:0: [sda] tag#0 Add. Sense: No additional sense information
[  740.680510] sd 10:0:0:0: [sda] tag#0 CDB: Write(10) 2a 00 00 01 42 28 00 00 10 00
[  740.680513] blk_update_request: I/O error, dev sda, sector 82472 op 0x1:(WRITE) flags 0x800 phys_seg 2 prio class 0
[  740.680520] Buffer I/O error on dev sda2, logical block 69, lost async page write
[  740.680526] Buffer I/O error on dev sda2, logical block 70, lost async page write
[  740.760463] sd 10:0:0:0: [sda] tag#0 FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE cmd_age=0s
[  740.760477] sd 10:0:0:0: [sda] tag#0 Sense Key : Hardware Error [current] 
[  740.760481] sd 10:0:0:0: [sda] tag#0 Add. Sense: No additional sense information
[  740.760485] sd 10:0:0:0: [sda] tag#0 CDB: Write(10) 2a 00 00 01 42 78 00 00 08 00
[  740.760488] blk_update_request: I/O error, dev sda, sector 82552 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[  740.760495] Buffer I/O error on dev sda2, logical block 79, lost async page write
[  740.840534] sd 10:0:0:0: [sda] tag#0 FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE cmd_age=0s
[  740.840539] sd 10:0:0:0: [sda] tag#0 Sense Key : Hardware Error [current] 
[  740.840542] sd 10:0:0:0: [sda] tag#0 Add. Sense: No additional sense information
[  740.840545] sd 10:0:0:0: [sda] tag#0 CDB: Write(10) 2a 00 00 01 42 88 00 00 10 00
[  740.840546] blk_update_request: I/O error, dev sda, sector 82568 op 0x1:(WRITE) flags 0x800 phys_seg 2 prio class 0
[  740.840552] Buffer I/O error on dev sda2, logical block 81, lost async page write
[  740.840557] Buffer I/O error on dev sda2, logical block 82, lost async page write
[  740.920793] sd 10:0:0:0: [sda] tag#0 FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE cmd_age=0s
[  740.920799] sd 10:0:0:0: [sda] tag#0 Sense Key : Hardware Error [current] 
[  740.920802] sd 10:0:0:0: [sda] tag#0 Add. Sense: No additional sense information
[  740.920805] sd 10:0:0:0: [sda] tag#0 CDB: Write(10) 2a 00 00 01 42 a8 00 00 20 00
[  740.920807] blk_update_request: I/O error, dev sda, sector 82600 op 0x1:(WRITE) flags 0x800 phys_seg 4 prio class 0
[  740.920813] Buffer I/O error on dev sda2, logical block 85, lost async page write
[  740.920818] Buffer I/O error on dev sda2, logical block 86, lost async page write
[  741.000536] sd 10:0:0:0: [sda] tag#0 FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE cmd_age=0s
[  741.000541] sd 10:0:0:0: [sda] tag#0 Sense Key : Hardware Error [current] 
[  741.000544] sd 10:0:0:0: [sda] tag#0 Add. Sense: No additional sense information
[  741.000547] sd 10:0:0:0: [sda] tag#0 CDB: Write(10) 2a 00 00 01 42 f0 00 00 08 00
[  741.000549] blk_update_request: I/O error, dev sda, sector 82672 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[  741.080480] sd 10:0:0:0: [sda] tag#0 FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE cmd_age=0s
[  741.080486] sd 10:0:0:0: [sda] tag#0 Sense Key : Hardware Error [current] 
[  741.080488] sd 10:0:0:0: [sda] tag#0 Add. Sense: No additional sense information
[  741.080491] sd 10:0:0:0: [sda] tag#0 CDB: Write(10) 2a 00 00 01 43 00 00 00 08 00
[  741.080493] blk_update_request: I/O error, dev sda, sector 82688 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[  741.160526] sd 10:0:0:0: [sda] tag#0 FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE cmd_age=0s
[  741.160531] sd 10:0:0:0: [sda] tag#0 Sense Key : Hardware Error [current] 
[  741.160534] sd 10:0:0:0: [sda] tag#0 Add. Sense: No additional sense information
[  741.160537] sd 10:0:0:0: [sda] tag#0 CDB: Write(10) 2a 00 00 01 43 10 00 00 08 00
[  741.160538] blk_update_request: I/O error, dev sda, sector 82704 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[  741.241183] sd 10:0:0:0: [sda] tag#0 FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE cmd_age=0s
[  741.241189] sd 10:0:0:0: [sda] tag#0 Sense Key : Hardware Error [current] 
[  741.241192] sd 10:0:0:0: [sda] tag#0 Add. Sense: No additional sense information
[  741.241195] sd 10:0:0:0: [sda] tag#0 CDB: Write(10) 2a 00 00 01 43 c8 00 00 30 00
[  741.241197] blk_update_request: I/O error, dev sda, sector 82888 op 0x1:(WRITE) flags 0x800 phys_seg 6 prio class 0
[  741.320500] sd 10:0:0:0: [sda] tag#0 FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE cmd_age=0s
[  741.320506] sd 10:0:0:0: [sda] tag#0 Sense Key : Hardware Error [current] 
[  741.320509] sd 10:0:0:0: [sda] tag#0 Add. Sense: No additional sense information
[  741.320512] sd 10:0:0:0: [sda] tag#0 CDB: Write(10) 2a 00 00 01 44 58 00 00 08 00
[  741.320514] blk_update_request: I/O error, dev sda, sector 83032 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[  773.192850] usb 1-10: reset high-speed USB device number 5 using xhci_hcd
[  918.073113] traps: slack[3829] trap int3 ip:55761aad709b sp:7ffeb2bcbf70 error:0 in slack (deleted)[55761a6d6000+6878000]
[  967.612196] INFO: task kworker/u258:8:614 blocked for more than 120 seconds.
[  967.612205]       Not tainted 5.11.0-40-generic #44~20.04.2-Ubuntu
[  967.612208] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  967.612210] task:kworker/u258:8  state:D stack:    0 pid:  614 ppid:     2 flags:0x00004000
[  967.612216] Workqueue: writeback wb_workfn (flush-8:0)
[  967.612223] Call Trace:
[  967.612228]  __schedule+0x44c/0x8a0
[  967.612233]  ? wbt_cleanup_cb+0x20/0x20
[  967.612238]  schedule+0x4f/0xc0
[  967.612240]  io_schedule+0x16/0x40
[  967.612243]  rq_qos_wait+0xbd/0x150
[  967.612246]  ? sysv68_partition+0x280/0x280
[  967.612249]  ? wbt_cleanup_cb+0x20/0x20
[  967.612253]  wbt_wait+0x92/0xc0
[  967.612256]  __rq_qos_throttle+0x28/0x40
[  967.612259]  blk_mq_submit_bio+0xf7/0x580
[  967.612262]  ? ktime_get+0x3e/0xa0
[  967.612266]  submit_bio_noacct+0x423/0x4f0
[  967.612270]  submit_bio+0x51/0x1a0
[  967.612273]  ? bio_add_page+0x6a/0x90
[  967.612277]  submit_bh_wbc+0x195/0x1c0
[  967.612281]  __block_write_full_page+0x20e/0x470
[  967.612284]  ? end_buffer_write_sync+0x50/0x50
[  967.612287]  block_write_full_page+0x114/0x180
[  967.612290]  blkdev_writepage+0x18/0x20
[  967.612294]  __writepage+0x1b/0x70
[  967.612297]  write_cache_pages+0x190/0x430
[  967.612301]  ? wb_update_dirty_ratelimit+0x1a0/0x1a0
[  967.612305]  generic_writepages+0x57/0x90
[  967.612309]  blkdev_writepages+0xe/0x10
[  967.612312]  do_writepages+0x43/0xd0
[  967.612315]  ? fprop_reflect_period_percpu.isra.0+0x8b/0xc0
[  967.612319]  __writeback_single_inode+0x44/0x2b0
[  967.612322]  writeback_sb_inodes+0x22d/0x4c0
[  967.612326]  __writeback_inodes_wb+0x56/0xf0
[  967.612329]  wb_writeback+0x1ea/0x2a0
[  967.612332]  ? cpumask_next+0x1b/0x20
[  967.612336]  wb_workfn+0x354/0x490
[  967.612339]  process_one_work+0x220/0x3c0
[  967.612343]  worker_thread+0x4d/0x3f0
[  967.612345]  ? process_one_work+0x3c0/0x3c0
[  967.612348]  kthread+0x12b/0x150
[  967.612351]  ? set_kthread_struct+0x40/0x40
[  967.612354]  ret_from_fork+0x22/0x30
[  967.612539] INFO: task scsi_eh_10:9127 blocked for more than 120 seconds.
[  967.612542]       Not tainted 5.11.0-40-generic #44~20.04.2-Ubuntu
[  967.612544] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  967.612545] task:scsi_eh_10      state:D stack:    0 pid: 9127 ppid:     2 flags:0x00004000
[  967.612549] Call Trace:

@timg236
Copy link
Collaborator

timg236 commented Nov 24, 2021

The recommended setup for the usbboot host is

  • Raspberry Pi OS on a Raspberry Pi 4 (or 3)
  • Git clone the latest usbboot software and build from source
  • Use a direct USB cable connection and not a hub

libusb on Windows seems to be a bit flakey and doesn't always discover devices behind hubs. Since there's an infinite variety of device OS/USB configurations we only test with the above (we use that for manufacturing so it's well tested)

@dir-ableton
Copy link

Thank you for the clarification. And a good idea for a workaround if I can't get my Linux XHCI controllers to behave :)

@dir-ableton
Copy link

Ok I tried this - PI3, CM4 IO Board, latest Pi Os, cloned & buillt rpiboot on the system, and got essentially the same result I see everywhere else. See dmesg output below.

My interpretation here is that the writing is stuck somehow and the kernel worker queues responsible start complaining if the tasks they were given aren't finished.

I tested this for now just with one setup. However I did test several CM4 modules, SD-cards and cables with the same results, albeit with a PC host. I can conduct the same tests with the PI3, but am at this point a bit skeptical about it yielding different resutlts.

  83.667980] EXT4-fs (mmcblk0p2): resized filesystem to 7566848
[  996.281656] usb 1-1.4: USB disconnect, device number 4
[  996.284307] sd 0:0:0:0: [sda] Synchronizing SCSI cache
[  996.284654] sd 0:0:0:0: [sda] Synchronize Cache(10) failed: Result: hostbyte=0x01 driverbyte=0x00
[  999.135258] usb 1-1.4: new high-speed USB device number 5 using dwc_otg
[  999.265681] usb 1-1.4: config index 0 descriptor too short (expected 55, got 32)
[  999.266202] usb 1-1.4: New USB device found, idVendor=0a5c, idProduct=2711, bcdDevice= 0.00
[  999.266218] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[  999.266231] usb 1-1.4: Product: BCM2711 Boot
[  999.266243] usb 1-1.4: Manufacturer: Broadcom
[  999.266256] usb 1-1.4: SerialNumber: f06348ef
[  999.268494] pcm512x 1-004d: supply AVDD not found, using dummy regulator
[  999.268700] pcm512x 1-004d: supply DVDD not found, using dummy regulator
[  999.268776] pcm512x 1-004d: supply CPVDD not found, using dummy regulator
[ 1005.461342] pcm512x 1-004d: supply AVDD not found, using dummy regulator
[ 1005.461616] pcm512x 1-004d: supply DVDD not found, using dummy regulator
[ 1005.461713] pcm512x 1-004d: supply CPVDD not found, using dummy regulator
[ 1006.267678] usb 1-1.4: USB disconnect, device number 5
[ 1009.375251] usb 1-1.4: new high-speed USB device number 6 using dwc_otg
[ 1009.505701] usb 1-1.4: config index 0 descriptor too short (expected 55, got 32)
[ 1009.506208] usb 1-1.4: New USB device found, idVendor=0a5c, idProduct=2711, bcdDevice= 0.00
[ 1009.506225] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 1009.506238] usb 1-1.4: Product: BCM2711 Boot
[ 1009.506250] usb 1-1.4: Manufacturer: Broadcom
[ 1009.506263] usb 1-1.4: SerialNumber: f06348ef
[ 1009.508429] pcm512x 1-004d: supply AVDD not found, using dummy regulator
[ 1009.508611] pcm512x 1-004d: supply DVDD not found, using dummy regulator
[ 1009.508698] pcm512x 1-004d: supply CPVDD not found, using dummy regulator
[ 1010.553677] pcm512x 1-004d: supply AVDD not found, using dummy regulator
[ 1010.553931] pcm512x 1-004d: supply DVDD not found, using dummy regulator
[ 1010.554026] pcm512x 1-004d: supply CPVDD not found, using dummy regulator
[ 1012.005433] usb usb1-port1: disabled by hub (EMI?), re-enabling...
[ 1012.005467] usb 1-1: USB disconnect, device number 2
[ 1012.005488] usb 1-1.1: USB disconnect, device number 3

[ 1012.006400] WARN::dwc_otg_hcd_urb_dequeue:639: Timed out waiting for FSM NP transfer to complete on 3
[ 1012.006433] smsc95xx 1-1.1:1.0 eth0: unregister 'smsc95xx' usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet
[ 1012.006817] smsc95xx 1-1.1:1.0 eth0: Link is Down
[ 1012.006847] smsc95xx 1-1.1:1.0 eth0: Failed to read reg index 0x00000114: -19
[ 1012.006863] smsc95xx 1-1.1:1.0 eth0: Error reading MII_ACCESS
[ 1012.006878] smsc95xx 1-1.1:1.0 eth0: __smsc95xx_mdio_read: MII is busy
[ 1012.006923] smsc95xx 1-1.1:1.0 eth0: Failed to read reg index 0x00000114: -19
[ 1012.006938] smsc95xx 1-1.1:1.0 eth0: Error reading MII_ACCESS
[ 1012.006953] smsc95xx 1-1.1:1.0 eth0: __smsc95xx_mdio_read: MII is busy
[ 1012.006994] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
[ 1012.071161] usb 1-1.4: USB disconnect, device number 6
[ 1012.275373] Indeed it is in host mode hprt0 = 00001501
[ 1012.485235] usb 1-1: new high-speed USB device number 7 using dwc_otg
[ 1012.485327] Indeed it is in host mode hprt0 = 00001101
[ 1012.725418] usb 1-1: New USB device found, idVendor=0424, idProduct=9514, bcdDevice= 2.00
[ 1012.725432] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[ 1012.725930] hub 1-1:1.0: USB hub found
[ 1012.725996] hub 1-1:1.0: 5 ports detected
[ 1012.727648] pcm512x 1-004d: supply AVDD not found, using dummy regulator
[ 1012.727775] pcm512x 1-004d: supply DVDD not found, using dummy regulator
[ 1012.727829] pcm512x 1-004d: supply CPVDD not found, using dummy regulator
[ 1013.045250] usb 1-1.1: new high-speed USB device number 8 using dwc_otg
[ 1013.185545] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00, bcdDevice= 2.00
[ 1013.185563] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[ 1013.188433] smsc95xx v2.0.0
[ 1013.261600] libphy: smsc95xx-mdiobus: probed
[ 1013.262806] pcm512x 1-004d: supply AVDD not found, using dummy regulator
[ 1013.262993] pcm512x 1-004d: supply DVDD not found, using dummy regulator
[ 1013.263075] pcm512x 1-004d: supply CPVDD not found, using dummy regulator
[ 1013.264449] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:20:ea:31
[ 1013.277171] pcm512x 1-004d: supply AVDD not found, using dummy regulator
[ 1013.277393] pcm512x 1-004d: supply DVDD not found, using dummy regulator
[ 1013.277484] pcm512x 1-004d: supply CPVDD not found, using dummy regulator
[ 1013.365252] usb 1-1.4: new high-speed USB device number 9 using dwc_otg
[ 1013.495979] usb 1-1.4: New USB device found, idVendor=0a5c, idProduct=2711, bcdDevice= 0.00
[ 1013.496001] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=4
[ 1013.496016] usb 1-1.4: Product: BCM2711 Boot
[ 1013.496030] usb 1-1.4: Manufacturer: Broadcom
[ 1013.496045] usb 1-1.4: SerialNumber: f06348ef
[ 1013.498525] pcm512x 1-004d: supply AVDD not found, using dummy regulator
[ 1013.498823] pcm512x 1-004d: supply DVDD not found, using dummy regulator
[ 1013.498927] pcm512x 1-004d: supply CPVDD not found, using dummy regulator
[ 1013.776727] SMSC LAN8700 usb-001:008:01: attached PHY driver [SMSC LAN8700] (mii_bus:phy_addr=usb-001:008:01, irq=POLL)
[ 1013.776980] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
[ 1013.787864] smsc95xx 1-1.1:1.0 eth0: Link is Down
[ 1014.544200] pcm512x 1-004d: supply AVDD not found, using dummy regulator
[ 1014.544480] pcm512x 1-004d: supply DVDD not found, using dummy regulator
[ 1014.544912] pcm512x 1-004d: supply CPVDD not found, using dummy regulator
[ 1014.994053] usb 1-1.4: USB disconnect, device number 9
[ 1015.836591] smsc95xx 1-1.1:1.0 eth0: Link is Up - 100Mbps/Full - flow control off
[ 1015.836648] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[ 1016.575301] usb 1-1.4: new high-speed USB device number 10 using dwc_otg
[ 1016.706489] usb 1-1.4: New USB device found, idVendor=0a5c, idProduct=0001, bcdDevice= 0.01
[ 1016.706516] usb 1-1.4: New USB device strings: Mfr=2, Product=1, SerialNumber=3
[ 1016.706532] usb 1-1.4: Product: Compute Module
[ 1016.706546] usb 1-1.4: Manufacturer: Raspberry Pi
[ 1016.706561] usb 1-1.4: SerialNumber: f06348ef
[ 1016.707558] usb-storage 1-1.4:1.0: USB Mass Storage device detected
[ 1016.708302] scsi host0: usb-storage 1-1.4:1.0
[ 1016.710373] pcm512x 1-004d: supply AVDD not found, using dummy regulator
[ 1016.710605] pcm512x 1-004d: supply DVDD not found, using dummy regulator
[ 1016.710697] pcm512x 1-004d: supply CPVDD not found, using dummy regulator
[ 1017.756096] scsi 0:0:0:0: Direct-Access     RPi-MSD- 0001                  PQ: 0 ANSI: 2
[ 1017.756854] sd 0:0:0:0: Attached scsi generic sg0 type 0
[ 1017.757493] sd 0:0:0:0: [sda] 61067264 512-byte logical blocks: (31.3 GB/29.1 GiB)
[ 1017.757898] sd 0:0:0:0: [sda] Write Protect is off
[ 1017.757920] sd 0:0:0:0: [sda] Mode Sense: 0f 00 00 00
[ 1017.758294] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[ 1017.799086]  sda: sda1
[ 1017.802962] sd 0:0:0:0: [sda] Attached SCSI removable disk
[ 1017.804487] pcm512x 1-004d: supply AVDD not found, using dummy regulator
[ 1017.804745] pcm512x 1-004d: supply DVDD not found, using dummy regulator
[ 1017.804834] pcm512x 1-004d: supply CPVDD not found, using dummy regulator
[ 1322.835277] usb 1-1.4: reset high-speed USB device number 10 using dwc_otg
[ 1472.475311] INFO: task kworker/u8:1:89 blocked for more than 122 seconds.
[ 1472.475331]       Tainted: G         C        5.10.63-v7+ #1459
[ 1472.475343] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1472.475357] task:kworker/u8:1    state:D stack:    0 pid:   89 ppid:     2 flags:0x00000000
[ 1472.475405] Workqueue: writeback wb_workfn (flush-8:0)
[ 1472.475437] Backtrace: 
[ 1472.475478] [<809f9df0>] (__schedule) from [<809fa7c8>] (schedule+0x68/0xe4)
[ 1472.475500]  r10:ffffe000 r9:80f057c0 r8:80f05008 r7:847fa500 r6:834c0e00 r5:81ec1f00
[ 1472.475514]  r4:ffffe000
[ 1472.475537] [<809fa760>] (schedule) from [<809facfc>] (io_schedule+0x20/0x40)
[ 1472.475553]  r5:834c0e14 r4:00000000
[ 1472.475576] [<809facdc>] (io_schedule) from [<805fdce8>] (blk_mq_get_tag+0x170/0x304)
[ 1472.475591]  r5:834c0e14 r4:825cd9fc
[ 1472.475613] [<805fdb78>] (blk_mq_get_tag) from [<805f8750>] (__blk_mq_alloc_request+0x60/0x120)
[ 1472.475634]  r10:8dbd0000 r9:0000000c r8:825cd9fc r7:8dbd0000 r6:ffffe000 r5:847faa00
[ 1472.475648]  r4:80f057c0
[ 1472.475669] [<805f86f0>] (__blk_mq_alloc_request) from [<805fb014>] (blk_mq_submit_bio+0x12c/0x5ac)
[ 1472.475690]  r9:0000000c r8:00000000 r7:80f05008 r6:00000000 r5:8dbd0000 r4:826b8900
[ 1472.475713] [<805faee8>] (blk_mq_submit_bio) from [<805ed98c>] (submit_bio_noacct+0x374/0x3e8)
[ 1472.475734]  r9:0000000c r8:0000000a r7:00000000 r6:ffffffff r5:80f05008 r4:826b8900
[ 1472.475755] [<805ed618>] (submit_bio_noacct) from [<805eda58>] (submit_bio+0x58/0x1d8)
[ 1472.475778]  r10:00000001 r9:00000000 r8:00000008 r7:00100000 r6:00100001 r5:826b8900
[ 1472.475791]  r4:80f05008
[ 1472.475813] [<805eda00>] (submit_bio) from [<8037a9f4>] (submit_bh_wbc+0x19c/0x1cc)
[ 1472.475834]  r10:00000001 r9:00000000 r8:00000000 r7:00100000 r6:00100001 r5:826b8900
[ 1472.475848]  r4:85643340
[ 1472.475870] [<8037a858>] (submit_bh_wbc) from [<8037e880>] (__block_write_full_page+0x364/0x5ec)
[ 1472.475891]  r9:00000000 r8:825cdd60 r7:85643340 r6:823402b0 r5:85643340 r4:00100000
[ 1472.475914] [<8037e51c>] (__block_write_full_page) from [<8037eda0>] (block_write_full_page+0x13c/0x144)
[ 1472.475935]  r10:825cdc0c r9:babbeb24 r8:0000000f r7:825cdd60 r6:80381024 r5:babbeb24
[ 1472.475948]  r4:823402b0
[ 1472.475972] [<8037ec64>] (block_write_full_page) from [<803810f8>] (blkdev_writepage+0x24/0x28)
[ 1472.475991]  r8:0000000f r7:0000003c r6:823403c0 r5:825cdd60 r4:823403c0
[ 1472.476016] [<803810d4>] (blkdev_writepage) from [<802b5de4>] (__writepage+0x24/0x74)
[ 1472.476041] [<802b5dc0>] (__writepage) from [<802b8224>] (write_cache_pages+0x1e4/0x48c)
[ 1472.476056]  r5:825cdd60 r4:00000001
[ 1472.476080] [<802b8040>] (write_cache_pages) from [<802b8530>] (generic_writepages+0x64/0x90)
[ 1472.476101]  r10:80f05008 r9:ffffe000 r8:802b5dc0 r7:80f05008 r6:825cdd60 r5:823403c0
[ 1472.476114]  r4:80f05008
[ 1472.476137] [<802b84cc>] (generic_writepages) from [<803810a8>] (blkdev_writepages+0x18/0x1c)
[ 1472.476155]  r6:00001400 r5:825cdd60 r4:823403c0
[ 1472.476179] [<80381090>] (blkdev_writepages) from [<802b90f8>] (do_writepages+0x54/0xf0)
[ 1472.476202] [<802b90a4>] (do_writepages) from [<8036d314>] (__writeback_single_inode+0x44/0x468)
[ 1472.476222]  r8:823403c0 r7:80f03d00 r6:00001400 r5:825cdd60 r4:823402b0
[ 1472.476243] [<8036d2d0>] (__writeback_single_inode) from [<8036dc74>] (writeback_sb_inodes+0x214/0x50c)
[ 1472.476264]  r9:ffffe000 r8:823402b0 r7:80f03d00 r6:825cdea4 r5:84ec8040 r4:82340360
[ 1472.476286] [<8036da60>] (writeback_sb_inodes) from [<8036dfdc>] (__writeback_inodes_wb+0x70/0xbc)
[ 1472.476307]  r10:82340360 r9:80f03d00 r8:84ec8054 r7:825cdea4 r6:00000000 r5:84ec8040
[ 1472.476321]  r4:814c5000
[ 1472.476342] [<8036df6c>] (__writeback_inodes_wb) from [<8036e314>] (wb_writeback+0x2ec/0x394)
[ 1472.476363]  r10:ffffe000 r9:80f05058 r8:81033a04 r7:81459300 r6:84ec806c r5:825cdea4
[ 1472.476376]  r4:84ec8040
[ 1472.476397] [<8036e028>] (wb_writeback) from [<8036f674>] (wb_workfn+0x3b4/0x574)
[ 1472.476418]  r10:81033a04 r9:84ec8118 r8:84ec8040 r7:81459300 r6:00000000 r5:84ec8124
[ 1472.476432]  r4:00003737
[ 1472.476455] [<8036f2c0>] (wb_workfn) from [<8013b900>] (process_one_work+0x250/0x5a0)
[ 1472.476476]  r10:00000000 r9:00000000 r8:00000100 r7:81459300 r6:8144a400 r5:81723a80
[ 1472.476490]  r4:84ec8124
[ 1472.476512] [<8013b6b0>] (process_one_work) from [<8013bcb0>] (worker_thread+0x60/0x5c4)
[ 1472.476534]  r10:8144a400 r9:80f03d00 r8:8144a418 r7:00000088 r6:8144a400 r5:81723a94
[ 1472.476547]  r4:81723a80
[ 1472.476570] [<8013bc50>] (worker_thread) from [<80143790>] (kthread+0x170/0x174)
[ 1472.476591]  r10:81527e74 r9:81723a80 r8:8013bc50 r7:825cc000 r6:00000000 r5:81731f00
[ 1472.476604]  r4:81744540
[ 1472.476625] [<80143620>] (kthread) from [<801000ec>] (ret_from_fork+0x14/0x28)
[ 1472.476639] Exception stack(0x825cdfb0 to 0x825cdff8)
[ 1472.476657] dfa0:                                     00000000 00000000 00000000 00000000
[ 1472.476676] dfc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[ 1472.476694] dfe0: 00000000 00000000 00000000 00000000 00000013 00000000
[ 1472.476714]  r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:80143620
[ 1472.476727]  r4:81731f00
[ 1472.476787] INFO: task kworker/3:3:1767 blocked for more than 122 seconds.
[ 1472.476801]       Tainted: G         C        5.10.63-v7+ #1459
[ 1472.476812] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1472.476824] task:kworker/3:3     state:D stack:    0 pid: 1767 ppid:     2 flags:0x00000000
[ 1472.476860] Workqueue: events_freezable_power_ disk_events_workfn
[ 1472.476881] Backtrace: 
[ 1472.476916] [<809f9df0>] (__schedule) from [<809fa7c8>] (schedule+0x68/0xe4)
[ 1472.476937]  r10:ffffe000 r9:80f057c0 r8:80f05008 r7:847fa540 r6:834c0e00 r5:81f20000
[ 1472.476950]  r4:ffffe000
[ 1472.476971] [<809fa760>] (schedule) from [<809facfc>] (io_schedule+0x20/0x40)
[ 1472.476987]  r5:834c0e14 r4:00000000
[ 1472.477007] [<809facdc>] (io_schedule) from [<805fdce8>] (blk_mq_get_tag+0x170/0x304)
[ 1472.477023]  r5:834c0e14 r4:85857d84
[ 1472.477045] [<805fdb78>] (blk_mq_get_tag) from [<805f8750>] (__blk_mq_alloc_request+0x60/0x120)
[ 1472.477066]  r10:00000000 r9:00000000 r8:85857d84 r7:8dbd0000 r6:ffffe000 r5:847faa00
[ 1472.477079]  r4:80f057c0
[ 1472.477100] [<805f86f0>] (__blk_mq_alloc_request) from [<805f888c>] (blk_mq_alloc_request+0x7c/0xb4)
[ 1472.477121]  r9:00000000 r8:85857e46 r7:85883800 r6:8dbd0000 r5:00000000 r4:80f05008
[ 1472.477144] [<805f8810>] (blk_mq_alloc_request) from [<805eb044>] (blk_get_request+0x40/0xd0)
[ 1472.477161]  r6:8dbd0000 r5:00000000 r4:00000020
[ 1472.477187] [<805eb004>] (blk_get_request) from [<8074c23c>] (__scsi_execute+0x4c/0x1a4)
[ 1472.477205]  r7:85883800 r6:00000000 r5:00000000 r4:85857e7c
[ 1472.477230] [<8074c1f0>] (__scsi_execute) from [<8074c7d8>] (scsi_test_unit_ready+0x88/0x110)
[ 1472.477250]  r10:00000000 r9:80f05008 r8:00000bb8 r7:85883800 r6:00000005 r5:00000000
[ 1472.477263]  r4:85857e7c
[ 1472.477289] [<8074c750>] (scsi_test_unit_ready) from [<80761844>] (sd_check_events+0x114/0x158)
[ 1472.477310]  r9:834c032c r8:000000c0 r7:bab0af00 r6:85883800 r5:80f05008 r4:829b4000
[ 1472.477332] [<80761730>] (sd_check_events) from [<806022fc>] (disk_check_events+0x5c/0x180)
[ 1472.477349]  r6:80f05008 r5:829b7400 r4:834c0300
[ 1472.477373] [<806022a0>] (disk_check_events) from [<80602440>] (disk_events_workfn+0x20/0x24)
[ 1472.477394]  r10:00000000 r9:00000000 r8:000000c0 r7:bab0af00 r6:bab076c0 r5:81f03300
[ 1472.477408]  r4:834c0334
[ 1472.477431] [<80602420>] (disk_events_workfn) from [<8013b900>] (process_one_work+0x250/0x5a0)
[ 1472.477454] [<8013b6b0>] (process_one_work) from [<8013bcb0>] (worker_thread+0x60/0x5c4)
[ 1472.477475]  r10:bab076c0 r9:80f03d00 r8:bab076d8 r7:00000008 r6:bab076c0 r5:81f03314
[ 1472.477489]  r4:81f03300
[ 1472.477510] [<8013bc50>] (worker_thread) from [<80143790>] (kthread+0x170/0x174)
[ 1472.477532]  r10:81e65e74 r9:81f03300 r8:8013bc50 r7:85856000 r6:00000000 r5:84c7ed80
[ 1472.477545]  r4:8d95c080
[ 1472.477565] [<80143620>] (kthread) from [<801000ec>] (ret_from_fork+0x14/0x28)
[ 1472.477579] Exception stack(0x85857fb0 to 0x85857ff8)
[ 1472.477596] 7fa0:                                     00000000 00000000 00000000 00000000
[ 1472.477615] 7fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[ 1472.477633] 7fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[ 1472.477654]  r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:80143620
[ 1472.477667]  r4:84c7ed80
pi@raspberrypi:~ $ 

@timg236
Copy link
Collaborator

timg236 commented Dec 2, 2021

I think the callstack indicates that the a write command never completed so the kernel timed out and killed the process. How are you writing the image to the Compute Module e.g .imager or are you just accessing files directly?

@dir-ableton
Copy link

dir-ableton commented Dec 6, 2021

I've been using dd to flash the whole image in this case, but also observed problems in the past when mounting and accessing, especially again writing.

@dir-ableton
Copy link

A quick follow-up: it appears the SD-card-brand makes a difference. I got eMMC CMs today, and with them I was able to flash. I then used a SanDISK SD-card in the IO board + CM4 that was failing before, and have flashed 20 or so times in a row, no problem. Back to the NetAC-card I used, and I get sporadic failures.

The speed seems to have degraded between CM3 and CM4, it used to be between 5-6MB/s, now it's about 3.5-4, 4.7 with eMMC.

Is there a chance of increasing compatibility or speed?

@capiman2
Copy link

capiman2 commented Feb 23, 2022

I have/had a similar problem here. With one PC (Windows 64 bit, Dell, company notebook),
I get

Waiting for BCM2835/6/7/2711...
Loading embedded: bootcode4.bin
Loading embedded: bootcode4.bin
Sending bootcode.bin
Successful read 4 bytes
Waiting for BCM2835/6/7/2711...
Loading embedded: bootcode4.bin
Sending bootcode.bin
Failed control transfer (-9,24)
Failed to write correct length, returned -9
Waiting for BCM2835/6/7/2711...
Loading embedded: bootcode4.bin
Sending bootcode.bin
Failed control transfer (-9,24)
Failed to write correct length, returned -9
Waiting for BCM2835/6/7/2711...
Loading embedded: bootcode4.bin
Sending bootcode.bin
Failed control transfer (-9,24)
Failed to write correct length, returned -9
Waiting for BCM2835/6/7/2711...
Loading embedded: bootcode4.bin
Sending bootcode.bin
Failed control transfer (-9,24)
Failed to write correct length, returned -9
Waiting for BCM2835/6/7/2711...
Loading embedded: bootcode4.bin
Sending bootcode.bin
Failed control transfer (-9,24)
Failed to write correct length, returned -9
Waiting for BCM2835/6/7/2711...
Loading embedded: bootcode4.bin

Used the same CM4, on same self built baseboard, same USB cable on a different notebook
(very old, Win10, 32 bit, forced to do completely new install a few days ago), it worked flawlessly.
New disk were found and I was able to flash image via Win32DiskImager.exe.
I meanwhile even updated EEPROM and changed config. Again with old PC (Samsung RV520) it was working.
I see "BCM2711 Boot" in device manager of both PCs, so it looks like the general USB communication (enumeration) seems to be working on both PCs.

Afterwards I tried a mix: Start rpiboot on old PC, when new disk windows opened, disconnected the USB and connect it to new machine. From there also new disk windowed opened and I was able to flash the complete image without an error to a SD card.

@timg236
Copy link
Collaborator

timg236 commented Mar 31, 2022

@ddibiasi Please could you retry with the latest version. Over the last few months there's been some improvements to how the USB control is inherited from the ROM so it would be useful to know if that helps.

N.B. The recommended host is Raspberry Pi or Linux PC without a hub between the Compute Module and the host.

@brooksphilip
Copy link

I have this same problem on an M1 MacBook Pro. I can not get rpiboot to work.

Found candidate Compute Module...Loading embedded: bootcode4.bin
Device located successfully
Initialised device correctly
Found serial number 3
Sending bootcode.bin
libusb_bulk_transfer sent 24 bytes; returned 0
Writing 121888 bytes
libusb_bulk_transfer sent 121888 bytes; returned 0
Successful read 4 bytes
Waiting for BCM2835/6/7/2711...
Found device 1 idVendor=0x0a5c idProduct=0x2711
Bus: 1, Device: 1 Path: 1-1
Found candidate Compute Module...Loading embedded: bootcode4.bin
Device located successfully
Initialised device correctly
Found serial number 3
Sending bootcode.bin
libusb: warning [darwin_transfer_status] transfer error: device not responding (value = 0xe00002ed)
Failed control transfer (-1,24)
Failed to write correct length, returned -1
libusb: warning [darwin_close] USBDeviceClose: no connection to an IOService
Waiting for BCM2835/6/7/2711...

@boedy
Copy link

boedy commented Aug 24, 2022

I'm running into the same issue. I received a new batch of 10 CM4's that are all experiencing this issue. I've compared these units with working ones and noticed some visual differences between them. I've included a picture of the two below. I've marked some differences on the unit that's having this issue. This seems to be the newer device.

IMG_20220824_153547

Edit
I discovered the underlying issue. In my instance seems to be related to Balena Etcher not yet supporting the newer CM4's. When I tried running rpiboot Balena Etcher was still open in the background, which wouldn't allow rpiboot to connect as it seems to keep the device busy. Closing Etcher and re-running rpiboot allowed it to mount to my macbook.

@jonrot1906
Copy link

I'm running into the same issue. I received a new batch of 10 CM4's that are all experiencing this issue. I've compared these units with working ones and noticed some visual differences between them. I've included a picture of the two below. I've marked some differences on the unit that's having this issue. This seems to be the newer device.

IMG_20220824_153547

Edit I discovered the underlying issue. In my instance seems to be related to Balena Etcher not yet supporting the newer CM4's. When I tried running rpiboot Balena Etcher was still open in the background, which wouldn't allow rpiboot to connect as it seems to keep the device busy. Closing Etcher and re-running rpiboot allowed it to mount to my macbook.

Great finding. This was also the case for me - I was just a second to giving up on this CM4 and then saw your edit. Balena Etcher seemed to block a correct connection as well. I had to reattach the USB cable to my mac, rerun rpiboot and everything worked fine.

@fix3000
Copy link

fix3000 commented Sep 1, 2022

Yep, I also found that I had to update rpiboot to a newer version in order to handle the newer CM4 hardware I received. And unfortunately, you cannot run rpiboot and balenaEtcher simultaneously. You have to do rpiboot first, then bE.

Hopefully they'll fix this detection issue soon... I get the sense that a lot of folks were forced to the CM4 due to the CM3+ supply issues. Manufacturing is a complete cluster at the moment.

@JamesH65
Copy link

JamesH65 commented Sep 2, 2022

New devices have been sent to balena for verification of use with etcher, however, I've not had confirmation from them that it has yet been done, although it was a while ago. I'll email them again to see if there have been any progress.

@timg236
Copy link
Collaborator

timg236 commented Sep 2, 2022

The new CM4s report identical USB descriptors and the SoC is the same, there are no differences in the the USB interface. All that's required is to have a new enough version of rpiboot so that it loads firmware supporting the new PMIC.

The significant difference is not circled in the photos. See bottom left, the MXL power supply has been replaced with a Dialog part.

@capiman2
Copy link

capiman2 commented Sep 2, 2022

@timg236
Can you tell what happens when old rpiboot and new PMIC is used together? Is there a check and it fails?
What version supports both?
Is there some kind of comparison between old and new CM4? Any change in behaviour in general?
Is there a possibility to check if the one or the other is used? Some program which can be called to get this info?
Is there any possibility to buy/get one CM4 (Wifi, no MMC) with Dialog Part, so we can test/confirm our product works also with the dialog part?

@timg236
Copy link
Collaborator

timg236 commented Sep 2, 2022

The latest version of rpiboot supports both but I think it's been supported for well over a year now.
If the firmware used by rpiboot is too old then it will fail to boot - maybe an error pattern but the rpiboot host won't know anything about it.
I can't advise about ordering CM4 parts for test.

The Product Information Portal is the place to go for product update information
https://pip.raspberrypi.com/

@JamesH65
Copy link

JamesH65 commented Sep 2, 2022

Please email [email protected] to request parts for testing, please give as much information as possible on your use case, so our commercial team can make the appropriate decisions on supply. However, there is no guarantee parts are available at this time.

@capiman2
Copy link

capiman2 commented Sep 2, 2022

https://pip.raspberrypi.com/categories/645/documents/RP-001606-PC/RP-001606-PC-2.pdf

"
In software, new product can be distinguished by:
cat /proc/cpuinfo will report "Model" as "Raspberry Pi Compute Module 4 Rev 1.1"
"

@JamesH65
Copy link

JamesH65 commented Sep 2, 2022

https://pip.raspberrypi.com/categories/645/documents/RP-001606-PC/RP-001606-PC-2.pdf

" In software, new product can be distinguished by: cat /proc/cpuinfo will report "Model" as "Raspberry Pi Compute Module 4 Rev 1.1" "

Are you reporting this as an error in the PCN? Or just reporting it?

@capiman2
Copy link

capiman2 commented Sep 2, 2022

"Are you reporting this as an error in the PCN? Or just reporting it?"

Just for info, that above info can be found in an official document

@NeusAap
Copy link

NeusAap commented Apr 5, 2023

I had this problem as well with a CM4 on the official IO-Board.
I was using a (analog/old-school) variable power supply, which was set to 12.5V by accident.

Dialing it down to 12V exactly, fixed the problem for me. Might be worth a try for other people using variable power supplies.

@JaggerJo
Copy link

JaggerJo commented Sep 4, 2023

Had the same issue on a M2 Mac mini. Swapping USB cables worked.

@Jatin-Patel2331
Copy link

Hello,

I'm trying to flash the CM4 on the official IO board.

The jumper has been set to 'Fit jumper to disable eMMC Boot' and I am using the latest usbboot.

If i try to run sudo ./rpiboot it gets stuck in this loop:

Waiting for BCM2835/6/7/2711...
Loading embedded: bootcode4.bin
Sending bootcode.bin
Successful read 4 bytes
Waiting for BCM2835/6/7/2711...
Loading embedded: bootcode4.bin
Sending bootcode.bin
Failed control transfer (-7,24)
Failed to write correct length, returned -7
Waiting for BCM2835/6/7/2711...
Loading embedded: bootcode4.bin
Sending bootcode.bin
Failed control transfer (-7,24)
Failed to write correct length, returned -7
Waiting for BCM2835/6/7/2711...
Loading embedded: bootcode4.bin
Sending bootcode.bin
Failed control transfer (-7,24)
Failed to write correct length, returned -7

This issue is probably related to #82.

Output of sudo ./rpiboot -vv

Waiting for BCM2835/6/7/2711...
Found device 1 idVendor=0x1d6b idProduct=0x0003
Bus: 8, Device: 1 Path: 8
Found device 2 idVendor=0x045e idProduct=0x0719
Bus: 7, Device: 5 Path: 7-4
Found device 3 idVendor=0x03f0 idProduct=0x094a
Bus: 7, Device: 4 Path: 7-3
Found device 4 idVendor=0x17f6 idProduct=0x0862
Bus: 7, Device: 3 Path: 7-2
Found device 5 idVendor=0x05ac idProduct=0x1301
Bus: 7, Device: 2 Path: 7-1
Found device 6 idVendor=0x1d6b idProduct=0x0002
Bus: 7, Device: 1 Path: 7
Found device 7 idVendor=0x1d6b idProduct=0x0003
Bus: 6, Device: 1 Path: 6
Found device 8 idVendor=0x1d6b idProduct=0x0002
Bus: 5, Device: 1 Path: 5
Found device 9 idVendor=0x1d6b idProduct=0x0003
Bus: 4, Device: 1 Path: 4
Found device 10 idVendor=0x1d6b idProduct=0x0002
Bus: 3, Device: 1 Path: 3
Found device 11 idVendor=0x1d6b idProduct=0x0003
Bus: 2, Device: 1 Path: 2
Found device 12 idVendor=0x0a5c idProduct=0x2711
Bus: 1, Device: 8 Path: 1-6
Found candidate Compute Module...Loading embedded: bootcode4.bin
Device located successfully
Initialised device correctly
Found serial number 3
Sending bootcode.bin
libusb_bulk_transfer sent 24 bytes; returned 0
Writing 121944 bytes
libusb_bulk_transfer sent 121944 bytes; returned 0
Successful read 4 bytes
Waiting for BCM2835/6/7/2711...
Found device 1 idVendor=0x1d6b idProduct=0x0003
Bus: 8, Device: 1 Path: 8
Found device 2 idVendor=0x045e idProduct=0x0719
Bus: 7, Device: 5 Path: 7-4
Found device 3 idVendor=0x03f0 idProduct=0x094a
Bus: 7, Device: 4 Path: 7-3
Found device 4 idVendor=0x17f6 idProduct=0x0862
Bus: 7, Device: 3 Path: 7-2
Found device 5 idVendor=0x05ac idProduct=0x1301
Bus: 7, Device: 2 Path: 7-1
Found device 6 idVendor=0x1d6b idProduct=0x0002
Bus: 7, Device: 1 Path: 7
Found device 7 idVendor=0x1d6b idProduct=0x0003
Bus: 6, Device: 1 Path: 6
Found device 8 idVendor=0x1d6b idProduct=0x0002
Bus: 5, Device: 1 Path: 5
Found device 9 idVendor=0x1d6b idProduct=0x0003
Bus: 4, Device: 1 Path: 4
Found device 10 idVendor=0x1d6b idProduct=0x0002
Bus: 3, Device: 1 Path: 3
Found device 11 idVendor=0x1d6b idProduct=0x0003
Bus: 2, Device: 1 Path: 2
Found device 12 idVendor=0x0a5c idProduct=0x2711
Bus: 1, Device: 8 Path: 1-6
Found candidate Compute Module...Loading embedded: bootcode4.bin
Device located successfully
Initialised device correctly
Found serial number 3
Sending bootcode.bin
Failed control transfer (-7,24)
Failed to write correct length, returned -7
Waiting for BCM2835/6/7/2711...
Found device 1 idVendor=0x1d6b idProduct=0x0003
Bus: 8, Device: 1 Path: 8
Found device 2 idVendor=0x045e idProduct=0x0719
Bus: 7, Device: 5 Path: 7-4
Found device 3 idVendor=0x03f0 idProduct=0x094a
Bus: 7, Device: 4 Path: 7-3
Found device 4 idVendor=0x17f6 idProduct=0x0862
Bus: 7, Device: 3 Path: 7-2
Found device 5 idVendor=0x05ac idProduct=0x1301
Bus: 7, Device: 2 Path: 7-1
Found device 6 idVendor=0x1d6b idProduct=0x0002
Bus: 7, Device: 1 Path: 7
Found device 7 idVendor=0x1d6b idProduct=0x0003
Bus: 6, Device: 1 Path: 6
Found device 8 idVendor=0x1d6b idProduct=0x0002
Bus: 5, Device: 1 Path: 5
Found device 9 idVendor=0x1d6b idProduct=0x0003
Bus: 4, Device: 1 Path: 4
Found device 10 idVendor=0x1d6b idProduct=0x0002
Bus: 3, Device: 1 Path: 3
Found device 11 idVendor=0x1d6b idProduct=0x0003
Bus: 2, Device: 1 Path: 2
Found device 12 idVendor=0x0a5c idProduct=0x2711
Bus: 1, Device: 8 Path: 1-6
Found candidate Compute Module...Loading embedded: bootcode4.bin
Device located successfully
Initialised device correctly
Found serial number 3
Sending bootcode.bin
Failed control transfer (-7,24)
Failed to write correct length, returned -7

I had the same error, reinstalling the "rpiboot" worked for me.

@ll-O-ll
Copy link

ll-O-ll commented Jun 3, 2024

I get the same loop when running the sudo ./rpiboot -d recovery in the secure-boot-example

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests