eServiceMP3::construct!
eServiceMP3::playbin2 uri=file:///media/hdd/movie/Cocktail_cd1.avi
0:00:42.784817000 3226 0x1001db40 DEBUG               playbin2 gstplaybin2.c:1155:gst_play_bin_set_uri: set new uri to file:///media/hdd/movie/Cocktail_cd1.avi
0:00:42.878670000 3226 0x1001db40 INFO                playbin2 gstplaybin2.c:1513:gst_play_bin_set_sink:<playbin> (null)
0:00:42.879303000 3226 0x1001db40 LOG                 playbin2 gstplaybin2.c:1528:gst_play_bin_set_sink:<playbin> (null)
0:00:42.882799000 3226 0x1001db40 LOG                 playbin2 gstplaybin2.c:2826:gst_play_bin_change_state:<playbin> clearing shutdown flag
0:00:42.883350000 3226 0x1001db40 DEBUG               playbin2 gstplaybin2.c:2729:setup_next_source:<playbin> setup sources
0:00:42.883798000 3226 0x1001db40 DEBUG               playbin2 gstplaybin2.c:2522:activate_group:<playbin> activating group 0x10964220
0:00:42.884247000 3226 0x1001db40 DEBUG               playbin2 gstplaybin2.c:2537:activate_group:<playbin> making new uridecodebin
0:00:42.896580000 3226 0x1001db40 DEBUG             decodebin2 gstdecodebin2.c:2756:gst_decode_bin_plugin_init: binding text domain gst-plugins-base-0.10 to locale dir /usr/share/locale
0:00:42.897414000 3226 0x1001db40 DEBUG           uridecodebin gsturidecodebin.c:2004:gst_uri_decode_bin_plugin_init: binding text domain gst-plugins-base-0.10 to locale dir /usr/share/locale
0:00:42.906219000 3226 0x1001db40 DEBUG               playbin2 gstplaybin2.c:2496:group_set_locked_state_unlocked:<playbin> locked_state 0 on group 0x10964220
0:00:42.907486000 3226 0x1001db40 DEBUG           uridecodebin gsturidecodebin.c:1462:setup_source:<uridecodebin0> setup source
0:00:42.908037000 3226 0x1001db40 LOG             uridecodebin gsturidecodebin.c:831:gen_source_element:<uridecodebin0> finding source for file:///media/hdd/movie/Cocktail_cd1.avi
0:00:42.935597000 3226 0x1001db40 LOG             uridecodebin gsturidecodebin.c:843:gen_source_element:<uridecodebin0> found source type GstFileSrc
0:00:42.936233000 3226 0x1001db40 LOG             uridecodebin gsturidecodebin.c:846:gen_source_element:<uridecodebin0> source is stream: 0
0:00:42.936710000 3226 0x1001db40 LOG             uridecodebin gsturidecodebin.c:849:gen_source_element:<uridecodebin0> source needs queue: 0
0:00:42.938521000 3226 0x1001db40 DEBUG           uridecodebin gsturidecodebin.c:935:has_all_raw_caps:<source:src> (null)
0:00:42.939156000 3226 0x1001db40 DEBUG           uridecodebin gsturidecodebin.c:1526:setup_source:<uridecodebin0> Plugging decodebin to source
0:00:42.939632000 3226 0x1001db40 LOG             uridecodebin gsturidecodebin.c:1181:make_decoder:<uridecodebin0> making new decodebin2
0:00:42.956815000 3226 0x1001db40 DEBUG             decodebin2 gstdecodebin2.c:860:gst_decode_bin_set_subs_encoding:<decodebin20> Setting new encoding: (NULL)
0:00:42.957472000 3226 0x1001db40 LOG               decodebin2 gstdecodebin2.c:862:gst_decode_bin_set_subs_encoding:<decodebin20> locking from thread 0x1001db40
0:00:42.957951000 3226 0x1001db40 LOG               decodebin2 gstdecodebin2.c:862:gst_decode_bin_set_subs_encoding:<decodebin20> locked from thread 0x1001db40
0:00:42.958430000 3226 0x1001db40 LOG               decodebin2 gstdecodebin2.c:873:gst_decode_bin_set_subs_encoding:<decodebin20> unlocking from thread 0x1001db40
0:00:42.958984000 3226 0x1001db40 LOG             uridecodebin gsturidecodebin.c:1218:make_decoder:<uridecodebin0> have 1 pending dynamic objects
0:00:42.963319000 3226 0x1001db40 LOG               decodebin2 gstdecodebin2.c:2689:gst_decode_bin_change_state:<decodebin20> dynlocking from thread 0x1001db40
0:00:42.963877000 3226 0x1001db40 LOG               decodebin2 gstdecodebin2.c:2689:gst_decode_bin_change_state:<decodebin20> dynlocked from thread 0x1001db40
0:00:42.964357000 3226 0x1001db40 LOG               decodebin2 gstdecodebin2.c:2690:gst_decode_bin_change_state:<decodebin20> clearing shutdown flag
0:00:42.964803000 3226 0x1001db40 LOG               decodebin2 gstdecodebin2.c:2692:gst_decode_bin_change_state:<decodebin20> dynunlocking from thread 0x1001db40
0:00:43.121226000 3226 0x1001db40 DEBUG             decodebin2 gstdecodebin2.c:1503:type_found:<decodebin20> (null)
0:00:43.121904000 3226 0x1001db40 DEBUG             decodebin2 gstdecodebin2.c:1043:analyze_new_pad:<decodebin20> (null)
0:00:43.125918000 3226 0x1001db40 DEBUG           uridecodebin gsturidecodebin.c:1131:proxy_autoplug_continue_signal:<uridecodebin0> autoplug-continue returned 1
0:00:43.129799000 3226 0x1001db40 DEBUG             decodebin2 gstdecodebin2.c:945:gst_decode_bin_autoplug_continue:<decodebin20> autoplug-continue returns TRUE
0:00:43.130502000 3226 0x1001db40 LOG               decodebin2 gstdecodebin2.c:1725:are_raw_caps:<decodebin20> (null)
0:00:43.131003000 3226 0x1001db40 LOG               decodebin2 gstdecodebin2.c:1736:are_raw_caps:<decodebin20> Caps are not final caps
0:00:43.131637000 3226 0x1001db40 DEBUG               playbin2 gstplaybin2.c:2350:autoplug_factories_cb:<playbin> (null)
0:00:43.140306000 3226 0x1001db40 DEBUG               playbin2 gstplaybin2.c:2355:autoplug_factories_cb:<playbin> found factories 0x108c22b0
0:00:43.141128000 3226 0x1001db40 DEBUG           uridecodebin gsturidecodebin.c:1146:proxy_autoplug_factories_signal:<uridecodebin0> autoplug-factories returned 0x108c2280
0:00:43.141837000 3226 0x1001db40 DEBUG             decodebin2 gstdecodebin2.c:976:gst_decode_bin_autoplug_sort:<decodebin20> autoplug-sort returns 0x108c2260
0:00:43.142377000 3226 0x1001db40 LOG               decodebin2 gstdecodebin2.c:1094:analyze_new_pad:<typefind:src> Let's continue discovery on this pad
0:00:43.142840000 3226 0x1001db40 DEBUG             decodebin2 gstdecodebin2.c:1189:connect_pad:<decodebin20> pad typefind:src , group:(nil)
0:00:43.143527000 3226 0x1001db40 DEBUG               playbin2 gstplaybin2.c:2378:autoplug_select_cb:<playbin> (null)
0:00:43.143966000 3226 0x1001db40 DEBUG               playbin2 gstplaybin2.c:2381:autoplug_select_cb:<playbin> checking factory avidemux
0:00:43.144506000 3226 0x1001db40 DEBUG           uridecodebin gsturidecodebin.c:1161:proxy_autoplug_select_signal:<uridecodebin0> autoplug-select returned 0
0:00:43.145016000 3226 0x1001db40 DEBUG             decodebin2 gstdecodebin2.c:1226:connect_pad:<decodebin20> autoplug select requested try
0:00:43.224150000 3226 0x1001db40 DEBUG               avidemux gstavidemux.c:215:gst_avi_demux_reset: AVI: reset
0:00:43.226409000 3226 0x1001db40 LOG               decodebin2 gstdecodebin2.c:1292:connect_pad:<decodebin20> linked on pad typefind:src
0:00:43.226956000 3226 0x1001db40 DEBUG             decodebin2 gstdecodebin2.c:1346:connect_element:<decodebin20> Attempting to connect element avidemux0 [group:(nil)] further
0:00:43.227461000 3226 0x1001db40 DEBUG             decodebin2 gstdecodebin2.c:1359:connect_element:<decodebin20> got a source pad template audio_%02d
0:00:43.227926000 3226 0x1001db40 DEBUG             decodebin2 gstdecodebin2.c:1394:connect_element:<decodebin20> did not get the sometimes pad of template audio_%02d
0:00:43.228422000 3226 0x1001db40 DEBUG             decodebin2 gstdecodebin2.c:1359:connect_element:<decodebin20> got a source pad template video_%02d
0:00:43.228889000 3226 0x1001db40 DEBUG             decodebin2 gstdecodebin2.c:1394:connect_element:<decodebin20> did not get the sometimes pad of template video_%02d
0:00:43.229363000 3226 0x1001db40 DEBUG             decodebin2 gstdecodebin2.c:1359:connect_element:<decodebin20> got a source pad template subtitle_%02d
0:00:43.229849000 3226 0x1001db40 DEBUG             decodebin2 gstdecodebin2.c:1394:connect_element:<decodebin20> did not get the sometimes pad of template subtitle_%02d
0:00:43.231108000 3226 0x1001db40 DEBUG               avidemux gstavidemux.c:4278:gst_avi_demux_sink_activate: going to pull mode
0:00:43.239513000 3226 0x1001db40 DEBUG           uridecodebin gsturidecodebin.c:1960:gst_uri_decode_bin_change_state: ready to paused
eServiceMP3::starting pipeline
0:00:43.261952000 3226 0x10a15358 DEBUG               avidemux gstavidemux.c:3100:gst_avi_demux_stream_header_pull:<avidemux0> parsing headers
0:00:43.262737000 3226 0x10a15358 DEBUG               avidemux gstavidemux.c:3120:gst_avi_demux_stream_header_pull:<avidemux0> hdrl LIST tag found
0:00:43.263289000 3226 0x10a15358 INFO                avidemux gstavidemux.c:894:gst_avi_demux_parse_avih:<avidemux0> avih tag found:
0:00:43.263815000 3226 0x10a15358 INFO                avidemux gstavidemux.c:895:gst_avi_demux_parse_avih:<avidemux0>  us_frame    40000
0:00:43.264349000 3226 0x10a15358 INFO                avidemux gstavidemux.c:896:gst_avi_demux_parse_avih:<avidemux0>  max_bps     0
0:00:43.264863000 3226 0x10a15358 INFO                avidemux gstavidemux.c:897:gst_avi_demux_parse_avih:<avidemux0>  pad_gran    0
0:00:43.265302000 3226 0x10a15358 INFO                avidemux gstavidemux.c:898:gst_avi_demux_parse_avih:<avidemux0>  flags       0x00000110
0:00:43.265753000 3226 0x10a15358 INFO                avidemux gstavidemux.c:899:gst_avi_demux_parse_avih:<avidemux0>  tot_frames  66286
0:00:43.266182000 3226 0x10a15358 INFO                avidemux gstavidemux.c:900:gst_avi_demux_parse_avih:<avidemux0>  init_frames 0
0:00:43.266623000 3226 0x10a15358 INFO                avidemux gstavidemux.c:901:gst_avi_demux_parse_avih:<avidemux0>  streams     2
0:00:43.267057000 3226 0x10a15358 INFO                avidemux gstavidemux.c:902:gst_avi_demux_parse_avih:<avidemux0>  bufsize     0
0:00:43.267494000 3226 0x10a15358 INFO                avidemux gstavidemux.c:903:gst_avi_demux_parse_avih:<avidemux0>  width       576
0:00:43.267929000 3226 0x10a15358 INFO                avidemux gstavidemux.c:904:gst_avi_demux_parse_avih:<avidemux0>  height      336
0:00:43.268362000 3226 0x10a15358 INFO                avidemux gstavidemux.c:905:gst_avi_demux_parse_avih:<avidemux0>  scale       0
0:00:43.268808000 3226 0x10a15358 INFO                avidemux gstavidemux.c:906:gst_avi_demux_parse_avih:<avidemux0>  rate        0
0:00:43.269245000 3226 0x10a15358 INFO                avidemux gstavidemux.c:907:gst_avi_demux_parse_avih:<avidemux0>  start       0
0:00:43.269688000 3226 0x10a15358 INFO                avidemux gstavidemux.c:908:gst_avi_demux_parse_avih:<avidemux0>  length      0
0:00:43.270196000 3226 0x10a15358 DEBUG               avidemux gstavidemux.c:3130:gst_avi_demux_stream_header_pull:<avidemux0> AVI header ok, reading elements from header
0:00:43.270686000 3226 0x10a15358 DEBUG               avidemux gstavidemux.c:1418:gst_avi_demux_parse_stream:<avidemux0> Parsing stream
0:00:43.271549000 3226 0x10a15358 DEBUG               avidemux gstavidemux.c:1451:gst_avi_demux_parse_stream:<avidemux0> marking video as VBR, res 1
0:00:43.272448000 3226 0x10a15358 DEBUG               avidemux gstavidemux.c:1645:gst_avi_demux_parse_stream:<avidemux0> codec-name=DivX MS-MPEG-4 Version 3
0:00:43.272983000 3226 0x10a15358 DEBUG               avidemux gstavidemux.c:1646:gst_avi_demux_parse_stream:<avidemux0> (null)
0:00:43.274309000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1591:pad_added_cb:<avidemux0:video_00> Pad added to non-grouped element
0:00:43.276126000 3226 0x10a15358 DEBUG             decodebin2 gstdecodebin2.c:1043:analyze_new_pad:<decodebin20> (null)
0:00:43.280246000 3226 0x10a15358 DEBUG           uridecodebin gsturidecodebin.c:1131:proxy_autoplug_continue_signal:<uridecodebin0> autoplug-continue returned 1
0:00:43.280825000 3226 0x10a15358 DEBUG             decodebin2 gstdecodebin2.c:945:gst_decode_bin_autoplug_continue:<decodebin20> autoplug-continue returns TRUE
0:00:43.281308000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1725:are_raw_caps:<decodebin20> (null)
0:00:43.281853000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1736:are_raw_caps:<decodebin20> Caps are not final caps
0:00:43.282468000 3226 0x10a15358 DEBUG               playbin2 gstplaybin2.c:2350:autoplug_factories_cb:<playbin> (null)
0:00:43.284651000 3226 0x10a15358 DEBUG               playbin2 gstplaybin2.c:2355:autoplug_factories_cb:<playbin> found factories 0x10021320
0:00:43.288100000 3226 0x1001db40 LOG                 playbin2 gstplaybin2.c:1619:gst_play_bin_get_current_sink:<playbin> (null)
0:00:43.288812000 3226 0x1001db40 LOG                 playbin2 gstplaybin2.c:1619:gst_play_bin_get_current_sink:<playbin> (null)
0:00:43.302252000 3226 0x1001db40 LOG                 playbin2 gstplaybin2.c:1619:gst_play_bin_get_current_sink:<playbin> (null)
0:00:43.302921000 3226 0x1001db40 LOG                 playbin2 gstplaybin2.c:1619:gst_play_bin_get_current_sink:<playbin> (null)
eServiceMP3::state transition NULL -> READY
0:00:43.285220000 3226 0x10a15358 DEBUG           uridecodebin gsturidecodebin.c:1146:proxy_autoplug_factories_signal:<uridecodebin0> autoplug-factories returned 0x10880940
0:00:43.364103000 3226 0x10a15358 DEBUG             decodebin2 gstdecodebin2.c:976:gst_decode_bin_autoplug_sort:<decodebin20> autoplug-sort returns 0x10021410
0:00:43.364911000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1094:analyze_new_pad:<avidemux0:video_00> Let's continue discovery on this pad
0:00:43.365368000 3226 0x10a15358 DEBUG             decodebin2 gstdecodebin2.c:1189:connect_pad:<decodebin20> pad avidemux0:video_00 , group:(nil)
0:00:43.365948000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1193:connect_pad:<avidemux0> is a demuxer, connecting the pad through multiqueue
0:00:43.366578000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1856:get_current_group:<decodebin20> locking from thread 0x10a15358
0:00:43.367090000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1856:get_current_group:<decodebin20> locked from thread 0x10a15358
0:00:43.367643000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1795:gst_decode_group_new:<decodebin20> Creating new group
0:00:43.373182000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1833:gst_decode_group_new:<decodebin20> Returning new group 0x108c05f0
0:00:43.373755000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1873:get_current_group:<decodebin20> added group 0x108c05f0, demux 1
0:00:43.374224000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1881:get_current_group:<decodebin20> unlocking from thread 0x10a15358
0:00:43.375767000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1883:get_current_group:<decodebin20> Returning group 0x108c05f0
0:00:43.377151000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1904:gst_decode_group_control_demuxer_pad:<decodebin20> group:0x108c05f0 pad avidemux0:video_00
0:00:43.384257000 3226 0x1001db40 LOG                 playbin2 gstplaybin2.c:1619:gst_play_bin_get_current_sink:<playbin> (null)
0:00:43.385161000 3226 0x1001db40 LOG                 playbin2 gstplaybin2.c:1619:gst_play_bin_get_current_sink:<playbin> (null)
0:00:43.389029000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1925:gst_decode_group_control_demuxer_pad:<decodebin20> locking group 0x108c05f0 from thread 0x10a15358
0:00:43.389651000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1925:gst_decode_group_control_demuxer_pad:<decodebin20> locked group 0x108c05f0 from thread 0x10a15358
0:00:43.390153000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1934:gst_decode_group_control_demuxer_pad:<decodebin20> unlocking group 0x108c05f0 from thread 0x10a15358
0:00:43.392521000 3226 0x10a15358 DEBUG               playbin2 gstplaybin2.c:2378:autoplug_select_cb:<playbin> (null)
0:00:43.393029000 3226 0x10a15358 DEBUG               playbin2 gstplaybin2.c:2381:autoplug_select_cb:<playbin> checking factory dvbvideosink
0:00:43.393502000 3226 0x10a15358 DEBUG               playbin2 gstplaybin2.c:2388:autoplug_select_cb:<playbin> we found a sink
0:00:43.393927000 3226 0x10a15358 DEBUG               playbin2 gstplaybin2.c:2398:autoplug_select_cb:<playbin> we found a video sink
0:00:43.394364000 3226 0x10a15358 DEBUG               playbin2 gstplaybin2.c:2425:autoplug_select_cb:<playbin> we have no pending sink, try to create one
0:00:43.406499000 3226 0x10a15358 INFO            dvbvideosink gstdvbvideosink.c:308:gst_dvbvideosink_base_init: model is DM8000... set bcm7400 caps
0:00:43.411914000 3226 0x10a15358 DEBUG           dvbvideosink gstdvbvideosink.c:1507:gst_dvbvideosink_change_state:<dvbvideosink0> GST_STATE_CHANGE_NULL_TO_READY
0:00:43.412600000 3226 0x10a15358 DEBUG           dvbvideosink gstdvbvideosink.c:1433:gst_dvbvideosink_start:<dvbvideosink0> start
0:00:43.420942000 3226 0x10a15358 DEBUG               playbin2 gstplaybin2.c:2451:autoplug_select_cb:<playbin> remember sink
0:00:43.421544000 3226 0x10a15358 DEBUG               playbin2 gstplaybin2.c:2466:autoplug_select_cb:<playbin> we found a working sink, expose pad
0:00:43.422042000 3226 0x10a15358 DEBUG           uridecodebin gsturidecodebin.c:1161:proxy_autoplug_select_signal:<uridecodebin0> autoplug-select returned 1
0:00:43.422584000 3226 0x10a15358 DEBUG             decodebin2 gstdecodebin2.c:1229:connect_pad:<decodebin20> autoplug select requested expose
0:00:43.423108000 3226 0x10a15358 DEBUG             decodebin2 gstdecodebin2.c:1465:expose_pad:<decodebin20> pad multiqueue0:src0, group:0x108c05f0
0:00:43.423693000 3226 0x10a15358 DEBUG             decodebin2 gstdecodebin2.c:1947:gst_decode_group_control_source_pad:<'':decodepad1> adding decode pad to group 0x108c05f0
0:00:43.424222000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:2533:gst_decode_pad_set_blocked:<decodebin20> dynlocking from thread 0x10a15358
0:00:43.424686000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:2533:gst_decode_pad_set_blocked:<decodebin20> dynlocked from thread 0x10a15358
0:00:43.425157000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:2549:gst_decode_pad_set_blocked:<decodebin20> dynunlocking from thread 0x10a15358
0:00:43.425713000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1952:gst_decode_group_control_source_pad:<decodebin20> locking group 0x108c05f0 from thread 0x10a15358
0:00:43.426189000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1952:gst_decode_group_control_source_pad:<decodebin20> locked group 0x108c05f0 from thread 0x10a15358
0:00:43.426679000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1954:gst_decode_group_control_source_pad:<decodebin20> unlocking group 0x108c05f0 from thread 0x10a15358
0:00:43.427609000 3226 0x10a15358 DEBUG               avidemux gstavidemux.c:1418:gst_avi_demux_parse_stream:<avidemux0> Parsing stream
0:00:43.428315000 3226 0x10a15358 DEBUG               avidemux gstavidemux.c:1460:gst_avi_demux_parse_stream:<avidemux0> marking audio as VBR:1, res 1
0:00:43.429658000 3226 0x10a15358 DEBUG               avidemux gstavidemux.c:1645:gst_avi_demux_parse_stream:<avidemux0> codec-name=MPEG-1 layer 3
0:00:43.430121000 3226 0x10a15358 DEBUG               avidemux gstavidemux.c:1646:gst_avi_demux_parse_stream:<avidemux0> (null)
0:00:43.431356000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1591:pad_added_cb:<avidemux0:audio_00> Pad added to non-grouped element
0:00:43.432162000 3226 0x10a15358 DEBUG             decodebin2 gstdecodebin2.c:1043:analyze_new_pad:<decodebin20> (null)
0:00:43.435482000 3226 0x10a15358 DEBUG           uridecodebin gsturidecodebin.c:1131:proxy_autoplug_continue_signal:<uridecodebin0> autoplug-continue returned 1
0:00:43.436008000 3226 0x10a15358 DEBUG             decodebin2 gstdecodebin2.c:945:gst_decode_bin_autoplug_continue:<decodebin20> autoplug-continue returns TRUE
0:00:43.436477000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1725:are_raw_caps:<decodebin20> (null)
0:00:43.436934000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1736:are_raw_caps:<decodebin20> Caps are not final caps
0:00:43.437530000 3226 0x10a15358 DEBUG               playbin2 gstplaybin2.c:2350:autoplug_factories_cb:<playbin> (null)
0:00:43.439958000 3226 0x10a15358 DEBUG               playbin2 gstplaybin2.c:2355:autoplug_factories_cb:<playbin> found factories 0x10044bb0
0:00:43.440557000 3226 0x10a15358 DEBUG           uridecodebin gsturidecodebin.c:1146:proxy_autoplug_factories_signal:<uridecodebin0> autoplug-factories returned 0x10021370
0:00:43.441277000 3226 0x10a15358 DEBUG             decodebin2 gstdecodebin2.c:976:gst_decode_bin_autoplug_sort:<decodebin20> autoplug-sort returns 0x1002ad60
0:00:43.441841000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1094:analyze_new_pad:<avidemux0:audio_00> Let's continue discovery on this pad
0:00:43.442279000 3226 0x10a15358 DEBUG             decodebin2 gstdecodebin2.c:1189:connect_pad:<decodebin20> pad avidemux0:audio_00 , group:(nil)
0:00:43.442767000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1193:connect_pad:<avidemux0> is a demuxer, connecting the pad through multiqueue
0:00:43.443187000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1856:get_current_group:<decodebin20> locking from thread 0x10a15358
0:00:43.443630000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1856:get_current_group:<decodebin20> locked from thread 0x10a15358
0:00:43.444068000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1860:get_current_group:<decodebin20> locking group 0x108c05f0 from thread 0x10a15358
0:00:43.444605000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1860:get_current_group:<decodebin20> locked group 0x108c05f0 from thread 0x10a15358
0:00:43.445073000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1861:get_current_group:<decodebin20> group 0x108c05f0, complete:0
0:00:43.445538000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1865:get_current_group:<decodebin20> unlocking group 0x108c05f0 from thread 0x10a15358
0:00:43.446000000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1881:get_current_group:<decodebin20> unlocking from thread 0x10a15358
0:00:43.446440000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1883:get_current_group:<decodebin20> Returning group 0x108c05f0
0:00:43.447573000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1904:gst_decode_group_control_demuxer_pad:<decodebin20> group:0x108c05f0 pad avidemux0:audio_00
0:00:43.453358000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1925:gst_decode_group_control_demuxer_pad:<decodebin20> locking group 0x108c05f0 from thread 0x10a15358
0:00:43.453939000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1925:gst_decode_group_control_demuxer_pad:<decodebin20> locked group 0x108c05f0 from thread 0x10a15358
0:00:43.454439000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1934:gst_decode_group_control_demuxer_pad:<decodebin20> unlocking group 0x108c05f0 from thread 0x10a15358
0:00:43.456303000 3226 0x10a15358 DEBUG               playbin2 gstplaybin2.c:2378:autoplug_select_cb:<playbin> (null)
0:00:43.456768000 3226 0x10a15358 DEBUG               playbin2 gstplaybin2.c:2381:autoplug_select_cb:<playbin> checking factory mp3parse
0:00:43.457252000 3226 0x10a15358 DEBUG           uridecodebin gsturidecodebin.c:1161:proxy_autoplug_select_signal:<uridecodebin0> autoplug-select returned 0
0:00:43.457741000 3226 0x10a15358 DEBUG             decodebin2 gstdecodebin2.c:1226:connect_pad:<decodebin20> autoplug select requested try
0:00:43.476917000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1292:connect_pad:<decodebin20> linked on pad multiqueue0:src1
0:00:43.477477000 3226 0x10a15358 DEBUG             decodebin2 gstdecodebin2.c:1346:connect_element:<decodebin20> Attempting to connect element mpegaudioparse0 [group:0x108c05f0] further
0:00:43.477968000 3226 0x10a15358 DEBUG             decodebin2 gstdecodebin2.c:1359:connect_element:<decodebin20> got a source pad template src
0:00:43.478496000 3226 0x10a15358 DEBUG             decodebin2 gstdecodebin2.c:1370:connect_element:<decodebin20> got the pad for always template src
0:00:43.479137000 3226 0x10a15358 DEBUG             decodebin2 gstdecodebin2.c:1043:analyze_new_pad:<decodebin20> (null)
0:00:43.482376000 3226 0x10a15358 DEBUG           uridecodebin gsturidecodebin.c:1131:proxy_autoplug_continue_signal:<uridecodebin0> autoplug-continue returned 1
0:00:43.482896000 3226 0x10a15358 DEBUG             decodebin2 gstdecodebin2.c:945:gst_decode_bin_autoplug_continue:<decodebin20> autoplug-continue returns TRUE
0:00:43.483364000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1725:are_raw_caps:<decodebin20> (null)
0:00:43.483826000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1736:are_raw_caps:<decodebin20> Caps are not final caps
0:00:43.484256000 3226 0x10a15358 DEBUG             decodebin2 gstdecodebin2.c:1138:analyze_new_pad:<mpegaudioparse0:src> pad has non-fixed caps delay autoplugging
0:00:43.485659000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1152:analyze_new_pad:<decodebin20> locking group 0x108c05f0 from thread 0x10a15358
0:00:43.486138000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1152:analyze_new_pad:<decodebin20> locked group 0x108c05f0 from thread 0x10a15358
0:00:43.486599000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1155:analyze_new_pad:<decodebin20> Group 0x108c05f0 has now 2 dynamic elements
0:00:43.487056000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1156:analyze_new_pad:<decodebin20> unlocking group 0x108c05f0 from thread 0x10a15358
0:00:43.489747000 3226 0x10a15358 INFO                avidemux gstavidemux.c:1765:gst_avi_demux_parse_odml:<avidemux0> dmlh tag found:
0:00:43.490289000 3226 0x10a15358 INFO                avidemux gstavidemux.c:1766:gst_avi_demux_parse_odml:<avidemux0>  totalframes: 66286
0:00:43.490813000 3226 0x10a15358 DEBUG               avidemux gstavidemux.c:3185:gst_avi_demux_stream_header_pull: elements parsed
0:00:43.491199000 3226 0x10a15358 DEBUG               avidemux gstavidemux.c:3197:gst_avi_demux_stream_header_pull:<avidemux0> skipping junk between header and data, offset=8850
0:00:43.491958000 3226 0x10a15358 DEBUG               avidemux gstavidemux.c:3221:gst_avi_demux_stream_header_pull: tag LIST, size 28
0:00:43.492864000 3226 0x10a15358 DEBUG               avidemux gstavidemux.c:3235:gst_avi_demux_stream_header_pull: got size 28
0:00:43.493944000 3226 0x10a15358 DEBUG               avidemux gstavidemux.c:3221:gst_avi_demux_stream_header_pull: tag JUNK, size 1346
0:00:43.494711000 3226 0x10a15358 DEBUG               avidemux gstavidemux.c:3221:gst_avi_demux_stream_header_pull: tag LIST, size 688111212
0:00:43.495314000 3226 0x10a15358 DEBUG               avidemux gstavidemux.c:3257:gst_avi_demux_stream_header_pull:<avidemux0> skipping done ... (streams=2, stream[0].indexes=(nil))
0:00:43.495895000 3226 0x10a15358 DEBUG               avidemux gstavidemux.c:2000:gst_avi_demux_stream_index: demux stream index at offset 10240
0:00:43.496585000 3226 0x10a15358 DEBUG               avidemux gstavidemux.c:2018:gst_avi_demux_stream_index:<avidemux0> skip LIST chunk, size 688111220
0:00:43.497438000 3226 0x10a15358 DEBUG               avidemux gstavidemux.c:2037:gst_avi_demux_stream_index: index found at offset 688121460
0:00:43.520559000 3226 0x10a15358 INFO                avidemux gstavidemux.c:2045:gst_avi_demux_stream_index: will parse index chunk size 2684576 for tag idx1
0:00:43.521326000 3226 0x10a15358 INFO                avidemux gstavidemux.c:1844:gst_avi_demux_parse_index: Parsing index, nr_entries = 167786
0:00:43.521761000 3226 0x10a15358 DEBUG               avidemux gstavidemux.c:1892:gst_avi_demux_parse_index: index_offset = 10248
0:00:43.790318000 3226 0x1001db40 LOG                 playbin2 gstplaybin2.c:1619:gst_play_bin_get_current_sink:<playbin> (null)
0:00:43.790975000 3226 0x1001db40 LOG                 playbin2 gstplaybin2.c:1619:gst_play_bin_get_current_sink:<playbin> (null)
0:00:43.884318000 3226 0x1001db40 LOG                 playbin2 gstplaybin2.c:1619:gst_play_bin_get_current_sink:<playbin> (null)
0:00:43.884962000 3226 0x1001db40 LOG                 playbin2 gstplaybin2.c:1619:gst_play_bin_get_current_sink:<playbin> (null)
0:00:44.290319000 3226 0x1001db40 LOG                 playbin2 gstplaybin2.c:1619:gst_play_bin_get_current_sink:<playbin> (null)
0:00:44.290983000 3226 0x1001db40 LOG                 playbin2 gstplaybin2.c:1619:gst_play_bin_get_current_sink:<playbin> (null)
0:00:44.383280000 3226 0x1001db40 LOG                 playbin2 gstplaybin2.c:1619:gst_play_bin_get_current_sink:<playbin> (null)
0:00:44.383939000 3226 0x1001db40 LOG                 playbin2 gstplaybin2.c:1619:gst_play_bin_get_current_sink:<playbin> (null)
0:00:44.791305000 3226 0x1001db40 LOG                 playbin2 gstplaybin2.c:1619:gst_play_bin_get_current_sink:<playbin> (null)
0:00:44.791965000 3226 0x1001db40 LOG                 playbin2 gstplaybin2.c:1619:gst_play_bin_get_current_sink:<playbin> (null)
0:00:44.883247000 3226 0x1001db40 LOG                 playbin2 gstplaybin2.c:1619:gst_play_bin_get_current_sink:<playbin> (null)
0:00:44.883899000 3226 0x1001db40 LOG                 playbin2 gstplaybin2.c:1619:gst_play_bin_get_current_sink:<playbin> (null)
playing 4097:0:0:0:0:0:0:0:0:0:/media/hdd/movie/Krieg der Sterne_cd1.avi
eServiceMP3::stop /media/hdd/movie/Cocktail_cd1.avi
0:00:45.057721000 3226 0x1001db40 LOG                 playbin2 gstplaybin2.c:2833:gst_play_bin_change_state:<playbin> setting shutdown flag
0:00:45.058276000 3226 0x1001db40 LOG                 playbin2 gstplaybin2.c:2840:gst_play_bin_change_state:<playbin> dynamic lock taken, we can continue shutdown
0:00:45.059937000 3226 0x1001db40 LOG               decodebin2 gstdecodebin2.c:2698:gst_decode_bin_change_state:<decodebin20> dynlocking from thread 0x1001db40
0:00:45.060442000 3226 0x1001db40 LOG               decodebin2 gstdecodebin2.c:2698:gst_decode_bin_change_state:<decodebin20> dynlocked from thread 0x1001db40
0:00:45.060889000 3226 0x1001db40 LOG               decodebin2 gstdecodebin2.c:2699:gst_decode_bin_change_state:<decodebin20> setting shutdown flag
0:00:45.061351000 3226 0x1001db40 DEBUG             decodebin2 gstdecodebin2.c:2663:unblock_pads:<'':decodepad1> unblocking
0:00:45.061822000 3226 0x1001db40 DEBUG             decodebin2 gstdecodebin2.c:2669:unblock_pads:<'':decodepad1> unblocked
0:00:45.062254000 3226 0x1001db40 LOG               decodebin2 gstdecodebin2.c:2702:gst_decode_bin_change_state:<decodebin20> dynunlocking from thread 0x1001db40
main thread is non-idle! display spinner!
0:00:49.639386000 3226 0x10a15358 INFO                avidemux gstavidemux.c:1959:gst_avi_demux_parse_index: Parsed index, 167786 entries, 101994 keyframes, entry size = 48, total size =    8053728
0:00:49.653492000 3226 0x10a15358 DEBUG               avidemux gstavidemux.c:2057:gst_avi_demux_stream_index:<avidemux0> stream 0: 66286 frames, 655420954 bytes
0:00:49.654357000 3226 0x10a15358 DEBUG               avidemux gstavidemux.c:2057:gst_avi_demux_stream_index:<avidemux0> stream 1: 101500 frames, 31214479 bytes
0:00:50.980965000 3226 0x10a15358 INFO                avidemux gstavidemux.c:2736:gst_avi_demux_calculate_durations_from_index: Stream 0 duration according to header: 0:44:11.440000000
0:00:50.981673000 3226 0x10a15358 INFO                avidemux gstavidemux.c:2756:gst_avi_demux_calculate_durations_from_index: Stream 0 duration according to index: 0:44:11.440000000
0:00:50.982148000 3226 0x10a15358 INFO                avidemux gstavidemux.c:2736:gst_avi_demux_calculate_durations_from_index: Stream 1 duration according to header: 0:44:11.428571428
0:00:50.982623000 3226 0x10a15358 INFO                avidemux gstavidemux.c:2756:gst_avi_demux_calculate_durations_from_index: Stream 1 duration according to index: 0:44:11.428571428
0:00:50.983098000 3226 0x10a15358 INFO                avidemux gstavidemux.c:2786:gst_avi_demux_calculate_durations_from_index: Setting total duration to: 0:44:11.440000000
0:00:50.983553000 3226 0x10a15358 DEBUG               avidemux gstavidemux.c:3286:gst_avi_demux_stream_header_pull:<avidemux0> segment stop 2651440000000
0:00:50.984615000 3226 0x10a15358 DEBUG               avidemux gstavidemux.c:3296:gst_avi_demux_stream_header_pull:<avidemux0> signaling no more pads
0:00:50.985188000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1610:no_more_pads_cb:<avidemux0> No more pads, setting current group to complete
0:00:50.986185000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1856:get_current_group:<decodebin20> locking from thread 0x10a15358
0:00:50.986690000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1856:get_current_group:<decodebin20> locked from thread 0x10a15358
0:00:50.987141000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1860:get_current_group:<decodebin20> locking group 0x108c05f0 from thread 0x10a15358
0:00:50.987628000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1860:get_current_group:<decodebin20> locked group 0x108c05f0 from thread 0x10a15358
0:00:50.988106000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1861:get_current_group:<decodebin20> group 0x108c05f0, complete:0
0:00:50.988584000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1865:get_current_group:<decodebin20> unlocking group 0x108c05f0 from thread 0x10a15358
0:00:50.989055000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1881:get_current_group:<decodebin20> unlocking from thread 0x10a15358
0:00:50.989538000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1883:get_current_group:<decodebin20> Returning group 0x108c05f0
0:00:50.989999000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:2447:gst_decode_group_set_complete:<decodebin20> Setting group 0x108c05f0 to COMPLETE
0:00:50.990466000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:2449:gst_decode_group_set_complete:<decodebin20> locking group 0x108c05f0 from thread 0x10a15358
0:00:50.990944000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:2449:gst_decode_group_set_complete:<decodebin20> locked group 0x108c05f0 from thread 0x10a15358
0:00:50.991428000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:1979:gst_decode_group_check_if_blocked:<decodebin20> group : 0x108c05f0 , ->complete:1 , ->nbdynamic:1
0:00:50.991915000 3226 0x10a15358 DEBUG             decodebin2 gstdecodebin2.c:1983:gst_decode_group_check_if_blocked:<decodebin20> Group isn't complete yet
0:00:50.992350000 3226 0x10a15358 LOG               decodebin2 gstdecodebin2.c:2454:gst_decode_group_set_complete:<decodebin20> unlocking group 0x108c05f0 from thread 0x10a15358
0:00:50.994366000 3226 0x1001db40 DEBUG               avidemux gstavidemux.c:215:gst_avi_demux_reset: AVI: reset
0:00:50.995521000 3226 0x1001db40 LOG               decodebin2 gstdecodebin2.c:1602:pad_removed_cb:<avidemux0:video_00> Pad removed from non-grouped element
0:00:50.996930000 3226 0x1001db40 LOG               decodebin2 gstdecodebin2.c:1602:pad_removed_cb:<avidemux0:audio_00> Pad removed from non-grouped element
0:00:51.003836000 3226 0x1001db40 DEBUG             decodebin2 gstdecodebin2.c:671:gst_decode_bin_remove_groups:<decodebin20> cleaning up
0:00:51.004396000 3226 0x1001db40 DEBUG             decodebin2 gstdecodebin2.c:683:gst_decode_bin_remove_groups:<decodebin20> free group 0x108c05f0
0:00:51.004845000 3226 0x1001db40 LOG               decodebin2 gstdecodebin2.c:2383:gst_decode_group_free:<decodebin20> group 0x108c05f0
0:00:51.005290000 3226 0x1001db40 LOG               decodebin2 gstdecodebin2.c:2385:gst_decode_group_free:<decodebin20> locking group 0x108c05f0 from thread 0x1001db40
0:00:51.006307000 3226 0x1001db40 LOG               decodebin2 gstdecodebin2.c:2385:gst_decode_group_free:<decodebin20> locked group 0x108c05f0 from thread 0x1001db40
0:00:51.009541000 3226 0x1001db40 LOG               decodebin2 gstdecodebin2.c:2316:deactivate_free_recursive:<decodebin20> element:multiqueue0
0:00:51.010524000 3226 0x1001db40 LOG               decodebin2 gstdecodebin2.c:2363:deactivate_free_recursive:<decodebin20> locking from thread 0x1001db40
0:00:51.010991000 3226 0x1001db40 LOG               decodebin2 gstdecodebin2.c:2363:deactivate_free_recursive:<decodebin20> locked from thread 0x1001db40
0:00:51.011444000 3226 0x1001db40 LOG               decodebin2 gstdecodebin2.c:2366:deactivate_free_recursive:<decodebin20> unlocking from thread 0x1001db40
0:00:51.012050000 3226 0x1001db40 LOG               decodebin2 gstdecodebin2.c:2420:gst_decode_group_free:<decodebin20> unlocking group 0x108c05f0 from thread 0x1001db40
0:00:51.012551000 3226 0x1001db40 DEBUG             decodebin2 gstdecodebin2.c:698:gst_decode_bin_remove_groups:<decodebin20> removing last elements
0:00:51.013001000 3226 0x1001db40 DEBUG             decodebin2 gstdecodebin2.c:724:gst_decode_bin_remove_groups:<decodebin20> remove element mpegaudioparse0
0:00:51.014060000 3226 0x1001db40 DEBUG             decodebin2 gstdecodebin2.c:724:gst_decode_bin_remove_groups:<decodebin20> remove element avidemux0
0:00:51.016516000 3226 0x1001db40 DEBUG           uridecodebin gsturidecodebin.c:1965:gst_uri_decode_bin_change_state: paused to ready
0:00:51.016947000 3226 0x1001db40 DEBUG           uridecodebin gsturidecodebin.c:1087:remove_decoders:<uridecodebin0> removing old decoder element
0:00:51.018417000 3226 0x1001db40 DEBUG             decodebin2 gstdecodebin2.c:671:gst_decode_bin_remove_groups:<decodebin20> cleaning up
0:00:51.018881000 3226 0x1001db40 DEBUG             decodebin2 gstdecodebin2.c:698:gst_decode_bin_remove_groups:<decodebin20> removing last elements
0:00:51.020444000 3226 0x1001db40 DEBUG           uridecodebin gsturidecodebin.c:1387:remove_source:<uridecodebin0> removing old src element
0:00:51.021856000 3226 0x1001db40 DEBUG               playbin2 gstplaybin2.c:2779:save_current_group:<playbin> save current group
0:00:51.022416000 3226 0x1001db40 DEBUG               playbin2 gstplaybin2.c:2675:deactivate_group:<playbin> unlinking group 0x10964220
0:00:51.022937000 3226 0x1001db40 DEBUG               playbin2 gstplaybin2.c:2682:deactivate_group:<playbin> unlinking selector audio/x-raw-
0:00:51.023377000 3226 0x1001db40 DEBUG               playbin2 gstplaybin2.c:2682:deactivate_group:<playbin> unlinking selector audio/
0:00:51.023824000 3226 0x1001db40 DEBUG               playbin2 gstplaybin2.c:2682:deactivate_group:<playbin> unlinking selector video/x-raw-
0:00:51.024266000 3226 0x1001db40 DEBUG               playbin2 gstplaybin2.c:2682:deactivate_group:<playbin> unlinking selector video/x-dvd-subpicture
0:00:51.024713000 3226 0x1001db40 DEBUG               playbin2 gstplaybin2.c:2682:deactivate_group:<playbin> unlinking selector video/
0:00:51.025152000 3226 0x1001db40 DEBUG               playbin2 gstplaybin2.c:2682:deactivate_group:<playbin> unlinking selector text/
0:00:51.026130000 3226 0x1001db40 DEBUG           dvbvideosink gstdvbvideosink.c:396:gst_dvbvideosink_dispose:<dvbvideosink0> dispose
0:00:51.026629000 3226 0x1001db40 DEBUG           dvbvideosink gstdvbvideosink.c:427:gst_dvbvideosink_dispose:<dvbvideosink0> state in dispose 2, pending 0

(enigma2:3226): GStreamer-CRITICAL **: 
Trying to dispose element dvbvideosink0, but it is not in the NULL state.
You need to explicitly set elements to the NULL state before
dropping the final reference, to allow them to clean up.

