Skip to content

flip_done timed out on 5.10.52-v7l+ #1440 with vc4-kms-v3d #4493

@PeterPablo

Description

@PeterPablo

Applying dtoverlay=vc4-kms-v3d on an up-to-date Raspberry Pi OS and system yields flip_done error messages every 10s. Note that kodi is started on boot.

dmesg
[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 5.10.52-v7l+ (dom@buildbot) (arm-linux-gnueabihf-gcc-8 (Ubuntu/Linaro 8.4.0-3ubuntu1) 8.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1440 SMP Tue Jul 27 09:55:21 BST 2021
[    0.000000] CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d
[    0.000000] CPU: div instructions available: patching division code
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
[    0.000000] OF: fdt: Machine model: Raspberry Pi 4 Model B Rev 1.1
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] Reserved memory: created CMA memory pool at 0x000000000ec00000, size 512 MiB
[    0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool
[    0.000000] Zone ranges:
[    0.000000]   DMA      [mem 0x0000000000000000-0x000000002fffffff]
[    0.000000]   Normal   empty
[    0.000000]   HighMem  [mem 0x0000000030000000-0x000000003b3fffff]
[    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 totalpages: 242688
[    0.000000]   DMA zone: 1728 pages used for memmap
[    0.000000]   DMA zone: 0 pages reserved
[    0.000000]   DMA zone: 196608 pages, LIFO batch:63
[    0.000000]   HighMem zone: 46080 pages, LIFO batch:15
[    0.000000] percpu: Embedded 20 pages/cpu s50764 r8192 d22964 u81920
[    0.000000] pcpu-alloc: s50764 r8192 d22964 u81920 alloc=20*4096
[    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 240960
[    0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 video=HDMI-A-1:1920x1080M@50,margin_left=48,margin_right=48,margin_top=48,margin_bottom=48 smsc95xx.macaddr=DC:A6:32:00:97:FD vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000  dwc_otg.lpm_enable=0 console=ttyS0,115200 console=tty1 root=PARTUUID=66606d14-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait
[    0.000000] Kernel parameter elevator= does not have any effect anymore.
               Please use sysfs to set IO scheduler for individual devices.
[    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear)
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] software IO TLB: mapped [mem 0x000000000ac00000-0x000000000ec00000] (64MB)
[    0.000000] Memory: 351020K/970752K available (10240K kernel code, 1364K rwdata, 3188K rodata, 2048K init, 891K bss, 95444K reserved, 524288K cma-reserved, 184320K highmem)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] ftrace: allocating 34303 entries in 67 pages
[    0.000000] ftrace: allocated 67 pages with 3 groups
[    0.000000] rcu: Hierarchical RCU implementation.
[    0.000000] 	Rude variant of Tasks RCU enabled.
[    0.000000] 	Tracing variant of Tasks RCU enabled.
[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000000] GIC: Using split EOI/Deactivate mode
[    0.000000] irq_brcmstb_l2: registered L2 intc (/soc/interrupt-controller@7ef00100, parent irq: 25)
[    0.000000] random: get_random_bytes called from start_kernel+0x3c8/0x59c with crng_init=0
[    0.000008] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483647500ns
[    0.000035] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275 ns
[    0.000097] bcm2835: system timer (irq = 26)
[    0.000760] arch_timer: cp15 timer(s) running at 54.00MHz (phys).
[    0.000782] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns
[    0.000805] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns
[    0.000823] Switching to timer-based delay loop, resolution 18ns
[    0.001087] Console: colour dummy device 80x30
[    0.001848] printk: console [tty1] enabled
[    0.001916] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=540000)
[    0.001973] pid_max: default: 32768 minimum: 301
[    0.002152] LSM: Security Framework initializing
[    0.002361] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[    0.002406] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[    0.003933] cgroup: Disabling memory control group subsystem
[    0.004191] CPU: Testing write buffer coherency: ok
[    0.004690] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[    0.005957] Setting up static identity map for 0x200000 - 0x20003c
[    0.006177] rcu: Hierarchical SRCU implementation.
[    0.007145] smp: Bringing up secondary CPUs ...
[    0.008400] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[    0.009797] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[    0.011253] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[    0.011413] smp: Brought up 1 node, 4 CPUs
[    0.011460] SMP: Total of 4 processors activated (432.00 BogoMIPS).
[    0.011490] CPU: All CPU(s) started in HYP mode.
[    0.011517] CPU: Virtualization extensions available.
[    0.012412] devtmpfs: initialized
[    0.027036] VFP support v0.3: implementor 41 architecture 3 part 40 variant 8 rev 0
[    0.027283] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.027339] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)
[    0.039023] pinctrl core: initialized pinctrl subsystem
[    0.040137] NET: Registered protocol family 16
[    0.044327] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[    0.045163] audit: initializing netlink subsys (disabled)
[    0.045447] audit: type=2000 audit(0.040:1): state=initialized audit_enabled=0 res=1
[    0.046051] thermal_sys: Registered thermal governor 'step_wise'
[    0.046791] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[    0.046845] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.047279] Serial: AMBA PL011 UART driver
[    0.093127] bcm2835-mbox fe00b880.mailbox: mailbox enabled
[    0.110966] raspberrypi-firmware soc:firmware: Attached to firmware from 2021-07-21T16:21:46, variant start
[    0.120977] raspberrypi-firmware soc:firmware: Firmware hash is 6a796bb0062a6c75191c57cba1c13f9300076d02
[    0.162094] Kprobes globally optimized
[    0.167365] bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1
[    0.171875] vgaarb: loaded
[    0.172351] SCSI subsystem initialized
[    0.172610] usbcore: registered new interface driver usbfs
[    0.172685] usbcore: registered new interface driver hub
[    0.172783] usbcore: registered new device driver usb
[    0.173218] usb_phy_generic phy: supply vcc not found, using dummy regulator
[    0.175149] clocksource: Switched to clocksource arch_sys_counter
[    1.134515] VFS: Disk quotas dquot_6.6.0
[    1.134631] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    1.134807] FS-Cache: Loaded
[    1.135017] CacheFiles: Loaded
[    1.136223] simple-framebuffer 3e4e0000.framebuffer: framebuffer at 0x3e4e0000, 0x6e7000 bytes, mapped to 0x(ptrval)
[    1.136268] simple-framebuffer 3e4e0000.framebuffer: format=a8r8g8b8, mode=1824x984x32, linelength=7296
[    1.146076] Console: switching to colour frame buffer device 228x61
[    1.154676] simple-framebuffer 3e4e0000.framebuffer: fb0: simplefb registered!
[    1.165295] NET: Registered protocol family 2
[    1.165600] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)
[    1.166965] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear)
[    1.167190] TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear)
[    1.167333] TCP bind hash table entries: 8192 (order: 4, 65536 bytes, linear)
[    1.167484] TCP: Hash tables configured (established 8192 bind 8192)
[    1.167718] UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
[    1.167824] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
[    1.168152] NET: Registered protocol family 1
[    1.168981] RPC: Registered named UNIX socket transport module.
[    1.169061] RPC: Registered udp transport module.
[    1.169125] RPC: Registered tcp transport module.
[    1.169189] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    1.169276] PCI: CLS 0 bytes, default 64
[    1.172754] Initialise system trusted keyrings
[    1.173069] workingset: timestamp_bits=14 max_order=18 bucket_order=4
[    1.181601] zbud: loaded
[    1.183846] FS-Cache: Netfs 'nfs' registered for caching
[    1.184687] NFS: Registering the id_resolver key type
[    1.184792] Key type id_resolver registered
[    1.184854] Key type id_legacy registered
[    1.185058] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[    1.185175] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering...
[    1.186312] Key type asymmetric registered
[    1.186378] Asymmetric key parser 'x509' registered
[    1.189177] bounce: pool size: 64 pages
[    1.191801] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249)
[    1.194532] io scheduler mq-deadline registered
[    1.197138] io scheduler kyber registered
[    1.204678] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges:
[    1.207358] brcm-pcie fd500000.pcie:   No bus range found for /scb/pcie@7d500000, using [bus 00-ff]
[    1.210021] brcm-pcie fd500000.pcie:      MEM 0x0600000000..0x063fffffff -> 0x00c0000000
[    1.212690] brcm-pcie fd500000.pcie:   IB MEM 0x0000000000..0x003fffffff -> 0x0400000000
[    1.277257] brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC)
[    1.280207] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00
[    1.282717] pci_bus 0000:00: root bus resource [bus 00-ff]
[    1.285271] pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff])
[    1.287900] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400
[    1.290666] pci 0000:00:00.0: PME# supported from D0 D3hot
[    1.296729] PCI: bus0: Fast back to back transfers disabled
[    1.299604] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330
[    1.302254] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit]
[    1.305338] pci 0000:01:00.0: PME# supported from D0 D3cold
[    1.311444] PCI: bus1: Fast back to back transfers disabled
[    1.313984] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff]
[    1.316553] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit]
[    1.319172] pci 0000:00:00.0: PCI bridge to [bus 01]
[    1.321701] pci 0000:00:00.0:   bridge window [mem 0x600000000-0x6000fffff]
[    1.324637] pcieport 0000:00:00.0: enabling device (0140 -> 0142)
[    1.327454] pcieport 0000:00:00.0: PME: Signaling with IRQ 81
[    1.340249] iproc-rng200 fe104000.rng: hwrng registered
[    1.343137] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB)
[    1.346745] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000
[    1.361694] brd: module loaded
[    1.376797] loop: module loaded
[    1.381222] Loading iSCSI transport class v2.0-870.
[    1.387022] libphy: Fixed MDIO Bus: probed
[    1.391420] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000
[    1.415181] libphy: bcmgenet MII bus: probed
[    1.505300] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus
[    1.508950] usbcore: registered new interface driver r8152
[    1.511412] usbcore: registered new interface driver lan78xx
[    1.513760] usbcore: registered new interface driver smsc95xx
[    1.517688] xhci_hcd 0000:01:00.0: enabling device (0140 -> 0142)
[    1.520184] xhci_hcd 0000:01:00.0: xHCI Host Controller
[    1.522528] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1
[    1.528172] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0000060000000890
[    1.531905] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.10
[    1.534257] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.536654] usb usb1: Product: xHCI Host Controller
[    1.539066] usb usb1: Manufacturer: Linux 5.10.52-v7l+ xhci-hcd
[    1.541459] usb usb1: SerialNumber: 0000:01:00.0
[    1.544596] hub 1-0:1.0: USB hub found
[    1.547091] hub 1-0:1.0: 1 port detected
[    1.550113] xhci_hcd 0000:01:00.0: xHCI Host Controller
[    1.552492] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2
[    1.554789] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed
[    1.557731] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.10
[    1.560134] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.562529] usb usb2: Product: xHCI Host Controller
[    1.564897] usb usb2: Manufacturer: Linux 5.10.52-v7l+ xhci-hcd
[    1.567311] usb usb2: SerialNumber: 0000:01:00.0
[    1.570362] hub 2-0:1.0: USB hub found
[    1.572775] hub 2-0:1.0: 4 ports detected
[    1.577125] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    1.579848] dwc_otg: FIQ enabled
[    1.579864] dwc_otg: NAK holdoff enabled
[    1.579878] dwc_otg: FIQ split-transaction FSM enabled
[    1.579896] Module dwc_common_port init
[    1.580380] usbcore: registered new interface driver uas
[    1.582802] usbcore: registered new interface driver usb-storage
[    1.585336] mousedev: PS/2 mouse device common for all mice
[    1.589539] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
[    1.595548] sdhci: Secure Digital Host Controller Interface driver
[    1.597902] sdhci: Copyright(c) Pierre Ossman
[    1.601005] mmc-bcm2835 fe300000.mmcnr: could not get clk, deferring probe
[    1.604015] sdhci-pltfm: SDHCI platform and OF driver helper
[    1.612011] ledtrig-cpu: registered to indicate activity on CPUs
[    1.614608] hid: raw HID events driver (C) Jiri Kosina
[    1.617123] usbcore: registered new interface driver usbhid
[    1.619444] usbhid: USB HID core driver
[    1.627450] Initializing XFRM netlink socket
[    1.629856] NET: Registered protocol family 17
[    1.632424] Key type dns_resolver registered
[    1.635101] Registering SWP/SWPB emulation handler
[    1.637641] registered taskstats version 1
[    1.639942] Loading compiled-in X.509 certificates
[    1.643082] Key type ._fscrypt registered
[    1.645391] Key type .fscrypt registered
[    1.647647] Key type fscrypt-provisioning registered
[    1.661816] uart-pl011 fe201000.serial: there is not valid maps for state default
[    1.664412] uart-pl011 fe201000.serial: cts_event_workaround enabled
[    1.666768] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 38, base_baud = 0) is a PL011 rev2
[    1.676049] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver
[    1.679455] mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0
[    1.681782] mmc-bcm2835 fe300000.mmcnr: DMA channel allocated
[    1.712733] of_cfs_init
[    1.715244] of_cfs_init: OK
[    1.734466] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
[    1.738446] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    1.742374] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    1.747619] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
[    1.749903] mmc0: SDHCI controller on fe340000.emmc2 [fe340000.emmc2] using ADMA
[    1.752792] Waiting for root device PARTUUID=66606d14-02...
[    1.754252] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    1.757762] usb 2-1: new SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[    1.800215] random: fast init done
[    1.802542] usb 2-1: New USB device found, idVendor=0480, idProduct=a00d, bcdDevice= 4.07
[    1.804830] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[    1.807128] usb 2-1: Product: External USB 3.0
[    1.809434] usb 2-1: Manufacturer: TOSHIBA
[    1.811683] usb 2-1: SerialNumber: 23183C163A4D
[    1.818932] usb-storage 2-1:1.0: USB Mass Storage device detected
[    1.822300] scsi host0: usb-storage 2-1:1.0
[    1.879593] mmc1: new high speed SDIO card at address 0001
[    1.883422] mmc0: new ultra high speed DDR50 SDHC card at address aaaa
[    1.886623] mmcblk0: mmc0:aaaa SC16G 14.8 GiB
[    1.893883]  mmcblk0: p1 p2
[    1.939967] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[    1.942341] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[    1.945226] usb 1-1: new high-speed USB device number 2 using xhci_hcd
[    1.954887] devtmpfs: mounted
[    1.966323] Freeing unused kernel memory: 2048K
[    1.985501] Run /sbin/init as init process
[    1.987817]   with arguments:
[    1.987832]     /sbin/init
[    1.987845]   with environment:
[    1.987860]     HOME=/
[    1.987874]     TERM=linux
[    2.127803] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21
[    2.130250] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
[    2.132645] usb 1-1: Product: USB2.0 Hub
[    2.137365] hub 1-1:1.0: USB hub found
[    2.139976] hub 1-1:1.0: 4 ports detected
[    2.597139] systemd[1]: System time before build time, advancing clock.
[    2.699774] NET: Registered protocol family 10
[    2.703646] Segment Routing with IPv6
[    2.770895] systemd[1]: systemd 241 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 +IDN -PCRE2 default-hierarchy=hybrid)
[    2.777588] systemd[1]: Detected architecture arm.
[    2.879598] scsi 0:0:0:0: Direct-Access     TOSHIBA  External USB 3.0 5438 PQ: 0 ANSI: 6
[    2.882407] sd 0:0:0:0: [sda] 1953525164 512-byte logical blocks: (1.00 TB/932 GiB)
[    2.883080] sd 0:0:0:0: [sda] Write Protect is off
[    2.890286] sd 0:0:0:0: [sda] Mode Sense: 23 00 00 00
[    2.890805] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    2.893623] systemd[1]: Set hostname to <horst>.
[    3.017044]  sda: sda1 sda2
[    3.024751] sd 0:0:0:0: [sda] Attached SCSI disk
[    3.829552] random: systemd: uninitialized urandom read (16 bytes read)
[    3.846865] random: systemd: uninitialized urandom read (16 bytes read)
[    3.850474] systemd[1]: Listening on Journal Socket.
[    3.857294] random: systemd: uninitialized urandom read (16 bytes read)
[    3.863191] systemd[1]: Created slice system-systemd\x2dfsck.slice.
[    3.875757] systemd[1]: Mounting POSIX Message Queue File System...
[    3.883369] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[    3.890377] systemd[1]: Reached target Swap.
[    3.898040] systemd[1]: Listening on Journal Socket (/dev/log).
[    3.905907] systemd[1]: Listening on udev Control Socket.
[    4.902344] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[    5.041016] systemd-journald[133]: Received request to flush runtime journal from PID 1
[    5.637648] rpivid-mem feb00000.hevc-decoder: rpivid-hevcmem initialised: Registers at 0xfeb00000 length 0x00010000
[    5.638248] rpivid-mem feb10000.rpivid-local-intc: rpivid-intcmem initialised: Registers at 0xfeb10000 length 0x00001000
[    5.639052] rpivid-mem feb20000.h264-decoder: rpivid-h264mem initialised: Registers at 0xfeb20000 length 0x00010000
[    5.639628] rpivid-mem feb30000.vp9-decoder: rpivid-vp9mem initialised: Registers at 0xfeb30000 length 0x00010000
[    5.737248] mc: Linux media interface: v0.10
[    5.755249] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
[    5.766614] bcm2835_vc_sm_cma_probe: Videocore shared memory driver
[    5.766643] [vc_sm_connected_init]: start
[    5.780221] videodev: Linux video capture interface: v2.00
[    5.793602] [vc_sm_connected_init]: installed successfully
[    5.804005] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[    5.821116] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned.
[    5.837269] bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned.
[    5.884306] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned.
[    5.892345] bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13
[    5.892949] bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14
[    5.893296] bcm2835-codec bcm2835-codec: Device registered as /dev/video10
[    5.893346] bcm2835-codec bcm2835-codec: Loaded V4L2 decode
[    5.893957] bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15
[    5.894697] bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16
[    5.894728] bcm2835-isp bcm2835-isp: Register output node 0 with media controller
[    5.894753] bcm2835-isp bcm2835-isp: Register capture node 1 with media controller
[    5.894777] bcm2835-isp bcm2835-isp: Register capture node 2 with media controller
[    5.894799] bcm2835-isp bcm2835-isp: Register capture node 3 with media controller
[    5.895725] bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp
[    6.025279] bcm2835-codec bcm2835-codec: Device registered as /dev/video11
[    6.025333] bcm2835-codec bcm2835-codec: Loaded V4L2 encode
[    6.104909] sd 0:0:0:0: Attached scsi generic sg0 type 0
[    6.106401] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[    6.107004] brcmstb-i2c fef04500.i2c:  @97500hz registered in polling mode
[    6.107736] brcmstb-i2c fef09500.i2c:  @97500hz registered in polling mode
[    6.135615] bcm2835-codec bcm2835-codec: Device registered as /dev/video12
[    6.135670] bcm2835-codec bcm2835-codec: Loaded V4L2 isp
[    6.176323] checking generic (3e4e0000 6e7000) vs hw (0 ffffffffffffffff)
[    6.176345] fb0: switching to vc4drmfb from simple
[    6.177057] Console: switching to colour dummy device 80x30
[    6.193198] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops [vc4])
[    6.210054] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[    6.214789] Registered IR keymap rc-cec
[    6.214973] rc rc0: vc4 as /devices/platform/soc/fef00700.hdmi/rc/rc0
[    6.215249] input: vc4 as /devices/platform/soc/fef00700.hdmi/rc/rc0/input0
[    6.216139] vc4_hdmi fef00700.hdmi: 'dmas' DT property is missing or empty, no HDMI audio
[    6.216292] vc4-drm gpu: bound fef00700.hdmi (ops vc4_hdmi_ops [vc4])
[    6.255398] Registered IR keymap rc-cec
[    6.255598] rc rc1: vc4 as /devices/platform/soc/fef05700.hdmi/rc/rc1
[    6.255843] input: vc4 as /devices/platform/soc/fef05700.hdmi/rc/rc1/input1
[    6.256853] vc4_hdmi fef05700.hdmi: Could not register sound card: -517
[    6.267678] brcmfmac: F1 signature read @0x18000000=0x15264345
[    6.285461] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[    6.287388] usbcore: registered new interface driver brcmfmac
[    6.407142] [drm] Initialized v3d 1.0.0 20180419 for fec00000.v3d on minor 1
[    6.475492] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops [vc4])
[    6.496974] Registered IR keymap rc-cec
[    6.497157] rc rc0: vc4 as /devices/platform/soc/fef00700.hdmi/rc/rc0
[    6.497390] input: vc4 as /devices/platform/soc/fef00700.hdmi/rc/rc0/input2
[    6.498075] vc4_hdmi fef00700.hdmi: 'dmas' DT property is missing or empty, no HDMI audio
[    6.498229] vc4-drm gpu: bound fef00700.hdmi (ops vc4_hdmi_ops [vc4])
[    6.500179] Registered IR keymap rc-cec
[    6.500384] rc rc1: vc4 as /devices/platform/soc/fef05700.hdmi/rc/rc1
[    6.500709] input: vc4 as /devices/platform/soc/fef05700.hdmi/rc/rc1/input3
[    6.503267] vc4_hdmi fef05700.hdmi: Could not register sound card: -517
[    6.558514] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[    6.561914] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[    6.571235] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Jan  4 2021 19:56:29 version 7.45.229 (617f1f5 CY) FWID 01-2dbd9d2e
[    7.090732] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops [vc4])
[    7.109018] Registered IR keymap rc-cec
[    7.109200] rc rc0: vc4 as /devices/platform/soc/fef00700.hdmi/rc/rc0
[    7.109529] input: vc4 as /devices/platform/soc/fef00700.hdmi/rc/rc0/input4
[    7.110043] vc4_hdmi fef00700.hdmi: 'dmas' DT property is missing or empty, no HDMI audio
[    7.110206] vc4-drm gpu: bound fef00700.hdmi (ops vc4_hdmi_ops [vc4])
[    7.111825] Registered IR keymap rc-cec
[    7.112025] rc rc1: vc4 as /devices/platform/soc/fef05700.hdmi/rc/rc1
[    7.112256] input: vc4 as /devices/platform/soc/fef05700.hdmi/rc/rc1/input5
[    7.124868] vc4-drm gpu: bound fef05700.hdmi (ops vc4_hdmi_ops [vc4])
[    7.125758] vc4-drm gpu: bound fe004000.txp (ops vc4_txp_ops [vc4])
[    7.126139] vc4-drm gpu: bound fe206000.pixelvalve (ops vc4_crtc_ops [vc4])
[    7.126440] vc4-drm gpu: bound fe207000.pixelvalve (ops vc4_crtc_ops [vc4])
[    7.126759] vc4-drm gpu: bound fe20a000.pixelvalve (ops vc4_crtc_ops [vc4])
[    7.127014] vc4-drm gpu: bound fe216000.pixelvalve (ops vc4_crtc_ops [vc4])
[    7.127306] vc4-drm gpu: bound fec12000.pixelvalve (ops vc4_crtc_ops [vc4])
[    7.147193] [drm] Initialized vc4 0.0.0 20140616 for gpu on minor 0
[    7.238380] Console: switching to colour frame buffer device 240x67
[    7.277851] vc4-drm gpu: [drm] fb0: vc4drmfb frame buffer device
[    7.784418] fuse: init (API version 7.32)
[    8.711359] 8021q: 802.1Q VLAN Support v1.8
[    8.738195] uart-pl011 fe201000.serial: no DMA platform data
[    8.951961] random: crng init done
[    8.951977] random: 7 urandom warning(s) missed due to ratelimiting
[    9.225317] Adding 524284k swap on /var/swap.  Priority:-2 extents:427 across:7457280k SSFS
[    9.249965] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled
[    9.602479] bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay)
[    9.603520] bcmgenet fd580000.ethernet eth0: Link is Down
[    9.969816] EXT4-fs (sda2): mounted filesystem with ordered data mode. Opts: user_xattr
[   10.050756] NET: Registered protocol family 3
[   10.062102] NET: Registered protocol family 5
[   15.651744] Bluetooth: Core ver 2.22
[   15.651863] NET: Registered protocol family 31
[   15.651879] Bluetooth: HCI device and connection manager initialized
[   15.651912] Bluetooth: HCI socket layer initialized
[   15.651936] Bluetooth: L2CAP socket layer initialized
[   15.651989] Bluetooth: SCO socket layer initialized
[   15.663449] Bluetooth: HCI UART driver ver 2.3
[   15.663464] Bluetooth: HCI UART protocol H4 registered
[   15.663539] Bluetooth: HCI UART protocol Three-wire (H5) registered
[   15.663794] Bluetooth: HCI UART protocol Broadcom registered
[   15.890341] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[   15.890349] Bluetooth: BNEP filters: protocol multicast
[   15.890362] Bluetooth: BNEP socket layer initialized
[   27.519420] hdmi-audio-codec hdmi-audio-codec.2.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19
[   27.537329] hdmi-audio-codec hdmi-audio-codec.2.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19
[   27.538872] hdmi-audio-codec hdmi-audio-codec.2.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19
[   27.540319] hdmi-audio-codec hdmi-audio-codec.2.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19
[   27.540951] hdmi-audio-codec hdmi-audio-codec.2.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19
[   27.541404] hdmi-audio-codec hdmi-audio-codec.2.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19
[   38.235586] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[   48.486155] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[   58.716680] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CONNECTOR:32:HDMI-A-1] flip_done timed out
[   68.957089] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [PLANE:70:plane-3] flip_done timed out
[   79.197446] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[   89.437753] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[   99.678031] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CONNECTOR:32:HDMI-A-1] flip_done timed out
[  109.918514] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [PLANE:70:plane-3] flip_done timed out
[  120.158931] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[  130.399279] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[  140.639626] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CONNECTOR:32:HDMI-A-1] flip_done timed out
[  150.879834] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [PLANE:70:plane-3] flip_done timed out
[  161.119968] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[  171.360369] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[  181.600563] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CONNECTOR:32:HDMI-A-1] flip_done timed out
[  191.840750] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [PLANE:70:plane-3] flip_done timed out
[  202.080864] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[  212.321116] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[  222.561272] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CONNECTOR:32:HDMI-A-1] flip_done timed out
[  232.801483] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [PLANE:70:plane-3] flip_done timed out
[  243.041669] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[  253.281848] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[  263.522027] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CONNECTOR:32:HDMI-A-1] flip_done timed out
[  273.772252] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [PLANE:70:plane-3] flip_done timed out
[  284.002449] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[  294.242577] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[  304.482750] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CONNECTOR:32:HDMI-A-1] flip_done timed out
[  314.722930] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [PLANE:70:plane-3] flip_done timed out
[  324.963103] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[  337.763269] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[  348.003512] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CONNECTOR:32:HDMI-A-1] flip_done timed out
[  358.243685] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [PLANE:70:plane-3] flip_done timed out
[  368.483986] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[  379.364111] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[  389.604361] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [PLANE:91:plane-6] flip_done timed out
[  399.844603] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[  410.084852] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[  420.325098] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [PLANE:91:plane-6] flip_done timed out
[  430.565354] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[  431.197132] Bluetooth: RFCOMM TTY layer initialized
[  431.197149] Bluetooth: RFCOMM socket layer initialized
[  431.197165] Bluetooth: RFCOMM ver 1.11
[  433.365242] cec-vc4: message ff 84 10 00 06 timed out
[  435.525341] cec-vc4: message ff 87 00 15 82 timed out
[  437.685339] cec-vc4: message f0 timed out
[  439.845382] cec-vc4: message f0 timed out
[  442.005421] cec-vc4: message f0 timed out
[  442.095618] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[  444.175500] cec-vc4: message f0 timed out
[  446.325542] cec-vc4: message 11 timed out
[  448.485586] cec-vc4: message 11 timed out
[  450.645628] cec-vc4: message 11 timed out
[  452.325811] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [PLANE:91:plane-6] flip_done timed out
[  452.805692] cec-vc4: message 11 timed out
[  454.965700] cec-vc4: message 22 timed out
[  457.125704] cec-vc4: message 22 timed out
[  459.285754] cec-vc4: message 99 timed out
[  461.445798] cec-vc4: message 99 timed out
[  462.565961] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[  463.605873] cec-vc4: message ff 84 10 00 01 timed out
[  465.765920] cec-vc4: message ff 87 00 15 82 timed out
[  467.925963] cec-vc4: message 10 timed out
[  470.085993] cec-vc4: message 10 timed out
[  472.245990] cec-vc4: message 10 timed out
[  472.806147] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[  474.406084] cec-vc4: message 10 timed out
[  476.576107] cec-vc4: message 10 timed out
[  478.726105] cec-vc4: message 10 timed out
[  480.886150] cec-vc4: message 10 timed out
[  483.046234] cec-vc4: message 10 timed out
[  483.046383] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [PLANE:91:plane-6] flip_done timed out
[  485.206278] cec-vc4: message 10 timed out
[  487.366270] cec-vc4: message 10 timed out
[  489.526351] cec-vc4: message 10 timed out
[  491.686377] cec-vc4: message 10 timed out
[  493.286519] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[  493.856518] cec-vc4: message 10 timed out
[  496.006450] cec-vc4: message 10 timed out
[  498.166471] cec-vc4: message 10 timed out
[  500.326510] cec-vc4: message 10 timed out
[  502.486609] cec-vc4: message 10 timed out
[  503.526718] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[  504.646632] cec-vc4: message 10 timed out
[  506.806675] cec-vc4: message 10 timed out
[  508.966705] cec-vc4: message 10 timed out
[  511.126741] cec-vc4: message 10 timed out
[  513.286800] cec-vc4: message 10 timed out
[  513.766904] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [PLANE:91:plane-6] flip_done timed out
[  516.406850] cec-vc4: message 10 timed out
[  518.566847] cec-vc4: message 10 timed out
[  520.726910] cec-vc4: message 10 timed out
[  522.886926] cec-vc4: message 10 timed out
[  524.007135] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[  525.047005] cec-vc4: message 10 timed out
[  527.207047] cec-vc4: message 10 timed out
[  530.327176] cec-vc4: message 10 timed out
[  532.487145] cec-vc4: message 10 timed out
[  534.247276] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[  534.647184] cec-vc4: message 10 timed out
[  536.807232] cec-vc4: message 10 timed out
[  538.967244] cec-vc4: message 10 timed out
[  541.127275] cec-vc4: message 10 timed out
[  543.287298] cec-vc4: message 10 timed out
[  544.487474] [drm:drm_atomic_helper_wait_for_dependencies [drm_kms_helper]] *ERROR* [PLANE:91:plane-6] flip_done timed out
[  545.447379] cec-vc4: message 10 timed out
[  547.607383] cec-vc4: message 10 timed out
[  549.767467] cec-vc4: message 10 timed out
[  551.927504] cec-vc4: message 10 timed out
[  554.087557] cec-vc4: message 10 timed out
[  554.727652] [drm:drm_atomic_helper_wait_for_flip_done [drm_kms_helper]] *ERROR* [CRTC:76:crtc-3] flip_done timed out
[  556.247575] cec-vc4: message 10 timed out
pi@horst:~ $ cat /boot/config.txt | grep -v "^#" | grep -v "^[[:space:]]*$"
dtoverlay=hifiberry-dacplus
dtoverlay=vc4-kms-v3d,cma-256
hdmi_force_hotplug=1
hdmi_group=1
hdmi_mode=31
hdmi_ignore_cec_init=1
hdmi_ignore_cec=1
dtparam=audio=off
[pi4]
pi3-disable-bt

Once I return to fkms the system and reboot dmesg stays clean. Ref. raspinfo:
http://paste.debian.net/1206037/

Is this possibly related to #4320?

Best regards
Peter

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions