After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 728716 - Videos plays a video very slowly, while gst-launch plays it properly
Videos plays a video very slowly, while gst-launch plays it properly
Status: RESOLVED FIXED
Product: totem
Classification: Core
Component: general
3.12.x
Other Linux
: Normal normal
: ---
Assigned To: General Totem maintainer(s)
General Totem maintainer(s)
: 733182 (view as bug list)
Depends on:
Blocks: 784056
 
 
Reported: 2014-04-22 10:45 UTC by Elad Alfassa
Modified: 2017-06-21 17:48 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
main: Postpone loading library after playback (3.46 KB, patch)
2014-08-17 17:47 UTC, Bastien Nocera
committed Details | Review

Description Elad Alfassa 2014-04-22 10:45:22 UTC
When I try to play any video in totem (even non HD videos), the framerate is really low which means it's pretty much unwatchable.

I ran

gst-launch playbin uri=file:///path/to/video video-sink=ximagesink

And it played the video perfectly (I used video-sink=ximagesink because xvimagesink results in artifacts in the video display).

Then I opened it in Videos, and it played it very, very slowly.

So, is it a Videos bug? Or a bug in gstreamer?
fwiw when playing the same video with gst-launch, the cpu usage of it was 5%, when playing it with Videos, the cpu usage of Videos was 15%.
Comment 1 Bastien Nocera 2014-04-22 15:42:38 UTC
Totem doesn't use ximagesink, it uses cluttersink. Which graphics driver are you using, and does it support OpenGL?
Comment 2 Elad Alfassa 2014-04-22 16:06:54 UTC
I use the radeonsi mesa driver. It supports OpenGL and I can run the shell and various videogames with high framerates. 

I tried running

gst-launch-1.0 playbin uri=file:///path/to/video video-sink=cluttersink

It worked too, in reasonable framerate.
Comment 3 Elad Alfassa 2014-04-23 08:08:28 UTC
Trying to debug this I noticed that after ~20 seconds of watching the video playing in low framerate (sometimes less) it will suddenly "catch up" and become watchable.

If after that I switch to another video (without closing the app), the other video will play fine from the beginning.
Comment 4 Bastien Nocera 2014-04-23 16:00:21 UTC
Can you reproduce the problem with the bvw-test binary in the totem sources?
Comment 5 Elad Alfassa 2014-04-23 16:22:34 UTC
With a freshly built git master, I get this

[elad@weatherwax backend]$ ./bvw-test
**
ERROR:bacon-video-controls-actor.c:102:bacon_video_controls_actor_init: code should not be reached
Aborted (core dumped)
Comment 6 Bastien Nocera 2014-04-23 16:25:42 UTC
(In reply to comment #5)
> With a freshly built git master, I get this
> 
> [elad@weatherwax backend]$ ./bvw-test
> **
> ERROR:bacon-video-controls-actor.c:102:bacon_video_controls_actor_init: code
> should not be reached
> Aborted (core dumped)

It expects the controls.ui to be installed.
Comment 7 Elad Alfassa 2014-04-23 16:31:53 UTC
I get this output, the window appears, video doesn't play

[elad@weatherwax backend]$ ./bvw-test /path/to/video 

(bvw-test:10627): Gtk-WARNING **: Toplevel size doesn't seem to directly depend on the size of the geometry widget from gtk_window_set_geometry_hints(). The geometry widget might not be in the window, or it might not be packed into the window appropriately

(bvw-test:10627): Gtk-WARNING **: Toplevel size doesn't seem to directly depend on the size of the geometry widget from gtk_window_set_geometry_hints(). The geometry widget might not be in the window, or it might not be packed into the window appropriately

(bvw-test:10627): Clutter-WARNING **: ./clutter-actor.c:9834: Actor 'controls' tried to allocate a size of -63.00 x -31.00
bvw-test-Message: Error: The specified movie could not be found., playback stopped: 1, fatal: 0

(bvw-test:10627): Clutter-WARNING **: ./clutter-actor.c:9834: Actor 'controls' tried to allocate a size of -63.00 x -31.00
Comment 8 Bastien Nocera 2014-04-23 17:11:51 UTC
Needs a full URI.
Comment 9 Elad Alfassa 2014-04-23 17:14:34 UTC
Ah, I should have guessed. Thanks.

So, with this thing the video works as expected from the beginning, and the window responds to size changes faster and more responsively than the app itself.
Comment 10 Jean-François Fortin Tam 2014-05-04 18:13:20 UTC
Hi Bastien, 
Gave 3.12 a spin today on my laptop and Totem 3.12 is much slower than 3.10 (and older cluttersink-based 3.x releases, IIRC). mplayer and VLC play the same file fine, while Totem 3.12 drops a huge amount of frames and its UI (overlay controls etc.) lags.

My sample file is
http://jeff.ecchi.ca/public/sample-pitivi-projects/m%c3%a9tro%201.MOV

The CPU is an Intel U4100 @ 1.30GHz × 2, with the GM45 Express Chipset for graphics.

Do we consider this the same issue, or should I file a separate bug?
Comment 11 Jean-François Fortin Tam 2014-07-07 20:58:34 UTC
AFAICT comment #9 answered the NEEDINFO, so resetting to UNCONFIRMED.

Also, FWIW, Sushi (aka "press spacebar in Nautilus") plays the thing fine, and it seems like it uses the same sort of playback widgets (in a clutter interface?) than Totem.
Comment 12 Elad Alfassa 2014-07-07 21:16:53 UTC
Is it possible that this bug is actually the same issue I'm seeing in bug #725063?
Comment 13 kapouer 2014-07-22 23:58:49 UTC
Same problem on debian/sid with any avi file.
Comment 14 Jean-François Fortin Tam 2014-08-14 20:54:55 UTC
So, after discussing with Bastien at GUADEC, and testing a little bit for myself, this is caused by Totem's use of Tracker - it tries to index/query some stuff in the background even if you're not in the "browse" mode, which is not a good idea.
Comment 15 Elad Alfassa 2014-08-14 22:05:04 UTC
(In reply to comment #14)
> So, after discussing with Bastien at GUADEC, and testing a little bit for
> myself, this is caused by Totem's use of Tracker - it tries to index/query some
> stuff in the background even if you're not in the "browse" mode, which is not a
> good idea.

Seems weird to me that using tracker would make everything THAT slow. The window is slow to re-size, the menu is slow to draw and the video playback is extremely choppy. This also doesn't explain why sometimes it's suddenly fast after few seconds of video, and sometimes it isn't.

Also, using perf top, the topmost functions when everything is slow are:
  13.40%  libgdk-3.so.0.1306.0           [.] gdk_cairo_surface_paint_pixbuf
   5.81%  libgtk-3.so.0.1306.0           [.] blur_xspan

Which are not related to tracker.
Comment 16 Bastien Nocera 2014-08-15 13:56:17 UTC
(In reply to comment #15)
> (In reply to comment #14)
> > So, after discussing with Bastien at GUADEC, and testing a little bit for
> > myself, this is caused by Totem's use of Tracker - it tries to index/query some
> > stuff in the background even if you're not in the "browse" mode, which is not a
> > good idea.
> 
> Seems weird to me that using tracker would make everything THAT slow. The
> window is slow to re-size, the menu is slow to draw and the video playback is
> extremely choppy. This also doesn't explain why sometimes it's suddenly fast
> after few seconds of video, and sometimes it isn't.
> 
> Also, using perf top, the topmost functions when everything is slow are:
>   13.40%  libgdk-3.so.0.1306.0           [.] gdk_cairo_surface_paint_pixbuf
>    5.81%  libgtk-3.so.0.1306.0           [.] blur_xspan
> 
> Which are not related to tracker.

It's related to us filling in the recent view synchronously from tracker. If you wait long enough, does the video actually play back OK? If not, then the problem is something else...
Comment 17 Elad Alfassa 2014-08-15 14:00:15 UTC
Oh! yes, that's it! if I open the main view (as opposed to just opening what I want to watch from Files) and wait for everything to get rendered and THEN open a video, it plays back fine!
Comment 18 Bastien Nocera 2014-08-17 17:47:07 UTC
Created attachment 283666 [details] [review]
main: Postpone loading library after playback
Comment 19 Elad Alfassa 2014-08-17 17:50:28 UTC
I can confirm this patch fixes the issue for me.
Comment 20 Elad Alfassa 2014-08-17 18:45:50 UTC
Now in further testing I see that for some specific video files the window doesn't show at all. 

I attached gdb to the process when it's running and the window is invisible (and, judging by the lack of audio, it's not playing) and got this backtrace:

  • #0 syscall
    at ../sysdeps/unix/sysv/linux/x86_64/syscall.S line 38
  • #1 g_cond_wait
    at gthread-posix.c line 1390
  • #2 gst_element_get_state_func
    at gstelement.c line 2054
  • #3 bacon_video_widget_set_text_subtitle
    at bacon-video-widget.c line 4310
  • #4 totem_object_set_mrl
    at totem-object.c line 1811
  • #5 playlist_changed_cb
    at totem-object.c line 1437
  • #6 playlist_changed_cb
    at totem-object.c line 2873
  • #7 _g_closure_invoke_va
    at gclosure.c line 831
  • #8 g_signal_emit_valist
    at gsignal.c line 3218
  • #9 g_signal_emit
    at gsignal.c line 3365
  • #10 totem_playlist_add_one_mrl
    at totem-playlist.c line 969
  • #11 add_mrls_cb
    at totem-playlist.c line 1255
  • #12 g_simple_async_result_complete
    at gsimpleasyncresult.c line 763
  • #13 complete_in_idle_cb_for_thread
    at gsimpleasyncresult.c line 832
  • #14 g_main_context_dispatch
    at gmain.c line 3064
  • #15 g_main_context_dispatch
    at gmain.c line 3663
  • #16 g_main_context_iterate
    at gmain.c line 3734
  • #17 g_main_context_iteration
    at gmain.c line 3795
  • #18 g_application_run
    at gapplication.c line 2219
  • #19 main
    at totem.c line 266


From this backtrace I assumed the issue is subtitles, so I deleted the .srt file that video had, and opened it again. This caused the window to show, but the video is still not playing.

I attached strace to the process and got a lot of these

recvmsg(9, 0x7fff2f643570, 0)           = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=3, events=POLLIN}, {fd=9, events=POLLIN}, {fd=7, events=POLLIN}, {fd=13, events=POLLIN}], 4, 0) = 0 (Timeout)
recvmsg(9, 0x7fff2f643570, 0)           = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=3, events=POLLIN}, {fd=9, events=POLLIN}, {fd=7, events=POLLIN}, {fd=13, events=POLLIN}], 4, 9991) = 0 (Timeout)
open("/home/elad/.config/totem/session_state.xspf", O_WRONLY|O_CREAT|O_EXCL, 0666) = -1 EEXIST (File exists)
open("/home/elad/.config/totem/session_state.xspf", O_WRONLY|O_CREAT|O_NOFOLLOW, 0666) = 20
fstat(20, {st_mode=S_IFREG|0664, st_size=334, ...}) = 0
open("/home/elad/.config/totem/.goutputstream-214XKX", O_WRONLY|O_CREAT|O_EXCL, 0666) = 21
fchown(21, 1000, 1000)                  = 0
fchmod(21, 0100664)                     = 0
close(20)                               = 0
write(21, "<?xml version=\"1.0\" encoding=\"UT"..., 105) = 105
write(21, "  <track>\n   <location>file:///h"..., 98) = 98
write(21, "   <extension application=\"http:"..., 79) = 79
write(21, "   </extension>\n", 16)      = 16
write(21, "  </track>\n", 11)           = 11
write(21, " </trackList>\n</playlist>", 25) = 25
fsync(21)                               = 0
rename("/home/elad/.config/totem/.goutputstream-214XKX", "/home/elad/.config/totem/session_state.xspf") = 0
fstat(21, {st_mode=S_IFREG|0664, st_size=334, ...}) = 0
close(21)                               = 0
recvmsg(9, 0x7fff2f643570, 0)           = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=3, events=POLLIN}, {fd=9, events=POLLIN}, {fd=7, events=POLLIN}, {fd=13, events=POLLIN}], 4, 9967) = 0 (Timeout)
open("/home/elad/.config/totem/session_state.xspf", O_WRONLY|O_CREAT|O_EXCL, 0666) = -1 EEXIST (File exists)
open("/home/elad/.config/totem/session_state.xspf", O_WRONLY|O_CREAT|O_NOFOLLOW, 0666) = 20
fstat(20, {st_mode=S_IFREG|0664, st_size=334, ...}) = 0
open("/home/elad/.config/totem/.goutputstream-SYBYKX", O_WRONLY|O_CREAT|O_EXCL, 0666) = 21
fchown(21, 1000, 1000)                  = 0
fchmod(21, 0100664)                     = 0
close(20)                               = 0
write(21, "<?xml version=\"1.0\" encoding=\"UT"..., 105) = 105
write(21, "  <track>\n   <location>file:///h"..., 98) = 98
write(21, "   <extension application=\"http:"..., 79) = 79
write(21, "   </extension>\n", 16)      = 16
write(21, "  </track>\n", 11)           = 11
write(21, " </trackList>\n</playlist>", 25) = 25
fsync(21)                               = 0
rename("/home/elad/.config/totem/.goutputstream-SYBYKX", "/home/elad/.config/totem/session_state.xspf") = 0
fstat(21, {st_mode=S_IFREG|0664, st_size=334, ...}) = 0
close(21)                               = 0
recvmsg(9, 0x7fff2f643570, 0)           = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=3, events=POLLIN}, {fd=9, events=POLLIN}, {fd=7, events=POLLIN}, {fd=13, events=POLLIN}], 4, 0) = 0 (Timeout)
recvmsg(9, 0x7fff2f643570, 0)           = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=3, events=POLLIN}, {fd=9, events=POLLIN}, {fd=7, events=POLLIN}, {fd=13, events=POLLIN}], 4, 9979



but I have no idea why it would affect some video files and not others.
Comment 21 Elad Alfassa 2014-08-17 18:49:08 UTC
Ah, scratch that comment. It's not relevant to this patch, it happens with totem from git master regardless if the patch is applied. I'll open a separate bug, sorry for the spam :(
Comment 22 Bastien Nocera 2014-08-17 19:14:49 UTC
(In reply to comment #21)
> Ah, scratch that comment. It's not relevant to this patch, it happens with
> totem from git master regardless if the patch is applied. I'll open a separate
> bug, sorry for the spam :(

Maybe bug 733780 ?
Comment 23 Bastien Nocera 2014-08-17 19:20:48 UTC
Fixed in master and gnome-3-12

Attachment 283666 [details] pushed as 11af158 - main: Postpone loading library after playback
Comment 24 Bastien Nocera 2014-08-17 22:29:15 UTC
*** Bug 733182 has been marked as a duplicate of this bug. ***