Bug 542328 – media-video/vlc-2.2.0 with USE="ffmpeg vaapi", x11-drivers/ati-drivers-14.12-r3 and CONFIG_PREEMPT_VOLUNTARY kernel: [fglrx:firegl_lock_free] *ERROR* lock was not held by 9! (*lock=0x00000000)

• Status: RESOLVED INVALID
• Product: Gentoo Linux

[Description Fernando Rodriguez 2015-03-06 06:45:41 UTC]

VLC freezes when playing mp4 video with hardware decoding enabled using x11-drivers/ati-drivers

Reproducible: Always

Steps to Reproduce:
1. Build kernel
2. Delete ~/.config/vlc if necessary
3. Emerge x11-drivers/ati-drivers-14.12-r3, media-video/vlc-2.2.0 with USE ffmpeg and vaapi, and deps.
4. Play an mp4 video with hardware decoding set to enabled or automatic (which is the default hence step 2)
Actual Results:  
VLC freezes after a few seconds. The window may or may not close itself but the only way to kill the vlc process is with kill -9. The following message is shown several times in kernel log:

[ 1785.724020] <3>[fglrx:firegl_lock_free] *ERROR* lock was not held by 9! (*lock=0x00000000)
[ 1785.724031] <3>[fglrx:firegl_unlock] *ERROR* firegl_lock_free failed!


Expected Results:  
Video plays.

Compiling the kernel with CONFIG_PREEMPT works around this issue but then I'm affected by Bug 542320. I did not test with CONFIG_PREEMPT_NONE

Disabling hardware decoding on VLC also works around the problem.

libva version: 1.3.1
ffmpeg: 2.5.4

[Comment 1 Andrew Savchenko 2015-03-08 08:34:04 UTC]

Please always provide emerge --info output when reporting bugs.

[Comment 2 Fernando Rodriguez 2015-03-08 17:48:05 UTC]

Created attachment 398402 [details]
emerge --info

[Comment 3 Nick Andrade 2015-04-22 18:36:20 UTC]

Unfortunately I don't have the hardware to test this.  Could you check whether this occurs in other HW accelerated media players (i.e. mpv) or just VLC?  Also, could you see if this still occurs in 2.2.1?

[Comment 4 Fernando Rodriguez 2015-04-25 02:21:31 UTC]

2.2.1 has the same problem. 
mpv-0.8.3 using "mpv --hwdec vaapi movie.mp4" works fine.

[Comment 5 Nick Andrade 2015-04-25 02:55:15 UTC]

Thanks for checking Fernando.  I assume you probably have, but just to verify, have you tried VLC with hardware-accelerated decoding set to both 'VA-API decoder via X11' and 'VA-API decoder via DRM'?  I've checked upstream and so far haven't found any similar issues at this point.

[Comment 6 Fernando Rodriguez 2015-04-26 03:39:20 UTC]

Actually, when I said mpv works fine it was a lie, I do have a problem (video broken in little squares) but that just started recently, I believe after upgrading ffmpeg to 2.6.1 or 2.6.2 and it's happening with vlc 2.1.5 as well but it's not related because it wasn't happening when I filed this.

I did tried both acceleration options. At the time of filing this it was freezing with both. Today I reinstalled ffmpeg 2.6.0 and it does plays with the DRM option but it's not doing HW decoding, I think that requires a DRM chip or something because it prints device not found libva error on the console. And it segfaults when I close it (it may have been doing that all along since I never run it from the console). It also seldom freezes with ffmpeg 2.6.0 but it floods my logs with the firegl error (and going back to ffmpeg 2.6.0 didn't fix the corrupted video problem) and segfaults when I close it:

vlc[3639]: segfault at 7f25b0769100 ip 00007f257369ca90 sp 00007f259e4480a8 error 6 in libAMDXvBA.so.1.0[7f25733ea000+6c1000]

I compiled vlc with the debug use flag and symbols and this is what I get when I start playing:

libva info: VA-API version 0.35.1
libva info: va_getDriverName() returns 0
libva info: Trying to open /usr/lib64/va/drivers/fglrx_drv_video.so
libva info: Found init function __vaDriverInit_0_33
libva info: va_openDriver() returns 0
[00007fffc98dadc8] avcodec decoder: Using AMD MMD 1.0 for hardware decoding.
libva info: VA-API version 0.35.1
libva info: va_getDriverName() returns 0
libva info: Trying to open /usr/lib64/va/drivers/fglrx_drv_video.so
libva info: Found init function __vaDriverInit_0_33
libva info: va_openDriver() returns 0
[00007fffc98dadc8] avcodec decoder: Using AMD MMD 1.0 for hardware decoding.
LibVLC fatal error locking mutex (22) in thread 1240 at posix/thread.c:257 in vlc_mutex_lock
/usr/lib64/libvlccore.so.8(+0xad203)[0x7ffff71be203]
/usr/lib64/libvlccore.so.8(+0x15a2e)[0x7ffff7126a2e]
/usr/lib64/libvlccore.so.8(+0xad95c)[0x7ffff71be95c]
/usr/lib64/vlc/plugins/codec/libvaapi_x11_plugin.so(+0x3a16)[0x7fffba3e3a16]
/usr/lib64/vlc/plugins/codec/libavcodec_plugin.so(+0x2f63)[0x7fffc3047f63]
/usr/lib64/libavcodec.so.56(+0x7171e7)[0x7fffc23201e7]
/usr/lib64/libavcodec.so.56(+0x609dde)[0x7fffc2212dde]
/usr/lib64/libavcodec.so.56(+0x2c92b7)[0x7fffc1ed22b7]
/usr/lib64/libavcodec.so.56(+0x2cfb5d)[0x7fffc1ed8b5d]
/usr/lib64/libavcodec.so.56(+0x26dd25)[0x7fffc1e76d25]
/usr/lib64/libavcodec.so.56(+0x270618)[0x7fffc1e79618]
/usr/lib64/libavcodec.so.56(+0x608f40)[0x7fffc2211f40]
/lib64/libpthread.so.0(+0x8346)[0x7ffff79a8346]
/lib64/libc.so.6(clone+0x6d)[0x7ffff74ec80d]
Thread error: Invalid argument
[New Thread 0x7fffcc177700 (LWP 1245)]
[New Thread 0x7fffe41cb700 (LWP 1243)]
[New Thread 0x7fffbb7fe700 (LWP 1242)]
[New Thread 0x7fffbbfff700 (LWP 1241)]
[New Thread 0x7fffe4bce700 (LWP 1221)]
[New Thread 0x7fffe5479700 (LWP 1218)]
[New Thread 0x7ffff572c700 (LWP 1216)]
[New Thread 0x7ffff5a34700 (LWP 1215)]
[New Thread 0x7ffff3d6e700 (LWP 1214)]

Program received signal SIGABRT, Aborted.
[Switching to Thread 0x7fffc0ef7700 (LWP 1240)]
0x00007ffff743bba7 in raise () from /lib64/libc.so.6
(gdb) backtrace
#0  0x00007ffff743bba7 in raise () from /lib64/libc.so.6
#1  0x00007ffff743cf59 in abort () from /lib64/libc.so.6
#2  0x00007ffff7126a4e in ?? () from /usr/lib64/libvlccore.so.8
#3  0x00007ffff71be95c in vlc_mutex_lock () from /usr/lib64/libvlccore.so.8
#4  0x00007fffba3e3a16 in ?? () from /usr/lib64/vlc/plugins/codec/libvaapi_x11_plugin.so
#5  0x00007fffc3047f63 in ?? () from /usr/lib64/vlc/plugins/codec/libavcodec_plugin.so
#6  0x00007fffc23201e7 in ?? () from /usr/lib64/libavcodec.so.56
#7  0x00007fffc2212dde in ?? () from /usr/lib64/libavcodec.so.56
#8  0x00007fffc1ed22b7 in ?? () from /usr/lib64/libavcodec.so.56
#9  0x00007fffc1ed8b5d in ?? () from /usr/lib64/libavcodec.so.56
#10 0x00007fffc1e76d25 in ?? () from /usr/lib64/libavcodec.so.56
#11 0x00007fffc1e79618 in ?? () from /usr/lib64/libavcodec.so.56
#12 0x00007fffc2211f40 in ?? () from /usr/lib64/libavcodec.so.56
#13 0x00007ffff79a8346 in start_thread () from /lib64/libpthread.so.0
#14 0x00007ffff74ec80d in clone () from /lib64/libc.so.6

I'll file an upstream bug probably tomorrow.

[Comment 7 Fernando Rodriguez 2015-07-13 23:40:23 UTC]

Created attachment 406718 [details, diff]
ati-drivers-15.7-preempt.patch

This is mostly fixed on x11-drivers/ati-drivers-15.7. Acceleration works fine bug I get a bunch of errors similar to this when logging in to a KDM session:

Jul 13 17:05:04 navi kernel: BUG: using smp_processor_id() in preemptible [00000000] code: X/1005
Jul 13 17:05:04 navi kernel: caller is ip_drm_vm_close+0x175/0x500 [fglrx]
Jul 13 17:05:04 navi kernel: CPU: 1 PID: 1005 Comm: X Tainted: P           O   3.18.16 #3
Jul 13 17:05:04 navi kernel: Hardware name: Acer Aspire V5-122P/Aspire V5-122P, BIOS V2.12 01/20/2014
Jul 13 17:05:04 navi kernel:  0000000000000000 ffffffff8178498d ffffffff8158b1ca 0000000000000001
Jul 13 17:05:04 navi kernel:  ffffffff812c2036 4d2f4d4554535953 ffff8800b1bdf5c8 00000000000125c0
Jul 13 17:05:04 navi kernel:  ffff880114adec90 ffff880114ae7ca0 ffffffffa060da35 ffff880114ae7ca0
Jul 13 17:05:04 navi kernel: Call Trace:
Jul 13 17:05:04 navi kernel:  [<ffffffff8158b1ca>] ? dump_stack+0x4a/0x75
Jul 13 17:05:04 navi kernel:  [<ffffffff812c2036>] ? check_preemption_disabled+0x106/0x110
Jul 13 17:05:04 navi kernel:  [<ffffffffa060da35>] ? ip_drm_vm_close+0x175/0x500 [fglrx]
Jul 13 17:05:04 navi kernel:  [<ffffffffa0611e1b>] ? KAS_InterlockedList_InsertAtTail+0x7b/0x170 [fglrx]
Jul 13 17:05:04 navi kernel:  [<ffffffffa06484e2>] ? firegl_trace+0x72/0x1e0 [fglrx]
Jul 13 17:05:04 navi kernel:  [<ffffffffa062de33>] ? MCIL_InterlockedList+0x193/0x2a0 [fglrx]
Jul 13 17:05:04 navi kernel:  [<ffffffffa07237f6>] ? FIFO_Queue_Initialize+0xe6/0x100 [fglrx]
Jul 13 17:05:04 navi kernel:  [<ffffffffa0623ea5>] ? fireglPcsCommand+0xa5/0x140 [fglrx]
Jul 13 17:05:04 navi kernel:  [<ffffffffa0730fb2>] ? AvailableCallbacksQueue_Initialize+0x52/0x70 [fglrx]
Jul 13 17:05:04 navi kernel:  [<ffffffffa0733f8e>] ? InitializeExtension+0x18e/0x240 [fglrx]
Jul 13 17:05:04 navi kernel:  [<ffffffffa073483e>] ? InitializeInterrupts+0x3e/0x70 [fglrx]
Jul 13 17:05:04 navi kernel:  [<ffffffffa0721b74>] ? IRQMGR_InitializeIRQMGR+0x104/0x110 [fglrx]
Jul 13 17:05:04 navi kernel:  [<ffffffffa0632f8f>] ? firegl_find_interrupt_by_ddxid+0x32f/0x8e0 [fglrx]
Jul 13 17:05:04 navi kernel:  [<ffffffffa0632d47>] ? firegl_find_interrupt_by_ddxid+0xe7/0x8e0 [fglrx]
Jul 13 17:05:04 navi kernel:  [<ffffffffa0631602>] ? irqmgr_wrap_initialize+0x22/0xc0 [fglrx]
Jul 13 17:05:04 navi kernel:  [<ffffffffa0632b33>] ? firegl_irqmgr_init+0x53/0x100 [fglrx]
Jul 13 17:05:04 navi kernel:  [<ffffffffa0643e11>] ? hal_init_gpu+0x221/0x4d0 [fglrx]
Jul 13 17:05:04 navi kernel:  [<ffffffffa061d33e>] ? firegl_open+0x2de/0x310 [fglrx]
Jul 13 17:05:04 navi kernel:  [<ffffffffa060d7ee>] ? ip_firegl_fasync+0x126e/0x12e0 [fglrx]
Jul 13 17:05:04 navi kernel:  [<ffffffff81147f24>] ? chrdev_open+0xa4/0x1d0
Jul 13 17:05:04 navi kernel:  [<ffffffff81147e80>] ? cdev_put+0x20/0x20
Jul 13 17:05:04 navi kernel:  [<ffffffff81141159>] ? do_dentry_open+0x1f9/0x330
Jul 13 17:05:04 navi kernel:  [<ffffffff81151707>] ? do_last.isra.42+0x367/0xdf0
Jul 13 17:05:04 navi kernel:  [<ffffffff812c98f0>] ? __percpu_counter_add+0x90/0xd0
Jul 13 17:05:04 navi kernel:  [<ffffffff8115225c>] ? path_openat+0xcc/0x6e0
Jul 13 17:05:04 navi kernel:  [<ffffffff81064739>] ? get_parent_ip+0x9/0x20
Jul 13 17:05:04 navi kernel:  [<ffffffff811536f5>] ? do_filp_open+0x45/0xc0
Jul 13 17:05:04 navi kernel:  [<ffffffff81064797>] ? preempt_count_add+0x47/0xa0
Jul 13 17:05:04 navi kernel:  [<ffffffff8158fb91>] ? _raw_spin_unlock+0x11/0x40
Jul 13 17:05:04 navi kernel:  [<ffffffff8115ff87>] ? __alloc_fd+0x97/0x120
Jul 13 17:05:04 navi kernel:  [<ffffffff811428d9>] ? do_sys_open+0x149/0x230
Jul 13 17:05:04 navi kernel:  [<ffffffff81590636>] ? system_call_fastpath+0x16/0x1b

The attached patch fixed it for me.

[Comment 8 Fernando Rodriguez 2015-07-13 23:46:28 UTC]

Created attachment 406720 [details]
fglrx-errors.txt

These are all the errors I was getting before the patch.

[Comment 9 Fernando Rodriguez 2015-08-30 23:17:21 UTC]

This bug can be closed. It only happened with ati-drivers-15.1 and the remaining issues and patch actually belong on bug #542320 and was posted here by mistake. Sorry.