GNOME Bugzilla – Bug 623789
[souphttpsrc/playbin2] setting http timeout is ineffective
Last modified: 2011-05-09 10:03:08 UTC
GST_DEBUG=*:2,*soup*:4 enigma2 eServiceMP3::construct! eServiceMP3::playbin2 uri=http://cctv.ws/1/ssic01/VH1classic eServiceMP3::starting pipeline 0:00:21.470439000 24781 0x5b6b10 DEBUG souphttpsrc gstsouphttpsrc.c:1224:gst_soup_http_src_start:<source> start("http://cctv.ws/1/ssic01/VH1classic") 0:00:21.483122000 24781 0x5b6b10 DEBUG souphttpsrc gstsouphttpsrc.c:1334:gst_soup_http_src_get_size:<source> get_size() = FALSE 0:00:21.483652000 24781 0x5b6b10 DEBUG souphttpsrc gstsouphttpsrc.c:1315:gst_soup_http_src_unlock_stop:<source> unlock_stop() 0:00:21.484028000 24781 0x5b6b10 DEBUG souphttpsrc gstsouphttpsrc.c:1351:gst_soup_http_src_do_seek:<source> do_seek(0) 0:00:21.492287000 24781 0x13f16c0 DEBUG souphttpsrc gstsouphttpsrc.c:1148:gst_soup_http_src_build_message:<source> request headers: 0:00:21.492935000 24781 0x13f16c0 DEBUG souphttpsrc gstsouphttpsrc.c:714:gst_soup_http_src_headers_foreach:<source> Connection: close 0:00:21.493444000 24781 0x13f16c0 DEBUG souphttpsrc gstsouphttpsrc.c:714:gst_soup_http_src_headers_foreach:<source> icy-metadata: 1 0:00:21.493924000 24781 0x13f16c0 DEBUG souphttpsrc gstsouphttpsrc.c:714:gst_soup_http_src_headers_foreach:<source> transferMode.dlna.org: Streaming 0:00:21.494395000 24781 0x13f16c0 DEBUG souphttpsrc gstsouphttpsrc.c:1197:gst_soup_http_src_create:<source> Queueing connection request eServiceMP3::gst_message from playsink0: GstMessageState, old-state=(GstState)GST_STATE_NULL, new-state=(GstState)GST_STATE_READY, pending-state=(GstState)GST_STATE_VOID_PENDING; eServiceMP3::gst_message from playbin: GstMessageState, old-state=(GstState)GST_STATE_NULL, new-state=(GstState)GST_STATE_READY, pending-state=(GstState)GST_STATE_PLAYING; eServiceMP3::state transition NULL -> READY eServiceMP3::gst_message from uridecodebin0: GstMessageState, old-state=(GstState)GST_STATE_NULL, new-state=(GstState)GST_STATE_READY, pending-state=(GstState)GST_STATE_VOID_PENDING; eServiceMP3::gst_message from typefindelement0: GstMessageState, old-state=(GstState)GST_STATE_NULL, new-state=(GstState)GST_STATE_READY, pending-state=(GstState)GST_STATE_PAUSED; eServiceMP3::gst_message from typefindelement0: GstMessageState, old-state=(GstState)GST_STATE_READY, new-state=(GstState)GST_STATE_PAUSED, pending-state=(GstState)GST_STATE_VOID_PENDING; eServiceMP3::gst_message from source: GstMessageState, old-state=(GstState)GST_STATE_NULL, new-state=(GstState)GST_STATE_READY, pending-state=(GstState)GST_STATE_PAUSED; eServiceMP3::gst_message from src: GstMessageStreamStatus, type=(GstStreamStatusType)GST_STREAM_STATUS_TYPE_CREATE, owner=(GstElement)"\(GstSoupHTTPSrc\)\ source", object=(GstTask)"\(GstTask\)\ source:src"; eServiceMP3::caught GST_MESSAGE_STREAM_STATUS!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!11111 eServiceMP3::streaming source element (owner 'source' @0x1400040) type=0 eServiceMP3::GST_STREAM_STATUS_TYPE_CREATE -> setting network timeout to 10s... eServiceMP3::...checking... is now 10 eServiceMP3::gst_message from source: GstMessageState, old-state=(GstState)GST_STATE_READY, new-state=(GstState)GST_STATE_PAUSED, pending-state=(GstState)GST_STATE_VOID_PENDING; eServiceMP3::gst_message from uridecodebin0: GstMessageState, old-state=(GstState)GST_STATE_READY, new-state=(GstState)GST_STATE_PAUSED, pending-state=(GstState)GST_STATE_VOID_PENDING; eServiceMP3::gst_message from src: GstMessageStreamStatus, type=(GstStreamStatusType)GST_STREAM_STATUS_TYPE_ENTER, owner=(GstElement)"\(GstSoupHTTPSrc\)\ source", object=(GstTask)"\(GstTask\)\ source:src"; eServiceMP3::caught GST_MESSAGE_STREAM_STATUS!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!11111 eServiceMP3::streaming source element (owner 'source' @0x1400040) type=0 0:00:21.891357000 24781 0x13f16c0 DEBUG souphttpsrc gstsouphttpsrc.c:726:gst_soup_http_src_got_headers_cb:<source> got headers: 0:00:21.891693000 24781 0x13f16c0 DEBUG souphttpsrc gstsouphttpsrc.c:714:gst_soup_http_src_headers_foreach:<source> Connection: close 0:00:21.891918000 24781 0x13f16c0 DEBUG souphttpsrc gstsouphttpsrc.c:714:gst_soup_http_src_headers_foreach:<source> Date: Wed, 07 Jul 2010 22:15:52 GMT 0:00:21.892139000 24781 0x13f16c0 DEBUG souphttpsrc gstsouphttpsrc.c:714:gst_soup_http_src_headers_foreach:<source> Server: Microsoft-IIS/6.0 0:00:21.892356000 24781 0x13f16c0 DEBUG souphttpsrc gstsouphttpsrc.c:714:gst_soup_http_src_headers_foreach:<source> X-Powered-By: ASP.NET 0:00:21.892563000 24781 0x13f16c0 DEBUG souphttpsrc gstsouphttpsrc.c:714:gst_soup_http_src_headers_foreach:<source> X-Robots-Tag: noarchive 0:00:21.892771000 24781 0x13f16c0 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:21.893003000 24781 0x13f16c0 DEBUG souphttpsrc gstsouphttpsrc.c:714:gst_soup_http_src_headers_foreach:<source> Location: http://87.239.230.2:8019 0:00:21.893220000 24781 0x13f16c0 DEBUG souphttpsrc gstsouphttpsrc.c:714:gst_soup_http_src_headers_foreach:<source> Content-Length: 145 0:00:21.893431000 24781 0x13f16c0 DEBUG souphttpsrc gstsouphttpsrc.c:714:gst_soup_http_src_headers_foreach:<source> Content-Type: text/html 0:00:21.893642000 24781 0x13f16c0 DEBUG souphttpsrc gstsouphttpsrc.c:714:gst_soup_http_src_headers_foreach:<source> Cache-control: max-age=3600, public 0:00:21.893884000 24781 0x13f16c0 DEBUG souphttpsrc gstsouphttpsrc.c:732:gst_soup_http_src_got_headers_cb:<source> 302 redirect to "http://87.239.230.2:8019" 0:00:21.894166000 24781 0x13f16c0 DEBUG souphttpsrc gstsouphttpsrc.c:965:gst_soup_http_src_chunk_allocator:<source> alloc 4096 bytes <= 0 0:00:21.894695000 24781 0x13f16c0 DEBUG souphttpsrc gstsouphttpsrc.c:965:gst_soup_http_src_chunk_allocator:<source> alloc 4096 bytes <= 4294967151 0:03:30.899547000 24781 0x13f16c0 DEBUG souphttpsrc gstsouphttpsrc.c:898:gst_soup_http_src_finished_cb:<source> finished 0:03:30.899970000 24781 0x13f16c0 WARN souphttpsrc gstsouphttpsrc.c:914:gst_soup_http_src_finished_cb:<source> error: Cannot connect to destination 0:03:30.900272000 24781 0x13f16c0 WARN souphttpsrc gstsouphttpsrc.c:914:gst_soup_http_src_finished_cb:<source> error: libsoup status code 4 0:03:30.901732000 24781 0x13f16c0 DEBUG souphttpsrc gstsouphttpsrc.c:1044:gst_soup_http_src_response_cb:<source> got response 4: Cannot connect to destination 0:03:30.902072000 24781 0x13f16c0 WARN souphttpsrc gstsouphttpsrc.c:1079:gst_soup_http_src_parse_status:<source> error: "http://cctv.ws/1/ssic01/VH1classic": Cannot connect to destination 0:03:30.902403000 24781 0x13f16c0 WARN souphttpsrc gstsouphttpsrc.c:1079:gst_soup_http_src_parse_status:<source> error: libsoup status code 4 eServiceMP3::gst_message from source: GstMessageError, gerror=(GstGError)NULL, debug=(string)"gstsouphttpsrc.c\(914\):\ gst_soup_http_src_finished_cb\ \(\):\ /GstPlayBin2:playbin/GstURIDecodeBin:uridecodebin0/GstSoupHTTPSrc:source:\012libsoup\ status\ code\ 4"; Gstreamer error: Cannot connect to destination (3) from source eServiceMP3::gst_message from source: GstMessageError, gerror=(GstGError)NULL, debug=(string)"gstsouphttpsrc.c\(1079\):\ gst_soup_http_src_parse_status\ \(\):\ /GstPlayBin2:playbin/GstURIDecodeBin:uridecodebin0/GstSoupHTTPSrc:source:\012libsoup\ status\ code\ 4"; Gstreamer error: "http://cctv.ws/1/ssic01/VH1classic": Cannot connect to destination (5) from source 0:03:30.904598000 24781 0x13f16c0 WARN basesrc gstbasesrc.c:2543:gst_base_src_loop:<source> error: Internal data flow error. 0:03:30.905054000 24781 0x13f16c0 WARN basesrc gstbasesrc.c:2543:gst_base_src_loop:<source> error: streaming task paused, reason error (-5) 0:03:30.905987000 24781 0x13f16c0 WARN typefind gsttypefindelement.c:560:gst_type_find_element_handle_event:<typefindelement0> error: Stream contains no data. 0:03:30.906362000 24781 0x13f16c0 WARN typefind gsttypefindelement.c:560:gst_type_find_element_handle_event:<typefindelement0> error: Can't typefind empty stream eServiceMP3::gst_message from source: GstMessageError, gerror=(GstGError)NULL, debug=(string)"gstbasesrc.c\(2543\):\ gst_base_src_loop\ \(\):\ /GstPlayBin2:playbin/GstURIDecodeBin:uridecodebin0/GstSoupHTTPSrc:source:\012streaming\ task\ paused\,\ reason\ error\ \(-5\)"; Gstreamer error: Internal data flow error. (1) from source eServiceMP3::gst_message from typefindelement0: GstMessageError, gerror=(GstGError)NULL, debug=(string)"gsttypefindelement.c\(560\):\ gst_type_find_element_handle_event\ \(\):\ /GstPlayBin2:playbin/GstURIDecodeBin:uridecodebin0/GstTypeFindElement:typefindelement0:\012Can\'t\ typefind\ empty\ stream"; Gstreamer error: Stream contains no data. (4) from typefindelement0
On the one hand, setting souphttpsrc timeout to e.g. 10 works fine here with latest git. On the other hand, that timeout is used pretty early on (when initiating the connection). So, if the above bus messages are received asynchronously in the mainloop (as is typically the case), then setting the timeout property may simply happen too late. You would have to come up with a more synchronous mechanism to set the property early enough (monitoring bus messages synchronously or connecting to signals related to element adding etc).
To be sure, the right time/way to set such properties on the source in playbin2 is: - use the "source-setup" signal (new in the upcoming -base release, 0.10.33, and git) - use the "notify::source" signal and then g_object_get(playbin, "source", &src, NULL) in the notify callback where you can also set properties like this then (don't forget to unref src afterwards).
thx for the hints! i'm setting the prop in my notify::source cb now and it works perfectly.