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

Test duration: 64.417s

Failed Tests
tigase.tests.jaxmpp.TestHandlingOfConnectionIssues
testStateAfterConnectionFailureSocket 0.077s
2019-10-13 19:59:19 |

2019-10-13 19:59:19 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2019-10-13 19:59:19 | ------------------------------------

2019-10-13 19:59:19 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=524 thread=1] Connector  state changed: null->connecting

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=524 thread=1] DNS entry stored in session object: missing:5222

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=524 thread=1] Preparing connection to [missing:5222]

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=524 thread=1] missing. Trying next.

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=524 thread=1] Connector  state changed: connecting->disconnected

2019-10-13 19:59:19 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream, session]

2019-10-13 19:59:19 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=1] Connector  state changed: null->connecting

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=1] DNS entry stored in session object: localhost:5222

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=1] Preparing connection to [localhost:5222]

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=1] Opening connection to localhost/127.0.0.1:5222

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=1] Connector  state changed: connecting->connected

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=1] Whitespace ping period is setted to nullms

2019-10-13 19:59:19 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 19:59:19 | jaxmpp_ :: jaxmpp__h6wuzz0405@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-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=3413] Start TLS

2019-10-13 19:59:19 | jaxmpp_ :: jaxmpp__h6wuzz0405@localhost >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=3417] Proceeding TLS

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=3417] Start handshake

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=3417] Can't establish encrypted connection

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.Jaxmpp.onException: Catching exception

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=3413] Connector  state changed: connected->disconnecting

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=3413] Terminating XMPP Stream

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=3417] Connector  state changed: disconnecting->disconnected

java.lang.AssertionError: expected [null] but found [tigase.jaxmpp.core.client.exceptions.JaxmppException: tigase.jaxmpp.core.client.exceptions.JaxmppException: sun.security.validator.ValidatorException: PKIX path building failed: sun.security.provider.certpath.SunCertPathBuilderException: unable to find valid certification path to requested target]
org.testng.Assert.fail(Assert.java:96)
org.testng.Assert.failNotSame(Assert.java:772)
org.testng.Assert.assertNull(Assert.java:708)
org.testng.Assert.assertNull(Assert.java:697)
tigase.tests.jaxmpp.TestHandlingOfConnectionIssues.testStateAfterConnectionFailure(TestHandlingOfConnectionIssues.java:175)
tigase.tests.jaxmpp.TestHandlingOfConnectionIssues.testStateAfterConnectionFailureSocket(TestHandlingOfConnectionIssues.java:74)
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
java.base/java.lang.reflect.Method.invoke(Method.java:566)
org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:124)
org.testng.internal.Invoker.invokeMethod(Invoker.java:583)
org.testng.internal.Invoker.invokeTestMethod(Invoker.java:719)
org.testng.internal.Invoker.invokeTestMethods(Invoker.java:989)
org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:125)
org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:109)
org.testng.TestRunner.privateRun(TestRunner.java:648)
org.testng.TestRunner.run(TestRunner.java:505)
org.testng.SuiteRunner.runTest(SuiteRunner.java:455)
org.testng.SuiteRunner.runSequentially(SuiteRunner.java:450)
org.testng.SuiteRunner.privateRun(SuiteRunner.java:415)
org.testng.SuiteRunner.run(SuiteRunner.java:364)
org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52)
org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:84)
org.testng.TestNG.runSuitesSequentially(TestNG.java:1208)
org.testng.TestNG.runSuitesLocally(TestNG.java:1137)
org.testng.TestNG.runSuites(TestNG.java:1049)
org.testng.TestNG.run(TestNG.java:1017)
org.apache.maven.surefire.testng.TestNGExecutor.run(TestNGExecutor.java:283)
org.apache.maven.surefire.testng.TestNGXmlTestSuite.execute(TestNGXmlTestSuite.java:75)
org.apache.maven.surefire.testng.TestNGProvider.invoke(TestNGProvider.java:120)
org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384)
org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345)
org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126)
org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418)
Passed Tests
tigase.tests.jaxmpp.TestHandlingOfConnectionIssues
testStateAfterAuthTimeoutBosh 20.574s
2019-10-13 19:58:16 |

2019-10-13 19:58:16 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2019-10-13 19:58:16 | ------------------------------------

2019-10-13 19:58:16 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-10-13 19:58:16 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2019-10-13 19:58:16 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using BOSHConnector

2019-10-13 19:58:16 | jaxmpp_ :: jaxmpp__vo8xq20401@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-10-13 19:58:36 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onTerminate: Stream terminated. responseCode=200

2019-10-13 19:58:36 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-10-13 19:58:36 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2019-10-13 19:58:36 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using BOSHConnector

2019-10-13 19:58:36 | jaxmpp_ :: jaxmpp__vo8xq20401@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-10-13 19:58:36 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2019-10-13 19:58:36 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-10-13 19:58:36 | jaxmpp_ :: jaxmpp__vo8xq20401@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX3ZvOHhxMjA0MDEscj00emhXNzZBdWxZTVduOGNQM3BEbA==</auth>

2019-10-13 19:58:36 | jaxmpp_ :: jaxmpp__vo8xq20401@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj00emhXNzZBdWxZTVduOGNQM3BEbFpNTFhEbU5OclA4WXpkY2lCdHBYLHM9TjJ4TCtXUy9WUzB5NlE9PSxpPTQwOTY=</challenge>

2019-10-13 19:58:36 | jaxmpp_ :: jaxmpp__vo8xq20401@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9NHpoVzc2QXVsWU1XbjhjUDNwRGxaTUxYRG1OTnJQOFl6ZGNpQnRwWCxwPWNxTE5BVHBZSXAvSVMrM2ZIcXhEWlczeEY5MEc1Yi95bUJ5bkZHQy9rd0E9</response>

2019-10-13 19:58:36 | jaxmpp_ :: jaxmpp__vo8xq20401@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj05VWxNWnNTTUFIbzlUT1UrSkRCUlBRM0x1UWdhY0xycGdhNVlzcGI1U1lFPQ==</success>

2019-10-13 19:58:36 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 19:58:36 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 19:58:36 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 19:58:36 | jaxmpp_ :: jaxmpp__vo8xq20401@localhost >> <iq xmlns="jabber:client" id="A2XHw8taq12lSRX6gPHu16n" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-10-13 19:58:36 | jaxmpp_ :: jaxmpp__vo8xq20401@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 ver="fD1ATDhYhT37hyTvdBFDDag+4EU=" hash="SHA-1" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-10-13 19:58:36 | jaxmpp_ :: jaxmpp__vo8xq20401@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 ver="fD1ATDhYhT37hyTvdBFDDag+4EU=" hash="SHA-1" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-10-13 19:58:36 | jaxmpp_ :: jaxmpp__vo8xq20401@localhost >> <iq xmlns="jabber:client" id="d8d6jRUS39oPIBzs5q8wjWh" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-10-13 19:58:36 | jaxmpp_ :: jaxmpp__vo8xq20401@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 ver="fD1ATDhYhT37hyTvdBFDDag+4EU=" hash="SHA-1" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-10-13 19:58:36 | jaxmpp_ :: jaxmpp__vo8xq20401@localhost >> <iq xmlns="jabber:client" id="QVyGpSVdKFAsaBwr6EuhGs7" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-10-13 19:58:36 | jaxmpp_ :: jaxmpp__vo8xq20401@localhost << <iq id="A2XHw8taq12lSRX6gPHu16n" xmlns="jabber:client" type="result" to="jaxmpp__vo8xq20401@localhost/993927746-tigase-231"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__vo8xq20401@localhost/993927746-tigase-231</jid></bind></iq>

2019-10-13 19:58:36 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-10-13 19:58:36 | jaxmpp_ :: jaxmpp__vo8xq20401@localhost/993927746-tigase-231 >> <iq to="localhost" id="jcldw5eDDAlWaArcNO4kX2a" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-10-13 19:58:36 | jaxmpp_ :: jaxmpp__vo8xq20401@localhost/993927746-tigase-231 >> <iq id="OYD39oPIBzs5q8wjWhM0cHw" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 19:58:36 | jaxmpp_ :: jaxmpp__vo8xq20401@localhost/993927746-tigase-231 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-10-13 19:58:36 | jaxmpp_ :: jaxmpp__vo8xq20401@localhost/993927746-tigase-231 << <iq id="QVyGpSVdKFAsaBwr6EuhGs7" xmlns="jabber:client" type="result" to="jaxmpp__vo8xq20401@localhost/993927746-tigase-232"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__vo8xq20401@localhost/993927746-tigase-232</jid></bind></iq>

2019-10-13 19:58:36 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-10-13 19:58:36 | jaxmpp_ :: jaxmpp__vo8xq20401@localhost/993927746-tigase-232 >> <iq to="localhost" id="xkF2weLEoZcu9iRUV5mMRLC" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-10-13 19:58:36 | jaxmpp_ :: jaxmpp__vo8xq20401@localhost/993927746-tigase-232 >> <iq id="64RiNOIBcFw9xgAtZ4bq1p8" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 19:58:36 | jaxmpp_ :: jaxmpp__vo8xq20401@localhost/993927746-tigase-232 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-10-13 19:58:36 | jaxmpp_ :: jaxmpp__vo8xq20401@localhost/993927746-tigase-232 << <iq id="d8d6jRUS39oPIBzs5q8wjWh" xmlns="jabber:client" type="result" to="jaxmpp__vo8xq20401@localhost/993927746-tigase-233"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__vo8xq20401@localhost/993927746-tigase-233</jid></bind></iq>

2019-10-13 19:58:36 | jaxmpp_ :: jaxmpp__vo8xq20401@localhost/993927746-tigase-232 << <iq from="localhost" id="jcldw5eDDAlWaArcNO4kX2a" xmlns="jabber:client" type="result" to="jaxmpp__vo8xq20401@localhost/993927746-tigase-233"><query xmlns="http://jabber.org/protocol/disco#info"><identity category="component" type="router" name="Tigase ver. 8.1.0-SNAPSHOT-b10535/f55efd39"/><identity category="server" type="im" name="Tigase ver. 8.1.0-SNAPSHOT-b10535/f55efd39"/><feature var="http://jabber.org/protocol/commands"/><x xmlns="jabber:x:data" type="result"><field type="hidden" var="FORM_TYPE"><value>http://jabber.org/network/serverinfo</value></field><field type="text-multi" var="abuse-addresses"><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="http://jabber.org/protocol/amp"/><feature var="msgoffline"/><feature var="vcard-temp"/><feature var="jabber:iq:auth"/><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="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-10-13 19:58:36 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-10-13 19:58:36 | jaxmpp_ :: jaxmpp__vo8xq20401@localhost/993927746-tigase-233 >> <iq to="localhost" id="cXuJEp3iEBfAdu9FEtcGCvk" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-10-13 19:58:36 | jaxmpp_ :: jaxmpp__vo8xq20401@localhost/993927746-tigase-233 >> <iq id="R4N7iLT6n0iQXeRWkQZ6iNO" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 19:58:36 | jaxmpp_ :: jaxmpp__vo8xq20401@localhost/993927746-tigase-233 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-10-13 19:58:36 | jaxmpp_ :: jaxmpp__vo8xq20401@localhost/993927746-tigase-233 << <message from="localhost" xmlns="jabber:client" to="jaxmpp__vo8xq20401@localhost"><body>Wecome to eda3980f-6651-4b37-9ba7-1eab78362c5cThis message was set at: Sun Oct 13 19:45:03 PDT 2019</body><delay from="localhost" xmlns="urn:xmpp:delay" stamp="2019-10-14T02:58:16.303Z">Offline Storage - d4270859fb27</delay></message>

2019-10-13 19:58:36 | jaxmpp_ :: jaxmpp__vo8xq20401@localhost/993927746-tigase-233 << <iq id="OYD39oPIBzs5q8wjWhM0cHw" xmlns="jabber:client" type="result" to="jaxmpp__vo8xq20401@localhost/993927746-tigase-233"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 19:58:36 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

2019-10-13 19:58:36 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session]

2019-10-13 19:58:36 | tigase.jaxmpp.j2se.connectors.bosh.BoshWorker.run: Connection error

2019-10-13 19:58:36 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onError: responseCode=0

2019-10-13 19:58:36 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onError: responseCode=500

testStateAfterAuthTimeoutSocket 20.281s
2019-10-13 19:58:37 |

2019-10-13 19:58:37 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2019-10-13 19:58:37 | ------------------------------------

2019-10-13 19:58:37 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-10-13 19:58:37 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2019-10-13 19:58:37 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

2019-10-13 19:58:37 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=1] Connector  state changed: null->connecting

2019-10-13 19:58:37 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=1] DNS entry stored in session object: localhost:5222

2019-10-13 19:58:37 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=1] Preparing connection to [localhost:5222]

2019-10-13 19:58:37 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=1] Opening connection to localhost/127.0.0.1:5222

2019-10-13 19:58:37 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=1] Connector  state changed: connecting->connected

2019-10-13 19:58:37 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=1] Whitespace ping period is setted to nullms

2019-10-13 19:58:37 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 19:58:37 | jaxmpp_ :: jaxmpp__uxcoux0402@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-10-13 19:58:37 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=3351] Start TLS

2019-10-13 19:58:37 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

2019-10-13 19:58:37 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=3353] Proceeding TLS

2019-10-13 19:58:37 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=3353] Start handshake

2019-10-13 19:58:37 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 19:58:37 | jaxmpp_ :: jaxmpp__uxcoux0402@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-10-13 19:58:57 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=3353] Connector  state changed: connected->disconnected

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=3353] Stream terminated

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-10-13 19:58:57 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=1] Connector  state changed: null->connecting

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=1] DNS entry stored in session object: localhost:5222

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=1] Preparing connection to [localhost:5222]

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=1] Opening connection to localhost/127.0.0.1:5222

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=1] Connector  state changed: connecting->connected

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=1] Whitespace ping period is setted to nullms

2019-10-13 19:58:57 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@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-10-13 19:58:57 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=3351] Start TLS

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=3358] Proceeding TLS

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=3358] Start handshake

2019-10-13 19:58:57 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 19:58:57 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2019-10-13 19:58:57 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@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-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX3V4Y291eDA0MDIscj11R09HNTBaWXVtbkR3QWVmWU9Nbw==</auth>

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj11R09HNTBaWXVtbkR3QWVmWU9Nb3VLZnNrSEd3cTUyZEgzeUtOY3lHLHM9OHV1bWpxaWlDdEdtNWc9PSxpPTQwOTY=</challenge>

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9dUdPRzUwWll1bW5Ed0FlZllPTW91S2Zza0hHd3E1MmRIM3lLTmN5RyxwPXJDNTRreWYwU0hNemxEaTNVQStWN0JNd2VxMk9kRDF1OFI1QnV2eVJ2REk9</response>

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1KRHFiSVBnVlR0SmVsTXhrbUE5Q1M5cVdTOWxNbGpkdWwrZjlobkI4Y2l3PQ==</success>

2019-10-13 19:58:57 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 19:58:57 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 19:58:57 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@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 ver="fD1ATDhYhT37hyTvdBFDDag+4EU=" hash="SHA-1" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@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 ver="fD1ATDhYhT37hyTvdBFDDag+4EU=" hash="SHA-1" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@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 ver="fD1ATDhYhT37hyTvdBFDDag+4EU=" hash="SHA-1" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost >> <iq xmlns="jabber:client" id="Aea6kKHCkPEzkLLIuhBiDkP" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost >> <iq xmlns="jabber:client" id="c3BW4fJEm15gzczvkPU6sbG" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost << <iq id="Aea6kKHCkPEzkLLIuhBiDkP" xmlns="jabber:client" type="result" to="jaxmpp__uxcoux0402@localhost/993927746-tigase-234"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__uxcoux0402@localhost/993927746-tigase-234</jid></bind></iq>

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost >> <iq xmlns="jabber:client" id="ZmuHFEHCGypWY9w8rS1eznW" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost << <iq id="c3BW4fJEm15gzczvkPU6sbG" xmlns="jabber:client" type="result" to="jaxmpp__uxcoux0402@localhost/993927746-tigase-235"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__uxcoux0402@localhost/993927746-tigase-235</jid></bind></iq>

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost/993927746-tigase-235 >> <iq xmlns="jabber:client" id="zxZDzgCr6iLwjOJHAeLzev4" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost/993927746-tigase-235 << <iq id="ZmuHFEHCGypWY9w8rS1eznW" xmlns="jabber:client" type="result" to="jaxmpp__uxcoux0402@localhost/993927746-tigase-236"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__uxcoux0402@localhost/993927746-tigase-236</jid></bind></iq>

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost/993927746-tigase-235 >> <iq xmlns="jabber:client" id="2kkzkX2axiGx4p07t8kXX03" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost/993927746-tigase-236 << <iq id="zxZDzgCr6iLwjOJHAeLzev4" xmlns="jabber:client" type="result" to="jaxmpp__uxcoux0402@localhost/993927746-tigase-236"/>

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost/993927746-tigase-236 >> <iq xmlns="jabber:client" id="jqAGsXY7BwdGEyn4xi2gPME" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-10-13 19:58:57 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost/993927746-tigase-236 << <iq id="2kkzkX2axiGx4p07t8kXX03" xmlns="jabber:client" type="result" to="jaxmpp__uxcoux0402@localhost/993927746-tigase-236"/>

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost/993927746-tigase-236 >> <iq to="localhost" id="DeYCs0bmZar7qU7hElKFHIB" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost/993927746-tigase-236 << <iq id="jqAGsXY7BwdGEyn4xi2gPME" xmlns="jabber:client" type="result" to="jaxmpp__uxcoux0402@localhost/993927746-tigase-236"/>

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost/993927746-tigase-236 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/>

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost/993927746-tigase-236 << <enabled location="d4270859fb27" id="d5a846cd-d02b-4583-b998-bbfe6d3e24fb" xmlns="urn:xmpp:sm:3" resume="true" max="60"/>

2019-10-13 19:58:57 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost/993927746-tigase-236 >> <iq id="Klh8vcsdt27iLT6n0iQXeRW" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost/993927746-tigase-236 >> <iq to="localhost" id="vrxR7smU7mOPSQRIHAhNMCx" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost/993927746-tigase-236 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/>

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost/993927746-tigase-236 >> <iq to="localhost" id="YrvLMPYlUgIJAgJGs5aBoT1" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost/993927746-tigase-236 >> <iq id="tuCXbGLKW4r06p2av0hKBr4" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost/993927746-tigase-236 >> <iq id="5wGX0dEoXU5mPTY0jFqTQR5" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost/993927746-tigase-236 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost/993927746-tigase-236 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__uxcoux0402@localhost/993927746-tigase-236 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=1] Connector  state changed: connected->disconnecting

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=1] Terminating XMPP Stream

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=3358] Connector  state changed: disconnecting->disconnected

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=3358] Stream terminated

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-10-13 19:58:57 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

2019-10-13 19:58:57 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session]

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

testStateAfterAuthTimeoutWebSocket 20.371s
2019-10-13 19:58:57 |

2019-10-13 19:58:57 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2019-10-13 19:58:57 | ------------------------------------

2019-10-13 19:58:57 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using WebSocketConnector

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Start connector.

2019-10-13 19:58:57 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: null->connecting

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Preparing connection to localhost

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Opening connection to localhost/127.0.0.1:5290

2019-10-13 19:58:57 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connecting->connected

2019-10-13 19:58:57 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Whitespace ping period is setted to nullms

2019-10-13 19:58:57 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 19:58:57 | jaxmpp_ :: jaxmpp__3893lt0403@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-10-13 19:59:17 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connected->disconnecting

2019-10-13 19:59:17 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.terminateStream: Terminating XMPP Stream

2019-10-13 19:59:17 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.onStreamTerminate: Stream terminated

2019-10-13 19:59:17 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-10-13 19:59:17 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: disconnecting->disconnected

2019-10-13 19:59:17 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-10-13 19:59:17 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2019-10-13 19:59:17 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using WebSocketConnector

2019-10-13 19:59:17 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Start connector.

2019-10-13 19:59:17 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: null->connecting

2019-10-13 19:59:17 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Preparing connection to localhost

2019-10-13 19:59:17 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Opening connection to localhost/127.0.0.1:5290

2019-10-13 19:59:17 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connecting->connected

2019-10-13 19:59:17 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Whitespace ping period is setted to nullms

2019-10-13 19:59:17 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 19:59:17 | jaxmpp_ :: jaxmpp__3893lt0403@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-10-13 19:59:17 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2019-10-13 19:59:17 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-10-13 19:59:17 | jaxmpp_ :: jaxmpp__3893lt0403@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfXzM4OTNsdDA0MDMscj1URlVEeUNkWDNJOVFpYkV1a3B1Vg==</auth>

2019-10-13 19:59:17 | jaxmpp_ :: jaxmpp__3893lt0403@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1URlVEeUNkWDNJOVFpYkV1a3B1VkV6dFo2bk1QN1lDMWtmeXFMY0pzLHM9MVpTS2RBQWxCSVlja3c9PSxpPTQwOTY=</challenge>

2019-10-13 19:59:17 | jaxmpp_ :: jaxmpp__3893lt0403@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9VEZVRHlDZFgzSTlRaWJFdWtwdVZFenRaNm5NUDdZQzFrZnlxTGNKcyxwPWx6Z1NkOFdmZXNxMGx1ZmZWRHQ5YWNSUFV4cnVDVytEZ0lEb2JGQzF1TnM9</response>

2019-10-13 19:59:17 | jaxmpp_ :: jaxmpp__3893lt0403@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1FaGxvUHlNdkI0YlNncHpvNlVYQVJDNnNkOWM4Q3Z6NmxDUjlzRElyVHhNPQ==</success>

2019-10-13 19:59:17 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 19:59:17 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 19:59:17 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@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 ver="fD1ATDhYhT37hyTvdBFDDag+4EU=" hash="SHA-1" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@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 ver="fD1ATDhYhT37hyTvdBFDDag+4EU=" hash="SHA-1" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@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 ver="fD1ATDhYhT37hyTvdBFDDag+4EU=" hash="SHA-1" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@localhost >> <iq xmlns="jabber:client" id="tzH7vk3k6o5iGzmONAr4fJE" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@localhost >> <iq xmlns="jabber:client" id="Kuqq5mMRLChCpbGxkW8xobA" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@localhost >> <iq xmlns="jabber:client" id="gyAPIJv6fyhVavgOS1m7smU" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@localhost << <iq id="tzH7vk3k6o5iGzmONAr4fJE" xmlns="jabber:client" type="result" to="jaxmpp__3893lt0403@localhost/993927746-tigase-237"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__3893lt0403@localhost/993927746-tigase-237</jid></bind></iq>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@localhost << <iq id="Kuqq5mMRLChCpbGxkW8xobA" xmlns="jabber:client" type="result" to="jaxmpp__3893lt0403@localhost/993927746-tigase-238"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__3893lt0403@localhost/993927746-tigase-238</jid></bind></iq>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@localhost << <iq id="gyAPIJv6fyhVavgOS1m7smU" xmlns="jabber:client" type="result" to="jaxmpp__3893lt0403@localhost/993927746-tigase-239"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__3893lt0403@localhost/993927746-tigase-239</jid></bind></iq>

2019-10-13 19:59:18 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-10-13 19:59:18 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-10-13 19:59:18 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@localhost/993927746-tigase-239 >> <iq xmlns="jabber:client" id="2yy1eLEoZcu9iRUV5mMRLCh" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@localhost/993927746-tigase-239 >> <iq xmlns="jabber:client" id="3Nf9BkKHCkPEzkLLIuhBiDk" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@localhost/993927746-tigase-239 >> <iq xmlns="jabber:client" id="dDJ7lV28zbsXY7BwdGEyn4x" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@localhost/993927746-tigase-239 << <iq id="2yy1eLEoZcu9iRUV5mMRLCh" xmlns="jabber:client" type="result" to="jaxmpp__3893lt0403@localhost/993927746-tigase-239"/>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@localhost/993927746-tigase-239 << <iq id="3Nf9BkKHCkPEzkLLIuhBiDk" xmlns="jabber:client" type="result" to="jaxmpp__3893lt0403@localhost/993927746-tigase-239"/>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@localhost/993927746-tigase-239 << <iq id="dDJ7lV28zbsXY7BwdGEyn4x" xmlns="jabber:client" type="result" to="jaxmpp__3893lt0403@localhost/993927746-tigase-239"/>

2019-10-13 19:59:18 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management

2019-10-13 19:59:18 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management

2019-10-13 19:59:18 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@localhost/993927746-tigase-239 >> <iq to="localhost" id="Gtd48xgDvcsdt27iLT6n0iQ" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@localhost/993927746-tigase-239 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@localhost/993927746-tigase-239 >> <iq to="localhost" id="JFLbtbyaDjIt0bJMJIIGDAz" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@localhost/993927746-tigase-239 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@localhost/993927746-tigase-239 >> <iq to="localhost" id="JGMdxjOGFnQJwdNUZeKKLQ5" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@localhost/993927746-tigase-239 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@localhost/993927746-tigase-239 >> <iq id="hCyDzbsXY7BwdGEyn4xi2gP" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@localhost/993927746-tigase-239 >> <iq id="jKUkKx8rfONQYcFEHCGypWY" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@localhost/993927746-tigase-239 >> <iq id="Is0KGtbyaDjIt0bJMJIIGDA" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@localhost/993927746-tigase-239 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@localhost/993927746-tigase-239 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@localhost/993927746-tigase-239 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-10-13 19:59:18 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connected->disconnecting

2019-10-13 19:59:18 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.terminateStream: Terminating XMPP Stream

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__3893lt0403@localhost/993927746-tigase-239 << <enabled location="d4270859fb27" id="a0ee44b9-2dd7-4d58-8dab-f8a8230fa856" xmlns="urn:xmpp:sm:3" resume="true" max="60"/>

2019-10-13 19:59:18 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

2019-10-13 19:59:18 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session]

2019-10-13 19:59:18 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-10-13 19:59:18 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: disconnecting->disconnected

testStateAfterConnectionFailureBosh 0.733s
2019-10-13 19:59:18 |

2019-10-13 19:59:18 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2019-10-13 19:59:18 | ------------------------------------

2019-10-13 19:59:18 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-10-13 19:59:18 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2019-10-13 19:59:18 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using BOSHConnector

2019-10-13 19:59:18 | tigase.jaxmpp.j2se.connectors.bosh.BoshWorker.run: Connection error

2019-10-13 19:59:18 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onError: responseCode=0

2019-10-13 19:59:18 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream, session]

2019-10-13 19:59:18 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-10-13 19:59:18 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2019-10-13 19:59:18 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using BOSHConnector

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__ho0gvh0404@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-10-13 19:59:18 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2019-10-13 19:59:18 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__ho0gvh0404@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX2hvMGd2aDA0MDQscj1iUW5YR1NuZUlHTGY4N1NkZGlLdg==</auth>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__ho0gvh0404@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1iUW5YR1NuZUlHTGY4N1NkZGlLdjFvS1g4ZExReWNWZ0NPRlpEVUQ5LHM9M1A3M05DL0ZtcEdSR1E9PSxpPTQwOTY=</challenge>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__ho0gvh0404@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9YlFuWEdTbmVJR0xmODdTZGRpS3Yxb0tYOGRMUXljVmdDT0ZaRFVEOSxwPVl2aDYvVUV4ajhsUUhuT1lWWElCMnlUZWZnVXVmNDNraG5PeG44M3RGbk09</response>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__ho0gvh0404@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1uZE9IWXhrTDJsaHRPRTFkRkZrdy8ybWJZTEUwRWVWV3piOVA2dU02Mi93PQ==</success>

2019-10-13 19:59:18 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__ho0gvh0404@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 ver="fD1ATDhYhT37hyTvdBFDDag+4EU=" hash="SHA-1" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__ho0gvh0404@localhost >> <iq xmlns="jabber:client" id="9KK3hynWZdCiTPKx8rfONQY" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__ho0gvh0404@localhost << <iq id="9KK3hynWZdCiTPKx8rfONQY" xmlns="jabber:client" type="result" to="jaxmpp__ho0gvh0404@localhost/993927746-tigase-240"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__ho0gvh0404@localhost/993927746-tigase-240</jid></bind></iq>

2019-10-13 19:59:18 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__ho0gvh0404@localhost/993927746-tigase-240 >> <iq to="localhost" id="bICHFw9xgAtZ4bq1p8r8ymZ" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__ho0gvh0404@localhost/993927746-tigase-240 >> <iq id="qS4MOU4p8FyyiTUU1gCpOTY" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 19:59:18 | jaxmpp_ :: jaxmpp__ho0gvh0404@localhost/993927746-tigase-240 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-10-13 19:59:18 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onTerminate: Stream terminated. responseCode=200

2019-10-13 19:59:18 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onError: responseCode=500

2019-10-13 19:59:19 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

2019-10-13 19:59:19 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session]

testStateAfterConnectionFailureWebSocket 0.337s
2019-10-13 19:59:19 |

2019-10-13 19:59:19 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2019-10-13 19:59:19 | ------------------------------------

2019-10-13 19:59:19 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using WebSocketConnector

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Start connector.

2019-10-13 19:59:19 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: null->connecting

2019-10-13 19:59:19 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connecting->disconnected

2019-10-13 19:59:19 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream, session]

2019-10-13 19:59:19 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using WebSocketConnector

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Start connector.

2019-10-13 19:59:19 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: null->connecting

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Preparing connection to localhost

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Opening connection to localhost/127.0.0.1:5290

2019-10-13 19:59:19 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connecting->connected

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Whitespace ping period is setted to nullms

2019-10-13 19:59:19 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 19:59:19 | jaxmpp_ :: jaxmpp__tlpq4f0406@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-10-13 19:59:19 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2019-10-13 19:59:19 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-10-13 19:59:19 | jaxmpp_ :: jaxmpp__tlpq4f0406@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX3RscHE0ZjA0MDYscj1WdUR3d09LN25icnNnQzJHR2NZTg==</auth>

2019-10-13 19:59:19 | jaxmpp_ :: jaxmpp__tlpq4f0406@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1WdUR3d09LN25icnNnQzJHR2NZTmozMUNnZDlTOVoyWDlSZTkzOTRwLHM9Tm92Ti9WVys0VG42eWc9PSxpPTQwOTY=</challenge>

2019-10-13 19:59:19 | jaxmpp_ :: jaxmpp__tlpq4f0406@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9VnVEd3dPSzduYnJzZ0MyR0djWU5qMzFDZ2Q5UzlaMlg5UmU5Mzk0cCxwPXY2VDg3VnloM0hBczVOL0NPbzIxbEw3VWI2SDlNdmRUcUN6ZE1TK0V2aW89</response>

2019-10-13 19:59:19 | jaxmpp_ :: jaxmpp__tlpq4f0406@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj11Q3l3YXVCUlhLSlRUd05lbnU4OHJ2NDhxMTZTVmZHbllKc0ZNOHU3U3NVPQ==</success>

2019-10-13 19:59:19 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 19:59:19 | jaxmpp_ :: jaxmpp__tlpq4f0406@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 ver="fD1ATDhYhT37hyTvdBFDDag+4EU=" hash="SHA-1" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-10-13 19:59:19 | jaxmpp_ :: jaxmpp__tlpq4f0406@localhost >> <iq xmlns="jabber:client" id="MUWx8zbsXY7BwdGEyn4xi2g" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-10-13 19:59:19 | jaxmpp_ :: jaxmpp__tlpq4f0406@localhost << <iq id="MUWx8zbsXY7BwdGEyn4xi2g" xmlns="jabber:client" type="result" to="jaxmpp__tlpq4f0406@localhost/993927746-tigase-241"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__tlpq4f0406@localhost/993927746-tigase-241</jid></bind></iq>

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-10-13 19:59:19 | jaxmpp_ :: jaxmpp__tlpq4f0406@localhost/993927746-tigase-241 >> <iq xmlns="jabber:client" id="HRLZfGtbyaDjIt0bJMJIIGD" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-10-13 19:59:19 | jaxmpp_ :: jaxmpp__tlpq4f0406@localhost/993927746-tigase-241 << <iq id="HRLZfGtbyaDjIt0bJMJIIGD" xmlns="jabber:client" type="result" to="jaxmpp__tlpq4f0406@localhost/993927746-tigase-241"/>

2019-10-13 19:59:19 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management

2019-10-13 19:59:19 | jaxmpp_ :: jaxmpp__tlpq4f0406@localhost/993927746-tigase-241 >> <iq to="localhost" id="nLrwp8r8ymZiZcQS3eyjQMJ" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-10-13 19:59:19 | jaxmpp_ :: jaxmpp__tlpq4f0406@localhost/993927746-tigase-241 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/>

2019-10-13 19:59:19 | jaxmpp_ :: jaxmpp__tlpq4f0406@localhost/993927746-tigase-241 >> <iq id="AUQs2axiGx4p07t8kXX03av" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 19:59:19 | jaxmpp_ :: jaxmpp__tlpq4f0406@localhost/993927746-tigase-241 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-10-13 19:59:19 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connected->disconnecting

2019-10-13 19:59:19 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.terminateStream: Terminating XMPP Stream

2019-10-13 19:59:19 | jaxmpp_ :: jaxmpp__tlpq4f0406@localhost/993927746-tigase-241 << <enabled location="d4270859fb27" id="1ce9e250-a2ea-485d-b1aa-a452afbb70a5" xmlns="urn:xmpp:sm:3" resume="true" max="60"/>

2019-10-13 19:59:19 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-10-13 19:59:19 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: disconnecting->disconnected

2019-10-13 19:59:19 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

2019-10-13 19:59:19 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session]