GNOME Bugzilla – Bug 704442
avdec_h264: enormous CPU load on decoding on OSX
Last modified: 2013-07-19 12:04:02 UTC
It's strange, but avdec_h264 gives enormous CPU load (more, than 100% on multicore systems) when decoding H.264 video with CABAC setting on. Here's a test pipeline: gst-launch-1.0 filesrc location=~/sandwaves-1080.mp4 ! qtdemux ! avdec_h264 ! fakesink sync=true --gst-debug=2 Video sample is taken from here: http://www.mothernaturevideos.com/2012/09/06/sand-waves/ Same circumstances on Linux and Windows give no more, than 40-50% CPU in peak.
Did you build gst-libav yourself for OSX? What was the complete configure output, maybe assembly optimizations were disabled for some reason.
No, I use binary distribution from here: http://gstreamer.freedesktop.org/data/pkg/osx/1.0.7/ Is it possible to print configure command used out of the plugin?
Ok, so I should check my own build logs :) Will try to get to this later
Thanks, Sebastian.
By "Same circumstances on Linux and Windows give no more, than 40-50% CPU in peak." I assume it's also with gst-libav and also with similar processors, right ?
Yes, that's right. I just checked it again to get the exact values, so I have to a little bit correct myself: Ubuntu 13.04, x86_64: ~65%-80% Windows 7 x86_64: ~15%-20% All the systems installed on the same machine and same processor (Mac Mini, Intel(R) Core(TM) i5-2520M CPU @ 2.50GHz).
How do you get the CPU usage though? My guess is that this is a quadcore CPU, so Windows and Ubuntu numbers are basically the same. In theory the OSX numbers should be about the same as the Ubuntu ones from my understanding.
It might also be interesting to compare throughput, that is how long does it take on each OS to decode the video from start to end? If the decoder uses a slower path on some OS for some reason, that should show up there. And these numbers might be easier to compare than cpu usage stats.
(In reply to comment #7) > How do you get the CPU usage though? My guess is that this is a quadcore CPU, > so Windows and Ubuntu numbers are basically the same. > > In theory the OSX numbers should be about the same as the Ubuntu ones from my > understanding. I thought so, too, but it seems to have only 2 cores, I just learnt it: http://ark.intel.com/ru/products/52229/ I use Task Manager on Windows, htop on Ubuntu and Monitor on OS X.
(In reply to comment #8) > It might also be interesting to compare throughput, that is how long does it > take on each OS to decode the video from start to end? If the decoder uses a > slower path on some OS for some reason, that should show up there. And these > numbers might be easier to compare than cpu usage stats. Yes, I'll estimate it now and post the results here.
You don't need to estimate, gst-launch will print something like 'EOS after N seconds' :)
Oh, yes, forgot about that :) I started each version 3-6 times to get some stable results, end wrote down 'Execution ended after' values in ns and then got average value of them. So, here's the results: Ubuntu 13.04: 45773009663 ns ~ 45,77 s Windows 7: 46902343103 ns ~ 46,90 s Mac OS X: 99100055833 ns ~ 99,10 s So, yes, it's now obvious, that Mac version is about twice as slower.
Perhaps also check with GST_DEBUG=*:4 to see what gst_ffmpeg_auto_max_threads() determines to be the number of cores/threads to use.
Is it printed somewhere? Can't find it in the log. Here it is for Linux, maybe, you can: GST_DEBUG=*:4 gst-launch-1.0 filesrc location=~/emergency.mp4 ! qtdemux ! avdec_h264 ! fakesink 0:00:00.000251577 3962 0x105a800 INFO GST_INIT gst.c:568:init_pre: Initializing GStreamer Core Library version 1.0.6 0:00:00.000447127 3962 0x105a800 INFO GST_INIT gst.c:569:init_pre: Using library installed in /usr/lib/x86_64-linux-gnu 0:00:00.000501447 3962 0x105a800 INFO GST_INIT gst.c:579:init_pre: Linux user-Macmini 3.8.0-26-generic #38-Ubuntu SMP Mon Jun 17 21:43:33 UTC 2013 x86_64 0:00:00.002393157 3962 0x105a800 INFO GST_INIT gstmessage.c:121:_priv_gst_message_initialize: init messages 0:00:00.003514649 3962 0x105a800 INFO GST_PLUGIN_LOADING gstplugin.c:317:_priv_gst_plugin_initialize: registering 0 static plugins 0:00:00.003636210 3962 0x105a800 INFO GST_PLUGIN_LOADING gstplugin.c:225:gst_plugin_register_static: registered static plugin "staticelements" 0:00:00.003654008 3962 0x105a800 INFO GST_PLUGIN_LOADING gstplugin.c:227:gst_plugin_register_static: added static plugin "staticelements", result: 1 0:00:00.003676099 3962 0x105a800 INFO GST_REGISTRY gstregistry.c:1680:ensure_current_registry: reading registry cache: /home/alex/.cache/gstreamer-1.0/registry.x86_64.bin 0:00:00.016718640 3962 0x105a800 INFO GST_REGISTRY gstregistrybinary.c:617:priv_gst_registry_binary_read_cache: loaded /home/alex/.cache/gstreamer-1.0/registry.x86_64.bin in 0.013023 seconds 0:00:00.016795269 3962 0x105a800 INFO GST_REGISTRY gstregistry.c:1539:scan_and_update_registry: Validating plugins from registry cache: /home/alex/.cache/gstreamer-1.0/registry.x86_64.bin 0:00:00.017422620 3962 0x105a800 INFO GST_REGISTRY gstregistry.c:1638:scan_and_update_registry: Registry cache has not changed 0:00:00.017440754 3962 0x105a800 INFO GST_REGISTRY gstregistry.c:1715:ensure_current_registry: registry reading and updating done, result = 1 0:00:00.017452835 3962 0x105a800 INFO GST_INIT gst.c:769:init_post: GLib runtime version: 2.36.0 0:00:00.017464355 3962 0x105a800 INFO GST_INIT gst.c:771:init_post: GLib headers version: 2.36.0 0:00:00.017487983 3962 0x105a800 INFO GST_PIPELINE gstparse.c:322:gst_parse_launch_full: parsing pipeline description 'filesrc location=/home/alex/emergency.mp4 ! qtdemux ! avdec_h264 ! fakesink ' 0:00:00.017957005 3962 0x105a800 INFO GST_PLUGIN_LOADING gstplugin.c:830:gst_plugin_load_file: plugin "/usr/lib/x86_64-linux-gnu/gstreamer-1.0/libgstcoreelements.so" loaded 0:00:00.017977162 3962 0x105a800 INFO GST_ELEMENT_FACTORY gstelementfactory.c:365:gst_element_factory_create: creating element "filesrc" 0:00:00.018102863 3962 0x105a800 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstBaseSrc@0x11ce0d0> adding pad 'src' 0:00:00.018140271 3962 0x105a800 INFO filesrc gstfilesrc.c:253:gst_file_src_set_location: filename : /home/alex/emergency.mp4 0:00:00.018151936 3962 0x105a800 INFO filesrc gstfilesrc.c:254:gst_file_src_set_location: uri : file:///home/alex/emergency.mp4 0:00:00.019304138 3962 0x105a800 INFO GST_PLUGIN_LOADING gstplugin.c:830:gst_plugin_load_file: plugin "/usr/lib/x86_64-linux-gnu/gstreamer-1.0/libgstisomp4.so" loaded 0:00:00.019332804 3962 0x105a800 INFO GST_ELEMENT_FACTORY gstelementfactory.c:365:gst_element_factory_create: creating element "qtdemux" 0:00:00.019564885 3962 0x105a800 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstQTDemux@0x11de050> adding pad 'sink' 0:00:00.022894858 3962 0x105a800 INFO GST_TYPEFIND gsttypefind.c:73:gst_type_find_register: registering typefind function for avtype_avs 0:00:00.023029141 3962 0x105a800 INFO GST_TYPEFIND gsttypefind.c:73:gst_type_find_register: registering typefind function for avtype_daud 0:00:00.023072900 3962 0x105a800 INFO GST_TYPEFIND gsttypefind.c:73:gst_type_find_register: registering typefind function for avtype_ea 0:00:00.023107519 3962 0x105a800 INFO GST_TYPEFIND gsttypefind.c:73:gst_type_find_register: registering typefind function for avtype_ffm 0:00:00.023145405 3962 0x105a800 INFO GST_TYPEFIND gsttypefind.c:73:gst_type_find_register: registering typefind function for avtype_4xm 0:00:00.023176998 3962 0x105a800 INFO GST_TYPEFIND gsttypefind.c:73:gst_type_find_register: registering typefind function for avtype_gxf 0:00:00.023207607 3962 0x105a800 INFO GST_TYPEFIND gsttypefind.c:73:gst_type_find_register: registering typefind function for avtype_idcin 0:00:00.023238265 3962 0x105a800 INFO GST_TYPEFIND gsttypefind.c:73:gst_type_find_register: registering typefind function for avtype_ipmovie 0:00:00.023277818 3962 0x105a800 INFO GST_TYPEFIND gsttypefind.c:73:gst_type_find_register: registering typefind function for avtype_mm 0:00:00.023309155 3962 0x105a800 INFO GST_TYPEFIND gsttypefind.c:73:gst_type_find_register: registering typefind function for avtype_mmf 0:00:00.023374474 3962 0x105a800 INFO GST_TYPEFIND gsttypefind.c:73:gst_type_find_register: registering typefind function for avtype_nsv 0:00:00.023410862 3962 0x105a800 INFO GST_TYPEFIND gsttypefind.c:73:gst_type_find_register: registering typefind function for avtype_nut 0:00:00.023461605 3962 0x105a800 INFO GST_TYPEFIND gsttypefind.c:73:gst_type_find_register: registering typefind function for avtype_RoQ 0:00:00.023500303 3962 0x105a800 INFO GST_TYPEFIND gsttypefind.c:73:gst_type_find_register: registering typefind function for avtype_film_cpk 0:00:00.023532802 3962 0x105a800 INFO GST_TYPEFIND gsttypefind.c:73:gst_type_find_register: registering typefind function for avtype_smk 0:00:00.023563418 3962 0x105a800 INFO GST_TYPEFIND gsttypefind.c:73:gst_type_find_register: registering typefind function for avtype_sol 0:00:00.023597200 3962 0x105a800 INFO GST_TYPEFIND gsttypefind.c:73:gst_type_find_register: registering typefind function for avtype_psxstr 0:00:00.023640804 3962 0x105a800 INFO GST_TYPEFIND gsttypefind.c:73:gst_type_find_register: registering typefind function for avtype_vmd 0:00:00.023687676 3962 0x105a800 INFO GST_TYPEFIND gsttypefind.c:73:gst_type_find_register: registering typefind function for avtype_wc3movie 0:00:00.023733263 3962 0x105a800 INFO GST_TYPEFIND gsttypefind.c:73:gst_type_find_register: registering typefind function for avtype_wsaud 0:00:00.023779538 3962 0x105a800 INFO GST_TYPEFIND gsttypefind.c:73:gst_type_find_register: registering typefind function for avtype_wsvqa 0:00:00.023818836 3962 0x105a800 INFO GST_TYPEFIND gsttypefind.c:73:gst_type_find_register: registering typefind function for avtype_yuv4mpegpipe 0:00:00.024098466 3962 0x105a800 INFO GST_PLUGIN_LOADING gstplugin.c:830:gst_plugin_load_file: plugin "/usr/lib/x86_64-linux-gnu/gstreamer-1.0/libgstlibav.so" loaded 0:00:00.024116196 3962 0x105a800 INFO GST_ELEMENT_FACTORY gstelementfactory.c:365:gst_element_factory_create: creating element "avdec_h264" 0:00:00.024219977 3962 0x105a800 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstVideoDecoder@0x122a8e0> adding pad 'sink' 0:00:00.024251195 3962 0x105a800 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstVideoDecoder@0x122a8e0> adding pad 'src' 0:00:00.024767123 3962 0x105a800 INFO GST_ELEMENT_FACTORY gstelementfactory.c:365:gst_element_factory_create: creating element "fakesink" 0:00:00.024875736 3962 0x105a800 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstBaseSink@0x122f240> adding pad 'sink' 0:00:00.024907274 3962 0x105a800 INFO GST_ELEMENT_FACTORY gstelementfactory.c:365:gst_element_factory_create: creating element "pipeline" 0:00:00.025003431 3962 0x105a800 INFO GST_PIPELINE ./grammar.y:577:gst_parse_perform_link: linking filesrc0:(any) to qtdemux0:(any) (0/0) with caps "(NULL)" 0:00:00.025025056 3962 0x105a800 INFO GST_ELEMENT_PADS gstutils.c:1543:gst_element_link_pads_full: trying to link element filesrc0:(any) to element qtdemux0:(any) 0:00:00.025040075 3962 0x105a800 INFO GST_PADS gstutils.c:936:gst_pad_check_link: trying to link filesrc0:src and qtdemux0:sink 0:00:00.025067812 3962 0x105a800 INFO GST_PADS gstutils.c:1443:prepare_link_maybe_ghosting: filesrc0 and qtdemux0 in same bin, no need for ghost pads 0:00:00.025092096 3962 0x105a800 INFO GST_PADS gstpad.c:2062:gst_pad_link_prepare: trying to link filesrc0:src and qtdemux0:sink 0:00:00.025111402 3962 0x105a800 INFO GST_PADS gstpad.c:2264:gst_pad_link_full: linked filesrc0:src and qtdemux0:sink, successful 0:00:00.025123031 3962 0x105a800 INFO GST_EVENT gstevent.c:1313:gst_event_new_reconfigure: creating reconfigure event 0:00:00.025140836 3962 0x105a800 INFO GST_EVENT gstpad.c:4874:gst_pad_send_event_unchecked:<filesrc0:src> Received event on flushing pad. Discarding 0:00:00.025158972 3962 0x105a800 INFO GST_PIPELINE ./grammar.y:577:gst_parse_perform_link: linking qtdemux0:(any) to avdec_h264-0:(any) (0/0) with caps "(NULL)" 0:00:00.025172997 3962 0x105a800 INFO GST_ELEMENT_PADS gstutils.c:1543:gst_element_link_pads_full: trying to link element qtdemux0:(any) to element avdec_h264-0:(any) 0:00:00.025200495 3962 0x105a800 INFO GST_ELEMENT_PADS gstelement.c:891:gst_element_get_static_pad: no such pad 'video_%u' in element "qtdemux0" 0:00:00.025216989 3962 0x105a800 INFO GST_ELEMENT_PADS gstutils.c:1123:gst_element_get_compatible_pad:<qtdemux0> Could not find a compatible pad to link to avdec_h264-0:sink 0:00:00.025228648 3962 0x105a800 INFO default gstutils.c:1889:gst_element_link_pads_filtered: Could not link pads: qtdemux0:(null) - avdec_h264-0:(null) 0:00:00.025246839 3962 0x105a800 INFO GST_PIPELINE ./grammar.y:577:gst_parse_perform_link: linking avdec_h264-0:(any) to fakesink0:(any) (0/0) with caps "(NULL)" 0:00:00.025259138 3962 0x105a800 INFO GST_ELEMENT_PADS gstutils.c:1543:gst_element_link_pads_full: trying to link element avdec_h264-0:(any) to element fakesink0:(any) 0:00:00.025271364 3962 0x105a800 INFO GST_PADS gstutils.c:936:gst_pad_check_link: trying to link avdec_h264-0:src and fakesink0:sink 0:00:00.025288962 3962 0x105a800 INFO GST_PADS gstutils.c:1443:prepare_link_maybe_ghosting: avdec_h264-0 and fakesink0 in same bin, no need for ghost pads 0:00:00.025306018 3962 0x105a800 INFO GST_PADS gstpad.c:2062:gst_pad_link_prepare: trying to link avdec_h264-0:src and fakesink0:sink 0:00:00.025321898 3962 0x105a800 INFO GST_PADS gstpad.c:2264:gst_pad_link_full: linked avdec_h264-0:src and fakesink0:sink, successful 0:00:00.025332865 3962 0x105a800 INFO GST_EVENT gstevent.c:1313:gst_event_new_reconfigure: creating reconfigure event 0:00:00.025343571 3962 0x105a800 INFO GST_EVENT gstpad.c:4874:gst_pad_send_event_unchecked:<avdec_h264-0:src> Received event on flushing pad. Discarding Setting pipeline to PAUSED ... 0:00:00.025403314 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<fakesink0> current NULL pending VOID_PENDING, desired next READY 0:00:00.025419650 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<fakesink0> completed state change to READY 0:00:00.025432190 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<fakesink0> notifying about state-changed NULL to READY (VOID_PENDING pending) 0:00:00.025453820 3962 0x105a800 INFO GST_STATES gstbin.c:2602:gst_bin_change_state_func:<pipeline0> child 'fakesink0' changed state to 2(READY) successfully 0:00:00.025467789 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<avdec_h264-0> current NULL pending VOID_PENDING, desired next READY 0:00:00.025480957 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<avdec_h264-0> completed state change to READY 0:00:00.025491499 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<avdec_h264-0> notifying about state-changed NULL to READY (VOID_PENDING pending) 0:00:00.025504419 3962 0x105a800 INFO GST_STATES gstbin.c:2602:gst_bin_change_state_func:<pipeline0> child 'avdec_h264-0' changed state to 2(READY) successfully 0:00:00.025518062 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<qtdemux0> current NULL pending VOID_PENDING, desired next READY 0:00:00.025531483 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<qtdemux0> completed state change to READY 0:00:00.025541695 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<qtdemux0> notifying about state-changed NULL to READY (VOID_PENDING pending) 0:00:00.025554538 3962 0x105a800 INFO GST_STATES gstbin.c:2602:gst_bin_change_state_func:<pipeline0> child 'qtdemux0' changed state to 2(READY) successfully 0:00:00.025567066 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<filesrc0> current NULL pending VOID_PENDING, desired next READY 0:00:00.025578859 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<filesrc0> completed state change to READY 0:00:00.025588870 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<filesrc0> notifying about state-changed NULL to READY (VOID_PENDING pending) 0:00:00.025601415 3962 0x105a800 INFO GST_STATES gstbin.c:2602:gst_bin_change_state_func:<pipeline0> child 'filesrc0' changed state to 2(READY) successfully 0:00:00.025615627 3962 0x105a800 INFO GST_STATES gstelement.c:2296:gst_element_continue_state:<pipeline0> committing state from NULL to READY, pending PAUSED, next PAUSED 0:00:00.025626643 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed NULL to READY (PAUSED pending) 0:00:00.025656939 3962 0x105a800 INFO GST_STATES gstelement.c:2303:gst_element_continue_state:<pipeline0> continue state change READY to PAUSED, final PAUSED 0:00:00.025676411 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<fakesink0> current READY pending VOID_PENDING, desired next PAUSED 0:00:00.025697219 3962 0x105a800 INFO GST_STATES gstbin.c:2608:gst_bin_change_state_func:<pipeline0> child 'fakesink0' is changing state asynchronously to PAUSED 0:00:00.025710347 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<avdec_h264-0> current READY pending VOID_PENDING, desired next PAUSED 0:00:00.025724892 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<avdec_h264-0> completed state change to PAUSED 0:00:00.025735565 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<avdec_h264-0> notifying about state-changed READY to PAUSED (VOID_PENDING pending) 0:00:00.025748668 3962 0x105a800 INFO GST_STATES gstbin.c:2602:gst_bin_change_state_func:<pipeline0> child 'avdec_h264-0' changed state to 3(PAUSED) successfully 0:00:00.025761841 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<qtdemux0> current READY pending VOID_PENDING, desired next PAUSED 0:00:00.025778576 3962 0x105a800 INFO filesrc gstfilesrc.c:450:gst_file_src_start:<filesrc0> opening file /home/alex/emergency.mp4 0:00:00.025823903 3962 0x105a800 INFO filesrc gstfilesrc.c:450:gst_file_src_start:<filesrc0> opening file /home/alex/emergency.mp4 0:00:00.025855024 3962 0x105a800 INFO task gsttask.c:431:gst_task_set_lock: setting stream lock 0x11d0390 on task 0x1234000 0:00:00.025868082 3962 0x105a800 INFO GST_PADS gstpad.c:5204:gst_pad_start_task:<qtdemux0:sink> created task 0x1234000 0:00:00.025926850 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<qtdemux0> completed state change to PAUSED 0:00:00.025946982 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<qtdemux0> notifying about state-changed READY to PAUSED (VOID_PENDING pending) 0:00:00.025970524 3962 0x105a800 INFO GST_STATES gstbin.c:2602:gst_bin_change_state_func:<pipeline0> child 'qtdemux0' changed state to 3(PAUSED) successfully 0:00:00.025991602 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<filesrc0> current READY pending VOID_PENDING, desired next PAUSED 0:00:00.026016162 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<filesrc0> completed state change to PAUSED 0:00:00.026043598 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<filesrc0> notifying about state-changed READY to PAUSED (VOID_PENDING pending) 0:00:00.026066678 3962 0x105a800 INFO GST_STATES gstbin.c:2602:gst_bin_change_state_func:<pipeline0> child 'filesrc0' changed state to 3(PAUSED) successfully Pipeline is PREROLLING ... 0:00:00.026096489 3962 0x122e370 WARN qtdemux qtdemux_types.c:192:qtdemux_type_get: unknown QuickTime node type avc1 0:00:00.026122184 3962 0x122e370 WARN qtdemux qtdemux_types.c:192:qtdemux_type_get: unknown QuickTime node type avcC 0:00:00.026194869 3962 0x122e370 INFO qtdemux qtdemux.c:9045:qtdemux_parse_tree:<qtdemux0> timescale: 90000 0:00:00.026207506 3962 0x122e370 INFO qtdemux qtdemux.c:9046:qtdemux_parse_tree:<qtdemux0> duration: 7093086 0:00:00.026251902 3962 0x122e370 INFO qtdemux qtdemux.c:7048:qtdemux_parse_trak:<qtdemux0> type avc1 caps video/x-h264, stream-format=(string)avc, alignment=(string)au, level=(string)4, profile=(string)main, codec_data=(buffer)014d4028ffe1001b674d4028965603c0113f2e02a100000303e90000ea608da1e3d38001000448ee3720 0:00:00.026389038 3962 0x122e370 INFO GST_SCHEDULING gstpad.c:4157:gst_pad_get_range_unchecked:<filesrc0:src> getrange failed, flow: eos 0:00:00.026427299 3962 0x122e370 INFO GST_SCHEDULING gstpad.c:4360:gst_pad_pull_range:<qtdemux0:sink> pullrange failed, flow: eos 0:00:00.026608838 3962 0x122e370 INFO GST_ELEMENT_PADS gstelement.c:894:gst_element_get_static_pad: found pad qtdemux0:sink 0:00:00.026732968 3962 0x122e370 INFO GST_EVENT gstevent.c:628:gst_event_new_caps: creating caps event video/x-h264, stream-format=(string)avc, alignment=(string)au, level=(string)4, profile=(string)main, codec_data=(buffer)014d4028ffe1001b674d4028965603c0113f2e02a100000303e90000ea608da1e3d38001000448ee3720, width=(int)1920, height=(int)1080, framerate=(fraction)30000/1001, pixel-aspect-ratio=(fraction)1/1 0:00:00.026857679 3962 0x122e370 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<qtdemux0> adding pad 'video_0' 0:00:00.026890828 3962 0x122e370 INFO GST_PIPELINE ./grammar.y:505:gst_parse_found_pad: trying delayed linking qtdemux0:(NULL) to avdec_h264-0:(NULL) 0:00:00.026919458 3962 0x122e370 INFO GST_ELEMENT_PADS gstutils.c:1543:gst_element_link_pads_full: trying to link element qtdemux0:(any) to element avdec_h264-0:(any) 0:00:00.026947811 3962 0x122e370 INFO GST_PADS gstutils.c:936:gst_pad_check_link: trying to link qtdemux0:video_0 and avdec_h264-0:sink 0:00:00.026988208 3962 0x122e370 INFO GST_PADS gstutils.c:1443:prepare_link_maybe_ghosting: qtdemux0 and avdec_h264-0 in same bin, no need for ghost pads 0:00:00.027032563 3962 0x122e370 INFO GST_PADS gstpad.c:2062:gst_pad_link_prepare: trying to link qtdemux0:video_0 and avdec_h264-0:sink 0:00:00.027080295 3962 0x122e370 INFO GST_PADS gstpad.c:2264:gst_pad_link_full: linked qtdemux0:video_0 and avdec_h264-0:sink, successful 0:00:00.027107943 3962 0x122e370 INFO GST_EVENT gstevent.c:1313:gst_event_new_reconfigure: creating reconfigure event 0:00:00.027295054 3962 0x122e370 INFO GST_EVENT gstevent.c:709:gst_event_new_segment: creating segment event time segment start=0:00:00.000000000, stop=0:01:18.812066666, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0:00:00.000000000, base=0:00:00.000000000, position 0:00:00.000000000, duration 99:99:99.999999999 Redistribute latency... 0:00:00.029129720 3962 0x105a800 INFO GST_EVENT gstevent.c:1184:gst_event_new_latency: creating latency event 0:00:00.000000000 0:00:00.029164264 3962 0x105a800 INFO bin gstbin.c:2466:gst_bin_do_latency_func:<pipeline0> configured latency of 0:00:00.000000000 0:00:00.030745418 3962 0x122e370 INFO GST_EVENT gstevent.c:628:gst_event_new_caps: creating caps event video/x-raw, format=(string)I420, width=(int)1920, height=(int)1080, pixel-aspect-ratio=(fraction)1/1, interlace-mode=(string)progressive, colorimetry=(string)bt709, framerate=(fraction)30000/1001 0:00:00.103644194 3962 0x122e370 INFO GST_EVENT gstevent.c:628:gst_event_new_caps: creating caps event video/x-raw, format=(string)I420, width=(int)1920, height=(int)1080, pixel-aspect-ratio=(fraction)1/1, interlace-mode=(string)progressive, colorimetry=(string)bt709, framerate=(fraction)30000/1001 0:00:00.105013170 3962 0x122e370 INFO GST_STATES gstbin.c:3019:bin_handle_async_done:<pipeline0> committing state from READY to PAUSED, old pending PAUSED 0:00:00.105047096 3962 0x122e370 INFO GST_STATES gstbin.c:3039:bin_handle_async_done:<pipeline0> completed state change, pending VOID 0:00:00.105059500 3962 0x122e370 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed READY to PAUSED (VOID_PENDING pending) Pipeline is PREROLLED ... Setting pipeline to PLAYING ... 0:00:00.105327456 3962 0x105a800 INFO GST_EVENT gstevent.c:1184:gst_event_new_latency: creating latency event 0:00:00.000000000 0:00:00.105355301 3962 0x105a800 INFO bin gstbin.c:2466:gst_bin_do_latency_func:<pipeline0> configured latency of 0:00:00.000000000 0:00:00.105373818 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<fakesink0> current PAUSED pending VOID_PENDING, desired next PLAYING 0:00:00.105387558 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<fakesink0> completed state change to PLAYING 0:00:00.105406106 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<fakesink0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending) 0:00:00.105416947 3962 0x105a800 INFO GST_STATES gstbin.c:2602:gst_bin_change_state_func:<pipeline0> child 'fakesink0' changed state to 4(PLAYING) successfully 0:00:00.105427137 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<avdec_h264-0> current PAUSED pending VOID_PENDING, desired next PLAYING 0:00:00.105434973 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<avdec_h264-0> completed state change to PLAYING 0:00:00.105443393 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<avdec_h264-0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending) 0:00:00.105452635 3962 0x105a800 INFO GST_STATES gstbin.c:2602:gst_bin_change_state_func:<pipeline0> child 'avdec_h264-0' changed state to 4(PLAYING) successfully 0:00:00.105462311 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<qtdemux0> current PAUSED pending VOID_PENDING, desired next PLAYING 0:00:00.105470150 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<qtdemux0> completed state change to PLAYING 0:00:00.105476396 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<qtdemux0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending) 0:00:00.105485179 3962 0x105a800 INFO GST_STATES gstbin.c:2602:gst_bin_change_state_func:<pipeline0> child 'qtdemux0' changed state to 4(PLAYING) successfully 0:00:00.105493764 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<filesrc0> current PAUSED pending VOID_PENDING, desired next PLAYING 0:00:00.105501586 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<filesrc0> completed state change to PLAYING 0:00:00.105508059 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<filesrc0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending) 0:00:00.105517002 3962 0x105a800 INFO GST_STATES gstbin.c:2602:gst_bin_change_state_func:<pipeline0> child 'filesrc0' changed state to 4(PLAYING) successfully 0:00:00.105526135 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<pipeline0> completed state change to PLAYING 0:00:00.105532557 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending) New clock: GstSystemClock 0:00:48.032157825 3962 0x122e370 INFO task gsttask.c:300:gst_task_func:<qtdemux0:sink> Task going to paused Got EOS from element "pipeline0". Execution ended after 47926668558 ns. Setting pipeline to PAUSED ... 0:00:48.032327505 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<fakesink0> current PLAYING pending VOID_PENDING, desired next PAUSED 0:00:48.032393258 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<fakesink0> completed state change to PAUSED 0:00:48.032422198 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<fakesink0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending) 0:00:48.032476410 3962 0x105a800 INFO GST_STATES gstbin.c:2602:gst_bin_change_state_func:<pipeline0> child 'fakesink0' changed state to 3(PAUSED) successfully 0:00:48.032515954 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<avdec_h264-0> current PLAYING pending VOID_PENDING, desired next PAUSED 0:00:48.032544534 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<avdec_h264-0> completed state change to PAUSED 0:00:48.032568758 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<avdec_h264-0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending) 0:00:48.032602554 3962 0x105a800 INFO GST_STATES gstbin.c:2602:gst_bin_change_state_func:<pipeline0> child 'avdec_h264-0' changed state to 3(PAUSED) successfully 0:00:48.032638420 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<qtdemux0> current PLAYING pending VOID_PENDING, desired next PAUSED 0:00:48.032666889 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<qtdemux0> completed state change to PAUSED 0:00:48.032690247 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<qtdemux0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending) 0:00:48.032723327 3962 0x105a800 INFO GST_STATES gstbin.c:2602:gst_bin_change_state_func:<pipeline0> child 'qtdemux0' changed state to 3(PAUSED) successfully 0:00:48.032755058 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<filesrc0> current PLAYING pending VOID_PENDING, desired next PAUSED 0:00:48.032783888 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<filesrc0> completed state change to PAUSED 0:00:48.032807311 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<filesrc0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending) 0:00:48.032839639 3962 0x105a800 INFO GST_STATES gstbin.c:2602:gst_bin_change_state_func:<pipeline0> child 'filesrc0' changed state to 3(PAUSED) successfully 0:00:48.032875685 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<pipeline0> completed state change to PAUSED 0:00:48.032899288 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending) 0:00:48.032969251 3962 0x105a800 INFO GST_STATES gstbin.c:1794:gst_bin_get_state_func:<pipeline0> getting state Setting pipeline to READY ... 0:00:48.033054663 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<fakesink0> current PAUSED pending VOID_PENDING, desired next READY 0:00:48.033123112 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<fakesink0> completed state change to READY 0:00:48.033149096 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<fakesink0> notifying about state-changed PAUSED to READY (VOID_PENDING pending) 0:00:48.033184090 3962 0x105a800 INFO GST_STATES gstbin.c:2602:gst_bin_change_state_func:<pipeline0> child 'fakesink0' changed state to 2(READY) successfully 0:00:48.033219209 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<avdec_h264-0> current PAUSED pending VOID_PENDING, desired next READY 0:00:48.037403311 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<avdec_h264-0> completed state change to READY 0:00:48.037503802 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<avdec_h264-0> notifying about state-changed PAUSED to READY (VOID_PENDING pending) 0:00:48.037604996 3962 0x105a800 INFO GST_STATES gstbin.c:2602:gst_bin_change_state_func:<pipeline0> child 'avdec_h264-0' changed state to 2(READY) successfully 0:00:48.037701653 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<qtdemux0> current PAUSED pending VOID_PENDING, desired next READY 0:00:48.037929346 3962 0x122e370 INFO task gsttask.c:302:gst_task_func:<qtdemux0:sink> Task resume from paused 0:00:48.038087181 3962 0x105a800 INFO GST_ELEMENT_PADS gstelement.c:763:gst_element_remove_pad:<qtdemux0> removing pad 'video_0' 0:00:48.038157185 3962 0x105a800 INFO GST_ELEMENT_PADS gstpad.c:1819:gst_pad_unlink: unlinking qtdemux0:video_0(0x11d1270) and avdec_h264-0:sink(0x11d0550) 0:00:48.038264837 3962 0x105a800 INFO GST_ELEMENT_PADS gstpad.c:1873:gst_pad_unlink: unlinked qtdemux0:video_0 and avdec_h264-0:sink 0:00:48.038438293 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<qtdemux0> completed state change to READY 0:00:48.038512440 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<qtdemux0> notifying about state-changed PAUSED to READY (VOID_PENDING pending) 0:00:48.038622127 3962 0x105a800 INFO GST_STATES gstbin.c:2602:gst_bin_change_state_func:<pipeline0> child 'qtdemux0' changed state to 2(READY) successfully 0:00:48.038731268 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<fakesink0> current READY pending VOID_PENDING, desired next READY 0:00:48.038809590 3962 0x105a800 INFO GST_STATES gstbin.c:2311:gst_bin_element_set_state:<fakesink0> skipping transition from READY to READY 0:00:48.038878244 3962 0x105a800 INFO GST_STATES gstbin.c:2602:gst_bin_change_state_func:<pipeline0> child 'fakesink0' changed state to 2(READY) successfully 0:00:48.038960114 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<avdec_h264-0> current READY pending VOID_PENDING, desired next READY 0:00:48.039031630 3962 0x105a800 INFO GST_STATES gstbin.c:2311:gst_bin_element_set_state:<avdec_h264-0> skipping transition from READY to READY 0:00:48.039099999 3962 0x105a800 INFO GST_STATES gstbin.c:2602:gst_bin_change_state_func:<pipeline0> child 'avdec_h264-0' changed state to 2(READY) successfully 0:00:48.039184735 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<qtdemux0> current READY pending VOID_PENDING, desired next READY 0:00:48.039258015 3962 0x105a800 INFO GST_STATES gstbin.c:2311:gst_bin_element_set_state:<qtdemux0> skipping transition from READY to READY 0:00:48.039328599 3962 0x105a800 INFO GST_STATES gstbin.c:2602:gst_bin_change_state_func:<pipeline0> child 'qtdemux0' changed state to 2(READY) successfully 0:00:48.039463683 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<filesrc0> current PAUSED pending VOID_PENDING, desired next READY 0:00:48.039554120 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<filesrc0> completed state change to READY 0:00:48.039572630 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<filesrc0> notifying about state-changed PAUSED to READY (VOID_PENDING pending) 0:00:48.039595730 3962 0x105a800 INFO GST_STATES gstbin.c:2602:gst_bin_change_state_func:<pipeline0> child 'filesrc0' changed state to 2(READY) successfully 0:00:48.039620972 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<pipeline0> completed state change to READY 0:00:48.039639243 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed PAUSED to READY (VOID_PENDING pending) 0:00:48.039672147 3962 0x105a800 INFO GST_STATES gstbin.c:1794:gst_bin_get_state_func:<pipeline0> getting state Setting pipeline to NULL ... 0:00:48.039720571 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<fakesink0> current READY pending VOID_PENDING, desired next NULL 0:00:48.039747241 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<fakesink0> completed state change to NULL 0:00:48.039766379 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<fakesink0> notifying about state-changed READY to NULL (VOID_PENDING pending) 0:00:48.039789518 3962 0x105a800 INFO GST_STATES gstbin.c:2602:gst_bin_change_state_func:<pipeline0> child 'fakesink0' changed state to 1(NULL) successfully 0:00:48.039811018 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<avdec_h264-0> current READY pending VOID_PENDING, desired next NULL 0:00:48.039835282 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<avdec_h264-0> completed state change to NULL 0:00:48.039853843 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<avdec_h264-0> notifying about state-changed READY to NULL (VOID_PENDING pending) 0:00:48.039876548 3962 0x105a800 INFO GST_STATES gstbin.c:2602:gst_bin_change_state_func:<pipeline0> child 'avdec_h264-0' changed state to 1(NULL) successfully 0:00:48.039897925 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<qtdemux0> current READY pending VOID_PENDING, desired next NULL 0:00:48.039915097 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<qtdemux0> completed state change to NULL 0:00:48.039932782 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<qtdemux0> notifying about state-changed READY to NULL (VOID_PENDING pending) 0:00:48.039956507 3962 0x105a800 INFO GST_STATES gstbin.c:2602:gst_bin_change_state_func:<pipeline0> child 'qtdemux0' changed state to 1(NULL) successfully 0:00:48.039978304 3962 0x105a800 INFO GST_STATES gstbin.c:2194:gst_bin_element_set_state:<filesrc0> current READY pending VOID_PENDING, desired next NULL 0:00:48.040002108 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<filesrc0> completed state change to NULL 0:00:48.040020543 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<filesrc0> notifying about state-changed READY to NULL (VOID_PENDING pending) 0:00:48.040043186 3962 0x105a800 INFO GST_STATES gstbin.c:2602:gst_bin_change_state_func:<pipeline0> child 'filesrc0' changed state to 1(NULL) successfully 0:00:48.040089789 3962 0x105a800 INFO GST_STATES gstelement.c:2321:gst_element_continue_state:<pipeline0> completed state change to NULL 0:00:48.040109679 3962 0x105a800 INFO GST_STATES gstelement.c:2226:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed READY to NULL (VOID_PENDING pending) Freeing pipeline ... 0:00:48.040152994 3962 0x105a800 INFO GST_ELEMENT_PADS gstpad.c:1819:gst_pad_unlink: unlinking avdec_h264-0:src(0x11d0780) and fakesink0:sink(0x11d09b0) 0:00:48.040180856 3962 0x105a800 INFO GST_ELEMENT_PADS gstpad.c:1873:gst_pad_unlink: unlinked avdec_h264-0:src and fakesink0:sink 0:00:48.040209766 3962 0x105a800 INFO GST_PARENTAGE gstbin.c:1523:gst_bin_remove_func:<pipeline0> removed child "fakesink0" 0:00:48.040245515 3962 0x105a800 INFO GST_REFCOUNTING gstelement.c:2865:gst_element_dispose:<fakesink0> dispose 0:00:48.040263776 3962 0x105a800 INFO GST_ELEMENT_PADS gstelement.c:763:gst_element_remove_pad:<fakesink0> removing pad 'sink' 0:00:48.040286276 3962 0x105a800 INFO GST_REFCOUNTING gstelement.c:2909:gst_element_dispose:<fakesink0> parent class dispose 0:00:48.040305191 3962 0x105a800 INFO GST_REFCOUNTING gstelement.c:2940:gst_element_finalize:<fakesink0> finalize 0:00:48.040322263 3962 0x105a800 INFO GST_REFCOUNTING gstelement.c:2945:gst_element_finalize:<fakesink0> finalize parent 0:00:48.040345803 3962 0x105a800 INFO GST_PARENTAGE gstbin.c:1523:gst_bin_remove_func:<pipeline0> removed child "avdec_h264-0" 0:00:48.040367973 3962 0x105a800 INFO GST_REFCOUNTING gstelement.c:2865:gst_element_dispose:<avdec_h264-0> dispose 0:00:48.040384519 3962 0x105a800 INFO GST_ELEMENT_PADS gstelement.c:763:gst_element_remove_pad:<avdec_h264-0> removing pad 'sink' 0:00:48.040405951 3962 0x105a800 INFO GST_ELEMENT_PADS gstelement.c:763:gst_element_remove_pad:<avdec_h264-0> removing pad 'src' 0:00:48.040428342 3962 0x105a800 INFO GST_REFCOUNTING gstelement.c:2909:gst_element_dispose:<avdec_h264-0> parent class dispose 0:00:48.041187843 3962 0x105a800 INFO GST_REFCOUNTING gstelement.c:2940:gst_element_finalize:<avdec_h264-0> finalize 0:00:48.041211198 3962 0x105a800 INFO GST_REFCOUNTING gstelement.c:2945:gst_element_finalize:<avdec_h264-0> finalize parent 0:00:48.041235333 3962 0x105a800 INFO GST_ELEMENT_PADS gstpad.c:1819:gst_pad_unlink: unlinking filesrc0:src(0x11d00f0) and qtdemux0:sink(0x11d0320) 0:00:48.041260482 3962 0x105a800 INFO GST_ELEMENT_PADS gstpad.c:1873:gst_pad_unlink: unlinked filesrc0:src and qtdemux0:sink 0:00:48.041288167 3962 0x105a800 INFO GST_PARENTAGE gstbin.c:1523:gst_bin_remove_func:<pipeline0> removed child "qtdemux0" 0:00:48.041313630 3962 0x105a800 INFO GST_REFCOUNTING gstelement.c:2865:gst_element_dispose:<qtdemux0> dispose 0:00:48.041331457 3962 0x105a800 INFO GST_ELEMENT_PADS gstelement.c:763:gst_element_remove_pad:<qtdemux0> removing pad 'sink' 0:00:48.041356216 3962 0x105a800 INFO GST_REFCOUNTING gstelement.c:2909:gst_element_dispose:<qtdemux0> parent class dispose 0:00:48.041377947 3962 0x105a800 INFO GST_REFCOUNTING gstelement.c:2940:gst_element_finalize:<qtdemux0> finalize 0:00:48.041395876 3962 0x105a800 INFO GST_REFCOUNTING gstelement.c:2945:gst_element_finalize:<qtdemux0> finalize parent 0:00:48.041420852 3962 0x105a800 INFO GST_PARENTAGE gstbin.c:1523:gst_bin_remove_func:<pipeline0> removed child "filesrc0" 0:00:48.041442779 3962 0x105a800 INFO GST_REFCOUNTING gstelement.c:2865:gst_element_dispose:<filesrc0> dispose 0:00:48.041460810 3962 0x105a800 INFO GST_ELEMENT_PADS gstelement.c:763:gst_element_remove_pad:<filesrc0> removing pad 'src' 0:00:48.041482316 3962 0x105a800 INFO GST_REFCOUNTING gstelement.c:2909:gst_element_dispose:<filesrc0> parent class dispose 0:00:48.041502986 3962 0x105a800 INFO GST_REFCOUNTING gstelement.c:2940:gst_element_finalize:<filesrc0> finalize 0:00:48.041521068 3962 0x105a800 INFO GST_REFCOUNTING gstelement.c:2945:gst_element_finalize:<filesrc0> finalize parent 0:00:48.041539408 3962 0x105a800 INFO GST_REFCOUNTING gstelement.c:2865:gst_element_dispose:<pipeline0> dispose 0:00:48.041568999 3962 0x105a800 INFO GST_REFCOUNTING gstelement.c:2909:gst_element_dispose:<pipeline0> parent class dispose 0:00:48.041588515 3962 0x105a800 INFO GST_REFCOUNTING gstelement.c:2940:gst_element_finalize:<pipeline0> finalize 0:00:48.041606319 3962 0x105a800 INFO GST_REFCOUNTING gstelement.c:2945:gst_element_finalize:<pipeline0> finalize parent 0:00:48.041624614 3962 0x105a800 INFO GST_INIT gst.c:987:gst_deinit: deinitializing GStreamer 0:00:48.043882828 3962 0x105a800 INFO GST_INIT gst.c:1108:gst_deinit: deinitialized GStreamer
Please don't paste stuff like this into the comments field, attach it next time. I don't see it in the log, but I see a GST_INFO statement in gstavutils.c, line 479 (in 1.0.8 anyway).
Yes, sorry, didn't expected it be so long. I'll try to reinstall to 1.0.8 and gather this information.
It doesn't build with yasm, and thus without MMX, SSE, etc support.
Should be fine now with latest 1.0 and master branch commit b131dadd9c73f96d43e88bd7b55b4e8b607049b5 Author: Sebastian Dröge <slomo@circular-chaos.org> Date: Fri Jul 19 09:45:24 2013 +0200 configure: Remove workaround from last decade and make SIMD optimizations work on OSX https://bugzilla.gnome.org/show_bug.cgi?id=704442
Nice! Thank you very much, Sebastian!
I've compiled gst-libav with latest changes, here's an updated result for OS X: 4 executions, average time is 48745428500 ns ~ 48,75 s. It's more, than 2x faster, than before.