ChromeOS 133 and later: UF2 boot drive not appearing

[dhalbert]

We (Adafruit) have had multiple reports recently that when a Chromebook is updated to ChromeOS 133 or later, it stops being able to see the UF2 boot drives on SAMD21 and SAMD51 boards.

I've reproduced this, on a vanilla N4020 Chromebook, though very occasionally I can get the drive to appear.

Non-SAMD boards like nRF52, Espressif, and RP2040 do still show their UF2 boot drives. So there is something different going on.

In the past, issues with ChromeOS have had more to do with allow/deny listing of USB devices, but I don't think that is what is going on here. /var/log/syslog seems to show it passes muster, but is never mounted.

Below are the logs from /var/log/syslog, first for a uf2-samx1 board (CPX) and second for an RP2040 Pi Pico.

@mmoskal et al: have you seen this kind of issue before? Thanks. I've tried various simple things to make the boot block more like a working bootloader, but that didn't help. I also turned off all modes but MSC. My next step would be to look at USB traces.

Circuit Playground Express (failed)

2025-04-03T19:22:30.528524Z INFO kernel: [ 1962.257011] usb 1-4: new full-speed USB device number 10 using xhci_hcd
2025-04-03T19:22:30.657003Z INFO kernel: [ 1962.384784] usb 1-4: New USB device found, idVendor=239a, idProduct=0018, bcdDevice=42.01
2025-04-03T19:22:30.657061Z INFO kernel: [ 1962.384812] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
2025-04-03T19:22:30.657074Z INFO kernel: [ 1962.384822] usb 1-4: Product: CPlay Express
2025-04-03T19:22:30.657082Z INFO kernel: [ 1962.384831] usb 1-4: Manufacturer: Adafruit Industries
2025-04-03T19:22:30.657090Z INFO kernel: [ 1962.384838] usb 1-4: SerialNumber: 146197CC50524641342E314AFF040C1E
2025-04-03T19:22:30.662197Z INFO kernel: [ 1962.391271] cdc_acm 1-4:1.0: ttyACM0: USB ACM device
2025-04-03T19:22:30.662256Z INFO kernel: [ 1962.391892] usb-storage 1-4:1.2: USB Mass Storage device detected
2025-04-03T19:22:30.663253Z INFO kernel: [ 1962.392330] scsi host0: usb-storage 1-4:1.2
2025-04-03T19:22:30.664122Z INFO kernel: [ 1962.393768] hid-generic 0003:239A:0018.0008: hiddev96,hidraw1: USB HID v1.00 Device [Adafruit Industries CPlay Express] on usb-0000:00:15.0-4/input3
2025-04-03T19:22:30.691191Z INFO usb_bouncer[10157]: Reporting metrics for /devices/pci0000:00/0000:00:15.0/usb1/1-4
2025-04-03T19:22:30.700249Z INFO usb_bouncer[10157]: Events at exceeded timer. Triggering a flush.
2025-04-03T19:22:30.853174Z INFO permission_broker[1701]: ProcessPath(/dev/bus/usb/001/010)
2025-04-03T19:22:30.853912Z WARNING permission_broker[1701]: CROS_USB_LOCATION had a value but was not enough to determine permissibility, falling back to legacy logic.
2025-04-03T19:22:30.859875Z INFO permission_broker[1701]: Found claimed interface with driver: cdc_acm
2025-04-03T19:22:30.860851Z INFO permission_broker[1701]: Found claimed interface with driver: cdc_acm
2025-04-03T19:22:30.861264Z INFO permission_broker[1701]: Found claimed interface with driver: usb-storage
2025-04-03T19:22:30.861687Z INFO permission_broker[1701]: Found claimed interface with driver: usbhid
2025-04-03T19:22:30.863213Z INFO permission_broker[1701]: Found allowable serial device, safe to claim.
2025-04-03T19:22:30.863250Z INFO permission_broker[1701]:   AllowConformingUsbDeviceRule: ALLOW_WITH_DETACH
2025-04-03T19:22:30.863356Z INFO permission_broker[1701]: Verdict for /dev/bus/usb/001/010: ALLOW_WITH_DETACH
2025-04-03T19:22:30.863626Z INFO permission_broker[1701]: ProcessPath(/dev/bus/usb/001/010)
2025-04-03T19:22:30.865077Z WARNING permission_broker[1701]: CROS_USB_LOCATION had a value but was not enough to determine permissibility, falling back to legacy logic.
2025-04-03T19:22:30.875891Z INFO permission_broker[1701]: Found claimed interface with driver: cdc_acm
2025-04-03T19:22:30.877703Z INFO permission_broker[1701]: Found claimed interface with driver: cdc_acm
2025-04-03T19:22:30.878123Z INFO permission_broker[1701]: Found claimed interface with driver: usb-storage
2025-04-03T19:22:30.878541Z INFO permission_broker[1701]: Found claimed interface with driver: usbhid
2025-04-03T19:22:30.879898Z INFO permission_broker[1701]: Found allowable serial device, safe to claim.
2025-04-03T19:22:30.879984Z INFO permission_broker[1701]:   AllowConformingUsbDeviceRule: ALLOW_WITH_DETACH
2025-04-03T19:22:30.880105Z INFO permission_broker[1701]: Verdict for /dev/bus/usb/001/010: ALLOW_WITH_DETACH
2025-04-03T19:22:31.709905Z NOTICE kernel: [ 1963.439247] scsi 0:0:0:0: Direct-Access     CPlay Ex press            1.00 PQ: 0 ANSI: 2
2025-04-03T19:22:31.711793Z NOTICE kernel: [ 1963.440606] sd 0:0:0:0: [sda] 16000 512-byte logical blocks: (8.19 MB/7.81 MiB)
2025-04-03T19:22:31.711819Z NOTICE kernel: [ 1963.440786] sd 0:0:0:0: [sda] Write Protect is off
2025-04-03T19:22:31.711825Z DEBUG kernel: [ 1963.440794] sd 0:0:0:0: [sda] Mode Sense: 0f 00 00 00
2025-04-03T19:22:31.711829Z ERR kernel: [ 1963.440966] sd 0:0:0:0: [sda] No Caching mode page found
2025-04-03T19:22:31.711833Z ERR kernel: [ 1963.440972] sd 0:0:0:0: [sda] Assuming drive cache: write through
2025-04-03T19:22:31.718588Z INFO kernel: [ 1963.447953]  sda:
2025-04-03T19:22:31.719571Z NOTICE kernel: [ 1963.449189] sd 0:0:0:0: [sda] Attached SCSI removable disk

Pi Pico (succeeded)

2025-04-03T19:26:32.329473Z INFO kernel: [ 2204.057966] usb 1-4: new full-speed USB device number 12 using xhci_hcd
2025-04-03T19:26:32.454913Z INFO kernel: [ 2204.184465] usb 1-4: New USB device found, idVendor=2e8a, idProduct=0003, bcdDevice= 1.00
2025-04-03T19:26:32.454993Z INFO kernel: [ 2204.184526] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
2025-04-03T19:26:32.455004Z INFO kernel: [ 2204.184538] usb 1-4: Product: RP2 Boot
2025-04-03T19:26:32.455092Z INFO kernel: [ 2204.184546] usb 1-4: Manufacturer: Raspberry Pi
2025-04-03T19:26:32.455104Z INFO kernel: [ 2204.184582] usb 1-4: SerialNumber: E0C912D24340
2025-04-03T19:26:32.457505Z INFO kernel: [ 2204.187057] usb-storage 1-4:1.0: USB Mass Storage device detected
2025-04-03T19:26:32.458524Z INFO kernel: [ 2204.187423] scsi host0: usb-storage 1-4:1.0
2025-04-03T19:26:32.488397Z INFO usb_bouncer[10968]: Reporting metrics for /devices/pci0000:00/0000:00:15.0/usb1/1-4
2025-04-03T19:26:32.496368Z INFO usb_bouncer[10968]: Events at exceeded timer. Triggering a flush.
2025-04-03T19:26:32.654136Z INFO permission_broker[1701]: ProcessPath(/dev/bus/usb/001/012)
2025-04-03T19:26:32.655988Z WARNING permission_broker[1701]: CROS_USB_LOCATION had a value but was not enough to determine permissibility, falling back to legacy logic.
2025-04-03T19:26:32.664461Z INFO permission_broker[1701]: Found claimed interface with driver: usb-storage
2025-04-03T19:26:32.668670Z INFO permission_broker[1701]: Found allowable storage interface.
2025-04-03T19:26:32.669455Z INFO permission_broker[1701]: Found only detachable interface(s), safe to claim.
2025-04-03T19:26:32.683199Z INFO permission_broker[1701]: Found allowable serial device, safe to claim.
2025-04-03T19:26:32.683252Z INFO permission_broker[1701]:   AllowConformingUsbDeviceRule: ALLOW_WITH_DETACH
2025-04-03T19:26:32.683381Z INFO permission_broker[1701]: Verdict for /dev/bus/usb/001/012: ALLOW_WITH_DETACH
2025-04-03T19:26:32.683663Z INFO permission_broker[1701]: ProcessPath(/dev/bus/usb/001/012)
2025-04-03T19:26:32.685434Z WARNING permission_broker[1701]: CROS_USB_LOCATION had a value but was not enough to determine permissibility, falling back to legacy logic.
2025-04-03T19:26:32.693147Z INFO permission_broker[1701]: Found claimed interface with driver: usb-storage
2025-0
4-03T19:26:32.696815Z INFO permission_broker[1701]: Found allowable storage interface.
2025-04-03T19:26:32.697622Z INFO permission_broker[1701]: Found only detachable interface(s), safe to claim.
2025-04-03T19:26:32.699565Z INFO permission_broker[1701]: Found allowable serial device, safe to claim.
2025-04-03T19:26:32.699722Z INFO permission_broker[1701]:   AllowConformingUsbDeviceRule: ALLOW_WITH_DETACH
2025-04-03T19:26:32.699910Z INFO permission_broker[1701]: Verdict for /dev/bus/usb/001/012: ALLOW_WITH_DETACH
2025-04-03T19:26:33.448361Z ERR DPTF[1691]: ERROR:[<LINUX>GetPowerSliderMode@esif_uf_sensor_manager_os_lin.c#477]<1743708393448 ms>: Sysfs Read failed at path: /sys/devices/system/cpu/cpu0/cpufreq/type 
2025-04-03T19:26:33.501884Z NOTICE kernel: [ 2205.231182] scsi 0:0:0:0: Direct-Access     RPI      RP2              1    PQ: 0 ANSI: 2
2025-04-03T19:26:33.502774Z NOTICE kernel: [ 2205.232050] sd 0:0:0:0: [sda] 262144 512-byte logical blocks: (134 MB/128 MiB)
2025-04-03T19:26:33.502784Z NOTICE kernel: [ 2205.232407] sd 0:0:0:0: [sda] Write Protect is off
2025-04-03T19:26:33.502787Z DEBUG kernel: [ 2205.232411] sd 0:0:0:0: [sda] Mode Sense: 03 00 00 00
2025-04-03T19:26:33.503777Z ERR kernel: [ 2205.232762] sd 0:0:0:0: [sda] No Caching mode page found
2025-04-03T19:26:33.503787Z ERR kernel: [ 2205.232766] sd 0:0:0:0: [sda] Assuming drive cache: write through
2025-04-03T19:26:33.509791Z INFO kernel: [ 2205.238568]  sda: sda1
2025-04-03T19:26:33.512096Z NOTICE kernel: [ 2205.240160] sd 0:0:0:0: [sda] Attached SCSI removable disk

[mmoskal]

From what I can see in the trace, for Pico it finds partition sda1 and for CPX it doesn't. Maybe something about partition table? Otherwise I guess try doing a binary compare of the drives. Sorry...

[dhalbert]

Thanks @mmoskal. I also tried using our nRF UF2 bootloader, which presents as /dev/sda, not sda1, and it also works. I made some changes to the boot partition in the SAMD bootloader to get closer to the nRF version, and it did not help. The USB enumeration seems fine.

I tested in Developer mode in ChromeOS. On the command line, sudo mount /dev/sda mountpoint will just hang for SAMD UF2, and works for the others.

I've opened an issue on ChromeOS: https://issuetracker.google.com/issues/409576876 .

[tannewt]

A Beagle trace may help understand the differences at the USB level.

[dhalbert]

I have Beagle traces, but at first glance they are not that interesting. As described in the ChromeOS bug, the mount command hangs -- there didn't seem to be a problem reading blocks from the MSC.

[gilles-duboscq]

I am seeing something similar on fedora (kernel 6.14.6-300.fc42.x86_64) and after looking at a few usbmon captures i think communication with the bootloader gets stuck after it receives an unexpected scsi command (0xc3).
I have confirmed using a machine running an older distribution and kernel that this scsi command doesn't appear and the boot drive appears properly.
I also noticed that the boot drive from CircuitPython seems unaffected, it also gets the 0xc3 command, doesn't handle it but seems to fail more gracefully.
I have attached the traces bellow to show the difference in behaviour.
In both cases after the c3 command, the host tries to read 512 bytes, CirtcuitPy answers with URB status: Broken pipe (-EPIPE) (-32) and no data, uf2-samdx1 answers with URB status: Remote I/O error (-EREMOTEIO) (-121) and data for a command status wrapper.
Note that in the uf2-samdx1 trace the host seems to want to read more data but there is never any response from the bootloader.

c3-circuitpy.txt
c3-uf2-samdx1.txt

[dhalbert]

@gilles-duboscq These are interesting traces. Below are my traces, in .tdc (Beagle format), .csv (exported from Beagle), .pcapng, and .txt (.pcapng parsed in wireshark ). The metrom0 trace files are with uf2-samdx1 and show the problem; the nrf52840 traces are from another UF2 bootloader that does not show the problem.

The Beagle .csv files were exported from Beagle's Data Center software. I then used https://github.com/tannewt/python-pcapng/blob/master/convert_totalphase_csv.py to convert them to .pcapng and brought them into wiresharek.

In my traces, I do not see the 0xc3 commands from the host that you see in your traces. However, I do see that 0xc3 often appears as the first byte in IN packets. I'm not sure what to make of that. Do you think perhaps there is some bad logging of the packets going on?

I recently got a Cynthion USB capture device but have not attempted to use it yet.

UF2-problems.zip

[dhalbert]

Google engineers asked us for USB traces in https://issuetracker.google.com/issues/409576876, but have not yet responded further.