Firmware transaction timeout on Pi4B

Open
#4,047 23 comments 1 reaction 0 assignees View on GitHub

Nobody has claimed this yet.

Assessment

Difficulty
4/5
Estimated time
3-5 days
Newbie friendliness
35/100
Issue type
Bug
Clarity
Mostly clear
Activity status
Stale
Tech stack
c, linux

Research direction

Reproduce the hang with the reported gst-launch-1.0 command on a Pi 4B running the stated Raspberry Pi OS and kernel. Read drivers/firmware/raspberrypi.c, especially rpi_firmware_transaction, then follow the logged raspberrypi clock and cpufreq call path. Done means the firmware timeout, related clock errors, and gst-launch hang no longer occur in the reported setup.

Written by the indexing model from the issue text.

Description

Describe the bug
"Firmware transaction timeout" message and gst-launch hang on a Pi 4B 4GB when running gst-launch-1.0 playbin uri=https://some.domain/720p25-h264-aac.m3u8

To reproduce
Boot Pi 4B with Raspberry Pi OS (without X server), then run
gst-launch-1.0 playbin uri=https://some.domain/720p25-h264-aac.m3u8
I can try to upload the m3u8 file and associated stream somewhere.
So far, this has been 100% reproducible.

Expected behaviour
No hang.

Actual behaviour
"Firmware transaction timeout" message and gst-launch hang on a Pi 4B 4GB when running
gst-launch-1.0 playbin uri=https://some.domain/720p25-h264-aac.m3u8

System
raspinfo hangs, pasting all output before the hang:

System Information
Raspberry Pi 4 Model B Rev 1.2
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"

Raspberry Pi reference 2020-08-20
Generated using pi-gen, https://github.com/RPi-Distro/pi-gen, 9a3a10bf1019ebb2d59053564dc6b90068bad27d, stage4

Linux pi4-nak1 5.4.79-v7l+ #1373 SMP Mon Nov 23 13:27:40 GMT 2020 armv7l GNU/Linux
Revision : b03112
Serial : 100000004ad7632c
Model : Raspberry Pi 4 Model B Rev 1.2

Logs
If applicable, add the relevant output from dmesg or similar.

[   95.340807] fuse: init (API version 7.31)
[  711.440163] ------------[ cut here ]------------
[  711.440185] WARNING: CPU: 1 PID: 31 at drivers/firmware/raspberrypi.c:63 rpi_firmware_transaction+0xec/0x128
[  711.440190] Firmware transaction timeout
[  711.440193] Modules linked in: fuse cmac rfcomm bnep hci_uart btbcm bluetooth ecdh_generic ecc xfrm4_tunnel tunnel4 ipcomp xfrm_ipcomp esp4 ah4 af_key 8021q garp stp llc spidev brcmfmac brcmutil sha256_generic libsha256 cfg80211 v3d rfkill raspberrypi_hwmon gpu_sched i2c_mux_pinctrl i2c_mux bcm2835_codec(C) i2c_bcm2835 vc4 spi_bcm2835 v4l2_mem2mem bcm2835_v4l2(C) bcm2835_isp(C) bcm2835_mmal_vchiq(C) videobuf2_vmalloc cec videobuf2_dma_contig videobuf2_memops videobuf2_v4l2 videobuf2_common drm_kms_helper videodev drm snd_bcm2835(C) mc vc_sm_cma(C) drm_panel_orientation_quirks snd_soc_core snd_compress snd_pcm_dmaengine snd_pcm snd_timer rpivid_mem snd syscopyarea sysfillrect sysimgblt fb_sys_fops uio_pdrv_genirq uio i2c_dev ip_tables x_tables ipv6
[  711.440326] CPU: 1 PID: 31 Comm: kworker/1:1 Tainted: G         C        5.4.79-v7l+ #1373
[  711.440329] Hardware name: BCM2711
[  711.440336] Workqueue: events dbs_work_handler
[  711.440340] Backtrace: 
[  711.440350] [<c020dfb0>] (dump_backtrace) from [<c020e334>] (show_stack+0x20/0x24)
[  711.440355]  r7:ffffffff r6:00000000 r5:60000013 r4:c129fab0
[  711.440363] [<c020e314>] (show_stack) from [<c0a76254>] (dump_stack+0xd8/0x11c)
[  711.440370] [<c0a7617c>] (dump_stack) from [<c0222028>] (__warn+0xe0/0x108)
[  711.440375]  r10:cfc04008 r9:00000009 r8:c08dd810 r7:0000003f r6:00000009 r5:c08dd810
[  711.440378]  r4:c0e3a554 r3:00000000
[  711.440384] [<c0221f48>] (__warn) from [<c0222424>] (warn_slowpath_fmt+0xa4/0xc0)
[  711.440389]  r7:0000003f r6:c0e3a554 r5:c1204fc8 r4:c0e3a574
[  711.440395] [<c0222384>] (warn_slowpath_fmt) from [<c08dd810>] (rpi_firmware_transaction+0xec/0x128)
[  711.440400]  r9:cee307c0 r8:00000018 r7:00000000 r6:ffffff92 r5:cee307c0 r4:c1204fc8
[  711.440407] [<c08dd724>] (rpi_firmware_transaction) from [<c08dd908>] (rpi_firmware_property_list+0xbc/0x170)
[  711.440411]  r7:c1204fc8 r6:cfc04000 r5:00001000 r4:cfc04024
[  711.440418] [<c08dd84c>] (rpi_firmware_property_list) from [<c08dda2c>] (rpi_firmware_property+0x70/0x118)
[  711.440423]  r10:ceccb8cc r9:00030002 r8:00000018 r7:cee307c0 r6:cee19d48 r5:0000000c
[  711.440426]  r4:ceccb8c0
[  711.440434] [<c08dd9bc>] (rpi_firmware_property) from [<c0733718>] (raspberrypi_clock_property+0x54/0x7c)
[  711.440439]  r10:00000000 r9:c9e57100 r8:00000001 r7:c1367c98 r6:59682f00 r5:cee19d70
[  711.440442]  r4:c1204fc8 r3:0000000c
[  711.440449] [<c07336c4>] (raspberrypi_clock_property) from [<c073378c>] (raspberrypi_fw_get_rate+0x4c/0x70)
[  711.440452]  r5:00000000 r4:c1204fc8
[  711.440460] [<c0733740>] (raspberrypi_fw_get_rate) from [<c072a19c>] (clk_recalc+0x44/0x84)
[  711.440463]  r4:cef52900
[  711.440470] [<c072a158>] (clk_recalc) from [<c072a48c>] (__clk_recalc_rates+0x30/0x94)
[  711.440474]  r5:00000000 r4:cef52900
[  711.440480] [<c072a45c>] (__clk_recalc_rates) from [<c072a55c>] (clk_core_get_rate+0x6c/0x70)
[  711.440485]  r7:c1367c98 r6:c1204fc8 r5:29b92700 r4:cef52900
[  711.440491] [<c072a4f0>] (clk_core_get_rate) from [<c072a584>] (clk_get_rate+0x24/0x28)
[  711.440495]  r5:29b92700 r4:c9e53800
[  711.440501] [<c072a560>] (clk_get_rate) from [<c08aa2ac>] (dev_pm_opp_set_rate+0x70/0x4b4)
[  711.440507] [<c08aa23c>] (dev_pm_opp_set_rate) from [<c08b4af8>] (set_target+0x3c/0x64)
[  711.440512]  r10:00000000 r9:00000000 r8:00000001 r7:c1367c98 r6:00000000 r5:000aae60
[  711.440515]  r4:c9e53c00
[  711.440521] [<c08b4abc>] (set_target) from [<c08aef18>] (__cpufreq_driver_target+0x1a8/0x51c)
[  711.440526]  r7:c1367c98 r6:00000000 r5:c1204fc8 r4:c9e53c00
[  711.440532] [<c08aed70>] (__cpufreq_driver_target) from [<c08b2b5c>] (od_dbs_update+0xc4/0x170)
[  711.440537]  r10:00000000 r9:c87af800 r8:c864fa80 r7:c87af680 r6:c87af800 r5:c87af680
[  711.440540]  r4:c9e53c00
[  711.440546] [<c08b2a98>] (od_dbs_update) from [<c08b3da8>] (dbs_work_handler+0x3c/0x64)
[  711.440551]  r9:00000040 r8:c128fb08 r7:c9e53c00 r6:c87af684 r5:00000000 r4:c87af6b8
[  711.440558] [<c08b3d6c>] (dbs_work_handler) from [<c023e884>] (process_one_work+0x250/0x570)
[  711.440563]  r9:00000040 r8:00000000 r7:dff1e600 r6:dff1b300 r5:ced68080 r4:c87af6b8
[  711.440569] [<c023e634>] (process_one_work) from [<c023ec04>] (worker_thread+0x60/0x5d0)
[  711.440574]  r10:dff1b300 r9:c1203d00 r8:dff1b318 r7:00000008 r6:dff1b300 r5:ced68094
[  711.440577]  r4:ced68080
[  711.440584] [<c023eba4>] (worker_thread) from [<c0245fd0>] (kthread+0x170/0x174)
[  711.440588]  r10:ced15e74 r9:c023eba4 r8:ced68080 r7:cee18000 r6:00000000 r5:ced63080
[  711.440592]  r4:cee1a040
[  711.440597] [<c0245e60>] (kthread) from [<c02010ac>] (ret_from_fork+0x14/0x28)
[  711.440601] Exception stack(0xcee19fb0 to 0xcee19ff8)
[  711.440606] 9fa0:                                     00000000 00000000 00000000 00000000
[  711.440610] 9fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[  711.440614] 9fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[  711.440619]  r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c0245e60
[  711.440622]  r4:ced63080
[  711.440627] ---[ end trace 473967205885bfb5 ]---
[  711.440642] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967186 (-34)
[  712.480177] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -110
[  714.560189] hwmon hwmon1: Failed to get throttled (-110)
[  715.600193] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967186 (-34)
[  716.640198] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -110
[  724.301679] vc_sm_cma_import_dmabuf: imported vc_sm_cma_get_buffer failed -512
[  724.301686] bcm2835_mmal_vchiq: vchiq_mmal_submit_buffer: vc_sm_import_dmabuf_fd failed, ret -512
[  724.301693] bcm2835-codec bcm2835-codec: device_run: Failed submitting op buffer

Additional context
Attached devices:

  • HDMI monitor
  • Ethernet cable
  • No USB devices, I'm accessing the Pi via SSH.
Dominant language
C
Stars
13.2k
Forks
5.5k
Avg merge
2d 21h
Merged PRs (30d)
21

Contributor guide

No contributing guide indexed for this repository

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

More from raspberrypi/linux

All issues in raspberrypi/linux

Similar issues

More C issues

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.