Pipeline having v4l2src+encodebin hangs when propagating EOS to sink pads

Sun Jul 21 00:51:42 UTC 2019

Greetings! I’m tackling my first gstreamer project—capturing video+audio from an AJA USB 3.0 HDMI capture card and writing it out to an MP4.

I’ve now read the Application Developer manual from cover to cover, but I’m still having a heck of a time generating valid MP4 files which contain video+audio.

I recently came across encodebin and found the encodebin Rust example in the gstreamer-rs repo. I’ve been using it as a base. I think I’m nearing a working encodebin-based pipeline that will generate MP4 files, but have hit another snag…

When running the Rust script:

• When I use v4l2src as the src for the pipeline, I am not able to propagate an EOS message through the pipeline to end the capture. Looking at debug logs, the EOS propagates through the src elements successfully, then the script hangs right after outputting `bin gstbin.c:3172:gst_bin_send_event:<pipeline0> Sending eos event to sink pads`
• When I change the source to videotestsrc, EOS messages propagate just fine, and I am able to generate valid MP4 files.

Here is the script using v4l2src: https://github.com/kad3nce/gstreamer-rs/blob/v4l2-encodebin/examples/src/bin/encodebin-v4l2src.rs
And the same script, except using videotestsrc: https://github.com/kad3nce/gstreamer-rs/blob/v4l2-encodebin/examples/src/bin/encodebin-videotestsrc.rs

I’ve attached both scripts to this email as well.

I’m running these on:

• Ubuntu 19.04
• Cargo/Rust 1.36.0
• GStreamer 1.15.90

Here is the output from the scripts with GST_DEBUG=6 (I used Dropbox since the files are large):

encodebin-v4l2src: https://www.dropbox.com/s/v1howtf10j7uxo2/encodebin-v4l2src-debug-6.txt?dl=0
encodebin-videotestsrc: https://www.dropbox.com/s/gze85v0a0vs6tm2/encodebin-videotestsrc-debug-6.txt?dl=0

I’m happy to round any other info/logging which might be pertinent.

And for quick reference, here is the last bit of the output from the encodebin-v4l2src script right before it hangs:

0:00:01.194370240 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60e3cb0, state-changed from v4l2src0
0:00:01.194377854 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60e3d30, state-changed from queue0
0:00:01.194384867 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60e3db0, state-changed from videoconvert0
0:00:01.194391743 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60e3e30, state-changed from videoscale0
0:00:01.194398481 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60e3eb0, state-changed from encodebin0
0:00:01.194405276 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60e3f30, state-changed from queue2
0:00:01.194411955 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60ea840, state-changed from streamsplitter0
0:00:01.194418656 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60ea940, state-changed from videoconvert1
0:00:01.194425345 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60ea9c0, state-changed from videoscale1
0:00:01.194432096 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x7ff9f40028b0, state-changed from videoconvert2
0:00:01.194438574 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60eaa40, state-changed from videorate0
0:00:01.194445209 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60eaac0, state-changed from capsfilter1
0:00:01.194451854 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60eabc0, state-changed from x264enc1
0:00:01.194458563 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60eac40, state-changed from streamcombiner0
0:00:01.194465259 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60eae40, state-changed from h264parse0
0:00:01.194472135 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60eacc0, state-changed from capsfilter0
0:00:01.194478831 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60ead40, state-changed from queue1
0:00:01.194485505 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60eadc0, state-changed from muxer
0:00:01.194492190 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x7ffa04001c80, state-changed from filesink0
0:00:01.194499004 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x7ffa04001d00, state-changed from pipeline0
0:00:01.194505568 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x7ffa04001d80, state-changed from v4l2src0
0:00:01.194512343 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x7ff9f4002ab0, stream-status from src
0:00:01.194520576 28808 0x55ffe5e20000 DEBUG task gsttask.c:210:gst_task_finalize: task 0x55ffe60c65f0 finalize
0:00:01.194531180 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x7ffa04001e00, state-changed from v4l2src0
0:00:01.194538242 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x7ffa04001e80, state-changed from queue0
0:00:01.194545326 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x7ff9f4002eb0, stream-status from src
0:00:01.194552371 28808 0x55ffe5e20000 DEBUG task gsttask.c:210:gst_task_finalize: task 0x55ffe60c64d0 finalize
0:00:01.194560064 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x7ffa04001f00, state-changed from queue0
0:00:01.194566773 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60f8800, state-changed from videoconvert0
0:00:01.194573662 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60f8880, state-changed from videoconvert0
0:00:01.194580370 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60f8900, state-changed from videoscale0
0:00:01.194587057 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60f8980, state-changed from videoscale0
0:00:01.194593820 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60f8a00, state-changed from encodebin0
0:00:01.194600383 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60f8a80, state-changed from queue2
0:00:01.194607167 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60ee310, stream-status from src
0:00:01.194614731 28808 0x55ffe5e20000 DEBUG task gsttask.c:210:gst_task_finalize: task 0x55ffe60c63b0 finalize
0:00:01.194621569 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60f8b00, state-changed from streamsplitter0
0:00:01.194628408 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60f8b80, state-changed from videoconvert1
0:00:01.194635211 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60ee190, state-changed from videoscale1
0:00:01.194641810 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x7ff9f4002830, state-changed from videoconvert2
0:00:01.194648572 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60ee290, state-changed from videorate0
0:00:01.194655155 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x7ffa00002e20, state-changed from capsfilter1
0:00:01.194661721 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x7ffa00002ea0, state-changed from x264enc1
0:00:01.194668494 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x7ffa00002f20, state-changed from streamcombiner0
0:00:01.194675559 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60f3030, state-changed from h264parse0
0:00:01.194682159 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60f30b0, state-changed from capsfilter0
0:00:01.194688796 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x7ff9f4002e30, state-changed from queue1
0:00:01.194695441 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60eaec0, stream-status from src
0:00:01.194702141 28808 0x55ffe5e20000 DEBUG task gsttask.c:210:gst_task_finalize: task 0x55ffe60c6290 finalize
0:00:01.194708893 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60f3130, state-changed from muxer
0:00:01.194715860 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60f31b0, state-changed from encodebin0
0:00:01.194722479 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x7ff9f4002930, state-changed from queue2
0:00:01.194729188 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60ee210, state-changed from streamsplitter0
0:00:01.194860498 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60ea8c0, state-changed from videoconvert1
0:00:01.194888869 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x7ffa00002d20, state-changed from videoscale1
0:00:01.194899147 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60f8c80, state-changed from videoconvert2
0:00:01.194906284 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60f8d00, state-changed from videorate0
0:00:01.194913344 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60f8d80, state-changed from capsfilter1
0:00:01.195597899 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60f8e00, state-changed from x264enc1
0:00:01.195661959 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60f8e80, state-changed from streamcombiner0
0:00:01.195676673 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60f8f00, state-changed from h264parse0
0:00:01.195684465 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60ee010, state-changed from capsfilter0
0:00:01.195691758 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60ee090, state-changed from queue1
0:00:01.195698399 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60ee110, state-changed from muxer
0:00:01.195705273 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x7ffa00002ca0, state-changed from filesink0
0:00:01.195711934 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x7ffa00002da0, state-changed from filesink0
0:00:01.195718839 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x7ff9f4002a30, error from v4l2src0
0:00:01.195729328 28808 0x55ffe5e20000 DEBUG GST_STATES gstelement.c:2988:gst_element_change_state:<pipeline0> element changed state SUCCESS
0:00:01.195762922 28808 0x55ffe5e20000 INFO GST_STATES gstelement.c:2676:gst_element_continue_state:<pipeline0> completed state change to NULL
0:00:01.195771527 28808 0x55ffe5e20000 INFO GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:01.195780450 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:305:gst_message_new_custom: source pipeline0: creating new message 0x55ffe60f8f00 state-changed
0:00:01.195793981 28808 0x55ffe5e20000 DEBUG GST_BUS gstbus.c:316:gst_bus_post:<bus1> [msg 0x55ffe60f8f00] posting on bus state-changed message: 0x55ffe60f8f00, time 99:99:99.999999999, seq-num 214, element 'pipeline0', GstMessageStateChanged, old-state=(GstState)GST_STATE_READY, new-state=(GstState)GST_STATE_NULL, pending-state=(GstState)GST_STATE_VOID_PENDING;
0:00:01.195801913 28808 0x55ffe5e20000 DEBUG GST_BUS gstbus.c:408:gst_bus_post:<bus1> bus is flushing
0:00:01.195809140 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x55ffe60f8f00, state-changed from pipeline0
0:00:01.195817052 28808 0x55ffe5e20000 LOG GST_STATES gstelement.c:3004:gst_element_change_state:<pipeline0> exit state change 1
0:00:01.195823045 28808 0x55ffe5e20000 LOG GST_STATES gstelement.c:3004:gst_element_change_state:<pipeline0> exit state change 1
0:00:01.195829390 28808 0x55ffe5e20000 DEBUG GST_STATES gstelement.c:2911:gst_element_set_state_func:<pipeline0> returned SUCCESS
0:00:01.195842462 28808 0x55ffe5e20000 LOG GST_MESSAGE gstmessage.c:209:_gst_message_free: finalize message 0x7ff9f40029b0, error from v4l2src0
0:00:01.195850745 28808 0x55ffe5e20000 DEBUG GST_BUS gstbus.c:842:gst_bus_source_dispatch:<bus1> source 0x55ffe60e8000 handler returns 1
sending eos
0:00:05.999066233 28808 0x55ffe5e20000 DEBUG GST_EVENT gstevent.c:309:gst_event_new_custom: creating new event 0x7ff9f4006590 eos 28174
0:00:05.999086385 28808 0x55ffe5e20000 DEBUG GST_ELEMENT_PADS gstelement.c:1852:gst_element_send_event: send eos event on element pipeline0
0:00:05.999098369 28808 0x55ffe5e20000 DEBUG bin gstbin.c:3132:gst_bin_send_event:<pipeline0> Sending eos event to src children
0:00:05.999172712 28808 0x55ffe5e20000 DEBUG GST_STATES gstbin.c:2029:bin_element_is_src:<pipeline0> child videoscale0 is not src
0:00:05.999182878 28808 0x55ffe5e20000 DEBUG GST_STATES gstbin.c:2029:bin_element_is_src:<pipeline0> child videoconvert0 is not src
0:00:05.999190058 28808 0x55ffe5e20000 DEBUG GST_STATES gstbin.c:2029:bin_element_is_src:<pipeline0> child queue0 is not src
0:00:05.999212074 28808 0x55ffe5e20000 DEBUG GST_STATES gstbin.c:2029:bin_element_is_src:<pipeline0> child v4l2src0 is src
0:00:05.999218479 28808 0x55ffe5e20000 DEBUG GST_ELEMENT_PADS gstelement.c:1852:gst_element_send_event: send eos event on element v4l2src0
0:00:05.999228366 28808 0x55ffe5e20000 DEBUG basesrc gstbasesrc.c:1801:gst_base_src_send_event:<v4l2src0> handling event 0x7ff9f4006590 eos event: 0x7ff9f4006590, time 99:99:99.999999999, seq-num 215, (NULL)
0:00:05.999238188 28808 0x55ffe5e20000 LOG v4l2 gstv4l2object.c:4129:gst_v4l2_object_unlock:<v4l2src0:src> start flushing
0:00:05.999244356 28808 0x55ffe5e20000 LOG v4l2 gstv4l2object.c:4142:gst_v4l2_object_unlock_stop:<v4l2src0:src> stop flushing
0:00:05.999250916 28808 0x55ffe5e20000 LOG bin gstbin.c:3149:gst_bin_send_event:<v4l2src0> After handling eos event: 1
0:00:05.999258256 28808 0x55ffe5e20000 DEBUG GST_STATES gstbin.c:2029:bin_element_is_src:<pipeline0> child filesink0 is not src
0:00:05.999265297 28808 0x55ffe5e20000 DEBUG GST_STATES gstbin.c:2029:bin_element_is_src:<pipeline0> child encodebin0 is not src
0:00:05.999271983 28808 0x55ffe5e20000 DEBUG bin gstbin.c:3172:gst_bin_send_event:<pipeline0> Sending eos event to sink pads

Note: I’ve been using v4l2loopback for testing when I don't have a capture card or other v4l2 compatible device handy. Thought I’d mention it :) https://askubuntu.com/questions/881305/is-there-any-way-ffmpeg-send-video-to-dev-video0-on-ubuntu
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.freedesktop.org/archives/gstreamer-devel/attachments/20190720/8ba2ce55/attachment-0001.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: encodebin-v4l2src.rs
Type: application/octet-stream
Size: 14310 bytes
Desc: not available
URL: <https://lists.freedesktop.org/archives/gstreamer-devel/attachments/20190720/8ba2ce55/attachment-0002.obj>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: encodebin-videotestsrc.rs
Type: application/octet-stream
Size: 14259 bytes
Desc: not available
URL: <https://lists.freedesktop.org/archives/gstreamer-devel/attachments/20190720/8ba2ce55/attachment-0003.obj>