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

Test duration: 64.892s

Passed Tests
tigase.tests.jaxmpp.TestHandlingOfConnectionIssues
testStateAfterAuthTimeoutBosh 20.530s
2019-11-20 21:09:29 |

2019-11-20 21:09:29 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2019-11-20 21:09:29 | ------------------------------------

2019-11-20 21:09:29 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-20 21:09:29 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2019-11-20 21:09:29 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using BOSHConnector

2019-11-20 21:09:29 | jaxmpp_ :: jaxmpp__g3u7iy0518@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><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><register xmlns="http://jabber.org/features/iq-register"/><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-20 21:09:49 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onTerminate: Stream terminated. responseCode=200

2019-11-20 21:09:49 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-20 21:09:49 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2019-11-20 21:09:49 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using BOSHConnector

2019-11-20 21:09:49 | jaxmpp_ :: jaxmpp__g3u7iy0518@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><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><register xmlns="http://jabber.org/features/iq-register"/><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-20 21:09:49 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2019-11-20 21:09:49 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-11-20 21:09:49 | jaxmpp_ :: jaxmpp__g3u7iy0518@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX2czdTdpeTA1MTgscj1QVlQ0VTRkWXRYSXdBa016dkliOQ==</auth>

2019-11-20 21:09:49 | jaxmpp_ :: jaxmpp__g3u7iy0518@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1QVlQ0VTRkWXRYSXdBa016dkliOTJhSGRKd201amhDeTNqcUlDQzJpLHM9b1gwcG0xZ1JJczVwbEE9PSxpPTQwOTY=</challenge>

2019-11-20 21:09:49 | jaxmpp_ :: jaxmpp__g3u7iy0518@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9UFZUNFU0ZFl0WEl3QWtNenZJYjkyYUhkSndtNWpoQ3kzanFJQ0MyaSxwPWQ5V3NjcDNFYUs2TkJlaGEvWWxVdEw5a01rNlQ2RlFKNmltaDJBY2hNVk09</response>

2019-11-20 21:09:49 | jaxmpp_ :: jaxmpp__g3u7iy0518@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1vTDZ2b0xlcW5WU0d6WlJyMmpVU1ZBVXZZVnNhTFlEWE12SUVHOTM4eXhzPQ==</success>

2019-11-20 21:09:49 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-20 21:09:49 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-20 21:09:49 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-20 21:09:49 | jaxmpp_ :: jaxmpp__g3u7iy0518@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" ver="8SAx7sxxLI3422mjAeBbH2oWxJg=" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-11-20 21:09:49 | jaxmpp_ :: jaxmpp__g3u7iy0518@localhost >> <iq xmlns="jabber:client" id="zLktocsjQalN4xrVZYpUUSM" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-20 21:09:49 | jaxmpp_ :: jaxmpp__g3u7iy0518@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" ver="8SAx7sxxLI3422mjAeBbH2oWxJg=" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-11-20 21:09:49 | jaxmpp_ :: jaxmpp__g3u7iy0518@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" ver="8SAx7sxxLI3422mjAeBbH2oWxJg=" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-11-20 21:09:49 | jaxmpp_ :: jaxmpp__g3u7iy0518@localhost >> <iq xmlns="jabber:client" id="FxC6dxyvnNJsnQMCgPJMGMV" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-20 21:09:49 | jaxmpp_ :: jaxmpp__g3u7iy0518@localhost >> <iq xmlns="jabber:client" id="vBMZ1snbO28FyAbtqfRLFk7" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-20 21:09:49 | jaxmpp_ :: jaxmpp__g3u7iy0518@localhost << <iq type="result" xmlns="jabber:client" id="zLktocsjQalN4xrVZYpUUSM" to="jaxmpp__g3u7iy0518@localhost/993927746-tigase-276"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__g3u7iy0518@localhost/993927746-tigase-276</jid></bind></iq>

2019-11-20 21:09:49 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-20 21:09:49 | jaxmpp_ :: jaxmpp__g3u7iy0518@localhost/993927746-tigase-276 >> <iq to="localhost" id="FzEalN4xrVZYpUUSMRNUWiX" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-11-20 21:09:49 | jaxmpp_ :: jaxmpp__g3u7iy0518@localhost/993927746-tigase-276 >> <iq id="dQrFHr12xaqUQZ3qYm5gNDj" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-11-20 21:09:49 | jaxmpp_ :: jaxmpp__g3u7iy0518@localhost/993927746-tigase-276 << <iq type="result" xmlns="jabber:client" id="FxC6dxyvnNJsnQMCgPJMGMV" to="jaxmpp__g3u7iy0518@localhost/993927746-tigase-277"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__g3u7iy0518@localhost/993927746-tigase-277</jid></bind></iq>

2019-11-20 21:09:49 | jaxmpp_ :: jaxmpp__g3u7iy0518@localhost/993927746-tigase-276 << <iq type="result" xmlns="jabber:client" id="vBMZ1snbO28FyAbtqfRLFk7" to="jaxmpp__g3u7iy0518@localhost/993927746-tigase-278"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__g3u7iy0518@localhost/993927746-tigase-278</jid></bind></iq>

2019-11-20 21:09:49 | jaxmpp_ :: jaxmpp__g3u7iy0518@localhost/993927746-tigase-278 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-20 21:09:49 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-20 21:09:49 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-20 21:09:49 | jaxmpp_ :: jaxmpp__g3u7iy0518@localhost/993927746-tigase-278 >> <iq to="localhost" id="Ho3BGLTPNADmOGo5fOKUbsb" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-11-20 21:09:49 | jaxmpp_ :: jaxmpp__g3u7iy0518@localhost/993927746-tigase-278 >> <iq to="localhost" id="dStJPHx4BiGqS3bGuo9o39l" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-11-20 21:09:49 | jaxmpp_ :: jaxmpp__g3u7iy0518@localhost/993927746-tigase-278 >> <iq id="3SrHQ6gV4CfBGLTPNADmOGo" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-11-20 21:09:49 | jaxmpp_ :: jaxmpp__g3u7iy0518@localhost/993927746-tigase-278 << <iq type="result" xmlns="jabber:client" id="FzEalN4xrVZYpUUSMRNUWiX" from="localhost" to="jaxmpp__g3u7iy0518@localhost/993927746-tigase-278"><query xmlns="http://jabber.org/protocol/disco#info"><identity type="router" name="Tigase ver. 8.1.0-SNAPSHOT-b10574/f55efd39" category="component"/><identity type="im" name="Tigase ver. 8.1.0-SNAPSHOT-b10574/f55efd39" category="server"/><feature var="http://jabber.org/protocol/commands"/><x xmlns="jabber:x:data" type="result"><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="jabber:iq:auth"/><feature var="vcard-temp"/><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 type="pep" category="pubsub"/><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:encrypt:0"/><feature var="tigase:push:ignore-unknown:0"/><feature var="tigase:push:muc:0"/><feature var="tigase:push:muted:0"/><feature var="tigase:push:priority: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-20 21:09:49 | jaxmpp_ :: jaxmpp__g3u7iy0518@localhost/993927746-tigase-278 >> <iq id="zTsJUewr6GnRcNXX36FqWWU" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-11-20 21:09:49 | jaxmpp_ :: jaxmpp__g3u7iy0518@localhost/993927746-tigase-278 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-20 21:09:49 | jaxmpp_ :: jaxmpp__g3u7iy0518@localhost/993927746-tigase-278 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-20 21:09:49 | jaxmpp_ :: jaxmpp__g3u7iy0518@localhost/993927746-tigase-278 << <iq type="result" xmlns="jabber:client" id="dQrFHr12xaqUQZ3qYm5gNDj" to="jaxmpp__g3u7iy0518@localhost/993927746-tigase-278"><query xmlns="jabber:iq:roster"/></iq>

2019-11-20 21:09:49 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

2019-11-20 21:09:49 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session]

2019-11-20 21:09:49 | tigase.jaxmpp.j2se.connectors.bosh.BoshWorker.run: Connection error

2019-11-20 21:09:49 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onError: responseCode=0

2019-11-20 21:09:49 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onError: responseCode=500

2019-11-20 21:09:49 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onError: responseCode=500

testStateAfterAuthTimeoutSocket 20.261s
2019-11-20 21:09:49 |

2019-11-20 21:09:49 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2019-11-20 21:09:49 | ------------------------------------

2019-11-20 21:09:49 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-20 21:09:49 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2019-11-20 21:09:49 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

2019-11-20 21:09:49 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=566 thread=1] Connector  state changed: null->connecting

2019-11-20 21:09:49 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=566 thread=1] DNS entry stored in session object: localhost:5222

2019-11-20 21:09:49 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=566 thread=1] Preparing connection to [localhost:5222]

2019-11-20 21:09:49 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=566 thread=1] Opening connection to localhost/127.0.0.1:5222

2019-11-20 21:09:49 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=566 thread=1] Connector  state changed: connecting->connected

2019-11-20 21:09:49 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=566 thread=1] Whitespace ping period is setted to nullms

2019-11-20 21:09:49 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-20 21:09:49 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/><register xmlns="http://jabber.org/features/iq-register"/><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-20 21:09:49 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=566 thread=3675] Start TLS

2019-11-20 21:09:49 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

2019-11-20 21:09:49 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=566 thread=3677] Proceeding TLS

2019-11-20 21:09:49 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=566 thread=3677] Start handshake

2019-11-20 21:09:49 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-20 21:09:50 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><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><register xmlns="http://jabber.org/features/iq-register"/><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-20 21:10:09 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=566 thread=3677] Connector  state changed: connected->disconnected

2019-11-20 21:10:09 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=566 thread=3677] Stream terminated

2019-11-20 21:10:09 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-11-20 21:10:09 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-11-20 21:10:10 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-20 21:10:10 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2019-11-20 21:10:10 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

2019-11-20 21:10:10 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=567 thread=1] Connector  state changed: null->connecting

2019-11-20 21:10:10 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=567 thread=1] DNS entry stored in session object: localhost:5222

2019-11-20 21:10:10 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=567 thread=1] Preparing connection to [localhost:5222]

2019-11-20 21:10:10 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=567 thread=1] Opening connection to localhost/127.0.0.1:5222

2019-11-20 21:10:10 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=567 thread=1] Connector  state changed: connecting->connected

2019-11-20 21:10:10 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=567 thread=1] Whitespace ping period is setted to nullms

2019-11-20 21:10:10 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/><register xmlns="http://jabber.org/features/iq-register"/><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-20 21:10:10 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=567 thread=3675] Start TLS

2019-11-20 21:10:10 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=567 thread=3682] Proceeding TLS

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

2019-11-20 21:10:10 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=567 thread=3682] Start handshake

2019-11-20 21:10:10 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><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><register xmlns="http://jabber.org/features/iq-register"/><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-20 21:10:10 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2019-11-20 21:10:10 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX3J5aWRnbzA1MTkscj1RWFE1R1k1N1FMYXJuOUVIc3ZSQQ==</auth>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1RWFE1R1k1N1FMYXJuOUVIc3ZSQVFwbFNvaDZOS3VNUjVka2dSdXRaLHM9czZJbEdXbkNCdFoxc2c9PSxpPTQwOTY=</challenge>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9UVhRNUdZNTdRTGFybjlFSHN2UkFRcGxTb2g2Tkt1TVI1ZGtnUnV0WixwPWdaMG92d3FnVnhvby9xeG1MWk4yRGJPSFR4Wi9HTFg1eGZXL2RSMkhOWEE9</response>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1TVnVoNk9uUjdMSzlsdVJQZmRTYjlKMWJQSHhCMEh6ZktwckhXSW5wWHNjPQ==</success>

2019-11-20 21:10:10 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-20 21:10:10 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-20 21:10:10 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@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" ver="8SAx7sxxLI3422mjAeBbH2oWxJg=" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@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" ver="8SAx7sxxLI3422mjAeBbH2oWxJg=" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@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" ver="8SAx7sxxLI3422mjAeBbH2oWxJg=" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost >> <iq xmlns="jabber:client" id="oN2xoUePKLzbM1tocsjQalN" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost >> <iq xmlns="jabber:client" id="rDwQ3cFnN0tncOGLKYX1wrf" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost >> <iq xmlns="jabber:client" id="yWpFLYmMX8Kv7IP15jCHu4c" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost << <iq type="result" xmlns="jabber:client" id="oN2xoUePKLzbM1tocsjQalN" to="jaxmpp__ryidgo0519@localhost/993927746-tigase-279"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__ryidgo0519@localhost/993927746-tigase-279</jid></bind></iq>

2019-11-20 21:10:10 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost/993927746-tigase-279 >> <iq xmlns="jabber:client" id="d1C1pRRITSQKwlLQO2rYdtZ" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost/993927746-tigase-279 << <iq type="result" xmlns="jabber:client" id="rDwQ3cFnN0tncOGLKYX1wrf" to="jaxmpp__ryidgo0519@localhost/993927746-tigase-280"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__ryidgo0519@localhost/993927746-tigase-280</jid></bind></iq>

2019-11-20 21:10:10 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost/993927746-tigase-280 >> <iq xmlns="jabber:client" id="8XoogxbQ5x7nKX06gypT6k4" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost/993927746-tigase-280 << <iq type="result" xmlns="jabber:client" id="yWpFLYmMX8Kv7IP15jCHu4c" to="jaxmpp__ryidgo0519@localhost/993927746-tigase-281"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__ryidgo0519@localhost/993927746-tigase-281</jid></bind></iq>

2019-11-20 21:10:10 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost/993927746-tigase-281 >> <iq xmlns="jabber:client" id="vQ1tZofVi04xi49piZlJBcR" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost/993927746-tigase-281 << <iq type="result" xmlns="jabber:client" id="d1C1pRRITSQKwlLQO2rYdtZ" to="jaxmpp__ryidgo0519@localhost/993927746-tigase-281"/>

2019-11-20 21:10:10 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost/993927746-tigase-281 >> <iq to="localhost" id="IHyYl39rSdw8kGFp8ocLCv3" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost/993927746-tigase-281 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost/993927746-tigase-281 << <iq type="result" xmlns="jabber:client" id="8XoogxbQ5x7nKX06gypT6k4" to="jaxmpp__ryidgo0519@localhost/993927746-tigase-281"/>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost/993927746-tigase-281 >> <iq id="XJC2rYdtZofVi04xi49piZl" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost/993927746-tigase-281 << <enabled xmlns="urn:xmpp:sm:3" id="e8bf8c42-e6a6-4fa8-b083-da851ff97aa3" resume="true" max="60" location="d4270859fb27"/>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost/993927746-tigase-281 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost/993927746-tigase-281 << <iq type="result" xmlns="jabber:client" id="vQ1tZofVi04xi49piZlJBcR" to="jaxmpp__ryidgo0519@localhost/993927746-tigase-281"/>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost/993927746-tigase-281 >> <iq to="localhost" id="1FoADHQ6gV4CfBGLTPNADmO" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost/993927746-tigase-281 >> <iq id="Y3wNGDjFKXl8GqfIUPL0pbp" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost/993927746-tigase-281 >> <iq to="localhost" id="mItm17yeS7kVTP4BDIQKT0u" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost/993927746-tigase-281 >> <iq id="UYdT6k4v6tZ1snbO28FyAbt" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost/993927746-tigase-281 << <iq type="result" xmlns="jabber:client" id="XJC2rYdtZofVi04xi49piZl" to="jaxmpp__ryidgo0519@localhost/993927746-tigase-281"><query xmlns="jabber:iq:roster"/></iq>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost/993927746-tigase-281 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost/993927746-tigase-281 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost/993927746-tigase-281 << <presence xmlns="jabber:client" from="jaxmpp__ryidgo0519@localhost/993927746-tigase-281" to="jaxmpp__ryidgo0519@localhost"><c hash="sha-1" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp"/></presence>

2019-11-20 21:10:10 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=567 thread=1] Connector  state changed: connected->disconnecting

2019-11-20 21:10:10 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=567 thread=1] Terminating XMPP Stream

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost/993927746-tigase-281 << <iq type="result" xmlns="jabber:client" id="Y3wNGDjFKXl8GqfIUPL0pbp" to="jaxmpp__ryidgo0519@localhost/993927746-tigase-281"><query xmlns="jabber:iq:roster"/></iq>

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__ryidgo0519@localhost/993927746-tigase-281 << <iq type="result" xmlns="jabber:client" id="IHyYl39rSdw8kGFp8ocLCv3" from="localhost" to="jaxmpp__ryidgo0519@localhost/993927746-tigase-281"><query xmlns="http://jabber.org/protocol/disco#info"><identity type="router" name="Tigase ver. 8.1.0-SNAPSHOT-b10574/f55efd39" category="component"/><identity type="im" name="Tigase ver. 8.1.0-SNAPSHOT-b10574/f55efd39" category="server"/><feature var="http://jabber.org/protocol/commands"/><x xmlns="jabber:x:data" type="result"><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="jabber:iq:auth"/><feature var="vcard-temp"/><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 type="pep" category="pubsub"/><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:encrypt:0"/><feature var="tigase:push:ignore-unknown:0"/><feature var="tigase:push:muc:0"/><feature var="tigase:push:muted:0"/><feature var="tigase:push:priority: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-20 21:10:10 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=567 thread=3682] Connector  state changed: disconnecting->disconnected

2019-11-20 21:10:10 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=567 thread=3682] Stream terminated

2019-11-20 21:10:10 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-11-20 21:10:10 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

2019-11-20 21:10:10 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session]

2019-11-20 21:10:10 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-11-20 21:10:10 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

testStateAfterAuthTimeoutWebSocket 20.403s
2019-11-20 21:10:10 |

2019-11-20 21:10:10 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2019-11-20 21:10:10 | ------------------------------------

2019-11-20 21:10:10 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-20 21:10:10 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2019-11-20 21:10:10 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using WebSocketConnector

2019-11-20 21:10:10 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Start connector.

2019-11-20 21:10:10 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: null->connecting

2019-11-20 21:10:10 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Preparing connection to localhost

2019-11-20 21:10:10 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Opening connection to localhost/127.0.0.1:5290

2019-11-20 21:10:10 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connecting->connected

2019-11-20 21:10:10 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Whitespace ping period is setted to nullms

2019-11-20 21:10:10 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-20 21:10:10 | jaxmpp_ :: jaxmpp__9zuzq90520@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><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><register xmlns="http://jabber.org/features/iq-register"/><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-20 21:10:30 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connected->disconnecting

2019-11-20 21:10:30 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.terminateStream: Terminating XMPP Stream

2019-11-20 21:10:30 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.onStreamTerminate: Stream terminated

2019-11-20 21:10:30 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-11-20 21:10:30 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: disconnecting->disconnected

2019-11-20 21:10:30 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-20 21:10:30 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2019-11-20 21:10:30 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using WebSocketConnector

2019-11-20 21:10:30 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Start connector.

2019-11-20 21:10:30 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: null->connecting

2019-11-20 21:10:30 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Preparing connection to localhost

2019-11-20 21:10:30 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Opening connection to localhost/127.0.0.1:5290

2019-11-20 21:10:30 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connecting->connected

2019-11-20 21:10:30 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Whitespace ping period is setted to nullms

2019-11-20 21:10:30 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-20 21:10:30 | jaxmpp_ :: jaxmpp__9zuzq90520@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><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><register xmlns="http://jabber.org/features/iq-register"/><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-20 21:10:30 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2019-11-20 21:10:30 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-11-20 21:10:30 | jaxmpp_ :: jaxmpp__9zuzq90520@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfXzl6dXpxOTA1MjAscj1TOGxpVko0TGhmYnZXUUdaYWx4TA==</auth>

2019-11-20 21:10:30 | jaxmpp_ :: jaxmpp__9zuzq90520@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1TOGxpVko0TGhmYnZXUUdaYWx4TERJeVc4YWJuOGdKOVRic1AwanZKLHM9Rk8vRTNTeVZZTHZ0MVE9PSxpPTQwOTY=</challenge>

2019-11-20 21:10:30 | jaxmpp_ :: jaxmpp__9zuzq90520@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9UzhsaVZKNExoZmJ2V1FHWmFseExESXlXOGFibjhnSjlUYnNQMGp2SixwPS9Sd3NoTVdRUUV2bkhVOFRBK3h6aTdjSk5QN3laSHpUQ0U1OEdnWldFVEk9</response>

2019-11-20 21:10:30 | jaxmpp_ :: jaxmpp__9zuzq90520@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1iYWpYUzZUMjlRL0xZSGs3WnI2Vk55NG1MNWs5Z3phclJ5cDlsc1o2Y3NRPQ==</success>

2019-11-20 21:10:30 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-20 21:10:30 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-20 21:10:30 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-20 21:10:30 | jaxmpp_ :: jaxmpp__9zuzq90520@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" ver="8SAx7sxxLI3422mjAeBbH2oWxJg=" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-11-20 21:10:30 | jaxmpp_ :: jaxmpp__9zuzq90520@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" ver="8SAx7sxxLI3422mjAeBbH2oWxJg=" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-11-20 21:10:30 | jaxmpp_ :: jaxmpp__9zuzq90520@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" ver="8SAx7sxxLI3422mjAeBbH2oWxJg=" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-11-20 21:10:30 | jaxmpp_ :: jaxmpp__9zuzq90520@localhost >> <iq xmlns="jabber:client" id="bKpj6Bzbv0t2aoOVVask18x" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-20 21:10:30 | jaxmpp_ :: jaxmpp__9zuzq90520@localhost >> <iq xmlns="jabber:client" id="4bGcOGLKYX1wrfxdqjIw6eL" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-20 21:10:30 | jaxmpp_ :: jaxmpp__9zuzq90520@localhost >> <iq xmlns="jabber:client" id="SPAAt1mQ6zeJv3wvrk4cNO6" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-20 21:10:30 | jaxmpp_ :: jaxmpp__9zuzq90520@localhost << <iq type="result" xmlns="jabber:client" id="bKpj6Bzbv0t2aoOVVask18x" to="jaxmpp__9zuzq90520@localhost/993927746-tigase-282"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__9zuzq90520@localhost/993927746-tigase-282</jid></bind></iq>

2019-11-20 21:10:30 | jaxmpp_ :: jaxmpp__9zuzq90520@localhost << <iq type="result" xmlns="jabber:client" id="4bGcOGLKYX1wrfxdqjIw6eL" to="jaxmpp__9zuzq90520@localhost/993927746-tigase-283"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__9zuzq90520@localhost/993927746-tigase-283</jid></bind></iq>

2019-11-20 21:10:30 | jaxmpp_ :: jaxmpp__9zuzq90520@localhost << <iq type="result" xmlns="jabber:client" id="SPAAt1mQ6zeJv3wvrk4cNO6" to="jaxmpp__9zuzq90520@localhost/993927746-tigase-284"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__9zuzq90520@localhost/993927746-tigase-284</jid></bind></iq>

2019-11-20 21:10:30 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-20 21:10:30 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-20 21:10:30 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-20 21:10:30 | jaxmpp_ :: jaxmpp__9zuzq90520@localhost/993927746-tigase-284 >> <iq xmlns="jabber:client" id="RSHQIJxoUePKLzbM1tocsjQ" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-11-20 21:10:30 | jaxmpp_ :: jaxmpp__9zuzq90520@localhost/993927746-tigase-284 >> <iq xmlns="jabber:client" id="nPwJxoUePKLzbM1tocsjQal" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-11-20 21:10:30 | jaxmpp_ :: jaxmpp__9zuzq90520@localhost/993927746-tigase-284 >> <iq xmlns="jabber:client" id="RUJUQZ3qYm5gNDj2xvskIPS" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-11-20 21:10:30 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connected->disconnecting

2019-11-20 21:10:30 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.terminateStream: Terminating XMPP Stream

2019-11-20 21:10:30 | jaxmpp_ :: jaxmpp__9zuzq90520@localhost/993927746-tigase-284 << <iq type="result" xmlns="jabber:client" id="RSHQIJxoUePKLzbM1tocsjQ" to="jaxmpp__9zuzq90520@localhost/993927746-tigase-284"/>

2019-11-20 21:10:30 | jaxmpp_ :: jaxmpp__9zuzq90520@localhost/993927746-tigase-284 << <iq type="result" xmlns="jabber:client" id="nPwJxoUePKLzbM1tocsjQal" to="jaxmpp__9zuzq90520@localhost/993927746-tigase-284"/>

2019-11-20 21:10:30 | jaxmpp_ :: jaxmpp__9zuzq90520@localhost/993927746-tigase-284 << <iq type="result" xmlns="jabber:client" id="RUJUQZ3qYm5gNDj2xvskIPS" to="jaxmpp__9zuzq90520@localhost/993927746-tigase-284"/>

2019-11-20 21:10:30 | tigase.jaxmpp.j2se.eventbus.ThreadSafeEventBus$2.run:

2019-11-20 21:10:30 | tigase.jaxmpp.j2se.eventbus.ThreadSafeEventBus$2.run:

2019-11-20 21:10:30 | tigase.jaxmpp.j2se.eventbus.ThreadSafeEventBus$2.run:

2019-11-20 21:10:30 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-11-20 21:10:30 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: disconnecting->disconnected

2019-11-20 21:10:30 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

2019-11-20 21:10:30 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session]

2019-11-20 21:10:33 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

testStateAfterConnectionFailureBosh 0.750s
2019-11-20 21:10:31 |

2019-11-20 21:10:31 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2019-11-20 21:10:31 | ------------------------------------

2019-11-20 21:10:31 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-20 21:10:31 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2019-11-20 21:10:31 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using BOSHConnector

2019-11-20 21:10:31 | tigase.jaxmpp.j2se.connectors.bosh.BoshWorker.run: Connection error

2019-11-20 21:10:31 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onError: responseCode=0

2019-11-20 21:10:31 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session, stream]

2019-11-20 21:10:31 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-20 21:10:31 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2019-11-20 21:10:31 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using BOSHConnector

2019-11-20 21:10:31 | jaxmpp_ :: jaxmpp__vrzsk60521@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><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><register xmlns="http://jabber.org/features/iq-register"/><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-20 21:10:31 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2019-11-20 21:10:31 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-11-20 21:10:31 | jaxmpp_ :: jaxmpp__vrzsk60521@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX3ZyenNrNjA1MjEscj1nUk53aEpKNnI3Uk1OY0w1YWxaUQ==</auth>

2019-11-20 21:10:31 | jaxmpp_ :: jaxmpp__vrzsk60521@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1nUk53aEpKNnI3Uk1OY0w1YWxaUXV0YzFXcDhoUEJGaVY1Q3FweEtzLHM9NldQRXk1Zy9seHg1cEE9PSxpPTQwOTY=</challenge>

2019-11-20 21:10:31 | jaxmpp_ :: jaxmpp__vrzsk60521@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9Z1JOd2hKSjZyN1JNTmNMNWFsWlF1dGMxV3A4aFBCRmlWNUNxcHhLcyxwPTFoTExmQjFFVXlLSlJXWElYanQ3UkwzS1RUNlk5L241V0taVlN1cnRXbk09</response>

2019-11-20 21:10:31 | jaxmpp_ :: jaxmpp__vrzsk60521@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1lQTB0bmU5aFhzc3BTbThhYktuMDFRSFVSZjVNZjZRb3hjZGdhbTZOSll3PQ==</success>

2019-11-20 21:10:31 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-20 21:10:31 | jaxmpp_ :: jaxmpp__vrzsk60521@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" ver="8SAx7sxxLI3422mjAeBbH2oWxJg=" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-11-20 21:10:31 | jaxmpp_ :: jaxmpp__vrzsk60521@localhost >> <iq xmlns="jabber:client" id="joXoSOEBhSSaHufx7ELXm8k" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-20 21:10:31 | jaxmpp_ :: jaxmpp__vrzsk60521@localhost << <iq type="result" xmlns="jabber:client" id="joXoSOEBhSSaHufx7ELXm8k" to="jaxmpp__vrzsk60521@localhost/993927746-tigase-285"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__vrzsk60521@localhost/993927746-tigase-285</jid></bind></iq>

2019-11-20 21:10:31 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-20 21:10:31 | jaxmpp_ :: jaxmpp__vrzsk60521@localhost/993927746-tigase-285 >> <iq to="localhost" id="r4XINGDjFKXl8GqfIUPL0pb" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-11-20 21:10:31 | jaxmpp_ :: jaxmpp__vrzsk60521@localhost/993927746-tigase-285 >> <iq id="M0JZYpUUSMRNUWiX0hBfUhZ" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-11-20 21:10:31 | jaxmpp_ :: jaxmpp__vrzsk60521@localhost/993927746-tigase-285 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-20 21:10:31 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onTerminate: Stream terminated. responseCode=200

2019-11-20 21:10:31 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onError: responseCode=500

2019-11-20 21:10:31 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

2019-11-20 21:10:31 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session]

testStateAfterConnectionFailureSocket 0.267s
2019-11-20 21:10:32 |

2019-11-20 21:10:32 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2019-11-20 21:10:32 | ------------------------------------

2019-11-20 21:10:32 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=571 thread=1] Connector  state changed: null->connecting

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=571 thread=1] DNS entry stored in session object: missing:5222

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=571 thread=1] Preparing connection to [missing:5222]

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=571 thread=1] missing. Trying next.

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=571 thread=1] Connector  state changed: connecting->disconnected

2019-11-20 21:10:32 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session, stream]

2019-11-20 21:10:32 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=572 thread=1] Connector  state changed: null->connecting

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=572 thread=1] DNS entry stored in session object: localhost:5222

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=572 thread=1] Preparing connection to [localhost:5222]

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=572 thread=1] Opening connection to localhost/127.0.0.1:5222

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=572 thread=1] Connector  state changed: connecting->connected

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=572 thread=1] Whitespace ping period is setted to nullms

2019-11-20 21:10:32 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-20 21:10:32 | jaxmpp_ :: jaxmpp__ndglvd0522@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/><register xmlns="http://jabber.org/features/iq-register"/><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-20 21:10:32 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=572 thread=3735] Start TLS

2019-11-20 21:10:32 | jaxmpp_ :: jaxmpp__ndglvd0522@localhost >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=572 thread=3739] Proceeding TLS

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=572 thread=3739] Start handshake

2019-11-20 21:10:32 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-20 21:10:32 | jaxmpp_ :: jaxmpp__ndglvd0522@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><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><register xmlns="http://jabber.org/features/iq-register"/><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-20 21:10:32 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2019-11-20 21:10:32 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-11-20 21:10:32 | jaxmpp_ :: jaxmpp__ndglvd0522@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX25kZ2x2ZDA1MjIscj1wcWl6WlNLOENUZFJNdVdEa0RHdw==</auth>

2019-11-20 21:10:32 | jaxmpp_ :: jaxmpp__ndglvd0522@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1wcWl6WlNLOENUZFJNdVdEa0RHdzZtREZnREJFSTVWMmFzeWY3VUZlLHM9MzI4UjhnUGgvOWRXRWc9PSxpPTQwOTY=</challenge>

2019-11-20 21:10:32 | jaxmpp_ :: jaxmpp__ndglvd0522@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9cHFpelpTSzhDVGRSTXVXRGtER3c2bURGZ0RCRUk1VjJhc3lmN1VGZSxwPXpneXpGdzdUckxQOHVMK0tIVUNiSWVrR2tnZ2RFQlhZY2g4ZVZvNGxIZ2M9</response>

2019-11-20 21:10:32 | jaxmpp_ :: jaxmpp__ndglvd0522@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1NM3NENEJYZGxiYWJrSU5KVzlQZXlIbGxMQTJockgvUVptN1djbExEajg0PQ==</success>

2019-11-20 21:10:32 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-20 21:10:32 | jaxmpp_ :: jaxmpp__ndglvd0522@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" ver="8SAx7sxxLI3422mjAeBbH2oWxJg=" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-11-20 21:10:32 | jaxmpp_ :: jaxmpp__ndglvd0522@localhost >> <iq xmlns="jabber:client" id="I80R7BfDgZ4ew4rXeAAxaBf" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-20 21:10:32 | jaxmpp_ :: jaxmpp__ndglvd0522@localhost << <iq type="result" xmlns="jabber:client" id="I80R7BfDgZ4ew4rXeAAxaBf" to="jaxmpp__ndglvd0522@localhost/993927746-tigase-286"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__ndglvd0522@localhost/993927746-tigase-286</jid></bind></iq>

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-20 21:10:32 | jaxmpp_ :: jaxmpp__ndglvd0522@localhost/993927746-tigase-286 >> <iq xmlns="jabber:client" id="p7VxcOZ4pRLWl7GMCDusVXo" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-11-20 21:10:32 | jaxmpp_ :: jaxmpp__ndglvd0522@localhost/993927746-tigase-286 << <iq type="result" xmlns="jabber:client" id="p7VxcOZ4pRLWl7GMCDusVXo" to="jaxmpp__ndglvd0522@localhost/993927746-tigase-286"/>

2019-11-20 21:10:32 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management

2019-11-20 21:10:32 | jaxmpp_ :: jaxmpp__ndglvd0522@localhost/993927746-tigase-286 >> <iq to="localhost" id="Ia2VfRLFk7kKy8zdKCEFq7h" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-11-20 21:10:32 | jaxmpp_ :: jaxmpp__ndglvd0522@localhost/993927746-tigase-286 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/>

2019-11-20 21:10:32 | jaxmpp_ :: jaxmpp__ndglvd0522@localhost/993927746-tigase-286 << <enabled xmlns="urn:xmpp:sm:3" id="9de56cc0-8084-4836-8ece-6344898ecb35" resume="true" max="60" location="d4270859fb27"/>

2019-11-20 21:10:32 | jaxmpp_ :: jaxmpp__ndglvd0522@localhost/993927746-tigase-286 >> <iq id="x7RvtncOGLKYX1wrfxdqjIw" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-11-20 21:10:32 | jaxmpp_ :: jaxmpp__ndglvd0522@localhost/993927746-tigase-286 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-20 21:10:32 | jaxmpp_ :: jaxmpp__ndglvd0522@localhost/993927746-tigase-286 << <iq type="result" xmlns="jabber:client" id="Ia2VfRLFk7kKy8zdKCEFq7h" from="localhost" to="jaxmpp__ndglvd0522@localhost/993927746-tigase-286"><query xmlns="http://jabber.org/protocol/disco#info"><identity type="router" name="Tigase ver. 8.1.0-SNAPSHOT-b10574/f55efd39" category="component"/><identity type="im" name="Tigase ver. 8.1.0-SNAPSHOT-b10574/f55efd39" category="server"/><feature var="http://jabber.org/protocol/commands"/><x xmlns="jabber:x:data" type="result"><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="jabber:iq:auth"/><feature var="vcard-temp"/><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 type="pep" category="pubsub"/><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:encrypt:0"/><feature var="tigase:push:ignore-unknown:0"/><feature var="tigase:push:muc:0"/><feature var="tigase:push:muted:0"/><feature var="tigase:push:priority: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-20 21:10:32 | jaxmpp_ :: jaxmpp__ndglvd0522@localhost/993927746-tigase-286 << <iq type="result" xmlns="jabber:client" id="x7RvtncOGLKYX1wrfxdqjIw" to="jaxmpp__ndglvd0522@localhost/993927746-tigase-286"><query xmlns="jabber:iq:roster"/></iq>

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=572 thread=1] Connector  state changed: connected->disconnecting

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=572 thread=1] Terminating XMPP Stream

2019-11-20 21:10:32 | jaxmpp_ :: jaxmpp__ndglvd0522@localhost/993927746-tigase-286 << <presence xmlns="jabber:client" from="jaxmpp__ndglvd0522@localhost/993927746-tigase-286" to="jaxmpp__ndglvd0522@localhost"><c hash="sha-1" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp"/></presence>

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=572 thread=3739] Connector  state changed: disconnecting->disconnected

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=572 thread=3739] Stream terminated

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-11-20 21:10:32 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

2019-11-20 21:10:32 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session]

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

testStateAfterConnectionFailureWebSocket 0.363s
2019-11-20 21:10:32 |

2019-11-20 21:10:32 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2019-11-20 21:10:32 | ------------------------------------

2019-11-20 21:10:32 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using WebSocketConnector

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Start connector.

2019-11-20 21:10:32 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: null->connecting

2019-11-20 21:10:32 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connecting->disconnected

2019-11-20 21:10:32 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session, stream]

2019-11-20 21:10:32 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using WebSocketConnector

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Start connector.

2019-11-20 21:10:32 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: null->connecting

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Preparing connection to localhost

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Opening connection to localhost/127.0.0.1:5290

2019-11-20 21:10:32 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connecting->connected

2019-11-20 21:10:32 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Whitespace ping period is setted to nullms

2019-11-20 21:10:32 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-20 21:10:32 | jaxmpp_ :: jaxmpp__yc2z0e0523@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><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><register xmlns="http://jabber.org/features/iq-register"/><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-20 21:10:32 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2019-11-20 21:10:32 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-11-20 21:10:32 | jaxmpp_ :: jaxmpp__yc2z0e0523@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX3ljMnowZTA1MjMscj01NUN0WmlMZG1kdEk4azZpWmRkZw==</auth>

2019-11-20 21:10:32 | jaxmpp_ :: jaxmpp__yc2z0e0523@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj01NUN0WmlMZG1kdEk4azZpWmRkZ2xQMlBZOFZnR3NUMGpiWjlBcGM3LHM9TUw0ZVVna05WcUswK2c9PSxpPTQwOTY=</challenge>

2019-11-20 21:10:32 | jaxmpp_ :: jaxmpp__yc2z0e0523@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9NTVDdFppTGRtZHRJOGs2aVpkZGdsUDJQWThWZ0dzVDBqYlo5QXBjNyxwPUFVaWo1U3BDWjQ5cUI1dGxWL2JqQ3dPd2p5UzYxVVZKcisyR29KeFluMTA9</response>

2019-11-20 21:10:32 | jaxmpp_ :: jaxmpp__yc2z0e0523@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1EWmlGZTI3YjVudnQ3WjNSSkV0cEcySUE2cGtZemVrRTZRY3dhdnJ5Q1U4PQ==</success>

2019-11-20 21:10:32 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-20 21:10:33 | jaxmpp_ :: jaxmpp__yc2z0e0523@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" ver="8SAx7sxxLI3422mjAeBbH2oWxJg=" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-11-20 21:10:33 | jaxmpp_ :: jaxmpp__yc2z0e0523@localhost >> <iq xmlns="jabber:client" id="8xZzCfBGLTPNADmOGo5fOKU" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-20 21:10:33 | jaxmpp_ :: jaxmpp__yc2z0e0523@localhost << <iq type="result" xmlns="jabber:client" id="8xZzCfBGLTPNADmOGo5fOKU" to="jaxmpp__yc2z0e0523@localhost/993927746-tigase-287"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__yc2z0e0523@localhost/993927746-tigase-287</jid></bind></iq>

2019-11-20 21:10:33 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-20 21:10:33 | jaxmpp_ :: jaxmpp__yc2z0e0523@localhost/993927746-tigase-287 >> <iq xmlns="jabber:client" id="SdZn3bGuo9o39l6FLYmMX8K" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-11-20 21:10:33 | jaxmpp_ :: jaxmpp__yc2z0e0523@localhost/993927746-tigase-287 << <iq type="result" xmlns="jabber:client" id="SdZn3bGuo9o39l6FLYmMX8K" to="jaxmpp__yc2z0e0523@localhost/993927746-tigase-287"/>

2019-11-20 21:10:33 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management

2019-11-20 21:10:33 | jaxmpp_ :: jaxmpp__yc2z0e0523@localhost/993927746-tigase-287 >> <iq to="localhost" id="yA4YncOGLKYX1wrfxdqjIw6" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-11-20 21:10:33 | jaxmpp_ :: jaxmpp__yc2z0e0523@localhost/993927746-tigase-287 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/>

2019-11-20 21:10:33 | jaxmpp_ :: jaxmpp__yc2z0e0523@localhost/993927746-tigase-287 >> <iq id="LyWiJsnQMCgPJMGMVW9lJSd" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-11-20 21:10:33 | jaxmpp_ :: jaxmpp__yc2z0e0523@localhost/993927746-tigase-287 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-20 21:10:33 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connected->disconnecting

2019-11-20 21:10:33 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.terminateStream: Terminating XMPP Stream

2019-11-20 21:10:33 | jaxmpp_ :: jaxmpp__yc2z0e0523@localhost/993927746-tigase-287 << <enabled xmlns="urn:xmpp:sm:3" id="074be192-94f3-40d0-a7dd-116bac16867a" resume="true" max="60" location="d4270859fb27"/>

2019-11-20 21:10:33 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-11-20 21:10:33 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: disconnecting->disconnected

2019-11-20 21:10:33 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

2019-11-20 21:10:33 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session]