Testing state of JaXMPP instance after issues with connection or authentication timeout - #4378

Test duration: 64.920s

Passed Tests
tigase.tests.jaxmpp.TestHandlingOfConnectionIssues
testStateAfterAuthTimeoutBosh 20.656s
2019-11-25 19:44:14 |

2019-11-25 19:44:14 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2019-11-25 19:44:14 | ------------------------------------

2019-11-25 19:44:14 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-25 19:44:14 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2019-11-25 19:44:14 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using BOSHConnector

2019-11-25 19:44:14 | jaxmpp_ :: jaxmpp__1dqaoj0530@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>SCRAM-SHA-256</mechanism><mechanism>SCRAM-SHA-1</mechanism><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2019-11-25 19:44:34 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onTerminate: Stream terminated. responseCode=200

2019-11-25 19:44:34 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-25 19:44:34 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2019-11-25 19:44:34 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using BOSHConnector

2019-11-25 19:44:34 | jaxmpp_ :: jaxmpp__1dqaoj0530@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>SCRAM-SHA-256</mechanism><mechanism>SCRAM-SHA-1</mechanism><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2019-11-25 19:44:34 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2019-11-25 19:44:34 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-11-25 19:44:34 | jaxmpp_ :: jaxmpp__1dqaoj0530@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfXzFkcWFvajA1MzAscj1odDlFNU9DRmFCdDg3dmV6ZVRtWQ==</auth>

2019-11-25 19:44:34 | jaxmpp_ :: jaxmpp__1dqaoj0530@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1odDlFNU9DRmFCdDg3dmV6ZVRtWVlJamg2aWF5Mk5NcG9Ubms3QUtjLHM9WURNUXFiUlVzcWcwUVE9PSxpPTQwOTY=</challenge>

2019-11-25 19:44:34 | jaxmpp_ :: jaxmpp__1dqaoj0530@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9aHQ5RTVPQ0ZhQnQ4N3ZlemVUbVlZSWpoNmlheTJOTXBvVG5rN0FLYyxwPUU5QUp3L3dUV3ZDUnR6Sld0eWFmejJPcW05NzNUZGorRTdIK2tyT3hyd1E9</response>

2019-11-25 19:44:35 | jaxmpp_ :: jaxmpp__1dqaoj0530@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1vbVlJOXlHT1lOVURkL0VBek9taXIrMC9GZytDb2JPVUprZlJzYmZ1b3o4PQ==</success>

2019-11-25 19:44:35 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-25 19:44:35 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-25 19:44:35 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-25 19:44:35 | jaxmpp_ :: jaxmpp__1dqaoj0530@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><register xmlns="http://jabber.org/features/iq-register"/><csi xmlns="urn:xmpp:csi:0"/><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/><session xmlns="urn:ietf:params:xml:ns:xmpp-session"><optional/></session><c hash="SHA-1" node="https://tigase.net/tigase-xmpp-server" ver="bt2mj6vq9J3s6VE0/7D8Mo0TIoU=" xmlns="http://jabber.org/protocol/caps"/></features>

2019-11-25 19:44:35 | jaxmpp_ :: jaxmpp__1dqaoj0530@localhost >> <iq xmlns="jabber:client" id="e5DQMykJWlbp3iIHT7m4cHR" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-25 19:44:35 | jaxmpp_ :: jaxmpp__1dqaoj0530@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><register xmlns="http://jabber.org/features/iq-register"/><csi xmlns="urn:xmpp:csi:0"/><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/><session xmlns="urn:ietf:params:xml:ns:xmpp-session"><optional/></session><c hash="SHA-1" node="https://tigase.net/tigase-xmpp-server" ver="bt2mj6vq9J3s6VE0/7D8Mo0TIoU=" xmlns="http://jabber.org/protocol/caps"/></features>

2019-11-25 19:44:35 | jaxmpp_ :: jaxmpp__1dqaoj0530@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><register xmlns="http://jabber.org/features/iq-register"/><csi xmlns="urn:xmpp:csi:0"/><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/><session xmlns="urn:ietf:params:xml:ns:xmpp-session"><optional/></session><c hash="SHA-1" node="https://tigase.net/tigase-xmpp-server" ver="bt2mj6vq9J3s6VE0/7D8Mo0TIoU=" xmlns="http://jabber.org/protocol/caps"/></features>

2019-11-25 19:44:35 | jaxmpp_ :: jaxmpp__1dqaoj0530@localhost >> <iq xmlns="jabber:client" id="XV76xcKyphZhGNDBBiIKHQT" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-25 19:44:35 | jaxmpp_ :: jaxmpp__1dqaoj0530@localhost >> <iq xmlns="jabber:client" id="saOkMUS3zzr0rVbLCm2h0dw" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-25 19:44:35 | jaxmpp_ :: jaxmpp__1dqaoj0530@localhost << <iq to="jaxmpp__1dqaoj0530@localhost/993927746-tigase-287" type="result" id="e5DQMykJWlbp3iIHT7m4cHR" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__1dqaoj0530@localhost/993927746-tigase-287</jid></bind></iq>

2019-11-25 19:44:35 | jaxmpp_ :: jaxmpp__1dqaoj0530@localhost << <iq to="jaxmpp__1dqaoj0530@localhost/993927746-tigase-288" type="result" id="XV76xcKyphZhGNDBBiIKHQT" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__1dqaoj0530@localhost/993927746-tigase-288</jid></bind></iq>

2019-11-25 19:44:35 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-25 19:44:35 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-25 19:44:35 | jaxmpp_ :: jaxmpp__1dqaoj0530@localhost/993927746-tigase-288 >> <iq to="localhost" id="jLzZrnNPQOThTUao5DHHwtZ" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-11-25 19:44:35 | jaxmpp_ :: jaxmpp__1dqaoj0530@localhost/993927746-tigase-288 >> <iq to="localhost" id="dUYLJy6qVk7JvfGufZjKQKN" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-11-25 19:44:35 | jaxmpp_ :: jaxmpp__1dqaoj0530@localhost/993927746-tigase-288 >> <iq id="kcOspRX6kVl1aGq9LXdyx7z" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-11-25 19:44:35 | jaxmpp_ :: jaxmpp__1dqaoj0530@localhost/993927746-tigase-288 >> <iq id="98ADo6pgJy6qVk7JvfGufZj" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-11-25 19:44:35 | jaxmpp_ :: jaxmpp__1dqaoj0530@localhost/993927746-tigase-288 << <iq to="jaxmpp__1dqaoj0530@localhost/993927746-tigase-289" type="result" id="saOkMUS3zzr0rVbLCm2h0dw" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__1dqaoj0530@localhost/993927746-tigase-289</jid></bind></iq>

2019-11-25 19:44:35 | jaxmpp_ :: jaxmpp__1dqaoj0530@localhost/993927746-tigase-289 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-25 19:44:35 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-25 19:44:35 | jaxmpp_ :: jaxmpp__1dqaoj0530@localhost/993927746-tigase-289 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-25 19:44:35 | jaxmpp_ :: jaxmpp__1dqaoj0530@localhost/993927746-tigase-289 >> <iq to="localhost" id="3bH4gXXfTSS4l8t24mN4BHr" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-11-25 19:44:35 | jaxmpp_ :: jaxmpp__1dqaoj0530@localhost/993927746-tigase-289 >> <iq id="jQE9L15p08xzt4u2ndR1aLz" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-11-25 19:44:35 | jaxmpp_ :: jaxmpp__1dqaoj0530@localhost/993927746-tigase-289 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-25 19:44:35 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

2019-11-25 19:44:35 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session]

2019-11-25 19:44:35 | tigase.jaxmpp.j2se.connectors.bosh.BoshWorker.run: Connection error

2019-11-25 19:44:35 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onError: responseCode=0

2019-11-25 19:44:35 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onError: responseCode=500

testStateAfterAuthTimeoutSocket 20.272s
2019-11-25 19:44:35 |

2019-11-25 19:44:35 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2019-11-25 19:44:35 | ------------------------------------

2019-11-25 19:44:35 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-25 19:44:35 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2019-11-25 19:44:35 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

2019-11-25 19:44:35 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=590 thread=1] Connector  state changed: null->connecting

2019-11-25 19:44:35 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=590 thread=1] DNS entry stored in session object: localhost:5222

2019-11-25 19:44:35 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=590 thread=1] Preparing connection to [localhost:5222]

2019-11-25 19:44:35 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=590 thread=1] Opening connection to localhost/127.0.0.1:5222

2019-11-25 19:44:35 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=590 thread=1] Connector  state changed: connecting->connected

2019-11-25 19:44:35 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=590 thread=1] Whitespace ping period is setted to nullms

2019-11-25 19:44:35 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-25 19:44:35 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"><required/></starttls><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2019-11-25 19:44:35 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=590 thread=3832] Start TLS

2019-11-25 19:44:35 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=590 thread=3834] Proceeding TLS

2019-11-25 19:44:35 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=590 thread=3834] Start handshake

2019-11-25 19:44:35 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

2019-11-25 19:44:35 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-25 19:44:35 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>SCRAM-SHA-256</mechanism><mechanism>SCRAM-SHA-1</mechanism><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2019-11-25 19:44:55 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=590 thread=3834] Connector  state changed: connected->disconnected

2019-11-25 19:44:55 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=590 thread=3834] Stream terminated

2019-11-25 19:44:55 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-11-25 19:44:55 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-11-25 19:44:55 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-25 19:44:55 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2019-11-25 19:44:55 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

2019-11-25 19:44:55 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=591 thread=1] Connector  state changed: null->connecting

2019-11-25 19:44:55 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=591 thread=1] DNS entry stored in session object: localhost:5222

2019-11-25 19:44:55 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=591 thread=1] Preparing connection to [localhost:5222]

2019-11-25 19:44:55 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=591 thread=1] Opening connection to localhost/127.0.0.1:5222

2019-11-25 19:44:55 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=591 thread=1] Connector  state changed: connecting->connected

2019-11-25 19:44:55 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=591 thread=1] Whitespace ping period is setted to nullms

2019-11-25 19:44:55 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"><required/></starttls><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2019-11-25 19:44:55 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=591 thread=3832] Start TLS

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

2019-11-25 19:44:55 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=591 thread=3839] Proceeding TLS

2019-11-25 19:44:55 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=591 thread=3839] Start handshake

2019-11-25 19:44:55 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>SCRAM-SHA-256</mechanism><mechanism>SCRAM-SHA-1</mechanism><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2019-11-25 19:44:55 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2019-11-25 19:44:55 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX3NmMXBlOTA1MzEscj1oNDdneW14ZlJGR3Q1VUI4WFVZSQ==</auth>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1oNDdneW14ZlJGR3Q1VUI4WFVZSTNNRXpwb0UxeHBDeTdWN0dReGVhLHM9T0ZTNTFXZXVDNlpoVnc9PSxpPTQwOTY=</challenge>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9aDQ3Z3lteGZSRkd0NVVCOFhVWUkzTUV6cG9FMXhwQ3k3VjdHUXhlYSxwPUxteFl6a29QVHJKUEoydUYwa1IwdXh1dW95cEdRc21udUh1SlJGQ0t0WXc9</response>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1KN0kwZXgwNERhQTlNTGw1Z3c1c0Z0M1R5S0RaMUdUd1RQSklmcDU4OUI0PQ==</success>

2019-11-25 19:44:55 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-25 19:44:55 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-25 19:44:55 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><register xmlns="http://jabber.org/features/iq-register"/><csi xmlns="urn:xmpp:csi:0"/><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/><session xmlns="urn:ietf:params:xml:ns:xmpp-session"><optional/></session><c hash="SHA-1" node="https://tigase.net/tigase-xmpp-server" ver="bt2mj6vq9J3s6VE0/7D8Mo0TIoU=" xmlns="http://jabber.org/protocol/caps"/></features>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><register xmlns="http://jabber.org/features/iq-register"/><csi xmlns="urn:xmpp:csi:0"/><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/><session xmlns="urn:ietf:params:xml:ns:xmpp-session"><optional/></session><c hash="SHA-1" node="https://tigase.net/tigase-xmpp-server" ver="bt2mj6vq9J3s6VE0/7D8Mo0TIoU=" xmlns="http://jabber.org/protocol/caps"/></features>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><register xmlns="http://jabber.org/features/iq-register"/><csi xmlns="urn:xmpp:csi:0"/><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/><session xmlns="urn:ietf:params:xml:ns:xmpp-session"><optional/></session><c hash="SHA-1" node="https://tigase.net/tigase-xmpp-server" ver="bt2mj6vq9J3s6VE0/7D8Mo0TIoU=" xmlns="http://jabber.org/protocol/caps"/></features>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost >> <iq xmlns="jabber:client" id="3gMeABfP3cwmViNGmWXofZ1" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost >> <iq xmlns="jabber:client" id="6hN0l5gECrkROCsZsnfxjOK" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost << <iq to="jaxmpp__sf1pe90531@localhost/993927746-tigase-290" type="result" id="3gMeABfP3cwmViNGmWXofZ1" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__sf1pe90531@localhost/993927746-tigase-290</jid></bind></iq>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost >> <iq xmlns="jabber:client" id="bZTt9KHuYapi3BfJEq7JNIM" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-25 19:44:55 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost/993927746-tigase-290 >> <iq xmlns="jabber:client" id="Yn1KCAeLZp7m9l1rY4s7Gze" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost/993927746-tigase-290 << <iq to="jaxmpp__sf1pe90531@localhost/993927746-tigase-291" type="result" id="6hN0l5gECrkROCsZsnfxjOK" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__sf1pe90531@localhost/993927746-tigase-291</jid></bind></iq>

2019-11-25 19:44:55 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost/993927746-tigase-291 >> <iq xmlns="jabber:client" id="IdvACrYW6h2xzbBoU5FFsgA" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost/993927746-tigase-291 << <iq to="jaxmpp__sf1pe90531@localhost/993927746-tigase-292" type="result" id="bZTt9KHuYapi3BfJEq7JNIM" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__sf1pe90531@localhost/993927746-tigase-292</jid></bind></iq>

2019-11-25 19:44:55 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost/993927746-tigase-292 >> <iq xmlns="jabber:client" id="mp3whKCvvlOY0j5Bv8HrdPK" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost/993927746-tigase-292 << <iq to="jaxmpp__sf1pe90531@localhost/993927746-tigase-292" type="result" id="Yn1KCAeLZp7m9l1rY4s7Gze" xmlns="jabber:client"/>

2019-11-25 19:44:55 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost/993927746-tigase-292 >> <iq to="localhost" id="oai9q7JNIMCxxvjKVT7DmQ0" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost/993927746-tigase-292 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost/993927746-tigase-292 << <enabled max="60" resume="true" id="e7d82319-8c62-439d-9f22-d5dbf7a3b2db" location="d4270859fb27" xmlns="urn:xmpp:sm:3"/>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost/993927746-tigase-292 >> <iq id="rdpGHwoQZrjVYnNVfAiU1ub" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost/993927746-tigase-292 << <iq to="jaxmpp__sf1pe90531@localhost/993927746-tigase-292" type="result" id="IdvACrYW6h2xzbBoU5FFsgA" xmlns="jabber:client"/>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost/993927746-tigase-292 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost/993927746-tigase-292 << <iq to="jaxmpp__sf1pe90531@localhost/993927746-tigase-292" type="result" id="mp3whKCvvlOY0j5Bv8HrdPK" xmlns="jabber:client"/>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost/993927746-tigase-292 >> <iq to="localhost" id="ibh0urnNPQOThTUao5DHHwt" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost/993927746-tigase-292 >> <iq to="localhost" id="b60HBEv6cCj6FPHDs2lbHwo" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost/993927746-tigase-292 >> <iq id="dcglTSKIvurnNPQOThTUao5" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost/993927746-tigase-292 >> <iq id="j5TDJXX9u6trdysYfXlZ6Dj" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost/993927746-tigase-292 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost/993927746-tigase-292 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost/993927746-tigase-292 << <iq to="jaxmpp__sf1pe90531@localhost/993927746-tigase-292" type="result" id="oai9q7JNIMCxxvjKVT7DmQ0" from="localhost" xmlns="jabber:client"><query xmlns="http://jabber.org/protocol/disco#info"><identity category="component" name="Tigase ver. 8.1.0-SNAPSHOT-b10580/f55efd39" type="router"/><identity category="server" name="Tigase ver. 8.1.0-SNAPSHOT-b10580/f55efd39" type="im"/><feature var="http://jabber.org/protocol/commands"/><x type="result" xmlns="jabber:x:data"><field var="FORM_TYPE" type="hidden"><value>http://jabber.org/network/serverinfo</value></field><field var="abuse-addresses" type="text-multi"><value>mailto:abuse@localhost</value><value>xmpp:abuse@localhost</value></field></x><feature var="urn:xmpp:carbons:2"/><feature var="http://jabber.org/protocol/stats"/><feature var="vcard-temp"/><feature var="jabber:iq:auth"/><feature var="http://jabber.org/protocol/amp"/><feature var="msgoffline"/><feature var="http://jabber.org/protocol/disco#info"/><feature var="http://jabber.org/protocol/disco#items"/><feature var="urn:xmpp:blocking"/><feature var="urn:xmpp:ping"/><feature var="urn:ietf:params:xml:ns:xmpp-sasl"/><feature var="http://jabber.org/protocol/pubsub"/><feature var="http://jabber.org/protocol/pubsub#owner"/><feature var="http://jabber.org/protocol/pubsub#publish"/><identity category="pubsub" type="pep"/><feature var="urn:xmpp:pep-vcard-conversion:0"/><feature var="urn:xmpp:bookmarks-conversion:0"/><feature var="urn:xmpp:archive:auto"/><feature var="urn:xmpp:archive:manage"/><feature var="urn:xmpp:push:0"/><feature var="tigase:push:away:0"/><feature var="tigase:push:encrypt:0"/><feature var="tigase:push:ignore-unknown:0"/><feature var="tigase:push:muc:0"/><feature var="tigase:push:priority:0"/><feature var="tigase:push:muted:0"/><feature var="jabber:iq:roster"/><feature var="jabber:iq:roster-dynamic"/><feature var="urn:xmpp:mam:1"/><feature var="jabber:iq:version"/><feature var="urn:xmpp:time"/><feature var="jabber:iq:privacy"/><feature var="urn:ietf:params:xml:ns:xmpp-bind"/><feature var="http://jabber.org/protocol/commands"/><feature var="urn:ietf:params:xml:ns:vcard-4.0"/><feature var="urn:ietf:params:xml:ns:xmpp-session"/><feature var="jabber:iq:private"/></query></iq>

2019-11-25 19:44:55 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=591 thread=1] Connector  state changed: connected->disconnecting

2019-11-25 19:44:55 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=591 thread=1] Terminating XMPP Stream

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost/993927746-tigase-292 << <iq to="jaxmpp__sf1pe90531@localhost/993927746-tigase-292" type="result" id="rdpGHwoQZrjVYnNVfAiU1ub" xmlns="jabber:client"><query xmlns="jabber:iq:roster"/></iq>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost/993927746-tigase-292 << <presence to="jaxmpp__sf1pe90531@localhost" from="jaxmpp__sf1pe90531@localhost/993927746-tigase-292" xmlns="jabber:client"><c node="http://tigase.org/jaxmpp" hash="sha-1" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" xmlns="http://jabber.org/protocol/caps"/></presence>

2019-11-25 19:44:55 | jaxmpp_ :: jaxmpp__sf1pe90531@localhost/993927746-tigase-292 << <iq to="jaxmpp__sf1pe90531@localhost/993927746-tigase-292" type="result" id="dcglTSKIvurnNPQOThTUao5" xmlns="jabber:client"><query xmlns="jabber:iq:roster"/></iq>

2019-11-25 19:44:55 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-11-25 19:44:55 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

2019-11-25 19:44:55 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session]

2019-11-25 19:44:55 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-11-25 19:44:55 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=591 thread=3839] Connector  state changed: disconnecting->disconnected

testStateAfterAuthTimeoutWebSocket 20.358s
2019-11-25 19:44:56 |

2019-11-25 19:44:56 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2019-11-25 19:44:56 | ------------------------------------

2019-11-25 19:44:56 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-25 19:44:56 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2019-11-25 19:44:56 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using WebSocketConnector

2019-11-25 19:44:56 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Start connector.

2019-11-25 19:44:56 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: null->connecting

2019-11-25 19:44:56 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Preparing connection to localhost

2019-11-25 19:44:56 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Opening connection to localhost/127.0.0.1:5290

2019-11-25 19:44:56 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connecting->connected

2019-11-25 19:44:56 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Whitespace ping period is setted to nullms

2019-11-25 19:44:56 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-25 19:44:56 | jaxmpp_ :: jaxmpp__2gbio90532@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>SCRAM-SHA-256</mechanism><mechanism>SCRAM-SHA-1</mechanism><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2019-11-25 19:45:16 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connected->disconnecting

2019-11-25 19:45:16 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.terminateStream: Terminating XMPP Stream

2019-11-25 19:45:16 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.onStreamTerminate: Stream terminated

2019-11-25 19:45:16 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-11-25 19:45:16 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: disconnecting->disconnected

2019-11-25 19:45:16 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-25 19:45:16 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2019-11-25 19:45:16 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using WebSocketConnector

2019-11-25 19:45:16 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Start connector.

2019-11-25 19:45:16 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: null->connecting

2019-11-25 19:45:16 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Preparing connection to localhost

2019-11-25 19:45:16 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Opening connection to localhost/127.0.0.1:5290

2019-11-25 19:45:16 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connecting->connected

2019-11-25 19:45:16 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Whitespace ping period is setted to nullms

2019-11-25 19:45:16 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-25 19:45:16 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2019-11-25 19:45:16 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-11-25 19:45:16 | jaxmpp_ :: jaxmpp__2gbio90532@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfXzJnYmlvOTA1MzIscj1hSEs1d3dRUFRvdVc2VHBvRkl3WA==</auth>

2019-11-25 19:45:16 | jaxmpp_ :: jaxmpp__2gbio90532@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>SCRAM-SHA-256</mechanism><mechanism>SCRAM-SHA-1</mechanism><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2019-11-25 19:45:16 | jaxmpp_ :: jaxmpp__2gbio90532@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1hSEs1d3dRUFRvdVc2VHBvRkl3WDhaVUl5UFVPVkdYR1UzZGpoNE1WLHM9NTUrSUt3RUFldFVQaFE9PSxpPTQwOTY=</challenge>

2019-11-25 19:45:16 | jaxmpp_ :: jaxmpp__2gbio90532@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9YUhLNXd3UVBUb3VXNlRwb0ZJd1g4WlVJeVBVT1ZHWEdVM2RqaDRNVixwPVFPbG5hOUNCTmpKNUpYamhOeHpiWHNZdlJrRGJKci9BMk1VdENHcTUyNGs9</response>

2019-11-25 19:45:16 | jaxmpp_ :: jaxmpp__2gbio90532@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1kWEdQeWNiaENaVlVISDVTSmxjU0JLNWZuTVFGeTN0Q0paeFNsVnNpdGMwPQ==</success>

2019-11-25 19:45:16 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-25 19:45:16 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-25 19:45:16 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-25 19:45:16 | jaxmpp_ :: jaxmpp__2gbio90532@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><register xmlns="http://jabber.org/features/iq-register"/><csi xmlns="urn:xmpp:csi:0"/><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/><session xmlns="urn:ietf:params:xml:ns:xmpp-session"><optional/></session><c hash="SHA-1" node="https://tigase.net/tigase-xmpp-server" ver="bt2mj6vq9J3s6VE0/7D8Mo0TIoU=" xmlns="http://jabber.org/protocol/caps"/></features>

2019-11-25 19:45:16 | jaxmpp_ :: jaxmpp__2gbio90532@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><register xmlns="http://jabber.org/features/iq-register"/><csi xmlns="urn:xmpp:csi:0"/><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/><session xmlns="urn:ietf:params:xml:ns:xmpp-session"><optional/></session><c hash="SHA-1" node="https://tigase.net/tigase-xmpp-server" ver="bt2mj6vq9J3s6VE0/7D8Mo0TIoU=" xmlns="http://jabber.org/protocol/caps"/></features>

2019-11-25 19:45:16 | jaxmpp_ :: jaxmpp__2gbio90532@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><register xmlns="http://jabber.org/features/iq-register"/><csi xmlns="urn:xmpp:csi:0"/><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/><session xmlns="urn:ietf:params:xml:ns:xmpp-session"><optional/></session><c hash="SHA-1" node="https://tigase.net/tigase-xmpp-server" ver="bt2mj6vq9J3s6VE0/7D8Mo0TIoU=" xmlns="http://jabber.org/protocol/caps"/></features>

2019-11-25 19:45:16 | jaxmpp_ :: jaxmpp__2gbio90532@localhost >> <iq xmlns="jabber:client" id="xnE7FDodthX08AncBiAoRcR" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-25 19:45:16 | jaxmpp_ :: jaxmpp__2gbio90532@localhost >> <iq xmlns="jabber:client" id="Mb2q4dUh39xgEzDBk04rl7x" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-25 19:45:16 | jaxmpp_ :: jaxmpp__2gbio90532@localhost >> <iq xmlns="jabber:client" id="JjoAnQGAfYpjFzkMP9Do8kX" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-25 19:45:16 | jaxmpp_ :: jaxmpp__2gbio90532@localhost << <iq to="jaxmpp__2gbio90532@localhost/993927746-tigase-293" type="result" id="xnE7FDodthX08AncBiAoRcR" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__2gbio90532@localhost/993927746-tigase-293</jid></bind></iq>

2019-11-25 19:45:16 | jaxmpp_ :: jaxmpp__2gbio90532@localhost << <iq to="jaxmpp__2gbio90532@localhost/993927746-tigase-294" type="result" id="Mb2q4dUh39xgEzDBk04rl7x" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__2gbio90532@localhost/993927746-tigase-294</jid></bind></iq>

2019-11-25 19:45:16 | jaxmpp_ :: jaxmpp__2gbio90532@localhost << <iq to="jaxmpp__2gbio90532@localhost/993927746-tigase-295" type="result" id="JjoAnQGAfYpjFzkMP9Do8kX" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__2gbio90532@localhost/993927746-tigase-295</jid></bind></iq>

2019-11-25 19:45:16 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-25 19:45:16 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-25 19:45:16 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-25 19:45:16 | jaxmpp_ :: jaxmpp__2gbio90532@localhost/993927746-tigase-295 >> <iq xmlns="jabber:client" id="ZsN4u2ndR1aLztlMGGzAnQG" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-11-25 19:45:16 | jaxmpp_ :: jaxmpp__2gbio90532@localhost/993927746-tigase-295 >> <iq xmlns="jabber:client" id="mDiZdCmZthGIuh1tfCFn5ze" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-11-25 19:45:16 | jaxmpp_ :: jaxmpp__2gbio90532@localhost/993927746-tigase-295 >> <iq xmlns="jabber:client" id="Bhcbp9Hu6wfW5gwgBGP9lV2" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-11-25 19:45:16 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connected->disconnecting

2019-11-25 19:45:16 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.terminateStream: Terminating XMPP Stream

2019-11-25 19:45:16 | jaxmpp_ :: jaxmpp__2gbio90532@localhost/993927746-tigase-295 << <iq to="jaxmpp__2gbio90532@localhost/993927746-tigase-295" type="result" id="ZsN4u2ndR1aLztlMGGzAnQG" xmlns="jabber:client"/>

2019-11-25 19:45:16 | jaxmpp_ :: jaxmpp__2gbio90532@localhost/993927746-tigase-295 << <iq to="jaxmpp__2gbio90532@localhost/993927746-tigase-295" type="result" id="mDiZdCmZthGIuh1tfCFn5ze" xmlns="jabber:client"/>

2019-11-25 19:45:16 | jaxmpp_ :: jaxmpp__2gbio90532@localhost/993927746-tigase-295 << <iq to="jaxmpp__2gbio90532@localhost/993927746-tigase-295" type="result" id="Bhcbp9Hu6wfW5gwgBGP9lV2" xmlns="jabber:client"/>

2019-11-25 19:45:16 | tigase.jaxmpp.j2se.eventbus.ThreadSafeEventBus$2.run:

2019-11-25 19:45:16 | tigase.jaxmpp.j2se.eventbus.ThreadSafeEventBus$2.run:

2019-11-25 19:45:16 | tigase.jaxmpp.j2se.eventbus.ThreadSafeEventBus$2.run:

2019-11-25 19:45:16 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

2019-11-25 19:45:16 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session]

2019-11-25 19:45:16 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-11-25 19:45:16 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: disconnecting->disconnected

testStateAfterConnectionFailureBosh 0.793s
2019-11-25 19:45:16 |

2019-11-25 19:45:16 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2019-11-25 19:45:16 | ------------------------------------

2019-11-25 19:45:16 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-25 19:45:16 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2019-11-25 19:45:16 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using BOSHConnector

2019-11-25 19:45:16 | tigase.jaxmpp.j2se.connectors.bosh.BoshWorker.run: Connection error

2019-11-25 19:45:16 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onError: responseCode=0

2019-11-25 19:45:16 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session, stream]

2019-11-25 19:45:16 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-25 19:45:16 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2019-11-25 19:45:16 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using BOSHConnector

2019-11-25 19:45:16 | jaxmpp_ :: jaxmpp__68o7zj0533@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>SCRAM-SHA-256</mechanism><mechanism>SCRAM-SHA-1</mechanism><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2019-11-25 19:45:16 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2019-11-25 19:45:16 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-11-25 19:45:16 | jaxmpp_ :: jaxmpp__68o7zj0533@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfXzY4bzd6ajA1MzMscj03WGVwWGxBbzFwZzA1bHdIWkQ1cQ==</auth>

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__68o7zj0533@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj03WGVwWGxBbzFwZzA1bHdIWkQ1cTlWUkJzUTBtRzd5QWxud0w1YTRaLHM9eFJtdld4TzhaT2hqWGc9PSxpPTQwOTY=</challenge>

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__68o7zj0533@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9N1hlcFhsQW8xcGcwNWx3SFpENXE5VlJCc1EwbUc3eUFsbndMNWE0WixwPWhiUUtYQjFabXZBY2xJS3h4QzlKS3I4WEJCMVUyc3hXY0dSeS9ORlBYbUU9</response>

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__68o7zj0533@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1MbjR4NTZGTjMyOE5URkdaM3QzbDFPbUdWWWpyaDJvSXBEUitpZXNKWmdVPQ==</success>

2019-11-25 19:45:17 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__68o7zj0533@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><register xmlns="http://jabber.org/features/iq-register"/><csi xmlns="urn:xmpp:csi:0"/><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/><session xmlns="urn:ietf:params:xml:ns:xmpp-session"><optional/></session><c hash="SHA-1" node="https://tigase.net/tigase-xmpp-server" ver="bt2mj6vq9J3s6VE0/7D8Mo0TIoU=" xmlns="http://jabber.org/protocol/caps"/></features>

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__68o7zj0533@localhost >> <iq xmlns="jabber:client" id="6HeR3v6kY9KHuYapi3BfJEq" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__68o7zj0533@localhost << <iq to="jaxmpp__68o7zj0533@localhost/993927746-tigase-296" type="result" id="6HeR3v6kY9KHuYapi3BfJEq" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__68o7zj0533@localhost/993927746-tigase-296</jid></bind></iq>

2019-11-25 19:45:17 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__68o7zj0533@localhost/993927746-tigase-296 >> <iq to="localhost" id="KJi9oMMDKXpRX6kVl1aGq9L" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__68o7zj0533@localhost/993927746-tigase-296 >> <iq id="LvACeGrmbRLLIynfPMUS3zz" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__68o7zj0533@localhost/993927746-tigase-296 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-25 19:45:17 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onTerminate: Stream terminated. responseCode=200

2019-11-25 19:45:17 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onError: responseCode=500

2019-11-25 19:45:17 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

2019-11-25 19:45:17 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session]

testStateAfterConnectionFailureSocket 0.247s
2019-11-25 19:45:17 |

2019-11-25 19:45:17 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2019-11-25 19:45:17 | ------------------------------------

2019-11-25 19:45:17 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-25 19:45:17 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2019-11-25 19:45:17 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

2019-11-25 19:45:17 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=595 thread=1] Connector  state changed: null->connecting

2019-11-25 19:45:17 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=595 thread=1] DNS entry stored in session object: missing:5222

2019-11-25 19:45:17 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=595 thread=1] Preparing connection to [missing:5222]

2019-11-25 19:45:17 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=595 thread=1] missing. Trying next.

2019-11-25 19:45:17 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=595 thread=1] Connector  state changed: connecting->disconnected

2019-11-25 19:45:17 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session, stream]

2019-11-25 19:45:17 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-25 19:45:17 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2019-11-25 19:45:17 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

2019-11-25 19:45:17 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=596 thread=1] Connector  state changed: null->connecting

2019-11-25 19:45:17 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=596 thread=1] DNS entry stored in session object: localhost:5222

2019-11-25 19:45:17 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=596 thread=1] Preparing connection to [localhost:5222]

2019-11-25 19:45:17 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=596 thread=1] Opening connection to localhost/127.0.0.1:5222

2019-11-25 19:45:17 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=596 thread=1] Connector  state changed: connecting->connected

2019-11-25 19:45:17 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=596 thread=1] Whitespace ping period is setted to nullms

2019-11-25 19:45:17 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__jqt59b0534@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"><required/></starttls><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2019-11-25 19:45:17 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=596 thread=3893] Start TLS

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__jqt59b0534@localhost >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

2019-11-25 19:45:17 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=596 thread=3897] Proceeding TLS

2019-11-25 19:45:17 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=596 thread=3897] Start handshake

2019-11-25 19:45:17 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__jqt59b0534@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>SCRAM-SHA-256</mechanism><mechanism>SCRAM-SHA-1</mechanism><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2019-11-25 19:45:17 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2019-11-25 19:45:17 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__jqt59b0534@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX2pxdDU5YjA1MzQscj1qUlN4TmVtTXZqbkdNR2p2SkNuUg==</auth>

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__jqt59b0534@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1qUlN4TmVtTXZqbkdNR2p2SkNuUmhQT1lGbjBQYk94eDJPeUVwZngyLHM9eW8ybzFWbUdPUGhneWc9PSxpPTQwOTY=</challenge>

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__jqt59b0534@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9alJTeE5lbU12am5HTUdqdkpDblJoUE9ZRm4wUGJPeHgyT3lFcGZ4MixwPWdIUHB3Rzk3OE9NdzUzRGI2Sk1ZSWNMRWhEMkZNWDhpRWFsOVBxWXIwaUU9</response>

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__jqt59b0534@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj02L0I5UW1ydGl3Y1ZVSjR6aGNxOWxSUGl5VkRuaG84a2FneGdxbHBidzc0PQ==</success>

2019-11-25 19:45:17 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__jqt59b0534@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><register xmlns="http://jabber.org/features/iq-register"/><csi xmlns="urn:xmpp:csi:0"/><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/><session xmlns="urn:ietf:params:xml:ns:xmpp-session"><optional/></session><c hash="SHA-1" node="https://tigase.net/tigase-xmpp-server" ver="bt2mj6vq9J3s6VE0/7D8Mo0TIoU=" xmlns="http://jabber.org/protocol/caps"/></features>

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__jqt59b0534@localhost >> <iq xmlns="jabber:client" id="cGZxwfAaybQ9NDvcwj7zgSO" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__jqt59b0534@localhost << <iq to="jaxmpp__jqt59b0534@localhost/993927746-tigase-297" type="result" id="cGZxwfAaybQ9NDvcwj7zgSO" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__jqt59b0534@localhost/993927746-tigase-297</jid></bind></iq>

2019-11-25 19:45:17 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__jqt59b0534@localhost/993927746-tigase-297 >> <iq xmlns="jabber:client" id="bvqwfW5gwgBGP9lV2cFPZ6y" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__jqt59b0534@localhost/993927746-tigase-297 << <iq to="jaxmpp__jqt59b0534@localhost/993927746-tigase-297" type="result" id="bvqwfW5gwgBGP9lV2cFPZ6y" xmlns="jabber:client"/>

2019-11-25 19:45:17 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__jqt59b0534@localhost/993927746-tigase-297 >> <iq to="localhost" id="GulaEvs7kEw7IThBr4gN5v8" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__jqt59b0534@localhost/993927746-tigase-297 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/>

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__jqt59b0534@localhost/993927746-tigase-297 << <enabled max="60" resume="true" id="52e298ff-fba6-4e0e-bffe-fc207cec456b" location="d4270859fb27" xmlns="urn:xmpp:sm:3"/>

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__jqt59b0534@localhost/993927746-tigase-297 >> <iq id="LCHQGAfYpjFzkMP9Do8kXnb" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__jqt59b0534@localhost/993927746-tigase-297 << <iq to="jaxmpp__jqt59b0534@localhost/993927746-tigase-297" type="result" id="GulaEvs7kEw7IThBr4gN5v8" from="localhost" xmlns="jabber:client"><query xmlns="http://jabber.org/protocol/disco#info"><identity category="component" name="Tigase ver. 8.1.0-SNAPSHOT-b10580/f55efd39" type="router"/><identity category="server" name="Tigase ver. 8.1.0-SNAPSHOT-b10580/f55efd39" type="im"/><feature var="http://jabber.org/protocol/commands"/><x type="result" xmlns="jabber:x:data"><field var="FORM_TYPE" type="hidden"><value>http://jabber.org/network/serverinfo</value></field><field var="abuse-addresses" type="text-multi"><value>mailto:abuse@localhost</value><value>xmpp:abuse@localhost</value></field></x><feature var="urn:xmpp:carbons:2"/><feature var="http://jabber.org/protocol/stats"/><feature var="vcard-temp"/><feature var="jabber:iq:auth"/><feature var="http://jabber.org/protocol/amp"/><feature var="msgoffline"/><feature var="http://jabber.org/protocol/disco#info"/><feature var="http://jabber.org/protocol/disco#items"/><feature var="urn:xmpp:blocking"/><feature var="urn:xmpp:ping"/><feature var="urn:ietf:params:xml:ns:xmpp-sasl"/><feature var="http://jabber.org/protocol/pubsub"/><feature var="http://jabber.org/protocol/pubsub#owner"/><feature var="http://jabber.org/protocol/pubsub#publish"/><identity category="pubsub" type="pep"/><feature var="urn:xmpp:pep-vcard-conversion:0"/><feature var="urn:xmpp:bookmarks-conversion:0"/><feature var="urn:xmpp:archive:auto"/><feature var="urn:xmpp:archive:manage"/><feature var="urn:xmpp:push:0"/><feature var="tigase:push:away:0"/><feature var="tigase:push:encrypt:0"/><feature var="tigase:push:ignore-unknown:0"/><feature var="tigase:push:muc:0"/><feature var="tigase:push:priority:0"/><feature var="tigase:push:muted:0"/><feature var="jabber:iq:roster"/><feature var="jabber:iq:roster-dynamic"/><feature var="urn:xmpp:mam:1"/><feature var="jabber:iq:version"/><feature var="urn:xmpp:time"/><feature var="jabber:iq:privacy"/><feature var="urn:ietf:params:xml:ns:xmpp-bind"/><feature var="http://jabber.org/protocol/commands"/><feature var="urn:ietf:params:xml:ns:vcard-4.0"/><feature var="urn:ietf:params:xml:ns:xmpp-session"/><feature var="jabber:iq:private"/></query></iq>

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__jqt59b0534@localhost/993927746-tigase-297 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__jqt59b0534@localhost/993927746-tigase-297 << <iq to="jaxmpp__jqt59b0534@localhost/993927746-tigase-297" type="result" id="LCHQGAfYpjFzkMP9Do8kXnb" xmlns="jabber:client"><query xmlns="jabber:iq:roster"/></iq>

2019-11-25 19:45:17 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=596 thread=1] Connector  state changed: connected->disconnecting

2019-11-25 19:45:17 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=596 thread=1] Terminating XMPP Stream

2019-11-25 19:45:17 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-11-25 19:45:17 | jaxmpp_ :: jaxmpp__jqt59b0534@localhost/993927746-tigase-297 << <presence to="jaxmpp__jqt59b0534@localhost" from="jaxmpp__jqt59b0534@localhost/993927746-tigase-297" xmlns="jabber:client"><c node="http://tigase.org/jaxmpp" hash="sha-1" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" xmlns="http://jabber.org/protocol/caps"/></presence>

2019-11-25 19:45:17 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-11-25 19:45:17 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=596 thread=3897] Connector  state changed: disconnecting->disconnected

2019-11-25 19:45:17 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

2019-11-25 19:45:17 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session]

testStateAfterConnectionFailureWebSocket 0.355s
2019-11-25 19:45:18 |

2019-11-25 19:45:18 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2019-11-25 19:45:18 | ------------------------------------

2019-11-25 19:45:18 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-25 19:45:18 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2019-11-25 19:45:18 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using WebSocketConnector

2019-11-25 19:45:18 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Start connector.

2019-11-25 19:45:18 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: null->connecting

2019-11-25 19:45:18 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connecting->disconnected

2019-11-25 19:45:18 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session, stream]

2019-11-25 19:45:18 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-25 19:45:18 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2019-11-25 19:45:18 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using WebSocketConnector

2019-11-25 19:45:18 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Start connector.

2019-11-25 19:45:18 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: null->connecting

2019-11-25 19:45:18 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Preparing connection to localhost

2019-11-25 19:45:18 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Opening connection to localhost/127.0.0.1:5290

2019-11-25 19:45:18 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connecting->connected

2019-11-25 19:45:18 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Whitespace ping period is setted to nullms

2019-11-25 19:45:18 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-25 19:45:18 | jaxmpp_ :: jaxmpp__jgyi3g0535@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>SCRAM-SHA-256</mechanism><mechanism>SCRAM-SHA-1</mechanism><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2019-11-25 19:45:18 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2019-11-25 19:45:18 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-11-25 19:45:18 | jaxmpp_ :: jaxmpp__jgyi3g0535@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX2pneWkzZzA1MzUscj1RN2UwQkVnQ2FSYzl6MGlUOHpYTA==</auth>

2019-11-25 19:45:18 | jaxmpp_ :: jaxmpp__jgyi3g0535@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1RN2UwQkVnQ2FSYzl6MGlUOHpYTFhOdUltQktHNk1lZFlMaEE3RTFKLHM9WitrTDdtVSsyeDJNd2c9PSxpPTQwOTY=</challenge>

2019-11-25 19:45:18 | jaxmpp_ :: jaxmpp__jgyi3g0535@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9UTdlMEJFZ0NhUmM5ejBpVDh6WExYTnVJbUJLRzZNZWRZTGhBN0UxSixwPXA1eWhmbzEzejdSTFFQT0Z0UCtlZ1g0dC9QeER3R0I5QWMzaW1KbDRBVWs9</response>

2019-11-25 19:45:18 | jaxmpp_ :: jaxmpp__jgyi3g0535@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1wcS81TXlUNWM3b0lkd2o0MU5PVmszaUNzRjN2NHNmd3VPUG52dERmN2N3PQ==</success>

2019-11-25 19:45:18 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-25 19:45:18 | jaxmpp_ :: jaxmpp__jgyi3g0535@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><register xmlns="http://jabber.org/features/iq-register"/><csi xmlns="urn:xmpp:csi:0"/><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/><session xmlns="urn:ietf:params:xml:ns:xmpp-session"><optional/></session><c hash="SHA-1" node="https://tigase.net/tigase-xmpp-server" ver="bt2mj6vq9J3s6VE0/7D8Mo0TIoU=" xmlns="http://jabber.org/protocol/caps"/></features>

2019-11-25 19:45:18 | jaxmpp_ :: jaxmpp__jgyi3g0535@localhost >> <iq xmlns="jabber:client" id="xM3VhRQ7hTbs2oZq3co05EL" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-25 19:45:18 | jaxmpp_ :: jaxmpp__jgyi3g0535@localhost << <iq to="jaxmpp__jgyi3g0535@localhost/993927746-tigase-298" type="result" id="xM3VhRQ7hTbs2oZq3co05EL" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__jgyi3g0535@localhost/993927746-tigase-298</jid></bind></iq>

2019-11-25 19:45:18 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-25 19:45:18 | jaxmpp_ :: jaxmpp__jgyi3g0535@localhost/993927746-tigase-298 >> <iq xmlns="jabber:client" id="fHM00exyzDjRUW9NVYiEBFL" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-11-25 19:45:18 | jaxmpp_ :: jaxmpp__jgyi3g0535@localhost/993927746-tigase-298 << <iq to="jaxmpp__jgyi3g0535@localhost/993927746-tigase-298" type="result" id="fHM00exyzDjRUW9NVYiEBFL" xmlns="jabber:client"/>

2019-11-25 19:45:18 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management

2019-11-25 19:45:18 | jaxmpp_ :: jaxmpp__jgyi3g0535@localhost/993927746-tigase-298 >> <iq to="localhost" id="bDyMLY9oMMDKXpRX6kVl1aG" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-11-25 19:45:18 | jaxmpp_ :: jaxmpp__jgyi3g0535@localhost/993927746-tigase-298 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/>

2019-11-25 19:45:18 | jaxmpp_ :: jaxmpp__jgyi3g0535@localhost/993927746-tigase-298 >> <iq id="FVoeAubOPKuctqj7hNMGDLR" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-11-25 19:45:18 | jaxmpp_ :: jaxmpp__jgyi3g0535@localhost/993927746-tigase-298 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-25 19:45:18 | jaxmpp_ :: jaxmpp__jgyi3g0535@localhost/993927746-tigase-298 << <enabled max="60" resume="true" id="16eb319d-35d9-4d2b-8766-3980f7083956" location="d4270859fb27" xmlns="urn:xmpp:sm:3"/>

2019-11-25 19:45:18 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connected->disconnecting

2019-11-25 19:45:18 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.terminateStream: Terminating XMPP Stream

2019-11-25 19:45:18 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-11-25 19:45:18 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: disconnecting->disconnected

2019-11-25 19:45:18 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

2019-11-25 19:45:18 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session]