raspberrypi / rpi-eeprom

Installation scripts and binaries for the Raspberry Pi 4 and Raspberry Pi 5 bootloader EEPROMs
https://www.raspberrypi.com/documentation/computers/raspberry-pi.html#raspberry-pi-boot-eeprom
Other
1.26k stars 201 forks source link

RPI4 4GB won't enumerate JMicron 567 IC based external HDD #361

Closed borisbme closed 3 years ago

borisbme commented 3 years ago

Hi! I have an issue with the RPI4 and JMicron 567 based external HDDs

Some data first:

I boot from a 16 GB SD card NAME FSTYPE LABEL UUID FSAVAIL FSUSE% MOUNTPOINT mmcblk0
├─mmcblk0p1 vfat boot 5DE4-665C 204M 19% /boot └─mmcblk0p2 ext4 rootfs 7295bbc3-bbc2-4267-9fa0-099e10ef5bf0 12.2G 11% /

The OS is: PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian

Kernel verison: Linux raspberrypi 5.10.60-v8+ #1449 SMP PREEMPT Wed Aug 25 15:01:33 BST 2021 aarch64 GNU/Linux

The EEPROM version: BOOTLOADER: up to date CURRENT: Tue 6 Jul 10:44:53 UTC 2021 (1625568293) LATEST: Tue 6 Jul 10:44:53 UTC 2021 (1625568293) RELEASE: stable (/lib/firmware/raspberrypi/bootloader/stable) Use raspi-config to change the release.

VL805_FW: Using bootloader EEPROM VL805: up to date CURRENT: 000138a1 LATEST: 000138a1

The EEPROM config: [all] BOOT_UART=1 WAKE_ON_GPIO=1 POWER_OFF_ON_HALT=0 USB_MSD_PWR_OFF_TIME=0

The UART Boot log: =~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2021.09.21 23:51:25 =~=~=~=~=~=~=~=~=~=~=~= [ 1305.099741] reboot: Restarting system

PM_RSTS: 0x00000020 RPi: BOOTLOADER release VERSION:c258ef8f DATE: Jul 6 2021 TIME: 11:44:56 BOOTMODE: 0x00000006 part: 0 BUILD_TIMESTAMP=1625568293 0xbe3321ed 0x00c03114 0x000cb235 PM_RSTS: 0x00000020 part 00000000 reset_info 00000000 uSD voltage 3.3V Initialising SDRAM 'Samsung' 16Gb x2 total-size: 32 Gbit 3200 XHCI-STOP xHC ver: 256 HCS: 05000420 fc000031 00e70004 HCC: 002841eb USBSTS 1 xHC ver: 256 HCS: 05000420 fc000031 00e70004 HCC: 002841eb xHC ports 5 slots 32 intrs 4 Boot mode: SD (01) order f4 SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080 SD HOST: 250000000 CTL0: 0x00000f00 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080 OCR c0ff8000 [19] CID: 00035344534331364780ac93cb35012c CSD: 400e00325b59000076b27f800a404000 SD: bus-width: 4 spec: 2 SCR: 0x02358443 0x00000000 SD HOST: 250000000 CTL0: 0x00000f04 BUS: 50000000 Hz actual: 41666666 HZ div: 6 (3) status: 0x1fff0000 delay: 2 MBR: 0x00002000, 524288 type: 0x0c MBR: 0x00082000,30583808 type: 0x83 MBR: 0x00000000, 0 type: 0x00 MBR: 0x00000000, 0 type: 0x00 Trying partition: 0 lba: 8192 oem: 'mkfs.fat' volume: ' boot ' rsc 32 fat-sectors 4033 c-count 516190 c-size 1 r-dir 2 r-sec 0 r-entries 0 FAT32 clusters 516190 PM_RSTS: 0x00000020 Trying partition: 0 lba: 8192 oem: 'mkfs.fat' volume: ' boot ' rsc 32 fat-sectors 4033 c-count 516190 c-size 1 r-dir 2 r-sec 0 r-entries 0 FAT32 clusters 516190 Read config.txt bytes 1844 hnd 0x00000000 Read start4.elf bytes 2240352 hnd 0x00000000 Read fixup4.dat bytes 5407 hnd 0x00000000 Firmware: 67615e950e1e28b92dfae6303cf7a8b879a8908f Aug 31 2021 14:52:47 0x00c03114 0x00000000 0x00000fff MEM GPU: 76 ARM: 948 TOTAL: 1024 Starting start4.elf @ 0xfec00200 partition 0 +

[ 0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd083] [ 0.000000] Linux version 5.10.60-v8+ (dom@buildbot) (aarch64-linux-gnu-gcc-8 (Ubuntu/Linaro 8.4.0-3ubuntu1) 8.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1449 SMP PREEMPT Wed Aug 25 15:01:33 BST 2021 [ 0.000000] random: fast init done [ 0.000000] Machine model: Raspberry Pi 4 Model B Rev 1.4 [ 0.000000] efi: UEFI not found. [ 0.000000] Reserved memory: created CMA memory pool at 0x000000001ac00000, size 320 MiB [ 0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000000000-0x000000003fffffff] [ 0.000000] DMA32 [mem 0x0000000040000000-0x00000000fbffffff] [ 0.000000] Normal empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000000000-0x000000003b3fffff] [ 0.000000] node 0: [mem 0x0000000040000000-0x00000000fbffffff] [ 0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000000fbffffff] [ 0.000000] percpu: Embedded 32 pages/cpu s91224 r8192 d31656 u131072 [ 0.000000] Detected PIPT I-cache on CPU0 [ 0.000000] CPU features: detected: Spectre-v2 [ 0.000000] CPU features: detected: Spectre-v4 [ 0.000000] CPU features: detected: ARM errata 1165522, 1319367, or 1530923 [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 996912 [ 0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=1 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 smsc95xx.macaddr=E4:5F:01:25:98:9E vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 console=ttyS0,115200 console=tty1 root=PARTUUID=ec4bf566-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait [ 0.000000] Kernel parameter elevator= does not have any effect anymore. [ 0.000000] Please use sysfs to set IO scheduler for individual devices. [ 0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear) [ 0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear) [ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off [ 0.000000] software IO TLB: mapped [mem 0x0000000037400000-0x000000003b400000] (64MB) [ 0.000000] Memory: 3554648K/4050944K available (11136K kernel code, 1946K rwdata, 3984K rodata, 3776K init, 1260K bss, 168616K reserved, 327680K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] ftrace: allocating 36750 entries in 144 pages [ 0.000000] ftrace: allocated 144 pages with 2 groups [ 0.000000] rcu: Preemptible hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=4. [ 0.000000] Trampoline variant of Tasks RCU enabled. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies. [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 [ 0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0 [ 0.000000] GIC: Using split EOI/Deactivate mode [ 0.000000] random: get_random_bytes called from start_kernel+0x3b0/0x570 with crng_init=1 [ 0.000000] arch_timer: cp15 timer(s) running at 54.00MHz (phys). [ 0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns [ 0.000006] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns [ 0.000248] Console: colour dummy device 80x25 [ 0.000781] printk: console [tty1] enabled [ 0.000839] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=216000) [ 0.000880] pid_max: default: 32768 minimum: 301 [ 0.001027] LSM: Security Framework initializing [ 0.001254] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear) [ 0.001323] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear) [ 0.002580] cgroup: Disabling memory control group subsystem [ 0.004835] rcu: Hierarchical SRCU implementation. [ 0.005854] EFI services will not be available. [ 0.006347] smp: Bringing up secondary CPUs ... [ 0.007286] Detected PIPT I-cache on CPU1 [ 0.007357] CPU1: Booted secondary processor 0x0000000001 [0x410fd083] [ 0.008474] Detected PIPT I-cache on CPU2 [ 0.008522] CPU2: Booted secondary processor 0x0000000002 [0x410fd083] [ 0.009566] Detected PIPT I-cache on CPU3 [ 0.009613] CPU3: Booted secondary processor 0x0000000003 [0x410fd083] [ 0.009762] smp: Brought up 1 node, 4 CPUs [ 0.009850] SMP: Total of 4 processors activated. [ 0.009874] CPU features: detected: 32-bit EL0 Support [ 0.009896] CPU features: detected: CRC32 instructions [ 0.009918] CPU features: detected: 32-bit EL1 Support [ 0.042176] CPU: All CPU(s) started at EL2 [ 0.042254] alternatives: patching kernel code [ 0.043702] devtmpfs: initialized [ 0.054058] Enabled cp15_barrier support [ 0.054117] Enabled setend support [ 0.054322] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns [ 0.054366] futex hash table entries: 1024 (order: 4, 65536 bytes, linear) [ 0.062945] pinctrl core: initialized pinctrl subsystem [ 0.063699] DMI not present or invalid. [ 0.064065] NET: Registered protocol family 16 [ 0.067079] DMA: preallocated 1024 KiB GFP_KERNEL pool for atomic allocations [ 0.067355] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.068304] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.068411] audit: initializing netlink subsys (disabled) [ 0.068776] audit: type=2000 audit(0.068:1): state=initialized audit_enabled=0 res=1 [ 0.069257] thermal_sys: Registered thermal governor 'step_wise' [ 0.069686] cpuidle: using governor menu [ 0.070030] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers. [ 0.070211] ASID allocator initialised with 65536 entries [ 0.070351] Serial: AMBA PL011 UART driver [ 0.099609] bcm2835-mbox fe00b880.mailbox: mailbox enabled [ 0.108340] raspberrypi-firmware soc:firmware: Attached to firmware from 2021-08-31T14:52:47, variant start [ 0.112350] raspberrypi-firmware soc:firmware: Firmware hash is 67615e950e1e28b92dfae6303cf7a8b879a8908f [ 0.145950] bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1 [ 0.149762] vgaarb: loaded [ 0.150183] SCSI subsystem initialized [ 0.150392] usbcore: registered new interface driver usbfs [ 0.150465] usbcore: registered new interface driver hub [ 0.150540] usbcore: registered new device driver usb [ 0.150845] usb_phy_generic phy: supply vcc not found, using dummy regulator [ 0.152659] clocksource: Switched to clocksource arch_sys_counter [ 1.182822] VFS: Disk quotas dquot_6.6.0 [ 1.182934] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 1.183107] FS-Cache: Loaded [ 1.183329] CacheFiles: Loaded [ 1.193751] NET: Registered protocol family 2 [ 1.194202] IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear) [ 1.197382] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear) [ 1.197450] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear) [ 1.197761] TCP bind hash table entries: 32768 (order: 7, 524288 bytes, linear) [ 1.198270] TCP: Hash tables configured (established 32768 bind 32768) [ 1.198499] UDP hash table entries: 2048 (order: 4, 65536 bytes, linear) [ 1.198569] UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes, linear) [ 1.198886] NET: Registered protocol family 1 [ 1.199775] RPC: Registered named UNIX socket transport module. [ 1.199803] RPC: Registered udp transport module. [ 1.199823] RPC: Registered tcp transport module. [ 1.199842] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 1.199873] PCI: CLS 0 bytes, default 64 [ 1.202120] hw perfevents: enabled with armv8_cortex_a72 PMU driver, 7 counters available [ 1.202415] kvm [1]: IPA Size Limit: 44 bits [ 1.203571] kvm [1]: vgic interrupt IRQ9 [ 1.203850] kvm [1]: Hyp mode initialized successfully [ 1.205957] Initialise system trusted keyrings [ 1.206301] workingset: timestamp_bits=46 max_order=20 bucket_order=0 [ 1.212683] zbud: loaded [ 1.214388] FS-Cache: Netfs 'nfs' registered for caching [ 1.215070] NFS: Registering the id_resolver key type [ 1.215118] Key type id_resolver registered [ 1.215139] Key type id_legacy registered [ 1.215263] nfs4filelayout_init: NFSv4 File Layout Driver Registering... [ 1.215288] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering... [ 1.216390] Key type asymmetric registered [ 1.216415] Asymmetric key parser 'x509' registered [ 1.216472] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249) [ 1.216773] io scheduler mq-deadline registered [ 1.216798] io scheduler kyber registered [ 1.220529] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges: [ 1.220572] brcm-pcie fd500000.pcie: No bus range found for /scb/pcie@7d500000, using [bus 00-ff] [ 1.220687] brcm-pcie fd500000.pcie: MEM 0x0600000000..0x063fffffff -> 0x00c0000000 [ 1.220779] brcm-pcie fd500000.pcie: IB MEM 0x0000000000..0x00bfffffff -> 0x0400000000 [ 1.286753] brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC) [ 1.287120] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00 [ 1.287151] pci_bus 0000:00: root bus resource [bus 00-ff] [ 1.287179] pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff]) [ 1.287273] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400 [ 1.287510] pci 0000:00:00.0: PME# supported from D0 D3hot [ 1.291320] pci 0000:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring [ 1.291684] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330 [ 1.291814] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit] [ 1.292240] pci 0000:01:00.0: PME# supported from D0 D3hot [ 1.296082] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01 [ 1.296133] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff] [ 1.296165] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit] [ 1.296213] pci 0000:00:00.0: PCI bridge to [bus 01] [ 1.296243] pci 0000:00:00.0: bridge window [mem 0x600000000-0x6000fffff] [ 1.301112] Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled [ 1.301923] bcm2835-aux-uart fe215040.serial: there is not valid maps for state default [ 1.303969] iproc-rng200 fe104000.rng: hwrng registered [ 1.304312] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB) [ 1.305244] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000 [ 1.305658] cacheinfo: Unable to detect cache hierarchy for CPU 0 [ 1.316315] brd: module loaded [ 1.328080] loop: module loaded [ 1.330098] Loading iSCSI transport class v2.0-870. [ 1.333248] libphy: Fixed MDIO Bus: probed [ 1.334777] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000 [ 1.344693] libphy: bcmgenet MII bus: probed [ 1.396812] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus [ 1.397887] usbcore: registered new interface driver r8152 [ 1.397971] usbcore: registered new interface driver lan78xx [ 1.398036] usbcore: registered new interface driver smsc95xx [ 1.443884] pci 0000:00:00.0: enabling device (0000 -> 0002) [ 1.444082] xhci_hcd 0000:01:00.0: xHCI Host Controller [ 1.444132] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1 [ 1.444833] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0000060000000890 [ 1.446123] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.10 [ 1.446155] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 [ 1.446181] usb usb1: Product: xHCI Host Controller [ 1.446203] usb usb1: Manufacturer: Linux 5.10.60-v8+ xhci-hcd [ 1.446225] usb usb1: SerialNumber: 0000:01:00.0 [ 1.446918] hub 1-0:1.0: USB hub found [ 1.447023] hub 1-0:1.0: 1 port detected [ 1.447643] xhci_hcd 0000:01:00.0: xHCI Host Controller [ 1.447685] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2 [ 1.447722] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed [ 1.448145] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.10 [ 1.448175] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 [ 1.448200] usb usb2: Product: xHCI Host Controller [ 1.448222] usb usb2: Manufacturer: Linux 5.10.60-v8+ xhci-hcd [ 1.448245] usb usb2: SerialNumber: 0000:01:00.0 [ 1.448934] hub 2-0:1.0: USB hub found [ 1.449010] hub 2-0:1.0: 4 ports detected [ 1.450487] dwc_otg: version 3.00a 10-AUG-2012 (platform bus) [ 1.451300] usbcore: registered new interface driver uas [ 1.451408] usbcore: registered new interface driver usb-storage [ 1.451615] mousedev: PS/2 mouse device common for all mice [ 1.453485] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer [ 1.456962] sdhci: Secure Digital Host Controller Interface driver [ 1.456988] sdhci: Copyright(c) Pierre Ossman [ 1.457630] mmc-bcm2835 fe300000.mmcnr: could not get clk, deferring probe [ 1.458156] sdhci-pltfm: SDHCI platform and OF driver helper [ 1.461874] ledtrig-cpu: registered to indicate activity on CPUs [ 1.462258] hid: raw HID events driver (C) Jiri Kosina [ 1.462500] usbcore: registered new interface driver usbhid [ 1.462524] usbhid: USB HID core driver [ 1.462869] ashmem: initialized [ 1.470564] Initializing XFRM netlink socket [ 1.470629] NET: Registered protocol family 17 [ 1.470772] Key type dns_resolver registered [ 1.471336] registered taskstats version 1 [ 1.471376] Loading compiled-in X.509 certificates [ 1.471858] Key type ._fscrypt registered [ 1.471882] Key type .fscrypt registered [ 1.471901] Key type fscrypt-provisioning registered [ 1.482743] uart-pl011 fe201000.serial: there is not valid maps for state default [ 1.483042] uart-pl011 fe201000.serial: cts_event_workaround enabled [ 1.483142] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 21, base_baud = 0) is a PL011 rev2 [ 1.489178] bcm2835-aux-uart fe215040.serial: there is not valid maps for state default [ 1.489801] printk: console [ttyS0] disabled [ 1.489928] fe215040.serial: ttyS0 at MMIO 0xfe215040 (irq = 22, base_baud = 62500000) is a 16550 [ 2.825425] printk: console [ttyS0] enabled [ 2.830550] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver [ 2.838889] mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0 [ 2.845078] mmc-bcm2835 fe300000.mmcnr: DMA channel allocated [ 2.879530] of_cfs_init [ 2.882260] of_cfs_init: OK [ 2.903180] mmc1: queuing unknown CIS tuple 0x80 (2 bytes) [ 2.910414] mmc1: queuing unknown CIS tuple 0x80 (3 bytes) [ 2.915114] mmc0: SDHCI controller on fe340000.mmc [fe340000.mmc] using ADMA [ 2.917653] mmc1: queuing unknown CIS tuple 0x80 (3 bytes) [ 2.929002] Waiting for root device PARTUUID=ec4bf566-02... [ 2.937739] mmc1: queuing unknown CIS tuple 0x80 (7 bytes) [ 2.945024] mmc1: queuing unknown CIS tuple 0x80 (3 bytes) [ 3.014560] mmc1: new high speed SDIO card at address 0001 [ 3.024964] mmc0: new ultra high speed DDR50 SDHC card at address aaaa [ 3.032502] mmcblk0: mmc0:aaaa SC16G 14.8 GiB [ 3.043549] mmcblk0: p1 p2 [ 3.073752] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null) [ 3.082146] VFS: Mounted root (ext4 filesystem) readonly on device 179:2. [ 3.098977] devtmpfs: mounted [ 3.110670] Freeing unused kernel memory: 3776K [ 3.115466] Run /sbin/init as init process [ 3.515292] systemd[1]: System time before build time, advancing clock. [ 3.620276] NET: Registered protocol family 10 [ 3.626489] Segment Routing with IPv6 [ 3.698768] systemd[1]: systemd 241 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 +IDN -PCRE2 default-hierarchy=hybrid) [ 3.721720] systemd[1]: Detected architecture arm64. [ 3.774762] systemd[1]: Set hostname to . [ 4.322920] systemd[1]: /lib/systemd/system/smbd.service:9: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/smbd.pid /run/samba/smbd.pid; please update the unit file accordingly. [ 4.368052] systemd[1]: /lib/systemd/system/nmbd.service:9: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/nmbd.pid /run/samba/nmbd.pid; please update the unit file accordingly. [ 4.475193] random: systemd: uninitialized urandom read (16 bytes read) [ 4.495413] random: systemd: uninitialized urandom read (16 bytes read) [ 4.505575] systemd[1]: Created slice system-serial\x2dgetty.slice. [ 4.512631] random: systemd: uninitialized urandom read (16 bytes read) [ 4.520747] systemd[1]: Created slice system-getty.slice. [ 4.526782] systemd[1]: Reached target Swap. [ 4.531946] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ 4.541301] systemd[1]: Listening on fsck to fsckd communication Socket.

Raspbian GNU/Linux 10 raspberrypi ttyS0

raspberrypi login:

The external HDD enclosures are: https://iponcomp.com/shop/product/kolink-hdsub3u3/505572

The HDDs are: WD Red plus 4TB drives (WDC WD40 EFZX-68AWUN0)

The problem: I have the HDDs connected to the USB3 port of the PI, they are formatted to btrfs raid1 The drives are powered externally

When I do a power cycle on the drives the PI recognizes them and can use them normally. Also they are detected by lsusb.

But after reboot the drives are not detected

I have tried the USB_MSD_PWR_OFF_TIME=0 eeprom config, but it did not help

There is the dmesg when the drives are not recognized:

[ 6.876959] xhci_hcd 0000:01:00.0: Timeout while waiting for setup device command [ 7.084970] usb 2-1: Device not responding to setup address. [ 7.292813] usb 2-1: device not accepting address 2, error -71

[ 19.580762] usb 2-1: device not accepting address 4, error -71 [ 24.796993] xhci_hcd 0000:01:00.0: Timeout while waiting for setup device command [ 25.004950] usb 2-1: Device not responding to setup address. [ 25.212795] usb 2-1: device not accepting address 5, error -71 [ 25.221160] usb usb2-port1: unable to enumerate USB device [ 29.316814] usb usb2-port2: Cannot enable. Maybe the USB cable is bad? [ 33.404811] usb usb2-port2: Cannot enable. Maybe the USB cable is bad? [ 33.405016] usb usb2-port2: attempt power cycle

[ 120.077133] usb usb2-port2: attempt power cycle [ 124.240719] usb usb2-port2: Cannot enable. Maybe the USB cable is bad? [ 128.328726] usb usb2-port2: Cannot enable. Maybe the USB cable is bad? [ 128.329108] usb usb2-port2: unable to enumerate USB device [ 132.400723] usb usb2-port2: Cannot enable. Maybe the USB cable is bad? [ 136.632743] usb usb2-port2: Cannot enable. Maybe the USB cable is bad? [ 140.720850] usb usb2-port2: Cannot enable. Maybe the USB cable is bad? [ 140.721249] usb usb2-port2: attempt power cycle [ 144.884956] usb usb2-port2: Cannot enable. Maybe the USB cable is bad? [ 148.972979] usb usb2-port2: Cannot enable. Maybe the USB cable is bad? [ 148.973354] usb usb2-port2: unable to enumerate USB device [ 153.045064] usb usb2-port2: Cannot enable. Maybe the USB cable is bad? [ 157.277106] usb usb2-port2: Cannot enable. Maybe the USB cable is bad? [ 161.365152] usb usb2-port2: Cannot enable. Maybe the USB cable is bad? [ 161.365537] usb usb2-port2: attempt power cycle [ 165.529222] usb usb2-port2: Cannot enable. Maybe the USB cable is bad? [ 169.621241] usb usb2-port2: Cannot enable. Maybe the USB cable is bad? [ 169.621621] usb usb2-port2: unable to enumerate USB device [ 173.837278] usb usb2-port2: Cannot enable. Maybe the USB cable is bad? [ 178.073338] usb usb2-port2: Cannot enable. Maybe the USB cable is bad? [ 182.165370] usb usb2-port2: Cannot enable. Maybe the USB cable is bad?

check the timestamp, I power cycle the device and poof it gets recognized:

[ 189.069636] usb 2-2: new SuperSpeed Gen 1 USB device number 37 using xhci_hcd [ 189.090898] usb 2-2: New USB device found, idVendor=152d, idProduct=0578, bcdDevice= 1.00 [ 189.090917] usb 2-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3 [ 189.090930] usb 2-2: Product: USB3.0 External HDD [ 189.090942] usb 2-2: Manufacturer: JMicron [ 189.090954] usb 2-2: SerialNumber: 0000AB123A9B [ 189.103941] scsi host1: uas [ 189.106393] scsi 1:0:0:0: Direct-Access WDC WD40 EFZX-68AWUN0 8101 PQ: 0 ANSI: 6 [ 189.108406] sd 1:0:0:0: Attached scsi generic sg1 type 0 [ 194.590787] sd 1:0:0:0: [sdb] 7814037168 512-byte logical blocks: (4.00 TB/3.64 TiB) [ 194.590809] sd 1:0:0:0: [sdb] 4096-byte physical blocks [ 194.591055] sd 1:0:0:0: [sdb] Write Protect is off [ 194.591073] sd 1:0:0:0: [sdb] Mode Sense: 53 00 00 08 [ 194.591536] sd 1:0:0:0: [sdb] Disabling FUA [ 194.591552] sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA [ 194.592314] sd 1:0:0:0: [sdb] Optimal transfer size 33553920 bytes not a multiple of physical block size (4096 bytes) [ 194.622270] sd 1:0:0:0: [sdb] Attached SCSI disk [ 194.865379] raid6: neonx8 gen() 1993 MB/s [ 194.933308] raid6: neonx8 xor() 3241 MB/s [ 195.001309] raid6: neonx4 gen() 4414 MB/s [ 195.069309] raid6: neonx4 xor() 3388 MB/s [ 195.137310] raid6: neonx2 gen() 3850 MB/s [ 195.205309] raid6: neonx2 xor() 3018 MB/s [ 195.273314] raid6: neonx1 gen() 2904 MB/s [ 195.341355] raid6: neonx1 xor() 2351 MB/s [ 195.409313] raid6: int64x8 gen() 2571 MB/s [ 195.477310] raid6: int64x8 xor() 1476 MB/s [ 195.545315] raid6: int64x4 gen() 2512 MB/s [ 195.613310] raid6: int64x4 xor() 1485 MB/s [ 195.681317] raid6: int64x2 gen() 2333 MB/s [ 195.749309] raid6: int64x2 xor() 1314 MB/s [ 195.817335] raid6: int64x1 gen() 1810 MB/s [ 195.885316] raid6: int64x1 xor() 980 MB/s [ 195.885322] raid6: using algorithm neonx4 gen() 4414 MB/s [ 195.885327] raid6: .... xor() 3388 MB/s, rmw enabled [ 195.885332] raid6: using neon recovery algorithm [ 195.897702] xor: measuring software checksum speed [ 195.899275] 8regs : 6323 MB/sec [ 195.900631] 32regs : 7278 MB/sec [ 195.902254] arm64_neon : 6191 MB/sec [ 195.902261] xor: using function: 32regs (7278 MB/sec) [ 195.984977] Btrfs loaded, crc32c=crc32c-generic [ 195.986398] BTRFS: device fsid 4d356723-64bb-4fec-b114-e067e5b07aa7 devid 2 transid 583 /dev/sdb scanned by systemd-udevd (979)

[ 242.281897] usb 2-1: new SuperSpeed Gen 1 USB device number 38 using xhci_hcd [ 242.303356] usb 2-1: New USB device found, idVendor=152d, idProduct=0578, bcdDevice= 1.00 [ 242.303376] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3 [ 242.303389] usb 2-1: Product: USB3.0 External HDD [ 242.303401] usb 2-1: Manufacturer: JMicron [ 242.303413] usb 2-1: SerialNumber: 0000AB1236AA [ 242.318941] scsi host2: uas [ 242.320470] scsi 2:0:0:0: Direct-Access WDC WD40 EFZX-68AWUN0 8101 PQ: 0 ANSI: 6 [ 242.322131] sd 2:0:0:0: Attached scsi generic sg2 type 0 [ 247.620066] sd 2:0:0:0: [sdc] 7814037168 512-byte logical blocks: (4.00 TB/3.64 TiB) [ 247.620088] sd 2:0:0:0: [sdc] 4096-byte physical blocks [ 247.620333] sd 2:0:0:0: [sdc] Write Protect is off [ 247.620351] sd 2:0:0:0: [sdc] Mode Sense: 53 00 00 08 [ 247.620809] sd 2:0:0:0: [sdc] Disabling FUA [ 247.620827] sd 2:0:0:0: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA [ 247.621610] sd 2:0:0:0: [sdc] Optimal transfer size 33553920 bytes not a multiple of physical block size (4096 bytes) [ 247.662294] sd 2:0:0:0: [sdc] Attached SCSI disk [ 247.832007] BTRFS: device fsid 4d356723-64bb-4fec-b114-e067e5b07aa7 devid 1 transid 583 /dev/sdc scanned by systemd-udevd (1005)

And I do an lsusb and the result is: Bus 002 Device 058: ID 152d:0578 JMicron Technology Corp. / JMicron USA Technology Corp. JMS567 SATA 6Gb/s bridge Bus 002 Device 059: ID 152d:0578 JMicron Technology Corp. / JMicron USA Technology Corp. JMS567 SATA 6Gb/s bridge

lurch commented 3 years ago

Have you tried disabling UAS? https://github.com/raspberrypi/rpi-eeprom/issues/360

timg236 commented 3 years ago

It sounds like the JMicron doesn't handle the USB disconnect on reset properly. You could try forcing a long power off by adding USB_MSD_PWR_OFF_TIME=5000. Alternatively, you can try adding a powered hub. Closing and hardware issue.