Project

General

Profile

Tigase replicates messages with Stream Management?

Natale Vinto
Added over 3 years ago

Hello,

I was posting few days ago for an issue that I could investigate better, and it looks that Tigase duplicates n-times messages if stream management is active and session is destroyed and recreated but not resumed.

In order to isolate the problem from my enviroment, I've done the test with a vanilla latest Tigase 7.1 from nightly builds and a Java XMPP client that enable stream management and also ack immediately stanzas.

Those are steps to reproduce the issue with Stream Management enabled both client and server side:

  1. Deliverer login

  2. Sender sends a message, also with Psi

  3. Deliverer got message, and also immediately request acknowledgement of received stanzas

  4. Deliverer interrupt connection without annoucing presence and destroy all client sessions

  5. Deliverer reconnect with another sessionId

  6. Deliverer got again the message after few time (60s of SM timeout?)

and this happens for any messages sent in this scenario, and for any new reconnection in that way!

I share with you client side XML with an example of a duplicate reception, based on a test from admin@domain.tld that send a message with Psi+ to foo@sub.domain.tld that is on a Java xmpp client, and here's the output:

SENT (0): <stream:stream xmlns='jabber:client' to='sub.domain.tld' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' from='foo@sub.domain.tld' xml:lang='en'>
RECV (0): <?xml version='1.0'?><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' from='sub.domain.tld' id='d60f9e41-ac0e-47ae-a344-79982e44b246' version='1.0' xml:lang='en'>
RECV (0): <stream:features><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>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><ver xmlns="urn:xmpp:features:rosterver"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></stream:features>
SENT (0): <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'></starttls>
RECV (0): <proceed xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>
SENT (0): <stream:stream xmlns='jabber:client' to='sub.domain.tld' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' from='foo@sub.domain.tld' xml:lang='en'>
RECV (0): <?xml version='1.0'?><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' from='sub.domain.tld' id='d60f9e41-ac0e-47ae-a344-79982e44b246' version='1.0' xml:lang='en'>
RECV (0): <
RECV (0): stream:features><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>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><ver xmlns="urn:xmpp:features:rosterver"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression></stream:features>
SENT (0): <auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='PLAIN'>AGZvbwBmb28=</auth>
RECV (0): <
RECV (0): success xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/>
SENT (0): <stream:stream xmlns='jabber:client' to='sub.domain.tld' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' from='foo@sub.domain.tld' id='d60f9e41-ac0e-47ae-a344-79982e44b246' xml:lang='en'>
RECV (0): <
RECV (0): ?xml version='1.0'?><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' from='sub.domain.tld' id='d60f9e41-ac0e-47ae-a344-79982e44b246' version='1.0' xml:lang='en'>
RECV (0): <
RECV (0): stream:features><sm xmlns="urn:xmpp:sm:3"/><register xmlns="http://jabber.org/features/iq-register"/><ver xmlns="urn:xmpp:features:rosterver"/><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"/></stream:features>
SENT (0): <compress xmlns='http://jabber.org/protocol/compress'><method>zlib</method></compress>
RECV (0): <
RECV (0): compressed xmlns="http://jabber.org/protocol/compress"/>
SENT (0): <stream:stream xmlns='jabber:client' to='sub.domain.tld' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' from='foo@sub.domain.tld' id='d60f9e41-ac0e-47ae-a344-79982e44b246' xml:lang='en'>
RECV (0): <?xml version='1.0'?><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' from='sub.domain.tld' id='d60f9e41-ac0e-47ae-a344-79982e44b246' version='1.0' xml:lang='en'>
RECV (0): <stream:features><sm xmlns="urn:xmpp:sm:3"/><register xmlns="http://jabber.org/features/iq-register"/><ver xmlns="urn:xmpp:features:rosterver"/><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></stream:features>
SENT (0): <iq id='55gzJ-3' type='set'><bind xmlns='urn:ietf:params:xml:ns:xmpp-bind'><resource>Smack</resource></bind></iq>
RECV (0): <iq type="result" id="55gzJ-3" xmlns="jabber:client" to="foo@sub.domain.tld/Smack"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>foo@sub.domain.tld/Smack</jid></bind></iq>
SENT (0): <iq id='55gzJ-5' type='set'><session xmlns='urn:ietf:params:xml:ns:xmpp-session'/></iq>
RECV (0): <iq type="result" id="55gzJ-5" xmlns="jabber:client" to="foo@sub.domain.tld/Smack"/>
SENT (0): <enable xmlns='urn:xmpp:sm:3' resume='true'/>
RECV (0): <enabled xmlns='urn:xmpp:sm:3' id='13850a96-f1b2-47fb-a095-6cf1d1e144ad' resume='true' max='60' location='domain.tld' />
SENT (0): <iq id='55gzJ-7' type='get'><query xmlns='jabber:iq:roster'></query></iq>
SENT (0): <presence id='55gzJ-8'><c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='http://www.igniterealtime.org/projects/smack' ver='NfJ3flI83zSdUDzCEICtbypursw='/></presence>
SENT (0): <presence to='admin@domain.tld/iMac-di-bluesman' id='55gzJ-9' type='subscribed'><c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='http://www.igniterealtime.org/projects/smack' ver='NfJ3flI83zSdUDzCEICtbypursw='/></presence>
RECV (0): <iq type="result" id="55gzJ-7" xmlns="jabber:client" to="foo@sub.domain.tld/Smack"><query xmlns="jabber:iq:roster"><item jid="admin@domain.tld" subscription="from" name="admin"/></query></iq>
RECV (0): <presence xmlns="jabber:client" id="55gzJ-8" to="foo@sub.domain.tld" from="foo@sub.domain.tld/Smack"><c xmlns="http://jabber.org/protocol/caps" node="http://www.igniterealtime.org/projects/smack" hash="sha-1" ver="NfJ3flI83zSdUDzCEICtbypursw="/></presence>
RECV (0): <message type="normal" xmlns="jabber:client" id="q1Q19-14" to="foo@sub.domain.tld/Smack" from="admin@domain.tld/iMac-di-bluesman">
<body>TEST</body><request xmlns="urn:xmpp:receipts"/><delay stamp="2015-07-28T14:04:40.182Z" xmlns="urn:xmpp:delay" from="sub.domain.tld"/></message>
SENT (0): <message to='admin@domain.tld/iMac-di-bluesman' id='55gzJ-13' type='normal'><received xmlns='urn:xmpp:receipts' id='q1Q19-14'/></message>
SENT (0): <r xmlns='urn:xmpp:sm:3'/>
RECV (0): <a xmlns='urn:xmpp:sm:3' h='4'/>

as you can see, a is immediately done getting the h='4' count of 3 presence stanza and 1 message reply, should the sender also ask for stanza acking in order to trigger tigase stanzas conciliation and let know it that it really sent the message?

Because it looks it doesn't know that it send the message due nexts enable/enabled, while if a resume come then no duplication happens.

Here also Tigase logs attached, and init.properties I've used:

--virt-hosts=domain.tld, sub.domain.tld
--admins=admin@domain.tld
--debug=server,db,xmpp,xmpp.impl,server.xmppclient
--user-db-uri=jdbc:derby:tigasedb;create=true
--sm-plugins=+amp
--comp-name-3=http
--comp-class-3=tigase.http.HttpMessageReceiver
c2s/processors[s]=urn:xmpp:sm:3

Hope you can help me to understand, because I got all messages duplicated

Thanks


Replies (5)

Added by Daniele Ricci over 3 years ago

I'd like to add that it might (and I stress might) be related to the changeset linked to https://projects.tigase.org/issues/2596

Added by Natale Vinto over 3 years ago

Hi Daniele,

but the problem persist on Tigase 7.0.2 also, with the same test, the only difference that I noticed is that duplicated messages are not delivered with tag as in Tigase 7.1.0 case shown before, they arrive identically as they were sent

Added by Andrzej Wójcik IoT 1 CloudTigaseTeam over 3 years ago

I checked logs of Tigase XMPP Server and current behavior is correct according to XEP-0198, as XMPP client never confirmed using stanza that it received this packets/messages. Until messages are confirmed to be received they are marked as not delivered on server side. So when disconnection happens in this state messages after resumption time are resent once again to client - this is source of message duplication.

Normally XMPP clients do not confirm that each message is received due to performance reasons. Our Jaxmpp2 library confirms delivery when it receives each 10 stanzas.

This is not related to #2596 as messages are sent to full jid and #2596 is related only to messages sent to bare jid.

Added by Daniele Ricci over 3 years ago

Ok I see what is happening here. The only case that is not specified in the XEP is graceful disconnection. The server is not required to send an at the end of the stream right? That's because the client should then reply with an , but since the stream was already closed is not possible. So the only solution here is the client sending the right before closing the stream, right?

Added by Andrzej Wójcik IoT 1 CloudTigaseTeam over 3 years ago

Almost. It is possible to correctly close stream using /stream:stream which will mark all packets as received.

However in this case connection is broken.

    (1-5/5)