Testing reconnections - #4266

Test duration: 15.819s

Passed Tests
tigase.tests.jaxmpp.TestReconnections
testMultipleReconnectionsBosh 5.377s
2019-11-22 20:47:59 |

2019-11-22 20:47:59 | null / [TestClass name=class tigase.tests.jaxmpp.TestReconnections]

2019-11-22 20:47:59 | ------------------------------------

2019-11-22 20:47:59 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-22 20:47:59 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2019-11-22 20:47:59 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using BOSHConnector

2019-11-22 20:47:59 | jaxmpp_ :: jaxmpp__ojhanv0530@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>SCRAM-SHA-256</mechanism><mechanism>SCRAM-SHA-1</mechanism><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2019-11-22 20:47:59 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2019-11-22 20:47:59 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-11-22 20:47:59 | jaxmpp_ :: jaxmpp__ojhanv0530@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX29qaGFudjA1MzAscj1mY0pFSGt1ZERSd2VUVVRnazQ3Mg==</auth>

2019-11-22 20:47:59 | jaxmpp_ :: jaxmpp__ojhanv0530@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1mY0pFSGt1ZERSd2VUVVRnazQ3MjM2ZFdJWFhrNHlOTGlyc21vNWtrLHM9OUc5Nk1VUGoydWlCNlE9PSxpPTQwOTY=</challenge>

2019-11-22 20:47:59 | jaxmpp_ :: jaxmpp__ojhanv0530@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9ZmNKRUhrdWREUndlVFVUZ2s0NzIzNmRXSVhYazR5TkxpcnNtbzVrayxwPU5nWUFNZXpVYllMZXorSjBmVFJBdUJoVTBNRDF5RStkYXVvM0RWTFhwaWc9</response>

2019-11-22 20:47:59 | jaxmpp_ :: jaxmpp__ojhanv0530@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1YcEJiOFc0YkQyYVllcGc2aXNwTTZzMnA0M3B3V1pNZUlpMk1mS3Y5R2swPQ==</success>

2019-11-22 20:47:59 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-22 20:47:59 | jaxmpp_ :: jaxmpp__ojhanv0530@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 xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server" ver="vxsZDK3itTHNCC9pNOSKIQZW/14=" hash="SHA-1"/></features>

2019-11-22 20:47:59 | jaxmpp_ :: jaxmpp__ojhanv0530@localhost >> <iq xmlns="jabber:client" id="CwSy6eL0lUWhMJIGKSQ9AEG" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-22 20:47:59 | jaxmpp_ :: jaxmpp__ojhanv0530@localhost << <iq xmlns="jabber:client" to="jaxmpp__ojhanv0530@localhost/993927746-tigase-279" id="CwSy6eL0lUWhMJIGKSQ9AEG" type="result"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__ojhanv0530@localhost/993927746-tigase-279</jid></bind></iq>

2019-11-22 20:47:59 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-22 20:47:59 | jaxmpp_ :: jaxmpp__ojhanv0530@localhost/993927746-tigase-279 >> <iq to="localhost" id="1xT9IGIMZYYfYhMGLKFAqeQ" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-11-22 20:47:59 | jaxmpp_ :: jaxmpp__ojhanv0530@localhost/993927746-tigase-279 >> <iq id="AsCXgXUQZsfIyveDwiYkKXc" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-11-22 20:47:59 | jaxmpp_ :: jaxmpp__ojhanv0530@localhost/993927746-tigase-279 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-22 20:47:59 | jaxmpp_ :: jaxmpp__ojhanv0530@localhost/993927746-tigase-279 << <iq xmlns="jabber:client" to="jaxmpp__ojhanv0530@localhost/993927746-tigase-279" id="AsCXgXUQZsfIyveDwiYkKXc" type="result"><query xmlns="jabber:iq:roster"/></iq>

2019-11-22 20:47:59 | jaxmpp_ :: jaxmpp__ojhanv0530@localhost/993927746-tigase-279 << <iq from="localhost" xmlns="jabber:client" to="jaxmpp__ojhanv0530@localhost/993927746-tigase-279" id="1xT9IGIMZYYfYhMGLKFAqeQ" type="result"><query xmlns="http://jabber.org/protocol/disco#info"><identity category="component" name="Tigase ver. 8.1.0-SNAPSHOT-b10588/f55efd39" type="router"/><identity category="server" name="Tigase ver. 8.1.0-SNAPSHOT-b10588/f55efd39" type="im"/><feature var="http://jabber.org/protocol/commands"/><x xmlns="jabber:x:data" type="result"><field var="FORM_TYPE" type="hidden"><value>http://jabber.org/network/serverinfo</value></field><field var="abuse-addresses" type="text-multi"><value>mailto:abuse@localhost</value><value>xmpp:abuse@localhost</value></field></x><feature var="urn:xmpp:carbons:2"/><feature var="http://jabber.org/protocol/stats"/><feature var="vcard-temp"/><feature var="jabber:iq:auth"/><feature var="http://jabber.org/protocol/amp"/><feature var="msgoffline"/><feature var="http://jabber.org/protocol/disco#info"/><feature var="http://jabber.org/protocol/disco#items"/><feature var="urn:xmpp:blocking"/><feature var="urn:xmpp:ping"/><feature var="urn:ietf:params:xml:ns:xmpp-sasl"/><feature var="http://jabber.org/protocol/pubsub"/><feature var="http://jabber.org/protocol/pubsub#owner"/><feature var="http://jabber.org/protocol/pubsub#publish"/><identity category="pubsub" type="pep"/><feature var="urn:xmpp:pep-vcard-conversion:0"/><feature var="urn:xmpp:bookmarks-conversion:0"/><feature var="urn:xmpp:archive:auto"/><feature var="urn:xmpp:archive:manage"/><feature var="urn:xmpp:push:0"/><feature var="tigase:push:away:0"/><feature var="tigase:push:encrypt:0"/><feature var="tigase:push:ignore-unknown:0"/><feature var="tigase:push:muc:0"/><feature var="tigase:push:priority:0"/><feature var="tigase:push:muted: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>

2019-11-22 20:47:59 | jaxmpp_ :: jaxmpp__ojhanv0530@localhost/993927746-tigase-279 << <presence from="jaxmpp__ojhanv0530@localhost/993927746-tigase-279" xmlns="jabber:client" to="jaxmpp__ojhanv0530@localhost"><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-22 20:48:01 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onTerminate: Stream terminated. responseCode=200

2019-11-22 20:48:01 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onError: responseCode=500

2019-11-22 20:48:02 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

2019-11-22 20:48:02 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session]

2019-11-22 20:48:04 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-22 20:48:04 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2019-11-22 20:48:04 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using BOSHConnector

2019-11-22 20:48:04 | jaxmpp_ :: jaxmpp__ojhanv0530@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>SCRAM-SHA-256</mechanism><mechanism>SCRAM-SHA-1</mechanism><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2019-11-22 20:48:04 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2019-11-22 20:48:04 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-11-22 20:48:04 | jaxmpp_ :: jaxmpp__ojhanv0530@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX29qaGFudjA1MzAscj03TFA4ZkxYZVVlOVVNSWljaDBCRQ==</auth>

2019-11-22 20:48:04 | jaxmpp_ :: jaxmpp__ojhanv0530@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj03TFA4ZkxYZVVlOVVNSWljaDBCRUowZUU0NHR4WUVVVTlyUkQ2U2NoLHM9OUc5Nk1VUGoydWlCNlE9PSxpPTQwOTY=</challenge>

2019-11-22 20:48:04 | jaxmpp_ :: jaxmpp__ojhanv0530@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9N0xQOGZMWGVVZTlVTUlpY2gwQkVKMGVFNDR0eFlFVVU5clJENlNjaCxwPXlQaHZaQUdKYSs2UlRUM3FKSjBQUlVYeTNqeFVFb290VmR3YVdML0piU009</response>

2019-11-22 20:48:04 | jaxmpp_ :: jaxmpp__ojhanv0530@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj04aHJ0b0NQVXlXcDRUUS9EWDlxNlNpdkxRcUxqZEVlMFRPVmRkUEo3eE5BPQ==</success>

2019-11-22 20:48:04 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-22 20:48:04 | jaxmpp_ :: jaxmpp__ojhanv0530@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 xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server" ver="vxsZDK3itTHNCC9pNOSKIQZW/14=" hash="SHA-1"/></features>

2019-11-22 20:48:04 | jaxmpp_ :: jaxmpp__ojhanv0530@localhost >> <iq xmlns="jabber:client" id="MrxCueQ4eV8KS5wsl9vmIQW" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-22 20:48:04 | jaxmpp_ :: jaxmpp__ojhanv0530@localhost << <iq xmlns="jabber:client" to="jaxmpp__ojhanv0530@localhost/993927746-tigase-280" id="MrxCueQ4eV8KS5wsl9vmIQW" type="result"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__ojhanv0530@localhost/993927746-tigase-280</jid></bind></iq>

2019-11-22 20:48:04 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-22 20:48:04 | jaxmpp_ :: jaxmpp__ojhanv0530@localhost/993927746-tigase-280 >> <iq to="localhost" id="AuE1odqS3AveAzmT2k2s0te" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-11-22 20:48:04 | jaxmpp_ :: jaxmpp__ojhanv0530@localhost/993927746-tigase-280 >> <iq id="dtzDFyhOS8EofM2sfQ6DJFG" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-11-22 20:48:04 | jaxmpp_ :: jaxmpp__ojhanv0530@localhost/993927746-tigase-280 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-22 20:48:04 | tigase.jaxmpp.core.client.connector.AbstractBoshConnector.onTerminate: Stream terminated. responseCode=200

testMultipleReconnectionsSocket 4.457s
2019-11-22 20:48:04 |

2019-11-22 20:48:04 | null / [TestClass name=class tigase.tests.jaxmpp.TestReconnections]

2019-11-22 20:48:04 | ------------------------------------

2019-11-22 20:48:04 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-22 20:48:04 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2019-11-22 20:48:04 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

2019-11-22 20:48:04 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=587 thread=1] Connector  state changed: null->connecting

2019-11-22 20:48:04 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=587 thread=1] DNS entry stored in session object: localhost:5222

2019-11-22 20:48:04 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=587 thread=1] Preparing connection to [localhost:5222]

2019-11-22 20:48:04 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=587 thread=1] Opening connection to localhost/127.0.0.1:5222

2019-11-22 20:48:04 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=587 thread=1] Connector  state changed: connecting->connected

2019-11-22 20:48:04 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=587 thread=1] Whitespace ping period is setted to nullms

2019-11-22 20:48:04 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-22 20:48:04 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=587 thread=3761] Start TLS

2019-11-22 20:48:04 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"><required/></starttls><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2019-11-22 20:48:04 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

2019-11-22 20:48:04 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=587 thread=3763] Proceeding TLS

2019-11-22 20:48:04 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=587 thread=3763] Start handshake

2019-11-22 20:48:04 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-22 20:48:05 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>SCRAM-SHA-256</mechanism><mechanism>SCRAM-SHA-1</mechanism><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2019-11-22 20:48:05 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2019-11-22 20:48:05 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-11-22 20:48:05 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX2hobHE2azA1MzEscj05RFdub1hOVjY3V09SaTN6ZVJRQw==</auth>

2019-11-22 20:48:05 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj05RFdub1hOVjY3V09SaTN6ZVJRQ2dGZVNQZjhoUG9EYkhlYURXTHpjLHM9bjNSK1g3VTgvVjFXbkE9PSxpPTQwOTY=</challenge>

2019-11-22 20:48:05 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9OURXbm9YTlY2N1dPUmkzemVSUUNnRmVTUGY4aFBvRGJIZWFEV0x6YyxwPVlVcWU2N0tVSlVOUnFGMDNVZXlCRGxJMHVpYlZFMFM5eXRQYWlxd2tZZ289</response>

2019-11-22 20:48:05 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1oSnpSditRa0JnbnlZcmNYTmtOZU5SaDRDMnVMZFcveXZnUkJGYWszTjlVPQ==</success>

2019-11-22 20:48:05 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-22 20:48:05 | jaxmpp_ :: jaxmpp__hhlq6k0531@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 xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server" ver="vxsZDK3itTHNCC9pNOSKIQZW/14=" hash="SHA-1"/></features>

2019-11-22 20:48:05 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost >> <iq xmlns="jabber:client" id="WH7WeSbPR48GCAwtWU7ILKC" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-22 20:48:05 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost << <iq xmlns="jabber:client" to="jaxmpp__hhlq6k0531@localhost/993927746-tigase-281" id="WH7WeSbPR48GCAwtWU7ILKC" type="result"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__hhlq6k0531@localhost/993927746-tigase-281</jid></bind></iq>

2019-11-22 20:48:05 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-22 20:48:05 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost/993927746-tigase-281 >> <iq xmlns="jabber:client" id="wxBVQ6sgSbmKN4tasjQRYcM" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-11-22 20:48:05 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost/993927746-tigase-281 << <iq xmlns="jabber:client" to="jaxmpp__hhlq6k0531@localhost/993927746-tigase-281" id="wxBVQ6sgSbmKN4tasjQRYcM" type="result"/>

2019-11-22 20:48:05 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management

2019-11-22 20:48:05 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost/993927746-tigase-281 >> <iq to="localhost" id="QJ93cR0um3sk5DtiAAqcKVQ" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-11-22 20:48:05 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost/993927746-tigase-281 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/>

2019-11-22 20:48:05 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost/993927746-tigase-281 << <enabled max="60" xmlns="urn:xmpp:sm:3" resume="true" id="3f46507b-c63e-4f73-84f3-129c0b63be42" location="d4270859fb27"/>

2019-11-22 20:48:05 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost/993927746-tigase-281 >> <iq id="xI4vq6yslGo5EDu6Bq1iQ4w" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-11-22 20:48:05 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost/993927746-tigase-281 << <iq from="localhost" xmlns="jabber:client" to="jaxmpp__hhlq6k0531@localhost/993927746-tigase-281" id="QJ93cR0um3sk5DtiAAqcKVQ" type="result"><query xmlns="http://jabber.org/protocol/disco#info"><identity category="component" name="Tigase ver. 8.1.0-SNAPSHOT-b10588/f55efd39" type="router"/><identity category="server" name="Tigase ver. 8.1.0-SNAPSHOT-b10588/f55efd39" type="im"/><feature var="http://jabber.org/protocol/commands"/><x xmlns="jabber:x:data" type="result"><field var="FORM_TYPE" type="hidden"><value>http://jabber.org/network/serverinfo</value></field><field var="abuse-addresses" type="text-multi"><value>mailto:abuse@localhost</value><value>xmpp:abuse@localhost</value></field></x><feature var="urn:xmpp:carbons:2"/><feature var="http://jabber.org/protocol/stats"/><feature var="vcard-temp"/><feature var="jabber:iq:auth"/><feature var="http://jabber.org/protocol/amp"/><feature var="msgoffline"/><feature var="http://jabber.org/protocol/disco#info"/><feature var="http://jabber.org/protocol/disco#items"/><feature var="urn:xmpp:blocking"/><feature var="urn:xmpp:ping"/><feature var="urn:ietf:params:xml:ns:xmpp-sasl"/><feature var="http://jabber.org/protocol/pubsub"/><feature var="http://jabber.org/protocol/pubsub#owner"/><feature var="http://jabber.org/protocol/pubsub#publish"/><identity category="pubsub" type="pep"/><feature var="urn:xmpp:pep-vcard-conversion:0"/><feature var="urn:xmpp:bookmarks-conversion:0"/><feature var="urn:xmpp:archive:auto"/><feature var="urn:xmpp:archive:manage"/><feature var="urn:xmpp:push:0"/><feature var="tigase:push:away:0"/><feature var="tigase:push:encrypt:0"/><feature var="tigase:push:ignore-unknown:0"/><feature var="tigase:push:muc:0"/><feature var="tigase:push:priority:0"/><feature var="tigase:push:muted: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>

2019-11-22 20:48:05 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost/993927746-tigase-281 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-22 20:48:05 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost/993927746-tigase-281 << <iq xmlns="jabber:client" to="jaxmpp__hhlq6k0531@localhost/993927746-tigase-281" id="xI4vq6yslGo5EDu6Bq1iQ4w" type="result"><query xmlns="jabber:iq:roster"/></iq>

2019-11-22 20:48:05 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost/993927746-tigase-281 << <presence from="jaxmpp__hhlq6k0531@localhost/993927746-tigase-281" xmlns="jabber:client" to="jaxmpp__hhlq6k0531@localhost"><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-22 20:48:07 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=587 thread=1] Connector  state changed: connected->disconnecting

2019-11-22 20:48:07 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=587 thread=1] Terminating XMPP Stream

2019-11-22 20:48:07 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=587 thread=3763] Connector  state changed: disconnecting->disconnected

2019-11-22 20:48:07 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=587 thread=3763] Stream terminated

2019-11-22 20:48:07 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-11-22 20:48:07 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

2019-11-22 20:48:07 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session]

2019-11-22 20:48:07 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-11-22 20:48:07 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-11-22 20:48:09 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-22 20:48:09 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=true

2019-11-22 20:48:09 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

2019-11-22 20:48:09 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=588 thread=1] Connector  state changed: null->connecting

2019-11-22 20:48:09 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=588 thread=1] DNS entry stored in session object: localhost:5222

2019-11-22 20:48:09 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=588 thread=1] Preparing connection to [localhost:5222]

2019-11-22 20:48:09 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=588 thread=1] Opening connection to localhost/127.0.0.1:5222

2019-11-22 20:48:09 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=588 thread=1] Connector  state changed: connecting->connected

2019-11-22 20:48:09 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=588 thread=1] Whitespace ping period is setted to nullms

2019-11-22 20:48:09 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"><required/></starttls><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2019-11-22 20:48:09 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=588 thread=3761] Start TLS

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

2019-11-22 20:48:09 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=588 thread=3769] Proceeding TLS

2019-11-22 20:48:09 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=588 thread=3769] Start handshake

2019-11-22 20:48:09 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>SCRAM-SHA-256</mechanism><mechanism>SCRAM-SHA-1</mechanism><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2019-11-22 20:48:09 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2019-11-22 20:48:09 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfX2hobHE2azA1MzEscj1lYkJpSTlDb1NWczVFeFR1RG1vdg==</auth>

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1lYkJpSTlDb1NWczVFeFR1RG1vdjJXT1BTZFE1U3NJbFJSVzJUVWN4LHM9bjNSK1g3VTgvVjFXbkE9PSxpPTQwOTY=</challenge>

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9ZWJCaUk5Q29TVnM1RXhUdURtb3YyV09QU2RRNVNzSWxSUlcyVFVjeCxwPVdlYm1Pd2FmdmQxWXAzcFUrOHRLSUROY01UcWpzVWk4QVZTOU1LK3YxbG89</response>

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1UR3hKTmIveUtnUlF1VUhNSHpZSWJvRXB6Qlc2bVJZQnUyanNwazNrV1BJPQ==</success>

2019-11-22 20:48:09 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__hhlq6k0531@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 xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server" ver="vxsZDK3itTHNCC9pNOSKIQZW/14=" hash="SHA-1"/></features>

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost >> <iq xmlns="jabber:client" id="cI2FsjQRYcMWYp6GKP0qh1f" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost << <iq xmlns="jabber:client" to="jaxmpp__hhlq6k0531@localhost/993927746-tigase-282" id="cI2FsjQRYcMWYp6GKP0qh1f" type="result"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__hhlq6k0531@localhost/993927746-tigase-282</jid></bind></iq>

2019-11-22 20:48:09 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost/993927746-tigase-282 >> <iq xmlns="jabber:client" id="XJ3P4zBpak4o8CFkGFOX8ob" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost/993927746-tigase-282 << <iq xmlns="jabber:client" to="jaxmpp__hhlq6k0531@localhost/993927746-tigase-282" id="XJ3P4zBpak4o8CFkGFOX8ob" type="result"/>

2019-11-22 20:48:09 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost/993927746-tigase-282 >> <iq to="localhost" id="zPjfQ2v02neNOKT0bCum6i3" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost/993927746-tigase-282 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/>

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost/993927746-tigase-282 << <enabled max="60" xmlns="urn:xmpp:sm:3" resume="true" id="eedff7e2-5605-46ca-90db-a1ab0f654010" location="d4270859fb27"/>

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost/993927746-tigase-282 >> <iq id="PGQrgCHGQ4ti0rlT8gW8CAB" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost/993927746-tigase-282 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost/993927746-tigase-282 << <iq from="localhost" xmlns="jabber:client" to="jaxmpp__hhlq6k0531@localhost/993927746-tigase-282" id="zPjfQ2v02neNOKT0bCum6i3" type="result"><query xmlns="http://jabber.org/protocol/disco#info"><identity category="component" name="Tigase ver. 8.1.0-SNAPSHOT-b10588/f55efd39" type="router"/><identity category="server" name="Tigase ver. 8.1.0-SNAPSHOT-b10588/f55efd39" type="im"/><feature var="http://jabber.org/protocol/commands"/><x xmlns="jabber:x:data" type="result"><field var="FORM_TYPE" type="hidden"><value>http://jabber.org/network/serverinfo</value></field><field var="abuse-addresses" type="text-multi"><value>mailto:abuse@localhost</value><value>xmpp:abuse@localhost</value></field></x><feature var="urn:xmpp:carbons:2"/><feature var="http://jabber.org/protocol/stats"/><feature var="vcard-temp"/><feature var="jabber:iq:auth"/><feature var="http://jabber.org/protocol/amp"/><feature var="msgoffline"/><feature var="http://jabber.org/protocol/disco#info"/><feature var="http://jabber.org/protocol/disco#items"/><feature var="urn:xmpp:blocking"/><feature var="urn:xmpp:ping"/><feature var="urn:ietf:params:xml:ns:xmpp-sasl"/><feature var="http://jabber.org/protocol/pubsub"/><feature var="http://jabber.org/protocol/pubsub#owner"/><feature var="http://jabber.org/protocol/pubsub#publish"/><identity category="pubsub" type="pep"/><feature var="urn:xmpp:pep-vcard-conversion:0"/><feature var="urn:xmpp:bookmarks-conversion:0"/><feature var="urn:xmpp:archive:auto"/><feature var="urn:xmpp:archive:manage"/><feature var="urn:xmpp:push:0"/><feature var="tigase:push:away:0"/><feature var="tigase:push:encrypt:0"/><feature var="tigase:push:ignore-unknown:0"/><feature var="tigase:push:muc:0"/><feature var="tigase:push:priority:0"/><feature var="tigase:push:muted: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>

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost/993927746-tigase-282 << <iq xmlns="jabber:client" to="jaxmpp__hhlq6k0531@localhost/993927746-tigase-282" id="PGQrgCHGQ4ti0rlT8gW8CAB" type="result"><query xmlns="jabber:iq:roster"/></iq>

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__hhlq6k0531@localhost/993927746-tigase-282 << <presence from="jaxmpp__hhlq6k0531@localhost/993927746-tigase-282" xmlns="jabber:client" to="jaxmpp__hhlq6k0531@localhost"><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-22 20:48:09 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=588 thread=3769] Connector  state changed: connected->disconnected

2019-11-22 20:48:09 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=588 thread=3769] Stream terminated

2019-11-22 20:48:09 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-11-22 20:48:09 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

testMultipleReconnectionsWebSocket 4.676s
2019-11-22 20:48:09 |

2019-11-22 20:48:09 | null / [TestClass name=class tigase.tests.jaxmpp.TestReconnections]

2019-11-22 20:48:09 | ------------------------------------

2019-11-22 20:48:09 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2019-11-22 20:48:09 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2019-11-22 20:48:09 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using WebSocketConnector

2019-11-22 20:48:09 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Start connector.

2019-11-22 20:48:09 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: null->connecting

2019-11-22 20:48:09 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Preparing connection to localhost

2019-11-22 20:48:09 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Opening connection to localhost/127.0.0.1:5290

2019-11-22 20:48:09 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connecting->connected

2019-11-22 20:48:09 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Whitespace ping period is setted to nullms

2019-11-22 20:48:09 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>SCRAM-SHA-256</mechanism><mechanism>SCRAM-SHA-1</mechanism><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2019-11-22 20:48:09 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2019-11-22 20:48:09 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfXzV2NW1uNjA1MzIscj1HN2N0aVNES0VHMndPc2s2dXhlYQ==</auth>

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1HN2N0aVNES0VHMndPc2s2dXhlYUVLbjhMYkszSnBSdWpyeFp3MUtBLHM9SnpTZzJRanYxR3NwWkE9PSxpPTQwOTY=</challenge>

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9RzdjdGlTREtFRzJ3T3NrNnV4ZWFFS244TGJLM0pwUnVqcnhadzFLQSxwPXZ3ZXBWdklGMzYzcFJlZ1BCMlBOM1RjQnBsWWU5b0Uvbkc1LzRmVWFmN1k9</response>

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj1PNVM1d3hLOWloT09qYzE0RTBralIxanRzZUczM3B0SGxCbklRM2VUOU1FPQ==</success>

2019-11-22 20:48:09 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__5v5mn60532@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 xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server" ver="vxsZDK3itTHNCC9pNOSKIQZW/14=" hash="SHA-1"/></features>

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost >> <iq xmlns="jabber:client" id="qSiiWi1vdMywiWeTMAtqbAi" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost << <iq xmlns="jabber:client" to="jaxmpp__5v5mn60532@localhost/993927746-tigase-283" id="qSiiWi1vdMywiWeTMAtqbAi" type="result"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__5v5mn60532@localhost/993927746-tigase-283</jid></bind></iq>

2019-11-22 20:48:09 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost/993927746-tigase-283 >> <iq xmlns="jabber:client" id="MJPcEyumO5soaFGMZr5w2ue" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost/993927746-tigase-283 << <iq xmlns="jabber:client" to="jaxmpp__5v5mn60532@localhost/993927746-tigase-283" id="MJPcEyumO5soaFGMZr5w2ue" type="result"/>

2019-11-22 20:48:09 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost/993927746-tigase-283 >> <iq to="localhost" id="YSefVjP00q6yslGo5EDu6Bq" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost/993927746-tigase-283 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/>

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost/993927746-tigase-283 >> <iq id="v0AKQGMOYi126vujQO1gHEy" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost/993927746-tigase-283 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost/993927746-tigase-283 << <enabled max="60" xmlns="urn:xmpp:sm:3" resume="true" id="0b8d9272-7ca7-4a02-a834-fa3b505c6bc5" location="d4270859fb27"/>

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost/993927746-tigase-283 << <iq from="localhost" xmlns="jabber:client" to="jaxmpp__5v5mn60532@localhost/993927746-tigase-283" id="YSefVjP00q6yslGo5EDu6Bq" type="result"><query xmlns="http://jabber.org/protocol/disco#info"><identity category="component" name="Tigase ver. 8.1.0-SNAPSHOT-b10588/f55efd39" type="router"/><identity category="server" name="Tigase ver. 8.1.0-SNAPSHOT-b10588/f55efd39" type="im"/><feature var="http://jabber.org/protocol/commands"/><x xmlns="jabber:x:data" type="result"><field var="FORM_TYPE" type="hidden"><value>http://jabber.org/network/serverinfo</value></field><field var="abuse-addresses" type="text-multi"><value>mailto:abuse@localhost</value><value>xmpp:abuse@localhost</value></field></x><feature var="urn:xmpp:carbons:2"/><feature var="http://jabber.org/protocol/stats"/><feature var="vcard-temp"/><feature var="jabber:iq:auth"/><feature var="http://jabber.org/protocol/amp"/><feature var="msgoffline"/><feature var="http://jabber.org/protocol/disco#info"/><feature var="http://jabber.org/protocol/disco#items"/><feature var="urn:xmpp:blocking"/><feature var="urn:xmpp:ping"/><feature var="urn:ietf:params:xml:ns:xmpp-sasl"/><feature var="http://jabber.org/protocol/pubsub"/><feature var="http://jabber.org/protocol/pubsub#owner"/><feature var="http://jabber.org/protocol/pubsub#publish"/><identity category="pubsub" type="pep"/><feature var="urn:xmpp:pep-vcard-conversion:0"/><feature var="urn:xmpp:bookmarks-conversion:0"/><feature var="urn:xmpp:archive:auto"/><feature var="urn:xmpp:archive:manage"/><feature var="urn:xmpp:push:0"/><feature var="tigase:push:away:0"/><feature var="tigase:push:encrypt:0"/><feature var="tigase:push:ignore-unknown:0"/><feature var="tigase:push:muc:0"/><feature var="tigase:push:priority:0"/><feature var="tigase:push:muted: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>

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost/993927746-tigase-283 << <iq xmlns="jabber:client" to="jaxmpp__5v5mn60532@localhost/993927746-tigase-283" id="v0AKQGMOYi126vujQO1gHEy" type="result"><query xmlns="jabber:iq:roster"/></iq>

2019-11-22 20:48:09 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost/993927746-tigase-283 << <presence from="jaxmpp__5v5mn60532@localhost/993927746-tigase-283" xmlns="jabber:client" to="jaxmpp__5v5mn60532@localhost"><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-22 20:48:11 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connected->disconnecting

2019-11-22 20:48:11 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.terminateStream: Terminating XMPP Stream

2019-11-22 20:48:11 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-11-22 20:48:11 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: disconnecting->disconnected

2019-11-22 20:48:11 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

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

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

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

2019-11-22 20:48:13 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using WebSocketConnector

2019-11-22 20:48:13 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Start connector.

2019-11-22 20:48:13 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: null->connecting

2019-11-22 20:48:13 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Preparing connection to localhost

2019-11-22 20:48:13 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Opening connection to localhost/127.0.0.1:5290

2019-11-22 20:48:13 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connecting->connected

2019-11-22 20:48:13 | tigase.jaxmpp.j2se.connectors.websocket.WebSocketConnector.start: Whitespace ping period is setted to nullms

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

2019-11-22 20:48:14 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>SCRAM-SHA-256</mechanism><mechanism>SCRAM-SHA-1</mechanism><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2019-11-22 20:48:14 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.login: Authenticating with SASL Non-SASL

2019-11-22 20:48:14 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2019-11-22 20:48:14 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj1qYXhtcHBfXzV2NW1uNjA1MzIscj1JaEZHQ3BVSlJOWksycTRJVk1RWQ==</auth>

2019-11-22 20:48:14 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1JaEZHQ3BVSlJOWksycTRJVk1RWTZKT1FjNDhJakl5V2FqWTNBQ1NJLHM9SnpTZzJRanYxR3NwWkE9PSxpPTQwOTY=</challenge>

2019-11-22 20:48:14 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9SWhGR0NwVUpSTlpLMnE0SVZNUVk2Sk9RYzQ4SWpJeVdhalkzQUNTSSxwPUkxSE5PVC9vR2IxSnBXTkNyUSsxVlNIN0trV0dCeUdrRG5nV1ZQNTBIVlE9</response>

2019-11-22 20:48:14 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj05S3ZmZjBSNk9WRlpwR2Z2U3NqWCtZREQxc3RuRVg0VUg5WnlCcktKR3RvPQ==</success>

2019-11-22 20:48:14 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2019-11-22 20:48:14 | jaxmpp_ :: jaxmpp__5v5mn60532@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 xmlns="http://jabber.org/protocol/caps" node="https://tigase.net/tigase-xmpp-server" ver="vxsZDK3itTHNCC9pNOSKIQZW/14=" hash="SHA-1"/></features>

2019-11-22 20:48:14 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost >> <iq xmlns="jabber:client" id="1UgTcEEEJsWbQ1gEHCp4oaI" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2019-11-22 20:48:14 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost << <iq xmlns="jabber:client" to="jaxmpp__5v5mn60532@localhost/993927746-tigase-284" id="1UgTcEEEJsWbQ1gEHCp4oaI" type="result"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>jaxmpp__5v5mn60532@localhost/993927746-tigase-284</jid></bind></iq>

2019-11-22 20:48:14 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2019-11-22 20:48:14 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost/993927746-tigase-284 >> <iq xmlns="jabber:client" id="wMQpO2k0m9iCxyr6k3kPU4w" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2019-11-22 20:48:14 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost/993927746-tigase-284 << <iq xmlns="jabber:client" to="jaxmpp__5v5mn60532@localhost/993927746-tigase-284" id="wMQpO2k0m9iCxyr6k3kPU4w" type="result"/>

2019-11-22 20:48:14 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management

2019-11-22 20:48:14 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost/993927746-tigase-284 >> <iq to="localhost" id="Z0uM1fQGMOYi126vujQO1gH" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2019-11-22 20:48:14 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost/993927746-tigase-284 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/>

2019-11-22 20:48:14 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost/993927746-tigase-284 >> <iq id="GUabHCm7s5q6AycR0um3sk5" type="get"><query xmlns="jabber:iq:roster"/></iq>

2019-11-22 20:48:14 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost/993927746-tigase-284 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2019-11-22 20:48:14 | jaxmpp_ :: jaxmpp__5v5mn60532@localhost/993927746-tigase-284 << <enabled max="60" xmlns="urn:xmpp:sm:3" resume="true" id="d1a2e724-5606-4f5c-a308-599ab91ec457" location="d4270859fb27"/>

2019-11-22 20:48:14 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: connected->disconnecting

2019-11-22 20:48:14 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.terminateStream: Terminating XMPP Stream

2019-11-22 20:48:14 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.onStreamTerminate: Stream terminated

2019-11-22 20:48:14 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2019-11-22 20:48:14 | tigase.jaxmpp.core.client.connector.AbstractWebSocketConnector.setStage: Connector state changed: disconnecting->disconnected