Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

kernel 6.6.30-v8+ and 6.6.31-v8+ strange system freeze due to firmware error #6170

Closed
qrp73 opened this issue May 15, 2024 · 12 comments
Closed

Comments

@qrp73
Copy link

qrp73 commented May 15, 2024

Describe the bug

I catch it several times when switched from 6.6.28 to 6.6.30 (I switch with sudo rpi-update rpi-6.6.y). The mouse cursor freezes, and after some time background sound player is stopped. When it happens I cannot connect with ssh, it asks the password, but then freezes.

Sometimes Alt+SysRq+I allows to restart the Wayfire. But this time it didn't helped. Complete freeze...

I tried to switch back to 6.6.28 and it didn't happens. Then I switched to 6.6.30 and after about half hour it happens again.

Steps to reproduce the behaviour

I don't know how to reproduce it. It just happens after some runtime.

Device (s)

Raspberry Pi 4 Mod. B

System

$ cat /etc/rpi-issue
Raspberry Pi reference 2023-09-22
Generated using pi-gen, https://github.com/RPi-Distro/pi-gen, 40f37458ae7cadea1aec913ae10b5e7008ebce0a, stage4

$ vcgencmd version
Apr 17 2024 17:27:09 
Copyright (c) 2012 Broadcom
version 86ccc427f35fdc604edc511881cdf579df945fb4 (clean) (release) (start)

$ uname -a
Linux raspi 6.6.30-v8+ #1 SMP PREEMPT Tue May 14 13:53:14 UTC 2024 aarch64 GNU/Linux

Logs

May 15 14:18:53 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 15 14:18:53 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 15 14:18:53 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 15 14:18:53 raspi kernel: ThreadPoolSingl: page allocation failure: order:10, mode:0xcc1(GFP_KERNEL|GFP_DMA), nodemask=(null),cpuset=/,mems_allowed=0
May 15 14:18:53 raspi kernel: CPU: 3 PID: 42371 Comm: ThreadPoolSingl Tainted: G         C         6.6.30-v8+ #1
May 15 14:18:53 raspi kernel: Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
May 15 14:18:53 raspi kernel: Call trace:
May 15 14:18:53 raspi kernel:  dump_backtrace+0x9c/0x100
May 15 14:18:53 raspi kernel:  show_stack+0x20/0x38
May 15 14:18:53 raspi kernel:  dump_stack_lvl+0x48/0x60
May 15 14:18:53 raspi kernel:  dump_stack+0x18/0x28
May 15 14:18:53 raspi kernel:  warn_alloc+0x11c/0x1a8
May 15 14:18:53 raspi kernel:  __alloc_pages+0xdbc/0xe28
May 15 14:18:53 raspi kernel:  __dma_direct_alloc_pages.constprop.0+0x16c/0x1d8
May 15 14:18:53 raspi kernel:  dma_direct_alloc+0xd4/0x300
May 15 14:18:53 raspi kernel:  dma_alloc_attrs+0x88/0x108
May 15 14:18:53 raspi kernel:  vb2_dc_alloc+0xa8/0x198 [videobuf2_dma_contig]
May 15 14:18:53 raspi kernel:  __vb2_queue_alloc+0x1a4/0x4a0 [videobuf2_common]
May 15 14:18:53 raspi kernel:  vb2_core_reqbufs+0x258/0x470 [videobuf2_common]
May 15 14:18:53 raspi kernel:  vb2_reqbufs+0x90/0xb8 [videobuf2_v4l2]
May 15 14:18:53 raspi kernel:  v4l2_m2m_ioctl_reqbufs+0x54/0x98 [v4l2_mem2mem]
May 15 14:18:53 raspi kernel:  v4l_reqbufs+0x58/0x78 [videodev]
May 15 14:18:53 raspi kernel:  __video_do_ioctl+0x194/0x400 [videodev]
May 15 14:18:53 raspi kernel:  video_usercopy+0x1e4/0x780 [videodev]
May 15 14:18:53 raspi kernel:  video_ioctl2+0x20/0x40 [videodev]
May 15 14:18:53 raspi kernel:  v4l2_ioctl+0x48/0x70 [videodev]
May 15 14:18:53 raspi kernel:  __arm64_sys_ioctl+0xb0/0x100
May 15 14:18:53 raspi kernel:  invoke_syscall+0x50/0x128
May 15 14:18:53 raspi kernel:  el0_svc_common.constprop.0+0x48/0xf8
May 15 14:18:53 raspi kernel:  do_el0_svc+0x28/0x40
May 15 14:18:53 raspi kernel:  el0_svc+0x40/0xf8
May 15 14:18:53 raspi kernel:  el0t_64_sync_handler+0x13c/0x158
May 15 14:18:53 raspi kernel:  el0t_64_sync+0x190/0x198
May 15 14:18:53 raspi kernel: Mem-Info:
May 15 14:18:53 raspi kernel: active_anon:266632 inactive_anon:822 isolated_anon:0
                               active_file:281045 inactive_file:119129 isolated_file:0
                               unevictable:104518 dirty:6357 writeback:0
                               slab_reclaimable:13422 slab_unreclaimable:11529
                               mapped:124076 shmem:130410 pagetables:5081
                               sec_pagetables:0 bounce:0
                               kernel_misc_reclaimable:0
                               free:32714 free_pcp:70 free_cma:4095
May 15 14:18:53 raspi kernel: Node 0 active_anon:1066528kB inactive_anon:3288kB active_file:1124180kB inactive_file:476516kB unevictable:418072kB isolated(an>
May 15 14:18:53 raspi kernel: DMA free:82520kB boost:0kB min:3728kB low:4660kB high:5592kB reserved_highatomic:0KB active_anon:130324kB inactive_anon:0kB act>
May 15 14:18:53 raspi kernel: lowmem_reserve[]: 0 2928 2928 2928
May 15 14:18:53 raspi kernel: DMA: 376*4kB (UMEC) 159*8kB (UMEC) 144*16kB (UMEC) 88*32kB (UMEC) 58*64kB (UMEC) 44*128kB (UMEC) 42*256kB (MEC) 51*512kB (UMEC)>
May 15 14:18:53 raspi kernel: 530627 total pagecache pages
May 15 14:18:53 raspi kernel: 0 pages in swap cache
May 15 14:18:53 raspi kernel: Free swap  = 0kB
May 15 14:18:53 raspi kernel: Total swap = 0kB
May 15 14:18:53 raspi kernel: 1012736 pages RAM
May 15 14:18:53 raspi kernel: 0 pages HighMem/MovableOnly
May 15 14:18:53 raspi kernel: 41971 pages reserved
May 15 14:18:53 raspi kernel: 131072 pages cma reserved
May 15 14:18:53 raspi kernel: bcm2835-codec bcm2835-codec: dma alloc of size 4194304 failed
May 15 14:18:53 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 15 14:18:53 raspi kernel: bcm2835-codec bcm2835-codec: dma alloc of size 4194304 failed
May 15 14:18:56 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 15 14:18:56 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 15 14:18:56 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 15 14:18:56 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 15 14:18:56 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 15 14:18:56 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 15 14:18:56 raspi kernel: bcm2835-codec bcm2835-codec: dma alloc of size 4194304 failed
May 15 14:20:34 raspi kernel: ------------[ cut here ]------------
May 15 14:20:34 raspi kernel: Firmware transaction timeout
May 15 14:20:34 raspi kernel: WARNING: CPU: 0 PID: 38971 at drivers/firmware/raspberrypi.c:68 rpi_firmware_property_list+0x218/0x258
May 15 14:20:34 raspi kernel: Modules linked in: ntfs3 rfcomm snd_seq_dummy snd_hrtimer snd_seq cmac algif_hash aes_arm64 aes_generic algif_skcipher af_alg b>
May 15 14:20:34 raspi kernel: CPU: 0 PID: 38971 Comm: kworker/u9:0 Tainted: G         C         6.6.30-v8+ #1
May 15 14:20:34 raspi kernel: Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
May 15 14:20:34 raspi kernel: Workqueue: events_unbound commit_work [drm_kms_helper]
May 15 14:20:34 raspi kernel: pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
May 15 14:20:34 raspi kernel: pc : rpi_firmware_property_list+0x218/0x258
May 15 14:20:34 raspi kernel: lr : rpi_firmware_property_list+0x218/0x258
May 15 14:20:34 raspi kernel: sp : ffffffc085a13b30
May 15 14:20:34 raspi kernel: x29: ffffffc085a13b30 x28: ffffff804092bcc0 x27: ffffffeb709cae88
May 15 14:20:34 raspi kernel: x26: ffffffeb709cada0 x25: ffffffc08049e008 x24: 0000000000001000
May 15 14:20:34 raspi kernel: x23: ffffff80015ea880 x22: 00000000ffffff92 x21: 0000000000000018
May 15 14:20:34 raspi kernel: x20: ffffff804092bc80 x19: ffffffc08049e000 x18: 0000000000000000
May 15 14:20:34 raspi kernel: x17: 0000000000000000 x16: 0000000000000002 x15: 0000000000000000
May 15 14:20:34 raspi kernel: x14: 0000000000000000 x13: 74756f656d697420 x12: 6e6f69746361736e
May 15 14:20:34 raspi kernel: x11: fffffffffffe0000 x10: ffffffeb708a73b0 x9 : ffffffeb6f30897c
May 15 14:20:34 raspi kernel: x8 : 00000000ffffefff x7 : ffffffeb708a3708 x6 : 0000000000003ca8
May 15 14:20:34 raspi kernel: x5 : ffffff80fb76bd48 x4 : 0000000000000000 x3 : 0000000000000027
May 15 14:20:34 raspi kernel: x2 : 0000000000000000 x1 : 0000000000000000 x0 : ffffff808a258000
May 15 14:20:34 raspi kernel: Call trace:
May 15 14:20:34 raspi kernel:  rpi_firmware_property_list+0x218/0x258
May 15 14:20:34 raspi kernel:  rpi_firmware_property+0x78/0x118
May 15 14:20:34 raspi kernel:  raspberrypi_fw_get_rate+0x4c/0x88
May 15 14:20:34 raspi kernel:  clk_recalc+0x40/0xb8
May 15 14:20:34 raspi kernel:  __clk_recalc_rates+0x44/0xc0
May 15 14:20:34 raspi kernel:  clk_set_rate_range_nolock.part.0+0x1f0/0x2e8
May 15 14:20:34 raspi kernel:  clk_set_min_rate+0x4c/0x108
May 15 14:20:34 raspi kernel:  vc4_atomic_commit_tail+0x23c/0x880 [vc4]
May 15 14:20:34 raspi kernel:  commit_tail+0xac/0x1a0 [drm_kms_helper]
May 15 14:20:34 raspi kernel:  commit_work+0x1c/0x30 [drm_kms_helper]
May 15 14:20:34 raspi kernel:  process_one_work+0x148/0x388
May 15 14:20:34 raspi kernel:  worker_thread+0x338/0x450
May 15 14:20:34 raspi kernel:  kthread+0x120/0x130
May 15 14:20:34 raspi kernel:  ret_from_fork+0x10/0x20
May 15 14:20:34 raspi kernel: ---[ end trace 0000000000000000 ]---
May 15 14:20:36 raspi kernel: hwmon hwmon1: Failed to get throttled (-110)
May 15 14:20:36 raspi kernel: bcm2835_mmal_vchiq: timed out waiting for sync completion
May 15 14:20:37 raspi kernel: raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-core frequency: -110
May 15 14:21:35 raspi kernel: sysrq: Kill All Tasks

Additional context

3 user processes were running during issue: sdrpp, chromium-browser and vlc. Previously I catched it without sdrpp.
Power supply is ok, temperature didn't exceed 50 °C (usually it is 39-46°C under load).

@popcornmix
Copy link
Collaborator

Can you identify the exact update which caused this. See:
https://github.com/raspberrypi/rpi-firmware/commits/master

If you click on each commit the end of the url contains a git hash. Run
sudo rpi-update <hash>
to revert back to that version. Report the first version with this error.

You know it's between 6.6.28 and 6.6.30 so there aren't too many commits to check.

@qrp73
Copy link
Author

qrp73 commented May 16, 2024

just catch it again. I will try different commits. But it's not easy, because this issue is floating and I cannot reproduce it with stable steps.

This time it happens when I clicked on close tab button on chromium-browser:

May 16 08:53:41 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 16 08:53:41 raspi kernel: ThreadPoolSingl: page allocation failure: order:10, mode:0xcc1(GFP_KERNEL|GFP_DMA), nodemask=(null),cpuset=/,mems_allowed=0
May 16 08:53:41 raspi kernel: CPU: 1 PID: 98136 Comm: ThreadPoolSingl Tainted: G         C         6.6.30-v8+ #1
May 16 08:53:41 raspi kernel: Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
May 16 08:53:41 raspi kernel: Call trace:
May 16 08:53:41 raspi kernel:  dump_backtrace+0x9c/0x100
May 16 08:53:41 raspi kernel:  show_stack+0x20/0x38
May 16 08:53:41 raspi kernel:  dump_stack_lvl+0x48/0x60
May 16 08:53:41 raspi kernel:  dump_stack+0x18/0x28
May 16 08:53:41 raspi kernel:  warn_alloc+0x11c/0x1a8
May 16 08:53:41 raspi kernel:  __alloc_pages+0xdbc/0xe28
May 16 08:53:41 raspi kernel:  __dma_direct_alloc_pages.constprop.0+0x16c/0x1d8
May 16 08:53:41 raspi kernel:  dma_direct_alloc+0xd4/0x300
May 16 08:53:41 raspi kernel:  dma_alloc_attrs+0x88/0x108
May 16 08:53:41 raspi kernel:  vb2_dc_alloc+0xa8/0x198 [videobuf2_dma_contig]
May 16 08:53:41 raspi kernel:  __vb2_queue_alloc+0x1a4/0x4a0 [videobuf2_common]
May 16 08:53:41 raspi kernel:  vb2_core_reqbufs+0x258/0x470 [videobuf2_common]
May 16 08:53:41 raspi kernel:  vb2_reqbufs+0x90/0xb8 [videobuf2_v4l2]
May 16 08:53:41 raspi kernel:  v4l2_m2m_ioctl_reqbufs+0x54/0x98 [v4l2_mem2mem]
May 16 08:53:41 raspi kernel:  v4l_reqbufs+0x58/0x78 [videodev]
May 16 08:53:41 raspi kernel:  __video_do_ioctl+0x194/0x400 [videodev]
May 16 08:53:41 raspi kernel:  video_usercopy+0x1e4/0x780 [videodev]
May 16 08:53:41 raspi kernel:  video_ioctl2+0x20/0x40 [videodev]
May 16 08:53:41 raspi kernel:  v4l2_ioctl+0x48/0x70 [videodev]
May 16 08:53:41 raspi kernel:  __arm64_sys_ioctl+0xb0/0x100
May 16 08:53:41 raspi kernel:  invoke_syscall+0x50/0x128
May 16 08:53:41 raspi kernel:  el0_svc_common.constprop.0+0x48/0xf8
May 16 08:53:41 raspi kernel:  do_el0_svc+0x28/0x40
May 16 08:53:41 raspi kernel:  el0_svc+0x40/0xf8
May 16 08:53:41 raspi kernel:  el0t_64_sync_handler+0x13c/0x158
May 16 08:53:41 raspi kernel:  el0t_64_sync+0x190/0x198
May 16 08:53:41 raspi kernel: Mem-Info:
May 16 08:53:41 raspi kernel: active_anon:253404 inactive_anon:8102 isolated_anon:25
                               active_file:280053 inactive_file:168585 isolated_file:0
                               unevictable:84368 dirty:1451 writeback:0
                               slab_reclaimable:13132 slab_unreclaimable:11041
                               mapped:122612 shmem:104701 pagetables:5039
                               sec_pagetables:0 bounce:0
                               kernel_misc_reclaimable:0
                               free:21639 free_pcp:163 free_cma:5817
May 16 08:53:41 raspi kernel: Node 0 active_anon:1013616kB inactive_anon:32408kB active_file:1120212kB inactive_file:674340kB unevictable:337472kB isolated(a>
May 16 08:53:41 raspi kernel: DMA free:65088kB boost:0kB min:3728kB low:4660kB high:5592kB reserved_highatomic:0KB active_anon:193640kB inactive_anon:8kB act>
May 16 08:53:41 raspi kernel: lowmem_reserve[]: 0 2928 2928 2928
May 16 08:53:41 raspi kernel: DMA: 516*4kB (UMEC) 307*8kB (UMEC) 129*16kB (UMEC) 50*32kB (UMEC) 45*64kB (UMEC) 91*128kB (UC) 68*256kB (UEC) 21*512kB (UC) 6*1>
May 16 08:53:41 raspi kernel: 553376 total pagecache pages
May 16 08:53:41 raspi kernel: 0 pages in swap cache
May 16 08:53:41 raspi kernel: Free swap  = 0kB
May 16 08:53:41 raspi kernel: Total swap = 0kB
May 16 08:53:41 raspi kernel: 1012736 pages RAM
May 16 08:53:41 raspi kernel: 0 pages HighMem/MovableOnly
May 16 08:53:41 raspi kernel: 41971 pages reserved
May 16 08:53:41 raspi kernel: 131072 pages cma reserved
May 16 08:53:41 raspi kernel: bcm2835-codec bcm2835-codec: dma alloc of size 4194304 failed
May 16 08:53:49 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 16 08:53:56 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 16 08:53:56 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 16 08:53:56 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 16 08:53:56 raspi kernel: ThreadPoolSingl: page allocation failure: order:10, mode:0xcc1(GFP_KERNEL|GFP_DMA), nodemask=(null),cpuset=/,mems_allowed=0
May 16 08:53:56 raspi kernel: CPU: 2 PID: 98166 Comm: ThreadPoolSingl Tainted: G         C         6.6.30-v8+ #1
May 16 08:53:56 raspi kernel: Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
May 16 08:53:56 raspi kernel: Call trace:
May 16 08:53:56 raspi kernel:  dump_backtrace+0x9c/0x100
May 16 08:53:56 raspi kernel:  show_stack+0x20/0x38
May 16 08:53:56 raspi kernel:  dump_stack_lvl+0x48/0x60
May 16 08:53:56 raspi kernel:  dump_stack+0x18/0x28
May 16 08:53:56 raspi kernel:  warn_alloc+0x11c/0x1a8
May 16 08:53:56 raspi kernel:  __alloc_pages+0xdbc/0xe28
May 16 08:53:56 raspi kernel:  __dma_direct_alloc_pages.constprop.0+0x16c/0x1d8
May 16 08:53:56 raspi kernel:  dma_direct_alloc+0xd4/0x300
May 16 08:53:56 raspi kernel:  dma_alloc_attrs+0x88/0x108
May 16 08:53:56 raspi kernel:  vb2_dc_alloc+0xa8/0x198 [videobuf2_dma_contig]
May 16 08:53:56 raspi kernel:  __vb2_queue_alloc+0x1a4/0x4a0 [videobuf2_common]
May 16 08:53:56 raspi kernel:  vb2_core_reqbufs+0x258/0x470 [videobuf2_common]
May 16 08:53:56 raspi kernel:  vb2_reqbufs+0x90/0xb8 [videobuf2_v4l2]
May 16 08:53:56 raspi kernel:  v4l2_m2m_ioctl_reqbufs+0x54/0x98 [v4l2_mem2mem]
May 16 08:53:56 raspi kernel:  v4l_reqbufs+0x58/0x78 [videodev]
May 16 08:53:56 raspi kernel:  __video_do_ioctl+0x194/0x400 [videodev]
May 16 08:53:56 raspi kernel:  video_usercopy+0x1e4/0x780 [videodev]
May 16 08:53:56 raspi kernel:  video_ioctl2+0x20/0x40 [videodev]
May 16 08:53:56 raspi kernel:  v4l2_ioctl+0x48/0x70 [videodev]
May 16 08:53:56 raspi kernel:  __arm64_sys_ioctl+0xb0/0x100
May 16 08:53:56 raspi kernel:  invoke_syscall+0x50/0x128
May 16 08:53:56 raspi kernel:  el0_svc_common.constprop.0+0x48/0xf8
May 16 08:53:56 raspi kernel:  do_el0_svc+0x28/0x40
May 16 08:53:56 raspi kernel:  el0_svc+0x40/0xf8
May 16 08:53:56 raspi kernel:  el0t_64_sync_handler+0x13c/0x158
May 16 08:53:56 raspi kernel:  el0t_64_sync+0x190/0x198
May 16 08:53:56 raspi kernel: Mem-Info:
May 16 08:53:56 raspi kernel: active_anon:258404 inactive_anon:8102 isolated_anon:0
                               active_file:280045 inactive_file:141933 isolated_file:0
                               unevictable:106524 dirty:1856 writeback:0
                               slab_reclaimable:12819 slab_unreclaimable:11155
                               mapped:123903 shmem:128611 pagetables:5052
                               sec_pagetables:0 bounce:0
                               kernel_misc_reclaimable:0
                               free:18570 free_pcp:390 free_cma:4140
May 16 08:53:56 raspi kernel: Node 0 active_anon:1033616kB inactive_anon:32408kB active_file:1120180kB inactive_file:567732kB unevictable:426096kB isolated(a>
May 16 08:53:56 raspi kernel: DMA free:32848kB boost:0kB min:3728kB low:4660kB high:5592kB reserved_highatomic:0KB active_anon:192296kB inactive_anon:8kB act>
May 16 08:53:56 raspi kernel: lowmem_reserve[]: 0 2928 2928 2928
May 16 08:53:56 raspi kernel: DMA: 405*4kB (UMEC) 303*8kB (UMEC) 168*16kB (UMEC) 88*32kB (UMEC) 51*64kB (UMEC) 25*128kB (UMC) 30*256kB (UMEC) 8*512kB (MC) 1*>
May 16 08:53:56 raspi kernel: 550663 total pagecache pages
May 16 08:53:56 raspi kernel: 0 pages in swap cache
May 16 08:53:56 raspi kernel: Free swap  = 0kB
May 16 08:53:56 raspi kernel: Total swap = 0kB
May 16 08:53:56 raspi kernel: 1012736 pages RAM
May 16 08:53:56 raspi kernel: 0 pages HighMem/MovableOnly
May 16 08:53:56 raspi kernel: 41971 pages reserved
May 16 08:53:56 raspi kernel: 131072 pages cma reserved
May 16 08:53:56 raspi kernel: bcm2835-codec bcm2835-codec: dma alloc of size 4194304 failed
May 16 08:55:44 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 16 08:55:44 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 16 08:57:19 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 16 08:57:19 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 16 08:57:19 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 16 08:57:19 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 16 08:57:19 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 16 08:57:19 raspi kernel: ThreadPoolSingl: page allocation failure: order:10, mode:0xcc1(GFP_KERNEL|GFP_DMA), nodemask=(null),cpuset=/,mems_allowed=0
May 16 08:57:19 raspi kernel: CPU: 0 PID: 98477 Comm: ThreadPoolSingl Tainted: G         C         6.6.30-v8+ #1
May 16 08:57:19 raspi kernel: Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
May 16 08:57:19 raspi kernel: Call trace:
May 16 08:57:19 raspi kernel:  dump_backtrace+0x9c/0x100
May 16 08:57:19 raspi kernel:  show_stack+0x20/0x38
May 16 08:57:19 raspi kernel:  dump_stack_lvl+0x48/0x60
May 16 08:57:19 raspi kernel:  dump_stack+0x18/0x28
May 16 08:57:19 raspi kernel:  warn_alloc+0x11c/0x1a8
May 16 08:57:19 raspi kernel:  __alloc_pages+0xdbc/0xe28
May 16 08:57:19 raspi kernel:  __dma_direct_alloc_pages.constprop.0+0x16c/0x1d8
May 16 08:57:19 raspi kernel:  dma_direct_alloc+0xd4/0x300
May 16 08:57:19 raspi kernel:  dma_alloc_attrs+0x88/0x108
May 16 08:57:19 raspi kernel:  vb2_dc_alloc+0xa8/0x198 [videobuf2_dma_contig]
May 16 08:57:19 raspi kernel:  __vb2_queue_alloc+0x1a4/0x4a0 [videobuf2_common]
May 16 08:57:19 raspi kernel:  vb2_core_reqbufs+0x258/0x470 [videobuf2_common]
May 16 08:57:19 raspi kernel:  vb2_reqbufs+0x90/0xb8 [videobuf2_v4l2]
May 16 08:57:19 raspi kernel:  v4l2_m2m_ioctl_reqbufs+0x54/0x98 [v4l2_mem2mem]
May 16 08:57:19 raspi kernel:  v4l_reqbufs+0x58/0x78 [videodev]
May 16 08:57:19 raspi kernel:  __video_do_ioctl+0x194/0x400 [videodev]
May 16 08:57:19 raspi kernel:  video_usercopy+0x1e4/0x780 [videodev]
May 16 08:57:19 raspi kernel:  video_ioctl2+0x20/0x40 [videodev]
May 16 08:57:19 raspi kernel:  v4l2_ioctl+0x48/0x70 [videodev]
May 16 08:57:19 raspi kernel:  __arm64_sys_ioctl+0xb0/0x100
May 16 08:57:19 raspi kernel:  invoke_syscall+0x50/0x128
May 16 08:57:19 raspi kernel:  el0_svc_common.constprop.0+0x48/0xf8
May 16 08:57:19 raspi kernel:  do_el0_svc+0x28/0x40
May 16 08:57:19 raspi kernel:  el0_svc+0x40/0xf8
May 16 08:57:19 raspi kernel:  el0t_64_sync_handler+0x13c/0x158
May 16 08:57:19 raspi kernel:  el0t_64_sync+0x190/0x198
May 16 08:57:19 raspi kernel: Mem-Info:
May 16 08:57:19 raspi kernel: active_anon:261165 inactive_anon:8101 isolated_anon:0
                               active_file:288226 inactive_file:134364 isolated_file:0
                               unevictable:72240 dirty:143 writeback:0
                               slab_reclaimable:12050 slab_unreclaimable:11255
                               mapped:123143 shmem:93063 pagetables:5091
                               sec_pagetables:0 bounce:0
                               kernel_misc_reclaimable:0
                               free:47395 free_pcp:0 free_cma:4985
May 16 08:57:19 raspi kernel: Node 0 active_anon:1044660kB inactive_anon:32404kB active_file:1152904kB inactive_file:537456kB unevictable:288960kB isolated(a>
May 16 08:57:19 raspi kernel: DMA free:111040kB boost:0kB min:3728kB low:4660kB high:5592kB reserved_highatomic:0KB active_anon:183792kB inactive_anon:4kB ac>
May 16 08:57:19 raspi kernel: lowmem_reserve[]: 0 2928 2928 2928
May 16 08:57:19 raspi kernel: DMA: 1611*4kB (UMEC) 1072*8kB (UMEC) 544*16kB (UMEC) 394*32kB (UMEC) 189*64kB (UMEC) 130*128kB (UMC) 66*256kB (UMEC) 25*512kB (>
May 16 08:57:19 raspi kernel: 515690 total pagecache pages
May 16 08:57:19 raspi kernel: 0 pages in swap cache
May 16 08:57:19 raspi kernel: Free swap  = 0kB
May 16 08:57:19 raspi kernel: Total swap = 0kB
May 16 08:57:19 raspi kernel: 1012736 pages RAM
May 16 08:57:19 raspi kernel: 0 pages HighMem/MovableOnly
May 16 08:57:19 raspi kernel: 41971 pages reserved
May 16 08:57:19 raspi kernel: 131072 pages cma reserved
May 16 08:57:19 raspi kernel: bcm2835-codec bcm2835-codec: dma alloc of size 4194304 failed
May 16 08:57:31 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 16 08:57:31 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 16 08:57:31 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 16 08:57:31 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 16 08:57:31 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 16 08:57:31 raspi kernel: ThreadPoolSingl: page allocation failure: order:10, mode:0xcc1(GFP_KERNEL|GFP_DMA), nodemask=(null),cpuset=/,mems_allowed=0
May 16 08:57:31 raspi kernel: CPU: 3 PID: 98495 Comm: ThreadPoolSingl Tainted: G         C         6.6.30-v8+ #1
May 16 08:57:31 raspi kernel: Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
May 16 08:57:31 raspi kernel: Call trace:
May 16 08:57:31 raspi kernel:  dump_backtrace+0x9c/0x100
May 16 08:57:31 raspi kernel:  show_stack+0x20/0x38
May 16 08:57:31 raspi kernel:  dump_stack_lvl+0x48/0x60
May 16 08:57:31 raspi kernel:  dump_stack+0x18/0x28
May 16 08:57:31 raspi kernel:  warn_alloc+0x11c/0x1a8
May 16 08:57:31 raspi kernel:  __alloc_pages+0xdbc/0xe28
May 16 08:57:31 raspi kernel:  __dma_direct_alloc_pages.constprop.0+0x16c/0x1d8
May 16 08:57:31 raspi kernel:  dma_direct_alloc+0xd4/0x300
May 16 08:57:31 raspi kernel:  dma_alloc_attrs+0x88/0x108
May 16 08:57:31 raspi kernel:  vb2_dc_alloc+0xa8/0x198 [videobuf2_dma_contig]
May 16 08:57:31 raspi kernel:  __vb2_queue_alloc+0x1a4/0x4a0 [videobuf2_common]
May 16 08:57:31 raspi kernel:  vb2_core_reqbufs+0x258/0x470 [videobuf2_common]
May 16 08:57:31 raspi kernel:  vb2_reqbufs+0x90/0xb8 [videobuf2_v4l2]
May 16 08:57:31 raspi kernel:  v4l2_m2m_ioctl_reqbufs+0x54/0x98 [v4l2_mem2mem]
May 16 08:57:31 raspi kernel:  v4l_reqbufs+0x58/0x78 [videodev]
May 16 08:57:31 raspi kernel:  __video_do_ioctl+0x194/0x400 [videodev]
May 16 08:57:31 raspi kernel:  video_usercopy+0x1e4/0x780 [videodev]
May 16 08:57:31 raspi kernel:  video_ioctl2+0x20/0x40 [videodev]
May 16 08:57:31 raspi kernel:  v4l2_ioctl+0x48/0x70 [videodev]
May 16 08:57:31 raspi kernel:  __arm64_sys_ioctl+0xb0/0x100
May 16 08:57:31 raspi kernel:  invoke_syscall+0x50/0x128
May 16 08:57:31 raspi kernel:  el0_svc_common.constprop.0+0x48/0xf8
May 16 08:57:31 raspi kernel:  do_el0_svc+0x28/0x40
May 16 08:57:31 raspi kernel:  el0_svc+0x40/0xf8
May 16 08:57:31 raspi kernel:  el0t_64_sync_handler+0x13c/0x158
May 16 08:57:31 raspi kernel:  el0t_64_sync+0x190/0x198
May 16 08:57:31 raspi kernel: Mem-Info:
May 16 08:57:31 raspi kernel: active_anon:18199 inactive_anon:251839 isolated_anon:0
                               active_file:285957 inactive_file:136605 isolated_file:0
                               unevictable:82953 dirty:248 writeback:0
                               slab_reclaimable:10955 slab_unreclaimable:11253
                               mapped:123134 shmem:104228 pagetables:5101
                               sec_pagetables:0 bounce:0
                               kernel_misc_reclaimable:0
                               free:33171 free_pcp:0 free_cma:2118
May 16 08:57:31 raspi kernel: Node 0 active_anon:72796kB inactive_anon:1007356kB active_file:1143976kB inactive_file:546272kB unevictable:331812kB isolated(a>
May 16 08:57:31 raspi kernel: DMA free:95572kB boost:0kB min:3728kB low:4660kB high:5592kB reserved_highatomic:0KB active_anon:13624kB inactive_anon:170096kB>
May 16 08:57:31 raspi kernel: lowmem_reserve[]: 0 2928 2928 2928
May 16 08:57:31 raspi kernel: DMA: 951*4kB (UMEC) 713*8kB (UMEC) 397*16kB (UMEC) 345*32kB (UMEC) 161*64kB (UMEC) 124*128kB (UMC) 58*256kB (UMEC) 22*512kB (UM>
May 16 08:57:31 raspi kernel: 526791 total pagecache pages
May 16 08:57:31 raspi kernel: 0 pages in swap cache
May 16 08:57:31 raspi kernel: Free swap  = 0kB
May 16 08:57:31 raspi kernel: Total swap = 0kB
May 16 08:57:31 raspi kernel: 1012736 pages RAM
May 16 08:57:31 raspi kernel: 0 pages HighMem/MovableOnly
May 16 08:57:31 raspi kernel: 41971 pages reserved
May 16 08:57:31 raspi kernel: 131072 pages cma reserved
May 16 08:57:31 raspi kernel: bcm2835-codec bcm2835-codec: dma alloc of size 4194304 failed
May 16 08:57:44 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 16 08:57:44 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 16 08:57:44 raspi kernel: ThreadPoolSingl: page allocation failure: order:10, mode:0xcc1(GFP_KERNEL|GFP_DMA), nodemask=(null),cpuset=/,mems_allowed=0
May 16 08:57:44 raspi kernel: CPU: 3 PID: 98518 Comm: ThreadPoolSingl Tainted: G         C         6.6.30-v8+ #1
May 16 08:57:44 raspi kernel: Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
May 16 08:57:44 raspi kernel: Call trace:
May 16 08:57:44 raspi kernel:  dump_backtrace+0x9c/0x100
May 16 08:57:44 raspi kernel:  show_stack+0x20/0x38
May 16 08:57:44 raspi kernel:  dump_stack_lvl+0x48/0x60
May 16 08:57:44 raspi kernel:  dump_stack+0x18/0x28
May 16 08:57:44 raspi kernel:  warn_alloc+0x11c/0x1a8
May 16 08:57:44 raspi kernel:  __alloc_pages+0xdbc/0xe28
May 16 08:57:44 raspi kernel:  __dma_direct_alloc_pages.constprop.0+0x16c/0x1d8
May 16 08:57:44 raspi kernel:  dma_direct_alloc+0xd4/0x300
May 16 08:57:44 raspi kernel:  dma_alloc_attrs+0x88/0x108
May 16 08:57:44 raspi kernel:  vb2_dc_alloc+0xa8/0x198 [videobuf2_dma_contig]
May 16 08:57:44 raspi kernel:  __vb2_queue_alloc+0x1a4/0x4a0 [videobuf2_common]
May 16 08:57:44 raspi kernel:  vb2_core_reqbufs+0x258/0x470 [videobuf2_common]
May 16 08:57:44 raspi kernel:  vb2_reqbufs+0x90/0xb8 [videobuf2_v4l2]
May 16 08:57:44 raspi kernel:  v4l2_m2m_ioctl_reqbufs+0x54/0x98 [v4l2_mem2mem]
May 16 08:57:44 raspi kernel:  v4l_reqbufs+0x58/0x78 [videodev]
May 16 08:57:44 raspi kernel:  __video_do_ioctl+0x194/0x400 [videodev]
May 16 08:57:44 raspi kernel:  video_usercopy+0x1e4/0x780 [videodev]
May 16 08:57:44 raspi kernel:  video_ioctl2+0x20/0x40 [videodev]
May 16 08:57:44 raspi kernel:  v4l2_ioctl+0x48/0x70 [videodev]
May 16 08:57:44 raspi kernel:  __arm64_sys_ioctl+0xb0/0x100
May 16 08:57:44 raspi kernel:  invoke_syscall+0x50/0x128
May 16 08:57:44 raspi kernel:  el0_svc_common.constprop.0+0x48/0xf8
May 16 08:57:44 raspi kernel:  do_el0_svc+0x28/0x40
May 16 08:57:44 raspi kernel:  el0_svc+0x40/0xf8
May 16 08:57:44 raspi kernel:  el0t_64_sync_handler+0x13c/0x158
May 16 08:57:44 raspi kernel:  el0t_64_sync+0x190/0x198
May 16 08:57:44 raspi kernel: Mem-Info:
May 16 08:57:44 raspi kernel: active_anon:255140 inactive_anon:17396 isolated_anon:0
                               active_file:303080 inactive_file:119773 isolated_file:0
                               unevictable:90812 dirty:400 writeback:0
                               slab_reclaimable:10954 slab_unreclaimable:11254
                               mapped:123327 shmem:113654 pagetables:5116
                               sec_pagetables:0 bounce:0
                               kernel_misc_reclaimable:0
                               free:21307 free_pcp:25 free_cma:781
May 16 08:57:44 raspi kernel: Node 0 active_anon:1020560kB inactive_anon:69584kB active_file:1212320kB inactive_file:479092kB unevictable:363248kB isolated(a>
May 16 08:57:44 raspi kernel: DMA free:65556kB boost:0kB min:3728kB low:4660kB high:5592kB reserved_highatomic:0KB active_anon:174812kB inactive_anon:13624kB>
May 16 08:57:44 raspi kernel: lowmem_reserve[]: 0 2928 2928 2928
May 16 08:57:44 raspi kernel: DMA: 133*4kB (UMEC) 120*8kB (UMEC) 103*16kB (UMEC) 33*32kB (UMEC) 87*64kB (UEC) 116*128kB (UMC) 54*256kB (UMEC) 19*512kB (UM) 7>
May 16 08:57:44 raspi kernel: 536507 total pagecache pages
May 16 08:57:44 raspi kernel: 0 pages in swap cache
May 16 08:57:44 raspi kernel: Free swap  = 0kB
May 16 08:57:44 raspi kernel: Total swap = 0kB
May 16 08:57:44 raspi kernel: 1012736 pages RAM
May 16 08:57:44 raspi kernel: 0 pages HighMem/MovableOnly
May 16 08:57:44 raspi kernel: 41971 pages reserved
May 16 08:57:44 raspi kernel: 131072 pages cma reserved
May 16 08:57:44 raspi kernel: bcm2835-codec bcm2835-codec: dma alloc of size 4194304 failed
May 16 08:57:47 raspi kernel: ------------[ cut here ]------------
May 16 08:57:47 raspi kernel: Firmware transaction timeout
May 16 08:57:47 raspi kernel: WARNING: CPU: 0 PID: 98194 at drivers/firmware/raspberrypi.c:68 rpi_firmware_property_list+0x218/0x258
May 16 08:57:47 raspi kernel: Modules linked in: ntfs3 rfcomm snd_seq_dummy snd_hrtimer snd_seq cmac algif_hash aes_arm64 aes_generic algif_skcipher af_alg b>
May 16 08:57:47 raspi kernel: CPU: 0 PID: 98194 Comm: kworker/u9:0 Tainted: G         C         6.6.30-v8+ #1
May 16 08:57:47 raspi kernel: Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
May 16 08:57:47 raspi kernel: Workqueue: events_unbound commit_work [drm_kms_helper]
May 16 08:57:47 raspi kernel: pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
May 16 08:57:47 raspi kernel: pc : rpi_firmware_property_list+0x218/0x258
May 16 08:57:47 raspi kernel: lr : rpi_firmware_property_list+0x218/0x258
May 16 08:57:47 raspi kernel: sp : ffffffc082a5bb30
May 16 08:57:47 raspi kernel: x29: ffffffc082a5bb30 x28: ffffff804092bcc0 x27: ffffffe081bcae88
May 16 08:57:47 raspi kernel: x26: ffffffe081bcada0 x25: ffffffc08049e008 x24: 0000000000001000
May 16 08:57:47 raspi kernel: x23: ffffff80098b3380 x22: 00000000ffffff92 x21: 0000000000000018
May 16 08:57:47 raspi kernel: x20: ffffff804092bc80 x19: ffffffc08049e000 x18: 0000000000000000
May 16 08:57:47 raspi kernel: x17: 0000000000000000 x16: 0000000000000003 x15: 0000047dcd45951e
May 16 08:57:47 raspi kernel: x14: 0000000000000000 x13: 74756f656d697420 x12: 6e6f69746361736e
May 16 08:57:47 raspi kernel: x11: fffffffffffe0000 x10: ffffffe081aa82c8 x9 : ffffffe08050897c
May 16 08:57:47 raspi kernel: x8 : 00000000ffffefff x7 : ffffffe081aa3708 x6 : 0000000000004bc0
May 16 08:57:47 raspi kernel: x5 : ffffff80fb76bd48 x4 : 0000000000000000 x3 : 0000000000000027
May 16 08:57:47 raspi kernel: x2 : 0000000000000000 x1 : 0000000000000000 x0 : ffffff8070c5dc40
May 16 08:57:47 raspi kernel: Call trace:
May 16 08:57:47 raspi kernel:  rpi_firmware_property_list+0x218/0x258
May 16 08:57:47 raspi kernel:  rpi_firmware_property+0x78/0x118
May 16 08:57:47 raspi kernel:  raspberrypi_fw_get_rate+0x4c/0x88
May 16 08:57:47 raspi kernel:  clk_recalc+0x40/0xb8
May 16 08:57:47 raspi kernel:  __clk_recalc_rates+0x44/0xc0
May 16 08:57:47 raspi kernel:  clk_set_rate_range_nolock.part.0+0x1f0/0x2e8
May 16 08:57:47 raspi kernel:  clk_set_min_rate+0x4c/0x108
May 16 08:57:47 raspi kernel:  vc4_atomic_commit_tail+0x23c/0x880 [vc4]
May 16 08:57:47 raspi kernel:  commit_tail+0xac/0x1a0 [drm_kms_helper]
May 16 08:57:47 raspi kernel:  commit_work+0x1c/0x30 [drm_kms_helper]
May 16 08:57:47 raspi kernel:  process_one_work+0x148/0x388
May 16 08:57:47 raspi kernel:  worker_thread+0x338/0x450
May 16 08:57:47 raspi kernel:  kthread+0x120/0x130
May 16 08:57:47 raspi kernel:  ret_from_fork+0x10/0x20
May 16 08:57:47 raspi kernel: ---[ end trace 0000000000000000 ]---
May 16 08:57:48 raspi kernel: raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-core frequency: -110
May 16 08:57:49 raspi kernel: bcm2835_mmal_vchiq: timed out waiting for sync completion
May 16 08:57:49 raspi kernel: hwmon hwmon1: Failed to get throttled (-110)
May 16 08:57:57 raspi kernel: sysrq: Kill All Tasks

I see there are a lot of errors, but system freeze happened at about 08:57:45

@qrp73
Copy link
Author

qrp73 commented May 16, 2024

I tried to install sudo rpi-update 42312de, still testing, but found some issues.

I had some short freezes (for about 1-2 sec) and check the log, the last messages are:

[ 9962.991318] vc4-drm gpu: swiotlb buffer is full (sz: 524288 bytes), total 32768 (slots), used 76 (slots)
[ 9963.511759] vc4-drm gpu: swiotlb buffer is full (sz: 524288 bytes), total 32768 (slots), used 76 (slots)
[ 9971.347461] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 9971.347499] bcm2835_mmal_vchiq: vchiq_mmal_component_init: failed to create component -62 (Not enough GPU mem?)
[ 9971.347511] bcm2835-codec bcm2835-codec: bcm2835_codec_create_component: failed to create component ril.video_decode
[ 9991.382612] vc4-drm gpu: swiotlb buffer is full (sz: 376832 bytes), total 32768 (slots), used 1600 (slots)
[ 9991.517494] vc4-drm gpu: swiotlb buffer is full (sz: 376832 bytes), total 32768 (slots), used 1600 (slots)

but before that it has a lot of errors, here is some of them:

[ 8724.347982] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 8724.348016] bcm2835-codec bcm2835-codec: bcm2835_codec_stop_streaming: Failed disabling i/p port, ret -62
[ 8726.368001] bcm2835-codec bcm2835-codec: bcm2835_codec_flush_buffers: Timeout waiting for buffers to be returned - 8 outstanding
[ 8726.368146] ------------[ cut here ]------------
[ 8726.368149] WARNING: CPU: 3 PID: 21695 at drivers/media/common/videobuf2/videobuf2-core.c:2024 __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[ 8726.368184] Modules linked in: ntfs3 rfcomm snd_seq_dummy snd_hrtimer snd_seq cmac algif_hash aes_arm64 aes_generic algif_skcipher af_alg bnep brcmfmac_wcc brcmfmac brcmutil joydev binfmt_misc cfg80211 hci_uart btbcm vc4 snd_usb_audio bluetooth raspberrypi_hwmon snd_hwdep snd_soc_hdmi_codec snd_usbmidi_lib bcm2835_v4l2(C) drm_display_helper snd_rawmidi cec bcm2835_isp(C) bcm2835_codec(C) rpivid_hevc(C) drm_dma_helper ecdh_generic snd_seq_device bcm2835_mmal_vchiq(C) sg drm_kms_helper ecc v4l2_mem2mem i2c_brcmstb v3d rfkill snd_soc_core i2c_bcm2835 videobuf2_dma_contig libaes videobuf2_vmalloc snd_bcm2835(C) snd_compress videobuf2_memops snd_pcm_dmaengine videobuf2_v4l2 gpu_sched snd_pcm videodev vc_sm_cma(C) videobuf2_common drm_shmem_helper snd_timer raspberrypi_gpiomem mc snd nvmem_rmem uio_pdrv_genirq uio i2c_dev drm fuse drm_panel_orientation_quirks dm_mod backlight ip_tables x_tables ipv6
[ 8726.368318] CPU: 3 PID: 21695 Comm: ThreadPoolSingl Tainted: G        WC         6.6.29-v8+ #1760
[ 8726.368325] Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
[ 8726.368328] pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
[ 8726.368333] pc : __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[ 8726.368347] lr : __vb2_queue_cancel+0x38/0x2a0 [videobuf2_common]
[ 8726.368360] sp : ffffffc083393ae0
[ 8726.368363] x29: ffffffc083393ae0 x28: ffffffdbb742ce18 x27: ffffff80a23d2000
[ 8726.368372] x26: ffffff80442f8530 x25: 0000000000000000 x24: 0000000040045613
[ 8726.368381] x23: 0000000000000000 x22: ffffff8008d9e298 x21: ffffff8008d9e298
[ 8726.368389] x20: 000000000000000a x19: ffffff8008d9e298 x18: ffffffffffffffff
[ 8726.368395] x17: 756f656d6954203a x16: ffffffdc2b2d32a8 x15: 6873756c665f6365
[ 8726.368402] x14: 0000000000000001 x13: ffffff8044240028 x12: 0000000000000000
[ 8726.368411] x11: ffffff8005417260 x10: ffffff8005417230 x9 : ffffffdc2b329e68
[ 8726.368417] x8 : ffffff8005417258 x7 : 0000000000000001 x6 : fffffffffffffffc
[ 8726.368423] x5 : 0000000041001000 x4 : 0000000000150013 x3 : ffffff8045535e40
[ 8726.368429] x2 : 0000000000000000 x1 : 0000000000000000 x0 : 0000000000000008
[ 8726.368437] Call trace:
[ 8726.368443]  __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[ 8726.368457]  vb2_core_streamoff+0x2c/0xe0 [videobuf2_common]
[ 8726.368470]  vb2_streamoff+0x24/0x80 [videobuf2_v4l2]
[ 8726.368499]  v4l2_m2m_streamoff+0x50/0x160 [v4l2_mem2mem]
[ 8726.368534]  v4l2_m2m_ioctl_streamoff+0x20/0x38 [v4l2_mem2mem]
[ 8726.368546]  v4l_streamoff+0x2c/0x40 [videodev]
[ 8726.368665]  __video_do_ioctl+0x194/0x400 [videodev]
[ 8726.368693]  video_usercopy+0x1e4/0x780 [videodev]
[ 8726.368721]  video_ioctl2+0x20/0x40 [videodev]
[ 8726.368750]  v4l2_ioctl+0x48/0x70 [videodev]
[ 8726.368778]  __arm64_sys_ioctl+0xb0/0x100
[ 8726.368803]  invoke_syscall+0x50/0x128
[ 8726.368816]  el0_svc_common.constprop.0+0x48/0xf8
[ 8726.368822]  do_el0_svc+0x28/0x40
[ 8726.368826]  el0_svc+0x40/0xf8
[ 8726.368840]  el0t_64_sync_handler+0x13c/0x158
[ 8726.368847]  el0t_64_sync+0x190/0x198
[ 8726.368854] ---[ end trace 0000000000000000 ]---
[ 8726.368863] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000cdf0c294 in active state
[ 8726.368878] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000266bf4a1 in active state
[ 8726.368881] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000dfd94176 in active state
[ 8726.368887] videobuf2_common: driver bug: stop_streaming operation is leaving buf 0000000084ff8e03 in active state
[ 8726.368891] videobuf2_common: driver bug: stop_streaming operation is leaving buf 0000000003024712 in active state
[ 8726.368894] videobuf2_common: driver bug: stop_streaming operation is leaving buf 0000000018a71992 in active state
[ 8726.368900] videobuf2_common: driver bug: stop_streaming operation is leaving buf 0000000038cfb820 in active state
[ 8726.368905] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000d7e7d37a in active state
[ 8729.468068] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 8729.468094] bcm2835-codec bcm2835-codec: bcm2835_codec_stop_streaming: Failed disabling i/p port, ret -62
[ 8731.484096] bcm2835-codec bcm2835-codec: bcm2835_codec_flush_buffers: Timeout waiting for buffers to be returned - 8 outstanding
[ 8731.484196] ------------[ cut here ]------------
[ 8731.484198] WARNING: CPU: 3 PID: 21071 at drivers/media/common/videobuf2/videobuf2-core.c:2024 __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[ 8731.484229] Modules linked in: ntfs3 rfcomm snd_seq_dummy snd_hrtimer snd_seq cmac algif_hash aes_arm64 aes_generic algif_skcipher af_alg bnep brcmfmac_wcc brcmfmac brcmutil joydev binfmt_misc cfg80211 hci_uart btbcm vc4 snd_usb_audio bluetooth raspberrypi_hwmon snd_hwdep snd_soc_hdmi_codec snd_usbmidi_lib bcm2835_v4l2(C) drm_display_helper snd_rawmidi cec bcm2835_isp(C) bcm2835_codec(C) rpivid_hevc(C) drm_dma_helper ecdh_generic snd_seq_device bcm2835_mmal_vchiq(C) sg drm_kms_helper ecc v4l2_mem2mem i2c_brcmstb v3d rfkill snd_soc_core i2c_bcm2835 videobuf2_dma_contig libaes videobuf2_vmalloc snd_bcm2835(C) snd_compress videobuf2_memops snd_pcm_dmaengine videobuf2_v4l2 gpu_sched snd_pcm videodev vc_sm_cma(C) videobuf2_common drm_shmem_helper snd_timer raspberrypi_gpiomem mc snd nvmem_rmem uio_pdrv_genirq uio i2c_dev drm fuse drm_panel_orientation_quirks dm_mod backlight ip_tables x_tables ipv6
[ 8731.484355] CPU: 3 PID: 21071 Comm: ThreadPoolSingl Tainted: G        WC         6.6.29-v8+ #1760
[ 8731.484360] Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
[ 8731.484363] pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
[ 8731.484368] pc : __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[ 8731.484381] lr : __vb2_queue_cancel+0x38/0x2a0 [videobuf2_common]
[ 8731.484392] sp : ffffffc0833abae0
[ 8731.484394] x29: ffffffc0833abae0 x28: ffffffdbb742ce18 x27: ffffff809ed82000
[ 8731.484401] x26: ffffff80442f8530 x25: 0000000000000000 x24: 0000000040045613
[ 8731.484408] x23: 0000000000000000 x22: ffffff809ed72a98 x21: ffffff809ed72a98
[ 8731.484414] x20: 000000000000000a x19: ffffff809ed72a98 x18: ffffffffffffffff
[ 8731.484420] x17: 756f656d6954203a x16: ffffffdc2b2d32a8 x15: 6873756c665f6365
[ 8731.484427] x14: 000000000000000c x13: ffffff8044240028 x12: 0000000000000000
[ 8731.484433] x11: ffffff800a4099a0 x10: ffffff800a409918 x9 : ffffffdc2b329e68
[ 8731.484440] x8 : ffffff800a409940 x7 : 0000000000000001 x6 : f8007ff800000000
[ 8731.484446] x5 : 0000000041001000 x4 : 0000000000150013 x3 : ffffff80eef8e840
[ 8731.484453] x2 : 0000000000000000 x1 : 0000000000000000 x0 : 0000000000000008
[ 8731.484460] Call trace:
[ 8731.484463]  __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[ 8731.484476]  vb2_core_streamoff+0x2c/0xe0 [videobuf2_common]
[ 8731.484489]  vb2_streamoff+0x24/0x80 [videobuf2_v4l2]
[ 8731.484503]  v4l2_m2m_streamoff+0x50/0x160 [v4l2_mem2mem]
[ 8731.484531]  v4l2_m2m_ioctl_streamoff+0x20/0x38 [v4l2_mem2mem]
[ 8731.484542]  v4l_streamoff+0x2c/0x40 [videodev]
[ 8731.484629]  __video_do_ioctl+0x194/0x400 [videodev]
[ 8731.484657]  video_usercopy+0x1e4/0x780 [videodev]
[ 8731.484687]  video_ioctl2+0x20/0x40 [videodev]
[ 8731.484715]  v4l2_ioctl+0x48/0x70 [videodev]
[ 8731.484743]  __arm64_sys_ioctl+0xb0/0x100
[ 8731.484754]  invoke_syscall+0x50/0x128
[ 8731.484761]  el0_svc_common.constprop.0+0x48/0xf8
[ 8731.484767]  do_el0_svc+0x28/0x40
[ 8731.484772]  el0_svc+0x40/0xf8
[ 8731.484779]  el0t_64_sync_handler+0x13c/0x158
[ 8731.484784]  el0t_64_sync+0x190/0x198
[ 8731.484789] ---[ end trace 0000000000000000 ]---
[ 8731.484794] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000409f1dd6 in active state
[ 8731.484801] videobuf2_common: driver bug: stop_streaming operation is leaving buf 0000000094d13ffc in active state
[ 8731.484804] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000401345ed in active state
[ 8731.484806] videobuf2_common: driver bug: stop_streaming operation is leaving buf 000000008c65c5de in active state
[ 8731.484809] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000ad24c291 in active state
[ 8731.484811] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000cb018e71 in active state
[ 8731.484814] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000db283289 in active state
[ 8731.484817] videobuf2_common: driver bug: stop_streaming operation is leaving buf 0000000057fa0ed4 in active state
[ 8734.591127] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 8734.591156] bcm2835-codec bcm2835-codec: bcm2835_codec_stop_streaming: Failed disabling o/p port, ret -62
[ 8736.604198] bcm2835-codec bcm2835-codec: bcm2835_codec_flush_buffers: Timeout waiting for buffers to be returned - 10 outstanding
[ 8739.708286] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 8739.708338] bcm2835-codec bcm2835-codec: bcm2835_codec_stop_streaming: Failed enabling component, ret -62
[ 8739.708613] ------------[ cut here ]------------
[ 8739.708619] WARNING: CPU: 3 PID: 21071 at drivers/media/common/videobuf2/videobuf2-core.c:2024 __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[ 8739.708698] Modules linked in: ntfs3 rfcomm snd_seq_dummy snd_hrtimer snd_seq cmac algif_hash aes_arm64 aes_generic algif_skcipher af_alg bnep brcmfmac_wcc brcmfmac brcmutil joydev binfmt_misc cfg80211 hci_uart btbcm vc4 snd_usb_audio bluetooth raspberrypi_hwmon snd_hwdep snd_soc_hdmi_codec snd_usbmidi_lib bcm2835_v4l2(C) drm_display_helper snd_rawmidi cec bcm2835_isp(C) bcm2835_codec(C) rpivid_hevc(C) drm_dma_helper ecdh_generic snd_seq_device bcm2835_mmal_vchiq(C) sg drm_kms_helper ecc v4l2_mem2mem i2c_brcmstb v3d rfkill snd_soc_core i2c_bcm2835 videobuf2_dma_contig libaes videobuf2_vmalloc snd_bcm2835(C) snd_compress videobuf2_memops snd_pcm_dmaengine videobuf2_v4l2 gpu_sched snd_pcm videodev vc_sm_cma(C) videobuf2_common drm_shmem_helper snd_timer raspberrypi_gpiomem mc snd nvmem_rmem uio_pdrv_genirq uio i2c_dev drm fuse drm_panel_orientation_quirks dm_mod backlight ip_tables x_tables ipv6
[ 8739.708881] CPU: 3 PID: 21071 Comm: ThreadPoolSingl Tainted: G        WC         6.6.29-v8+ #1760
[ 8739.708889] Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
[ 8739.708893] pstate: 80000005 (Nzcv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
[ 8739.708899] pc : __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[ 8739.708914] lr : __vb2_queue_cancel+0x38/0x2a0 [videobuf2_common]
[ 8739.708927] sp : ffffffc0833abae0
[ 8739.708930] x29: ffffffc0833abae0 x28: ffffffdbb742ce18 x27: ffffff809ed82000
[ 8739.708940] x26: ffffff80442f8530 x25: 0000000000000000 x24: 0000000040045613
[ 8739.708947] x23: 0000000000000000 x22: ffffff809ed72828 x21: ffffff809ed72828
[ 8739.708954] x20: 0000000000000009 x19: ffffff809ed72828 x18: ffffffffffffffff
[ 8739.708961] x17: 656c696146203a67 x16: 6e696d6165727473 x15: 5f706f74735f6365
[ 8739.708970] x14: 646f635f35333832 x13: 32362d2074657220 x12: 2c746e656e6f706d
[ 8739.708977] x11: 6f6320676e696c62 x10: ffffffdc2c6a3708 x9 : ffffffdc2b108924
[ 8739.708985] x8 : 00000000ffffefff x7 : ffffffdc2c6a3708 x6 : 0000000000000000
[ 8739.708995] x5 : ffffff80fb7c5d48 x4 : 0000000000000000 x3 : 0000000000000000
[ 8739.709002] x2 : 0000000000000000 x1 : 0000000000000000 x0 : 000000000000000a
[ 8739.709009] Call trace:
[ 8739.709017]  __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[ 8739.709032]  vb2_core_streamoff+0x2c/0xe0 [videobuf2_common]
[ 8739.709044]  vb2_streamoff+0x24/0x80 [videobuf2_v4l2]
[ 8739.709076]  v4l2_m2m_streamoff+0x80/0x160 [v4l2_mem2mem]
[ 8739.709131]  v4l2_m2m_ioctl_streamoff+0x20/0x38 [v4l2_mem2mem]
[ 8739.709142]  v4l_streamoff+0x2c/0x40 [videodev]
[ 8739.709298]  __video_do_ioctl+0x194/0x400 [videodev]
[ 8739.709326]  video_usercopy+0x1e4/0x780 [videodev]
[ 8739.709355]  video_ioctl2+0x20/0x40 [videodev]
[ 8739.709383]  v4l2_ioctl+0x48/0x70 [videodev]
[ 8739.709411]  __arm64_sys_ioctl+0xb0/0x100
[ 8739.709443]  invoke_syscall+0x50/0x128
[ 8739.709461]  el0_svc_common.constprop.0+0x48/0xf8
[ 8739.709468]  do_el0_svc+0x28/0x40
[ 8739.709473]  el0_svc+0x40/0xf8
[ 8739.709488]  el0t_64_sync_handler+0x13c/0x158
[ 8739.709494]  el0t_64_sync+0x190/0x198
[ 8739.709502] ---[ end trace 0000000000000000 ]---
[ 8739.709530] videobuf2_common: driver bug: stop_streaming operation is leaving buf 000000004def5b87 in active state
[ 8739.709559] videobuf2_common: driver bug: stop_streaming operation is leaving buf 000000000874fef8 in active state
[ 8739.709564] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000fef1f2d3 in active state
[ 8739.709569] videobuf2_common: driver bug: stop_streaming operation is leaving buf 000000004d7a3888 in active state
[ 8739.709573] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000ae02a83c in active state
[ 8739.709578] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000f55084ec in active state
[ 8739.709581] videobuf2_common: driver bug: stop_streaming operation is leaving buf 0000000095ec30b9 in active state
[ 8739.709585] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000c4bca385 in active state
[ 8739.709590] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000550422dc in active state
[ 8739.709595] videobuf2_common: driver bug: stop_streaming operation is leaving buf 000000005a978a46 in active state
[ 8742.780326] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 8745.852383] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 8748.924442] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 8748.924471] bcm2835-codec bcm2835-codec: bcm2835_codec_stop_streaming: Failed disabling i/p port, ret -62
[ 8750.940509] bcm2835-codec bcm2835-codec: bcm2835_codec_flush_buffers: Timeout waiting for buffers to be returned - 8 outstanding
[ 8750.940675] ------------[ cut here ]------------
[ 8750.940678] WARNING: CPU: 2 PID: 21103 at drivers/media/common/videobuf2/videobuf2-core.c:2024 __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[ 8750.940731] Modules linked in: ntfs3 rfcomm snd_seq_dummy snd_hrtimer snd_seq cmac algif_hash aes_arm64 aes_generic algif_skcipher af_alg bnep brcmfmac_wcc brcmfmac brcmutil joydev binfmt_misc cfg80211 hci_uart btbcm vc4 snd_usb_audio bluetooth raspberrypi_hwmon snd_hwdep snd_soc_hdmi_codec snd_usbmidi_lib bcm2835_v4l2(C) drm_display_helper snd_rawmidi cec bcm2835_isp(C) bcm2835_codec(C) rpivid_hevc(C) drm_dma_helper ecdh_generic snd_seq_device bcm2835_mmal_vchiq(C) sg drm_kms_helper ecc v4l2_mem2mem i2c_brcmstb v3d rfkill snd_soc_core i2c_bcm2835 videobuf2_dma_contig libaes videobuf2_vmalloc snd_bcm2835(C) snd_compress videobuf2_memops snd_pcm_dmaengine videobuf2_v4l2 gpu_sched snd_pcm videodev vc_sm_cma(C) videobuf2_common drm_shmem_helper snd_timer raspberrypi_gpiomem mc snd nvmem_rmem uio_pdrv_genirq uio i2c_dev drm fuse drm_panel_orientation_quirks dm_mod backlight ip_tables x_tables ipv6
[ 8750.940873] CPU: 2 PID: 21103 Comm: ThreadPoolSingl Tainted: G        WC         6.6.29-v8+ #1760
[ 8750.940880] Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
[ 8750.940883] pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
[ 8750.940888] pc : __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[ 8750.940907] lr : __vb2_queue_cancel+0x38/0x2a0 [videobuf2_common]
[ 8750.940920] sp : ffffffc0834dbae0
[ 8750.940922] x29: ffffffc0834dbae0 x28: ffffffdbb742ce18 x27: ffffff806590a000
[ 8750.940929] x26: ffffff80442f8530 x25: 0000000000000000 x24: 0000000040045613
[ 8750.940936] x23: 0000000000000000 x22: ffffff80036cba98 x21: ffffff80036cba98
[ 8750.940943] x20: 000000000000000a x19: ffffff80036cba98 x18: ffffffffffffffff
[ 8750.940950] x17: 756f656d6954203a x16: ffffffdc2b2d32a8 x15: 6873756c665f6365
[ 8750.940957] x14: 0000000000000030 x13: ffffff8044240028 x12: 0000000000000000
[ 8750.940965] x11: ffffff800a409ac0 x10: ffffff800a409918 x9 : ffffffdc2b329e68
[ 8750.940971] x8 : ffffff800a409940 x7 : 0000000000000001 x6 : f8007ff8007ffff0
[ 8750.940979] x5 : 0000000041001000 x4 : 0000000000150008 x3 : ffffff80f59a5600
[ 8750.940987] x2 : 0000000000000000 x1 : 0000000000000000 x0 : 0000000000000008
[ 8750.940996] Call trace:
[ 8750.941006]  __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[ 8750.941021]  vb2_core_streamoff+0x2c/0xe0 [videobuf2_common]
[ 8750.941036]  vb2_streamoff+0x24/0x80 [videobuf2_v4l2]
[ 8750.941070]  v4l2_m2m_streamoff+0x50/0x160 [v4l2_mem2mem]
[ 8750.941122]  v4l2_m2m_ioctl_streamoff+0x20/0x38 [v4l2_mem2mem]
[ 8750.941133]  v4l_streamoff+0x2c/0x40 [videodev]
[ 8750.941298]  __video_do_ioctl+0x194/0x400 [videodev]
[ 8750.941328]  video_usercopy+0x1e4/0x780 [videodev]
[ 8750.941356]  video_ioctl2+0x20/0x40 [videodev]
[ 8750.941385]  v4l2_ioctl+0x48/0x70 [videodev]
[ 8750.941413]  __arm64_sys_ioctl+0xb0/0x100
[ 8750.941426]  invoke_syscall+0x50/0x128
[ 8750.941441]  el0_svc_common.constprop.0+0x48/0xf8
[ 8750.941447]  do_el0_svc+0x28/0x40
[ 8750.941451]  el0_svc+0x40/0xf8
[ 8750.941461]  el0t_64_sync_handler+0x13c/0x158
[ 8750.941468]  el0t_64_sync+0x190/0x198
[ 8750.941473] ---[ end trace 0000000000000000 ]---
[ 8750.941480] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000c0367e91 in active state
[ 8750.941491] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000d6d92df0 in active state
[ 8750.941494] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000f2e30a74 in active state
[ 8750.941497] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000cdb7a9c6 in active state
[ 8750.941499] videobuf2_common: driver bug: stop_streaming operation is leaving buf 0000000015eeaeb3 in active state
[ 8750.941503] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000246cf04a in active state
[ 8750.941507] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000c6c7308d in active state
[ 8750.941511] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000b626479a in active state
[ 8754.046408] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 8754.046463] bcm2835-codec bcm2835-codec: bcm2835_codec_stop_streaming: Failed disabling o/p port, ret -62
[ 8756.060639] bcm2835-codec bcm2835-codec: bcm2835_codec_flush_buffers: Timeout waiting for buffers to be returned - 9 outstanding
[ 8759.164630] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 8759.164658] bcm2835-codec bcm2835-codec: bcm2835_codec_stop_streaming: Failed enabling component, ret -62
[ 8759.164777] ------------[ cut here ]------------
[ 8759.164780] WARNING: CPU: 2 PID: 21103 at drivers/media/common/videobuf2/videobuf2-core.c:2024 __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[ 8759.164820] Modules linked in: ntfs3 rfcomm snd_seq_dummy snd_hrtimer snd_seq cmac algif_hash aes_arm64 aes_generic algif_skcipher af_alg bnep brcmfmac_wcc brcmfmac brcmutil joydev binfmt_misc cfg80211 hci_uart btbcm vc4 snd_usb_audio bluetooth raspberrypi_hwmon snd_hwdep snd_soc_hdmi_codec snd_usbmidi_lib bcm2835_v4l2(C) drm_display_helper snd_rawmidi cec bcm2835_isp(C) bcm2835_codec(C) rpivid_hevc(C) drm_dma_helper ecdh_generic snd_seq_device bcm2835_mmal_vchiq(C) sg drm_kms_helper ecc v4l2_mem2mem i2c_brcmstb v3d rfkill snd_soc_core i2c_bcm2835 videobuf2_dma_contig libaes videobuf2_vmalloc snd_bcm2835(C) snd_compress videobuf2_memops snd_pcm_dmaengine videobuf2_v4l2 gpu_sched snd_pcm videodev vc_sm_cma(C) videobuf2_common drm_shmem_helper snd_timer raspberrypi_gpiomem mc snd nvmem_rmem uio_pdrv_genirq uio i2c_dev drm fuse drm_panel_orientation_quirks dm_mod backlight ip_tables x_tables ipv6
[ 8759.164950] CPU: 2 PID: 21103 Comm: ThreadPoolSingl Tainted: G        WC         6.6.29-v8+ #1760
[ 8759.164956] Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
[ 8759.164959] pstate: 80000005 (Nzcv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
[ 8759.164963] pc : __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[ 8759.164977] lr : __vb2_queue_cancel+0x38/0x2a0 [videobuf2_common]
[ 8759.164989] sp : ffffffc0834dbae0
[ 8759.164992] x29: ffffffc0834dbae0 x28: ffffffdbb742ce18 x27: ffffff806590a000
[ 8759.164999] x26: ffffff80442f8530 x25: 0000000000000000 x24: 0000000040045613
[ 8759.165006] x23: 0000000000000000 x22: ffffff80036cb828 x21: ffffff80036cb828
[ 8759.165012] x20: 0000000000000009 x19: ffffff80036cb828 x18: ffffffffffffffff
[ 8759.165019] x17: 656c696146203a67 x16: 6e696d6165727473 x15: 5f706f74735f6365
[ 8759.165025] x14: 646f635f35333832 x13: 32362d2074657220 x12: 2c746e656e6f706d
[ 8759.165031] x11: 6f6320676e696c62 x10: ffffffdc2c6a3708 x9 : ffffffdc2b108924
[ 8759.165038] x8 : 00000000ffffefff x7 : ffffffdc2c6a3708 x6 : 0000000000000000
[ 8759.165045] x5 : ffffff80fb7a7d48 x4 : 0000000000000000 x3 : 0000000000000000
[ 8759.165051] x2 : 0000000000000000 x1 : 0000000000000000 x0 : 0000000000000009
[ 8759.165057] Call trace:
[ 8759.165060]  __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[ 8759.165073]  vb2_core_streamoff+0x2c/0xe0 [videobuf2_common]
[ 8759.165085]  vb2_streamoff+0x24/0x80 [videobuf2_v4l2]
[ 8759.165099]  v4l2_m2m_streamoff+0x80/0x160 [v4l2_mem2mem]
[ 8759.165117]  v4l2_m2m_ioctl_streamoff+0x20/0x38 [v4l2_mem2mem]
[ 8759.165129]  v4l_streamoff+0x2c/0x40 [videodev]
[ 8759.165185]  __video_do_ioctl+0x194/0x400 [videodev]
[ 8759.165215]  video_usercopy+0x1e4/0x780 [videodev]
[ 8759.165243]  video_ioctl2+0x20/0x40 [videodev]
[ 8759.165270]  v4l2_ioctl+0x48/0x70 [videodev]
[ 8759.165298]  __arm64_sys_ioctl+0xb0/0x100
[ 8759.165310]  invoke_syscall+0x50/0x128
[ 8759.165318]  el0_svc_common.constprop.0+0x48/0xf8
[ 8759.165323]  do_el0_svc+0x28/0x40
[ 8759.165328]  el0_svc+0x40/0xf8
[ 8759.165335]  el0t_64_sync_handler+0x13c/0x158
[ 8759.165341]  el0t_64_sync+0x190/0x198
[ 8759.165345] ---[ end trace 0000000000000000 ]---
[ 8759.165351] videobuf2_common: driver bug: stop_streaming operation is leaving buf 0000000039bef332 in active state
[ 8759.165359] videobuf2_common: driver bug: stop_streaming operation is leaving buf 000000006413828a in active state
[ 8759.165362] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000fcf70dc4 in active state
[ 8759.165365] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000496b9bf9 in active state
[ 8759.165368] videobuf2_common: driver bug: stop_streaming operation is leaving buf 0000000046ddee10 in active state
[ 8759.165370] videobuf2_common: driver bug: stop_streaming operation is leaving buf 0000000097a0350c in active state
[ 8759.165372] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000f3c6f0e3 in active state
[ 8759.165376] videobuf2_common: driver bug: stop_streaming operation is leaving buf 000000009ef124f7 in active state
[ 8759.165378] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000476d719d in active state
[ 8762.236993] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 8765.308744] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 8768.380831] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 8768.380848] bcm2835_mmal_vchiq: vchiq_mmal_component_init: failed to create component -62 (Not enough GPU mem?)
[ 8768.380855] bcm2835-codec bcm2835-codec: bcm2835_codec_create_component: failed to create component ril.video_decode
[ 8771.453128] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 8774.524947] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 8777.597174] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 8780.669072] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 8783.741205] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 8783.741229] bcm2835_mmal_vchiq: vchiq_mmal_component_init: failed to create component -62 (Not enough GPU mem?)
[ 8783.741240] bcm2835-codec bcm2835-codec: bcm2835_codec_create_component: failed to create component ril.video_decode
[ 8789.049825] vc4-drm gpu: swiotlb buffer is full (sz: 524288 bytes), total 32768 (slots), used 478 (slots)
[ 8789.055755] vc4-drm gpu: swiotlb buffer is full (sz: 1634304 bytes), total 32768 (slots), used 0 (slots)
[ 8789.701276] vc4-drm gpu: swiotlb buffer is full (sz: 524288 bytes), total 32768 (slots), used 478 (slots)
[ 8789.743332] vc4-drm gpu: swiotlb buffer is full (sz: 1634304 bytes), total 32768 (slots), used 0 (slots)
[ 9880.465312] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 9880.465329] bcm2835_mmal_vchiq: vchiq_mmal_component_init: failed to create component -62 (Not enough GPU mem?)

I also tried sudo vclog -m and it shows some corrupted text:

$ sudo vclog -m
1830825.008: ailedqf
1768383.858: de=7) failedъ4m
1869488.235: d)��;m
1601463.137: (space=3291328, in_low_region=0, mode=7) failed�5Jm
1767990.816: 
1869178.725: e=7) failed�Fqm
1818324.594: 291328, in_low_region=0, mode=7) failed@�wm
1919905.824: uffer header callback not defined)��m
1986355.060: : event lost on port 1,0 (buffer header callback not defined)�"�m
539766.845: failed@�m
1818324.333: ent_send: event lost on port 1,0 (buffer header callback not defined)Ԩm
1918859.119:  mode=7) failed0K�m
1953656.688: ffer header callback not defined)�w�m
1763716.152: gion=0, mode=7) failed >�m
544108.320:  (buffer header callback not defined)�\�m

when I tried to execute it again:

$ sudo vclog -m
2203542.729: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2203542.758: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2203542.951: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2203542.979: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2203543.181: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2203543.208: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2203560.389: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2203560.419: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2203560.615: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2203560.642: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2203560.845: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2203560.873: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2203582.749: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2203582.779: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2203582.970: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2203583.000: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2203583.239: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2203583.275: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2203600.427: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2203600.465: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2203600.699: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2203600.729: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2203600.974: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2203601.003: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2203620.788: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2203620.817: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
...
...<a lot of the same messages>
...
2217420.629: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2217420.657: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2217420.859: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2217420.887: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2217440.440: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2217440.475: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2217440.683: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2217440.713: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2217440.933: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2217440.962: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2217460.406: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2217460.437: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2217460.663: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2217460.693: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2217460.905: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2217460.932: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)

it is full of the same messages

@qrp73
Copy link
Author

qrp73 commented May 16, 2024

I found that there is huge memory leak in firefox, so out of memory may be the reason for this issue.
But I'm not sure why it cannot kill all processes and restart wayfire.
Needs more testing.

@qrp73
Copy link
Author

qrp73 commented May 25, 2024

catch the issue several times with Linux raspi 6.6.31-v8+ #1764 SMP PREEMPT Mon May 20 15:26:28 BST 2024 aarch64 GNU/Linux

The system is freezed and don't respond even on ssh connections. Alt+SysRq+E don't works. It happens when I click on close tab in chromium-browser.

May 25 22:40:57 raspi kernel: cma_alloc: 105 callbacks suppressed
May 25 22:40:57 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 25 22:40:57 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 25 22:40:57 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 25 22:40:57 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 25 22:41:02 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 25 22:41:02 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 25 22:41:02 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 25 22:41:02 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 25 22:41:02 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 25 22:41:02 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 25 22:41:02 raspi kernel: warn_alloc: 4 callbacks suppressed
May 25 22:41:02 raspi kernel: ThreadPoolSingl: page allocation failure: order:10, mode:0xcc1(GFP_KERNEL|GFP_DMA), nodemask=(null),cpuset=/,mems_allowed=0
May 25 22:41:02 raspi kernel: CPU: 2 PID: 138261 Comm: ThreadPoolSingl Tainted: G        WC         6.6.31-v8+ #1764
May 25 22:41:02 raspi kernel: Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
May 25 22:41:02 raspi kernel: Call trace:
May 25 22:41:02 raspi kernel:  dump_backtrace+0x9c/0x100
May 25 22:41:02 raspi kernel:  show_stack+0x20/0x38
May 25 22:41:02 raspi kernel:  dump_stack_lvl+0x48/0x60
May 25 22:41:02 raspi kernel:  dump_stack+0x18/0x28
May 25 22:41:02 raspi kernel:  warn_alloc+0x11c/0x1a8
May 25 22:41:02 raspi kernel:  __alloc_pages+0xdbc/0xe28
May 25 22:41:02 raspi kernel:  __dma_direct_alloc_pages.constprop.0+0x16c/0x1d8
May 25 22:41:02 raspi kernel:  dma_direct_alloc+0xd4/0x300
May 25 22:41:02 raspi kernel:  dma_alloc_attrs+0x88/0x108
May 25 22:41:02 raspi kernel:  vb2_dc_alloc+0xa8/0x198 [videobuf2_dma_contig]
May 25 22:41:02 raspi kernel:  __vb2_queue_alloc+0x1a4/0x4a0 [videobuf2_common]
May 25 22:41:02 raspi kernel:  vb2_core_reqbufs+0x258/0x470 [videobuf2_common]
May 25 22:41:02 raspi kernel:  vb2_reqbufs+0x90/0xb8 [videobuf2_v4l2]
May 25 22:41:02 raspi kernel:  v4l2_m2m_ioctl_reqbufs+0x54/0x98 [v4l2_mem2mem]
May 25 22:41:02 raspi kernel:  v4l_reqbufs+0x58/0x78 [videodev]
May 25 22:41:02 raspi kernel:  __video_do_ioctl+0x194/0x400 [videodev]
May 25 22:41:02 raspi kernel:  video_usercopy+0x1e4/0x780 [videodev]
May 25 22:41:02 raspi kernel:  video_ioctl2+0x20/0x40 [videodev]
May 25 22:41:02 raspi kernel:  v4l2_ioctl+0x48/0x70 [videodev]
May 25 22:41:02 raspi kernel:  __arm64_sys_ioctl+0xb0/0x100
May 25 22:41:02 raspi kernel:  invoke_syscall+0x50/0x128
May 25 22:41:02 raspi kernel:  el0_svc_common.constprop.0+0x48/0xf8
May 25 22:41:02 raspi kernel:  do_el0_svc+0x28/0x40
May 25 22:41:02 raspi kernel:  el0_svc+0x40/0xf8
May 25 22:41:02 raspi kernel:  el0t_64_sync_handler+0x13c/0x158
May 25 22:41:02 raspi kernel:  el0t_64_sync+0x190/0x198
May 25 22:41:02 raspi kernel: Mem-Info:
May 25 22:41:02 raspi kernel: active_anon:132946 inactive_anon:102507 isolated_anon:0
                               active_file:145804 inactive_file:208771 isolated_file:0
                               unevictable:69566 dirty:1382 writeback:0
                               slab_reclaimable:14608 slab_unreclaimable:11834
                               mapped:110352 shmem:84325 pagetables:4766
                               sec_pagetables:0 bounce:0
                               kernel_misc_reclaimable:0
                               free:137639 free_pcp:131 free_cma:9970
May 25 22:41:02 raspi kernel: Node 0 active_anon:531784kB inactive_anon:410028kB active_file:583216kB inactive_file:835084kB unevictable:278264kB isolated(an>
May 25 22:41:02 raspi kernel: DMA free:206968kB boost:0kB min:3660kB low:4572kB high:5484kB reserved_highatomic:0KB active_anon:2268kB inactive_anon:70560kB >
May 25 22:41:02 raspi kernel: lowmem_reserve[]: 0 2928 2928 2928
May 25 22:41:02 raspi kernel: DMA: 918*4kB (UMEC) 795*8kB (UMEC) 728*16kB (UMEC) 610*32kB (UMEC) 410*64kB (UMC) 276*128kB (UMEC) 148*256kB (UMEC) 70*512kB (U>
May 25 22:41:02 raspi kernel: 438863 total pagecache pages
May 25 22:41:02 raspi kernel: 0 pages in swap cache
May 25 22:41:02 raspi kernel: Free swap  = 0kB
May 25 22:41:02 raspi kernel: Total swap = 0kB
May 25 22:41:02 raspi kernel: 1007616 pages RAM
May 25 22:41:02 raspi kernel: 0 pages HighMem/MovableOnly
May 25 22:41:02 raspi kernel: 41962 pages reserved
May 25 22:41:02 raspi kernel: 131072 pages cma reserved
May 25 22:41:02 raspi kernel: bcm2835-codec bcm2835-codec: dma alloc of size 4194304 failed
May 25 22:41:04 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 25 22:41:04 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
May 25 22:41:04 raspi kernel: bcm2835-codec bcm2835-codec: dma alloc of size 4194304 failed
May 25 22:41:10 raspi kernel: ------------[ cut here ]------------
May 25 22:41:10 raspi kernel: Firmware transaction timeout
May 25 22:41:10 raspi kernel: WARNING: CPU: 2 PID: 124009 at drivers/firmware/raspberrypi.c:68 rpi_firmware_property_list+0x218/0x258
May 25 22:41:10 raspi kernel: Modules linked in: tun rfcomm snd_seq_dummy snd_hrtimer snd_seq cmac algif_hash aes_arm64 aes_generic algif_skcipher af_alg bne>
May 25 22:41:10 raspi kernel: CPU: 2 PID: 124009 Comm: kworker/u11:3 Tainted: G        WC         6.6.31-v8+ #1764
May 25 22:41:10 raspi kernel: Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
May 25 22:41:10 raspi kernel: Workqueue: events_unbound commit_work [drm_kms_helper]
May 25 22:41:10 raspi kernel: pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
May 25 22:41:10 raspi kernel: pc : rpi_firmware_property_list+0x218/0x258
May 25 22:41:10 raspi kernel: lr : rpi_firmware_property_list+0x218/0x258
May 25 22:41:10 raspi kernel: sp : ffffffc08af33b30
May 25 22:41:10 raspi kernel: x29: ffffffc08af33b30 x28: ffffff804092bcc0 x27: ffffffde403cae98
May 25 22:41:10 raspi kernel: x26: ffffffde403cadb0 x25: ffffffc08049e008 x24: 0000000000001000
May 25 22:41:10 raspi kernel: x23: ffffff80b3ebd140 x22: 00000000ffffff92 x21: 0000000000000018
May 25 22:41:10 raspi kernel: x20: ffffff804092bc80 x19: ffffffc08049e000 x18: 0000000000000000
May 25 22:41:10 raspi kernel: x17: 0000000000000000 x16: 0000000000000007 x15: ffffffde3f93ca08
May 25 22:41:10 raspi kernel: x14: 000000000000001a x13: 74756f656d697420 x12: 6e6f69746361736e
May 25 22:41:10 raspi kernel: x11: fffffffffffe0000 x10: ffffffde402a9078 x9 : ffffffde3ed08994
May 25 22:41:10 raspi kernel: x8 : 00000000ffffefff x7 : ffffffde402a3708 x6 : 0000000000005970
May 25 22:41:10 raspi kernel: x5 : ffffff80fb7b0d48 x4 : 0000000000000000 x3 : 0000000000000027
May 25 22:41:10 raspi kernel: x2 : 0000000000000000 x1 : 0000000000000000 x0 : ffffff8080ca1ec0
May 25 22:41:10 raspi kernel: Call trace:
May 25 22:41:10 raspi kernel:  rpi_firmware_property_list+0x218/0x258
May 25 22:41:10 raspi kernel:  rpi_firmware_property+0x78/0x118
May 25 22:41:10 raspi kernel:  raspberrypi_fw_get_rate+0x4c/0x88
May 25 22:41:10 raspi kernel:  clk_recalc+0x40/0xb8
May 25 22:41:10 raspi kernel:  __clk_recalc_rates+0x44/0xc0
May 25 22:41:10 raspi kernel:  clk_set_rate_range_nolock.part.0+0x1f0/0x2e8
May 25 22:41:10 raspi kernel:  clk_set_min_rate+0x4c/0x108
May 25 22:41:10 raspi kernel:  vc4_atomic_commit_tail+0x23c/0x880 [vc4]
May 25 22:41:10 raspi kernel:  commit_tail+0xac/0x1a0 [drm_kms_helper]
May 25 22:41:10 raspi kernel:  commit_work+0x1c/0x30 [drm_kms_helper]
May 25 22:41:10 raspi kernel:  process_one_work+0x148/0x388
May 25 22:41:10 raspi kernel:  worker_thread+0x338/0x450
May 25 22:41:10 raspi kernel:  kthread+0x120/0x130
May 25 22:41:10 raspi kernel:  ret_from_fork+0x10/0x20
May 25 22:41:10 raspi kernel: ---[ end trace 0000000000000000 ]---
May 25 22:41:11 raspi kernel: raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-core frequency: -110
May 25 22:41:12 raspi kernel: bcm2835_mmal_vchiq: timed out waiting for sync completion
May 25 22:41:12 raspi kernel: hwmon hwmon1: Failed to get throttled (-110)
May 25 22:41:18 raspi kernel: sysrq: Terminate All Tasks
May 25 22:41:18 raspi systemd-journald[276]: Received SIGTERM.
May 25 22:41:18 raspi avahi-daemon[669]: Got SIGTERM, quitting.
May 25 22:41:18 raspi systemd[1]: cron.service: Deactivated successfully.
May 25 22:41:18 raspi bluetoothd[768]: Terminating
May 25 22:41:18 raspi org.freedesktop.secrets[1463]: discover_other_daemon: 1

@qrp73
Copy link
Author

qrp73 commented May 25, 2024

just catch it again, but this time I was able to connect via ssh and see the logs before the system stopped responding completely.

This time I reproduced it with reboot and opening chromium-browser with one tab (tg.me page), I read page for some time and then opened new tab and clicked on close button for old tab, at this moment Wayland desktop was freezes, but I connected via ssh and take logs:

vclog contains thousands of the same alloc_compact_internal errors in a loop, github don't accept so many text, so I skipped it.

sudo vclog -m:

1476722.338: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
1476722.378: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
1476722.621: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
1476722.664: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
1476722.874: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
1476722.909: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
1476723.115: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
1476723.152: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
1476727.195: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
1476727.233: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
1476731.550: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
<...skip thousands of the same alloc_compact error messages...>
1483624.136: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
1483624.167: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
1483641.663: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
1483641.701: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
1483641.901: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
1483641.932: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
1483691.042: smservice: sm_remove_resource: failed to find resource (0) in resource list
1483691.063: smservice: sm_remove_resource: failed to find resource (0) in resource list
1483691.081: smservice: sm_remove_resource: failed to find resource (0) in resource list
1483691.102: smservice: sm_remove_resource: failed to find resource (0) in resource list
1483691.119: smservice: sm_remove_resource: failed to find resource (0) in resource list
1483691.141: smservice: sm_remove_resource: failed to find resource (0) in resource list
1483691.161: smservice: sm_remove_resource: failed to find resource (0) in resource list
1483691.182: smservice: sm_remove_resource: failed to find resource (0) in resource list
1483691.202: smservice: sm_remove_resource: failed to find resource (0) in resource list
1483691.224: smservice: sm_remove_resource: failed to find resource (0) in resource list
1483691.248: smservice: sm_remove_resource: failed to find resource (0) in resource list
1483691.269: smservice: sm_remove_resource: failed to find resource (0) in resource list
1483691.288: smservice: sm_remove_resource: failed to find resource (0) in resource list
1483691.309: smservice: sm_remove_resource: failed to find resource (0) in resource list
1483691.328: smservice: sm_remove_resource: failed to find resource (0) in resource list
1483691.349: smservice: sm_remove_resource: failed to find resource (0) in resource list
1483691.368: smservice: sm_remove_resource: failed to find resource (0) in resource list
1483691.405: smservice: sm_remove_resource: failed to find resource (0) in resource list
1483691.440: smservice: sm_remove_resource: failed to find resource (0) in resource list
1483691.460: smservice: sm_remove_resource: failed to find resource (0) in resource list
1483691.478: smservice: sm_remove_resource: failed to find resource (0) in resource list
1483691.499: smservice: sm_remove_resource: failed to find resource (0) in resource list
1483691.518: smservice: sm_remove_resource: failed to find resource (0) in resource list
1483691.538: smservice: sm_remove_resource: failed to find resource (0) in resource list
1483691.555: smservice: sm_remove_resource: failed to find resource (0) in resource list
1483691.576: smservice: sm_remove_resource: failed to find resource (0) in resource list

dmesg:

[ 1090.500290] vc4-drm gpu: swiotlb buffer is full (sz: 581632 bytes), total 32768 (slots), used 0 (slots)
[ 1090.504107] vc4-drm gpu: swiotlb buffer is full (sz: 843776 bytes), total 32768 (slots), used 0 (slots)
[ 1090.508205] vc4-drm gpu: swiotlb buffer is full (sz: 1048576 bytes), total 32768 (slots), used 28 (slots)
[ 1090.513071] vc4-drm gpu: swiotlb buffer is full (sz: 581632 bytes), total 32768 (slots), used 0 (slots)
[ 1091.079446] vc4-drm gpu: swiotlb buffer is full (sz: 843776 bytes), total 32768 (slots), used 0 (slots)
[ 1091.089192] vc4-drm gpu: swiotlb buffer is full (sz: 1048576 bytes), total 32768 (slots), used 28 (slots)
[ 1113.275010] vc4-drm gpu: swiotlb buffer is full (sz: 524288 bytes), total 32768 (slots), used 1596 (slots)
[ 1113.968446] vc4-drm gpu: swiotlb buffer is full (sz: 524288 bytes), total 32768 (slots), used 1596 (slots)
[ 1446.670829] cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
[ 1446.672935] cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
[ 1451.478444] cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
[ 1451.481337] cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
[ 1451.484478] cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
[ 1451.487574] cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
[ 1451.489747] cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
[ 1451.493198] cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
[ 1451.495566] cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
[ 1451.497437] cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
[ 1458.993862] cma_alloc: 16 callbacks suppressed
[ 1458.993870] cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
[ 1458.995356] cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
[ 1458.997048] cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
[ 1458.998469] cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
[ 1459.000007] cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
[ 1459.001489] cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
[ 1459.002997] cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
[ 1459.004505] cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
[ 1459.942198] cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
[ 1459.943779] cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -12
[ 1472.755309] ------------[ cut here ]------------
[ 1472.755322] Firmware transaction timeout
[ 1472.755352] WARNING: CPU: 1 PID: 1012 at drivers/firmware/raspberrypi.c:68 rpi_firmware_property_list+0x218/0x258
[ 1472.755369] Modules linked in: rfcomm snd_seq_dummy snd_hrtimer snd_seq cmac algif_hash aes_arm64 aes_generic algif_skcipher af_alg bnep vc4 snd_usb_audio brcmfmac_wcc snd_soc_hdmi_codec drm_display_helper brcmfmac cec joydev snd_hwdep snd_usbmidi_lib snd_rawmidi brcmutil binfmt_misc drm_dma_helper hci_uart cfg80211 btbcm snd_seq_device drm_kms_helper bluetooth snd_soc_core ecdh_generic rpivid_hevc(C) ecc bcm2835_codec(C) bcm2835_v4l2(C) bcm2835_isp(C) v3d rfkill v4l2_mem2mem gpu_sched libaes snd_compress raspberrypi_hwmon bcm2835_mmal_vchiq(C) drm_shmem_helper videobuf2_dma_contig videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 snd_bcm2835(C) snd_pcm_dmaengine i2c_brcmstb videodev snd_pcm i2c_bcm2835 vc_sm_cma(C) videobuf2_common snd_timer mc snd raspberrypi_gpiomem nvmem_rmem uio_pdrv_genirq uio i2c_dev drm fuse drm_panel_orientation_quirks dm_mod backlight ip_tables x_tables ipv6
[ 1472.755495] CPU: 1 PID: 1012 Comm: wayfire Tainted: G         C         6.6.31-v8+ #1
[ 1472.755501] Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
[ 1472.755503] pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
[ 1472.755508] pc : rpi_firmware_property_list+0x218/0x258
[ 1472.755512] lr : rpi_firmware_property_list+0x218/0x258
[ 1472.755515] sp : ffffffc0813c3930
[ 1472.755517] x29: ffffffc0813c3930 x28: ffffff804092bcc0 x27: ffffffe8573cae98
[ 1472.755525] x26: ffffffe8573cadb0 x25: ffffffc08049e008 x24: 0000000000001000
[ 1472.755531] x23: ffffff80aed072c0 x22: 00000000ffffff92 x21: 0000000000000018
[ 1472.755538] x20: ffffff804092bc80 x19: ffffffc08049e000 x18: 0000000000000000
[ 1472.755544] x17: 0000000000000000 x16: 0000000000000000 x15: 0000000000000000
[ 1472.755551] x14: 0000000000000000 x13: 74756f656d697420 x12: 6e6f69746361736e
[ 1472.755557] x11: fffffffffffe0000 x10: ffffffe8572a6c48 x9 : ffffffe855d08994
[ 1472.755564] x8 : 00000000ffffefff x7 : ffffffe8572a3708 x6 : 0000000000003540
[ 1472.755570] x5 : ffffff80fb793d48 x4 : 0000000000000000 x3 : 0000000000000027
[ 1472.755576] x2 : 0000000000000000 x1 : 0000000000000000 x0 : ffffff8043201ec0
[ 1472.755582] Call trace:
[ 1472.755585]  rpi_firmware_property_list+0x218/0x258
[ 1472.755590]  rpi_firmware_property+0x78/0x118
[ 1472.755593]  raspberrypi_fw_get_rate+0x4c/0x88
[ 1472.755600]  clk_recalc+0x40/0xb8
[ 1472.755606]  __clk_recalc_rates+0x44/0xc0
[ 1472.755611]  clk_set_rate_range_nolock.part.0+0x1f0/0x2e8
[ 1472.755615]  clk_set_min_rate+0x4c/0x108
[ 1472.755618]  v3d_clock_up_get+0x6c/0xa0 [v3d]
[ 1472.755641]  v3d_job_init.constprop.0+0xe0/0x258 [v3d]
[ 1472.755653]  v3d_submit_tfu_ioctl+0xac/0x388 [v3d]
[ 1472.755664]  drm_ioctl_kernel+0xd4/0x188 [drm]
[ 1472.755789]  drm_ioctl+0x21c/0x4d8 [drm]
[ 1472.755851]  __arm64_sys_ioctl+0xb0/0x100
[ 1472.755858]  invoke_syscall+0x50/0x128
[ 1472.755864]  el0_svc_common.constprop.0+0x48/0xf8
[ 1472.755869]  do_el0_svc+0x28/0x40
[ 1472.755874]  el0_svc+0x40/0xf8
[ 1472.755880]  el0t_64_sync_handler+0x13c/0x158
[ 1472.755884]  el0t_64_sync+0x190/0x198
[ 1472.755888] ---[ end trace 0000000000000000 ]---
[ 1473.779342] hwmon hwmon1: Failed to get throttled (-110)
[ 1474.803340] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 1474.803357] bcm2835-codec bcm2835-codec: bcm2835_codec_stop_streaming: Failed disabling i/p port, ret -62
[ 1475.827586] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-v3d frequency: -110
[ 1476.819408] bcm2835-codec bcm2835-codec: bcm2835_codec_flush_buffers: Timeout waiting for buffers to be returned - 8 outstanding
[ 1476.819488] ------------[ cut here ]------------
[ 1476.819490] WARNING: CPU: 1 PID: 5865 at drivers/media/common/videobuf2/videobuf2-core.c:2024 __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[ 1476.819519] Modules linked in: rfcomm snd_seq_dummy snd_hrtimer snd_seq cmac algif_hash aes_arm64 aes_generic algif_skcipher af_alg bnep vc4 snd_usb_audio brcmfmac_wcc snd_soc_hdmi_codec drm_display_helper brcmfmac cec joydev snd_hwdep snd_usbmidi_lib snd_rawmidi brcmutil binfmt_misc drm_dma_helper hci_uart cfg80211 btbcm snd_seq_device drm_kms_helper bluetooth snd_soc_core ecdh_generic rpivid_hevc(C) ecc bcm2835_codec(C) bcm2835_v4l2(C) bcm2835_isp(C) v3d rfkill v4l2_mem2mem gpu_sched libaes snd_compress raspberrypi_hwmon bcm2835_mmal_vchiq(C) drm_shmem_helper videobuf2_dma_contig videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 snd_bcm2835(C) snd_pcm_dmaengine i2c_brcmstb videodev snd_pcm i2c_bcm2835 vc_sm_cma(C) videobuf2_common snd_timer mc snd raspberrypi_gpiomem nvmem_rmem uio_pdrv_genirq uio i2c_dev drm fuse drm_panel_orientation_quirks dm_mod backlight ip_tables x_tables ipv6
[ 1476.819638] CPU: 1 PID: 5865 Comm: ThreadPoolSingl Tainted: G        WC         6.6.31-v8+ #1
[ 1476.819643] Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
[ 1476.819646] pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
[ 1476.819650] pc : __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[ 1476.819663] lr : __vb2_queue_cancel+0x38/0x2a0 [videobuf2_common]
[ 1476.819675] sp : ffffffc080fa3ae0
[ 1476.819677] x29: ffffffc080fa3ae0 x28: ffffffe830cf6e18 x27: ffffff80a08bc000
[ 1476.819685] x26: ffffff8041f85d30 x25: 0000000000000000 x24: 0000000040045613
[ 1476.819692] x23: 0000000000000000 x22: ffffff809fedfa98 x21: ffffff809fedfa98
[ 1476.819698] x20: 000000000000000a x19: ffffff809fedfa98 x18: ffffffffffffffff
[ 1476.819705] x17: 756f656d6954203a x16: ffffffe855ed4350 x15: 6873756c665f6365
[ 1476.819711] x14: 0000000000000019 x13: ffffff8042a40028 x12: 0000000000000000
[ 1476.819717] x11: ffffff80961f7c40 x10: ffffff80961f7b50 x9 : ffffffe855f2b1a0
[ 1476.819724] x8 : ffffff80961f7b78 x7 : 0000000000000001 x6 : ffffff8000000000
[ 1476.819730] x5 : 0000000041001000 x4 : 000000008015000e x3 : ffffff809fcfc180
[ 1476.819737] x2 : 0000000000000000 x1 : 0000000000000000 x0 : 0000000000000008
[ 1476.819743] Call trace:
[ 1476.819746]  __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[ 1476.819759]  vb2_core_streamoff+0x2c/0xe0 [videobuf2_common]
[ 1476.819771]  vb2_streamoff+0x24/0x80 [videobuf2_v4l2]
[ 1476.819784]  v4l2_m2m_streamoff+0x50/0x160 [v4l2_mem2mem]
[ 1476.819800]  v4l2_m2m_ioctl_streamoff+0x20/0x38 [v4l2_mem2mem]
[ 1476.819811]  v4l_streamoff+0x2c/0x40 [videodev]
[ 1476.819855]  __video_do_ioctl+0x194/0x400 [videodev]
[ 1476.819882]  video_usercopy+0x1e4/0x780 [videodev]
[ 1476.819910]  video_ioctl2+0x20/0x40 [videodev]
[ 1476.819937]  v4l2_ioctl+0x48/0x70 [videodev]
[ 1476.819964]  __arm64_sys_ioctl+0xb0/0x100
[ 1476.819975]  invoke_syscall+0x50/0x128
[ 1476.819982]  el0_svc_common.constprop.0+0x48/0xf8
[ 1476.819987]  do_el0_svc+0x28/0x40
[ 1476.819991]  el0_svc+0x40/0xf8
[ 1476.819998]  el0t_64_sync_handler+0x13c/0x158
[ 1476.820001]  el0t_64_sync+0x190/0x198
[ 1476.820005] ---[ end trace 0000000000000000 ]---
[ 1476.820008] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000a3f8c7e5 in active state
[ 1476.820015] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000ef01ee92 in active state
[ 1476.820018] videobuf2_common: driver bug: stop_streaming operation is leaving buf 0000000084766702 in active state
[ 1476.820021] videobuf2_common: driver bug: stop_streaming operation is leaving buf 0000000035c4910d in active state
[ 1476.820023] videobuf2_common: driver bug: stop_streaming operation is leaving buf 000000002d98a9e1 in active state
[ 1476.820026] videobuf2_common: driver bug: stop_streaming operation is leaving buf 000000009ab771a5 in active state
[ 1476.820029] videobuf2_common: driver bug: stop_streaming operation is leaving buf 0000000042d55251 in active state
[ 1476.820031] videobuf2_common: driver bug: stop_streaming operation is leaving buf 000000006448c5cf in active state
[ 1479.923427] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 1482.995468] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 1482.995486] bcm2835-codec bcm2835-codec: bcm2835_codec_stop_streaming: Failed disabling i/p port, ret -62
[ 1485.011530] bcm2835-codec bcm2835-codec: bcm2835_codec_flush_buffers: Timeout waiting for buffers to be returned - 8 outstanding
[ 1485.011609] ------------[ cut here ]------------
[ 1485.011611] WARNING: CPU: 1 PID: 5852 at drivers/media/common/videobuf2/videobuf2-core.c:2024 __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[ 1485.011640] Modules linked in: rfcomm snd_seq_dummy snd_hrtimer snd_seq cmac algif_hash aes_arm64 aes_generic algif_skcipher af_alg bnep vc4 snd_usb_audio brcmfmac_wcc snd_soc_hdmi_codec drm_display_helper brcmfmac cec joydev snd_hwdep snd_usbmidi_lib snd_rawmidi brcmutil binfmt_misc drm_dma_helper hci_uart cfg80211 btbcm snd_seq_device drm_kms_helper bluetooth snd_soc_core ecdh_generic rpivid_hevc(C) ecc bcm2835_codec(C) bcm2835_v4l2(C) bcm2835_isp(C) v3d rfkill v4l2_mem2mem gpu_sched libaes snd_compress raspberrypi_hwmon bcm2835_mmal_vchiq(C) drm_shmem_helper videobuf2_dma_contig videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 snd_bcm2835(C) snd_pcm_dmaengine i2c_brcmstb videodev snd_pcm i2c_bcm2835 vc_sm_cma(C) videobuf2_common snd_timer mc snd raspberrypi_gpiomem nvmem_rmem uio_pdrv_genirq uio i2c_dev drm fuse drm_panel_orientation_quirks dm_mod backlight ip_tables x_tables ipv6
[ 1485.011759] CPU: 1 PID: 5852 Comm: ThreadPoolSingl Tainted: G        WC         6.6.31-v8+ #1
[ 1485.011764] Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
[ 1485.011767] pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
[ 1485.011771] pc : __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[ 1485.011784] lr : __vb2_queue_cancel+0x38/0x2a0 [videobuf2_common]
[ 1485.011797] sp : ffffffc082cbbae0
[ 1485.011799] x29: ffffffc082cbbae0 x28: ffffffe830cf6e18 x27: ffffff8093c6a000
[ 1485.011807] x26: ffffff8041f85d30 x25: 0000000000000000 x24: 0000000040045613
[ 1485.011814] x23: 0000000000000000 x22: ffffff80b25f6a98 x21: ffffff80b25f6a98
[ 1485.011820] x20: 000000000000000a x19: ffffff80b25f6a98 x18: ffffffffffffffff
[ 1485.011827] x17: 756f656d6954203a x16: ffffffe855ed4350 x15: 6873756c665f6365
[ 1485.011833] x14: 0000000000000026 x13: ffffff8042a40028 x12: 0000000000000000
[ 1485.011840] x11: ffffff809293fca8 x10: ffffff809293fb50 x9 : ffffffe855f2b1a0
[ 1485.011846] x8 : ffffff809293fb78 x7 : 0000000000000001 x6 : ffffffbffc003fff
[ 1485.011853] x5 : 0000000041001000 x4 : 0000000080150004 x3 : ffffff8093b6b900
[ 1485.011859] x2 : 0000000000000000 x1 : 0000000000000000 x0 : 0000000000000008
[ 1485.011866] Call trace:
[ 1485.011869]  __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[ 1485.011882]  vb2_core_streamoff+0x2c/0xe0 [videobuf2_common]
[ 1485.011894]  vb2_streamoff+0x24/0x80 [videobuf2_v4l2]
[ 1485.011906]  v4l2_m2m_streamoff+0x50/0x160 [v4l2_mem2mem]
[ 1485.011922]  v4l2_m2m_ioctl_streamoff+0x20/0x38 [v4l2_mem2mem]
[ 1485.011933]  v4l_streamoff+0x2c/0x40 [videodev]
[ 1485.011978]  __video_do_ioctl+0x194/0x400 [videodev]
[ 1485.012005]  video_usercopy+0x1e4/0x780 [videodev]
[ 1485.012033]  video_ioctl2+0x20/0x40 [videodev]
[ 1485.012060]  v4l2_ioctl+0x48/0x70 [videodev]
[ 1485.012087]  __arm64_sys_ioctl+0xb0/0x100
[ 1485.012098]  invoke_syscall+0x50/0x128
[ 1485.012105]  el0_svc_common.constprop.0+0x48/0xf8
[ 1485.012110]  do_el0_svc+0x28/0x40
[ 1485.012115]  el0_svc+0x40/0xf8
[ 1485.012121]  el0t_64_sync_handler+0x13c/0x158
[ 1485.012124]  el0t_64_sync+0x190/0x198
[ 1485.012128] ---[ end trace 0000000000000000 ]---
[ 1485.012139] videobuf2_common: driver bug: stop_streaming operation is leaving buf 0000000057c4f323 in active state
[ 1485.012145] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000c15d4ad7 in active state
[ 1485.012149] videobuf2_common: driver bug: stop_streaming operation is leaving buf 0000000039d619e7 in active state
[ 1485.012152] videobuf2_common: driver bug: stop_streaming operation is leaving buf 000000009c31cd1e in active state
[ 1485.012155] videobuf2_common: driver bug: stop_streaming operation is leaving buf 000000005a57c3d1 in active state
[ 1485.012158] videobuf2_common: driver bug: stop_streaming operation is leaving buf 000000002dd246a4 in active state
[ 1485.012160] videobuf2_common: driver bug: stop_streaming operation is leaving buf 0000000018c1e2e0 in active state
[ 1485.012163] videobuf2_common: driver bug: stop_streaming operation is leaving buf 0000000081fefa82 in active state
[ 1488.115576] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 1488.115593] bcm2835-codec bcm2835-codec: bcm2835_codec_stop_streaming: Failed disabling i/p port, ret -62
[ 1491.187633] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 1491.187649] bcm2835-codec bcm2835-codec: bcm2835_codec_stop_streaming: Failed disabling i/p port, ret -62
[ 1494.259661] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 1494.259679] bcm2835-codec bcm2835-codec: bcm2835_codec_stop_streaming: Failed disabling o/p port, ret -62
[ 1496.275693] bcm2835-codec bcm2835-codec: bcm2835_codec_flush_buffers: Timeout waiting for buffers to be returned - 10 outstanding
[ 1499.379740] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 1499.379758] bcm2835-codec bcm2835-codec: bcm2835_codec_stop_streaming: Failed enabling component, ret -62
[ 1499.379824] ------------[ cut here ]------------
[ 1499.379827] WARNING: CPU: 0 PID: 5687 at drivers/media/common/videobuf2/videobuf2-core.c:2024 __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[ 1499.379856] Modules linked in: rfcomm snd_seq_dummy snd_hrtimer snd_seq cmac algif_hash aes_arm64 aes_generic algif_skcipher af_alg bnep vc4 snd_usb_audio brcmfmac_wcc snd_soc_hdmi_codec drm_display_helper brcmfmac cec joydev snd_hwdep snd_usbmidi_lib snd_rawmidi brcmutil binfmt_misc drm_dma_helper hci_uart cfg80211 btbcm snd_seq_device drm_kms_helper bluetooth snd_soc_core ecdh_generic rpivid_hevc(C) ecc bcm2835_codec(C) bcm2835_v4l2(C) bcm2835_isp(C) v3d rfkill v4l2_mem2mem gpu_sched libaes snd_compress raspberrypi_hwmon bcm2835_mmal_vchiq(C) drm_shmem_helper videobuf2_dma_contig videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 snd_bcm2835(C) snd_pcm_dmaengine i2c_brcmstb videodev snd_pcm i2c_bcm2835 vc_sm_cma(C) videobuf2_common snd_timer mc snd raspberrypi_gpiomem nvmem_rmem uio_pdrv_genirq uio i2c_dev drm fuse drm_panel_orientation_quirks dm_mod backlight ip_tables x_tables ipv6
[ 1499.379975] CPU: 0 PID: 5687 Comm: ThreadPoolSingl Tainted: G        WC         6.6.31-v8+ #1
[ 1499.379980] Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
[ 1499.379983] pstate: 80000005 (Nzcv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
[ 1499.379987] pc : __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[ 1499.380000] lr : __vb2_queue_cancel+0x38/0x2a0 [videobuf2_common]
[ 1499.380012] sp : ffffffc082d0bae0
[ 1499.380014] x29: ffffffc082d0bae0 x28: ffffffe830cf6e18 x27: ffffff8043454000
[ 1499.380022] x26: ffffff8041f85d30 x25: 0000000000000000 x24: 0000000040045613
[ 1499.380028] x23: 0000000000000000 x22: ffffff80ba83a828 x21: ffffff80ba83a828
[ 1499.380035] x20: 0000000000000009 x19: ffffff80ba83a828 x18: ffffffffffffffff
[ 1499.380042] x17: 656c696146203a67 x16: 6e696d6165727473 x15: 5f706f74735f6365
[ 1499.380048] x14: 646f635f35333832 x13: 32362d2074657220 x12: 2c746e656e6f706d
[ 1499.380055] x11: 6f6320676e696c62 x10: ffffffe8572a3708 x9 : ffffffe855d08994
[ 1499.380061] x8 : 00000000ffffefff x7 : ffffffe8572a3708 x6 : 0000000000000000
[ 1499.380068] x5 : ffffff80fb775d48 x4 : 0000000000000000 x3 : 0000000000000000
[ 1499.380074] x2 : 0000000000000000 x1 : 0000000000000000 x0 : 000000000000000a
[ 1499.380080] Call trace:
[ 1499.380083]  __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[ 1499.380096]  vb2_core_streamoff+0x2c/0xe0 [videobuf2_common]
[ 1499.380108]  vb2_streamoff+0x24/0x80 [videobuf2_v4l2]
[ 1499.380120]  v4l2_m2m_streamoff+0x80/0x160 [v4l2_mem2mem]
[ 1499.380136]  v4l2_m2m_ioctl_streamoff+0x20/0x38 [v4l2_mem2mem]
[ 1499.380147]  v4l_streamoff+0x2c/0x40 [videodev]
[ 1499.380194]  __video_do_ioctl+0x194/0x400 [videodev]
[ 1499.380221]  video_usercopy+0x1e4/0x780 [videodev]
[ 1499.380249]  video_ioctl2+0x20/0x40 [videodev]
[ 1499.380276]  v4l2_ioctl+0x48/0x70 [videodev]
[ 1499.380304]  __arm64_sys_ioctl+0xb0/0x100
[ 1499.380315]  invoke_syscall+0x50/0x128
[ 1499.380322]  el0_svc_common.constprop.0+0x48/0xf8
[ 1499.380327]  do_el0_svc+0x28/0x40
[ 1499.380332]  el0_svc+0x40/0xf8
[ 1499.380338]  el0t_64_sync_handler+0x13c/0x158
[ 1499.380341]  el0t_64_sync+0x190/0x198
[ 1499.380345] ---[ end trace 0000000000000000 ]---
[ 1499.380349] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000fc40d0c8 in active state
[ 1499.380355] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000e1747286 in active state
[ 1499.380358] videobuf2_common: driver bug: stop_streaming operation is leaving buf 0000000047b8516a in active state
[ 1499.380361] videobuf2_common: driver bug: stop_streaming operation is leaving buf 000000004ed99605 in active state
[ 1499.380364] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000add5c240 in active state
[ 1499.380367] videobuf2_common: driver bug: stop_streaming operation is leaving buf 0000000097839225 in active state
[ 1499.380369] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000c31c4456 in active state
[ 1499.380372] videobuf2_common: driver bug: stop_streaming operation is leaving buf 0000000098cb7cff in active state
[ 1499.380375] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000ada451ab in active state
[ 1499.380377] videobuf2_common: driver bug: stop_streaming operation is leaving buf 000000000b7c71db in active state
[ 1502.451782] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 1505.523831] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 1508.595880] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 1511.667930] bcm2835_mmal_vchiq: timed out waiting for sync completion
[ 1692.662673] INFO: task kworker/3:1:57 blocked for more than 120 seconds.
[ 1692.662691]       Tainted: G        WC         6.6.31-v8+ #1
[ 1692.662694] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1692.662697] task:kworker/3:1     state:D stack:0     pid:57    ppid:2      flags:0x00000008
[ 1692.662707] Workqueue: events dbs_work_handler
[ 1692.662723] Call trace:
[ 1692.662726]  __switch_to+0xe8/0x168
[ 1692.662733]  __schedule+0x31c/0xd60
[ 1692.662736]  schedule+0x64/0x108
[ 1692.662740]  schedule_preempt_disabled+0x2c/0x50
[ 1692.662744]  __mutex_lock.constprop.0+0x284/0x5f0
[ 1692.662749]  __mutex_lock_slowpath+0x1c/0x30
[ 1692.662753]  mutex_lock+0x50/0x68
[ 1692.662757]  rpi_firmware_property_list+0xe4/0x258
[ 1692.662761]  rpi_firmware_property+0x78/0x118
[ 1692.662765]  raspberrypi_fw_set_rate+0x5c/0xe8
[ 1692.662771]  clk_change_rate+0xe0/0x508
[ 1692.662774]  clk_core_set_rate_nolock+0x168/0x298
[ 1692.662778]  clk_set_rate+0x40/0x190
[ 1692.662781]  _opp_config_clk_single+0x38/0xb8
[ 1692.662786]  _set_opp+0xf4/0x410
[ 1692.662791]  dev_pm_opp_set_rate+0x190/0x290
[ 1692.662796]  set_target+0x38/0x50
[ 1692.662800]  __cpufreq_driver_target+0x188/0x2a0
[ 1692.662804]  od_dbs_update+0xc4/0x1c0
[ 1692.662808]  dbs_work_handler+0x48/0x90
[ 1692.662813]  process_one_work+0x148/0x388
[ 1692.662818]  worker_thread+0x338/0x450
[ 1692.662821]  kthread+0x120/0x130
[ 1692.662826]  ret_from_fork+0x10/0x20
[ 1692.662859] INFO: task wayfire:1012 blocked for more than 120 seconds.
[ 1692.662862]       Tainted: G        WC         6.6.31-v8+ #1
[ 1692.662864] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1692.662866] task:wayfire         state:D stack:0     pid:1012  ppid:988    flags:0x00000004
[ 1692.662872] Call trace:
[ 1692.662874]  __switch_to+0xe8/0x168
[ 1692.662878]  __schedule+0x31c/0xd60
[ 1692.662882]  schedule+0x64/0x108
[ 1692.662885]  schedule_timeout+0x1a0/0x1d0
[ 1692.662890]  wait_for_completion+0x7c/0x168
[ 1692.662894]  __flush_work.isra.0+0x184/0x2e8
[ 1692.662899]  __cancel_work_timer+0x12c/0x1b0
[ 1692.662902]  cancel_delayed_work_sync+0x1c/0x30
[ 1692.662906]  v3d_clock_up_get+0x58/0xa0 [v3d]
[ 1692.662929]  v3d_job_init.constprop.0+0xe0/0x258 [v3d]
[ 1692.662941]  v3d_submit_cl_ioctl+0x9c/0x780 [v3d]
[ 1692.662953]  drm_ioctl_kernel+0xd4/0x188 [drm]
[ 1692.663073]  drm_ioctl+0x21c/0x4d8 [drm]
[ 1692.663138]  __arm64_sys_ioctl+0xb0/0x100
[ 1692.663144]  invoke_syscall+0x50/0x128
[ 1692.663149]  el0_svc_common.constprop.0+0x48/0xf8
[ 1692.663155]  do_el0_svc+0x28/0x40
[ 1692.663159]  el0_svc+0x40/0xf8
[ 1692.663164]  el0t_64_sync_handler+0x13c/0x158
[ 1692.663167]  el0t_64_sync+0x190/0x198
[ 1692.663200] INFO: task kworker/u11:3:3079 blocked for more than 120 seconds.
[ 1692.663203]       Tainted: G        WC         6.6.31-v8+ #1
[ 1692.663206] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1692.663208] task:kworker/u11:3   state:D stack:0     pid:3079  ppid:2      flags:0x00000008
[ 1692.663215] Workqueue: events_unbound commit_work [drm_kms_helper]
[ 1692.663270] Call trace:
[ 1692.663272]  __switch_to+0xe8/0x168
[ 1692.663277]  __schedule+0x31c/0xd60
[ 1692.663280]  schedule+0x64/0x108
[ 1692.663284]  schedule_preempt_disabled+0x2c/0x50
[ 1692.663287]  __mutex_lock.constprop.0+0x284/0x5f0
[ 1692.663291]  __mutex_lock_slowpath+0x1c/0x30
[ 1692.663295]  mutex_lock+0x50/0x68
[ 1692.663299]  clk_prepare_lock+0x4c/0xb0
[ 1692.663304]  clk_set_min_rate+0x3c/0x108
[ 1692.663307]  vc4_atomic_commit_tail+0x23c/0x880 [vc4]
[ 1692.663338]  commit_tail+0xac/0x1a0 [drm_kms_helper]
[ 1692.663369]  commit_work+0x1c/0x30 [drm_kms_helper]
[ 1692.663397]  process_one_work+0x148/0x388
[ 1692.663400]  worker_thread+0x338/0x450
[ 1692.663403]  kthread+0x120/0x130
[ 1692.663409]  ret_from_fork+0x10/0x20
[ 1692.663425] INFO: task chromium-browse:4317 blocked for more than 120 seconds.
[ 1692.663428]       Tainted: G        WC         6.6.31-v8+ #1
[ 1692.663430] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1692.663432] task:chromium-browse state:D stack:0     pid:4317  ppid:4282   flags:0x00000005
[ 1692.663437] Call trace:
[ 1692.663439]  __switch_to+0xe8/0x168
[ 1692.663444]  __schedule+0x31c/0xd60
[ 1692.663447]  schedule+0x64/0x108
[ 1692.663451]  schedule_preempt_disabled+0x2c/0x50
[ 1692.663454]  __mutex_lock.constprop.0+0x284/0x5f0
[ 1692.663458]  __mutex_lock_slowpath+0x1c/0x30
[ 1692.663462]  mutex_lock+0x50/0x68
[ 1692.663465]  v3d_clock_up_get+0x28/0xa0 [v3d]
[ 1692.663479]  v3d_job_init.constprop.0+0xe0/0x258 [v3d]
[ 1692.663490]  v3d_submit_cl_ioctl+0x9c/0x780 [v3d]
[ 1692.663501]  drm_ioctl_kernel+0xd4/0x188 [drm]
[ 1692.663573]  drm_ioctl+0x21c/0x4d8 [drm]
[ 1692.663635]  __arm64_sys_ioctl+0xb0/0x100
[ 1692.663640]  invoke_syscall+0x50/0x128
[ 1692.663645]  el0_svc_common.constprop.0+0x48/0xf8
[ 1692.663650]  do_el0_svc+0x28/0x40
[ 1692.663654]  el0_svc+0x40/0xf8
[ 1692.663660]  el0t_64_sync_handler+0x13c/0x158
[ 1692.663663]  el0t_64_sync+0x190/0x198
[ 1692.663681] INFO: task kworker/0:1:5825 blocked for more than 120 seconds.
[ 1692.663684]       Tainted: G        WC         6.6.31-v8+ #1
[ 1692.663686] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1692.663688] task:kworker/0:1     state:D stack:0     pid:5825  ppid:2      flags:0x00000008
[ 1692.663694] Workqueue: events v3d_clock_down_work [v3d]
[ 1692.663708] Call trace:
[ 1692.663710]  __switch_to+0xe8/0x168
[ 1692.663714]  __schedule+0x31c/0xd60
[ 1692.663717]  schedule+0x64/0x108
[ 1692.663720]  schedule_preempt_disabled+0x2c/0x50
[ 1692.663724]  __mutex_lock.constprop.0+0x284/0x5f0
[ 1692.663727]  __mutex_lock_slowpath+0x1c/0x30
[ 1692.663731]  mutex_lock+0x50/0x68
[ 1692.663735]  clk_prepare_lock+0x4c/0xb0
[ 1692.663739]  clk_set_min_rate+0x3c/0x108
[ 1692.663742]  v3d_clock_down_work+0x28/0x60 [v3d]
[ 1692.663753]  process_one_work+0x148/0x388
[ 1692.663757]  worker_thread+0x338/0x450
[ 1692.663759]  kthread+0x120/0x130
[ 1692.663764]  ret_from_fork+0x10/0x20
[ 1692.663773] INFO: task kworker/3:3:5919 blocked for more than 120 seconds.
[ 1692.663776]       Tainted: G        WC         6.6.31-v8+ #1
[ 1692.663778] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1692.663780] task:kworker/3:3     state:D stack:0     pid:5919  ppid:2      flags:0x00000008
[ 1692.663786] Workqueue: events get_values_poll [raspberrypi_hwmon]
[ 1692.663795] Call trace:
[ 1692.663797]  __switch_to+0xe8/0x168
[ 1692.663801]  __schedule+0x31c/0xd60
[ 1692.663804]  schedule+0x64/0x108
[ 1692.663808]  schedule_preempt_disabled+0x2c/0x50
[ 1692.663811]  __mutex_lock.constprop.0+0x284/0x5f0
[ 1692.663815]  __mutex_lock_slowpath+0x1c/0x30
[ 1692.663819]  mutex_lock+0x50/0x68
[ 1692.663823]  rpi_firmware_property_list+0xe4/0x258
[ 1692.663827]  rpi_firmware_property+0x78/0x118
[ 1692.663831]  get_values_poll+0x54/0x120 [raspberrypi_hwmon]
[ 1692.663837]  process_one_work+0x148/0x388
[ 1692.663840]  worker_thread+0x338/0x450
[ 1692.663842]  kthread+0x120/0x130
[ 1692.663847]  ret_from_fork+0x10/0x20
[ 1692.663851] INFO: task vcgencmd:5923 blocked for more than 120 seconds.
[ 1692.663853]       Tainted: G        WC         6.6.31-v8+ #1
[ 1692.663855] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1692.663857] task:vcgencmd        state:D stack:0     pid:5923  ppid:5922   flags:0x0000000c
[ 1692.663862] Call trace:
[ 1692.663863]  __switch_to+0xe8/0x168
[ 1692.663867]  __schedule+0x31c/0xd60
[ 1692.663870]  schedule+0x64/0x108
[ 1692.663874]  schedule_timeout+0xa0/0x1d0
[ 1692.663878]  wait_for_completion_timeout+0x7c/0x158
[ 1692.663882]  mbox_send_message+0xc0/0x158
[ 1692.663886]  rpi_firmware_property_list+0xf4/0x258
[ 1692.663889]  vcio_user_property_list+0xd4/0x210
[ 1692.663894]  vcio_device_ioctl+0x34/0x58
[ 1692.663898]  __arm64_sys_ioctl+0xb0/0x100
[ 1692.663902]  invoke_syscall+0x50/0x128
[ 1692.663907]  el0_svc_common.constprop.0+0x48/0xf8
[ 1692.663912]  do_el0_svc+0x28/0x40
[ 1692.663917]  el0_svc+0x40/0xf8
[ 1692.663922]  el0t_64_sync_handler+0x13c/0x158
[ 1692.663924]  el0t_64_sync+0x190/0x198

@qrp73 qrp73 changed the title kernel 6.6.30-v8+ strange system freeze kernel 6.6.30-v8+ and 6.6.31-v8+ strange system freeze May 25, 2024
@qrp73 qrp73 changed the title kernel 6.6.30-v8+ and 6.6.31-v8+ strange system freeze kernel 6.6.30-v8+ and 6.6.31-v8+ strange system freeze due to firmware error May 25, 2024
@qrp73
Copy link
Author

qrp73 commented Jun 3, 2024

after latest update to 6.6.31 it happens again:

Jun 04 00:35:54 raspi kernel: cma_alloc: 11 callbacks suppressed
Jun 04 00:35:54 raspi kernel: cma: cma_alloc: linux,cma: alloc failed, req-size: 1024 pages, ret: -16
Jun 04 00:35:54 raspi kernel: ThreadPoolSingl: page allocation failure: order:10, mode:0xcc1(GFP_KERNEL|GFP_DMA), nodemask=(null),cpuset=/,mems_allowed=0
Jun 04 00:35:54 raspi kernel: CPU: 1 PID: 352523 Comm: ThreadPoolSingl Tainted: G        WC         6.6.31+rpt-rpi-v8 #1  Debian 1:6.6.31-1+rpt1
Jun 04 00:35:54 raspi kernel: Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
Jun 04 00:35:54 raspi kernel: Call trace:
Jun 04 00:35:54 raspi kernel:  dump_backtrace+0xa0/0x100
Jun 04 00:35:54 raspi kernel:  show_stack+0x20/0x38
Jun 04 00:35:54 raspi kernel:  dump_stack_lvl+0x48/0x60
Jun 04 00:35:54 raspi kernel:  dump_stack+0x18/0x28
Jun 04 00:35:54 raspi kernel:  warn_alloc+0x128/0x1b8
Jun 04 00:35:54 raspi kernel:  __alloc_pages+0xdc0/0xe68
Jun 04 00:35:54 raspi kernel:  __dma_direct_alloc_pages.constprop.0+0x15c/0x238
Jun 04 00:35:54 raspi kernel:  dma_direct_alloc+0x78/0x310
Jun 04 00:35:54 raspi kernel:  dma_alloc_attrs+0x8c/0x108
Jun 04 00:35:54 raspi kernel:  vb2_dc_alloc+0xa8/0x188 [videobuf2_dma_contig]
Jun 04 00:35:54 raspi kernel:  __vb2_queue_alloc+0x1cc/0x4a8 [videobuf2_common]
Jun 04 00:35:54 raspi kernel:  vb2_core_reqbufs+0x244/0x470 [videobuf2_common]
Jun 04 00:35:54 raspi kernel:  vb2_reqbufs+0x90/0xb8 [videobuf2_v4l2]
Jun 04 00:35:54 raspi kernel:  v4l2_m2m_ioctl_reqbufs+0x54/0x98 [v4l2_mem2mem]
Jun 04 00:35:54 raspi kernel:  v4l_reqbufs+0x58/0x78 [videodev]
Jun 04 00:35:54 raspi kernel:  __video_do_ioctl+0x170/0x3e0 [videodev]
Jun 04 00:35:54 raspi kernel:  video_usercopy+0x208/0x770 [videodev]
Jun 04 00:35:54 raspi kernel:  video_ioctl2+0x20/0x40 [videodev]
Jun 04 00:35:54 raspi kernel:  v4l2_ioctl+0x48/0x70 [videodev]
Jun 04 00:35:54 raspi kernel:  __arm64_sys_ioctl+0xb4/0x100
Jun 04 00:35:54 raspi kernel:  invoke_syscall+0x50/0x128
Jun 04 00:35:54 raspi kernel:  el0_svc_common.constprop.0+0x48/0xf0
Jun 04 00:35:54 raspi kernel:  do_el0_svc+0x24/0x38
Jun 04 00:35:54 raspi kernel:  el0_svc+0x40/0xe8
Jun 04 00:35:54 raspi kernel:  el0t_64_sync_handler+0x100/0x130
Jun 04 00:35:54 raspi kernel:  el0t_64_sync+0x190/0x198
Jun 04 00:35:54 raspi kernel: Mem-Info:
Jun 04 00:35:54 raspi kernel: active_anon:341433 inactive_anon:58266 isolated_anon:0
                               active_file:204163 inactive_file:92138 isolated_file:0
                               unevictable:90421 dirty:2384 writeback:0
                               slab_reclaimable:15666 slab_unreclaimable:13238
                               mapped:134485 shmem:110979 pagetables:6680
                               sec_pagetables:0 bounce:0
                               kernel_misc_reclaimable:0
                               free:17601 free_pcp:0 free_cma:1471
Jun 04 00:35:54 raspi kernel: Node 0 active_anon:1365732kB inactive_anon:233064kB active_file:816652kB inactive_file:368552kB unevictable:361684kB isolated(a>
Jun 04 00:35:54 raspi kernel: DMA free:28456kB boost:0kB min:3660kB low:4572kB high:5484kB reserved_highatomic:4096KB active_anon:215092kB inactive_anon:3332>
Jun 04 00:35:54 raspi kernel: lowmem_reserve[]: 0 2928 2928 2928
Jun 04 00:35:54 raspi kernel: DMA: 313*4kB (UMEHC) 179*8kB (UMEHC) 46*16kB (UMEHC) 54*32kB (UMEHC) 39*64kB (UMEHC) 10*128kB (HC) 11*256kB (UHC) 9*512kB (UC) >
Jun 04 00:35:54 raspi kernel: 406540 total pagecache pages
Jun 04 00:35:54 raspi kernel: 0 pages in swap cache
Jun 04 00:35:54 raspi kernel: Free swap  = 0kB
Jun 04 00:35:54 raspi kernel: Total swap = 0kB
Jun 04 00:35:54 raspi kernel: 1007616 pages RAM
Jun 04 00:35:54 raspi kernel: 0 pages HighMem/MovableOnly
Jun 04 00:35:54 raspi kernel: 41961 pages reserved
Jun 04 00:35:54 raspi kernel: 131072 pages cma reserved
Jun 04 00:35:54 raspi kernel: bcm2835-codec bcm2835-codec: dma alloc of size 4194304 failed
Jun 04 00:36:00 raspi kernel: ------------[ cut here ]------------
Jun 04 00:36:00 raspi kernel: Firmware transaction timeout
Jun 04 00:36:00 raspi kernel: WARNING: CPU: 3 PID: 329121 at drivers/firmware/raspberrypi.c:68 rpi_firmware_property_list+0x254/0x278
Jun 04 00:36:00 raspi kernel: Modules linked in: ntfs3 rfcomm snd_seq_dummy snd_hrtimer snd_seq cmac algif_hash aes_arm64 aes_generic algif_skcipher af_alg b>
Jun 04 00:36:00 raspi kernel: CPU: 3 PID: 329121 Comm: kworker/u12:2 Tainted: G        WC         6.6.31+rpt-rpi-v8 #1  Debian 1:6.6.31-1+rpt1
Jun 04 00:36:00 raspi kernel: Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
Jun 04 00:36:00 raspi kernel: Workqueue: events_unbound commit_work [drm_kms_helper]
Jun 04 00:36:00 raspi kernel: pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
Jun 04 00:36:00 raspi kernel: pc : rpi_firmware_property_list+0x254/0x278
Jun 04 00:36:00 raspi kernel: lr : rpi_firmware_property_list+0x254/0x278
Jun 04 00:36:00 raspi kernel: sp : ffffffc08c7e3b40
Jun 04 00:36:00 raspi kernel: x29: ffffffc08c7e3b40 x28: 0000000000000000 x27: ffffff804092bcc0
Jun 04 00:36:00 raspi kernel: x26: 000000000000000b x25: ffffffc08049e008 x24: 0000000000001000
Jun 04 00:36:00 raspi kernel: x23: ffffff806d225100 x22: ffffffe0d51caea0 x21: 0000000000000018
Jun 04 00:36:00 raspi kernel: x20: ffffff804092bc80 x19: ffffffc08049e000 x18: 0000000000000000
Jun 04 00:36:00 raspi kernel: x17: 0000000000000000 x16: 0000000000000000 x15: 0000000000000000
Jun 04 00:36:00 raspi kernel: x14: 0000000000000000 x13: 74756f656d697420 x12: 6e6f69746361736e
Jun 04 00:36:00 raspi kernel: x11: fffffffffffe0000 x10: ffffffe0d50a9c20 x9 : ffffffe0d3b09594
Jun 04 00:36:00 raspi kernel: x8 : 00000000ffffefff x7 : ffffffe0d50a3710 x6 : 0000000000000436
Jun 04 00:36:00 raspi kernel: x5 : ffffff80fb7cfd48 x4 : 0000000000000000 x3 : 0000000000000027
Jun 04 00:36:00 raspi kernel: x2 : 0000000000000000 x1 : 0000000000000000 x0 : ffffff806d141ec0
Jun 04 00:36:00 raspi kernel: Call trace:
Jun 04 00:36:00 raspi kernel:  rpi_firmware_property_list+0x254/0x278
Jun 04 00:36:00 raspi kernel:  rpi_firmware_property+0x78/0x120
Jun 04 00:36:00 raspi kernel:  raspberrypi_fw_get_rate+0x4c/0x88
Jun 04 00:36:00 raspi kernel:  clk_recalc+0x40/0xb8
Jun 04 00:36:00 raspi kernel:  __clk_recalc_rates+0x44/0xc0
Jun 04 00:36:00 raspi kernel:  clk_set_rate_range_nolock.part.0+0x1f8/0x2f0
Jun 04 00:36:00 raspi kernel:  clk_set_min_rate+0x4c/0x100
Jun 04 00:36:00 raspi kernel:  vc4_atomic_commit_tail+0x2d0/0x860 [vc4]
Jun 04 00:36:00 raspi kernel:  commit_tail+0xac/0x1a0 [drm_kms_helper]
Jun 04 00:36:00 raspi kernel:  commit_work+0x1c/0x30 [drm_kms_helper]
Jun 04 00:36:00 raspi kernel:  process_one_work+0x148/0x3b8
Jun 04 00:36:00 raspi kernel:  worker_thread+0x32c/0x450
Jun 04 00:36:00 raspi kernel:  kthread+0x11c/0x128
Jun 04 00:36:00 raspi kernel:  ret_from_fork+0x10/0x20
Jun 04 00:36:00 raspi kernel: ---[ end trace 0000000000000000 ]---
Jun 04 00:36:01 raspi kernel: raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-core frequency: -110
Jun 04 00:36:02 raspi kernel: bcm2835_mmal_vchiq: timed out waiting for sync completion
Jun 04 00:36:03 raspi kernel: hwmon hwmon1: Failed to get throttled (-110)

Jun 04 00:37:05 raspi kernel: bcm2835_mmal_vchiq: timed out waiting for sync completion
Jun 04 00:37:05 raspi kernel: bcm2835-codec bcm2835-codec: bcm2835_codec_stop_streaming: Failed disabling i/p port, ret -62
Jun 04 00:37:07 raspi kernel: bcm2835-codec bcm2835-codec: bcm2835_codec_flush_buffers: Timeout waiting for buffers to be returned - 4 outstanding
Jun 04 00:37:07 raspi kernel: ------------[ cut here ]------------
Jun 04 00:37:07 raspi kernel: WARNING: CPU: 1 PID: 352523 at drivers/media/common/videobuf2/videobuf2-core.c:2024 __vb2_queue_cancel+0x220/0x2a0 [videobuf2_c>
Jun 04 00:37:07 raspi kernel: Modules linked in: ntfs3 rfcomm snd_seq_dummy snd_hrtimer snd_seq cmac algif_hash aes_arm64 aes_generic algif_skcipher af_alg b>
Jun 04 00:37:07 raspi kernel: CPU: 1 PID: 352523 Comm: ThreadPoolSingl Tainted: G        WC         6.6.31+rpt-rpi-v8 #1  Debian 1:6.6.31-1+rpt1
Jun 04 00:37:07 raspi kernel: Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
Jun 04 00:37:07 raspi kernel: pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
Jun 04 00:37:07 raspi kernel: pc : __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
Jun 04 00:37:07 raspi kernel: lr : __vb2_queue_cancel+0x38/0x2a0 [videobuf2_common]
Jun 04 00:37:07 raspi kernel: sp : ffffffc082be3b00
Jun 04 00:37:07 raspi kernel: x29: ffffffc082be3b00 x28: ffffffe0b7204d38 x27: ffffffe0b6de80d0
Jun 04 00:37:07 raspi kernel: x26: 0000000000000000 x25: ffffff804365bd30 x24: ffffff805413f500
Jun 04 00:37:07 raspi kernel: x23: 0000000000000000 x22: ffffff8050e31298 x21: ffffff8050e31298
Jun 04 00:37:07 raspi kernel: x20: 000000000000000a x19: ffffff8050e31298 x18: ffffffffffffffff
Jun 04 00:37:07 raspi kernel: x17: 756f656d6954203a x16: ffffffe0d3cd4348 x15: 6873756c665f6365
Jun 04 00:37:07 raspi kernel: x14: 0000000000000004 x13: ffffff8044400028 x12: 0000000000000000
Jun 04 00:37:07 raspi kernel: x11: ffffff804688fe68 x10: ffffff804688fd98 x9 : ffffffe0d3d2baf8
Jun 04 00:37:07 raspi kernel: x8 : ffffffc082be3a00 x7 : 0000000000000000 x6 : ffffff800957f210
Jun 04 00:37:07 raspi kernel: x5 : ffffff8053c96780 x4 : fffffffe014f25a0 x3 : 0000000000150010
Jun 04 00:37:07 raspi kernel: x2 : 0000000000000000 x1 : 0000000000000000 x0 : 0000000000000004
Jun 04 00:37:07 raspi kernel: Call trace:
Jun 04 00:37:07 raspi kernel:  __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
Jun 04 00:37:07 raspi kernel:  vb2_core_streamoff+0x2c/0xd0 [videobuf2_common]
Jun 04 00:37:07 raspi kernel:  vb2_streamoff+0x20/0x78 [videobuf2_v4l2]
Jun 04 00:37:07 raspi kernel:  v4l2_m2m_streamoff+0x50/0x160 [v4l2_mem2mem]
Jun 04 00:37:07 raspi kernel:  v4l2_m2m_ioctl_streamoff+0x20/0x38 [v4l2_mem2mem]
Jun 04 00:37:07 raspi kernel:  v4l_streamoff+0x2c/0x40 [videodev]
Jun 04 00:37:07 raspi kernel:  __video_do_ioctl+0x170/0x3e0 [videodev]
Jun 04 00:37:07 raspi kernel:  video_usercopy+0x208/0x770 [videodev]
Jun 04 00:37:07 raspi kernel:  video_ioctl2+0x20/0x40 [videodev]
Jun 04 00:37:07 raspi kernel:  v4l2_ioctl+0x48/0x70 [videodev]
Jun 04 00:37:07 raspi kernel:  __arm64_sys_ioctl+0xb4/0x100
Jun 04 00:37:07 raspi kernel:  invoke_syscall+0x50/0x128
Jun 04 00:37:07 raspi kernel:  el0_svc_common.constprop.0+0x48/0xf0
Jun 04 00:37:07 raspi kernel:  do_el0_svc+0x24/0x38
Jun 04 00:37:07 raspi kernel:  el0_svc+0x40/0xe8
Jun 04 00:37:07 raspi kernel:  el0t_64_sync_handler+0x100/0x130
Jun 04 00:37:07 raspi kernel:  el0t_64_sync+0x190/0x198
Jun 04 00:37:07 raspi kernel: ---[ end trace 0000000000000000 ]---
Jun 04 00:37:07 raspi kernel: videobuf2_common: driver bug: stop_streaming operation is leaving buf 000000000b633818 in active state
Jun 04 00:37:07 raspi kernel: videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000501d46e6 in active state
Jun 04 00:37:07 raspi kernel: videobuf2_common: driver bug: stop_streaming operation is leaving buf 000000000832a854 in active state
Jun 04 00:37:07 raspi kernel: videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000fca022f5 in active state
Jun 04 00:37:10 raspi kernel: bcm2835_mmal_vchiq: timed out waiting for sync completion
Jun 04 00:37:10 raspi kernel: bcm2835-codec bcm2835-codec: bcm2835_codec_stop_streaming: Failed disabling i/p port, ret -62
Jun 04 00:37:12 raspi kernel: bcm2835-codec bcm2835-codec: bcm2835_codec_flush_buffers: Timeout waiting for buffers to be returned - 8 outstanding
Jun 04 00:37:12 raspi kernel: ------------[ cut here ]------------
Jun 04 00:37:12 raspi kernel: WARNING: CPU: 1 PID: 352512 at drivers/media/common/videobuf2/videobuf2-core.c:2024 __vb2_queue_cancel+0x220/0x2a0 [videobuf2_c>
Jun 04 00:37:12 raspi kernel: Modules linked in: ntfs3 rfcomm snd_seq_dummy snd_hrtimer snd_seq cmac algif_hash aes_arm64 aes_generic algif_skcipher af_alg b>
Jun 04 00:37:12 raspi kernel: CPU: 1 PID: 352512 Comm: ThreadPoolSingl Tainted: G        WC         6.6.31+rpt-rpi-v8 #1  Debian 1:6.6.31-1+rpt1
Jun 04 00:37:12 raspi kernel: Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
Jun 04 00:37:12 raspi kernel: pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
Jun 04 00:37:12 raspi kernel: pc : __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
Jun 04 00:37:12 raspi kernel: lr : __vb2_queue_cancel+0x38/0x2a0 [videobuf2_common]
Jun 04 00:37:12 raspi kernel: sp : ffffffc082b83b00
Jun 04 00:37:12 raspi kernel: x29: ffffffc082b83b00 x28: ffffffe0b7204d38 x27: ffffffe0b6de80d0
Jun 04 00:37:12 raspi kernel: x26: 0000000000000000 x25: ffffff804365bd30 x24: ffffff804b28af00
Jun 04 00:37:12 raspi kernel: x23: 0000000000000000 x22: ffffff8003e0a298 x21: ffffff8003e0a298
Jun 04 00:37:12 raspi kernel: x20: 000000000000000a x19: ffffff8003e0a298 x18: ffffffffffffffff
Jun 04 00:37:12 raspi kernel: x17: 756f656d6954203a x16: ffffffe0d3cd4348 x15: 6873756c665f6365
Jun 04 00:37:12 raspi kernel: x14: 0000000000000004 x13: ffffff8044400028 x12: 0000000000000000
Jun 04 00:37:12 raspi kernel: x11: ffffff800957ef70 x10: ffffff800957eda0 x9 : ffffffe0d3d2baf8
Jun 04 00:37:12 raspi kernel: x8 : ffffffc082b83a00 x7 : 0000000000000000 x6 : ffffff800957f210
Jun 04 00:37:12 raspi kernel: x5 : ffffff80be0ef900 x4 : fffffffe02f83be0 x3 : 0000000080150012
Jun 04 00:37:12 raspi kernel: x2 : 0000000000000000 x1 : 0000000000000000 x0 : 0000000000000008
Jun 04 00:37:12 raspi kernel: Call trace:
Jun 04 00:37:12 raspi kernel:  __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
Jun 04 00:37:12 raspi kernel:  vb2_core_streamoff+0x2c/0xd0 [videobuf2_common]
Jun 04 00:37:12 raspi kernel:  vb2_streamoff+0x20/0x78 [videobuf2_v4l2]
Jun 04 00:37:12 raspi kernel:  v4l2_m2m_streamoff+0x50/0x160 [v4l2_mem2mem]
Jun 04 00:37:12 raspi kernel:  v4l2_m2m_ioctl_streamoff+0x20/0x38 [v4l2_mem2mem]
Jun 04 00:37:12 raspi kernel:  v4l_streamoff+0x2c/0x40 [videodev]
Jun 04 00:37:12 raspi kernel:  __video_do_ioctl+0x170/0x3e0 [videodev]
Jun 04 00:37:12 raspi kernel:  video_usercopy+0x208/0x770 [videodev]
Jun 04 00:37:12 raspi kernel:  video_ioctl2+0x20/0x40 [videodev]
Jun 04 00:37:12 raspi kernel:  v4l2_ioctl+0x48/0x70 [videodev]
Jun 04 00:37:12 raspi kernel:  __arm64_sys_ioctl+0xb4/0x100
Jun 04 00:37:12 raspi kernel:  invoke_syscall+0x50/0x128
Jun 04 00:37:12 raspi kernel:  el0_svc_common.constprop.0+0x48/0xf0
Jun 04 00:37:12 raspi kernel:  do_el0_svc+0x24/0x38
Jun 04 00:37:12 raspi kernel:  el0_svc+0x40/0xe8
Jun 04 00:37:12 raspi kernel:  el0t_64_sync_handler+0x100/0x130
Jun 04 00:37:12 raspi kernel:  el0t_64_sync+0x190/0x198
Jun 04 00:37:12 raspi kernel: ---[ end trace 0000000000000000 ]---
Jun 04 00:37:12 raspi kernel: videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000461d2cdb in active state
Jun 04 00:37:12 raspi kernel: videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000ca36a5a0 in active state
Jun 04 00:37:12 raspi kernel: videobuf2_common: driver bug: stop_streaming operation is leaving buf 000000003812bf2a in active state
Jun 04 00:37:12 raspi kernel: videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000c4e7614c in active state
Jun 04 00:37:12 raspi kernel: videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000ae03b124 in active state
Jun 04 00:37:12 raspi kernel: videobuf2_common: driver bug: stop_streaming operation is leaving buf 000000000714e9dd in active state
Jun 04 00:37:12 raspi kernel: videobuf2_common: driver bug: stop_streaming operation is leaving buf 0000000007257184 in active state
Jun 04 00:37:12 raspi kernel: videobuf2_common: driver bug: stop_streaming operation is leaving buf 0000000055c319ce in active state
Jun 04 00:37:15 raspi kernel: bcm2835_mmal_vchiq: timed out waiting for sync completion
Jun 04 00:37:15 raspi kernel: bcm2835-codec bcm2835-codec: bcm2835_codec_stop_streaming: Failed disabling i/p port, ret -62
Jun 04 00:37:17 raspi kernel: bcm2835-codec bcm2835-codec: bcm2835_codec_flush_buffers: Timeout waiting for buffers to be returned - 8 outstanding
Jun 04 00:37:17 raspi kernel: ------------[ cut here ]------------
Jun 04 00:37:17 raspi kernel: WARNING: CPU: 1 PID: 352522 at drivers/media/common/videobuf2/videobuf2-core.c:2024 __vb2_queue_cancel+0x220/0x2a0 [videobuf2_c>
Jun 04 00:37:17 raspi kernel: Modules linked in: ntfs3 rfcomm snd_seq_dummy snd_hrtimer snd_seq cmac algif_hash aes_arm64 aes_generic algif_skcipher af_alg b>
Jun 04 00:37:17 raspi kernel: CPU: 1 PID: 352522 Comm: ThreadPoolSingl Tainted: G        WC         6.6.31+rpt-rpi-v8 #1  Debian 1:6.6.31-1+rpt1
Jun 04 00:37:17 raspi kernel: Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
Jun 04 00:37:17 raspi kernel: pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
Jun 04 00:37:17 raspi kernel: pc : __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
Jun 04 00:37:17 raspi kernel: lr : __vb2_queue_cancel+0x38/0x2a0 [videobuf2_common]
Jun 04 00:37:17 raspi kernel: sp : ffffffc082bdbb00
Jun 04 00:37:17 raspi kernel: x29: ffffffc082bdbb00 x28: ffffffe0b7204d38 x27: ffffffe0b6de80d0
Jun 04 00:37:17 raspi kernel: x26: 0000000000000000 x25: ffffff804365bd30 x24: ffffff8053c81300
Jun 04 00:37:17 raspi kernel: x23: 0000000000000000 x22: ffffff8006dd2a98 x21: ffffff8006dd2a98
Jun 04 00:37:17 raspi kernel: x20: 000000000000000a x19: ffffff8006dd2a98 x18: ffffffffffffffff
Jun 04 00:37:17 raspi kernel: x17: 756f656d6954203a x16: ffffffe0d3cd4348 x15: 6873756c665f6365
Jun 04 00:37:17 raspi kernel: x14: 0000000000000004 x13: ffffff8044400028 x12: 0000000000000000
Jun 04 00:37:17 raspi kernel: x11: ffffff804688fe60 x10: ffffff804688fd98 x9 : ffffffe0d3d2baf8
Jun 04 00:37:17 raspi kernel: x8 : ffffffc082bdba00 x7 : 0000000000000000 x6 : ffffff800957f210
Jun 04 00:37:17 raspi kernel: x5 : ffffff8053c96480 x4 : fffffffe014f25a0 x3 : 000000000015000f
Jun 04 00:37:17 raspi kernel: x2 : 0000000000000000 x1 : 0000000000000000 x0 : 0000000000000008
Jun 04 00:37:17 raspi kernel: Call trace:
Jun 04 00:37:17 raspi kernel:  __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
Jun 04 00:37:17 raspi kernel:  vb2_core_streamoff+0x2c/0xd0 [videobuf2_common]
Jun 04 00:37:17 raspi kernel:  vb2_streamoff+0x20/0x78 [videobuf2_v4l2]
Jun 04 00:37:17 raspi kernel:  v4l2_m2m_streamoff+0x50/0x160 [v4l2_mem2mem]
Jun 04 00:37:17 raspi kernel:  v4l2_m2m_ioctl_streamoff+0x20/0x38 [v4l2_mem2mem]
Jun 04 00:37:17 raspi kernel:  v4l_streamoff+0x2c/0x40 [videodev]
Jun 04 00:37:17 raspi kernel:  __video_do_ioctl+0x170/0x3e0 [videodev]
Jun 04 00:37:17 raspi kernel:  video_usercopy+0x208/0x770 [videodev]
Jun 04 00:37:17 raspi kernel:  video_ioctl2+0x20/0x40 [videodev]
Jun 04 00:37:17 raspi kernel:  v4l2_ioctl+0x48/0x70 [videodev]
Jun 04 00:37:17 raspi kernel:  __arm64_sys_ioctl+0xb4/0x100
Jun 04 00:37:17 raspi kernel:  invoke_syscall+0x50/0x128
Jun 04 00:37:17 raspi kernel:  el0_svc_common.constprop.0+0x48/0xf0
Jun 04 00:37:17 raspi kernel:  do_el0_svc+0x24/0x38
Jun 04 00:37:17 raspi kernel:  el0_svc+0x40/0xe8
Jun 04 00:37:17 raspi kernel:  el0t_64_sync_handler+0x100/0x130
Jun 04 00:37:17 raspi kernel:  el0t_64_sync+0x190/0x198
Jun 04 00:37:17 raspi kernel: ---[ end trace 0000000000000000 ]---
Jun 04 00:37:17 raspi kernel: videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000aca34737 in active state
Jun 04 00:37:17 raspi kernel: videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000ca242f59 in active state
Jun 04 00:37:17 raspi kernel: videobuf2_common: driver bug: stop_streaming operation is leaving buf 000000000436ee35 in active state
Jun 04 00:37:17 raspi kernel: videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000a644fa26 in active state
Jun 04 00:37:17 raspi kernel: videobuf2_common: driver bug: stop_streaming operation is leaving buf 000000007a822fab in active state
Jun 04 00:37:17 raspi kernel: videobuf2_common: driver bug: stop_streaming operation is leaving buf 000000004e3005f5 in active state
Jun 04 00:37:17 raspi kernel: videobuf2_common: driver bug: stop_streaming operation is leaving buf 000000007408ecf8 in active state
Jun 04 00:37:17 raspi kernel: videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000f91afb97 in active state
Jun 04 00:37:20 raspi kernel: bcm2835_mmal_vchiq: timed out waiting for sync completion

@popcornmix
Copy link
Collaborator

Are you viewing a web page with multiple videos on? What is the url?

@qrp73
Copy link
Author

qrp73 commented Jun 8, 2024

usually this is telegram site, sometimes youtube. Almost any channel has many videos on the page.
Note that I don't watching several videos simultaneously. I watch just one video at a time.
But the page contains many videos and the browser probably pre-load all of them.
For example: https://t.me/s/wildlifen

The issue happens again and again on a regular basis. But note, it don't happens immediately, it needs to spend some long time (at minimum several hours) to catch it. But in some rare cases I catch it immediately after reboot.

Very often unrecoverable Wayfire freeze happens when I open a new blank tab in the browser and clicking on close for old tab. At the moment of close tab click it leads to complete freeze. Usually there are just two tabs at that moment - new empty and old with loaded some page that I read before (it can happens for page with video, but sometimes it happens for usual page like stackoverflow.com, some technical forum, or just google.com)

The log consists a bunch of errors in drivers/media/common/videobuf2/videobuf2-core.c
vclog -m shows thousands of the same errors like

alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)

Usually these error messages appears after visiting web sites with video, but the system still works normally.
I suspect it may be due to overloading log buffer, because it consists too much the same errors in a loop (thousands or even hundreds of thousands of the same error message in a loop).

But after some time something happens and some kernel code stops to respond. First it leads to a frozen chormium-browser or firefox. I notice that at this time web sites which uses graphics (web games like slither.io and agar.io) can't be loaded and attempt to open it leads to a browser freeze with no way to close it in usual way. But my OpenGL app which uses a lot of OpenGL calls with textures still works ok. Force kill from system-monitor kills it, but attempt to start it again and open such page again leads to the same app freeze issue. Only system reboot can solve that state.

Then after some time Wayfire apparently freezes (current picture stops and don't update anymore), but the system may still respond on ssh connections. Attempt to kill and restart Wayfire don't have effect, it still shows the frozen picture with no changes.

At this point it is noticeable that ssh connection has some strange random long duration freezes even when I type command it may stop to give echo for several seconds.

And in short period after Wayfire freeze, entire system freezes and stops to respond even on ssh connections. At early stage of this state it just refuse ssh connections, but later just stops to respond at all.

Sometimes it leads to unrecoverable complete kernel freeze (with no way to connect through ssh) immediately after clicking on close tab in the browser, but sometimes the issue may going worse and worse step by step. When it happens step by step, attempt to force kill browser app which cause it don't help. The browser process is killed, but once it happens something in firmware code is broken at that point and if you restart the browser it will happens again.

Only manual sudo reboot or power off (when complete kernel freeze happens) can fix this state.

I even thinking about rollback to kernel 6.6.28, but unfortunately old kernel has some issue with video codec support and cannot play some video formats.

@qrp73
Copy link
Author

qrp73 commented Jun 9, 2024

just catch it again (complete freeze, but ssh still alive), here is the log:
dmesg:

[20187.913299] sd 0:0:0:0: [sda] Attached SCSI removable disk
[20188.395468] ntfs3: Max link count 4000
[22338.297672] vc4-drm gpu: swiotlb buffer is full (sz: 524288 bytes), total 32768 (slots), used 2354 (slots)
[22338.308075] vc4-drm gpu: swiotlb buffer is full (sz: 524288 bytes), total 32768 (slots), used 1020 (slots)
[22338.318831] vc4-drm gpu: swiotlb buffer is full (sz: 499712 bytes), total 32768 (slots), used 192 (slots)
[22338.753802] vc4-drm gpu: swiotlb buffer is full (sz: 524288 bytes), total 32768 (slots), used 2354 (slots)
[22338.896181] vc4-drm gpu: swiotlb buffer is full (sz: 524288 bytes), total 32768 (slots), used 1020 (slots)
[22338.945986] vc4-drm gpu: swiotlb buffer is full (sz: 499712 bytes), total 32768 (slots), used 192 (slots)
[22340.128838] vc4-drm gpu: swiotlb buffer is full (sz: 524288 bytes), total 32768 (slots), used 1462 (slots)
[22340.321078] vc4-drm gpu: swiotlb buffer is full (sz: 524288 bytes), total 32768 (slots), used 1462 (slots)
[24595.826238] cma: cma_alloc: linux,cma: alloc failed, req-size: 900 pages, ret: -16
[24595.826389] ThreadPoolSingl: page allocation failure: order:10, mode:0xcc1(GFP_KERNEL|GFP_DMA), nodemask=(null),cpuset=/,mems_allowed=0
[24595.826413] CPU: 0 PID: 59062 Comm: ThreadPoolSingl Tainted: G         C         6.6.31+rpt-rpi-v8 #1  Debian 1:6.6.31-1+rpt1
[24595.826419] Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
[24595.826422] Call trace:
[24595.826425]  dump_backtrace+0xa0/0x100
[24595.826435]  show_stack+0x20/0x38
[24595.826439]  dump_stack_lvl+0x48/0x60
[24595.826445]  dump_stack+0x18/0x28
[24595.826449]  warn_alloc+0x128/0x1b8
[24595.826454]  __alloc_pages+0xdc0/0xe68
[24595.826457]  __dma_direct_alloc_pages.constprop.0+0x15c/0x238
[24595.826462]  dma_direct_alloc+0x78/0x310
[24595.826465]  dma_alloc_attrs+0x8c/0x108
[24595.826471]  vb2_dc_alloc+0xa8/0x188 [videobuf2_dma_contig]
[24595.826485]  __vb2_queue_alloc+0x1cc/0x4a8 [videobuf2_common]
[24595.826505]  vb2_core_reqbufs+0x244/0x470 [videobuf2_common]
[24595.826518]  vb2_reqbufs+0x90/0xb8 [videobuf2_v4l2]
[24595.826532]  v4l2_m2m_ioctl_reqbufs+0x54/0x98 [v4l2_mem2mem]
[24595.826548]  v4l_reqbufs+0x58/0x78 [videodev]
[24595.826600]  __video_do_ioctl+0x170/0x3e0 [videodev]
[24595.826632]  video_usercopy+0x208/0x770 [videodev]
[24595.826663]  video_ioctl2+0x20/0x40 [videodev]
[24595.826693]  v4l2_ioctl+0x48/0x70 [videodev]
[24595.826724]  __arm64_sys_ioctl+0xb4/0x100
[24595.826733]  invoke_syscall+0x50/0x128
[24595.826738]  el0_svc_common.constprop.0+0x48/0xf0
[24595.826743]  do_el0_svc+0x24/0x38
[24595.826748]  el0_svc+0x40/0xe8
[24595.826754]  el0t_64_sync_handler+0x100/0x130
[24595.826759]  el0t_64_sync+0x190/0x198
[24595.826781] Mem-Info:
[24595.826784] active_anon:389361 inactive_anon:34871 isolated_anon:0
                active_file:181521 inactive_file:107326 isolated_file:0
                unevictable:68597 dirty:2652 writeback:0
                slab_reclaimable:18728 slab_unreclaimable:12868
                mapped:122242 shmem:94840 pagetables:6419
                sec_pagetables:0 bounce:0
                kernel_misc_reclaimable:0
                free:26355 free_pcp:195 free_cma:8178
[24595.826793] Node 0 active_anon:1557444kB inactive_anon:139484kB active_file:726084kB inactive_file:429304kB unevictable:274388kB isolated(anon):0kB isolated(file):0kB mapped:488968kB dirty:10608kB writeback:0kB shmem:379360kB writeback_tmp:0kB kernel_stack:11552kB pagetables:25676kB sec_pagetables:0kB all_unreclaimable? no
[24595.826800] DMA free:50260kB boost:0kB min:3660kB low:4572kB high:5484kB reserved_highatomic:0KB active_anon:217316kB inactive_anon:2480kB active_file:21984kB inactive_file:46672kB unevictable:57396kB writepending:7840kB present:950272kB managed:863628kB mlocked:72kB bounce:0kB free_pcp:780kB local_pcp:0kB free_cma:32712kB
[24595.826808] lowmem_reserve[]: 0 2928 2928 2928
[24595.826817] DMA: 305*4kB (UMEC) 137*8kB (UMEC) 32*16kB (UMEC) 39*32kB (UEC) 19*64kB (UEC) 16*128kB (UC) 28*256kB (UC) 16*512kB (C) 15*1024kB (UC) 6*2048kB (UC) 0*4096kB = 50348kB
[24595.826851] 383688 total pagecache pages
[24595.826853] 0 pages in swap cache
[24595.826855] Free swap  = 0kB
[24595.826856] Total swap = 0kB
[24595.826858] 1007616 pages RAM
[24595.826895] 0 pages HighMem/MovableOnly
[24595.826899] 41961 pages reserved
[24595.826901] 131072 pages cma reserved
[24595.826907] bcm2835-codec bcm2835-codec: dma alloc of size 3686400 failed
[24597.226913] ------------[ cut here ]------------
[24597.226925] Firmware transaction timeout
[24597.226959] WARNING: CPU: 2 PID: 58403 at drivers/firmware/raspberrypi.c:68 rpi_firmware_property_list+0x254/0x278
[24597.226977] Modules linked in: ntfs3 rfcomm snd_seq_dummy snd_hrtimer snd_seq cmac algif_hash aes_arm64 aes_generic algif_skcipher af_alg bnep brcmfmac_wcc hci_uart btbcm brcmfmac bluetooth brcmutil raspberrypi_hwmon binfmt_misc sg snd_usb_audio cfg80211 bcm2835_codec(C) rpivid_hevc(C) joydev bcm2835_isp(C) v4l2_mem2mem ecdh_generic ecc bcm2835_v4l2(C) bcm2835_mmal_vchiq(C) videobuf2_vmalloc videobuf2_dma_contig snd_hwdep videobuf2_memops rfkill libaes snd_usbmidi_lib videobuf2_v4l2 snd_rawmidi videodev raspberrypi_gpiomem snd_seq_device snd_bcm2835(C) videobuf2_common vc_sm_cma(C) mc nvmem_rmem uio_pdrv_genirq uio i2c_dev fuse dm_mod ip_tables x_tables ipv6 vc4 snd_soc_hdmi_codec drm_display_helper cec drm_dma_helper v3d gpu_sched drm_kms_helper drm_shmem_helper drm drm_panel_orientation_quirks i2c_brcmstb i2c_bcm2835 snd_soc_core snd_compress snd_pcm_dmaengine snd_pcm snd_timer snd backlight
[24597.227108] CPU: 2 PID: 58403 Comm: kworker/2:2 Tainted: G         C         6.6.31+rpt-rpi-v8 #1  Debian 1:6.6.31-1+rpt1
[24597.227114] Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
[24597.227118] Workqueue: events get_values_poll [raspberrypi_hwmon]
[24597.227131] pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
[24597.227135] pc : rpi_firmware_property_list+0x254/0x278
[24597.227139] lr : rpi_firmware_property_list+0x254/0x278
[24597.227142] sp : ffffffc082eebcb0
[24597.227144] x29: ffffffc082eebcb0 x28: 0000000000000000 x27: ffffff804092bcc0
[24597.227151] x26: 000000000000000e x25: ffffffc08049e008 x24: 0000000000001000
[24597.227158] x23: ffffff805284b200 x22: ffffffd91e5caea0 x21: 0000000000000010
[24597.227164] x20: ffffff804092bc80 x19: ffffffc08049e000 x18: 0000000000000000
[24597.227171] x17: 0000000000000000 x16: 0000000000000000 x15: 0000000000000000
[24597.227177] x14: 0000000000000000 x13: 74756f656d697420 x12: 6e6f69746361736e
[24597.227183] x11: fffffffffffe0000 x10: ffffffd91e4a7430 x9 : ffffffd91cf09594
[24597.227189] x8 : 00000000ffffefff x7 : ffffffd91e4a3710 x6 : 000000000000028c
[24597.227196] x5 : ffffff80fb7b1d48 x4 : 0000000000000000 x3 : 0000000000000027
[24597.227202] x2 : 0000000000000000 x1 : 0000000000000000 x0 : ffffff805f3f8000
[24597.227208] Call trace:
[24597.227212]  rpi_firmware_property_list+0x254/0x278
[24597.227215]  rpi_firmware_property+0x78/0x120
[24597.227219]  get_values_poll+0x54/0x120 [raspberrypi_hwmon]
[24597.227226]  process_one_work+0x148/0x3b8
[24597.227231]  worker_thread+0x32c/0x450
[24597.227234]  kthread+0x11c/0x128
[24597.227241]  ret_from_fork+0x10/0x20
[24597.227246] ---[ end trace 0000000000000000 ]---
[24597.227265] hwmon hwmon1: Failed to get throttled (-110)
[24599.178957] bcm2835_mmal_vchiq: timed out waiting for sync completion
[24599.178978] bcm2835-codec bcm2835-codec: bcm2835_codec_stop_streaming: Failed disabling i/p port, ret -62
[24600.298968] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-v3d frequency: -110
[24601.194957] bcm2835-codec bcm2835-codec: bcm2835_codec_flush_buffers: Timeout waiting for buffers to be returned - 1 outstanding
[24601.195035] ------------[ cut here ]------------
[24601.195038] WARNING: CPU: 2 PID: 59065 at drivers/media/common/videobuf2/videobuf2-core.c:2024 __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[24601.195067] Modules linked in: ntfs3 rfcomm snd_seq_dummy snd_hrtimer snd_seq cmac algif_hash aes_arm64 aes_generic algif_skcipher af_alg bnep brcmfmac_wcc hci_uart btbcm brcmfmac bluetooth brcmutil raspberrypi_hwmon binfmt_misc sg snd_usb_audio cfg80211 bcm2835_codec(C) rpivid_hevc(C) joydev bcm2835_isp(C) v4l2_mem2mem ecdh_generic ecc bcm2835_v4l2(C) bcm2835_mmal_vchiq(C) videobuf2_vmalloc videobuf2_dma_contig snd_hwdep videobuf2_memops rfkill libaes snd_usbmidi_lib videobuf2_v4l2 snd_rawmidi videodev raspberrypi_gpiomem snd_seq_device snd_bcm2835(C) videobuf2_common vc_sm_cma(C) mc nvmem_rmem uio_pdrv_genirq uio i2c_dev fuse dm_mod ip_tables x_tables ipv6 vc4 snd_soc_hdmi_codec drm_display_helper cec drm_dma_helper v3d gpu_sched drm_kms_helper drm_shmem_helper drm drm_panel_orientation_quirks i2c_brcmstb i2c_bcm2835 snd_soc_core snd_compress snd_pcm_dmaengine snd_pcm snd_timer snd backlight
[24601.195191] CPU: 2 PID: 59065 Comm: ThreadPoolSingl Tainted: G        WC         6.6.31+rpt-rpi-v8 #1  Debian 1:6.6.31-1+rpt1
[24601.195197] Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
[24601.195200] pstate: 80000005 (Nzcv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
[24601.195204] pc : __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[24601.195218] lr : __vb2_queue_cancel+0x38/0x2a0 [videobuf2_common]
[24601.195230] sp : ffffffc082b6bb00
[24601.195233] x29: ffffffc082b6bb00 x28: ffffffd8f52d0d38 x27: ffffffd8f52090d0
[24601.195240] x26: 0000000000000000 x25: ffffff80435e5530 x24: ffffff8035814f00
[24601.195246] x23: 0000000000000000 x22: ffffff8047f99298 x21: ffffff8047f99298
[24601.195253] x20: 000000000000000a x19: ffffff8047f99298 x18: ffffffffffffffff
[24601.195259] x17: 756f656d6954203a x16: ffffffd91d0d4348 x15: 6873756c665f6365
[24601.195265] x14: 0000000000000004 x13: ffffff8047440028 x12: 0000000000000000
[24601.195271] x11: ffffff808daab180 x10: ffffff808daaafe8 x9 : ffffffd91d12a754
[24601.195277] x8 : ffffffc082b6ba00 x7 : 0000000000000000 x6 : ffffff808daab458
[24601.195283] x5 : ffffff8003553300 x4 : fffffffe000d54e0 x3 : ffffffd91e0aaf48
[24601.195289] x2 : 0000000100000000 x1 : 0000000000000000 x0 : 0000000000000001
[24601.195296] Call trace:
[24601.195299]  __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[24601.195312]  vb2_core_streamoff+0x2c/0xd0 [videobuf2_common]
[24601.195325]  vb2_streamoff+0x20/0x78 [videobuf2_v4l2]
[24601.195338]  v4l2_m2m_streamoff+0x50/0x160 [v4l2_mem2mem]
[24601.195354]  v4l2_m2m_ioctl_streamoff+0x20/0x38 [v4l2_mem2mem]
[24601.195366]  v4l_streamoff+0x2c/0x40 [videodev]
[24601.195417]  __video_do_ioctl+0x170/0x3e0 [videodev]
[24601.195448]  video_usercopy+0x208/0x770 [videodev]
[24601.195479]  video_ioctl2+0x20/0x40 [videodev]
[24601.195509]  v4l2_ioctl+0x48/0x70 [videodev]
[24601.195540]  __arm64_sys_ioctl+0xb4/0x100
[24601.195551]  invoke_syscall+0x50/0x128
[24601.195557]  el0_svc_common.constprop.0+0x48/0xf0
[24601.195562]  do_el0_svc+0x24/0x38
[24601.195567]  el0_svc+0x40/0xe8
[24601.195573]  el0t_64_sync_handler+0x100/0x130
[24601.195577]  el0t_64_sync+0x190/0x198
[24601.195582] ---[ end trace 0000000000000000 ]---
[24601.195586] videobuf2_common: driver bug: stop_streaming operation is leaving buf 0000000049c934fb in active state
[24604.298989] bcm2835_mmal_vchiq: timed out waiting for sync completion
[24604.299008] bcm2835-codec bcm2835-codec: bcm2835_codec_stop_streaming: Failed disabling o/p port, ret -62
[24606.315032] bcm2835-codec bcm2835-codec: bcm2835_codec_flush_buffers: Timeout waiting for buffers to be returned - 1 outstanding
[24609.419056] bcm2835_mmal_vchiq: timed out waiting for sync completion
[24609.419074] bcm2835-codec bcm2835-codec: bcm2835_codec_stop_streaming: Failed enabling component, ret -62
[24609.419137] ------------[ cut here ]------------
[24609.419140] WARNING: CPU: 2 PID: 59065 at drivers/media/common/videobuf2/videobuf2-core.c:2024 __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[24609.419168] Modules linked in: ntfs3 rfcomm snd_seq_dummy snd_hrtimer snd_seq cmac algif_hash aes_arm64 aes_generic algif_skcipher af_alg bnep brcmfmac_wcc hci_uart btbcm brcmfmac bluetooth brcmutil raspberrypi_hwmon binfmt_misc sg snd_usb_audio cfg80211 bcm2835_codec(C) rpivid_hevc(C) joydev bcm2835_isp(C) v4l2_mem2mem ecdh_generic ecc bcm2835_v4l2(C) bcm2835_mmal_vchiq(C) videobuf2_vmalloc videobuf2_dma_contig snd_hwdep videobuf2_memops rfkill libaes snd_usbmidi_lib videobuf2_v4l2 snd_rawmidi videodev raspberrypi_gpiomem snd_seq_device snd_bcm2835(C) videobuf2_common vc_sm_cma(C) mc nvmem_rmem uio_pdrv_genirq uio i2c_dev fuse dm_mod ip_tables x_tables ipv6 vc4 snd_soc_hdmi_codec drm_display_helper cec drm_dma_helper v3d gpu_sched drm_kms_helper drm_shmem_helper drm drm_panel_orientation_quirks i2c_brcmstb i2c_bcm2835 snd_soc_core snd_compress snd_pcm_dmaengine snd_pcm snd_timer snd backlight
[24609.419292] CPU: 2 PID: 59065 Comm: ThreadPoolSingl Tainted: G        WC         6.6.31+rpt-rpi-v8 #1  Debian 1:6.6.31-1+rpt1
[24609.419299] Hardware name: Raspberry Pi 4 Model B Rev 1.5 (DT)
[24609.419302] pstate: 80000005 (Nzcv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
[24609.419306] pc : __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[24609.419320] lr : __vb2_queue_cancel+0x38/0x2a0 [videobuf2_common]
[24609.419332] sp : ffffffc082b6bb00
[24609.419335] x29: ffffffc082b6bb00 x28: ffffffd8f52d0d38 x27: ffffffd8f52090d0
[24609.419342] x26: 0000000000000000 x25: ffffff80435e5530 x24: ffffff8035814f00
[24609.419348] x23: 0000000000000000 x22: ffffff8047f99028 x21: ffffff8047f99028
[24609.419354] x20: 0000000000000009 x19: ffffff8047f99028 x18: 00000000fffffffe
[24609.419360] x17: 656c696146203a67 x16: 6e696d6165727473 x15: 5f706f74735f6365
[24609.419367] x14: 646f635f35333832 x13: 32362d2074657220 x12: 2c746e656e6f706d
[24609.419373] x11: 6f6320676e696c62 x10: ffffffd91e4a3710 x9 : ffffffd91cf09594
[24609.419379] x8 : 00000000ffffefff x7 : ffffffd91e4a3710 x6 : 80000000fffff000
[24609.419385] x5 : ffffff80fb7b1d48 x4 : 0000000000000000 x3 : 0000000000000000
[24609.419391] x2 : 0000000000000000 x1 : 0000000000000000 x0 : 0000000000000001
[24609.419398] Call trace:
[24609.419400]  __vb2_queue_cancel+0x220/0x2a0 [videobuf2_common]
[24609.419414]  vb2_core_streamoff+0x2c/0xd0 [videobuf2_common]
[24609.419427]  vb2_streamoff+0x20/0x78 [videobuf2_v4l2]
[24609.419440]  v4l2_m2m_streamoff+0x80/0x160 [v4l2_mem2mem]
[24609.419457]  v4l2_m2m_ioctl_streamoff+0x20/0x38 [v4l2_mem2mem]
[24609.419469]  v4l_streamoff+0x2c/0x40 [videodev]
[24609.419520]  __video_do_ioctl+0x170/0x3e0 [videodev]
[24609.419551]  video_usercopy+0x208/0x770 [videodev]
[24609.419581]  video_ioctl2+0x20/0x40 [videodev]
[24609.419612]  v4l2_ioctl+0x48/0x70 [videodev]
[24609.419643]  __arm64_sys_ioctl+0xb4/0x100
[24609.419654]  invoke_syscall+0x50/0x128
[24609.419661]  el0_svc_common.constprop.0+0x48/0xf0
[24609.419666]  do_el0_svc+0x24/0x38
[24609.419671]  el0_svc+0x40/0xe8
[24609.419677]  el0t_64_sync_handler+0x100/0x130
[24609.419681]  el0t_64_sync+0x190/0x198
[24609.419686] ---[ end trace 0000000000000000 ]---
[24609.419689] videobuf2_common: driver bug: stop_streaming operation is leaving buf 00000000446d96e2 in active state
[24612.491094] bcm2835_mmal_vchiq: timed out waiting for sync completion
[24615.563129] bcm2835_mmal_vchiq: timed out waiting for sync completion
[24771.981142] INFO: task wayfire:995 blocked for more than 120 seconds.
[24771.981161]       Tainted: G        WC         6.6.31+rpt-rpi-v8 #1 Debian 1:6.6.31-1+rpt1
[24771.981165] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[24771.981167] task:wayfire         state:D stack:0     pid:995   ppid:971    flags:0x00000004
[24771.981177] Call trace:
[24771.981179]  __switch_to+0xe8/0x168
[24771.981190]  __schedule+0x37c/0xd60
[24771.981194]  schedule+0x64/0x108
[24771.981197]  schedule_preempt_disabled+0x2c/0x50
[24771.981201]  __mutex_lock.constprop.0+0x2ac/0x608
[24771.981205]  __mutex_lock_slowpath+0x1c/0x30
[24771.981209]  mutex_lock+0x50/0x68
[24771.981212]  v3d_clock_up_get+0x28/0xa0 [v3d]
[24771.981235]  v3d_job_init.constprop.0+0xe0/0x268 [v3d]
[24771.981248]  v3d_submit_cl_ioctl+0xb0/0x780 [v3d]
[24771.981260]  drm_ioctl_kernel+0xd8/0x190 [drm]
[24771.981402]  drm_ioctl+0x220/0x4c0 [drm]
[24771.981472]  __arm64_sys_ioctl+0xb4/0x100
[24771.981482]  invoke_syscall+0x50/0x128
[24771.981489]  el0_svc_common.constprop.0+0x48/0xf0
[24771.981494]  do_el0_svc+0x24/0x38
[24771.981499]  el0_svc+0x40/0xe8
[24771.981505]  el0t_64_sync_handler+0x100/0x130
[24771.981510]  el0t_64_sync+0x190/0x198
[24771.981606] INFO: task chromium-browse:54238 blocked for more than 120 seconds.
[24771.981610]       Tainted: G        WC         6.6.31+rpt-rpi-v8 #1 Debian 1:6.6.31-1+rpt1
[24771.981612] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[24771.981614] task:chromium-browse state:D stack:0     pid:54238 ppid:54202  flags:0x00000005
[24771.981620] Call trace:
[24771.981622]  __switch_to+0xe8/0x168
[24771.981625]  __schedule+0x37c/0xd60
[24771.981629]  schedule+0x64/0x108
[24771.981632]  schedule_timeout+0x1a0/0x1b8
[24771.981636]  wait_for_completion+0xc0/0x168
[24771.981639]  __flush_work.isra.0+0x18c/0x2d8
[24771.981646]  __cancel_work_timer+0x11c/0x1a8
[24771.981649]  cancel_delayed_work_sync+0x1c/0x30
[24771.981652]  v3d_clock_up_get+0x58/0xa0 [v3d]
[24771.981666]  v3d_job_init.constprop.0+0xe0/0x268 [v3d]
[24771.981678]  v3d_submit_cl_ioctl+0xb0/0x780 [v3d]
[24771.981689]  drm_ioctl_kernel+0xd8/0x190 [drm]
[24771.981766]  drm_ioctl+0x220/0x4c0 [drm]
[24771.981835]  __arm64_sys_ioctl+0xb4/0x100
[24771.981841]  invoke_syscall+0x50/0x128
[24771.981846]  el0_svc_common.constprop.0+0x48/0xf0
[24771.981851]  do_el0_svc+0x24/0x38
[24771.981856]  el0_svc+0x40/0xe8
[24771.981861]  el0t_64_sync_handler+0x100/0x130
[24771.981865]  el0t_64_sync+0x190/0x198
[24771.981877] INFO: task kworker/u12:1:55676 blocked for more than 120 seconds.
[24771.981880]       Tainted: G        WC         6.6.31+rpt-rpi-v8 #1 Debian 1:6.6.31-1+rpt1
[24771.981883] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[24771.981885] task:kworker/u12:1   state:D stack:0     pid:55676 ppid:2      flags:0x00000008
[24771.981892] Workqueue: events_unbound commit_work [drm_kms_helper]
[24771.981950] Call trace:
[24771.981952]  __switch_to+0xe8/0x168
[24771.981956]  __schedule+0x37c/0xd60
[24771.981959]  schedule+0x64/0x108
[24771.981962]  schedule_preempt_disabled+0x2c/0x50
[24771.981966]  __mutex_lock.constprop.0+0x2ac/0x608
[24771.981969]  __mutex_lock_slowpath+0x1c/0x30
[24771.981973]  mutex_lock+0x50/0x68
[24771.981976]  clk_prepare_lock+0x4c/0xb0
[24771.981982]  clk_set_min_rate+0x3c/0x100
[24771.981988]  vc4_atomic_commit_tail+0x2d0/0x860 [vc4]
[24771.982019]  commit_tail+0xac/0x1a0 [drm_kms_helper]
[24771.982052]  commit_work+0x1c/0x30 [drm_kms_helper]
[24771.982084]  process_one_work+0x148/0x3b8
[24771.982087]  worker_thread+0x32c/0x450
[24771.982091]  kthread+0x11c/0x128
[24771.982096]  ret_from_fork+0x10/0x20
[24771.982102] INFO: task kworker/3:2:55783 blocked for more than 120 seconds.
[24771.982104]       Tainted: G        WC         6.6.31+rpt-rpi-v8 #1 Debian 1:6.6.31-1+rpt1
[24771.982107] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[24771.982109] task:kworker/3:2     state:D stack:0     pid:55783 ppid:2      flags:0x00000008
[24771.982115] Workqueue: events dbs_work_handler
[24771.982122] Call trace:
[24771.982124]  __switch_to+0xe8/0x168
[24771.982127]  __schedule+0x37c/0xd60
[24771.982130]  schedule+0x64/0x108
[24771.982133]  schedule_timeout+0xa4/0x1b8
[24771.982137]  wait_for_completion_timeout+0x7c/0x158
[24771.982141]  mbox_send_message+0xf8/0x140
[24771.982145]  rpi_firmware_property_list+0xf8/0x278
[24771.982149]  rpi_firmware_property+0x78/0x120
[24771.982152]  raspberrypi_fw_set_rate+0x5c/0xe8
[24771.982158]  clk_change_rate+0xe0/0x518
[24771.982163]  clk_core_set_rate_nolock+0x17c/0x2d0
[24771.982169]  clk_set_rate+0x40/0x190
[24771.982174]  _opp_config_clk_single+0x38/0xb8
[24771.982179]  _set_opp+0x160/0x410
[24771.982184]  dev_pm_opp_set_rate+0x190/0x290
[24771.982188]  set_target+0x38/0x50
[24771.982193]  __cpufreq_driver_target+0x2ac/0x6d8
[24771.982196]  od_dbs_update+0xc4/0x1c0
[24771.982200]  dbs_work_handler+0x48/0x90
[24771.982204]  process_one_work+0x148/0x3b8
[24771.982208]  worker_thread+0x32c/0x450
[24771.982211]  kthread+0x11c/0x128
[24771.982216]  ret_from_fork+0x10/0x20
[24771.982223] INFO: task kworker/2:2:58403 blocked for more than 120 seconds.
[24771.982225]       Tainted: G        WC         6.6.31+rpt-rpi-v8 #1 Debian 1:6.6.31-1+rpt1
[24771.982228] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[24771.982230] task:kworker/2:2     state:D stack:0     pid:58403 ppid:2      flags:0x00000008
[24771.982235] Workqueue: events v3d_clock_down_work [v3d]
[24771.982250] Call trace:
[24771.982252]  __switch_to+0xe8/0x168
[24771.982256]  __schedule+0x37c/0xd60
[24771.982259]  schedule+0x64/0x108
[24771.982262]  schedule_preempt_disabled+0x2c/0x50
[24771.982265]  __mutex_lock.constprop.0+0x2ac/0x608
[24771.982269]  __mutex_lock_slowpath+0x1c/0x30
[24771.982273]  mutex_lock+0x50/0x68
[24771.982276]  clk_prepare_lock+0x4c/0xb0
[24771.982280]  clk_set_min_rate+0x3c/0x100
[24771.982285]  v3d_clock_down_work+0x28/0x60 [v3d]
[24771.982296]  process_one_work+0x148/0x3b8
[24771.982300]  worker_thread+0x32c/0x450
[24771.982303]  kthread+0x11c/0x128
[24771.982308]  ret_from_fork+0x10/0x20
[24771.982314] INFO: task kworker/2:1:58884 blocked for more than 120 seconds.
[24771.982316]       Tainted: G        WC         6.6.31+rpt-rpi-v8 #1 Debian 1:6.6.31-1+rpt1
[24771.982319] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[24771.982321] task:kworker/2:1     state:D stack:0     pid:58884 ppid:2      flags:0x00000008
[24771.982326] Workqueue: events get_values_poll [raspberrypi_hwmon]
[24771.982335] Call trace:
[24771.982337]  __switch_to+0xe8/0x168
[24771.982340]  __schedule+0x37c/0xd60
[24771.982343]  schedule+0x64/0x108
[24771.982346]  schedule_preempt_disabled+0x2c/0x50
[24771.982350]  __mutex_lock.constprop.0+0x2ac/0x608
[24771.982353]  __mutex_lock_slowpath+0x1c/0x30
[24771.982356]  mutex_lock+0x50/0x68
[24771.982360]  rpi_firmware_property_list+0xe8/0x278
[24771.982363]  rpi_firmware_property+0x78/0x120
[24771.982366]  get_values_poll+0x54/0x120 [raspberrypi_hwmon]
[24771.982373]  process_one_work+0x148/0x3b8
[24771.982376]  worker_thread+0x32c/0x450
[24771.982379]  kthread+0x11c/0x128
[24771.982384]  ret_from_fork+0x10/0x20
[24771.982393] INFO: task vcgencmd:59089 blocked for more than 120 seconds.
[24771.982396]       Tainted: G        WC         6.6.31+rpt-rpi-v8 #1 Debian 1:6.6.31-1+rpt1
[24771.982398] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[24771.982399] task:vcgencmd        state:D stack:0     pid:59089 ppid:59088  flags:0x0000000c
[24771.982404] Call trace:
[24771.982405]  __switch_to+0xe8/0x168
[24771.982409]  __schedule+0x37c/0xd60
[24771.982411]  schedule+0x64/0x108
[24771.982414]  schedule_preempt_disabled+0x2c/0x50
[24771.982417]  __mutex_lock.constprop.0+0x2ac/0x608
[24771.982421]  __mutex_lock_slowpath+0x1c/0x30
[24771.982424]  mutex_lock+0x50/0x68
[24771.982428]  rpi_firmware_property_list+0xe8/0x278
[24771.982430]  vcio_user_property_list+0xd8/0x210
[24771.982435]  vcio_device_ioctl+0x34/0x58
[24771.982438]  __arm64_sys_ioctl+0xb4/0x100
[24771.982443]  invoke_syscall+0x50/0x128
[24771.982448]  el0_svc_common.constprop.0+0x48/0xf0
[24771.982453]  do_el0_svc+0x24/0x38
[24771.982458]  el0_svc+0x40/0xe8
[24771.982462]  el0t_64_sync_handler+0x100/0x130
[24771.982467]  el0t_64_sync+0x190/0x198

vclog:

...
3136549.278: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
3136549.303: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
3136549.333: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
3136549.382: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
3136569.688: video_decode:50:RIL: resolution changing
3136578.886: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
3136578.920: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
3136578.959: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
3136578.991: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
3136579.053: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
3136579.109: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
3136601.746: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
3136601.830: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
3136602.362: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
3136602.432: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
3136602.957: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
3136603.028: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
3136618.757: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
3136618.794: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
3136619.022: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
3136619.055: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
3136619.260: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
3136619.293: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
3136638.762: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
3136638.800: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
3136639.019: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
3136639.053: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
3136639.265: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
3136639.299: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
3136658.760: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
3136658.800: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
3136659.049: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
3136659.082: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
3136659.317: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
3136659.354: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
3136678.738: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
3136678.779: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
3136679.009: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
3136679.044: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
3136679.267: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
3136679.301: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
3136804.986: smservice: sm_remove_resource: failed to find resource (0) in resource list
3136805.009: smservice: sm_remove_resource: failed to find resource (0) in resource list
3136805.026: smservice: sm_remove_resource: failed to find resource (0) in resource list
3136805.048: smservice: sm_remove_resource: failed to find resource (0) in resource list
3136805.065: smservice: sm_remove_resource: failed to find resource (0) in resource list
3136805.086: smservice: sm_remove_resource: failed to find resource (0) in resource list
3136805.104: smservice: sm_remove_resource: failed to find resource (0) in resource list
3136805.126: smservice: sm_remove_resource: failed to find resource (0) in resource list
3136805.147: smservice: sm_remove_resource: failed to find resource (0) in resource list
3136805.167: smservice: sm_remove_resource: failed to find resource (0) in resource list
3136805.185: smservice: sm_remove_resource: failed to find resource (0) in resource list
3136805.206: smservice: sm_remove_resource: failed to find resource (0) in resource list
3136805.225: smservice: sm_remove_resource: failed to find resource (0) in resource list
3136805.247: smservice: sm_remove_resource: failed to find resource (0) in resource list
3136805.264: smservice: sm_remove_resource: failed to find resource (0) in resource list
3136805.286: smservice: sm_remove_resource: failed to find resource (0) in resource list
3136805.306: smservice: sm_remove_resource: failed to find resource (0) in resource list

@qrp73
Copy link
Author

qrp73 commented Jun 10, 2024

The same report from other user: https://forums.raspberrypi.com/viewtopic.php?t=372078

@qrp73
Copy link
Author

qrp73 commented Jul 23, 2024

Since there is kernel 6.6.32-v8+ and issue is not reproduced for a long time, the issue is not relevant anymore and I will close it.

@qrp73 qrp73 closed this as completed Jul 23, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants