[Telepathy] Timeout for SOCKS5 proxy stream initiation

Sven Brauch svenbrauch at googlemail.com
Wed Aug 14 06:22:05 PDT 2013


Hi list,

I'm trying to use stream tubes to proxy an existing protocol. The problem 
I'm facing is that sometimes it takes several minutes for the TCP connection 
to be established, although the tube is accepted immediately. We have tracked 
this down to probably being related to SOCKS5 proxy timeouts: gabble first 
tries to contact a SOCKS5 proxy with a timeout of 180 seconds, and if that 
fails, it sequentially contacts further proxies (each with a 180 seconds 
timeout) and finally falls back to in-band bytestreams if none works.

Here are some relevant log excerpts; [1] this is when the connection is 
requested, then nothing happens for several minutes, until [2] takes place.

The test was performed with the telepathy-qt stream tube examples, but similar 
behaviour can be observed in all applications using stream tubes.

What could be done to resolve this problem? I would suggest to decrease the 
proxy timeout from 180 to 15 seconds, since a proxy which takes 120 seconds to 
reply is obviously not suitable for real-time communication. Additionally, it 
might be a good idea to try more than one proxy at once instead of trying them 
all sequentially.

Greetings,
Sven

______________________________

[1] ====================
(telepathy-gabble:18914): wocky-DEBUG: _end_element_ns: Received stanza
* iq xmlns='jabber:client' type='set' to='svenbrauch at googlemail.com/kde-
telepa35BC7106' id='166934183620' from='david at gmail.com/kde-telepa8D2D8D8D'
    * si xmlns='http://jabber.org/protocol/si' id='1376431759-547228821' 
profile='http://telepathy.freedesktop.org/xmpp/tubes'
        * feature xmlns='http://jabber.org/protocol/feature-neg'
            * x xmlns='jabber:x:data' type='form'
                * field var='stream-method' type='list-single'
                    * option
                        * value
                            "http://jabber.org/protocol/bytestreams"
                    * option
                        * value
                            "http://jabber.org/protocol/ibb"
        * si-multiple xmlns='http://telepathy.freedesktop.org/xmpp/si-multiple'
        * stream xmlns='http://telepathy.freedesktop.org/xmpp/tubes' 
tube='1165566942'
(telepathy-gabble:18914): gabble-DEBUG: streaminit_parse_request (bytestream-
factory.c:941): Got stream-method http://jabber.org/protocol/bytestreams
(telepathy-gabble:18914): gabble-DEBUG: streaminit_parse_request (bytestream-
factory.c:941): Got stream-method http://jabber.org/protocol/ibb
(telepathy-gabble:18914): gabble-DEBUG: bytestream_factory_iq_si_cb 
(bytestream-factory.c:1154): received a SI request
(telepathy-gabble:18914): gabble-DEBUG: bytestream_factory_iq_si_cb 
(bytestream-factory.c:1210): Receiver supports multi bytestreams
(telepathy-gabble:18914): gabble-DEBUG: gabble_signal_connect_weak 
(util.c:666): connecting to 0x7f94f0002820:state-changed with context 
0x3e87000
(telepathy-gabble:18914): gabble-DEBUG: 
gabble_bytestream_factory_create_multiple (bytestream-factory.c:1881): add 
multi bytestream <1376431759-547228821> from <david at gmail.com/kde-
telepa8D2D8D8D>
(telepathy-gabble:18914): gabble-DEBUG: bytestream_factory_iq_si_cb 
(bytestream-factory.c:1226): add http://jabber.org/protocol/bytestreams to 
multi-bytestream methods
(telepathy-gabble:18914): gabble-DEBUG: 
gabble_bytestream_multiple_add_stream_method (bytestream-multiple.c:616): Add 
bytestream method http://jabber.org/protocol/bytestreams
(telepathy-gabble:18914): gabble-DEBUG: gabble_signal_connect_weak 
(util.c:666): connecting to 0x264e270:state-changed with context 0x2a96640
(telepathy-gabble:18914): gabble-DEBUG: 
gabble_bytestream_factory_create_socks5 (bytestream-factory.c:1844): add 
SOCKS5 bytestream <1376431759-547228821> from <david at gmail.com/kde-
telepa8D2D8D8D>
(telepathy-gabble:18914): gabble-DEBUG: bytestream_factory_iq_si_cb 
(bytestream-factory.c:1226): add http://jabber.org/protocol/ibb to multi-
bytestream methods
(telepathy-gabble:18914): gabble-DEBUG: 
gabble_bytestream_multiple_add_stream_method (bytestream-multiple.c:616): Add 
bytestream method http://jabber.org/protocol/ibb
(telepathy-gabble:18914): gabble-DEBUG: 
gabble_private_tubes_factory_handle_si_stream_request (private-tubes-
factory.c:756): contact#1571 stream 1376431759-547228821
(telepathy-gabble:18914): gabble-DEBUG: 
gabble_private_tubes_factory_handle_si_stream_request (private-tubes-
factory.c:805): received new bytestream request for existing tube: 1165566942
(telepathy-gabble:18914): gabble-DEBUG: new_connection_to_socket (tube-
stream.c:906): Called.
(telepathy-gabble:18914): gabble-DEBUG: gabble_tube_stream_add_bytestream 
(tube-stream.c:1799): Received first connection. Tube is now open
(telepathy-gabble:18914): gabble-DEBUG: gabble_tube_stream_add_bytestream 
(tube-stream.c:1808): accept the extra bytestream
(telepathy-gabble:18914): wocky-DEBUG: _write_node_tree: Serializing tree:
* iq xmlns='jabber:client' type='result' to='david at gmail.com/kde-
telepa8D2D8D8D' id='166934183620'
    * si xmlns='http://jabber.org/protocol/si'
        * si-multiple xmlns='http://telepathy.freedesktop.org/xmpp/si-multiple'
            * value
                "http://jabber.org/protocol/bytestreams"
            * value
                "http://jabber.org/protocol/ibb"
        * tube xmlns='http://telepathy.freedesktop.org/xmpp/tubes'
(telepathy-gabble:18914): wocky-DEBUG: Writing xml: <iq type="result" 
to="david at gmail.com/kde-telepa8D2D8D8D" id="166934183620"><si 
xmlns="http://jabber.org/protocol/si"><si-multiple 
xmlns="http://telepathy.freedesktop.org/xmpp/si-multiple"><value>http://jabber.org/protocol/bytestreams</value><value>http://jabber.org/protocol/ibb</value></si-multiple><tube xmlns="http://telepathy.freedesktop.org/xmpp/tubes"/></si></iq>
(telepathy-gabble:18914): gabble-DEBUG: gabble_bytestream_multiple_accept 
(bytestream-multiple.c:423): stream 1376431759-547228821 with 
david at gmail.com/kde-te<D8D8D is now accepted
(telepathy-gabble:18914): gabble-DEBUG: extra_bytestream_state_changed_cb 
(tube-stream.c:366): Called.
(telepathy-gabble:18914): wocky-DEBUG: Parsing chunk: <iq type="set" 
to="svenbrauch at googlemail.com/kde-telepa35BC7106" id="167448495381" 
from="david at gmail.com/kde-telepa8D2D8D8D"><query sid="1376431759-547228821" 
mode="tcp" xmlns="http://jabber.org/protocol/bytestreams"><streamhost 
jid="david at gmail.com/kde-telepa8D2D8D8D" host="192.168.1.72" 
port="38282"/><streamhost jid="proxy.eu.jabber.org" host="91.121.109.155" 
port="7777"/></query></iq>
(telepathy-gabble:18914): wocky-DEBUG: _end_element_ns: Received stanza
* iq xmlns='jabber:client' type='set' to='svenbrauch at googlemail.com/kde-
telepa35BC7106' id='167448495381' from='david at gmail.com/kde-telepa8D2D8D8D'
    * query xmlns='http://jabber.org/protocol/bytestreams' 
sid='1376431759-547228821' mode='tcp'
        * streamhost jid='david at gmail.com/kde-telepa8D2D8D8D' 
host='192.168.1.72' port='38282'
        * streamhost jid='proxy.eu.jabber.org' host='91.121.109.155' 
port='7777'
(telepathy-gabble:18914): gabble-DEBUG: 
gabble_bytestream_socks5_add_streamhost (bytestream-socks5.c:1305): streamhost 
with jid david at gmail.com/kde-telepa8D2D8D8D, host 192.168.1.72 and port 38282 
added
(telepathy-gabble:18914): gabble-DEBUG: 
gabble_bytestream_socks5_add_streamhost (bytestream-socks5.c:1305): streamhost 
with jid proxy.eu.jabber.org, host 91.121.109.155 and port 7777 added
(telepathy-gabble:18914): gabble-DEBUG: socks5_connect (bytestream-
socks5.c:1226): Trying streamhost 192.168.1.72 on port 38282

[2] ====================
elepathy-gabble:18914): gabble-DEBUG: transport_disconnected_cb (bytestream-
socks5.c:529): Sock5 transport disconnected
(telepathy-gabble:18914): gabble-DEBUG: socks5_error (bytestream-
socks5.c:652): no more streamhosts to try
(telepathy-gabble:18914): gabble-DEBUG: bytestream_connection_error_cb 
(bytestream-multiple.c:550): Trying alternative streaming method
(telepathy-gabble:18914): gabble-DEBUG: gabble_signal_connect_weak 
(util.c:666): connecting to 0x2eb58c0:state-changed with context 0x2ab8300
(telepathy-gabble:18914): gabble-DEBUG: gabble_bytestream_factory_create_ibb 
(bytestream-factory.c:1778): add IBB bytestream <1376431759-547228821> from 
<david at gmail.com/kde-telepa8D2D8D8D>
(telepathy-gabble:18914): wocky-DEBUG: _write_node_tree: Serializing tree:
* iq xmlns='jabber:client' type='error' from='svenbrauch at googlemail.com/kde-
telepa35BC7106' to='david at gmail.com/kde-telepa8D2D8D8D' id='167448495381'
    * query xmlns='http://jabber.org/protocol/bytestreams' 
sid='1376431759-547228821' mode='tcp'
        * streamhost jid='david at gmail.com/kde-telepa8D2D8D8D' 
host='192.168.1.72' port='38282'
        * streamhost jid='proxy.eu.jabber.org' host='91.121.109.155' 
port='7777'
    * error code='404' type='cancel'
        * item-not-found xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'
        * text xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'
            "impossible to connect to any streamhost"


More information about the telepathy mailing list