User avatar
jbeale
Posts: 3884
Joined: Tue Nov 22, 2011 11:51 pm
Contact: Website

lockup on 4b : Firmware transaction timeout ?

Thu May 27, 2021 9:16 pm

I am running Linux rp49 5.10.17-v7l+ #1403 SMP Mon Feb 22 11:33:35 GMT 2021 armv7l GNU/Linux
on a Pi4b (4 GB) and the system is running from an external SSD, with no SD card. It has worked without trouble for many months.

Recently when I am using the Chromium browser (Facebook, etc) it will sometimes lock up, by which I mean the mouse freezes and I can't do anything on the screen. However, I can still login to it from another computer via ssh and see what 'dmesg' reports, and I copy the end of that report below. I don't know what "Firmware transaction timeout" means, or what causes "INFO: task Xorg:579 blocked for more than 245 seconds" but I'd like to know how to fix this problem. I've been using this as my main computer for many months now and this only started happening recently, after I did an update/upgrade.

Note: right now, I have these lines in my /boot/config.txt file:

Code: Select all

# Enable DRM VC4 V3D driver on top of the dispmanx display stack
dtoverlay=vc4-fkms-v3d
max_framebuffers=2
I have found I can avoid this lockup problem if I comment out those two lines, but that also causes any video in the browser to play very, very slowly, and the only way to get normal video is playing a local file with mplayer.

Anyone know how to fix this?

Code: Select all

[187478.208656] bcm2835-codec bcm2835-codec: bcm2835_codec_buf_prepare data will not fit into plane (1536 < 556800)
[187478.211020] bcm2835-codec bcm2835-codec: bcm2835_codec_buf_prepare data will not fit into plane (1536 < 556800)
[187478.213594] bcm2835-codec bcm2835-codec: bcm2835_codec_buf_prepare data will not fit into plane (1536 < 556800)
[187546.425981] ------------[ cut here ]------------
[187546.426014] WARNING: CPU: 1 PID: 30393 at drivers/firmware/raspberrypi.c:64 rpi_firmware_transaction+0xec/0x128
[187546.426026] Firmware transaction timeout
[187546.426037] Modules linked in: snd_seq_dummy snd_seq rtl8192cu rtl_usb rtl8192c_common rtlwifi mac80211 libarc4 rfcomm bnep hci_uart btbcm bluetooth ecdh_generic ecc fuse 8021q garp stp llc mct_u232 cdc_acm usbserial sg rpivid_mem brcmfmac brcmutil v3d gpu_sched vc4 sha256_generic cec drm_kms_helper cfg80211 raspberrypi_hwmon rfkill i2c_bcm2835 bcm2835_codec(C) bcm2835_isp(C) bcm2835_v4l2(C) v4l2_mem2mem bcm2835_mmal_vchiq(C) videobuf2_dma_contig drm videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_common vc_sm_cma(C) snd_bcm2835(C) videodev drm_panel_orientation_quirks snd_usb_audio snd_hwdep snd_usbmidi_lib snd_soc_core snd_rawmidi snd_compress snd_seq_device mc snd_pcm_dmaengine snd_pcm snd_timer snd syscopyarea sysfillrect sysimgblt fb_sys_fops backlight nvmem_rmem uio_pdrv_genirq uio i2c_dev ip_tables x_tables ipv6
[187546.426841] CPU: 1 PID: 30393 Comm: kworker/1:1 Tainted: G        WC        5.10.17-v7l+ #1403
[187546.426849] Hardware name: BCM2711
[187546.426864] Workqueue: events dbs_work_handler
[187546.426877] Backtrace:
[187546.426901] [<c0b63050>] (dump_backtrace) from [<c0b633e4>] (show_stack+0x20/0x24)
[187546.426913]  r7:ffffffff r6:00000000 r5:60000013 r4:c12e69fc
[187546.426927] [<c0b633c4>] (show_stack) from [<c0b67774>] (dump_stack+0xcc/0xf8)
[187546.426942] [<c0b676a8>] (dump_stack) from [<c0220bac>] (__warn+0xfc/0x114)
[187546.426954]  r10:dec19008 r9:00000009 r8:c099d5b8 r7:00000040 r6:00000009 r5:c099d5b8
[187546.426962]  r4:c0e9abc8 r3:c1205094
[187546.426975] [<c0220ab0>] (__warn) from [<c0b63b88>] (warn_slowpath_fmt+0xa4/0xd8)
[187546.426984]  r7:00000040 r6:c0e9abc8 r5:c1205048 r4:c0e9abe8
[187546.427000] [<c0b63ae8>] (warn_slowpath_fmt) from [<c099d5b8>] (rpi_firmware_transaction+0xec/0x128)
[187546.427010]  r9:c1a94740 r8:00000018 r7:00000000 r6:ffffff92 r5:c1a94740 r4:c1205048
[187546.427024] [<c099d4cc>] (rpi_firmware_transaction) from [<c099d6b0>] (rpi_firmware_property_list+0xbc/0x170)
[187546.427034]  r7:c1205048 r6:dec19000 r5:00001000 r4:dec19024
[187546.427047] [<c099d5f4>] (rpi_firmware_property_list) from [<c099d7d4>] (rpi_firmware_property+0x70/0x118)
[187546.427058]  r10:cff8d70c r9:00030002 r8:00000018 r7:c1a94740 r6:ceb8bd48 r5:0000000c
[187546.427065]  r4:cff8d700
[187546.427080] [<c099d764>] (rpi_firmware_property) from [<c07e4e54>] (raspberrypi_clock_property+0x54/0x7c)
[187546.427090]  r10:00000000 r9:00000000 r8:c22baf80 r7:00000000 r6:2faf0800 r5:ceb8bd70
[187546.427098]  r4:c1205048 r3:0000000c
[187546.427109] [<c07e4e00>] (raspberrypi_clock_property) from [<c07e4ec8>] (raspberrypi_fw_get_rate+0x4c/0x70)
[187546.427117]  r5:00000000 r4:c1205048
[187546.427129] [<c07e4e7c>] (raspberrypi_fw_get_rate) from [<c07db7d4>] (clk_recalc+0x44/0x84)
[187546.427137]  r4:c1b79900
[187546.427148] [<c07db790>] (clk_recalc) from [<c07dbac4>] (__clk_recalc_rates+0x30/0x94)
[187546.427156]  r5:00000000 r4:c1b79900
[187546.427168] [<c07dba94>] (__clk_recalc_rates) from [<c07dbb80>] (clk_core_get_rate_recalc+0x58/0x5c)
[187546.427177]  r7:00000000 r6:c1205048 r5:59682f00 r4:c1b79900
[187546.427188] [<c07dbb28>] (clk_core_get_rate_recalc) from [<c07dbbac>] (clk_get_rate+0x28/0x38)
[187546.427197]  r5:59682f00 r4:c22baf80
[187546.427208] [<c07dbb84>] (clk_get_rate) from [<c0968a10>] (dev_pm_opp_set_rate+0x70/0x588)
[187546.427216]  r5:59682f00 r4:c22cd200
[187546.427229] [<c09689a0>] (dev_pm_opp_set_rate) from [<c0973900>] (set_target+0x38/0x3c)
[187546.427239]  r10:00000000 r9:00000000 r8:00000009 r7:00000000 r6:c1404e44 r5:c1205048
[187546.427246]  r4:c22cd400
[187546.427260] [<c09738c8>] (set_target) from [<c096e604>] (__cpufreq_driver_target+0x1bc/0x540)
[187546.427274] [<c096e448>] (__cpufreq_driver_target) from [<c0971a1c>] (od_dbs_update+0x14c/0x170)
[187546.427284]  r10:00000000 r9:c3c16e00 r8:c458e180 r7:c458e180 r6:c3c16e00 r5:c3c16b00
[187546.427291]  r4:c22cd400
[187546.427305] [<c09718d0>] (od_dbs_update) from [<c0972bf8>] (dbs_work_handler+0x3c/0x64)
[187546.427315]  r9:00000000 r8:c131beac r7:c22cd400 r6:c3c16b04 r5:00000000 r4:c3c16b38
[187546.427330] [<c0972bbc>] (dbs_work_handler) from [<c023dc18>] (process_one_work+0x250/0x5a0)
[187546.427340]  r9:00000000 r8:00000040 r7:eff29900 r6:eff26640 r5:cecd4780 r4:c3c16b38
[187546.427353] [<c023d9c8>] (process_one_work) from [<c023dfc8>] (worker_thread+0x60/0x5c4)
[187546.427364]  r10:eff26640 r9:c1203d00 r8:eff26658 r7:00000008 r6:eff26640 r5:cecd4794
[187546.427371]  r4:cecd4780
[187546.427385] [<c023df68>] (worker_thread) from [<c0245a50>] (kthread+0x170/0x174)
[187546.427395]  r10:c4541e74 r9:cecd4780 r8:c023df68 r7:ceb8a000 r6:00000000 r5:c91ddfc0
[187546.427402]  r4:c320a300
[187546.427415] [<c02458e0>] (kthread) from [<c02000ec>] (ret_from_fork+0x14/0x28)
[187546.427423] Exception stack(0xceb8bfb0 to 0xceb8bff8)
[187546.427432] bfa0:                                     00000000 00000000 00000000 00000000
[187546.427442] bfc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[187546.427452] bfe0: 00000000 00000000 00000000 00000000 00000013 00000000
[187546.427463]  r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c02458e0
[187546.427470]  r4:c91ddfc0
[187546.427479] ---[ end trace 55520c408cfd8f64 ]---
[187546.427516] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967186 (-34)
[187547.466033] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -110
[187548.426029] bcm2835_mmal_vchiq: timed out waiting for sync completion
[187548.426050] bcm2835-codec bcm2835-codec: bcm2835_codec_start_streaming: Failed enabling o/p port, ret -62
[187548.426063] ------------[ cut here ]------------
[187548.426104] WARNING: CPU: 0 PID: 31231 at drivers/media/common/videobuf2/videobuf2-core.c:1548 vb2_start_streaming+0x108/0x178 [videobuf2_common]
[187548.426116] Modules linked in: snd_seq_dummy snd_seq rtl8192cu rtl_usb rtl8192c_common rtlwifi mac80211 libarc4 rfcomm bnep hci_uart btbcm bluetooth ecdh_generic ecc fuse 8021q garp stp llc mct_u232 cdc_acm usbserial sg rpivid_mem brcmfmac brcmutil v3d gpu_sched vc4 sha256_generic cec drm_kms_helper cfg80211 raspberrypi_hwmon rfkill i2c_bcm2835 bcm2835_codec(C) bcm2835_isp(C) bcm2835_v4l2(C) v4l2_mem2mem bcm2835_mmal_vchiq(C) videobuf2_dma_contig drm videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_common vc_sm_cma(C) snd_bcm2835(C) videodev drm_panel_orientation_quirks snd_usb_audio snd_hwdep snd_usbmidi_lib snd_soc_core snd_rawmidi snd_compress snd_seq_device mc snd_pcm_dmaengine snd_pcm snd_timer snd syscopyarea sysfillrect sysimgblt fb_sys_fops backlight nvmem_rmem uio_pdrv_genirq uio i2c_dev ip_tables x_tables ipv6
[187548.426913] CPU: 0 PID: 31231 Comm: V4L2DecoderThre Tainted: G        WC        5.10.17-v7l+ #1403
[187548.426921] Hardware name: BCM2711
[187548.426928] Backtrace:
[187548.426958] [<c0b63050>] (dump_backtrace) from [<c0b633e4>] (show_stack+0x20/0x24)
[187548.426970]  r7:ffffffff r6:00000000 r5:60000013 r4:c12e69fc
[187548.426985] [<c0b633c4>] (show_stack) from [<c0b67774>] (dump_stack+0xcc/0xf8)
[187548.427000] [<c0b676a8>] (dump_stack) from [<c0220bac>] (__warn+0xfc/0x114)
[187548.427011]  r10:bf2c48dc r9:00000009 r8:bf30c1ec r7:0000060c r6:00000009 r5:bf30c1ec
[187548.427020]  r4:bf310f90 r3:c1205094
[187548.427033] [<c0220ab0>] (__warn) from [<c0b63b54>] (warn_slowpath_fmt+0x70/0xd8)
[187548.427042]  r7:0000060c r6:bf310f90 r5:c1205048 r4:00000000
[187548.427071] [<c0b63ae8>] (warn_slowpath_fmt) from [<bf30c1ec>] (vb2_start_streaming+0x108/0x178 [videobuf2_common])
[187548.427081]  r9:bf20a068 r8:c30ccbe0 r7:00000001 r6:c66cc014 r5:c66cc114 r4:ffffffc2
[187548.427119] [<bf30c0e4>] (vb2_start_streaming [videobuf2_common]) from [<bf30c8c8>] (vb2_core_streamon+0x90/0x180 [videobuf2_common])
[187548.427128]  r7:00000001 r6:c1205048 r5:c66cc000 r4:c66cc014
[187548.427163] [<bf30c838>] (vb2_core_streamon [videobuf2_common]) from [<bf34e044>] (vb2_streamon+0x24/0x64 [videobuf2_v4l2])
[187548.427171]  r5:c66cc000 r4:00000009
[187548.427203] [<bf34e020>] (vb2_streamon [videobuf2_v4l2]) from [<bf19f0dc>] (v4l2_m2m_streamon+0x30/0x60 [v4l2_mem2mem])
[187548.427235] [<bf19f0ac>] (v4l2_m2m_streamon [v4l2_mem2mem]) from [<bf19f12c>] (v4l2_m2m_ioctl_streamon+0x20/0x24 [v4l2_mem2mem])
[187548.427244]  r7:00000001 r6:c1205048 r5:40045612 r4:bf19f10c
[187548.427321] [<bf19f10c>] (v4l2_m2m_ioctl_streamon [v4l2_mem2mem]) from [<bf20a094>] (v4l_streamon+0x2c/0x30 [videodev])
[187548.427437] [<bf20a068>] (v4l_streamon [videodev]) from [<bf20f114>] (__video_do_ioctl+0x234/0x460 [videodev])
[187548.427446]  r5:40045612 r4:c30cc8a0
[187548.427557] [<bf20eee0>] (__video_do_ioctl [videodev]) from [<bf20fb28>] (video_usercopy+0x128/0x5ac [videodev])
[187548.427568]  r10:cdc75e3c r9:9c8a24dc r8:00000000 r7:c62ebf00 r6:c1205048 r5:40045612
[187548.427575]  r4:40045612
[187548.427684] [<bf20fa00>] (video_usercopy [videodev]) from [<bf20ffcc>] (video_ioctl2+0x20/0x24 [videodev])
[187548.427695]  r10:00000095 r9:cdc74000 r8:00000000 r7:c62ebf00 r6:c62ebf01 r5:c1205048
[187548.427702]  r4:bf20ffac
[187548.427810] [<bf20ffac>] (video_ioctl2 [videodev]) from [<bf2081f4>] (v4l2_ioctl+0x4c/0x60 [videodev])
[187548.427878] [<bf2081a8>] (v4l2_ioctl [videodev]) from [<c045178c>] (sys_ioctl+0x1d4/0x8ec)
[187548.427886]  r5:c1205048 r4:40045612
[187548.427899] [<c04515b8>] (sys_ioctl) from [<c02001e4>] (__sys_trace_return+0x0/0x1c)
[187548.427907] Exception stack(0xcdc75fa8 to 0xcdc75ff0)
[187548.427917] 5fa0:                   9c8a24dc 40045612 00000095 40045612 9c8a24dc 037a12ec
[187548.427928] 5fc0: 9c8a24dc 40045612 0b718c40 00000036 9c8a2508 00000000 9c8a2504 9c8a2428
[187548.427937] 5fe0: 08fa9a48 9c8a2414 037a1310 b549151c
[187548.427947]  r10:00000036 r9:cdc74000 r8:c0200204 r7:00000036 r6:0b718c40 r5:40045612
[187548.427955]  r4:9c8a24dc
[187548.427965] ---[ end trace 55520c408cfd8f65 ]---
[187549.546098] hwmon hwmon1: Failed to get throttled (-110)
[187550.586086] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-v3d frequency: -110
[187762.510726] INFO: task Xorg:579 blocked for more than 122 seconds.
[187762.510743]       Tainted: G        WC        5.10.17-v7l+ #1403
[187762.510754] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[187762.510767] task:Xorg            state:D stack:    0 pid:  579 ppid:   543 flags:0x00000001
[187762.510793] Backtrace:
[187762.510836] [<c0b6d050>] (__schedule) from [<c0b6da28>] (schedule+0x68/0xe4)
[187762.510854]  r10:00000000 r9:00000002 r8:c1205048 r7:c467a000 r6:c467bcd4 r5:c46a9f00
[187762.510866]  r4:ffffe000
[187762.510886] [<c0b6d9c0>] (schedule) from [<c0b6de70>] (schedule_preempt_disabled+0x18/0x1c)
[187762.510899]  r5:ffffe000 r4:c2ceb3e8
[187762.510920] [<c0b6de58>] (schedule_preempt_disabled) from [<c0b700f8>] (__mutex_lock.constprop.9+0x344/0x58c)
[187762.510939] [<c0b6fdb4>] (__mutex_lock.constprop.9) from [<c0b7045c>] (__mutex_lock_slowpath+0x1c/0x20)
[187762.510955]  r10:c46a3800 r9:00000000 r8:cd790f50 r7:c2ceb000 r6:00000000 r5:c2ceb3e8
[187762.510967]  r4:c2ceb3e8
[187762.510986] [<c0b70440>] (__mutex_lock_slowpath) from [<c0b704bc>] (mutex_lock+0x5c/0x60)
[187762.511029] [<c0b70460>] (mutex_lock) from [<bf326d18>] (v3d_clock_up_get+0x24/0xac [v3d])
[187762.511042]  r5:c2ceb3e8 r4:c2ceb000
[187762.511090] [<bf326cf4>] (v3d_clock_up_get [v3d]) from [<bf326e6c>] (v3d_job_init+0xcc/0xdc [v3d])
[187762.511102]  r5:c1205048 r4:cd790f00
[187762.511147] [<bf326da0>] (v3d_job_init [v3d]) from [<bf327e68>] (v3d_submit_cl_ioctl+0xa4/0x63c [v3d])
[187762.511162]  r9:c0eb13f8 r8:c2ceb000 r7:c50b2e00 r6:cd790f00 r5:c1205048 r4:c467be64
[187762.511333] [<bf327dc4>] (v3d_submit_cl_ioctl [v3d]) from [<bf37546c>] (drm_ioctl_kernel+0xb8/0xfc [drm])
[187762.511349]  r10:c467be64 r9:bf327dc4 r8:00000021 r7:00000000 r6:c50b2e00 r5:c2ceb000
[187762.511361]  r4:c1205048
[187762.511646] [<bf3753b4>] (drm_ioctl_kernel [drm]) from [<bf375694>] (drm_ioctl+0x1e4/0x3a8 [drm])
[187762.511662]  r10:00000038 r9:c467be64 r8:c50b2e00 r7:00000040 r6:bf327dc4 r5:c1205048
[187762.511674]  r4:bf32e398
[187762.511825] [<bf3754b0>] (drm_ioctl [drm]) from [<c045178c>] (sys_ioctl+0x1d4/0x8ec)
[187762.511841]  r10:0000000e r9:c467a000 r8:00000000 r7:c5052480 r6:c5052481 r5:c1205048
[187762.511853]  r4:c0386440
[187762.511871] [<c04515b8>] (sys_ioctl) from [<c0200040>] (ret_fast_syscall+0x0/0x28)
[187762.511884] Exception stack(0xc467bfa8 to 0xc467bff0)
[187762.511900] bfa0:                   0156db50 0156db98 0000000e c0386440 0156db98 b5ff11cc
[187762.511916] bfc0: 0156db50 0156db98 c0386440 00000036 b5dda000 00aac0b0 00007fff 00aa9128
[187762.511929] bfe0: b6cfa08c bef303cc b6ce088c b696c51c
[187762.511945]  r10:00000036 r9:c467a000 r8:c0200204 r7:00000036 r6:c0386440 r5:0156db98
[187762.511957]  r4:0156db50
[187762.511971] INFO: task InputThread:606 blocked for more than 122 seconds.
[187762.511984]       Tainted: G        WC        5.10.17-v7l+ #1403
[187762.511995] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[187762.512008] task:InputThread     state:D stack:    0 pid:  606 ppid:   543 flags:0x00000000
[187762.512032] Backtrace:
[187762.512061] [<c0b6d050>] (__schedule) from [<c0b6da28>] (schedule+0x68/0xe4)
[187762.512077]  r10:00000000 r9:00000002 r8:c1205048 r7:c3d8c000 r6:c3d8d9d4 r5:c442dd00
[187762.512089]  r4:ffffe000
[187762.512107] [<c0b6d9c0>] (schedule) from [<c0b6de70>] (schedule_preempt_disabled+0x18/0x1c)
[187762.512120]  r5:ffffe000 r4:c131de10
[187762.512139] [<c0b6de58>] (schedule_preempt_disabled) from [<c0b700f8>] (__mutex_lock.constprop.9+0x344/0x58c)
[187762.512158] [<c0b6fdb4>] (__mutex_lock.constprop.9) from [<c0b7045c>] (__mutex_lock_slowpath+0x1c/0x20)
[187762.512173]  r10:dec1b008 r9:c1a94740 r8:00000048 r7:c1205048 r6:dec1b000 r5:c1a94740
[187762.512184]  r4:c131de10
[187762.512202] [<c0b70440>] (__mutex_lock_slowpath) from [<c0b704bc>] (mutex_lock+0x5c/0x60)
[187762.512223] [<c0b70460>] (mutex_lock) from [<c099d51c>] (rpi_firmware_transaction+0x50/0x128)
[187762.512235]  r5:c1a94740 r4:c1205048
[187762.512254] [<c099d4cc>] (rpi_firmware_transaction) from [<c099d6b0>] (rpi_firmware_property_list+0xbc/0x170)
[187762.512268]  r7:c1205048 r6:dec1b000 r5:00001000 r4:dec1b054
[187762.512337] [<c099d5f4>] (rpi_firmware_property_list) from [<bf2570e8>] (vc4_plane_set_blank+0x110/0x168 [vc4])
[187762.512352]  r10:c7629000 r9:00000000 r8:00000000 r7:c3384800 r6:c3c18a20 r5:c1205048
[187762.512364]  r4:c3c18840
[187762.512475] [<bf256fd8>] (vc4_plane_set_blank [vc4]) from [<bf2572c8>] (vc4_plane_atomic_update+0x34/0x38 [vc4])
[187762.512490]  r8:c804e200 r7:bf276b08 r6:c3c18840 r5:00000007 r4:cdcf9c80
[187762.512618] [<bf257294>] (vc4_plane_atomic_update [vc4]) from [<bf4f2ea8>] (drm_atomic_helper_commit_planes+0xe8/0x28c [drm_kms_helper])
[187762.512745] [<bf4f2dc0>] (drm_atomic_helper_commit_planes [drm_kms_helper]) from [<bf25998c>] (vc4_atomic_complete_commit+0x1b0/0x680 [vc4])
[187762.512761]  r10:d4cf0c00 r9:00000000 r8:c3384d00 r7:00000000 r6:c3384800 r5:cdcf9c80
[187762.512772]  r4:00000001
[187762.512877] [<bf2597dc>] (vc4_atomic_complete_commit [vc4]) from [<bf259fd8>] (vc4_atomic_commit+0x17c/0x1cc [vc4])
[187762.512893]  r10:d4cf0c00 r9:00000000 r8:c3384d00 r7:00000000 r6:00000000 r5:c3384800
[187762.512905]  r4:cdcf9c80 r3:00000001
[187762.513105] [<bf259e5c>] (vc4_atomic_commit [vc4]) from [<bf3878f8>] (drm_atomic_commit+0x54/0x60 [drm])
[187762.513121]  r9:0000042f r8:c3399c40 r7:00000000 r6:c3384800 r5:cdcf9c80 r4:00000000
[187762.513335] [<bf3878a4>] (drm_atomic_commit [drm]) from [<bf4f3b14>] (drm_atomic_helper_update_plane+0xfc/0x134 [drm_kms_helper])
[187762.513349]  r7:00000000 r6:c3c18840 r5:c804e200 r4:cdcf9c80
[187762.513561] [<bf4f3a18>] (drm_atomic_helper_update_plane [drm_kms_helper]) from [<bf392088>] (__setplane_atomic+0x104/0x144 [drm])
[187762.513577]  r10:00400000 r9:00400000 r8:00000000 r7:0000042f r6:c3399c40 r5:d4cf0c00
[187762.513589]  r4:bf4f3a18 r3:0000042f
[187762.513866] [<bf391f84>] (__setplane_atomic [drm]) from [<bf3923d8>] (drm_mode_cursor_universal+0x174/0x294 [drm])
[187762.513882]  r10:c3d8dd64 r9:c3384800 r8:c3c18840 r7:c1205048 r6:c3399c40 r5:c3d8ddb8
[187762.513894]  r4:d4cf0c00
[187762.514171] [<bf392264>] (drm_mode_cursor_universal [drm]) from [<bf3925f4>] (drm_mode_cursor_common+0xfc/0x250 [drm])
[187762.514186]  r10:c3d8de64 r9:00000000 r8:c3399c40 r7:c50b2f00 r6:c3399c54 r5:c3399c74
[187762.514198]  r4:c3d8ddb8
[187762.514473] [<bf3924f8>] (drm_mode_cursor_common [drm]) from [<bf392b08>] (drm_mode_cursor_ioctl+0x78/0x94 [drm])
[187762.514488]  r10:c3d8de64 r9:bf392a90 r8:00000002 r7:c50b2f00 r6:c3384800 r5:00000000
[187762.514500]  r4:c1205048
[187762.514775] [<bf392a90>] (drm_mode_cursor_ioctl [drm]) from [<bf37546c>] (drm_ioctl_kernel+0xb8/0xfc [drm])
[187762.514790]  r7:00000000 r6:c50b2f00 r5:c3384800 r4:c1205048
[187762.515066] [<bf3753b4>] (drm_ioctl_kernel [drm]) from [<bf375694>] (drm_ioctl+0x1e4/0x3a8 [drm])
[187762.515081]  r10:0000001c r9:c3d8de64 r8:c50b2f00 r7:000000a3 r6:bf392a90 r5:c1205048
[187762.515092]  r4:bf3aaa6c
[187762.515243] [<bf3754b0>] (drm_ioctl [drm]) from [<c045178c>] (sys_ioctl+0x1d4/0x8ec)
[187762.515258]  r10:0000000c r9:c3d8c000 r8:00000000 r7:c2eab840 r6:c2eab841 r5:c1205048
[187762.515270]  r4:c01c64a3
[187762.515288] [<c04515b8>] (sys_ioctl) from [<c0200040>] (ret_fast_syscall+0x0/0x28)
[187762.515300] Exception stack(0xc3d8dfa8 to 0xc3d8dff0)
[187762.515315] dfa0:                   b6f59968 b0a1f0c8 0000000c c01c64a3 b0a1f0c8 00000258
[187762.515330] dfc0: b6f59968 b0a1f0c8 c01c64a3 00000036 00000001 0000025a 001fd000 00201894
[187762.515344] dfe0: b6cfa08c b0a1f0ac b6ce088c b696c51c
[187762.515359]  r10:00000036 r9:c3d8c000 r8:c0200204 r7:00000036 r6:c01c64a3 r5:b0a1f0c8
[187762.515371]  r4:b6f59968
[187762.515410] INFO: task chromium-browse:4642 blocked for more than 122 seconds.
[187762.515424]       Tainted: G        WC        5.10.17-v7l+ #1403
[187762.515435] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[187762.515447] task:chromium-browse state:D stack:    0 pid: 4642 ppid:  4618 flags:0x00000081
[187762.515471] Backtrace:
[187762.515501] [<c0b6d050>] (__schedule) from [<c0b6da28>] (schedule+0x68/0xe4)
[187762.515516]  r10:00000000 r9:00000002 r8:c1205048 r7:cb5a4000 r6:cb5a5ca4 r5:c6242e80
[187762.515528]  r4:ffffe000
[187762.515545] [<c0b6d9c0>] (schedule) from [<c0b6de70>] (schedule_preempt_disabled+0x18/0x1c)
[187762.515558]  r5:ffffe000 r4:c12e8a74
[187762.515577] [<c0b6de58>] (schedule_preempt_disabled) from [<c0b700f8>] (__mutex_lock.constprop.9+0x344/0x58c)
[187762.515595] [<c0b6fdb4>] (__mutex_lock.constprop.9) from [<c0b7045c>] (__mutex_lock_slowpath+0x1c/0x20)
[187762.515610]  r10:cb643c00 r9:00000000 r8:cd790350 r7:c2ceb000 r6:00000000 r5:1dcd6500
[187762.515621]  r4:c12e8a74
[187762.515639] [<c0b70440>] (__mutex_lock_slowpath) from [<c0b704bc>] (mutex_lock+0x5c/0x60)
[187762.515660] [<c0b70460>] (mutex_lock) from [<c07d8ee4>] (clk_prepare_lock+0x60/0x110)
[187762.515672]  r5:1dcd6500 r4:c13fcdd4
[187762.515690] [<c07d8e84>] (clk_prepare_lock) from [<c07dd8cc>] (clk_set_rate+0x28/0x98)
[187762.515702]  r5:1dcd6500 r4:c3601580
[187762.515736] [<c07dd8a4>] (clk_set_rate) from [<bf326d58>] (v3d_clock_up_get+0x64/0xac [v3d])
[187762.515749]  r5:c2ceb3e8 r4:c2ceb000
[187762.515794] [<bf326cf4>] (v3d_clock_up_get [v3d]) from [<bf326e6c>] (v3d_job_init+0xcc/0xdc [v3d])
[187762.515807]  r5:c1205048 r4:cd790300
[187762.515850] [<bf326da0>] (v3d_job_init [v3d]) from [<bf327e68>] (v3d_submit_cl_ioctl+0xa4/0x63c [v3d])
[187762.515865]  r9:c0eb13f8 r8:c2ceb000 r7:c6dd6c00 r6:cd790300 r5:c1205048 r4:cb5a5e64
[187762.516031] [<bf327dc4>] (v3d_submit_cl_ioctl [v3d]) from [<bf37546c>] (drm_ioctl_kernel+0xb8/0xfc [drm])
[187762.516046]  r10:cb5a5e64 r9:bf327dc4 r8:00000021 r7:00000000 r6:c6dd6c00 r5:c2ceb000
[187762.516058]  r4:c1205048
[187762.516332] [<bf3753b4>] (drm_ioctl_kernel [drm]) from [<bf375694>] (drm_ioctl+0x1e4/0x3a8 [drm])
[187762.516348]  r10:00000038 r9:cb5a5e64 r8:c6dd6c00 r7:00000040 r6:bf327dc4 r5:c1205048
[187762.516360]  r4:bf32e398
[187762.516506] [<bf3754b0>] (drm_ioctl [drm]) from [<c045178c>] (sys_ioctl+0x1d4/0x8ec)
[187762.516522]  r10:00000017 r9:cb5a4000 r8:00000000 r7:c31a7000 r6:c31a7001 r5:c1205048
[187762.516534]  r4:c0386440
[187762.516551] [<c04515b8>] (sys_ioctl) from [<c02001e4>] (__sys_trace_return+0x0/0x1c)
[187762.516563] Exception stack(0xcb5a5fa8 to 0xcb5a5ff0)
[187762.516578] 5fa0:                   0b776918 0b776960 00000017 c0386440 0b776960 b20791cc
[187762.516593] 5fc0: 0b776918 0b776960 c0386440 00000036 b1e62000 09cc6900 09dc15f0 be9e8660
[187762.516606] 5fe0: b616a08c be9e8514 b615088c b549151c
[187762.516621]  r10:00000036 r9:cb5a4000 r8:c0200204 r7:00000036 r6:c0386440 r5:0b776960
[187762.516633]  r4:0b776918
[187762.516672] INFO: task kworker/0:1:28041 blocked for more than 122 seconds.
[187762.516685]       Tainted: G        WC        5.10.17-v7l+ #1403
[187762.516696] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[187762.516708] task:kworker/0:1     state:D stack:    0 pid:28041 ppid:     2 flags:0x00000000
[187762.516738] Workqueue: events_freezable mmc_rescan
[187762.516759] Backtrace:
[187762.516787] [<c0b6d050>] (__schedule) from [<c0b6da28>] (schedule+0x68/0xe4)
[187762.516802]  r10:00000000 r9:00000002 r8:c1205048 r7:cd5e6000 r6:cd5e7c14 r5:c5b65d00
[187762.516814]  r4:ffffe000
[187762.516831] [<c0b6d9c0>] (schedule) from [<c0b6de70>] (schedule_preempt_disabled+0x18/0x1c)
[187762.516844]  r5:ffffe000 r4:c131de10
[187762.516862] [<c0b6de58>] (schedule_preempt_disabled) from [<c0b700f8>] (__mutex_lock.constprop.9+0x344/0x58c)
[187762.516881] [<c0b6fdb4>] (__mutex_lock.constprop.9) from [<c0b7045c>] (__mutex_lock_slowpath+0x1c/0x20)
[187762.516896]  r10:dec1c008 r9:c1a94740 r8:00000014 r7:c1205048 r6:dec1c000 r5:c1a94740
[187762.516908]  r4:c131de10
[187762.516926] [<c0b70440>] (__mutex_lock_slowpath) from [<c0b704bc>] (mutex_lock+0x5c/0x60)
[187762.516945] [<c0b70460>] (mutex_lock) from [<c099d51c>] (rpi_firmware_transaction+0x50/0x128)
[187762.516958]  r5:c1a94740 r4:c1205048
[187762.516976] [<c099d4cc>] (rpi_firmware_transaction) from [<c099d6b0>] (rpi_firmware_property_list+0xbc/0x170)
[187762.516989]  r7:c1205048 r6:dec1c000 r5:00001000 r4:dec1c020
[187762.517007] [<c099d5f4>] (rpi_firmware_property_list) from [<c099d7d4>] (rpi_firmware_property+0x70/0x118)
[187762.517022]  r10:cdcf908c r9:00038041 r8:00000014 r7:c1a94740 r6:cd5e7d3c r5:00000008
[187762.517033]  r4:cdcf9080
[187762.517053] [<c099d764>] (rpi_firmware_property) from [<c0793f10>] (rpi_exp_gpio_set+0x5c/0xa0)
[187762.517068]  r10:00000000 r9:00000000 r8:00000000 r7:c1bcb440 r6:00000000 r5:00000006
[187762.517080]  r4:c1205048 r3:00000008
[187762.517097] [<c0793eb4>] (rpi_exp_gpio_set) from [<c0789b88>] (gpiod_set_raw_value_commit+0x50/0xfc)
[187762.517111]  r7:c1a5a034 r6:00000000 r5:c1bcb440 r4:c1b79750
[187762.517127] [<c0789b38>] (gpiod_set_raw_value_commit) from [<c0789d40>] (gpiod_set_value_nocheck+0x54/0x60)
[187762.517142]  r9:00000000 r8:00000000 r7:c1a5a034 r6:eeffc398 r5:00000000 r4:c1b79750
[187762.517157] [<c0789cec>] (gpiod_set_value_nocheck) from [<c0789df4>] (gpiod_set_value_cansleep+0x38/0x40)
[187762.517176] [<c0789dbc>] (gpiod_set_value_cansleep) from [<c07ef424>] (_regulator_do_disable+0x210/0x21c)
[187762.517190]  r5:c22daec0 r4:c1a5a000
[187762.517208] [<c07ef214>] (_regulator_do_disable) from [<c07f26ac>] (_regulator_disable+0xc8/0x1a8)
[187762.517222]  r7:c1a5a034 r6:c22e1780 r5:c22e1780 r4:c1a5a000
[187762.517241] [<c07f25e4>] (_regulator_disable) from [<c07f27d0>] (regulator_disable+0x44/0x74)
[187762.517255]  r8:c0c63e0c r7:00000000 r6:c22e1780 r5:c1a5a000 r4:c1205048
[187762.517273] [<c07f278c>] (regulator_disable) from [<c09856c8>] (mmc_regulator_set_ocr+0xe0/0xf0)
[187762.517287]  r6:c22e1780 r5:c21fc800 r4:c21fcb80
[187762.517304] [<c09855e8>] (mmc_regulator_set_ocr) from [<c098f3fc>] (sdhci_set_power_and_bus_voltage+0x48/0x4c)
[187762.517317]  r7:00000000 r6:00000000 r5:00000000 r4:c21fcb80
[187762.517332] [<c098f3b4>] (sdhci_set_power_and_bus_voltage) from [<c098ef40>] (sdhci_set_ios+0x100/0x574)
[187762.517346]  r7:00000000 r6:c21fcb80 r5:c21fca2c r4:c21fc800
[187762.517361] [<c098ee40>] (sdhci_set_ios) from [<c097717c>] (mmc_set_initial_state+0xa0/0xa4)
[187762.517375]  r7:000186a0 r6:00000004 r5:c21fca2c r4:c21fc800
[187762.517391] [<c09770dc>] (mmc_set_initial_state) from [<c09771b8>] (mmc_power_off.part.10+0x38/0x48)
[187762.517403]  r5:c21fc800 r4:c21fc800
[187762.517419] [<c0977180>] (mmc_power_off.part.10) from [<c0978044>] (mmc_rescan+0x33c/0x3b0)
[187762.517431]  r5:c21fc800 r4:c21fca8c
[187762.517450] [<c0977d08>] (mmc_rescan) from [<c023dc18>] (process_one_work+0x250/0x5a0)
[187762.517464]  r9:00000000 r8:00000000 r7:eff15c00 r6:eff12640 r5:cee1dc00 r4:c21fca8c
[187762.517482] [<c023d9c8>] (process_one_work) from [<c023dfc8>] (worker_thread+0x60/0x5c4)
[187762.517497]  r10:eff12640 r9:c1203d00 r8:eff12658 r7:00000008 r6:eff12640 r5:cee1dc14
[187762.517508]  r4:cee1dc00
[187762.517526] [<c023df68>] (worker_thread) from [<c0245a50>] (kthread+0x170/0x174)
[187762.517541]  r10:ceb5fe74 r9:cee1dc00 r8:c023df68 r7:cd5e6000 r6:00000000 r5:c9205d00
[187762.517553]  r4:c78896c0
[187762.517568] [<c02458e0>] (kthread) from [<c02000ec>] (ret_from_fork+0x14/0x28)
[187762.517580] Exception stack(0xcd5e7fb0 to 0xcd5e7ff8)
[187762.517593] 7fa0:                                     00000000 00000000 00000000 00000000
[187762.517608] 7fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[187762.517621] 7fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[187762.517636]  r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c02458e0
[187762.517648]  r4:c9205d00
[187762.517662] INFO: task kworker/2:2:29837 blocked for more than 122 seconds.
[187762.517674]       Tainted: G        WC        5.10.17-v7l+ #1403
[187762.517685] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[187762.517697] task:kworker/2:2     state:D stack:    0 pid:29837 ppid:     2 flags:0x00000000
[187762.517727] Workqueue: events dbs_work_handler
[187762.517748] Backtrace:
[187762.517776] [<c0b6d050>] (__schedule) from [<c0b6da28>] (schedule+0x68/0xe4)
[187762.517791]  r10:dec1a008 r9:eff33540 r8:eff33540 r7:c1205048 r6:c352dbfc r5:c3358000
[187762.517803]  r4:ffffe000
[187762.517821] [<c0b6d9c0>] (schedule) from [<c0b71d94>] (schedule_timeout+0x1d0/0x384)
[187762.517833]  r5:c1203d00 r4:01233648
[187762.517851] [<c0b71bc4>] (schedule_timeout) from [<c0b6ea08>] (wait_for_completion_timeout+0xb8/0x144)
[187762.517866]  r9:00000002 r8:ffffe000 r7:c197ae90 r6:c1205048 r5:00057e40 r4:c197ae8c
[187762.517885] [<c0b6e950>] (wait_for_completion_timeout) from [<c09cd84c>] (mbox_send_message+0xb8/0x11c)
[187762.517900]  r9:c1a94740 r8:00000018 r7:c352dc98 r6:c197aef8 r5:00000011 r4:c197ae80
[187762.517918] [<c09cd794>] (mbox_send_message) from [<c099d530>] (rpi_firmware_transaction+0x64/0x128)
[187762.517931]  r7:00000000 r6:dec1a000 r5:c1a94740 r4:c1205048
[187762.517949] [<c099d4cc>] (rpi_firmware_transaction) from [<c099d6b0>] (rpi_firmware_property_list+0xbc/0x170)
[187762.517963]  r7:c1205048 r6:dec1a000 r5:00001000 r4:dec1a024
[187762.517980] [<c099d5f4>] (rpi_firmware_property_list) from [<c099d7d4>] (rpi_firmware_property+0x70/0x118)
[187762.517995]  r10:c465198c r9:00030002 r8:00000018 r7:c1a94740 r6:c352dd48 r5:0000000c
[187762.518007]  r4:c4651980
[187762.518024] [<c099d764>] (rpi_firmware_property) from [<c07e4e54>] (raspberrypi_clock_property+0x54/0x7c)
[187762.518039]  r10:00000000 r9:00000000 r8:c22baf80 r7:00000000 r6:ffffff92 r5:c352dd70
[187762.518052]  r4:c1205048 r3:0000000c
[187762.518067] [<c07e4e00>] (raspberrypi_clock_property) from [<c07e4ec8>] (raspberrypi_fw_get_rate+0x4c/0x70)
[187762.518080]  r5:00000000 r4:c1205048
[187762.518096] [<c07e4e7c>] (raspberrypi_fw_get_rate) from [<c07db7d4>] (clk_recalc+0x44/0x84)
[187762.518109]  r4:c1b79900
[187762.518124] [<c07db790>] (clk_recalc) from [<c07dbac4>] (__clk_recalc_rates+0x30/0x94)
[187762.518137]  r5:00000000 r4:c1b79900
[187762.518153] [<c07dba94>] (__clk_recalc_rates) from [<c07dbb80>] (clk_core_get_rate_recalc+0x58/0x5c)
[187762.518167]  r7:00000000 r6:c1205048 r5:29b92700 r4:c1b79900
[187762.518183] [<c07dbb28>] (clk_core_get_rate_recalc) from [<c07dbbac>] (clk_get_rate+0x28/0x38)
[187762.518195]  r5:29b92700 r4:c22baf80
[187762.518212] [<c07dbb84>] (clk_get_rate) from [<c0968a10>] (dev_pm_opp_set_rate+0x70/0x588)
[187762.518224]  r5:29b92700 r4:c22cd200
[187762.518242] [<c09689a0>] (dev_pm_opp_set_rate) from [<c0973900>] (set_target+0x38/0x3c)
[187762.518256]  r10:00000000 r9:00000000 r8:00000001 r7:00000000 r6:c1404e44 r5:c1205048
[187762.518268]  r4:c22cd400
[187762.518286] [<c09738c8>] (set_target) from [<c096e604>] (__cpufreq_driver_target+0x1bc/0x540)
[187762.518304] [<c096e448>] (__cpufreq_driver_target) from [<c0971994>] (od_dbs_update+0xc4/0x170)
[187762.518319]  r10:00000000 r9:c3c16e00 r8:c458e180 r7:c3c16b00 r6:c3c16e00 r5:c3c16b00
[187762.518330]  r4:c22cd400
[187762.518348] [<c09718d0>] (od_dbs_update) from [<c0972bf8>] (dbs_work_handler+0x3c/0x64)
[187762.518363]  r9:00000000 r8:c131beac r7:c22cd400 r6:c3c16b04 r5:00000000 r4:c3c16b38
[187762.518382] [<c0972bbc>] (dbs_work_handler) from [<c023dc18>] (process_one_work+0x250/0x5a0)
[187762.518397]  r9:00000000 r8:00000080 r7:eff3d900 r6:eff3a640 r5:c2fef480 r4:c3c16b38
[187762.518414] [<c023d9c8>] (process_one_work) from [<c023dfc8>] (worker_thread+0x60/0x5c4)
[187762.518429]  r10:eff3a640 r9:c1203d00 r8:eff3a658 r7:00000008 r6:eff3a640 r5:c2fef494
[187762.518441]  r4:c2fef480
[187762.518457] [<c023df68>] (worker_thread) from [<c0245a50>] (kthread+0x170/0x174)
[187762.518472]  r10:c6755e74 r9:c2fef480 r8:c023df68 r7:c352c000 r6:00000000 r5:cdfda800
[187762.518484]  r4:d590e380
[187762.518499] [<c02458e0>] (kthread) from [<c02000ec>] (ret_from_fork+0x14/0x28)
[187762.518511] Exception stack(0xc352dfb0 to 0xc352dff8)
[187762.518525] dfa0:                                     00000000 00000000 00000000 00000000
[187762.518539] dfc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[187762.518552] dfe0: 00000000 00000000 00000000 00000000 00000013 00000000
[187762.518567]  r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c02458e0
[187762.518579]  r4:cdfda800
[187762.518603] INFO: task kworker/1:0:30939 blocked for more than 122 seconds.
[187762.518615]       Tainted: G        WC        5.10.17-v7l+ #1403
[187762.518627] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[187762.518638] task:kworker/1:0     state:D stack:    0 pid:30939 ppid:     2 flags:0x00000000
[187762.518670] Workqueue: events get_values_poll [raspberrypi_hwmon]
[187762.518690] Backtrace:
[187762.518718] [<c0b6d050>] (__schedule) from [<c0b6da28>] (schedule+0x68/0xe4)
[187762.518733]  r10:00000000 r9:00000002 r8:c1205048 r7:d3cba000 r6:d3cbbdbc r5:cb799f00
[187762.518744]  r4:ffffe000
[187762.518762] [<c0b6d9c0>] (schedule) from [<c0b6de70>] (schedule_preempt_disabled+0x18/0x1c)
[187762.518774]  r5:ffffe000 r4:c131de10
[187762.518792] [<c0b6de58>] (schedule_preempt_disabled) from [<c0b700f8>] (__mutex_lock.constprop.9+0x344/0x58c)
[187762.518811] [<c0b6fdb4>] (__mutex_lock.constprop.9) from [<c0b7045c>] (__mutex_lock_slowpath+0x1c/0x20)
[187762.518826]  r10:dec19008 r9:c1a94740 r8:00000010 r7:c1205048 r6:dec19000 r5:c1a94740
[187762.518838]  r4:c131de10
[187762.518856] [<c0b70440>] (__mutex_lock_slowpath) from [<c0b704bc>] (mutex_lock+0x5c/0x60)
[187762.518875] [<c0b70460>] (mutex_lock) from [<c099d51c>] (rpi_firmware_transaction+0x50/0x128)
[187762.518888]  r5:c1a94740 r4:c1205048
[187762.518905] [<c099d4cc>] (rpi_firmware_transaction) from [<c099d6b0>] (rpi_firmware_property_list+0xbc/0x170)
[187762.518919]  r7:c1205048 r6:dec19000 r5:00001000 r4:dec1901c
[187762.518937] [<c099d5f4>] (rpi_firmware_property_list) from [<c099d7d4>] (rpi_firmware_property+0x70/0x118)
[187762.518952]  r10:cde78a0c r9:00030046 r8:00000010 r7:c1a94740 r6:d3cbbed8 r5:00000004
[187762.518963]  r4:cde78a00
[187762.518982] [<c099d764>] (rpi_firmware_property) from [<bf1300c0>] (get_values_poll+0x4c/0x150 [raspberrypi_hwmon])
[187762.518997]  r10:00000000 r9:00000000 r8:00000040 r7:eff29900 r6:eff26640 r5:c2f6124c
[187762.519009]  r4:c1205048 r3:00000004
[187762.519028] [<bf130074>] (get_values_poll [raspberrypi_hwmon]) from [<c023dc18>] (process_one_work+0x250/0x5a0)
[187762.519041]  r5:d40cbd80 r4:c2f6124c
[187762.519058] [<c023d9c8>] (process_one_work) from [<c023dfc8>] (worker_thread+0x60/0x5c4)
[187762.519073]  r10:eff26640 r9:c1203d00 r8:eff26658 r7:00000008 r6:eff26640 r5:d40cbd94
[187762.519084]  r4:d40cbd80
[187762.519101] [<c023df68>] (worker_thread) from [<c0245a50>] (kthread+0x170/0x174)
[187762.519115]  r10:c4541e74 r9:d40cbd80 r8:c023df68 r7:d3cba000 r6:00000000 r5:c6542980
[187762.519127]  r4:d40f2380
[187762.519142] [<c02458e0>] (kthread) from [<c02000ec>] (ret_from_fork+0x14/0x28)
[187762.519154] Exception stack(0xd3cbbfb0 to 0xd3cbbff8)
[187762.519168] bfa0:                                     00000000 00000000 00000000 00000000
[187762.519182] bfc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[187762.519196] bfe0: 00000000 00000000 00000000 00000000 00000013 00000000
[187762.519210]  r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c02458e0
[187762.519222]  r4:c6542980
[187885.393195] INFO: task Xorg:579 blocked for more than 245 seconds.
[187885.393212]       Tainted: G        WC        5.10.17-v7l+ #1403
[187885.393223] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[187885.393237] task:Xorg            state:D stack:    0 pid:  579 ppid:   543 flags:0x00000001
[187885.393263] Backtrace:
[187885.393302] [<c0b6d050>] (__schedule) from [<c0b6da28>] (schedule+0x68/0xe4)
[187885.393321]  r10:00000000 r9:00000002 r8:c1205048 r7:c467a000 r6:c467bcd4 r5:c46a9f00
[187885.393333]  r4:ffffe000
[187885.393352] [<c0b6d9c0>] (schedule) from [<c0b6de70>] (schedule_preempt_disabled+0x18/0x1c)
[187885.393365]  r5:ffffe000 r4:c2ceb3e8
[187885.393387] [<c0b6de58>] (schedule_preempt_disabled) from [<c0b700f8>] (__mutex_lock.constprop.9+0x344/0x58c)
[187885.393407] [<c0b6fdb4>] (__mutex_lock.constprop.9) from [<c0b7045c>] (__mutex_lock_slowpath+0x1c/0x20)
[187885.393422]  r10:c46a3800 r9:00000000 r8:cd790f50 r7:c2ceb000 r6:00000000 r5:c2ceb3e8
[187885.393434]  r4:c2ceb3e8
[187885.393452] [<c0b70440>] (__mutex_lock_slowpath) from [<c0b704bc>] (mutex_lock+0x5c/0x60)
[187885.393497] [<c0b70460>] (mutex_lock) from [<bf326d18>] (v3d_clock_up_get+0x24/0xac [v3d])
[187885.393510]  r5:c2ceb3e8 r4:c2ceb000
[187885.393559] [<bf326cf4>] (v3d_clock_up_get [v3d]) from [<bf326e6c>] (v3d_job_init+0xcc/0xdc [v3d])
[187885.393572]  r5:c1205048 r4:cd790f00
[187885.393617] [<bf326da0>] (v3d_job_init [v3d]) from [<bf327e68>] (v3d_submit_cl_ioctl+0xa4/0x63c [v3d])
[187885.393632]  r9:c0eb13f8 r8:c2ceb000 r7:c50b2e00 r6:cd790f00 r5:c1205048 r4:c467be64
[187885.393804] [<bf327dc4>] (v3d_submit_cl_ioctl [v3d]) from [<bf37546c>] (drm_ioctl_kernel+0xb8/0xfc [drm])
[187885.393820]  r10:c467be64 r9:bf327dc4 r8:00000021 r7:00000000 r6:c50b2e00 r5:c2ceb000
[187885.393831]  r4:c1205048
[187885.394115] [<bf3753b4>] (drm_ioctl_kernel [drm]) from [<bf375694>] (drm_ioctl+0x1e4/0x3a8 [drm])
[187885.394131]  r10:00000038 r9:c467be64 r8:c50b2e00 r7:00000040 r6:bf327dc4 r5:c1205048
[187885.394143]  r4:bf32e398
[187885.394294] [<bf3754b0>] (drm_ioctl [drm]) from [<c045178c>] (sys_ioctl+0x1d4/0x8ec)
[187885.394309]  r10:0000000e r9:c467a000 r8:00000000 r7:c5052480 r6:c5052481 r5:c1205048
[187885.394321]  r4:c0386440
[187885.394339] [<c04515b8>] (sys_ioctl) from [<c0200040>] (ret_fast_syscall+0x0/0x28)
[187885.394352] Exception stack(0xc467bfa8 to 0xc467bff0)
[187885.394367] bfa0:                   0156db50 0156db98 0000000e c0386440 0156db98 b5ff11cc
[187885.394382] bfc0: 0156db50 0156db98 c0386440 00000036 b5dda000 00aac0b0 00007fff 00aa9128
[187885.394396] bfe0: b6cfa08c bef303cc b6ce088c b696c51c
[187885.394411]  r10:00000036 r9:c467a000 r8:c0200204 r7:00000036 r6:c0386440 r5:0156db98
[187885.394423]  r4:0156db50
[187885.394436] INFO: task InputThread:606 blocked for more than 245 seconds.
[187885.394449]       Tainted: G        WC        5.10.17-v7l+ #1403
[187885.394460] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
I also noticed, while logged in with ssh that the pi had about 20 processes running that were associated with the chromium browser. I tried to kill all of them and did get rid of most of them, but found that two could not be killed, as shown below.

Code: Select all

pi@rp49:~ $ sudo kill -9 4642 4769
pi@rp49:~ $ ps aux | grep chromium
pi         481  0.0  0.0   7348   528 pts/4    S+   14:13   0:00 grep --color=auto chromium
pi        4642  5.2  5.3 682220 207688 ?       D    May25 164:02 /usr/lib/chromium-browser/chromium-browser-v7 --type=gpu-process --field-trial-handle=12090159158383191599,15303737098169241985,131072 --enable-features=CookieDeprecationMessages,CriticalClientHint,CrossOriginEmbedderPolicy,CrossOriginIsolated,CrossOriginOpenerPolicyAccessReporting,CrossOriginOpenerPolicyReporting,DocumentPolicyNegotiation,EnableNewCanvas2DAPI,FeaturePolicyForClientHints,LangClientHintHeader,OriginIsolationHeader,OriginPolicy,SchemefulSameSite,UserAgentClientHint --disable-features=AudioServiceOutOfProcess --disable-breakpad --gpu-preferences=QAAAAAAAAAAgAABQAAAAAAAAAAAAAAAAAABgAAAAAAAgAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAABAAAAAAAAAEgAAAAIAAAAQAAAAAAAAABIAAAAAAAAAFAAAAAAAAAAWAAAAAAAAABgAAAAAAAAAGgAAAAAAAAAcAAAAAAAAAB4AAAAAAAAABAAAAAAAAAAAAAAAAwAAAAQAAAAAAAAAAAAAAANAAAAEAAAAAAAAAABAAAADAAAABAAAAAAAAAAAQAAAA0AAAAQAAAAAAAAAAQAAAAMAAAAEAAAAAAAAAAEAAAADQAAABAAAAAAAAAABwAAAAwAAAAQAAAAAAAAAAcAAAANAAAA --shared-files
pi        4769  0.0  0.0      0     0 ?        Z    May25   0:00 [chromium-browse] <defunct>

monkeyfork
Posts: 102
Joined: Tue Oct 29, 2013 10:14 am
Location: orlando

Re: lockup on 4b : Firmware transaction timeout ?

Fri May 28, 2021 12:18 am

@jbeale.

i have similar with the same dmesg errors (many many of them). i have rpi4 (4GB) as you and also it is my main computer but with rpi-zeroW helper and chromebook as a sidekick (with keystrokes + pointer originating at rpi-zero, shared with rpi4 via synergy and shared with chrome book through my own scheme).

However, i do not have total lockups but rather periodic stalls of a few seconds. But it is quite often and quite annoying. Hopefully someone has a clue. Oh yea, this is fairly recent occurrence. I think i have rpOS of last year but regularly update/upgrade. If anyone is chasing this and needs specifics i'll dig them up.

6by9
Raspberry Pi Engineer & Forum Moderator
Raspberry Pi Engineer & Forum Moderator
Posts: 11493
Joined: Wed Dec 04, 2013 11:27 am
Location: ZZ9 Plural Z Alpha, aka just outside Cambridge.

Re: lockup on 4b : Firmware transaction timeout ?

Fri May 28, 2021 4:54 pm

Code: Select all

[187546.426026] Firmware transaction timeout 
is just that a mailbox service call timed out. Normally the firmware is pretty speedy in handling those calls, so something is up with it.

bcm2835-codec is the V4L2 video decoder. I wasn't aware that we'd switched over to using that from Chromium as the person who supports Chromium was still reporting issues that need resolving. I'll make enquiries there.
Software Engineer at Raspberry Pi Trading. Views expressed are still personal views.
I'm not interested in doing contracts for bespoke functionality - please don't ask.

User avatar
jbeale
Posts: 3884
Joined: Tue Nov 22, 2011 11:51 pm
Contact: Website

Re: lockup on 4b : Firmware transaction timeout ?

Sun May 30, 2021 3:48 pm

Thank you 6by9 for checking into it. FWIW I just did apt update & upgrade today and a number of things were upgraded, so apparently I didn't have the latest. I will note here if it happens again now.

I am sure there is something off with my particular config, as whenever this glitch happens it forces me to reboot to restore normal operation, and I'm confident there would be huge numbers of complaints if this was a common problem.

User avatar
jbeale
Posts: 3884
Joined: Tue Nov 22, 2011 11:51 pm
Contact: Website

Re: lockup on 4b : Firmware transaction timeout ?

Tue Jun 01, 2021 3:39 pm

FWIW I have not yet had another lockup but I did get this "warning" since updating:

Code: Select all

[133258.395745] bcm2835-codec bcm2835-codec: bcm2835_codec_start_streaming: Failed enabling i/p port, ret -2
[133258.395757] ------------[ cut here ]------------
[133258.395787] WARNING: CPU: 3 PID: 4581 at drivers/media/common/videobuf2/videobuf2-core.c:1548 vb2_start_streaming+0x108/0x178 [videobuf2_common]
[133258.395794] Modules linked in: snd_seq_dummy snd_seq rfcomm bnep hci_uart btbcm bluetooth ecdh_generic ecc fuse 8021q garp stp llc sg cdc_acm mct_u232 usbserial rpivid_mem brcmfmac brcmutil v3d sha256_generic gpu_sched cfg80211 raspberrypi_hwmon rfkill i2c_bcm2835 vc4 cec bcm2835_codec(C) bcm2835_isp(C) bcm2835_v4l2(C) bcm2835_mmal_vchiq(C) v4l2_mem2mem videobuf2_vmalloc videobuf2_dma_contig videobuf2_memops videobuf2_v4l2 videobuf2_common snd_usb_audio drm_kms_helper snd_hwdep snd_bcm2835(C) snd_usbmidi_lib videodev vc_sm_cma(C) snd_rawmidi snd_seq_device mc drm drm_panel_orientation_quirks snd_soc_core snd_compress snd_pcm_dmaengine snd_pcm snd_timer snd syscopyarea sysfillrect sysimgblt fb_sys_fops backlight uio_pdrv_genirq nvmem_rmem uio i2c_dev ip_tables x_tables ipv6
[133258.396212] CPU: 3 PID: 4581 Comm: V4L2DecoderThre Tainted: G        WC        5.10.17-v7l+ #1421
[133258.396216] Hardware name: BCM2711
[133258.396221] Backtrace: 
[133258.396246] [<c0b63050>] (dump_backtrace) from [<c0b633e4>] (show_stack+0x20/0x24)
[133258.396252]  r7:ffffffff r6:00000000 r5:60000113 r4:c12e69fc
[133258.396260] [<c0b633c4>] (show_stack) from [<c0b67774>] (dump_stack+0xcc/0xf8)
[133258.396270] [<c0b676a8>] (dump_stack) from [<c0220bac>] (__warn+0xfc/0x114)
[133258.396276]  r10:bf3358dc r9:00000009 r8:bf4051ec r7:0000060c r6:00000009 r5:bf4051ec
[133258.396281]  r4:bf409f90 r3:c1205094
[133258.396288] [<c0220ab0>] (__warn) from [<c0b63b54>] (warn_slowpath_fmt+0x70/0xd8)
[133258.396293]  r7:0000060c r6:bf409f90 r5:c1205048 r4:00000000
[133258.396313] [<c0b63ae8>] (warn_slowpath_fmt) from [<bf4051ec>] (vb2_start_streaming+0x108/0x178 [videobuf2_common])
[133258.396319]  r9:bf275068 r8:c344e3e0 r7:00000001 r6:d3266d78 r5:d3266e78 r4:fffffffe
[133258.396339] [<bf4050e4>] (vb2_start_streaming [videobuf2_common]) from [<bf4058c8>] (vb2_core_streamon+0x90/0x180 [videobuf2_common])
[133258.396345]  r7:00000001 r6:c1205048 r5:d3266c00 r4:d3266d78
[133258.396364] [<bf405838>] (vb2_core_streamon [videobuf2_common]) from [<bf43b044>] (vb2_streamon+0x24/0x64 [videobuf2_v4l2])
[133258.396369]  r5:d3266c00 r4:0000000a
[133258.396387] [<bf43b020>] (vb2_streamon [videobuf2_v4l2]) from [<bf2e10dc>] (v4l2_m2m_streamon+0x30/0x60 [v4l2_mem2mem])
[133258.396404] [<bf2e10ac>] (v4l2_m2m_streamon [v4l2_mem2mem]) from [<bf2e112c>] (v4l2_m2m_ioctl_streamon+0x20/0x24 [v4l2_mem2mem])
[133258.396409]  r7:00000001 r6:c1205048 r5:40045612 r4:bf2e110c
[133258.396461] [<bf2e110c>] (v4l2_m2m_ioctl_streamon [v4l2_mem2mem]) from [<bf275094>] (v4l_streamon+0x2c/0x30 [videodev])
[133258.396526] [<bf275068>] (v4l_streamon [videodev]) from [<bf27a114>] (__video_do_ioctl+0x234/0x460 [videodev])
[133258.396531]  r5:40045612 r4:c344e0a0
[133258.396591] [<bf279ee0>] (__video_do_ioctl [videodev]) from [<bf27ab28>] (video_usercopy+0x128/0x5ac [videodev])
[133258.396598]  r10:d6243e3c r9:98c1228c r8:00000000 r7:c2cd66c0 r6:c1205048 r5:40045612
[133258.396601]  r4:40045612
[133258.396660] [<bf27aa00>] (video_usercopy [videodev]) from [<bf27afcc>] (video_ioctl2+0x20/0x24 [videodev])
[133258.396666]  r10:000000e5 r9:d6242000 r8:00000000 r7:c2cd66c0 r6:c2cd66c1 r5:c1205048
[133258.396670]  r4:bf27afac
[133258.396730] [<bf27afac>] (video_ioctl2 [videodev]) from [<bf2731f4>] (v4l2_ioctl+0x4c/0x60 [videodev])
[133258.396769] [<bf2731a8>] (v4l2_ioctl [videodev]) from [<c045178c>] (sys_ioctl+0x1d4/0x8ec)
[133258.396773]  r5:c1205048 r4:40045612
[133258.396781] [<c04515b8>] (sys_ioctl) from [<c02001e4>] (__sys_trace_return+0x0/0x1c)
[133258.396786] Exception stack(0xd6243fa8 to 0xd6243ff0)
[133258.396791] 3fa0:                   98c1228c 40045612 000000e5 40045612 98c1228c 037892ec
[133258.396797] 3fc0: 98c1228c 40045612 0b47d680 00000036 00000001 ffffffff 98c12360 98c121d8
[133258.396802] 3fe0: 08f91a48 98c121c4 03789310 b54c751c
[133258.396808]  r10:00000036 r9:d6242000 r8:c0200204 r7:00000036 r6:0b47d680 r5:40045612
[133258.396812]  r4:98c1228c
[133258.396818] ---[ end trace c6f7cb0f10279b2e ]---

User avatar
jbeale
Posts: 3884
Joined: Tue Nov 22, 2011 11:51 pm
Contact: Website

Re: lockup on 4b : Firmware transaction timeout ?

Wed Jun 02, 2021 9:38 pm

Unfortunately the update did not solve the problem. Mouse and display lockup still happens. Logging in remotely via ssh and doing 'dmesg' gives this:

Code: Select all

[279375.308861] bcm2835-codec bcm2835-codec: bcm2835_codec_buf_prepare data will not fit into plane (1536 < 264960)
[279375.309038] bcm2835-codec bcm2835-codec: bcm2835_codec_buf_prepare data will not fit into plane (1536 < 264960)
[279375.309177] bcm2835-codec bcm2835-codec: bcm2835_codec_buf_prepare data will not fit into plane (1536 < 264960)
[279375.311631] bcm2835-codec bcm2835-codec: bcm2835_codec_buf_prepare data will not fit into plane (1536 < 264960)
[279377.003728] ------------[ cut here ]------------
[279377.003749] WARNING: CPU: 3 PID: 31248 at drivers/firmware/raspberrypi.c:64 rpi_firmware_transaction+0xec/0x128
[279377.003755] Firmware transaction timeout
[279377.003761] Modules linked in: snd_seq_dummy snd_seq rfcomm bnep hci_uart btbcm bluetooth ecdh_generic ecc fuse 8021q garp stp llc sg cdc_acm mct_u232 usbserial rpivid_mem brcmfmac brcmutil v3d sha256_generic gpu_sched cfg80211 raspberrypi_hwmon rfkill i2c_bcm2835 vc4 cec bcm2835_codec(C) bcm2835_isp(C) bcm2835_v4l2(C) bcm2835_mmal_vchiq(C) v4l2_mem2mem videobuf2_vmalloc videobuf2_dma_contig videobuf2_memops videobuf2_v4l2 videobuf2_common snd_usb_audio drm_kms_helper snd_hwdep snd_bcm2835(C) snd_usbmidi_lib videodev vc_sm_cma(C) snd_rawmidi snd_seq_device mc drm drm_panel_orientation_quirks snd_soc_core snd_compress snd_pcm_dmaengine snd_pcm snd_timer snd syscopyarea sysfillrect sysimgblt fb_sys_fops backlight uio_pdrv_genirq nvmem_rmem uio i2c_dev ip_tables x_tables ipv6
[279377.004166] CPU: 3 PID: 31248 Comm: kworker/3:1 Tainted: G        WC        5.10.17-v7l+ #1421
[279377.004171] Hardware name: BCM2711
[279377.004180] Workqueue: events dbs_work_handler
[279377.004187] Backtrace:
[279377.004201] [<c0b63050>] (dump_backtrace) from [<c0b633e4>] (show_stack+0x20/0x24)
[279377.004207]  r7:ffffffff r6:00000000 r5:60000013 r4:c12e69fc
[279377.004215] [<c0b633c4>] (show_stack) from [<c0b67774>] (dump_stack+0xcc/0xf8)
[279377.004223] [<c0b676a8>] (dump_stack) from [<c0220bac>] (__warn+0xfc/0x114)
[279377.004230]  r10:dec09008 r9:00000009 r8:c099d5b8 r7:00000040 r6:00000009 r5:c099d5b8
[279377.004234]  r4:c0e9abc8 r3:c1205094
[279377.004241] [<c0220ab0>] (__warn) from [<c0b63b88>] (warn_slowpath_fmt+0xa4/0xd8)
[279377.004246]  r7:00000040 r6:c0e9abc8 r5:c1205048 r4:c0e9abe8
[279377.004255] [<c0b63ae8>] (warn_slowpath_fmt) from [<c099d5b8>] (rpi_firmware_transaction+0xec/0x128)
[279377.004260]  r9:c1a55740 r8:00000018 r7:00000000 r6:ffffff92 r5:c1a55740 r4:c1205048
[279377.004268] [<c099d4cc>] (rpi_firmware_transaction) from [<c099d6b0>] (rpi_firmware_property_list+0xbc/0x170)
[279377.004273]  r7:c1205048 r6:dec09000 r5:00001000 r4:dec09024
[279377.004280] [<c099d5f4>] (rpi_firmware_property_list) from [<c099d7d4>] (rpi_firmware_property+0x70/0x118)
[279377.004286]  r10:c9e966cc r9:00030002 r8:00000018 r7:c1a55740 r6:c9129d48 r5:0000000c
[279377.004290]  r4:c9e966c0
[279377.004299] [<c099d764>] (rpi_firmware_property) from [<c07e4e54>] (raspberrypi_clock_property+0x54/0x7c)
[279377.004304]  r10:00000000 r9:00000000 r8:c22b3f80 r7:00000000 r6:59682f00 r5:c9129d70
[279377.004309]  r4:c1205048 r3:0000000c
[279377.004315] [<c07e4e00>] (raspberrypi_clock_property) from [<c07e4ec8>] (raspberrypi_fw_get_rate+0x4c/0x70)
[279377.004319]  r5:00000000 r4:c1205048
[279377.004326] [<c07e4e7c>] (raspberrypi_fw_get_rate) from [<c07db7d4>] (clk_recalc+0x44/0x84)
[279377.004330]  r4:c1b79900
[279377.004337] [<c07db790>] (clk_recalc) from [<c07dbac4>] (__clk_recalc_rates+0x30/0x94)
[279377.004341]  r5:00000000 r4:c1b79900
[279377.004348] [<c07dba94>] (__clk_recalc_rates) from [<c07dbb80>] (clk_core_get_rate_recalc+0x58/0x5c)
[279377.004353]  r7:00000000 r6:c1205048 r5:3b9aca00 r4:c1b79900
[279377.004360] [<c07dbb28>] (clk_core_get_rate_recalc) from [<c07dbbac>] (clk_get_rate+0x28/0x38)
[279377.004364]  r5:3b9aca00 r4:c22b3f80
[279377.004370] [<c07dbb84>] (clk_get_rate) from [<c0968a10>] (dev_pm_opp_set_rate+0x70/0x588)
[279377.004375]  r5:3b9aca00 r4:c1ad7200
[279377.004382] [<c09689a0>] (dev_pm_opp_set_rate) from [<c0973900>] (set_target+0x38/0x3c)
[279377.004388]  r10:00000000 r9:00000000 r8:00000004 r7:00000000 r6:c1404e44 r5:c1205048
[279377.004392]  r4:c1ad7400
[279377.004399] [<c09738c8>] (set_target) from [<c096e604>] (__cpufreq_driver_target+0x1bc/0x540)
[279377.004406] [<c096e448>] (__cpufreq_driver_target) from [<c0971994>] (od_dbs_update+0xc4/0x170)
[279377.004412]  r10:00000000 r9:c3672300 r8:c4399780 r7:c3672380 r6:c3672300 r5:c3672380
[279377.004416]  r4:c1ad7400
[279377.004424] [<c09718d0>] (od_dbs_update) from [<c0972bf8>] (dbs_work_handler+0x3c/0x64)
[279377.004429]  r9:00000000 r8:c131beac r7:c1ad7400 r6:c3672384 r5:00000000 r4:c36723b8
[279377.004438] [<c0972bbc>] (dbs_work_handler) from [<c023dc18>] (process_one_work+0x250/0x5a0)
[279377.004444]  r9:00000000 r8:000000c0 r7:eff51900 r6:eff4e640 r5:c7600880 r4:c36723b8
[279377.004451] [<c023d9c8>] (process_one_work) from [<c023dfc8>] (worker_thread+0x60/0x5c4)
[279377.004456]  r10:eff4e640 r9:c1203d00 r8:eff4e658 r7:00000008 r6:eff4e640 r5:c7600894
[279377.004460]  r4:c7600880
[279377.004469] [<c023df68>] (worker_thread) from [<c0245a50>] (kthread+0x170/0x174)
[279377.004474]  r10:c84a9e74 r9:c7600880 r8:c023df68 r7:c9128000 r6:00000000 r5:c6e24900
[279377.004478]  r4:d5ffef40
[279377.004485] [<c02458e0>] (kthread) from [<c02000ec>] (ret_from_fork+0x14/0x28)
[279377.004490] Exception stack(0xc9129fb0 to 0xc9129ff8)
[279377.004495] 9fa0:                                     00000000 00000000 00000000 00000000
[279377.004500] 9fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[279377.004505] 9fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[279377.004512]  r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c02458e0
[279377.004515]  r4:c6e24900
[279377.004521] ---[ end trace c6f7cb0f10279b2f ]---
[279377.004543] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967186 (-34)
[279378.043767] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -110
[279378.603800] bcm2835_mmal_vchiq: timed out waiting for sync completion
[279379.083795] hwmon hwmon1: Failed to get throttled (-110)
[279381.163834] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-v3d frequency: -110
[279381.643819] bcm2835_mmal_vchiq: timed out waiting for sync completion
[279381.643836] bcm2835-codec bcm2835-codec: bcm2835_codec_stop_streaming: Failed disabling o/p port, ret -62
[279384.683883] bcm2835_mmal_vchiq: timed out waiting for sync completion
[279384.683900] bcm2835-codec bcm2835-codec: bcm2835_codec_stop_streaming: Failed disabling i/p port, ret -62
[279387.723940] bcm2835_mmal_vchiq: timed out waiting for sync completion
[279387.723956] bcm2835-codec bcm2835-codec: bcm2835_codec_stop_streaming: Failed enabling component, ret -62
[279390.764006] bcm2835_mmal_vchiq: timed out waiting for sync completion
[279390.764023] bcm2835-codec bcm2835-codec: bcm2835_codec_stop_streaming: Failed disabling o/p port, ret -62
[279393.804069] bcm2835_mmal_vchiq: timed out waiting for sync completion
[279393.804090] bcm2835-codec bcm2835-codec: bcm2835_codec_stop_streaming: Failed disabling i/p port, ret -62
[279396.844102] bcm2835_mmal_vchiq: timed out waiting for sync completion
[279396.844118] bcm2835-codec bcm2835-codec: bcm2835_codec_stop_streaming: Failed enabling component, ret -62
[279399.884159] bcm2835_mmal_vchiq: timed out waiting for sync completion
[279399.884175] bcm2835_mmal_vchiq: vchiq_mmal_component_init: failed to create component -62 (Not enough GPU mem?)
[279399.884183] bcm2835-codec bcm2835-codec: bcm2835_codec_create_component: failed to create component ril.video_decode
[279402.924222] bcm2835_mmal_vchiq: timed out waiting for sync completion
[279405.964284] bcm2835_mmal_vchiq: timed out waiting for sync completion
[279409.004340] bcm2835_mmal_vchiq: timed out waiting for sync completion
[279412.044400] bcm2835_mmal_vchiq: timed out waiting for sync completion
[279554.527217] INFO: task Xorg:598 blocked for more than 122 seconds.
[279554.527227]       Tainted: G        WC        5.10.17-v7l+ #1421
[279554.527234] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[279554.527241] task:Xorg            state:D stack:    0 pid:  598 ppid:   562 flags:0x00000001
[279554.527256] Backtrace:
[279554.527281] [<c0b6d050>] (__schedule) from [<c0b6da28>] (schedule+0x68/0xe4)
[279554.527291]  r10:00000000 r9:00000002 r8:c1205048 r7:c5320000 r6:c5321b44 r5:c42e9f00
[279554.527298]  r4:ffffe000
[279554.527308] [<c0b6d9c0>] (schedule) from [<c0b6de70>] (schedule_preempt_disabled+0x18/0x1c)
[279554.527315]  r5:ffffe000 r4:c131de10
[279554.527327] [<c0b6de58>] (schedule_preempt_disabled) from [<c0b700f8>] (__mutex_lock.constprop.9+0x344/0x58c)
[279554.527337] [<c0b6fdb4>] (__mutex_lock.constprop.9) from [<c0b7045c>] (__mutex_lock_slowpath+0x1c/0x20)
[279554.527346]  r10:dec09008 r9:c1a55740 r8:00000018 r7:c1205048 r6:dec09000 r5:c1a55740
[279554.527352]  r4:c131de10
[279554.527362] [<c0b70440>] (__mutex_lock_slowpath) from [<c0b704bc>] (mutex_lock+0x5c/0x60)
[279554.527374] [<c0b70460>] (mutex_lock) from [<c099d51c>] (rpi_firmware_transaction+0x50/0x128)
[279554.527381]  r5:c1a55740 r4:c1205048
[279554.527391] [<c099d4cc>] (rpi_firmware_transaction) from [<c099d6b0>] (rpi_firmware_property_list+0xbc/0x170)
[279554.527398]  r7:c1205048 r6:dec09000 r5:00001000 r4:dec09024
[279554.527408] [<c099d5f4>] (rpi_firmware_property_list) from [<c099d7d4>] (rpi_firmware_property+0x70/0x118)
[279554.527416]  r10:c9f8970c r9:00038002 r8:00000018 r7:c1a55740 r6:c5321c60 r5:0000000c
[279554.527422]  r4:c9f89700
[279554.527433] [<c099d764>] (rpi_firmware_property) from [<c07e4e54>] (raspberrypi_clock_property+0x54/0x7c)
[279554.527441]  r10:c33c3c00 r9:ffffff92 r8:1dcd6500 r7:c209b1c0 r6:00000000 r5:c5321c88
[279554.527448]  r4:c1205048 r3:0000000c
[279554.527456] [<c07e4e00>] (raspberrypi_clock_property) from [<c07e4fb0>] (raspberrypi_fw_set_rate+0x4c/0xb8)
[279554.527463]  r5:c209b640 r4:c1205048
[279554.527473] [<c07e4f64>] (raspberrypi_fw_set_rate) from [<c07dd348>] (clk_change_rate+0xf4/0x4ac)
[279554.527480]  r7:00000000 r6:00000000 r5:00000000 r4:c1b79a80
[279554.527489] [<c07dd254>] (clk_change_rate) from [<c07dd87c>] (clk_core_set_rate_nolock+0x17c/0x1a4)
[279554.527497]  r10:c33c3c00 r9:00000000 r8:c1b79a80 r7:1dcd6500 r6:00000000 r5:c1205048
[279554.527504]  r4:c1b79a80
[279554.527513] [<c07dd700>] (clk_core_set_rate_nolock) from [<c07dd8e4>] (clk_set_rate+0x40/0x98)
[279554.527520]  r8:d32a2d10 r7:c31e2000 r6:00000000 r5:1dcd6500 r4:c3660100
[279554.527545] [<c07dd8a4>] (clk_set_rate) from [<bf25dd58>] (v3d_clock_up_get+0x64/0xac [v3d])
[279554.527552]  r5:c31e23e8 r4:c31e2000
[279554.527578] [<bf25dcf4>] (v3d_clock_up_get [v3d]) from [<bf25de6c>] (v3d_job_init+0xcc/0xdc [v3d])
[279554.527585]  r5:c1205048 r4:d32a2cc0
[279554.527609] [<bf25dda0>] (v3d_job_init [v3d]) from [<bf25ee68>] (v3d_submit_cl_ioctl+0xa4/0x63c [v3d])
[279554.527618]  r9:c0eb13f8 r8:c31e2000 r7:c3d06100 r6:d32a2cc0 r5:c1205048 r4:c5321e64
[279554.527715] [<bf25edc4>] (v3d_submit_cl_ioctl [v3d]) from [<bf1c546c>] (drm_ioctl_kernel+0xb8/0xfc [drm])
[279554.527723]  r10:c5321e64 r9:bf25edc4 r8:00000021 r7:00000000 r6:c3d06100 r5:c31e2000
[279554.527729]  r4:c1205048
[279554.527880] [<bf1c53b4>] (drm_ioctl_kernel [drm]) from [<bf1c5694>] (drm_ioctl+0x1e4/0x3a8 [drm])
[279554.527888]  r10:00000038 r9:c5321e64 r8:c3d06100 r7:00000040 r6:bf25edc4 r5:c1205048
[279554.527895]  r4:bf265398
[279554.527975] [<bf1c54b0>] (drm_ioctl [drm]) from [<c045178c>] (sys_ioctl+0x1d4/0x8ec)
[279554.527984]  r10:0000000e r9:c5320000 r8:00000000 r7:c411b240 r6:c411b241 r5:c1205048
[279554.527990]  r4:c0386440
[279554.528000] [<c04515b8>] (sys_ioctl) from [<c0200040>] (ret_fast_syscall+0x0/0x28)
[279554.528007] Exception stack(0xc5321fa8 to 0xc5321ff0)
[279554.528015] 1fa0:                   00f7fe50 00f7fe98 0000000e c0386440 00f7fe98 b5fd31cc
[279554.528024] 1fc0: 00f7fe50 00f7fe98 c0386440 00000036 b5dbc000 0042ee50 00007fff 0042bec8
[279554.528031] 1fe0: b6cdc08c bed663cc b6cc288c b694e51c
[279554.528039]  r10:00000036 r9:c5320000 r8:c0200204 r7:00000036 r6:c0386440 r5:00f7fe98
[279554.528046]  r4:00f7fe50
[279554.528075] INFO: task chromium-browse:843 blocked for more than 122 seconds.
[279554.528083]       Tainted: G        WC        5.10.17-v7l+ #1421
[279554.528089] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[279554.528096] task:chromium-browse state:D stack:    0 pid:  843 ppid:   815 flags:0x00000081
[279554.528109] Backtrace:
[279554.528124] [<c0b6d050>] (__schedule) from [<c0b6da28>] (schedule+0x68/0xe4)
[279554.528132]  r10:00000000 r9:00000002 r8:c1205048 r7:cbad2000 r6:cbad3cd4 r5:ca580000
[279554.528139]  r4:ffffe000
[279554.528148] [<c0b6d9c0>] (schedule) from [<c0b6de70>] (schedule_preempt_disabled+0x18/0x1c)
[279554.528155]  r5:ffffe000 r4:c31e23e8
[279554.528165] [<c0b6de58>] (schedule_preempt_disabled) from [<c0b700f8>] (__mutex_lock.constprop.9+0x344/0x58c)
[279554.528176] [<c0b6fdb4>] (__mutex_lock.constprop.9) from [<c0b7045c>] (__mutex_lock_slowpath+0x1c/0x20)
[279554.528183]  r10:c3175c00 r9:00000000 r8:c2e14b90 r7:c31e2000 r6:00000000 r5:c31e23e8
[279554.528190]  r4:c31e23e8
[279554.528200] [<c0b70440>] (__mutex_lock_slowpath) from [<c0b704bc>] (mutex_lock+0x5c/0x60)
[279554.528218] [<c0b70460>] (mutex_lock) from [<bf25dd18>] (v3d_clock_up_get+0x24/0xac [v3d])
[279554.528225]  r5:c31e23e8 r4:c31e2000
[279554.528248] [<bf25dcf4>] (v3d_clock_up_get [v3d]) from [<bf25de6c>] (v3d_job_init+0xcc/0xdc [v3d])
[279554.528255]  r5:c1205048 r4:c2e14b40
[279554.528277] [<bf25dda0>] (v3d_job_init [v3d]) from [<bf25ee68>] (v3d_submit_cl_ioctl+0xa4/0x63c [v3d])
[279554.528285]  r9:c0eb13f8 r8:c31e2000 r7:d341de00 r6:c2e14b40 r5:c1205048 r4:cbad3e64
[279554.528373] [<bf25edc4>] (v3d_submit_cl_ioctl [v3d]) from [<bf1c546c>] (drm_ioctl_kernel+0xb8/0xfc [drm])
[279554.528381]  r10:cbad3e64 r9:bf25edc4 r8:00000021 r7:00000000 r6:d341de00 r5:c31e2000
[279554.528387]  r4:c1205048
[279554.528533] [<bf1c53b4>] (drm_ioctl_kernel [drm]) from [<bf1c5694>] (drm_ioctl+0x1e4/0x3a8 [drm])
[279554.528542]  r10:00000038 r9:cbad3e64 r8:d341de00 r7:00000040 r6:bf25edc4 r5:c1205048
[279554.528548]  r4:bf265398
[279554.528626] [<bf1c54b0>] (drm_ioctl [drm]) from [<c045178c>] (sys_ioctl+0x1d4/0x8ec)
[279554.528634]  r10:00000017 r9:cbad2000 r8:00000000 r7:c6e9bc00 r6:c6e9bc01 r5:c1205048
[279554.528641]  r4:c0386440
[279554.528650] [<c04515b8>] (sys_ioctl) from [<c02001e4>] (__sys_trace_return+0x0/0x1c)
[279554.528656] Exception stack(0xcbad3fa8 to 0xcbad3ff0)
[279554.528665] 3fa0:                   0ccf6318 0ccf6360 00000017 c0386440 0ccf6360 b20c41cc
[279554.528673] 3fc0: 0ccf6318 0ccf6360 c0386440 00000036 b1ead000 0981f900 0991c5f0 bec42720
[279554.528681] 3fe0: b61b508c bec425d4 b619b88c b54dc51c
[279554.528689]  r10:00000036 r9:cbad2000 r8:c0200204 r7:00000036 r6:c0386440 r5:0ccf6360
[279554.528696]  r4:0ccf6318
[279554.528728] INFO: task kworker/2:0:28007 blocked for more than 122 seconds.
[279554.528734]       Tainted: G        WC        5.10.17-v7l+ #1421
[279554.528740] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[279554.528748] task:kworker/2:0     state:D stack:    0 pid:28007 ppid:     2 flags:0x00000000
[279554.528766] Workqueue: events dbs_work_handler
[279554.528777] Backtrace:
[279554.528793] [<c0b6d050>] (__schedule) from [<c0b6da28>] (schedule+0x68/0xe4)
[279554.528801]  r10:00000001 r9:00000002 r8:c1205048 r7:c67f2000 r6:c67f3d3c r5:ca709f00
[279554.528807]  r4:ffffe000
[279554.528817] [<c0b6d9c0>] (schedule) from [<c0b6de70>] (schedule_preempt_disabled+0x18/0x1c)
[279554.528824]  r5:ffffe000 r4:c12e8a74
[279554.528834] [<c0b6de58>] (schedule_preempt_disabled) from [<c0b700f8>] (__mutex_lock.constprop.9+0x344/0x58c)
[279554.528845] [<c0b6fdb4>] (__mutex_lock.constprop.9) from [<c0b7045c>] (__mutex_lock_slowpath+0x1c/0x20)
[279554.528853]  r10:00000000 r9:00000000 r8:c22b3f80 r7:00000000 r6:23c34600 r5:c22b3f80
[279554.528859]  r4:c12e8a74
[279554.528869] [<c0b70440>] (__mutex_lock_slowpath) from [<c0b704bc>] (mutex_lock+0x5c/0x60)
[279554.528879] [<c0b70460>] (mutex_lock) from [<c07d8ee4>] (clk_prepare_lock+0x60/0x110)
[279554.528886]  r5:c22b3f80 r4:c13fcdd4
[279554.528896] [<c07d8e84>] (clk_prepare_lock) from [<c07dac14>] (clk_round_rate+0x3c/0xe4)
[279554.528903]  r5:c22b3f80 r4:c1205048
[279554.528912] [<c07dabd8>] (clk_round_rate) from [<c0968a00>] (dev_pm_opp_set_rate+0x60/0x588)
[279554.528920]  r6:c1205048 r5:23c34600 r4:c1ad7200
[279554.528929] [<c09689a0>] (dev_pm_opp_set_rate) from [<c0973900>] (set_target+0x38/0x3c)
[279554.528937]  r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:c1404e44 r5:c1205048
[279554.528943]  r4:c1ad7400
[279554.528953] [<c09738c8>] (set_target) from [<c096e604>] (__cpufreq_driver_target+0x1bc/0x540)
[279554.528963] [<c096e448>] (__cpufreq_driver_target) from [<c0971994>] (od_dbs_update+0xc4/0x170)
[279554.528971]  r10:00000000 r9:c3672300 r8:c4399780 r7:c3672380 r6:c3672300 r5:c3672380
[279554.528977]  r4:c1ad7400
[279554.528987] [<c09718d0>] (od_dbs_update) from [<c0972bf8>] (dbs_work_handler+0x3c/0x64)
[279554.528995]  r9:00000000 r8:c131beac r7:c1ad7400 r6:c3672384 r5:00000000 r4:c36723b8
[279554.529006] [<c0972bbc>] (dbs_work_handler) from [<c023dc18>] (process_one_work+0x250/0x5a0)
[279554.529015]  r9:00000000 r8:00000080 r7:eff3d900 r6:eff3a640 r5:d1f7e180 r4:c36723b8
[279554.529024] [<c023d9c8>] (process_one_work) from [<c023dfc8>] (worker_thread+0x60/0x5c4)
[279554.529032]  r10:eff3a640 r9:c1203d00 r8:eff3a658 r7:00000008 r6:eff3a640 r5:d1f7e194
[279554.529039]  r4:d1f7e180
[279554.529049] [<c023df68>] (worker_thread) from [<c0245a50>] (kthread+0x170/0x174)
[279554.529057]  r10:c5ad7e74 r9:d1f7e180 r8:c023df68 r7:c67f2000 r6:00000000 r5:d2072b80
[279554.529064]  r4:cb8f8600
[279554.529072] [<c02458e0>] (kthread) from [<c02000ec>] (ret_from_fork+0x14/0x28)
[279554.529079] Exception stack(0xc67f3fb0 to 0xc67f3ff8)
[279554.529086] 3fa0:                                     00000000 00000000 00000000 00000000
[279554.529094] 3fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[279554.529102] 3fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[279554.529110]  r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c02458e0
[279554.529116]  r4:d2072b80
[279554.529124] INFO: task kworker/0:0:30104 blocked for more than 122 seconds.
[279554.529131]       Tainted: G        WC        5.10.17-v7l+ #1421
[279554.529137] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[279554.529143] task:kworker/0:0     state:D stack:    0 pid:30104 ppid:     2 flags:0x00000000
[279554.529163] Workqueue: events get_values_poll [raspberrypi_hwmon]
[279554.529174] Backtrace:
[279554.529189] [<c0b6d050>] (__schedule) from [<c0b6da28>] (schedule+0x68/0xe4)
[279554.529197]  r10:00000000 r9:00000002 r8:c1205048 r7:d5c42000 r6:d5c43dbc r5:cf424d80
[279554.529204]  r4:ffffe000
[279554.529213] [<c0b6d9c0>] (schedule) from [<c0b6de70>] (schedule_preempt_disabled+0x18/0x1c)
[279554.529220]  r5:ffffe000 r4:c131de10
[279554.529230] [<c0b6de58>] (schedule_preempt_disabled) from [<c0b700f8>] (__mutex_lock.constprop.9+0x344/0x58c)
[279554.529240] [<c0b6fdb4>] (__mutex_lock.constprop.9) from [<c0b7045c>] (__mutex_lock_slowpath+0x1c/0x20)
[279554.529248]  r10:dec0c008 r9:c1a55740 r8:00000010 r7:c1205048 r6:dec0c000 r5:c1a55740
[279554.529255]  r4:c131de10
[279554.529264] [<c0b70440>] (__mutex_lock_slowpath) from [<c0b704bc>] (mutex_lock+0x5c/0x60)
[279554.529275] [<c0b70460>] (mutex_lock) from [<c099d51c>] (rpi_firmware_transaction+0x50/0x128)
[279554.529282]  r5:c1a55740 r4:c1205048
[279554.529292] [<c099d4cc>] (rpi_firmware_transaction) from [<c099d6b0>] (rpi_firmware_property_list+0xbc/0x170)
[279554.529299]  r7:c1205048 r6:dec0c000 r5:00001000 r4:dec0c01c
[279554.529309] [<c099d5f4>] (rpi_firmware_property_list) from [<c099d7d4>] (rpi_firmware_property+0x70/0x118)
[279554.529318]  r10:c9f899cc r9:00030046 r8:00000010 r7:c1a55740 r6:d5c43ed8 r5:00000004
[279554.529324]  r4:c9f899c0
[279554.529335] [<c099d764>] (rpi_firmware_property) from [<bf1410c0>] (get_values_poll+0x4c/0x150 [raspberrypi_hwmon])
[279554.529343]  r10:00000000 r9:00000000 r8:00000000 r7:eff15900 r6:eff12640 r5:c1a48c4c
[279554.529349]  r4:c1205048 r3:00000004
[279554.529360] [<bf141074>] (get_values_poll [raspberrypi_hwmon]) from [<c023dc18>] (process_one_work+0x250/0x5a0)
[279554.529367]  r5:d6852000 r4:c1a48c4c
[279554.529376] [<c023d9c8>] (process_one_work) from [<c023dfc8>] (worker_thread+0x60/0x5c4)
[279554.529384]  r10:eff12640 r9:c1203d00 r8:eff12658 r7:00000008 r6:eff12640 r5:d6852014
[279554.529391]  r4:d6852000
[279554.529400] [<c023df68>] (worker_thread) from [<c0245a50>] (kthread+0x170/0x174)
[279554.529408]  r10:c8925e74 r9:d6852000 r8:c023df68 r7:d5c42000 r6:00000000 r5:cba53f00
[279554.529415]  r4:cba53840
[279554.529423] [<c02458e0>] (kthread) from [<c02000ec>] (ret_from_fork+0x14/0x28)
[279554.529429] Exception stack(0xd5c43fb0 to 0xd5c43ff8)
[279554.529437] 3fa0:                                     00000000 00000000 00000000 00000000
[279554.529444] 3fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[279554.529452] 3fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[279554.529461]  r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c02458e0
[279554.529467]  r4:cba53f00
[279554.529474] INFO: task kworker/2:1:30251 blocked for more than 122 seconds.
[279554.529481]       Tainted: G        WC        5.10.17-v7l+ #1421
[279554.529487] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[279554.529494] task:kworker/2:1     state:D stack:    0 pid:30251 ppid:     2 flags:0x00000000
[279554.529510] Workqueue: events_freezable mmc_rescan
[279554.529521] Backtrace:
[279554.529537] [<c0b6d050>] (__schedule) from [<c0b6da28>] (schedule+0x68/0xe4)
[279554.529545]  r10:dec0b008 r9:eff33540 r8:eff33540 r7:c1205048 r6:c8759be4 r5:c3e48f80
[279554.529551]  r4:ffffe000
[279554.529561] [<c0b6d9c0>] (schedule) from [<c0b71d94>] (schedule_timeout+0x1d0/0x384)
[279554.529568]  r5:c1203d00 r4:01af5558
[279554.529578] [<c0b71bc4>] (schedule_timeout) from [<c0b6ea08>] (wait_for_completion_timeout+0xb8/0x144)
[279554.529586]  r9:00000002 r8:ffffe000 r7:c197ae90 r6:c1205048 r5:00057e40 r4:c197ae8c
[279554.529598] [<c0b6e950>] (wait_for_completion_timeout) from [<c09cd84c>] (mbox_send_message+0xb8/0x11c)
[279554.529606]  r9:c1a55740 r8:00000014 r7:c8759c80 r6:c197aef8 r5:00000000 r4:c197ae80
[279554.529615] [<c09cd794>] (mbox_send_message) from [<c099d530>] (rpi_firmware_transaction+0x64/0x128)
[279554.529623]  r7:00000000 r6:dec0b000 r5:c1a55740 r4:c1205048
[279554.529632] [<c099d4cc>] (rpi_firmware_transaction) from [<c099d6b0>] (rpi_firmware_property_list+0xbc/0x170)
[279554.529640]  r7:c1205048 r6:dec0b000 r5:00001000 r4:dec0b020
[279554.529650] [<c099d5f4>] (rpi_firmware_property_list) from [<c099d7d4>] (rpi_firmware_property+0x70/0x118)
[279554.529658]  r10:d1e2b10c r9:00038041 r8:00000014 r7:c1a55740 r6:c8759d3c r5:00000008
[279554.529664]  r4:d1e2b100
[279554.529675] [<c099d764>] (rpi_firmware_property) from [<c0793f10>] (rpi_exp_gpio_set+0x5c/0xa0)
[279554.529683]  r10:00000000 r9:00000000 r8:00000000 r7:c1bcb440 r6:00000000 r5:00000006
[279554.529690]  r4:c1205048 r3:00000008
[279554.529699] [<c0793eb4>] (rpi_exp_gpio_set) from [<c0789b88>] (gpiod_set_raw_value_commit+0x50/0xfc)
[279554.529707]  r7:c22d2034 r6:00000000 r5:c1bcb440 r4:c1b79750
[279554.529716] [<c0789b38>] (gpiod_set_raw_value_commit) from [<c0789d40>] (gpiod_set_value_nocheck+0x54/0x60)
[279554.529724]  r9:00000000 r8:00000000 r7:c22d2034 r6:eeffc398 r5:00000000 r4:c1b79750
[279554.529733] [<c0789cec>] (gpiod_set_value_nocheck) from [<c0789df4>] (gpiod_set_value_cansleep+0x38/0x40)
[279554.529743] [<c0789dbc>] (gpiod_set_value_cansleep) from [<c07ef424>] (_regulator_do_disable+0x210/0x21c)
[279554.529750]  r5:c22c1ec0 r4:c22d2000
[279554.529761] [<c07ef214>] (_regulator_do_disable) from [<c07f26ac>] (_regulator_disable+0xc8/0x1a8)
[279554.529768]  r7:c22d2034 r6:c22c8780 r5:c22c8780 r4:c22d2000
[279554.529779] [<c07f25e4>] (_regulator_disable) from [<c07f27d0>] (regulator_disable+0x44/0x74)
[279554.529787]  r8:c0c63e0c r7:00000000 r6:c22c8780 r5:c22d2000 r4:c1205048
[279554.529797] [<c07f278c>] (regulator_disable) from [<c09856c8>] (mmc_regulator_set_ocr+0xe0/0xf0)
[279554.529804]  r6:c22c8780 r5:c21fc800 r4:c21fcb80
[279554.529813] [<c09855e8>] (mmc_regulator_set_ocr) from [<c098f3fc>] (sdhci_set_power_and_bus_voltage+0x48/0x4c)
[279554.529821]  r7:00000000 r6:00000000 r5:00000000 r4:c21fcb80
[279554.529829] [<c098f3b4>] (sdhci_set_power_and_bus_voltage) from [<c098ef40>] (sdhci_set_ios+0x100/0x574)
[279554.529837]  r7:00000000 r6:c21fcb80 r5:c21fca2c r4:c21fc800
[279554.529845] [<c098ee40>] (sdhci_set_ios) from [<c097717c>] (mmc_set_initial_state+0xa0/0xa4)
[279554.529853]  r7:000186a0 r6:00000004 r5:c21fca2c r4:c21fc800
[279554.529862] [<c09770dc>] (mmc_set_initial_state) from [<c09771b8>] (mmc_power_off.part.10+0x38/0x48)
[279554.529869]  r5:c21fc800 r4:c21fc800
[279554.529877] [<c0977180>] (mmc_power_off.part.10) from [<c0978044>] (mmc_rescan+0x33c/0x3b0)
[279554.529884]  r5:c21fc800 r4:c21fca8c
[279554.529894] [<c0977d08>] (mmc_rescan) from [<c023dc18>] (process_one_work+0x250/0x5a0)
[279554.529902]  r9:00000000 r8:00000080 r7:eff3dc00 r6:eff3a640 r5:d0c51200 r4:c21fca8c
[279554.529911] [<c023d9c8>] (process_one_work) from [<c023dfc8>] (worker_thread+0x60/0x5c4)
[279554.529919]  r10:eff3a640 r9:c1203d00 r8:eff3a658 r7:00000008 r6:eff3a640 r5:d0c51214
[279554.529926]  r4:d0c51200
[279554.529935] [<c023df68>] (worker_thread) from [<c0245a50>] (kthread+0x170/0x174)
[279554.529943]  r10:d5f77e74 r9:d0c51200 r8:c023df68 r7:c8758000 r6:00000000 r5:ca4a1300
[279554.529949]  r4:c9397780
[279554.529958] [<c02458e0>] (kthread) from [<c02000ec>] (ret_from_fork+0x14/0x28)
[279554.529964] Exception stack(0xc8759fb0 to 0xc8759ff8)
[279554.529972] 9fa0:                                     00000000 00000000 00000000 00000000
[279554.529980] 9fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[279554.529987] 9fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[279554.529995]  r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c02458e0
[279554.530001]  r4:ca4a1300
[279677.409652] INFO: task Xorg:598 blocked for more than 245 seconds.
[279677.409662]       Tainted: G        WC        5.10.17-v7l+ #1421
[279677.409669] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[279677.409676] task:Xorg            state:D stack:    0 pid:  598 ppid:   562 flags:0x00000001
[279677.409691] Backtrace:
[279677.409716] [<c0b6d050>] (__schedule) from [<c0b6da28>] (schedule+0x68/0xe4)
[279677.409726]  r10:00000000 r9:00000002 r8:c1205048 r7:c5320000 r6:c5321b44 r5:c42e9f00
[279677.409733]  r4:ffffe000
[279677.409744] [<c0b6d9c0>] (schedule) from [<c0b6de70>] (schedule_preempt_disabled+0x18/0x1c)
[279677.409751]  r5:ffffe000 r4:c131de10
[279677.409762] [<c0b6de58>] (schedule_preempt_disabled) from [<c0b700f8>] (__mutex_lock.constprop.9+0x344/0x58c)
[279677.409773] [<c0b6fdb4>] (__mutex_lock.constprop.9) from [<c0b7045c>] (__mutex_lock_slowpath+0x1c/0x20)
[279677.409781]  r10:dec09008 r9:c1a55740 r8:00000018 r7:c1205048 r6:dec09000 r5:c1a55740
[279677.409787]  r4:c131de10
[279677.409797] [<c0b70440>] (__mutex_lock_slowpath) from [<c0b704bc>] (mutex_lock+0x5c/0x60)
[279677.409809] [<c0b70460>] (mutex_lock) from [<c099d51c>] (rpi_firmware_transaction+0x50/0x128)
[279677.409816]  r5:c1a55740 r4:c1205048
[279677.409826] [<c099d4cc>] (rpi_firmware_transaction) from [<c099d6b0>] (rpi_firmware_property_list+0xbc/0x170)
[279677.409834]  r7:c1205048 r6:dec09000 r5:00001000 r4:dec09024
[279677.409844] [<c099d5f4>] (rpi_firmware_property_list) from [<c099d7d4>] (rpi_firmware_property+0x70/0x118)
[279677.409853]  r10:c9f8970c r9:00038002 r8:00000018 r7:c1a55740 r6:c5321c60 r5:0000000c
[279677.409859]  r4:c9f89700
[279677.409870] [<c099d764>] (rpi_firmware_property) from [<c07e4e54>] (raspberrypi_clock_property+0x54/0x7c)
[279677.409878]  r10:c33c3c00 r9:ffffff92 r8:1dcd6500 r7:c209b1c0 r6:00000000 r5:c5321c88
[279677.409885]  r4:c1205048 r3:0000000c
[279677.409894] [<c07e4e00>] (raspberrypi_clock_property) from [<c07e4fb0>] (raspberrypi_fw_set_rate+0x4c/0xb8)
[279677.409901]  r5:c209b640 r4:c1205048
[279677.409910] [<c07e4f64>] (raspberrypi_fw_set_rate) from [<c07dd348>] (clk_change_rate+0xf4/0x4ac)
[279677.409918]  r7:00000000 r6:00000000 r5:00000000 r4:c1b79a80
[279677.409927] [<c07dd254>] (clk_change_rate) from [<c07dd87c>] (clk_core_set_rate_nolock+0x17c/0x1a4)
[279677.409936]  r10:c33c3c00 r9:00000000 r8:c1b79a80 r7:1dcd6500 r6:00000000 r5:c1205048
[279677.409942]  r4:c1b79a80
[279677.409952] [<c07dd700>] (clk_core_set_rate_nolock) from [<c07dd8e4>] (clk_set_rate+0x40/0x98)
[279677.409960]  r8:d32a2d10 r7:c31e2000 r6:00000000 r5:1dcd6500 r4:c3660100
[279677.409986] [<c07dd8a4>] (clk_set_rate) from [<bf25dd58>] (v3d_clock_up_get+0x64/0xac [v3d])
[279677.409993]  r5:c31e23e8 r4:c31e2000
[279677.410018] [<bf25dcf4>] (v3d_clock_up_get [v3d]) from [<bf25de6c>] (v3d_job_init+0xcc/0xdc [v3d])
[279677.410025]  r5:c1205048 r4:d32a2cc0
[279677.410050] [<bf25dda0>] (v3d_job_init [v3d]) from [<bf25ee68>] (v3d_submit_cl_ioctl+0xa4/0x63c [v3d])
[279677.410058]  r9:c0eb13f8 r8:c31e2000 r7:c3d06100 r6:d32a2cc0 r5:c1205048 r4:c5321e64
[279677.410153] [<bf25edc4>] (v3d_submit_cl_ioctl [v3d]) from [<bf1c546c>] (drm_ioctl_kernel+0xb8/0xfc [drm])
[279677.410161]  r10:c5321e64 r9:bf25edc4 r8:00000021 r7:00000000 r6:c3d06100 r5:c31e2000
[279677.410168]  r4:c1205048
[279677.410321] [<bf1c53b4>] (drm_ioctl_kernel [drm]) from [<bf1c5694>] (drm_ioctl+0x1e4/0x3a8 [drm])
[279677.410329]  r10:00000038 r9:c5321e64 r8:c3d06100 r7:00000040 r6:bf25edc4 r5:c1205048
[279677.410336]  r4:bf265398
[279677.410418] [<bf1c54b0>] (drm_ioctl [drm]) from [<c045178c>] (sys_ioctl+0x1d4/0x8ec)
[279677.410427]  r10:0000000e r9:c5320000 r8:00000000 r7:c411b240 r6:c411b241 r5:c1205048
[279677.410433]  r4:c0386440
[279677.410443] [<c04515b8>] (sys_ioctl) from [<c0200040>] (ret_fast_syscall+0x0/0x28)
[279677.410450] Exception stack(0xc5321fa8 to 0xc5321ff0)
[279677.410459] 1fa0:                   00f7fe50 00f7fe98 0000000e c0386440 00f7fe98 b5fd31cc
[279677.410467] 1fc0: 00f7fe50 00f7fe98 c0386440 00000036 b5dbc000 0042ee50 00007fff 0042bec8
[279677.410474] 1fe0: b6cdc08c bed663cc b6cc288c b694e51c
[279677.410482]  r10:00000036 r9:c5320000 r8:c0200204 r7:00000036 r6:c0386440 r5:00f7fe98
[279677.410489]  r4:00f7fe50
[279677.410518] INFO: task chromium-browse:843 blocked for more than 245 seconds.
[279677.410525]       Tainted: G        WC        5.10.17-v7l+ #1421
[279677.410531] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[279677.410537] task:chromium-browse state:D stack:    0 pid:  843 ppid:   815 flags:0x00000081
[279677.410550] Backtrace:
[279677.410565] [<c0b6d050>] (__schedule) from [<c0b6da28>] (schedule+0x68/0xe4)
[279677.410574]  r10:00000000 r9:00000002 r8:c1205048 r7:cbad2000 r6:cbad3cd4 r5:ca580000
[279677.410580]  r4:ffffe000
[279677.410590] [<c0b6d9c0>] (schedule) from [<c0b6de70>] (schedule_preempt_disabled+0x18/0x1c)
[279677.410597]  r5:ffffe000 r4:c31e23e8
[279677.410607] [<c0b6de58>] (schedule_preempt_disabled) from [<c0b700f8>] (__mutex_lock.constprop.9+0x344/0x58c)
[279677.410617] [<c0b6fdb4>] (__mutex_lock.constprop.9) from [<c0b7045c>] (__mutex_lock_slowpath+0x1c/0x20)
[279677.410626]  r10:c3175c00 r9:00000000 r8:c2e14b90 r7:c31e2000 r6:00000000 r5:c31e23e8
[279677.410632]  r4:c31e23e8
[279677.410642] [<c0b70440>] (__mutex_lock_slowpath) from [<c0b704bc>] (mutex_lock+0x5c/0x60)
[279677.410660] [<c0b70460>] (mutex_lock) from [<bf25dd18>] (v3d_clock_up_get+0x24/0xac [v3d])
[279677.410667]  r5:c31e23e8 r4:c31e2000
[279677.410692] [<bf25dcf4>] (v3d_clock_up_get [v3d]) from [<bf25de6c>] (v3d_job_init+0xcc/0xdc [v3d])
[279677.410698]  r5:c1205048 r4:c2e14b40
[279677.410722] [<bf25dda0>] (v3d_job_init [v3d]) from [<bf25ee68>] (v3d_submit_cl_ioctl+0xa4/0x63c [v3d])
[279677.410730]  r9:c0eb13f8 r8:c31e2000 r7:d341de00 r6:c2e14b40 r5:c1205048 r4:cbad3e64
[279677.410819] [<bf25edc4>] (v3d_submit_cl_ioctl [v3d]) from [<bf1c546c>] (drm_ioctl_kernel+0xb8/0xfc [drm])
[279677.410827]  r10:cbad3e64 r9:bf25edc4 r8:00000021 r7:00000000 r6:d341de00 r5:c31e2000
[279677.410834]  r4:c1205048
[279677.410982] [<bf1c53b4>] (drm_ioctl_kernel [drm]) from [<bf1c5694>] (drm_ioctl+0x1e4/0x3a8 [drm])
[279677.410991]  r10:00000038 r9:cbad3e64 r8:d341de00 r7:00000040 r6:bf25edc4 r5:c1205048
[279677.410997]  r4:bf265398
[279677.411077] [<bf1c54b0>] (drm_ioctl [drm]) from [<c045178c>] (sys_ioctl+0x1d4/0x8ec)
[279677.411085]  r10:00000017 r9:cbad2000 r8:00000000 r7:c6e9bc00 r6:c6e9bc01 r5:c1205048
[279677.411091]  r4:c0386440
[279677.411101] [<c04515b8>] (sys_ioctl) from [<c02001e4>] (__sys_trace_return+0x0/0x1c)
[279677.411108] Exception stack(0xcbad3fa8 to 0xcbad3ff0)
[279677.411116] 3fa0:                   0ccf6318 0ccf6360 00000017 c0386440 0ccf6360 b20c41cc
[279677.411124] 3fc0: 0ccf6318 0ccf6360 c0386440 00000036 b1ead000 0981f900 0991c5f0 bec42720
[279677.411131] 3fe0: b61b508c bec425d4 b619b88c b54dc51c
[279677.411140]  r10:00000036 r9:cbad2000 r8:c0200204 r7:00000036 r6:c0386440 r5:0ccf6360
[279677.411146]  r4:0ccf6318
[279677.411179] INFO: task kworker/2:0:28007 blocked for more than 245 seconds.
[279677.411186]       Tainted: G        WC        5.10.17-v7l+ #1421
[279677.411192] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[279677.411198] task:kworker/2:0     state:D stack:    0 pid:28007 ppid:     2 flags:0x00000000
[279677.411216] Workqueue: events dbs_work_handler
[279677.411227] Backtrace:
[279677.411242] [<c0b6d050>] (__schedule) from [<c0b6da28>] (schedule+0x68/0xe4)
[279677.411250]  r10:00000001 r9:00000002 r8:c1205048 r7:c67f2000 r6:c67f3d3c r5:ca709f00
[279677.411256]  r4:ffffe000
[279677.411266] [<c0b6d9c0>] (schedule) from [<c0b6de70>] (schedule_preempt_disabled+0x18/0x1c)
[279677.411273]  r5:ffffe000 r4:c12e8a74
[279677.411283] [<c0b6de58>] (schedule_preempt_disabled) from [<c0b700f8>] (__mutex_lock.constprop.9+0x344/0x58c)
[279677.411293] [<c0b6fdb4>] (__mutex_lock.constprop.9) from [<c0b7045c>] (__mutex_lock_slowpath+0x1c/0x20)
[279677.411302]  r10:00000000 r9:00000000 r8:c22b3f80 r7:00000000 r6:23c34600 r5:c22b3f80
[279677.411308]  r4:c12e8a74
[279677.411317] [<c0b70440>] (__mutex_lock_slowpath) from [<c0b704bc>] (mutex_lock+0x5c/0x60)
[279677.411328] [<c0b70460>] (mutex_lock) from [<c07d8ee4>] (clk_prepare_lock+0x60/0x110)
[279677.411335]  r5:c22b3f80 r4:c13fcdd4
[279677.411344] [<c07d8e84>] (clk_prepare_lock) from [<c07dac14>] (clk_round_rate+0x3c/0xe4)
[279677.411351]  r5:c22b3f80 r4:c1205048
[279677.411360] [<c07dabd8>] (clk_round_rate) from [<c0968a00>] (dev_pm_opp_set_rate+0x60/0x588)
[279677.411367]  r6:c1205048 r5:23c34600 r4:c1ad7200
[279677.411377] [<c09689a0>] (dev_pm_opp_set_rate) from [<c0973900>] (set_target+0x38/0x3c)
[279677.411385]  r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:c1404e44 r5:c1205048
[279677.411391]  r4:c1ad7400
[279677.411401] [<c09738c8>] (set_target) from [<c096e604>] (__cpufreq_driver_target+0x1bc/0x540)
[279677.411411] [<c096e448>] (__cpufreq_driver_target) from [<c0971994>] (od_dbs_update+0xc4/0x170)
[279677.411419]  r10:00000000 r9:c3672300 r8:c4399780 r7:c3672380 r6:c3672300 r5:c3672380
[279677.411426]  r4:c1ad7400
[279677.411436] [<c09718d0>] (od_dbs_update) from [<c0972bf8>] (dbs_work_handler+0x3c/0x64)
[279677.411444]  r9:00000000 r8:c131beac r7:c1ad7400 r6:c3672384 r5:00000000 r4:c36723b8
[279677.411455] [<c0972bbc>] (dbs_work_handler) from [<c023dc18>] (process_one_work+0x250/0x5a0)
[279677.411464]  r9:00000000 r8:00000080 r7:eff3d900 r6:eff3a640 r5:d1f7e180 r4:c36723b8
[279677.411473] [<c023d9c8>] (process_one_work) from [<c023dfc8>] (worker_thread+0x60/0x5c4)
[279677.411482]  r10:eff3a640 r9:c1203d00 r8:eff3a658 r7:00000008 r6:eff3a640 r5:d1f7e194
[279677.411488]  r4:d1f7e180
[279677.411498] [<c023df68>] (worker_thread) from [<c0245a50>] (kthread+0x170/0x174)
[279677.411506]  r10:c5ad7e74 r9:d1f7e180 r8:c023df68 r7:c67f2000 r6:00000000 r5:d2072b80
[279677.411512]  r4:cb8f8600
[279677.411521] [<c02458e0>] (kthread) from [<c02000ec>] (ret_from_fork+0x14/0x28)
[279677.411528] Exception stack(0xc67f3fb0 to 0xc67f3ff8)
[279677.411535] 3fa0:                                     00000000 00000000 00000000 00000000
[279677.411543] 3fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[279677.411551] 3fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[279677.411559]  r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c02458e0
[279677.411565]  r4:d2072b80

6by9
Raspberry Pi Engineer & Forum Moderator
Raspberry Pi Engineer & Forum Moderator
Posts: 11493
Joined: Wed Dec 04, 2013 11:27 am
Location: ZZ9 Plural Z Alpha, aka just outside Cambridge.

Re: lockup on 4b : Firmware transaction timeout ?

Thu Jun 03, 2021 6:05 am

I've been off for a couple of days, but this is my first job this morning.
There was a change a few months back to how i2c pin muxing was restored, but this resulted in a deadlock under some situations. One was fixed, but I'm suspecting something else similar.
Software Engineer at Raspberry Pi Trading. Views expressed are still personal views.
I'm not interested in doing contracts for bespoke functionality - please don't ask.

User avatar
jbeale
Posts: 3884
Joined: Tue Nov 22, 2011 11:51 pm
Contact: Website

Re: lockup on 4b : Firmware transaction timeout ?

Thu Jun 03, 2021 4:32 pm

Thanks again for looking into it. I've got a SSD on one USB3 port and various other normal USB things (keyboard, mouse, USB audio dongle, USB-serial dongle, Pi Pico) but I do not have anything connected to any GPIO pins. I presume there's something odd about my config, as if this was a common problem, I would expect to see a lot of posts here about it.

User avatar
jbeale
Posts: 3884
Joined: Tue Nov 22, 2011 11:51 pm
Contact: Website

Re: lockup on 4b : Firmware transaction timeout ?

Thu Jun 03, 2021 6:19 pm

Given that you mention I2C, I just noticed this in my /boot/config.txt
Apparently I've got i2c_arm ON. I don't remember if that is the default or if I manually enabled that at some point, for testing something or other.

Code: Select all

# Uncomment some or all of these to enable the optional hardware interfaces
dtparam=i2c_arm=on
#dtparam=i2s=on
#dtparam=spi=on

User avatar
Gavinmc42
Posts: 5876
Joined: Wed Aug 28, 2013 3:31 am

Re: lockup on 4b : Firmware transaction timeout ?

Fri Jun 04, 2021 5:52 am

Been getting similar mouse lockups, seems to be related to Chromium 88 after recent update/upgrade..
Re-flashed my USB3/SSD with new OS and did update/upgrade and it still happened on my Pi 400.
Same USB3/SSD on a Pi4 also locked up.
USB3 ASmedia adapter that has worked for more than a year.

Now have ver 90 installed via the software app and a bunch of other browsers.
Firefox ran all night, have not run Chromium 90 long yet.
Will go back to the Pi400 and try that again.

About the only other change apart from update/upgrade was enabling SPI pins.
USB audio dongle on the Pi400, not on the Pi4.

I was running 5.10.38, Mesa 20.3 and it locked up, went back to 5.10.17 and it still happened after update/upgrade.
At the moment I will be avoiding Chromium 88, no evidence except a gut feeling.
I'm dancing on Rainbows.
Raspberries are not Apples or Oranges

User avatar
jbeale
Posts: 3884
Joined: Tue Nov 22, 2011 11:51 pm
Contact: Website

Re: lockup on 4b : Firmware transaction timeout ?

Fri Jun 04, 2021 5:58 am

Very interesting! I am also running Chromium 88.

Code: Select all

Chromium Version 88.0.4324.187 (Official Build) Built on Raspbian , running on Raspbian 10 (32-bit)
I don't remember manually updating this, so I assumed this was the current default? But if that's the only factor, I'd expect thousands of people to have these lockups.

User avatar
Gavinmc42
Posts: 5876
Joined: Wed Aug 28, 2013 3:31 am

Re: lockup on 4b : Firmware transaction timeout ?

Fri Jun 04, 2021 7:43 am

I don't remember manually updating this, so I assumed this was the current default? But if that's the only factor, I'd expect thousands of people to have these lockups.
I know, but this was the first related post that was close to my hunch.
Maybe not everyone update a few times a week?
I will do some more checking on the weekend, because the other alternative guess is my Pi400 has issues :(
I'm dancing on Rainbows.
Raspberries are not Apples or Oranges

User avatar
jbeale
Posts: 3884
Joined: Tue Nov 22, 2011 11:51 pm
Contact: Website

Re: lockup on 4b : Firmware transaction timeout ?

Fri Jun 04, 2021 4:53 pm

Another thing- not a lockup, but while watching a FB video, just that window stopped with an error message that it could not play the video, and I saw 'dmesg' report

Code: Select all

[80931.936571] bcm2835-codec bcm2835-codec: bcm2835_codec_buf_prepare data will not fit into plane (1536 < 1775616)
[81070.586343] mmap: chromium-browse (6838): VmData 2147774464 exceed data ulimit 2147483647. Update limits or use boot option ignore_rlimit_data.

6by9
Raspberry Pi Engineer & Forum Moderator
Raspberry Pi Engineer & Forum Moderator
Posts: 11493
Joined: Wed Dec 04, 2013 11:27 am
Location: ZZ9 Plural Z Alpha, aka just outside Cambridge.

Re: lockup on 4b : Firmware transaction timeout ?

Fri Jun 04, 2021 5:24 pm

Apparently our Chromium 88 builds did switch to using the V4L2 decoder, I just wasn't aware of it. Chromium 90 is in the works and I need to look at a related startup issue for the V4L2 decoder.
Software Engineer at Raspberry Pi Trading. Views expressed are still personal views.
I'm not interested in doing contracts for bespoke functionality - please don't ask.

User avatar
Gavinmc42
Posts: 5876
Joined: Wed Aug 28, 2013 3:31 am

Re: lockup on 4b : Firmware transaction timeout ?

Sat Jun 05, 2021 12:58 am

just that window stopped with an error message that it could not play the video,
I got a lot of those too in YT, I just thought big brother had found me as they would stop in mid play.

Ran ver 90 all night playing rain music, seems to be better.
I'm dancing on Rainbows.
Raspberries are not Apples or Oranges

User avatar
jbeale
Posts: 3884
Joined: Tue Nov 22, 2011 11:51 pm
Contact: Website

Re: lockup on 4b : Firmware transaction timeout ?

Sat Jun 05, 2021 2:41 am

Happened twice to me again today. Most recently I got "Firmware transaction timeout" and then
"raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-v3d frequency: -110
bcm2835_mmal_vchiq: timed out waiting for sync completion"
I have to reboot from another system, or power cycle it each time, which is a pain. I guess I need to try Chromium version 90 and see if that helps.

Gavin, did you compile Chromium 90 yourself from source, or is there a way to install a pre-compiled version for the Pi?

cleverca22
Posts: 3976
Joined: Sat Aug 18, 2012 2:33 pm

Re: lockup on 4b : Firmware transaction timeout ?

Sat Jun 05, 2021 3:26 am

next time it fails, try running these, and post the result in a codeblock

Code: Select all

vcdbg log msg                                                                                                                                                                                                       
vcdbg log assert                                                                                                                                                                                                    

User avatar
Gavinmc42
Posts: 5876
Joined: Wed Aug 28, 2013 3:31 am

Re: lockup on 4b : Firmware transaction timeout ?

Sat Jun 05, 2021 4:13 am

I just used the menu - add/remove software, did a search for Browser.
Now have Chromium 90, Firefox, Arora, Xombrero as well as default Dillo

90 installed over 88.
Firefox got updated to 78.110esr
I'm dancing on Rainbows.
Raspberries are not Apples or Oranges

User avatar
Gavinmc42
Posts: 5876
Joined: Wed Aug 28, 2013 3:31 am

Re: lockup on 4b : Firmware transaction timeout ?

Mon Jun 07, 2021 1:42 am

Ran YT video all night on Chromium 90, now on the Pi400, seems fine.
Whatever was causing lockups on 88 has gone.

Was it the same fault?
No idea but things are working better now.
I'm dancing on Rainbows.
Raspberries are not Apples or Oranges

User avatar
jbeale
Posts: 3884
Joined: Tue Nov 22, 2011 11:51 pm
Contact: Website

Re: lockup on 4b : Firmware transaction timeout ?

Tue Jun 08, 2021 4:31 pm

"Firmware transaction timeout" just happened again.

Code: Select all

[ 2859.332873] ------------[ cut here ]------------
[ 2859.332912] WARNING: CPU: 3 PID: 3153 at drivers/firmware/raspberrypi.c:64 rpi_firmware_transaction+0xec/0x128
[ 2859.332924] Firmware transaction timeout
[ 2859.332935] Modules linked in: joydev cdc_acm rfcomm bnep hci_uart btbcm bluetooth ecdh_generic ecc fuse 8021q garp stp llc mct_u232 usbserial sg rpivid_mem brcmfmac brcmutil sha256_generic raspberrypi_hwmon cfg80211 v3d gpu_sched rfkill vc4 cec bcm2835_codec(C) bcm2835_isp(C) drm_kms_helper bcm2835_v4l2(C) bcm2835_mmal_vchiq(C) v4l2_mem2mem videobuf2_dma_contig snd_bcm2835(C) videobuf2_vmalloc videobuf2_memops vc_sm_cma(C) videobuf2_v4l2 videobuf2_common drm videodev drm_panel_orientation_quirks snd_soc_core snd_compress snd_pcm_dmaengine syscopyarea sysfillrect sysimgblt fb_sys_fops nvmem_rmem backlight uio_pdrv_genirq uio snd_usb_audio snd_hwdep snd_usbmidi_lib snd_rawmidi snd_seq_device mc snd_pcm snd_timer snd i2c_dev ip_tables x_tables ipv6
[ 2859.333669] CPU: 3 PID: 3153 Comm: kworker/3:0 Tainted: G         C        5.10.17-v7l+ #1421
[ 2859.333677] Hardware name: BCM2711
[ 2859.333695] Workqueue: events dbs_work_handler
[ 2859.333708] Backtrace:
[ 2859.333733] [<c0b63050>] (dump_backtrace) from [<c0b633e4>] (show_stack+0x20/0x24)
[ 2859.333746]  r7:ffffffff r6:00000000 r5:60000113 r4:c12e69fc
[ 2859.333760] [<c0b633c4>] (show_stack) from [<c0b67774>] (dump_stack+0xcc/0xf8)
[ 2859.333775] [<c0b676a8>] (dump_stack) from [<c0220bac>] (__warn+0xfc/0x114)
[ 2859.333787]  r10:dec0a008 r9:00000009 r8:c099d5b8 r7:00000040 r6:00000009 r5:c099d5b8
[ 2859.333795]  r4:c0e9abc8 r3:c1205094
[ 2859.333809] [<c0220ab0>] (__warn) from [<c0b63b88>] (warn_slowpath_fmt+0xa4/0xd8)
[ 2859.333818]  r7:00000040 r6:c0e9abc8 r5:c1205048 r4:c0e9abe8
[ 2859.333834] [<c0b63ae8>] (warn_slowpath_fmt) from [<c099d5b8>] (rpi_firmware_transaction+0xec/0x128)
[ 2859.333845]  r9:c1a94540 r8:00000018 r7:00000000 r6:ffffff92 r5:c1a94540 r4:c1205048
...and much more
'sudo vcdbg log assert' says only 'No messages available'.
The 'msg' log is over 4000 lines but I'll see if I can attach the file resulting from sudo vcdbg log msg >> debug-msg.txt 2>&1
(I had to use bzip2 on the file because this board does not allow attachments of type .txt )

For quick reference, here are the first 100 lines of it:

Code: Select all

012805.833: brfs: File read: /mfs/sd/config.txt
012806.639: brfs: File read: 1797 bytes
012903.807: brfs: File read: /mfs/sd/config.txt
012920.080: brfs: File read: 1797 bytes
013366.949: gpioman: gpioman_get_pin_num: pin DISPLAY_DSI_PORT not defined
013369.447: *** Restart logging
013411.944: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
013411.960: HDMI0: hdmi_pixel_encoding: 300000000
013411.971: HDMI1: hdmi_pixel_encoding: 300000000
013416.913: dtb_file 'bcm2711-rpi-4-b.dtb'
013420.936: brfs: File read: /mfs/sd/bcm2711-rpi-4-b.dtb
013420.951: Loading 'bcm2711-rpi-4-b.dtb' to 0x100 size 0xbfc2
013433.533: brfs: File read: 49090 bytes
013441.931: brfs: File read: /mfs/sd/overlays/overlay_map.dtb
013504.594: brfs: File read: 1523 bytes
013505.676: brfs: File read: /mfs/sd/config.txt
013506.187: dtparam: audio=on
013516.060: brfs: File read: 1797 bytes
013526.459: brfs: File read: /mfs/sd/overlays/vc4-fkms-v3d.dtbo
013543.662: Loaded overlay 'vc4-fkms-v3d'
013583.355: brfs: File read: 1446 bytes
013584.478: brfs: File read: /mfs/sd/cmdline.txt
013584.539: Read command line from file 'cmdline.txt':
013584.555: 'console=tty1 root=PARTUUID=222c7d4c-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait quiet splash plymouth.ignore-serial-consoles snd_bcm2835.enable_headphones=0 snd_bcm2835.enable_hdmi=0 snd_bcm2835.enable_compat_alsa=1'
014674.156: brfs: File read: 234 bytes
015012.278: brfs: File read: /mfs/sd/kernel7l.img
015012.300: Loading 'kernel7l.img' to 0x8000 size 0x662680
015012.325: Device tree loaded to 0x2eff3900 (size 0xc622)
015016.114: bfs_xhci_stop
015016.121: XHCI-STOP
015016.209: xHC ver: 256 HCS: 05000420 fc000031 00e70004 HCC: 002841eb
015018.262: PCI reset
018299.589: vchiq_core: vchiq_init_state: slot_zero = 0xded80000, is_master = 1
018301.694: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
018306.397: TV service:host side not connected, dropping notification 0x00000002, 0x00000001, 0x00000010
022848.622: TV service:host side not connected, dropping notification 0x00000008, 0x00000004, 0x00000000
1073405.435: TV service:host side not connected, dropping notification 0x00000001, 0x00000002, 0x00000000
1073738.758: TV service:host side not connected, dropping notification 0x00000002, 0x00000004, 0x00000000
1084977.650: TV service:host side not connected, dropping notification 0x00000001, 0x00000002, 0x00000000
1085310.397: TV service:host side not connected, dropping notification 0x00000002, 0x00000004, 0x00000000
2859842.040: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859842.091: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859842.524: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859842.591: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859842.976: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859843.045: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859843.370: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859843.407: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859843.673: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859843.711: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859843.993: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859844.028: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859844.323: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859844.374: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859844.638: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859844.672: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859844.924: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859844.958: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859845.202: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859845.236: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859845.486: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859845.521: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859845.764: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859845.799: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859846.034: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859846.066: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859846.306: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859846.341: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859862.600: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859862.635: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859882.701: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859882.746: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859902.637: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859902.682: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859913.362: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859913.431: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859913.748: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859913.782: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859914.116: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859914.154: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859914.465: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859914.537: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859914.849: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859914.896: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859915.197: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859915.233: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859915.558: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859915.593: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859915.840: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859915.874: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859916.113: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859916.147: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859916.391: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859916.426: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859916.687: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859916.720: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859916.957: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859916.990: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
2859922.710: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2859922.751: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
Attachments
debug-msg.txt.bz2
debug message log (bzip2 format)
(13.93 KiB) Downloaded 4 times
Last edited by jbeale on Tue Jun 08, 2021 4:44 pm, edited 1 time in total.

6by9
Raspberry Pi Engineer & Forum Moderator
Raspberry Pi Engineer & Forum Moderator
Posts: 11493
Joined: Wed Dec 04, 2013 11:27 am
Location: ZZ9 Plural Z Alpha, aka just outside Cambridge.

Re: lockup on 4b : Firmware transaction timeout ?

Tue Jun 08, 2021 4:43 pm

The "[ 2859.332924] Firmware transaction timeout" splat has no use - it generally means something later has come along and got no response. It doesn't give any answer as to what locked things up in the first place.
"vcdbg log assert" needs to have "start_debug=1" in config.txt to report anything.
Software Engineer at Raspberry Pi Trading. Views expressed are still personal views.
I'm not interested in doing contracts for bespoke functionality - please don't ask.

6by9
Raspberry Pi Engineer & Forum Moderator
Raspberry Pi Engineer & Forum Moderator
Posts: 11493
Joined: Wed Dec 04, 2013 11:27 am
Location: ZZ9 Plural Z Alpha, aka just outside Cambridge.

Re: lockup on 4b : Firmware transaction timeout ?

Tue Jun 08, 2021 4:53 pm

The logs reporting

Code: Select all

2874992.594: alloc_compact_internal(space=3291328, in_low_region=0, mode=7) failed
2874982.615: mmal: mmal_port_event_send: event lost on port 1,0 (buffer header callback not defined)
mean you're out of gpu_mem, and it has failed to compact the heap to release any extra. MMAL has then tried to report the event, but the client (presumably Chromium) hasn't registered a suitable callback to handle that error path.
That does give me a bit more to work with - thanks. My systems default to 256M of gpu_mem still (old habits die hard), so I wouldn't have encountered the issue.
Software Engineer at Raspberry Pi Trading. Views expressed are still personal views.
I'm not interested in doing contracts for bespoke functionality - please don't ask.

User avatar
jbeale
Posts: 3884
Joined: Tue Nov 22, 2011 11:51 pm
Contact: Website

Re: lockup on 4b : Firmware transaction timeout ?

Tue Jun 08, 2021 6:33 pm

Code: Select all

pi@rp49:~ $ vcgencmd get_mem gpu
gpu=76M
Looks like that is not enough. I don't see any kind of memory being set in my /boot/config.txt so that is some sort of default, I suppose?
EDIT: apparently yes, 76 is the default for 1G+ memory systems. https://www.raspberrypi.org/documentati ... /memory.md

6by9
Raspberry Pi Engineer & Forum Moderator
Raspberry Pi Engineer & Forum Moderator
Posts: 11493
Joined: Wed Dec 04, 2013 11:27 am
Location: ZZ9 Plural Z Alpha, aka just outside Cambridge.

Re: lockup on 4b : Firmware transaction timeout ?

Tue Jun 08, 2021 7:11 pm

jbeale wrote:
Tue Jun 08, 2021 6:33 pm

Code: Select all

pi@rp49:~ $ vcgencmd get_mem gpu
gpu=76M
Looks like that is not enough. I don't see any kind of memory being set in my /boot/config.txt so that is some sort of default, I suppose?
EDIT: apparently yes, 76 is the default for 1G+ memory systems. https://www.raspberrypi.org/documentati ... /memory.md
It's possible that we need to revisit the default just because of the exact ordering that resources get released when using the V4L2 drivers. It's hard to say until we've pinned it down a little further.
Software Engineer at Raspberry Pi Trading. Views expressed are still personal views.
I'm not interested in doing contracts for bespoke functionality - please don't ask.

User avatar
Gavinmc42
Posts: 5876
Joined: Wed Aug 28, 2013 3:31 am

Re: lockup on 4b : Firmware transaction timeout ?

Wed Jun 09, 2021 1:30 am

John, what is your Swap file size?
I have mine at 1000MB these days.
Had issues compiling on Pi3's with Chromium open years ago, increasing Swap helped.

Which Pi4 memory size do you have?
I'm dancing on Rainbows.
Raspberries are not Apples or Oranges

Return to “Troubleshooting”