Test Results Report - Testing state of JaXMPP instance after issues with connection or authentication timeout

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

Test duration: 64.997s

Failed Tests
tigase.tests.jaxmpp.TestHandlingOfConnectionIssues
testStateAfterConnectionFailureSocket	0.082s	2019-10-13 20:19:15 \| 2019-10-13 20:19:15 \| null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues] 2019-10-13 20:19:15 \| ------------------------------------ 2019-10-13 20:19:15 \| tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream] 2019-10-13 20:19:15 \| tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false 2019-10-13 20:19:15 \| tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector 2019-10-13 20:19:15 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=524 thread=1] Connector state changed: null->connecting 2019-10-13 20:19:15 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=524 thread=1] DNS entry stored in session object: missing:5222 2019-10-13 20:19:15 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=524 thread=1] Preparing connection to [missing:5222] 2019-10-13 20:19:15 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=524 thread=1] missing. Trying next. 2019-10-13 20:19:15 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=524 thread=1] Connector state changed: connecting->disconnected 2019-10-13 20:19:15 \| tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream, session] 2019-10-13 20:19:15 \| tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream] 2019-10-13 20:19:15 \| tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true 2019-10-13 20:19:15 \| tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector 2019-10-13 20:19:15 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=1] Connector state changed: null->connecting 2019-10-13 20:19:15 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=1] DNS entry stored in session object: localhost:5222 2019-10-13 20:19:15 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=1] Preparing connection to [localhost:5222] 2019-10-13 20:19:15 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=1] Opening connection to localhost/127.0.0.1:5222 2019-10-13 20:19:15 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=1] Connector state changed: connecting->connected 2019-10-13 20:19:15 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=1] Whitespace ping period is setted to nullms 2019-10-13 20:19:15 \| tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled 2019-10-13 20:19:15 \| jaxmpp_ :: jaxmpp__veh6bi0405@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:19:15 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=3408] Start TLS 2019-10-13 20:19:15 \| jaxmpp_ :: jaxmpp__veh6bi0405@localhost >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/> 2019-10-13 20:19:15 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=3412] Proceeding TLS 2019-10-13 20:19:15 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=3412] Start handshake 2019-10-13 20:19:15 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=3412] Can't establish encrypted connection 2019-10-13 20:19:15 \| tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted 2019-10-13 20:19:15 \| tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted 2019-10-13 20:19:15 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=3412] Connector state changed: connected->disconnected 2019-10-13 20:19:15 \| tigase.jaxmpp.j2se.Jaxmpp.onException: Catching exception 2019-10-13 20:19:15 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=3408] 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)

tigase.tests.jaxmpp.TestHandlingOfConnectionIssues

testStateAfterConnectionFailureSocket

0.082s

2019-10-13 20:19:15 |

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

2019-10-13 20:19:15 | jaxmpp_ :: jaxmpp__veh6bi0405@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"/><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:19:15 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=3408] Start TLS

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

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

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

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

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

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

2019-10-13 20:19:15 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=3412] Connector state changed: connected->disconnected

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

2019-10-13 20:19:15 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=525 thread=3408] 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.555s	2019-10-13 20:18:12 \| 2019-10-13 20:18:12 \| null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues] 2019-10-13 20:18:12 \| ------------------------------------ 2019-10-13 20:18:12 \| tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream] 2019-10-13 20:18:12 \| tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false 2019-10-13 20:18:12 \| tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using BOSHConnector 2019-10-13 20:18:12 \| jaxmpp_ :: jaxmpp__jhvpq50401@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:18:32 \| tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onTerminate: Stream terminated. responseCode=200 2019-10-13 20:18:32 \| tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream] 2019-10-13 20:18:32 \| tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true 2019-10-13 20:18:32 \| tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using BOSHConnector 2019-10-13 20:18:32 \| jaxmpp_ :: jaxmpp__jhvpq50401@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:18:32 \| tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL 2019-10-13 20:18:32 \| tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL 2019-10-13 20:18:32 \| jaxmpp_ :: jaxmpp__jhvpq50401@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX2podnBxNTA0MDEscj1Ta1pBNkxmZm1YWUUyMVJUdUhhZg==</auth> 2019-10-13 20:18:32 \| jaxmpp_ :: jaxmpp__jhvpq50401@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1Ta1pBNkxmZm1YWUUyMVJUdUhhZjk5SGdQRTliR0Z0ZktGcnpCbXJ4LHM9Ky9lY3pjb1lPdkJsT3c9PSxpPTQwOTY=</challenge> 2019-10-13 20:18:33 \| jaxmpp_ :: jaxmpp__jhvpq50401@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9U2taQTZMZmZtWFlFMjFSVHVIYWY5OUhnUEU5YkdGdGZLRnJ6Qm1yeCxwPTZhcWQxdm0wYXJRei9UZkloMTNOaGM2bnRVRnlIOFRoN1hWZWh0QlBjMEE9</response> 2019-10-13 20:18:33 \| jaxmpp_ :: jaxmpp__jhvpq50401@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj02ZHJTVkpSa3VYMUN2OTJWeHJPelFXVVIzdExUdkZnR0ZUVDJXb2hrTHJFPQ==</success> 2019-10-13 20:18:33 \| tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled 2019-10-13 20:18:33 \| tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled 2019-10-13 20:18:33 \| tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled 2019-10-13 20:18:33 \| jaxmpp_ :: jaxmpp__jhvpq50401@localhost >> <iq xmlns="jabber:client" id="JalqbCoUXW0aBzu0v4rmP9q" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq> 2019-10-13 20:18:33 \| jaxmpp_ :: jaxmpp__jhvpq50401@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" node="https://tigase.net/tigase-xmpp-server" xmlns="http://jabber.org/protocol/caps"/></features> 2019-10-13 20:18:33 \| jaxmpp_ :: jaxmpp__jhvpq50401@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" node="https://tigase.net/tigase-xmpp-server" xmlns="http://jabber.org/protocol/caps"/></features> 2019-10-13 20:18:33 \| jaxmpp_ :: jaxmpp__jhvpq50401@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" node="https://tigase.net/tigase-xmpp-server" xmlns="http://jabber.org/protocol/caps"/></features> 2019-10-13 20:18:33 \| jaxmpp_ :: jaxmpp__jhvpq50401@localhost >> <iq xmlns="jabber:client" id="oevQIVU7IxzgFKKu1eDDsfP" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq> 2019-10-13 20:18:33 \| jaxmpp_ :: jaxmpp__jhvpq50401@localhost >> <iq xmlns="jabber:client" id="WUvZ2nezDoVgMy9u9Fwn5ue" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq> 2019-10-13 20:18:33 \| jaxmpp_ :: jaxmpp__jhvpq50401@localhost << <iq id="JalqbCoUXW0aBzu0v4rmP9q" to="jaxmpp__jhvpq50401@localhost/993927746-tigase-231" type="result" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__jhvpq50401@localhost/993927746-tigase-231</jid></bind></iq> 2019-10-13 20:18:33 \| tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded. 2019-10-13 20:18:33 \| jaxmpp_ :: jaxmpp__jhvpq50401@localhost/993927746-tigase-231 >> <iq to="localhost" id="cerGCzoW09kMIHLSM3aDKBH" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq> 2019-10-13 20:18:33 \| jaxmpp_ :: jaxmpp__jhvpq50401@localhost/993927746-tigase-231 << <iq id="oevQIVU7IxzgFKKu1eDDsfP" to="jaxmpp__jhvpq50401@localhost/993927746-tigase-232" type="result" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__jhvpq50401@localhost/993927746-tigase-232</jid></bind></iq> 2019-10-13 20:18:33 \| jaxmpp_ :: jaxmpp__jhvpq50401@localhost/993927746-tigase-232 >> <iq id="a61R3q6xkOKDiIArfQIVU7I" type="get"><query xmlns="jabber:iq:roster"/></iq> 2019-10-13 20:18:33 \| tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded. 2019-10-13 20:18:33 \| jaxmpp_ :: jaxmpp__jhvpq50401@localhost/993927746-tigase-232 >> <iq to="localhost" id="WXy5eL07JAj2kElSVdCztgM" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq> 2019-10-13 20:18:33 \| jaxmpp_ :: jaxmpp__jhvpq50401@localhost/993927746-tigase-232 << <iq id="WUvZ2nezDoVgMy9u9Fwn5ue" to="jaxmpp__jhvpq50401@localhost/993927746-tigase-233" type="result" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__jhvpq50401@localhost/993927746-tigase-233</jid></bind></iq> 2019-10-13 20:18:33 \| jaxmpp_ :: jaxmpp__jhvpq50401@localhost/993927746-tigase-233 >> <iq id="ndireut0j6j7mR8w27q1p0l" type="get"><query xmlns="jabber:iq:roster"/></iq> 2019-10-13 20:18:33 \| tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded. 2019-10-13 20:18:33 \| jaxmpp_ :: jaxmpp__jhvpq50401@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 20:18:33 \| jaxmpp_ :: jaxmpp__jhvpq50401@localhost/993927746-tigase-233 >> <iq to="localhost" id="794NX6xp8wn0as38oW9FGoh" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq> 2019-10-13 20:18:33 \| tigase.jaxmpp.core.client.xmpp.modules.presence.PresenceModule$3.after: Could not write stanza 2019-10-13 20:18:33 \| jaxmpp_ :: jaxmpp__jhvpq50401@localhost/993927746-tigase-233 >> <iq id="Xt0ypiHTUXkUOFwdNMT7ym3" type="get"><query xmlns="jabber:iq:roster"/></iq> 2019-10-13 20:18:33 \| jaxmpp_ :: jaxmpp__jhvpq50401@localhost/993927746-tigase-233 << <iq id="a61R3q6xkOKDiIArfQIVU7I" to="jaxmpp__jhvpq50401@localhost/993927746-tigase-233" type="result" xmlns="jabber:client"><query xmlns="jabber:iq:roster"/></iq> 2019-10-13 20:18:33 \| jaxmpp_ :: jaxmpp__jhvpq50401@localhost/993927746-tigase-233 << <iq from="localhost" id="cerGCzoW09kMIHLSM3aDKBH" to="jaxmpp__jhvpq50401@localhost/993927746-tigase-233" type="result" xmlns="jabber:client"><query xmlns="http://jabber.org/protocol/disco#info"><identity name="Tigase ver. 8.1.0-SNAPSHOT-b10535/f55efd39" category="component" type="router"/><identity name="Tigase ver. 8.1.0-SNAPSHOT-b10535/f55efd39" category="server" type="im"/><feature var="http://jabber.org/protocol/commands"/><x type="result" xmlns="jabber:x:data"><field var="FORM_TYPE" type="hidden"><value>http://jabber.org/network/serverinfo</value></field><field var="abuse-addresses" type="text-multi"><value>mailto:abuse@localhost</value><value>xmpp:abuse@localhost</value></field></x><feature var="urn:xmpp:carbons:2"/><feature var="http://jabber.org/protocol/stats"/><feature var="vcard-temp"/><feature var="jabber:iq:auth"/><feature var="http://jabber.org/protocol/amp"/><feature var="msgoffline"/><feature var="http://jabber.org/protocol/disco#info"/><feature var="http://jabber.org/protocol/disco#items"/><feature var="urn:xmpp:blocking"/><feature var="urn:xmpp:ping"/><feature var="urn:ietf:params:xml:ns:xmpp-sasl"/><feature var="http://jabber.org/protocol/pubsub"/><feature var="http://jabber.org/protocol/pubsub#owner"/><feature var="http://jabber.org/protocol/pubsub#publish"/><identity category="pubsub" type="pep"/><feature var="urn:xmpp:pep-vcard-conversion:0"/><feature var="urn:xmpp:bookmarks-conversion:0"/><feature var="urn:xmpp:archive:auto"/><feature var="urn:xmpp:archive:manage"/><feature var="urn:xmpp:push:0"/><feature var="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:18:33 \| tigase.jaxmpp.core.client.xmpp.modules.presence.PresenceModule$3.after: Could not write stanza 2019-10-13 20:18:33 \| tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset. 2019-10-13 20:18:33 \| tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session] 2019-10-13 20:18:33 \| tigase.jaxmpp.j2se.connectors.bosh.BoshWorker.run: Connection error 2019-10-13 20:18:33 \| tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onError: responseCode=0 2019-10-13 20:18:33 \| tigase.jaxmpp.j2se.connectors.bosh.BoshWorker.run: Connection error 2019-10-13 20:18:33 \| tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onError: responseCode=0 2019-10-13 20:18:33 \| tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onError: responseCode=500 2019-10-13 20:18:33 \| tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onError: responseCode=500
testStateAfterAuthTimeoutSocket	20.280s	2019-10-13 20:18:33 \| 2019-10-13 20:18:33 \| null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues] 2019-10-13 20:18:33 \| ------------------------------------ 2019-10-13 20:18:33 \| tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream] 2019-10-13 20:18:33 \| tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false 2019-10-13 20:18:33 \| tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector 2019-10-13 20:18:33 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=1] Connector state changed: null->connecting 2019-10-13 20:18:33 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=1] DNS entry stored in session object: localhost:5222 2019-10-13 20:18:33 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=1] Preparing connection to [localhost:5222] 2019-10-13 20:18:33 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=1] Opening connection to localhost/127.0.0.1:5222 2019-10-13 20:18:33 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=1] Connector state changed: connecting->connected 2019-10-13 20:18:33 \| tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled 2019-10-13 20:18:33 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=1] Whitespace ping period is setted to nullms 2019-10-13 20:18:33 \| jaxmpp_ :: jaxmpp__kxnjbf0402@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:18:33 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=3347] Start TLS 2019-10-13 20:18:33 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/> 2019-10-13 20:18:33 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=3349] Proceeding TLS 2019-10-13 20:18:33 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=3349] Start handshake 2019-10-13 20:18:33 \| tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled 2019-10-13 20:18:33 \| jaxmpp_ :: jaxmpp__kxnjbf0402@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:18:53 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=3349] Connector state changed: connected->disconnected 2019-10-13 20:18:53 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=3349] Stream terminated 2019-10-13 20:18:53 \| tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted 2019-10-13 20:18:53 \| tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted 2019-10-13 20:18:53 \| tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream] 2019-10-13 20:18:53 \| tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true 2019-10-13 20:18:53 \| tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector 2019-10-13 20:18:53 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=1] Connector state changed: null->connecting 2019-10-13 20:18:53 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=1] DNS entry stored in session object: localhost:5222 2019-10-13 20:18:53 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=1] Preparing connection to [localhost:5222] 2019-10-13 20:18:53 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=1] Opening connection to localhost/127.0.0.1:5222 2019-10-13 20:18:53 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=1] Connector state changed: connecting->connected 2019-10-13 20:18:53 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=1] Whitespace ping period is setted to nullms 2019-10-13 20:18:53 \| tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@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:18:53 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=3347] Start TLS 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/> 2019-10-13 20:18:53 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=3354] Proceeding TLS 2019-10-13 20:18:53 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=3354] Start handshake 2019-10-13 20:18:53 \| tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@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:18:53 \| tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL 2019-10-13 20:18:53 \| tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX2t4bmpiZjA0MDIscj15Vm1jdmlSMFBUYXFKUDYwOG1nRg==</auth> 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj15Vm1jdmlSMFBUYXFKUDYwOG1nRlNhcTZSWjdSUFRHSFRQTjRGMldBLHM9OWdqNUxFcUJWQkYvcXc9PSxpPTQwOTY=</challenge> 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9eVZtY3ZpUjBQVGFxSlA2MDhtZ0ZTYXE2Ulo3UlBUR0hUUE40RjJXQSxwPVFLaUJCZnhsdEY3emliTWh3ZUs5c3IxMlV1QUs0NGQvY21CekdzbjlROTg9</response> 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1aOTNEVlhlNWd5QUtsdmVTQSszWGJZWHBjNDNkUnlIcHowMGN3eGNiaStZPQ==</success> 2019-10-13 20:18:53 \| tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled 2019-10-13 20:18:53 \| tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled 2019-10-13 20:18:53 \| tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@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" node="https://tigase.net/tigase-xmpp-server" xmlns="http://jabber.org/protocol/caps"/></features> 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@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" node="https://tigase.net/tigase-xmpp-server" xmlns="http://jabber.org/protocol/caps"/></features> 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@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" node="https://tigase.net/tigase-xmpp-server" xmlns="http://jabber.org/protocol/caps"/></features> 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost >> <iq xmlns="jabber:client" id="JmyPZeCmRKCo3tiCJwlarnS" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq> 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost >> <iq xmlns="jabber:client" id="W5HmMRcvv8peIqTY7Bo7zsa" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq> 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost >> <iq xmlns="jabber:client" id="Q6I1cFHKwx8zClbu7Ey6fGx" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq> 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost << <iq id="JmyPZeCmRKCo3tiCJwlarnS" to="jaxmpp__kxnjbf0402@localhost/993927746-tigase-234" type="result" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__kxnjbf0402@localhost/993927746-tigase-234</jid></bind></iq> 2019-10-13 20:18:53 \| tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded. 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-234 >> <iq xmlns="jabber:client" id="fqE1cwboUYdNWUjGFOJX2dQ" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq> 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-234 << <iq id="W5HmMRcvv8peIqTY7Bo7zsa" to="jaxmpp__kxnjbf0402@localhost/993927746-tigase-235" type="result" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__kxnjbf0402@localhost/993927746-tigase-235</jid></bind></iq> 2019-10-13 20:18:53 \| tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded. 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-235 >> <iq xmlns="jabber:client" id="9tLbHJMOXau6lIygNXgyBgP" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq> 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-235 << <iq id="Q6I1cFHKwx8zClbu7Ey6fGx" to="jaxmpp__kxnjbf0402@localhost/993927746-tigase-236" type="result" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__kxnjbf0402@localhost/993927746-tigase-236</jid></bind></iq> 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-235 << <iq id="fqE1cwboUYdNWUjGFOJX2dQ" to="jaxmpp__kxnjbf0402@localhost/993927746-tigase-236" type="result" xmlns="jabber:client"/> 2019-10-13 20:18:53 \| tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded. 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-236 >> <iq xmlns="jabber:client" id="7jf8DsfPYcJIAiJu6mZl26H" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq> 2019-10-13 20:18:53 \| tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-236 >> <iq to="localhost" id="NiaVZ08q7By8LAtqXpW1sak" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq> 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-236 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/> 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-236 << <iq id="9tLbHJMOXau6lIygNXgyBgP" to="jaxmpp__kxnjbf0402@localhost/993927746-tigase-236" type="result" xmlns="jabber:client"/> 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-236 >> <iq id="FwOhT7ym3mSSTOKEzvmKZ2n" type="get"><query xmlns="jabber:iq:roster"/></iq> 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-236 << <enabled id="f0560e46-a0f2-477f-a10e-36c47d1223e3" max="60" location="d4270859fb27" xmlns="urn:xmpp:sm:3" resume="true"/> 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@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 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-236 << <iq id="7jf8DsfPYcJIAiJu6mZl26H" to="jaxmpp__kxnjbf0402@localhost/993927746-tigase-236" type="result" xmlns="jabber:client"/> 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-236 >> <iq to="localhost" id="seUAEpjKDGCevczvcJNU4tc" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq> 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-236 << <iq from="localhost" id="NiaVZ08q7By8LAtqXpW1sak" to="jaxmpp__kxnjbf0402@localhost/993927746-tigase-236" type="result" xmlns="jabber:client"><query xmlns="http://jabber.org/protocol/disco#info"><identity name="Tigase ver. 8.1.0-SNAPSHOT-b10535/f55efd39" category="component" type="router"/><identity name="Tigase ver. 8.1.0-SNAPSHOT-b10535/f55efd39" category="server" type="im"/><feature var="http://jabber.org/protocol/commands"/><x type="result" xmlns="jabber:x:data"><field var="FORM_TYPE" type="hidden"><value>http://jabber.org/network/serverinfo</value></field><field var="abuse-addresses" type="text-multi"><value>mailto:abuse@localhost</value><value>xmpp:abuse@localhost</value></field></x><feature var="urn:xmpp:carbons:2"/><feature var="http://jabber.org/protocol/stats"/><feature var="vcard-temp"/><feature var="jabber:iq:auth"/><feature var="http://jabber.org/protocol/amp"/><feature var="msgoffline"/><feature var="http://jabber.org/protocol/disco#info"/><feature var="http://jabber.org/protocol/disco#items"/><feature var="urn:xmpp:blocking"/><feature var="urn:xmpp:ping"/><feature var="urn:ietf:params:xml:ns:xmpp-sasl"/><feature var="http://jabber.org/protocol/pubsub"/><feature var="http://jabber.org/protocol/pubsub#owner"/><feature var="http://jabber.org/protocol/pubsub#publish"/><identity category="pubsub" type="pep"/><feature var="urn:xmpp:pep-vcard-conversion:0"/><feature var="urn:xmpp:bookmarks-conversion:0"/><feature var="urn:xmpp:archive:auto"/><feature var="urn:xmpp:archive:manage"/><feature var="urn:xmpp:push:0"/><feature var="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:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-236 >> <iq to="localhost" id="Oj7QIygNXgyBgP8nfCnaAan" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq> 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-236 >> <iq id="MswFs38oW9FGohCxydVY5Aq" type="get"><query xmlns="jabber:iq:roster"/></iq> 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-236 >> <iq id="ymchOChKFHAvl0gRY6kNCmS" type="get"><query xmlns="jabber:iq:roster"/></iq> 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-236 << <iq id="FwOhT7ym3mSSTOKEzvmKZ2n" to="jaxmpp__kxnjbf0402@localhost/993927746-tigase-236" type="result" xmlns="jabber:client"><query xmlns="jabber:iq:roster"/></iq> 2019-10-13 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@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 20:18:53 \| jaxmpp_ :: jaxmpp__kxnjbf0402@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 20:18:53 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=1] Connector state changed: connected->disconnecting 2019-10-13 20:18:53 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=1] Terminating XMPP Stream 2019-10-13 20:18:53 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=3354] Connector state changed: disconnecting->disconnected 2019-10-13 20:18:53 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=3354] Stream terminated 2019-10-13 20:18:53 \| tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted 2019-10-13 20:18:53 \| tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset. 2019-10-13 20:18:53 \| tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session] 2019-10-13 20:18:53 \| tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted 2019-10-13 20:18:53 \| tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted
testStateAfterAuthTimeoutWebSocket	20.379s	2019-10-13 20:18:54 \| 2019-10-13 20:18:54 \| null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues] 2019-10-13 20:18:54 \| ------------------------------------ 2019-10-13 20:18:54 \| tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream] 2019-10-13 20:18:54 \| tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false 2019-10-13 20:18:54 \| tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using WebSocketConnector 2019-10-13 20:18:54 \| tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Start connector. 2019-10-13 20:18:54 \| tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: null->connecting 2019-10-13 20:18:54 \| tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Preparing connection to localhost 2019-10-13 20:18:54 \| tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Opening connection to localhost/127.0.0.1:5290 2019-10-13 20:18:54 \| tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connecting->connected 2019-10-13 20:18:54 \| tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Whitespace ping period is setted to nullms 2019-10-13 20:18:54 \| tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled 2019-10-13 20:18:54 \| jaxmpp_ :: jaxmpp__a8bvsy0403@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:19:14 \| tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connected->disconnecting 2019-10-13 20:19:14 \| tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.terminateStream: Terminating XMPP Stream 2019-10-13 20:19:14 \| tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.onStreamTerminate: Stream terminated 2019-10-13 20:19:14 \| tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted 2019-10-13 20:19:14 \| tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: disconnecting->disconnected 2019-10-13 20:19:14 \| tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream] 2019-10-13 20:19:14 \| tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true 2019-10-13 20:19:14 \| tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using WebSocketConnector 2019-10-13 20:19:14 \| tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Start connector. 2019-10-13 20:19:14 \| tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: null->connecting 2019-10-13 20:19:14 \| tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Preparing connection to localhost 2019-10-13 20:19:14 \| tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Opening connection to localhost/127.0.0.1:5290 2019-10-13 20:19:14 \| tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connecting->connected 2019-10-13 20:19:14 \| tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Whitespace ping period is setted to nullms 2019-10-13 20:19:14 \| tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@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:19:14 \| tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL 2019-10-13 20:19:14 \| tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX2E4YnZzeTA0MDMscj1HYTJHYkp3SzlBTExlZEI1V0FhQw==</auth> 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1HYTJHYkp3SzlBTExlZEI1V0FhQ3VkV3NwZ3ZWM05DSjFWRHR4N2czLHM9QnhYa0tUQ1RmejZpblE9PSxpPTQwOTY=</challenge> 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9R2EyR2JKd0s5QUxMZWRCNVdBYUN1ZFdzcGd2VjNOQ0oxVkR0eDdnMyxwPUk4cFNhSXJlUGxIbU13Sy9QamV6NWw1U1JvSUJZY0FIMU5MeHNRYmVzVGM9</response> 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1BVmJFWlZZT1ExVVQxcVgzVWVqZ05teHlBUkc1YnlYbk4xMnU2UUx5UVdRPQ==</success> 2019-10-13 20:19:14 \| tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled 2019-10-13 20:19:14 \| tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled 2019-10-13 20:19:14 \| tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@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" node="https://tigase.net/tigase-xmpp-server" xmlns="http://jabber.org/protocol/caps"/></features> 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@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" node="https://tigase.net/tigase-xmpp-server" xmlns="http://jabber.org/protocol/caps"/></features> 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@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" node="https://tigase.net/tigase-xmpp-server" xmlns="http://jabber.org/protocol/caps"/></features> 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@localhost >> <iq xmlns="jabber:client" id="qjVOGFOJX2dQWSNMJPQ1n4o" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq> 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@localhost >> <iq xmlns="jabber:client" id="WkWQKN4fZ6l6sURUZlS5vkU" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq> 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@localhost >> <iq xmlns="jabber:client" id="6m0FvnWdLQWdGwatY4iR5w4" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq> 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@localhost << <iq id="qjVOGFOJX2dQWSNMJPQ1n4o" to="jaxmpp__a8bvsy0403@localhost/993927746-tigase-237" type="result" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__a8bvsy0403@localhost/993927746-tigase-237</jid></bind></iq> 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@localhost << <iq id="WkWQKN4fZ6l6sURUZlS5vkU" to="jaxmpp__a8bvsy0403@localhost/993927746-tigase-238" type="result" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__a8bvsy0403@localhost/993927746-tigase-238</jid></bind></iq> 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@localhost << <iq id="6m0FvnWdLQWdGwatY4iR5w4" to="jaxmpp__a8bvsy0403@localhost/993927746-tigase-239" type="result" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__a8bvsy0403@localhost/993927746-tigase-239</jid></bind></iq> 2019-10-13 20:19:14 \| tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded. 2019-10-13 20:19:14 \| tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded. 2019-10-13 20:19:14 \| tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded. 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@localhost/993927746-tigase-239 >> <iq xmlns="jabber:client" id="0PnlP4oMBoXhKPZiQ1iKCnM" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq> 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@localhost/993927746-tigase-239 >> <iq xmlns="jabber:client" id="qnZWWbQN5iJS003iLTYhT6s" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq> 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@localhost/993927746-tigase-239 >> <iq xmlns="jabber:client" id="GyuMT6sfKEqZ08q7By8LAtq" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq> 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@localhost/993927746-tigase-239 << <iq id="0PnlP4oMBoXhKPZiQ1iKCnM" to="jaxmpp__a8bvsy0403@localhost/993927746-tigase-239" type="result" xmlns="jabber:client"/> 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@localhost/993927746-tigase-239 << <iq id="qnZWWbQN5iJS003iLTYhT6s" to="jaxmpp__a8bvsy0403@localhost/993927746-tigase-239" type="result" xmlns="jabber:client"/> 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@localhost/993927746-tigase-239 << <iq id="GyuMT6sfKEqZ08q7By8LAtq" to="jaxmpp__a8bvsy0403@localhost/993927746-tigase-239" type="result" xmlns="jabber:client"/> 2019-10-13 20:19:14 \| tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management 2019-10-13 20:19:14 \| tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management 2019-10-13 20:19:14 \| tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@localhost/993927746-tigase-239 >> <iq to="localhost" id="xvjeS003iLTYhT6sfKEqZ08" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq> 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@localhost/993927746-tigase-239 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/> 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@localhost/993927746-tigase-239 >> <iq to="localhost" id="SyqAxqSfypiHTUXkUOFwdNM" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq> 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@localhost/993927746-tigase-239 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/> 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@localhost/993927746-tigase-239 >> <iq to="localhost" id="dJVztcyeBeAkVdMAFo5EpjK" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq> 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@localhost/993927746-tigase-239 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/> 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@localhost/993927746-tigase-239 >> <iq id="VM2zDkXoThGvq6cr4jZaFFE" type="get"><query xmlns="jabber:iq:roster"/></iq> 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@localhost/993927746-tigase-239 >> <iq id="qt58kXoThGvq6cr4jZaFFEy" type="get"><query xmlns="jabber:iq:roster"/></iq> 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@localhost/993927746-tigase-239 >> <iq id="bN1Q0gRY6kNCmS1pamduh2b" type="get"><query xmlns="jabber:iq:roster"/></iq> 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@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:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@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:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@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:19:14 \| tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connected->disconnecting 2019-10-13 20:19:14 \| tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.terminateStream: Terminating XMPP Stream 2019-10-13 20:19:14 \| jaxmpp_ :: jaxmpp__a8bvsy0403@localhost/993927746-tigase-239 << <enabled id="cb8b4e5d-1a6a-4582-a643-8bd4f8c1ed1f" max="60" location="d4270859fb27" xmlns="urn:xmpp:sm:3" resume="true"/> 2019-10-13 20:19:14 \| tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset. 2019-10-13 20:19:14 \| tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session] 2019-10-13 20:19:14 \| tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted 2019-10-13 20:19:14 \| tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: disconnecting->disconnected
testStateAfterConnectionFailureBosh	0.759s	2019-10-13 20:19:14 \| 2019-10-13 20:19:14 \| null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues] 2019-10-13 20:19:14 \| ------------------------------------ 2019-10-13 20:19:14 \| tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream] 2019-10-13 20:19:14 \| tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false 2019-10-13 20:19:14 \| tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using BOSHConnector 2019-10-13 20:19:14 \| tigase.jaxmpp.j2se.connectors.bosh.BoshWorker.run: Connection error 2019-10-13 20:19:14 \| tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onError: responseCode=0 2019-10-13 20:19:14 \| tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream, session] 2019-10-13 20:19:14 \| tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream] 2019-10-13 20:19:14 \| tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true 2019-10-13 20:19:14 \| tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using BOSHConnector 2019-10-13 20:19:15 \| jaxmpp_ :: jaxmpp__luaerh0404@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:19:15 \| tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL 2019-10-13 20:19:15 \| tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL 2019-10-13 20:19:15 \| jaxmpp_ :: jaxmpp__luaerh0404@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX2x1YWVyaDA0MDQscj1PVEt1SzlxTGlINzVybzJzdTdEbA==</auth> 2019-10-13 20:19:15 \| jaxmpp_ :: jaxmpp__luaerh0404@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1PVEt1SzlxTGlINzVybzJzdTdEbENFZzBHOXc4Y0ZXM3BLMFlDNHpELHM9bmgvaHpiTnNzOVRFckE9PSxpPTQwOTY=</challenge> 2019-10-13 20:19:15 \| jaxmpp_ :: jaxmpp__luaerh0404@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9T1RLdUs5cUxpSDc1cm8yc3U3RGxDRWcwRzl3OGNGVzNwSzBZQzR6RCxwPXBidTlxcXpOSWs4eWMvWExwU1hKcFRpVzcvbDFXR1ZjajNwRWNOYS85Tmc9</response> 2019-10-13 20:19:15 \| jaxmpp_ :: jaxmpp__luaerh0404@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj13R0NtZTJUYmQ5Q3hHbys4c0ZHby9uUmpWQnV0UWRGaitiQU5jV1hzUjk0PQ==</success> 2019-10-13 20:19:15 \| tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled 2019-10-13 20:19:15 \| jaxmpp_ :: jaxmpp__luaerh0404@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" node="https://tigase.net/tigase-xmpp-server" xmlns="http://jabber.org/protocol/caps"/></features> 2019-10-13 20:19:15 \| jaxmpp_ :: jaxmpp__luaerh0404@localhost >> <iq xmlns="jabber:client" id="yFvT24byhV2p9CujSUW14gG" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq> 2019-10-13 20:19:15 \| tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded. 2019-10-13 20:19:15 \| jaxmpp_ :: jaxmpp__luaerh0404@localhost/993927746-tigase-240 >> <iq to="localhost" id="IS6ZeNQQOLyeCvn6eXYfY3B" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq> 2019-10-13 20:19:15 \| jaxmpp_ :: jaxmpp__luaerh0404@localhost/993927746-tigase-240 << <iq id="yFvT24byhV2p9CujSUW14gG" to="jaxmpp__luaerh0404@localhost/993927746-tigase-240" type="result" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__luaerh0404@localhost/993927746-tigase-240</jid></bind></iq> 2019-10-13 20:19:15 \| jaxmpp_ :: jaxmpp__luaerh0404@localhost/993927746-tigase-240 >> <iq id="TPVGIspS3Ah3eBCuYZavnWd" type="get"><query xmlns="jabber:iq:roster"/></iq> 2019-10-13 20:19:15 \| jaxmpp_ :: jaxmpp__luaerh0404@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:19:15 \| jaxmpp_ :: jaxmpp__luaerh0404@localhost/993927746-tigase-240 << <iq from="localhost" id="IS6ZeNQQOLyeCvn6eXYfY3B" to="jaxmpp__luaerh0404@localhost/993927746-tigase-240" type="result" xmlns="jabber:client"><query xmlns="http://jabber.org/protocol/disco#info"><identity name="Tigase ver. 8.1.0-SNAPSHOT-b10535/f55efd39" category="component" type="router"/><identity name="Tigase ver. 8.1.0-SNAPSHOT-b10535/f55efd39" category="server" type="im"/><feature var="http://jabber.org/protocol/commands"/><x type="result" xmlns="jabber:x:data"><field var="FORM_TYPE" type="hidden"><value>http://jabber.org/network/serverinfo</value></field><field var="abuse-addresses" type="text-multi"><value>mailto:abuse@localhost</value><value>xmpp:abuse@localhost</value></field></x><feature var="urn:xmpp:carbons:2"/><feature var="http://jabber.org/protocol/stats"/><feature var="vcard-temp"/><feature var="jabber:iq:auth"/><feature var="http://jabber.org/protocol/amp"/><feature var="msgoffline"/><feature var="http://jabber.org/protocol/disco#info"/><feature var="http://jabber.org/protocol/disco#items"/><feature var="urn:xmpp:blocking"/><feature var="urn:xmpp:ping"/><feature var="urn:ietf:params:xml:ns:xmpp-sasl"/><feature var="http://jabber.org/protocol/pubsub"/><feature var="http://jabber.org/protocol/pubsub#owner"/><feature var="http://jabber.org/protocol/pubsub#publish"/><identity category="pubsub" type="pep"/><feature var="urn:xmpp:pep-vcard-conversion:0"/><feature var="urn:xmpp:bookmarks-conversion:0"/><feature var="urn:xmpp:archive:auto"/><feature var="urn:xmpp:archive:manage"/><feature var="urn:xmpp:push:0"/><feature var="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:19:15 \| tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onTerminate: Stream terminated. responseCode=200 2019-10-13 20:19:15 \| tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onError: responseCode=500 2019-10-13 20:19:15 \| tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset. 2019-10-13 20:19:15 \| tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session]
testStateAfterConnectionFailureWebSocket	0.369s	2019-10-13 20:19:16 \| 2019-10-13 20:19:16 \| null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues] 2019-10-13 20:19:16 \| ------------------------------------ 2019-10-13 20:19:16 \| tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream] 2019-10-13 20:19:16 \| tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false 2019-10-13 20:19:16 \| tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using WebSocketConnector 2019-10-13 20:19:16 \| tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Start connector. 2019-10-13 20:19:16 \| tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: null->connecting 2019-10-13 20:19:16 \| tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connecting->disconnected 2019-10-13 20:19:16 \| tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream, session] 2019-10-13 20:19:16 \| tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream] 2019-10-13 20:19:16 \| tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true 2019-10-13 20:19:16 \| tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using WebSocketConnector 2019-10-13 20:19:16 \| tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Start connector. 2019-10-13 20:19:16 \| tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: null->connecting 2019-10-13 20:19:16 \| tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Preparing connection to localhost 2019-10-13 20:19:16 \| tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Opening connection to localhost/127.0.0.1:5290 2019-10-13 20:19:16 \| tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connecting->connected 2019-10-13 20:19:16 \| tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Whitespace ping period is setted to nullms 2019-10-13 20:19:16 \| tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled 2019-10-13 20:19:16 \| jaxmpp_ :: jaxmpp__n1c9nq0406@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:19:16 \| tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL 2019-10-13 20:19:16 \| tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL 2019-10-13 20:19:16 \| jaxmpp_ :: jaxmpp__n1c9nq0406@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX24xYzlucTA0MDYscj1tazdZSDR3dlZQN1N3WE9RN25IWA==</auth> 2019-10-13 20:19:16 \| jaxmpp_ :: jaxmpp__n1c9nq0406@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1tazdZSDR3dlZQN1N3WE9RN25IWHpQSDF4ZlNWVGJkVlRLSjQxRzhXLHM9Umh1U1pHdTlITnV4S2c9PSxpPTQwOTY=</challenge> 2019-10-13 20:19:16 \| jaxmpp_ :: jaxmpp__n1c9nq0406@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9bWs3WUg0d3ZWUDdTd1hPUTduSFh6UEgxeGZTVlRiZFZUS0o0MUc4VyxwPStFMngzM1lDMEZqaW9NaUdMMWhRVjVEenpTVmVGS3FhOUltQ3JZQXh4MVE9</response> 2019-10-13 20:19:16 \| jaxmpp_ :: jaxmpp__n1c9nq0406@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1zbExTaFRtUmNKeUdjOHIzQVJIOWM0ZllmOWN5alRyQmhsUk16NVZBRERzPQ==</success> 2019-10-13 20:19:16 \| tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled 2019-10-13 20:19:16 \| jaxmpp_ :: jaxmpp__n1c9nq0406@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" node="https://tigase.net/tigase-xmpp-server" xmlns="http://jabber.org/protocol/caps"/></features> 2019-10-13 20:19:16 \| jaxmpp_ :: jaxmpp__n1c9nq0406@localhost >> <iq xmlns="jabber:client" id="o2ktYrWbQN5iJS003iLTYhT" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq> 2019-10-13 20:19:16 \| jaxmpp_ :: jaxmpp__n1c9nq0406@localhost << <iq id="o2ktYrWbQN5iJS003iLTYhT" to="jaxmpp__n1c9nq0406@localhost/993927746-tigase-241" type="result" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__n1c9nq0406@localhost/993927746-tigase-241</jid></bind></iq> 2019-10-13 20:19:16 \| tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded. 2019-10-13 20:19:16 \| jaxmpp_ :: jaxmpp__n1c9nq0406@localhost/993927746-tigase-241 >> <iq xmlns="jabber:client" id="xOCQ6sURUZlS5vkU9ygErUW" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq> 2019-10-13 20:19:16 \| jaxmpp_ :: jaxmpp__n1c9nq0406@localhost/993927746-tigase-241 << <iq id="xOCQ6sURUZlS5vkU9ygErUW" to="jaxmpp__n1c9nq0406@localhost/993927746-tigase-241" type="result" xmlns="jabber:client"/> 2019-10-13 20:19:16 \| tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management 2019-10-13 20:19:16 \| jaxmpp_ :: jaxmpp__n1c9nq0406@localhost/993927746-tigase-241 >> <iq to="localhost" id="d1d9DwcwboUYdNWUjGFOJX2" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq> 2019-10-13 20:19:16 \| jaxmpp_ :: jaxmpp__n1c9nq0406@localhost/993927746-tigase-241 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/> 2019-10-13 20:19:16 \| jaxmpp_ :: jaxmpp__n1c9nq0406@localhost/993927746-tigase-241 >> <iq id="o5nzaPIJWZt4hYcoPQR5m3r" type="get"><query xmlns="jabber:iq:roster"/></iq> 2019-10-13 20:19:16 \| jaxmpp_ :: jaxmpp__n1c9nq0406@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 20:19:16 \| tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connected->disconnecting 2019-10-13 20:19:16 \| tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.terminateStream: Terminating XMPP Stream 2019-10-13 20:19:16 \| jaxmpp_ :: jaxmpp__n1c9nq0406@localhost/993927746-tigase-241 << <enabled id="659690cf-8ebc-41f8-895c-77b0a9da9de2" max="60" location="d4270859fb27" xmlns="urn:xmpp:sm:3" resume="true"/> 2019-10-13 20:19:16 \| tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted 2019-10-13 20:19:16 \| tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: disconnecting->disconnected 2019-10-13 20:19:16 \| tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset. 2019-10-13 20:19:16 \| tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session]

tigase.tests.jaxmpp.TestHandlingOfConnectionIssues

testStateAfterAuthTimeoutBosh

20.555s

2019-10-13 20:18:12 |

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

2019-10-13 20:18:12 | ------------------------------------

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

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

2019-10-13 20:18:12 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using BOSHConnector

2019-10-13 20:18:12 | jaxmpp_ :: jaxmpp__jhvpq50401@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"/><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:18:32 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onTerminate: Stream terminated. responseCode=200

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

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

2019-10-13 20:18:32 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using BOSHConnector

2019-10-13 20:18:32 | jaxmpp_ :: jaxmpp__jhvpq50401@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"/><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:18:32 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

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

2019-10-13 20:18:32 | jaxmpp_ :: jaxmpp__jhvpq50401@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX2podnBxNTA0MDEscj1Ta1pBNkxmZm1YWUUyMVJUdUhhZg==</auth>

2019-10-13 20:18:32 | jaxmpp_ :: jaxmpp__jhvpq50401@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1Ta1pBNkxmZm1YWUUyMVJUdUhhZjk5SGdQRTliR0Z0ZktGcnpCbXJ4LHM9Ky9lY3pjb1lPdkJsT3c9PSxpPTQwOTY=</challenge>

2019-10-13 20:18:33 | jaxmpp_ :: jaxmpp__jhvpq50401@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9U2taQTZMZmZtWFlFMjFSVHVIYWY5OUhnUEU5YkdGdGZLRnJ6Qm1yeCxwPTZhcWQxdm0wYXJRei9UZkloMTNOaGM2bnRVRnlIOFRoN1hWZWh0QlBjMEE9</response>

2019-10-13 20:18:33 | jaxmpp_ :: jaxmpp__jhvpq50401@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj02ZHJTVkpSa3VYMUN2OTJWeHJPelFXVVIzdExUdkZnR0ZUVDJXb2hrTHJFPQ==</success>

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

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

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

2019-10-13 20:18:33 | jaxmpp_ :: jaxmpp__jhvpq50401@localhost >> <iq xmlns="jabber:client" id="JalqbCoUXW0aBzu0v4rmP9q" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-10-13 20:18:33 | jaxmpp_ :: jaxmpp__jhvpq50401@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"/><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" node="https://tigase.net/tigase-xmpp-server" xmlns="http://jabber.org/protocol/caps"/></features>

2019-10-13 20:18:33 | jaxmpp_ :: jaxmpp__jhvpq50401@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"/><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" node="https://tigase.net/tigase-xmpp-server" xmlns="http://jabber.org/protocol/caps"/></features>

2019-10-13 20:18:33 | jaxmpp_ :: jaxmpp__jhvpq50401@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"/><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" node="https://tigase.net/tigase-xmpp-server" xmlns="http://jabber.org/protocol/caps"/></features>

2019-10-13 20:18:33 | jaxmpp_ :: jaxmpp__jhvpq50401@localhost >> <iq xmlns="jabber:client" id="oevQIVU7IxzgFKKu1eDDsfP" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-10-13 20:18:33 | jaxmpp_ :: jaxmpp__jhvpq50401@localhost >> <iq xmlns="jabber:client" id="WUvZ2nezDoVgMy9u9Fwn5ue" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-10-13 20:18:33 | jaxmpp_ :: jaxmpp__jhvpq50401@localhost << <iq id="JalqbCoUXW0aBzu0v4rmP9q" to="jaxmpp__jhvpq50401@localhost/993927746-tigase-231" type="result" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__jhvpq50401@localhost/993927746-tigase-231</jid></bind></iq>

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

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

2019-10-13 20:18:33 | jaxmpp_ :: jaxmpp__jhvpq50401@localhost/993927746-tigase-231 << <iq id="oevQIVU7IxzgFKKu1eDDsfP" to="jaxmpp__jhvpq50401@localhost/993927746-tigase-232" type="result" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__jhvpq50401@localhost/993927746-tigase-232</jid></bind></iq>

2019-10-13 20:18:33 | jaxmpp_ :: jaxmpp__jhvpq50401@localhost/993927746-tigase-232 >> <iq id="a61R3q6xkOKDiIArfQIVU7I" type="get"><query xmlns="jabber:iq:roster"/></iq>

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

2019-10-13 20:18:33 | jaxmpp_ :: jaxmpp__jhvpq50401@localhost/993927746-tigase-232 >> <iq to="localhost" id="WXy5eL07JAj2kElSVdCztgM" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-10-13 20:18:33 | jaxmpp_ :: jaxmpp__jhvpq50401@localhost/993927746-tigase-232 << <iq id="WUvZ2nezDoVgMy9u9Fwn5ue" to="jaxmpp__jhvpq50401@localhost/993927746-tigase-233" type="result" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__jhvpq50401@localhost/993927746-tigase-233</jid></bind></iq>

2019-10-13 20:18:33 | jaxmpp_ :: jaxmpp__jhvpq50401@localhost/993927746-tigase-233 >> <iq id="ndireut0j6j7mR8w27q1p0l" type="get"><query xmlns="jabber:iq:roster"/></iq>

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

2019-10-13 20:18:33 | jaxmpp_ :: jaxmpp__jhvpq50401@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 20:18:33 | jaxmpp_ :: jaxmpp__jhvpq50401@localhost/993927746-tigase-233 >> <iq to="localhost" id="794NX6xp8wn0as38oW9FGoh" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-10-13 20:18:33 | tigase.jaxmpp.core.client.xmpp.modules.presence.PresenceModule$3.after: Could not write stanza

2019-10-13 20:18:33 | jaxmpp_ :: jaxmpp__jhvpq50401@localhost/993927746-tigase-233 >> <iq id="Xt0ypiHTUXkUOFwdNMT7ym3" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 20:18:33 | jaxmpp_ :: jaxmpp__jhvpq50401@localhost/993927746-tigase-233 << <iq id="a61R3q6xkOKDiIArfQIVU7I" to="jaxmpp__jhvpq50401@localhost/993927746-tigase-233" type="result" xmlns="jabber:client"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 20:18:33 | jaxmpp_ :: jaxmpp__jhvpq50401@localhost/993927746-tigase-233 << <iq from="localhost" id="cerGCzoW09kMIHLSM3aDKBH" to="jaxmpp__jhvpq50401@localhost/993927746-tigase-233" type="result" xmlns="jabber:client"><query xmlns="http://jabber.org/protocol/disco#info"><identity name="Tigase ver. 8.1.0-SNAPSHOT-b10535/f55efd39" category="component" type="router"/><identity name="Tigase ver. 8.1.0-SNAPSHOT-b10535/f55efd39" category="server" type="im"/><feature var="http://jabber.org/protocol/commands"/><x type="result" xmlns="jabber:x:data"><field var="FORM_TYPE" type="hidden"><value>http://jabber.org/network/serverinfo</value></field><field var="abuse-addresses" type="text-multi"><value>mailto:abuse@localhost</value><value>xmpp:abuse@localhost</value></field></x><feature var="urn:xmpp:carbons:2"/><feature var="http://jabber.org/protocol/stats"/><feature var="vcard-temp"/><feature var="jabber:iq:auth"/><feature var="http://jabber.org/protocol/amp"/><feature var="msgoffline"/><feature var="http://jabber.org/protocol/disco#info"/><feature var="http://jabber.org/protocol/disco#items"/><feature var="urn:xmpp:blocking"/><feature var="urn:xmpp:ping"/><feature var="urn:ietf:params:xml:ns:xmpp-sasl"/><feature var="http://jabber.org/protocol/pubsub"/><feature var="http://jabber.org/protocol/pubsub#owner"/><feature var="http://jabber.org/protocol/pubsub#publish"/><identity category="pubsub" type="pep"/><feature var="urn:xmpp:pep-vcard-conversion:0"/><feature var="urn:xmpp:bookmarks-conversion:0"/><feature var="urn:xmpp:archive:auto"/><feature var="urn:xmpp:archive:manage"/><feature var="urn:xmpp:push:0"/><feature var="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:18:33 | tigase.jaxmpp.core.client.xmpp.modules.presence.PresenceModule$3.after: Could not write stanza

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

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

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

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

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

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

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

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

testStateAfterAuthTimeoutSocket

20.280s

2019-10-13 20:18:33 |

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

2019-10-13 20:18:33 | ------------------------------------

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

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

2019-10-13 20:18:33 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

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

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

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

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

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

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

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

2019-10-13 20:18:33 | jaxmpp_ :: jaxmpp__kxnjbf0402@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"/><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:18:33 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=3347] Start TLS

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

2019-10-13 20:18:33 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=3349] Proceeding TLS

2019-10-13 20:18:33 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=3349] Start handshake

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

2019-10-13 20:18:33 | jaxmpp_ :: jaxmpp__kxnjbf0402@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"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2019-10-13 20:18:53 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=3349] Connector state changed: connected->disconnected

2019-10-13 20:18:53 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=519 thread=3349] Stream terminated

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

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

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

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

2019-10-13 20:18:53 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

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

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

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

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

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

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

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

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@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"/><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:18:53 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=3347] Start TLS

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

2019-10-13 20:18:53 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=3354] Proceeding TLS

2019-10-13 20:18:53 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=3354] Start handshake

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

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@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"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

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

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

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX2t4bmpiZjA0MDIscj15Vm1jdmlSMFBUYXFKUDYwOG1nRg==</auth>

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj15Vm1jdmlSMFBUYXFKUDYwOG1nRlNhcTZSWjdSUFRHSFRQTjRGMldBLHM9OWdqNUxFcUJWQkYvcXc9PSxpPTQwOTY=</challenge>

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9eVZtY3ZpUjBQVGFxSlA2MDhtZ0ZTYXE2Ulo3UlBUR0hUUE40RjJXQSxwPVFLaUJCZnhsdEY3emliTWh3ZUs5c3IxMlV1QUs0NGQvY21CekdzbjlROTg9</response>

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1aOTNEVlhlNWd5QUtsdmVTQSszWGJZWHBjNDNkUnlIcHowMGN3eGNiaStZPQ==</success>

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

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

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

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@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"/><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" node="https://tigase.net/tigase-xmpp-server" xmlns="http://jabber.org/protocol/caps"/></features>

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@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"/><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" node="https://tigase.net/tigase-xmpp-server" xmlns="http://jabber.org/protocol/caps"/></features>

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@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"/><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" node="https://tigase.net/tigase-xmpp-server" xmlns="http://jabber.org/protocol/caps"/></features>

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@localhost >> <iq xmlns="jabber:client" id="JmyPZeCmRKCo3tiCJwlarnS" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@localhost >> <iq xmlns="jabber:client" id="W5HmMRcvv8peIqTY7Bo7zsa" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@localhost >> <iq xmlns="jabber:client" id="Q6I1cFHKwx8zClbu7Ey6fGx" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@localhost << <iq id="JmyPZeCmRKCo3tiCJwlarnS" to="jaxmpp__kxnjbf0402@localhost/993927746-tigase-234" type="result" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__kxnjbf0402@localhost/993927746-tigase-234</jid></bind></iq>

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

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-234 >> <iq xmlns="jabber:client" id="fqE1cwboUYdNWUjGFOJX2dQ" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

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

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

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-235 >> <iq xmlns="jabber:client" id="9tLbHJMOXau6lIygNXgyBgP" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-235 << <iq id="Q6I1cFHKwx8zClbu7Ey6fGx" to="jaxmpp__kxnjbf0402@localhost/993927746-tigase-236" type="result" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__kxnjbf0402@localhost/993927746-tigase-236</jid></bind></iq>

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-235 << <iq id="fqE1cwboUYdNWUjGFOJX2dQ" to="jaxmpp__kxnjbf0402@localhost/993927746-tigase-236" type="result" xmlns="jabber:client"/>

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

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-236 >> <iq xmlns="jabber:client" id="7jf8DsfPYcJIAiJu6mZl26H" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

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

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-236 >> <iq to="localhost" id="NiaVZ08q7By8LAtqXpW1sak" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-236 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/>

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-236 << <iq id="9tLbHJMOXau6lIygNXgyBgP" to="jaxmpp__kxnjbf0402@localhost/993927746-tigase-236" type="result" xmlns="jabber:client"/>

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-236 >> <iq id="FwOhT7ym3mSSTOKEzvmKZ2n" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-236 << <enabled id="f0560e46-a0f2-477f-a10e-36c47d1223e3" max="60" location="d4270859fb27" xmlns="urn:xmpp:sm:3" resume="true"/>

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@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 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-236 << <iq id="7jf8DsfPYcJIAiJu6mZl26H" to="jaxmpp__kxnjbf0402@localhost/993927746-tigase-236" type="result" xmlns="jabber:client"/>

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-236 >> <iq to="localhost" id="seUAEpjKDGCevczvcJNU4tc" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-236 << <iq from="localhost" id="NiaVZ08q7By8LAtqXpW1sak" to="jaxmpp__kxnjbf0402@localhost/993927746-tigase-236" type="result" xmlns="jabber:client"><query xmlns="http://jabber.org/protocol/disco#info"><identity name="Tigase ver. 8.1.0-SNAPSHOT-b10535/f55efd39" category="component" type="router"/><identity name="Tigase ver. 8.1.0-SNAPSHOT-b10535/f55efd39" category="server" type="im"/><feature var="http://jabber.org/protocol/commands"/><x type="result" xmlns="jabber:x:data"><field var="FORM_TYPE" type="hidden"><value>http://jabber.org/network/serverinfo</value></field><field var="abuse-addresses" type="text-multi"><value>mailto:abuse@localhost</value><value>xmpp:abuse@localhost</value></field></x><feature var="urn:xmpp:carbons:2"/><feature var="http://jabber.org/protocol/stats"/><feature var="vcard-temp"/><feature var="jabber:iq:auth"/><feature var="http://jabber.org/protocol/amp"/><feature var="msgoffline"/><feature var="http://jabber.org/protocol/disco#info"/><feature var="http://jabber.org/protocol/disco#items"/><feature var="urn:xmpp:blocking"/><feature var="urn:xmpp:ping"/><feature var="urn:ietf:params:xml:ns:xmpp-sasl"/><feature var="http://jabber.org/protocol/pubsub"/><feature var="http://jabber.org/protocol/pubsub#owner"/><feature var="http://jabber.org/protocol/pubsub#publish"/><identity category="pubsub" type="pep"/><feature var="urn:xmpp:pep-vcard-conversion:0"/><feature var="urn:xmpp:bookmarks-conversion:0"/><feature var="urn:xmpp:archive:auto"/><feature var="urn:xmpp:archive:manage"/><feature var="urn:xmpp:push:0"/><feature var="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:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-236 >> <iq to="localhost" id="Oj7QIygNXgyBgP8nfCnaAan" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-236 >> <iq id="MswFs38oW9FGohCxydVY5Aq" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-236 >> <iq id="ymchOChKFHAvl0gRY6kNCmS" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@localhost/993927746-tigase-236 << <iq id="FwOhT7ym3mSSTOKEzvmKZ2n" to="jaxmpp__kxnjbf0402@localhost/993927746-tigase-236" type="result" xmlns="jabber:client"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@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 20:18:53 | jaxmpp_ :: jaxmpp__kxnjbf0402@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 20:18:53 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=1] Connector state changed: connected->disconnecting

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

2019-10-13 20:18:53 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=3354] Connector state changed: disconnecting->disconnected

2019-10-13 20:18:53 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=520 thread=3354] Stream terminated

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

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

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

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

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

testStateAfterAuthTimeoutWebSocket

20.379s

2019-10-13 20:18:54 |

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

2019-10-13 20:18:54 | ------------------------------------

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

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

2019-10-13 20:18:54 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using WebSocketConnector

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

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

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

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

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

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

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

2019-10-13 20:18:54 | jaxmpp_ :: jaxmpp__a8bvsy0403@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"/><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:19:14 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connected->disconnecting

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

2019-10-13 20:19:14 | jaxmpp_ :: jaxmpp__a8bvsy0403@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1HYTJHYkp3SzlBTExlZEI1V0FhQ3VkV3NwZ3ZWM05DSjFWRHR4N2czLHM9QnhYa0tUQ1RmejZpblE9PSxpPTQwOTY=</challenge>

2019-10-13 20:19:14 | jaxmpp_ :: jaxmpp__a8bvsy0403@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9R2EyR2JKd0s5QUxMZWRCNVdBYUN1ZFdzcGd2VjNOQ0oxVkR0eDdnMyxwPUk4cFNhSXJlUGxIbU13Sy9QamV6NWw1U1JvSUJZY0FIMU5MeHNRYmVzVGM9</response>

2019-10-13 20:19:14 | jaxmpp_ :: jaxmpp__a8bvsy0403@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1BVmJFWlZZT1ExVVQxcVgzVWVqZ05teHlBUkc1YnlYbk4xMnU2UUx5UVdRPQ==</success>

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

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

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

2019-10-13 20:19:14 | jaxmpp_ :: jaxmpp__a8bvsy0403@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"/><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" node="https://tigase.net/tigase-xmpp-server" xmlns="http://jabber.org/protocol/caps"/></features>

2019-10-13 20:19:14 | jaxmpp_ :: jaxmpp__a8bvsy0403@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"/><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" node="https://tigase.net/tigase-xmpp-server" xmlns="http://jabber.org/protocol/caps"/></features>

2019-10-13 20:19:14 | jaxmpp_ :: jaxmpp__a8bvsy0403@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"/><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" node="https://tigase.net/tigase-xmpp-server" xmlns="http://jabber.org/protocol/caps"/></features>

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

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

2019-10-13 20:19:14 | jaxmpp_ :: jaxmpp__a8bvsy0403@localhost >> <iq xmlns="jabber:client" id="6m0FvnWdLQWdGwatY4iR5w4" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

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

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

2019-10-13 20:19:14 | jaxmpp_ :: jaxmpp__a8bvsy0403@localhost << <iq id="6m0FvnWdLQWdGwatY4iR5w4" to="jaxmpp__a8bvsy0403@localhost/993927746-tigase-239" type="result" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__a8bvsy0403@localhost/993927746-tigase-239</jid></bind></iq>

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

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

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

2019-10-13 20:19:14 | jaxmpp_ :: jaxmpp__a8bvsy0403@localhost/993927746-tigase-239 >> <iq xmlns="jabber:client" id="0PnlP4oMBoXhKPZiQ1iKCnM" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

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

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

2019-10-13 20:19:14 | jaxmpp_ :: jaxmpp__a8bvsy0403@localhost/993927746-tigase-239 << <iq id="0PnlP4oMBoXhKPZiQ1iKCnM" to="jaxmpp__a8bvsy0403@localhost/993927746-tigase-239" type="result" xmlns="jabber:client"/>

2019-10-13 20:19:14 | jaxmpp_ :: jaxmpp__a8bvsy0403@localhost/993927746-tigase-239 << <iq id="qnZWWbQN5iJS003iLTYhT6s" to="jaxmpp__a8bvsy0403@localhost/993927746-tigase-239" type="result" xmlns="jabber:client"/>

2019-10-13 20:19:14 | jaxmpp_ :: jaxmpp__a8bvsy0403@localhost/993927746-tigase-239 << <iq id="GyuMT6sfKEqZ08q7By8LAtq" to="jaxmpp__a8bvsy0403@localhost/993927746-tigase-239" type="result" xmlns="jabber:client"/>

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

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

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

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

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

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

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

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

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

2019-10-13 20:19:14 | jaxmpp_ :: jaxmpp__a8bvsy0403@localhost/993927746-tigase-239 >> <iq id="VM2zDkXoThGvq6cr4jZaFFE" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 20:19:14 | jaxmpp_ :: jaxmpp__a8bvsy0403@localhost/993927746-tigase-239 >> <iq id="qt58kXoThGvq6cr4jZaFFEy" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 20:19:14 | jaxmpp_ :: jaxmpp__a8bvsy0403@localhost/993927746-tigase-239 >> <iq id="bN1Q0gRY6kNCmS1pamduh2b" type="get"><query xmlns="jabber:iq:roster"/></iq>

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

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

2019-10-13 20:19:14 | jaxmpp_ :: jaxmpp__a8bvsy0403@localhost/993927746-tigase-239 << <enabled id="cb8b4e5d-1a6a-4582-a643-8bd4f8c1ed1f" max="60" location="d4270859fb27" xmlns="urn:xmpp:sm:3" resume="true"/>

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

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

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

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

testStateAfterConnectionFailureBosh

0.759s

2019-10-13 20:19:14 |

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

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

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

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

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

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

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

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

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

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

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

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

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

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

2019-10-13 20:19:15 | jaxmpp_ :: jaxmpp__luaerh0404@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1PVEt1SzlxTGlINzVybzJzdTdEbENFZzBHOXc4Y0ZXM3BLMFlDNHpELHM9bmgvaHpiTnNzOVRFckE9PSxpPTQwOTY=</challenge>

2019-10-13 20:19:15 | jaxmpp_ :: jaxmpp__luaerh0404@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9T1RLdUs5cUxpSDc1cm8yc3U3RGxDRWcwRzl3OGNGVzNwSzBZQzR6RCxwPXBidTlxcXpOSWs4eWMvWExwU1hKcFRpVzcvbDFXR1ZjajNwRWNOYS85Tmc9</response>

2019-10-13 20:19:15 | jaxmpp_ :: jaxmpp__luaerh0404@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj13R0NtZTJUYmQ5Q3hHbys4c0ZHby9uUmpWQnV0UWRGaitiQU5jV1hzUjk0PQ==</success>

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

2019-10-13 20:19:15 | jaxmpp_ :: jaxmpp__luaerh0404@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"/><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" node="https://tigase.net/tigase-xmpp-server" xmlns="http://jabber.org/protocol/caps"/></features>

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

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

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

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

2019-10-13 20:19:15 | jaxmpp_ :: jaxmpp__luaerh0404@localhost/993927746-tigase-240 >> <iq id="TPVGIspS3Ah3eBCuYZavnWd" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-10-13 20:19:15 | jaxmpp_ :: jaxmpp__luaerh0404@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:19:15 | jaxmpp_ :: jaxmpp__luaerh0404@localhost/993927746-tigase-240 << <iq from="localhost" id="IS6ZeNQQOLyeCvn6eXYfY3B" to="jaxmpp__luaerh0404@localhost/993927746-tigase-240" type="result" xmlns="jabber:client"><query xmlns="http://jabber.org/protocol/disco#info"><identity name="Tigase ver. 8.1.0-SNAPSHOT-b10535/f55efd39" category="component" type="router"/><identity name="Tigase ver. 8.1.0-SNAPSHOT-b10535/f55efd39" category="server" type="im"/><feature var="http://jabber.org/protocol/commands"/><x type="result" xmlns="jabber:x:data"><field var="FORM_TYPE" type="hidden"><value>http://jabber.org/network/serverinfo</value></field><field var="abuse-addresses" type="text-multi"><value>mailto:abuse@localhost</value><value>xmpp:abuse@localhost</value></field></x><feature var="urn:xmpp:carbons:2"/><feature var="http://jabber.org/protocol/stats"/><feature var="vcard-temp"/><feature var="jabber:iq:auth"/><feature var="http://jabber.org/protocol/amp"/><feature var="msgoffline"/><feature var="http://jabber.org/protocol/disco#info"/><feature var="http://jabber.org/protocol/disco#items"/><feature var="urn:xmpp:blocking"/><feature var="urn:xmpp:ping"/><feature var="urn:ietf:params:xml:ns:xmpp-sasl"/><feature var="http://jabber.org/protocol/pubsub"/><feature var="http://jabber.org/protocol/pubsub#owner"/><feature var="http://jabber.org/protocol/pubsub#publish"/><identity category="pubsub" type="pep"/><feature var="urn:xmpp:pep-vcard-conversion:0"/><feature var="urn:xmpp:bookmarks-conversion:0"/><feature var="urn:xmpp:archive:auto"/><feature var="urn:xmpp:archive:manage"/><feature var="urn:xmpp:push:0"/><feature var="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:19:15 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onTerminate: Stream terminated. responseCode=200

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

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

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

testStateAfterConnectionFailureWebSocket

0.369s

2019-10-13 20:19:16 |

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

2019-10-13 20:19:16 | jaxmpp_ :: jaxmpp__n1c9nq0406@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1tazdZSDR3dlZQN1N3WE9RN25IWHpQSDF4ZlNWVGJkVlRLSjQxRzhXLHM9Umh1U1pHdTlITnV4S2c9PSxpPTQwOTY=</challenge>

2019-10-13 20:19:16 | jaxmpp_ :: jaxmpp__n1c9nq0406@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9bWs3WUg0d3ZWUDdTd1hPUTduSFh6UEgxeGZTVlRiZFZUS0o0MUc4VyxwPStFMngzM1lDMEZqaW9NaUdMMWhRVjVEenpTVmVGS3FhOUltQ3JZQXh4MVE9</response>

2019-10-13 20:19:16 | jaxmpp_ :: jaxmpp__n1c9nq0406@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1zbExTaFRtUmNKeUdjOHIzQVJIOWM0ZllmOWN5alRyQmhsUk16NVZBRERzPQ==</success>

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

2019-10-13 20:19:16 | jaxmpp_ :: jaxmpp__n1c9nq0406@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"/><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" node="https://tigase.net/tigase-xmpp-server" xmlns="http://jabber.org/protocol/caps"/></features>

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

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

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

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

2019-10-13 20:19:16 | jaxmpp_ :: jaxmpp__n1c9nq0406@localhost/993927746-tigase-241 << <iq id="xOCQ6sURUZlS5vkU9ygErUW" to="jaxmpp__n1c9nq0406@localhost/993927746-tigase-241" type="result" xmlns="jabber:client"/>

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

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

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

2019-10-13 20:19:16 | jaxmpp_ :: jaxmpp__n1c9nq0406@localhost/993927746-tigase-241 >> <iq id="o5nzaPIJWZt4hYcoPQR5m3r" type="get"><query xmlns="jabber:iq:roster"/></iq>

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

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

2019-10-13 20:19:16 | jaxmpp_ :: jaxmpp__n1c9nq0406@localhost/993927746-tigase-241 << <enabled id="659690cf-8ebc-41f8-895c-77b0a9da9de2" max="60" location="d4270859fb27" xmlns="urn:xmpp:sm:3" resume="true"/>

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

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

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

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