GNOME Bugzilla – Bug 789473
vaapi plugins removed from registry at early boot
Last modified: 2018-03-30 08:31:34 UTC
I run gstreamer in a system daemon, that is run by systemd in WantedBy=multi-user.target If i do not set Environment=GST_REGISTRY_UPDATE=no, when the app starts and updates the registry, it blacklists all vaapi plugins ; i'm assuming it is not finding the hardware at that point, and blacklisting it. My current workaround is to update the registry manually with gst-launch and disable registry update in my daemon.
Have you tried with the current master? A couple days before the conference I pushed a patch where when element is registered, DRM display is tried first. Before it was tried fist with X11 (glx/egl) and the monitor is queried, thus, in a headless environment, the registering fails. Can you verify?
I'm trying to, but for now i'm having issues with using gst-uninstalled from python (https://bugzilla.gnome.org/show_bug.cgi?id=790123). In the meantime, in my usecase, the system is always headless, and there is never any X11 at all, i don't see how that patch could help... But i'll test as soon as possible anyway.
mmmhh... we'll need to figure out why the initial VA querying fails. Can you set you boot script to log out vaapi*:7 in a file?
I'm a bit confused by the results. $ cat /usr/local/bin/debugvaapi.sh #!/bin/bash rm -rf /home/ubicast/.cache/gstreamer-1.0/ GST_DEBUG_NO_COLOR=yes GST_DEBUG=vaapi*:7 /usr/bin/gst-inspect-1.0 vaapih264enc &> /home/ubicast/vaapi.txt Running it manually produces the expected result (user.log). Running it from systemd with the following unit file (in /usr/lib/systemd/system/vaapidebug.service) doesn't print any vaapi related lines, just "No such element or plugin 'vaapih264enc' (along with some warnings, see systemd.log): $ cat /usr/lib/systemd/system/vaapidebug.service [Unit] Description=Debug vaapi [Service] ExecStart=/usr/local/bin/debugvaapi.sh User=ubicast [Install] WantedBy=multi-user.target
Created attachment 363298 [details] log from systemd
Created attachment 363299 [details] run manually
Actually it seems to work with master ! I am just changing the ExecStart between these two lines and in the first case with stable, the plugin is never found. # cat /usr/lib/systemd/system/vaapi.service [Unit] Description=Vaapi early boot test [Service] ExecStart=/usr/local/bin/vaapi.sh #ExecStart=/home/ubicast/gst-build/gst-uninstalled.py /usr/local/bin/vaapi.sh User=ubicast [Install] WantedBy=multi-user.target $ cat /usr/local/bin/vaapi.sh #!/bin/bash #rm -rf /home/ubicast/.cache/gstreamer-1.0/ GST_DEBUG_NO_COLOR=yes GST_DEBUG=7 /usr/bin/gst-inspect-1.0 vaapih264enc &> /home/ubicast/vaapi.txt It seems to detect vaapi, but adding zero features. I will attach the logs
Created attachment 363369 [details] Logs comparing master and stable
Actually, the problem is here when using the system packages on Arch, which just included 1.14.0, this may be related to using gst-uninstalled.py (gst-build) vs system packages. # pacman -Q gstreamer-vaapi gstreamer-vaapi 1.14.0-1 # cat /usr/lib/systemd/system/vaapi.service [Unit] Description=Vaapi early boot test [Service] ExecStart=/usr/local/bin/vaapi.sh User=ubicast [Install] WantedBy=multi-user.target # cat /usr/local/bin/vaapi.sh #!/bin/bash GST_DEBUG_NO_COLOR=yes GST_DEBUG=7 /usr/bin/gst-inspect-1.0 vaapih264enc &> /home/ubicast/vaapi.txt # rm /home/ubicast/.cache/gstreamer-1.0/registry.x86_64.bin # systemctl enable vaapi.service # reboot # tail -n 1 /home/ubicast/vaapi.txt 0:00:04.117413965 325 0x5591e0c10600 TRACE GST_REFCOUNTING gstobject.c:264:gst_object_unref:<vaapih264enc> 0x5591e0d605b0 unref 2->1 (it worked) # reboot # tail -n 1 /home/ubicast/vaapi.txt No such element or plugin 'vaapih264enc'
The logs are too big for bugzilla: https://www.ubicast.eu/media/downloads/tmp/gst/vaapi_first_boot.txt.gz https://www.ubicast.eu/media/downloads/tmp/gst/vaapi_second_boot.txt.gz
Created attachment 370236 [details] first boot log grepping vaapi grep vaapi vaapi_first_boot.txt > vaapi_first_boot_greped.log
Created attachment 370237 [details] vaapi second boot grepping vaapi grep vaapi vaapi_second_boot.txt > vaapi_second_boot_greped.log
On the first boot, creating the display does work: 0:00:01.231246780 311 0x56038bc4f800 INFO vaapidisplay gstvaapidisplay.c:899:gst_vaapi_display_create_unlocked:<vaapidisplaydrm0> new display addr=0x56038c2da0c0 On the second boot, when creating , creating the VA display fails: 0:00:00.074045621 326 0x55d8657a3800 ERROR default gstvaapi.c:254:plugin_init: Cannot create a VA display By catting /proc/uptime, we can see that the script is executed at 2.29s uptime, and completes at 7.03 Mar 28 12:44:11 mediacoder vaapi.sh[301]: 2.29 5.56 Mar 28 12:44:16 mediacoder vaapi.sh[301]: 7.03 16.79 Identically, the second boot, the scripts completes at 4.93s Mar 28 12:45:05 mediacoder vaapi.sh[306]: 2.27 5.52 Mar 28 12:45:08 mediacoder vaapi.sh[306]: 4.93 11.41 Funnily, adding a sleep to the script before running gst-inspect does seem to fix it: # cat /usr/local/bin/vaapi.sh #!/bin/bash cat /proc/uptime sleep 5 GST_DEBUG_NO_COLOR=yes GST_DEBUG=7 /usr/bin/gst-inspect-1.0 vaapih264enc &> /home/ubicast/vaapi.txt cat /proc/uptime What seems to happen is some kind of race condition, where the gstreamer cache is so efficient that the moment where vaapi is probing the display is too soon and will fail.
This means the reason why i believed that latest master (run with gst-uninstalled) was fixing this is because is was taking more time to run it from gst-uninstalled vs the system installation.
Note that when vaapi fails to initialize, the script exits at 4.93s Mar 28 12:45:08 mediacoder vaapi.sh[306]: 4.93 11.41 This seems pretty close to the following dmesg line: [ 4.080562] [drm] RC6 on
It is odd that vaapi could not create a DRM display at the second boot. You might be right that there's a race condition, but I don't see it in gstreamer-vaapi code itself, but between your system boot sequence. What if you delay a bit the gstreamer-vaapi test? at least until you're sure that the /dev filesystem is done. This is because the DRM display needs a complete I'm thinking in something like adding in [Unit] the key After=local-fs.target or After=systemd-udevd.service or something
jackpot, when it fails: # systemctl status vaapi ● vaapi.service - Vaapi early boot test Loaded: loaded (/usr/lib/systemd/system/vaapi.service; enabled; vendor preset: disabled) Active: inactive (dead) since Thu 2018-03-29 18:08:05 CEST; 26s ago Process: 308 ExecStart=/usr/local/bin/vaapi.sh (code=exited, status=0/SUCCESS) Main PID: 308 (code=exited, status=0/SUCCESS) Mar 29 18:08:05 mediacoder-i3 vaapi.sh[308]: 2.48 5.93 Mar 29 18:08:05 mediacoder-i3 vaapi.sh[308]: ls: cannot access '/dev/dri': No such file or directory Mar 29 18:08:05 mediacoder-i3 systemd[1]: Started Vaapi early boot test. Mar 29 18:08:05 mediacoder-i3 vaapi.sh[308]: 2.73 6.06 I tried a lot of things with systemd, but none that would allow me to still start the service on a system that does not have a GPU, so i ended up adding an exec start pre condition waiting for /dev/dri/card0 and timing out after a delay. I am closing this as this is not really gstreamer's fault...
Actually, would it be possible to never cache vaapi in the plugin cache ? In other terms, how expensive is the libva "inspection" step that conditions the plugins capabilities ? Why not do it every time ? The point that i am still concerned about is that once blacklisted, the plugin never comes back.