Smart encoding re-encodes last GOP needlessly on a H.264 video
└─ env GST_DEBUG=4 ges-launch-1.0 +clip '2020-09-28 19-55-45.mp4' -o out.mp4 --smart-rendering 2>| grep 'gstsmartencoder.c'
Encoding details:
================
-> Output file: out.mp4
-> Profile: (selected from input files format for efficient smart rendering
> ∋ Quicktime: auto-generated (Automatically generated from GstDiscovererInfo)
- ▶ /001 (H.264 (High Profile)) (1120x360@60/1fps)
- ♫ /002 (MPEG-4 AAC) (2 channels @ 48000hz)
**Mixing is disabled for smart rendering to work**
Timeline description:
====================
- Clip from: 'file:///home/yalter/2020-09-28%2019-55-45.mp4' [∋Quicktime, ♫MPEG-4 AAC, ▶H.264 (High Profile)]
start=0:00:00.000000000 duration=0:00:18.467000000
0:00:02.831054272 52430 0x1b00520 INFO smartencoder gstsmartencoder.c:538:smart_encoder_sink_event:<smartencoder0> Pushing pending GOP on new segment
0:00:02.831084529 52430 0x1b00520 INFO smartencoder gstsmartencoder.c:409:gst_smart_encoder_push_pending_gop:<smartencoder0> Empty gop!
0:00:02.831088702 52430 0x1b00520 INFO smartencoder gstsmartencoder.c:554:smart_encoder_sink_event:<smartencoder0> Eating segment
0:00:02.837184726 52430 0x1b00520 INFO smartencoder gstsmartencoder.c:436:gst_smart_encoder_push_pending_gop:<smartencoder0> GOP doesn't need to be modified, pushing downstream: 0:00:00.033333333 to 0:00:04.200000000
0:00:02.851891576 52430 0x1b00520 INFO smartencoder gstsmartencoder.c:436:gst_smart_encoder_push_pending_gop:<smartencoder0> GOP doesn't need to be modified, pushing downstream: 0:00:04.200000000 to 0:00:08.366666666
0:00:02.865587270 52430 0x1b00520 INFO smartencoder gstsmartencoder.c:436:gst_smart_encoder_push_pending_gop:<smartencoder0> GOP doesn't need to be modified, pushing downstream: 0:00:08.366666666 to 0:00:12.533333333
0:00:02.878726198 52430 0x1b00520 INFO smartencoder gstsmartencoder.c:436:gst_smart_encoder_push_pending_gop:<smartencoder0> GOP doesn't need to be modified, pushing downstream: 0:00:12.533333333 to 0:00:16.700000000
0:00:02.885650027 52430 0x1b00520 INFO smartencoder gstsmartencoder.c:429:gst_smart_encoder_push_pending_gop:<smartencoder0> GOP needs to be re-encoded from 0:00:16.700000000 to 0:00:18.500333333 - time segment start=0:00:00.033333333, offset=0:00:00.000000000, stop=0:00:18.500333333, rate=1.000000, applied_rate=1.000000, flags=0x01, time=0:00:00.000000000, base=0:00:00.000000000, position 0:00:00.033333333, duration 99:99:99.999999999
0:00:02.888334223 52430 0x1b00520 INFO smartencoder gstsmartencoder.c:318:gst_smart_encoder_reencode_gop: Pushing Flush start/stop to clean decoder/encoder
0:00:02.888381352 52430 0x1b00520 INFO smartencoder gstsmartencoder.c:323:gst_smart_encoder_reencode_gop: Pushing segment_event segment event: 0x7f8580003030, time 99:99:99.999999999, seq-num 793, GstEventSegment, segment=(GstSegment)"segment, flags=(GstSegmentFlags)GST_SEGMENT_FLAG_RESET, rate=(double)1, applied-rate=(double)1, format=(GstFormat)time, base=(guint64)0, offset=(guint64)0, start=(guint64)33333333, stop=(guint64)18500333333, time=(guint64)0, position=(guint64)33333333, duration=(guint64)18446744073709551615;";
<position: 0:00:18.483333333 duration: 0:00:18.467000000 speed: 1.000000 />
Done
warning : Buffer didn't have expected DISCONT flag
Detected on <GESVideoUriSource:nlesource0:src>
Detected on <muxer:src>
Detected on <internal-encodebin:src>
Detected on <filesink0:sink, internal-encodebin:src, filesink0:sink>
Detected on <decodebin6:sink>
Detected on <typefind:sink, typefind:src, h264parse5:sink>
Description : Buffers after SEGMENT and FLUSH must have a DISCONT flag
warning : Query position reported a value superior than what query duration returned
Detected on <gespipeline0>
issue : SEGMENT events that are part of the same pipeline 'operation' should have the same seqnum
Detected on <decodebin6:sink>
Detected on <typefind:sink, typefind:src>
Description : when events/messages are created from another event/message, they should have their seqnums set to the original event/message seqnum
warning : received the same caps twice
Detected on <filesink0:sink>
Detected on <avdec_h264-1:sink>
Detected on <h264parse5:sink>
warning : received an unexpected flush stop event
Detected on <GESAudioUriSource:nlesource1:src>
Detected on <GESVideoUriSource:nlesource0:src>
issue : FLUSH_START events that are part of the same pipeline 'operation' should have the same seqnum
Detected on <GESAudioUriSource:nlesource1:src>
Detected on <audio_nlecomposition1:src>
Detected on <GESVideoUriSource:nlesource0:src>
Detected on <video_nlecomposition0:src>
Description : when events/messages are created from another event/message, they should have their seqnums set to the original event/message seqnum
issue : EOS events that are part of the same pipeline 'operation' should have the same seqnum
Detected on <decodebin6:sink>
Detected on <typefind:sink, typefind:src, h264parse5:sink, h264parse5:src, capsfilter15:sink, capsfilter15:src, avdec_h264-1:sink, avdec_h264-1:src>
Detected on <decodebin6:src_0>
Detected on <bin1:sink>
Detected on <videoconvert4:sink, videoconvert4:src, nvh264enc1:sink, nvh264enc1:src, h264parse3:sink, h264parse3:src, capsfilter9:sink, capsfilter9:src>
Detected on <bin1:src>
Detected on <capsfilter14:sink, capsfilter14:src>
Detected on <smartencoder0:src, streamcombiner2:passthroughsink, streamcombiner2:src, h264parse2:sink, h264parse2:src, capsfilter8:sink, capsfilter8:src, queue5:sink, queue5:src, muxer:video_0>
Description : when events/messages are created from another event/message, they should have their seqnums set to the original event/message seqnum
warning : EOS received without segment event before
Detected on <streamsplitter3:encodingsrc, audiorate1:sink, audiorate1:src, audioconvert3:sink, audioconvert3:src, audioresample2:sink, audioresample2:src, audioconvert4:sink, audioconvert4:src, capsfilter13:sink, capsfilter13:src, fakesink1:sink>
Detected on <streamsplitter2:encodingsrc, videoconvert5:sink, videoconvert5:src, videoscale1:sink, videoscale1:src, videoconvert6:sink, videoconvert6:src, videorate2:sink, videorate2:src, capsfilter11:sink, capsfilter11:src, nvh264enc2:sink, nvh264enc2:src, streamcombiner2:encodingsink>
Description : A segment event should always be sent before data flow EOS being some kind of data flow, there is no exception in that regard
warning : a serialized event received should be pushed in the same 'time' as it was received
Detected on <multiqueue1:src_0>
Detected on <queue6:src>
Detected on <avdec_h264-1:src>
Detected on <nvh264enc1:src>
Description : serialized events should be pushed in the same order they are received and serialized with buffers. If an event is received after a buffer with timestamp end 'X', it should be pushed right after buffers with timestamp end 'X'
warning : buffer timestamp is out of the received buffer timestamps' range
Detected on <nvh264enc1:src>
Description : a buffer leaving an element should have its timestamps in the range of the received buffers timestamps. i.e. If an element received buffers with timestamps from 0s to 10s, it can't push a buffer with a 11s timestamp, because it doesn't have data for that
warning : a new segment event has different value than the received one
Detected on <nvh264enc1:src>
Description : when receiving a new segment, an element should push an equivalent segment downstream
warning : We got a g_log warning
Detected on <gespipeline0>
Details : (../subprojects/gstreamer/gst/gstinfo.c:534):gst_debug_log_valist: runtime check failed: (object == NULL || G_IS_OBJECT (object))
Details : (../subprojects/gstreamer/gst/gstinfo.c:534):gst_debug_log_valist: runtime check failed: (object == NULL || G_IS_OBJECT (object))
Details : (../subprojects/gstreamer/gst/gstinfo.c:1270):gst_debug_log_default: runtime check failed: (object == NULL || G_IS_OBJECT (object))
Details : (../subprojects/gstreamer/gst/gstinfo.c:1270):gst_debug_log_default: runtime check failed: (object == NULL || G_IS_OBJECT (object))
backtrace :
gst_debug_get_stack_trace (gstinfo.c:3126)
gst_validate_report_new (gst-validate-report.c:840)
gst_validate_report_valist (gst-validate-reporter.c:189)
gst_validate_report (gst-validate-reporter.c:323)
g_logv (gmessages.c:1350)
g_log (gmessages.c:1415)
g_warn_message (gmessages.c:2806)
gst_debug_log_valist (gstinfo.c:534)
gst_debug_log (gstinfo.c:480)
autoplug_select_cb (ges-uri-source.c:106)
ffi_call_unix64 (unix64.S:73)
ffi_call (ffi64.c:525)
g_cclosure_marshal_generic (gclosure.c:1500)
g_closure_invoke (gclosure.c:810)
signal_emit_unlocked_R.isra.0 (gsignal.c:3738)
g_signal_emit_valist (gsignal.c:3504)
g_signal_emit (gsignal.c:3550)
proxy_autoplug_select_signal (gsturidecodebin.c:1775)
ffi_call_unix64 (unix64.S:73)
ffi_call (ffi64.c:525)
g_cclosure_marshal_generic (gclosure.c:1500)
g_closure_invoke (gclosure.c:810)
signal_emit_unlocked_R.isra.0 (gsignal.c:3738)
g_signal_emit_valist (gsignal.c:3504)
g_signal_emit (gsignal.c:3550)
connect_pad (gstdecodebin2.c:2283)
analyze_new_pad (gstdecodebin2.c:1850)
pad_added_cb (gstdecodebin2.c:2990)
g_closure_invoke (gclosure.c:810)
signal_emit_unlocked_R.isra.0 (gsignal.c:3738)
g_signal_emit_valist (gsignal.c:3494)
g_signal_emit (gsignal.c:3550)
gst_element_add_pad (gstelement.c:795)
gst_qtdemux_add_stream.constprop.0 (qtdemux.c:8784)
qtdemux_expose_streams (qtdemux.c:13155)
gst_qtdemux_loop (qtdemux.c:4571)
gst_task_func (gsttask.c:328)
g_thread_pool_thread_proxy.lto_priv.0 (gthreadpool.c:354)
g_thread_proxy (gthread.c:820)
start_thread (pthread_create.c:463)
__clone (clone.S:93)
Issues found: 15
Fedora 33, 1.18.1 as well as 6434db52