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

Test duration: 64.979s

Failed Tests
tigase.tests.jaxmpp.TestHandlingOfConnectionIssues
testStateAfterConnectionFailureSocket 0.121s
2019-10-13 20:39:22 |

2019-10-13 20:39:22 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2019-10-13 20:39:22 | ------------------------------------

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

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=523 thread=1] Connector  state changed: null->connecting

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

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=523 thread=1] Preparing connection to [missing:5222]

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=523 thread=1] missing. Trying next.

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=523 thread=1] Connector  state changed: connecting->disconnected

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

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

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

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

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

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=524 thread=1] Preparing connection to [localhost:5222]

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=524 thread=1] Opening connection to localhost/127.0.0.1:5222

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=524 thread=1] Connector  state changed: connecting->connected

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=524 thread=1] Whitespace ping period is setted to nullms

2019-10-13 20:39:23 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 20:39:23 | jaxmpp_ :: jaxmpp__wr362q0405@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 20:39:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=524 thread=3399] Start TLS

2019-10-13 20:39:23 | jaxmpp_ :: jaxmpp__wr362q0405@localhost >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=524 thread=3403] Proceeding TLS

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=524 thread=3403] Start handshake

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=524 thread=3403] Can't establish encrypted connection

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=524 thread=3403] Connector  state changed: connected->disconnected

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.Jaxmpp.onException: Catching exception

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=524 thread=3399] Ignoring stop connector.

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.643s
2019-10-13 20:38:19 |

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

2019-10-13 20:38:19 | ------------------------------------

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

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

2019-10-13 20:38:19 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using BOSHConnector

2019-10-13 20:38:19 | jaxmpp_ :: jaxmpp__b1nsmi0401@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 20:38:39 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onTerminate: Stream terminated. responseCode=200

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

2019-10-13 20:38:39 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2019-10-13 20:38:39 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using BOSHConnector

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

2019-10-13 20:38:40 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-10-13 20:38:40 | jaxmpp_ :: jaxmpp__b1nsmi0401@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX2IxbnNtaTA0MDEscj1ldFRuNGJqTjVVd2xQZTh0ZEZ6Sw==</auth>

2019-10-13 20:38:40 | jaxmpp_ :: jaxmpp__b1nsmi0401@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1ldFRuNGJqTjVVd2xQZTh0ZEZ6S3E2ZE91cVlTVHBSeGVvRmJXdnVDLHM9U3FCK3NtenlvU0FYVHc9PSxpPTQwOTY=</challenge>

2019-10-13 20:38:40 | jaxmpp_ :: jaxmpp__b1nsmi0401@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9ZXRUbjRiak41VXdsUGU4dGRGektxNmRPdXFZU1RwUnhlb0ZiV3Z1QyxwPXFoOUJNcWNLN3dyMkJLUmVhbWMrWk5qVmRwd1ZHQWxzM1dpVEFUcU92SFk9</response>

2019-10-13 20:38:40 | jaxmpp_ :: jaxmpp__b1nsmi0401@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1EZVdaSGJGNW9zRDJYLzZPdGxnM015Qzg2clB5T2gxR21hcElacFppOGNjPQ==</success>

2019-10-13 20:38:40 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 20:38:40 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 20:38:40 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 20:38:40 | jaxmpp_ :: jaxmpp__b1nsmi0401@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=" xmlns="http://jabber.org/protocol/caps" hash="SHA-1" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-10-13 20:38:40 | jaxmpp_ :: jaxmpp__b1nsmi0401@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=" xmlns="http://jabber.org/protocol/caps" hash="SHA-1" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-10-13 20:38:40 | jaxmpp_ :: jaxmpp__b1nsmi0401@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=" xmlns="http://jabber.org/protocol/caps" hash="SHA-1" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-10-13 20:38:40 | jaxmpp_ :: jaxmpp__b1nsmi0401@localhost >> <iq xmlns="jabber:client" id="5VQADHCFwv4CpiKZ9lKY0kP" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-10-13 20:38:40 | jaxmpp_ :: jaxmpp__b1nsmi0401@localhost >> <iq xmlns="jabber:client" id="4SF0qj3k5mbqkP8qlRLAEm2" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-10-13 20:38:40 | jaxmpp_ :: jaxmpp__b1nsmi0401@localhost >> <iq xmlns="jabber:client" id="NVMxfx8Kyq1rcAiCkO0qTU0" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-10-13 20:38:40 | jaxmpp_ :: jaxmpp__b1nsmi0401@localhost << <iq type="result" xmlns="jabber:client" id="4SF0qj3k5mbqkP8qlRLAEm2" to="jaxmpp__b1nsmi0401@localhost/993927746-tigase-230"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__b1nsmi0401@localhost/993927746-tigase-230</jid></bind></iq>

2019-10-13 20:38:40 | jaxmpp_ :: jaxmpp__b1nsmi0401@localhost << <iq type="result" xmlns="jabber:client" id="5VQADHCFwv4CpiKZ9lKY0kP" to="jaxmpp__b1nsmi0401@localhost/993927746-tigase-231"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__b1nsmi0401@localhost/993927746-tigase-231</jid></bind></iq>

2019-10-13 20:38:40 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-10-13 20:38:40 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-10-13 20:38:40 | jaxmpp_ :: jaxmpp__b1nsmi0401@localhost/993927746-tigase-231 >> <iq to="localhost" id="GdCUhCIBGwxfx8Kyq1rcAiC" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-10-13 20:38:40 | jaxmpp_ :: jaxmpp__b1nsmi0401@localhost/993927746-tigase-231 >> <iq to="localhost" id="aeDWlKY7IAFv3aOGGxtgIy8" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-10-13 20:38:40 | jaxmpp_ :: jaxmpp__b1nsmi0401@localhost/993927746-tigase-231 >> <iq id="OjQlJww6wdPY8oOIAyw5iMY" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 20:38:40 | jaxmpp_ :: jaxmpp__b1nsmi0401@localhost/993927746-tigase-231 >> <iq id="L0TKENLzcSOW3vkQOEoWgWV" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 20:38:40 | jaxmpp_ :: jaxmpp__b1nsmi0401@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 20:38:40 | jaxmpp_ :: jaxmpp__b1nsmi0401@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 20:38:40 | jaxmpp_ :: jaxmpp__b1nsmi0401@localhost/993927746-tigase-231 << <iq type="result" from="localhost" xmlns="jabber:client" id="aeDWlKY7IAFv3aOGGxtgIy8" to="jaxmpp__b1nsmi0401@localhost/993927746-tigase-231"><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 type="result" xmlns="jabber:x:data"><field var="FORM_TYPE" type="hidden"><value>http://jabber.org/network/serverinfo</value></field><field var="abuse-addresses" type="text-multi"><value>mailto:abuse@localhost</value><value>xmpp:abuse@localhost</value></field></x><feature var="urn:xmpp:carbons:2"/><feature var="http://jabber.org/protocol/stats"/><feature var="vcard-temp"/><feature var="jabber:iq:auth"/><feature var="http://jabber.org/protocol/amp"/><feature var="msgoffline"/><feature var="http://jabber.org/protocol/disco#info"/><feature var="http://jabber.org/protocol/disco#items"/><feature var="urn:xmpp:blocking"/><feature var="urn:xmpp:ping"/><feature var="urn:ietf:params:xml:ns:xmpp-sasl"/><feature var="http://jabber.org/protocol/pubsub"/><feature var="http://jabber.org/protocol/pubsub#owner"/><feature var="http://jabber.org/protocol/pubsub#publish"/><identity category="pubsub" type="pep"/><feature var="urn:xmpp:pep-vcard-conversion:0"/><feature var="urn:xmpp:bookmarks-conversion:0"/><feature var="urn:xmpp:archive:auto"/><feature var="urn:xmpp:archive:manage"/><feature var="urn:xmpp:push:0"/><feature var="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="jabber:iq:private"/><feature var="urn:ietf:params:xml:ns:xmpp-session"/></query></iq>

2019-10-13 20:38:40 | jaxmpp_ :: jaxmpp__b1nsmi0401@localhost/993927746-tigase-231 << <iq type="result" xmlns="jabber:client" id="L0TKENLzcSOW3vkQOEoWgWV" to="jaxmpp__b1nsmi0401@localhost/993927746-tigase-231"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 20:38:40 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

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

2019-10-13 20:38:40 | jaxmpp_ :: jaxmpp__b1nsmi0401@localhost << <presence from="jaxmpp__b1nsmi0401@localhost/993927746-tigase-231" xmlns="jabber:client" to="jaxmpp__b1nsmi0401@localhost"><c ver="mg5bXbOeu1848vxdgu3jELgbQF8=" xmlns="http://jabber.org/protocol/caps" hash="sha-1" node="http://tigase.org/jaxmpp"/></presence>

2019-10-13 20:38:40 | jaxmpp_ :: jaxmpp__b1nsmi0401@localhost << <iq type="result" xmlns="jabber:client" id="OjQlJww6wdPY8oOIAyw5iMY" to="jaxmpp__b1nsmi0401@localhost/993927746-tigase-231"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 20:38:40 | jaxmpp_ :: jaxmpp__b1nsmi0401@localhost << <iq type="result" from="localhost" xmlns="jabber:client" id="GdCUhCIBGwxfx8Kyq1rcAiC" to="jaxmpp__b1nsmi0401@localhost/993927746-tigase-231"><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 type="result" xmlns="jabber:x:data"><field var="FORM_TYPE" type="hidden"><value>http://jabber.org/network/serverinfo</value></field><field var="abuse-addresses" type="text-multi"><value>mailto:abuse@localhost</value><value>xmpp:abuse@localhost</value></field></x><feature var="urn:xmpp:carbons:2"/><feature var="http://jabber.org/protocol/stats"/><feature var="vcard-temp"/><feature var="jabber:iq:auth"/><feature var="http://jabber.org/protocol/amp"/><feature var="msgoffline"/><feature var="http://jabber.org/protocol/disco#info"/><feature var="http://jabber.org/protocol/disco#items"/><feature var="urn:xmpp:blocking"/><feature var="urn:xmpp:ping"/><feature var="urn:ietf:params:xml:ns:xmpp-sasl"/><feature var="http://jabber.org/protocol/pubsub"/><feature var="http://jabber.org/protocol/pubsub#owner"/><feature var="http://jabber.org/protocol/pubsub#publish"/><identity category="pubsub" type="pep"/><feature var="urn:xmpp:pep-vcard-conversion:0"/><feature var="urn:xmpp:bookmarks-conversion:0"/><feature var="urn:xmpp:archive:auto"/><feature var="urn:xmpp:archive:manage"/><feature var="urn:xmpp:push:0"/><feature var="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="jabber:iq:private"/><feature var="urn:ietf:params:xml:ns:xmpp-session"/></query></iq>

2019-10-13 20:38:40 | tigase.jaxmpp.j2se.connectors.bosh.BoshWorker.run: Connection error

2019-10-13 20:38:40 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onError: responseCode=0

2019-10-13 20:38:40 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onError: responseCode=500

testStateAfterAuthTimeoutSocket 20.290s
2019-10-13 20:38:40 |

2019-10-13 20:38:40 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2019-10-13 20:38:40 | ------------------------------------

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

2019-10-13 20:38:40 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2019-10-13 20:38:40 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

2019-10-13 20:38:40 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=518 thread=1] Connector  state changed: null->connecting

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

2019-10-13 20:38:40 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=518 thread=1] Preparing connection to [localhost:5222]

2019-10-13 20:38:40 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=518 thread=1] Opening connection to localhost/127.0.0.1:5222

2019-10-13 20:38:40 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=518 thread=1] Connector  state changed: connecting->connected

2019-10-13 20:38:40 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=518 thread=1] Whitespace ping period is setted to nullms

2019-10-13 20:38:40 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 20:38:40 | jaxmpp_ :: jaxmpp__kjclh10402@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 20:38:40 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=518 thread=3339] Start TLS

2019-10-13 20:38:40 | jaxmpp_ :: jaxmpp__kjclh10402@localhost >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

2019-10-13 20:38:40 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=518 thread=3341] Proceeding TLS

2019-10-13 20:38:40 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=518 thread=3341] Start handshake

2019-10-13 20:38:40 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 20:38:40 | jaxmpp_ :: jaxmpp__kjclh10402@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 20:39:00 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=518 thread=3341] Connector  state changed: connected->disconnected

2019-10-13 20:39:00 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=518 thread=3341] Stream terminated

2019-10-13 20:39:00 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-10-13 20:39:00 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

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

2019-10-13 20:39:00 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2019-10-13 20:39:00 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

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

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

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

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

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

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

2019-10-13 20:39:00 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 20:39:00 | jaxmpp_ :: jaxmpp__kjclh10402@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 20:39:00 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=3339] Start TLS

2019-10-13 20:39:00 | jaxmpp_ :: jaxmpp__kjclh10402@localhost >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

2019-10-13 20:39:00 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=3346] Proceeding TLS

2019-10-13 20:39:00 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=3346] Start handshake

2019-10-13 20:39:00 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

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

2019-10-13 20:39:00 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-10-13 20:39:00 | jaxmpp_ :: jaxmpp__kjclh10402@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX2tqY2xoMTA0MDIscj1PWVdTZG93bUNEMEJOaG01UFdaSQ==</auth>

2019-10-13 20:39:00 | jaxmpp_ :: jaxmpp__kjclh10402@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1PWVdTZG93bUNEMEJOaG01UFdaSTdiSml4ZnR5UU5qMVJNeTFFNldtLHM9YSttQXEvNzFQVWhWN1E9PSxpPTQwOTY=</challenge>

2019-10-13 20:39:00 | jaxmpp_ :: jaxmpp__kjclh10402@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9T1lXU2Rvd21DRDBCTmhtNVBXWkk3YkppeGZ0eVFOajFSTXkxRTZXbSxwPWtKeTlDVkZJaGxHVkpmZ0RXeVo1TFJKYnFoWkJ6Q0JmcXF5TDZNK29CcUE9</response>

2019-10-13 20:39:00 | jaxmpp_ :: jaxmpp__kjclh10402@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj13eDAvK1VLTWNuQ3Q2aDdVN09SRjlDMjIvT2RFRHFYWWpMZHNZUVhHdFI4PQ==</success>

2019-10-13 20:39:00 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 20:39:00 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 20:39:00 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 20:39:00 | jaxmpp_ :: jaxmpp__kjclh10402@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=" xmlns="http://jabber.org/protocol/caps" hash="SHA-1" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-10-13 20:39:00 | jaxmpp_ :: jaxmpp__kjclh10402@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=" xmlns="http://jabber.org/protocol/caps" hash="SHA-1" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-10-13 20:39:00 | jaxmpp_ :: jaxmpp__kjclh10402@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=" xmlns="http://jabber.org/protocol/caps" hash="SHA-1" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-10-13 20:39:01 | jaxmpp_ :: jaxmpp__kjclh10402@localhost >> <iq xmlns="jabber:client" id="ImPcSVkO7pRM28Al5uasWY6" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-10-13 20:39:01 | jaxmpp_ :: jaxmpp__kjclh10402@localhost >> <iq xmlns="jabber:client" id="moTkY7DAmQIwcMYZ6ocR9wt" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-10-13 20:39:01 | jaxmpp_ :: jaxmpp__kjclh10402@localhost << <iq type="result" xmlns="jabber:client" id="ImPcSVkO7pRM28Al5uasWY6" to="jaxmpp__kjclh10402@localhost/993927746-tigase-233"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__kjclh10402@localhost/993927746-tigase-233</jid></bind></iq>

2019-10-13 20:39:01 | jaxmpp_ :: jaxmpp__kjclh10402@localhost >> <iq xmlns="jabber:client" id="epUtq0vbpSewmTbGyeu4iYm" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-10-13 20:39:01 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-10-13 20:39:01 | jaxmpp_ :: jaxmpp__kjclh10402@localhost/993927746-tigase-233 >> <iq xmlns="jabber:client" id="2mJZ6ocR9wt8JwwdUYr39mc" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-10-13 20:39:01 | jaxmpp_ :: jaxmpp__kjclh10402@localhost/993927746-tigase-233 << <iq type="result" xmlns="jabber:client" id="moTkY7DAmQIwcMYZ6ocR9wt" to="jaxmpp__kjclh10402@localhost/993927746-tigase-234"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__kjclh10402@localhost/993927746-tigase-234</jid></bind></iq>

2019-10-13 20:39:01 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-10-13 20:39:01 | jaxmpp_ :: jaxmpp__kjclh10402@localhost/993927746-tigase-234 >> <iq xmlns="jabber:client" id="45SqgZp2vcRM2fY6HzbqkIK" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-10-13 20:39:01 | jaxmpp_ :: jaxmpp__kjclh10402@localhost/993927746-tigase-234 << <iq type="result" xmlns="jabber:client" id="epUtq0vbpSewmTbGyeu4iYm" to="jaxmpp__kjclh10402@localhost/993927746-tigase-235"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__kjclh10402@localhost/993927746-tigase-235</jid></bind></iq>

2019-10-13 20:39:01 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-10-13 20:39:01 | jaxmpp_ :: jaxmpp__kjclh10402@localhost/993927746-tigase-235 >> <iq xmlns="jabber:client" id="h8ZX5dusYgHNU08iGwqgzgI" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-10-13 20:39:01 | jaxmpp_ :: jaxmpp__kjclh10402@localhost/993927746-tigase-235 << <iq type="result" xmlns="jabber:client" id="2mJZ6ocR9wt8JwwdUYr39mc" to="jaxmpp__kjclh10402@localhost/993927746-tigase-235"/>

2019-10-13 20:39:01 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management

2019-10-13 20:39:01 | jaxmpp_ :: jaxmpp__kjclh10402@localhost/993927746-tigase-235 >> <iq to="localhost" id="Ou1HrWmMSVfOOKw8qeSNICE" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-10-13 20:39:01 | jaxmpp_ :: jaxmpp__kjclh10402@localhost/993927746-tigase-235 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/>

2019-10-13 20:39:01 | jaxmpp_ :: jaxmpp__kjclh10402@localhost/993927746-tigase-235 << <iq type="result" xmlns="jabber:client" id="45SqgZp2vcRM2fY6HzbqkIK" to="jaxmpp__kjclh10402@localhost/993927746-tigase-235"/>

2019-10-13 20:39:01 | jaxmpp_ :: jaxmpp__kjclh10402@localhost/993927746-tigase-235 >> <iq id="d4Jq1wcTXXYqU8rhSW02aum" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 20:39:01 | jaxmpp_ :: jaxmpp__kjclh10402@localhost/993927746-tigase-235 << <enabled location="d4270859fb27" xmlns="urn:xmpp:sm:3" id="4fdc40ad-89fa-4207-aabb-6169e5d2c4e3" resume="true" max="60"/>

2019-10-13 20:39:01 | jaxmpp_ :: jaxmpp__kjclh10402@localhost/993927746-tigase-235 >> <iq to="localhost" id="T5LjNZiMGoSUcOFs6CHPSby" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-10-13 20:39:01 | jaxmpp_ :: jaxmpp__kjclh10402@localhost/993927746-tigase-235 << <iq type="result" xmlns="jabber:client" id="h8ZX5dusYgHNU08iGwqgzgI" to="jaxmpp__kjclh10402@localhost/993927746-tigase-235"/>

2019-10-13 20:39:01 | jaxmpp_ :: jaxmpp__kjclh10402@localhost/993927746-tigase-235 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-10-13 20:39:01 | jaxmpp_ :: jaxmpp__kjclh10402@localhost/993927746-tigase-235 >> <iq id="R6Mv4s5zs6kGs4wsX2gWl7s" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 20:39:01 | jaxmpp_ :: jaxmpp__kjclh10402@localhost/993927746-tigase-235 >> <iq to="localhost" id="Sx3DAl5uasWY6AAdyi0tnYn" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-10-13 20:39:01 | jaxmpp_ :: jaxmpp__kjclh10402@localhost/993927746-tigase-235 >> <iq id="avVvt0u9MIV15eWWczxoY4a" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 20:39:01 | jaxmpp_ :: jaxmpp__kjclh10402@localhost/993927746-tigase-235 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-10-13 20:39:01 | jaxmpp_ :: jaxmpp__kjclh10402@localhost/993927746-tigase-235 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-10-13 20:39:01 | jaxmpp_ :: jaxmpp__kjclh10402@localhost/993927746-tigase-235 << <iq type="result" from="localhost" xmlns="jabber:client" id="Ou1HrWmMSVfOOKw8qeSNICE" to="jaxmpp__kjclh10402@localhost/993927746-tigase-235"><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 type="result" xmlns="jabber:x:data"><field var="FORM_TYPE" type="hidden"><value>http://jabber.org/network/serverinfo</value></field><field var="abuse-addresses" type="text-multi"><value>mailto:abuse@localhost</value><value>xmpp:abuse@localhost</value></field></x><feature var="urn:xmpp:carbons:2"/><feature var="http://jabber.org/protocol/stats"/><feature var="vcard-temp"/><feature var="jabber:iq:auth"/><feature var="http://jabber.org/protocol/amp"/><feature var="msgoffline"/><feature var="http://jabber.org/protocol/disco#info"/><feature var="http://jabber.org/protocol/disco#items"/><feature var="urn:xmpp:blocking"/><feature var="urn:xmpp:ping"/><feature var="urn:ietf:params:xml:ns:xmpp-sasl"/><feature var="http://jabber.org/protocol/pubsub"/><feature var="http://jabber.org/protocol/pubsub#owner"/><feature var="http://jabber.org/protocol/pubsub#publish"/><identity category="pubsub" type="pep"/><feature var="urn:xmpp:pep-vcard-conversion:0"/><feature var="urn:xmpp:bookmarks-conversion:0"/><feature var="urn:xmpp:archive:auto"/><feature var="urn:xmpp:archive:manage"/><feature var="urn:xmpp:push:0"/><feature var="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="jabber:iq:private"/><feature var="urn:ietf:params:xml:ns:xmpp-session"/></query></iq>

2019-10-13 20:39:01 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=1] Connector  state changed: connected->disconnecting

2019-10-13 20:39:01 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=1] Terminating XMPP Stream

2019-10-13 20:39:01 | jaxmpp_ :: jaxmpp__kjclh10402@localhost/993927746-tigase-235 << <iq type="result" xmlns="jabber:client" id="d4Jq1wcTXXYqU8rhSW02aum" to="jaxmpp__kjclh10402@localhost/993927746-tigase-235"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 20:39:01 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=3346] Connector  state changed: disconnecting->disconnected

2019-10-13 20:39:01 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=3346] Stream terminated

2019-10-13 20:39:01 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-10-13 20:39:01 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

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

2019-10-13 20:39:01 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-10-13 20:39:01 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

testStateAfterAuthTimeoutWebSocket 20.400s
2019-10-13 20:39:01 |

2019-10-13 20:39:01 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2019-10-13 20:39:01 | ------------------------------------

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

2019-10-13 20:39:01 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2019-10-13 20:39:01 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using WebSocketConnector

2019-10-13 20:39:01 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Start connector.

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

2019-10-13 20:39:01 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Preparing connection to localhost

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

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

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

2019-10-13 20:39:01 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 20:39:01 | jaxmpp_ :: jaxmpp__e2xcns0403@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 20:39:21 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connected->disconnecting

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

2019-10-13 20:39:21 | jaxmpp_ :: jaxmpp__e2xcns0403@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1TczJWbEZJMmgwbFNlMDdwSTRZeDVVWlYxaDFPZlN0eTJxSmVET3lhLHM9NWd3WVU2U2wvd3k1akE9PSxpPTQwOTY=</challenge>

2019-10-13 20:39:21 | jaxmpp_ :: jaxmpp__e2xcns0403@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9U3MyVmxGSTJoMGxTZTA3cEk0WXg1VVpWMWgxT2ZTdHkycUplRE95YSxwPTFTVW5zNXExd1doOXZBSTRwMUQ0SnphdHY4a0o0WGdObFhBa1VhTUVkTlU9</response>

2019-10-13 20:39:21 | jaxmpp_ :: jaxmpp__e2xcns0403@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1tcXFGT0VkVjdTTSs3SkJpWTh0ZlJJY0YzNERYM21CK2lLcGgzazc1RUVrPQ==</success>

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

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

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

2019-10-13 20:39:21 | jaxmpp_ :: jaxmpp__e2xcns0403@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=" xmlns="http://jabber.org/protocol/caps" hash="SHA-1" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-10-13 20:39:21 | jaxmpp_ :: jaxmpp__e2xcns0403@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=" xmlns="http://jabber.org/protocol/caps" hash="SHA-1" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-10-13 20:39:21 | jaxmpp_ :: jaxmpp__e2xcns0403@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=" xmlns="http://jabber.org/protocol/caps" hash="SHA-1" node="https://tigase.net/tigase-xmpp-server"/></features>

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

2019-10-13 20:39:21 | jaxmpp_ :: jaxmpp__e2xcns0403@localhost >> <iq xmlns="jabber:client" id="9nnEurWmTgGRTPIUS4j1mUW" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

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

2019-10-13 20:39:21 | jaxmpp_ :: jaxmpp__e2xcns0403@localhost << <iq type="result" xmlns="jabber:client" id="WxTzkMAgGKURQSaN1gX6Fog" to="jaxmpp__e2xcns0403@localhost/993927746-tigase-236"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__e2xcns0403@localhost/993927746-tigase-236</jid></bind></iq>

2019-10-13 20:39:21 | jaxmpp_ :: jaxmpp__e2xcns0403@localhost << <iq type="result" xmlns="jabber:client" id="9nnEurWmTgGRTPIUS4j1mUW" to="jaxmpp__e2xcns0403@localhost/993927746-tigase-237"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__e2xcns0403@localhost/993927746-tigase-237</jid></bind></iq>

2019-10-13 20:39:21 | jaxmpp_ :: jaxmpp__e2xcns0403@localhost << <iq type="result" xmlns="jabber:client" id="QdRfY0kP3q2cqW2skHweSdR" to="jaxmpp__e2xcns0403@localhost/993927746-tigase-238"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__e2xcns0403@localhost/993927746-tigase-238</jid></bind></iq>

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

2019-10-13 20:39:21 | jaxmpp_ :: jaxmpp__e2xcns0403@localhost/993927746-tigase-236 >> <iq xmlns="jabber:client" id="xzTFnSWi3xi1eVUiL0aPPHs" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

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

2019-10-13 20:39:21 | jaxmpp_ :: jaxmpp__e2xcns0403@localhost/993927746-tigase-237 >> <iq xmlns="jabber:client" id="MGc1xfx8Kyq1rcAiCkO0qTU" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-10-13 20:39:21 | jaxmpp_ :: jaxmpp__e2xcns0403@localhost/993927746-tigase-237 << <iq type="result" xmlns="jabber:client" id="xzTFnSWi3xi1eVUiL0aPPHs" to="jaxmpp__e2xcns0403@localhost/993927746-tigase-238"/>

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

2019-10-13 20:39:21 | jaxmpp_ :: jaxmpp__e2xcns0403@localhost/993927746-tigase-238 >> <iq xmlns="jabber:client" id="tl9NGwqgzgIQ9JGNM16Gxyg" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

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

2019-10-13 20:39:21 | jaxmpp_ :: jaxmpp__e2xcns0403@localhost/993927746-tigase-238 >> <iq to="localhost" id="YqmjEoWgWVY8GP5odCHsoXo" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-10-13 20:39:21 | jaxmpp_ :: jaxmpp__e2xcns0403@localhost/993927746-tigase-238 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/>

2019-10-13 20:39:21 | jaxmpp_ :: jaxmpp__e2xcns0403@localhost/993927746-tigase-238 >> <iq id="ziWt8GP5odCHsoXoWnVTQao" type="get"><query xmlns="jabber:iq:roster"/></iq>

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

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

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

2019-10-13 20:39:21 | jaxmpp_ :: jaxmpp__e2xcns0403@localhost/993927746-tigase-238 << <enabled location="d4270859fb27" xmlns="urn:xmpp:sm:3" id="fe7630dc-53ef-45af-848a-089834216dd8" resume="true" max="60"/>

2019-10-13 20:39:21 | jaxmpp_ :: jaxmpp__e2xcns0403@localhost/993927746-tigase-238 << <iq type="result" xmlns="jabber:client" id="MGc1xfx8Kyq1rcAiCkO0qTU" to="jaxmpp__e2xcns0403@localhost/993927746-tigase-238"/>

2019-10-13 20:39:21 | jaxmpp_ :: jaxmpp__e2xcns0403@localhost/993927746-tigase-238 << <iq type="result" xmlns="jabber:client" id="tl9NGwqgzgIQ9JGNM16Gxyg" to="jaxmpp__e2xcns0403@localhost/993927746-tigase-238"/>

2019-10-13 20:39:21 | jaxmpp_ :: jaxmpp__e2xcns0403@localhost/993927746-tigase-238 << <iq type="result" from="localhost" xmlns="jabber:client" id="YqmjEoWgWVY8GP5odCHsoXo" to="jaxmpp__e2xcns0403@localhost/993927746-tigase-238"><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 type="result" xmlns="jabber:x:data"><field var="FORM_TYPE" type="hidden"><value>http://jabber.org/network/serverinfo</value></field><field var="abuse-addresses" type="text-multi"><value>mailto:abuse@localhost</value><value>xmpp:abuse@localhost</value></field></x><feature var="urn:xmpp:carbons:2"/><feature var="http://jabber.org/protocol/stats"/><feature var="vcard-temp"/><feature var="jabber:iq:auth"/><feature var="http://jabber.org/protocol/amp"/><feature var="msgoffline"/><feature var="http://jabber.org/protocol/disco#info"/><feature var="http://jabber.org/protocol/disco#items"/><feature var="urn:xmpp:blocking"/><feature var="urn:xmpp:ping"/><feature var="urn:ietf:params:xml:ns:xmpp-sasl"/><feature var="http://jabber.org/protocol/pubsub"/><feature var="http://jabber.org/protocol/pubsub#owner"/><feature var="http://jabber.org/protocol/pubsub#publish"/><identity category="pubsub" type="pep"/><feature var="urn:xmpp:pep-vcard-conversion:0"/><feature var="urn:xmpp:bookmarks-conversion:0"/><feature var="urn:xmpp:archive:auto"/><feature var="urn:xmpp:archive:manage"/><feature var="urn:xmpp:push:0"/><feature var="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="jabber:iq:private"/><feature var="urn:ietf:params:xml:ns:xmpp-session"/></query></iq>

2019-10-13 20:39:21 | jaxmpp_ :: jaxmpp__e2xcns0403@localhost/993927746-tigase-238 << <iq type="result" xmlns="jabber:client" id="ziWt8GP5odCHsoXoWnVTQao" to="jaxmpp__e2xcns0403@localhost/993927746-tigase-238"><query xmlns="jabber:iq:roster"/></iq>

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

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

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

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

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

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

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

2019-10-13 20:39:24 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

testStateAfterConnectionFailureBosh 0.708s
2019-10-13 20:39:22 |

2019-10-13 20:39:22 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2019-10-13 20:39:22 | ------------------------------------

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

2019-10-13 20:39:22 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2019-10-13 20:39:22 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using BOSHConnector

2019-10-13 20:39:22 | tigase.jaxmpp.j2se.connectors.bosh.BoshWorker.run: Connection error

2019-10-13 20:39:22 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onError: responseCode=0

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

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

2019-10-13 20:39:22 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2019-10-13 20:39:22 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using BOSHConnector

2019-10-13 20:39:22 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2019-10-13 20:39:22 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-10-13 20:39:22 | jaxmpp_ :: jaxmpp__x20nkp0404@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX3gyMG5rcDA0MDQscj1YZlRBbktuVDBBM0RYNDVTaEVwRw==</auth>

2019-10-13 20:39:22 | jaxmpp_ :: jaxmpp__x20nkp0404@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 20:39:22 | jaxmpp_ :: jaxmpp__x20nkp0404@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1YZlRBbktuVDBBM0RYNDVTaEVwR3ZiT3pTOGNESGlCVERROVVQcFV6LHM9elZyTjE1QzgwMmFiT3c9PSxpPTQwOTY=</challenge>

2019-10-13 20:39:22 | jaxmpp_ :: jaxmpp__x20nkp0404@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9WGZUQW5LblQwQTNEWDQ1U2hFcEd2Yk96UzhjREhpQlREUTlVUHBVeixwPUQzWXpEYWdmTWl5SkRrTWdjQndQeDJwOWpMVnk5eUdTdTFCdGpxRmEzWkU9</response>

2019-10-13 20:39:22 | jaxmpp_ :: jaxmpp__x20nkp0404@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj0rbnhHNDRocjgydXdJY1VEWXZML1hSajRWL0F2cDlFSFFpb1BpcW54VlVJPQ==</success>

2019-10-13 20:39:22 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 20:39:22 | jaxmpp_ :: jaxmpp__x20nkp0404@localhost >> <iq xmlns="jabber:client" id="0vnBChGywvr6DsnO6neCJDj" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-10-13 20:39:22 | jaxmpp_ :: jaxmpp__x20nkp0404@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=" xmlns="http://jabber.org/protocol/caps" hash="SHA-1" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-10-13 20:39:22 | jaxmpp_ :: jaxmpp__x20nkp0404@localhost << <iq type="result" xmlns="jabber:client" id="0vnBChGywvr6DsnO6neCJDj" to="jaxmpp__x20nkp0404@localhost/993927746-tigase-239"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__x20nkp0404@localhost/993927746-tigase-239</jid></bind></iq>

2019-10-13 20:39:22 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-10-13 20:39:22 | jaxmpp_ :: jaxmpp__x20nkp0404@localhost/993927746-tigase-239 >> <iq to="localhost" id="HyuUSeDKENLzcSOW3vkQOEo" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-10-13 20:39:22 | jaxmpp_ :: jaxmpp__x20nkp0404@localhost/993927746-tigase-239 >> <iq id="up1Bm6ChGywvr6DsnO6neCJ" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 20:39:22 | jaxmpp_ :: jaxmpp__x20nkp0404@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 20:39:22 | jaxmpp_ :: jaxmpp__x20nkp0404@localhost/993927746-tigase-239 << <iq type="result" from="localhost" xmlns="jabber:client" id="HyuUSeDKENLzcSOW3vkQOEo" to="jaxmpp__x20nkp0404@localhost/993927746-tigase-239"><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 type="result" xmlns="jabber:x:data"><field var="FORM_TYPE" type="hidden"><value>http://jabber.org/network/serverinfo</value></field><field var="abuse-addresses" type="text-multi"><value>mailto:abuse@localhost</value><value>xmpp:abuse@localhost</value></field></x><feature var="urn:xmpp:carbons:2"/><feature var="http://jabber.org/protocol/stats"/><feature var="vcard-temp"/><feature var="jabber:iq:auth"/><feature var="http://jabber.org/protocol/amp"/><feature var="msgoffline"/><feature var="http://jabber.org/protocol/disco#info"/><feature var="http://jabber.org/protocol/disco#items"/><feature var="urn:xmpp:blocking"/><feature var="urn:xmpp:ping"/><feature var="urn:ietf:params:xml:ns:xmpp-sasl"/><feature var="http://jabber.org/protocol/pubsub"/><feature var="http://jabber.org/protocol/pubsub#owner"/><feature var="http://jabber.org/protocol/pubsub#publish"/><identity category="pubsub" type="pep"/><feature var="urn:xmpp:pep-vcard-conversion:0"/><feature var="urn:xmpp:bookmarks-conversion:0"/><feature var="urn:xmpp:archive:auto"/><feature var="urn:xmpp:archive:manage"/><feature var="urn:xmpp:push:0"/><feature var="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="jabber:iq:private"/><feature var="urn:ietf:params:xml:ns:xmpp-session"/></query></iq>

2019-10-13 20:39:22 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onError: responseCode=404

2019-10-13 20:39:22 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onError: responseCode=500

2019-10-13 20:39:22 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

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

testStateAfterConnectionFailureWebSocket 0.445s
2019-10-13 20:39:23 |

2019-10-13 20:39:23 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2019-10-13 20:39:23 | ------------------------------------

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

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using WebSocketConnector

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Start connector.

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

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

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

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

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using WebSocketConnector

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Start connector.

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

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Preparing connection to localhost

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

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

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

2019-10-13 20:39:23 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

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

2019-10-13 20:39:23 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-10-13 20:39:23 | jaxmpp_ :: jaxmpp__dc6vx30406@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX2RjNnZ4MzA0MDYscj1hdHNKTTdsMFJsRFpoWmlqc2k1Tg==</auth>

2019-10-13 20:39:23 | jaxmpp_ :: jaxmpp__dc6vx30406@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1hdHNKTTdsMFJsRFpoWmlqc2k1TllYdWdwNnI0T1ZXMkpnV1FaekVOLHM9UFp4S2lxSURqT2FPbXc9PSxpPTQwOTY=</challenge>

2019-10-13 20:39:23 | jaxmpp_ :: jaxmpp__dc6vx30406@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9YXRzSk03bDBSbERaaFppanNpNU5ZWHVncDZyNE9WVzJKZ1dRWnpFTixwPWh5MGxsUXd6bkIwV2VZbklPTTRGNXFnaTJzTTdOS2Z1YmkvRDV3UktGQjQ9</response>

2019-10-13 20:39:23 | jaxmpp_ :: jaxmpp__dc6vx30406@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1KcS9FRG1YOVRtTXR6UG00eCs0eU5lMENFYUEyNU5LMi9QMVQweU13SjdvPQ==</success>

2019-10-13 20:39:23 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-10-13 20:39:23 | jaxmpp_ :: jaxmpp__dc6vx30406@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=" xmlns="http://jabber.org/protocol/caps" hash="SHA-1" node="https://tigase.net/tigase-xmpp-server"/></features>

2019-10-13 20:39:23 | jaxmpp_ :: jaxmpp__dc6vx30406@localhost >> <iq xmlns="jabber:client" id="oO0EHICmKAk2u1awsnbABof" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-10-13 20:39:23 | jaxmpp_ :: jaxmpp__dc6vx30406@localhost << <iq type="result" xmlns="jabber:client" id="oO0EHICmKAk2u1awsnbABof" to="jaxmpp__dc6vx30406@localhost/993927746-tigase-240"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__dc6vx30406@localhost/993927746-tigase-240</jid></bind></iq>

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-10-13 20:39:23 | jaxmpp_ :: jaxmpp__dc6vx30406@localhost/993927746-tigase-240 >> <iq xmlns="jabber:client" id="WUgjOKw8qeSNICELX8HADk8" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-10-13 20:39:23 | jaxmpp_ :: jaxmpp__dc6vx30406@localhost/993927746-tigase-240 << <iq type="result" xmlns="jabber:client" id="WUgjOKw8qeSNICELX8HADk8" to="jaxmpp__dc6vx30406@localhost/993927746-tigase-240"/>

2019-10-13 20:39:23 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management

2019-10-13 20:39:23 | jaxmpp_ :: jaxmpp__dc6vx30406@localhost/993927746-tigase-240 >> <iq to="localhost" id="4Eszyzzm9urWmTgGRTPIUS4" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-10-13 20:39:23 | jaxmpp_ :: jaxmpp__dc6vx30406@localhost/993927746-tigase-240 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/>

2019-10-13 20:39:23 | jaxmpp_ :: jaxmpp__dc6vx30406@localhost/993927746-tigase-240 >> <iq id="bJFgAEtq0vbpSewmTbGyeu4" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 20:39:23 | jaxmpp_ :: jaxmpp__dc6vx30406@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 20:39:23 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connected->disconnecting

2019-10-13 20:39:23 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.terminateStream: Terminating XMPP Stream

2019-10-13 20:39:23 | jaxmpp_ :: jaxmpp__dc6vx30406@localhost/993927746-tigase-240 << <enabled location="d4270859fb27" xmlns="urn:xmpp:sm:3" id="155eaae0-df7b-4e0c-b3ca-299a11c391c2" resume="true" max="60"/>

2019-10-13 20:39:23 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

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

2019-10-13 20:39:23 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

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