Signal-android: Some sent group messages appear twice very briefly before first delivery mark

[AlfonsoMuskedunder]

I have:

• [x] searched open and closed issues for duplicates
• [x] read https://github.com/WhisperSystems/Signal-Android/wiki/Submitting-useful-bug-reports

---

Bug description

Sometimes, but not always, when I send a group message via Android, said message appears twice in a row for a split second. It will do so as long as the three delivery dots are jumping next to the lock icon, and the duplicate message disappears as soon as the first delivery mark appears.

Below there is a video; unfortunately the interesting part is a bit hidden under the video editor's watermark.

Screenshots

Device info

Device: Motorola Moto G 2014
Android version: 7.1.2 (Lineage)
Signal version: 4.6.0

Link to debug log

Here it is. Not the message from the screenshot! (The latter can be found here; it was sent around 15:09.)

[2-4601]

I've been having this too: https://gist.github.com/anonymous/36f1578c8d26f9ca083f4cad5e25b684 (that log seems to also contain some unrelated crash?)

[FeuRenard]

I carried out an investigation 🤓

tl;dr

cb670d6783e47f8f3c8dc187c8c26a6ee8cbad52 introduced this issue.
@moxie0 Make sure, that insertListener.onComplete() is called before notifyConversationListeners(...)

Explanation

This issue was first raised in the community forum. The problem is not reliably reproducible. This is due to the presence of a race condition. It occurs inside sendMediaMessage(...) but not inside sendTextMessage(...). Therefore the issue can only be observed if

attachmentManager.isAttachmentPresent() || !recipients.isSingleRecipient() || recipients.isGroupRecipient() || recipients.isEmailRecipient())

In other words: the race condition basically exists for media messages in single conversations and any group message. The issue can happen with these message types.

The crucial things are happening in doInBackground(...). In there is the call MessageSender.send(..., InsertListener). The listener is important here. cb670d6783e47f8f3c8dc187c8c26a6ee8cbad52 introduced, that a copy of the sent message is shown in the conversation before the message is inserted into the message database (done here). As soon as the message is inserted into the database (that's what the listener wants to "hear"), the copy should disappear from the conversation (done here).
Database insertion happens inside MessageSender.send(...) -> database.insertMessageOutbox. Now we reached the core of this issue:

long messageId = insertMediaMessage(masterSecret, addresses, message.getBody(),
                                    message.getAttachments(), contentValues);

if (insertListener != null) {
  insertListener.onComplete();
}

insertListener.onComplete() will mark the copy of the sent message to be deleted from the conversation fragment (fragment.releaseOutgoingMessage(id)). It will be deleted as soon as something happens in the message database belonging to the conversation. (ConversationFragment.onLoadFinished(...) -> changeCursor(...) -> cleanFastRecords()) onLoadFinished(...) will get triggered some time after a call to notifyConversationListeners, which happens near the end of insertMediaMessage(...). Here is the beginning of the race. The notification of the conversation listeners and the according update of the conversation (includes database queries) takes some time.

• Sometimes releaseFastRecords() (in here) will mark the message copy as deletable before the conversation update. Then the conversation update will remove the message copy and insert the message from the database. They will look exactly the same, no visible change for the user, expected behaviour.
• But sometimes the message copy will be marked as deletable after the conversation update. Then the copy of the message is visible and the message from the database. This situation will be resolved by the next conversation update, which is in most cases the sent tick (actual behaviour).