GNOME Bugzilla – Bug 786561
baseparse: excessive tag updates - totem uses about a quarter more CPU than "gst-play-1.0 --videosink=clutterautovideosink"
Last modified: 2017-10-25 11:57:03 UTC
totem uses about a quarter more CPU than "gst-play-1.0 --videosink=clutterautovideosink" This bug might sounds similar to other totem bugs but I'm logging this because I have a fix already for this one, and it doesn't perfectly fit any of the existing bug reports.
Created attachment 358055 [details] [review] fix-stutter-and-high-cpu.patch
Comment on attachment 358055 [details] [review] fix-stutter-and-high-cpu.patch Please provide a git-formatted patch for this.
Created attachment 358105 [details] [review] 0001-Avoid-pointless-clutter-scene-graph-updates.patch The same patch again, but with git formatting. I didn't provide this one before because I wasn't happy with my git commit comment. But realistically it doesn't matter.
Sorry, it looks like another minor fix is required...
Created attachment 358109 [details] [review] 0001-Reduce-CPU-usage-and-stuttery-playback.patch Same fix, now with bonus silencing of harmless assertions about null pointers.
The problem is that when we get to this point, the tags have already had to be put inside a data structure, and marshalled back to the main thread. The real question is why are "video-tags-changed", "audio-tags-changed" or "text-tags-changed" emitted when there's no tags changes? Do you have an easy way to trigger this bug? With which type of media? If grep GStreamer's debug output, will we see tons of "Tags: ..." lines?
Yeah that's the root cause, but I think it would be a bad idea to not make bvw_update_tags resilient to the problem still. Here's a simple test case: $ env GST_DEBUG=5 totem ~/Videos/bbb_sunflower_1080p_60fps_normal.mp4 |& grep Tags: using the video from: http://bbb3d.renderfarming.net/download.html And the problem persisted regardless of whether I was using the vaapi plugin or software decoding.
(In reply to Daniel van Vugt from comment #7) > Yeah that's the root cause, but I think it would be a bad idea to not make > bvw_update_tags resilient to the problem still. I'd really like to see whether there are legitimate cases when the above signals are emitted this aggressively before papering over this problem. > Here's a simple test case: > > $ env GST_DEBUG=5 totem ~/Videos/bbb_sunflower_1080p_60fps_normal.mp4 |& > grep Tags: > > using the video from: http://bbb3d.renderfarming.net/download.html > > And the problem persisted regardless of whether I was using the vaapi plugin > or software decoding. It's likely a problem in the demuxer (if it is a problem). What's the output of: gst-inspect-1.0 qtdemux | grep Version on the system where you reproduce this?
$ gst-inspect-1.0 qtdemux | grep Version Version 1.12.2
I think it might be worth checking whether in qtdemux those are generated. Breaking on bvw_update_tags_delayed and getting a backtrace should be alright. Something like this in gdb should do: set breakpoint pending on break bvw_update_tags_delayed commands bt continue end
Ignoring the first instance, the recurring calls are all coming from audio_tags_changed_cb via libgstaudio-1.0.so.0 and libgstlibav.so (because it's using the a52 audio stream?).
Thread 16 "multiqueue0:src" hit Breakpoint 1, bvw_update_tags_delayed ( bvw=0x1007c6540, tags=0x7f9774000f70, type=0x7f97a5bf02ee "audio") at ../src/backend/bacon-video-widget.c:2135 2135 bvw_update_tags_delayed (BaconVideoWidget *bvw, GstTagList *tags, const gchar *type) {
+ Trace 237816
(In reply to Daniel van Vugt from comment #11) > Ignoring the first instance, the recurring calls are all coming from > audio_tags_changed_cb via libgstaudio-1.0.so.0 and libgstlibav.so (because > it's using the a52 audio stream?). Can you reproduce the constant "*-tags-changed" emission with any other types of file then? grepping as above would be the easiest way to find if something was triggering the same problem. If you can't reproduce the problem, then we'll probably chalk this as a bug in the decoder. We can then push a version of your patch that would complain a bit louder when the decoder constantly sends signals without actual changes.
It appears the problem is localized to MP3 audio only... 0:00:03.062754928 30351 0x7f33000032a0 DEBUG totem bacon-video-widget.c:2066:bvw_update_tags: Tags: taglist, audio-codec=(string)"MPEG-1\ Layer\ 3\ \(MP3\)", maximum-bitrate=(uint)165120, bitrate=(uint)160000, datetime=(datetime)2013-12-16T17:59:32Z, title=(string)"Big\ Buck\ Bunny\,\ Sunflower\ version", composer=(string)"Sacha\ Goedegebure", artist=(string)"Blender\ Foundation\ 2008\,\ Janus\ Bager\ Kristensen\ 2013", comment=(string)"Creative\ Commons\ Attribution\ 3.0\ -\ http://bbb3d.renderfarming.net", genre=(string)Animation, private-qt-tag=(sample)00000027a9636f6d0000001f6461746100000001000000004a616e204d6f7267656e737465726e:None:R3N0U2VnbWVudCwgZmxhZ3M9KEdzdFNlZ21lbnRGbGFncylHU1RfU0VHTUVOVF9GTEFHX05PTkUsIHJhdGU9KGRvdWJsZSkxLCBhcHBsaWVkLXJhdGU9KGRvdWJsZSkxLCBmb3JtYXQ9KEdzdEZvcm1hdClHU1RfRk9STUFUX1RJTUUsIGJhc2U9KGd1aW50NjQpMCwgb2Zmc2V0PShndWludDY0KTAsIHN0YXJ0PShndWludDY0KTAsIHN0b3A9KGd1aW50NjQpMTg0NDY3NDQwNzM3MDk1NTE2MTUsIHRpbWU9KGd1aW50NjQpMCwgcG9zaXRpb249KGd1aW50NjQpMCwgZHVyYXRpb249KGd1aW50NjQpMTg0NDY3NDQwNzM3MDk1NTE2MTU7AA__:YXBwbGljYXRpb24veC1nc3QtcXQtX2NvbS10YWcsIHN0eWxlPShzdHJpbmcpaXR1bmVzOwA_, container-format=(string)"ISO\ MP4/M4A", has-crc=(boolean)false, channel-mode=(string)joint-stereo, minimum-bitrate=(uint)160000; Just about any other common MP4 file using AAC doesn't log the problem. That said, I never expected I had fixed a significant portion of the performance issues. Now investigating clutter/cogl/cairo and friends...
Although that assessment might be wrong. The affected file also has a bunch of text tags that most other videos don't... title=(string)"Big\ Buck\ Bunny\,\ Sunflower\ version", composer=(string)"Sacha\ Goedegebure", artist=(string)"Blender\ Foundation\ 2008\,\ Janus\ Bager\ Kristensen\ 2013", comment=(string)"Creative\ Commons\ Attribution\ 3.0\ -\ http://bbb3d.renderfarming.net", genre=(string)Animation, So maybe that's the issue.
Tim mentioned on IRC that the issue with the AC3 stream (and maybe also with MP3) that the tags are constantly updated to send new bitrates. Is this something you can reproduce?
Nope. Every debug message mentioning bitrate, including the Tags list, remains unchanged. Same bitrate every time.
Could you make a GST_DEBUG=*:6 log please? $ GST_DEBUG=*:6 totem 2>/tmp/dbg.log; xz -9 /tmp/dbg.log First 10-20 seconds should be enough.
Sorry, that's not feasible. Bugzilla has a file size limit of 3.6MB yet that log is 330MB, or 17MB with maximum compression. But you should be able to reproduce the problem locally per comment #7.
(In reply to Daniel van Vugt from comment #19) > Sorry, that's not feasible. Bugzilla has a file size limit of 3.6MB yet that > log is 330MB, or 17MB with maximum compression. Can you upload the compressed version to an external site and post the link here? > But you should be able to reproduce the problem locally per comment #7. I couldn't because of combined bugs in gtk+ and gnome-shell, and the lack of time to apply all the fixes. We're also right at the start of GNOME's freeze so we're focusing on crashers all across the board, performance problems that seem limited to specific files won't be the priority, especially when the problems already exist in older released versions.
OK here's a fresh log: https://bugs.launchpad.net/bugs/1698282/+attachment/4937819/+files/totemdebug.log.xz
Looks like an issue with baseparse at first glance. Can also be reproduced with: $ wget http://distribution.bbb3d.renderfarming.net/video/mp4/bbb_sunflower_1080p_60fps_normal.mp4 $ gst-play-1.0 -v bbb_sunflower_1080p_60fps_normal.mp4
Created attachment 358354 [details] [review] baseparse: fix taglist update spam Does this helps?
commit 39e21bb6dd79e467ff747ab93b19078f03d03646 Author: Tim-Philipp Müller <tim@centricular.com> Date: Thu Aug 24 16:00:42 2017 +0100 baseparse: fix taglist update spam We would constantly re-post the taglist because posted_avg_rate only gets set to avg_bitrate if parse->priv->post_avg_bitrate is true, so if it's false the posted rate will always differ from the current average rate and we'd queue an update, which leads to us spamming downstream and the application with taglist updates. Fix this by only queuing an update if the average rate will actually be posted. These taglists updates could cause expensive operations on the application side, e.g. in Totem. https://bugzilla.gnome.org/show_bug.cgi?id=786561 Should be okay to also pick into 1.12 branch, but let's give it some timer in master first.
Thanks. I will refresh Ubuntu 17.10 with the totem fix/workaround from comment #5 too. It might be nice to upstream that one too.
(In reply to Daniel van Vugt from comment #25) > Thanks. I will refresh Ubuntu 17.10 with the totem fix/workaround from > comment #5 too. It might be nice to upstream that one too. It's not needed and would just hide (somewhat( some more of the excessive resource utilisation. No, that's not the way we do things.
Comment on attachment 358109 [details] [review] 0001-Reduce-CPU-usage-and-stuttery-playback.patch Marking as rejected as the problem has been root-caused.
In that case, your idea from comment #13 should probably be implemented in totem: "complain a bit louder when the decoder constantly sends signals without actual changes." I understand you want to expose mistakes in other components, but leaving totem fragile and vulnerable to them isn't ideal. If the bug were to happen again there is no guarantee another person would come along and diagnose it again any time soon. Such a regression could linger indefinitely (again).
(In reply to Daniel van Vugt from comment #28) > In that case, your idea from comment #13 should probably be implemented in > totem: > > "complain a bit louder when the decoder constantly sends signals without > actual changes." > > I understand you want to expose mistakes in other components, but leaving > totem fragile and vulnerable to them isn't ideal. If the bug were to happen > again there is no guarantee another person would come along and diagnose it > again any time soon. Such a regression could linger indefinitely (again). Writing a regression test case for GStreamer would be a good way to avoid this problem appearing again. This code now throws a GStreamer warning when the problem happens, which should make it a bit more visible: commit 2f2230b6da805b7aa31794c6b49929369865176a Author: Bastien Nocera <hadess@hadess.net> Date: Mon Aug 28 13:01:46 2017 +0200 backend: Warn when tag updates are sent with no changes When tag updates are sent but no tags changed, we end up constantly changing bits of UI, and eating CPU for no actual change. Warn loudly when this happens so that culprits can be fixed. See https://bugzilla.gnome.org/show_bug.cgi?id=786561