GNOME Bugzilla – Bug 758234
baseparse regression causes performance problem on embedded systems
Last modified: 2018-05-01 07:04:56 UTC
Created attachment 315764 [details] Log Test.mpg sample mpeg2 vid LPCM audio Device : linux stb dreambox series, vu+ series and ... Openpli40 gst-1 branch. Own gstmediasink : https://github.com/christophecvr/gstreamer1.0-plugin-multibox-dvbmediasink. But same issue with other still in developpement based stb gstmediasink's such as: https://github.com/OpenPLi/gst-plugin-dvbmediasink/tree/gst-1.0 . Up to gst-1.5.1 all mpeg media with variable bit-rate runned fine.Live streams or filesrc. (Sorry I did not test 1.5.2 tag). From 1.5.9 tagged gstreamer versions all mpeg streams who do have a variable bit-rate freeze continu freeze continu and ... this for filesrc media or live streams whatever resolution they use HD or non HD. In logs there is only one difference by gst-1.5.1 we had only a bit-rate tag when bit-rate changed since 1.5.9 its' always a full tag. I just added a log specially made for here off playing media test sample: https://www.dropbox.com/s/2hvrixw0xsg6sjb/Test.mpg?dl=1
This plays fine with 1.6.1 and git master as of today here with the elements from the GStreamer plugin modules. I suspect a problem in your custom sink or other elements. Can you confirm that it works without your custom elements?
Unfortunately we have no other option for our embedded boxes, we have to use our customized sink that writes PES into a linux tv device (/dev/dvb/adapter0/video0 and /dev/dvb/adapter0/audio0). Using latest GStreamer we are flooded with many bitrate changes. GST_DEBUG_NO_COLOR=1 GST_DEBUG=dvbvideosink:4 gst-launch-1.0 playbin uri=file:///media/NAS_MEDIA/Test/Test.mpg video-sink=fakesink audio-sink=fakesink -m ... Got message #378 from element "fakesink0" (tag): GstMessageTag, taglist=(taglist)"taglist\,\ video-codec\=\(string\)\"MPEG-2\\\ Video\\\ \\\(Main\\\ Profile\\\)\"\,\ minimum-bitrate\=\(uint\)34673200\,\ maximum-bitrate\=\(uint\)45326800\,\ bitrate\=\(uint\)39893670\;"; Got message #381 from element "fakesink0" (tag): GstMessageTag, taglist=(taglist)"taglist\,\ video-codec\=\(string\)\"MPEG-2\\\ Video\\\ \\\(Main\\\ Profile\\\)\"\,\ minimum-bitrate\=\(uint\)34673200\,\ maximum-bitrate\=\(uint\)49515400\,\ bitrate\=\(uint\)40067385\;"; Got message #384 from element "fakesink0" (tag): GstMessageTag, taglist=(taglist)"taglist\,\ video-codec\=\(string\)\"MPEG-2\\\ Video\\\ \\\(Main\\\ Profile\\\)\"\,\ minimum-bitrate\=\(uint\)30484600\,\ maximum-bitrate\=\(uint\)49515400\,\ bitrate\=\(uint\)39899266\;"; Got message #388 from element "fakesink0" (tag): GstMessageTag, taglist=(taglist)"taglist\,\ video-codec\=\(string\)\"MPEG-2\\\ Video\\\ \\\(Main\\\ Profile\\\)\"\,\ minimum-bitrate\=\(uint\)30484600\,\ maximum-bitrate\=\(uint\)49515400\,\ bitrate\=\(uint\)39921387\;"; ... Is there any way to stop receiving bitrate changes?
You should report the problem to whoever wrote that custom sink and other elements then. There still might be a problem somewhere in GStreamer, but it's more likely that the sink is doing something wrong if it works with other sinks.
For the bitrate tags, these shouldn't break anything but are indeed a bit verbose sometimes. Can you open another bug for that?
You shouldn't get "flooded" with them, not on a regular basis anyway (not more than before).
Most probably we need to revert some changes made here: https://bugzilla.gnome.org/show_bug.cgi?id=679768 Tim, you mentioning the follown on the above ticket: >> we now send updated tags way too often (~every frame) Maybe that kills our embedded boxes with variable bitrate?
I believe I fixed that before the 1.6 release. Those patches are not going to be reverted, we'd need to figure out why it sends more updated than it should, that's a bug in the logic somewhere then. What version are you testing with exactly? 1.6.x or 1.5.9x?
>> Those patches are not going to be reverted I was mention it for testing only. In order to have the commit that issue starts. >> What version are you testing with exactly? 1.6.x or 1.5.9x? We are on stable 1.6.1 release (using tar.xz).
Now currently I'm using : http://cgit.freedesktop.org/gstreamer/gstreamer/commit/?h=1.6&id=ce147f81dd6d4aecb61b2879b28d6591baccdd2f The last tagged gst-1.6.1. The problem is same. up to 1.5.1 no issues att all by media with var bitrate.Since 1.5.9 up to 1.6.1 (tagged). With the sample I posted it's really pronounced. But also received reports off problem with live streams. Ok by live streams media type may and do change. But indeed the moment they used media type with variable bitrate for the time the part is bussy it is indeed with video freeze, video continu (while by the live streams the audio continu to play normally). I spend a lot of time in analyzing this. And do confirm that those live strams are always 100 % ok with 1.5.1 but problems also with them are starting as from 1.5.9. As test I even tried to filter out al tags concerning the var bitrate (tag self is only meta data). But problem remains. Since it's ok by you, We need to adapt something in our custom sink's. (Which are unfortunately required on stb devices). Question is what ?
Someone with access to the hardware has to debug it and find the problem. You could start with git bisect.
Maybe the problem is that we do not honor MIN_FRAMES_TO_POST_BITRATE or update_threshold when bitrate changes in gstbaseparse.c I will test if the following patch that honors MIN_FRAMES_TO_POST_BITRATE helps. --- a/libs/gst/base/gstbaseparse.c +++ b/libs/gst/base/gstbaseparse.c @@ -1725,7 +1725,8 @@ gst_base_parse_update_bitrates (GstBaseParse * parse, GstBaseParseFrame * frame) if (parse->priv->bitrate) { parse->priv->avg_bitrate = parse->priv->bitrate; /* spread this (confirmed) info ASAP */ - if (parse->priv->posted_avg_bitrate != parse->priv->avg_bitrate) + if (parse->priv->posted_avg_bitrate != parse->priv->avg_bitrate && + parse->priv->framecount >= MIN_FRAMES_TO_POST_BITRATE) parse->priv->tags_changed = TRUE; }
http://gstreamer.freedesktop.org/wiki/SubmittingPatches/
Created attachment 315828 [details] compile-error-git-master-plugins-good
Thank's athoik, Somehow I think it's somewhere a small issue but with big consequences one some devices. @Sebastian Dröge Yes on a pc it would be the best way to use using bisect, unfortunately we are building in cross enviroment for a stb mips32 device using bitbake. However i started to adapt my recipes to build from git head master. At start I first give a try with the real last master git. I well just had a compile issue by the build off plugins-good. see log off relevant items included here. Just solved it by declaration of the var on line gstrtph261pay.c:870:8 from gint num_gobs; to gint num_gobs = 0; Build ok I could file a new bug report only for that but looks a very small issue.
@Sebastian Dröge and athoik, I tried with the very last head master gst. with or whitout athoik patch same issue (regression). Due to or cross build enviroment unfortunately the git bisect is not really handy. I well compiled now git based and rebuild (and reflashed the stb with the new image) git based build on SRCREV commit's for gstreamer,libav,plug-base,good,bad,ugly. equal to those on the tagged version-1.5.2. All ok there. media runs fine. This means regression on stb is between tagged 1.5.2 and 1.5.90. Tommorow I do not have time. But friday I'll continue, to find the commit which caused regression by our stb's.
Did you test only gstreamer 1.5.2 and 1.5.90? Or did you update gst-plugins-base/good/etc to 1.5.2 or 1.5.90 at the same time too? Try to first limit it to a single module :)
When i used the tags, I always do all which we are using. So I also did do for commits now. Now I'm building git based, we use : gstreamer,gst-libav,plugins-good,plugins-base,plugins-bad,plugins-ugly. But now I builded the gst git based at the commits for the tagged ver 1.5.2. used the srcrev respectif to the tagged one. like for 1.5.2 it's : gstreamer SRCREV = "9909c08807bda709fd12b6270bb5bcdc467e6e72" libav SRCREV = "afdbe664602f42208948296024e9484c522f01f9" plugins-bad SRCREV = "ad827597e38201c6f97973c76d6131129883f574" plugins-base SRCREV = "f10db521f31936220ed1b9fd9ef2e7a7736cfdab" plugins-good SRCREV = "f12899878ffc8e4526cd01ea4b9a42b70766297c" plugins-ugly SRCREV = "73d91f9409e36a6dd50bffe1451f216d878d062a" Since on this stage all is ok, I will work further up in order to find the culprit commit for the regression by us. But I think its in the base gstreamer. So friday I will start looking commit by commit there and try to find as from which commit we have a regression. At last then we can pin point on what action must be taken by us in the customized mediasink and or gstreamer self. The longer the more i think it's a small issue but with nasty creeping consequences. On a pc no problem by you're test's, but the day other devices then the stb's will use higher versions it could be that same problem which show up by variable bitrate mpeg media types.
oops I forgot to answer that, Try to first limit it to a single module :) That I will now do starting from the: gstreamer SRCREV = "9909c08807bda709fd12b6270bb5bcdc467e6e72" I will leave the others like they are.
The commit that causes issues is this one: http://cgit.freedesktop.org/gstreamer/gstreamer/commit/?id=c3bcbadd5452d5b3450f70e49dad3e64f14de00a Reverting that commit the video plays just fine!
So it's my fault, ok ;) Can you check what exactly is different after that commit? One thing I could imagine is the buffer flags or some GstMeta.
Can you help us with the debugging? What GST_DEBUG can help?
For starters, just connect the parser with a "fakesink silent=false", run with gst-launch-1.0 -v and provide the output with and without that commit. Compare and find the differences.
I tried the following: gst-launch-1.0 filesrc location=...Test.mpg ! mpegpsdemux ! fakesink silent=false -v gst-launch-1.0 filesrc location=...Test.mpg ! mpegpsdemux ! mpegvideoparse ! fakesink silent=false -v gst-launch-1.0 filesrc location=...Test.mpg ! mpegvideoparse ! fakesink silent=false -v Comparing the output didn't show something.
And your sink is directly processing the raw MPEG2 elementary stream? I guess you'll then have to check what exactly is different inside the sink, according to the above it should receive buffers but apparently has problems handling them.
We are requesting only video caps to present. video/mpeg, mpegversion = (int) { 1, 2 }, width = (int) [ 16, 4096 ], height = (int) [ 16, 4096 ] ; Using playbin we are receiving the following caps: /GstPlayBin:playbin0/GstURIDecodeBin:uridecodebin0/GstDecodeBin:decodebin0/GstMultiQueue:multiqueue0.GstPad:sink_0: caps = "video/mpeg\,\ mpegversion\=\(int\)2\,\ systemstream\=\(boolean\)false\,\ parsed\=\(boolean\)false" /GstPlayBin:playbin0/GstURIDecodeBin:uridecodebin0/GstDecodeBin:decodebin0/GstMultiQueue:multiqueue0.GstPad:sink_0: caps = "video/mpeg\,\ mpegversion\=\(int\)2\,\ systemstream\=\(boolean\)false\,\ parsed\=\(boolean\)false" /GstPlayBin:playbin0/GstURIDecodeBin:uridecodebin0/GstDecodeBin:decodebin0/GstMpegvParse:mpegvparse0.GstPad:src: caps = "video/mpeg\,\ mpegversion\=\(int\)2\,\ systemstream\=\(boolean\)false\,\ parsed\=\(boolean\)true\,\ width\=\(int\)1920\,\ height\=\(int\)800\,\ framerate\=\(fraction\)25/1\,\ pixel-aspect-ratio\=\(fraction\)221/240\,\ codec_data\=\(buffer\)000001b37803204361a82380000001b5148200010000000001b243726561746564206279204e654d70656732456e632028323031332d31322d30395431302d30362d353329\,\ profile\=\(string\)main\,\ level\=\(string\)main\,\ interlace-mode\=\(string\)mixed" /GstPlayBin:playbin0/GstURIDecodeBin:uridecodebin0/GstDecodeBin:decodebin0/GstMultiQueue:multiqueue0.GstPad:sink_1: caps = audio/x-private1-lpcm /GstPlayBin:playbin0/GstURIDecodeBin:uridecodebin0/GstDecodeBin:decodebin0/GstMultiQueue:multiqueue0.GstPad:sink_1: caps = audio/x-private1-lpcm So parsed is plugged. Maybe I need to recostruct pipeline on another way to do proper testing?
PS. parsed if false above, but before prerolled it switches to parsed true. /GstPlayBin:playbin0/GstPlaySink:playsink/GstBin:vbin/GstPlaySinkVideoConvert:vconv/GstIdentity:identity.GstPad:src: caps = "video/mpeg\,\ mpegversion\=\(int\)2\,\ systemstream\=\(boolean\)false\,\ parsed\=\(boolean\)true\,\ width\=\(int\)1920\,\ height\=\(int\)800\,\ framerate\=\(fraction\)25/1\,\ pixel-aspect-ratio\=\(fraction\)221/240\,\ codec_data\=\(buffer\)000001b37803204361a82380000001b5148200010000000001b243726561746564206279204e654d70656732456e632028323031332d31322d30395431302d30362d353329\,\ profile\=\(string\)main\,\ level\=\(string\)main\,\ interlace-mode\=\(string\)mixed" /GstPlayBin:playbin0/GstPlaySink:playsink/GstBin:vbin/GstPlaySinkVideoConvert:vconv/GstIdentity:identity.GstPad:src: caps = "video/mpeg\,\ mpegversion\=\(int\)2\,\ systemstream\=\(boolean\)false\,\ parsed\=\(boolean\)true\,\ width\=\(int\)1920\,\ height\=\(int\)800\,\ framerate\=\(fraction\)25/1\,\ pixel-aspect-ratio\=\(fraction\)221/240\,\ codec_data\=\(buffer\)000001b37803204361a82380000001b5148200010000000001b243726561746564206279204e654d70656732456e632028323031332d31322d30395431302d30362d353329\,\ profile\=\(string\)main\,\ level\=\(string\)main\,\ interlace-mode\=\(string\)mixed" /GstPlayBin:playbin0/GstInputSelector:inputselector0.GstSelectorPad:sink_0: tags = "taglist\,\ video-codec\=\(string\)\"MPEG-2\\\ Video\"\;" /GstPlayBin:playbin0/GstPlaySink:playsink/GstBin:vbin/GstPlaySinkVideoConvert:vconv/GstIdentity:identity.GstPad:src: caps = "video/mpeg\,\ mpegversion\=\(int\)2\,\ systemstream\=\(boolean\)false\,\ parsed\=\(boolean\)true\,\ width\=\(int\)1920\,\ height\=\(int\)800\,\ framerate\=\(fraction\)25/1\,\ pixel-aspect-ratio\=\(fraction\)221/240\,\ codec_data\=\(buffer\)000001b37803204361a82380000001b5148200010000000001b243726561746564206279204e654d70656732456e632028323031332d31322d30395431302d30362d353329\,\ profile\=\(string\)main\,\ level\=\(string\)main\,\ interlace-mode\=\(string\)mixed" /GstPlayBin:playbin0/GstPlaySink:playsink/GstBin:vbin/GstPlaySinkVideoConvert:vconv/GstIdentity:identity.GstPad:src: caps = "video/mpeg\,\ mpegversion\=\(int\)2\,\ systemstream\=\(boolean\)false\,\ parsed\=\(boolean\)true\,\ width\=\(int\)1920\,\ height\=\(int\)800\,\ framerate\=\(fraction\)25/1\,\ pixel-aspect-ratio\=\(fraction\)221/240\,\ codec_data\=\(buffer\)000001b37803204361a82380000001b5148200010000000001b243726561746564206279204e654d70656732456e632028323031332d31322d30395431302d30362d353329\,\ profile\=\(string\)main\,\ level\=\(string\)main\,\ interlace-mode\=\(string\)mixed" /GstPlayBin:playbin0/GstPlaySink:playsink/GstBin:vbin/GstPlaySinkVideoConvert:vconv/GstIdentity:identity.GstPad:src: caps = "video/mpeg\,\ mpegversion\=\(int\)2\,\ systemstream\=\(boolean\)false\,\ parsed\=\(boolean\)true\,\ width\=\(int\)1920\,\ height\=\(int\)800\,\ framerate\=\(fraction\)25/1\,\ pixel-aspect-ratio\=\(fraction\)221/240\,\ codec_data\=\(buffer\)000001b37803204361a82380000001b5148200010000000001b243726561746564206279204e654d70656732456e632028323031332d31322d30395431302d30362d353329\,\ profile\=\(string\)main\,\ level\=\(string\)main\,\ interlace-mode\=\(string\)mixed" /GstPlayBin:playbin0/GstPlaySink:playsink/GstBin:vbin/GstPlaySinkVideoConvert:vconv/GstIdentity:identity.GstPad:src: caps = "video/mpeg\,\ mpegversion\=\(int\)2\,\ systemstream\=\(boolean\)false\,\ parsed\=\(boolean\)true\,\ width\=\(int\)1920\,\ height\=\(int\)800\,\ framerate\=\(fraction\)25/1\,\ pixel-aspect-ratio\=\(fraction\)221/240\,\ codec_data\=\(buffer\)000001b37803204361a82380000001b5148200010000000001b243726561746564206279204e654d70656732456e632028323031332d31322d30395431302d30362d353329\,\ profile\=\(string\)main\,\ level\=\(string\)main\,\ interlace-mode\=\(string\)mixed" /GstPlayBin:playbin0/GstPlaySink:playsink/GstBin:vbin/GstPlaySinkVideoConvert:vconv.GstGhostPad:src: caps = "video/mpeg\,\ mpegversion\=\(int\)2\,\ systemstream\=\(boolean\)false\,\ parsed\=\(boolean\)true\,\ width\=\(int\)1920\,\ height\=\(int\)800\,\ framerate\=\(fraction\)25/1\,\ pixel-aspect-ratio\=\(fraction\)221/240\,\ codec_data\=\(buffer\)000001b37803204361a82380000001b5148200010000000001b243726561746564206279204e654d70656732456e632028323031332d31322d30395431302d30362d353329\,\ profile\=\(string\)main\,\ level\=\(string\)main\,\ interlace-mode\=\(string\)mixed" /GstPlayBin:playbin0/GstInputSelector:inputselector1.GstSelectorPad:sink_0: tags = "taglist\,\ audio-codec\=\(string\)\"DVD\\\ LPCM\"\;" /GstPlayBin:playbin0/GstPlaySink:playsink/GstBin:abin/GstDVBAudioSink:dvbaudiosink0.GstPad:sink: caps = audio/x-private1-lpcm /GstPlayBin:playbin0/GstPlaySink:playsink/GstBin:abin/GstPlaySinkAudioConvert:aconv.GstGhostPad:src.GstProxyPad:proxypad12: caps = audio/x-private1-lpcm /GstPlayBin:playbin0/GstPlaySink:playsink/GstBin:abin/GstPlaySinkAudioConvert:aconv/GstIdentity:identity.GstPad:sink: caps = audio/x-private1-lpcm /GstPlayBin:playbin0/GstPlaySink:playsink/GstBin:abin/GstPlaySinkAudioConvert:aconv.GstGhostPad:sink: caps = audio/x-private1-lpcm /GstPlayBin:playbin0/GstPlaySink:playsink/GstBin:abin/GstPlaySinkAudioConvert:aconv.GstGhostPad:sink: caps = audio/x-private1-lpcm Pipeline is PREROLLED ... Setting pipeline to PLAYING ... New clock: GstSystemClock
It looks like that this commit is causing much higher CPU load Tested on vusolose - mipsel BCM 7429, dual core 1.3Ghz: With commit c3bcbadd5452d5b3450f70e49dad3e64f14de00a: PID PPID USER STAT VSZ %VSZ %CPU COMMAND 24272 23487 root S 76244 13% 72% gst-launch-1.0 playbin uri=file:///media/net/DOMA/Test/Test.mpg Without commit c3bcbadd5452d5b3450f70e49dad3e64f14de00a: PID PPID USER STAT VSZ %VSZ %CPU COMMAND 24434 23487 root S 78096 14% 38% gst-launch-1.0 playbin uri=file:///media/net/DOMA/Test/Test.mpg
Note as test I just recompiled the gst-1.6.1 tagged. And revert the commit then all runs fine.
Created attachment 315996 [details] [review] baseparse: post tag list when avg bitrate changes at least 2% Without the above patch the sample (test.mpg) will post 91 tag list updates for bitrate. With the above patch the sample (test.mpg) will post only 6 tag list updates for bitrate.
Using latest HEAD we still need to revert http://cgit.freedesktop.org/gstreamer/gstreamer/commit/?id=c3bcbadd5452d5b3450f70e49dad3e64f14de00a in order sample to work. Also is it possible somebody to review the patch that sends post tag list when avg bitrate changes at least 2%? Or I should create separate bug to for that?
Is that patch fixing your problem or is there more to it?
A new bug for the patch would be good if it's independent of this problem here.
Review of attachment 315996 [details] [review]: I general makes sense IMHO. ::: libs/gst/base/gstbaseparse.c @@ +1695,3 @@ { + /* Only update the tag on a 2% change */ + static const gfloat update_threshold = 2.0; We usually use #defines for this kind of stuff @@ +1760,3 @@ + if (parse->priv->post_avg_bitrate && parse->priv->avg_bitrate) { + gfloat diffprev = (float) 100.0 * (ABSDIFF (parse->priv->avg_bitrate, + parse->priv->posted_avg_bitrate)) / (float) parse->priv->avg_bitrate; Would be nicer to do this without floating point operations, which is easily possible here.
> A new bug for the patch would be good if it's independent of this problem here. Yes, you are right. I created a new bug for tag list updates, https://bugzilla.gnome.org/show_bug.cgi?id=759055
Review of attachment 315996 [details] [review]: A newer version of the patch was created here: https://bugzilla.gnome.org/show_bug.cgi?id=759055
I think someone has to debug on the target device why http://cgit.freedesktop.org/gstreamer/gstreamer/commit/?id=c3bcbadd5452d5b3450f70e49dad3e64f14de00a causes such a performance problem. Perhaps try and find the smallest pipeline that demonstrates this, and then run perf on that?
The only difference this can really make is that the buffer returned by the adapter now can be multiple memories, has the flags/timestamp/etc from the input and also the GstMetas from the input.
No reply in 3 years. Closing. Please re-open if you can reproduce the issue with current stable GStreamer.