Connection fails with exception after "Write Error: g-io-error-quark: Stream has outstanding operation (20)"
Versions
- OS: Debian GNU/Linux stretch/sid
- GTK Version: 3.24.14
- PyGObject Version: 3.34.0
- GLib Version : 2.62.4
- python-nbxmpp Version: 0.9.94+087a2798
- Gajim Version: 1.1.94+df2f93c08603
Steps to reproduce the problem
- If network connectivity gets unstable during connection establishment.
Expected
No operation is expected to succeed, so that continuing leads to follow-up exceptions. Instead a failed operation will be retried.
Log
03/28/2020 16:00:27 (I) nbxmpp.stream | (jabber.ccc.de) Connect
03/28/2020 16:00:27 (I) nbxmpp.stream | (jabber.ccc.de) Set state: StreamState.RESOLVE
03/28/2020 16:00:28 (I) nbxmpp.resolver | g-resolver-error-quark: No DNS record of the requested type for “_xmppconnect.jabber.ccc.de” (0)
03/28/2020 16:00:28 (I) nbxmpp.stream | (jabber.ccc.de) Domain resolved
03/28/2020 16:00:28 (I) nbxmpp.stream | (jabber.ccc.de) ServerAddress(domain='jabber.ccc.de', service='xmpps-client', host=None, uri=None, protocol=<ConnectionProtocol.TCP: 0>, type=<ConnectionType.DIRECT_TLS: 'DIRECT TLS'>, proxy=None)
ServerAddress(domain='jabber.ccc.de', service='xmpp-client', host=None, uri=None, protocol=<ConnectionProtocol.TCP: 0>, type=<ConnectionType.START_TLS: 'START TLS'>, proxy=None)
ServerAddress(domain='jabber.ccc.de', service='xmpp-client', host=None, uri=None, protocol=<ConnectionProtocol.TCP: 0>, type=<ConnectionType.PLAIN: 'PLAIN'>, proxy=None)
ServerAddress(domain='jabber.ccc.de', service=None, host='jabber.ccc.de:5222', uri=None, protocol=<ConnectionProtocol.TCP: 0>, type=<ConnectionType.START_TLS: 'START TLS'>, proxy=None)
ServerAddress(domain='jabber.ccc.de', service=None, host='jabber.ccc.de:5222', uri=None, protocol=<ConnectionProtocol.TCP: 0>, type=<ConnectionType.PLAIN: 'PLAIN'>, proxy=None)
03/28/2020 16:00:28 (I) nbxmpp.stream | (jabber.ccc.de) Set state: StreamState.RESOLVED
03/28/2020 16:00:28 (I) nbxmpp.stream | (jabber.ccc.de) Current address: ServerAddress(domain='jabber.ccc.de', service='xmpps-client', host=None, uri=None, protocol=<ConnectionProtocol.TCP: 0>, type=<ConnectionType.DIRECT_TLS: 'DIRECT TLS'>, proxy=None)
03/28/2020 16:00:28 (I) nbxmpp.stream | (jabber.ccc.de) Set state: StreamState.CONNECTING
03/28/2020 16:00:28 (I) nbxmpp.connection | (jabber.ccc.de) Set Connection State: TCPState.CONNECTING
03/28/2020 16:00:28 (I) nbxmpp.connection | (jabber.ccc.de) Connect Error: g-resolver-error-quark: No DNS record of the requested type for “_xmpps-client._tcp.jabber.ccc.de” (0)
03/28/2020 16:00:28 (I) nbxmpp.connection | (jabber.ccc.de) Set Connection State: TCPState.DISCONNECTED
03/28/2020 16:00:28 (I) nbxmpp.connection | (jabber.ccc.de) Signal: connection-failed
03/28/2020 16:00:28 (I) nbxmpp.stream | (jabber.ccc.de) Set state: StreamState.DISCONNECTED
03/28/2020 16:00:28 (I) nbxmpp.stream | (jabber.ccc.de) Current address: ServerAddress(domain='jabber.ccc.de', service='xmpp-client', host=None, uri=None, protocol=<ConnectionProtocol.TCP: 0>, type=<ConnectionType.START_TLS: 'START TLS'>, proxy=None)
03/28/2020 16:00:28 (I) nbxmpp.stream | (jabber.ccc.de) Set state: StreamState.CONNECTING
03/28/2020 16:00:28 (I) nbxmpp.connection | (jabber.ccc.de) Set Connection State: TCPState.CONNECTING
03/28/2020 16:00:28 (I) nbxmpp.connection | (jabber.ccc.de) Connecting to jabber.ccc.de (146.255.57.229:5222)
03/28/2020 16:00:28 (I) nbxmpp.connection | (jabber.ccc.de) Set Connection State: TCPState.CONNECTED
03/28/2020 16:00:28 (I) nbxmpp.connection | (jabber.ccc.de) Connected to jabber.ccc.de (146.255.57.229:5222)
03/28/2020 16:00:28 (I) nbxmpp.connection | (jabber.ccc.de) Signal: connected
03/28/2020 16:00:28 (I) nbxmpp.stream | (jabber.ccc.de) Set state: StreamState.CONNECTED
03/28/2020 16:00:28 (I) nbxmpp.stream | (jabber.ccc.de) Execute state machine
03/28/2020 16:00:28 (I) nbxmpp.stream | (jabber.ccc.de) Start stream
03/28/2020 16:00:28 (I) nbxmpp.stream | (jabber.ccc.de) Set state: StreamState.WAIT_FOR_STREAM_START
03/28/2020 16:00:28 (I) nbxmpp.connection | (jabber.ccc.de) ::::: DATA SENT ::::
<?xml version='1.0'?><stream:stream xmlns="jabber:client" version="1.0" xmlns:stream="http://etherx.jabber.org/streams" to="jabber.ccc.de" xml:lang="en">
03/28/2020 16:00:28 (I) nbxmpp.connection | (jabber.ccc.de) Signal: data-sent
03/28/2020 16:00:28 (I) nbxmpp.stream | (jabber.ccc.de) Signal: stanza-sent
03/28/2020 16:00:29 (I) nbxmpp.connection | (jabber.ccc.de) ::::: DATA RECEIVED ::::
<?xml version='1.0'?><stream:stream id='1234567890123456789' version='1.0' xml:lang='en' xmlns:stream='http://etherx.jabber.org/streams' from='jabber.ccc.de' xmlns='jabber:client'><stream:features><starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'><required/></starttls></stream:features>
03/28/2020 16:00:29 (I) nbxmpp.connection | (jabber.ccc.de) Signal: data-received
03/28/2020 16:00:29 (I) nbxmpp.stream | (jabber.ccc.de) Signal: stanza-received
03/28/2020 16:00:29 (I) nbxmpp.stream | (jabber.ccc.de) Execute state machine
03/28/2020 16:00:29 (I) nbxmpp.stream | (jabber.ccc.de) Set state: StreamState.WAIT_FOR_FEATURES
03/28/2020 16:00:29 (I) nbxmpp.stream | (jabber.ccc.de) Signal: stanza-received
03/28/2020 16:00:29 (I) nbxmpp.stream | (jabber.ccc.de) Execute state machine
03/28/2020 16:00:29 (I) nbxmpp.stream | (jabber.ccc.de) Set state: StreamState.WAIT_FOR_TLS_PROCEED
03/28/2020 16:00:29 (I) nbxmpp.connection | (jabber.ccc.de) ::::: DATA SENT ::::
<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls" />
03/28/2020 16:00:29 (I) nbxmpp.connection | (jabber.ccc.de) Signal: data-sent
03/28/2020 16:00:29 (I) nbxmpp.stream | (jabber.ccc.de) Signal: stanza-sent
03/28/2020 16:00:29 (I) nbxmpp.connection | (jabber.ccc.de) ::::: DATA RECEIVED ::::
<proceed xmlns='urn:ietf:params:xml:ns:xmpp-tls'/>
03/28/2020 16:00:29 (I) nbxmpp.connection | (jabber.ccc.de) Signal: data-received
03/28/2020 16:00:29 (I) nbxmpp.stream | (jabber.ccc.de) Signal: stanza-received
03/28/2020 16:00:29 (I) nbxmpp.stream | (jabber.ccc.de) Execute state machine
03/28/2020 16:00:29 (I) nbxmpp.connection | (jabber.ccc.de) Start TLS negotiation
03/28/2020 16:00:29 (I) nbxmpp.stream | (jabber.ccc.de) Start stream
03/28/2020 16:00:29 (I) nbxmpp.stream | (jabber.ccc.de) Set state: StreamState.WAIT_FOR_STREAM_START
03/28/2020 16:00:29 (E) nbxmpp.connection | (jabber.ccc.de) Write Error: g-io-error-quark: Stream has outstanding operation (20)
Traceback (most recent call last):
File "/home/andrey/progs/python-nbxmpp.git/nbxmpp/util.py", line 403, in utf8_decode
return data.decode(), b''
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xa8 in position 13: invalid start byte
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/home/andrey/progs/python-nbxmpp.git/nbxmpp/tcp.py", line 235, in _on_read_async_finish
data, self._read_buffer = utf8_decode(self._read_buffer)
File "/home/andrey/progs/python-nbxmpp.git/nbxmpp/util.py", line 409, in utf8_decode
return data[:i].decode(), data[i:]
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xa8 in position 13: invalid start byte