Generated by TestNG with ReportNG at 10:57 PDT on Friday 15 April 2022
root@1bc69cf4cb94 / Java 17.0.2 (Private Build) / Linux 4.14.186-146.268.amzn2.x86_64 (amd64)

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

Suites · Log Output

Test duration : 110.071s

Failed Configuration
tigase.tests.jaxmpp.TestHandlingOfConnectionIssues
setupSuite 110.071s Method arguments: org.testng.TestRunner@16423501
2022-04-15 11:10:03 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2022-04-15 11:10:03 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2022-04-15 11:10:03 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

2022-04-15 11:10:03 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=15 thread=1] Connector  state changed: null->connecting

2022-04-15 11:10:03 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=15 thread=1] DNS entry stored in session object: localhost:5222

2022-04-15 11:10:03 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=15 thread=1] Preparing connection to [localhost:5222]

2022-04-15 11:10:03 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=15 thread=1] Opening connection to localhost/127.0.0.1:5222

2022-04-15 11:10:03 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=15 thread=1] Connector  state changed: connecting->connected

2022-04-15 11:10:03 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=15 thread=1] Whitespace ping period is setted to nullms

2022-04-15 11:10:03 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2022-04-15 11:10:03 |  >> <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/><register xmlns="http://jabber.org/features/iq-register"/><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"><required/></starttls><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2022-04-15 11:10:03 | admin :: admin@test-domain.com << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/><register xmlns="http://jabber.org/features/iq-register"/><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"><required/></starttls><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2022-04-15 11:10:03 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=15 thread=96] Start TLS

2022-04-15 11:10:03 |  << <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

2022-04-15 11:10:03 | admin :: admin@test-domain.com >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

2022-04-15 11:10:03 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=15 thread=98] Proceeding TLS

2022-04-15 11:10:03 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=15 thread=98] Start handshake

2022-04-15 11:10:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=15 thread=98] Can't establish encrypted connection

2022-04-15 11:10:23 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2022-04-15 11:10:23 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2022-04-15 11:10:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=15 thread=98] Connector  state changed: connected->disconnected

2022-04-15 11:10:23 | tigase.jaxmpp.j2se.Jaxmpp.onException: Catching exception

2022-04-15 11:10:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=15 thread=96] Ignoring stop connector.

2022-04-15 11:10:23 | Could not connect with admin account credentials (tigase.jaxmpp.core.client.exceptions.JaxmppException: javax.net.ssl.SSLException: Unsupported or unrecognized SSL message), trying to register account...

2022-04-15 11:10:23 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2022-04-15 11:10:23 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2022-04-15 11:10:23 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

2022-04-15 11:10:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=16 thread=1] Using XEP-0077 mode!!!!

2022-04-15 11:10:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=16 thread=1] Connector  state changed: null->connecting

2022-04-15 11:10:23 | tigase.jaxmpp.core.client.SessionObject$ClearedHandler$ClearedEvent@25d0b114

2022-04-15 11:10:23 | StateChangedEvent{oldState=null, newState=connecting}

2022-04-15 11:10:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=16 thread=1] DNS entry stored in session object: localhost:5222

2022-04-15 11:10:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=16 thread=1] Preparing connection to [localhost:5222]

2022-04-15 11:10:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=16 thread=1] Opening connection to localhost/127.0.0.1:5222

2022-04-15 11:10:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=16 thread=1] Connector  state changed: connecting->connected

2022-04-15 11:10:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=16 thread=1] Whitespace ping period is setted to nullms

2022-04-15 11:10:23 | [Mutex] waiting for: [registration]

2022-04-15 11:10:23 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2022-04-15 11:10:23 | tigase.jaxmpp.core.client.Connector$StreamRestartedHandler$StreamRestaredEvent@2b174bde

2022-04-15 11:10:23 | StateChangedEvent{oldState=connecting, newState=connected}

2022-04-15 11:10:23 | tigase.jaxmpp.core.client.Connector$ConnectedHandler$ConnectedEvent@2f28da64

2022-04-15 11:10:23 | admin :: null << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/><register xmlns="http://jabber.org/features/iq-register"/><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"><required/></starttls><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2022-04-15 11:10:23 | StanzaReceivedEvent{stanza=<features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/><register xmlns="http://jabber.org/features/iq-register"/><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"><required/></starttls><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>}

2022-04-15 11:10:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=16 thread=101] Start TLS

2022-04-15 11:10:23 | StreamFeaturesReceivedEvent[<features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/><register xmlns="http://jabber.org/features/iq-register"/><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"><required/></starttls><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>]

2022-04-15 11:10:23 | admin :: null >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

2022-04-15 11:10:23 | StanzaSendingEvent{stanza=<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>}

2022-04-15 11:10:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=16 thread=103] Proceeding TLS

2022-04-15 11:10:23 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=16 thread=103] Start handshake

2022-04-15 11:10:43 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=16 thread=103] Can't establish encrypted connection

2022-04-15 11:10:43 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2022-04-15 11:10:43 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2022-04-15 11:10:43 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=16 thread=103] Connector  state changed: connected->disconnected

2022-04-15 11:10:43 | ErrorEvent{condition=null, caught=javax.net.ssl.SSLException: Unsupported or unrecognized SSL message, sessionObject=AbstractSessionObject{properties={TRUST_MANAGERS_KEY=Entry{scope=user, value=[Ljavax.net.ssl.X509TrustManager;@2c1cbce4}, CONNECTOR#DISABLEKEEPALIVE=Entry{scope=stream, value=false}, StreamFeaturesModule#STREAMS_FEATURES_LIST=Entry{scope=session, value=[<features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/><register xmlns="http://jabber.org/features/iq-register"/><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"><required/></starttls><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>]}, STREAMS_MANAGER_KEY=Entry{scope=user, value=tigase.jaxmpp.core.client.xmpp.stream.XmppStreamsManager@6a2a41e5}, COMPRESSION_DISABLED=Entry{scope=user, value=true}, HOSTNAME_VERIFIER_KEY=Entry{scope=session, value=tigase.jaxmpp.j2se.connectors.socket.DefaultHostnameVerifier@1d7af358}, BOSH#SEE_OTHER_HOST_KEY=Entry{scope=user, value=false}, CONNECTOR#STAGE_KEY=Entry{scope=stream, value=disconnected}, RosterModule#ROSTER_STORE=Entry{scope=user, value=tigase.jaxmpp.core.client.xmpp.modules.roster.DefaultRosterStore@4ad215a5}, PresenceModule#PRESENCE_STORE=Entry{scope=user, value=tigase.jaxmpp.j2se.J2SEPresenceStore@5b8aee9a}, ResponseManager#RESPONSE_MANAGER=Entry{scope=user, value=tigase.jaxmpp.j2se.ThreadSafeResponseManager@3298e475}, StreamFeaturesModule#PIPELINING_ACTIVE=Entry{scope=session, value=false}, DEFAULT_XMPP_STREAM_KEY=Entry{scope=session, value=DefaultXMPPStream}, domainName=Entry{scope=user, value=test-domain.com}, StreamFeaturesModule#EMBEDDED_STREAMS_COUNTER=Entry{scope=session, value=1}, LOG_PREFIX=Entry{scope=user, value=admin}, socket#ServerHost=Entry{scope=user, value=localhost}, IN_BAND_REGISTRATION_MODE_KEY=Entry{scope=session, value=true}, CONNECTOR#CONNECTOR_STAGE_TIMESTAMP_KEY=Entry{scope=stream, value=Fri Apr 15 11:10:43 PDT 2022}}}}

2022-04-15 11:10:43 | StateChangedEvent{oldState=connected, newState=disconnected}

2022-04-15 11:10:43 | tigase.jaxmpp.core.client.Connector$StreamTerminatedHandler$StreamTerminatedEvent@a05beaa

2022-04-15 11:10:43 | tigase.jaxmpp.core.client.Connector$DisconnectedHandler$DisconnectedEvent@50a0fd72

2022-04-15 11:10:43 | tigase.jaxmpp.core.client.JaxmppCore$LoggedOutHandler$LoggedOutEvent@5c5227c2

2022-04-15 11:11:53 | [Mutex] timeout. Not received [registration]

2022-04-15 11:11:53 | [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
Skipped Tests
tigase.tests.jaxmpp.TestHandlingOfConnectionIssues
testStateAfterAuthTimeoutBosh 0.000s
2022-04-15 11:11:53 |

2022-04-15 11:11:53 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2022-04-15 11:11:53 | ------------------------------------

testStateAfterAuthTimeoutSocket 0.000s
2022-04-15 11:11:53 |

2022-04-15 11:11:53 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2022-04-15 11:11:53 | ------------------------------------

testStateAfterAuthTimeoutWebSocket 0.000s
2022-04-15 11:11:53 |

2022-04-15 11:11:53 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2022-04-15 11:11:53 | ------------------------------------

testStateAfterConnectionFailureBosh 0.000s
2022-04-15 11:11:53 |

2022-04-15 11:11:53 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2022-04-15 11:11:53 | ------------------------------------

testStateAfterConnectionFailureSocket 0.000s
2022-04-15 11:11:53 |

2022-04-15 11:11:53 | null / [TestClass name=class tigase.tests.jaxmpp.TestHandlingOfConnectionIssues]

2022-04-15 11:11:53 | ------------------------------------

testStateAfterConnectionFailureWebSocket 0.000s