Signal-desktop: messages out of order

[dgobaud]

Bug description

was chatting on mobile then open desktop app and messages show up out of order

Steps to reproduce

1. chat on ios mobile

2. open desktop app after chat

Actual result:

order of messages on desktop different than actual conversation and the messages were not super close together in time so it shouldn't be some "same time" issue

Expected result:

desktop message display order matches real order and order shown on ios

Screenshots

desktop - wrong order

ios - correct order where chat happened. last 4 messages

Platform info

Signal version:

1.11.0

Operating System:

osx

Linked device version:

Link to debug log

desktop
https://debuglogs.org/03fa13400a56d08ba585e0771e76d4c639d1e9cef7522ebbe2557b05bc68d00e

ios
https://debuglogs.org/fe78834c9bdaceec0101a3e2ab192f47f46204c4482e308e2ef5067d93c8d4ac.zip

[scode]

I can confirm having seen what sounds the same. I'm unsure if I was on Linux or MacOS at the time, but I had conversations load up completely scrambled. As in this report, there was significant time between messages and they appeared effectively random in order. I had to look at my phone as the point of authority to have an idea what the other party was actually saying.

I remember restarting the client but it did not work.

On the same day I also had a case where one message received was simply "missing" on the desktop client despite restarting it.

[amosshapira]

This is happening to me when opening (or switching to) Signal on MacOS after conversing on Android.

[Ulyssys]

Also experiencing the same issue using the Android client and the Signal Desktop for Windows client.

[IvanTrendafilov]

+1, Signal on OS X and Android

[tuxayo]

Same on Linux so not platform specific it seems.

And restarting the program doesn't fix the order. (it could have if we were lucky ^^")

[scottnonnenberg-signal]

One thing to watch for is specifically when this happens. There seems to be a correlation between this out-of-order behavior and reconnections. So if you have Signal running and close your laptop then come back, you can end up with messages out of order. But if you had it closed and start up after opening your laptop, it would be in order. I'd love to know if that matches what you're seeing.

[Trolldemorted]

@scottnonnenberg-signal the reordering issue identified almost a year ago does not correlate with reconnections only, but also with normal connections (aka app starts).

Is there another issue that happens only with reconnects?

[scottnonnenberg-signal]

@Trolldemorted I encourage you to try it, see if it repros for you. :0)

[Trolldemorted]

I don't have any Signal-Desktop slaves at the moment, but all of my slaves are hit by severe reorderings as well (I assumed it was due to #1826). You spoke specifically of reconnects - do you assume there is a Signal-Desktop specific bug that is related to its reconnects?

And can you estimate when #1826 will be fixed? It is hard to know whether you are hit by #1826 or a different bug, so if you would address that one tracking down remaining ones will become much easier :)

[scottnonnenberg-signal]

@Trolldemorted No, I suspect that reconnect is causing another server bug, not a Desktop bug.

Regarding #1826, it's pretty easy to rule that out. If you know you got no other new messages during the test period, then that issue, 'queue-jumping,' isn't the problem. As for when it will be fixed, we're hiring in server roles: https://signal.org/workworkwork/#server

[Trolldemorted]

Are you sure this is related to reconnects? From the server's perspective, a reconnect and a new start do look the same, don't they?

Ruling that out during tests is easy indeed, but that doesn't help too much with bug reports from normal users. I encounter reordered messages frequently (they are polled with short-lived background tasks), but I assumed that it was still the queue jumping issue, just blurred by more caching on the server.

If you are certain that no server changes could have caused messages that were sent in the "near past" to be sent to a connecting client using the "queue-jumping" method, we are indeed facing another issue here (that imo occurs if the ws connection is closed before the queue was drained) :(

I really would have applied, but unfortunately you are considering US-based employees only. Would you merge PRs from the community, or appreciate help in tracking down the server issues? I really hope you find someone soon, the frequent reordering and dropping of messages are really bad for signal's reputation.

[Dyras]

This has happened for me at least twice now.

https://debuglogs.org/c7e46c6128643a796b30f22682ac9f6e5aab6c525de41b07b04330dc0cf02127
Message 1533204513381 appears before messages 1533169376442 and 1533205258960 even if it should appear after them.

[scottnonnenberg-signal]

I made some changes in the last few beta builds that should make this better. Please let me know how things go on v1.15.0-beta.9 or higher. Thanks!

[philkunz]

Still happening with 1.18.0

[scottnonnenberg-signal]

@philkunz You haven't previously commented above. What is still happening, exactly? Please describe exactly what you're seeing, ideally with message 'sent id' values for the out-of-order messages (from the Message details screen) and a full debug log.

[bbhopesh]

I can confirm that this happens between Linux on desktop and ios on phone.

[filikun]

Same issue here, deleting the conversation on Linux client is the only solution I've found.

Ubuntu 18.04.1 LTS
Signal version 1.21.0

[cdenyar]

I noticed this today. I had my laptop and Signal client open for a period without issue, but then noticed the issue started occurring. I updated the group avatar, and both desktop and android properly showed the note about the group updating, then without going offline the conversation continued and I observed messages were appearing out of order, including messages I sent from the desktop client.

Screenshots:
Desktop, wrong order:

Desktop message info for each sent/received message (in order they appear on the desktop client):

Android, correct order:

Desktop logs:
https://debuglogs.org/7a336ce42d104656d51cac7163c48bca102bb261f7cb134d37aed1dc47364148

Android logs:
https://debuglogs.org/65b5527f46023c93c0a015b9a752b002f6627723a74ede6f30d18daca272e3a2

[adioe3]

It seems Signal is using Time Received instead of Time Sent to sort messages which IMHO is incorrect? I believe time received is device-specific whereas sent is message-specific?

[scottnonnenberg-signal]

@adioe3 You're right. We don't trust the sent time provided by sending clients. We only trust the order that we received the message in.

[adioe3]

@scottnonnenberg-signal are the messages fetched in FIFO or FILO ordering? Maybe that's the cause of the bug?

[scottnonnenberg-signal]

It's FIFO queue, very clearly. Messages appear in order most of the time after all!

[scode]

I don't know anything about the code base or internal design, but if the order is based on the time of receipt, is it possible this is caused by transport level problems? For example, is it possible the client somehow ends up with multiple outstanding long polls (or some equivalent) that may result in duplicate delivery from competing background tasks with different times? (For example, a retry is attempted on timeout without synchronizing with the timed out task to ensure it is stopped prior to determining what the most recently received message is.)

[LogicalDash]

This happened to me with a particularly long time-lag -- messages from last week appearing after messages sent right now.

Last message I received:

Sent | Sunday, March 31, 2019 10:39 AM (1554043167016)
-- | --
Received | Sunday, March 31, 2019 10:39 AM (1554043170890)

Last message I sent:

Sent | Sunday, March 31, 2019 10:40 AM (1554043216271)
-- | --
Received | Sunday, March 31, 2019 10:40 AM (1554043216271)

The message from March 24:

Sent | Sunday, March 24, 2019 10:35 AM (1553438102872)
-- | --
Received | Sunday, March 31, 2019 2:16 PM (1554056216572)

[darrellenns]

@scottnonnenberg-signal What are your thoughts on adding a client option to sort by sent date as a workaround until the root cause can be fixed? Even if it's off by default or hidden away in a CLI option/config file, it would at least give users suffering from this issue a stopgap option.

[fynnay]

I'm also experiencing this issue on Windows 10 with Signal Desktop _v1.27.3_ .

Messages don't get reordered correctly after restarting the app.

[scottnonnenberg-signal]

@fynnay More details on exactly how messages are out of order would really help. How many total? Looks like it's just one message in that screenshot? How many conversations did this happen in?

[fynnay]

@scottnonnenberg-signal So far it only happened with this one message. When I received it on my phone I afterwards opened the Desktop app, where the new message appeared to be missing although it had only been inserted further up in the conversation.

[adioe3]

I keep getting this all the time. The messages get sorted by time received instead of time sent. Time sent is always correct but time received seems to be shuffled around. Looks like some kind of ring buffer wraparound bug or something.

[rainerzufall]

It just happened to me. I will try to give as much data points as possible to help you get to the bottom of this.

First a screenshot of the miss-ordered message:

What happened:

• writing a signal message from one of my three windows desktop apps (from the beta app in this case; I call it B hereafter). Two instances are on my private laptop; one beta (B) and one stable instance S The work laptop app (W) is still offline.
• restarting S did not change the order there.

Speculation:

• It could be related to start up of S. I am not completely sure if I have sent the message from B during or short after starting S.

Things that are weird:

• today is Friday noon and the miss-ordered message has been ordered to Wednesday evening. So it is quite a bit off. ~60messages off.
• Left pane and conversation have different time stamps. Which is coincidentally also the difference between received and sent time on S - see below.

Here the timestamps as well as the individual number of the message from the message detail screen:

• on B were the message was written:

Sent | Freitag, 25. Oktober 2019 13:07 (1572001657763)
-- | --
Received | Freitag, 25. Oktober 2019 13:07 (1572001657763)

plus the debug log from B: https://debuglogs.org/59cf06f7fb4f545e99c70c1a210f71ab2bd312be4634d479bfd79b7a4b6549f6

• on S where the message was miss-ordered:

Sent | Freitag, 25. Oktober 2019 13:07 (1572001657763)
-- | --
Received | Freitag, 25. Oktober 2019 13:09 (1572001761794)

plus the debug log from S: https://debuglogs.org/bcd5bc6efc05c93d51138fe90918d9bc858df27e6ed5b1e055377a5635e4c9e9

Android A which received the message correctly ordered:
screenshot:

log from A:
https://debuglogs.org/2be86c1d037fafebe43fd216008991ee488b9f77fdef4f84c1a7e9f7b00ce67f

questions:

• what additional information could I provide?
• would another log from W help?

[scottnonnenberg-signal]

@rainerzufall Your scenario fits the pattern: loading a lot of messages at once, and some very recent messages are sorted older than they should be. We believe this to be a server issue; messages can jump the queue while Desktop is downloading older messages. This causes problems because, as always, Desktop sorts in the order it receives messages from the server.

You can help us verify this by providing messages that should go right before or after the out-of-order messages, as well as the messages that actually were before or after.

[rainerzufall]

"messages that should go right before or after the out-of-order messages" aka correctly ordered thread:

• 10 correctly ordered messages on B before the out-of-order message on S [written on A]:

Gesendet | Donnerstag, 24. Oktober 2019 20:40 (1571942451957)
-- | --
Empfangen | Freitag, 25. Oktober 2019 12:52 (1572000774448)

Gesendet | Donnerstag, 24. Oktober 2019 20:44 (1571942642533)
-- | --
Empfangen | Freitag, 25. Oktober 2019 12:52 (1572000774979)

Gesendet | Donnerstag, 24. Oktober 2019 20:44 (1571942651655)
-- | --
Empfangen | Freitag, 25. Oktober 2019 12:52 (1572000774983)

Gesendet | Donnerstag, 24. Oktober 2019 20:44 (1571942660687)
-- | --
Empfangen | Freitag, 25. Oktober 2019 12:52 (1572000775067)

Gesendet | Donnerstag, 24. Oktober 2019 20:45 (1571942736058)
-- | --
Empfangen | Freitag, 25. Oktober 2019 12:52 (1572000775238)

Gesendet | Freitag, 25. Oktober 2019 09:14 (1571987675477)
-- | --
Empfangen | Freitag, 25. Oktober 2019 12:52 (1572000776093)

Gesendet | Freitag, 25. Oktober 2019 11:53 (1571997203879)
-- | --
Empfangen | Freitag, 25. Oktober 2019 12:52 (1572000778669)

Gesendet | Freitag, 25. Oktober 2019 11:53 (1571997228674)
-- | --
Empfangen | Freitag, 25. Oktober 2019 12:52 (1572000778680)

Gesendet | Freitag, 25. Oktober 2019 11:55 (1571997322347)
-- | --
Empfangen | Freitag, 25. Oktober 2019 12:52 (1572000778736)

Gesendet | Freitag, 25. Oktober 2019 12:01 (1571997667768)
-- | --
Empfangen | Freitag, 25. Oktober 2019 12:52 (1572000778754)

• the correctly ordered message onB which is out-of-order on S [written on B]:

Gesendet | Freitag, 25. Oktober 2019 13:07 (1572001657763)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:07 (1572001657763)

• 10 correctly ordered messages on B after out-of-order message on S [not 100% sure on which device they were written]:

Gesendet | Freitag, 25. Oktober 2019 13:16 (1572002193951)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:16 (1572002198355)

Gesendet | Freitag, 25. Oktober 2019 13:18 (1572002282301)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:18 (1572002286594)

Gesendet | Freitag, 25. Oktober 2019 13:18 (1572002292164)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:18 (1572002296571)

Gesendet | Freitag, 25. Oktober 2019 13:19 (1572002348459)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:19 (1572002349394)

Gesendet | Freitag, 25. Oktober 2019 13:19 (1572002364358)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:19 (1572002368254)

Gesendet | Freitag, 25. Oktober 2019 13:19 (1572002369405)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:19 (1572002373377)

Gesendet | Freitag, 25. Oktober 2019 13:19 (1572002393130)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:19 (1572002397116)

Gesendet | Freitag, 25. Oktober 2019 13:20 (1572002418212)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:20 (1572002422221)

Gesendet | Freitag, 25. Oktober 2019 13:21 (1572002484371)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:21 (1572002485373)

Gesendet | Freitag, 25. Oktober 2019 13:21 (1572002489286)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:21 (1572002490144)

• I verified the order on B with A

---

"the messages that actually were before or after" the out-of-order message

• 10 messages on S before the out-of-order message:

Gesendet | Mittwoch, 23. Oktober 2019 15:36 (1571837811682)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:09 (1572001753790)

Gesendet | Mittwoch, 23. Oktober 2019 15:44 (1571838273579)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:09 (1572001754240)

Gesendet | Mittwoch, 23. Oktober 2019 15:44 (1571838284472)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:09 (1572001754469)

Gesendet | Mittwoch, 23. Oktober 2019 15:47 (1571838461297)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:09 (1572001754847)

Gesendet | Mittwoch, 23. Oktober 2019 16:07 (1571839650022)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:09 (1572001755350)

Gesendet | Mittwoch, 23. Oktober 2019 16:25 (1571840700275)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:09 (1572001755659)

Gesendet | Mittwoch, 23. Oktober 2019 16:25 (1571840701851)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:09 (1572001755841)

Gesendet | Mittwoch, 23. Oktober 2019 17:19 (1571843971908)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:09 (1572001756833)

Gesendet | Mittwoch, 23. Oktober 2019 17:25 (1571844340099)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:09 (1572001757362)

Gesendet | Mittwoch, 23. Oktober 2019 18:34 (1571848446367)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:09 (1572001757725)

• the out-of-order message onS:

Gesendet | Freitag, 25. Oktober 2019 13:07 (1572001657763)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:09 (1572001761794)

• 10 messages on S after the out-of-order message:

Gesendet | Mittwoch, 23. Oktober 2019 20:44 (1571856296094)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:09 (1572001766815)

Gesendet | Mittwoch, 23. Oktober 2019 21:47 (1571860068289)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:09 (1572001767488)

Gesendet | Mittwoch, 23. Oktober 2019 21:50 (1571860222487)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:09 (1572001767830)

Gesendet | Mittwoch, 23. Oktober 2019 21:52 (1571860363253)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:09 (1572001768075)

Gesendet | Mittwoch, 23. Oktober 2019 21:52 (1571860374101)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:09 (1572001768154)

Gesendet | Mittwoch, 23. Oktober 2019 21:53 (1571860391081)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:09 (1572001768319)

Gesendet | Mittwoch, 23. Oktober 2019 21:53 (1571860415620)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:09 (1572001768420)

Gesendet | Donnerstag, 24. Oktober 2019 00:06 (1571868415939)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:09 (1572001769923)

Gesendet | Donnerstag, 24. Oktober 2019 00:07 (1571868437210)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:09 (1572001770146)

Gesendet | Donnerstag, 24. Oktober 2019 00:07 (1571868451182)
-- | --
Empfangen | Freitag, 25. Oktober 2019 13:09 (1572001770412)

---

- just from the time stamps it seems to confirm the theory that the out-of-order message did jump the queue.

if needed new logs from B for the messages after the out-of-order message:
https://debuglogs.org/566cf092614f215931f37c94b144bd6de6482a113f7b62701966f0a1e08aa17d
and from S:
https://debuglogs.org/044ab5f6937889a185f084e79ef78a337c5cdee8ae300f3b9057ec9301a0a20d

[scottnonnenberg-signal]

@rainerzufall Thanks for that additional information. This still fits the scenario I described earlier:

INFO  2019-10-25T11:09:07.397Z queueing envelope +[REDACTED]453.6 1572001657763 (005a895c-6863-4c1e-ac12-be7f1ab30153)
INFO  2019-10-25T11:09:09.914Z message from +[REDACTED]453.6 1572001657763 (005a895c-6863-4c1e-ac12-be7f1ab30153)
INFO  2019-10-25T11:09:10.034Z sent message to +[REDACTED]442 1572001657763 from +[REDACTED]453.6 1572001657763 (005a895c-6863-4c1e-ac12-be7f1ab30153)
INFO  2019-10-25T11:09:21.817Z Starting handleDataMessage for message +[REDACTED]453.6 1572001657763 in conversation +[REDACTED]442
--- this is the message that should go before 1572001657763, queued 27 seconds afterwards
INFO  2019-10-25T11:09:34.026Z queueing envelope 31c666ca-efa5-4d5c-80ad-b59d2577cb6a
INFO  2019-10-25T11:09:41.688Z data message from +[REDACTED]442.1 1571997667768 (31c666ca-efa5-4d5c-80ad-b59d2577cb6a)
INFO  2019-10-25T11:09:50.056Z Starting handleDataMessage for message +[REDACTED]442.1 1571997667768 in conversation

[denisbider]

The fact this is still open after 1.5 years, and new instances of the issue are being resolved as duplicates, makes me concerned this bug is being treated as if this is "operating as intended". Such a development mindset would certainly discourage me from further recommending Signal...

[jlindgren90]

@rainerzufall Your scenario fits the pattern: loading a lot of messages at once, and some very recent messages are sorted older than they should be. We believe this to be a server issue; messages can jump the queue while Desktop is downloading older messages. This causes problems because, as always, Desktop sorts in the order it receives messages from the server.

@scottnonnenberg-signal This definitely happened to me just now, I had two new messages received while the desktop client was loading ~400 messages from the past two weeks, and the new ones got mixed in with the old ones in the wrong order.

The symptoms of the bug seem pretty clear. What's holding up a fix at this point? The messages all have timestamps, so it doesn't seem like it should be difficult for the desktop client to display them in chronological order.

[djdadspins]

I just started having this problem. On Android it appears to be in order but on desktop newer messages are moving up a conversation or two. Has there been any progress on fixing this?

[kaktusztea]

I had this again.

It was a group chat message with 10 members. The message was misplaced in the past (8 hours before) on Win Desktop receiver side. On iOS mobile side the order was OK.

Phone numbers
Sender: xxx377
Receiver: xxx759

Versions, logs
Receiver: iOS 3.8.2.7
https://debuglogs.org/71e581cb9bad6e0f476be20fac5ebbd20af501461d31b08d3814b14155b4ad88.zip

Receiver Desktop app (Windows, 1.33.4)
https://debuglogs.org/17fd68b89c281c78d9096845bd0ef80dc129ff31a9035a05d9cb3470a6076c63

Sender: from Win Desktop (linked with Android mobile device)

• Desktop: v1.33.4 (Win)
• Android: 4.58.5
• Desktop debug log:
  https://debuglogs.org/029b55f68b3e80f9f69fd2b09e8d3ed7c62441106ee79db0d4b84b624b4e036a
• Android debug log: he was unable to submit it, he got an error message every time ("Could not send the log" or something).

Timestamps
Sent: 1588775949760
Received: 1588776219324

Log snippet

2020/05/06 16:39:11:494  💛 [OWSMessageDecrypter.m:203 -[OWSMessageDecrypter decryptEnvelope:envelopeData:successBlock:failureBlock:]]: decrypting envelope: <Envelope type: UnidentifiedSender, source: (null).0, timestamp: 1588775949760 content.length: 549 />
2020/05/06 16:39:11:497  [SessionCipher] [ REDACTED_PHONE_NUMBER:xxx377 ].2 creating new chains.
2020/05/06 16:39:11:498  [SessionState] Trimming excessive receivingChain count: 6
2

What is interesting
The misplaced message was _8_ minutes old when I opened the conversation and looked at it. The message was placed directly after an another normal (but old) message that was 8 _hours_ old. I don't know is this relevant, maybe just coincidence.

message old1: "blah blah" - 8 hours ago
message new-misplaced: "woof woof" - 8 minutes ago
message old2: "hello world" - 8 hours ago

[scottnonnenberg-signal]

The known 'out-of-order' scenario is that Desktop, when downloading a lot of messages, can have a new message jump the queue. It looks like a couple of your newest messages nestled among old messages.

Here's my previous mention of that scenario: https://github.com/signalapp/Signal-Desktop/issues/2424#issuecomment-546509787

You can help us by telling us when your scenario seems to match what I've described, and when it doesn't.

[kaktusztea]

Hi @scottnonnenberg-signal,

All right here are the preceding and the following messages at the RIGHT PLACE:

Message _before_ the problematic one
Sender: xxx270
Sent: 1588775730730
Received: 1588794113060

Message _after_ the problematic one
Sender: xxx270 (same person as "before" message above)
Sent: 1588778934460
Received: 1588794115505

---

And here are the preceding and the following messages at the WRONG PLACE (in the past):
Message _before_ the problematic one
Number: xxx164
Sent: 1588705197587
Received: 1588776218837

Message _after_ the problematic one
Number: xxx377
Sent: 1588746567030
Received: 1588776220006

[harikrishnasdp-n]

Same problem...

Debug Log Mac OS: https://debuglogs.org/30d9a5ddb02ff35b61bc98726db5fc13e5ce2d1ba87c0f4f12f98f53da074ead
Debug Log iOS:
https://debuglogs.org/f981f44f1b67f1d07a7c8c5ea4fcd81bc61e2fb97e9e336ac4805b0ec9bfd983.zip

[kaktusztea]

I was just thinking yesterday: could it be a timezone issue maybe?
And maybe is it so hard to reproduce it for developers because they all are in the US...?

[denisbider]

@kaktusztea - I live in the US, both phone and computer are in the same time zone, I've had this issue happen just like that.

As far as I can tell, the developers seem to be ignoring this as "by design", while they add support for annoying stickers.

Oh, and don't even get me started on forcing the user to choose a PIN, and then making you verify the PIN to make sure you remember it. The developers appear to be out of touch with the users.

[amosshapira]

Oh, and don't even get me started on forcing the user to choose a PIN, and then making you verify the PIN to make sure you remember it. The developers appear to be out of touch with the users.

While we are bitching - I just discovered that Signal on iPhone is the only messaging app among the ones my partner uses (vs. Signal, WhatsApp) that won't allow her to take her messages with her to a new phone number on another phone...

[scottnonnenberg-signal]

@amosshapira https://signal.org/blog/ios-device-transfer/

[beatschubser]

I have the same issue on multiple devices. Wrong order of messages is an absolute deal breaker for a chat app. This and the ridiculous time it takes to load the chat history even on high end mobile devices.

[scottnonnenberg-signal]

@beatschubser Have you reported your mobile performance issues? I'm sure the iOS or Android team would appreciate hearing about your scenario.

[danafton]

Using latest version of Windows and android apps, I just had a message show up out of sync. Message from an hour ago is showing up in between messages from 9 hours ago.

[itkfm]

Happened here today.
https://debuglogs.org/05c7c13f90e9964c8236a896df0b20091684c944859925eebf47e7626dd6bb4b

[strybe]

The problem with messages in wrong time order happens regularly for me. At first I thought some messages are missing, only to discover they are inserted somewhere earlier. Time varies, but it's not always just few minutes. This makes reading an conversation unpleasant and the meaning get's distorted.

If it's no easy fix please provide an option to order by time sent.
The argument of overseen messages, that are inserted way back in the timeline might be solved by an indicator of unread messages (and possibility to jump to).

[scottnonnenberg-signal]

@strybe The more you can tell us about these scenarios, and in particular the situations surrounding the sends of those messages, the better. And of course a debug log with the 'sent id' of the messages (the number next to the 'sent' header in the message details screen). We can only make progress if we have information we can use to fuel the investigation.

[beatschubser]

@scottnonnenberg It is very easy to reproduce. Just make sure the Android-app is closed and doesn't run in background for a while. Then when you open the Android app again it starts loading the messages that have been sent from other devices since it was last opened. While the app is loading them very slowly, send a new message in the app. It will be displayed in the chat history whereever the loading of the old messages is when you send the new message. It will never appear correctly as the newest message, even after closing and re-opening the app.

[scottnonnenberg-signal]

@beatschubser Yes, that is a known scenario - sending messages while downloading other messages. And I don't believe we have any plans to address it, because from the app's perspective things are happening in that order.

The scenario @strybe describes doesn't seem to involve sending messages in the middle of a download like that.

[denisbider]

And I don't believe we have any plans to address it, because from the app's perspective things are happening in that order.

"It's not a bug, it's a feature." 🤦‍♂️

[denisbider]

When developers think that behaviors which are CLEARLY BUGS from the user's perspective are actually features because the behaviors follow some sacred and occult principle, then this sacred and occult principle is the actual bug. To fix such a bug, the developers involved in the denial must first debug their brains.

[scottnonnenberg-signal]

@denisbider You appear to be quite angry about this, but I'm going to try to continue this conversation in good faith. Please consider: people very much hate it when their conversation timeline changes order after initially put in place. What do you propose?

Also, how often are you sending message while downloading a large amount of other messages? Perhaps we are off in our expectations, since we believe that to be relatively rare.

[beatschubser]

@scottnonnenberg Why would people want to "put their timeline in place"? Chats are always ordered by date, nothing else makes sense.

When I don't use the Android app for a while it can take 20 minutes until all the recent messages are loaded (on a high end phone). I'm not exaggerating. Often I just want to share a picture from my phone, and I'm not going to wait that long.

I have never seen a chat app that does not/can not sort messages by timestamp. It is one of the most basic features of a communication tool. And although I wouldn't insult people over this, I understand that @denisbider is shocked that you guys don't seem to care much about it, even it it's not reported by a lot of people.

[scottnonnenberg-signal]

This has been discussed elsewhere in this repo before, but I'll say it again. Signal is a security-focused application. It's not that we're not listening to user feedback. It's that we cannot trust the timestamps given to us by sender devices. We must trust the server, and therefore the order the server gives us the messages in.

Your feedback is certainly heard. We haven't considered making any changes in this space for a long time, but the more voices we hear, the more you tell us about your usage patterns, the more specific scenarios you mention (remember we don't have analytics), the better we'll be able to make decisions.

[denisbider]

@scottnonnenberg-signal - if your current principles lead you to the conclusion that the current design is OK, then you are missing additional principles which could be incorporated into the design in a way that would address this issue, without compromising on the security.

If you think this is a tradeoff of security vs. usability, it is not. It is a failure to find a solution that properly addresses both aspects.

[adioe3]

I agree with @denisbider , if the issue is that the sender timestamp cannot be trusted, what can be done to make it trusted? If I already have an established session with a sender I would trust their (verifiable) data more than I would trust the (unverifiable) server transmitting it. Would it not be possible to send a signature of the sender timestamp along with the sender message body so it can be verified?

[Ulyssys]

This has been discussed elsewhere in this repo before, but I'll say it again. Signal is a security-focused application. It's not that we're not listening to user feedback. It's that we cannot trust the timestamps given to us by sender devices. We must trust the server, and therefore the order the server gives us the messages in.

@scottnonnenberg-signal The problem here is that there's a leap in how we get from "we must trust the server" to "therefore [we trust] the order that the server gives us the messages in". Why do this when we can use metadata and not rely on whatever order it happens to show up in?

First, we need to agree that the order in which messages are intended to be read is important. Next, we need to agree that the user's intent could be discarded in favor of the server's intent. Finally, we need to have the server produce useful ordering data for clients to use.

A simple fix:
Have the server timestamp messages as they are processed. Messages will effectively have two timestamps: one from the sender, and one from the server. Choose to use the server's timestamp by default on clients. In this way, we preserve user intent as closely as possible.

Longer thoughts:
In the case that messages are somehow received on a client in an out-of-order fashion, messages can be sorted in-order by trusting the metadata which effectively signifies the time that the server processed the receipt of the message from its sender.

From the receiver's perspective, this will order them properly on the receiver's client. Whether the sender's client's own timestamp can be trusted is no longer important, as relative order is preserved by the reading of the metadata.

From the sender's perspective, the messages could be reordered as the sender's client receives confirmation from the server that the message was processed as "sent" and now receives this timestamp to sort their client as well.* (long explanation below)

Downside: The server must be trusted with timestamping messages, and doing so correctly and effectively, for this to work. Lag on the server or delays in sending due to network connections could change the timestamp. This is probably fine and how most people expect such things to work. I suppose If the receiver would prefer to sort by what the sender's client provides, that could be a kind of advanced debugging option, but not really necessary for most practical purposes (would a user choose to send messages with altered timestamps intentionally?).

---

*An example of this would be a client that fails to send three messages starting on December 3rd, 2020 at midnight UTC, each occurring a minute apart:

Message A, client timestamp 2020-12-03 at 00:00:00 UTC, no server timestamp - unsent pending retry
Message B, client timestamp 2020-12-03 at 00:01:00 UTC, no server timestamp - unsent pending retry
Message C, client timestamp 2020-12-03 at 00:02:00 UTC, no server timestamp - unsent pending retry

The user notices the failures at 00:10:00 (darned wifi went out!) and retries them. However, the user retries the messages in reverse order: First C, then waits 5 minutes for B, then another 5 minutes for A.

As the user presses retry on each message, it is sent to the server and processed as "sent", and a server timestamp is received. That server timestamp is then added into the message. If the user starts by pressing retry on "C", then the prompt for the other two failed messages remains, but message "C" is now ordered into the conversation with the server timestamp. Since this just occurred "immediately", the message is effectively placed at the end of the conversation where we expect it to be. There is no jarring or unexpected behavior in the client.

For sake of example, the server processes Message C immediately within that second at 00:10:00 and timestamps it as such.

The messages look like this so far:

Message A, client original timestamp 2020-12-03 at 00:00:00 UTC, no server timestamp - unsent pending retry
Message B, client original timestamp 2020-12-03 at 00:01:00 UTC, no server timestamp - unsent pending retry
Message C, client original timestamp 2020-12-03 at 00:02:00 UTC, server timestamp 00:10:00

Per our timeline, the user presses retry on B at 00:15:00. Message B is now processed by the server with a bit of lag due to having a poor network connection. The server receives and immediately processes the message 30 seconds later than hoped, and thus timestamps it at 00:15:30.

The messages now look like this:

Message A, client original timestamp 2020-12-03 at 00:00:00 UTC, no server timestamp - unsent pending retry
Message B, client original timestamp 2020-12-03 at 00:01:00 UTC, server timestamp 00:15:30
Message C, client original timestamp 2020-12-03 at 00:02:00 UTC, server timestamp 00:10:00

The user now presses retry on A at 00:20:00. The connection is good now, so Message A is now received and processed by the server immediately and thus timestamped at 00:20:00.

The messages are stored thus:

Message A, client original timestamp 2020-12-03 at 00:00:00 UTC, server timestamp 00:20:00
Message B, client original timestamp 2020-12-03 at 00:01:00 UTC, server timestamp 00:15:30
Message C, client original timestamp 2020-12-03 at 00:02:00 UTC, server timestamp 00:10:00

Finally, the user switches to their desktop client. The desktop client syncs the three messages sent so far (Messages A, B, and C). The desktop client receives them among many other messages and perhaps they are not in order. The desktop client receives the messages in the order B->C->A:

Message B, client original timestamp 2020-12-03 at 00:01:00 UTC, server timestamp 00:15:30
Message C, client original timestamp 2020-12-03 at 00:02:00 UTC, server timestamp 00:10:00
Message A, client original timestamp 2020-12-03 at 00:00:00 UTC, server timestamp 00:20:00

This is fine: As each message is received, it sorts them by the server timestamp. This sorting process could potentially be one of:

1) the client could sort as it receives each individual message with no knowledge of the next one to arrive (more chance for things to move around with each message received before they are confirmed)
2) the server could send a batch of messages chronologically by the server's timestamp and ensure each is received in a single "sync session"
3) the client could also wait to simply confirm no further messages are available on the server to receive (all messages marked as received), and begin processing and sorting.

I'm sure there are other options, but either option 2 and 3 would minimize jarring behavior while allowing for more messages to arrive at the same time. By the receiver syncing the message received status with the server, no jarring movement of messages or unexpected UI changes occur.

In any case, the receiver now sees:

Message C, client original timestamp 2020-12-03 at 00:02:00 UTC, server timestamp 00:10:00
Message B, client original timestamp 2020-12-03 at 00:01:00 UTC, server timestamp 00:15:30
Message A, client original timestamp 2020-12-03 at 00:00:00 UTC, server timestamp 00:20:00

This is what the sender intended by pressing "retry" in the order chosen, and it is what the receiver will see.

If you want, you could always have the client update the "original" timestamp when the retry button is pressed, minimizing the delta between the server's timestamp and the one that the sender provided--just in case. That would result in the messages looking something like this:

Message C, client revised timestamp 2020-12-03 at 00:10:00 UTC, server timestamp 00:10:00
Message B, client revised timestamp 2020-12-03 at 00:15:00 UTC, server timestamp 00:15:30
Message A, client revised timestamp 2020-12-03 at 00:20:00 UTC, server timestamp 00:20:00

This is all based on my very basic understanding of what is being said to happen here. Hopefully this adds some clarity and addresses the UX issue.

[scottnonnenberg-signal]

@Ulyssys Thank you for your analysis.

I think the best way forward for this conversation is to list out scenarios which are broken today, and how often they happen to you, on what devices, etc.

That would provide us with fuel for our own internal problem-solving and prioritization discussions. 'Retrying messages after network connectivity interruptions,' and 'sending messages while still downloading messages' have been mentioned.

What other scenarios are there? Perhaps there are some that aren't easily explained with the way the system works today, and are just bugs? Perhaps there are more problematic scenarios given the intended design, like the two mentioned?

[denisbider]

@scottnonnenberg-signal, I don't think you need further feedback, I think you need the will to resolve this issue, take a walk and break the Gordian knot (which exists in the mind) which prevents you from implementing behavior the users intuitively expect and want (and in a way that meets the users' security expectations).

My previous comments make it seem like I do not appreciate your work, which I do. I think actions speak stronger than words, so I made a $100 donation. Words also speak though, so thank you for your excellent work. :)

[awkto]

Same issue happened to me just now on Windows desktop client. Anything I can do or provide any further data?

Can I help gather more info around the issue for the developers?

I have 2 screenshots I can share if it helps