Signal-android: group messages don't get sent for a while

[dcherian]

• [ ] I have searched open and closed issues for duplicates
• [ ] I am submitting a bug report for existing functionality that does not work as intended
• [ ] I have read https://github.com/signalapp/Signal-Android/wiki/Submitting-useful-bug-reports
• [ ] This isn't a feature request or a discussion topic

---

Bug description

Group messages aren't getting sent for a while. I hada signal video call in the mean time so it's not necessarily a network issue.

Steps to reproduce

• send a message and wait

Actual result: message doesn't get sent
Expected result: message gets sent immediately

Device info

Device: Nokia 6.1
Android version: 8.1.0
Signal version: 4.29.5

Link to debug log

https://debuglogs.org/3b26aaada0fc34b0f7231aa0586b5d62114334a9f32ffe15e98a000514174653

[dcherian]

My friend on the same group had the same issue yesterday and today. It's frustrated him enough that he has quit

[greyson-signal]

It looks like you're getting rate-limited:

10-25 20:51:52.803 12339 12524 I Job     : [6838bbbe-f9e7-442e-bd79-7993e6331dfb] PushGroupSendJob :: Retrying after a retryable exception. (Time since submission: 804187 ms, Run attempt: 5)
10-25 20:51:52.803 12339 12524 I Job     : org.whispersystems.signalservice.api.push.exceptions.RateLimitException: Rate limit exceeded: 413
10-25 20:51:52.803 12339 12524 I Job     :  at org.whispersystems.signalservice.internal.push.PushServiceSocket.makeServiceRequest(PushServiceSocket.java:754)
10-25 20:51:52.803 12339 12524 I Job     :  at org.whispersystems.signalservice.internal.push.PushServiceSocket.getPreKeys(PushServiceSocket.java:257)
10-25 20:51:52.803 12339 12524 I Job     :  at org.whispersystems.signalservice.api.SignalServiceMessageSender.getEncryptedMessage(SignalServiceMessageSender.java:774)
10-25 20:51:52.803 12339 12524 I Job     :  at org.whispersystems.signalservice.api.SignalServiceMessageSender.getEncryptedMessages(SignalServiceMessageSender.java:754)
10-25 20:51:52.803 12339 12524 I Job     :  at org.whispersystems.signalservice.api.SignalServiceMessageSender.sendMessage(SignalServiceMessageSender.java:654)
10-25 20:51:52.803 12339 12524 I Job     :  at org.whispersystems.signalservice.api.SignalServiceMessageSender.sendMessage(SignalServiceMessageSender.java:632)
10-25 20:51:52.803 12339 12524 I Job     :  at org.whispersystems.signalservice.api.SignalServiceMessageSender.sendMessage(SignalServiceMessageSender.java:196)
10-25 20:51:52.803 12339 12524 I Job     :  at org.thoughtcrime.securesms.jobs.PushGroupSendJob.deliver(PushGroupSendJob.java:211)
10-25 20:51:52.803 12339 12524 I Job     :  at org.thoughtcrime.securesms.jobs.PushGroupSendJob.onPushSend(PushGroupSendJob.java:107)
10-25 20:51:52.803 12339 12524 I Job     :  at org.thoughtcrime.securesms.jobs.PushSendJob.onSend(PushSendJob.java:71)
10-25 20:51:52.803 12339 12524 I Job     :  at org.thoughtcrime.securesms.jobs.SendJob.onRun(SendJob.java:49)
10-25 20:51:52.803 12339 12524 I Job     :  at org.thoughtcrime.securesms.jobs.MasterSecretJob.onRun(MasterSecretJob.java:18)
10-25 20:51:52.803 12339 12524 I Job     :  at org.thoughtcrime.securesms.jobmanager.Job.doWork(Job.java:75)
10-25 20:51:52.803 12339 12524 I Job     :  at androidx.work.Worker$1.run(Worker.java:95)
10-25 20:51:52.803 12339 12524 I Job     :  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162)
10-25 20:51:52.803 12339 12524 I Job     :  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636)
10-25 20:51:52.803 12339 12524 I Job     :  at java.lang.Thread.run(Thread.java:764)

Can I ask how large the group is that you're in?

[dcherian]

I suspected so. It's 5 numbers including me but 2 of those don't work.

Are messages being worde queued up for delivery to those?

[greyson-signal]

By "2 of those don't work", what do you mean?

And looking at the logs I can't say if a message is going to a specific person or not. All I know is that there's some GroupSendJobs that aren't going out because the service thinks you've gone over a send limit.

[dcherian]

It's a group with 5 numbers, 2 of which aren't active.

What is the send limit?

[greyson-signal]

What is the send limit?

There's various limits we have in place for different server actions to prevent abuse. You shouldn't be able to hit them in normal usage, but here we are :)

2 of which aren't active

Ok, so does that mean that they've uninstalled Signal, but are still in the group? Do you know if they manually unregistered before doing so?

If you long-press a message that you've successfully sent and look at the message details (by pressing the 'i' button in the action bar), what do you see in terms of checkmarks next to people's names? For a message that is stuck sending, do the same thing and tell me what you see there as well.

Thank you!

[dcherian]

Ok, so does that mean that they've uninstalled Signal, but are still in the group? Do you know if they manually unregistered before doing so?

The numbers are in the group. One was a typo. The second's been uninstalled; not sure if they deregisterd.

If you long-press a message that you've successfully sent and look at the message details (by pressing the 'i' button in the action bar), what do you see in terms of checkmarks next to people's names?

Delivered to everyone but the 2 numbers above.

For a message that is stuck sending, do the same thing and tell me what you see there as well.

When this happened, I only saw a spinner in the main conversation view. The check mark appeared 20 minutes after hitting send.

[dcherian]

Happening right now in a single person conversation

https://debuglogs.org/98d50512d2c480f37b1892d98b22aef88f8f027d5de07bed6f0b2254defb1040

Message hasnt sent for 10 minutes and I have internet access right now. When i hit the info button on the message I see "pending"

[dcherian]

Still hasnt sent after 45 minutes. I tried sending another one and it's pending too. I'm receiving messages from the other person.

https://debuglogs.org/c07c5c227690ddd187b2ba38bc513a1208509712b3a1662ad89f63e89b9cddac

Update: messages were finally sent
https://debuglogs.org/5f1a22f460a61829e129aceef4fdba93e20bd4a221f41963f3a55bca853e84cd

[kyleedwardsny]

This is affecting me too. Very annoying in groups with dead numbers :(

[brownstic]

This is affecting me too. Very annoying in groups with dead numbers :(

Yeah true and same here

[dcherian]

Again trouble in a single person conversation. This is becoming unusable

https://debuglogs.org/8d0300b8fa2fef9eefdc21c3ef5db25d627527116fc48050c801ab82964b791d

I hit send at approximately 14.19. hasn't sent in twenty minutes now

[AtHeartEngineer]

Our group chats are also having the same issue, multiple of my friends are reporting it...and since I'm the one who convinced everyone to switch to signal, here I am.

Some of the messages never get sent. Most of them come out of order, and it's across multiple group chats.

Debug: https://debuglogs.org/3303cfaa3e5eb617f16330ed744808cefd188ba98e58c1e8078469bb0a756d37

[Someguitarist]

I can confirm the issues with @AtHeartEngineer above. I can also confirm that for @greyson-signal that my issues aren't just rate limits but messages just not sending. On mobile I hit the rate limit regularly with one number, so I'm used to the rate limit issue. But in the last week messages get stuck with the spinning circle. If I open the desktop app 30 minutes later the messages that I've sent aren't there, and I can confirm via regular text that no one has seen them.

It also seems to be causing multiple messages to come out of order. Suddenly I'll receive a message that's 'New' but saying it was delivered up to ~20-30 minutes later. After confirming with the sender, I can confirm that he did send it 30 minutes ago and I'm only just now receiving it out or order in my messages.

Oddly if I restart my phone, a few of my 'Stuck Circle' messages will go through, but not all. Force closing the app doesn't seem to work. I'd say this started just a few days ago.

Edit: I can also now confirm that the problem exists on both Android and Apple. No problem with the desktop client as of yet.

[dcherian]

Restarting did not help in both my cases.

[WoodenGhost]

I have the same issue in a group chat with few members, one of which is not active.
Restarting also didn't help.

[greyson-signal]

@AtHeartEngineer It looks like you're also bumping into the rate limit issue. It looks like we're somehow mishandling situations when you start group chats with new people, or when you have people in a group chat that have unregistered.

@Someguitarist How are you confirming that this isn't a rate limit issue? Can you provide a debug log?

@dcherian Your situation is different. Originally you had a rate limiting issue, but in your one-on-one conversations, what's basically happening is that we're telling the system to schedule a job to send your message, and the system is choosing to delay that send for a long time. Given that you have network and your app is foregrounded at the time, it shouldn't be delaying it, but every phone can potentially have a different implementation of JobScheduler, so here we are. I'll have to think of a way to work around it.

@WoodenGhost Please provide a debug log.

[WoodenGhost]

@greyson-signal Thank you for the quick response and your work in general!
Here is the debug log.

[greyson-signal]

@WoodenGhost Thanks for the log! However, I don't see anything in this log to indicate a longer-than-normal send time? There was one case where a send took ~4s (not unreasonable in poor network or if there was an attachement), but the majority took < 100ms.

The log only covers ~2.5 hrs. Did the long send happen before then? If so, can you send a debug log the next time you see it happen? Thanks!

[2-4601]

Reporting in behalf of a friend:

• Messages in one group have not been sent since 3-4 days (and other members confirm they haven't received anything from that user since 3-4 days in that group).
• Sent messages have the spinning status indicator.
• Receiving messages works
• There are 12 members in the group (plus around 5 slave devices)
• 1 member (+**********07) is not a Signal user anymore and has unregistered at some point but still lives on as a zombie user in the group.
• Same device with @dcherian but Android 9 and Signal 4.29.7

Debug logs:
1) https://debuglogs.org/766c48c8bef03892f247e7a0a2734ff397c342c0d067ac93fd4256b7a37f46e4
2) I couldn't find anything in the first log so I asked my friend to try sending a new message to the group and capture another log (I believe he tried to remove the thread in the mean time and we tried to update the group too): https://debuglogs.org/04547856287a0edb1d00e1f3091536d8ca6015ebeca69b9c04c3f3a0181e437e
3) I didn't see any rate limit errors in the new log so I asked one more https://debuglogs.org/9cd1da91b430cfac9f1ad8e1c834b9415c18c156b26960003ea2693ec1d7d96d

No rate limit errors in the last log either but sending messages still doesn't work in this group.

I have no clue what's causing this.

[WoodenGhost]

@greyson-signal Yes it happend slightly before that time. Also I'm currently not getting this problem when posting in the same group. I restarted the phone once in between, but an earlier restart hadn't helped. Will post a log as soon as I see this again.

[greyson-signal]

@2-4601 What I'm seeing in logs 2+3 is that there's a group thread (appears to be jobId 2ef7adc4-a599-41cd-9cd7-dce4f0ea22b0) where sends aren't even being attempted. However, this is almost certainly because there's pending messages that have to be sent before new ones can be attempted. So the problem is that the earliest unsent message isn't being sent, and it's blocking the sending of all later messages.

The thing is, that original message should have failed to send some time ago if the JobScheduler chose to ran it, since at minimum we fail message sends that are over a day old, prompting the user to manually resend. That tells me that the JobScheduler might not have even attempted that message send yet for whatever reason. Could be a bug in either the JobScheduler or WorkManager (the wrapper around JobScheduler that we use).

If this ever happens in a different group, try to grab a log as soon as you notice a message is taking longer than it should to send, and maybe we can see the initial failure.

[Someguitarist]

Sorry for the late response, been traveling. It could be related to the rate limit but I don't get that message when looking at the info for the message. It actually happened to me again and I managed to both capture the log here https://debuglogs.org/032eef20f3afd9c507098ebc6c6f6076fb573bf8188e919a3bd2b01e9d62659b and a few images of the problem here https://imgur.com/a/4WNarPx

I blanked out the names for privacy reasons, but this message went ~45 minutes or so before it went through. I don't have images from the other side of the problem at the moment, but what happens when receiving these messages is that they appear at the bottom of the conversation looking most recent, but with a time stamp of an hour ago or however long it took to send.

I can confirm that this happens both on Android and iPhone platforms. Oddly whenever I have the issue the desktop client still seems to send fine.

I hope this is moved up the priority rung a bit, because obviously not being able to send messages and receiving them out of order is completely unacceptable for a messaging platform. Our group is discussing the possibility of moving to an alternative platform because multiple users are having this issue.

[greyson-signal]

@Someguitarist

Thank you for the log!

It could be related to the rate limit but I don't get that message when looking at the info for the message.

Looking at your logs, you're also experiencing the rate-limit version of this problem. We don't surface this as a user-visible error because we consider it a "retry-able" failure, so we basically just keep trying to send it with linear backoff. Do you also have an unregistered user in your group? I think we may be making certain requests too often when you have a conversation that includes an unregistered user.

but what happens when receiving these messages is that they appear at the bottom of the conversation looking most recent, but with a time stamp of an hour ago or however long it took to send.

This happens because Signal will always sort messages by received_timestamp, but render the sent_timestamp in the bubble. This is to so people can't send you messages in the past, effectively changing your conversation history. I agree that this can result in some funny corner cases, but rendering the original sent_timestamp in the bubble is intended to resolve some of that confusion.

[2-4601]

If this ever happens in a different group, try to grab a log as soon as you notice a message is taking longer than it should to send, and maybe we can see the initial failure.

It happened again. The user reinstalled Signal after the first report to get rid of the issue but now it happened again in the same group.

Log:
https://debuglogs.org/ad6dc1d67d5f9bbc6a68f6b1f06a69c703b67fdb05068925d4ababb774e0a594
(now there are rate limits)

Please note that this is also a Nokia 6.1 device with Android Pie which has been reported in other issues as well.

[gehaxelt]

Just going to chime in here as another Signal user who had the same issue recently.

Please fix or increase the rate limits. It's pretty annoying :-/

[Someguitarist]

If this ever happens in a different group...

This is happening in all of our groups. We've just started remaking the groups entirely when we run into this issue without people who are idle. This isn't a random one-off occurrence, it's somewhat frequent.

[Trolldemorted]

Even our smaller groups (<30 members) are experiencing this problem. Weren't rate limits user-specific before?

[behrmann]

I've been experiencing this problem both in group conversations as well as one-to-one-conversations. Here are some logs.

[Trolldemorted]

In case you require more logs: https://debuglogs.org/0345247cb71791809370c3555170d0fc5c7cdea308d06949ed829216c992427b

Heavily delayed receives and sends occured at ~1100 local time (GMT+1).

[PiCob]

Hmm. Facing this since I updated from v4.29.x to v4.31.0.

Only on one of my phones (Moto G on Android 4.4.4), but not limited to groups (also in 1:1 convos).

I just created an entirely new group for test purposes - and even the first message failed to send. Receiving messages from another phone and/or group member works, though. Log:

https://debuglogs.org/4fb1020862b2b43fd44c5e205da8cbaf80eaf83bba155544600b4d815a76f551

Timestamps of message sending (the first two tries were in the newly created group, the third on in a 1:1 convo:
19:54:35, 19:55:54, 19:56:38 (MEZ)

Can't find any group or conversation with a pending message on that phone (but not absolutely ruling out that there has been a pending message that I already deleted).

Hope it helps.

[greyson-signal]

@PiCob The logs indicate that the group message sends at 19:54:35 and 19:55:54 both completed successfully.

• Can you elaborate what you mean by "failed to send"?
• Is the message still being shown as sending (spinning circle)?
• Did any of the recipients receive the message?
• How many people are in the group?
• What does the message details screen say -- are any of the messages marked as sent/delivered?

Unfortunately the logs don't continue to 19:56:38, so I can't see that message. Could you upload another log?

Thanks!

[PiCob]

Me idiot :facepalm:

You're absolutely right, the sending process seems to complete (1 checkmark, no more spinning circle - sorry for the confusion!), but the message never arrives at the recipient (although the messages in the other direction work absolutely fine). The group only contained my two phones.

[greyson-signal]

@PiCob Oh interesting, if you control both endpoints, can you send me logs from both devices? Thanks!

[PiCob]

Sure!

Sending phone: https://debuglogs.org/7b0b5018a4cbe0e269fc2fda526e78ba610b1029e860fe11cc273cd3df5ec68c

(Not) receiving phone:
https://debuglogs.org/132e7d8f40a74e89c522465f3aead73a0e658e68694519d86f00df5ea6ba72b3

[PiCob]

I just messaged someone else from the same phone and it worked. Seems the receiving side is the culprit and my issue is definitely different from what the OP is facing. I guess it's rather #8387 what I'm facing.

Sorry for mixing everything up here.

[2-4601]

More logs of recent occurrences:
https://debuglogs.org/2f40f12e178beb7093f4d9753b6abbbef0d3e1c2144e1c9dd4419e2d4136d0c2

[greyson-signal]

@2-4601 It appears this is still the rate-limiting version of the problem. We have some ideas in progress to address this. Thanks!

2018-11-27 17:04:18.349 GMT+02:00 I Job: [b314ba18-5e51-4870-89c5-e4a63961a3e0] PushGroupSendJob :: Retrying after a retryable exception. (Time since submission: 113604 ms, Run attempt: 4, isStopped: false)
2018-11-27 17:04:18.349 GMT+02:00 I Job: org.whispersystems.signalservice.api.push.exceptions.RateLimitException: Rate limit exceeded: 413
2018-11-27 17:04:18.349 GMT+02:00 I Job:    at org.whispersystems.signalservice.internal.push.PushServiceSocket.makeServiceRequest(PushServiceSocket.java:778)
2018-11-27 17:04:18.349 GMT+02:00 I Job:    at org.whispersystems.signalservice.internal.push.PushServiceSocket.getPreKeys(PushServiceSocket.java:280)
2018-11-27 17:04:18.349 GMT+02:00 I Job:    at org.whispersystems.signalservice.api.SignalServiceMessageSender.getEncryptedMessage(SignalServiceMessageSender.java:912)
2018-11-27 17:04:18.349 GMT+02:00 I Job:    at org.whispersystems.signalservice.api.SignalServiceMessageSender.getEncryptedMessages(SignalServiceMessageSender.java:888)
2018-11-27 17:04:18.349 GMT+02:00 I Job:    at org.whispersystems.signalservice.api.SignalServiceMessageSender.sendMessage(SignalServiceMessageSender.java:760)
2018-11-27 17:04:18.349 GMT+02:00 I Job:    at org.whispersystems.signalservice.api.SignalServiceMessageSender.sendMessage(SignalServiceMessageSender.java:734)
2018-11-27 17:04:18.349 GMT+02:00 I Job:    at org.whispersystems.signalservice.api.SignalServiceMessageSender.sendMessage(SignalServiceMessageSender.java:248)
2018-11-27 17:04:18.349 GMT+02:00 I Job:    at org.thoughtcrime.securesms.jobs.PushGroupSendJob.deliver(PushGroupSendJob.java:252)
2018-11-27 17:04:18.349 GMT+02:00 I Job:    at org.thoughtcrime.securesms.jobs.PushGroupSendJob.onPushSend(PushGroupSendJob.java:131)
2018-11-27 17:04:18.349 GMT+02:00 I Job:    at org.thoughtcrime.securesms.jobs.PushSendJob.onSend(PushSendJob.java:74)
2018-11-27 17:04:18.349 GMT+02:00 I Job:    at org.thoughtcrime.securesms.jobs.SendJob.onRun(SendJob.java:49)
2018-11-27 17:04:18.349 GMT+02:00 I Job:    at org.thoughtcrime.securesms.jobs.MasterSecretJob.onRun(MasterSecretJob.java:18)
2018-11-27 17:04:18.349 GMT+02:00 I Job:    at org.thoughtcrime.securesms.jobmanager.Job.doWorkInternal(Job.java:95)
2018-11-27 17:04:18.349 GMT+02:00 I Job:    at org.thoughtcrime.securesms.jobmanager.Job.doWork(Job.java:61)
2018-11-27 17:04:18.349 GMT+02:00 I Job:    at androidx.work.Worker$1.run(Worker.java:95)
2018-11-27 17:04:18.349 GMT+02:00 I Job:    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
2018-11-27 17:04:18.349 GMT+02:00 I Job:    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
2018-11-27 17:04:18.349 GMT+02:00 I Job:    at java.lang.Thread.run(Thread.java:764)

[greyson-signal]

The rate-limiting issue should be resolved, which is what I'm going to say has been the protagonist (antagonist?) of this thread. So I'm going to close it, but please reopen this if it's happening again, or open a new issue if you feel like you had a different sending problem that wasn't addressed. Thanks!

[kmkr]

I'm having the same, or at least a similar issue. In one of my group chats, I'm not longer able to send messages. I can receive from other people in the same group, but messages I try to send spins infinitely and are not received by other members of the group. Another Signal group works as expected, and sending directly to other people works fine. I got another person in the group to update the group. I see he updated it, but the problem persists.

There are 27 people in the group, a couple of them no longer on Signal.

Here's the log a minute or so after I've tried to send a message
https://debuglogs.org/5ee39099a621102f9ef3fe1fba5067152fe447c2bb8c8831c00b76471bae3c7b