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

CM4: Booting from NVMe works fine, but reboot got stuck with "failed to open nvme" #378

Closed
ctschach opened this issue Nov 13, 2021 · 16 comments

Comments

@ctschach
Copy link

ctschach commented Nov 13, 2021

Mandatory information

  • Raspberry Pi model
    CM4 with 4 GB Memory and no eMMC - attached to https://www.waveshare.com/wiki/CM4-IO-BASE-A
  • Board revision (cat /proc/cpuinfo | grep Revision)
    Revision : c03140
  • Operating system version .
    Rasbian Bullseye

Describe the bug
The system boots without any trouble from the attached NVMe disk. No problem in running the machine, no hiccups, everything works fine. However, a simple "reboot now" got stuck which the following error on the boot console:

root@raspberrypi:/home/pi# reboot now
[  437.212975] reboot: Restar
PM_RSTS: 0x00001020
RPi: BOOTLOADER release VERSION:c258ef8f DATE: Jul  6 2021 TIME: 11:44:56 BOOTMODE: 0x00000006 part: 0 BUILD_TIMESTAMP=1625568293 0x11471181 0x00c03140 0x000c658a
PM_RSTS: 0x00001020
part 00000000 reset_info 00000000
uSD voltage 3.3V
Initialising SDRAM 'Samsung' 16Gb x2 total-size: 32 Gbit 3200
Boot mode: NVME (06) order f1
Failed to open device: 'nvme'
Boot mode: SD (01) order f
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
EMMC
SD retry 1 oc 0
SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080
SD retry 2 oc 0
SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080
SDV1
SD retry 3 oc 0
SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080
SD CMD: 0x371a0010 (55) 0x0 0x1fff0001
Failed to open device: 'sdcard' (cmd 371a0010 status 1fff0001)
Retry SD 1
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
EMMC
SD retry 1 oc 0
SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080
SD retry 2 oc 0
SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080
SDV1
SD retry 3 oc 0
SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080
SD CMD: 0x371a0010 (55) 0x0 0x1fff0001
Failed to open device: 'sdcard' (cmd 371a0010 status 1fff0001)
Boot mode: RESTART (0f) order 0
Restart 0 max -1
Boot mode: NVME (06) order f1
Failed to open device: 'nvme'
Boot mode: SD (01) order f
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

This loops endless. The only way to restart the machine is by power-cycling.

Bootloader version and configuration
Please include the bootloader version and config.

* vcgencmd bootloader_version
timestamp 1625568293
update-time 1636809771
capabilities 0x0000007f
* vcgencmd bootloader_config
[all]
BOOT_UART=1
WAKE_ON_GPIO=1
POWER_OFF_ON_HALT=0

# Try  SD- > USB PCIe MSD -> USB 2.0 BCM XHCI -> Network ->  Loop
BOOT_ORDER=0xf16

# Set to 0 to prevent bootloader updates from USB/Network boot
# For remote units EEPROM hardware write protection should be used.
ENABLE_SELF_UPDATE=1

NVMe boot (please complete the following information):

sudo apt-get install nvme-cli
* sudo nvme list
Node             SN                   Model                                    Namespace Usage                      Format           FW Rev
---------------- -------------------- ---------------------------------------- --------- -------------------------- ---------------- --------
/dev/nvme0n1     A5CD07140E9183417109 Sabrent Rocket nano                      1         512.11  GB / 512.11  GB    512   B +  0 B   RKT301.3

* sudo nvme id-ctrl -H /dev/nvme0
root@raspberrypi:/home/pi# nvme id-ctrl -H /dev/nvme0
NVME Identify Controller:
vid       : 0x1987
ssvid     : 0x1987
sn        : A5CD07140E9183417109
mn        : Sabrent Rocket nano
fr        : RKT301.3
rab       : 1
ieee      : 6479a7
cmic      : 0
  [3:3] : 0     ANA not supported
  [2:2] : 0     PCI
  [1:1] : 0     Single Controller
  [0:0] : 0     Single Port

mdts      : 6
cntlid    : 0x1
ver       : 0x10300
rtd3r     : 0x124f80
rtd3e     : 0x2191c0
oaes      : 0
[14:14] : 0     Endurance Group Event Aggregate Log Page Change Notice Not Supported
[13:13] : 0     LBA Status Information Notices Not Supported
[12:12] : 0     Predictable Latency Event Aggregate Log Change Notices Not Supported
[11:11] : 0     Asymmetric Namespace Access Change Notices Not Supported
  [9:9] : 0     Firmware Activation Notices Not Supported
  [8:8] : 0     Namespace Attribute Changed Event Not Supported

ctratt    : 0
  [9:9] : 0     UUID List Not Supported
  [7:7] : 0     Namespace Granularity Not Supported
  [5:5] : 0     Predictable Latency Mode Not Supported
  [4:4] : 0     Endurance Groups Not Supported
  [3:3] : 0     Read Recovery Levels Not Supported
  [2:2] : 0     NVM Sets Not Supported
  [1:1] : 0     Non-Operational Power State Permissive Not Supported
  [0:0] : 0     128-bit Host Identifier Not Supported

rrls      : 0
cntrltype : 0
  [7:2] : 0     Reserved
  [1:0] : 0     Controller type not reported
fguid     :
crdt1     : 0
crdt2     : 0
crdt3     : 0
oacs      : 0x17
  [9:9] : 0     Get LBA Status Capability Not Supported
  [8:8] : 0     Doorbell Buffer Config Not Supported
  [7:7] : 0     Virtualization Management Not Supported
  [6:6] : 0     NVMe-MI Send and Receive Not Supported
  [5:5] : 0     Directives Not Supported
  [4:4] : 0x1   Device Self-test Supported
  [3:3] : 0     NS Management and Attachment Not Supported
  [2:2] : 0x1   FW Commit and Download Supported
  [1:1] : 0x1   Format NVM Supported
  [0:0] : 0x1   Security Send and Receive Supported

acl       : 0
aerl      : 3
frmw      : 0x12
  [4:4] : 0x1   Firmware Activate Without Reset Supported
  [3:1] : 0x1   Number of Firmware Slots
  [0:0] : 0     Firmware Slot 1 Read/Write

lpa       : 0xe
  [4:4] : 0     Persistent Event log Not Supported
  [3:3] : 0x1   Telemetry host/controller initiated log page Supported
  [2:2] : 0x1   Extended data for Get Log Page Supported
  [1:1] : 0x1   Command Effects Log Page Supported
  [0:0] : 0     SMART/Health Log Page per NS Not Supported

elpe      : 15
npss      : 4
avscc     : 0x1
  [0:0] : 0x1   Admin Vendor Specific Commands uses NVMe Format

apsta     : 0x1
  [0:0] : 0x1   Autonomous Power State Transitions Supported

wctemp    : 358
cctemp    : 368
mtfa      : 100
hmpre     : 139672
hmmin     : 546
tnvmcap   : 512110190592
unvmcap   : 0
rpmbs     : 0
 [31:24]: 0     Access Size
 [23:16]: 0     Total Size
  [5:3] : 0     Authentication Method
  [2:0] : 0     Number of RPMB Units

edstt     : 30
dsto      : 1
fwug      : 4
kas       : 1
hctma     : 0x1
  [0:0] : 0x1   Host Controlled Thermal Management Supported
mntmt     : 273
mxtmt     : 358
sanicap   : 0x6
  [31:30] : 0   Additional media modification after sanitize operation completes successfully is not defined
  [29:29] : 0   No-Deallocate After Sanitize bit in Sanitize command Supported
    [2:2] : 0x1 Overwrite Sanitize Operation Supported
    [1:1] : 0x1 Block Erase Sanitize Operation Supported
    [0:0] : 0   Crypto Erase Sanitize Operation Not Supported

hmminds   : 0
hmmaxd    : 0
nsetidmax : 0
endgidmax : 0
anatt     : 0
anacap    : 0
  [7:7] : 0     Non-zero group ID Not Supported
  [6:6] : 0     Group ID does not change
  [4:4] : 0     ANA Change state Not Supported
  [3:3] : 0     ANA Persistent Loss state Not Supported
  [2:2] : 0     ANA Inaccessible state Not Supported
  [1:1] : 0     ANA Non-optimized state Not Supported
  [0:0] : 0     ANA Optimized state Not Supported

anagrpmax : 0
nanagrpid : 0
pels      : 0
sqes      : 0x66
  [7:4] : 0x6   Max SQ Entry Size (64)
  [3:0] : 0x6   Min SQ Entry Size (64)

cqes      : 0x44
  [7:4] : 0x4   Max CQ Entry Size (16)
  [3:0] : 0x4   Min CQ Entry Size (16)

maxcmd    : 0
nn        : 1
oncs      : 0x5e
  [7:7] : 0     Verify Not Supported
  [6:6] : 0x1   Timestamp Supported
  [5:5] : 0     Reservations Not Supported
  [4:4] : 0x1   Save and Select Supported
  [3:3] : 0x1   Write Zeroes Supported
  [2:2] : 0x1   Data Set Management Supported
  [1:1] : 0x1   Write Uncorrectable Supported
  [0:0] : 0     Compare Not Supported

fuses     : 0
  [0:0] : 0     Fused Compare and Write Not Supported

fna       : 0x1
  [2:2] : 0     Crypto Erase Not Supported as part of Secure Erase
  [1:1] : 0     Crypto Erase Applies to Single Namespace(s)
  [0:0] : 0x1   Format Applies to All Namespace(s)

vwc       : 0x1
  [2:1] : 0     Support for the NSID field set to FFFFFFFFh is not indicated
  [0:0] : 0x1   Volatile Write Cache Present

awun      : 255
awupf     : 0
nvscc     : 1
  [0:0] : 0x1   NVM Vendor Specific Commands uses NVMe Format

nwpc      : 0
  [2:2] : 0     Permanent Write Protect Not Supported
  [1:1] : 0     Write Protect Until Power Supply Not Supported
  [0:0] : 0     No Write Protect and Write Protect Namespace Not Supported

acwu      : 0
sgls      : 0
 [1:0]  : 0     Scatter-Gather Lists Not Supported

mnan      : 0
subnqn    :
ioccsz    : 0
iorcsz    : 0
icdoff    : 0
ctrattr   : 0
  [0:0] : 0     Dynamic Controller Model

msdbd     : 0
ps    0 : mp:4.50W operational enlat:0 exlat:0 rrt:0 rrl:0
          rwt:0 rwl:0 idle_power:- active_power:-
ps    1 : mp:2.70W operational enlat:0 exlat:0 rrt:1 rrl:1
          rwt:1 rwl:1 idle_power:- active_power:-
ps    2 : mp:2.16W operational enlat:0 exlat:0 rrt:2 rrl:2
          rwt:2 rwl:2 idle_power:- active_power:-
ps    3 : mp:0.0700W non-operational enlat:1000 exlat:1000 rrt:3 rrl:3
          rwt:3 rwl:3 idle_power:- active_power:-
ps    4 : mp:0.0020W non-operational enlat:5000 exlat:45000 rrt:4 rrl:4
          rwt:4 rwl:4 idle_power:- active_power:-

* sudo nvme list-ns /dev/nvme0
[   0]:0x1

sudo nvme id-ns -H /dev/nvme0 --namespace-id=1
NVME Identify Namespace 1:
nsze    : 0x3b9e12b0
ncap    : 0x3b9e12b0
nuse    : 0x3b9e12b0
nsfeat  : 0
  [4:4] : 0     NPWG, NPWA, NPDG, NPDA, and NOWS are Not Supported
  [2:2] : 0     Deallocated or Unwritten Logical Block error Not Supported
  [1:1] : 0     Namespace uses AWUN, AWUPF, and ACWU
  [0:0] : 0     Thin Provisioning Not Supported

nlbaf   : 1
flbas   : 0
  [4:4] : 0     Metadata Transferred in Separate Contiguous Buffer
  [3:0] : 0     Current LBA Format Selected

mc      : 0
  [1:1] : 0     Metadata Pointer Not Supported
  [0:0] : 0     Metadata as Part of Extended Data LBA Not Supported

dpc     : 0
  [4:4] : 0     Protection Information Transferred as Last 8 Bytes of Metadata Not Supported
  [3:3] : 0     Protection Information Transferred as First 8 Bytes of Metadata Not Supported
  [2:2] : 0     Protection Information Type 3 Not Supported
  [1:1] : 0     Protection Information Type 2 Not Supported
  [0:0] : 0     Protection Information Type 1 Not Supported

dps     : 0
  [3:3] : 0     Protection Information is Transferred as Last 8 Bytes of Metadata
  [2:0] : 0     Protection Information Disabled

nmic    : 0
  [0:0] : 0     Namespace Multipath Not Capable

rescap  : 0
  [6:6] : 0     Exclusive Access - All Registrants Not Supported
  [5:5] : 0     Write Exclusive - All Registrants Not Supported
  [4:4] : 0     Exclusive Access - Registrants Only Not Supported
  [3:3] : 0     Write Exclusive - Registrants Only Not Supported
  [2:2] : 0     Exclusive Access Not Supported
  [1:1] : 0     Write Exclusive Not Supported
  [0:0] : 0     Persist Through Power Loss Not Supported

fpi     : 0
  [7:7] : 0     Format Progress Indicator Not Supported

dlfeat  : 8
  [4:4] : 0     Guard Field of Deallocated Logical Blocks is set to 0xFFFF
  [3:3] : 0x1   Deallocate Bit in the Write Zeroes Command is Supported
  [2:0] : 0     Bytes Read From a Deallocated Logical Block and its Metadata are Not Reported

nawun   : 255
nawupf  : 0
nacwu   : 0
nabsn   : 255
nabo    : 0
nabspf  : 0
noiob   : 0
nvmcap  : 512110190592
nsattr  : 0
nvmsetid: 0
anagrpid: 0
endgid  : 0
nguid   : 00000000000000000000000000000000
eui64   : 6479a74af02003fd
LBA Format  0 : Metadata Size: 0   bytes - Data Size: 512 bytes - Relative Performance: 0x1 Better (in use)
LBA Format  1 : Metadata Size: 0   bytes - Data Size: 4096 bytes - Relative Performance: 0 Best

Additional context

A dump of the successful boot log when turning on the power:

PM_RSTS: 0x00001000
RPi: BOOTLOADER release VERSION:c258ef8f DATE: Jul  6 2021 TIME: 11:44:56 BOOTMODE: 0x00000006 part: 0 BUILD_TIMESTAMP=1625568293 0x11471181 0x00c03140 0x000c6c13
PM_RSTS: 0x00001000
part 00000000 reset_info 00000000
uSD voltage 3.3V
Initialising SDRAM 'Samsung' 16Gb x2 total-size: 32 Gbit 3200
Boot mode: NVME (06) order f1
VID 0x1987 MN Sabrent Rocket nano
NVME on
MBR: 0x00002000,  524288 type: 0x0c
MBR: 0x00082000,999682736 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: 0x00001000
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     2196 hnd 0x00000000
SIG pieeprom.sig fe5e7fbd74d1de2c854d9b916c40b6d32d6b0cd6f3a5f7eae47a56b35e1517b4 1636787695
SELF-UPDATE timestamp current 1636809771 new 1636787695 skip
Read start4cd.elf bytes   798812 hnd 0x00000000
Read fixup4cd.dat bytes     3143 hnd 0x00000000
Firmware: 4f73dcaefcfd5b20317e44a81d10e9d74fd3dffe Nov  8 2021 18:47:46
0x00c03140 0x00000000 0x00000fff
MEM GPU: 16 ARM: 998 TOTAL: 1014
[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 5.10.78-v7l+ (dom@buildbot) (arm-linux-gnueabihf-gcc-8 (Ubuntu/Linaro 8.4.0-3ubuntu1) 8.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1484 SMP Thu Nov 11 16:36:06 GMT 2021
[    0.000000] CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d
[    0.000000] CPU: div instructions available: patching division code
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
[    0.000000] OF: fdt: Machine model: Raspberry Pi Compute Module 4 Rev 1.0
[    0.000000] random: fast init done
[    0.000000] Memory policy: Data cache writealloc
[    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-0x000000002fffffff]
[    0.000000]   Normal   empty
[    0.000000]   HighMem  [mem 0x0000000030000000-0x00000000fbffffff]
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000000000-0x000000003e5fffff]
[    0.000000]   node   0: [mem 0x0000000040000000-0x00000000fbffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000000fbffffff]
[    0.000000] percpu: Embedded 20 pages/cpu s50828 r8192 d22900 u81920
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 1023808
[    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=DC:A6:32:FE:89:27 vc_mem.mem_base=0x3f000000 vc_mem.mem_size=0x3f600000  console=ttyAMA0,115200 cons
ole=tty1 root=PARTUUID=0507689b-02 rootfstype=ext4 fsck.repair=yes rootwait
[    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear)
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] software IO TLB: mapped [mem 0x0000000014890000-0x0000000018890000] (64MB)
[    0.000000] Memory: 3651872K/4102144K available (10240K kernel code, 1366K rwdata, 3192K rodata, 2048K init, 883K bss, 122592K reserved, 327680K cma-reserved, 3315712K highmem)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] ftrace: allocating 34341 entries in 101 pages
[    0.000000] ftrace: allocated 101 pages with 4 groups
[    0.000000] rcu: Hierarchical RCU implementation.
[    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 10 jiffies.
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000000] GIC: Using split EOI/Deactivate mode
[    0.000000] irq_brcmstb_l2: registered L2 intc (/soc/interrupt-controller@7ef00100, parent irq: 25)
[    0.000000] random: get_random_bytes called from start_kernel+0x3c8/0x59c with crng_init=1
[    0.000008] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483647500ns
[    0.000034] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275 ns
[    0.000094] bcm2835: system timer (irq = 26)
[    0.000745] arch_timer: cp15 timer(s) running at 54.00MHz (phys).
[    0.000766] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns
[    0.000788] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns
[    0.000806] Switching to timer-based delay loop, resolution 18ns
[    0.001069] Console: colour dummy device 80x30
[    0.001823] printk: console [tty1] enabled
[    0.001893] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=540000)
[    0.001948] pid_max: default: 32768 minimum: 301
[    0.002126] LSM: Security Framework initializing
[    0.002323] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[    0.002368] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[    0.003847] cgroup: Disabling memory control group subsystem
[    0.004101] CPU: Testing write buffer coherency: ok
[    0.004576] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[    0.005804] Setting up static identity map for 0x200000 - 0x20003c
[    0.006020] rcu: Hierarchical SRCU implementation.
[    0.006969] smp: Bringing up secondary CPUs ...
[    0.008206] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[    0.009572] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[    0.010981] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[    0.011140] smp: Brought up 1 node, 4 CPUs
[    0.011187] SMP: Total of 4 processors activated (432.00 BogoMIPS).
[    0.011217] CPU: All CPU(s) started in HYP mode.
[    0.011243] CPU: Virtualization extensions available.
[    0.012101] devtmpfs: initialized
[    0.026343] VFP support v0.3: implementor 41 architecture 3 part 40 variant 8 rev 0
[    0.026581] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.026635] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)
[    0.034700] pinctrl core: initialized pinctrl subsystem
[    0.035818] NET: Registered protocol family 16
[    0.039865] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[    0.040688] audit: initializing netlink subsys (disabled)
[    0.041002] audit: type=2000 audit(0.040:1): state=initialized audit_enabled=0 res=1
[    0.041589] thermal_sys: Registered thermal governor 'step_wise'
[    0.042260] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[    0.042316] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.042737] Serial: AMBA PL011 UART driver
[    0.085801] bcm2835-mbox fe00b880.mailbox: mailbox enabled
[    0.100916] raspberrypi-firmware soc:firmware: Attached to firmware from 2021-11-08T18:47:46, variant start_cd
[    0.110928] raspberrypi-firmware soc:firmware: Firmware hash is 4f73dcaefcfd5b20317e44a81d10e9d74fd3dffe
[    0.151945] Kprobes globally optimized
[    0.157388] bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1
[    0.161792] vgaarb: loaded
[    0.162255] SCSI subsystem initialized
[    0.162503] usbcore: registered new interface driver usbfs
[    0.162580] usbcore: registered new interface driver hub
[    0.162683] usbcore: registered new device driver usb
[    0.163083] usb_phy_generic phy: supply vcc not found, using dummy regulator
[    0.165010] clocksource: Switched to clocksource arch_sys_counter
[    1.124360] VFS: Disk quotas dquot_6.6.0
[    1.124483] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    1.124693] FS-Cache: Loaded
[    1.124899] CacheFiles: Loaded
[    1.135311] NET: Registered protocol family 2
[    1.135574] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)
[    1.136899] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear)
[    1.137061] TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear)
[    1.137150] TCP bind hash table entries: 8192 (order: 4, 65536 bytes, linear)
[    1.137240] TCP: Hash tables configured (established 8192 bind 8192)
[    1.137421] UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
[    1.137478] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
[    1.138163] NET: Registered protocol family 1
[    1.138931] RPC: Registered named UNIX socket transport module.
[    1.138964] RPC: Registered udp transport module.
[    1.138992] RPC: Registered tcp transport module.
[    1.139020] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    1.139059] PCI: CLS 0 bytes, default 64
[    1.142325] Initialise system trusted keyrings
[    1.142601] workingset: timestamp_bits=14 max_order=20 bucket_order=6
[    1.151085] zbud: loaded
[    1.152915] FS-Cache: Netfs 'nfs' registered for caching
[    1.153720] NFS: Registering the id_resolver key type
[    1.153782] Key type id_resolver registered
[    1.153811] Key type id_legacy registered
[    1.153955] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[    1.153988] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering...
[    1.155057] Key type asymmetric registered
[    1.155089] Asymmetric key parser 'x509' registered
[    1.155298] bounce: pool size: 64 pages
[    1.155355] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249)
[    1.155592] io scheduler mq-deadline registered
[    1.155623] io scheduler kyber registered
[    1.160243] gpio-507 (ant1): hogged as output/high
[    1.161675] gpio-511 (ant2): hogged as output/low
[    1.163214] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges:
[    1.163263] brcm-pcie fd500000.pcie:   No bus range found for /scb/pcie@7d500000, using [bus 00-ff]
[    1.163365] brcm-pcie fd500000.pcie:      MEM 0x0600000000..0x063fffffff -> 0x00c0000000
[    1.163474] brcm-pcie fd500000.pcie:   IB MEM 0x0000000000..0x00ffffffff -> 0x0400000000
[    1.217150] brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC)
[    1.217570] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00
[    1.217608] pci_bus 0000:00: root bus resource [bus 00-ff]
[    1.217643] pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff])
[    1.217756] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400
[    1.218017] pci 0000:00:00.0: PME# supported from D0 D3hot
[    1.221512] PCI: bus0: Fast back to back transfers disabled
[    1.221552] pci 0000:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[    1.221888] pci 0000:01:00.0: [1987:5013] type 00 class 0x010802
[    1.221980] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00003fff 64bit]
[    1.222395] pci 0000:01:00.0: 4.000 Gb/s available PCIe bandwidth, limited by 5.0 GT/s PCIe x1 link at 0000:00:00.0 (capable of 31.504 Gb/s with 8.0 GT/s PCIe x4 link)
[    1.225767] PCI: bus1: Fast back to back transfers disabled
[    1.225805] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01
[    1.225862] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff]
[    1.225903] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600003fff 64bit]
[    1.225967] pci 0000:00:00.0: PCI bridge to [bus 01]
[    1.226007] pci 0000:00:00.0:   bridge window [mem 0x600000000-0x6000fffff]
[    1.226435] pcieport 0000:00:00.0: enabling device (0140 -> 0142)
[    1.226682] pcieport 0000:00:00.0: PME: Signaling with IRQ 81
[    1.234149] Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled
[    1.237522] iproc-rng200 fe104000.rng: hwrng registered
[    1.237909] vc-mem: phys_addr:0x00000000 mem_base=0x3f000000 mem_size:0x3f600000(1014 MiB)
[    1.239419] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000
[    1.251846] brd: module loaded
[    1.264209] loop: module loaded
[    1.266096] Loading iSCSI transport class v2.0-870.
[    1.268187] nvme nvme0: pci function 0000:01:00.0
[    1.268444] nvme 0000:01:00.0: enabling device (0140 -> 0142)
[    1.270806] libphy: Fixed MDIO Bus: probed
[    1.272711] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000
[    1.274068] nvme nvme0: missing or invalid SUBNQN field.
[    1.285047] libphy: bcmgenet MII bus: probed
[    1.323572] nvme nvme0: allocated 128 MiB host memory buffer.
[    1.328053] nvme nvme0: 4/0/0 default/read/poll queues
[    1.331711]  nvme0n1: p1 p2
[    1.365185] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus
[    1.366466] usbcore: registered new interface driver r8152
[    1.366555] usbcore: registered new interface driver lan78xx
[    1.366631] usbcore: registered new interface driver smsc95xx
[    1.392727] xhci-hcd fe9c0000.xhci: xHCI Host Controller
[    1.392781] xhci-hcd fe9c0000.xhci: new USB bus registered, assigned bus number 1
[    1.393934] xhci-hcd fe9c0000.xhci: hcc params 0x0220fe65 hci version 0x110 quirks 0x0000000000010010
[    1.394060] xhci-hcd fe9c0000.xhci: irq 78, io mem 0xfe9c0000
[    1.394668] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.10
[    1.394710] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.394746] usb usb1: Product: xHCI Host Controller
[    1.394775] usb usb1: Manufacturer: Linux 5.10.78-v7l+ xhci-hcd
[    1.394806] usb usb1: SerialNumber: fe9c0000.xhci
[    1.395569] hub 1-0:1.0: USB hub found
[    1.395654] hub 1-0:1.0: 1 port detected
[    1.396205] xhci-hcd fe9c0000.xhci: xHCI Host Controller
[    1.396248] xhci-hcd fe9c0000.xhci: new USB bus registered, assigned bus number 2
[    1.396293] xhci-hcd fe9c0000.xhci: Host supports USB 3.0 SuperSpeed
[    1.396466] usb usb2: We don't know the algorithms for LPM for this host, disabling LPM.
[    1.396781] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.10
[    1.396820] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.396855] usb usb2: Product: xHCI Host Controller
[    1.396885] usb usb2: Manufacturer: Linux 5.10.78-v7l+ xhci-hcd
[    1.396915] usb usb2: SerialNumber: fe9c0000.xhci
[    1.397568] hub 2-0:1.0: USB hub found
[    1.397651] hub 2-0:1.0: config failed, hub doesn't have any ports! (err -19)
[    1.398513] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    1.399388] usbcore: registered new interface driver uas
[    1.399511] usbcore: registered new interface driver usb-storage
[    1.399731] mousedev: PS/2 mouse device common for all mice
[    1.401526] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
[    1.405132] sdhci: Secure Digital Host Controller Interface driver
[    1.405165] sdhci: Copyright(c) Pierre Ossman
[    1.405893] sdhci-pltfm: SDHCI platform and OF driver helper
[    1.408894] ledtrig-cpu: registered to indicate activity on CPUs
[    1.409275] hid: raw HID events driver (C) Jiri Kosina
[    1.409498] usbcore: registered new interface driver usbhid
[    1.409528] usbhid: USB HID core driver
[    1.415663] Initializing XFRM netlink socket
[    1.415726] NET: Registered protocol family 17
[    1.415862] Key type dns_resolver registered
[    1.416224] Registering SWP/SWPB emulation handler
[    1.416410] registered taskstats version 1
[    1.416451] Loading compiled-in X.509 certificates
[    1.417338] Key type ._fscrypt registered
[    1.417369] Key type .fscrypt registered
[    1.417397] Key type fscrypt-provisioning registered
[    1.429123] uart-pl011 fe201000.serial: there is not valid maps for state default
[    1.429401] uart-pl011 fe201000.serial: cts_event_workaround enabled
[    1.429493] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 38, base_baud = 0) is a PL011 rev2
[    2.736726] printk: console [ttyAMA0] enabled
[    2.748181] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver
[    2.760010] of_cfs_init
[    2.762608] of_cfs_init: OK
[    2.802701] mmc0: SDHCI controller on fe340000.mmc [fe340000.mmc] using ADMA
[    2.846749] EXT4-fs (nvme0n1p2): mounted filesystem with ordered data mode. Opts: (null)
[    2.854948] VFS: Mounted root (ext4 filesystem) readonly on device 259:2.
[    2.863865] devtmpfs: mounted
[    2.877118] Freeing unused kernel memory: 2048K
[    2.881974] Run /sbin/init as init process
[    2.999483] systemd[1]: System time before build time, advancing clock.
[    3.005069] usb 1-1: new high-speed USB device number 2 using xhci-hcd
[    3.063316] NET: Registered protocol family 10
[    3.069262] Segment Routing with IPv6
[    3.105144] systemd[1]: systemd 247.3-6+rpi1 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +ZSTD +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=unified)
[    3.135135] systemd[1]: Detected architecture arm.
[    3.142826] systemd[1]: Set hostname to <raspberrypi>.
[    3.196133] usb 1-1: New USB device found, idVendor=1a40, idProduct=0101, bcdDevice= 1.11
[    3.204457] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
[    3.211730] usb 1-1: Product: USB 2.0 Hub
[    3.246891] uart-pl011 fe201000.serial: no DMA platform data
[    3.284699] hub 1-1:1.0: USB hub found
[    3.288737] hub 1-1:1.0: 4 ports detected
[    3.910701] systemd[1]: Queued start job for default target Graphical Interface.
[    3.919626] random: systemd: uninitialized urandom read (16 bytes read)
[    3.928676] systemd[1]: Created slice system-getty.slice.
[    3.934849] random: systemd: uninitialized urandom read (16 bytes read)
[    3.942554] systemd[1]: Created slice system-modprobe.slice.
[    3.949023] random: systemd: uninitialized urandom read (16 bytes read)
[    3.956667] systemd[1]: Created slice system-postfix.slice.
[    3.963662] systemd[1]: Created slice system-serial\x2dgetty.slice.
[    3.971300] systemd[1]: Created slice system-systemd\x2dfsck.slice.
[    3.978897] systemd[1]: Created slice User and Session Slice.
[    3.985486] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
[    3.994187] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[    4.003269] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
[    4.013406] systemd[1]: Reached target Local Encrypted Volumes.
[    4.020224] systemd[1]: Reached target Paths.
[    4.025241] systemd[1]: Reached target Slices.
[    4.030222] systemd[1]: Reached target Swap.
[    4.035919] systemd[1]: Listening on Syslog Socket.
[    4.041889] systemd[1]: Listening on fsck to fsckd communication Socket.
[    4.049460] systemd[1]: Listening on initctl Compatibility Named Pipe.
[    4.057506] systemd[1]: Listening on Journal Audit Socket.
[    4.064064] systemd[1]: Listening on Journal Socket (/dev/log).
[    4.071305] systemd[1]: Listening on Journal Socket.
[    4.077728] systemd[1]: Listening on udev Control Socket.
[    4.084247] systemd[1]: Listening on udev Kernel Socket.
[    4.090952] systemd[1]: Condition check resulted in Huge Pages File System being skipped.
[    4.104004] systemd[1]: Mounting POSIX Message Queue File System...
[    4.116078] systemd[1]: Mounting RPC Pipe File System...
[    4.127884] systemd[1]: Mounting Kernel Debug File System...
[    4.139542] systemd[1]: Mounting Kernel Trace File System...
[    4.146221] systemd[1]: Condition check resulted in Kernel Module supporting RPCSEC_GSS being skipped.
[    4.161533] systemd[1]: Starting Restore / save the current clock...
[    4.174459] systemd[1]: Starting Set the console keyboard layout...
[    4.187585] systemd[1]: Starting Create list of static device nodes for the current kernel...
[    4.203464] systemd[1]: Starting Load Kernel Module configfs...
[    4.217073] systemd[1]: Starting Load Kernel Module drm...
[    4.229909] systemd[1]: Starting Load Kernel Module fuse...
[    4.238419] systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped.
[    4.253274] systemd[1]: Starting File System Check on Root Device...
[    4.276122] fuse: init (API version 7.32)
[    4.278120] systemd[1]: Starting Journal Service...
[    4.293140] systemd[1]: Starting Load Kernel Modules...
[    4.304962] systemd[1]: Starting Coldplug All udev Devices...
[    4.324892] systemd[1]: Mounted POSIX Message Queue File System.
[    4.332495] systemd[1]: Mounted RPC Pipe File System.
[    4.338851] systemd[1]: Mounted Kernel Debug File System.
[    4.345500] systemd[1]: Mounted Kernel Trace File System.
[    4.353231] systemd[1]: Finished Restore / save the current clock.
[    4.362535] systemd[1]: Finished Create list of static device nodes for the current kernel.
[    4.373289] systemd[1]: modprobe@configfs.service: Succeeded.
[    4.381367] systemd[1]: Finished Load Kernel Module configfs.
[    4.386570] i2c /dev entries driver
[    4.392925] systemd[1]: modprobe@drm.service: Succeeded.
[    4.400119] systemd[1]: Finished Load Kernel Module drm.
[    4.417615] systemd[1]: modprobe@fuse.service: Succeeded.
[    4.424396] systemd[1]: Finished Load Kernel Module fuse.
[    4.447390] systemd[1]: Finished Load Kernel Modules.
[    4.475632] systemd[1]: Mounting FUSE Control File System...
[    4.496909] systemd[1]: Mounting Kernel Configuration File System...
[    4.539834] systemd[1]: Started File System Check Daemon to report status.
[    4.571499] systemd[1]: Starting Apply Kernel Variables...
[    4.587911] systemd[1]: Mounted FUSE Control File System.
[    4.594292] systemd[1]: Started Journal Service.

Raspbian GNU/Linux 11 raspberrypi ttyAMA0

raspberrypi login:

@lurch
Copy link
Contributor

lurch commented Nov 13, 2021

Sounds quite similar to raspberrypi/Raspberry-Pi-OS-64bit#188 ?

@peterharperuk
Copy link
Collaborator

I've tried to reproduce this but it seems to work for me. I've tried a LITE and 8GB EMMC CM4. I'm using the waveshare board mentioned in raspberrypi/Raspberry-Pi-OS-64bit#188 that has the resistor fix, but I don't know why that would be relevant. I'm using a different make of NVME disk.

@peterharperuk
Copy link
Collaborator

@ctschach if I sent you a version of the bootloader with some extra logging - would you be prepared to update the eeprom on your CM4 using USBBOOT and repro the problem?

@ctschach
Copy link
Author

@ctschach if I sent you a version of the bootloader with some extra logging - would you be prepared to update the eeprom on your CM4 using USBBOOT and repro the problem?

Absolutely....

@peterharperuk
Copy link
Collaborator

Ok, first attempt... pieeprom.original1.zip

cd usbboot\recovery
cp pieeprom.original1.bin pieeprom.original.bin
./update-pieeprom.sh
../rpiboot.exe -d .

switch [RPI]boot switch on and connect your PC to the USB type-C interface to program the eeprom with this image. Switch off the boot switch and power cycle and repro the problem. If you can attach any UART logging that would be helpful

@ctschach
Copy link
Author

So here is what happened: I flashed the new EEPROM and booted the RPi from the NVMe card. This ended up in a kernel panic (see below). Since then the NVMe became unusable. If I boot from an SD card, I see the NVMe disk, but an fsck giving me error. Putting it into an external enclosure and attaching it to another Raspi did not work either.

The interesting thing: It worked directly before changing the EEPROM. I don't think that this could have destroyed the NVMe disk - maybe just some unfortunate coincidences.

I've now ordered two new (and different) disks which should arrive early next week. I'll test them and report back.

´´´
[ 0.000000] Booting Linux on physical CPU 0x0
[ 0.000000] Linux version 5.10.78-v7l+ (dom@buildbot) (arm-linux-gnueabihf-gcc-8 (Ubuntu/Linaro 8.4.0-3ubuntu1) 8.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1484 SMP Thu Nov 11 16:36:06 GMT 2021
[ 0.000000] CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d
[ 0.000000] CPU: div instructions available: patching division code
[ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
[ 0.000000] OF: fdt: Machine model: Raspberry Pi Compute Module 4 Rev 1.0
[ 0.000000] random: fast init done
[ 0.000000] Memory policy: Data cache writealloc
[ 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-0x000000002fffffff]
[ 0.000000] Normal empty
[ 0.000000] HighMem [mem 0x0000000030000000-0x00000001ffffffff]
[ 0.000000] Movable zone start for each node
[ 0.000000] Early memory node ranges
[ 0.000000] node 0: [mem 0x0000000000000000-0x000000003e5fffff]
[ 0.000000] node 0: [mem 0x0000000040000000-0x00000000fbffffff]
[ 0.000000] node 0: [mem 0x0000000100000000-0x00000001ffffffff]
[ 0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000001ffffffff]
[ 0.000000] percpu: Embedded 20 pages/cpu s50828 r8192 d22900 u81920
[ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 2072384
[ 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:62:3B:5C vc_mem.mem_base=0x3f000000 vc_mem.mem_size=0x3f600000 console=ttyAMA0,115200 console=tty1 root=PARTUUID=0507689b-02 rootfstype=ext4 fsck.repair=yes rootwait
[ 0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear)
[ 0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear)
[ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[ 0.000000] software IO TLB: mapped [mem 0x0000000012400000-0x0000000016400000] (64MB)
[ 0.000000] Memory: 7809312K/8296448K available (10240K kernel code, 1366K rwdata, 3192K rodata, 2048K init, 883K bss, 159456K reserved, 327680K cma-reserved, 7510016K highmem)
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[ 0.000000] ftrace: allocating 34341 entries in 101 pages
[ 0.000000] ftrace: allocated 101 pages with 4 groups
[ 0.000000] rcu: Hierarchical RCU implementation.
[ 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 10 jiffies.
[ 0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[ 0.000000] GIC: Using split EOI/Deactivate mode
[ 0.000000] irq_brcmstb_l2: registered L2 intc (/soc/interrupt-controller@7ef00100, parent irq: 25)
[ 0.000000] random: get_random_bytes called from start_kernel+0x3c8/0x59c with crng_init=1
[ 0.000008] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483647500ns
[ 0.000034] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275 ns
[ 0.000094] bcm2835: system timer (irq = 26)
[ 0.000746] arch_timer: cp15 timer(s) running at 54.00MHz (phys).
[ 0.000767] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns
[ 0.000789] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns
[ 0.000807] Switching to timer-based delay loop, resolution 18ns
[ 0.001070] Console: colour dummy device 80x30
[ 0.001834] printk: console [tty1] enabled
[ 0.001903] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=540000)
[ 0.001958] pid_max: default: 32768 minimum: 301
[ 0.002135] LSM: Security Framework initializing
[ 0.002332] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[ 0.002378] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[ 0.003855] cgroup: Disabling memory control group subsystem
[ 0.004114] CPU: Testing write buffer coherency: ok
[ 0.004589] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[ 0.005814] Setting up static identity map for 0x200000 - 0x20003c
[ 0.006028] rcu: Hierarchical SRCU implementation.
[ 0.006972] smp: Bringing up secondary CPUs ...
[ 0.008200] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[ 0.009560] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[ 0.010956] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[ 0.011116] smp: Brought up 1 node, 4 CPUs
[ 0.011162] SMP: Total of 4 processors activated (432.00 BogoMIPS).
[ 0.011193] CPU: All CPU(s) started in HYP mode.
[ 0.011220] CPU: Virtualization extensions available.
[ 0.012075] devtmpfs: initialized
[ 0.026254] VFP support v0.3: implementor 41 architecture 3 part 40 variant 8 rev 0
[ 0.026490] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[ 0.026543] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)
[ 0.034624] pinctrl core: initialized pinctrl subsystem
[ 0.035739] NET: Registered protocol family 16
[ 0.039779] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[ 0.040600] audit: initializing netlink subsys (disabled)
[ 0.040888] audit: type=2000 audit(0.040:1): state=initialized audit_enabled=0 res=1
[ 0.041474] thermal_sys: Registered thermal governor 'step_wise'
[ 0.042148] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[ 0.042203] hw-breakpoint: maximum watchpoint size is 8 bytes.
[ 0.042622] Serial: AMBA PL011 UART driver
[ 0.085620] bcm2835-mbox fe00b880.mailbox: mailbox enabled
[ 0.100915] raspberrypi-firmware soc:firmware: Attached to firmware from 2021-11-08T18:47:46, variant start_cd
[ 0.110928] raspberrypi-firmware soc:firmware: Firmware hash is 4f73dcaefcfd5b20317e44a81d10e9d74fd3dffe
[ 0.151960] Kprobes globally optimized
[ 0.157392] bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1
[ 0.161791] vgaarb: loaded
[ 0.162250] SCSI subsystem initialized
[ 0.162494] usbcore: registered new interface driver usbfs
[ 0.162570] usbcore: registered new interface driver hub
[ 0.162671] usbcore: registered new device driver usb
[ 0.163074] usb_phy_generic phy: supply vcc not found, using dummy regulator
[ 0.164994] clocksource: Switched to clocksource arch_sys_counter
[ 1.124459] VFS: Disk quotas dquot_6.6.0
[ 1.124580] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[ 1.124790] FS-Cache: Loaded
[ 1.125044] CacheFiles: Loaded
[ 1.135421] NET: Registered protocol family 2
[ 1.135685] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)
[ 1.136985] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear)
[ 1.137146] TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear)
[ 1.137234] TCP bind hash table entries: 8192 (order: 4, 65536 bytes, linear)
[ 1.137324] TCP: Hash tables configured (established 8192 bind 8192)
[ 1.137505] UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
[ 1.137563] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
[ 1.138249] NET: Registered protocol family 1
[ 1.139016] RPC: Registered named UNIX socket transport module.
[ 1.139049] RPC: Registered udp transport module.
[ 1.139077] RPC: Registered tcp transport module.
[ 1.139106] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 1.139144] PCI: CLS 0 bytes, default 64
[ 1.142401] Initialise system trusted keyrings
[ 1.142678] workingset: timestamp_bits=14 max_order=21 bucket_order=7
[ 1.151221] zbud: loaded
[ 1.153060] FS-Cache: Netfs 'nfs' registered for caching
[ 1.153862] NFS: Registering the id_resolver key type
[ 1.153925] Key type id_resolver registered
[ 1.153954] Key type id_legacy registered
[ 1.154095] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[ 1.154128] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering...
[ 1.155205] Key type asymmetric registered
[ 1.155237] Asymmetric key parser 'x509' registered
[ 1.155445] bounce: pool size: 64 pages
[ 1.155502] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249)
[ 1.155743] io scheduler mq-deadline registered
[ 1.155775] io scheduler kyber registered
[ 1.160392] gpio-507 (ant1): hogged as output/high
[ 1.161824] gpio-511 (ant2): hogged as output/low
[ 1.163359] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges:
[ 1.163408] brcm-pcie fd500000.pcie: No bus range found for /scb/pcie@7d500000, using [bus 00-ff]
[ 1.163509] brcm-pcie fd500000.pcie: MEM 0x0600000000..0x063fffffff -> 0x00c0000000
[ 1.163618] brcm-pcie fd500000.pcie: IB MEM 0x0000000000..0x01ffffffff -> 0x0400000000
[ 1.217101] brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC)
[ 1.217523] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00
[ 1.217560] pci_bus 0000:00: root bus resource [bus 00-ff]
[ 1.217596] pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff])
[ 1.217710] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400
[ 1.217970] pci 0000:00:00.0: PME# supported from D0 D3hot
[ 1.221453] PCI: bus0: Fast back to back transfers disabled
[ 1.221492] pci 0000:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[ 1.221827] pci 0000:01:00.0: [1987:5013] type 00 class 0x010802
[ 1.221919] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00003fff 64bit]
[ 1.222335] pci 0000:01:00.0: 4.000 Gb/s available PCIe bandwidth, limited by 5.0 GT/s PCIe x1 link at 0000:00:00.0 (capable of 31.504 Gb/s with 8.0 GT/s PCIe x4 link)
[ 1.225688] PCI: bus1: Fast back to back transfers disabled
[ 1.225726] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01
[ 1.225783] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff]
[ 1.225822] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600003fff 64bit]
[ 1.225887] pci 0000:00:00.0: PCI bridge to [bus 01]
[ 1.225926] pci 0000:00:00.0: bridge window [mem 0x600000000-0x6000fffff]
[ 1.226355] pcieport 0000:00:00.0: enabling device (0140 -> 0142)
[ 1.226604] pcieport 0000:00:00.0: PME: Signaling with IRQ 81
[ 1.234059] Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled
[ 1.237426] iproc-rng200 fe104000.rng: hwrng registered
[ 1.237811] vc-mem: phys_addr:0x00000000 mem_base=0x3f000000 mem_size:0x3f600000(1014 MiB)
[ 1.239319] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000
[ 1.251792] brd: module loaded
[ 1.264194] loop: module loaded
[ 1.266089] Loading iSCSI transport class v2.0-870.
[ 1.268180] nvme nvme0: pci function 0000:01:00.0
[ 1.268438] nvme 0000:01:00.0: enabling device (0140 -> 0142)
[ 1.270796] libphy: Fixed MDIO Bus: probed
[ 1.272697] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000
[ 1.273494] nvme nvme0: missing or invalid SUBNQN field.
[ 1.273713] nvme nvme0: failed to set APST feature (8578)
[ 1.273818] nvme nvme0: could not set timestamp (8578)
[ 1.285029] libphy: bcmgenet MII bus: probed
[ 1.322199] nvme nvme0: allocated 128 MiB host memory buffer.
[ 1.322337] nvme nvme0: failed to set host mem (err 8578, flags 0x1).
[ 1.385170] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus
[ 1.386533] usbcore: registered new interface driver r8152
[ 1.386626] usbcore: registered new interface driver lan78xx
[ 1.386704] usbcore: registered new interface driver smsc95xx
[ 1.410145] nvme nvme0: 4/0/0 default/read/poll queues
[ 1.412806] nvme0n1: p1 p2
[ 1.412837] xhci-hcd fe9c0000.xhci: xHCI Host Controller
[ 1.412889] xhci-hcd fe9c0000.xhci: new USB bus registered, assigned bus number 1
[ 1.414140] xhci-hcd fe9c0000.xhci: hcc params 0x0220fe65 hci version 0x110 quirks 0x0000000000010010
[ 1.414264] xhci-hcd fe9c0000.xhci: irq 78, io mem 0xfe9c0000
[ 1.414894] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.10
[ 1.414935] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 1.415004] usb usb1: Product: xHCI Host Controller
[ 1.415035] usb usb1: Manufacturer: Linux 5.10.78-v7l+ xhci-hcd
[ 1.415066] usb usb1: SerialNumber: fe9c0000.xhci
[ 1.415784] hub 1-0:1.0: USB hub found
[ 1.415869] hub 1-0:1.0: 1 port detected
[ 1.416417] xhci-hcd fe9c0000.xhci: xHCI Host Controller
[ 1.416461] xhci-hcd fe9c0000.xhci: new USB bus registered, assigned bus number 2
[ 1.416507] xhci-hcd fe9c0000.xhci: Host supports USB 3.0 SuperSpeed
[ 1.416681] usb usb2: We don't know the algorithms for LPM for this host, disabling LPM.
[ 1.416995] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.10
[ 1.417034] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 1.417070] usb usb2: Product: xHCI Host Controller
[ 1.417099] usb usb2: Manufacturer: Linux 5.10.78-v7l+ xhci-hcd
[ 1.417129] usb usb2: SerialNumber: fe9c0000.xhci
[ 1.417780] hub 2-0:1.0: USB hub found
[ 1.417866] hub 2-0:1.0: config failed, hub doesn't have any ports! (err -19)
[ 1.418731] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[ 1.419624] usbcore: registered new interface driver uas
[ 1.419753] usbcore: registered new interface driver usb-storage
[ 1.419964] mousedev: PS/2 mouse device common for all mice
[ 1.421805] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
[ 1.425428] sdhci: Secure Digital Host Controller Interface driver
[ 1.425462] sdhci: Copyright(c) Pierre Ossman
[ 1.426191] sdhci-pltfm: SDHCI platform and OF driver helper
[ 1.429203] ledtrig-cpu: registered to indicate activity on CPUs
[ 1.429584] hid: raw HID events driver (C) Jiri Kosina
[ 1.429809] usbcore: registered new interface driver usbhid
[ 1.429839] usbhid: USB HID core driver
[ 1.435946] Initializing XFRM netlink socket
[ 1.436010] NET: Registered protocol family 17
[ 1.436138] Key type dns_resolver registered
[ 1.436496] Registering SWP/SWPB emulation handler
[ 1.436682] registered taskstats version 1
[ 1.436723] Loading compiled-in X.509 certificates
[ 1.437599] Key type ._fscrypt registered
[ 1.437630] Key type .fscrypt registered
[ 1.437659] Key type fscrypt-provisioning registered
[ 1.449373] uart-pl011 fe201000.serial: there is not valid maps for state default
[ 1.449653] uart-pl011 fe201000.serial: cts_event_workaround enabled
[ 1.449747] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 38, base_baud = 0) is a PL011 rev2
[ 2.780257] printk: console [ttyAMA0] enabled
[ 2.791688] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver
[ 2.803529] of_cfs_init
[ 2.806171] of_cfs_init: OK
[ 2.843358] mmc0: SDHCI controller on fe340000.mmc [fe340000.mmc] using ADMA
[ 2.856233] EXT4-fs (nvme0n1p2): INFO: recovery required on readonly filesystem
[ 2.863577] EXT4-fs (nvme0n1p2): write access will be enabled during recovery
[ 3.045038] usb 1-1: new high-speed USB device number 2 using xhci-hcd
[ 3.223031] blk_update_request: critical medium error, dev nvme0n1, sector 532480 op 0x1:(WRITE) flags 0x800 phys_seg 3 prio class 0
[ 3.225448] usb 1-1: New USB device found, idVendor=1a40, idProduct=0101, bcdDevice= 1.11
[ 3.234972] Buffer I/O error on dev nvme0n1p2, logical block 0, lost async page write
[ 3.243184] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
[ 3.251018] Buffer I/O error on dev nvme0n1p2, logical block 1, lost async page write
[ 3.258165] usb 1-1: Product: USB 2.0 Hub
[ 3.265994] Buffer I/O error on dev nvme0n1p2, logical block 2, lost async page write
[ 3.266089] blk_update_request: critical medium error, dev nvme0n1, sector 533320 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[ 3.289776] Buffer I/O error on dev nvme0n1p2, logical block 105, lost async page write
[ 3.297856] blk_update_request: critical medium error, dev nvme0n1, sector 533416 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[ 3.309789] Buffer I/O error on dev nvme0n1p2, logical block 117, lost async page write
[ 3.317824] blk_update_request: critical medium error, dev nvme0n1, sector 533440 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[ 3.329757] Buffer I/O error on dev nvme0n1p2, logical block 120, lost async page write
[ 3.337791] blk_update_request: critical medium error, dev nvme0n1, sector 533856 op 0x1:(WRITE) flags 0x800 phys_seg 2 prio class 0
[ 3.349723] Buffer I/O error on dev nvme0n1p2, logical block 172, lost async page write
[ 3.357752] Buffer I/O error on dev nvme0n1p2, logical block 173, lost async page write
[ 3.365786] blk_update_request: critical medium error, dev nvme0n1, sector 533920 op 0x1:(WRITE) flags 0x800 phys_seg 2 prio class 0
[ 3.377717] Buffer I/O error on dev nvme0n1p2, logical block 180, lost async page write
[ 3.385746] Buffer I/O error on dev nvme0n1p2, logical block 181, lost async page write
[ 3.393779] blk_update_request: critical medium error, dev nvme0n1, sector 534080 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[ 3.405724] blk_update_request: critical medium error, dev nvme0n1, sector 534456 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[ 3.417670] blk_update_request: critical medium error, dev nvme0n1, sector 537704 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[ 3.429615] blk_update_request: critical medium error, dev nvme0n1, sector 544992 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[ 3.473628] JBD2: recovery failed
[ 3.477007] EXT4-fs (nvme0n1p2): error loading journal
[ 3.487235] VFS: Cannot open root device "PARTUUID=0507689b-02" or unknown-block(259,2): error -5
[ 3.496159] Please append a correct "root=" boot option; here are the available partitions:
[ 3.504555] 0100 4096 ram0
[ 3.504568] (driver?)
[ 3.510736] 0101 4096 ram1
[ 3.510749] (driver?)
[ 3.516897] 0102 4096 ram2
[ 3.516910] (driver?)
[ 3.523040] 0103 4096 ram3
[ 3.523054] (driver?)
[ 3.529245] 0104 4096 ram4
[ 3.529258] (driver?)
[ 3.535405] 0105 4096 ram5
[ 3.535425] (driver?)
[ 3.541554] 0106 4096 ram6
[ 3.541567] (driver?)
[ 3.547710] 0107 4096 ram7
[ 3.547723] (driver?)
[ 3.553851] 0108 4096 ram8
[ 3.553864] (driver?)
[ 3.560010] 0109 4096 ram9
[ 3.560023] (driver?)
[ 3.566167] 010a 4096 ram10
[ 3.566180] (driver?)
[ 3.572396] 010b 4096 ram11
[ 3.572409] (driver?)
[ 3.578641] 010c 4096 ram12
[ 3.578654] (driver?)
[ 3.584870] 010d 4096 ram13
[ 3.584883] (driver?)
[ 3.591112] 010e 4096 ram14
[ 3.591125] (driver?)
[ 3.597358] 010f 4096 ram15
[ 3.597371] (driver?)
[ 3.603608] 103:00000 500107608 nvme0n1
[ 3.603622] (driver?)
[ 3.610025] 103:00001 262144 nvme0n1p1 0507689b-01
[ 3.610038]
[ 3.616879] 103:00002 499841368 nvme0n1p2 0507689b-02
[ 3.616892]
[ 3.623720] Kernel panic - not syncing: VFS: Unable to mount root fs on unknown-block(259,2)
[ 3.632179] CPU: 1 PID: 1 Comm: swapper/0 Not tainted 5.10.78-v7l+ #1484
[ 3.638891] Hardware name: BCM2711
[ 3.642301] Backtrace:
[ 3.644781] [] (dump_backtrace) from [] (show_stack+0x20/0x24)
[ 3.652371] r7:ffffffff r6:00000000 r5:60000093 r4:c12e6f58
[ 3.658048] [] (show_stack) from [] (dump_stack+0xcc/0xf8)
[ 3.665292] [] (dump_stack) from [] (panic+0x130/0x33c)
[ 3.672270] r10:c1356000 r9:c0e1c824 r8:d645bdac r7:00008001 r6:c0e1c790 r5:00000000
[ 3.680116] r4:c13564b8 r3:00000001
[ 3.683707] [] (panic) from [] (mount_block_root+0x1f0/0x270)
[ 3.691206] r3:daeb6380 r2:daeb6380 r1:c190bea4 r0:c0e1c790
[ 3.696875] r7:00008001
[ 3.699420] [] (mount_block_root) from [] (mount_root+0x11c/0x138)
[ 3.707356] r10:c1356000 r9:c1054858 r8:c1000450 r7:c1811a00 r6:c1054838 r5:00000002
[ 3.715200] r4:c1205048
[ 3.717744] [] (mount_root) from [] (prepare_namespace+0x160/0x1a0)
[ 3.725766] r8:c1000450 r7:c1811a00 r6:c1054838 r5:c1054868 r4:c1356028
[ 3.732482] [] (prepare_namespace) from [] (kernel_init_freeable+0x2e8/0x300)
[ 3.741370] r5:00000143 r4:c1208084
[ 3.744959] [] (kernel_init_freeable) from [] (kernel_init+0x18/0x134)
[ 3.753242] r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c0b8e658
[ 3.761086] r4:00000000
[ 3.763633] [] (kernel_init) from [] (ret_from_fork+0x14/0x28)
[ 3.771218] Exception stack(0xc190bfb0 to 0xc190bff8)
[ 3.776280] bfa0: 00000000 00000000 00000000 00000000
[ 3.784476] bfc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[ 3.792670] bfe0: 00000000 00000000 00000000 00000000 00000013 00000000
[ 3.799296] r5:c0b8e658 r4:00000000
[ 3.802894] CPU3: stopping
[ 3.805618] CPU: 3 PID: 0 Comm: swapper/3 Not tainted 5.10.78-v7l+ #1484
[ 3.812330] Hardware name: BCM2711
[ 3.815738] Backtrace:
[ 3.818212] [] (dump_backtrace) from [] (show_stack+0x20/0x24)
[ 3.825801] r7:ffffffff r6:00000000 r5:60000193 r4:c12e6f58
[ 3.831479] [] (show_stack) from [] (dump_stack+0xcc/0xf8)
[ 3.838725] [] (dump_stack) from [] (do_handle_IPI+0x30c/0x340)
[ 3.846400] r10:c0e23cfc r9:c194c000 r8:c1818800 r7:00000001 r6:2ee96000 r5:00000003
[ 3.854245] r4:c1356390 r3:daeb6380
[ 3.857835] [] (do_handle_IPI) from [] (ipi_handler+0x28/0x30)
[ 3.865422] r9:c194c000 r8:c1818800 r7:00000001 r6:2ee96000 r5:00000014 r4:c1804d40
[ 3.873188] [] (ipi_handler) from [] (handle_percpu_devid_fasteoi_ipi+0x80/0x154)
[ 3.882431] [] (handle_percpu_devid_fasteoi_ipi) from [] (generic_handle_irq+0x44/0x54)
[ 3.892190] r7:00000001 r6:00000000 r5:00000000 r4:c1096d90
[ 3.897866] [] (generic_handle_irq) from [] (__handle_domain_irq+0x6c/0xc4)
[ 3.906588] [] (__handle_domain_irq) from [] (gic_handle_irq+0x90/0xa4)
[ 3.914957] r9:c194c000 r8:c1096d9c r7:c194df30 r6:f081400c r5:f0814000 r4:c1205b74
[ 3.922719] [] (gic_handle_irq) from [] (__irq_svc+0x5c/0x7c)
[ 3.930216] Exception stack(0xc194df30 to 0xc194df78)
[ 3.935279] df20: 00000000 00001310 eff2e344 c021ae40
[ 3.943475] df40: ffffe000 c120509c c12050e4 00000008 00000001 c133d86f c0e23cfc c194df8c
[ 3.951669] df60: c194df90 c194df80 c0208850 c0208854 60000013 ffffffff
[ 3.958298] r9:c194c000 r8:00000001 r7:c194df64 r6:ffffffff r5:60000013 r4:c0208854
[ 3.966068] [] (arch_cpu_idle) from [] (default_idle_call+0x4c/0x118)
[ 3.974268] [] (default_idle_call) from [] (do_idle+0x118/0x168)
[ 3.982031] [] (do_idle) from [] (cpu_startup_entry+0x28/0x30)
[ 3.989619] r10:00000000 r9:410fd083 r8:00007000 r7:c194dff8 r6:30c0387d r5:00000003
[ 3.997464] r4:00000092 r3:60000093
[ 4.001054] [] (cpu_startup_entry) from [] (secondary_start_kernel+0x170/0x17c)
[ 4.010122] [] (secondary_start_kernel) from [<002018b0>] (0x2018b0)
[ 4.017359] r5:00000000 r4:018f8c40
[ 4.020944] CPU2: stopping
[ 4.023670] CPU: 2 PID: 0 Comm: swapper/2 Not tainted 5.10.78-v7l+ #1484
[ 4.030384] Hardware name: BCM2711
[ 4.033793] Backtrace:
[ 4.036265] [] (dump_backtrace) from [] (show_stack+0x20/0x24)
[ 4.043855] r7:ffffffff r6:00000000 r5:60000193 r4:c12e6f58
[ 4.049533] [] (show_stack) from [] (dump_stack+0xcc/0xf8)
[ 4.056779] [] (dump_stack) from [] (do_handle_IPI+0x30c/0x340)
[ 4.064455] r10:c0e23cfc r9:c194a000 r8:c1818800 r7:00000001 r6:2ee82000 r5:00000002
[ 4.072301] r4:c1356390 r3:daeb6380
[ 4.075891] [] (do_handle_IPI) from [] (ipi_handler+0x28/0x30)
[ 4.083479] r9:c194a000 r8:c1818800 r7:00000001 r6:2ee82000 r5:00000014 r4:c1804d40
[ 4.091244] [] (ipi_handler) from [] (handle_percpu_devid_fasteoi_ipi+0x80/0x154)
[ 4.100487] [] (handle_percpu_devid_fasteoi_ipi) from [] (generic_handle_irq+0x44/0x54)
[ 4.110247] r7:00000001 r6:00000000 r5:00000000 r4:c1096d90
[ 4.115924] [] (generic_handle_irq) from [] (__handle_domain_irq+0x6c/0xc4)
[ 4.124646] [] (__handle_domain_irq) from [] (gic_handle_irq+0x90/0xa4)
[ 4.133016] r9:c194a000 r8:c1096d9c r7:c194bf30 r6:f081400c r5:f0814000 r4:c1205b74
[ 4.140779] [] (gic_handle_irq) from [] (__irq_svc+0x5c/0x7c)
[ 4.148276] Exception stack(0xc194bf30 to 0xc194bf78)
[ 4.153339] bf20: 00000000 000017f8 eff1a344 c021ae40
[ 4.161536] bf40: ffffe000 c120509c c12050e4 00000004 00000001 c133d86f c0e23cfc c194bf8c
[ 4.169731] bf60: c194bf90 c194bf80 c0208850 c0208854 60000013 ffffffff
[ 4.176360] r9:c194a000 r8:00000001 r7:c194bf64 r6:ffffffff r5:60000013 r4:c0208854
[ 4.184129] [] (arch_cpu_idle) from [] (default_idle_call+0x4c/0x118)
[ 4.192329] [] (default_idle_call) from [] (do_idle+0x118/0x168)
[ 4.200092] [] (do_idle) from [] (cpu_startup_entry+0x28/0x30)
[ 4.207679] r10:00000000 r9:410fd083 r8:00007000 r7:c194bff8 r6:30c0387d r5:00000002
[ 4.215524] r4:00000092 r3:60000093
[ 4.219114] [] (cpu_startup_entry) from [] (secondary_start_kernel+0x170/0x17c)
[ 4.228181] [] (secondary_start_kernel) from [<002018b0>] (0x2018b0)
[ 4.235418] r5:00000000 r4:018f8c40
[ 4.239002] CPU0: stopping
[ 4.241727] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.10.78-v7l+ #1484
[ 4.248439] Hardware name: BCM2711
[ 4.251848] Backtrace:
[ 4.254320] [] (dump_backtrace) from [] (show_stack+0x20/0x24)
[ 4.261908] r7:ffffffff r6:00000000 r5:60000193 r4:c12e6f58
[ 4.267585] [] (show_stack) from [] (dump_stack+0xcc/0xf8)
[ 4.274830] [] (dump_stack) from [] (do_handle_IPI+0x30c/0x340)
[ 4.282507] r10:c0e23cfc r9:c1200000 r8:c1818800 r7:00000001 r6:2ee5a000 r5:00000000
[ 4.290353] r4:c1356390 r3:daeb6380
[ 4.293942] [] (do_handle_IPI) from [] (ipi_handler+0x28/0x30)
[ 4.301530] r9:c1200000 r8:c1818800 r7:00000001 r6:2ee5a000 r5:00000014 r4:c1804d40
[ 4.309295] [] (ipi_handler) from [] (handle_percpu_devid_fasteoi_ipi+0x80/0x154)
[ 4.318538] [] (handle_percpu_devid_fasteoi_ipi) from [] (generic_handle_irq+0x44/0x54)
[ 4.328297] r7:00000001 r6:00000000 r5:00000000 r4:c1096d90
[ 4.333973] [] (generic_handle_irq) from [] (__handle_domain_irq+0x6c/0xc4)
[ 4.342694] [] (__handle_domain_irq) from [] (gic_handle_irq+0x90/0xa4)
[ 4.351064] r9:c1200000 r8:c1096d9c r7:c1201ec8 r6:f081400c r5:f0814000 r4:c1205b74
[ 4.358827] [] (gic_handle_irq) from [] (__irq_svc+0x5c/0x7c)
[ 4.366324] Exception stack(0xc1201ec8 to 0xc1201f10)
[ 4.371388] 1ec0: 00000000 00004634 efef2344 c021ae40 ffffe000 c120509c
[ 4.379584] 1ee0: c12050e4 00000001 00000001 c133d86f c0e23cfc c1201f24 c1201f28 c1201f18
[ 4.387777] 1f00: c0208850 c0208854 60000013 ffffffff
[ 4.392841] r9:c1200000 r8:00000001 r7:c1201efc r6:ffffffff r5:60000013 r4:c0208854
[ 4.400608] [] (arch_cpu_idle) from [] (default_idle_call+0x4c/0x118)
[ 4.408807] [] (default_idle_call) from [] (do_idle+0x118/0x168)
[ 4.416571] [] (do_idle) from [] (cpu_startup_entry+0x28/0x30)
[ 4.424159] r10:0000011e r9:c1054a60 r8:ffffffff r7:c1054a60 r6:c1205040 r5:c1205048
[ 4.432004] r4:000000d9 r3:c108c294
[ 4.435592] [] (cpu_startup_entry) from [] (rest_init+0xbc/0xc4)
[ 4.443358] [] (rest_init) from [] (arch_call_rest_init+0x18/0x1c)
[ 4.451291] r5:c1205048 r4:c1356068
[ 4.454880] [] (arch_call_rest_init) from [] (start_kernel+0x568/0x59c)
[ 4.463250] [] (start_kernel) from [<00000000>] (0x0)
[ 4.469183] r10:30c5387d r9:410fd083 r8:2eff3500 r7:00000c42 r6:30c0387d r5:00000000
[ 4.477027] r4:c1000330
[ 4.479588] ---[ end Kernel panic - not syncing: VFS: Unable to mount root fs on unknown-block(259,2) ]---
´´´

@peterharperuk
Copy link
Collaborator

Oh dear...
I have one of your disks on order so I'll be testing that. I really can't imagine why that bootloader would cause a problem. It's the same code as the stable build with debug logging enabled in a couple of modules.

@peterharperuk
Copy link
Collaborator

I've got the SSD you mentioned and can reproduce the problem you were seeing.

@peterharperuk
Copy link
Collaborator

I can repro the issue on a RPI IO board so it doesn't seem to be an issue with the Waveshare board.

@ctschach
Copy link
Author

I can repro the issue on a RPI IO board so it doesn't seem to be an issue with the Waveshare board.

No sure if I'm allowed to say: "great that you are facing the same problem" :-)

But definitely good that it's wasn't my fault. My other two disks are still in transit. I'll definitely test them both and will report back.

@peterharperuk
Copy link
Collaborator

The hardware is indicating a pcie error which seems to "appear" after initialisation. To recover we have to re-initialise the hardware. I have a change that fixes the issue for me - can you give it a try to confirm?
pieeprom.original2.zip

@ctschach
Copy link
Author

Are you sure this is the correct EEPROM? I

I do see an "Unknown boot mode 0x6. Trying SD." in the output on the console. I though the I need boot-mode "6" for NVME boot, but looks like this eeprom you just gave me do not support it.

SIG pieeprom.sig b440356d2b26f3b6434ea2750239d7e8e239023dea95447092de1297549e5959 1637330510
Reading EEPROM: 524288
Writing EEPROM
++++++++++++++++++++++++++++++..++++++++++++++++++++++++++++++++++++++++++++++++++++++.........................................+
Verify BOOT EEPROM
Reading EEPROM: 524288
BOOT-EEPROM: UPDATED

PM_RSTS: 0x00001000
RPi: BOOTLOADER release VERSION:ca381952 DATE: Nov 19 2021 TIME: 10:22:04 BOOTMODE: 0x00000006 part: 0 BUILD_TIMESTAMP=1637317322 0x72d970ff 0x00d03140 0x000b33c8
PM_RSTS: 0x00001000
part 00000000 reset_info 00000000
uSD voltage 3.3V
Initialising SDRAM 'Micron' 32Gb x2 total-size: 64 Gbit 3200
PCI reset
PCI reset
USB xHC init failed
Boot mode: SD (01) order f6
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
EMMC
SD retry 1 oc 0
SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080
SD retry 2 oc 0
SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080
SDV1
SD retry 3 oc 0
SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080
SD CMD: 0x371a0010 (55) 0x0 0x1fff0001
Failed to open device: 'sdcard' (cmd 371a0010 status 1fff0001)
Retry SD 1
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
EMMC
SD retry 1 oc 0
SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080
SD retry 2 oc 0
SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080
SDV1
SD retry 3 oc 0
SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080
SD CMD: 0x371a0010 (55) 0x0 0x1fff0001
Failed to open device: 'sdcard' (cmd 371a0010 status 1fff0001)
Boot mode:  (06) order f
Unknown boot mode 0x6. Trying SD.
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
EMMC
SD retry 1 oc 0
SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080
SD retry 2 oc 0
SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080
SDV1
SD retry 3 oc 0

@peterharperuk
Copy link
Collaborator

So sorry to waste your time. I picked an old branch. Here's the right one, and I've actually tested it! It should show up as version e0c6d67c
pieeprom.original3.zip

@ctschach
Copy link
Author

Okay, that one works better...much better :-)
No problem with a reboot at all.

But this is a different brand of NVMe card. The other one is already on it's way back to the vendor. Not sure it I get a replacement or a refund.

SIG pieeprom.sig 09c6c294f0270e91b5d4f591c83090c27bc18fb1a421d9027fd2a252a86d053b 1637336099
Reading EEPROM: 524288
Writing EEPROM
++++++++++++++++++++++++++++++.................................................................................................+
Verify BOOT EEPROM
Reading EEPROM: 524288
BOOT-EEPROM: UPDATED

PM_RSTS: 0x00001000
RPi: BOOTLOADER release VERSION:e0c6d67c DATE: Nov 19 2021 TIME: 14:17:52 BOOTMODE: 0x00000006 part: 0 BUILD_TIMESTAMP=1637331471 0x72d970ff 0x00d03140 0x000c6c09
PM_RSTS: 0x00001000
part 00000000 reset_info 00000000
uSD voltage 3.3V
Initialising SDRAM 'Micron' 32Gb x2 total-size: 64 Gbit 3200
Boot mode: SD (01) order f6
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
EMMC
SD retry 1 oc 0
SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080
SD retry 2 oc 0
SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080
SDV1
SD retry 3 oc 0
SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080
SD CMD: 0x371a0010 (55) 0x0 0x1fff0001
Failed to open device: 'sdcard' (cmd 371a0010 status 1fff0001)
Retry SD 1
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
EMMC
SD retry 1 oc 0
SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080
SD retry 2 oc 0
SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080
SDV1
SD retry 3 oc 0
SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080
SD CMD: 0x371a0010 (55) 0x0 0x1fff0001
Failed to open device: 'sdcard' (cmd 371a0010 status 1fff0001)
Boot mode: NVME (06) order f
VID 0x1e0f MN KBG40ZNS512G NVMe KIOXIA 512GB
NVME on
MBR: 0x00002000,  524288 type: 0x0c
MBR: 0x00082000,124203008 type: 0x83
MBR: 0x076f500c,875479716 type: 0x83
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: 0x00001000
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     2090 hnd 0x00000000
Read start4.elf bytes  2241504 hnd 0x00000000
Read fixup4.dat bytes     5411 hnd 0x00000000
Firmware: b8a114e5a9877e91ca8f26d1a5ce904b2ad3cf13 Oct 29 2021 10:47:33
0x00d03140 0x00000000 0x00000fff
MEM GPU: 76 ARM: 948 TOTAL: 1024
[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 5.10.63-v7l+ (dom@buildbot) (arm-linux-gnueabihf-gcc-8 (Ubuntu/Linaro 8.4.0-3ubuntu1) 8.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1459 SMP Wed Oct 6 16:41:57 BST 2021
[    0.000000] CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d
[    0.000000] CPU: div instructions available: patching division code
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
[    0.000000] OF: fdt: Machine model: Raspberry Pi Compute Module 4 Rev 1.0
[    0.000000] random: fast init done
[    0.000000] Memory policy: Data cache writealloc
[    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-0x000000002fffffff]
[    0.000000]   Normal   empty
[    0.000000]   HighMem  [mem 0x0000000030000000-0x00000001ffffffff]
[    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]   node   0: [mem 0x0000000100000000-0x00000001ffffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000001ffffffff]
[    0.000000] percpu: Embedded 20 pages/cpu s50828 r8192 d22900 u81920
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 2059584
[    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:62:3B:5C vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000  console=ttyS0,115200 console=tty1 root=PARTUUID=18fa53af-02 rootfstype=ext4 fsck.repair=yes rootwait
[    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear)
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] software IO TLB: mapped [mem 0x0000000012400000-0x0000000016400000] (64MB)
[    0.000000] Memory: 7758572K/8245248K available (10240K kernel code, 1364K rwdata, 3192K rodata, 2048K init, 891K bss, 158996K reserved, 327680K cma-reserved, 7458816K highmem)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] ftrace: allocating 34315 entries in 68 pages
[    0.000000] ftrace: allocated 68 pages with 2 groups
[    0.000000] rcu: Hierarchical RCU implementation.
[    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 10 jiffies.
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000000] GIC: Using split EOI/Deactivate mode
[    0.000000] irq_brcmstb_l2: registered L2 intc (/soc/interrupt-controller@7ef00100, parent irq: 25)
[    0.000000] random: get_random_bytes called from start_kernel+0x3c8/0x59c with crng_init=1
[    0.000008] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483647500ns
[    0.000034] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275 ns
[    0.000094] bcm2835: system timer (irq = 26)
[    0.000747] arch_timer: cp15 timer(s) running at 54.00MHz (phys).
[    0.000768] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns
[    0.000792] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns
[    0.000810] Switching to timer-based delay loop, resolution 18ns
[...]
[    4.594590] systemd[1]: Mounted Kernel Configuration File System.
[    4.609077] systemd[1]: Finished File System Check on Root Device.
[    4.621849] systemd[1]: Starting Remount Root and Kernel File Systems...

Raspbian GNU/Linux 11 raspberrypi ttyS0

raspberrypi login: pi
Password:
Linux raspberrypi 5.10.63-v7l+ #1459 SMP Wed Oct 6 16:41:57 BST 2021 armv7l

The programs included with the Debian GNU/Linux system are free software;
the exact distribution terms for each program are described in the
individual files in /usr/share/doc/*/copyright.

Debian GNU/Linux comes with ABSOLUTELY NO WARRANTY, to the extent
permitted by applicable law.
Last login: Fri Nov 19 14:23:20 GMT 2021 on ttyS0
pi@raspberrypi:~$ reboot now
Failed to write reboot parameter file: Permission denied
pi@raspberrypi:~$ sudo su
root@raspberrypi:/home/pi# reboot now

PM_RSTS: 0x00001020
RPi: BOOTLOADER release VERSION:e0c6d67c DATE: Nov 19 2021 TIME: 14:17:52 BOOTMODE: 0x00000006 part: 0 BUILD_TIMESTAMP=1637331471 0x72d970ff 0x00d03140 0x000c657d
PM_RSTS: 0x00001020
part 00000000 reset_info 00000000
uSD voltage 3.3V
Initialising SDRAM 'Micron' 32Gb x2 total-size: 64 Gbit 3200
Boot mode: SD (01) order f6
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
EMMC
SD retry 1 oc 0
SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080
SD retry 2 oc 0
SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080
SDV1
SD retry 3 oc 0
SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080
SD CMD: 0x371a0010 (55) 0x0 0x1fff0001
Failed to open device: 'sdcard' (cmd 371a0010 status 1fff0001)
Retry SD 1
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
EMMC
SD retry 1 oc 0
SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080
SD retry 2 oc 0
SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080
SDV1
SD retry 3 oc 0
SD HOST: 250000000 CTL0: 0x00000000 BUS: 100000 Hz actual: 100000 HZ div: 2500 (1250) status: 0x1fff0000 delay: 1080
SD CMD: 0x371a0010 (55) 0x0 0x1fff0001
Failed to open device: 'sdcard' (cmd 371a0010 status 1fff0001)
Boot mode: NVME (06) order f
VID 0x1e0f MN KBG40ZNS512G NVMe KIOXIA 512GB
NVME on
MBR: 0x00002000,  524288 type: 0x0c
MBR: 0x00082000,124203008 type: 0x83
MBR: 0x076f500c,875479716 type: 0x83
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: 0x00001020
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     2090 hnd 0x00000000
Read start4.elf bytes  2241504 hnd 0x00000000
Read fixup4.dat bytes     5411 hnd 0x00000000
Firmware: b8a114e5a9877e91ca8f26d1a5ce904b2ad3cf13 Oct 29 2021 10:47:33
0x00d03140 0x00000000 0x00000fff
MEM GPU: 76 ARM: 948 TOTAL: 1024
[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 5.10.63-v7l+ (dom@buildbot) (arm-linux-gnueabihf-gcc-8 (Ubuntu/Linaro 8.4.0-3ubuntu1) 8.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1459 SMP Wed Oct 6 16:41:57 BST 2021
[    0.000000] CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d
[    0.000000] CPU: div instructions available: patching division code
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
[    0.000000] OF: fdt: Machine model: Raspberry Pi Compute Module 4 Rev 1.0
[    0.000000] random: fast init done
[    0.000000] Memory policy: Data cache writealloc
[    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-0x000000002fffffff]
[    0.000000]   Normal   empty
[    0.000000]   HighMem  [mem 0x0000000030000000-0x00000001ffffffff]
[    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]   node   0: [mem 0x0000000100000000-0x00000001ffffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000001ffffffff]
[...]
``

@peterharperuk
Copy link
Collaborator

Thanks, much appreciated. I'll keep this open until a fix is released.

@peterharperuk
Copy link
Collaborator

The fix for this should be in released now.

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

No branches or pull requests

3 participants