GNOME Bugzilla – Bug 753257
avenc_mjpeg does not play well with appsrc do-timestamp=true
Last modified: 2018-11-03 12:57:29 UTC
Spice (http://www.spice-space.org/) provides access to remote desktops, particularly in virtualized environments. One of the features is the auto-detection and reencoding of videos to limit bandwidth and ensure smooth playback over the network. Currently it uses an internal MJPEG encoder and I'm adding GStreamer support so more options are available. The pipeline is: appsrc format=2 do-timestamp=true ! videoconvert ! avenc_mjpeg ! appsink The problem is avenc_mjpeg quickly locks up with the following message: 0:00:00.845940069 23436 0x7f5318649800 ERROR libav :0:: Error, Invalid timestamp=12, last=12 The issue is that the frame rate is not really constant as it depends on the delays occurring in the virtual machine's media player and in Spice, and also that we only have an estimate of the fps. So the DTS and PTS timestamps appsrc puts on the buffers are not evenly spaced. Actually I'm not entirely sure why they are even set since we set the format to GST_FORMAT_BYTES. In the above case we had an estimated fps of 18, and the following buffer timestamps: 002513154 -> 0.0450 -> 0 071591170 -> 1.2870 -> 1 118313226 -> 2.1294 -> 2 165181751 -> 2.9718 -> 3 245834444 -> 4.4244 -> 4 332598247 -> 5.9850 -> 6 371301628 -> 6.6834 -> 7 418700233 -> 7.5366 -> 8 506639922 -> 9.1188 -> 9 544309390 -> 9.7974 -> 10 591892626 -> 10.6524 -> 11 639620343 -> 11.5128 -> 12 677606008 -> 12.1968 -> 12 vp8enc and x264enc have no problem with the timestamps produced by appsrc so I'd expect avenc_mjpeg to work with them too. Bug 724103 looks similar but it has not seen a resolution so far. Here are the relevant GStreamer traces: 0:00:00.168343602 23436 0x7f5318649800 LOG GST_SCHEDULING gstpad.c:3828:gst_pad_chain_data_unchecked:<encoder:sink> calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7f531864f730, pts 0:00:00.002513154, dts 0:00:00.002513154, dur 99:99:99.999999999, size 2536960, offset 1, offset_end 18446744073709551615, flags 0x0 0:00:00.235083367 23436 0x7f5318649800 LOG GST_SCHEDULING gstpad.c:3828:gst_pad_chain_data_unchecked:<encoder:sink> calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7f531864f730, pts 0:00:00.071591170, dts 0:00:00.071591170, dur 99:99:99.999999999, size 2536960, offset 2, offset_end 18446744073709551615, flags 0x0 0:00:00.281803710 23436 0x7f5318649800 LOG GST_SCHEDULING gstpad.c:3828:gst_pad_chain_data_unchecked:<encoder:sink> calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7f531864f730, pts 0:00:00.118313226, dts 0:00:00.118313226, dur 99:99:99.999999999, size 2536960, offset 3, offset_end 18446744073709551615, flags 0x0 0:00:00.331504042 23436 0x7f5318649800 LOG GST_SCHEDULING gstpad.c:3828:gst_pad_chain_data_unchecked:<encoder:sink> calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7f531864f730, pts 0:00:00.165181751, dts 0:00:00.165181751, dur 99:99:99.999999999, size 2536960, offset 4, offset_end 18446744073709551615, flags 0x0 0:00:00.409095156 23436 0x7f5318649800 LOG GST_SCHEDULING gstpad.c:3828:gst_pad_chain_data_unchecked:<encoder:sink> calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7f531864f730, pts 0:00:00.245834444, dts 0:00:00.245834444, dur 99:99:99.999999999, size 2536960, offset 5, offset_end 18446744073709551615, flags 0x0 0:00:00.497658441 23436 0x7f5318649800 LOG GST_SCHEDULING gstpad.c:3828:gst_pad_chain_data_unchecked:<encoder:sink> calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7f531864f730, pts 0:00:00.332598247, dts 0:00:00.332598247, dur 99:99:99.999999999, size 2536960, offset 6, offset_end 18446744073709551615, flags 0x0 0:00:00.534940768 23436 0x7f5318649800 LOG GST_SCHEDULING gstpad.c:3828:gst_pad_chain_data_unchecked:<encoder:sink> calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7f531864f730, pts 0:00:00.371301628, dts 0:00:00.371301628, dur 99:99:99.999999999, size 2536960, offset 7, offset_end 18446744073709551615, flags 0x0 0:00:00.582394393 23436 0x7f5318649800 LOG GST_SCHEDULING gstpad.c:3828:gst_pad_chain_data_unchecked:<encoder:sink> calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7f531864f730, pts 0:00:00.418700233, dts 0:00:00.418700233, dur 99:99:99.999999999, size 2536960, offset 8, offset_end 18446744073709551615, flags 0x0 0:00:00.670202868 23436 0x7f5318649800 LOG GST_SCHEDULING gstpad.c:3828:gst_pad_chain_data_unchecked:<encoder:sink> calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7f531864f730, pts 0:00:00.506639922, dts 0:00:00.506639922, dur 99:99:99.999999999, size 2536960, offset 9, offset_end 18446744073709551615, flags 0x0 0:00:00.707709735 23436 0x7f5318649800 LOG GST_SCHEDULING gstpad.c:3828:gst_pad_chain_data_unchecked:<encoder:sink> calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7f531864f730, pts 0:00:00.544309390, dts 0:00:00.544309390, dur 99:99:99.999999999, size 2536960, offset 10, offset_end 18446744073709551615, flags 0x0 0:00:00.756213906 23436 0x7f5318649800 LOG GST_SCHEDULING gstpad.c:3828:gst_pad_chain_data_unchecked:<encoder:sink> calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7f531864f730, pts 0:00:00.591892626, dts 0:00:00.591892626, dur 99:99:99.999999999, size 2536960, offset 11, offset_end 18446744073709551615, flags 0x0 0:00:00.803863082 23436 0x7f5318649800 LOG GST_SCHEDULING gstpad.c:3828:gst_pad_chain_data_unchecked:<encoder:sink> calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7f531864f730, pts 0:00:00.639620343, dts 0:00:00.639620343, dur 99:99:99.999999999, size 2536960, offset 12, offset_end 18446744073709551615, flags 0x0 0:00:00.845885669 23436 0x7f5318649800 LOG GST_SCHEDULING gstpad.c:3828:gst_pad_chain_data_unchecked:<encoder:sink> calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7f531864f730, pts 0:00:00.677606008, dts 0:00:00.677606008, dur 99:99:99.999999999, size 2536960, offset 13, offset_end 18446744073709551615, flags 0x0 0:00:00.845940069 23436 0x7f5318649800 ERROR libav :0:: Error, Invalid timestamp=12, last=12 0:00:00.845960574 23436 0x7f5318649800 ERROR libav gstavvidenc.c:675:gst_ffmpegvidenc_handle_frame:<encoder> avenc_mjpeg: failed to encode buffer 0:00:00.845970442 23436 0x7f5318649800 DEBUG videoencoder gstvideoencoder.c:1902:gst_video_encoder_finish_frame:<encoder> skipping frame 0:00:00.677606008
What about choosing appsrc format=3 (time), would make more sense.
The other bug looks like the exact same issue. What caps do you set on appsrc? Try with framerate=0/1 (which signals variable rate). Maybe we need to tell the encoder that the rate is not fixed.
Setting appsrc format=3 and/or framerate=0/1 in the appsrc caps makes no change: I still get the Invalid timestamp error. Here is the code creating the caps for appsrc: encoder->src_caps = gst_caps_new_simple( "video/x-raw", "format", G_TYPE_STRING, "BGRx", "bpp", G_TYPE_INT, encoder->format->bpp, "depth", G_TYPE_INT, encoder->format->depth, "width", G_TYPE_INT, encoder->width, "height", G_TYPE_INT, encoder->height, "endianness", G_TYPE_INT, encoder->format->endianness, "red_mask", G_TYPE_INT, encoder->format->red_mask, "green_mask", G_TYPE_INT, encoder->format->green_mask, "blue_mask", G_TYPE_INT, encoder->format->blue_mask, "framerate", GST_TYPE_FRACTION, get_source_fps(encoder), 1, NULL); g_object_set(G_OBJECT(encoder->appsrc), "caps", encoder->src_caps, NULL); For the full source code, see the GitHub references in: http://lists.freedesktop.org/archives/spice-devel/2015-July/020982.html
I hope you understand GStreamer 0.10 has no longer been supported for few years now. Would it be possible to test against a recent version of GStreamer. If not, we'll have to close this ticket, I am sorry.
It might also be that you miss-ported your application, what makes me think of it is that you have red_mask, green_mask, blue_mask in your caps, which no longer exist, and setting it will cause issues (also depth, width and bpp).
The code does have to support GStreamer 0.10 too, but as I mentioned from the start this issue is present with avenc_mjpeg which is specific to GStreamer 1.0. So this bug is still present in GStreamer 1.0 which is why I reported it. As for red_mask, green_mask, blue_mask, depth, width and bpp, I have not found any documentation that says which values are required, optional or obsolete. Could you point me to the relevant page?
http://cgit.freedesktop.org/gstreamer/gst-plugins-base/tree/docs/design/part-mediatype-video-raw.txt bpp/depth/endianness/*mask are now expressed as part of the format string. I would not expect them to do any harm though, as long as all the other fields are there.
Thanks. I updated the caps so that in GStreamer 1.0 they are now set to: encoder->src_caps = gst_caps_new_simple( "video/x-raw", "format", G_TYPE_STRING, encoder->format->format, "width", G_TYPE_INT, encoder->width, "height", G_TYPE_INT, encoder->height, "framerate", GST_TYPE_FRACTION, get_source_fps(encoder), 1, NULL); There's no change on the timestamp front though.
The bug is still marked "NEEDINFO". Do you need more information? What other information can I provide?
A small self-contained test program in C that reproduces the issue would be great.
Created attachment 312667 [details] Small self-contained test program in C To reproduce the problem invoke the test program with no argument. It will remain stuck after a couple of frames: $ GST_DEBUG=1 ./mjpeg-timestamp appsrc name=src format=2 do-timestamp=true ! videoconvert ! avenc_mjpeg max-threads=1 ! appsink name=sink setting state to PLAYING encoding frame 0 pushing... pulling... encoding frame 1 pushing... pulling... encoding frame 2 pushing... pulling... 0:00:00.013567948 17286 0xba4190 ERROR libav :0:: Invalid pts (0) <= last (0) 0:00:00.013589815 17286 0xba4190 ERROR libav gstavvidenc.c:703:gst_ffmpegvidenc_handle_frame:<encoder> avenc_mjpeg: failed to encode buffer But if you tell it to remove the clock it will successfully encode the 40 frames: $ ./mjpeg-timestamp jpeg,noclock For comparison points you can also try the VP8 encoder which works just fine, clock or no clock: $ ./mjpeg-timestamp vp8 $ ./mjpeg-timestamp vp8,noclock Finally enabling threading in avenc_mjpeg locks up which I guess is somewhat expected at this point. So I'll ignore that for now: $ ./mjpeg-timestamp jpeg,threads $ ./mjpeg-timestamp jpeg,threads,noclock
I believe NEEDINFO can be cleared at this point?
The problem here is the transformation of GStreamer timestamps in ffmpeg timestamps/ticks. The scaling is based on the framerate (or some notional framerate) in such a way that you're likely get the same result in case your timestamps are much closer together. In your example code you basically just push/pull in a tight loop without sleeping, so the timestamps are only a fraction of a millisecond apart, but things are set up for 30fps. This fixes it for me, but it might need other changes, like adjustment of ticks_per_frame or such, to make sure the bitrate estimation is not affected: diff --git a/ext/libav/gstavutils.h b/ext/libav/gstavutils.h index 6d111a2..8485908 100644 --- a/ext/libav/gstavutils.h +++ b/ext/libav/gstavutils.h @@ -57,7 +57,7 @@ gst_ffmpeg_time_ff_to_gst (gint64 pts, AVRational base) if (pts == AV_NOPTS_VALUE){ out = GST_CLOCK_TIME_NONE; } else { - AVRational bq = { 1, GST_SECOND }; + AVRational bq = { 1000, GST_SECOND }; out = av_rescale_q (pts, base, bq); } @@ -72,7 +72,7 @@ gst_ffmpeg_time_gst_to_ff (guint64 time, AVRational base) if (!GST_CLOCK_TIME_IS_VALID (time) || base.num == 0) { out = AV_NOPTS_VALUE; } else { - AVRational bq = { 1, GST_SECOND }; + AVRational bq = { 1000, GST_SECOND }; out = av_rescale_q (time, bq, base); } In your code, you should: 1) set appsrc to is-live=true, because that's more appropriate for your case, and because without the first buffer will not have a valid timestamp (since it's produced before the pipeline goes to playing, so no clock yet at that point. 2) set appsrc to format=time, which is the right thing to do. 3) maybe set framerate=0/1 which means variable framerate (could cause other issues though, only one way to find out)
-- GitLab Migration Automatic Message -- This bug has been migrated to freedesktop.org's GitLab instance and has been closed from further activity. You can subscribe and participate further through the new bug through this link to our GitLab instance: https://gitlab.freedesktop.org/gstreamer/gst-libav/issues/24.