6by9
commented
2 years ago (Having some woes building GStreamer as FFmpeg wants atomic operations that aren't supported by the normal Raspberry Pi OS gcc. https://trac.ffmpeg.org/ticket/9275 and https://git.videolan.org/?p=ffmpeg.git;a=commitdiff;h=2f0a214a6202516b4dda2bb22b6b3ac20e465d6d)
AFAIK the codec should be flushing the buffers back. CMD_STOP passes an EOS flag into the codec, and that should be returned when the codec has emptied the internal FIFOs. I'll have to look at logging once I have a build.
fduncanh
popcornmix
engnfrc
Describe the bug
There are two (related?) bugs in driver bcm2835-v4l2-codec.c working with the GStreamer-1.21 (current development) Video4Linux2 plugin where VIDIOC_DQBUF does not dequeue a few frames that were previously successfully queued to the driver by VIDIOC_QBUF. The bugs are associated with Caps renegotiations.
GStreamer Video4Linux2 maintainer Nicolas Dufresne (ndufresne) believes the evidence shows these are driver bugs, not GStreamer v4l2 bugs.
Both produce the GStreamer-1.21 g_warning "v4l2h264dec0: Too old frames, bug in decoder -- please file a bug" which is triggered by Garbage Collection in gst_v4l2_video_dec_loop of queued-but-undequeued frames, which should not occur.
The bugs are seen when using the Video4Linux2 plugin from the GStreamer-1.21 development branch (compiled from source) which is now finally working extremely well on Raspberry Pi OS (32/64 bit, Bullseye) (apart from these annoying warnings from each lost frame)
If the initial frame of the h264 bitstream starts with a SPS NAL, a Caps renegotiation is triggered. Frames 0,1,2... are successfully queued by VIDIOC_QBUF in gst_v4l2_allocator_qbuf in the OUTPUT thread (gst_v4l2_video_dec_handle_frame) but only frames x, x+1, x+2 ,... (where x is variable between frame 2 and frame 5, maybe a race condition) are dequeued by VIDIOC_DQBUF in gst_v4l2_allocator_dqbuf in the CAPTURE thread (gst_v4l2_video_dec_loop).
If a midstream frame with a SPS NAL is detected, and triggers CAPS renegotiation, CMD_STOP is sent to the decoder by gst_v4l2_video_dec_finish, and all pending frames should be drained by VIDIOC_DQBUF in gst_v4l2_allocator_dqbuf, but sometimes (not always) the decoder sends V4L2_BUF_FLAG_LAST prematurely, and a few frames are left un-dequeued. With the test video clip provided here, where a number of midstream Caps renegotiations occur, the number of "lost frames" is different in each event (but does not seem to vary each time the video is played, unlike 1.)
This has been discussed (a bit confusedly, on my part) at
https://gitlab.freedesktop.org/gstreamer/gstreamer/-/merge_requests/2518
https://gitlab.freedesktop.org/gstreamer/gstreamer/-/merge_requests/2517
(These suggested GStreamer Merge Requests are cosmetic attempts to reduce the level of warning messages, not to fix the underlying bug which appears to be a bcm2835-v4l2-codec.c driver bug.)
Steps to reproduce the behaviour
Use the latest https://gitlab.freedesktop.org/gstreamer/gstreamer GStreamer code, built with latest meson 0.62.2 and ninja 1.11.0. (On Raspberry Pi OS Bullseye 64bit Lite, some difficulties due to presence of remnants of deprecated dispmanx require
meson build -Dgst-plugins-base:gl_winsys=eglto successfully build GStreamer, as the default gl_winsys=auto incorrectly detects dispmanx)Use the pipeline
where $1 is the test h264 video clip https://gitlab.freedesktop.org/gstreamer/gstreamer/uploads/f98eab8fe15d2f03df3001febdc63cf6/videodump.h264
This is a 20sec capture from Big Buck Bunny streamed from YouTube to an Apple iPad, then re-streamed at 30fps with Apple AirPlay to an Airplay server running on Raspberry Pi model 4B 64bit , which renders video with GPU decoding using Video4Linux2 and bcm2835. The bitstream was captured as it was sent into the Gstreamer video pipeline.
The capssetter in the pipeline is needed because Apple's colorimetry 1:3:5:1 is not recognized by GStreamer during Caps negotiation, and bt709 = 2:3:5:1 works.
The h264 clip has frames 0-712. Frames 0, 114, 270, 454, 560 contain a type 7 (SPS) + a type 8 (PPS) + a type 5 (VCL) NAL, other frames just contain a single type-1 (VCL) NAL. (frames are type MPLANE). The midstream SPS NALs occur when the iPad is rotated to change the picture between Landscape and Portrait. (changes image width, height is maintained at 1080)
By adding code to monitor the timestamp in V4l2 buffers as they are queued (VIDIOC_QBUF) and dequeued (VIDIOC_DQBUF) by the gstv4l2allocator, and checking pending frames before and after draining, I get the following frame history:
Note: CMD_STOP is also sent to start draining when EOS after frame 712 is detected.
The GStreamer code uses "Garbage Collection" to drop any pending frame that is more than 100 frames older than the current frame being rendered, with an un-hideable warning message for each of these "lost frames".
Device (s)
Raspberry Pi 4 Mod. B
System
Logs
No response
Additional context
ndufresne's suggestion is: "Perhaps the driver author implemented both legacy and specced drain, but forgot to skip the empty buffer if the drain was triggered by cmd_stop. This is easier to fix in the driver."
When the draining ends prematurely at e.g., frame 450 instead of 453, after the 450 buffer is DQBUF'ed with timestamp 450 000 000 000 nsec (450 sec), an empty buffer with flag V4L2_BUF_FLAG_LAST set, and timestamp 450 003 333 000, is DQBUF'ed instead of 451. The same thing, with 450 replaced by 113, 263, 553, 710 happens every time CMD_STOP is sent. Note that the case 113 does NOT lose any frames, so this seems correct behavior, except for lost frames.