CM usbboot fails

172 views
Skip to first unread message

Nathaniel McAuliffe

unread,
Oct 23, 2020, 9:48:28 PM10/23/20
to ClusterHAT
I am running the 64bit CBRIDGE image on a 3B+ and attempting to boot to the 64bit lite image on CM3s. I see some files being loaded but the device never finishes booting.

==> /var/log/kern.log <==
Oct 24 02:47:20 gru kernel: [ 1385.392375] usb 1-1.1.2.4: new high-speed USB device number 19 using dwc_otg
Oct 24 02:47:20 gru kernel: [ 1385.524769] usb 1-1.1.2.4: config index 0 descriptor too short (expected 55, got 32)
Oct 24 02:47:20 gru kernel: [ 1385.525154] usb 1-1.1.2.4: New USB device found, idVendor=0a5c, idProduct=2764, bcdDevice
= 0.00
Oct 24 02:47:20 gru kernel: [ 1385.525162] usb 1-1.1.2.4: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Oct 24 02:47:20 gru kernel: [ 1385.525174] usb 1-1.1.2.4: Product: BCM2710 Boot
Oct 24 02:47:20 gru kernel: [ 1385.525181] usb 1-1.1.2.4: Manufacturer: Broadcom

==> /var/log/daemon.log <==
Oct 24 02:47:20 gru rpiboot[1100]: Device located successfully
Oct 24 02:47:20 gru rpiboot[1100]: libusb: error [udev_hotplug_event] ignoring udev action bind
Oct 24 02:47:21 gru rpiboot[1100]: Initialised device correctly
Oct 24 02:47:21 gru rpiboot[1100]: Found serial number 0
Oct 24 02:47:21 gru rpiboot[1100]: Sending bootcode.bin
Oct 24 02:47:21 gru rpiboot[1100]: libusb_bulk_transfer sent 24 bytes; returned 0
Oct 24 02:47:21 gru rpiboot[1100]: Writing 51992 bytes
Oct 24 02:47:21 gru rpiboot[1100]: libusb_bulk_transfer sent 51992 bytes; returned 0
Oct 24 02:47:22 gru rpiboot[1100]: Successful read 4 bytes
Oct 24 02:47:23 gru rpiboot[1100]: Waiting for BCM2835/6/7/2711...
Oct 24 02:47:23 gru rpiboot[1100]: Device located successfully

==> /var/log/kern.log <==
Oct 24 02:47:23 gru kernel: [ 1388.754520] usb 1-1.1.2.4: USB disconnect, device number 19
Oct 24 02:47:23 gru kernel: [ 1388.976361] usb 1-1.1.2.4: new full-speed USB device number 20 using dwc_otg
Oct 24 02:47:23 gru kernel: [ 1389.079600] usb 1-1.1.2.4: not running at top speed; connect to a high speed hub
Oct 24 02:47:23 gru kernel: [ 1389.089481] usb 1-1.1.2.4: New USB device found, idVendor=0a5c, idProduct=2764, bcdDevice
= 0.00
Oct 24 02:47:23 gru kernel: [ 1389.089492] usb 1-1.1.2.4: New USB device strings: Mfr=1, Product=2, SerialNumber=1
Oct 24 02:47:23 gru kernel: [ 1389.089499] usb 1-1.1.2.4: Product: BCM2710 Boot
Oct 24 02:47:23 gru kernel: [ 1389.089506] usb 1-1.1.2.4: Manufacturer: Broadcom
Oct 24 02:47:23 gru kernel: [ 1389.089513] usb 1-1.1.2.4: SerialNumber: Broadcom

==> /var/log/daemon.log <==
Oct 24 02:47:24 gru rpiboot[1100]: libusb: error [udev_hotplug_event] ignoring udev action bind
Oct 24 02:47:24 gru rpiboot[1100]: Failed to open the requested device
Oct 24 02:47:24 gru rpiboot[1100]: Device located successfully
Oct 24 02:47:25 gru rpiboot[1100]: Initialised device correctly
Oct 24 02:47:25 gru rpiboot[1100]: Found serial number 1
Oct 24 02:47:25 gru rpiboot[1100]: Second stage boot server
Oct 24 02:47:25 gru rpiboot[1100]: Received message GetFileSize: autoboot.txt
Oct 24 02:47:25 gru rpiboot[1100]: libusb_bulk_transfer sent 0 bytes; returned 0
Oct 24 02:47:25 gru rpiboot[1100]: Cannot open file autoboot.txt
Oct 24 02:47:25 gru rpiboot[1100]: Received message GetFileSize: config.txt
Oct 24 02:47:25 gru rpiboot[1100]: File size = 1906 bytes
Oct 24 02:47:25 gru rpiboot[1100]: Received message ReadFile: config.txt
Oct 24 02:47:25 gru rpiboot[1100]: File read: config.txt
Oct 24 02:47:25 gru rpiboot[1100]: libusb_bulk_transfer sent 1906 bytes; returned 0
Oct 24 02:47:25 gru rpiboot[1100]: Received message GetFileSize: recovery.elf
Oct 24 02:47:25 gru rpiboot[1100]: libusb_bulk_transfer sent 0 bytes; returned 0
Oct 24 02:47:25 gru rpiboot[1100]: Cannot open file recovery.elf
Oct 24 02:47:25 gru rpiboot[1100]: Received message GetFileSize: start.elf
Oct 24 02:47:25 gru rpiboot[1100]: File size = 2949600 bytes
Oct 24 02:47:25 gru rpiboot[1100]: Received message ReadFile: start.elf
Oct 24 02:47:25 gru rpiboot[1100]: File read: start.elf
Oct 24 02:47:31 gru rpiboot[1100]: libusb_bulk_transfer sent 2949600 bytes; returned 0
Oct 24 02:47:31 gru rpiboot[1100]: Received message GetFileSize: fixup.dat
Oct 24 02:47:31 gru rpiboot[1100]: File size = 7289 bytes
Oct 24 02:47:31 gru rpiboot[1100]: Received message ReadFile: fixup.dat
Oct 24 02:47:31 gru rpiboot[1100]: File read: fixup.dat
Oct 24 02:47:31 gru rpiboot[1100]: libusb_bulk_transfer sent 7289 bytes; returned 0

==> /var/log/kern.log <==
Oct 24 02:47:38 gru kernel: [ 1403.831081] WARN::dwc_otg_hcd_urb_dequeue:639: Timed out waiting for FSM NP transfer to c
omplete on 2
Oct 24 02:47:50 gru kernel: [ 1415.832362] WARN::dwc_otg_hcd_urb_dequeue:639: Timed out waiting for FSM NP transfer to c
omplete on 4

Chris Burton

unread,
Oct 24, 2020, 4:59:54 AM10/24/20
to ClusterHAT
Hi,
I am running the 64bit CBRIDGE image on a 3B+ and attempting to boot to the 64bit lite image on CM3s. I see some files being loaded but the device never finishes booting.

To confirm it's a CM3 not CM3+?

Is the CM3 in a ClusterCTRL boards (if so which), CMIO3 board, or something else?

How is the CM3 carrier and 3B+ powered?

Have you tried a different USB data cable between 3B+ and CM3 carrier?

What is the output of "clusterctrl status;lsusb -t" on the 3B+ after it fails to boot?

Do you have a kernel oops in /var/log/kern.log before you the "WARN::dwc_otg_hcd_urb_dequeue" lines, if so can you paste it here?

After you see the error does the onboard USB network still work?

If you run the 32bit image on the controller does the CM3 boot (with either 32 or 64 bit usbboot)?

Chris. 

Ciprian Manea

unread,
Oct 24, 2020, 5:12:44 AM10/24/20
to clust...@googlegroups.com
Well, 64bit is not yet ready for prime time

--
You received this message because you are subscribed to the Google Groups "ClusterHAT" group.
To unsubscribe from this group and stop receiving emails from it, send an email to clusterhat+...@googlegroups.com.
To view this discussion on the web, visit https://groups.google.com/d/msgid/clusterhat/ccb18c25-7e82-4f1b-9e7e-bd19e5ba0e13n%40googlegroups.com.

Nathaniel McAuliffe

unread,
Oct 24, 2020, 9:00:17 AM10/24/20
to ClusterHAT
My bad, it is a CM3+, using a  ClusterCTRL Triple.
The triple has a 2.5A power supply. The 3B+ is the only thing on a hub right now,  should be getting its full 2.5A. I'm looking for a single hub that can power both.
I am using the included USB data cables. I should note that this all worked well with the 32bit and 64bit versions a few months ago. The only thing that changed on the 3B+ side was I switched to USB boot (msata).

pi@gru:~ $ clusterctrl status;lsusb -t
clusterhat:False
clusterctrl:1
maxpi:3
throttled:0x50000
ctrl_bus:20:11:3
ctrl20:FW:1.3 ADC1:5162mV T1:19.67C
p1:1
u1:1
p2:0
u2:1
p3:0
u3:1
/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=dwc_otg/1p, 480M
    |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/4p, 480M
        |__ Port 1: Dev 3, If 0, Class=Hub, Driver=hub/3p, 480M
            |__ Port 2: Dev 21, If 0, Class=Hub, Driver=hub/4p, 480M
                |__ Port 4: Dev 24, If 0, Class=Vendor Specific Class, Driver=usbfs, 12M
                |__ Port 1: Dev 22, If 0, Class=, Driver=i2c-tiny-usb, 1.5M
            |__ Port 1: Dev 6, If 0, Class=Vendor Specific Class, Driver=lan78xx, 480M
        |__ Port 2: Dev 8, If 0, Class=Mass Storage, Driver=usb-storage, 480M
        |__ Port 3: Dev 4, If 0, Class=Human Interface Device, Driver=usbhid, 12M
        |__ Port 3: Dev 4, If 1, Class=Human Interface Device, Driver=usbhid, 12M
        |__ Port 3: Dev 4, If 2, Class=Human Interface Device, Driver=usbhid, 12M



new log output, immediately following p1 on:

pi@gru:~ $ clusterctrl on p1
pi@gru:~ $ tail -f /var/log/daemon.log /var/log/kern.log
==> /var/log/daemon.log <==
Oct 24 13:51:31 gru systemd[3712]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Oct 24 13:51:31 gru systemd[3712]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Oct 24 13:51:31 gru systemd[3712]: Reached target Sockets.
Oct 24 13:51:31 gru systemd[3712]: Reached target Basic System.
Oct 24 13:51:31 gru systemd[3712]: Reached target Default.
Oct 24 13:51:31 gru systemd[3712]: Startup finished in 298ms.
Oct 24 13:51:31 gru systemd[1]: Started User Manager for UID 1000.
Oct 24 13:51:31 gru systemd[1]: Started Session c3 of user pi.
Oct 24 13:51:52 gru rpiboot[1100]: libusb: error [udev_hotplug_event] ignoring udev action bind
Oct 24 13:51:52 gru rpiboot[1100]: libusb: error [udev_hotplug_event] ignoring udev action bind

==> /var/log/kern.log <==
Oct 24 13:51:52 gru kernel: [41257.733255] hub 1-1.1.2:1.0: 4 ports detected
Oct 24 13:51:52 gru kernel: [41258.035079] usb 1-1.1.2.1: new low-speed USB device number 22 using dwc_otg
Oct 24 13:51:52 gru kernel: [41258.142474] usb 1-1.1.2.1: New USB device found, idVendor=3171, idProduct=0014, bcdDevice
= 1.05
Oct 24 13:51:52 gru kernel: [41258.142485] usb 1-1.1.2.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Oct 24 13:51:52 gru kernel: [41258.142492] usb 1-1.1.2.1: Product: Cluster CTRL
Oct 24 13:51:52 gru kernel: [41258.142499] usb 1-1.1.2.1: Manufacturer: 8086 Consultancy
Oct 24 13:51:52 gru kernel: [41258.143654] i2c-tiny-usb 1-1.1.2.1:1.0: version 1.05 found at bus 001 address 022
Oct 24 13:51:52 gru kernel: [41258.145181] i2c i2c-11: connected i2c-tiny-usb device
Oct 24 13:51:53 gru kernel: [41259.056038] Under-voltage detected! (0x00050005)
Oct 24 13:51:57 gru kernel: [41263.103112] Voltage normalised (0x00000000)
Oct 24 13:52:27 gru kernel: [41293.247230] usb 1-1.1.2.4: new high-speed USB device number 23 using dwc_otg
Oct 24 13:52:28 gru kernel: [41293.347664] usb 1-1.1.2.4: config index 0 descriptor too short (expected 55, got 32)
Oct 24 13:52:28 gru kernel: [41293.348087] usb 1-1.1.2.4: New USB device found, idVendor=0a5c, idProduct=2764, bcdDevice
= 0.00
Oct 24 13:52:28 gru kernel: [41293.348095] usb 1-1.1.2.4: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Oct 24 13:52:28 gru kernel: [41293.348102] usb 1-1.1.2.4: Product: BCM2710 Boot
Oct 24 13:52:28 gru kernel: [41293.348109] usb 1-1.1.2.4: Manufacturer: Broadcom

==> /var/log/daemon.log <==
Oct 24 13:52:28 gru rpiboot[1100]: Device located successfully
Oct 24 13:52:28 gru rpiboot[1100]: libusb: error [udev_hotplug_event] ignoring udev action bind
Oct 24 13:52:29 gru rpiboot[1100]: Initialised device correctly
Oct 24 13:52:29 gru rpiboot[1100]: Found serial number 0
Oct 24 13:52:29 gru rpiboot[1100]: Sending bootcode.bin
Oct 24 13:52:29 gru rpiboot[1100]: libusb_bulk_transfer sent 24 bytes; returned 0
Oct 24 13:52:29 gru rpiboot[1100]: Writing 51992 bytes
Oct 24 13:52:29 gru rpiboot[1100]: libusb_bulk_transfer sent 51992 bytes; returned 0
Oct 24 13:52:30 gru rpiboot[1100]: Successful read 4 bytes
Oct 24 13:52:31 gru rpiboot[1100]: Waiting for BCM2835/6/7/2711...
Oct 24 13:52:31 gru rpiboot[1100]: Device located successfully

==> /var/log/kern.log <==
Oct 24 13:52:31 gru kernel: [41296.601639] usb 1-1.1.2.4: USB disconnect, device number 23
Oct 24 13:52:31 gru kernel: [41296.823247] usb 1-1.1.2.4: new full-speed USB device number 24 using dwc_otg
Oct 24 13:52:31 gru kernel: [41296.926594] usb 1-1.1.2.4: not running at top speed; connect to a high speed hub
Oct 24 13:52:31 gru kernel: [41296.936603] usb 1-1.1.2.4: New USB device found, idVendor=0a5c, idProduct=2764, bcdDevice
= 0.00
Oct 24 13:52:31 gru kernel: [41296.936614] usb 1-1.1.2.4: New USB device strings: Mfr=1, Product=2, SerialNumber=1
Oct 24 13:52:31 gru kernel: [41296.936622] usb 1-1.1.2.4: Product: BCM2710 Boot
Oct 24 13:52:31 gru kernel: [41296.936629] usb 1-1.1.2.4: Manufacturer: Broadcom
Oct 24 13:52:31 gru kernel: [41296.936635] usb 1-1.1.2.4: SerialNumber: Broadcom

==> /var/log/daemon.log <==
Oct 24 13:52:31 gru rpiboot[1100]: libusb: error [udev_hotplug_event] ignoring udev action bind
Oct 24 13:52:32 gru rpiboot[1100]: Failed to open the requested device
Oct 24 13:52:32 gru rpiboot[1100]: Device located successfully
Oct 24 13:52:33 gru rpiboot[1100]: Initialised device correctly
Oct 24 13:52:33 gru rpiboot[1100]: Found serial number 1
Oct 24 13:52:33 gru rpiboot[1100]: Second stage boot server
Oct 24 13:52:33 gru rpiboot[1100]: Received message GetFileSize: autoboot.txt
Oct 24 13:52:33 gru rpiboot[1100]: libusb_bulk_transfer sent 0 bytes; returned 0
Oct 24 13:52:33 gru rpiboot[1100]: Cannot open file autoboot.txt
Oct 24 13:52:33 gru rpiboot[1100]: Received message GetFileSize: config.txt
Oct 24 13:52:33 gru rpiboot[1100]: File size = 1906 bytes
Oct 24 13:52:33 gru rpiboot[1100]: Received message ReadFile: config.txt
Oct 24 13:52:33 gru rpiboot[1100]: File read: config.txt
Oct 24 13:52:33 gru rpiboot[1100]: libusb_bulk_transfer sent 1906 bytes; returned 0
Oct 24 13:52:33 gru rpiboot[1100]: Received message GetFileSize: recovery.elf
Oct 24 13:52:33 gru rpiboot[1100]: libusb_bulk_transfer sent 0 bytes; returned 0
Oct 24 13:52:33 gru rpiboot[1100]: Cannot open file recovery.elf
Oct 24 13:52:33 gru rpiboot[1100]: Received message GetFileSize: start.elf
Oct 24 13:52:33 gru rpiboot[1100]: File size = 2949600 bytes
Oct 24 13:52:33 gru rpiboot[1100]: Received message ReadFile: start.elf
Oct 24 13:52:33 gru rpiboot[1100]: File read: start.elf
Oct 24 13:52:39 gru rpiboot[1100]: libusb_bulk_transfer sent 2949600 bytes; returned 0
Oct 24 13:52:39 gru rpiboot[1100]: Received message GetFileSize: fixup.dat
Oct 24 13:52:39 gru rpiboot[1100]: File size = 7289 bytes
Oct 24 13:52:39 gru rpiboot[1100]: Received message ReadFile: fixup.dat
Oct 24 13:52:39 gru rpiboot[1100]: File read: fixup.dat
Oct 24 13:52:39 gru rpiboot[1100]: libusb_bulk_transfer sent 7289 bytes; returned 0

==> /var/log/kern.log <==
Oct 24 13:53:58 gru kernel: [41383.659898] WARN::dwc_otg_hcd_urb_dequeue:639: Timed out waiting for FSM NP transfer to c
omplete on 1
Oct 24 13:54:22 gru kernel: [41407.662032] WARN::dwc_otg_hcd_urb_dequeue:639: Timed out waiting for FSM NP transfer to c
omplete on 6
Oct 24 13:54:50 gru kernel: [41435.664165] WARN::dwc_otg_hcd_urb_dequeue:639: Timed out waiting for FSM NP transfer to c
omplete on 0
Oct 24 13:55:18 gru kernel: [41463.666297] WARN::dwc_otg_hcd_urb_dequeue:639: Timed out waiting for FSM NP transfer to c
omplete on 1

I will hopefully be able to try some different combos later today.

Chris Burton

unread,
Oct 24, 2020, 9:35:59 AM10/24/20
to ClusterHAT
Hi,
My bad, it is a CM3+, using a  ClusterCTRL Triple.
The triple has a 2.5A power supply. The 3B+ is the only thing on a hub right now,  should be getting its full 2.5A. I'm looking for a single hub that can power both.
I am using the included USB data cables. I should note that this all worked well with the 32bit and 64bit versions a few months ago. The only thing that changed on the 3B+ side was I switched to USB boot (msata).

Thanks for the additional info - both the status and log output are showing the Pi3 has undervoltage issue so I'd advise looking at that first.

To test you could try with the Triple and single CM3+ powered via the hub and the 3B+ on the 2.5A PSU to see if you can get it to boot OK that way but you obviously wouldn't get to see any power issue the CM3+  might be having until after it's booted.

Chris.

Peter Cross

unread,
Oct 24, 2020, 12:03:35 PM10/24/20
to clust...@googlegroups.com
Highly recommend the Anker USB power hubs on Amazon. 

Anker 40W 5-Port USB Wall Charger, PowerPort 5 for iPhone XS / XS Max / XR / X / 8 / 7 / 6 / Plus, iPad Pro / Air 2 / mini, Galaxy S9 / S8 / Edge / Plus, Note 8 / 7, LG, Nexus, HTC and More, Black (AK-A2124111) https://smile.amazon.com/dp/B00VH8ZW02/ref=cm_sw_r_cp_api_i_bbfLFbXYG539C 

Sent from my iPhone

On Oct 24, 2020, at 08:36, Chris Burton <bur...@gmail.com> wrote:


--
You received this message because you are subscribed to the Google Groups "ClusterHAT" group.
To unsubscribe from this group and stop receiving emails from it, send an email to clusterhat+...@googlegroups.com.

Nathaniel McAuliffe

unread,
Oct 24, 2020, 6:49:34 PM10/24/20
to ClusterHAT
I switched power supplies and same thing. Guess I'll wait for the new power supply.

@pjc - that is similar to the one I ordered this morning. Thank you for confirming my choice!

Peter Cross

unread,
Oct 24, 2020, 7:24:02 PM10/24/20
to clust...@googlegroups.com
I run all my pi’s off of either the official RPi PS or Anker’s power bricks for my clusters. 

Sent from my iPhone

On Oct 24, 2020, at 17:49, Nathaniel McAuliffe <nathaniel...@gmail.com> wrote:

I switched power supplies and same thing. Guess I'll wait for the new power supply.

Nathaniel McAuliffe

unread,
Oct 26, 2020, 8:27:10 PM10/26/20
to ClusterHAT
Power supply replaced, same issue.

Nathaniel McAuliffe

unread,
Oct 27, 2020, 11:10:54 AM10/27/20
to ClusterHAT
I switched back to using the sdcard and now its working with the same 64-bit image. Something is not right when pulling the image from the msata drive.

Chris Burton

unread,
Oct 29, 2020, 8:41:58 AM10/29/20
to ClusterHAT
Hi,
I switched back to using the sdcard and now its working with the same 64-bit image. Something is not right when pulling the image from the msata drive.

Have you checked to see if the power supply change has fixed the power issues on the Pi ( "vcgencmd get_throttled" should output 0x0 - also shown in "clusterctrl status" output)? Does you mSATA require additional power?

Chris.

Nathaniel McAuliffe

unread,
Oct 29, 2020, 10:54:01 AM10/29/20
to ClusterHAT
Looks OK to me:

pi@gru:~ $ vcgencmd get_throttled
throttled=0x0
pi@gru:~ $ lsusb
Bus 001 Device 004: ID 046d:c52b Logitech, Inc. Unifying Receiver
Bus 001 Device 020: ID 174c:0850 ASMedia Technology Inc.
Bus 001 Device 022: ID 3171:0014
Bus 001 Device 021: ID 05e3:0608 Genesys Logic, Inc. Hub
Bus 001 Device 006: ID 0424:7800 Standard Microsystems Corp.
Bus 001 Device 003: ID 0424:2514 Standard Microsystems Corp. USB 2.0 Hub
Bus 001 Device 002: ID 0424:2514 Standard Microsystems Corp. USB 2.0 Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

pi@gru:~ $ clusterctrl status
clusterhat:False
clusterctrl:1
maxpi:3
throttled:0x0
ctrl_bus:20:11:3
ctrl20:FW:1.3 ADC1:5143mV T1:17.21C
p1:0

u1:1
p2:0
u2:1
p3:0
u3:1
Reply all
Reply to author
Forward
0 new messages