Siskin beta displaying duplicated messages in MUC (#323)
Closed
wojciech.kapcia@tigase.net opened 3 years ago
[2021-12-23 09:55:30] <ij>: With current Siskin I see my own messages twice in a muc
[2021-12-23 09:56:23] <ij>: On Beagle I see it only once: 

[2021-12-23 09:57:05] <ij>: Funny enough, this doesn’t happen in this muc… 
[2021-12-23 09:57:40] <ij>: s/current Siskin/current Siskin beta/
[2021-12-23 10:56:10] <marekT3@siskin>: Current beta cross test
[2021-12-23 10:58:50] <marekT3@siskin>: > s/current Siskin/current Siskin beta/
In this public muc and in one private muc on my server (ejabberd) I don’t have duplicates. @lj
[2021-12-23 11:00:38] <Licaon_Kter>: marekT3@siskin: you're logged with multiple clients in those mucs that duplicate?
[2021-12-23 12:28:07] <ij>: @Wojtek, well, my own on xmpp.social running ejabberd
[2021-12-23 12:19:58] <Wojtek>: @ij any particular server (software-wise)?
[2021-12-23 12:30:20] <Wojtek>: do you have multiple sessions (clients)?
[2021-12-23 12:29:30] <ij>: Another user with Siskin beta has the same issue in that room
[2021-12-23 12:30:48] <ij>: yes, Siskin, Beagle, Dino
[2021-12-23 12:31:35] <Andrzej>: I suppose that maybe Message Carbons are causing some harm, but we do have that in Tigase and Siskin is working fine here
[2021-12-23 12:44:53] <ij>: Ok, it does not happen on Prosody servers, but on ejabberd servers, afaict
[2021-12-23 12:33:03] <Andrzej>: or there is some issue with origin-id not being sent (or sent back?)
[2021-12-23 12:45:10] <ij>: @Holger ping ;) 
[2021-12-23 12:49:46] <Holger>: ejabberd will never touch the origin-id, and will never carbon-copy groupchat messages.
[2021-12-23 12:50:47] <Andrzej>: then we have something weird here and we will need to look at it, but weird that it is an issue onle with ejabberd servers..
[2021-12-23 12:51:31] <Wojtek>: @ij does it happen with all ejabberd servers or only particular one (which could have some custom code)?
[2021-12-23 12:52:01] <ij>: apparently with all… tried on conversations.im as well
[2021-12-23 12:52:31] <ij>: pix-art.de and yax.im seem to be fine (both Prosody)
[2021-12-23 12:59:42] <Holger>: ij, this is about *rooms* on those servers, right?  I.e. you're affected as soon as you join a room on that server, regardless of whether your own server is Prosody or ejabberd?
[2021-12-23 13:02:05] <ij>: that’s from the ejabberDE muc on conferences.conversations.im
[2021-12-23 13:02:46] <Holger>: Yes, and when you join a room on yax.im you don't see that problem, right?
[2021-12-23 13:03:17] <Holger>: And you see it immediately, every time.  Not just when catching up from MAM after being offline, or so.
[2021-12-23 13:04:46] <Zash>: fwiw origin-id was a mistake, it was only needed on conference.jabber.org before that got migrated to Prosody
[2021-12-23 13:05:04] <Zash>: it should be safe to go back to message@id
[2021-12-23 13:13:41] <Andrzej>: Zash, if there is no origin-id then Siskin will fallback to message@id
[2021-12-23 13:14:04] <Zash>: I mean, stop sending origin-id at all
[2021-12-23 13:14:40] <Holger>: Sounds good for cleaning up old cruft, but unrelated to the problem at hand, probably ??
[2021-12-23 13:15:16] <Andrzej>: not sending origin-id would make an issue for MIX.. but it could be solved in some other way
[2021-12-23 13:16:44] <ij>: > And you see it immediately, every time.  Not just when catching up from MAM after being offline, or so.
Yes, the double message is shown instantly when sending, not from fetching MAM
[2021-12-23 22:26:25] <ij>: @Andrzej @Wojtek We did some debugging today, which was a little bit difficult, but Holger was able to do a packet capture of a session where the „message is displayed twice“ occurs… 
[2021-12-23 13:17:35] <ij>: will try to do some more debugging later (after breakfast)
[2021-12-24 12:14:30] <Wojtek>: @ij would it be possible to somehow share the capture (maybe github)? where there any conclussions (  @Holger )?
[2021-12-23 22:26:40] <ij>: Maybe we can have a look at this the other day… 
[2021-12-24 12:16:01] <ij>: @Wojtek think so… not sure about Github, but I can send you the link to download
[2021-12-24 12:17:36] <Wojtek>: > @Wojtek think so… not sure about Github, but I can send you the link to download
you can send and email (with Holger in CC) to support@tigase.net and it will be included in our private bugtracker
[2021-12-24 12:18:12] <Wojtek>: link to pastebin or somesuch would work as well I guess
[2021-12-24 12:17:47] <Wojtek>: @ij PM with details :-)
[2021-12-24 12:18:43] <ij>: @Wojtek I sent you a PM with link
[2021-12-24 12:19:55] <Wojtek>: @ij where? PM in this MUC?
[2021-12-24 12:20:56] <ij>: Conclusion was like: it’s maybe a timing issue, but it should be now up to Tigase to review and give more instructions. 
What we also discovered: 
- it’s reproducible
- it’s happening mostly shortly after restart (most reproducible)
- according to my other user it happened with 7.1 beta release
[2021-12-24 12:21:08] <ij>: @Wojtek yes, in this MUC
[2021-12-24 12:24:42] <ij>: ah, another strange thing: it seems to not happen when ejabberd is doing debug logging… hence the idea it could be timing related

siskin.log

Andrzej Wójcik (Tigase) commented 3 years ago

I've found that this weird behavior may happen if message from the server is send back very fast an Siskin IM processing of events is slow (ie. threads are busy with other tasks). This in rare situations could lead to the race condition in MUC rooms and duplicated messages. I've changed the flow by adding additional check for MUC messages just before writting a message to database (this code is synchronized on writer, so there is no way that race condition will happen again).

wojciech.kapcia@tigase.net commented 3 years ago

Seems to be fixed

issue 1 of 1
Type
Bug
Priority
Normal
Assignee
Version
7.1
Issue Votes (0)
Watchers (0)
Reference
tigase/_clients/siskin-im#323
Please wait...
Page is in error, reload to recover