search

raspberrypi / firmware

This repository contains pre-compiled binaries of the current Raspberry Pi kernel and modules, userspace libraries, and bootloader/GPU firmware.
5.15k stars 1.68k forks source link

Boot process hangs during start.elf when MT7921K is connected #1766

Open jolla opened 1 year ago

jolla commented 1 year ago

Describe the bug Boot process intermittantly hangs during (or just after) start.elf stage when Mediatek MT7921K (Wi-Fi 6E module) is connected

To reproduce Insert MT7921K Wi-Fi module and power on or reboot system

Expected behaviour start.elf process should complete and linux kernel should start booting

Actual behaviour System hangs during (or just after) start.elf process (see log output below)

System

Logs If applicable, add the relevant output from dmesg or similar. This is where it hangs during the boot process

recover4.elf not found (6) recovery.elf not found (6) Read start4db.elf bytes 3746856 hnd 0x000163a2 hash '06629a6b6aeaa30e' Read fixup4db.dat bytes 8382 hnd 0x0000040e hash 'd93f7d3e8ffe6eb8' 0x00a03140 0x00000000 0x00001fff MEM GPU: 76 ARM: 948 TOTAL: 1024 Starting start4db.elf @ 0xfec00200 partition 0

ASRT:00:00:05.088140:0: ../../../../../vcfw/drivers/chip/vciv/2708/clock_2711.c::clock_wait_busy!2151: timeout != 0 MESS:00:00:05.184667:0: arasan: arasan_emmc_open MESS:00:00:05.347863:0: brfs: File read: /mfs/sd/config.txt MESS:00:00:05.351212:0: brfs: File read: 1521 bytes MESS:00:00:05.371331:0: HDMI0:EDID error reading EDID block 0 attempt 0 MESS:00:00:05.375837:0: HDMI0:EDID giving up on reading EDID block 0 MESS:00:00:05.392886:0: HDMI1:EDID error reading EDID block 0 attempt 0 MESS:00:00:05.397393:0: HDMI1:EDID giving up on reading EDID block 0 MESS:00:00:05.404059:0: brfs: File read: /mfs/sd/config.txt MESS:00:00:05.408612:0: gpioman: gpioman_get_pin_num: pin DISPLAY_SDA not defined MESS:00:00:05.414974:0: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not defined MESS:00:00:05.950519:0: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not defined MESS:00:00:05.956326:0: *** Restart logging MESS:00:00:05.958807:0: brfs: File read: 1521 bytes MESS:00:00:05.968848:0: hdmi: HDMI0:EDID error reading EDID block 0 attempt 0 MESS:00:00:05.973871:0: hdmi: HDMI0:EDID giving up on reading EDID block 0 MESS:00:00:05.984497:0: hdmi: HDMI0:EDID error reading EDID block 0 attempt 0 MESS:00:00:05.989525:0: hdmi: HDMI0:EDID giving up on reading EDID block 0 MESS:00:00:05.995124:0: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead MESS:00:00:06.008916:0: hdmi: HDMI1:EDID error reading EDID block 0 attempt 0 MESS:00:00:06.013945:0: hdmi: HDMI1:EDID giving up on reading EDID block 0 MESS:00:00:06.024568:0: hdmi: HDMI1:EDID error reading EDID block 0 attempt 0 MESS:00:00:06.029589:0: hdmi: HDMI1:EDID giving up on reading EDID block 0 MESS:00:00:06.035187:0: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead MESS:00:00:06.043952:0: HDMI0: hdmi_pixel_encoding: 300000000 MESS:00:00:06.049425:0: HDMI1: hdmi_pixel_encoding: 300000000 MESS:00:00:06.055254:0: gpioman: gpioman_get_pin_num: pin CAMERA_0_I2C_PORT not defined MESS:00:00:06.085198:0: dtb_file 'bcm2711-rpi-cm4.dtb' MESS:00:00:06.093897:0: brfs: File read: /mfs/sd/bcm2711-rpi-cm4.dtb MESS:00:00:06.097144:0: Loaded 'bcm2711-rpi-cm4.dtb' to 0x100 size 0xcddf MESS:00:00:06.116912:0: brfs: File read: 52703 bytes MESS:00:00:06.135922:0: brfs: File read: /mfs/sd/overlays/overlay_map.dtb MESS:00:00:06.211636:0: brfs: File read: 2231 bytes MESS:00:00:06.228913:0: brfs: File read: /mfs/sd/overlays/rpi-poe.dtbo MESS:00:00:06.250264:0: Loaded overlay 'rpi-poe' MESS:00:00:06.332295:0: brfs: File read: 4168 bytes MESS:00:00:06.336557:0: brfs: File read: /mfs/sd/config.txt MESS:00:00:06.339571:0: brfs: File read: 1521 bytes MESS:00:00:06.356614:0: brfs: File read: /mfs/sd/overlays/pcie-32bit-dma.dtbo MESS:00:00:06.367462:0: Loaded overlay 'pcie-32bit-dma' MESS:00:00:06.380079:0: brfs: File read: 438 bytes MESS:00:00:06.387356:0: brfs: File read: /mfs/sd/overlays/dwc2.dtbo MESS:00:00:06.396796:0: Loaded overlay 'dwc2' MESS:00:00:06.398036:0: dtparam: dr_mode=host MESS:00:00:06.413274:0: brfs: File read: 801 bytes MESS:00:00:06.419708:0: brfs: File read: /mfs/sd/overlays/disable-wifi.dtbo MESS:00:00:06.432527:0: Loaded overlay 'disable-wifi' MESS:00:00:06.448799:0: brfs: File read: 387 bytes MESS:00:00:06.455827:0: brfs: File read: /mfs/sd/overlays/disable-bt.dtbo MESS:00:00:06.474765:0: Loaded overlay 'disable-bt' MESS:00:00:06.511022:0: brfs: File read: 1073 bytes MESS:00:00:06.532603:0: brfs: File read: /mfs/sd/overlays/vc4-fkms-v3d-pi4.dtbo MESS:00:00:06.555179:0: Loaded overlay 'vc4-fkms-v3d' MESS:00:00:06.593679:0: brfs: File read: 1446 bytes MESS:00:00:06.600197:0: brfs: File read: /mfs/sd/overlays/disable-wifi.dtbo MESS:00:00:06.613020:0: Loaded overlay 'disable-wifi' MESS:00:00:06.629180:0: brfs: File read: 387 bytes MESS:00:00:06.636456:0: brfs: File read: /mfs/sd/overlays/dwc2.dtbo MESS:00:00:06.645905:0: Loaded overlay 'dwc2' MESS:00:00:06.647147:0: dtparam: dr_mode=otg MESS:00:00:06.651356:0: dtparam: i2c_arm=on MESS:00:00:06.664105:0: dtparam: spi=on MESS:00:00:06.673350:0: dtparam: act_led_trigger=heartbeat MESS:00:00:06.719890:0: brfs: File read: 801 bytes MESS:00:00:06.723579:0: brfs: File read: /mfs/sd/cmdline.txt MESS:00:00:06.726968:0: Read command line from file 'cmdline.txt': MESS:00:00:06.732847:0: 'console=serial0,115200 console=tty1 root=PARTUUID=46a9230e-02 rootfstype=ext4 fsck.repair=yes rootwait' MESS:00:00:06.774038:0: CMA size reduced to 256MB (total_mem 1024MB, gpu_mem 76MB) MESS:00:00:06.849640:0: kernel=kernel8-wp.img MESS:00:00:06.850886:0: brfs: File read: 103 bytes MESS:00:00:08.627399:0: brfs: File read: /mfs/sd/kernel8-wp.img MESS:00:00:08.630218:0: Loaded 'kernel8-wp.img' to 0x80000 size 0x157ca00 MESS:00:00:08.657841:0: Kernel relocated to 0x200000 MESS:00:00:08.659694:0: Device tree loaded to 0x2eff2500 (size 0xda30) MESS:00:00:08.668777:0: uart: Set PL011 baud rate to 103448.300000 Hz MESS:00:00:08.675104:0: uart: Baud rate change done... MESS:00:00:08.677164:0: uart: Baud rate change done... MESS:00:00:08.686287:0: gpioman: gpioman_get_pin_num: pin SDCARD_CONTROL_POWER not defined

jolla commented 1 year ago

After a successful reboot I can trigger a kernel panic by disabling and enabling PCIe via an overlay, it sometimes requires disabling and enabling PCIe several times, but eventually I can trigger a kernel panic. Here is the output.

[ 69.005037] SError Interrupt on CPU0, code 0x00000000bf000002 -- SError [ 69.005051] CPU: 0 PID: 3491 Comm: dtoverlay Tainted: G C 5.19.17-v8-wlanpi+ #1 [ 69.005057] Hardware name: Raspberry Pi Compute Module 4 Rev 1.0 (DT) [ 69.005060] pstate: 200000c5 (nzCv daIF -PAN -UAO -TCO -DIT -SSBS BTYPE=--) [ 69.005065] pc : pci_generic_config_read+0x44/0xe0 [ 69.005080] lr : pci_generic_config_read+0x2c/0xe0 [ 69.005085] sp : ffffffc0092c33c0 [ 69.005087] x29: ffffffc0092c33c0 x28: ffffff8003ccb800 x27: 0000000000000001 [ 69.005096] x26: 0000000000000001 x25: ffffffd9536299b0 x24: 0000000000000000 [ 69.005102] x23: ffffffc0092c34f4 x22: ffffff8003ccb400 x21: 0000000000000087 [ 69.005108] x20: 0000000000000004 x19: ffffffc0092c3434 x18: 0000000000000000 [ 69.005113] x17: 0000000000000000 x16: 0000000000000000 x15: 0000000000000000 [ 69.005118] x14: 0000000000000000 x13: 0000000000000000 x12: 0000000000000000 [ 69.005124] x11: 0000000000000000 x10: 0000000000001a80 x9 : ffffffd9526c09ec [ 69.005129] x8 : 0000000080b5111d x7 : 000000000000ea60 x6 : ffffffc0092c34f4 [ 69.005135] x5 : ffffffc009280000 x4 : ffffff8003cc8f40 x3 : ffffffc009289000 [ 69.005140] x2 : 0000000000008000 x1 : 00000000deaddead x0 : ffffffc009288000 [ 69.005147] Kernel panic - not syncing: Asynchronous SError Interrupt [ 69.005151] CPU: 0 PID: 3491 Comm: dtoverlay Tainted: G C 5.19.17-v8-wlanpi+ #1 [ 69.005155] Hardware name: Raspberry Pi Compute Module 4 Rev 1.0 (DT) [ 69.005158] Call trace: [ 69.005159] dump_backtrace+0xe8/0xf8 [ 69.005165] show_stack+0x20/0x58 [ 69.005168] dump_stack_lvl+0x8c/0xb8 [ 69.005175] dump_stack+0x18/0x34 [ 69.005179] panic+0x184/0x37c [ 69.005183] add_taint+0x0/0xb0 [ 69.005188] arm64_serror_panic+0x6c/0x80 [ 69.005192] do_serror+0x3c/0x88 [ 69.005194] el1h_64_error_handler+0x38/0x50 [ 69.005199] el1h_64_error+0x64/0x68 [ 69.005203] pci_generic_config_read+0x44/0xe0 [ 69.005208] pci_bus_read_config_dword+0x88/0xf0 [ 69.005212] pci_bus_generic_read_dev_vendor_id+0x3c/0x1b8 [ 69.005217] pci_bus_read_dev_vendor_id+0x54/0x78 [ 69.005220] pci_scan_single_device+0x88/0xf8 [ 69.005223] pci_scan_slot+0x48/0x128 [ 69.005227] pci_scan_child_bus_extend+0x5c/0x2c0 [ 69.005230] pci_scan_child_bus+0x1c/0x28 [ 69.005234] pci_scan_bridge_extend+0x188/0x598 [ 69.005237] pci_scan_child_bus_extend+0x15c/0x2c0 [ 69.005240] pci_scan_root_bus_bridge+0x6c/0xe0 [ 69.005244] pci_host_probe+0x20/0xd0 [ 69.005247] brcm_pcie_probe+0x26c/0x5b8 [ 69.005251] platform_probe+0x70/0xe0 [ 69.005257] really_probe+0x124/0x2c8 [ 69.005260] driver_probe_device+0x80/0xe8 [ 69.005263] driver_probe_device+0x44/0xf8 [ 69.005266] device_attach_driver+0xc0/0x100 [ 69.005269] bus_for_each_drv+0x80/0xd8 [ 69.005275] device_attach+0x104/0x198 [ 69.005278] device_initial_probe+0x1c/0x28 [ 69.005281] bus_probe_device+0xa4/0xb0 [ 69.005286] device_add+0x390/0x830 [ 69.005290] of_device_add+0x5c/0x70 [ 69.005295] of_platform_device_create_pdata+0x98/0x100 [ 69.005299] of_platform_notify+0xec/0x180 [ 69.005302] blocking_notifier_call_chain+0x74/0xa8 [ 69.005308] of_property_notify+0x68/0xb0 [ 69.005313] __of_changeset_entry_notify+0xb8/0x118 [ 69.005318] of_changeset_revert_notify+0x4c/0x80 [ 69.005323] of_overlay_remove+0x1c0/0x2b8 [ 69.005327] cfs_overlay_release+0x34/0x60 [ 69.005332] config_item_release+0x64/0x138 [ 69.005338] config_item_put+0x70/0x120 [ 69.005342] configfs_rmdir+0x1f0/0x2d0 [ 69.005346] vfs_rmdir+0x100/0x210 [ 69.005350] do_rmdir+0x194/0x1c0 [ 69.005354] __arm64_sys_unlinkat+0x70/0x90 [ 69.005358] invoke_syscall+0x4c/0x110 [ 69.005364] el0_svc_common.constprop.0+0x68/0x128 [ 69.005369] do_el0_svc+0x34/0xc0 [ 69.005374] el0_svc+0x30/0x98 [ 69.005377] el0t_64_sync_handler+0xb8/0xc0 [ 69.005380] el0t_64_sync+0x18c/0x190 [ 69.005385] SMP: stopping secondary CPUs [ 69.005393] Kernel Offset: 0x194a000000 from 0xffffffc008000000 [ 69.005396] PHYS_OFFSET: 0x0 [ 69.005398] CPU features: 0x2000,04027810,00001086 [ 69.005401] Memory Limit: none [ 69.379250] ---[ end Kernel panic - not syncing: Asynchronous SError Interrupt ]---

pelwell commented 1 year ago

I don't think enabling PCie at runtime is supported. I wouldn't be surprised (can't check right now) if the firmware has to turn on some clocks etc.

jolla commented 1 year ago

Adding dtparm=pcie=off to boot/config.txt I was able to disable PCIe and get the system to reliably boot/reboot without hanging. After the system is booted I can use dtparm pcie=on to enable PCIe and the MT7921K Wi-Fi module, however intermittently the system will kernel panic while PCIe is enabling, I'm assuming this is the same reason the system hangs trying to load the kernel. Any ideas how to debug what is causing this?

�recover4.elf not found (6) recovery.elf not found (6) Read start4db.elf bytes 3746856 hnd 0x000163a2 hash '06629a6b6aeaa30e' Read fixup4db.dat bytes 8382 hnd 0x0000040e hash 'd93f7d3e8ffe6eb8' 0x00a03140 0x00000000 0x00001fff MEM GPU: 76 ARM: 948 TOTAL: 1024 Starting start4db.elf @ 0xfec00200 partition 0

ASRT:00:00:05.120497:0: ../../../../../vcfw/drivers/chip/vciv/2708/clock_2711.c::clock_wait_busy!2151: timeout != 0 MESS:00:00:05.217023:0: arasan: arasan_emmc_open MESS:00:00:05.379322:0: brfs: File read: /mfs/sd/config.txt MESS:00:00:05.382697:0: brfs: File read: 1577 bytes MESS:00:00:05.402809:0: HDMI0:EDID error reading EDID block 0 attempt 0 MESS:00:00:05.407314:0: HDMI0:EDID giving up on reading EDID block 0 MESS:00:00:05.424363:0: HDMI1:EDID error reading EDID block 0 attempt 0 MESS:00:00:05.428870:0: HDMI1:EDID giving up on reading EDID block 0 MESS:00:00:05.435576:0: brfs: File read: /mfs/sd/config.txt MESS:00:00:05.440105:0: gpioman: gpioman_get_pin_num: pin DISPLAY_SDA not defined MESS:00:00:05.446450:0: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not defined MESS:00:00:05.949045:0: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not defined MESS:00:00:05.954851:0: *** Restart logging MESS:00:00:05.957333:0: brfs: File read: 1577 bytes MESS:00:00:05.967394:0: hdmi: HDMI0:EDID error reading EDID block 0 attempt 0 MESS:00:00:05.972416:0: hdmi: HDMI0:EDID giving up on reading EDID block 0 MESS:00:00:05.983042:0: hdmi: HDMI0:EDID error reading EDID block 0 attempt 0 MESS:00:00:05.988071:0: hdmi: HDMI0:EDID giving up on reading EDID block 0 MESS:00:00:05.993669:0: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead MESS:00:00:06.007461:0: hdmi: HDMI1:EDID error reading EDID block 0 attempt 0 MESS:00:00:06.012491:0: hdmi: HDMI1:EDID giving up on reading EDID block 0 MESS:00:00:06.023114:0: hdmi: HDMI1:EDID error reading EDID block 0 attempt 0 MESS:00:00:06.028135:0: hdmi: HDMI1:EDID giving up on reading EDID block 0 MESS:00:00:06.033733:0: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead MESS:00:00:06.042498:0: HDMI0: hdmi_pixel_encoding: 300000000 MESS:00:00:06.047966:0: HDMI1: hdmi_pixel_encoding: 300000000 MESS:00:00:06.053791:0: gpioman: gpioman_get_pin_num: pin CAMERA_0_I2C_PORT not defined MESS:00:00:06.083743:0: dtb_file 'bcm2711-rpi-cm4.dtb' MESS:00:00:06.091669:0: brfs: File read: /mfs/sd/bcm2711-rpi-cm4.dtb MESS:00:00:06.094916:0: Loaded 'bcm2711-rpi-cm4.dtb' to 0x100 size 0xcddf MESS:00:00:06.114633:0: brfs: File read: 52703 bytes MESS:00:00:06.134484:0: brfs: File read: /mfs/sd/overlays/overlay_map.dtb MESS:00:00:06.210310:0: brfs: File read: 2231 bytes MESS:00:00:06.227425:0: brfs: File read: /mfs/sd/overlays/rpi-poe.dtbo MESS:00:00:06.248925:0: Loaded overlay 'rpi-poe' MESS:00:00:06.330913:0: brfs: File read: 4168 bytes MESS:00:00:06.335103:0: brfs: File read: /mfs/sd/config.txt MESS:00:00:06.338193:0: brfs: File read: 1577 bytes MESS:00:00:06.354523:0: brfs: File read: /mfs/sd/overlays/pcie-32bit-dma.dtbo MESS:00:00:06.365378:0: Loaded overlay 'pcie-32bit-dma' MESS:00:00:06.367505:0: dtparam: pcie=off MESS:00:00:06.392913:0: brfs: File read: 438 bytes MESS:00:00:06.399950:0: brfs: File read: /mfs/sd/overlays/dwc2.dtbo MESS:00:00:06.409292:0: Loaded overlay 'dwc2' MESS:00:00:06.410535:0: dtparam: dr_mode=host MESS:00:00:06.425769:0: brfs: File read: 801 bytes MESS:00:00:06.432012:0: brfs: File read: /mfs/sd/overlays/disable-wifi.dtbo MESS:00:00:06.444817:0: Loaded overlay 'disable-wifi' MESS:00:00:06.461118:0: brfs: File read: 387 bytes MESS:00:00:06.467445:0: brfs: File read: /mfs/sd/overlays/disable-bt.dtbo MESS:00:00:06.486359:0: Loaded overlay 'disable-bt' MESS:00:00:06.522485:0: brfs: File read: 1073 bytes MESS:00:00:06.543724:0: brfs: File read: /mfs/sd/overlays/vc4-fkms-v3d-pi4.dtbo MESS:00:00:06.566179:0: Loaded overlay 'vc4-fkms-v3d' MESS:00:00:06.604574:0: brfs: File read: 1446 bytes MESS:00:00:06.610871:0: brfs: File read: /mfs/sd/overlays/disable-wifi.dtbo MESS:00:00:06.623733:0: Loaded overlay 'disable-wifi' MESS:00:00:06.639902:0: brfs: File read: 387 bytes MESS:00:00:06.646533:0: brfs: File read: /mfs/sd/overlays/dwc2.dtbo MESS:00:00:06.655881:0: Loaded overlay 'dwc2' MESS:00:00:06.657119:0: dtparam: dr_mode=otg MESS:00:00:06.661328:0: dtparam: i2c_arm=on MESS:00:00:06.674012:0: dtparam: spi=on MESS:00:00:06.683254:0: dtparam: act_led_trigger=heartbeat MESS:00:00:06.729386:0: brfs: File read: 801 bytes MESS:00:00:06.733044:0: brfs: File read: /mfs/sd/cmdline.txt MESS:00:00:06.736469:0: Read command line from file 'cmdline.txt': MESS:00:00:06.742348:0: 'console=serial0,115200 console=tty1 root=PARTUUID=46a9230e-02 rootfstype=ext4 fsck.repair=yes rootwait' MESS:00:00:06.783490:0: CMA size reduced to 256MB (total_mem 1024MB, gpu_mem 76MB) MESS:00:00:06.859181:0: kernel=kernel8-wp.img MESS:00:00:06.860430:0: brfs: File read: 103 bytes MESS:00:00:08.630052:0: brfs: File read: /mfs/sd/kernel8-wp.img MESS:00:00:08.632867:0: Loaded 'kernel8-wp.img' to 0x80000 size 0x157d200 MESS:00:00:08.660495:0: Kernel relocated to 0x200000 MESS:00:00:08.662345:0: Device tree loaded to 0x2eff2500 (size 0xda48) MESS:00:00:08.670695:0: uart: Set PL011 baud rate to 103448.300000 Hz MESS:00:00:08.677732:0: uart: Baud rate change done... MESS:00:00:08.679788:0: uart: Baud rate change done... MESS:00:00:08.688202:0: gpioman: gpioman_get_pin_num: pin SDCARD_CONTROL_POWER not defined [ 0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd083] [ 0.000000] Linux version 5.19.17-v8-wlanpi+ (runner@fv-az77-370) (aarch64-linux-gnu-gcc (Ubuntu 9.4.0-1ubuntu1~20.04.1) 9.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1 SMP PREEMPT Thu Dec 22 19:55:42 UTC 2022 [ 0.000000] random: crng init done [ 0.000000] Machine model: Raspberry Pi Compute Module 4 Rev 1.0 [ 0.000000] efi: UEFI not found. [ 0.000000] Reserved memory: created CMA memory pool at 0x000000001ec00000, size 256 MiB [ 0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000000000-0x000000003b3fffff] [ 0.000000] DMA32 empty [ 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] Initmem setup node 0 [mem 0x0000000000000000-0x000000003b3fffff] [ 0.000000] On node 0, zone DMA: 19456 pages in unavailable ranges [ 0.000000] percpu: Embedded 29 pages/cpu s78184 r8192 d32408 u118784 [ 0.000000] Detected PIPT I-cache on CPU0 [ 0.000000] CPU features: detected: Spectre-v2 [ 0.000000] CPU features: detected: Spectre-v3a [ 0.000000] CPU features: detected: Spectre-v4 [ 0.000000] CPU features: detected: Spectre-BHB [ 0.000000] CPU features: kernel page table isolation forced ON by KASLR [ 0.000000] CPU features: detected: Kernel page table isolation (KPTI) [ 0.000000] CPU features: detected: ARM erratum 1742098 [ 0.000000] CPU features: detected: ARM errata 1165522, 1319367, or 1530923 [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 238896 [ 0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=1 snd_bcm2835.enable_headphones=0 smsc95xx.macaddr=DC:A6:32:E7:26:27 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 console=ttyAMA0,115200 console=tty1 root=PARTUUID=46a9230e-02 rootfstype=ext4 fsck.repair=yes rootwait [ 0.000000] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes, linear) [ 0.000000] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes, linear) [ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off [ 0.000000] Memory: 664480K/970752K available (11712K kernel code, 2036K rwdata, 4168K rodata, 3968K init, 1439K bss, 44128K reserved, 262144K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] ftrace: allocating 39160 entries in 153 pages [ 0.000000] ftrace: allocated 153 pages with 4 groups [ 0.000000] trace event string verifier disabled [ 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] Root IRQ handler: gic_handle_irq [ 0.000000] GIC: Using split EOI/Deactivate mode [ 0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention. [ 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.000001] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns [ 0.000375] Console: colour dummy device 80x25 [ 0.000918] printk: console [tty1] enabled [ 0.000977] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=216000) [ 0.001017] pid_max: default: 32768 minimum: 301 [ 0.001146] LSM: Security Framework initializing [ 0.001361] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes, linear) [ 0.001407] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes, linear) [ 0.002536] cgroup: Disabling memory control group subsystem [ 0.004556] cblist_init_generic: Setting adjustable number of callback queues. [ 0.004588] cblist_init_generic: Setting shift to 2 and lim to 1. [ 0.004769] cblist_init_generic: Setting shift to 2 and lim to 1. [ 0.004947] cblist_init_generic: Setting shift to 2 and lim to 1. [ 0.005349] rcu: Hierarchical SRCU implementation. [ 0.005373] rcu: Max phase no-delay instances is 1000. [ 0.006705] EFI services will not be available. [ 0.007212] smp: Bringing up secondary CPUs ... [ 0.008297] Detected PIPT I-cache on CPU1 [ 0.008375] CPU1: Booted secondary processor 0x0000000001 [0x410fd083] [ 0.009471] Detected PIPT I-cache on CPU2 [ 0.009522] CPU2: Booted secondary processor 0x0000000002 [0x410fd083] [ 0.010548] Detected PIPT I-cache on CPU3 [ 0.010597] CPU3: Booted secondary processor 0x0000000003 [0x410fd083] [ 0.010736] smp: Brought up 1 node, 4 CPUs [ 0.010825] SMP: Total of 4 processors activated. [ 0.010845] CPU features: detected: 32-bit EL0 Support [ 0.010864] CPU features: detected: 32-bit EL1 Support [ 0.010885] CPU features: detected: CRC32 instructions [ 0.012889] CPU: All CPU(s) started at EL2 [ 0.012966] alternatives: patching kernel code [ 0.014247] devtmpfs: initialized [ 0.025193] Enabled cp15_barrier support [ 0.025261] Enabled setend support [ 0.025290] KASLR enabled [ 0.037703] DMA-API: preallocated 65536 debug entries [ 0.037755] DMA-API: debugging enabled by kernel config [ 0.037776] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns [ 0.037825] futex hash table entries: 1024 (order: 4, 65536 bytes, linear) [ 0.044869] pinctrl core: initialized pinctrl subsystem [ 0.045737] DMI not present or invalid. [ 0.046411] NET: Registered PF_NETLINK/PF_ROUTE protocol family [ 0.049944] DMA: preallocated 1024 KiB GFP_KERNEL pool for atomic allocations [ 0.050303] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations [ 0.051225] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations [ 0.051328] audit: initializing netlink subsys (disabled) [ 0.051597] audit: type=2000 audit(0.048:1): state=initialized audit_enabled=0 res=1 [ 0.052159] thermal_sys: Registered thermal governor 'step_wise' [ 0.052580] cpuidle: using governor menu [ 0.052876] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers. [ 0.053078] ASID allocator initialised with 32768 entries [ 0.053231] Serial: AMBA PL011 UART driver [ 0.063337] bcm2835-mbox fe00b880.mailbox: mailbox enabled [ 0.080348] raspberrypi-firmware soc:firmware: Attached to firmware from 2022-10-26T11:09:36, variant start_db [ 0.084324] raspberrypi-firmware soc:firmware: Firmware hash is c72ad6b26ff40c91ef776b847436094ee63fabee [ 0.126361] bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1 [ 0.130878] SCSI subsystem initialized [ 0.131106] usbcore: registered new interface driver usbfs [ 0.131185] usbcore: registered new interface driver hub [ 0.131260] usbcore: registered new device driver usb [ 0.131577] usb_phy_generic phy: supply vcc not found, using dummy regulator [ 0.131774] usb_phy_generic phy: dummy supplies not allowed for exclusive requests [ 0.132078] pps_core: LinuxPPS API ver. 1 registered [ 0.132101] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti giometti@linux.it [ 0.132147] PTP clock support registered [ 0.133190] vgaarb: loaded [ 0.133840] clocksource: Switched to clocksource arch_sys_counter [ 1.137991] VFS: Disk quotas dquot_6.6.0 [ 1.138115] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 1.138280] FS-Cache: Loaded [ 1.138520] CacheFiles: Loaded [ 1.148763] NET: Registered PF_INET protocol family [ 1.149073] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear) [ 1.151098] tcp_listen_portaddr_hash hash table entries: 512 (order: 1, 8192 bytes, linear) [ 1.151157] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear) [ 1.151195] TCP established hash table entries: 8192 (order: 4, 65536 bytes, linear) [ 1.151284] TCP bind hash table entries: 8192 (order: 5, 131072 bytes, linear) [ 1.151433] TCP: Hash tables configured (established 8192 bind 8192) [ 1.151664] UDP hash table entries: 512 (order: 2, 16384 bytes, linear) [ 1.151715] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear) [ 1.151980] NET: Registered PF_UNIX/PF_LOCAL protocol family [ 1.152753] RPC: Registered named UNIX socket transport module. [ 1.152782] RPC: Registered udp transport module. [ 1.152801] RPC: Registered tcp transport module. [ 1.152820] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 1.152849] PCI: CLS 0 bytes, default 64 [ 1.155125] hw perfevents: enabled with armv8_cortex_a72 PMU driver, 7 counters available [ 1.155518] kvm [1]: IPA Size Limit: 44 bits [ 1.156927] kvm [1]: vgic interrupt IRQ9 [ 1.157166] kvm [1]: Hyp mode initialized successfully [ 1.159213] Initialise system trusted keyrings [ 1.159540] workingset: timestamp_bits=46 max_order=18 bucket_order=0 [ 1.166280] zbud: loaded [ 1.168744] NFS: Registering the id_resolver key type [ 1.168804] Key type id_resolver registered [ 1.168825] Key type id_legacy registered [ 1.168934] nfs4filelayout_init: NFSv4 File Layout Driver Registering... [ 1.168960] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering... [ 1.170279] Key type asymmetric registered [ 1.170307] Asymmetric key parser 'x509' registered [ 1.170384] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 1.170640] io scheduler mq-deadline registered [ 1.170665] io scheduler kyber registered [ 1.174747] gpio gpiochip0: (pinctrl-bcm2711): not an immutable chip, please consider fixing it! [ 1.178749] gpio-507 (ant1): hogged as output/high [ 1.180261] gpio-511 (ant2): hogged as output/low [ 1.191498] Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled [ 1.193999] iproc-rng200 fe104000.rng: hwrng registered [ 1.194438] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB) [ 1.195725] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000 [ 1.208569] brd: module loaded [ 1.217007] loop: module loaded [ 1.217729] Loading iSCSI transport class v2.0-870. [ 1.222588] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000 [ 1.281995] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus [ 1.283097] usbcore: registered new interface driver r8152 [ 1.283174] usbcore: registered new interface driver lan78xx [ 1.283265] usbcore: registered new interface driver smsc95xx [ 1.309282] xhci-hcd fe9c0000.xhci: xHCI Host Controller [ 1.309329] xhci-hcd fe9c0000.xhci: new USB bus registered, assigned bus number 1 [ 1.309748] xhci-hcd fe9c0000.xhci: USB3 root hub has no ports [ 1.309777] xhci-hcd fe9c0000.xhci: hcc params 0x0220fe65 hci version 0x110 quirks 0x0000000000010010 [ 1.309935] xhci-hcd fe9c0000.xhci: irq 31, io mem 0xfe9c0000 [ 1.310518] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.19 [ 1.310554] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 [ 1.310581] usb usb1: Product: xHCI Host Controller [ 1.310603] usb usb1: Manufacturer: Linux 5.19.17-v8-wlanpi+ xhci-hcd [ 1.310626] usb usb1: SerialNumber: fe9c0000.xhci [ 1.311316] hub 1-0:1.0: USB hub found [ 1.311392] hub 1-0:1.0: 1 port detected [ 1.312100] dwc_otg: version 3.00a 10-AUG-2012 (platform bus) [ 1.312936] usbcore: registered new interface driver uas [ 1.313037] usbcore: registered new interface driver usb-storage [ 1.313285] mousedev: PS/2 mouse device common for all mice [ 1.318249] sdhci: Secure Digital Host Controller Interface driver [ 1.318286] sdhci: Copyright(c) Pierre Ossman [ 1.318782] sdhci-pltfm: SDHCI platform and OF driver helper [ 1.322302] ledtrig-cpu: registered to indicate activity on CPUs [ 1.322663] hid: raw HID events driver (C) Jiri Kosina [ 1.322884] usbcore: registered new interface driver usbhid [ 1.322909] usbhid: USB HID core driver [ 1.323117] bcm2835_vchiq fe00b840.mailbox: there is not valid maps for state default [ 1.331276] NET: Registered PF_PACKET protocol family [ 1.331431] Key type dns_resolver registered [ 1.332634] registered taskstats version 1 [ 1.332698] Loading compiled-in X.509 certificates [ 1.333517] Key type ._fscrypt registered [ 1.333543] Key type .fscrypt registered [ 1.333562] Key type fscrypt-provisioning registered [ 1.349412] uart-pl011 fe201000.serial: there is not valid maps for state default [ 1.350103] uart-pl011 fe201000.serial: cts_event_workaround enabled [ 1.350266] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 33, base_baud = 0) is a PL011 rev2 [ 1.565873] usb 1-1: new high-speed USB device number 2 using xhci-hcd [ 1.568132] printk: console [ttyAMA0] enabled [ 1.756390] usb 1-1: New USB device found, idVendor=0424, idProduct=2514, bcdDevice= b.b3 [ 1.770283] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer [ 1.770958] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 [ 1.775962] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver [ 1.831654] hub 1-1:1.0: USB hub found [ 1.842807] of_cfs_init [ 1.843591] hub 1-1:1.0: 4 ports detected [ 1.847646] of_cfs_init: OK [ 1.874644] mmc0: SDHCI controller on fe340000.mmc [fe340000.mmc] using ADMA [ 2.589037] Waiting for root device PARTUUID=46a9230e-02... [ 2.691264] mmc0: new ultra high speed DDR50 SDHC card at address aaaa [ 2.698916] mmcblk0: mmc0:aaaa SH32G 29.7 GiB [ 2.706951] mmcblk0: p1 p2 [ 2.710325] mmcblk0: mmc0:aaaa SH32G 29.7 GiB (quirks 0x00004000) [ 2.732413] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Quota mode: none. [ 2.741095] VFS: Mounted root (ext4 filesystem) readonly on device 179:2. [ 2.749203] devtmpfs: mounted [ 2.761064] Freeing unused kernel memory: 3968K [ 2.774007] Run /sbin/init as init process [ 3.113961] systemd[1]: System time before build time, advancing clock. [ 3.321957] NET: Registered PF_INET6 protocol family [ 3.328918] Segment Routing with IPv6 [ 3.332671] In-situ OAM (IOAM) with IPv6 [ 3.401806] systemd[1]: systemd 247.3-7+deb11u1 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.425962] systemd[1]: Detected architecture arm64. [ 3.452716] systemd[1]: Set hostname to . [ 3.614225] uart-pl011 fe201000.serial: no DMA platform data [ 4.169874] systemd[1]: Queued start job for default target Multi-User System. [ 4.181784] systemd[1]: Created slice system-getty.slice. [ 4.189081] systemd[1]: Created slice system-modprobe.slice. [ 4.196107] systemd[1]: Created slice system-serial\x2dgetty.slice. [ 4.203743] systemd[1]: Created slice system-systemd\x2dfsck.slice. [ 4.211200] systemd[1]: Created slice User and Session Slice. [ 4.217801] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ 4.226630] systemd[1]: Started Forward Password Requests to Wall Directory Watch. [ 4.235585] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point. [ 4.245567] systemd[1]: Reached target Local Encrypted Volumes. [ 4.252025] systemd[1]: Reached target Paths. [ 4.256827] systemd[1]: Reached target Slices. [ 4.261695] systemd[1]: Reached target Swap. [ 4.266388] systemd[1]: Reached target System Time Set. [ 4.272827] systemd[1]: Listening on Syslog Socket. [ 4.278770] systemd[1]: Listening on fsck to fsckd communication Socket. [ 4.286202] systemd[1]: Listening on initctl Compatibility Named Pipe. [ 4.294239] systemd[1]: Listening on Journal Audit Socket. [ 4.300823] systemd[1]: Listening on Journal Socket (/dev/log). [ 4.308050] systemd[1]: Listening on Journal Socket. [ 4.314468] systemd[1]: Listening on Network Service Netlink Socket. [ 4.324579] systemd[1]: Listening on udev Control Socket. [ 4.331386] systemd[1]: Listening on udev Kernel Socket. [ 4.338004] systemd[1]: Condition check resulted in Huge Pages File System being skipped. [ 4.350209] systemd[1]: Mounting POSIX Message Queue File System... [ 4.361113] systemd[1]: Mounting RPC Pipe File System... [ 4.371647] systemd[1]: Mounting Kernel Debug File System... [ 4.382562] systemd[1]: Mounting Kernel Trace File System... [ 4.389108] systemd[1]: Condition check resulted in Kernel Module supporting RPCSEC_GSS being skipped. [ 4.403982] systemd[1]: Starting Restore / save the current clock... [ 4.416635] systemd[1]: Starting Set the console keyboard layout... [ 4.428646] systemd[1]: Starting Create list of static device nodes for the current kernel... [ 4.442696] systemd[1]: Starting Load Kernel Module configfs... [ 4.454092] systemd[1]: Starting Load Kernel Module drm... [ 4.466402] systemd[1]: Starting Load Kernel Module fuse... [ 4.476950] systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. [ 4.491020] systemd[1]: Starting File System Check on Root Device... [ 4.509032] systemd[1]: Starting Journal Service... [ 4.515989] fuse: init (API version 7.36) [ 4.539287] systemd[1]: Starting Load Kernel Modules... [ 4.550208] systemd[1]: Starting Coldplug All udev Devices... [ 4.561609] systemd[1]: Starting Uncomplicated firewall... [ 4.590594] systemd[1]: Mounted POSIX Message Queue File System. [ 4.598950] systemd[1]: Mounted RPC Pipe File System. [ 4.605218] systemd[1]: Mounted Kernel Debug File System. [ 4.612368] systemd[1]: Mounted Kernel Trace File System. [ 4.636360] systemd[1]: Finished Restore / save the current clock. [ 4.658244] systemd[1]: Finished Create list of static device nodes for the current kernel. [ 4.684386] systemd[1]: modprobe@configfs.service: Succeeded. [ 4.703611] systemd[1]: Finished Load Kernel Module configfs. [ 4.712939] systemd[1]: modprobe@drm.service: Succeeded. [ 4.726309] systemd[1]: Finished Load Kernel Module drm. [ 4.734416] systemd[1]: modprobe@fuse.service: Succeeded. [ 4.751300] UDC core: g_ether: couldn't find an available UDC [ 4.757671] systemd[1]: Finished Load Kernel Module fuse. [ 4.769454] systemd[1]: Finished File System Check on Root Device. [ 4.779037] systemd[1]: Finished Load Kernel Modules. [ 4.790698] systemd[1]: Mounting FUSE Control File System... [ 4.802118] systemd[1]: Mounting Kernel Configuration File System... [ 4.822092] systemd[1]: Started File System Check Daemon to report status. [ 4.844581] systemd[1]: Starting Remount Root and Kernel File Systems... [ 4.856553] systemd[1]: Starting Apply Kernel Variables... [ 4.869712] systemd[1]: Started Journal Service. [ 18.516046] SError Interrupt on CPU2, code 0x00000000bf000002 -- SError [ 18.516057] CPU: 2 PID: 1198 Comm: dtparam Tainted: G C 5.19.17-v8-wlanpi+ #1 [ 18.516063] Hardware name: Raspberry Pi Compute Module 4 Rev 1.0 (DT) [ 18.516066] pstate: 200000c5 (nzCv daIF -PAN -UAO -TCO -DIT -SSBS BTYPE=--) [ 18.516070] pc : pci_generic_config_read+0x44/0xe0 [ 18.516087] lr : pci_generic_config_read+0x2c/0xe0 [ 18.516093] sp : ffffffc009463390 [ 18.516095] x29: ffffffc009463390 x28: ffffff8005540800 x27: 0000000000000000 [ 18.516104] x26: 0000000000000001 x25: ffffffdfef68a9b0 x24: 0000000000000000 [ 18.516110] x23: ffffffc009463460 x22: ffffff8005ccec00 x21: 0000000000000087 [ 18.516116] x20: 0000000000000004 x19: ffffffc009463404 x18: 0000000000000001 [ 18.516121] x17: 6572202c295d6666 x16: 2d6666207375625b x15: ffffff801150e2a8 [ 18.516126] x14: ffffffffffffffff x13: ffffff80117b618d x12: ffffff80117b618b [ 18.516132] x11: 0000000000000000 x10: 000000000000002e x9 : ffffffdfee6c512c [ 18.516137] x8 : 000000000000002e x7 : ffffffc0094634a0 x6 : 0000000000000000 [ 18.516142] x5 : ffffffc0094e0000 x4 : ffffff8005542b40 x3 : ffffffc0094e9000 [ 18.516147] x2 : 0000000000008000 x1 : 00000000deaddead x0 : ffffffc0094e8000 [ 18.516155] Kernel panic - not syncing: Asynchronous SError Interrupt [ 18.516158] CPU: 2 PID: 1198 Comm: dtparam Tainted: G C 5.19.17-v8-wlanpi+ #1 [ 18.516162] Hardware name: Raspberry Pi Compute Module 4 Rev 1.0 (DT) [ 18.516165] Call trace: [ 18.516166] dump_backtrace+0xe8/0xf8 [ 18.516172] show_stack+0x20/0x58 [ 18.516175] dump_stack_lvl+0x8c/0xb8 [ 18.516183] dump_stack+0x18/0x34 [ 18.516187] panic+0x184/0x37c [ 18.516191] add_taint+0x0/0xb0 [ 18.516196] arm64_serror_panic+0x6c/0x80 [ 18.516199] do_serror+0x3c/0x88 [ 18.516202] el1h_64_error_handler+0x38/0x50 [ 18.516208] el1h_64_error+0x64/0x68 [ 18.516212] pci_generic_config_read+0x44/0xe0 [ 18.516217] pci_bus_read_config_dword+0x88/0xf0 [ 18.516222] pci_read_config_dword+0x38/0x58 [ 18.516228] pci_cfg_space_size_ext+0x60/0xd0 [ 18.516231] pci_cfg_space_size+0xb4/0xc0 [ 18.516235] pci_setup_device+0x104/0x6a8 [ 18.516239] pci_scan_single_device+0xb0/0xf8 [ 18.516243] pci_scan_slot+0x48/0x128 [ 18.516246] pci_scan_child_bus_extend+0x5c/0x2c0 [ 18.516250] pci_scan_bridge_extend+0x2a8/0x598 [ 18.516254] pci_scan_child_bus_extend+0x1f4/0x2c0 [ 18.516258] pci_scan_root_bus_bridge+0x6c/0xe0 [ 18.516262] pci_host_probe+0x20/0xd0 [ 18.516266] brcm_pcie_probe+0x26c/0x5b8 [ 18.516271] platform_probe+0x70/0xe0 [ 18.516277] really_probe+0x124/0x2c8 [ 18.516281] driver_probe_device+0x80/0xe8 [ 18.516284] driver_probe_device+0x44/0xf8 [ 18.516287] device_attach_driver+0xc0/0x100 [ 18.516291] bus_for_each_drv+0x80/0xd8 [ 18.516297] device_attach+0x104/0x198 [ 18.516300] device_initial_probe+0x1c/0x28 [ 18.516303] bus_probe_device+0xa4/0xb0 [ 18.516307] device_add+0x390/0x830 [ 18.516311] of_device_add+0x5c/0x70 [ 18.516316] of_platform_device_create_pdata+0x98/0x100 [ 18.516321] of_platform_notify+0xec/0x180 [ 18.516324] blocking_notifier_call_chain+0x74/0xa8 [ 18.516331] of_property_notify+0x68/0xb0 [ 18.516337] __of_changeset_entry_notify+0xb8/0x118 [ 18.516342] of_changeset_apply_notify+0x4c/0x80 [ 18.516347] of_overlay_fdt_apply+0x6e8/0x8b8 [ 18.516351] cfs_overlay_item_dtbo_write+0x64/0xc0 [ 18.516356] configfs_release_bin_file+0x98/0xa8 [ 18.516363] fput+0x78/0x238 [ 18.516368] __fput+0x18/0x28 [ 18.516372] task_work_run+0x88/0x180 [ 18.516375] do_notify_resume+0x1f0/0x4a0 [ 18.516378] el0_svc+0x80/0x98 [ 18.516382] el0t_64_sync_handler+0xb8/0xc0 [ 18.516386] el0t_64_sync+0x18c/0x190 [ 18.516391] SMP: stopping secondary CPUs [ 18.516397] Kernel Offset: 0x1fe6000000 from 0xffffffc008000000 [ 18.516400] PHYS_OFFSET: 0x0 [ 18.516401] CPU features: 0x2000,04027810,00001086 [ 18.516404] Memory Limit: none [ 18.877135] ---[ end Kernel panic - not syncing: Asynchronous SError Interrupt ]---

CGDevHusky92 commented 1 year ago

We are running into the exact same issue on our custom board. Except on the other end of our PCI lane is a PCI Packet Switch (PI7C9X2G606PRDNJAE) off of that is a Texas Instruments USB host controller (TUSB7340IRKMT). We plug in various E key wifi modules, but even without any plugged in we run into this unfortunate reboot issue. This is a piece of industrial equipment that will be placed in hard to reach places. Unreliable reboots are going to be an issue that we need to resolve before we can deploy. Any insight on how to handle this would be appreciated.

Boot Uart final output before getting stuck:

[ 201.589330] reboot: Restarting system

RPi: BOOTLOADER release VERSION:0fc8fc8e DATE: 2022/12/07 TIME: 14:24:15 BOOTMODE: 0x06 partition 0 build-ts BUILD_TIMESTAMP=1670423055 serial 81d5d5c7 boardrev c03140 stc 477177 PM_RSTS: 0x00000020 part 00000000 reset_info 00000000 uSD voltage 3.3V Initialising SDRAM 'Samsung' 16Gb x2 total-size: 32 Gbit 3200 DDR 3200 1 0 32 152

Boot mode: USB-MSD (04) order f2561 USB xHC init failed Boot mode: SD (01) order f256 SD HOST: 200000000 CTL0: 0x00800000 BUS: 400000 Hz actual: 390625 HZ div: 512 (256) status: 0x1fff0000 delay: 276 SD HOST: 200000000 CTL0: 0x00800f00 BUS: 400000 Hz actual: 390625 HZ div: 512 (256) status: 0x1fff0000 delay: 276 EMMC SD retry 1 oc 0 SD HOST: 200000000 CTL0: 0x00800000 BUS: 400000 Hz actual: 390625 HZ div: 512 (256) status: 0x1fff0000 delay: 276 OCR c0ff8080 [0] CID: 0015010038475446345206095552c387 SD HOST: 200000000 CTL0: 0x00800f04 BUS: 25000000 Hz actual: 25000000 HZ div: 8 (4) status: 0x1fff0000 delay: 4 SD HOST: 200000000 CTL0: 0x00800f04 BUS: 50000000 Hz actual: 50000000 HZ div: 4 (2) status: 0x1fff0000 delay: 2 MBR: 0x00000800, 524288 type: 0x0c MBR: 0x00080800,14743519 type: 0x83 MBR: 0x00000000, 0 type: 0x00 MBR: 0x00000000, 0 type: 0x00 Trying partition: 0 type: 32 lba: 2048 oem: 'mkfs.fat' volume: ' system-boot' rsc 32 fat-sectors 4033 c-count 516190 c-size 1 root dir cluster 2 sectors 0 entries 0 FAT32 clusters 516190 Trying partition: 0 type: 32 lba: 2048 oem: 'mkfs.fat' volume: ' system-boot' rsc 32 fat-sectors 4033 c-count 516190 c-size 1 root dir cluster 2 sectors 0 entries 0 FAT32 clusters 516190 Read config.txt bytes 2810 hnd 0x24938 gpio_cmd: '2=op,dh' pins: 2-2 drive: 1 fsel: 1 term: -1 gpio_cmd: '12=op,dh' pins: 12-12 drive: 1 fsel: 1 term: -1 Invalid GPIO command 14=in,pu Invalid GPIO command 15=in,pu Invalid GPIO command 18=in,pu gpio_cmd: '20=op,dh' pins: 20-20 drive: 1 fsel: 1 term: -1 gpio_cmd: '21=op,dh' pins: 21-21 drive: 1 fsel: 1 term: -1 Invalid GPIO command 23=in,pu Invalid GPIO command 24=in,pn/np gpio_cmd: '25=ip,pu' pins: 25-25 drive: -1 fsel: 0 term: 2 Read start4.elf bytes 2241504 hnd 0x4fcd5 Read fixup4.dat bytes 5411 hnd 0x58386 0x00c03140 0x00000000 0x00000fff MEM GPU: 76 ARM: 948 TOTAL: 1024 Firmware: d9b293558b4cef6aabedcc53c178e7604de90788 Nov 18 2021 16:16:49 Starting start4.elf @ 0xfec00200 partition 0 +

A successful boot looks like this:

RPi: BOOTLOADER release VERSION:0fc8fc8e DATE: 2022/12/07 TIME: 14:24:15 BOOTMODE: 0x06 partition 0 build-ts BUILD_TIMESTAMP=1670423055 serial 81d5d5c7 boardrev c03140 stc 478850 PM_RSTS: 0x00001000 part 00000000 reset_info 00000000 uSD voltage 3.3V Initialising SDRAM 'Samsung' 16Gb x2 total-size: 32 Gbit 3200 DDR 3200 1 0 32 152

Boot mode: USB-MSD (04) order f2561 USB xHC init failed Boot mode: SD (01) order f256 SD HOST: 200000000 CTL0: 0x00800000 BUS: 400000 Hz actual: 390625 HZ div: 512 (256) status: 0x1fff0000 delay: 276 SD HOST: 200000000 CTL0: 0x00800f00 BUS: 400000 Hz actual: 390625 HZ div: 512 (256) status: 0x1fff0000 delay: 276 EMMC SD retry 1 oc 0 SD HOST: 200000000 CTL0: 0x00800000 BUS: 400000 Hz actual: 390625 HZ div: 512 (256) status: 0x1fff0000 delay: 276 OCR c0ff8080 [0] CID: 0015010038475446345206095552c387 SD HOST: 200000000 CTL0: 0x00800f04 BUS: 25000000 Hz actual: 25000000 HZ div: 8 (4) status: 0x1fff0000 delay: 4 SD HOST: 200000000 CTL0: 0x00800f04 BUS: 50000000 Hz actual: 50000000 HZ div: 4 (2) status: 0x1fff0000 delay: 2 MBR: 0x00000800, 524288 type: 0x0c MBR: 0x00080800,14743519 type: 0x83 MBR: 0x00000000, 0 type: 0x00 MBR: 0x00000000, 0 type: 0x00 Trying partition: 0 type: 32 lba: 2048 oem: 'mkfs.fat' volume: ' system-boot' rsc 32 fat-sectors 4033 c-count 516190 c-size 1 root dir cluster 2 sectors 0 entries 0 FAT32 clusters 516190 Trying partition: 0 type: 32 lba: 2048 oem: 'mkfs.fat' volume: ' system-boot' rsc 32 fat-sectors 4033 c-count 516190 c-size 1 root dir cluster 2 sectors 0 entries 0 FAT32 clusters 516190 Read config.txt bytes 2810 hnd 0x24938 gpio_cmd: '2=op,dh' pins: 2-2 drive: 1 fsel: 1 term: -1 gpio_cmd: '12=op,dh' pins: 12-12 drive: 1 fsel: 1 term: -1 Invalid GPIO command 14=in,pu Invalid GPIO command 15=in,pu Invalid GPIO command 18=in,pu gpio_cmd: '20=op,dh' pins: 20-20 drive: 1 fsel: 1 term: -1 gpio_cmd: '21=op,dh' pins: 21-21 drive: 1 fsel: 1 term: -1 Invalid GPIO command 23=in,pu Invalid GPIO command 24=in,pn/np gpio_cmd: '25=ip,pu' pins: 25-25 drive: -1 fsel: 0 term: 2 Read start4.elf bytes 2241504 hnd 0x4fcd5 Read fixup4.dat bytes 5411 hnd 0x58386 0x00c03140 0x00000000 0x00000fff MEM GPU: 76 ARM: 948 TOTAL: 1024 Firmware: d9b293558b4cef6aabedcc53c178e7604de90788 Nov 18 2021 16:16:49 Starting start4.elf @ 0xfec00200 partition 0 + 1343 printk messages dropped [ 0.504391] pcieport 0000:00:00.0: PCIe Bus Error: severity=Uncorrected (Non-Fatal), type=Transaction Layer, (Requester ID) [ 0.504454] pcieport 0000:00:00.0: device [14e4:2711] error status/mask=00100000/00000000 [ 0.504489] pcieport 0000:00:00.0: [20] UnsupReq (First) [ 0.504528] pcieport 0000:00:00.0: AER: TLP Header: 30000000 02280032 00000000 00000000 [ 0.506250] pcieport 0000:00:00.0: PCIe Bus Error: severity=Uncorrected (Non-Fatal), type=Transaction Layer, (Requester ID) [ 0.506309] pcieport 0000:00:00.0: device [14e4:2711] error status/mask=00100000/00000000 [ 0.506372] pcieport 0000:00:00.0: [20] UnsupReq (First) [ 0.506404] pcieport 0000:00:00.0: AER: TLP Header: 30000000 02280032 00000000 00000000 [ 0.515964] pcieport 0000:00:00.0: PCIe Bus Error: severity=Uncorrected (Non-Fatal), type=Transaction Layer, (Requester ID) [ 0.516035] pcieport 0000:00:00.0: device [14e4:2711] error status/mask=00100000/00000000 [ 0.516088] pcieport 0000:00:00.0: [20] UnsupReq (First) [ 0.516129] pcieport 0000:00:00.0: AER: TLP Header: 30000000 02280032 00000000 00000000 [ 0.519406] pcieport 0000:00:00.0: PCIe Bus Error: severity=Uncorrected (Non-Fatal), type=Transaction Layer, (Requester ID) [ 0.519460] pcieport 0000:00:00.0: device [14e4:2711] error status/mask=00100000/00000000 [ 0.519507] pcieport 0000:00:00.0: [20] UnsupReq (First) [ 0.519594] pcieport 0000:00:00.0: AER: TLP Header: 30000000 02280032 00000000 00000000 [ 0.520749] pcieport 0000:00:00.0: PCIe Bus Error: severity=Uncorrected (Non-Fatal), type=Transaction Layer, (Requester ID) [ 0.520801] pcieport 0000:00:00.0: device [14e4:2711] error status/mask=00100000/00000000 [ 0.520858] pcieport 0000:00:00.0: [20] UnsupReq (First) [ 0.520884] pcieport 0000:00:00.0: AER: TLP Header: 30000000 02280032 00000000 00000000 [ 0.523330] pcieport 0000:00:00.0: PCIe Bus Error: severity=Uncorrected (Non-Fatal), type=Transaction Layer, (Requester ID) [ 0.523404] pcieport 0000:00:00.0: device [14e4:2711] error status/mask=00100000/00000000 [ 0.523449] pcieport 0000:00:00.0: [20] UnsupReq (First) [ 0.523487] pcieport 0000:00:00.0: AER: TLP Header: 30000000 02280032 00000000 00000000 [ 0.527847] pcieport 0000:00:00.0: PCIe Bus Error: severity=Uncorrected (Non-Fatal), type=Transaction Layer, (Requester ID) [ 0.527909] pcieport 0000:00:00.0: device [14e4:2711] error status/mask=00100000/00000000 [ 0.527961] pcieport 0000:00:00.0: [20] UnsupReq (First) [ 0.527999] pcieport 0000:00:00.0: AER: TLP Header: 30000000 02280032 00000000 00000000 [ 0.529414] pcieport 0000:00:00.0: PCIe Bus Error: severity=Uncorrected (Non-Fatal), type=Transaction Layer, (Requester ID) [ 0.529476] pcieport 0000:00:00.0: device [14e4:2711] error status/mask=00100000/00000000 [ 0.529524] pcieport 0000:00:00.0: [20] UnsupReq (First) [ 0.529568] pcieport 0000:00:00.0: AER: TLP Header: 30000000 02280032 00000000 00000000 [ 0.534360] pcieport 0000:00:00.0: PCIe Bus Error: severity=Uncorrected (Non-Fatal), type=Transaction Layer, (Requester ID) [ 0.534423] pcieport 0000:00:00.0: device [14e4:2711] error status/mask=00100000/00000000 [ 0.534498] pcieport 0000:00:00.0: [20] UnsupReq (First) [ 0.534542] pcieport 0000:00:00.0: AER: TLP Header: 30000000 02280032 00000000 00000000 [ 0.537207] pcieport 0000:00:00.0: PCIe Bus Error: severity=Uncorrected (Non-Fatal), type=Transaction Layer, (Requester ID) [ 0.537257] pcieport 0000:00:00.0: device [14e4:2711] error status/mask=00100000/00000000 [ 0.537297] pcieport 0000:00:00.0: [20] UnsupReq (First) [ 0.537335] pcieport 0000:00:00.0: AER: TLP Header: 30000000 02280032 00000000 00000000 [ 0.538701] pcieport 0000:00:00.0: PCIe Bus Error: severity=Uncorrected (Non-Fatal), type=Transaction Layer, (Requester ID) [ 0.538752] pcieport 0000:00:00.0: device [14e4:2711] error status/mask=00100000/00000000 [ 0.538801] pcieport 0000:00:00.0: [20] UnsupReq (First) [ 0.538826] pcieport 0000:00:00.0: AER: TLP Header: 30000000 02280032 00000000 00000000 [ 0.539990] pcieport 0000:00:00.0: PCIe Bus Error: severity=Uncorrected (Non-Fatal), type=Transaction Layer, (Requester ID) [ 0.540064] pcieport 0000:00:00.0: device [14e4:2711] error status/mask=00100000/00000000 [ 0.540101] pcieport 0000:00:00.0: [20] UnsupReq (First) [ 0.540132] pcieport 0000:00:00.0: AER: TLP Header: 30000000 02280032 00000000 00000000 [ 0.545889] pcieport 0000:00:00.0: PCIe Bus Error: severity=Uncorrected (Non-Fatal), type=Transaction Layer, (Requester ID) [ 0.545931] pcieport 0000:00:00.0: device [14e4:2711] error status/mask=00100000/00000000 [ 0.545960] pcieport 0000:00:00.0: [20] UnsupReq (First) [ 0.545986] pcieport 0000:00:00.0: AER: TLP Header: 30000000 02280032 00000000 00000000 [ 0.546654] pcieport 0000:00:00.0: PCIe Bus Error: severity=Uncorrected (Non-Fatal), type=Transaction Layer, (Requester ID) [ 0.546687] pcieport 0000:00:00.0: device [14e4:2711] error status/mask=00100000/00000000 [ 0.546716] pcieport 0000:00:00.0: [20] UnsupReq (First) [ 0.546740] pcieport 0000:00:00.0: AER: TLP Header: 30000000 02280032 00000000 00000000 [ 0.548053] pcieport 0000:00:00.0: PCIe Bus Error: severity=Uncorrected (Non-Fatal), type=Transaction Layer, (Requester ID) [ 0.548089] pcieport 0000:00:00.0: device [14e4:2711] error status/mask=00100000/00000000 [ 0.548118] pcieport 0000:00:00.0: [20] UnsupReq (First) [ 0.548142] pcieport 0000:00:00.0: AER: TLP Header: 30000000 02280032 00000000 00000000 [ 0.549514] pcieport 0000:00:00.0: PCIe Bus Error: severity=Uncorrected (Non-Fatal), type=Transaction Layer, (Requester ID) [ 0.549551] pcieport 0000:00:00.0: device [14e4:2711] error status/mask=00100000/00000000 [ 0.549579] pcieport 0000:00:00.0: [20] UnsupReq (First) [ 0.549604] pcieport 0000:00:00.0: AER: TLP Header: 30000000 02280032 00000000 00000000 [ 0.552425] pcieport 0000:00:00.0: PCIe Bus Error: severity=Uncorrected (Non-Fatal), type=Transaction Layer, (Requester ID) [ 0.552473] pcieport 0000:00:00.0: device [14e4:2711] error status/mask=00100000/00000000 [ 0.552501] pcieport 0000:00:00.0: [20] UnsupReq (First) [ 0.552526] pcieport 0000:00:00.0: AER: TLP Header: 30000000 02280032 00000000 00000000 [ 0.553882] pcieport 0000:00:00.0: PCIe Bus Error: severity=Uncorrected (Non-Fatal), type=Transaction Layer, (Requester ID) [ 0.553915] pcieport 0000:00:00.0: device [14e4:2711] error status/mask=00100000/00000000 [ 0.553944] pcieport 0000:00:00.0: [20] UnsupReq (First) [ 0.553968] pcieport 0000:00:00.0: AER: TLP Header: 30000000 02280032 00000000 00000000 [ 0.554897] pcieport 0000:00:00.0: PCIe Bus Error: severity=Uncorrected (Non-Fatal), type=Transaction Layer, (Requester ID) [ 0.554928] pcieport 0000:00:00.0: device [14e4:2711] error status/mask=00100000/00000000 [ 0.554957] pcieport 0000:00:00.0: [20] UnsupReq (First) [ 0.554981] pcieport 0000:00:00.0: AER: TLP Header: 30000000 02280032 00000000 00000000 [ 0.556747] pcieport 0000:00:00.0: PCIe Bus Error: severity=Uncorrected (Non-Fatal), type=Transaction Layer, (Requester ID) [ 0.556790] pcieport 0000:00:00.0: device [14e4:2711] error status/mask=00100000/00000000 [ 0.556818] pcieport 0000:00:00.0: [20] UnsupReq (First) [ 0.556843] pcieport 0000:00:00.0: AER: TLP Header: 30000000 02280032 00000000 00000000 [ 0.557574] pcieport 0000:00:00.0: PCIe Bus Error: severity=Uncorrected (Non-Fatal), type=Transaction Layer, (Requester ID) [ 0.557605] pcieport 0000:00:00.0: device [14e4:2711] error status/mask=00100000/00000000 [ 0.557633] pcieport 0000:00:00.0: [20] UnsupReq (First) [ 0.557658] pcieport 0000:00:00.0: AER: TLP Header: 30000000 02280032 00000000 00000000 [ 0.559966] pcieport 0000:00:00.0: PCIe Bus Error: severity=Uncorrected (Non-Fatal), type=Transaction Layer, (Requester ID) [ 0.560008] pcieport 0000:00:00.0: device [14e4:2711] error status/mask=00100000/00000000 [ 0.560037] pcieport 0000:00:00.0: [20] UnsupReq (First) [ 0.560062] pcieport 0000:00:00.0: AER: TLP Header: 30000000 02280032 00000000 00000000 [ 7.412007] systemd[1]: Failed to start Load Kernel Modules.

Ubuntu 22.04 LTS node4969 ttyS0

node4969 login:

Lots of pcieport errors, but once it is up pci works great and without any issues. Any pointers on where to start looking for a solution would be great!

jolla commented 1 year ago

@CGDevHusky92 the workaround we've come up with is to disable PCIe on boot and then enable PCIe after boot. Not ideal, but it does work around the issue and prevents the unit from hanging on boot.