Testing reconnections - #4266

Test duration: 15.570s

Passed Tests
tigase.tests.jaxmpp.TestReconnections
testMultipleReconnectionsBosh 5.354s
2020-06-01 23:08:43 |

2020-06-01 23:08:43 | null / [TestClass name=class tigase.tests.jaxmpp.TestReconnections]

2020-06-01 23:08:43 | ------------------------------------

2020-06-01 23:08:43 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2020-06-01 23:08:43 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2020-06-01 23:08:43 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using BOSHConnector

2020-06-01 23:08:43 | jaxmpp_ :: jaxmpp__i99vnt0552@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><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><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"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2020-06-01 23:08:43 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2020-06-01 23:08:43 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2020-06-01 23:08:43 | jaxmpp_ :: jaxmpp__i99vnt0552@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX2k5OXZudDA1NTIscj13QlFBaHFBWXFkaU5LOUo2cExQRw==</auth>

2020-06-01 23:08:43 | jaxmpp_ :: jaxmpp__i99vnt0552@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj13QlFBaHFBWXFkaU5LOUo2cExQR2VKcHE1eEJVTjdDUFdPbERVVjFpLHM9TEdwczljOGlPT2JLV3c9PSxpPTQwOTY=</challenge>

2020-06-01 23:08:43 | jaxmpp_ :: jaxmpp__i99vnt0552@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9d0JRQWhxQVlxZGlOSzlKNnBMUEdlSnBxNXhCVU43Q1BXT2xEVVYxaSxwPVEzNFlDUitRbnN2amNTejFnYU4vdXBUdEE1bnRBcVVYWUVXUEhQbGFPMWM9</response>

2020-06-01 23:08:43 | jaxmpp_ :: jaxmpp__i99vnt0552@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1KeG53VXRvOXdvSDIxVi8yRGQybmpYZXlTcXFPZktFVG16RkIzcGJuVktnPQ==</success>

2020-06-01 23:08:43 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2020-06-01 23:08:44 | jaxmpp_ :: jaxmpp__i99vnt0552@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="AD4uCFRGHwjXvLmXoK7swQZnVag=" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server" hash="SHA-1"/></features>

2020-06-01 23:08:44 | jaxmpp_ :: jaxmpp__i99vnt0552@localhost >> <iq xmlns="jabber:client" id="NaqDwrYcvi1oTWfWnP7Dyvu" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2020-06-01 23:08:44 | jaxmpp_ :: jaxmpp__i99vnt0552@localhost << <iq type="result" id="NaqDwrYcvi1oTWfWnP7Dyvu" to="jaxmpp__i99vnt0552@localhost/2095755800-tigase-305" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__i99vnt0552@localhost/2095755800-tigase-305</jid></bind></iq>

2020-06-01 23:08:44 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2020-06-01 23:08:44 | jaxmpp_ :: jaxmpp__i99vnt0552@localhost/2095755800-tigase-305 >> <iq to="localhost" id="aWILMLAso4AqfAqXcP07o9K" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2020-06-01 23:08:44 | jaxmpp_ :: jaxmpp__i99vnt0552@localhost/2095755800-tigase-305 >> <iq id="ocsGIxeP6HtpdIP8jNKURIG" type="get"><query xmlns="jabber:iq:roster"/></iq>

2020-06-01 23:08:44 | jaxmpp_ :: jaxmpp__i99vnt0552@localhost/2095755800-tigase-305 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2020-06-01 23:08:44 | jaxmpp_ :: jaxmpp__i99vnt0552@localhost/2095755800-tigase-305 << <iq type="result" id="aWILMLAso4AqfAqXcP07o9K" from="localhost" to="jaxmpp__i99vnt0552@localhost/2095755800-tigase-305" xmlns="jabber:client"><query xmlns="http://jabber.org/protocol/disco#info"><identity name="Tigase ver. 8.1.0-SNAPSHOT-b10747/15d7a283" type="router" category="component"/><identity name="Tigase ver. 8.1.0-SNAPSHOT-b10747/15d7a283" type="im" category="server"/><feature var="http://jabber.org/protocol/commands"/><x type="result" xmlns="jabber:x:data"><field type="hidden" var="FORM_TYPE"><value>http://jabber.org/network/serverinfo</value></field><field type="text-multi" var="abuse-addresses"><value>mailto:abuse@localhost</value><value>xmpp:abuse@localhost</value></field></x><feature var="urn:xmpp:carbons:2"/><feature var="http://jabber.org/protocol/stats"/><feature var="http://jabber.org/protocol/amp"/><feature var="msgoffline"/><feature var="jabber:iq:auth"/><feature var="vcard-temp"/><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 type="pep" category="pubsub"/><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="tigase:push:away:0"/><feature var="tigase:push:encrypt:0"/><feature var="tigase:push:encrypt:aes-128-gcm"/><feature var="tigase:push:filter:ignore-unknown:0"/><feature var="tigase:push:filter:groupchat:0"/><feature var="tigase:push:filter:muted:0"/><feature var="tigase:push:priority:0"/><feature var="jabber:iq:roster"/><feature var="jabber:iq:roster-dynamic"/><feature var="urn:xmpp:mam:1"/><feature var="jabber:iq:version"/><feature var="urn:xmpp:time"/><feature var="jabber:iq:privacy"/><feature var="urn:ietf:params:xml:ns:xmpp-bind"/><feature var="http://jabber.org/protocol/commands"/><feature var="urn:ietf:params:xml:ns:vcard-4.0"/><feature var="urn:ietf:params:xml:ns:xmpp-session"/><feature var="jabber:iq:private"/></query></iq>

2020-06-01 23:08:44 | jaxmpp_ :: jaxmpp__i99vnt0552@localhost/2095755800-tigase-305 << <iq type="result" id="ocsGIxeP6HtpdIP8jNKURIG" to="jaxmpp__i99vnt0552@localhost/2095755800-tigase-305" xmlns="jabber:client"><query xmlns="jabber:iq:roster"/></iq>

2020-06-01 23:08:44 | jaxmpp_ :: jaxmpp__i99vnt0552@localhost/2095755800-tigase-305 << <presence to="jaxmpp__i99vnt0552@localhost" from="jaxmpp__i99vnt0552@localhost/2095755800-tigase-305" xmlns="jabber:client"><c ver="mg5bXbOeu1848vxdgu3jELgbQF8=" xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" hash="sha-1"/></presence>

2020-06-01 23:08:46 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onTerminate: Stream terminated. responseCode=200

2020-06-01 23:08:46 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onError: responseCode=500

2020-06-01 23:08:46 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

2020-06-01 23:08:46 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session]

2020-06-01 23:08:48 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2020-06-01 23:08:48 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2020-06-01 23:08:48 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using BOSHConnector

2020-06-01 23:08:48 | jaxmpp_ :: jaxmpp__i99vnt0552@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><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><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"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2020-06-01 23:08:48 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2020-06-01 23:08:48 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2020-06-01 23:08:48 | jaxmpp_ :: jaxmpp__i99vnt0552@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX2k5OXZudDA1NTIscj1OUjA2bm5DZHZNRkd1ck9LSFRsVQ==</auth>

2020-06-01 23:08:48 | jaxmpp_ :: jaxmpp__i99vnt0552@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1OUjA2bm5DZHZNRkd1ck9LSFRsVVVCTWFETVh3Z1dYSkMxblgxYjZCLHM9TEdwczljOGlPT2JLV3c9PSxpPTQwOTY=</challenge>

2020-06-01 23:08:48 | jaxmpp_ :: jaxmpp__i99vnt0552@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9TlIwNm5uQ2R2TUZHdXJPS0hUbFVVQk1hRE1Yd2dXWEpDMW5YMWI2QixwPWxVdFhiNCtiNVY5UWRyZUdZQXZ5dTBJRGxRY0VVd1JTekZnT3JVODBuRG89</response>

2020-06-01 23:08:48 | jaxmpp_ :: jaxmpp__i99vnt0552@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1TR0U0cVprbXhueFlRVzFFTCtqYmxvbi9LcWlKZDUxWDh6ZUZzaUdYOU84PQ==</success>

2020-06-01 23:08:48 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2020-06-01 23:08:48 | jaxmpp_ :: jaxmpp__i99vnt0552@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="AD4uCFRGHwjXvLmXoK7swQZnVag=" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server" hash="SHA-1"/></features>

2020-06-01 23:08:48 | jaxmpp_ :: jaxmpp__i99vnt0552@localhost >> <iq xmlns="jabber:client" id="HVBNNEAEACunQWZgXgDqdSf" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2020-06-01 23:08:48 | jaxmpp_ :: jaxmpp__i99vnt0552@localhost << <iq type="result" id="HVBNNEAEACunQWZgXgDqdSf" to="jaxmpp__i99vnt0552@localhost/2095755800-tigase-306" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__i99vnt0552@localhost/2095755800-tigase-306</jid></bind></iq>

2020-06-01 23:08:48 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2020-06-01 23:08:48 | jaxmpp_ :: jaxmpp__i99vnt0552@localhost/2095755800-tigase-306 >> <iq to="localhost" id="aZLRY9m0ugYcNGClYn6jMVi" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2020-06-01 23:08:48 | jaxmpp_ :: jaxmpp__i99vnt0552@localhost/2095755800-tigase-306 >> <iq id="w2SyviZsX5k4bmY9m0ugYcN" type="get"><query xmlns="jabber:iq:roster"/></iq>

2020-06-01 23:08:48 | jaxmpp_ :: jaxmpp__i99vnt0552@localhost/2095755800-tigase-306 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2020-06-01 23:08:48 | jaxmpp_ :: jaxmpp__i99vnt0552@localhost/2095755800-tigase-306 << <iq type="result" id="aZLRY9m0ugYcNGClYn6jMVi" from="localhost" to="jaxmpp__i99vnt0552@localhost/2095755800-tigase-306" xmlns="jabber:client"><query xmlns="http://jabber.org/protocol/disco#info"><identity name="Tigase ver. 8.1.0-SNAPSHOT-b10747/15d7a283" type="router" category="component"/><identity name="Tigase ver. 8.1.0-SNAPSHOT-b10747/15d7a283" type="im" category="server"/><feature var="http://jabber.org/protocol/commands"/><x type="result" xmlns="jabber:x:data"><field type="hidden" var="FORM_TYPE"><value>http://jabber.org/network/serverinfo</value></field><field type="text-multi" var="abuse-addresses"><value>mailto:abuse@localhost</value><value>xmpp:abuse@localhost</value></field></x><feature var="urn:xmpp:carbons:2"/><feature var="http://jabber.org/protocol/stats"/><feature var="http://jabber.org/protocol/amp"/><feature var="msgoffline"/><feature var="jabber:iq:auth"/><feature var="vcard-temp"/><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 type="pep" category="pubsub"/><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="tigase:push:away:0"/><feature var="tigase:push:encrypt:0"/><feature var="tigase:push:encrypt:aes-128-gcm"/><feature var="tigase:push:filter:ignore-unknown:0"/><feature var="tigase:push:filter:groupchat:0"/><feature var="tigase:push:filter:muted:0"/><feature var="tigase:push:priority:0"/><feature var="jabber:iq:roster"/><feature var="jabber:iq:roster-dynamic"/><feature var="urn:xmpp:mam:1"/><feature var="jabber:iq:version"/><feature var="urn:xmpp:time"/><feature var="jabber:iq:privacy"/><feature var="urn:ietf:params:xml:ns:xmpp-bind"/><feature var="http://jabber.org/protocol/commands"/><feature var="urn:ietf:params:xml:ns:vcard-4.0"/><feature var="urn:ietf:params:xml:ns:xmpp-session"/><feature var="jabber:iq:private"/></query></iq>

2020-06-01 23:08:48 | jaxmpp_ :: jaxmpp__i99vnt0552@localhost/2095755800-tigase-306 << <iq type="result" id="w2SyviZsX5k4bmY9m0ugYcN" to="jaxmpp__i99vnt0552@localhost/2095755800-tigase-306" xmlns="jabber:client"><query xmlns="jabber:iq:roster"/></iq>

2020-06-01 23:08:48 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onTerminate: Stream terminated. responseCode=200

testMultipleReconnectionsSocket 4.530s
2020-06-01 23:08:49 |

2020-06-01 23:08:49 | null / [TestClass name=class tigase.tests.jaxmpp.TestReconnections]

2020-06-01 23:08:49 | ------------------------------------

2020-06-01 23:08:49 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2020-06-01 23:08:49 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2020-06-01 23:08:49 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

2020-06-01 23:08:49 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=623 thread=1] Connector  state changed: null->connecting

2020-06-01 23:08:49 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=623 thread=1] DNS entry stored in session object: localhost:5222

2020-06-01 23:08:49 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=623 thread=1] Preparing connection to [localhost:5222]

2020-06-01 23:08:49 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=623 thread=1] Opening connection to localhost/127.0.0.1:5222

2020-06-01 23:08:49 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=623 thread=1] Connector  state changed: connecting->connected

2020-06-01 23:08:49 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=623 thread=1] Whitespace ping period is setted to nullms

2020-06-01 23:08:49 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2020-06-01 23:08:49 | jaxmpp_ :: jaxmpp__ufkl910553@localhost << <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>

2020-06-01 23:08:49 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=623 thread=3988] Start TLS

2020-06-01 23:08:49 | jaxmpp_ :: jaxmpp__ufkl910553@localhost >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

2020-06-01 23:08:49 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=623 thread=3990] Proceeding TLS

2020-06-01 23:08:49 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=623 thread=3990] Start handshake

2020-06-01 23:08:49 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2020-06-01 23:08:49 | jaxmpp_ :: jaxmpp__ufkl910553@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><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><register xmlns="http://jabber.org/features/iq-register"/><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>

2020-06-01 23:08:49 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2020-06-01 23:08:49 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2020-06-01 23:08:49 | jaxmpp_ :: jaxmpp__ufkl910553@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX3Vma2w5MTA1NTMscj05aGRLbTRvRU1vNTRRSlV1cUttRA==</auth>

2020-06-01 23:08:49 | jaxmpp_ :: jaxmpp__ufkl910553@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj05aGRLbTRvRU1vNTRRSlV1cUttREl0SFY4T21wemM0WEFBV1BOZmpkLHM9UGp3L3R0dmtoRS9DclE9PSxpPTQwOTY=</challenge>

2020-06-01 23:08:49 | jaxmpp_ :: jaxmpp__ufkl910553@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9OWhkS200b0VNbzU0UUpVdXFLbURJdEhWOE9tcHpjNFhBQVdQTmZqZCxwPUt5MzhaUmI5ZFczQVYxZ0txR25MUTJOcEdBbkxUWHVIR1BhUzRYN3V0SWc9</response>

2020-06-01 23:08:49 | jaxmpp_ :: jaxmpp__ufkl910553@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj03Y1BLOFlWUktGZ2w3VnRpRDltcWxqalZnTUlHREdsbDBram1lWlpoNE1BPQ==</success>

2020-06-01 23:08:49 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2020-06-01 23:08:49 | jaxmpp_ :: jaxmpp__ufkl910553@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="AD4uCFRGHwjXvLmXoK7swQZnVag=" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server" hash="SHA-1"/></features>

2020-06-01 23:08:49 | jaxmpp_ :: jaxmpp__ufkl910553@localhost >> <iq xmlns="jabber:client" id="PhuHuezqhUV0ncTRbLO1w5l" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2020-06-01 23:08:49 | jaxmpp_ :: jaxmpp__ufkl910553@localhost << <iq type="result" id="PhuHuezqhUV0ncTRbLO1w5l" to="jaxmpp__ufkl910553@localhost/2095755800-tigase-307" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__ufkl910553@localhost/2095755800-tigase-307</jid></bind></iq>

2020-06-01 23:08:49 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2020-06-01 23:08:49 | jaxmpp_ :: jaxmpp__ufkl910553@localhost/2095755800-tigase-307 >> <iq xmlns="jabber:client" id="07YJR0piDr2u12kRMQaCGCD" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2020-06-01 23:08:49 | jaxmpp_ :: jaxmpp__ufkl910553@localhost/2095755800-tigase-307 << <iq type="result" id="07YJR0piDr2u12kRMQaCGCD" to="jaxmpp__ufkl910553@localhost/2095755800-tigase-307" xmlns="jabber:client"/>

2020-06-01 23:08:49 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management

2020-06-01 23:08:49 | jaxmpp_ :: jaxmpp__ufkl910553@localhost/2095755800-tigase-307 >> <iq to="localhost" id="7eh2u12kRMQaCGCDmY3odMF" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2020-06-01 23:08:49 | jaxmpp_ :: jaxmpp__ufkl910553@localhost/2095755800-tigase-307 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/>

2020-06-01 23:08:49 | jaxmpp_ :: jaxmpp__ufkl910553@localhost/2095755800-tigase-307 << <enabled id="ee348aeb-f3cf-4d53-8089-91c923021382" resume="true" max="60" xmlns="urn:xmpp:sm:3" location="9585556aacac"/>

2020-06-01 23:08:49 | jaxmpp_ :: jaxmpp__ufkl910553@localhost/2095755800-tigase-307 >> <iq id="ZrSwx9LV8FOFvaKx4oZ2mcG" type="get"><query xmlns="jabber:iq:roster"/></iq>

2020-06-01 23:08:49 | jaxmpp_ :: jaxmpp__ufkl910553@localhost/2095755800-tigase-307 << <iq type="result" id="7eh2u12kRMQaCGCDmY3odMF" from="localhost" to="jaxmpp__ufkl910553@localhost/2095755800-tigase-307" xmlns="jabber:client"><query xmlns="http://jabber.org/protocol/disco#info"><identity name="Tigase ver. 8.1.0-SNAPSHOT-b10747/15d7a283" type="router" category="component"/><identity name="Tigase ver. 8.1.0-SNAPSHOT-b10747/15d7a283" type="im" category="server"/><feature var="http://jabber.org/protocol/commands"/><x type="result" xmlns="jabber:x:data"><field type="hidden" var="FORM_TYPE"><value>http://jabber.org/network/serverinfo</value></field><field type="text-multi" var="abuse-addresses"><value>mailto:abuse@localhost</value><value>xmpp:abuse@localhost</value></field></x><feature var="urn:xmpp:carbons:2"/><feature var="http://jabber.org/protocol/stats"/><feature var="http://jabber.org/protocol/amp"/><feature var="msgoffline"/><feature var="jabber:iq:auth"/><feature var="vcard-temp"/><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 type="pep" category="pubsub"/><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="tigase:push:away:0"/><feature var="tigase:push:encrypt:0"/><feature var="tigase:push:encrypt:aes-128-gcm"/><feature var="tigase:push:filter:ignore-unknown:0"/><feature var="tigase:push:filter:groupchat:0"/><feature var="tigase:push:filter:muted:0"/><feature var="tigase:push:priority:0"/><feature var="jabber:iq:roster"/><feature var="jabber:iq:roster-dynamic"/><feature var="urn:xmpp:mam:1"/><feature var="jabber:iq:version"/><feature var="urn:xmpp:time"/><feature var="jabber:iq:privacy"/><feature var="urn:ietf:params:xml:ns:xmpp-bind"/><feature var="http://jabber.org/protocol/commands"/><feature var="urn:ietf:params:xml:ns:vcard-4.0"/><feature var="urn:ietf:params:xml:ns:xmpp-session"/><feature var="jabber:iq:private"/></query></iq>

2020-06-01 23:08:49 | jaxmpp_ :: jaxmpp__ufkl910553@localhost/2095755800-tigase-307 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2020-06-01 23:08:49 | jaxmpp_ :: jaxmpp__ufkl910553@localhost/2095755800-tigase-307 << <iq type="result" id="ZrSwx9LV8FOFvaKx4oZ2mcG" to="jaxmpp__ufkl910553@localhost/2095755800-tigase-307" xmlns="jabber:client"><query xmlns="jabber:iq:roster"/></iq>

2020-06-01 23:08:49 | jaxmpp_ :: jaxmpp__ufkl910553@localhost/2095755800-tigase-307 << <presence to="jaxmpp__ufkl910553@localhost" from="jaxmpp__ufkl910553@localhost/2095755800-tigase-307" xmlns="jabber:client"><c ver="mg5bXbOeu1848vxdgu3jELgbQF8=" xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" hash="sha-1"/></presence>

2020-06-01 23:08:51 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=623 thread=1] Connector  state changed: connected->disconnecting

2020-06-01 23:08:51 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=623 thread=1] Terminating XMPP Stream

2020-06-01 23:08:51 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2020-06-01 23:08:51 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2020-06-01 23:08:51 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=623 thread=3990] Connector  state changed: disconnecting->disconnected

2020-06-01 23:08:51 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

2020-06-01 23:08:51 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session]

2020-06-01 23:08:53 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2020-06-01 23:08:53 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2020-06-01 23:08:53 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

2020-06-01 23:08:53 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=624 thread=1] Connector  state changed: null->connecting

2020-06-01 23:08:53 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=624 thread=1] DNS entry stored in session object: localhost:5222

2020-06-01 23:08:53 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=624 thread=1] Preparing connection to [localhost:5222]

2020-06-01 23:08:53 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=624 thread=1] Opening connection to localhost/127.0.0.1:5222

2020-06-01 23:08:53 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=624 thread=1] Connector  state changed: connecting->connected

2020-06-01 23:08:53 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=624 thread=1] Whitespace ping period is setted to nullms

2020-06-01 23:08:53 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2020-06-01 23:08:53 | jaxmpp_ :: jaxmpp__ufkl910553@localhost << <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>

2020-06-01 23:08:53 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=624 thread=3988] Start TLS

2020-06-01 23:08:53 | jaxmpp_ :: jaxmpp__ufkl910553@localhost >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

2020-06-01 23:08:53 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=624 thread=3995] Proceeding TLS

2020-06-01 23:08:53 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=624 thread=3995] Start handshake

2020-06-01 23:08:53 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2020-06-01 23:08:53 | jaxmpp_ :: jaxmpp__ufkl910553@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><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><register xmlns="http://jabber.org/features/iq-register"/><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>

2020-06-01 23:08:53 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2020-06-01 23:08:53 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2020-06-01 23:08:53 | jaxmpp_ :: jaxmpp__ufkl910553@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX3Vma2w5MTA1NTMscj1raEJrV1dKc2t1S1J0TVhWS2J0eg==</auth>

2020-06-01 23:08:53 | jaxmpp_ :: jaxmpp__ufkl910553@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1raEJrV1dKc2t1S1J0TVhWS2J0enBOVDNMZDVvUzRFS1NjMnhoSzVvLHM9UGp3L3R0dmtoRS9DclE9PSxpPTQwOTY=</challenge>

2020-06-01 23:08:53 | jaxmpp_ :: jaxmpp__ufkl910553@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9a2hCa1dXSnNrdUtSdE1YVktidHpwTlQzTGQ1b1M0RUtTYzJ4aEs1byxwPWVjWDVScnpWemJ6ZkVxeEhvSklnRm1kalcwYW9yY0pSRTF1cnV3QXd6bFU9</response>

2020-06-01 23:08:53 | jaxmpp_ :: jaxmpp__ufkl910553@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1ONXJuUjF5QzlPa041TFVKZFNVOUdscUZVQ2E4SjJQVFhWckZiNkNJZGVZPQ==</success>

2020-06-01 23:08:53 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2020-06-01 23:08:53 | jaxmpp_ :: jaxmpp__ufkl910553@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="AD4uCFRGHwjXvLmXoK7swQZnVag=" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server" hash="SHA-1"/></features>

2020-06-01 23:08:53 | jaxmpp_ :: jaxmpp__ufkl910553@localhost >> <iq xmlns="jabber:client" id="hnE4obsaraLSRS7GRN3viZs" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2020-06-01 23:08:53 | jaxmpp_ :: jaxmpp__ufkl910553@localhost << <iq type="result" id="hnE4obsaraLSRS7GRN3viZs" to="jaxmpp__ufkl910553@localhost/2095755800-tigase-308" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__ufkl910553@localhost/2095755800-tigase-308</jid></bind></iq>

2020-06-01 23:08:53 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2020-06-01 23:08:53 | jaxmpp_ :: jaxmpp__ufkl910553@localhost/2095755800-tigase-308 >> <iq xmlns="jabber:client" id="8ghiDgMLAso4AqfAqXcP07o" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2020-06-01 23:08:53 | jaxmpp_ :: jaxmpp__ufkl910553@localhost/2095755800-tigase-308 << <iq type="result" id="8ghiDgMLAso4AqfAqXcP07o" to="jaxmpp__ufkl910553@localhost/2095755800-tigase-308" xmlns="jabber:client"/>

2020-06-01 23:08:53 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management

2020-06-01 23:08:53 | jaxmpp_ :: jaxmpp__ufkl910553@localhost/2095755800-tigase-308 >> <iq to="localhost" id="py7UV0ncTRbLO1w5lQ6fueF" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2020-06-01 23:08:53 | jaxmpp_ :: jaxmpp__ufkl910553@localhost/2095755800-tigase-308 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/>

2020-06-01 23:08:53 | jaxmpp_ :: jaxmpp__ufkl910553@localhost/2095755800-tigase-308 << <enabled id="2c27f423-ce93-47bc-9139-663b83b234f9" resume="true" max="60" xmlns="urn:xmpp:sm:3" location="9585556aacac"/>

2020-06-01 23:08:53 | jaxmpp_ :: jaxmpp__ufkl910553@localhost/2095755800-tigase-308 >> <iq id="tvWENFNZgVkHzi036s7iSeK" type="get"><query xmlns="jabber:iq:roster"/></iq>

2020-06-01 23:08:53 | jaxmpp_ :: jaxmpp__ufkl910553@localhost/2095755800-tigase-308 << <iq type="result" id="py7UV0ncTRbLO1w5lQ6fueF" from="localhost" to="jaxmpp__ufkl910553@localhost/2095755800-tigase-308" xmlns="jabber:client"><query xmlns="http://jabber.org/protocol/disco#info"><identity name="Tigase ver. 8.1.0-SNAPSHOT-b10747/15d7a283" type="router" category="component"/><identity name="Tigase ver. 8.1.0-SNAPSHOT-b10747/15d7a283" type="im" category="server"/><feature var="http://jabber.org/protocol/commands"/><x type="result" xmlns="jabber:x:data"><field type="hidden" var="FORM_TYPE"><value>http://jabber.org/network/serverinfo</value></field><field type="text-multi" var="abuse-addresses"><value>mailto:abuse@localhost</value><value>xmpp:abuse@localhost</value></field></x><feature var="urn:xmpp:carbons:2"/><feature var="http://jabber.org/protocol/stats"/><feature var="http://jabber.org/protocol/amp"/><feature var="msgoffline"/><feature var="jabber:iq:auth"/><feature var="vcard-temp"/><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 type="pep" category="pubsub"/><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="tigase:push:away:0"/><feature var="tigase:push:encrypt:0"/><feature var="tigase:push:encrypt:aes-128-gcm"/><feature var="tigase:push:filter:ignore-unknown:0"/><feature var="tigase:push:filter:groupchat:0"/><feature var="tigase:push:filter:muted:0"/><feature var="tigase:push:priority:0"/><feature var="jabber:iq:roster"/><feature var="jabber:iq:roster-dynamic"/><feature var="urn:xmpp:mam:1"/><feature var="jabber:iq:version"/><feature var="urn:xmpp:time"/><feature var="jabber:iq:privacy"/><feature var="urn:ietf:params:xml:ns:xmpp-bind"/><feature var="http://jabber.org/protocol/commands"/><feature var="urn:ietf:params:xml:ns:vcard-4.0"/><feature var="urn:ietf:params:xml:ns:xmpp-session"/><feature var="jabber:iq:private"/></query></iq>

2020-06-01 23:08:53 | jaxmpp_ :: jaxmpp__ufkl910553@localhost/2095755800-tigase-308 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2020-06-01 23:08:53 | jaxmpp_ :: jaxmpp__ufkl910553@localhost/2095755800-tigase-308 << <iq type="result" id="tvWENFNZgVkHzi036s7iSeK" to="jaxmpp__ufkl910553@localhost/2095755800-tigase-308" xmlns="jabber:client"><query xmlns="jabber:iq:roster"/></iq>

2020-06-01 23:08:53 | jaxmpp_ :: jaxmpp__ufkl910553@localhost/2095755800-tigase-308 << <presence to="jaxmpp__ufkl910553@localhost" from="jaxmpp__ufkl910553@localhost/2095755800-tigase-308" xmlns="jabber:client"><c ver="mg5bXbOeu1848vxdgu3jELgbQF8=" xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" hash="sha-1"/></presence>

2020-06-01 23:08:53 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=624 thread=3995] Connector  state changed: connected->disconnected

2020-06-01 23:08:53 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=624 thread=3995] Stream terminated

2020-06-01 23:08:53 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2020-06-01 23:08:53 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

testMultipleReconnectionsWebSocket 4.597s
2020-06-01 23:08:53 |

2020-06-01 23:08:53 | null / [TestClass name=class tigase.tests.jaxmpp.TestReconnections]

2020-06-01 23:08:53 | ------------------------------------

2020-06-01 23:08:53 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2020-06-01 23:08:53 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2020-06-01 23:08:53 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using WebSocketConnector

2020-06-01 23:08:53 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Start connector.

2020-06-01 23:08:53 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: null->connecting

2020-06-01 23:08:53 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Preparing connection to localhost

2020-06-01 23:08:53 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Opening connection to localhost/127.0.0.1:5290

2020-06-01 23:08:53 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connecting->connected

2020-06-01 23:08:53 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Whitespace ping period is setted to nullms

2020-06-01 23:08:53 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2020-06-01 23:08:53 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><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><register xmlns="http://jabber.org/features/iq-register"/><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>

2020-06-01 23:08:53 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2020-06-01 23:08:53 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2020-06-01 23:08:53 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX2xtZG53eDA1NTQscj1sQWpPMkc4UWNwZlFLSEcxUmtkag==</auth>

2020-06-01 23:08:54 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1sQWpPMkc4UWNwZlFLSEcxUmtkanhpaFVpRldFQUhDTzNCZk1Danp6LHM9ejAyenRRNjdGbHZPQmc9PSxpPTQwOTY=</challenge>

2020-06-01 23:08:54 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9bEFqTzJHOFFjcGZRS0hHMVJrZGp4aWhVaUZXRUFIQ08zQmZNQ2p6eixwPXo4WFE1UXlud01BYmlvOXVnc2l1djY0by81OHlCSUdMMno2Uzd6TVFJbzA9</response>

2020-06-01 23:08:54 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1ReHdzNTU1ekFVK3U3VWwweWxzbUkrWXgxRCtZL1dtbWg3eXVjNmk3NTBnPQ==</success>

2020-06-01 23:08:54 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2020-06-01 23:08:54 | jaxmpp_ :: jaxmpp__lmdnwx0554@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="AD4uCFRGHwjXvLmXoK7swQZnVag=" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server" hash="SHA-1"/></features>

2020-06-01 23:08:54 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost >> <iq xmlns="jabber:client" id="wh83viZsX5k4bmY9m0ugYcN" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2020-06-01 23:08:54 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost << <iq type="result" id="wh83viZsX5k4bmY9m0ugYcN" to="jaxmpp__lmdnwx0554@localhost/2095755800-tigase-309" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__lmdnwx0554@localhost/2095755800-tigase-309</jid></bind></iq>

2020-06-01 23:08:54 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2020-06-01 23:08:54 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost/2095755800-tigase-309 >> <iq xmlns="jabber:client" id="NvMkUdwiHGNWZ8DIVVj1k3A" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2020-06-01 23:08:54 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost/2095755800-tigase-309 << <iq type="result" id="NvMkUdwiHGNWZ8DIVVj1k3A" to="jaxmpp__lmdnwx0554@localhost/2095755800-tigase-309" xmlns="jabber:client"/>

2020-06-01 23:08:54 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management

2020-06-01 23:08:54 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost/2095755800-tigase-309 >> <iq to="localhost" id="ah4sax8yAsmYlMOJKVcvaHQ" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2020-06-01 23:08:54 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost/2095755800-tigase-309 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/>

2020-06-01 23:08:54 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost/2095755800-tigase-309 >> <iq id="QE9IGteT8nUbO7j5zqfYZ9s" type="get"><query xmlns="jabber:iq:roster"/></iq>

2020-06-01 23:08:54 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost/2095755800-tigase-309 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2020-06-01 23:08:54 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost/2095755800-tigase-309 << <enabled id="7d5302f7-5747-4fe1-b70f-1c6bac8ab627" resume="true" max="60" xmlns="urn:xmpp:sm:3" location="9585556aacac"/>

2020-06-01 23:08:54 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost/2095755800-tigase-309 << <iq type="result" id="QE9IGteT8nUbO7j5zqfYZ9s" to="jaxmpp__lmdnwx0554@localhost/2095755800-tigase-309" xmlns="jabber:client"><query xmlns="jabber:iq:roster"/></iq>

2020-06-01 23:08:54 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost/2095755800-tigase-309 << <iq type="result" id="ah4sax8yAsmYlMOJKVcvaHQ" from="localhost" to="jaxmpp__lmdnwx0554@localhost/2095755800-tigase-309" xmlns="jabber:client"><query xmlns="http://jabber.org/protocol/disco#info"><identity name="Tigase ver. 8.1.0-SNAPSHOT-b10747/15d7a283" type="router" category="component"/><identity name="Tigase ver. 8.1.0-SNAPSHOT-b10747/15d7a283" type="im" category="server"/><feature var="http://jabber.org/protocol/commands"/><x type="result" xmlns="jabber:x:data"><field type="hidden" var="FORM_TYPE"><value>http://jabber.org/network/serverinfo</value></field><field type="text-multi" var="abuse-addresses"><value>mailto:abuse@localhost</value><value>xmpp:abuse@localhost</value></field></x><feature var="urn:xmpp:carbons:2"/><feature var="http://jabber.org/protocol/stats"/><feature var="http://jabber.org/protocol/amp"/><feature var="msgoffline"/><feature var="jabber:iq:auth"/><feature var="vcard-temp"/><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 type="pep" category="pubsub"/><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="tigase:push:away:0"/><feature var="tigase:push:encrypt:0"/><feature var="tigase:push:encrypt:aes-128-gcm"/><feature var="tigase:push:filter:ignore-unknown:0"/><feature var="tigase:push:filter:groupchat:0"/><feature var="tigase:push:filter:muted:0"/><feature var="tigase:push:priority:0"/><feature var="jabber:iq:roster"/><feature var="jabber:iq:roster-dynamic"/><feature var="urn:xmpp:mam:1"/><feature var="jabber:iq:version"/><feature var="urn:xmpp:time"/><feature var="jabber:iq:privacy"/><feature var="urn:ietf:params:xml:ns:xmpp-bind"/><feature var="http://jabber.org/protocol/commands"/><feature var="urn:ietf:params:xml:ns:vcard-4.0"/><feature var="urn:ietf:params:xml:ns:xmpp-session"/><feature var="jabber:iq:private"/></query></iq>

2020-06-01 23:08:54 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost/2095755800-tigase-309 << <presence to="jaxmpp__lmdnwx0554@localhost" from="jaxmpp__lmdnwx0554@localhost/2095755800-tigase-309" xmlns="jabber:client"><c ver="mg5bXbOeu1848vxdgu3jELgbQF8=" xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" hash="sha-1"/></presence>

2020-06-01 23:08:56 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connected->disconnecting

2020-06-01 23:08:56 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.terminateStream: Terminating XMPP Stream

2020-06-01 23:08:56 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2020-06-01 23:08:56 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

2020-06-01 23:08:56 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session]

2020-06-01 23:08:56 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: disconnecting->disconnected

2020-06-01 23:08:58 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2020-06-01 23:08:58 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2020-06-01 23:08:58 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using WebSocketConnector

2020-06-01 23:08:58 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Start connector.

2020-06-01 23:08:58 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: null->connecting

2020-06-01 23:08:58 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Preparing connection to localhost

2020-06-01 23:08:58 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Opening connection to localhost/127.0.0.1:5290

2020-06-01 23:08:58 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connecting->connected

2020-06-01 23:08:58 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Whitespace ping period is setted to nullms

2020-06-01 23:08:58 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2020-06-01 23:08:58 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><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><register xmlns="http://jabber.org/features/iq-register"/><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>

2020-06-01 23:08:58 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2020-06-01 23:08:58 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2020-06-01 23:08:58 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX2xtZG53eDA1NTQscj1ObWNwbWhHN0xBa25sZW5ZZTJ1Vw==</auth>

2020-06-01 23:08:58 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1ObWNwbWhHN0xBa25sZW5ZZTJ1V0NLQnpvM0RQSE5BcVZ5b0RuVmozLHM9ejAyenRRNjdGbHZPQmc9PSxpPTQwOTY=</challenge>

2020-06-01 23:08:58 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9Tm1jcG1oRzdMQWtubGVuWWUydVdDS0J6bzNEUEhOQXFWeW9EblZqMyxwPUtCY1ZjYkMrY2hpVXpER0M0Sm5GS3lwbGJLM2piT1RHVlo0eDRqM3prb1U9</response>

2020-06-01 23:08:58 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1nd1JkVU50MHBkTjZaakRPckRuNlVlQXY1ZDk0dUwySjVQcFVTZ2sya09NPQ==</success>

2020-06-01 23:08:58 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2020-06-01 23:08:58 | jaxmpp_ :: jaxmpp__lmdnwx0554@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="AD4uCFRGHwjXvLmXoK7swQZnVag=" xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server" hash="SHA-1"/></features>

2020-06-01 23:08:58 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost >> <iq xmlns="jabber:client" id="vLsj5zqfYZ9skHo2hCwwk6s" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2020-06-01 23:08:58 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost << <iq type="result" id="vLsj5zqfYZ9skHo2hCwwk6s" to="jaxmpp__lmdnwx0554@localhost/2095755800-tigase-310" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__lmdnwx0554@localhost/2095755800-tigase-310</jid></bind></iq>

2020-06-01 23:08:58 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2020-06-01 23:08:58 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost/2095755800-tigase-310 >> <iq xmlns="jabber:client" id="9HePEyjGEMQ8wrYcvi1oTWf" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2020-06-01 23:08:58 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost/2095755800-tigase-310 << <iq type="result" id="9HePEyjGEMQ8wrYcvi1oTWf" to="jaxmpp__lmdnwx0554@localhost/2095755800-tigase-310" xmlns="jabber:client"/>

2020-06-01 23:08:58 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management

2020-06-01 23:08:58 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost/2095755800-tigase-310 >> <iq to="localhost" id="7twwsXU4lKM2maAzeIxm9Ep" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2020-06-01 23:08:58 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost/2095755800-tigase-310 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/>

2020-06-01 23:08:58 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost/2095755800-tigase-310 >> <iq id="Hj0AnOUiScEHuezqhUV0ncT" type="get"><query xmlns="jabber:iq:roster"/></iq>

2020-06-01 23:08:58 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost/2095755800-tigase-310 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2020-06-01 23:08:58 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost/2095755800-tigase-310 << <enabled id="7e216671-fcdc-4864-854b-7f4452eff3fc" resume="true" max="60" xmlns="urn:xmpp:sm:3" location="9585556aacac"/>

2020-06-01 23:08:58 | jaxmpp_ :: jaxmpp__lmdnwx0554@localhost/2095755800-tigase-310 << <iq type="result" id="Hj0AnOUiScEHuezqhUV0ncT" to="jaxmpp__lmdnwx0554@localhost/2095755800-tigase-310" xmlns="jabber:client"><query xmlns="jabber:iq:roster"/></iq>

2020-06-01 23:08:58 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connected->disconnecting

2020-06-01 23:08:58 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.terminateStream: Terminating XMPP Stream

2020-06-01 23:08:58 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: disconnecting->disconnected

2020-06-01 23:08:58 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.onStreamTerminate: Stream terminated

2020-06-01 23:08:58 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2020-06-01 23:08:59 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted