Signal-desktop: "Message encrypted for non-existing session" after failed sync of a stale desktop client

Created on 19 Sep 2018  ·  28Comments  ·  Source: signalapp/Signal-Desktop
  • [x] I have searched open and closed issues for duplicates

Bug description

On 18 September, I opened Signal on my Windows 10 desktop after not using it on this machine for some time (~1 month?). After allowing it to update to 1.16.1 the desktop client reopened and I promptly received a message _from my own number_ with the status "Message encrypted for non-existing session". I can't know that the message is related to the desktop client update, but it happened seconds after I updated and re-opened the desktop app.

The desktop client is also missing any messages sent and received after 14 September, although it did sync up messages from when it was not opened in the previous weeks. I have another desktop with Signal that I use more frequently that has not had any sync issues recently.

Steps to reproduce

Unfortunately I re-opened the app several times and did not receive another mystery message.

Platform info

Signal version: 1.16.1
Operating System: Windows 10 1803 64 bit
Linked device version: Android 4.25.10

I also have another desktop app synced up but I don't know the version off-hand as it's my work machine.

Link to debug log

I see a lot of 404 errors at the end of the desktop log. My number is the *200 one.
Desktop and Android

Need Information
Source
picture wesQ3

Most helpful comment

Okay, we now have a solution to this problem in place. If you start up a desktop after 30 days of it being offline, it will need to be linked with your mobile device once more.

picture scottnonnenberg-signal on 24 Jan 2019
❤5 🚀4

All 28 comments

Wow, I'm sorry you ran into these errors and missing messages. Sadly, there are some known problems with a desktop instance offline for that long. Each device's queue is only 1000 messages long, which means that old messages can fall off the end as new messages are added to your Desktop's server queue.

But it does sound like the missing messages are recent, and shouldn't have fallen off. I could track those messages down in the log if you went to your other desktop device and found their Sent ID (in the More Info screen for that message, the long number next to the Sent header).

There are indeed a lot of 404 errors in that log, and my guess for those is that they are attachments which have expired. When you send a message, you upload the encrypted attachment to a server, and then only it stays there until it expires.

For the 'encrypted for non-existing session' error, I don't see those in the log. Either way, that was likely a normally-invisible sync message from your phone to your desktop device. If you continue to see those, you can go to the conversation in Desktop and choose 'Reset session' in the menu in the top right.

scottnonnenberg-signal picture scottnonnenberg-signal on 19 Sep 2018

Thanks for the response. I'm back at my other desktop now (Ubuntu 16.04, on 1.16.0) so here's the log from that end.

I have a lot of messages that were dropped from the stale Windows client but here's a few Sent IDs: 1537196658063, 1537196496242, 1537143686474, 1537143492569
Looks like they show up in the Windows client logs as INFO 2018-09-19T03:28:19.173Z No message for delivery receipt +[REDACTED]234 1537143492569 So I guess the question is why they weren't available even though older messages were.

My Ubuntu desktop client has a lot of Error handling incoming message messages on my own number starting _after_ I synced up the stale client, which is surprising to me. Maybe these are more sync messages like you described before. Sent IDs for some of those: 1537420151948, 1537419253817, 1537406050529

INFO  2018-09-20T05:09:11.748Z queueing envelope +[REDACTED]200.3 1537420151948
INFO  2018-09-20T05:09:11.748Z message from +[REDACTED]200.3 1537420151948
ERROR 2018-09-20T05:09:11.749Z background onError: Error: No record for device +[REDACTED]200.3
    at SessionCipher.<anonymous> (file://[REDACTED]/app.asar/js/libtextsecure.js:36307:23)
    at <anonymous>
wesQ3 picture wesQ3 on 20 Sep 2018

Can I provide any more info?

wesQ3 picture wesQ3 on 27 Sep 2018

Hm. Hard to tell. That 'no record for device' error makes me think that perhaps we deleted the wrong session when another device was linked?

Can you provide a list of all of your devices, and when they were linked? Also, any devices that you unlinked in the last couple months. Feel free to provide this information to me directly, or to [email protected]. Thanks!

scottnonnenberg-signal picture scottnonnenberg-signal on 27 Sep 2018

Sure, my Windows 10 desktop was linked 8 June 2018 and my Linux desktop was linked 6 June 2018.

I switched phones around then which prompted those re-syncs, first week of June but I don't know exactly when I switched signal over to the new phone.

I don't _think_ I unlinked a device in the past few months but I can't remember for sure. I think the last time I had to unlink was when I re-installed Ubuntu at work, about a year ago.

Sorry, I know vague recollections aren't going to help track a bug down but I'll keep my eyes peeled if it happens again.

wesQ3 picture wesQ3 on 27 Sep 2018

FWIW, I've experienced this exact problem twice in the past week. Each time I started up a signal desktop client that I hadn't used in several months. Both times I did this, I got ~ about 5 "message encrypted for non-existing session" messages, and a contact who I most frequently talk with (who uses Signal only to talk to me) gets several more sent to them when I opened the desktop client.

snevetsxam picture snevetsxam on 20 Dec 2018
😕1 👍1

Exactly as above.

I just spammed several of my contacts with hundreds of this error message after opening Signal.

Ubuntu 16.04 desktop.
Signal 1.19.0

Android 9
Signal 4.31.6

This was before signal was 'open' it was doing the loading messages part.

https://photos.app.goo.gl/HwLuYHHbtbfePQgm7

Debug log for signal desktop: https://debuglogs.org/53423f9e8f43402037ced08f25d4967d9b4f27791678099f296802bfcec3b6e9

Signal Android: https://debuglogs.org/f3499ee40ef3f638d31b06fe0175df900ce0ab01e1e938214cf2b531ac8eefa7

After reopening signal is seems ok now...

ikt picture ikt on 29 Dec 2018

@ikt Same here. I was just spammed with hundreds of these messages. Never happened before. Could be something wrong with Signal's servers?

Update: My friend hadn't booted his PC in a long time and Signal started spamming his contacts with this error message. The expiration date of these messages was 1 week, so why is this happening? Isn't they deleted from the server queue?

Brog33 picture Brog33 on 29 Dec 2018

@ikt @Brog33 What's likely happening here is that Signal Desktop is sending 'delivery receipt' messages to clients who sent them 'sealed sender' style messages. We can did deeper on this with a log from the desktop instance that did this, as well as the last three digits of the affected contacts' phone numbers.

scottnonnenberg-signal picture scottnonnenberg-signal on 2 Jan 2019

Same thing here. Just spammed a bunch of contacts.

Here's my debug log from Signal Desktop:
https://debuglogs.org/46d42f7c43fd7d9ac2e8c4e8fab35ed40fed0c35a1cae5620aadfb3d536d4557

jperryhouts picture jperryhouts on 15 Jan 2019

@jperryhouts Please, if you can, grab debug logs from the clients you sent to. The Desktop log doesn't have the exact errors that its recipient devices are seeing. That will really help us track this down. Thanks!

scottnonnenberg-signal picture scottnonnenberg-signal on 15 Jan 2019

@scottnonnenberg-signal
Yes, here's the debug log from my phone (xxx-xxx-x924):
https://debuglogs.org/1a77a5a97260d65050f944ff3132b048a9d9f42b046962c6f74cc3d692e3813e

Here's one from one of my contacts (xxx-xxx-x202):
https://debuglogs.org/380310b04d8da1d460f755775d41c8b635cc2d08eacc40caffa3cc3f0b7d53f5

And one from another one of my contacts (xxx-xxx-x063):
https://debuglogs.org/69f6d8e7d62903fdf7b708d6343143a3e388c4e02819d5aa72892e922004031c.zip

This log submission system rocks, by the way! There's no way I could have gotten those people to help with a bug report otherwise (especially that quickly).

jperryhouts picture jperryhouts on 15 Jan 2019

Relevant-looking part from x063's log:

2019/01/15 12:51:48:011  [OWSScreenLockUI.m:466 -[OWSScreenLockUI clockDidChange:]]: clock did change
2019/01/15 12:51:48:040  [PushRegistrationManager.swift:115 pushRegistry(_:didReceiveIncomingPushWith:for:)]: 
2019/01/15 12:51:48:040  [PushManager.m:106 -[PushManager application:didReceiveRemoteNotification:]]: received remote notification
2019/01/15 12:51:49:230  [PushRegistrationManager.swift:115 pushRegistry(_:didReceiveIncomingPushWith:for:)]: 
2019/01/15 12:51:49:230  [PushManager.m:106 -[PushManager application:didReceiveRemoteNotification:]]: received remote notification
2019/01/15 12:51:49:299  [OWSWebSocket.m:393 -[OWSWebSocket setState:]]: Socket state: Connecting -> Open
2019/01/15 12:51:49:353  [OWSWebSocket.m:759 -[OWSWebSocket processWebSocketRequestMessage:]]: Got message with verb: PUT and path: /api/v1/message
2019/01/15 12:51:49:354  [OWSWebSocket.m:759 -[OWSWebSocket processWebSocketRequestMessage:]]: Got message with verb: PUT and path: /api/v1/message
2019/01/15 12:51:49:354  [OWSWebSocket.m:759 -[OWSWebSocket processWebSocketRequestMessage:]]: Got message with verb: PUT and path: /api/v1/message
2019/01/15 12:51:49:355  [OWSWebSocket.m:759 -[OWSWebSocket processWebSocketRequestMessage:]]: Got message with verb: PUT and path: /api/v1/queue/empty
2019/01/15 12:51:49:367  [OWSWebSocket.m:759 -[OWSWebSocket processWebSocketRequestMessage:]]: Got message with verb: PUT and path: /api/v1/message
2019/01/15 12:51:49:508  [OWSMessageDecrypter.m:197 -[OWSMessageDecrypter decryptEnvelope:envelopeData:successBlock:failureBlock:]]: decrypting envelope: <Envelope type: UnidentifiedSender, source: (null).0, timestamp: 1547585506805 conten
t.length: 549 />
2019/01/15 12:51:49:656  [SessionCipher] No valid session for recipient: [ REDACTED_PHONE_NUMBER:xxx924 ] containsActiveSession: NO, previousStates: 0
2019/01/15 12:51:49:717  [OWSMessageDecrypter.m:580 -[OWSMessageDecrypter processException:envelope:]]: Got exception: No session for: [ REDACTED_PHONE_NUMBER:xxx924 ], 3 of type: AxolotlNoSessionException with reason: No session for: [ REDACTED_PHONE_NUMBER:xxx924 ], 3
2019/01/15 12:51:49:732  [OWSMessageDecrypter.m:593 -[OWSMessageDecrypter processException:envelope:]_block_invoke]: -[OWSMessageDecrypter processException:envelope:]_block_invoke:593 message_manager_error_no_session: <Envelope type: UnidentifiedSender, source: [ REDACTED_PHONE_NUMBER:xxx924 ].3, timestamp: 1547585506805 content.length: 549 />
2019/01/15 12:51:49:734  -[OWSMessageDecrypter processException:envelope:]_block_invoke:593 message_manager_error_no_session
2019/01/15 12:51:49:757  [OWSWebSocket.m:759 -[OWSWebSocket processWebSocketRequestMessage:]]: Got message with verb: PUT and path: /api/v1/message
2019/01/15 12:51:49:951  [OWSMessageDecrypter.m:517 -[OWSMessageDecrypter decryptUnidentifiedSender:successBlock:failureBlock:]_block_invoke_2]: Exception while decrypting ud message: No session for: [ REDACTED_PHONE_NUMBER:xxx924 ], 3
2019/01/15 12:51:50:046  [OWSMessageDecrypter.m:278 -[OWSMessageDecrypter decryptEnvelope:envelopeData:successBlock:failureBlock:]_block_invoke]: decrypting unidentified sender message from address: (null).0 failed with error: Error Domain=OWSSignalServiceKitErrorDomain Code=100 "Exception while decrypting ud message: No session for: [ REDACTED_PHONE_NUMBER:xxx924 ], 3" UserInfo={NSLocalizedDescription=Exception while decrypting ud message: No session for: [ REDACTED_PHONE_NUMBER:xxx924 ], 3}
2019/01/15 12:51:50:048  -[OWSMessageDecrypter decryptEnvelope:envelopeData:successBlock:failureBlock:]_block_invoke:279 message_manager_error_could_not_handle_unidentified_sender_message
2019/01/15 12:51:50:148  [OWSMessageDecrypter.m:197 -[OWSMessageDecrypter decryptEnvelope:envelopeData:successBlock:failureBlock:]]: decrypting envelope: <Envelope type: UnidentifiedSender, source: (null).0, timestamp: 1547585507288 content.length: 549 />
2019/01/15 12:51:50:329  [OWSWebSocket.m:759 -[OWSWebSocket processWebSocketRequestMessage:]]: Got message with verb: PUT and path: /api/v1/message
2019/01/15 12:51:50:385  [SessionCipher] No valid session for recipient: [ REDACTED_PHONE_NUMBER:xxx924 ] containsActiveSession: NO, previousStates: 0
2019/01/15 12:51:50:387  [OWSMessageDecrypter.m:580 -[OWSMessageDecrypter processException:envelope:]]: Got exception: No session for: [ REDACTED_PHONE_NUMBER:xxx924 ], 3 of type: AxolotlNoSessionException with reason: No session for: [ REDACTED_PHONE_NUMBER:xxx924 ], 3
2019/01/15 12:51:50:389  [OWSMessageDecrypter.m:593 -[OWSMessageDecrypter processException:envelope:]_block_invoke]: -[OWSMessageDecrypter processException:envelope:]_block_invoke:593 message_manager_error_no_session: <Envelope type: UnidentifiedSender, source: [ REDACTED_PHONE_NUMBER:xxx924 ].3, timestamp: 1547585507288 content.length: 549 />
2019/01/15 12:51:50:389  -[OWSMessageDecrypter processException:envelope:]_block_invoke:593 message_manager_error_no_session
2019/01/15 12:51:50:403  [OWSMessageDecrypter.m:517 -[OWSMessageDecrypter decryptUnidentifiedSender:successBlock:failureBlock:]_block_invoke_2]: Exception while decrypting ud message: No session for: [ REDACTED_PHONE_NUMBER:xxx924 ], 3
2019/01/15 12:51:50:415  [OWSMessageDecrypter.m:278 -[OWSMessageDecrypter decryptEnvelope:envelopeData:successBlock:failureBlock:]_block_invoke]: decrypting unidentified sender message from address: (null).0 failed with error: Error Domain=OWSSignalServiceKitErrorDomain Code=100 "Exception while decrypting ud message: No session for: [ REDACTED_PHONE_NUMBER:xxx924 ], 3" UserInfo={NSLocalizedDescription=Exception while decrypting ud message: No session for: [ REDACTED_PHONE_NUMBER:xxx924 ], 3}
2019/01/15 12:51:50:416  -[OWSMessageDecrypter decryptEnvelope:envelopeData:successBlock:failureBlock:]_block_invoke:279 message_manager_error_could_not_handle_unidentified_sender_message
2019/01/15 12:51:50:423  [OWSMessageDecrypter.m:197 -[OWSMessageDecrypter decryptEnvelope:envelopeData:successBlock:failureBlock:]]: decrypting envelope: <Envelope type: UnidentifiedSender, source: (null).0, timestamp: 1547585508537 content.length: 549 />
jperryhouts picture jperryhouts on 16 Jan 2019

@jperryhouts Thanks for providing all that. Can you talk about the history of your desktop instance? The one you provided the log for originally. When was the last time you used it? When was the last time successful messages went from it to the contacts who recently had problems?

scottnonnenberg-signal picture scottnonnenberg-signal on 16 Jan 2019

@scottnonnenberg-signal It's my work computer. I last used it in early December, and hadn't touched it until today (~ six or seven weeks). I'm sure messages had begun falling off the end of the queue a long time ago (I was using my phone and laptop in the mean time). It might be worth noting that my phone is on the beta release channel, so it's possible that I was sending "sealed sender" messages before these contacts were on a version that supported them. If that were the case, then the asymmetry might have confused Signal-Desktop somehow. Just spitballing, I have no idea whether that's plausible.

Signal-Desktop worked fine in December, and it works fine now. It just caused this snafu while starting up today but then everything went back to normal. I didn't even have to restart it today, it just sent out a bunch of spam and then begun working as usual. I'm not sure how many contacts it affected. I assume it only happened to contacts with whom my session key changed since early December, and who I've been in contact with since then. That would make it less awkward, since those are people I actually interact with. It'd be worse if these went out to random folks that I never communicate with otherwise.

Anyway, thanks for looking into it! I don't know how much more information I have, but let me know if there's anything else I can help with.

jperryhouts picture jperryhouts on 16 Jan 2019

Hey, @scottnonnenberg-signal I also had this issue a few minutes ago. My scenario is almost identical to the previous commenter. The spamming occurred on my work machine (MacBook Air running High Sierra) and I had not opened the signal app since some time in December.

Additionally, my contacts can now only see our threads on the desktop app, despite having open 1:1 threads on mobile previously. This also applies to group threads.

None of us are running any beta releases.

My log is here.

This is an example of what was sent to my contacts.
image

Fixed by sending a message or resetting the secure session.

I have asked the contacts who received the message to submit logs if they had them enabled on mobile and will add links.

Let me know if I can help with anything else :)

edit to add logs
One recipient's log is here, anothers was too big to send but I have attached the zip.
cleaned.zip

edit 2
It appears this was also sent to all of the contacts that signal force imported from my mobile - despite not ever initiating a thread... this is very, very annoying :(
image

llomain picture llomain on 17 Jan 2019

@llomain What exactly do you mean by "Additionally, my contacts can now only see our threads on the desktop app, despite having open 1:1 threads on mobile previously."

"It appears this was also sent to all of the contacts that signal force imported from my mobile - despite not ever initiating a thread" The messages in question are delivery receipts, Desktop letting the recipient know that it got the message (so the double check can be displayed). It shouldn't be the case that messages are sent to people with whom you've never exchanged messages. Can you do a little more checking here?

scottnonnenberg-signal picture scottnonnenberg-signal on 17 Jan 2019

After this happened at work I reset the session keys with several of my contacts and then when I opened Signal Desktop at home it started doing it all over (I force quit it before it could get very far -- thus I also don't have a debug log for that one).

Anyway, it seems that even though this apparently affects very few people, it's a pretty big deal to those who are affected. Is there anything I can do to help accelerate the patching process? I can spend some time tomorrow afternoon doing some sleuthing in the logs, and hacking on the code, but it would be helpful if you could point me in a promising direction first.

Thanks again @scottnonnenberg-signal for your work.

jperryhouts picture jperryhouts on 17 Jan 2019

No worries @scottnonnenberg-signal 👍

Re point 1 - Any threads between myself and recipients that were active on mobile and desktop were closed on the recipients mobile after the desktop errors were sent to the recipient on Desktop. This was not the same for users on mobile only (eg. do not use Signal on Desktop), who only received the messages on mobile.

Re point 2 - I did have an open thread with this contact, but had never sent anything to them on Desktop or mobile.

Trust this helps!

llomain picture llomain on 17 Jan 2019

I turned on signal desktop on one of my machines after some time off, and apparently all my contacts are getting spammed with some variation on "message encrypted for non-existing session".

For my partner, this is turning into hundreds of messages.

$ dpkg -l signal-desktop
Desired=Unknown/Install/Remove/Purge/Hold
| Status=Not/Inst/Conf-files/Unpacked/halF-conf/Half-inst/trig-aWait/Trig-pend
|/ Err?=(none)/Reinst-required (Status,Err: uppercase=bad)
||/ Name                               Version                Architecture           Description
+++-==================================-======================-======================-=========================================================================
ii  signal-desktop                     1.19.0                 amd64

Signal android 4.31.8

signal-2019-01-18-094413

To mitigate, I went on my phone and de-linked my desktop. Now signal desktop won't open on this computer at all. I'll probably purge the package and try from scratch when I get a chance.

But it's definitely important that all my contacts don't get spammed because I opened signal-desktop when I hadn't in a while.

sean-abbott picture sean-abbott on 18 Jan 2019

@sean-abbott When you say that it doesn't open at all, what error do you get? Please provide a log!

scottnonnenberg-signal picture scottnonnenberg-signal on 18 Jan 2019

Identical issue, spammed many contacts with "Message encrypted for non-existing session"

Debug log from my phone

Debug log from my desktop

INFO  2019-01-22T15:05:23.736Z SQL channel job 15054 (getItemById) succeeded in 30ms
INFO  2019-01-22T15:05:23.818Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]818 (unauth)
INFO  2019-01-22T15:05:24.012Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]818 200 Success
INFO  2019-01-22T15:05:24.019Z Set message expiration {"expiresAt":1548774324014,"sentAt":1548169523322}
INFO  2019-01-22T15:05:24.049Z SQL channel job 15066 (getSessionById) succeeded in 22ms
INFO  2019-01-22T15:05:24.049Z SQL channel job 15067 (getSessionById) succeeded in 23ms
INFO  2019-01-22T15:05:24.070Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]904
INFO  2019-01-22T15:05:24.217Z fetchMessages
INFO  2019-01-22T15:05:24.252Z GET https://textsecure-service.whispersystems.org/v1/profile/+[REDACTED]241 (unauth)
INFO  2019-01-22T15:05:24.252Z SQL channel job 15081 (getMessagesByConversation) succeeded in 30ms
INFO  2019-01-22T15:05:24.252Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]904 200 Success
INFO  2019-01-22T15:05:24.257Z SQL channel job 15082 (getMessagesByConversation) succeeded in 15ms
INFO  2019-01-22T15:05:24.267Z SQL channel job 15083 (saveMessage) succeeded in 16ms
INFO  2019-01-22T15:05:24.269Z Conversation +[REDACTED]241 took 53 milliseconds to load
INFO  2019-01-22T15:05:24.302Z SQL channel job 15086 (saveMessage) succeeded in 21ms
INFO  2019-01-22T15:05:24.394Z SQL channel job 15087 (getConversationById) succeeded in 92ms
INFO  2019-01-22T15:05:24.401Z Sending 1 read receipts
INFO  2019-01-22T15:05:24.401Z next message expires 2019-01-22T22:42:02.115Z
INFO  2019-01-22T15:05:24.425Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]904
INFO  2019-01-22T15:05:24.461Z GET https://textsecure-service.whispersystems.org/v1/profile/+[REDACTED]241 200 Success
INFO  2019-01-22T15:05:24.463Z Setting sealedSender to ENABLED for conversation +[REDACTED]241
INFO  2019-01-22T15:05:24.465Z done with status fetch
INFO  2019-01-22T15:05:24.619Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]904 200 Success
INFO  2019-01-22T15:05:24.684Z Worker job 1586 (arrayBufferToStringBase64) succeeded in 1ms
INFO  2019-01-22T15:05:24.687Z queueing envelope af258844-5d06-41e7-9b36-5a68d82b50e5
INFO  2019-01-22T15:05:24.687Z received unidentified sender message
INFO  2019-01-22T15:05:24.735Z New remote ephemeral key
INFO  2019-01-22T15:05:24.749Z Worker job 1587 (arrayBufferToStringBase64) succeeded in 14ms
INFO  2019-01-22T15:05:24.782Z SQL channel job 15114 (saveUnprocessed) succeeded in 32ms
INFO  2019-01-22T15:05:24.782Z queueing envelope 13eac860-8072-4b09-8411-9f4216dc5a10
INFO  2019-01-22T15:05:24.795Z Worker job 1588 (arrayBufferToStringBase64) succeeded in 1ms
INFO  2019-01-22T15:05:24.797Z read receipt +[REDACTED]818 1548169523322
INFO  2019-01-22T15:05:24.800Z received unidentified sender message
INFO  2019-01-22T15:05:24.859Z Worker job 1589 (arrayBufferToStringBase64) succeeded in 0ms
INFO  2019-01-22T15:05:24.861Z delivery receipt from +[REDACTED]818.1 1548169523322
INFO  2019-01-22T15:05:25.397Z next message expires 2019-01-22T22:42:02.115Z
INFO  2019-01-22T15:05:25.967Z SQL channel job 15141 (getMessagesByConversation) succeeded in 55ms
INFO  2019-01-22T15:05:25.968Z SQL channel job 15142 (getIdentityKeyById) succeeded in 26ms
INFO  2019-01-22T15:05:25.969Z done with status fetch
INFO  2019-01-22T15:05:27.979Z SQL channel job 15155 (saveMessage) succeeded in 15ms
INFO  2019-01-22T15:05:27.979Z resetting secure session
INFO  2019-01-22T15:05:27.980Z SQL channel job 15156 (getConversationById) succeeded in 11ms
INFO  2019-01-22T15:05:27.981Z next message expires 2019-01-22T22:42:02.115Z
INFO  2019-01-22T15:05:27.981Z deleting sessions for +[REDACTED]756.2
INFO  2019-01-22T15:05:27.982Z deleting sessions for +[REDACTED]756.1
INFO  2019-01-22T15:05:27.993Z finished closing local sessions, now sending to contact
INFO  2019-01-22T15:05:27.995Z GET https://textsecure-service.whispersystems.org/v2/keys/+[REDACTED]756/2 (unauth)
INFO  2019-01-22T15:05:28.004Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]904
INFO  2019-01-22T15:05:28.193Z SQL channel job 15184 (getConversationById) succeeded in 26ms
INFO  2019-01-22T15:05:28.209Z GET https://textsecure-service.whispersystems.org/v2/keys/+[REDACTED]756/2 200 Success
INFO  2019-01-22T15:05:28.251Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]904 200 Success
INFO  2019-01-22T15:05:28.425Z GET https://textsecure-service.whispersystems.org/v2/keys/+[REDACTED]756/1 (unauth)
INFO  2019-01-22T15:05:28.672Z GET https://textsecure-service.whispersystems.org/v2/keys/+[REDACTED]756/1 200 Success
INFO  2019-01-22T15:05:28.710Z SQL channel job 15195 (getItemById) succeeded in 11ms
INFO  2019-01-22T15:05:28.861Z SQL channel job 15215 (getIdentityKeyById) succeeded in 31ms
INFO  2019-01-22T15:05:28.937Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]756 (unauth)
INFO  2019-01-22T15:05:29.134Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]756 200 Success
INFO  2019-01-22T15:05:29.136Z deleting sessions for +[REDACTED]756.2
INFO  2019-01-22T15:05:29.136Z deleting sessions for +[REDACTED]756.1
INFO  2019-01-22T15:05:29.150Z next message expires 2019-01-22T22:42:02.115Z
INFO  2019-01-22T15:05:31.978Z Send pre-checks took 9 milliseconds
INFO  2019-01-22T15:05:31.994Z Sending message to conversation +[REDACTED]756 with timestamp 1548169531987
INFO  2019-01-22T15:05:31.994Z SQL channel job 15230 (getConversationById) succeeded in 20ms
INFO  2019-01-22T15:05:32.018Z SQL channel job 15233 (updateConversation) succeeded in 24ms
INFO  2019-01-22T15:05:32.018Z SQL channel job 15232 (getConversationById) succeeded in 26ms
INFO  2019-01-22T15:05:32.032Z SQL channel job 15235 (saveMessage) succeeded in 12ms
INFO  2019-01-22T15:05:32.035Z next message expires 2019-01-22T22:42:02.115Z
INFO  2019-01-22T15:05:32.037Z GET https://textsecure-service.whispersystems.org/v2/keys/+[REDACTED]756/2 (unauth)
INFO  2019-01-22T15:05:32.089Z GET https://textsecure-service.whispersystems.org/v2/keys/+[REDACTED]756/2 200 Success
INFO  2019-01-22T15:05:32.220Z GET https://textsecure-service.whispersystems.org/v2/keys/+[REDACTED]756/1 (unauth)
INFO  2019-01-22T15:05:32.275Z GET https://textsecure-service.whispersystems.org/v2/keys/+[REDACTED]756/1 200 Success
INFO  2019-01-22T15:05:32.409Z SQL channel job 15249 (createOrUpdateSession) succeeded in 18ms
INFO  2019-01-22T15:05:32.409Z SQL channel job 15250 (getIdentityKeyById) succeeded in 18ms
INFO  2019-01-22T15:05:32.451Z SQL channel job 15267 (getIdentityKeyById) succeeded in 28ms
INFO  2019-01-22T15:05:32.513Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]756 (unauth)
INFO  2019-01-22T15:05:32.599Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]756 200 Success
INFO  2019-01-22T15:05:32.629Z SQL channel job 15276 (getSessionById) succeeded in 15ms
INFO  2019-01-22T15:05:32.629Z SQL channel job 15277 (getSessionById) succeeded in 15ms
INFO  2019-01-22T15:05:32.647Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]904
INFO  2019-01-22T15:05:32.740Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]904 200 Success
INFO  2019-01-22T15:05:33.034Z next message expires 2019-01-22T22:42:02.115Z
INFO  2019-01-22T15:06:15.013Z Worker job 1590 (arrayBufferToStringBase64) succeeded in 0ms
INFO  2019-01-22T15:06:15.018Z queueing envelope 4a8c59c3-d128-429a-8e55-6a1ba09eb36d
INFO  2019-01-22T15:06:15.018Z received unidentified sender message
INFO  2019-01-22T15:06:15.132Z SQL channel job 15300 (createOrUpdateSession) succeeded in 24ms
INFO  2019-01-22T15:06:15.134Z Worker job 1591 (arrayBufferToStringBase64) succeeded in 1ms
INFO  2019-01-22T15:06:15.936Z Worker job 1592 (arrayBufferToStringBase64) succeeded in 0ms
INFO  2019-01-22T15:06:15.938Z queueing envelope fd884419-df86-41f1-ae16-f1613d1fc1b9
INFO  2019-01-22T15:06:15.938Z received unidentified sender message
INFO  2019-01-22T15:06:15.995Z Worker job 1593 (arrayBufferToStringBase64) succeeded in 0ms
INFO  2019-01-22T15:06:15.997Z data message from +[REDACTED]818.1 1548169574933 (fd884419-df86-41f1-ae16-f1613d1fc1b9)
INFO  2019-01-22T15:06:16.036Z SQL channel job 15333 (getIdentityKeyById) succeeded in 27ms
INFO  2019-01-22T15:06:16.095Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]818 (unauth)
INFO  2019-01-22T15:06:16.150Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]818 200 Success
INFO  2019-01-22T15:06:16.160Z Update conversation 'expireTimer' {"id":"+[REDACTED]818","expireTimer":604800,"source":"handleDataMessage"}
INFO  2019-01-22T15:06:16.183Z SQL channel job 15337 (saveMessage) succeeded in 16ms
INFO  2019-01-22T15:06:16.186Z next message expires 2019-01-22T22:42:02.115Z
INFO  2019-01-22T15:06:16.209Z SQL channel job 15342 (getMessageById) succeeded in 14ms
INFO  2019-01-22T15:06:16.209Z Add notification {"conversationId":"+[REDACTED]818","isExpiringMessage":true,"messageSentAt":1548169574933}
INFO  2019-01-22T15:06:16.211Z Update notifications: {"shouldClearNotifications":false,"shouldPlayNotificationSound":false,"shouldShowNotifications":true,"type":"ok","isNotificationGroupingSupported":true}
INFO  2019-01-22T15:06:16.212Z draw attention
INFO  2019-01-22T15:06:16.214Z Worker job 1594 (arrayBufferToStringBase64) succeeded in 2ms
INFO  2019-01-22T15:06:16.220Z queueing envelope 5906ce0f-8799-4eba-8811-d35ebc5d2107
INFO  2019-01-22T15:06:16.220Z received unidentified sender message
INFO  2019-01-22T15:06:16.222Z Approving request for permission 'notifications'
INFO  2019-01-22T15:06:16.303Z Worker job 1595 (arrayBufferToStringBase64) succeeded in 0ms
INFO  2019-01-22T15:06:19.358Z Remove all notifications
INFO  2019-01-22T15:06:19.360Z SQL channel job 15360 (getUnreadByConversation) succeeded in 15ms
INFO  2019-01-22T15:06:20.221Z SQL channel job 15363 (getMessagesByConversation) succeeded in 57ms
INFO  2019-01-22T15:06:20.223Z SQL channel job 15364 (getIdentityKeyById) succeeded in 21ms
INFO  2019-01-22T15:06:20.223Z done with status fetch
INFO  2019-01-22T15:06:20.260Z SQL channel job 15367 (saveMessage) succeeded in 34ms
INFO  2019-01-22T15:06:20.260Z Set message expiration {"expiresAt":1548774380226,"sentAt":1548169574933}
INFO  2019-01-22T15:06:20.264Z SQL channel job 15368 (saveMessage) succeeded in 35ms
INFO  2019-01-22T15:06:20.273Z SQL channel job 15369 (updateConversation) succeeded in 44ms
INFO  2019-01-22T15:06:20.273Z SQL channel job 15370 (getNextExpiringMessage) succeeded in 13ms
INFO  2019-01-22T15:06:20.274Z next message expires 2019-01-22T22:42:02.115Z
INFO  2019-01-22T15:06:20.277Z Sending 1 read receipts
INFO  2019-01-22T15:06:20.320Z SQL channel job 15388 (createOrUpdateSession) succeeded in 28ms
INFO  2019-01-22T15:06:20.321Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]904
INFO  2019-01-22T15:06:20.345Z Update notifications: {"shouldClearNotifications":false,"shouldPlayNotificationSound":false,"shouldShowNotifications":false,"type":"noNotifications","isNotificationGroupingSupported":true}
INFO  2019-01-22T15:06:20.372Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]904 200 Success
INFO  2019-01-22T15:06:21.262Z next message expires 2019-01-22T22:42:02.115Z
INFO  2019-01-22T15:06:25.188Z Worker job 1596 (arrayBufferToStringBase64) succeeded in 0ms
INFO  2019-01-22T15:06:25.191Z queueing envelope 4a7f66f4-6f1a-4324-8142-2e3716d0c15d
INFO  2019-01-22T15:06:25.191Z received unidentified sender message
INFO  2019-01-22T15:06:25.243Z New remote ephemeral key
INFO  2019-01-22T15:06:25.293Z Worker job 1597 (arrayBufferToStringBase64) succeeded in 1ms
INFO  2019-01-22T15:06:25.294Z data message from +[REDACTED]818.1 1548169584086 (4a7f66f4-6f1a-4324-8142-2e3716d0c15d)
INFO  2019-01-22T15:06:25.332Z SQL channel job 15423 (getIdentityKeyById) succeeded in 26ms
INFO  2019-01-22T15:06:25.387Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]818 (unauth)
INFO  2019-01-22T15:06:25.436Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]818 200 Success
INFO  2019-01-22T15:06:25.439Z Update conversation 'expireTimer' {"id":"+[REDACTED]818","expireTimer":604800,"source":"handleDataMessage"}
INFO  2019-01-22T15:06:25.449Z next message expires 2019-01-22T22:42:02.115Z
WARN  2019-01-22T15:06:25.467Z Caught race condition on new message read state! Manually starting timers.
INFO  2019-01-22T15:06:25.474Z Set message expiration {"expiresAt":1548774385464,"sentAt":1548169584086}
INFO  2019-01-22T15:06:25.480Z SQL channel job 15436 (saveMessage) succeeded in 12ms
INFO  2019-01-22T15:06:25.480Z SQL channel job 15437 (removeUnprocessed) succeeded in 12ms
INFO  2019-01-22T15:06:25.483Z Sending 1 read receipts
INFO  2019-01-22T15:06:25.501Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]904
INFO  2019-01-22T15:06:25.555Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]904 200 Success
INFO  2019-01-22T15:06:26.451Z next message expires 2019-01-22T22:42:02.115Z
INFO  2019-01-22T15:06:26.756Z Worker job 1598 (arrayBufferToStringBase64) succeeded in 0ms
INFO  2019-01-22T15:06:26.758Z queueing envelope 51130b2f-1e65-4e5f-a3c2-b23d6b84b087
INFO  2019-01-22T15:06:26.758Z received unidentified sender message
INFO  2019-01-22T15:06:26.806Z New remote ephemeral key
INFO  2019-01-22T15:06:26.852Z Worker job 1599 (arrayBufferToStringBase64) succeeded in 1ms
INFO  2019-01-22T15:06:26.854Z onProgress: Message count is 30
INFO  2019-01-22T15:06:29.590Z Worker job 1600 (arrayBufferToStringBase64) succeeded in 0ms
INFO  2019-01-22T15:06:29.593Z queueing envelope 966f5fa1-c61b-4091-86db-a72853cc4f45
INFO  2019-01-22T15:06:29.593Z received unidentified sender message
INFO  2019-01-22T15:06:29.656Z Worker job 1601 (arrayBufferToStringBase64) succeeded in 1ms
INFO  2019-01-22T15:06:29.658Z data message from +[REDACTED]818.1 1548169588558 (966f5fa1-c61b-4091-86db-a72853cc4f45)
INFO  2019-01-22T15:06:29.698Z SQL channel job 15505 (getIdentityKeyById) succeeded in 26ms
INFO  2019-01-22T15:06:29.758Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]818 (unauth)
INFO  2019-01-22T15:06:29.809Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]818 200 Success
INFO  2019-01-22T15:06:29.811Z Update conversation 'expireTimer' {"id":"+[REDACTED]818","expireTimer":604800,"source":"handleDataMessage"}
INFO  2019-01-22T15:06:29.822Z next message expires 2019-01-22T22:42:02.115Z
WARN  2019-01-22T15:06:29.842Z Caught race condition on new message read state! Manually starting timers.
INFO  2019-01-22T15:06:29.849Z Set message expiration {"expiresAt":1548774389838,"sentAt":1548169588558}
INFO  2019-01-22T15:06:29.857Z SQL channel job 15518 (saveMessage) succeeded in 14ms
INFO  2019-01-22T15:06:29.858Z SQL channel job 15519 (removeUnprocessed) succeeded in 13ms
INFO  2019-01-22T15:06:29.861Z Sending 1 read receipts
INFO  2019-01-22T15:06:29.879Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]904
INFO  2019-01-22T15:06:29.928Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]904 200 Success
INFO  2019-01-22T15:06:30.824Z next message expires 2019-01-22T22:42:02.115Z
INFO  2019-01-22T15:06:33.134Z Send pre-checks took 9 milliseconds
INFO  2019-01-22T15:06:33.151Z Sending message to conversation +[REDACTED]818 with timestamp 1548169593143
INFO  2019-01-22T15:06:33.157Z SQL channel job 15550 (updateConversation) succeeded in 27ms
INFO  2019-01-22T15:06:33.177Z SQL channel job 15551 (getConversationById) succeeded in 27ms
INFO  2019-01-22T15:06:33.196Z next message expires 2019-01-22T22:42:02.115Z
INFO  2019-01-22T15:06:33.264Z SQL channel job 15574 (getIdentityKeyById) succeeded in 37ms
INFO  2019-01-22T15:06:33.328Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]818 (unauth)
INFO  2019-01-22T15:06:33.384Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]818 200 Success
INFO  2019-01-22T15:06:33.390Z Set message expiration {"expiresAt":1548774393385,"sentAt":1548169593143}
INFO  2019-01-22T15:06:33.413Z SQL channel job 15584 (getSessionsByNumber) succeeded in 15ms
INFO  2019-01-22T15:06:33.427Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]904
INFO  2019-01-22T15:06:33.487Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]904 200 Success
INFO  2019-01-22T15:06:34.196Z next message expires 2019-01-22T22:42:02.115Z
INFO  2019-01-22T15:06:34.249Z Worker job 1602 (arrayBufferToStringBase64) succeeded in 0ms
INFO  2019-01-22T15:06:34.254Z queueing envelope 288c79a1-19fa-474e-990b-99ad9b1ce0da
INFO  2019-01-22T15:06:34.254Z received unidentified sender message
INFO  2019-01-22T15:06:34.295Z Worker job 1603 (arrayBufferToStringBase64) succeeded in 0ms
INFO  2019-01-22T15:06:34.305Z queueing envelope b9c4e27a-826a-4783-b57c-fe40924d613a
INFO  2019-01-22T15:06:34.340Z New remote ephemeral key
INFO  2019-01-22T15:06:34.417Z Worker job 1604 (arrayBufferToStringBase64) succeeded in 0ms
INFO  2019-01-22T15:06:34.427Z SQL channel job 15612 (saveUnprocessed) succeeded in 11ms
INFO  2019-01-22T15:06:34.427Z read receipt +[REDACTED]818 1548169593143
INFO  2019-01-22T15:06:34.430Z received unidentified sender message
INFO  2019-01-22T15:06:34.494Z Worker job 1605 (arrayBufferToStringBase64) succeeded in 0ms
INFO  2019-01-22T15:06:34.495Z delivery receipt from +[REDACTED]818.1 1548169593143
INFO  2019-01-22T15:06:35.197Z next message expires 2019-01-22T22:42:02.115Z
INFO  2019-01-22T15:06:37.998Z Send pre-checks took 9 milliseconds
INFO  2019-01-22T15:06:38.017Z Sending message to conversation +[REDACTED]818 with timestamp 1548169598006
INFO  2019-01-22T15:06:38.037Z SQL channel job 15631 (updateConversation) succeeded in 42ms
INFO  2019-01-22T15:06:38.037Z SQL channel job 15632 (getConversationById) succeeded in 22ms
INFO  2019-01-22T15:06:38.047Z next message expires 2019-01-22T22:42:02.115Z
INFO  2019-01-22T15:06:38.097Z SQL channel job 15655 (getIdentityKeyById) succeeded in 32ms
INFO  2019-01-22T15:06:38.155Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]818 (unauth)
INFO  2019-01-22T15:06:38.472Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]818 200 Success
INFO  2019-01-22T15:06:38.485Z SQL channel job 15659 (saveMessage) succeeded in 11ms
INFO  2019-01-22T15:06:38.485Z Set message expiration {"expiresAt":1548774398474,"sentAt":1548169598006}
INFO  2019-01-22T15:06:38.488Z SQL channel job 15660 (saveMessage) succeeded in 13ms
INFO  2019-01-22T15:06:38.506Z SQL channel job 15663 (getSessionById) succeeded in 15ms
INFO  2019-01-22T15:06:38.506Z SQL channel job 15664 (getSessionById) succeeded in 16ms
INFO  2019-01-22T15:06:38.532Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]904
INFO  2019-01-22T15:06:38.590Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]904 200 Success
INFO  2019-01-22T15:06:38.844Z Send pre-checks took 8 milliseconds
INFO  2019-01-22T15:06:38.857Z Sending message to conversation +[REDACTED]818 with timestamp 1548169598853
INFO  2019-01-22T15:06:38.858Z SQL channel job 15683 (getConversationById) succeeded in 17ms
INFO  2019-01-22T15:06:38.877Z SQL channel job 15685 (getConversationById) succeeded in 20ms
INFO  2019-01-22T15:06:38.878Z SQL channel job 15686 (updateConversation) succeeded in 21ms
INFO  2019-01-22T15:06:38.939Z SQL channel job 15708 (getIdentityKeyById) succeeded in 28ms
INFO  2019-01-22T15:06:39.008Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]818 (unauth)
INFO  2019-01-22T15:06:39.048Z next message expires 2019-01-22T22:42:02.115Z
INFO  2019-01-22T15:06:39.266Z Worker job 1606 (arrayBufferToStringBase64) succeeded in 0ms
INFO  2019-01-22T15:06:39.269Z queueing envelope 80e73f59-7a30-474a-a291-0a7c51a7e3ac
INFO  2019-01-22T15:06:39.269Z received unidentified sender message
INFO  2019-01-22T15:06:39.320Z New remote ephemeral key
INFO  2019-01-22T15:06:39.333Z Worker job 1607 (arrayBufferToStringBase64) succeeded in 14ms
INFO  2019-01-22T15:06:39.362Z SQL channel job 15716 (saveUnprocessed) succeeded in 28ms
INFO  2019-01-22T15:06:39.362Z queueing envelope cdd86a24-b96e-46f6-83b6-11c866d04467
INFO  2019-01-22T15:06:39.363Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]818 200 Success
INFO  2019-01-22T15:06:39.368Z Set message expiration {"expiresAt":1548774399365,"sentAt":1548169598853}
INFO  2019-01-22T15:06:39.390Z SQL channel job 15725 (getSessionById) succeeded in 17ms
INFO  2019-01-22T15:06:39.390Z SQL channel job 15724 (getSessionById) succeeded in 17ms
INFO  2019-01-22T15:06:39.391Z SQL channel job 15726 (updateConversation) succeeded in 16ms
INFO  2019-01-22T15:06:39.403Z Worker job 1608 (arrayBufferToStringBase64) succeeded in 0ms
INFO  2019-01-22T15:06:39.409Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]904
INFO  2019-01-22T15:06:39.410Z read receipt +[REDACTED]818 1548169598006
INFO  2019-01-22T15:06:39.413Z received unidentified sender message
INFO  2019-01-22T15:06:39.470Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]904 200 Success
INFO  2019-01-22T15:06:39.476Z Worker job 1609 (arrayBufferToStringBase64) succeeded in 0ms
INFO  2019-01-22T15:06:39.478Z delivery receipt from +[REDACTED]818.1 1548169598006
INFO  2019-01-22T15:06:39.946Z Worker job 1610 (arrayBufferToStringBase64) succeeded in 0ms
INFO  2019-01-22T15:06:39.949Z queueing envelope 4dab1b8e-1145-4ebf-92e1-86775f353064
INFO  2019-01-22T15:06:39.949Z received unidentified sender message
INFO  2019-01-22T15:06:39.998Z Worker job 1611 (arrayBufferToStringBase64) succeeded in 0ms
INFO  2019-01-22T15:06:40.001Z queueing envelope b734f291-b0c7-416e-9135-c74e4e896b13
INFO  2019-01-22T15:06:40.007Z Worker job 1612 (arrayBufferToStringBase64) succeeded in 0ms
INFO  2019-01-22T15:06:40.009Z read receipt +[REDACTED]818 1548169598853
INFO  2019-01-22T15:06:40.011Z received unidentified sender message
INFO  2019-01-22T15:06:40.059Z next message expires 2019-01-22T22:42:02.115Z
INFO  2019-01-22T15:06:40.067Z Worker job 1613 (arrayBufferToStringBase64) succeeded in 0ms
INFO  2019-01-22T15:06:40.069Z delivery receipt from +[REDACTED]818.1 1548169598853
INFO  2019-01-22T15:06:41.059Z next message expires 2019-01-22T22:42:02.115Z
INFO  2019-01-22T15:06:43.643Z Worker job 1614 (arrayBufferToStringBase64) succeeded in 1ms
INFO  2019-01-22T15:06:43.652Z queueing envelope f36f6638-7d27-4a14-9fa9-6da1745bb5e2
INFO  2019-01-22T15:06:43.652Z received unidentified sender message
INFO  2019-01-22T15:06:43.734Z SQL channel job 15795 (createOrUpdateSession) succeeded in 28ms
INFO  2019-01-22T15:06:43.735Z Worker job 1615 (arrayBufferToStringBase64) succeeded in 0ms
INFO  2019-01-22T15:06:47.041Z Worker job 1616 (arrayBufferToStringBase64) succeeded in 0ms
INFO  2019-01-22T15:06:47.044Z queueing envelope b966beca-3678-4960-9ced-fc409611dcc9
INFO  2019-01-22T15:06:47.045Z received unidentified sender message
INFO  2019-01-22T15:06:47.103Z Worker job 1617 (arrayBufferToStringBase64) succeeded in 0ms
INFO  2019-01-22T15:06:47.105Z data message from +[REDACTED]818.1 1548169605971 (b966beca-3678-4960-9ced-fc409611dcc9)
INFO  2019-01-22T15:06:47.143Z SQL channel job 15826 (getItemById) succeeded in 24ms
INFO  2019-01-22T15:06:47.201Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]818 (unauth)
INFO  2019-01-22T15:06:47.336Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]818 200 Success
INFO  2019-01-22T15:06:47.339Z Update conversation 'expireTimer' {"id":"+[REDACTED]818","expireTimer":604800,"source":"handleDataMessage"}
INFO  2019-01-22T15:06:47.354Z next message expires 2019-01-22T22:42:02.115Z
INFO  2019-01-22T15:06:47.370Z Add notification {"conversationId":"+[REDACTED]818","isExpiringMessage":true,"messageSentAt":1548169605971}
INFO  2019-01-22T15:06:47.371Z Update notifications: {"shouldClearNotifications":false,"shouldPlayNotificationSound":false,"shouldShowNotifications":true,"type":"ok","isNotificationGroupingSupported":true}
INFO  2019-01-22T15:06:47.371Z draw attention
INFO  2019-01-22T15:06:47.375Z Approving request for permission 'notifications'
INFO  2019-01-22T15:06:48.380Z SQL channel job 15840 (createOrUpdateItem) succeeded in 40ms
INFO  2019-01-22T15:06:48.381Z SQL channel job 15841 (getIdentityKeyById) succeeded in 24ms
INFO  2019-01-22T15:06:56.665Z Remove all notifications
INFO  2019-01-22T15:06:56.672Z SQL channel job 15844 (getUnreadByConversation) succeeded in 38ms
INFO  2019-01-22T15:06:56.687Z SQL channel job 15845 (saveMessage) succeeded in 12ms
INFO  2019-01-22T15:06:56.688Z Set message expiration {"expiresAt":1548774416674,"sentAt":1548169605971}
INFO  2019-01-22T15:06:56.698Z SQL channel job 15846 (saveMessage) succeeded in 19ms
INFO  2019-01-22T15:06:56.703Z SQL channel job 15847 (getNextExpiringMessage) succeeded in 15ms
INFO  2019-01-22T15:06:56.703Z next message expires 2019-01-22T22:42:02.115Z
INFO  2019-01-22T15:06:56.709Z Sending 1 read receipts
INFO  2019-01-22T15:06:56.728Z SQL channel job 15855 (getItemById) succeeded in 13ms
INFO  2019-01-22T15:06:56.728Z SQL channel job 15856 (getSessionById) succeeded in 13ms
INFO  2019-01-22T15:06:56.728Z SQL channel job 15854 (getItemById) succeeded in 13ms
INFO  2019-01-22T15:06:56.729Z SQL channel job 15857 (getItemById) succeeded in 14ms
INFO  2019-01-22T15:06:56.729Z SQL channel job 15858 (getItemById) succeeded in 14ms
INFO  2019-01-22T15:06:56.729Z SQL channel job 15859 (getSessionById) succeeded in 15ms
INFO  2019-01-22T15:06:56.750Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]904
INFO  2019-01-22T15:06:56.802Z PUT https://textsecure-service.whispersystems.org/v1/messages/+[REDACTED]904 200 Success
INFO  2019-01-22T15:06:57.633Z Update notifications: {"shouldClearNotifications":false,"shouldPlayNotificationSound":false,"shouldShowNotifications":false,"type":"noNotifications","isNotificationGroupingSupported":true}
INFO  2019-01-22T15:06:57.688Z next message expires 2019-01-22T22:42:02.115Z
INFO  2019-01-22T15:06:58.257Z Worker job 1618 (arrayBufferToStringBase64) succeeded in 1ms
INFO  2019-01-22T15:06:58.262Z queueing envelope 1c51ddfe-ed12-4c16-b9ff-4fa1b28ccd99
INFO  2019-01-22T15:06:58.262Z received unidentified sender message
INFO  2019-01-22T15:06:58.340Z New remote ephemeral key
INFO  2019-01-22T15:06:58.387Z Worker job 1619 (arrayBufferToStringBase64) succeeded in 0ms
INFO  2019-01-22T15:06:58.389Z onProgress: Message count is 40
INFO  2019-01-22T15:07:07.713Z Worker job 1620 (arrayBufferToStringBase64) succeeded in 1ms
INFO  2019-01-22T15:07:07.716Z queueing envelope fd800542-ce19-46ac-8431-3c92e2440859
INFO  2019-01-22T15:07:07.717Z received unidentified sender message
INFO  2019-01-22T15:07:07.779Z Worker job 1621 (arrayBufferToStringBase64) succeeded in 0ms
INFO  2019-01-22T15:07:08.494Z Remove all notifications
INFO  2019-01-22T15:07:08.497Z SQL channel job 15890 (getUnreadByConversation) succeeded in 17ms
INFO  2019-01-22T15:07:09.479Z Update notifications: {"shouldClearNotifications":false,"shouldPlayNotificationSound":false,"shouldShowNotifications":false,"type":"noNotifications","isNotificationGroupingSupported":true}
INFO  2019-01-22T15:07:09.534Z SQL channel job 15893 (getUnreadByConversation) succeeded in 14ms
INFO  2019-01-22T15:07:21.576Z Loaded this list of log files from logPath: log.log, log.log.0, log.log.1, log.log.2
adrw picture adrw on 22 Jan 2019

This just happened to me minutes ago, fired up the desktop client after quite a while, all my Signal contacts got spammed. Several of them are now uninstalling Signal because of this issue

snokec picture snokec on 23 Jan 2019

I'm pretty frustrated with the lack of response on this. I'm happy to contribute to FOSS projects, but considering this one actually has funding I'd expect more support from the core developers. At least a suggestion where to look for the bug, or some communication that it's being worked on.

jperryhouts picture jperryhouts on 24 Jan 2019

@jperryhouts Generally we don't comment about things until we have a solution for them. And we don't have a shipped solution for this yet. And we really don't expect the community to solve problems like this for us, or really have the expertise to do so.

But I can tell you more about the problem - it happens for desktops which have been offline for longer than 30 days. It's worth noting that we discourage leaving Desktop offline for that long because it guarantees that it will be out of date when it does come back online.

scottnonnenberg-signal picture scottnonnenberg-signal on 24 Jan 2019

Okay, we now have a solution to this problem in place. If you start up a desktop after 30 days of it being offline, it will need to be linked with your mobile device once more.

scottnonnenberg-signal picture scottnonnenberg-signal on 24 Jan 2019
❤5 🚀4

Thank you @scottnonnenberg-signal !! I'm sorry to have sounded so harsh with my response; I really do appreciate all the work the Signal team puts into this.

jperryhouts picture jperryhouts on 24 Jan 2019

Hooray! Thank you very much!

On Thu, Jan 24, 2019 at 3:06 PM Scott Nonnenberg notifications@github.com
wrote:

Okay, we now have a solution to this problem in place. If you start up a
desktop after 30 days of it being offline, it will need to linked with your
mobile device once more.

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/signalapp/Signal-Desktop/issues/2746#issuecomment-457337840,
or mute the thread
https://github.com/notifications/unsubscribe-auth/ABVk15XAr8fEeVuh69wSA75EnOK4ELQ_ks5vGhJAgaJpZM4WvXzO
.

sean-abbott picture sean-abbott on 24 Jan 2019
Was this page helpful?
0 / 5 - 0 ratings

Related issues

McLoo picture McLoo  ·  3Comments
TarkanY picture TarkanY  ·  3Comments
halb9 picture halb9  ·  3Comments
gesus14 picture gesus14  ·  3Comments
ploum picture ploum  ·  3Comments