Signal-desktop: Received messages are not synced properly / some are missing

[mammuth]

Maybe related to #469 and #453

I did

• sending and receiving messages with multiple contacts on Android over the day
• turn on desktop client at the evening
• notice that at least one message I received on Android does not appear on the browser client

(The incoming messages immediately before and the one after the missing one, as well as all other messages have been synced properly I think)

Logs
Desktop: https://gist.github.com/anonymous/ba7c3fea49ae2fb0998f
Android: https://gist.github.com/anonymous/42b701452c7fa7bf1bad

(For the case this makes reading the Android-log easier: When I turned on the desktop-client, noticed the missing message and took both debug logs, the missing incoming message was around 25-30 minutes old. Furthermore the missing message is one of the last incoming messages.)

This happened the first time; at the moment I have no idea how to reproduce it.

[liliakai]

Desktop received a couple sync messages with no data in them, but I'm not sure if that event matches up with anything in the Android log.

[liliakai]

What client(s) is the sender of the missing message using?

[mammuth]

The android client, probably in the latest stable release at this time.

[ghost]

My Signal-Chrome missed a message from an iOS contact the other day. This contact had sent me two messages, but only one was synced with the chrome extension.

[mawed]

I use two chrome extension and I received one picture, which appeared on one extension when syncing. On the other extension just this picture is missing.

As it did not happen today (and I did not notice it, when syncing) I can't provide useful logs.

[Genis-Sage]

https://gist.github.com/anonymous/678f91db0fdbf4bceb77f4ef1dfa6291

I closed Chromium on my Ubuntu 15.10. VM.
Seconds after, I received tweo messages from the same acccount (Iphone client).
In my Android Singal, I can see both messages, in Desktop Signal only the second.

[liliakai]

It would help to know what time were those messages sent and the last 3 digits of the sender's phone number (just to find the relevant log statements).

[nrizzio]

_Context: this discussion at the community forum_

I've had this problem happen to me recently (one time with over 250 lost messages, once 3 days ago, and again today). My Android phone sent and received a number of messages while the desktop program was off. When the desktop app came back online, each time it missed a varying number of the last messages of the conversation with a person (same person across all incidents, uses iOS).

Debug logs (3 days ago):
Android
Desktop
Debug logs (today):
Android
Desktop

[nrizzio]

Ok, maybe I'm onto something. Today I experienced the same problem, but I noticed that Signal was disabled in the extensions menu before I opened it. After opening it, all of the messages sent in the meantime disappeared. Maybe the fact that the extension was disabled is the reason all of these messages are lost? I don't have a lot of time to experiment with this, unfortunately, but could someone else attempt to reproduce this?

[liliakai]

@nrizzio Nothing anomalous in your logs, at a glance. There is a server-side limit of 1000 pending messages per device. Pending messages include incoming ones from your contacts as well as outgoing ones sent by you from a different device, plus delivery receipts and read receipts. Is it possible you're exceeding this limit?

[Trolldemorted]

@liliakai any chances of increasing that limit?

Am i understanding this correctly? Assuming you got a group with 20 members, 2 devices each. For each message you send from another device signal-desktop has to receive at least 41 messages (1 receipt for each device + the message itself), so after 26 messages the queue will be full? This would explain a lot if issues i experienced with my signal-desktop client at work which is naturally off on the weekend.

[nrizzio]

@liliakai I think I am hitting the message queue limit.

I'm part of two groups, both of which contain seven logical devices (that's counting the sum of everyone's linked devices (including mine) plus each of their phones (also including mine)). I only have one Chrome app linked to my phone. Therefore, for each message I send from my phone:

• One encrypted message queues from my phone to my Chrome app
• Five delivery receipts queue for the Chrome app (the people I talk to almost always receive my messages immediately, and therefore send delivery receipts)

For each message I receive, it adds a single pending message to my Chrome app. When I read that message, it sends yet another message to my Chrome app indicating that I have read it (read receipt).

The Chrome app will receive six pending messages per message I send from my phone. 1000/6 = 166, therefore after I send 166 messages, my Chrome app will lose messages. Additionally, receiving and reading 500 messages will also cause the Chrome app to lose messages. I'm almost certain that this is what is happening to my linked device.

---

I hate to ask for raising the pending message limit because I know it will increase the load on the Signal server(s), but I don't see any other way of alleviating the problem. Is there a way to use the Signal server API to query how many pending messages a linked device has? It would be useful to write this event to the debug log.

[Wasseranomalie]

Today after starting Signal-Desktop only one out of seven messages (sent and received) got synced (the first one in chronological order). Restarting did not solve the issue.

Signal Desktop: 0.23.2
https://gist.github.com/anonymous/185db56d70652b3b4e08924ca126ff25

[janvlug]

I noticed that I have missing messages mainly in groups. Both on Android and the desktop. Also the order of the received messages seems to be incorrect sometimes.

[janvlug]

Last week I noticed that at least two times a message that I received on my Android phone did not appear in Signal Desktop.

https://gist.github.com/38629ca98aa110e0ce64c8198cd11bbe

The missing messages should have arrived at:
2017-09-17 21:11 (not in log any more)
2017-09-23 16:45 see below for log messages around this time:

2017-09-23T09:18:45.574Z queueing envelope +[REDACTED]623.1 1506158163187
2017-09-23T09:18:45.576Z message from +[REDACTED]623.1 1506158163187
2017-09-23T09:18:45.610Z queueEnvelope error handling envelope +[REDACTED]623.1 1506158163187 : Error: Unsupported content message
at MessageReceiver.innerHandleContentMessage (chrome-extension://bikioccmkafdpakkkcpdbppfkghcmihk/js/libtextsecure.js:38736:19)
at MessageReceiver. (chrome-extension://bikioccmkafdpakkkcpdbppfkghcmihk/js/libtextsecure.js:38723:25)
at
2017-09-23T09:18:46.119Z queueing envelope +[REDACTED]623.1 1506158163897
2017-09-23T09:18:46.121Z message from +[REDACTED]623.1 1506158163897
2017-09-23T09:18:46.158Z queueEnvelope error handling envelope +[REDACTED]623.1 1506158163897 : Error: Unsupported content message
at MessageReceiver.innerHandleContentMessage (chrome-extension://bikioccmkafdpakkkcpdbppfkghcmihk/js/libtextsecure.js:38736:19)
at MessageReceiver. (chrome-extension://bikioccmkafdpakkkcpdbppfkghcmihk/js/libtextsecure.js:38723:25)
at
2017-09-23T09:18:46.638Z queueing envelope +[REDACTED]623.1 1506158164440
2017-09-23T09:18:46.641Z message from +[REDACTED]623.1 1506158164440
2017-09-23T09:18:46.669Z queueEnvelope error handling envelope +[REDACTED]623.1 1506158164440 : Error: Unsupported content message
at MessageReceiver.innerHandleContentMessage (chrome-extension://bikioccmkafdpakkkcpdbppfkghcmihk/js/libtextsecure.js:38736:19)
at MessageReceiver. (chrome-extension://bikioccmkafdpakkkcpdbppfkghcmihk/js/libtextsecure.js:38723:25)
at
2017-09-23T09:18:47.156Z queueing envelope +[REDACTED]623.1 1506158164952
2017-09-23T09:18:47.159Z message from +[REDACTED]623.1 1506158164952
2017-09-23T09:18:47.186Z queueEnvelope error handling envelope +[REDACTED]623.1 1506158164952 : Error: Unsupported content message
at MessageReceiver.innerHandleContentMessage (chrome-extension://bikioccmkafdpakkkcpdbppfkghcmihk/js/libtextsecure.js:38736:19)
at MessageReceiver. (chrome-extension://bikioccmkafdpakkkcpdbppfkghcmihk/js/libtextsecure.js:38723:25)
at
2017-09-23T09:18:47.690Z queueing envelope +[REDACTED]623.1 1506158165472
2017-09-23T09:18:47.694Z message from +[REDACTED]623.1 1506158165472
2017-09-23T09:18:47.721Z queueEnvelope error handling envelope +[REDACTED]623.1 1506158165472 : Error: Unsupported content message
at MessageReceiver.innerHandleContentMessage (chrome-extension://bikioccmkafdpakkkcpdbppfkghcmihk/js/libtextsecure.js:38736:19)
at MessageReceiver. (chrome-extension://bikioccmkafdpakkkcpdbppfkghcmihk/js/libtextsecure.js:38723:25)
at
2017-09-23T09:18:52.523Z queueing envelope +[REDACTED]623.1 1506158325063
2017-09-23T09:18:52.526Z delivery receipt from +[REDACTED]623.1 1506158325063
2017-09-23T09:18:52.559Z No message for delivery receipt +[REDACTED]623 1506158325063
2017-09-23T09:18:53.704Z queueing envelope +[REDACTED]623.1 1506158328652
2017-09-23T09:18:53.707Z delivery receipt from +[REDACTED]623.1 1506158328652
2017-09-23T09:18:53.711Z No message for delivery receipt +[REDACTED]623 1506158328652

[scottnonnenberg]

'Unsupported content message' is usually added to the log when you make or receive a Signal phone call. Desktop doesn't understand those messages. Can you tell us any more about the messages in question? Were they sent really close to each other, for example? We attempt to de-duplicate incoming messages by comparing the 'sent' timestamps of incoming messages with what we already have. In that case you should see a log entry refering to 'duplicate' messages.

[janvlug]

The messages were not sent close to each other. No notification is visible in Signal on Android about an incoming call around the time of the lost messages (though it could be that an incoming call failed, without any notifications). Unfortunately, the Signal Android logs do not go back to the time of the missing messages.

[devurandom]

There is also a message missing here. I received a voice message (no phone call, but a recorded message) on my Android phone, but it cannot be played back there. On Signal Desktop, I see this message in the logs:

queueEnvelope error handling envelope ...37 ... : Error
    at ajax (chrome-extension://bikioccmkafdpakkkcpdbppfkghcmihk/js/libtextsecure.js:37670:25)
    at TextSecureServer.<anonymous> (chrome-extension://bikioccmkafdpakkkcpdbppfkghcmihk/js/libtextsecure.js:37916:24)
    at <anonymous>

During the 3s before that message, there are 6 GET lines in the log, three of them with an additional 0 Error string at the end of the line. The next log line after the queueEnvelope error handling envelope line is dated 30s later:

queuing envelope ...47
message from ...47
read messages from ...47
read receipt ...37
No message for read receipt ...37

47 is my own number, 37 the other party.

The Signal Android log does not show anything obvious. It does not even seem to show the "Error playing audio!" error message, that is being displayed to me when pressing the play button of the broken message.

The sender is using an iPhone.

[devurandom]

I was able to solve the "Error playing audio!" error by rebooting the phone (it stopped playing any audio messages at all). The missing message did not magically show up on the desktop, though.

[devurandom]

After restarting Signal Desktop, the message magically appeared there, too.

[scottnonnenberg]

@devurandom Based on the libtextsecure.js:37916 from your provided log entries, we had trouble downloading the attachment associated with that missing message on desktop. When we tried again, it showed up! Does that match with what you saw?

[devurandom]

@scottnonnenberg That sounds very much like what I described in my previous 3 comments (sorry for the spam). First the message was missing, then I restarted the client, then it appeared. At the same time I had some audio issues on my Android phone, which might be caused by the broken message or have caused the broken message -- causality is unknown.

[il0]

I'm also having sync issues. Both Mac Desktop Standalone and Android updated to the latest version today. Some messages are not shown in Desktop, and when sending new messages from Desktop, they show in Android client as "Message encrypted for non-existing session".

[scottnonnenberg]

@il0 Please enter a new bug, and provide a debug log so we have enough information to start the investigation. Please include as much detail as you can provide - when you say things like 'when sending new messages' please be specific about which contacts if any you are messaging (or yourself).

Anyway, I'm closing this to encourage new bugs. It has collected too many tangentially-related issues.

[imdyakov]

I am also missing all threads from contacts which are not in my address book. All transactional and service messages are missing at the Mac version. I tried to disconnect the app and then connect it again with Android but that didn't help. Any messages from senders not in the contact list are missing at the computer but visible on Android.