Sending bootcode.bin repeatedly failing

infinnovation-dev commented 6 years ago

Trying to flash a CM3 from a Pi B+ (Jessie), I found that the rpiboot was repeatedly failing

Waiting for BCM2835/6/7
Sending bootcode.bin
Successful read 4 bytes 
Waiting for BCM2835/6/7
Sending bootcode.bin
Successful read 4 bytes 
Waiting for BCM2835/6/7
Sending bootcode.bin
Failed to write correct length, returned 0
Waiting for BCM2835/6/7
Sending bootcode.bin
Failed to write correct length, returned 0
Waiting for BCM2835/6/7
Sending bootcode.bin
Failed to write correct length, returned 0
Waiting for BCM2835/6/7
Sending bootcode.bin

The -v option provided more information:

Sending bootcode.bin
libusb_bulk_transfer returned -7
Failed to write correct length, returned 0

From libusb.h, -7 is LIBUSB_ERROR_TIMEOUT and this corresponded with it taking 100 seconds per attempt.

After a couple of hours debugging (including trying from a different machine), I found the problem: the length field of boot_message was being set to zero. This in turn is due to the way fseek(f,SEEK_END) works on a file opened with the (somewhat non-portable) fmemopen() function: when opened with "r" as opposed to "rb", the end of the file is the location of the first null byte, i.e. the very beginning of the bootcode. Probably this behaviour depends on version or implementation of fmemopen, as I guess it must have worked OK for other people.

I would suggest adding at least a sanity check on the length, or maybe ditching the use of fmemread and passing pointer+size info around instead of file handles.

The work-around is to specify the directory explicitly i.e.

  sudo ./rpiboot -d msd

ghollingworth commented 6 years ago

So just changing "r" to "rb" fixes the issue?

infinnovation-dev commented 6 years ago

I'd guess so, from the manpage. No idea about other host platforms.

ghollingworth commented 6 years ago

Looks like a fairly safe change, I'll commit the change but can't push a new build yet...

hartmannathan commented 3 years ago

I'm running into this on latest master.

Host OS: Ubuntu 20.04 x86_64 Target device: Compute Module 4 (CM4108032) on official Compute Module 4 IO Board.

It appears to work occasionally. Occasional invocations of the program work but most fail.

When it works (which is only occasionally) it prints this:

$ sudo ./rpiboot -d msd
Loading: msd/bootcode.bin
Loading: msd/bootcode4.bin
Waiting for BCM2835/6/7/2711...
Loading: msd/bootcode4.bin
Second stage boot server
Loading: msd/start4.elf
File read: start4.elf
Second stage boot server done
$

When it fails (usually) it prints this:

$ sudo ./rpiboot 
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
Waiting for BCM2835/6/7/2711...
Loading embedded: bootcode4.bin
Sending bootcode.bin
^C
$

and gets stuck in an endless loop doing that.

Same result happens with and without workaround mentioned above:

With workaround: $ sudo ./rpiboot -d msd
Without workaround: $ sudo ./rpiboot

To be clear, I checked code and the fmemopen() calls are using 'rb'.

This may be a sensitivity to timing or other issues like that. In case anyone wonders, I tried different USB cables between PC and the CM4 IO board.

hartmannathan commented 3 years ago

Just following up to my previous post. I had to do this again today and this time the messages printed at successful execution were slightly different:

$ sudo ./rpiboot -d msd
Loading: msd/bootcode.bin
Loading: msd/bootcode4.bin
Waiting for BCM2835/6/7/2711...
Loading: msd/bootcode4.bin
Sending bootcode.bin
Successful read 4 bytes 
Waiting for BCM2835/6/7/2711...
Loading: msd/bootcode4.bin
Second stage boot server
Loading: msd/start4.elf
File read: start4.elf
Second stage boot server done

Once again it took at least 20 failed attempts before it worked.

Not sure what's going on here or why the same device seems to respond differently.

agners commented 2 years ago

We see the same problem in production. With the very same setup (same usbboot binary, same USB cable etc.), countless devices work flawlessly. But just some CM4 seem to cause this Failed control transfer errors:

Loading: usbboot/ha/bootcode4.bin
Waiting for BCM2835/6/7/2711...
Loading: usbboot/ha/bootcode4.bin
Sending bootcode.bin
Failed control transfer (-7,24)
Failed to write correct length, returned -7
Waiting for BCM2835/6/7/2711...
Loading: usbboot/ha/bootcode4.bin
Sending bootcode.bin
Failed control transfer (-7,24)
Failed to write correct length, returned -7
Waiting for BCM2835/6/7/2711...
Loading: usbboot/ha/bootcode4.bin
Sending bootcode.bin
...

It is definitely CM4 dependent, as we can test another CM4 successfully on the same IO board every time. But the "bad" CM4 does not succeed for several time. So far, we did not went on to test 20 times.

maxromanovsky commented 2 years ago

Well, here's what I did (with Waveshare CM4-IO-BASE-B):

unplugged the fan (because of power consumption)
unplugged the external antenna (because I could...)
unplugged the m.2 NVMe (because of power consumption)
took out RTC battery (because I was desperate)
took out HDMI and USB cable connectors (you know, these for additional ports)

nothing helped

Then I tried different cables, different USB ports... Rebooting the MacBook did the trick :D

(And I haven't tried it with all the things plugged in again).

timg236 commented 2 years ago

I've seen this behavior on Windows as well. Sometimes the host-os decides that it doesn't like the USB port (e.g. over-current / glitch when plugging cables) and disables / ignores it. Linux doesn't do this and gives detailed information in dmesg.

maxromanovsky commented 1 year ago

At first I was optimistic, and simple MacBook reboot helped me with that issue, but after som time now this workaround stopped working. I tried it on:

MacBook Pro 15" mid-2014 (+ resetting SMC)
Windows running in VMWare Fusion on mid-2014 MacBook Pro
MacBook Pro M1 16" (it worked the first time the module was connected, but didn't work in subsequent attempts, even after reboot)

But it works great if CM4 is connected to Raspberry PI 4 (non-CM).

I have a feeling this is not purely hardware related.

Here's the latest log from MBP2014:

sudo ./rpiboot

RPIBOOT: build-date Aug 21 2022 version 20220815~145439 1e651a88
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

nickjvturner commented 1 year ago

I have been using an RPi4 as my host device to update the EEPROM of many CM4, I updated ~20 without any issue, then suddenly 6 in a row that would fail.

Loading: recovery/bootcode4.bin
Waiting for BCM2835/6/7/2711...
Loading: recovery/bootcode4.bin
Sending bootcode.bin
Failed to read correct length, returned 0
Waiting for BCM2835/6/7/2711...
Loading: recovery/bootcode4.bin
Sending bootcode.bin
Failed to read correct length, returned 0
Waiting for BCM2835/6/7/2711...
Loading: recovery/bootcode4.bin
Sending bootcode.bin
Failed to write correct length, returned 0
Waiting for BCM2835/6/7/2711...

or

Loading: recovery/bootcode4.bin
Waiting for BCM2835/6/7/2711...
Loading: recovery/bootcode4.bin
Sending bootcode.bin
Failed to read correct length, returned 16384
Waiting for BCM2835/6/7/2711...
Loading: recovery/bootcode4.bin
Sending bootcode.bin
Failed to read correct length, returned 0
Waiting for BCM2835/6/7/2711...
Loading: recovery/bootcode4.bin
Sending bootcode.bin
Failed to write correct length, returned 0
Waiting for BCM2835/6/7/2711...
Loading: recovery/bootcode4.bin
Sending bootcode.bin
Failed to write correct length, returned 0
Waiting for BCM2835/6/7/2711...

sometimes: Failed to write complete file to USB device

I rebooted my RPi4, I don't think this changed anything, however switching my cable from USB 3.0 over to USB 2.0 port did resolve the problem, 5 of the problematic 6 accepted the EEPROM update. For the the final stubborn unit I switched back to the 'other' USB 3.0 port with a different USB type-A to USB type-C cable and this resolved the problem.

I would like to understand more about why this is happening, but in the meantime I am happy to have gotten this far!

trimixtimo commented 1 year ago

As stated in #159, the error also appears frequently with my Windows host setup. Some combination of CM4 and base board works better than others. That's why I have changed the CM4 in the past.

Two days ago I put a USB switch with external power supply between Windows PC and CM4. Since then I could also write a whole set of the CM4, which otherwise could not be programmed at all, immediately on the first try.

JurgenLB commented 1 year ago

on my Mac I'm using a external powered usb 3.0 hub, my output is;

$ sudo ./rpiboot
RPIBOOT: build-date Sep 24 2022 version 20220815~145439 2472aaf9
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
Second stage boot server
Loading embedded: start4.elf
File read: start4.elf
Second stage boot server done
lauwers@84 usbboot % sudo ./rpiboot -v
RPIBOOT: build-date Sep 24 2022 version 20220815~145439 2472aaf9
Waiting for BCM2835/6/7/2711...
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 106008 bytes
libusb_bulk_transfer sent 106008 bytes; returned 0
Successful read 4 bytes 
Waiting for BCM2835/6/7/2711...
Loading embedded: bootcode4.bin
Device located successfully
Initialised device correctly
Found serial number 4
Second stage boot server
Received message GetFileSize: config.txt
libusb_bulk_transfer sent 0 bytes; returned 0
Cannot open file config.txt
Received message GetFileSize: pieeprom.sig
libusb_bulk_transfer sent 0 bytes; returned 0
Cannot open file pieeprom.sig
Received message GetFileSize: start4.elf
Loading embedded: start4.elf
File size = 301628 bytes
Received message ReadFile: start4.elf
File read: start4.elf
libusb_bulk_transfer sent 301628 bytes; returned 0
Received message GetFileSize: fixup4.dat
libusb_bulk_transfer sent 0 bytes; returned 0
Cannot open file fixup4.dat
libusb: warning [darwin_transfer_status] transfer error: device not responding (value = 0xe00002ed)
Second stage boot server done

The same Hub on Raspbian and the output is;

$ sudo ./rpiboot -v
RPIBOOT: build-date Sep 24 2022 version 20220815~145439 2472aaf9
Waiting for BCM2835/6/7/2711...
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 106008 bytes
libusb_bulk_transfer sent 106008 bytes; returned 0
Successful read 4 bytes 
Waiting for BCM2835/6/7/2711...
Loading embedded: bootcode4.bin
Device located successfully
Initialised device correctly
Found serial number 4
Second stage boot server
Received message GetFileSize: config.txt
libusb_bulk_transfer sent 0 bytes; returned 0
Cannot open file config.txt
Received message GetFileSize: pieeprom.sig
libusb_bulk_transfer sent 0 bytes; returned 0
Cannot open file pieeprom.sig
Received message GetFileSize: start4.elf
Loading embedded: start4.elf
File size = 301628 bytes
Received message ReadFile: start4.elf
File read: start4.elf
libusb_bulk_transfer sent 301628 bytes; returned 0
Received message GetFileSize: fixup4.dat
libusb_bulk_transfer sent 0 bytes; returned 0
Cannot open file fixup4.dat
Second stage boot server done

My board is Raspberry Pi 4 model B 2018

when I do sudo ./rpiboot -v -d recovery the output is the same but the screen on HDMI1 goes RED

Any recommendations?

missilebat commented 1 year ago

I have a problematic CM3+ that doesn't boot. When trying rpiboot, output is as follows:

~/src/rpiusbboot-git/src/usbboot` :( $ ./rpiboot -v
RPIBOOT: build-date Nov  5 2022 version 20221104~153421 a6976b71
Waiting for BCM2835/6/7/2711...
Loading embedded: bootcode.bin
Device located successfully
Initialised device correctly
Found serial number 0
Sending bootcode.bin
libusb_bulk_transfer sent 24 bytes; returned 0
Writing 52456 bytes
libusb_bulk_transfer sent 52456 bytes; returned 0
Successful read 4 bytes 
Waiting for BCM2835/6/7/2711...
Loading embedded: bootcode.bin
Device located successfully
Failed to open the requested device

Reading through manuals and doc I understand this would be a stage when all internal HW is being set up. How to debug and find out further to figure out what is happening internally and see what's failing?

phillipwgardner commented 1 year ago

Just wanted to chime in on this issue, having the same with rpiboot on Windows 11 laptop, USB 3 host interface with a CM4 module on a Waveshare IO board.

More verbose debugging showing a constant connect/disconnect by the USB because of a libusb problem.

Waiting for BCM2835/6/7/2711...
libusb: warning [windows_get_device_list] could not retrieve port number for device '\\.\USB#VID_1038&PID_202D&MI_00#2&228D4B4E&0&0000', skipping: [13] The data is invalid.
libusb: warning [windows_get_device_list] could not retrieve port number for device '\\.\USB#VID_1038&PID_202D#1&79F5D87&1&4784', skipping: [13] The data is invalid.
libusb: error [init_device] device '\\.\USB#VID_046D&PID_C52B&MI_01#6&2108CF30&1&0001' is no longer connected!
libusb: error [init_device] device '\\.\USB#VID_534D&PID_2109&MI_04#6&47611BB&0&0004' is no longer connected!
libusb: error [init_device] device '\\.\USB#VID_046D&PID_C52B&MI_02#6&2108CF30&1&0002' is no longer connected!
Loading embedded: bootcode4.bin
Device located successfully
Failed to open the requested device
libusb: warning [windows_get_device_list] could not retrieve port number for device '\\.\USB#VID_1038&PID_202D&MI_00#2&228D4B4E&0&0000', skipping: [13] The data is invalid.
libusb: warning [windows_get_device_list] could not retrieve port number for device '\\.\USB#VID_1038&PID_202D#1&79F5D87&1&4784', skipping: [13] The data is invalid.
libusb: error [init_device] device '\\.\USB#VID_046D&PID_C52B&MI_01#6&2108CF30&1&0001' is no longer connected!
libusb: error [init_device] device '\\.\USB#VID_534D&PID_2109&MI_04#6&47611BB&0&0004' is no longer connected!
libusb: error [init_device] device '\\.\USB#VID_046D&PID_C52B&MI_02#6&2108CF30&1&0002' is no longer connected!
Loading embedded: bootcode4.bin
Device located successfully

phillipwgardner commented 1 year ago

Just wanted to chime in on this issue, having the same with rpiboot on Windows 11 laptop, USB 3 host interface with a CM4 module on a Waveshare IO board.

More verbose debugging showing a constant connect/disconnect by the USB because of a libusb problem.

Waiting for BCM2835/6/7/2711...
libusb: warning [windows_get_device_list] could not retrieve port number for device '\\.\USB#VID_1038&PID_202D&MI_00#2&228D4B4E&0&0000', skipping: [13] The data is invalid.
libusb: warning [windows_get_device_list] could not retrieve port number for device '\\.\USB#VID_1038&PID_202D#1&79F5D87&1&4784', skipping: [13] The data is invalid.
libusb: error [init_device] device '\\.\USB#VID_046D&PID_C52B&MI_01#6&2108CF30&1&0001' is no longer connected!
libusb: error [init_device] device '\\.\USB#VID_534D&PID_2109&MI_04#6&47611BB&0&0004' is no longer connected!
libusb: error [init_device] device '\\.\USB#VID_046D&PID_C52B&MI_02#6&2108CF30&1&0002' is no longer connected!
Loading embedded: bootcode4.bin
Device located successfully
Failed to open the requested device
libusb: warning [windows_get_device_list] could not retrieve port number for device '\\.\USB#VID_1038&PID_202D&MI_00#2&228D4B4E&0&0000', skipping: [13] The data is invalid.
libusb: warning [windows_get_device_list] could not retrieve port number for device '\\.\USB#VID_1038&PID_202D#1&79F5D87&1&4784', skipping: [13] The data is invalid.
libusb: error [init_device] device '\\.\USB#VID_046D&PID_C52B&MI_01#6&2108CF30&1&0001' is no longer connected!
libusb: error [init_device] device '\\.\USB#VID_534D&PID_2109&MI_04#6&47611BB&0&0004' is no longer connected!
libusb: error [init_device] device '\\.\USB#VID_046D&PID_C52B&MI_02#6&2108CF30&1&0002' is no longer connected!
Loading embedded: bootcode4.bin
Device located successfully

Same computer with Ubuntu and it works fine:

kim@GS75-Stealth-10SE:~$ rpiboot
RPIBOOT: build-date Jan 31 2022 version 0~20220315+git6fa2ec0+nowin-0ubuntu1 
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
Second stage boot server
Loading embedded: start4.elf
File read: start4.elf
Second stage boot server done
kim@GS75-Stealth-10SE:~$

akhileshmoghe commented 1 year ago

Just an update for someone facing this issue: Release: CM4 R1.1 / CM4S latest seems to have solved this repeated failing of rpiboot utility for CM4. I could successfully flash the RevPi CM4S module today.

timg236 commented 7 months ago

Closing since this has become a rather ad-hoc mix of intermittent USB failures on different boards.

Faizan4333 commented 4 months ago

Just change your USB port use the USB 3.0 ports instead of USB 2.0 if you're using desktop don't use the ports on the front panel instead use the ports present on the back.

JmartinezCID commented 4 months ago

when i encountered this issue the only thing i found that rectified it was removing anything from the usb ports on my computer. in my instance it was a wireless mouse dongle that i disconnected. nothing else connected to the pc but the medium for the cm4 to the pc.

raspberrypi / usbboot

Sending bootcode.bin repeatedly failing #36