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

Failed Configuration
tigase.tests.jaxmpp.TestHandlingOfConnectionIssues
setupSuite	0.202s	Method arguments: org.testng.TestRunner@9d3d54e 2022-07-22 22:51:26 \| tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream] 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=467 thread=1] Connector state changed: null->connecting 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=467 thread=1] DNS entry stored in session object: localhost:5222 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=467 thread=1] Preparing connection to [localhost:5222] 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=467 thread=1] Opening connection to localhost/127.0.0.1:5222 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=467 thread=1] Connector state changed: connecting->connected 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=467 thread=1] Whitespace ping period is setted to nullms 2022-07-22 22:51:26 \| tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=467 thread=2948] Start TLS 2022-07-22 22:51:26 \| >> <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> 2022-07-22 22:51:26 \| admin :: admin@test-domain.com << <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> 2022-07-22 22:51:26 \| << <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/> 2022-07-22 22:51:26 \| admin :: admin@test-domain.com >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/> 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=467 thread=2950] Proceeding TLS 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=467 thread=2950] Start handshake 2022-07-22 22:51:26 \| tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled 2022-07-22 22:51:26 \| >> <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-512</mechanism><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> 2022-07-22 22:51:26 \| admin :: admin@test-domain.com << <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-512</mechanism><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> 2022-07-22 22:51:26 \| tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.isAuthAvailable: saslSupportedtrue, nonSaslSupported: true 2022-07-22 22:51:26 \| tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL 2022-07-22 22:51:26 \| tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL 2022-07-22 22:51:26 \| << <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1hZG1pbixyPWZTWm4zV0RoOXFsb3psdm5wekM3</auth> 2022-07-22 22:51:26 \| admin :: admin@test-domain.com >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1hZG1pbixyPWZTWm4zV0RoOXFsb3psdm5wekM3</auth> 2022-07-22 22:51:26 \| >> <failure xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><not-authorized/></failure> 2022-07-22 22:51:26 \| admin :: admin@test-domain.com << <failure xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><not-authorized/></failure> 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.Jaxmpp.onException: Catching exception 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=467 thread=2948] Connector state changed: connected->disconnecting 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=467 thread=2948] Terminating XMPP Stream 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=467 thread=2950] Connector state changed: disconnecting->disconnected 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=467 thread=2950] Stream terminated 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted 2022-07-22 22:51:26 \| Could not connect with admin account credentials (tigase.jaxmpp.core.client.exceptions.JaxmppException: Unauthorized with condition=not_authorized), trying to register account... 2022-07-22 22:51:26 \| tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream] 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=468 thread=1] Using XEP-0077 mode!!!! 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=468 thread=1] Connector state changed: null->connecting 2022-07-22 22:51:26 \| tigase.jaxmpp.core.client.SessionObject$ClearedHandler$ClearedEvent@37a8d7d1 2022-07-22 22:51:26 \| StateChangedEvent{oldState=null, newState=connecting} 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=468 thread=1] DNS entry stored in session object: localhost:5222 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=468 thread=1] Preparing connection to [localhost:5222] 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=468 thread=1] Opening connection to localhost/127.0.0.1:5222 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=468 thread=1] Connector state changed: connecting->connected 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=468 thread=1] Whitespace ping period is setted to nullms 2022-07-22 22:51:26 \| [Mutex] waiting for: [registration] 2022-07-22 22:51:26 \| tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled 2022-07-22 22:51:26 \| tigase.jaxmpp.core.client.Connector$StreamRestartedHandler$StreamRestaredEvent@396f2f54 2022-07-22 22:51:26 \| StateChangedEvent{oldState=connecting, newState=connected} 2022-07-22 22:51:26 \| tigase.jaxmpp.core.client.Connector$ConnectedHandler$ConnectedEvent@3d50bca1 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=468 thread=2955] Start TLS 2022-07-22 22:51:26 \| StreamFeaturesReceivedEvent[<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>] 2022-07-22 22:51:26 \| admin :: null << <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> 2022-07-22 22:51:26 \| StanzaReceivedEvent{stanza=<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>} 2022-07-22 22:51:26 \| admin :: null >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/> 2022-07-22 22:51:26 \| StanzaSendingEvent{stanza=<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>} 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=468 thread=2957] Proceeding TLS 2022-07-22 22:51:26 \| tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=468 thread=2957] Start handshake 2022-07-22 22:51:26 \| tigase.jaxmpp.core.client.Connector$EncryptionEstablishedHandler$EncryptionEstablishedEvent@7852256f 2022-07-22 22:51:26 \| tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled 2022-07-22 22:51:26 \| tigase.jaxmpp.core.client.Connector$StreamRestartedHandler$StreamRestaredEvent@93573eb 2022-07-22 22:51:26 \| admin :: null << <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-512</mechanism><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> 2022-07-22 22:51:26 \| StanzaReceivedEvent{stanza=<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-512</mechanism><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>} 2022-07-22 22:51:26 \| StreamFeaturesReceivedEvent[<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-512</mechanism><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>] 2022-07-22 22:51:26 \| admin :: null >> <iq to="test-domain.com" id="GOjgHFyazgIureWlQW1uav4" type="get"><query xmlns="jabber:iq:register"/></iq> 2022-07-22 22:51:26 \| StanzaSendingEvent{stanza=<iq to="test-domain.com" id="GOjgHFyazgIureWlQW1uav4" type="get"><query xmlns="jabber:iq:register"/></iq>} 2022-07-22 22:51:26 \| admin :: null << <iq from="test-domain.com" xmlns="jabber:client" id="GOjgHFyazgIureWlQW1uav4" type="result"><query xmlns="jabber:iq:register"><instructions>Please provide the following information to sign up for an account Please also provide your e-mail address (must be valid!) to which we will send confirmation link.</instructions><x xmlns="jabber:x:data" type="form"><title>Account Registration</title><instructions>Please provide the following information to sign up for an account Please also provide your e-mail address (must be valid!) to which we will send confirmation link.</instructions><field type="hidden" var="FORM_TYPE"><value>jabber:iq:register</value></field><field label="Username" type="text-single" var="username"><required/><value/></field><field label="Password" type="text-private" var="password"><required/><value/></field><field label="Email (MUST BE VALID!)" type="text-single" var="email"><required/><value/></field></x></query></iq> 2022-07-22 22:51:26 \| StanzaReceivedEvent{stanza=<iq from="test-domain.com" xmlns="jabber:client" id="GOjgHFyazgIureWlQW1uav4" type="result"><query xmlns="jabber:iq:register"><instructions>Please provide the following information to sign up for an account Please also provide your e-mail address (must be valid!) to which we will send confirmation link.</instructions><x xmlns="jabber:x:data" type="form"><title>Account Registration</title><instructions>Please provide the following information to sign up for an account Please also provide your e-mail address (must be valid!) to which we will send confirmation link.</instructions><field type="hidden" var="FORM_TYPE"><value>jabber:iq:register</value></field><field label="Username" type="text-single" var="username"><required/><value/></field><field label="Password" type="text-private" var="password"><required/><value/></field><field label="Email (MUST BE VALID!)" type="text-single" var="email"><required/><value/></field></x></query></iq>} 2022-07-22 22:51:26 \| tigase.jaxmpp.core.client.xmpp.modules.registration.InBandRegistrationModule$ReceivedRequestedFieldsHandler$ReceivedRequestedFieldsEvent@49e0f816 2022-07-22 22:51:26 \| admin :: null >> <iq to="test-domain.com" id="uRqMZ27JxhGR2nMCp5oQVY8" type="set"><query xmlns="jabber:iq:register"><username>admin</username><password>admin</password><email>576e1d5f-b9c2-4ce8-ab9e-c9169e5dac5e@localhost</email></query></iq> 2022-07-22 22:51:26 \| StanzaSendingEvent{stanza=<iq to="test-domain.com" id="uRqMZ27JxhGR2nMCp5oQVY8" type="set"><query xmlns="jabber:iq:register"><username>admin</username><password>admin</password><email>576e1d5f-b9c2-4ce8-ab9e-c9169e5dac5e@localhost</email></query></iq>} 2022-07-22 22:51:26 \| admin :: null << <iq from="test-domain.com" xmlns="jabber:client" id="uRqMZ27JxhGR2nMCp5oQVY8" type="error"><query xmlns="jabber:iq:register"><username>admin</username><password>admin</password><email>576e1d5f-b9c2-4ce8-ab9e-c9169e5dac5e@localhost</email></query><error code="500" type="wait"><internal-server-error xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/><text xml:lang="en" xmlns="urn:ietf:params:xml:ns:xmpp-stanzas">Database access problem, please contact administrator.</text></error></iq> 2022-07-22 22:51:26 \| StanzaReceivedEvent{stanza=<iq from="test-domain.com" xmlns="jabber:client" id="uRqMZ27JxhGR2nMCp5oQVY8" type="error"><query xmlns="jabber:iq:register"><username>admin</username><password>admin</password><email>576e1d5f-b9c2-4ce8-ab9e-c9169e5dac5e@localhost</email></query><error code="500" type="wait"><internal-server-error xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/><text xml:lang="en" xmlns="urn:ietf:params:xml:ns:xmpp-stanzas">Database access problem, please contact administrator.</text></error></iq>} 2022-07-22 22:51:26 \| [Mutex] received everything. 2022-07-22 22:51:26 \| [Mutex] isItemNotified: registrationSuccess :: false java.lang.AssertionError: Registration failed! org.testng.AssertJUnit.fail(AssertJUnit.java:65) org.testng.AssertJUnit.assertTrue(AssertJUnit.java:23) tigase.tests.utils.AccountsManager.registerAccount(AccountsManager.java:195) tigase.tests.utils.AccountBuilder.build(AccountBuilder.java:123) tigase.tests.AbstractTest.ensureAdminAccountExists(AbstractTest.java:474) tigase.tests.AbstractTest.setupSuite(AbstractTest.java:779) java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) java.base/java.lang.reflect.Method.invoke(Method.java:568) org.testng.internal.invokers.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:135) org.testng.internal.invokers.MethodInvocationHelper.invokeMethodConsideringTimeout(MethodInvocationHelper.java:65) org.testng.internal.invokers.ConfigInvoker.invokeConfigurationMethod(ConfigInvoker.java:381) org.testng.internal.invokers.ConfigInvoker.invokeConfigurations(ConfigInvoker.java:319) org.testng.SuiteRunner.privateRun(SuiteRunner.java:368) org.testng.SuiteRunner.run(SuiteRunner.java:326) org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52) org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:95) org.testng.TestNG.runSuitesSequentially(TestNG.java:1249) org.testng.TestNG.runSuitesLocally(TestNG.java:1169) org.testng.TestNG.runSuites(TestNG.java:1092) org.testng.TestNG.run(TestNG.java:1060) 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)

Skipped Configuration
tigase.tests.jaxmpp.TestHandlingOfConnectionIssues
setUp	0.000s
setUp	0.000s
setUp	0.000s
setUp	0.000s
setUp	0.000s
setUp	0.000s
setupClass	0.000s
setupMethod	0.000s
setupMethod	0.000s
setupMethod	0.000s
setupMethod	0.000s
setupMethod	0.000s
setupMethod	0.000s
tearDownClass	0.000s
tearDownMethod	0.000s
tearDownMethod	0.000s
tearDownMethod	0.000s
tearDownMethod	0.000s
tearDownMethod	0.000s
tearDownMethod	0.000s
tearDownSuite	0.000s

2022-07-22 22:51:26 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=467 thread=1] Connector state changed: null->connecting

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=467 thread=1] DNS entry stored in session object: localhost:5222

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=467 thread=1] Preparing connection to [localhost:5222]

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=467 thread=1] Opening connection to localhost/127.0.0.1:5222

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=467 thread=1] Connector state changed: connecting->connected

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=467 thread=1] Whitespace ping period is setted to nullms

2022-07-22 22:51:26 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=467 thread=2948] Start TLS

2022-07-22 22:51:26 | >> <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>

2022-07-22 22:51:26 | admin :: admin@test-domain.com << <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>

2022-07-22 22:51:26 | << <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

2022-07-22 22:51:26 | admin :: admin@test-domain.com >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=467 thread=2950] Proceeding TLS

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=467 thread=2950] Start handshake

2022-07-22 22:51:26 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2022-07-22 22:51:26 | >> <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-512</mechanism><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>

2022-07-22 22:51:26 | admin :: admin@test-domain.com << <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-512</mechanism><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>

2022-07-22 22:51:26 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.isAuthAvailable: saslSupportedtrue, nonSaslSupported: true

2022-07-22 22:51:26 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2022-07-22 22:51:26 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2022-07-22 22:51:26 | << <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1hZG1pbixyPWZTWm4zV0RoOXFsb3psdm5wekM3</auth>

2022-07-22 22:51:26 | admin :: admin@test-domain.com >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1hZG1pbixyPWZTWm4zV0RoOXFsb3psdm5wekM3</auth>

2022-07-22 22:51:26 | >> <failure xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><not-authorized/></failure>

2022-07-22 22:51:26 | admin :: admin@test-domain.com << <failure xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><not-authorized/></failure>

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.Jaxmpp.onException: Catching exception

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=467 thread=2948] Connector state changed: connected->disconnecting

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=467 thread=2948] Terminating XMPP Stream

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=467 thread=2950] Connector state changed: disconnecting->disconnected

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=467 thread=2950] Stream terminated

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2022-07-22 22:51:26 | Could not connect with admin account credentials (tigase.jaxmpp.core.client.exceptions.JaxmppException: Unauthorized with condition=not_authorized), trying to register account...

2022-07-22 22:51:26 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=468 thread=1] Using XEP-0077 mode!!!!

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=468 thread=1] Connector state changed: null->connecting

2022-07-22 22:51:26 | tigase.jaxmpp.core.client.SessionObject$ClearedHandler$ClearedEvent@37a8d7d1

2022-07-22 22:51:26 | StateChangedEvent{oldState=null, newState=connecting}

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=468 thread=1] DNS entry stored in session object: localhost:5222

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=468 thread=1] Preparing connection to [localhost:5222]

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=468 thread=1] Opening connection to localhost/127.0.0.1:5222

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=468 thread=1] Connector state changed: connecting->connected

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=468 thread=1] Whitespace ping period is setted to nullms

2022-07-22 22:51:26 | [Mutex] waiting for: [registration]

2022-07-22 22:51:26 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2022-07-22 22:51:26 | tigase.jaxmpp.core.client.Connector$StreamRestartedHandler$StreamRestaredEvent@396f2f54

2022-07-22 22:51:26 | StateChangedEvent{oldState=connecting, newState=connected}

2022-07-22 22:51:26 | tigase.jaxmpp.core.client.Connector$ConnectedHandler$ConnectedEvent@3d50bca1

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=468 thread=2955] Start TLS

2022-07-22 22:51:26 | StreamFeaturesReceivedEvent[<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>]

2022-07-22 22:51:26 | admin :: null << <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>

2022-07-22 22:51:26 | StanzaReceivedEvent{stanza=<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>}

2022-07-22 22:51:26 | admin :: null >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

2022-07-22 22:51:26 | StanzaSendingEvent{stanza=<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>}

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=468 thread=2957] Proceeding TLS

2022-07-22 22:51:26 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=468 thread=2957] Start handshake

2022-07-22 22:51:26 | tigase.jaxmpp.core.client.Connector$EncryptionEstablishedHandler$EncryptionEstablishedEvent@7852256f

2022-07-22 22:51:26 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2022-07-22 22:51:26 | tigase.jaxmpp.core.client.Connector$StreamRestartedHandler$StreamRestaredEvent@93573eb

2022-07-22 22:51:26 | admin :: null << <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-512</mechanism><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>

2022-07-22 22:51:26 | StanzaReceivedEvent{stanza=<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-512</mechanism><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>}

2022-07-22 22:51:26 | StreamFeaturesReceivedEvent[<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-512</mechanism><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>]

2022-07-22 22:51:26 | admin :: null >> <iq to="test-domain.com" id="GOjgHFyazgIureWlQW1uav4" type="get"><query xmlns="jabber:iq:register"/></iq>

2022-07-22 22:51:26 | StanzaSendingEvent{stanza=<iq to="test-domain.com" id="GOjgHFyazgIureWlQW1uav4" type="get"><query xmlns="jabber:iq:register"/></iq>}

2022-07-22 22:51:26 | admin :: null << <iq from="test-domain.com" xmlns="jabber:client" id="GOjgHFyazgIureWlQW1uav4" type="result"><query xmlns="jabber:iq:register"><instructions>Please provide the following information to sign up for an account

Please also provide your e-mail address (must be valid!) to which we will send confirmation link.</instructions><x xmlns="jabber:x:data" type="form"><title>Account Registration</title><instructions>Please provide the following information to sign up for an account

Please also provide your e-mail address (must be valid!) to which we will send confirmation link.</instructions><field type="hidden" var="FORM_TYPE"><value>jabber:iq:register</value></field><field label="Username" type="text-single" var="username"><required/><value/></field><field label="Password" type="text-private" var="password"><required/><value/></field><field label="Email (MUST BE VALID!)" type="text-single" var="email"><required/><value/></field></x></query></iq>

2022-07-22 22:51:26 | StanzaReceivedEvent{stanza=<iq from="test-domain.com" xmlns="jabber:client" id="GOjgHFyazgIureWlQW1uav4" type="result"><query xmlns="jabber:iq:register"><instructions>Please provide the following information to sign up for an account

Please also provide your e-mail address (must be valid!) to which we will send confirmation link.</instructions><x xmlns="jabber:x:data" type="form"><title>Account Registration</title><instructions>Please provide the following information to sign up for an account

Please also provide your e-mail address (must be valid!) to which we will send confirmation link.</instructions><field type="hidden" var="FORM_TYPE"><value>jabber:iq:register</value></field><field label="Username" type="text-single" var="username"><required/><value/></field><field label="Password" type="text-private" var="password"><required/><value/></field><field label="Email (MUST BE VALID!)" type="text-single" var="email"><required/><value/></field></x></query></iq>}

2022-07-22 22:51:26 | tigase.jaxmpp.core.client.xmpp.modules.registration.InBandRegistrationModule$ReceivedRequestedFieldsHandler$ReceivedRequestedFieldsEvent@49e0f816

2022-07-22 22:51:26 | admin :: null >> <iq to="test-domain.com" id="uRqMZ27JxhGR2nMCp5oQVY8" type="set"><query xmlns="jabber:iq:register"><username>admin</username><password>admin</password><email>576e1d5f-b9c2-4ce8-ab9e-c9169e5dac5e@localhost</email></query></iq>

2022-07-22 22:51:26 | StanzaSendingEvent{stanza=<iq to="test-domain.com" id="uRqMZ27JxhGR2nMCp5oQVY8" type="set"><query xmlns="jabber:iq:register"><username>admin</username><password>admin</password><email>576e1d5f-b9c2-4ce8-ab9e-c9169e5dac5e@localhost</email></query></iq>}

2022-07-22 22:51:26 | admin :: null << <iq from="test-domain.com" xmlns="jabber:client" id="uRqMZ27JxhGR2nMCp5oQVY8" type="error"><query xmlns="jabber:iq:register"><username>admin</username><password>admin</password><email>576e1d5f-b9c2-4ce8-ab9e-c9169e5dac5e@localhost</email></query><error code="500" type="wait"><internal-server-error xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/><text xml:lang="en" xmlns="urn:ietf:params:xml:ns:xmpp-stanzas">Database access problem, please contact administrator.</text></error></iq>

2022-07-22 22:51:26 | StanzaReceivedEvent{stanza=<iq from="test-domain.com" xmlns="jabber:client" id="uRqMZ27JxhGR2nMCp5oQVY8" type="error"><query xmlns="jabber:iq:register"><username>admin</username><password>admin</password><email>576e1d5f-b9c2-4ce8-ab9e-c9169e5dac5e@localhost</email></query><error code="500" type="wait"><internal-server-error xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/><text xml:lang="en" xmlns="urn:ietf:params:xml:ns:xmpp-stanzas">Database access problem, please contact administrator.</text></error></iq>}

2022-07-22 22:51:26 | [Mutex] received everything.

2022-07-22 22:51:26 | [Mutex] isItemNotified: registrationSuccess :: false

Skipped Tests
tigase.tests.jaxmpp.TestHandlingOfConnectionIssues
testStateAfterAuthTimeoutBosh	0.000s	2022-07-22 22:51:26 \| 2022-07-22 22:51:26 \| null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues] 2022-07-22 22:51:26 \| ------------------------------------
testStateAfterAuthTimeoutSocket	0.000s	2022-07-22 22:51:26 \| 2022-07-22 22:51:26 \| null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues] 2022-07-22 22:51:26 \| ------------------------------------
testStateAfterAuthTimeoutWebSocket	0.000s	2022-07-22 22:51:26 \| 2022-07-22 22:51:26 \| null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues] 2022-07-22 22:51:26 \| ------------------------------------
testStateAfterConnectionFailureBosh	0.000s	2022-07-22 22:51:26 \| 2022-07-22 22:51:26 \| null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues] 2022-07-22 22:51:26 \| ------------------------------------
testStateAfterConnectionFailureSocket	0.000s	2022-07-22 22:51:26 \| 2022-07-22 22:51:26 \| null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues] 2022-07-22 22:51:26 \| ------------------------------------
testStateAfterConnectionFailureWebSocket	0.000s

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