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 623761 - [neonhttpsrc] unavailable stream sources lock up the system for 12 minutes
[neonhttpsrc] unavailable stream sources lock up the system for 12 minutes
Status: RESOLVED NOTABUG
Product: GStreamer
Classification: Platform
Component: gst-plugins-bad
unspecified
Other Linux
: Normal normal
: git master
Assigned To: GStreamer Maintainers
GStreamer Maintainers
Depends on:
Blocks:
 
 
Reported: 2010-07-07 15:41 UTC by Andreas Frisch
Modified: 2011-06-06 05:47 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
full debug log (124.15 KB, application/x-bzip)
2011-02-11 07:57 UTC, Andreas Frisch
Details

Description Andreas Frisch 2010-07-07 15:41:37 UTC
GST_DEBUG=*:4 gst-launch-0.10  playbin2 uri=http://cctv.ws/1/ssic01/VH1classic

causes
....
0:00:01.019658000 23718   0x416050 DEBUG                basesrc gstbasesrc.c:2673:gst_base_src_start:<source> starting source
0:00:01.436213000 23718   0x416050 INFO             neonhttpsrc gstneonhttpsrc.c:901:gst_neonhttp_src_send_request_and_redirect:<source> Redirecting to 87.239.230.2
0:03:10.436447000 23718   0x416050 INFO             neonhttpsrc gstneonhttpsrc.c:901:gst_neonhttp_src_send_request_and_redirect:<source> Redirecting to 87.239.230.2
0:06:19.436448000 23718   0x416050 INFO             neonhttpsrc gstneonhttpsrc.c:901:gst_neonhttp_src_send_request_and_redirect:<source> Redirecting to 87.239.230.2
0:09:28.436442000 23718   0x416050 INFO             neonhttpsrc gstneonhttpsrc.c:901:gst_neonhttp_src_send_request_and_redirect:<source> Redirecting to 87.239.230.2
0:12:37.437442000 23718   0x416050 WARN             neonhttpsrc gstneonhttpsrc.c:904:gst_neonhttp_src_send_request_and_redirect:<source> Will not redirect, try again with a different URI or redirect location 87.239.230.2
0:12:37.437810000 23718   0x416050 WARN             neonhttpsrc gstneonhttpsrc.c:603:gst_neonhttp_src_start:<source> error: Could not begin request: 5
0:12:37.438151000 23718   0x416050 DEBUG            GST_MESSAGE gstelement.c:1715:gst_element_message_full:<source> start
0:12:37.438905000 23718   0x416050 INFO        GST_ERROR_SYSTEM gstelement.c:1746:gst_element_message_full:<source> posting message: Could not open resource for reading.
0:12:37.439336000 23718   0x416050 DEBUG                GST_BUS gstbus.c:307:gst_bus_post:<bus3> [msg 0x48df48] posting on bus, type error, GstMessageError, gerror=(GstGError)NULL, debug=(string)"gstneonhttpsrc.c\(603\):\ gst_neonhttp_src_start\ \(\):\ /GstPlayBin2:playbin20/GstURIDecodeBin:uridecodebin0/GstNeonhttpSrc:source:\012Could\ not\ begin\ request:\ 5"; from source <source>
0:12:37.440281000 23718   0x416050 DEBUG                    bin gstbin.c:3002:gst_bin_handle_message_func:<uridecodebin0> [msg 0x48df48] handling child source message of type error
0:12:37.440617000 23718   0x416050 DEBUG                    bin gstbin.c:3276:gst_bin_handle_message_func:<uridecodebin0> posting message upward
0:12:37.440892000 23718   0x416050 DEBUG                GST_BUS gstbus.c:307:gst_bus_post:<bus0> [msg 0x48df48] posting on bus, type error, GstMessageError, gerror=(GstGError)NULL, debug=(string)"gstneonhttpsrc.c\(603\):\ gst_neonhttp_src_start\ \(\):\ /GstPlayBin2:playbin20/GstURIDecodeBin:uridecodebin0/GstNeonhttpSrc:source:\012Could\ not\ begin\ request:\ 5"; from source <source>
0:12:37.441464000 23718   0x416050 DEBUG                    bin gstbin.c:3002:gst_bin_handle_message_func:<playbin20> [msg 0x48df48] handling child source message of type error
0:12:37.441752000 23718   0x416050 DEBUG                    bin gstbin.c:3276:gst_bin_handle_message_func:<playbin20> posting message upward
0:12:37.442022000 23718   0x416050 DEBUG                GST_BUS gstbus.c:307:gst_bus_post:<bus1> [msg 0x48df48] posting on bus, type error, GstMessageError, gerror=(GstGError)NULL, debug=(string)"gstneonhttpsrc.c\(603\):\ gst_neonhttp_src_start\ \(\):\ /GstPlayBin2:playbin20/GstURIDecodeBin:uridecodebin0/GstNeonhttpSrc:source:\012Could\ not\ begin\ request:\ 5"; from source <source>
0:12:37.442557000 23718   0x416050 DEBUG                GST_BUS gstbus.c:337:gst_bus_post:<bus1> [msg 0x48df48] pushing on async queue
0:12:37.442842000 23718   0x416050 DEBUG                GST_BUS gstbus.c:342:gst_bus_post:<bus1> [msg 0x48df48] pushed on async queue
0:12:37.443128000 23718   0x416050 DEBUG                GST_BUS gstbus.c:333:gst_bus_post:<bus0> [msg 0x48df48] dropped
0:12:37.443427000 23718   0x416050 DEBUG                GST_BUS gstbus.c:333:gst_bus_post:<bus3> [msg 0x48df48] dropped
0:12:37.443701000 23718   0x416050 INFO        GST_ERROR_SYSTEM gstelement.c:1769:gst_element_message_full:<source> posted error message: Could not open resource for reading.
...

setting the automatic-redirect property to false is not possible because we're actually working with playbin2

using souphttpsrc is not an option either because we have very limited resources on the embedded system
Comment 1 Tim-Philipp Müller 2010-07-07 15:45:10 UTC
neonhttpsrc lives in bad, for a reason, moving bug there.
Comment 2 Andreas Frisch 2010-07-07 20:53:30 UTC
also happens with soup ,_, 

root@dm500hd:/testProgs# GST_DEBUG=*:3,*soup*:5 gst-launch playbin2 uri=http://cctv.ws/1/ssic01/VH1classi                         
0:00:00.001319000 19226   0x416050 INFO                GST_INIT gst.c:610:init_pre: Initializing GStreamer Core Library version 0.10.29
0:00:00.042306000 19226   0x416050 INFO                GST_INIT gst.c:611:init_pre: Using library installed in /usr/lib
0:00:00.042854000 19226   0x416050 INFO                GST_INIT gst.c:621:init_pre: Linux dm500hd 2.6.18-7.3-dm500hd #1 SMP Thu May 20 16:51:01 CEST 2010 7405b0-smp
0:00:00.044264000 19226   0x416050 INFO                GST_INIT gstquery.c:105:_gst_query_initialize: init queries
0:00:00.058978000 19226   0x416050 INFO                GST_INIT gstmessage.c:73:_gst_message_initialize: init messages
0:00:00.062197000 19226   0x416050 INFO      GST_PLUGIN_LOADING gstplugin.c:337:_gst_plugin_initialize: registering 0 static plugins
0:00:00.064680000 19226   0x416050 INFO      GST_PLUGIN_LOADING gstplugin.c:253:gst_plugin_register_static: registered static plugin "staticelements"
0:00:00.065012000 19226   0x416050 INFO      GST_PLUGIN_LOADING gstplugin.c:255:gst_plugin_register_static: added static plugin "staticelements", result: 1
0:00:00.074278000 19226   0x416050 INFO            GST_REGISTRY gstregistry.c:1537:ensure_current_registry: reading registry cache: /home/root/.gstreamer-0.10/registry.mipsel.bin
0:00:00.168208000 19226   0x416050 INFO            GST_REGISTRY gstregistrybinary.c:583:gst_registry_binary_read_cache: loaded /home/root/.gstreamer-0.10/registry.mipsel.bin in 0.093377 seconds
0:00:00.169106000 19226   0x416050 INFO            GST_REGISTRY gstregistry.c:1407:scan_and_update_registry: Validating plugins from registry cache: /home/root/.gstreamer-0.10/registry.mipsel.bin
0:00:00.209447000 19226   0x416050 INFO            GST_REGISTRY gstregistry.c:1499:scan_and_update_registry: Registry cache has not changed
0:00:00.209781000 19226   0x416050 INFO            GST_REGISTRY gstregistry.c:1566:ensure_current_registry: registry reading and updating done, result = 1
0:00:00.209993000 19226   0x416050 INFO                GST_INIT gst.c:796:init_post: GLib runtime version: 2.22.4

0:00:00.210329000 19226   0x416050 INFO                GST_INIT gst.c:798:init_post: GLib headers version: 2.22.4

0:00:00.210981000 19226   0x416050 INFO            GST_PIPELINE gstparse.c:291:gst_parse_launch_full: parsing pipeline description 'playbin2 uri=http://cctv.ws/1/ssic01/VH1classi '
0:00:00.238081000 19226   0x416050 INFO      GST_PLUGIN_LOADING gstplugin.c:659:gst_plugin_load_file: plugin "/usr/lib/gstreamer-0.10/libgstplaybin.so" loaded
0:00:00.238873000 19226   0x416050 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:363:gst_element_factory_create: creating element "playbin2"
Setting pipeline to PAUSED ...
0:00:00.253082000 19226   0x416050 INFO              GST_STATES gstelement.c:2221:gst_element_continue_state:<playsink0> completed state change to READY
0:00:00.253396000 19226   0x416050 INFO              GST_STATES gstelement.c:2234:gst_element_continue_state:<playsink0> posting state-changed NULL to READY
0:00:00.254142000 19226   0x416050 INFO              GST_STATES gstbin.c:2428:gst_bin_change_state_func:<playbin20> child 'playsink0' changed state to 2(READY) successfully
0:00:00.254503000 19226   0x416050 INFO              GST_STATES gstelement.c:2194:gst_element_continue_state:<playbin20> committing state from NULL to READY, pending PAUSED, next PAUSED
0:00:00.254992000 19226   0x416050 INFO              GST_STATES gstelement.c:2203:gst_element_continue_state:<playbin20> continue state change READY to PAUSED, final PAUSED
0:00:00.260397000 19226   0x416050 INFO      GST_PLUGIN_LOADING gstplugin.c:659:gst_plugin_load_file: plugin "/usr/lib/gstreamer-0.10/libgstdecodebin2.so" loaded
0:00:00.260759000 19226   0x416050 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:363:gst_element_factory_create: creating element "uridecodebin"
0:00:00.267801000 19226   0x416050 INFO              GST_STATES gstelement.c:2221:gst_element_continue_state:<uridecodebin0> completed state change to READY
0:00:00.268147000 19226   0x416050 INFO              GST_STATES gstelement.c:2234:gst_element_continue_state:<uridecodebin0> posting state-changed NULL to READY
0:00:00.268800000 19226   0x416050 INFO                playsink gstplaysink.c:893:do_async_start:<playsink0> Sending async_start message
0:00:00.269420000 19226   0x416050 INFO              GST_STATES gstbin.c:2434:gst_bin_change_state_func:<playbin20> child 'playsink0' is changing state asynchronously to PAUSED
0:00:00.350020000 19226   0x416050 INFO      GST_PLUGIN_LOADING gstplugin.c:659:gst_plugin_load_file: plugin "/usr/lib/gstreamer-0.10/libgstsouphttpsrc.so" loaded
0:00:00.350387000 19226   0x416050 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:361:gst_element_factory_create: creating element "souphttpsrc" named "source"
0:00:00.354195000 19226   0x416050 INFO        GST_ELEMENT_PADS gstelement.c:698:gst_element_add_pad:<GstBaseSrc@0x49e020> adding pad 'src'
0:00:00.364274000 19226   0x416050 INFO      GST_PLUGIN_LOADING gstplugin.c:659:gst_plugin_load_file: plugin "/usr/lib/gstreamer-0.10/libgstcoreelements.so" loaded
0:00:00.364667000 19226   0x416050 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:363:gst_element_factory_create: creating element "typefind"
0:00:00.367350000 19226   0x416050 INFO        GST_ELEMENT_PADS gstelement.c:698:gst_element_add_pad:<GstTypeFindElement@0x4a1828> adding pad 'sink'
0:00:00.368941000 19226   0x416050 INFO        GST_ELEMENT_PADS gstelement.c:698:gst_element_add_pad:<GstTypeFindElement@0x4a1828> adding pad 'src'
0:00:00.369796000 19226   0x416050 INFO        GST_ELEMENT_PADS gstutils.c:1585:gst_element_link_pads: trying to link element source:(any) to element typefindelement0:sink
0:00:00.370099000 19226   0x416050 INFO        GST_ELEMENT_PADS gstelement.c:944:gst_element_get_static_pad: found pad typefindelement0:sink
0:00:00.370396000 19226   0x416050 INFO                GST_PADS gstutils.c:1493:prepare_link_maybe_ghosting: source and typefindelement0 in same bin, no need for ghost pads
0:00:00.370948000 19226   0x416050 INFO                GST_PADS gstpad.c:1886:gst_pad_link_prepare: trying to link source:src and typefindelement0:sink
0:00:00.371286000 19226   0x416050 INFO                GST_PADS gstpad.c:2059:gst_pad_link: linked source:src and typefindelement0:sink, successful
0:00:00.372788000 19226   0x416050 INFO              GST_STATES gstelement.c:2194:gst_element_continue_state:<typefindelement0> committing state from NULL to READY, pending PAUSED, next PAUSED
0:00:00.373298000 19226   0x416050 INFO              GST_STATES gstelement.c:2203:gst_element_continue_state:<typefindelement0> continue state change READY to PAUSED, final PAUSED
0:00:00.373821000 19226   0x416050 INFO              GST_STATES gstelement.c:2221:gst_element_continue_state:<typefindelement0> completed state change to PAUSED
0:00:00.374127000 19226   0x416050 INFO              GST_STATES gstelement.c:2234:gst_element_continue_state:<typefindelement0> posting state-changed READY to PAUSED
0:00:00.374645000 19226   0x416050 INFO              GST_STATES gstbin.c:2428:gst_bin_change_state_func:<uridecodebin0> child 'typefindelement0' changed state to 3(PAUSED) successfully
0:00:00.375004000 19226   0x416050 INFO              GST_STATES gstelement.c:2194:gst_element_continue_state:<source> committing state from NULL to READY, pending PAUSED, next PAUSED
0:00:00.375479000 19226   0x416050 INFO              GST_STATES gstelement.c:2203:gst_element_continue_state:<source> continue state change READY to PAUSED, final PAUSED
0:00:00.375873000 19226   0x416050 DEBUG            souphttpsrc gstsouphttpsrc.c:1224:gst_soup_http_src_start:<source> start("http://cctv.ws/1/ssic01/VH1classi")
0:00:00.381337000 19226   0x416050 DEBUG            souphttpsrc gstsouphttpsrc.c:1334:gst_soup_http_src_get_size:<source> get_size() = FALSE
0:00:00.381806000 19226   0x416050 DEBUG            souphttpsrc gstsouphttpsrc.c:1315:gst_soup_http_src_unlock_stop:<source> unlock_stop()
0:00:00.382122000 19226   0x416050 DEBUG            souphttpsrc gstsouphttpsrc.c:1351:gst_soup_http_src_do_seek:<source> do_seek(0)
0:00:00.382467000 19226   0x416050 INFO               GST_EVENT gstevent.c:605:gst_event_new_new_segment_full: creating newsegment update 0, rate 1.000000, format bytes, start 0, stop -1, position 0
0:00:00.384455000 19226   0x416050 INFO              GST_STATES gstelement.c:2221:gst_element_continue_state:<source> completed state change to PAUSED
0:00:00.384823000 19226   0x416050 INFO              GST_STATES gstelement.c:2234:gst_element_continue_state:<source> posting state-changed READY to PAUSED
0:00:00.386877000 19226   0x416050 INFO              GST_STATES gstbin.c:2428:gst_bin_change_state_func:<uridecodebin0> child 'source' changed state to 3(PAUSED) successfully
0:00:00.387469000 19226   0x416050 INFO              GST_STATES gstelement.c:2221:gst_element_continue_state:<uridecodebin0> completed state change to PAUSED
0:00:00.387886000 19226   0x416050 INFO              GST_STATES gstelement.c:2234:gst_element_continue_state:<uridecodebin0> posting state-changed READY to PAUSED
0:00:00.388479000 19226   0x416050 INFO              GST_STATES gstbin.c:2428:gst_bin_change_state_func:<playbin20> child 'uridecodebin0' changed state to 3(PAUSED) successfully
Pipeline is PREROLLING ...
0:00:00.391673000 19226   0x4a33a0 DEBUG            souphttpsrc gstsouphttpsrc.c:1148:gst_soup_http_src_build_message:<source> request headers:
0:00:00.392725000 19226   0x4a33a0 DEBUG            souphttpsrc gstsouphttpsrc.c:714:gst_soup_http_src_headers_foreach:<source>  Connection: close
0:00:00.393228000 19226   0x4a33a0 DEBUG            souphttpsrc gstsouphttpsrc.c:714:gst_soup_http_src_headers_foreach:<source>  icy-metadata: 1
0:00:00.393641000 19226   0x4a33a0 DEBUG            souphttpsrc gstsouphttpsrc.c:714:gst_soup_http_src_headers_foreach:<source>  transferMode.dlna.org: Streaming
0:00:00.394075000 19226   0x4a33a0 DEBUG            souphttpsrc gstsouphttpsrc.c:1197:gst_soup_http_src_create:<source> Queueing connection request
0:00:00.834887000 19226   0x4a33a0 DEBUG            souphttpsrc gstsouphttpsrc.c:726:gst_soup_http_src_got_headers_cb:<source> got headers:
0:00:00.835243000 19226   0x4a33a0 DEBUG            souphttpsrc gstsouphttpsrc.c:714:gst_soup_http_src_headers_foreach:<source>  Connection: close
0:00:00.835474000 19226   0x4a33a0 DEBUG            souphttpsrc gstsouphttpsrc.c:714:gst_soup_http_src_headers_foreach:<source>  Date: Wed, 07 Jul 2010 20:49:29 GMT
0:00:00.835853000 19226   0x4a33a0 DEBUG            souphttpsrc gstsouphttpsrc.c:714:gst_soup_http_src_headers_foreach:<source>  Server: Microsoft-IIS/6.0
0:00:00.836126000 19226   0x4a33a0 DEBUG            souphttpsrc gstsouphttpsrc.c:714:gst_soup_http_src_headers_foreach:<source>  X-Powered-By: ASP.NET
0:00:00.836386000 19226   0x4a33a0 DEBUG            souphttpsrc gstsouphttpsrc.c:714:gst_soup_http_src_headers_foreach:<source>  X-Robots-Tag: noarchive
0:00:00.836684000 19226   0x4a33a0 DEBUG            souphttpsrc gstsouphttpsrc.c:714:gst_soup_http_src_headers_foreach:<source>  P3P: CP="ADMa OUR COM NAV NID DSP NOI COR", policyref="/w3c/p3p.xml"
0:00:00.836973000 19226   0x4a33a0 DEBUG            souphttpsrc gstsouphttpsrc.c:714:gst_soup_http_src_headers_foreach:<source>  Location: http://87.239.230.2:8019
0:00:00.837241000 19226   0x4a33a0 DEBUG            souphttpsrc gstsouphttpsrc.c:714:gst_soup_http_src_headers_foreach:<source>  Content-Length: 145
0:00:00.837501000 19226   0x4a33a0 DEBUG            souphttpsrc gstsouphttpsrc.c:714:gst_soup_http_src_headers_foreach:<source>  Content-Type: text/html
0:00:00.837790000 19226   0x4a33a0 DEBUG            souphttpsrc gstsouphttpsrc.c:714:gst_soup_http_src_headers_foreach:<source>  Cache-control: max-age=3600, public
0:00:00.838128000 19226   0x4a33a0 DEBUG            souphttpsrc gstsouphttpsrc.c:732:gst_soup_http_src_got_headers_cb:<source> 302 redirect to "http://87.239.230.2:8019"
0:00:00.838487000 19226   0x4a33a0 DEBUG            souphttpsrc gstsouphttpsrc.c:965:gst_soup_http_src_chunk_allocator:<source> alloc 4096 bytes <= 0
0:00:00.839155000 19226   0x4a33a0 DEBUG            souphttpsrc gstsouphttpsrc.c:965:gst_soup_http_src_chunk_allocator:<source> alloc 4096 bytes <= 4294967151
0:03:09.843374000 19226   0x4a33a0 DEBUG            souphttpsrc gstsouphttpsrc.c:898:gst_soup_http_src_finished_cb:<source> finished
0:03:09.843749000 19226   0x4a33a0 WARN             souphttpsrc gstsouphttpsrc.c:914:gst_soup_http_src_finished_cb:<source> error: Cannot connect to destination
0:03:09.843987000 19226   0x4a33a0 WARN             souphttpsrc gstsouphttpsrc.c:914:gst_soup_http_src_finished_cb:<source> error: libsoup status code 4
0:03:09.844710000 19226   0x4a33a0 INFO        GST_ERROR_SYSTEM gstelement.c:1746:gst_element_message_full:<source> posting message: Cannot connect to destination
0:03:09.845297000 19226   0x4a33a0 INFO        GST_ERROR_SYSTEM gstelement.c:1769:gst_element_message_full:<source> posted error message: Cannot connect to destination
0:03:09.846209000 19226   0x4a33a0 DEBUG            souphttpsrc gstsouphttpsrc.c:1044:gst_soup_http_src_response_cb:<source> got response 4: Cannot connect to destination
0:03:09.846512000 19226   0x4a33a0 WARN             souphttpsrc gstsouphttpsrc.c:1079:gst_soup_http_src_parse_status:<source> error: "http://cctv.ws/1/ssic01/VH1classi": Cannot connect to destination
0:03:09.846858000 19226   0x4a33a0 WARN             souphttpsrc gstsouphttpsrc.c:1079:gst_soup_http_src_parse_status:<source> error: libsoup status code 4
ERROR: from element /GstPlayBin2:playbin20/GstURIDecodeBin:uridecodebin0/GstSoupHTTPSrc:source: Cannot connect to destination
Additional debug info:
gstsouphttpsrc.c(914): gst_soup_http_src_finished_cb (): /GstPlayBin2:playbin20/GstURIDecodeBin:uridecodebin0/GstSoupHTTPSrc:source:
libsoup status code 4
0:03:09.847403000 19226   0x4a33a0 INFO        GST_ERROR_SYSTEM gstelement.c:1746:gst_element_message_full:<source> posting message: "http://cctv.ws/1/ssic01/VH1classi": Cannot connect to destination
ERROR: pipeline doesn't want to preroll.
Setting pipeline to NULL ...
0:03:09.848000000 19226   0x4a33a0 INFO        GST_ERROR_SYSTEM gstelement.c:1769:gst_element_message_full:<source> posted error message: "http://cctv.ws/1/ssic01/VH1classi": Cannot connect to destination
0:03:09.848799000 19226   0x416050 INFO                playsink gstplaysink.c:905:do_async_done:<playsink0> Sending async_done message
0:03:09.848961000 19226   0x4a33a0 INFO                 basesrc gstbasesrc.c:2372:gst_base_src_loop:<source> pausing after gst_base_src_get_range() = error
0:03:09.849171000 19226   0x416050 INFO              GST_STATES gstelement.c:2221:gst_element_continue_state:<playsink0> completed state change to READY
0:03:09.849373000 19226   0x4a33a0 WARN                 basesrc gstbasesrc.c:2543:gst_base_src_loop:<source> error: Internal data flow error.
0:03:09.849432000 19226   0x416050 INFO              GST_STATES gstelement.c:2234:gst_element_continue_state:<playsink0> posting state-changed READY to READY
0:03:09.849607000 19226   0x4a33a0 WARN                 basesrc gstbasesrc.c:2543:gst_base_src_loop:<source> error: streaming task paused, reason error (-5)
0:03:09.849888000 19226   0x416050 INFO              GST_STATES gstbin.c:2428:gst_bin_change_state_func:<playbin20> child 'playsink0' changed state to 2(READY) successfully
0:03:09.850149000 19226   0x4a33a0 INFO        GST_ERROR_SYSTEM gstelement.c:1746:gst_element_message_full:<source> posting message: Internal data flow error.
0:03:09.850854000 19226   0x416050 INFO              GST_STATES gstelement.c:2221:gst_element_continue_state:<typefindelement0> completed state change to READY
0:03:09.850707000 19226   0x4a33a0 INFO        GST_ERROR_SYSTEM gstelement.c:1769:gst_element_message_full:<source> posted error message: Internal data flow error.
0:03:09.851185000 19226   0x416050 INFO              GST_STATES gstelement.c:2234:gst_element_continue_state:<typefindelement0> posting state-changed PAUSED to READY
0:03:09.851459000 19226   0x4a33a0 INFO               GST_EVENT gstpad.c:5093:gst_pad_send_event:<typefindelement0:sink> Received event on flushing pad. Discarding
0:03:09.851727000 19226   0x416050 INFO              GST_STATES gstbin.c:2428:gst_bin_change_state_func:<uridecodebin0> child 'typefindelement0' changed state to 2(READY) successfully
0:03:09.852106000 19226   0x416050 DEBUG            souphttpsrc gstsouphttpsrc.c:1300:gst_soup_http_src_unlock:<source> unlock()
0:03:09.852318000 19226   0x416050 DEBUG            souphttpsrc gstsouphttpsrc.c:1315:gst_soup_http_src_unlock_stop:<source> unlock_stop()
0:03:09.853494000 19226   0x416050 DEBUG            souphttpsrc gstsouphttpsrc.c:1276:gst_soup_http_src_stop:<source> stop()
0:03:09.854556000 19226   0x416050 INFO              GST_STATES gstelement.c:2221:gst_element_continue_state:<source> completed state change to READY
0:03:09.854824000 19226   0x416050 INFO              GST_STATES gstelement.c:2234:gst_element_continue_state:<source> posting state-changed PAUSED to READY
0:03:09.855221000 19226   0x416050 INFO              GST_STATES gstbin.c:2428:gst_bin_change_state_func:<uridecodebin0> child 'source' changed state to 2(READY) successfully
0:03:09.855754000 19226   0x416050 INFO              GST_STATES gstelement.c:2221:gst_element_continue_state:<source> completed state change to NULL
0:03:09.855978000 19226   0x416050 INFO              GST_STATES gstelement.c:2234:gst_element_continue_state:<source> posting state-changed READY to NULL
0:03:09.856402000 19226   0x416050 INFO        GST_ELEMENT_PADS gstpad.c:1680:gst_pad_unlink: unlinking source:src(0x4a0010) and typefindelement0:sink(0x4a00d8)
0:03:09.856814000 19226   0x416050 INFO        GST_ELEMENT_PADS gstpad.c:1723:gst_pad_unlink: unlinked source:src and typefindelement0:sink
0:03:09.857303000 19226   0x416050 INFO           GST_PARENTAGE gstbin.c:1373:gst_bin_remove_func:<uridecodebin0> removed child "source"
0:03:09.857899000 19226   0x416050 INFO              GST_STATES gstelement.c:2221:gst_element_continue_state:<typefindelement0> completed state change to NULL
0:03:09.858186000 19226   0x416050 INFO              GST_STATES gstelement.c:2234:gst_element_continue_state:<typefindelement0> posting state-changed READY to NULL
0:03:09.858708000 19226   0x416050 INFO           GST_PARENTAGE gstbin.c:1373:gst_bin_remove_func:<uridecodebin0> removed child "typefindelement0"
0:03:09.859183000 19226   0x416050 INFO              GST_STATES gstelement.c:2221:gst_element_continue_state:<uridecodebin0> completed state change to READY
0:03:09.859437000 19226   0x416050 INFO              GST_STATES gstelement.c:2234:gst_element_continue_state:<uridecodebin0> posting state-changed PAUSED to READY
0:03:09.859867000 19226   0x416050 INFO              GST_STATES gstbin.c:2428:gst_bin_change_state_func:<playbin20> child 'uridecodebin0' changed state to 2(READY) successfully
0:03:09.860557000 19226   0x416050 INFO           GST_PARENTAGE gstbin.c:1373:gst_bin_remove_func:<playbin20> removed child "uridecodebin0"
0:03:09.861019000 19226   0x416050 INFO              GST_STATES gstelement.c:2194:gst_element_continue_state:<playbin20> committing state from READY to READY, pending NULL, next NULL
0:03:09.861392000 19226   0x416050 INFO              GST_STATES gstelement.c:2203:gst_element_continue_state:<playbin20> continue state change READY to NULL, final NULL
0:03:09.862204000 19226   0x416050 INFO              GST_STATES gstelement.c:2221:gst_element_continue_state:<uridecodebin0> completed state change to NULL
0:03:09.862533000 19226   0x416050 INFO              GST_STATES gstelement.c:2234:gst_element_continue_state:<uridecodebin0> posting state-changed READY to NULL
0:03:09.863309000 19226   0x416050 INFO              GST_STATES gstelement.c:2221:gst_element_continue_state:<playsink0> completed state change to NULL
0:03:09.863575000 19226   0x416050 INFO              GST_STATES gstelement.c:2234:gst_element_continue_state:<playsink0> posting state-changed READY to NULL
0:03:09.864029000 19226   0x416050 INFO              GST_STATES gstbin.c:2428:gst_bin_change_state_func:<playbin20> child 'playsink0' changed state to 1(NULL) successfully
0:03:09.865012000 19226   0x416050 INFO         GST_REFCOUNTING gstelement.c:2835:gst_element_dispose:<typefindelement0> dispose
0:03:09.865331000 19226   0x416050 INFO        GST_ELEMENT_PADS gstelement.c:816:gst_element_remove_pad:<typefindelement0> removing pad 'src'
0:03:09.865888000 19226   0x416050 INFO        GST_ELEMENT_PADS gstelement.c:816:gst_element_remove_pad:<typefindelement0> removing pad 'sink'
0:03:09.866338000 19226   0x416050 INFO         GST_REFCOUNTING gstelement.c:2859:gst_element_dispose:<typefindelement0> parent class dispose
0:03:09.866668000 19226   0x416050 INFO         GST_REFCOUNTING gstelement.c:2890:gst_element_finalize:<typefindelement0> finalize
0:03:09.866935000 19226   0x416050 INFO         GST_REFCOUNTING gstelement.c:2901:gst_element_finalize:<typefindelement0> finalize parent
0:03:09.867345000 19226   0x416050 INFO         GST_REFCOUNTING gstelement.c:2835:gst_element_dispose:<uridecodebin0> dispose
0:03:09.867600000 19226   0x416050 INFO         GST_REFCOUNTING gstelement.c:2859:gst_element_dispose:<uridecodebin0> parent class dispose
0:03:09.868116000 19226   0x416050 INFO         GST_REFCOUNTING gstelement.c:2890:gst_element_finalize:<uridecodebin0> finalize
0:03:09.868375000 19226   0x416050 INFO         GST_REFCOUNTING gstelement.c:2901:gst_element_finalize:<uridecodebin0> finalize parent
0:03:09.868816000 19226   0x416050 INFO              GST_STATES gstelement.c:2221:gst_element_continue_state:<playbin20> completed state change to NULL
0:03:09.869078000 19226   0x416050 INFO              GST_STATES gstelement.c:2234:gst_element_continue_state:<playbin20> posting state-changed READY to NULL
0:03:09.869487000 19226   0x416050 INFO              GST_STATES gstbin.c:1695:gst_bin_get_state_func:<playbin20> getting state
Freeing pipeline ...
0:03:09.869957000 19226   0x416050 INFO           GST_PARENTAGE gstbin.c:1373:gst_bin_remove_func:<playbin20> removed child "playsink0"
0:03:09.870520000 19226   0x416050 INFO         GST_REFCOUNTING gstelement.c:2835:gst_element_dispose:<playsink0> dispose
0:03:09.870802000 19226   0x416050 INFO         GST_REFCOUNTING gstelement.c:2859:gst_element_dispose:<playsink0> parent class dispose
0:03:09.871166000 19226   0x416050 INFO         GST_REFCOUNTING gstelement.c:2890:gst_element_finalize:<playsink0> finalize
0:03:09.871485000 19226   0x416050 INFO         GST_REFCOUNTING gstelement.c:2901:gst_element_finalize:<playsink0> finalize parent
0:03:09.871795000 19226   0x416050 INFO         GST_REFCOUNTING gstelement.c:2835:gst_element_dispose:<playbin20> dispose
0:03:09.872122000 19226   0x416050 INFO         GST_REFCOUNTING gstelement.c:2859:gst_element_dispose:<playbin20> parent class dispose
0:03:09.872433000 19226   0x416050 INFO         GST_REFCOUNTING gstelement.c:2835:gst_element_dispose:<source> dispose
0:03:09.872700000 19226   0x416050 INFO        GST_ELEMENT_PADS gstelement.c:816:gst_element_remove_pad:<source> removing pad 'src'
0:03:09.873077000 19226   0x416050 INFO         GST_REFCOUNTING gstelement.c:2859:gst_element_dispose:<source> parent class dispose
0:03:09.873361000 19226   0x416050 DEBUG            souphttpsrc gstsouphttpsrc.c:364:gst_soup_http_src_finalize:<source> finalize
0:03:09.873585000 19226   0x416050 INFO         GST_REFCOUNTING gstelement.c:2890:gst_element_finalize:<source> finalize
0:03:09.873873000 19226   0x416050 INFO         GST_REFCOUNTING gstelement.c:2901:gst_element_finalize:<source> finalize parent
0:03:09.874341000 19226   0x416050 INFO         GST_REFCOUNTING gstelement.c:2890:gst_element_finalize:<playbin20> finalize
0:03:09.874588000 19226   0x416050 INFO         GST_REFCOUNTING gstelement.c:2901:gst_element_finalize:<playbin20> finalize parent
0:03:09.874910000 19226   0x416050 INFO                GST_INIT gst.c:1014:gst_deinit: deinitializing GStreamer
0:03:09.903355000 19226   0x416050 INFO                GST_INIT gst.c:1116:gst_deinit: deinitialized GStreamer
root@dm500hd:/testProgs#
Comment 3 Tim-Philipp Müller 2010-09-23 17:10:05 UTC
 - how does this "lock up the system"?

 - for me souphttpsrc and gnomevfssrc
   work fine (timeout within 20secs), only
   neonhttpsrc takes a bit longer to timeout,
   but you can shorten set by setting the two
   *-timeout properties and/or adjusting the
   system defaults



tpm@zingle:~/gst/git/gst-plugins-good$ time gst-launch-0.10  playbin2 uri=http://cctv.ws/1/ssic01/VH1classic
Setting pipeline to PAUSED ...
Pipeline is PREROLLING ...
ERROR: from element /GstPlayBin2:playbin20/GstURIDecodeBin:uridecodebin0/GstSoupHTTPSrc:source: Cannot connect to destination
Additional debug info:
gstsouphttpsrc.c(915): gst_soup_http_src_finished_cb (): /GstPlayBin2:playbin20/GstURIDecodeBin:uridecodebin0/GstSoupHTTPSrc:source:
libsoup status code 4
ERROR: pipeline doesn't want to preroll.
Setting pipeline to NULL ...
Freeing pipeline ...

real	0m21.878s
user	0m0.084s
sys	0m0.104s

tpm@zingle:~/gst/git/gst-plugins-good$ time gst-launch-0.10  playbin2 uri=http://cctv.ws/1/ssic01/VH1classic
Setting pipeline to PAUSED ...
ERROR: Pipeline doesn't want to pause.
ERROR: from element /GstURIDecodeBin:uridecodebin0/GstGnomeVFSSrc:source: Could not open resource for reading.
Additional debug info:
gstgnomevfssrc.c(861): gst_gnome_vfs_src_start (): /GstPlayBin2:playbin20/GstURIDecodeBin:uridecodebin0/GstGnomeVFSSrc:source:
Could not open vfs file "http://cctv.ws/1/ssic01/VH1classic" for reading: Timeout reached (46)
Setting pipeline to NULL ...
Freeing pipeline ...

real	0m22.121s
user	0m0.096s
sys	0m0.132s

tpm@zingle:~/gst/git/gst-plugins-good$ time gst-launch-0.10  playbin2 uri=http://cctv.ws/1/ssic01/VH1classic
Setting pipeline to PAUSED ...
ERROR: Pipeline doesn't want to pause.
ERROR: from element /GstURIDecodeBin:uridecodebin0/GstNeonhttpSrc:source: Could not open resource for reading.
Additional debug info:
gstneonhttpsrc.c(671): gst_neonhttp_src_start (): /GstPlayBin2:playbin20/GstURIDecodeBin:uridecodebin0/GstNeonhttpSrc:source:
Could not begin request: 5
Setting pipeline to NULL ...
Freeing pipeline ...

real	1m30.317s
user	0m0.096s
sys	0m0.148s


$ time gst-launch-0.10 neonhttpsrc location=http://cctv.ws/1/ssic01/VH1classic connect-timeout=5 read-timeout=5 ! fakesink -v
Setting pipeline to PAUSED ...
ERROR: Pipeline doesn't want to pause.
ERROR: from element /GstPipeline:pipeline0/GstNeonhttpSrc:neonhttpsrc0: Could not open resource for reading.
Additional debug info:
gstneonhttpsrc.c(671): gst_neonhttp_src_start (): /GstPipeline:pipeline0/GstNeonhttpSrc:neonhttpsrc0:
Could not begin request: 6
Setting pipeline to NULL ...
Freeing pipeline ...

real	0m5.563s
user	0m0.072s
sys	0m0.072s
Comment 4 Tobias Mueller 2011-02-11 01:10:50 UTC
Closing this bug report as no further information has been provided. Please feel free to reopen this bug if you can provide the information asked for.
Thanks!
Comment 5 Andreas Frisch 2011-02-11 07:57:31 UTC
Created attachment 180639 [details]
full debug log

GST_DEBUG_NO_COLOR=1 GST_DEBUG_DUMP_DOT_DIR=/dream/testProgs/ GST_DEBUG=*:5 gst-launch-0.10 playbin2 uri=http://cctv.ws/1/ssic01/VH1classic >httpsrc_unavailable.log 2>&1
Comment 6 Andreas Frisch 2011-02-11 07:59:34 UTC
it happens both on our mips box and on a amd64 ubuntu pc
the "locking up" is pretty much being stuck in a poll loop...
poll([{fd=3, events=POLLIN}, {fd=11, events=POLLIN|POLLPRI}, {fd=13, events=POLLIN|POLLPRI}, {fd=14, events=POLLIN|POLLPRI}, {fd=15, events=POLLIN|POLLPRI}], 5, 0) = 0 (Timeout)
poll([{fd=3, events=POLLIN}, {fd=11, events=POLLIN|POLLPRI}, {fd=13, events=POLLIN|POLLPRI}, {fd=14, events=POLLIN|POLLPRI}, {fd=15, events=POLLIN|POLLPRI}], 5, 250) = 0 (Timeout)
poll([{fd=3, events=POLLIN}, {fd=11, events=POLLIN|POLLPRI}, {fd=13, events=POLLIN|POLLPRI}, {fd=14, events=POLLIN|POLLPRI}, {fd=15, events=POLLIN|POLLPRI}], 5, 249) = 0 (Timeout)
poll([{fd=3, events=POLLIN}, {fd=11, events=POLLIN|POLLPRI}, {fd=13, events=POLLIN|POLLPRI}, {fd=14, events=POLLIN|POLLPRI}, {fd=15, events=POLLIN|POLLPRI}], 5, 0) = 0 (Timeout)
poll([{fd=3, events=POLLIN}, {fd=11, events=POLLIN|POLLPRI}, {fd=13, events=POLLIN|POLLPRI}, {fd=14, events=POLLIN|POLLPRI}, {fd=15, events=POLLIN|POLLPRI}], 5, 249) = 0 (Timeout)
poll([{fd=3, events=POLLIN}, {fd=11, events=POLLIN|POLLPRI}, {fd=13, events=POLLIN|POLLPRI}, {fd=14, events=POLLIN|POLLPRI}, {fd=15, events=POLLIN|POLLPRI}], 5, 0) = 0 (Timeout)
poll([{fd=3, events=POLLIN}, {fd=11, events=POLLIN|POLLPRI}, {fd=13, events=POLLIN|POLLPRI}, {fd=14, events=POLLIN|POLLPRI}, {fd=15, events=POLLIN|POLLPRI}], 5, 249^C <unfinished ...>

therefore i'd like to reopen the issue
Comment 7 David Schleef 2011-06-05 23:34:05 UTC
Being stuck in a poll loop is completely normal.  It's waiting for the server to send data, and the server never does.  Eventually it times out.

What do you want to happen here?
Comment 8 Andreas Frisch 2011-06-06 05:47:38 UTC
hi david!
this issue is not a bug. i was just setting the timeout property somewhere wrong. i've fixed it a while ago, setting the timeout property of souphttpsource in a notify::source callback function now and it worked after that.
sorry i forgot to mark this a resolved!