Generated by TestNG with ReportNG at 22:31 PDT on Wednesday 20 July 2022
root@7c41cec37518 / Java 17.0.2 (Private Build) / Linux 4.14.281-212.502.amzn2.x86_64 (amd64)

MAM2#extended: Support for XEP-0313 for PubSub - #4733

Suites · Log Output

Test duration : 0.660s

Failed Configuration
tigase.tests.pubsub.TestPubSubMAM2Extended
setUp 0.473s
2022-07-20 22:43:32 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [stream]

2022-07-20 22:43:32 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2022-07-20 22:43:32 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

2022-07-20 22:43:32 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=461 thread=1] Using XEP-0077 mode!!!!

2022-07-20 22:43:32 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=461 thread=1] Connector  state changed: null->connecting

2022-07-20 22:43:32 | tigase.jaxmpp.core.client.SessionObject$ClearedHandler$ClearedEvent@1af01309

2022-07-20 22:43:32 | StateChangedEvent{oldState=null, newState=connecting}

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

2022-07-20 22:43:33 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=461 thread=1] Preparing connection to [localhost:5222]

2022-07-20 22:43:33 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=461 thread=1] Opening connection to localhost/127.0.0.1:5222

2022-07-20 22:43:33 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=461 thread=1] Connector  state changed: connecting->connected

2022-07-20 22:43:33 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2022-07-20 22:43:33 | tigase.jaxmpp.core.client.Connector$StreamRestartedHandler$StreamRestaredEvent@1437fe27

2022-07-20 22:43:33 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=461 thread=1] Whitespace ping period is setted to nullms

2022-07-20 22:43:33 | StateChangedEvent{oldState=connecting, newState=connected}

2022-07-20 22:43:33 | tigase.jaxmpp.core.client.Connector$ConnectedHandler$ConnectedEvent@10087879

2022-07-20 22:43:33 | [Mutex] waiting for: [registration]

2022-07-20 22:43:33 | user1 :: null << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"><required/></starttls><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

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

2022-07-20 22:43:33 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=461 thread=2907] Start TLS

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

2022-07-20 22:43:33 | user1 :: null >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

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

2022-07-20 22:43:33 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=461 thread=2909] Proceeding TLS

2022-07-20 22:43:33 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=461 thread=2909] Start handshake

2022-07-20 22:43:33 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2022-07-20 22:43:33 | tigase.jaxmpp.core.client.Connector$StreamRestartedHandler$StreamRestaredEvent@550af41c

2022-07-20 22:43:33 | tigase.jaxmpp.core.client.Connector$EncryptionEstablishedHandler$EncryptionEstablishedEvent@4f78cdef

2022-07-20 22:43:33 | user1 :: null << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>SCRAM-SHA-512</mechanism><mechanism>SCRAM-SHA-256</mechanism><mechanism>SCRAM-SHA-1</mechanism><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2022-07-20 22:43:33 | StanzaReceivedEvent{stanza=<features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>SCRAM-SHA-512</mechanism><mechanism>SCRAM-SHA-256</mechanism><mechanism>SCRAM-SHA-1</mechanism><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>}

2022-07-20 22:43:33 | StreamFeaturesReceivedEvent[<features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>SCRAM-SHA-512</mechanism><mechanism>SCRAM-SHA-256</mechanism><mechanism>SCRAM-SHA-1</mechanism><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>]

2022-07-20 22:43:33 | user1 :: null >> <iq to="test-domain.com" id="3eDlbIMBu0bP6BzeP6kVT5j" type="get"><query xmlns="jabber:iq:register"/></iq>

2022-07-20 22:43:33 | StanzaSendingEvent{stanza=<iq to="test-domain.com" id="3eDlbIMBu0bP6BzeP6kVT5j" type="get"><query xmlns="jabber:iq:register"/></iq>}

2022-07-20 22:43:33 | user1 :: null << <iq xmlns="jabber:client" id="3eDlbIMBu0bP6BzeP6kVT5j" from="test-domain.com" type="result"><query xmlns="jabber:iq:register"><instructions>Please provide the following information to sign up for an account

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

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

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

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

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

2022-07-20 22:43:33 | tigase.jaxmpp.core.client.xmpp.modules.registration.InBandRegistrationModule$ReceivedRequestedFieldsHandler$ReceivedRequestedFieldsEvent@6415c4e1

2022-07-20 22:43:33 | user1 :: null >> <iq to="test-domain.com" id="0Oll3AFP0mLOEtpgVdwpgEz" type="set"><query xmlns="jabber:iq:register"><username>user1_mft7h80196</username><password>user1_mft7h80196</password><email>41b632a8-d744-4bff-a6f1-8bf126d81b07@localhost</email></query></iq>

2022-07-20 22:43:33 | StanzaSendingEvent{stanza=<iq to="test-domain.com" id="0Oll3AFP0mLOEtpgVdwpgEz" type="set"><query xmlns="jabber:iq:register"><username>user1_mft7h80196</username><password>user1_mft7h80196</password><email>41b632a8-d744-4bff-a6f1-8bf126d81b07@localhost</email></query></iq>}

2022-07-20 22:43:33 | user1 :: null << <iq xmlns="jabber:client" id="0Oll3AFP0mLOEtpgVdwpgEz" from="test-domain.com" type="result"/>

2022-07-20 22:43:33 | StanzaReceivedEvent{stanza=<iq xmlns="jabber:client" id="0Oll3AFP0mLOEtpgVdwpgEz" from="test-domain.com" type="result"/>}

2022-07-20 22:43:33 | [Mutex] received everything.

2022-07-20 22:43:33 | [Mutex] isItemNotified: registrationSuccess :: true

2022-07-20 22:43:33 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=461 thread=1] Connector  state changed: connected->disconnecting

2022-07-20 22:43:33 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=461 thread=1] Terminating XMPP Stream

2022-07-20 22:43:33 | StateChangedEvent{oldState=connected, newState=disconnecting}

2022-07-20 22:43:33 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=461 thread=2909] Connector  state changed: disconnecting->disconnected

2022-07-20 22:43:33 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=461 thread=2909] Stream terminated

2022-07-20 22:43:33 | StateChangedEvent{oldState=disconnecting, newState=disconnected}

2022-07-20 22:43:33 | tigase.jaxmpp.core.client.Connector$StreamTerminatedHandler$StreamTerminatedEvent@378da3aa

2022-07-20 22:43:33 | tigase.jaxmpp.core.client.JaxmppCore$LoggedOutHandler$LoggedOutEvent@35250b53

2022-07-20 22:43:33 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2022-07-20 22:43:33 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.reset: Reset.

2022-07-20 22:43:33 | tigase.jaxmpp.core.client.AbstractSessionObject.clear: Clearing properties in scopes [session]

2022-07-20 22:43:33 | tigase.jaxmpp.core.client.SessionObject$ClearedHandler$ClearedEvent@3cbbbfad

2022-07-20 22:43:33 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2022-07-20 22:43:33 | tigase.jaxmpp.j2se.connectors.socket.Worker.interrupt: Worker Interrupted

2022-07-20 22:43:33 | tigase.jaxmpp.core.client.Connector$StreamTerminatedHandler$StreamTerminatedEvent@76c34617

2022-07-20 22:43:33 | tigase.jaxmpp.core.client.Connector$DisconnectedHandler$DisconnectedEvent@2c892b96

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

2022-07-20 22:43:33 | tigase.jaxmpp.j2se.Jaxmpp.login: state=disconnected cr=false

2022-07-20 22:43:33 | tigase.jaxmpp.j2se.Jaxmpp.createConnector: Using SocketConnector

2022-07-20 22:43:33 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=462 thread=1] Connector  state changed: null->connecting

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

2022-07-20 22:43:33 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=462 thread=1] Preparing connection to [localhost:5222]

2022-07-20 22:43:33 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=462 thread=1] Opening connection to localhost/127.0.0.1:5222

2022-07-20 22:43:33 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=462 thread=1] Connector  state changed: connecting->connected

2022-07-20 22:43:33 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=462 thread=1] Whitespace ping period is setted to nullms

2022-07-20 22:43:33 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

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

2022-07-20 22:43:33 | user1 :: user1_mft7h80196@test-domain.com << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"><required/></starttls><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2022-07-20 22:43:33 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=462 thread=2914] Start TLS

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

2022-07-20 22:43:33 | user1 :: user1_mft7h80196@test-domain.com >> <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

2022-07-20 22:43:33 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=462 thread=2916] Proceeding TLS

2022-07-20 22:43:33 | tigase.jaxmpp.j2se.connectors.socket.SocketConnector.printLog: [scid=462 thread=2916] Start handshake

2022-07-20 22:43:33 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2022-07-20 22:43:33 |  >> <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>SCRAM-SHA-512</mechanism><mechanism>SCRAM-SHA-256</mechanism><mechanism>SCRAM-SHA-1</mechanism><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

2022-07-20 22:43:33 | user1 :: user1_mft7h80196@test-domain.com << <features xmlns="http://etherx.jabber.org/streams"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><register xmlns="http://jabber.org/features/iq-register"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>SCRAM-SHA-512</mechanism><mechanism>SCRAM-SHA-256</mechanism><mechanism>SCRAM-SHA-1</mechanism><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><ver xmlns="urn:xmpp:features:rosterver"/><sub xmlns="urn:xmpp:features:pre-approval"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></features>

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

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

2022-07-20 22:43:33 | tigase.jaxmpp.core.client.xmpp.modules.auth.SaslModule.login: Try login with SASL

2022-07-20 22:43:33 |  << <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj11c2VyMV9tZnQ3aDgwMTk2LHI9VU56dDlGRkhsNzVIRmhUdDJCdmQ=</auth>

2022-07-20 22:43:33 | user1 :: user1_mft7h80196@test-domain.com >> <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-256">biwsbj11c2VyMV9tZnQ3aDgwMTk2LHI9VU56dDlGRkhsNzVIRmhUdDJCdmQ=</auth>

2022-07-20 22:43:33 |  >> <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1VTnp0OUZGSGw3NUhGaFR0MkJ2ZDNqVmJrTHF4VnA0cGJIY0xBRGhQLHM9Ti9XdlBKZGd6K2FVTkE9PSxpPTQwOTY=</challenge>

2022-07-20 22:43:33 | user1 :: user1_mft7h80196@test-domain.com << <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">cj1VTnp0OUZGSGw3NUhGaFR0MkJ2ZDNqVmJrTHF4VnA0cGJIY0xBRGhQLHM9Ti9XdlBKZGd6K2FVTkE9PSxpPTQwOTY=</challenge>

2022-07-20 22:43:33 |  << <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9VU56dDlGRkhsNzVIRmhUdDJCdmQzalZia0xxeFZwNHBiSGNMQURoUCxwPXowNUVPbGM5ZGY4OHZvRFVmSFFJemxxNFd1NjMrVXp5MGVGR2NERWdWTzg9</response>

2022-07-20 22:43:33 | user1 :: user1_mft7h80196@test-domain.com >> <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9VU56dDlGRkhsNzVIRmhUdDJCdmQzalZia0xxeFZwNHBiSGNMQURoUCxwPXowNUVPbGM5ZGY4OHZvRFVmSFFJemxxNFd1NjMrVXp5MGVGR2NERWdWTzg9</response>

2022-07-20 22:43:33 |  >> <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj10SktKOFFmL2tTWEpoRG1QdzZZVUdVQ3FjQU9rdGNESExpR3ZobjdqNUdZPQ==</success>

2022-07-20 22:43:33 | user1 :: user1_mft7h80196@test-domain.com << <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dj10SktKOFFmL2tTWEpoRG1QdzZZVUdVQ3FjQU9rdGNESExpR3ZobjdqNUdZPQ==</success>

2022-07-20 22:43:33 | tigase.jaxmpp.core.client.xmpp.modules.StreamFeaturesModule.streamRestarted: Pipelining is disabled

2022-07-20 22:43:33 |  >> <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="v8+oP97pDn0X/TwpG7D4YlkAi2s=" xmlns="http://jabber.org/protocol/caps" hash="SHA-1" node="https://tigase.net/tigase-xmpp-server"/></features>

2022-07-20 22:43:33 | user1 :: user1_mft7h80196@test-domain.com << <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="v8+oP97pDn0X/TwpG7D4YlkAi2s=" xmlns="http://jabber.org/protocol/caps" hash="SHA-1" node="https://tigase.net/tigase-xmpp-server"/></features>

2022-07-20 22:43:33 | tigase.jaxmpp.core.client.xmpp.modules.auth.AuthModule.isAuthAvailable: saslSupportedfalse, nonSaslSupported: false

2022-07-20 22:43:33 |  << <iq xmlns="jabber:client" id="BhIm4bEkP7GLTS7GufxnT3a" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2022-07-20 22:43:33 | user1 :: user1_mft7h80196@test-domain.com >> <iq xmlns="jabber:client" id="BhIm4bEkP7GLTS7GufxnT3a" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource/></bind></iq>

2022-07-20 22:43:33 |  >> <iq xmlns="jabber:client" id="BhIm4bEkP7GLTS7GufxnT3a" to="user1_mft7h80196@test-domain.com/228467168-tigase-210" type="result"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>user1_mft7h80196@test-domain.com/228467168-tigase-210</jid></bind></iq>

2022-07-20 22:43:33 | user1 :: user1_mft7h80196@test-domain.com << <iq xmlns="jabber:client" id="BhIm4bEkP7GLTS7GufxnT3a" to="user1_mft7h80196@test-domain.com/228467168-tigase-210" type="result"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>user1_mft7h80196@test-domain.com/228467168-tigase-210</jid></bind></iq>

2022-07-20 22:43:33 | tigase.jaxmpp.j2se.Jaxmpp.onResourceBindSuccess: Connected. Resource binded.

2022-07-20 22:43:33 |  << <iq xmlns="jabber:client" id="4iJxqcramTfWhVWfW0hBv9z" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2022-07-20 22:43:33 | user1 :: user1_mft7h80196@test-domain.com/228467168-tigase-210 >> <iq xmlns="jabber:client" id="4iJxqcramTfWhVWfW0hBv9z" type="set"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>

2022-07-20 22:43:33 |  >> <iq xmlns="jabber:client" id="4iJxqcramTfWhVWfW0hBv9z" to="user1_mft7h80196@test-domain.com/228467168-tigase-210" type="result"/>

2022-07-20 22:43:33 | user1 :: user1_mft7h80196@test-domain.com/228467168-tigase-210 << <iq xmlns="jabber:client" id="4iJxqcramTfWhVWfW0hBv9z" to="user1_mft7h80196@test-domain.com/228467168-tigase-210" type="result"/>

2022-07-20 22:43:33 | tigase.jaxmpp.core.client.xmpp.modules.streammng.StreamManagementModule.enable: Enabling stream management

2022-07-20 22:43:33 |  << <iq to="test-domain.com" id="2bmM3BysXcq1vsjZ4vs2lJL" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2022-07-20 22:43:33 | user1 :: user1_mft7h80196@test-domain.com/228467168-tigase-210 >> <iq to="test-domain.com" id="2bmM3BysXcq1vsjZ4vs2lJL" type="get"><query xmlns="http://jabber.org/protocol/disco#info"/></iq>

2022-07-20 22:43:33 |  << <enable xmlns="urn:xmpp:sm:3" resume="true"/>

2022-07-20 22:43:33 | user1 :: user1_mft7h80196@test-domain.com/228467168-tigase-210 >> <enable xmlns="urn:xmpp:sm:3" resume="true"/>

2022-07-20 22:43:33 |  >> <enabled max="60" xmlns="urn:xmpp:sm:3" resume="true" id="a21e183b-7d65-4f57-8840-a482b73e5dbe" location="7c41cec37518"/>

2022-07-20 22:43:33 | user1 :: user1_mft7h80196@test-domain.com/228467168-tigase-210 << <enabled max="60" xmlns="urn:xmpp:sm:3" resume="true" id="a21e183b-7d65-4f57-8840-a482b73e5dbe" location="7c41cec37518"/>

2022-07-20 22:43:33 |  << <iq id="rdqQJBnNFHSfZk03oON3yvn" type="get"><query xmlns="jabber:iq:roster"/></iq>

2022-07-20 22:43:33 | user1 :: user1_mft7h80196@test-domain.com/228467168-tigase-210 >> <iq id="rdqQJBnNFHSfZk03oON3yvn" type="get"><query xmlns="jabber:iq:roster"/></iq>

2022-07-20 22:43:33 |  >> <iq xmlns="jabber:client" id="2bmM3BysXcq1vsjZ4vs2lJL" to="user1_mft7h80196@test-domain.com/228467168-tigase-210" from="test-domain.com" type="result"><query xmlns="http://jabber.org/protocol/disco#info"><identity name="Tigase ver. 8.3.0-SNAPSHOT-b11939/bf36c6a5" category="component" type="router"/><identity name="Tigase ver. 8.3.0-SNAPSHOT-b11939/bf36c6a5" category="server" 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="list-multi"><value>mailto:abuse@test-domain.com</value><value>xmpp:abuse@test-domain.com</value></field></x><feature var="urn:xmpp:mix:pam:2"/><feature var="urn:xmpp:carbons:2"/><feature var="urn:xmpp:carbons:rules:0"/><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:reporting:0"/><feature var="urn:xmpp:reporting:abuse:0"/><feature var="urn:xmpp:reporting:spam:0"/><feature var="urn:xmpp:reporting:1"/><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: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="tigase:push:jingle:0"/><feature var="jabber:iq:roster"/><feature var="jabber:iq:roster-dynamic"/><feature var="urn:xmpp:mam:1"/><feature var="urn:xmpp:mam:2"/><feature var="urn:xmpp:mam:2#extended"/><feature var="urn:xmpp:mix:pam:2#archive"/><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="urn:xmpp:extdisco:2"/><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>

2022-07-20 22:43:33 | user1 :: user1_mft7h80196@test-domain.com/228467168-tigase-210 << <iq xmlns="jabber:client" id="2bmM3BysXcq1vsjZ4vs2lJL" to="user1_mft7h80196@test-domain.com/228467168-tigase-210" from="test-domain.com" type="result"><query xmlns="http://jabber.org/protocol/disco#info"><identity name="Tigase ver. 8.3.0-SNAPSHOT-b11939/bf36c6a5" category="component" type="router"/><identity name="Tigase ver. 8.3.0-SNAPSHOT-b11939/bf36c6a5" category="server" 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="list-multi"><value>mailto:abuse@test-domain.com</value><value>xmpp:abuse@test-domain.com</value></field></x><feature var="urn:xmpp:mix:pam:2"/><feature var="urn:xmpp:carbons:2"/><feature var="urn:xmpp:carbons:rules:0"/><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:reporting:0"/><feature var="urn:xmpp:reporting:abuse:0"/><feature var="urn:xmpp:reporting:spam:0"/><feature var="urn:xmpp:reporting:1"/><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: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="tigase:push:jingle:0"/><feature var="jabber:iq:roster"/><feature var="jabber:iq:roster-dynamic"/><feature var="urn:xmpp:mam:1"/><feature var="urn:xmpp:mam:2"/><feature var="urn:xmpp:mam:2#extended"/><feature var="urn:xmpp:mix:pam:2#archive"/><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="urn:xmpp:extdisco:2"/><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>

2022-07-20 22:43:33 |  << <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2022-07-20 22:43:33 | user1 :: user1_mft7h80196@test-domain.com/228467168-tigase-210 >> <presence><c xmlns="http://jabber.org/protocol/caps" node="http://tigase.org/jaxmpp" ver="mg5bXbOeu1848vxdgu3jELgbQF8=" hash="sha-1"/></presence>

2022-07-20 22:43:33 |  >> <iq xmlns="jabber:client" id="rdqQJBnNFHSfZk03oON3yvn" to="user1_mft7h80196@test-domain.com/228467168-tigase-210" type="result"><query xmlns="jabber:iq:roster"/></iq>

2022-07-20 22:43:33 | user1 :: user1_mft7h80196@test-domain.com/228467168-tigase-210 << <iq xmlns="jabber:client" id="rdqQJBnNFHSfZk03oON3yvn" to="user1_mft7h80196@test-domain.com/228467168-tigase-210" type="result"><query xmlns="jabber:iq:roster"/></iq>

2022-07-20 22:43:33 | [Mutex] isItemNotified: root-6942b52a-caa1-4faa-bf82-d7c0c835eafb:exists :: false

2022-07-20 22:43:33 |  >> <presence xmlns="jabber:client" to="user1_mft7h80196@test-domain.com" from="user1_mft7h80196@test-domain.com/228467168-tigase-210"><c ver="mg5bXbOeu1848vxdgu3jELgbQF8=" xmlns="http://jabber.org/protocol/caps" hash="sha-1" node="http://tigase.org/jaxmpp"/></presence>

2022-07-20 22:43:33 | user1 :: user1_mft7h80196@test-domain.com/228467168-tigase-210 << <presence xmlns="jabber:client" to="user1_mft7h80196@test-domain.com" from="user1_mft7h80196@test-domain.com/228467168-tigase-210"><c ver="mg5bXbOeu1848vxdgu3jELgbQF8=" xmlns="http://jabber.org/protocol/caps" hash="sha-1" node="http://tigase.org/jaxmpp"/></presence>

2022-07-20 22:43:33 |  >> <message xmlns="jabber:client" to="user1_mft7h80196@test-domain.com" from="test-domain.com"><body>Wecome to 19b2ff74-bc6a-4417-9c44-154a68c698d2
This message was set at: Wed Jul 20 22:32:13 PDT 2022</body><delay stamp="2022-07-21T05:43:33.206Z" xmlns="urn:xmpp:delay" from="test-domain.com">Offline Storage - 7c41cec37518</delay></message>

2022-07-20 22:43:33 | user1 :: user1_mft7h80196@test-domain.com/228467168-tigase-210 << <message xmlns="jabber:client" to="user1_mft7h80196@test-domain.com" from="test-domain.com"><body>Wecome to 19b2ff74-bc6a-4417-9c44-154a68c698d2
This message was set at: Wed Jul 20 22:32:13 PDT 2022</body><delay stamp="2022-07-21T05:43:33.206Z" xmlns="urn:xmpp:delay" from="test-domain.com">Offline Storage - 7c41cec37518</delay></message>

2022-07-20 22:43:33 |  << <iq to="pubsub.test-domain.com" id="7cljUQRbO1pUbOKLzr1jGLU" type="set"><pubsub xmlns="http://jabber.org/protocol/pubsub"><create node="root-6942b52a-caa1-4faa-bf82-d7c0c835eafb"/><configure><x xmlns="jabber:x:data" type="submit"><field type="text-single" var="pubsub#title"><value>root-6942b52a-caa1-4faa-bf82-d7c0c835eafb</value></field><field type="text-single" var="pubsub#node_type"><value>collection</value></field></x></configure></pubsub></iq>

2022-07-20 22:43:33 | user1 :: user1_mft7h80196@test-domain.com/228467168-tigase-210 >> <iq to="pubsub.test-domain.com" id="7cljUQRbO1pUbOKLzr1jGLU" type="set"><pubsub xmlns="http://jabber.org/protocol/pubsub"><create node="root-6942b52a-caa1-4faa-bf82-d7c0c835eafb"/><configure><x xmlns="jabber:x:data" type="submit"><field type="text-single" var="pubsub#title"><value>root-6942b52a-caa1-4faa-bf82-d7c0c835eafb</value></field><field type="text-single" var="pubsub#node_type"><value>collection</value></field></x></configure></pubsub></iq>

2022-07-20 22:43:33 | [Mutex] waiting for: [root-6942b52a-caa1-4faa-bf82-d7c0c835eafb:create_node]

2022-07-20 22:43:33 |  >> <iq xmlns="jabber:client" id="7cljUQRbO1pUbOKLzr1jGLU" to="user1_mft7h80196@test-domain.com/228467168-tigase-210" from="pubsub.test-domain.com" type="error"><pubsub xmlns="http://jabber.org/protocol/pubsub"><create node="root-6942b52a-caa1-4faa-bf82-d7c0c835eafb"/><configure><x xmlns="jabber:x:data" type="submit"><field var="pubsub#title" type="text-single"><value>root-6942b52a-caa1-4faa-bf82-d7c0c835eafb</value></field><field var="pubsub#node_type" type="text-single"><value>collection</value></field></x></configure></pubsub><error code="500" type="wait"><internal-server-error xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/></error></iq>

2022-07-20 22:43:33 | user1 :: user1_mft7h80196@test-domain.com/228467168-tigase-210 << <iq xmlns="jabber:client" id="7cljUQRbO1pUbOKLzr1jGLU" to="user1_mft7h80196@test-domain.com/228467168-tigase-210" from="pubsub.test-domain.com" type="error"><pubsub xmlns="http://jabber.org/protocol/pubsub"><create node="root-6942b52a-caa1-4faa-bf82-d7c0c835eafb"/><configure><x xmlns="jabber:x:data" type="submit"><field var="pubsub#title" type="text-single"><value>root-6942b52a-caa1-4faa-bf82-d7c0c835eafb</value></field><field var="pubsub#node_type" type="text-single"><value>collection</value></field></x></configure></pubsub><error code="500" type="wait"><internal-server-error xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/></error></iq>

2022-07-20 22:43:33 | [Mutex] received everything.

2022-07-20 22:43:33 | [Mutex] isItemNotified: root-6942b52a-caa1-4faa-bf82-d7c0c835eafb:create_node:success :: false

java.lang.AssertionError: PubSub node root-6942b52a-caa1-4faa-bf82-d7c0c835eafb not created expected [true] but found [false]
org.testng.Assert.fail(Assert.java:110)
org.testng.Assert.failNotEquals(Assert.java:1413)
org.testng.Assert.assertTrue(Assert.java:56)
tigase.tests.utils.PubSubManager.createNode(PubSubManager.java:220)
tigase.tests.utils.PubSubNodeBuilder.build(PubSubNodeBuilder.java:68)
tigase.tests.pubsub.TestPubSubMAM2Extended.setUp(TestPubSubMAM2Extended.java:92)
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
java.base/java.lang.reflect.Method.invoke(Method.java:568)
org.testng.internal.invokers.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:135)
org.testng.internal.invokers.MethodInvocationHelper.invokeMethodConsideringTimeout(MethodInvocationHelper.java:65)
org.testng.internal.invokers.ConfigInvoker.invokeConfigurationMethod(ConfigInvoker.java:381)
org.testng.internal.invokers.ConfigInvoker.invokeConfigurations(ConfigInvoker.java:319)
org.testng.internal.invokers.TestMethodWorker.invokeBeforeClassMethods(TestMethodWorker.java:178)
org.testng.internal.invokers.TestMethodWorker.run(TestMethodWorker.java:122)
java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
org.testng.TestRunner.privateRun(TestRunner.java:808)
org.testng.TestRunner.run(TestRunner.java:603)
org.testng.SuiteRunner.runTest(SuiteRunner.java:429)
org.testng.SuiteRunner.runSequentially(SuiteRunner.java:423)
org.testng.SuiteRunner.privateRun(SuiteRunner.java:383)
org.testng.SuiteRunner.run(SuiteRunner.java:326)
org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52)
org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:95)
org.testng.TestNG.runSuitesSequentially(TestNG.java:1249)
org.testng.TestNG.runSuitesLocally(TestNG.java:1169)
org.testng.TestNG.runSuites(TestNG.java:1092)
org.testng.TestNG.run(TestNG.java:1060)
org.apache.maven.surefire.testng.TestNGExecutor.run(TestNGExecutor.java:283)
org.apache.maven.surefire.testng.TestNGXmlTestSuite.execute(TestNGXmlTestSuite.java:75)
org.apache.maven.surefire.testng.TestNGProvider.invoke(TestNGProvider.java:120)
org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384)
org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345)
org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126)
org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418)
 
Skipped Configuration
tigase.tests.pubsub.TestPubSubMAM2Extended
cleanUp 0.000s
setupMethod 0.000s
setupMethod 0.000s
setupMethod 0.000s
setupMethod 0.000s
setupMethod 0.000s
tearDownClass 0.000s
tearDownMethod 0.000s
tearDownMethod 0.000s
tearDownMethod 0.000s
tearDownMethod 0.000s
tearDownMethod 0.000s
Skipped Tests
tigase.tests.pubsub.TestPubSubMAM2Extended
testRetrieveWithAfterIdAndBeforeIdFromLeaf 0.000s
2022-07-20 22:43:33 |

2022-07-20 22:43:33 | null / [TestClass name=class tigase.tests.pubsub.TestPubSubMAM2Extended]

2022-07-20 22:43:33 | ------------------------------------
testRetrieveWithAfterIdFromLeaf 0.000s
2022-07-20 22:43:33 |

2022-07-20 22:43:33 | null / [TestClass name=class tigase.tests.pubsub.TestPubSubMAM2Extended]

2022-07-20 22:43:33 | ------------------------------------
testRetrieveWithLimitAndAfterFromLeaf 0.000s
2022-07-20 22:43:33 |

2022-07-20 22:43:33 | null / [TestClass name=class tigase.tests.pubsub.TestPubSubMAM2Extended]

2022-07-20 22:43:33 | ------------------------------------
testRetriveAllFromLeaf 0.000s
2022-07-20 22:43:33 |

2022-07-20 22:43:33 | null / [TestClass name=class tigase.tests.pubsub.TestPubSubMAM2Extended]

2022-07-20 22:43:33 | ------------------------------------
testSupportAdvertisement 0.001s
2022-07-20 22:43:33 |

2022-07-20 22:43:33 | Running: REST: Node and item manipulation using REST API - XML - #4229, #4728

2022-07-20 22:43:33 | ------------------------------------