Messages don't come in immediately

[awnumar]

Bug description

Incoming messages don't always come in immediately. Sometimes, even with the app open, messages don't come in until minutes or even hours after they were sent.

Link to debug log

Here's a debug log from a friend who it affected too: https://gist.github.com/takhlaq/1bfa1144cb79b6bb7380cc3abbe827df

I'll submit a debug log from my own device (Nexus 6P Android 7.0) when it happens again.

[riyapenn]

In case you haven't already checked out steps from the support page regarding Doze mode & Android Marshmallow permissions please make sure have enabled all the permissions for Signal. Specifically for Marshmallow OS: Go to Android Phone Settings > Apps > Signal > App Permissions > Enable all permissions. Even if this is enabled, please re-toggle the setting (turn it off and back on) and restart your phone.

[awnumar]

Doze only turns on when the screen is off, and even more rarely in
marshmallow than in Android. Are you sure that's causing it? This happens
even when I have the app open and screen on.

On 6 Sep 2016 21:24, "riyapenn" notifications@github.com wrote:

In case you haven't already checked out steps from the support page
http://support.whispersystems.org/hc/en-us/articles/213190487-Why-is-there-a-delay-in-receiving-messages-
regarding Doze mode & Android Marshmallow permissions please make sure have
enabled all the permissions for Signal. Specifically for Marshmallow OS: Go
to Android Phone Settings > Apps > Signal > App Permissions > Enable all
permissions. Even if this is enabled, please re-toggle the setting (turn it
off and back on) and restart your phone.

—
You are receiving this because you authored the thread.
Reply to this email directly, view it on GitHub
#5670 (comment),
or mute the thread
https://github.com/notifications/unsubscribe-auth/AIhzn7BfQYZSN2KT0UU3yKKAJ5y5BBpGks5qncwMgaJpZM4J14m_
.

[awnumar]

Here's my debug log. Seems to be a few errors in it: https://gist.github.com/24da1610df87f8abb92ccd1ada516aad

[anoxi]

I can confirm this with Nexus 5 on Android 6 and latest Nova Launcher (without Teslaunread), my debug log https://gist.github.com/anoxi/dc10f8a39c7c923e51b333423dfb558f

Error Messages with com.teslacoilsw.notifier might point to Teslaunread Plugin of Nova Launcher, dont know if this is related.

I'll install Teslaunread and report back.

[awnumar]

I'm also running nova launcher but without teslaunread. Might be related.

On 29 Sep 2016 12:14, "Alexander Nolis" notifications@github.com wrote:

I can confirm this with Nexus 5 on Android 6 and latest Nova Launcher, my
debug log https://gist.github.com/anoxi/dc10f8a39c7c923e51b333423dfb558f

Error Messages with com.teslacoilsw.notifier might point to Teslaunread
Plugin of Nava Launcher, dont know if this is related.

—
You are receiving this because you authored the thread.
Reply to this email directly, view it on GitHub
#5670 (comment),
or mute the thread
https://github.com/notifications/unsubscribe-auth/AIhzn1EtD9afNBygaO9QL5sB7wrc6HUkks5qu52ogaJpZM4J14m_
.

[anoxi]

I've installed Teslaunread and still get messages delayed. In "Message details" the time difference of "Sent" and "Received" ranges between some seconds and 10 minutes.
Interestingly, i got the same message in about 20 seconds on the desktop app and over 5 minutes on Android.
The delayed messages all came from an user on iOS, i could not reproduce this with someone on Android.

[awnumar]

In my case, the delayed messages are from another android user, but this
anecdotal evidence may be slightly skewed since the majority of my
conversations on signal are with the aforementioned person.

On 29 Sep 2016 19:07, "Alexander Nolis" notifications@github.com wrote:

I've installed Teslaunread and still get messages delayed. In "Message
details" the time difference of "Sent" and "Received" ranges between some
seconds and 10 minutes.
Interestingly, i got the same message in about 20 seconds on the desktop
app and over 5 minutes on Android.
The delayed messages all came from a user on iOS, i could not reproduce
this with someone on Android.

—
You are receiving this because you authored the thread.
Reply to this email directly, view it on GitHub
#5670 (comment),
or mute the thread
https://github.com/notifications/unsubscribe-auth/AIhzn9Eyy5xeUyPUWlIW0UZDWLKep9v1ks5qu_5xgaJpZM4J14m_
.

[anoxi]

I just tested messaging from ios to myself on wifi and could not reproduce this.
Maybe mobile networking issues cause transmission delays, although I doubt my partner had a 10 minutes signal loss.

[anoxi]

This time I received a message from an ios user twice, first one took 4 seconds, the second one about 1 hour.

[Hedaja]

Me and my conversation partner have seen something similar.
For me it seems to work at the moment but a while ago I usually only got all the messages at once when I newly opened the App. Doze mode is deactivated for the app and all permissions are given. My friend using an IOS device had the same problm in the last few days.

[bme13]

While having a conversation with someone, all of a sudden a message just got one check mark and this lasted for more than 5 minutes. While typing a new message (requesting a debug log from that person) I've noticed the message received a 2nd check mark, so the situation resolved itself. However I've added the debug log because from that it seems there is nearly 10 minutes of no activity. The log contains 2 messages send by me (from desktop app). One at 13:26. This one seemed to be handled correctly and the message with the delay which is send at 13:33. I've also asked the contact about the message timestamps for that message and those were:
Sent 8 nov. 2017 1:33:25 p.m. CET
Received 8 nov. 2017 1:43:46 p.m. CET
From the logfile I guess the line:
13:33:54.891 14275 14275 W GcmBroadcastReceiver: GCM message...
is where the push message is triggered. The next line is then at 13:43:44.891 which happens to be nearly 10 minutes later and at the same ms. That might be a coincidence but perhaps there is some timeout?
https://gist.github.com/anonymous/49af3fcd2feb6e68a3245d3f5f4b58af

[moxie0]

@bme13 From that log, it looks as if the OS killed the app immediately after 13:33. What you see at 13:44 is the entire app being started again. It's possible that the owner also has a task killer, or that they manually killed the app as well.

[bme13]

I've just asked and he's not aware of any task killer. He's sure he didn't manually killed Signal (we were actually in a conversation) Sorry to be ignorance but is that line: GcmBroadcastReceiver: GCM message the moment a push message was received? If so, that would mean the OS killed the app at exact the moment a message was received. What would trigger the app being started again? Would that only be my contact opening Signal? I'll meet him tomorrow and see if we can find out what exactly happened.

[moxie0]

@bme13 Yes that's the moment a GCM message was received. It seems that the OS did kill the app immediately or very shortly after. I assume that the app restarted when it was manually opened, but Android doesn't really make any guarantees about these things.

[bme13]

Just noticed this again with different phone. I did send a message from my partners phone to my own phone and didn't get a notification. On the sending phone I just got one tick. After waiting a while I decided to connect my phone to the computer since I didn't want to open Signal (that would probably trigger things and would result in the notification) In logcat I saw a couple of "Early receipt" lines, not sure what those mean. They seem from just before the actual message was send. After waiting longer (>10minutes) I opened Signal on my phone and indeed I got a notification that a message was received. The details of that message are:
Send: 8 dec. 1017 12:36:07 CET
Received: 8 dec. 12:47:31 CET
Here are the logs I've gathered:
logcat, please note that this is not the full logcat, only around the send time. If you think the full logcat would be useful please let me know. Though I prefer to not add that to the ticket.
logcat.txt
Receiving phone log:
https://gist.github.com/anonymous/238c2701d49d168773dbb16e2d712e22
And to be complete also the log from the sending phone:
https://gist.github.com/anonymous/005862feea97093d0d0a7e8dea8f9510
I hope it's of any help.

[bme13]

Hope I don't bother you too much with another occurrence. Yesterday I've got 2 Signal notifications after unlocking my phone. It appears someone send me 2 messages like 20-30 minutes ago and I didn't receive them until unlocking the phone. When checking the details of the messages these are:
msg 1:
Send 12 dec. 2017 14:24:35 CET
Received 12 dec. 2017 14:54:12 CET
msg 2:
Send 12 dec 2017 14:37:44 CET
Received 12 dec. 2017 14:54:14 CET
Now, in the logfile I see 2 lines:

12-12 14:24:39.233 18772 18772 W GcmBroadcastReceiver: GCM message...
12-12 14:37:48.941 18772 18772 W GcmBroadcastReceiver: GCM message...

To me it seems a bit like the log from Nov 8th (although that was a log from a contact's phone, this one is from my own phone) However since it contains 2 GCM message lines I would not expect that the application was killed in between both lines.
https://gist.github.com/anonymous/19884a69976fce00239d07d6479d7ca6

[automated-signal]

GitHub Issue Cleanup:
See #7598 for more information.