vchiq: vchiq_ioctl: cmd VCHIQ_IOC_RELEASE_SERVICE returned error -1 for service TVNT:17277

[rodizio1]

This seems to be randomly happening when there is more stuff being drawn with OpenVG. Have never seen this issue, until I activated more graphical options in an OpenVG program. System is not overclocked.

[  938.591239] ------------[ cut here ]------------
[  938.591267] WARNING: CPU: 2 PID: 17281 at drivers/misc/vc04_services/interface/vchiq_arm/vchiq_arm.c:2502 vchiq_release_internal+0xb4/0x24c()
[  938.591274] Modules linked in: arc4 rt2800usb rt2800lib crc_ccitt evdev rt2x00usb rt2x00lib brcmfmac mac80211 brcmutil cfg80211 bcm2835_gpiomem smsc95xx usbnet mii
[  938.591320] CPU: 2 PID: 17281 Comm: HTV Notify Not tainted 4.4.11-v7+ #24
[  938.591326] Hardware name: BCM2709
[  938.591330] Backtrace:
[  938.591349] [<80012940>] (dump_backtrace) from [<80012b38>] (show_stack+0x18/0x1c)
[  938.591355]  r6:60000013 r5:80542648 r4:00000000 r3:00000000
[  938.591374] [<80012b20>] (show_stack) from [<8020bd7c>] (dump_stack+0xac/0xcc)
[  938.591385] [<8020bcd0>] (dump_stack) from [<8001cc28>] (warn_slowpath_common+0x8c/0xbc)
[  938.591390]  r7:000009c6 r6:80298730 r5:00000009 r4:00000000
[  938.591407] [<8001cb9c>] (warn_slowpath_common) from [<8001ccfc>] (warn_slowpath_null+0x24/0x2c)
[  938.591412]  r8:80587154 r7:ffffffff r6:b6266608 r5:805478a8 r4:b563b244
[  938.591429] [<8001ccd8>] (warn_slowpath_null) from [<80298730>] (vchiq_release_internal+0xb4/0x24c)
[  938.591440] [<8029867c>] (vchiq_release_internal) from [<802993c0>] (vchiq_ioctl+0x7ec/0x1870)
[  938.591444]  r9:b563b200 r8:00304006 r7:b563b400 r6:0000c40d r5:805478a8 r4:0000c40c
[  938.591465] [<80298bd4>] (vchiq_ioctl) from [<800e5c14>] (do_vfs_ioctl+0x41c/0x60c)
[  938.591469]  r10:00000000 r9:adfae000 r8:00000003 r7:0000c40d r6:b2d179c0 r5:00304006
[  938.591483]  r4:b62f8648
[  938.591491] [<800e57f8>] (do_vfs_ioctl) from [<800e5e40>] (SyS_ioctl+0x3c/0x64)
[  938.591496]  r9:adfae000 r8:00000003 r7:0000c40d r6:b2d179c0 r5:00304006 r4:b2d179c1
[  938.591517] [<800e5e04>] (SyS_ioctl) from [<8000f760>] (ret_fast_syscall+0x0/0x34)
[  938.591522]  r8:8000f904 r7:00000036 r6:7e9e4adc r5:00000002 r4:76e332f0 r3:000000a4
[  938.591536] ---[ end trace 3cf8661a1aa3d6c9 ]---
[  938.591545] vchiq: vchiq_ioctl: cmd VCHIQ_IOC_RELEASE_SERVICE returned error -1 for service TVNT:17277
[ 1233.341567] ------------[ cut here ]------------
[ 1233.341596] WARNING: CPU: 1 PID: 22457 at drivers/misc/vc04_services/interface/vchiq_arm/vchiq_arm.c:2502 vchiq_release_internal+0xb4/0x24c()
[ 1233.341617] Modules linked in: arc4 rt2800usb rt2800lib crc_ccitt evdev rt2x00usb rt2x00lib brcmfmac mac80211 brcmutil cfg80211 bcm2835_gpiomem smsc95xx usbnet mii
[ 1233.341666] CPU: 1 PID: 22457 Comm: HTV Notify Tainted: G        W       4.4.11-v7+ #24
[ 1233.341671] Hardware name: BCM2709
[ 1233.341675] Backtrace:
[ 1233.341694] [<80012940>] (dump_backtrace) from [<80012b38>] (show_stack+0x18/0x1c)
[ 1233.341699]  r6:60000013 r5:80542648 r4:00000000 r3:00000000
[ 1233.341720] [<80012b20>] (show_stack) from [<8020bd7c>] (dump_stack+0xac/0xcc)
[ 1233.341733] [<8020bcd0>] (dump_stack) from [<8001cc28>] (warn_slowpath_common+0x8c/0xbc)
[ 1233.341737]  r7:000009c6 r6:80298730 r5:00000009 r4:00000000
[ 1233.341754] [<8001cb9c>] (warn_slowpath_common) from [<8001ccfc>] (warn_slowpath_null+0x24/0x2c)
[ 1233.341759]  r8:80587154 r7:ffffffff r6:b6266608 r5:805478a8 r4:b563b444
[ 1233.341776] [<8001ccd8>] (warn_slowpath_null) from [<80298730>] (vchiq_release_internal+0xb4/0x24c)
[ 1233.341787] [<8029867c>] (vchiq_release_internal) from [<802993c0>] (vchiq_ioctl+0x7ec/0x1870)
[ 1233.341791]  r9:b563b400 r8:00464006 r7:b563a000 r6:0000c40d r5:805478a8 r4:0000c40c
[ 1233.341813] [<80298bd4>] (vchiq_ioctl) from [<800e5c14>] (do_vfs_ioctl+0x41c/0x60c)
[ 1233.341818]  r10:00000000 r9:a949c000 r8:00000003 r7:0000c40d r6:b2d97f00 r5:00464006
[ 1233.341831]  r4:b62f8648
[ 1233.341840] [<800e57f8>] (do_vfs_ioctl) from [<800e5e40>] (SyS_ioctl+0x3c/0x64)
[ 1233.341845]  r9:a949c000 r8:00000003 r7:0000c40d r6:b2d97f00 r5:00464006 r4:b2d97f01
[ 1233.341865] [<800e5e04>] (SyS_ioctl) from [<8000f760>] (ret_fast_syscall+0x0/0x34)
[ 1233.341869]  r8:8000f904 r7:00000036 r6:7eca7adc r5:00000002 r4:76e1b2f0 r3:000000a4
[ 1233.341884] ---[ end trace 3cf8661a1aa3d6ca ]---
[ 1233.341895] vchiq: vchiq_ioctl: cmd VCHIQ_IOC_RELEASE_SERVICE returned error -1 for service TVNT:22453

[Electron752]

Hi,

I was wondering if you could give some more details on some of the applications you are using that uses OpenVG?

Although not directly related to your issue, I've been making some changes to VCHIQ for ARM64 on the RPI. I'm almost to the point that I can get accelerated video to work and I'm looking for some applications that I can run to stress the video subsystem. As part of testing, I may well be able to reproduce the same issues and possibly submit some changes to VCHIQ or provide some more information on the issue so that someone else can fix it.

One thing you may want to try that should be easy to check is to upgrade your kernel. I think 4.4.11 is older(if I'm reading the logs correctly) and I've noticed a change or two to that component since then.

[rodizio1]

It's an application that draws an "OSD" (or "HUD") on the screen for usage with FPV model airplanes and copters: https://github.com/SamuelBrucksch/wifibroadcast_osd

I use it in these ready-to-use Raspberry images:
https://github.com/bortek/EZ-WifiBroadcast

Upgrading the kernel is still on my to do list. I've tried with 4.4.32 already some time ago (from the Raspbian release before the latest that came out in January) but this one has some issues with scheduling or whatever,there is packetloss, so I kept 4.4.11.

Hopefully it's better with the Kernel/firmware included in the latest Raspbian version from January.

[rodizio1]

Did some more tests. The funny thing is, this started happening after disabling overclocking because of some other kernel flakiness.

After overclocking the system again it seems stable (Atleast the graphical system).

[Electron752]

It's most certainly a concurrency or timing issue then. You can get weird issues like that where something can be broke on a slow cpu but work just fine on a fast cpu. And to make it even more interesting, since it's calling into the firmware to do the actual work, it can depend on the exact firmware version or difference between the speed of the gpu and the arm.

BTW, the picture from the airplane is cool. Maybe you just need to put a cell phone connection in the airplane and then be able to control it anywhere you can get a cell service. From anywhere in the world with an Internet connection of course. Would just need to watch your data cap on the cell connection though :)

[rodizio1]

It's most certainly a concurrency or timing issue then. You can get weird issues like that where something can be broke on a slow cpu but work just fine on a fast cpu. And to make it even more interesting, since it's calling into the firmware to do the actual work, it can depend on the exact firmware version or difference between the speed of the gpu and the arm.

Is this considered "normal" on the Pi? In my experience, slower computers just run slower, but they don't crash. Actually, after all those years, I'm not really used to that type of completely weird and unreproducible crashes anymore, dimly remember that from Windows 3.1 and 95/98, but not Linux (or Win NT and it's successors).

BTW, the picture from the airplane is cool. Maybe you just need to put a cell phone connection in the airplane and then be able to control it anywhere you can get a cell service. From anywhere in the world with an Internet connection of course. Would just need to watch your data cap on the cell connection though :)

Yeah, it's really cool what you can do nowadays with Raspberrys and cheap Wifi sticks. Range with $10 70mW transmit power wifi sticks is about 1km and unlike analog video transmission, the picture is much better quality and rock-solid.

I think there are actually open source projects that support using LTE cell services for video, but I don't have too good high-speed/low-latency mobile coverage here and no flat-rate tarrifs, that would get quite expensive.

[Electron752]

I'm actually not associated with the PI Foundation. I've just submitted a few 64 bit related changes to both upstream and here for 64 bit regarding vchiq. So maybe someone who knows more can chime in.

No, it's not normal on the Pi. Just at the same time you are getting what is in the US a $30 computer. And NT and Linux core I'm sure both have much higher budgets(Linux core has corporate employee time that gets donated).

I have seen a few fixes to vchiq recently that might help.
f4c962d
203d8a5
d99e8fa
3d17f0e

If finding a different version of the kernel and firmware doesn't help(4.9 is the stable version now), you can also try using kms or fkms for video instead of the default. kms bypasses the firmware and vchiq completely for video, so you would be using newer and open source software.

You can select either of these by using in your config.txt:
dtoverlay=vc4-kms-v3d
or
dtoverlay=vc4-fkms-v3d

A final option that may provide debugging information is to turn on logging for vchiq. You can find the settings in debugfs under /sys/kernel/debug/vchiq. Although with these kinds of timing issues, sometimes turning on logging will make the issue go away.

[JamesH65]

Is this still present? Any simple use cases that demonstrate the problem?

[rodizio1]

dtoverlay=vc4-fkms-v3d is no option for me unfortunately because I need the video decoder and raspivid.

Since I went back to the overclocked settings, the problem didn't occur anymore.

[JamesH65]

@popcornmix @pelwell I'm inclined to close this unless you have other ideas?

[JamesH65]

Closing due to lack of activity. Reopen if you feel this issue is still relevant.