[Solved] Kodi cause kernel stack trace when running video

[vincent26]

Hi,

I've just reinstalled my pi4 4Gb and when I watch video with Kodi, it freeze and I get a kernel stack trace in dmesg logs.
Before reinstalling it, it worked fine

$this->bbcode_second_pass_code('', '------------[ cut here ]------------
WARNING: CPU: 0 PID: 1726 at drivers/firmware/raspberrypi.c:63 rpi_firmware_transaction+0xe8/0x124
Firmware transaction timeout
Modules linked in: md4 cmac nls_utf8 cifs gcm libarc4 btsdio bluetooth ecdh_generic ecc brcmfmac brcmutil vc4 cfg80211 bcm2835_isp(C) bcm2835_codec(C) bcm2835_v4l2(C) v4l2_mem2mem videobuf2_dma_contig cec bcm2835_mmal_vchiq(C) videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_common v3d drm_kms_helper raspberrypi_hwmon gpu_sched videodev snd_soc_core mc snd_compress rpivid_mem iproc_rng200 rng_core snd_pcm_dmaengine syscopyarea sysfillrect sysimgblt fb_sys_fops uio_pdrv_genirq uio sch_fq_codel snd_bcm2835(C) snd_pcm snd_timer snd fuse drm drm_panel_orientation_quirks ip_tables x_tables ipv6
CPU: 0 PID: 1726 Comm: kworker/0:1 Tainted: G C 5.4.83-1-ARCH #1
Hardware name: BCM2711
Workqueue: events dbs_work_handler
[<c0210cdc>] (unwind_backtrace) from [<c020c594>] (show_stack+0x10/0x14)
[<c020c594>] (show_stack) from [<c0d0780c>] (dump_stack+0x90/0xb0)
[<c0d0780c>] (dump_stack) from [<c022c844>] (__warn+0xd0/0xf8)
[<c022c844>] (__warn) from [<c022cc0c>] (warn_slowpath_fmt+0x7c/0xa8)
[<c022cc0c>] (warn_slowpath_fmt) from [<c0b66c6c>] (rpi_firmware_transaction+0xe8/0x124)
[<c0b66c6c>] (rpi_firmware_transaction) from [<c0b66d54>] (rpi_firmware_property_list+0xac/0x16c)
[<c0b66d54>] (rpi_firmware_property_list) from [<c0b66e74>] (rpi_firmware_property+0x60/0x108)
[<c0b66e74>] (rpi_firmware_property) from [<c0948034>] (raspberrypi_fw_get_rate+0x4c/0x78)
[<c0948034>] (raspberrypi_fw_get_rate) from [<c093d58c>] (clk_recalc+0x34/0x78)
[<c093d58c>] (clk_recalc) from [<c093d884>] (__clk_recalc_rates+0x20/0x84)
[<c093d884>] (__clk_recalc_rates) from [<c093d944>] (clk_core_get_rate+0x5c/0x60)
[<c093d944>] (clk_core_get_rate) from [<c0b32d40>] (dev_pm_opp_set_rate+0x84/0x504)
[<c0b32d40>] (dev_pm_opp_set_rate) from [<c0b3c5a8>] (set_target+0x2c/0x54)
[<c0b3c5a8>] (set_target) from [<c0b36cbc>] (__cpufreq_driver_target+0x180/0x540)
[<c0b36cbc>] (__cpufreq_driver_target) from [<c0b3a77c>] (od_dbs_update+0xbc/0x168)
[<c0b3a77c>] (od_dbs_update) from [<c0b3b9d4>] (dbs_work_handler+0x2c/0x58)
[<c0b3b9d4>] (dbs_work_handler) from [<c0248c04>] (process_one_work+0x1e8/0x584)
[<c0248c04>] (process_one_work) from [<c0248ffc>] (worker_thread+0x5c/0x568)
[<c0248ffc>] (worker_thread) from [<c024eb14>] (kthread+0x170/0x188)
[<c024eb14>] (kthread) from [<c02010d8>] (ret_from_fork+0x14/0x3c)
Exception stack(0xc5615fb0 to 0xc5615ff8)
5fa0: 00000000 00000000 00000000 00000000
5fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
5fe0: 00000000 00000000 00000000 00000000 00000013 00000000
---[ end trace 4340e650ab5684ad ]---
cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967186 (-34)
hwmon hwmon1: Failed to get throttled (-110)
raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -110
cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967186 (-34)
raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -110')

I google part of this calltrace but I don't found any solution…
I have an official Raspberry power supply.

Kernel version
$this->bbcode_second_pass_code('', 'uname -r
5.4.83-1-ARCH')

I use the latest stable firware version
$this->bbcode_second_pass_code('', '
rpi-eeprom-update
BCM2711 detected
Dedicated VL805 EEPROM detected
BOOTLOADER: up-to-date
CURRENT: Thu Sep 3 12:11:43 UTC 2020 (1599135103)
LATEST: Thu Sep 3 12:11:43 UTC 2020 (1599135103)
FW DIR: /lib/firmware/raspberrypi/bootloader/stable
VL805: up-to-date
CURRENT: 000138a1
LATEST: 000138a1
')

Boot options
$this->bbcode_second_pass_code('', '
cat /boot/config.txt
# See /boot/overlays/README for all available options

gpu_mem=512
dtparam=audio=on
hdmi_drive=2
dtoverlay=vc4-fkms-v3d

initramfs initramfs-linux.img followkernel
')

Kernel cmdline (if usefull…)
$this->bbcode_second_pass_code('', '
cat /proc/cmdline
coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 video=HDMI-A-1:1920x1080M@60,margin_left=48,margin_right=48,margin_top=48,margin_bottom=48 smsc95xx.macaddr=DC:A6:32:62:28:15 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 root=/dev/sda1 rw rootwait console=ttyS0,115200 console=tty1 selinux=0 plymouth.enable=0 smsc95xx.turbo_mode=N dwc_otg.lpm_enable=0 kgdboc=ttyS0,115200 elevator=noop
')

Has anyone ever encountered this problem ?

[graysky]

Have not encountered before. Which package... kodi-rpi? Enable debug logging in kodi and post a link to the kodi.log. Recommend you try a standard video like jellyfish-120-mbps-4k-uhd-hevc-10bit.mkv.

[vincent26]

Thank you for your answer.

kodi-rpi package
$this->bbcode_second_pass_code('', '
yay -Q kodi
kodi-rpi 18.9-3
')

I just try with debug enable with this file https://www.jell.yfish.us/media/jellyfi ... d-h264.mkv

Kodi's logs
https://pastebin.pl/view/ac0a544b

Note that I reimport a backup of my kodi dir and kodi's version change (minor)…
I'll try with clean kodi's install

[graysky]

Your /boot/config.txt is correct for kodi-rpi. I have seen extraneous settings in a kodi profile cause hardware decoding problems. Try a new profile and report back.

Assuming you're using kodi.service:
$this->bbcode_second_pass_code('', '# systemctl stop kodi
# mv /var/lib/kodi/.kodi /var/lib/kodi/dotkodi-backup
# systemctl start kodi')

If not, the profile is in your homedir:
$this->bbcode_second_pass_code('', '$ mv ~/.kodi ~/dotkodi-backup')

[vincent26]

Not better with new kodi's profile

[graysky]

When I boot my RPi4 8GB with your /boot/config.txt I get a kernel panic. 512 meg of gpu mem is not needed even for 1080 content.

$this->bbcode_second_pass_quote('pacman', '
')installed kodi-rpi (18.9-3)
-> Make sure the following lines are added to /boot/config.txt
gpu_mem=320
dtoverlay=vc4-fkms-v3d

[vincent26]

After upgrading to kodi-rpi-git it works !

$this->bbcode_second_pass_code('', '
yay -Q kodi
kodi-rpi-git 19.0b2.56840.579551ef13-1
')

Thank you so much for you help.
Hope this topic cloud help if needed

[edit] I tried to set gpu_mem=320 with kodi-rpi (not git version) package but it got a kernel panic

[jessbo]

Just stopped by to say I had the same issue after updating one of my RPI 4's yesterday. Downgrading raspberrypi-bootloader and raspberrypi-bootloader-x resolved it for me. 20201220 and 20201215 had this issue, 20201016 does not. Not sure about versions inbetween. This one boots off a USB SSD.

My other RPI 4, using a SD card, does not have this issue. ¯\_(ツ)_/¯

[graysky]

$this->bbcode_second_pass_quote('jessbo', 'J')ust stopped by to say I had the same issue after updating one of my RPI 4's yesterday. Downgrading raspberrypi-bootloader and raspberrypi-bootloader-x resolved it for me. 20201220 and 20201215 had this issue, 20201016 does not. Not sure about versions inbetween. This one boots off a USB SSD.

My other RPI 4, using a SD card, does not have this issue. ¯\_(ツ)_/¯

[jessbo]

$this->bbcode_second_pass_code('', 'jessbo@rpi4b8 ~> pacman -Q kodi-rpi raspberrypi-bootloader
kodi-rpi 18.9-3
raspberrypi-bootloader 20201220-1')

$this->bbcode_second_pass_code('', 'Dec 23 21:53:06 rpi4b8 kodi-standalone[5164]: Can't load /etc/samba/smb.conf - run testparm to debug it
Dec 23 21:54:22 rpi4b8 kernel: ------------[ cut here ]------------
Dec 23 21:54:22 rpi4b8 kernel: WARNING: CPU: 2 PID: 4174 at drivers/firmware/raspberrypi.c:63 rpi_firmware_transaction+0xe8/0x124
Dec 23 21:54:22 rpi4b8 kernel: Firmware transaction timeout
Dec 23 21:54:22 rpi4b8 kernel: Modules linked in: z3fold zstd zbud v3d gpu_sched raspberrypi_hwmon bcm2835_codec(C) iproc_rng200 rng_core ftdi_sio usbserial rpivid_hevc(C) v4l2_mem2mem bcm2835_v4l2(C) bcm2835_isp(C) bcm2835_mmal_vchiq(C) videobuf2_vmalloc videobuf2_dma_contig videobuf2_memops videobuf2_v4l2 videobuf2_common videodev mc vc4 cec drm_kms_helper snd_soc_core snd_compress snd_pcm_dmaengine syscopyarea sysfillrect sysimgblt fb_sys_fops uio_pdrv_genirq uio sch_fq_codel snd_bcm2835(C) snd_pcm snd_timer snd fuse drm drm_panel_orientation_quirks ip_tables x_tables ipv6
Dec 23 21:54:22 rpi4b8 kernel: CPU: 2 PID: 4174 Comm: kworker/2:1 Tainted: G C 5.4.83-1-ARCH #1
Dec 23 21:54:22 rpi4b8 kernel: Hardware name: BCM2711
Dec 23 21:54:22 rpi4b8 kernel: Workqueue: events_freezable mmc_rescan
Dec 23 21:54:22 rpi4b8 kernel: [<c0210cdc>] (unwind_backtrace) from [<c020c594>] (show_stack+0x10/0x14)
Dec 23 21:54:22 rpi4b8 kernel: [<c020c594>] (show_stack) from [<c0d0780c>] (dump_stack+0x90/0xb0)
Dec 23 21:54:22 rpi4b8 kernel: [<c0d0780c>] (dump_stack) from [<c022c844>] (__warn+0xd0/0xf8)
Dec 23 21:54:22 rpi4b8 kernel: [<c022c844>] (__warn) from [<c022cc0c>] (warn_slowpath_fmt+0x7c/0xa8)
Dec 23 21:54:22 rpi4b8 kernel: [<c022cc0c>] (warn_slowpath_fmt) from [<c0b66c6c>] (rpi_firmware_transaction+0xe8/0x124)
Dec 23 21:54:22 rpi4b8 kernel: [<c0b66c6c>] (rpi_firmware_transaction) from [<c0b66d54>] (rpi_firmware_property_list+0xac/0x16c)
Dec 23 21:54:22 rpi4b8 kernel: [<c0b66d54>] (rpi_firmware_property_list) from [<c0b66e74>] (rpi_firmware_property+0x60/0x108)
Dec 23 21:54:22 rpi4b8 kernel: [<c0b66e74>] (rpi_firmware_property) from [<c08f724c>] (rpi_exp_gpio_set+0x50/0xa0)
Dec 23 21:54:22 rpi4b8 kernel: [<c08f724c>] (rpi_exp_gpio_set) from [<c09519d8>] (_regulator_do_enable+0x404/0x414)
Dec 23 21:54:22 rpi4b8 kernel: [<c09519d8>] (_regulator_do_enable) from [<c0954f38>] (_regulator_enable+0x13c/0x1ac)
Dec 23 21:54:22 rpi4b8 kernel: [<c0954f38>] (_regulator_enable) from [<c0954fe0>] (regulator_enable+0x38/0x70)
Dec 23 21:54:22 rpi4b8 kernel: [<c0954fe0>] (regulator_enable) from [<c0b4c918>] (mmc_regulator_set_ocr+0xb0/0xdc)
Dec 23 21:54:22 rpi4b8 kernel: [<c0b4c918>] (mmc_regulator_set_ocr) from [<c0b61c44>] (sdhci_iproc_set_power+0x24/0x38)
Dec 23 21:54:22 rpi4b8 kernel: [<c0b61c44>] (sdhci_iproc_set_power) from [<c0b593ac>] (sdhci_set_ios+0xa4/0x62c)
Dec 23 21:54:22 rpi4b8 kernel: [<c0b593ac>] (sdhci_set_ios) from [<c0b3f9d0>] (mmc_power_up.part.0+0x40/0x148)
Dec 23 21:54:22 rpi4b8 kernel: [<c0b3f9d0>] (mmc_power_up.part.0) from [<c0b407e8>] (mmc_rescan+0x264/0x430)
Dec 23 21:54:22 rpi4b8 kernel: [<c0b407e8>] (mmc_rescan) from [<c0248c04>] (process_one_work+0x1e8/0x584)
Dec 23 21:54:22 rpi4b8 kernel: [<c0248c04>] (process_one_work) from [<c0248ffc>] (worker_thread+0x5c/0x568)
Dec 23 21:54:22 rpi4b8 kernel: [<c0248ffc>] (worker_thread) from [<c024eb14>] (kthread+0x170/0x188)
Dec 23 21:54:22 rpi4b8 kernel: [<c024eb14>] (kthread) from [<c02010d8>] (ret_from_fork+0x14/0x3c)
Dec 23 21:54:22 rpi4b8 kernel: Exception stack(0xefa25fb0 to 0xefa25ff8)
Dec 23 21:54:22 rpi4b8 kernel: 5fa0: 00000000 00000000 00000000 00000000
Dec 23 21:54:22 rpi4b8 kernel: 5fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
Dec 23 21:54:22 rpi4b8 kernel: 5fe0: 00000000 00000000 00000000 00000000 00000013 00000000
Dec 23 21:54:22 rpi4b8 kernel: ---[ end trace bb2f8cebd116cf08 ]---
Dec 23 21:54:22 rpi4b8 kernel: raspberrypi-exp-gpio soc:firmware:gpio: Failed to set GPIO 6 state (-110 86)
Dec 23 21:54:23 rpi4b8 kernel: raspberrypi-exp-gpio soc:firmware:gpio: Failed to set GPIO 4 state (-110 84)
Dec 23 21:54:24 rpi4b8 kernel: cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967186 (-34)
Dec 23 21:54:25 rpi4b8 kernel: raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -110
Dec 23 21:54:26 rpi4b8 kernel: hwmon hwmon1: Failed to get throttled (-110)
Dec 23 21:54:27 rpi4b8 kernel: raspberrypi-exp-gpio soc:firmware:gpio: Failed to set GPIO 6 state (-110 86)')

vs.

$this->bbcode_second_pass_code('', 'jessbo@rpi4b8 ~> pacman -Q kodi-rpi raspberrypi-bootloader
kodi-rpi 18.9-3
raspberrypi-bootloader 20201016-1')

$this->bbcode_second_pass_code('', 'Dec 23 22:03:11 rpi4b8 kodi-standalone[727]: Can't load /etc/samba/smb.conf - run testparm to debug it')

No more to that log because it doesn't hang with the older bootloader. ¯\_(ツ)_/¯. Not meant as a request for help, but just a datapoint in case anyone runs into this in the future and cares to figure it out (as I'm certainly not going to bother.)