Pi 5: i2c: i2c_designware: controller timed out, requiring power cycle to fix

[Gadgetoid]

Describe the bug

When using i2c on either of the display connectors to drive an IO expander and touch, I'm getting frequent hard crashes of the i2c controller, requiring a full power cycle to fix:

[    6.593324] i2c_designware 1f00088000.i2c: controller timed out
[    6.593343] (NULL device *): regmap_read of register 0x1 failed: -ETIMEDOUT

Steps to reproduce the behaviour

I don't have a minimum repro since I'm connecting and trying to talk to i2c hardware, normally I'd chalk this up as user-error but I'm concerned that a fault like this should be cleared on a soft reboot...

This is the dtoverlay that may or may not be triggering the problem-

/dts-v1/;
/plugin/;

/ {
	compatible = "brcm,bcm2835";

	fragment@0 {
		target = <&i2c0if>;
		__overlay__ {
			status = "okay";
		};
	};
		
	fragment@1 {
		target = <&i2c0mux>;
		__overlay__ {
			status = "okay";
		};
	};

	fragment@2 {};

	pca9685: fragment@3 {
		target = <&i2c_csi_dsi>;
		__overlay__ {
			#address-cells = <1>;
			#size-cells = <0>;
			status = "okay";

			pca: pca@56 {
				compatible = "nxp,pca9685-pwm";
				#pwm-cells = <2>;
				gpio-controller;
				#gpio-cells = <2>;
				reg = <0x56>;
				status = "okay";

				gpio-line-names = "PCA_PWM0",
					"PCA_PWM1",
					"PCA_PWM2",
					"PCA_PWM3",
					"PCA_PWM4",
					"PCA_PWM5",
					"PCA_PWM6",
					"PCA_PWM7",
					"PCA_GPIO8_LCD_RST",
					"PCA_PWM9_LCD_BL",
					"PCA_GPIO10_TOUCH_RST",
					"PCA_PWM11",
					"PCA_PWM12",
					"PCA_PWM13",
					"PCA_PWM14",
					"PCA_PWM15";
			};
		};
	};

	fragment@4 {
		target-path = "/";
		__overlay__ {
			backlight_lcd: backlight_lcd {
				compatible = "pwm-backlight";
				brightness-levels = <0 4095>;
				num-interpolated-steps = <4096>;
				default-brightness-level = <4096>;
				pwms = <&pca 9 5000000>;
				status = "okay";
			};

			reg_touch: reg_touch@1 {
				compatible = "regulator-fixed";
				regulator-name = "touch_reg";
				gpio = <&pca 10 0>;
				enable-active-high;
			};

            reg_panel: reg_panel@1 {
                compatible = "regulator-fixed";
                regulator-name = "panel_reg";
                gpio = <&pca 8 0>;
                enable-active-high;
            };

		};
	};

	gt9271: fragment@5 {
		target = <&i2c_csi_dsi>;
		__overlay__ {
			#address-cells = <1>;
			#size-cells = <0>;
			status = "okay";

			gt9271@5d {
				compatible = "goodix,gt9271";
				reg = <0x5d>;
				VDDIO-supply = <&reg_touch>;
			};
		};
	};

	panel: fragment@6 {
		target = <&dsi1>;

		__overlay__ {
			#address-cells = <1>;
			#size-cells = <0>;
			status = "okay";

			port {
				dsi_out_port: endpoint {
					remote-endpoint = <&panel_dsi_in>;
				};
			};

			panel_dsi: panel@0 {
				compatible = "pimoroni,lcd";

				reg = <0>;
				label = "lcd";
				power-supply = <&reg_panel>;
				port {
					panel_dsi_in: endpoint {
						remote-endpoint = <&dsi_out_port>;
					};
				};
			};

		};
	};

	__overrides__ {
		dsi0 = <&panel>, "target:0=",<&dsi0>,
			<&gt9271>, "target:0=",<&i2c_csi_dsi0>,
			<&pca9685>, "target:0=",<&i2c_csi_dsi0>;
	};

};

Device (s)

Raspberry Pi 5 Model B Rev 1.0

System

Raspberry Pi reference 2023-12-05
Generated using pi-gen, https://github.com/RPi-Distro/pi-gen, 70cd6f2a1e34d07f5cba7047aea5b92457372e05, stage4

version c2da2ae7 (release) (embedded)

Linux pi4 6.1.0-rpi7-rpi-2712 #1 SMP PREEMPT Debian 1:6.1.63-1+rpt1 (2023-11-24) aarch64 GNU/Linux

Logs

Full dmesg output of a failure state:

[    0.000000] Booting Linux on physical CPU 0x0000000000 [0x414fd0b1]
[    0.000000] Linux version 6.1.0-rpi7-rpi-2712 (debian-kernel@lists.debian.org) (gcc-12 (Debian 12.2.0-14) 12.2.0, GNU ld (GNU Binutils for Debian) 2.40) #1 SMP PREEMPT Debian 1:6.1.63-1+rpt1 (2023-11-24)
[    0.000000] random: crng init done
[    0.000000] Machine model: Raspberry Pi 5 Model B Rev 1.0
[    0.000000] efi: UEFI not found.
[    0.000000] Reserved memory: created CMA memory pool at 0x0000000018000000, 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-0x00000000ffffffff]
[    0.000000]   DMA32    empty
[    0.000000]   Normal   [mem 0x0000000100000000-0x00000001ffffffff]
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000000000-0x000000000007ffff]
[    0.000000]   node   0: [mem 0x0000000000080000-0x000000003f7fffff]
[    0.000000]   node   0: [mem 0x0000000040000000-0x00000001ffffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000001ffffffff]
[    0.000000] On node 0, zone DMA: 512 pages in unavailable ranges
[    0.000000] psci: probing for conduit method from DT.
[    0.000000] psci: PSCIv1.1 detected in firmware.
[    0.000000] psci: Using standard PSCI v0.2 function IDs
[    0.000000] psci: MIGRATE_INFO_TYPE not supported.
[    0.000000] psci: SMC Calling Convention v1.2
[    0.000000] percpu: Embedded 14 pages/cpu s177448 r8192 d43736 u229376
[    0.000000] pcpu-alloc: s177448 r8192 d43736 u229376 alloc=14*16384
[    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 
[    0.000000] Detected PIPT I-cache on CPU0
[    0.000000] CPU features: detected: Virtualization Host Extensions
[    0.000000] CPU features: detected: Hardware dirty bit management
[    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] alternatives: applying boot alternatives
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 521728
[    0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=1 pci=pcie_bus_safe snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1  smsc95xx.macaddr=D8:3A:DD:79:FE:F9 vc_mem.mem_base=0x3fc00000 vc_mem.mem_size=0x40000000  console=ttyAMA10,115200 console=tty1 root=PARTUUID=2d4d4fe5-02 rootfstype=ext4 fsck.repair=yes rootwait quiet splash plymouth.ignore-serial-consoles cfg80211.ieee80211_regdom=GB
[    0.000000] Unknown kernel command line parameters "splash", will be passed to user space.
[    0.000000] Dentry cache hash table entries: 1048576 (order: 9, 8388608 bytes, linear)
[    0.000000] Inode-cache hash table entries: 524288 (order: 8, 4194304 bytes, linear)
[    0.000000] mem auto-init: stack:all(zero), heap alloc:off, heap free:off
[    0.000000] software IO TLB: area num 4.
[    0.000000] software IO TLB: mapped [mem 0x00000000fbffc000-0x00000000ffffc000] (64MB)
[    0.000000] Memory: 7894048K/8380416K available (12352K kernel code, 2186K rwdata, 4112K rodata, 4480K init, 1216K bss, 158688K reserved, 327680K cma-reserved)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] ftrace: allocating 40061 entries in 40 pages
[    0.000000] ftrace: allocated 40 pages with 2 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.000000] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns
[    0.000156] Console: colour dummy device 80x25
[    0.000177] printk: console [tty1] enabled
[    0.000197] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=216000)
[    0.000204] pid_max: default: 32768 minimum: 301
[    0.000228] LSM: Security Framework initializing
[    0.000301] Mount-cache hash table entries: 16384 (order: 3, 131072 bytes, linear)
[    0.000334] Mountpoint-cache hash table entries: 16384 (order: 3, 131072 bytes, linear)
[    0.000779] cgroup: Disabling memory control group subsystem
[    0.001305] cblist_init_generic: Setting adjustable number of callback queues.
[    0.001309] cblist_init_generic: Setting shift to 2 and lim to 1.
[    0.001352] cblist_init_generic: Setting adjustable number of callback queues.
[    0.001354] cblist_init_generic: Setting shift to 2 and lim to 1.
[    0.001387] cblist_init_generic: Setting adjustable number of callback queues.
[    0.001389] cblist_init_generic: Setting shift to 2 and lim to 1.
[    0.001476] rcu: Hierarchical SRCU implementation.
[    0.001478] rcu: 	Max phase no-delay instances is 1000.
[    0.002103] EFI services will not be available.
[    0.002205] smp: Bringing up secondary CPUs ...
[    0.002424] Detected PIPT I-cache on CPU1
[    0.002470] CPU1: Booted secondary processor 0x0000000100 [0x414fd0b1]
[    0.002703] Detected PIPT I-cache on CPU2
[    0.002740] CPU2: Booted secondary processor 0x0000000200 [0x414fd0b1]
[    0.002972] Detected PIPT I-cache on CPU3
[    0.003006] CPU3: Booted secondary processor 0x0000000300 [0x414fd0b1]
[    0.003042] smp: Brought up 1 node, 4 CPUs
[    0.003047] SMP: Total of 4 processors activated.
[    0.003050] CPU features: detected: 32-bit EL0 Support
[    0.003054] CPU features: detected: Data cache clean to the PoU not required for I/D coherence
[    0.003057] CPU features: detected: Common not Private translations
[    0.003059] CPU features: detected: CRC32 instructions
[    0.003062] CPU features: detected: RCpc load-acquire (LDAPR)
[    0.003064] CPU features: detected: LSE atomic instructions
[    0.003067] CPU features: detected: Privileged Access Never
[    0.003069] CPU features: detected: RAS Extension Support
[    0.003073] CPU features: detected: Speculative Store Bypassing Safe (SSBS)
[    0.003111] CPU: All CPU(s) started at EL2
[    0.003113] alternatives: applying system-wide alternatives
[    0.005022] devtmpfs: initialized
[    0.007650] Enabled cp15_barrier support
[    0.007657] Enabled setend support
[    0.007723] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[    0.007731] futex hash table entries: 1024 (order: 2, 65536 bytes, linear)
[    0.008645] pinctrl core: initialized pinctrl subsystem
[    0.008869] DMI not present or invalid.
[    0.009059] NET: Registered PF_NETLINK/PF_ROUTE protocol family
[    0.010279] DMA: preallocated 1024 KiB GFP_KERNEL pool for atomic allocations
[    0.010332] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
[    0.010408] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
[    0.010432] audit: initializing netlink subsys (disabled)
[    0.010496] audit: type=2000 audit(0.008:1): state=initialized audit_enabled=0 res=1
[    0.010630] thermal_sys: Registered thermal governor 'step_wise'
[    0.010649] cpuidle: using governor menu
[    0.010719] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers.
[    0.010765] ASID allocator initialised with 32768 entries
[    0.011056] Serial: AMBA PL011 UART driver
[    0.013032] bcm2835-mbox 107c013880.mailbox: mailbox enabled
[    0.013730] 107d001000.serial: ttyAMA10 at MMIO 0x107d001000 (irq = 15, base_baud = 0) is a PL011 rev2
[    0.013767] printk: console [ttyAMA10] enabled
[    0.020774] raspberrypi-firmware soc:firmware: Attached to firmware from 2023-10-18T17:30:17, variant start_cd
[    0.024776] raspberrypi-firmware soc:firmware: Firmware hash is c2da2ae700000000000000000000000000000000
[    0.033494] KASLR enabled
[    0.043433] bcm2835-dma 1000010000.dma: DMA legacy API manager, dmachans=0x1
[    0.044516] iommu: Default domain type: Translated 
[    0.044520] iommu: DMA domain TLB invalidation policy: strict mode 
[    0.044615] SCSI subsystem initialized
[    0.044667] usbcore: registered new interface driver usbfs
[    0.044678] usbcore: registered new interface driver hub
[    0.044689] usbcore: registered new device driver usb
[    0.044796] usb_phy_generic phy: supply vcc not found, using dummy regulator
[    0.044886] pps_core: LinuxPPS API ver. 1 registered
[    0.044889] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[    0.044895] PTP clock support registered
[    0.045144] vgaarb: loaded
[    0.045281] clocksource: Switched to clocksource arch_sys_counter
[    0.045443] VFS: Disk quotas dquot_6.6.0
[    0.045461] VFS: Dquot-cache hash table entries: 2048 (order 0, 16384 bytes)
[    0.045497] FS-Cache: Loaded
[    0.045526] CacheFiles: Loaded
[    0.046949] NET: Registered PF_INET protocol family
[    0.047119] IP idents hash table entries: 131072 (order: 6, 1048576 bytes, linear)
[    0.049545] tcp_listen_portaddr_hash hash table entries: 4096 (order: 2, 65536 bytes, linear)
[    0.049595] Table-perturb hash table entries: 65536 (order: 4, 262144 bytes, linear)
[    0.049602] TCP established hash table entries: 65536 (order: 5, 524288 bytes, linear)
[    0.049872] TCP bind hash table entries: 65536 (order: 7, 2097152 bytes, linear)
[    0.051646] TCP: Hash tables configured (established 65536 bind 65536)
[    0.051793] MPTCP token hash table entries: 8192 (order: 3, 196608 bytes, linear)
[    0.051913] UDP hash table entries: 4096 (order: 3, 131072 bytes, linear)
[    0.052013] UDP-Lite hash table entries: 4096 (order: 3, 131072 bytes, linear)
[    0.052167] NET: Registered PF_UNIX/PF_LOCAL protocol family
[    0.052347] RPC: Registered named UNIX socket transport module.
[    0.052351] RPC: Registered udp transport module.
[    0.052353] RPC: Registered tcp transport module.
[    0.052356] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    0.052361] PCI: CLS 0 bytes, default 64
[    0.052496] Trying to unpack rootfs image as initramfs...
[    0.061855] hw perfevents: enabled with armv8_cortex_a76 PMU driver, 7 counters available
[    0.062025] kvm [1]: IPA Size Limit: 40 bits
[    0.062038] kvm [1]: GICV region size/alignment is unsafe, using trapping (reduced performance)
[    0.062091] kvm [1]: vgic interrupt IRQ9
[    0.062138] kvm [1]: VHE mode initialized successfully
[    0.305030] Freeing initrd memory: 16704K
[    0.339491] Initialise system trusted keyrings
[    0.339637] workingset: timestamp_bits=46 max_order=19 bucket_order=0
[    0.341464] zbud: loaded
[    0.342030] NFS: Registering the id_resolver key type
[    0.342041] Key type id_resolver registered
[    0.342044] Key type id_legacy registered
[    0.342064] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[    0.342067] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering...
[    0.342136] F2FS not supported on PAGE_SIZE(16384) != 4096
[    0.342222] Key type asymmetric registered
[    0.342225] Asymmetric key parser 'x509' registered
[    0.342246] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247)
[    0.342317] io scheduler mq-deadline registered
[    0.342322] io scheduler kyber registered
[    0.343024] irq_brcmstb_l2: registered L2 intc (/soc/interrupt-controller@7c502000, parent irq: 31)
[    0.343172] irq_brcmstb_l2: registered L2 intc (/soc/intc@7d503000, parent irq: 32)
[    0.343287] irq_brcmstb_l2: registered L2 intc (/soc/intc@7d508380, parent irq: 33)
[    0.343407] irq_brcmstb_l2: registered L2 intc (/soc/intc@7d508400, parent irq: 34)
[    0.343519] irq_brcmstb_l2: registered L2 intc (/soc/interrupt-controller@7d510600, parent irq: 35)
[    0.343631] irq_brcmstb_l2: registered L2 intc (/soc/intc@7d517b00, parent irq: 36)
[    0.345417] gpio-461 (RP1 RUN pin): hogged as output/high
[    0.346245] simple-framebuffer 3f800000.framebuffer: framebuffer at 0x3f800000, 0x3f4800 bytes
[    0.346251] simple-framebuffer 3f800000.framebuffer: format=r5g6b5, mode=1920x1080x16, linelength=3840
[    0.346386] Console: switching to colour frame buffer device 240x67
[    0.347917] simple-framebuffer 3f800000.framebuffer: fb0: simplefb registered!
[    0.380781] Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled
[    0.381380] 107d50c000.serial: ttyS0 at MMIO 0x107d50c000 (irq = 38, base_baud = 6000000) is a 16550A
[    0.381427] serial serial0: tty port ttyS0 registered
[    0.382005] iproc-rng200 107d208000.rng: hwrng registered
[    0.382138] vc-mem: phys_addr:0x00000000 mem_base=0x3fc00000 mem_size:0x40000000(1024 MiB)
[    0.382842] bcm2712-iommu-cache 1000005b00.iommuc: bcm2712_iommu_cache_probe
[    0.384818] brd: module loaded
[    0.386354] loop: module loaded
[    0.386579] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver
[    0.386763] Loading iSCSI transport class v2.0-870.
[    0.387849] usbcore: registered new interface driver r8152
[    0.387862] usbcore: registered new interface driver lan78xx
[    0.387872] usbcore: registered new interface driver smsc95xx
[    0.388013] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    0.388092] dwc_otg: FIQ enabled
[    0.388094] dwc_otg: NAK holdoff enabled
[    0.388097] dwc_otg: FIQ split-transaction FSM enabled
[    0.388100] Module dwc_common_port init
[    0.388369] usbcore: registered new interface driver uas
[    0.388389] usbcore: registered new interface driver usb-storage
[    0.388591] mousedev: PS/2 mouse device common for all mice
[    0.396370] rpi-rtc soc:rpi_rtc: registered as rtc0
[    0.397818] rpi-rtc soc:rpi_rtc: setting system clock to 2023-12-11T15:16:18 UTC (1702307778)
[    0.398487] bcm2835-wdt bcm2835-wdt: Poweroff handler already present!
[    0.398491] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
[    0.401223] sdhci: Secure Digital Host Controller Interface driver
[    0.401227] sdhci: Copyright(c) Pierre Ossman
[    0.401390] sdhci-pltfm: SDHCI platform and OF driver helper
[    0.401822] ledtrig-cpu: registered to indicate activity on CPUs
[    0.401860] SMCCC: SOC_ID: ARCH_SOC_ID not implemented, skipping ....
[    0.401872] hid: raw HID events driver (C) Jiri Kosina
[    0.401896] usbcore: registered new interface driver usbhid
[    0.401899] usbhid: USB HID core driver
[    0.402092] NET: Registered PF_PACKET protocol family
[    0.402123] Key type dns_resolver registered
[    0.402382] registered taskstats version 1
[    0.402402] Loading compiled-in X.509 certificates
[    0.408873] Loaded X.509 cert 'Debian Secure Boot CA: 6ccece7e4c6c0d1f6149f3dd27dfcc5cbb419ea1'
[    0.408902] Loaded X.509 cert 'Debian Secure Boot Signer 2022 - linux: 14011249c2675ea8e5148542202005810584b25f'
[    0.409086] Key type .fscrypt registered
[    0.409089] Key type fscrypt-provisioning registered
[    0.410948] brcm-pcie 1000120000.pcie: host bridge /axi/pcie@120000 ranges:
[    0.410958] brcm-pcie 1000120000.pcie:   No bus range found for /axi/pcie@120000, using [bus 00-ff]
[    0.410984] brcm-pcie 1000120000.pcie:      MEM 0x1f00000000..0x1ffffffffb -> 0x0000000000
[    0.410997] brcm-pcie 1000120000.pcie:      MEM 0x1c00000000..0x1effffffff -> 0x0400000000
[    0.411022] brcm-pcie 1000120000.pcie:   IB MEM 0x1f00000000..0x1f003fffff -> 0x0000000000
[    0.411035] brcm-pcie 1000120000.pcie:   IB MEM 0x0000000000..0x0fffffffff -> 0x1000000000
[    0.412226] brcm-pcie 1000120000.pcie: setting SCB_ACCESS_EN, READ_UR_MODE, MAX_BURST_SIZE
[    0.412237] brcm-pcie 1000120000.pcie: Forcing gen 2
[    0.412281] brcm-pcie 1000120000.pcie: PCI host bridge to bus 0000:00
[    0.412285] pci_bus 0000:00: root bus resource [bus 00-ff]
[    0.412289] pci_bus 0000:00: root bus resource [mem 0x1f00000000-0x1ffffffffb] (bus address [0x00000000-0xfffffffb])
[    0.412294] pci_bus 0000:00: root bus resource [mem 0x1c00000000-0x1effffffff pref] (bus address [0x400000000-0x6ffffffff])
[    0.412312] pci 0000:00:00.0: [14e4:2712] type 01 class 0x060400
[    0.412371] pci 0000:00:00.0: PME# supported from D0 D3hot
[    0.413386] pci 0000:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[    0.521287] brcm-pcie 1000120000.pcie: link up, 5.0 GT/s PCIe x4 (!SSC)
[    0.521315] pci 0000:01:00.0: [1de4:0001] type 00 class 0x020000
[    0.521333] pci 0000:01:00.0: reg 0x10: [mem 0xffffc000-0xffffffff]
[    0.521344] pci 0000:01:00.0: reg 0x14: [mem 0xffc00000-0xffffffff]
[    0.521353] pci 0000:01:00.0: reg 0x18: [mem 0xffff0000-0xffffffff]
[    0.521445] pci 0000:01:00.0: supports D1
[    0.521447] pci 0000:01:00.0: PME# supported from D0 D1 D3hot D3cold
[    0.533295] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01
[    0.533307] pci 0000:00:00.0: BAR 8: assigned [mem 0x1f00000000-0x1f005fffff]
[    0.533313] pci 0000:01:00.0: BAR 1: assigned [mem 0x1f00000000-0x1f003fffff]
[    0.533319] pci 0000:01:00.0: BAR 2: assigned [mem 0x1f00400000-0x1f0040ffff]
[    0.533325] pci 0000:01:00.0: BAR 0: assigned [mem 0x1f00410000-0x1f00413fff]
[    0.533332] pci 0000:00:00.0: PCI bridge to [bus 01]
[    0.533337] pci 0000:00:00.0:   bridge window [mem 0x1f00000000-0x1f005fffff]
[    0.533346] pci 0000:00:00.0: Max Payload Size set to  256/ 512 (was  128), Max Read Rq  512
[    0.533357] pci 0000:01:00.0: Max Payload Size set to  256/ 256 (was  128), Max Read Rq  512
[    0.533485] pcieport 0000:00:00.0: enabling device (0000 -> 0002)
[    0.533539] pcieport 0000:00:00.0: PME: Signaling with IRQ 39
[    0.533627] pcieport 0000:00:00.0: AER: enabled with IRQ 39
[    0.533802] rp1 0000:01:00.0: bar0 len 0x4000, start 0x1f00410000, end 0x1f00413fff, flags, 0x40200
[    0.533807] rp1 0000:01:00.0: bar1 len 0x400000, start 0x1f00000000, end 0x1f003fffff, flags, 0x40200
[    0.533819] rp1 0000:01:00.0: enabling device (0000 -> 0002)
[    0.534971] rp1 0000:01:00.0: chip_id 0x20001927
[    0.557350] macb 1f00100000.ethernet eth0: Cadence GEM rev 0x00070109 at 0x1f00100000 irq 107 (d8:3a:dd:79:fe:f9)
[    0.558127] dw_axi_dmac_platform 1f00188000.dma: DesignWare AXI DMA Controller, 8 channels
[    0.617395] xhci-hcd xhci-hcd.0: xHCI Host Controller
[    0.617404] xhci-hcd xhci-hcd.0: new USB bus registered, assigned bus number 1
[    0.617873] xhci-hcd xhci-hcd.0: hcc params 0x0240fe6d hci version 0x110 quirks 0x0000000000010810
[    0.617890] xhci-hcd xhci-hcd.0: irq 132, io mem 0x1f00200000
[    0.617971] xhci-hcd xhci-hcd.0: xHCI Host Controller
[    0.617975] xhci-hcd xhci-hcd.0: new USB bus registered, assigned bus number 2
[    0.617980] xhci-hcd xhci-hcd.0: Host supports USB 3.0 SuperSpeed
[    0.618057] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.01
[    0.618061] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    0.618065] usb usb1: Product: xHCI Host Controller
[    0.618068] usb usb1: Manufacturer: Linux 6.1.0-rpi7-rpi-2712 xhci-hcd
[    0.618072] usb usb1: SerialNumber: xhci-hcd.0
[    0.618228] hub 1-0:1.0: USB hub found
[    0.618247] hub 1-0:1.0: 2 ports detected
[    0.618454] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 6.01
[    0.618459] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    0.618462] usb usb2: Product: xHCI Host Controller
[    0.618465] usb usb2: Manufacturer: Linux 6.1.0-rpi7-rpi-2712 xhci-hcd
[    0.618468] usb usb2: SerialNumber: xhci-hcd.0
[    0.618582] hub 2-0:1.0: USB hub found
[    0.618602] hub 2-0:1.0: 1 port detected
[    0.677381] xhci-hcd xhci-hcd.1: xHCI Host Controller
[    0.677387] xhci-hcd xhci-hcd.1: new USB bus registered, assigned bus number 3
[    0.677847] xhci-hcd xhci-hcd.1: hcc params 0x0240fe6d hci version 0x110 quirks 0x0000000000010810
[    0.677862] xhci-hcd xhci-hcd.1: irq 137, io mem 0x1f00300000
[    0.677935] xhci-hcd xhci-hcd.1: xHCI Host Controller
[    0.677939] xhci-hcd xhci-hcd.1: new USB bus registered, assigned bus number 4
[    0.677944] xhci-hcd xhci-hcd.1: Host supports USB 3.0 SuperSpeed
[    0.678026] usb usb3: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.01
[    0.678030] usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    0.678034] usb usb3: Product: xHCI Host Controller
[    0.678037] usb usb3: Manufacturer: Linux 6.1.0-rpi7-rpi-2712 xhci-hcd
[    0.678040] usb usb3: SerialNumber: xhci-hcd.1
[    0.678158] hub 3-0:1.0: USB hub found
[    0.678175] hub 3-0:1.0: 2 ports detected
[    0.678368] usb usb4: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 6.01
[    0.678372] usb usb4: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    0.678376] usb usb4: Product: xHCI Host Controller
[    0.678378] usb usb4: Manufacturer: Linux 6.1.0-rpi7-rpi-2712 xhci-hcd
[    0.678381] usb usb4: SerialNumber: xhci-hcd.1
[    0.678496] hub 4-0:1.0: USB hub found
[    0.678511] hub 4-0:1.0: 1 port detected
[    0.678775] platform 1f00118000.dsi: Fixed dependency cycle(s) with /axi/pcie@120000/rp1/dsi@110000/panel@0/port/endpoint
[    0.679891] bcm2712-iommu 1000005100.iommu: bcm2712_iommu_init: DEBUG_INFO = 0x20804774
[    0.680318] platform 1000800000.codec: bcm2712_iommu_probe_device: MMU 1000005100.iommu
[    0.680321] platform 1000800000.codec: bcm2712_iommu_device_group: MMU 1000005100.iommu
[    0.680327] platform 1000800000.codec: Adding to iommu group 0
[    0.680362] platform 1000880000.pisp_be: bcm2712_iommu_probe_device: MMU 1000005100.iommu
[    0.680365] platform 1000880000.pisp_be: bcm2712_iommu_device_group: MMU 1000005100.iommu
[    0.680370] platform 1000880000.pisp_be: Adding to iommu group 0
[    0.680443] platform 1000800000.codec: bcm2712_iommu_attach_dev: MMU 1000005100.iommu
[    0.680447] platform 1000880000.pisp_be: bcm2712_iommu_attach_dev: MMU 1000005100.iommu
[    0.680454] bcm2712-iommu 1000005100.iommu: bcm2712_iommu_probe: Success
[    0.681066] bcm2712-iommu 1000005200.iommu: bcm2712_iommu_init: DEBUG_INFO = 0x20804774
[    0.681442] platform axi:gpu: bcm2712_iommu_probe_device: MMU 1000005200.iommu
[    0.681445] platform axi:gpu: bcm2712_iommu_device_group: MMU 1000005200.iommu
[    0.681452] platform axi:gpu: Adding to iommu group 1
[    0.681523] platform axi:gpu: bcm2712_iommu_attach_dev: MMU 1000005200.iommu
[    0.681529] bcm2712-iommu 1000005200.iommu: bcm2712_iommu_probe: Success
[    0.682028] bcm2712-iommu 1000005280.iommu: bcm2712_iommu_init: DEBUG_INFO = 0x20804774
[    0.682424] platform 1f00118000.dsi: bcm2712_iommu_probe_device: MMU 1000005280.iommu
[    0.682427] platform 1f00118000.dsi: bcm2712_iommu_device_group: MMU 1000005280.iommu
[    0.682432] platform 1f00118000.dsi: Adding to iommu group 2
[    0.682438] platform 1f00118000.dsi: bcm2712_iommu_attach_dev: MMU 1000005280.iommu
[    0.682444] bcm2712-iommu 1000005280.iommu: bcm2712_iommu_probe: Success
[    0.682652] sdhci-brcmstb 1000fff000.mmc: there is not valid maps for state default
[    0.683039] mmc0: CQHCI version 5.10
[    0.683086] mmc1: CQHCI version 5.10
[    0.684547] of_cfs_init
[    0.684583] of_cfs_init: OK
[    0.718871] mmc0: SDHCI controller on 1000fff000.mmc [1000fff000.mmc] using ADMA 64-bit
[    0.817951] mmc0: new ultra high speed SDR104 SDHC card at address aaaa
[    0.818217] mmcblk0: mmc0:aaaa SH32G 29.7 GiB 
[    0.819813]  mmcblk0: p1 p2
[    0.819916] mmcblk0: mmc0:aaaa SH32G 29.7 GiB (quirks 0x00004000)
[    0.871826] mmc1: SDHCI controller on 1001100000.mmc [1001100000.mmc] using ADMA 64-bit
[    0.874885] Freeing unused kernel memory: 4480K
[    0.874937] Run /init as init process
[    0.874940]   with arguments:
[    0.874942]     /init
[    0.874944]     splash
[    0.874947]   with environment:
[    0.874949]     HOME=/
[    0.874951]     TERM=linux
[    0.902703] mmc1: new ultra high speed DDR50 SDIO card at address 0001
[    0.937425] usb 3-1: new high-speed USB device number 2 using xhci-hcd
[    1.083162] input: pwr_button as /devices/platform/pwr_button/input/input0
[    1.091788] [drm] Initialized v3d 1.0.0 20180419 for 1002000000.v3d on minor 0
[    1.094603] usb 3-1: New USB device found, idVendor=05e3, idProduct=0610, bcdDevice=32.98
[    1.094613] usb 3-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
[    1.094617] usb 3-1: Product: USB2.0 Hub
[    1.101127] drm-rp1-dsi 1f00118000.dsi: bcm2712_iommu_of_xlate: MMU 1000005280.iommu
[    1.133512] brcmstb-i2c 107d508200.i2c:  @200000hz registered in interrupt mode
[    1.133839] brcmstb-i2c 107d508280.i2c:  @200000hz registered in interrupt mode
[    1.165712] hub 3-1:1.0: USB hub found
[    1.166020] hub 3-1:1.0: 4 ports detected
[    1.168112] vc4-drm axi:gpu: bcm2712_iommu_of_xlate: MMU 1000005200.iommu
[    1.169416] Console: switching to colour dummy device 80x25
[    1.171666] vc4-drm axi:gpu: bound 107c580000.hvs (ops vc4_hvs_ops [vc4])
[    1.174030] Registered IR keymap rc-cec
[    1.174079] rc rc0: vc4-hdmi-0 as /devices/platform/soc/107c701400.hdmi/rc/rc0
[    1.174128] input: vc4-hdmi-0 as /devices/platform/soc/107c701400.hdmi/rc/rc0/input1
[    1.174858] vc4-drm axi:gpu: bound 107c701400.hdmi (ops vc4_hdmi_ops [vc4])
[    1.177211] Registered IR keymap rc-cec
[    1.177252] rc rc1: vc4-hdmi-1 as /devices/platform/soc/107c706400.hdmi/rc/rc1
[    1.177312] input: vc4-hdmi-1 as /devices/platform/soc/107c706400.hdmi/rc/rc1/input2
[    1.178818] vc4-drm axi:gpu: bound 107c706400.hdmi (ops vc4_hdmi_ops [vc4])
[    1.178963] vc4-drm axi:gpu: bound 107c500000.mop (ops vc4_txp_ops [vc4])
[    1.179048] vc4-drm axi:gpu: bound 107c501000.moplet (ops vc4_txp_ops [vc4])
[    1.179140] vc4-drm axi:gpu: bound 107c410000.pixelvalve (ops vc4_crtc_ops [vc4])
[    1.179221] vc4-drm axi:gpu: bound 107c411000.pixelvalve (ops vc4_crtc_ops [vc4])
[    1.225950] [drm] Initialized vc4 0.0.0 20140616 for axi:gpu on minor 2
[    1.280116] Console: switching to colour frame buffer device 240x67
[    1.298397] vc4-drm axi:gpu: [drm] fb0: vc4drmfb frame buffer device
[    1.441285] usb 3-2: new high-speed USB device number 3 using xhci-hcd
[    1.619244] usb 3-2: New USB device found, idVendor=0bda, idProduct=0306, bcdDevice= 1.17
[    1.619250] usb 3-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[    1.619253] usb 3-2: Product: USB3.0 Card Reader
[    1.619257] usb 3-2: Manufacturer: Realtek
[    1.619260] usb 3-2: SerialNumber: 201506301013
[    1.624846] usb-storage 3-2:1.0: USB Mass Storage device detected
[    1.625010] scsi host0: usb-storage 3-2:1.0
[    1.673290] usb 3-1.1: new low-speed USB device number 4 using xhci-hcd
[    1.797613] usb 3-1.1: New USB device found, idVendor=04d9, idProduct=0006, bcdDevice= 1.10
[    1.797618] usb 3-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    1.797622] usb 3-1.1: Product: RPI Wired Keyboard 1
[    1.797625] usb 3-1.1: Manufacturer:  
[    1.926108] input:   RPI Wired Keyboard 1 as /devices/platform/axi/1000120000.pcie/1f00300000.usb/xhci-hcd.1/usb3/3-1/3-1.1/3-1.1:1.0/0003:04D9:0006.0001/input/input3
[    1.985453] hid-generic 0003:04D9:0006.0001: input,hidraw0: USB HID v1.11 Keyboard [  RPI Wired Keyboard 1] on usb-xhci-hcd.1-1.1/input0
[    2.022074] input:   RPI Wired Keyboard 1 as /devices/platform/axi/1000120000.pcie/1f00300000.usb/xhci-hcd.1/usb3/3-1/3-1.1/3-1.1:1.1/0003:04D9:0006.0002/input/input4
[    2.081367] hid-generic 0003:04D9:0006.0002: input,hidraw1: USB HID v1.11 Device [  RPI Wired Keyboard 1] on usb-xhci-hcd.1-1.1/input1
[    2.161285] usb 3-1.2: new low-speed USB device number 5 using xhci-hcd
[    2.264944] usb 3-1.2: New USB device found, idVendor=093a, idProduct=2510, bcdDevice= 1.00
[    2.264949] usb 3-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    2.264953] usb 3-1.2: Product: USB Optical Mouse
[    2.264956] usb 3-1.2: Manufacturer: PixArt
[    2.342097] input: PixArt USB Optical Mouse as /devices/platform/axi/1000120000.pcie/1f00300000.usb/xhci-hcd.1/usb3/3-1/3-1.2/3-1.2:1.0/0003:093A:2510.0003/input/input5
[    2.342188] hid-generic 0003:093A:2510.0003: input,hidraw2: USB HID v1.11 Mouse [PixArt USB Optical Mouse] on usb-xhci-hcd.1-1.2/input0
[    2.604512] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Quota mode: none.
[    2.677395] scsi 0:0:0:0: Direct-Access     Generic- USB3.0 CRW   -SD 1.00 PQ: 0 ANSI: 4
[    2.680057] sd 0:0:0:0: [sda] Media removed, stopped polling
[    2.680371] sd 0:0:0:0: [sda] Attached SCSI removable disk
[    2.688766] scsi 0:0:0:1: Direct-Access     Generic- USB3.0 CRW   -SD 1.00 PQ: 0 ANSI: 4
[    2.976240] NET: Registered PF_INET6 protocol family
[    2.976692] Segment Routing with IPv6
[    2.976700] In-situ OAM (IOAM) with IPv6
[    4.142627] sd 0:0:0:1: [sdb] 249670656 512-byte logical blocks: (128 GB/119 GiB)
[    4.143238] sd 0:0:0:1: [sdb] Write Protect is off
[    4.143242] sd 0:0:0:1: [sdb] Mode Sense: 2f 00 00 00
[    4.143733] sd 0:0:0:1: [sdb] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[    4.153687]  sdb: sdb1 sdb2
[    4.153799] sd 0:0:0:1: [sdb] Attached SCSI removable disk
[    4.188625] systemd[1]: systemd 252.19-1~deb12u1 running in system mode (+PAM +AUDIT +SELINUX +APPARMOR +IMA +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP +LIBFDISK +PCRE2 -PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD -BPF_FRAMEWORK -XKBCOMMON +UTMP +SYSVINIT default-hierarchy=unified)
[    4.188639] systemd[1]: Detected architecture arm64.
[    4.201449] systemd[1]: Hostname set to <pi4>.
[    4.294507] uart-pl011 107d001000.serial: no DMA platform data
[    4.599102] systemd[1]: Queued start job for default target graphical.target.
[    4.626156] systemd[1]: Created slice system-getty.slice - Slice /system/getty.
[    4.626549] systemd[1]: Created slice system-modprobe.slice - Slice /system/modprobe.
[    4.626849] systemd[1]: Created slice system-serial\x2dgetty.slice - Slice /system/serial-getty.
[    4.627147] systemd[1]: Created slice system-systemd\x2dfsck.slice - Slice /system/systemd-fsck.
[    4.627335] systemd[1]: Created slice user.slice - User and Session Slice.
[    4.627451] systemd[1]: Started systemd-ask-password-wall.path - Forward Password Requests to Wall Directory Watch.
[    4.627714] systemd[1]: Set up automount proc-sys-fs-binfmt_misc.automount - Arbitrary Executable File Formats File System Automount Point.
[    4.627792] systemd[1]: Reached target integritysetup.target - Local Integrity Protected Volumes.
[    4.627846] systemd[1]: Reached target nss-user-lookup.target - User and Group Name Lookups.
[    4.627889] systemd[1]: Reached target slices.target - Slice Units.
[    4.627918] systemd[1]: Reached target swap.target - Swaps.
[    4.627960] systemd[1]: Reached target veritysetup.target - Local Verity Protected Volumes.
[    4.628154] systemd[1]: Listening on systemd-fsckd.socket - fsck to fsckd communication Socket.
[    4.628238] systemd[1]: Listening on systemd-initctl.socket - initctl Compatibility Named Pipe.
[    4.628649] systemd[1]: Listening on systemd-journald-audit.socket - Journal Audit Socket.
[    4.628842] systemd[1]: Listening on systemd-journald-dev-log.socket - Journal Socket (/dev/log).
[    4.629061] systemd[1]: Listening on systemd-journald.socket - Journal Socket.
[    4.631870] systemd[1]: Listening on systemd-udevd-control.socket - udev Control Socket.
[    4.632052] systemd[1]: Listening on systemd-udevd-kernel.socket - udev Kernel Socket.
[    4.632279] systemd[1]: dev-hugepages.mount - Huge Pages File System was skipped because of an unmet condition check (ConditionPathExists=/sys/kernel/mm/hugepages).
[    4.633332] systemd[1]: Mounting dev-mqueue.mount - POSIX Message Queue File System...
[    4.634536] systemd[1]: Mounting sys-kernel-debug.mount - Kernel Debug File System...
[    4.635832] systemd[1]: Mounting sys-kernel-tracing.mount - Kernel Trace File System...
[    4.636036] systemd[1]: auth-rpcgss-module.service - Kernel Module supporting RPCSEC_GSS was skipped because of an unmet condition check (ConditionPathExists=/etc/krb5.keytab).
[    4.639142] systemd[1]: Starting fake-hwclock.service - Restore / save the current clock...
[    4.642426] systemd[1]: Starting keyboard-setup.service - Set the console keyboard layout...
[    4.643858] systemd[1]: Starting kmod-static-nodes.service - Create List of Static Device Nodes...
[    4.645647] systemd[1]: Starting modprobe@configfs.service - Load Kernel Module configfs...
[    4.647536] systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod...
[    4.649674] systemd[1]: Starting modprobe@drm.service - Load Kernel Module drm...
[    4.651748] systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore...
[    4.653767] systemd[1]: Starting modprobe@fuse.service - Load Kernel Module fuse...
[    4.655816] systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop...
[    4.656126] systemd[1]: systemd-fsck-root.service - File System Check on Root Device was skipped because of an unmet condition check (ConditionPathExists=!/run/initramfs/fsck-root).
[    4.659195] systemd[1]: Starting systemd-journald.service - Journal Service...
[    4.671733] systemd[1]: Starting systemd-modules-load.service - Load Kernel Modules...
[    4.673242] systemd[1]: Starting systemd-remount-fs.service - Remount Root and Kernel File Systems...
[    4.675057] systemd[1]: Starting systemd-udev-trigger.service - Coldplug All udev Devices...
[    4.677633] systemd[1]: Finished kmod-static-nodes.service - Create List of Static Device Nodes.
[    4.678568] systemd[1]: modprobe@configfs.service: Deactivated successfully.
[    4.678773] systemd[1]: Finished modprobe@configfs.service - Load Kernel Module configfs.
[    4.679387] systemd[1]: modprobe@efi_pstore.service: Deactivated successfully.
[    4.679594] systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore.
[    4.680135] systemd[1]: modprobe@drm.service: Deactivated successfully.
[    4.680318] systemd[1]: Finished modprobe@drm.service - Load Kernel Module drm.
[    4.680800] systemd[1]: modprobe@loop.service: Deactivated successfully.
[    4.680963] systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop.
[    4.681982] device-mapper: ioctl: 4.47.0-ioctl (2022-07-28) initialised: dm-devel@redhat.com
[    4.682550] systemd[1]: Mounting sys-kernel-config.mount - Kernel Configuration File System...
[    4.685593] systemd[1]: modprobe@dm_mod.service: Deactivated successfully.
[    4.685903] systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod.
[    4.686371] systemd[1]: systemd-repart.service - Repartition Root Disk was skipped because no trigger condition checks were met.
[    4.693968] systemd[1]: Mounted dev-mqueue.mount - POSIX Message Queue File System.
[    4.694374] systemd[1]: Mounted sys-kernel-debug.mount - Kernel Debug File System.
[    4.694668] systemd[1]: Mounted sys-kernel-tracing.mount - Kernel Trace File System.
[    4.694715] fuse: init (API version 7.37)
[    4.694991] systemd[1]: Mounted sys-kernel-config.mount - Kernel Configuration File System.
[    4.695756] systemd[1]: modprobe@fuse.service: Deactivated successfully.
[    4.696210] systemd[1]: Finished modprobe@fuse.service - Load Kernel Module fuse.
[    4.698475] systemd[1]: Mounting sys-fs-fuse-connections.mount - FUSE Control File System...
[    4.702334] systemd[1]: Mounted sys-fs-fuse-connections.mount - FUSE Control File System.
[    4.714102] i2c_dev: i2c /dev entries driver
[    4.715164] systemd[1]: Finished systemd-modules-load.service - Load Kernel Modules.
[    4.716286] EXT4-fs (mmcblk0p2): re-mounted. Quota mode: none.
[    4.716812] systemd[1]: Starting systemd-sysctl.service - Apply Kernel Variables...
[    4.718493] systemd[1]: Finished systemd-remount-fs.service - Remount Root and Kernel File Systems.
[    4.718989] systemd[1]: systemd-firstboot.service - First Boot Wizard was skipped because of an unmet condition check (ConditionFirstBoot=yes).
[    4.719090] systemd[1]: systemd-pstore.service - Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore).
[    4.720370] systemd[1]: Starting systemd-random-seed.service - Load/Save Random Seed...
[    4.721987] systemd[1]: Starting systemd-sysusers.service - Create System Users...
[    4.759887] systemd[1]: Started systemd-journald.service - Journal Service.
[    4.785792] systemd-journald[317]: Received client request to flush runtime journal.
[    5.562806] pimoroni_panel_ilitek_ili9881c: loading out-of-tree module taints kernel.
[    5.565316] rpi-gpiomem 107d508500.gpiomem: window base 0x107d508500 size 0x00000040
[    5.565437] rpi-gpiomem 107d508500.gpiomem: initialised 1 regions as /dev/gpiomem1
[    5.565554] rpi-gpiomem 107d517c00.gpiomem: window base 0x107d517c00 size 0x00000040
[    5.565628] rpi-gpiomem 107d517c00.gpiomem: initialised 1 regions as /dev/gpiomem2
[    5.565721] rpi-gpiomem 107d504100.gpiomem: window base 0x107d504100 size 0x00000020
[    5.566330] rpi-gpiomem 107d504100.gpiomem: initialised 1 regions as /dev/gpiomem3
[    5.566938] rpi-gpiomem 107d510700.gpiomem: window base 0x107d510700 size 0x00000020
[    5.568130] rpi-gpiomem 107d510700.gpiomem: initialised 1 regions as /dev/gpiomem4
[    5.569480] rpi-gpiomem 1f000d0000.gpiomem: window base 0x1f000d0000 size 0x00030000
[    5.571896] rpi-gpiomem 1f000d0000.gpiomem: initialised 1 regions as /dev/gpiomem0
[    5.672328] sd 0:0:0:0: Attached scsi generic sg0 type 0
[    5.692956] mc: Linux media interface: v0.10
[    5.721455] sd 0:0:0:1: Attached scsi generic sg1 type 0
[    5.743093] videodev: Linux video capture interface: v2.00
[    5.750406] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[    5.750762] cfg80211: Loaded X.509 cert 'benh@debian.org: 577e021cb980e0e820821ba7b54b4961b8b4fadf'
[    5.751073] cfg80211: Loaded X.509 cert 'romain.perier@gmail.com: 3abbc6ec146e09d1b6016ab9d6cf71dd233f0328'
[    5.751390] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[    5.822107] brcmfmac: F1 signature read @0x18000000=0x15264345
[    5.825778] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[    5.842498] usbcore: registered new interface driver brcmfmac
[    5.859999] pispbe 1000880000.pisp_be: bcm2712_iommu_of_xlate: MMU 1000005100.iommu
[    5.860184] pispbe 1000880000.pisp_be: pispbe_probe: HW version:  0x02252700
[    5.860190] pispbe 1000880000.pisp_be: pispbe_probe: BatchStatus: 0x00000000
[    5.860193] pispbe 1000880000.pisp_be: pispbe_probe: Status:      0x00000000
[    5.860197] pispbe 1000880000.pisp_be: Register nodes for group 0
[    5.865170] pispbe 1000880000.pisp_be: input device node registered as /dev/video20
[    5.866342] pispbe 1000880000.pisp_be: tdn_input device node registered as /dev/video21
[    5.866551] pispbe 1000880000.pisp_be: stitch_input device node registered as /dev/video22
[    5.871146] pispbe 1000880000.pisp_be: hog_output device node registered as /dev/video23
[    5.871551] rpivid_hevc: module is from the staging directory, the quality is unknown, you have been warned.
[    5.872461] pispbe 1000880000.pisp_be: output0 device node registered as /dev/video24
[    5.873323] rpivid 1000800000.codec: bcm2712_iommu_of_xlate: MMU 1000005100.iommu
[    5.874085] pispbe 1000880000.pisp_be: output1 device node registered as /dev/video25
[    5.874159] pispbe 1000880000.pisp_be: tdn_output device node registered as /dev/video26
[    5.874210] pispbe 1000880000.pisp_be: stitch_output device node registered as /dev/video27
[    5.874257] pispbe 1000880000.pisp_be: config device node registered as /dev/video28
[    5.874571] pispbe 1000880000.pisp_be: Register nodes for group 1
[    5.874701] pispbe 1000880000.pisp_be: input device node registered as /dev/video29
[    5.875119] pispbe 1000880000.pisp_be: tdn_input device node registered as /dev/video30
[    5.875218] pispbe 1000880000.pisp_be: stitch_input device node registered as /dev/video31
[    5.875309] pispbe 1000880000.pisp_be: hog_output device node registered as /dev/video32
[    5.875393] pispbe 1000880000.pisp_be: output0 device node registered as /dev/video33
[    5.875484] pispbe 1000880000.pisp_be: output1 device node registered as /dev/video34
[    5.875605] pispbe 1000880000.pisp_be: tdn_output device node registered as /dev/video35
[    5.875750] pispbe 1000880000.pisp_be: stitch_output device node registered as /dev/video36
[    5.875857] pispbe 1000880000.pisp_be: config device node registered as /dev/video37
[    5.884263] rpivid 1000800000.codec: Device registered as /dev/video19
[    6.020132] Bluetooth: Core ver 2.22
[    6.020183] NET: Registered PF_BLUETOOTH protocol family
[    6.020187] Bluetooth: HCI device and connection manager initialized
[    6.020199] Bluetooth: HCI socket layer initialized
[    6.020203] Bluetooth: L2CAP socket layer initialized
[    6.020212] Bluetooth: SCO socket layer initialized
[    6.028063] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Nov  1 2021 00:37:25 version 7.45.241 (1a2f2fa CY) FWID 01-703fd60
[    6.054656] Bluetooth: HCI UART driver ver 2.3
[    6.054666] Bluetooth: HCI UART protocol H4 registered
[    6.054705] Bluetooth: HCI UART protocol Three-wire (H5) registered
[    6.054851] Bluetooth: HCI UART protocol Broadcom registered
[    6.054938] hci_uart_bcm serial0-0: supply vbat not found, using dummy regulator
[    6.055009] hci_uart_bcm serial0-0: supply vddio not found, using dummy regulator
[    6.409928] Bluetooth: hci0: BCM: chip id 107
[    6.410378] Bluetooth: hci0: BCM: features 0x2f
[    6.411845] Bluetooth: hci0: BCM4345C0
[    6.411856] Bluetooth: hci0: BCM4345C0 (003.001.025) build 0000
[    6.417873] Bluetooth: hci0: BCM4345C0 'brcm/BCM4345C0.raspberrypi,5-model-b.hcd' Patch
[    6.584488] Adding 102384k swap on /var/swap.  Priority:-2 extents:1 across:102384k SSFS
[    6.881301] i2c_designware 1f00088000.i2c: controller timed out
[    6.881321] (NULL device *): regmap_read of register 0x1 failed: -ETIMEDOUT
[    6.881358] pca9685-pwm: probe of 6-0056 failed with error -110
[    7.149970] Bluetooth: hci0: BCM: features 0x2f
[    7.151379] Bluetooth: hci0: BCM43455 37.4MHz Raspberry Pi 3+-0190
[    7.151389] Bluetooth: hci0: BCM4345C0 (003.001.025) build 0382
[    7.151738] Bluetooth: hci0: BCM: Using default device address (43:45:c0:00:1f:ac)
[    7.450912] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[    7.450923] Bluetooth: BNEP filters: protocol multicast
[    7.450933] Bluetooth: BNEP socket layer initialized
[    7.454315] Bluetooth: MGMT ver 1.22
[    7.463357] NET: Registered PF_ALG protocol family
[    7.512224] macb 1f00100000.ethernet eth0: PHY [1f00100000.ethernet-ffffffff:01] driver [Broadcom BCM54213PE] (irq=POLL)
[    7.512245] macb 1f00100000.ethernet eth0: configuring for phy/rgmii-id link mode
[    7.515110] pps pps0: new PPS source ptp0
[    7.516916] macb 1f00100000.ethernet: gem-ptp-timer ptp clock registered.
[    7.529509] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled
[    9.496973] Bluetooth: RFCOMM TTY layer initialized
[    9.496986] Bluetooth: RFCOMM socket layer initialized
[    9.496996] Bluetooth: RFCOMM ver 1.11
[   12.365945] EXT4-fs (sdb2): mounted filesystem with ordered data mode. Quota mode: none.
[   12.896309] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[   13.173343] FAT-fs (sdb1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
[   17.117551] platform backlight_lcd: deferred probe pending
[   17.117558] platform reg_panel@1: deferred probe pending
[   17.117560] platform reg_touch@1: deferred probe pending
[   17.117563] mipi-dsi 1f00118000.dsi.0: deferred probe pending
[   17.117565] i2c 6-005d: deferred probe pending

Additional context

No response

[Gadgetoid]

This bug has just happened to me on 6.6.5 too.

[pelwell]

After the first instance, before I had the logic analyser attached (running a simple program to mirror the levels of GPIOs 40&41 onto GPIOs 6&7), I can't get this to fail. Whether I load the overlay from config.txt or at runtime using "sudo dtoverlay hyperportal10" (*) doesn't seem to make a difference - it's still solid. The only errors I see are:

[    7.206607] Goodix-TS 4-005d: Error reading 1 bytes from 0x8140: -121
[    7.263835] Goodix-TS 4-005d: Invalid config (0, 0, 0), using defaults

The first of these is because the Goodix controller NAKs the first read, not surprising since it happens less than a millisecond after the reset is released. The retry that happens about 37ms later is successful.
I'm not sure about the second error yet.

It may also be worth saying that I see the backlight turn on, and a flickering band of largely white pixels about 6cm wide across one side (in landscape) of the display.

(*) The overlay needs some sanitisation before the kernel will accept it at runtime, but it ends up looking like this:

/dts-v1/;
/plugin/;

/ {
	compatible = "brcm,bcm2835";

	fragment@0 {
		target = <&i2c0if>;
		__overlay__ {
			status = "okay";
		};
	};
		
	fragment@1 {
		target = <&i2c0mux>;
		__overlay__ {
			status = "okay";
		};
	};

	i2cbus: fragment@2 {
		target = <&i2c_csi_dsi>;
		__overlay__ {
			#address-cells = <1>;
			#size-cells = <0>;
			status = "okay";

			pca: pca@56 {
				compatible = "nxp,pca9685-pwm";
				reg = <0x56>;
				#pwm-cells = <2>;
				gpio-controller;
				#gpio-cells = <2>;
				status = "okay";

				gpio-line-names = "PCA_PWM0",
					"PCA_PWM1",
					"PCA_PWM2",
					"PCA_PWM3",
					"PCA_PWM4",
					"PCA_PWM5",
					"PCA_PWM6",
					"PCA_PWM7",
					"PCA_GPIO8_LCD_RST",
					"PCA_PWM9_LCD_BL",
					"PCA_GPIO10_TOUCH_RST",
					"PCA_PWM11",
					"PCA_PWM12",
					"PCA_PWM13",
					"PCA_PWM14",
					"PCA_PWM15";
			};

			gt9271@5d {
				compatible = "goodix,gt9271";
				reg = <0x5d>;
				VDDIO-supply = <&reg_touch>;
				//interrupt-parent = <&pca>;
				//reset-gpios = <&pca 10 0>;
			};
		};
	};

	fragment@3 {
		target-path = "/";
		__overlay__ {
			backlight_lcd: backlight_lcd {
				compatible = "pwm-backlight";
				brightness-levels = <0 4095>;
				num-interpolated-steps = <4096>;
				default-brightness-level = <4096>;
				pwms = <&pca 9 5000000>;
			};

			reg_touch: reg_touch {
				compatible = "regulator-fixed";
				regulator-name = "touch_reg";
				gpio = <&pca 10 0>;
				enable-active-high;
			};

			reg_panel: reg_panel {
				compatible = "regulator-fixed";
				regulator-name = "panel_reg";
				gpio = <&pca 8 0>;
				enable-active-high;
			};
		};
	};

	panel: fragment@4 {
		target = <&dsi1>;
		__overlay__ {
			#address-cells = <1>;
			#size-cells = <0>;
			status = "okay";

			port {
				dsi_out_port: endpoint {
					remote-endpoint = <&panel_dsi_in>;
				};
			};

			panel_dsi: panel@0 {
				compatible = "pimoroni,lcd10";

				reg = <0>;
				label = "hyperportal0";
				//reset-gpios = <&pca 8 1>;
				power-supply = <&reg_panel>;
				port {
					panel_dsi_in: endpoint {
						remote-endpoint = <&dsi_out_port>;
					};
				};
			};
		};
	};

	__overrides__ {
		dsi0 = <&panel>, "target:0=",<&dsi0>,
			<&i2cbus>, "target:0=",<&i2c_csi_dsi0>;
	};
};

[pelwell]

And then it failed hard, with SCL high and SDA held low:

pi@raspberrypi:~$ i2cdetect -y 4
     0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f
00:                         [  106.864317] i2c_designware 1f00080000.i2c: controller timed out
-- [  107.888296] i2c_designware 1f00080000.i2c: controller timed out
-- [  108.912255] i2c_designware 1f00080000.i2c: controller timed out
-- [  109.936233] i2c_designware 1f00080000.i2c: controller timed out
-- [  110.960209] i2c_designware 1f00080000.i2c: controller timed out
-- [  111.984188] i2c_designware 1f00080000.i2c: controller timed out
-- [  113.008155] i2c_designware 1f00080000.i2c: controller timed out
-- [  114.032134] i2c_designware 1f00080000.i2c: controller timed out
--
10: [  115.056110] i2c_designware 1f00080000.i2c: controller timed out
-- [  116.080086] i2c_designware 1f00080000.i2c: controller timed out
-- [  117.104065] i2c_designware 1f00080000.i2c: controller timed out
-- [  118.128058] i2c_designware 1f00080000.i2c: controller timed out
-- [  119.152032] i2c_designware 1f00080000.i2c: controller timed out
-- [  120.176012] i2c_designware 1f00080000.i2c: controller timed out
-- [  121.199983] i2c_designware 1f00080000.i2c: controller timed out
-- [  122.223957] i2c_designware 1f00080000.i2c: controller timed out
-- [  123.247940] i2c_designware 1f00080000.i2c: controller timed out
-- [  124.271916] i2c_designware 1f00080000.i2c: controller timed out
-- [  125.295901] i2c_designware 1f00080000.i2c: controller timed out
-- [  126.319881] i2c_designware 1f00080000.i2c: controller timed out
-- [  127.343857] i2c_designware 1f00080000.i2c: controller timed out
-- [  128.367843] i2c_designware 1f00080000.i2c: controller timed out
-- [  129.391824] i2c_designware 1f00080000.i2c: controller timed out
-- [  130.415804] i2c_designware 1f00080000.i2c: controller timed out
--

Until I flipped the catch on the touchscreen cable and it sprang into life:

20: 20 -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
30: -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
40: -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
50: -- -- -- -- -- -- 56 -- -- -- -- -- -- 5d -- --
60: -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
70: -- -- -- -- -- -- -- --
pi@raspberrypi:~$ i2cdetect -y 4
     0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f
00:                         -- -- -- -- -- -- -- --
10: -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
20: -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
30: -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
40: -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
50: -- -- -- -- -- -- 56 -- -- -- -- -- -- 5d -- --
60: -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --
70: -- -- -- -- -- -- -- --

In other words, I think the touchscreen controller (or perhaps the PWM/GPIO chip) is holding the SDA line low and causing the bus to malfunction. It's hard to tell which, since they are both on the other end of an I2C bus and my bucket has a hole.

[Gadgetoid]

Oh good grief. Thank you for looking into this. I should have known it would be our hardware. This would explain why it took a full power-cycle to recover.

The display flickering is expected. It works on Pi 4 (possibly due to timings being more forgiving) but I have not yet found the right magic incantations to get it working on 5.

At a guess I'd pin it on the touchscreen controller. It's quite possible that using a vreg instead of a proper reset pin assignment causes much more trouble than I'd imagined. I will have to dig deeper into the reset logic of the driver and reconcile that with #5777

[mozcelikors]

@Gadgetoid Hi, I have a similar issue with i2c_designware on Pi 5 when plugging in a Waveshare 4.3inch Capacitive on a custom kernel 6.1.77 I built from here. I was wondering if you had any update on this.

This doesn't happen on Raspberry Pi OS Bookworm, but only happens when I custom compile the kernel. Even tried copying and using exact dtbo from Bookworm, no help.
Issue can be viewed here: https://forums.raspberrypi.com/viewtopic.php?t=366281

@pelwell I also saw contributions by you, Phil, regarding these topics, it would be great to have some insight on the issue I am having, which seems similar here. SCL held high and SDA held low.

Help is greately appreciated. Thanks

[pelwell]

You're asking me to guess what you have got wrong in your configuration, in a forum which is intended for reporting problems in our kernel, not for general help requests.

You need to put a logic analyser on the I2C lines to see what is going wrong, which may then help you figure out why. But if you are getting the same timeout errors as above then it's likely that the device is holding one or both of the lines low when it shouldn't.

[mozcelikors]

@pelwell Okay, thanks regardless. Will do.
I understand that this might be the wrong place to ask this, but I have seen many similar questions asked&answered, so I took a shot. Not a problem. Not the first time I received such attitude in this repo :)

[JamesH65]

@pelwell Okay, thanks regardless. Will do. I understand that this might be the wrong place to ask this, but I have seen many similar questions asked&answered, so I took a shot. Not a problem. Not the first time I received such attitude in this repo :)

For general help requests, the forums are the right place to ask. forums.raspberrypi.com. You are likely to get a faster response as well, since there are more people there with knowledge than hang around here.

[mozcelikors]

The problem I have described above (not the original) is fixed when Linux kernel is downgraded to 6.1.63 (official Bookworm kernel version that worked). I guess the fixes in i2c_designware that was introduced after 6.1.63 regarding I2C timings doesn't really get along with some of the devices, causing "i2c timed out" issues.
I haven't tested with official display, but this is the case for Waveshare display. I hope this helps others having the same issue.
Cheers.

[steveiliop56]

I have the exact same problem with the 4.3 inch screen from waveshare. Most of the times it works but sometimes the display will not show anything and I will just keep getting these i2c timeouts.

[pelwell]

As I said above:

it's likely that the device is holding one or both of the lines low when it shouldn't.

If you are also on a Pi 5 then you can check the state of the I2C lines with:

pi@raspberrypi:~$ pinctrl 38-41
38: ip    pd | hi // CD0_SDA/GPIO38 = input
39: ip    pd | hi // CD0_SCL/GPIO39 = input
40: a2    pu | hi // CD1_SDA/GPIO40 = SDA4
41: a2    pu | hi // CD1_SCL/GPIO41 = SCL4

Run this command next time the display doesn't work. One of the pairs - probably 40&41 - will be SDA and SCL, and all of the signal levels should be hi if it's idle.

[steveiliop56]

Is there any fix for that, I mean how would you know waveshare hardware but maybe there is a way? Or just don't buy waveshare things ever again?

[pelwell]

If (and it currently is an "if") the hardware is permanently holding one of the I2C lines low, possibly as a result of an incomplete reset, then there is nothing we can do. If it turns out that the device is intentionally using clock stretching and that it is exceeding some time limit programmed into the I2C controller then there may be a possibility to increase the time limit.

[steveiliop56]

Is there any way to tell the pi to actually reset the screen? Like a "dsi-reinit" thing?

[steveiliop56]

Also the funny thing is that for some reason even after 50 reboots the display won't reset. In some cases it crashes so bad I have to format the SD card for it to work again.