Anti-ctrl commented 4 years ago

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

Bug description

If I have a long Chat with someone, probably multiple thousand Messages and Media in History, then the Chat gets REALLY slow. We talking about 40-50 sec for one Message to get send and it only gets slower. If you send multiple Messages after the first one, it can take up to multiple Minutes till they get send. Receiving Messages takes ~10-15 sec. Short Chats dont seem to be affected. Its the most brutal if the other Person is writing/answering at the same time as your Message sends. Signal gets really laggy, the phone gets hot and slow, till anything is sent. Not related to this, but maybe Interesting: Backups take around 3 hours to finish. Backupfile is around 7GB in Size.

Steps to reproduce

Open Signal
Go to Chat with long History (opening and closing that Chat is also really slow)
Send one or Multiple Messages

Actual result: Messages take sometimes Minutes to Send. Expected result: Messages should be send almost instant, like in a fresh Chat.

Device info

Device: Galaxy S5 klte / SM-G900F and One Plus 6T Android version: 9.0 LineageOS 16 / Stock Rom Signal version: 4.68.8, persists in 4.69.6, persists in 4.70.3, persists in 4.70.5, persists in 5.8.10, solved in 5.20.4

Link to debug log

https://debuglogs.org/fff230b9173168bd607d678f019b51b7dc38c12ced3661f169c51e1968b147d8

EDIT: New Log, while sending and receiving Messages at the same time:

https://debuglogs.org/7eead199b7af5be480058d38b128f766cf4536beb0be0b4a24aa2ad962aada09

EDIT2: Now (28th Aug) the Problem is so bad, that the App gets nearly unusable. Messages take around 90 Seconds to get send. Only in that one, long Chat. As long as one Message in that Chat is sending, anything else is almost not responding and the App locks up sometimes. Even receiving Messages in that Chat is so slow, that sometimes the Person thinks i lost connection or turned off my Phone. Isnt there anything that can be done, without loosing all the History ? I used Whatsapp for some time before and had Chats with around 30-40k Messages and NEVER had any Problems like that, why is it, that Signal has such poor Performance ?

EDIT3 (4th Nov): Time to send one Message went up to ~130 secs. Pics dont always send. Just the Text under them. App is barely usable whenever i access a long Chat.

EDIT4 (Feb 2021): Changed Phone from a Galaxy S5 with Snapdragon 801 and 2GB RAM, to a One Plus 6T with Snapdragon 845 and 8GB RAM. Problem still persists, but is better thanks to more Raw Power. Chat still gets slower every Day, even tho not as noticeable anymore, probably also thanks to more power.

EDIT5 (18th Aug 2021): Problem seems resolved. Performance in a long Chat is drastically Improved with Version 5.20.4. A Message takes around 2-3 seconds now, which i consider "instant". Good Job Guys and Girls!

Probably Related

9881

teynav commented 3 years ago

Hi Wheest, I have 90 Gb free storage on my device and 6 gb of ram where around 3gb is always free , there's nothing i do on phone except calling and texting someone, not even browsing (very rarely) .So this is not any issue related to available free space or RAM. This must be something related to database optimization.

JordyEGNL commented 3 years ago

Yes this is sometimes the case, when for example I'm sending 3 messages after each other, and my chat partner sends a message after he received the first one, my other 2 messages stay at the loading icon until I have received his message on my phone.

Try and Trigger that Behavior and then Post a Debug Log here Immediately after. Do the same on the Other Side. More Debuglogs=more better.

You can find the Option for that in the App under Options --> More Options. Hope its translated like that, as my App is in German.

https://debuglogs.org/740243c2005660b15ba94b124f9c8d656c85f33de9b446c87ae712a23cd8bd23

This is the debug log, at around 09:55

Edit April 19th: Another debug log :) https://debuglogs.org/a7e01e62557992f1ccd766853f41002f739cb74971f57d949de210bb8b7e2064

niktss commented 3 years ago

https://debuglogs.org/0782c079cb52fa04e4cc7e927d35e223f8d3f259cda70ce695a9b7764bc46dac

gabrc52 commented 3 years ago

Seems like this happens on slower phones. Didn't happen on a Xiaomi Redmi Note 8, but does happen on a Moto G Play (low-speced phone for today's standards).

https://debuglogs.org/cadfc090a6b76c6807e31700dccd74a1e66ec9c6e8c4d2b6a47f05fea15da873 , sent a message near the end of the debug log (I'm not using the phone to message due to this very issue) Edit: seems like it's longer, so there are other messages in the debug log

niktss commented 3 years ago

Seems like this happens on slower phones.

I'm assuming newer phones have it too, they're just fast enough to cover it up

suganth215 commented 3 years ago

I'm using an Oneplus Nord and I'm from India. Been using signal on both wifi and mobile data. On both of them sending and receiving messages is slow. My friends are also having the same issue. I joined signal on January. By then it was fine. But for the past month or so it is so slow. I'm the one who made my friends use signal, they are thinking of leaving signal. This is a letdown from signal's part

https://debuglogs.org/779cdb4cbc2574cd7328fca58e9801a28eb8f1817e2fa09a0ecc80fdb961e016

gabrc52 commented 3 years ago

Seems like this happens on slower phones.

I'm assuming newer phones have it too, they're just fast enough to cover it up

Yes, even on faster phones it took like 3 or 4 seconds, which wasn't that big of a deal, but other apps send messages instantly (but they don't do any encryption).

suganth215 commented 3 years ago

No that isn't the case. If it is like that all the time then it's not an issue. But it was faster earlier.

On Thu, Apr 22, 2021, 11:44 PM Gabriel Rodríguez @.***> wrote:

Seems like this happens on slower phones.

I'm assuming newer phones have it too, they're just fast enough to cover it up

Yes, even on faster phones it took like 3 or 4 seconds, which wasn't that big of a deal, but other apps send messages instantly (but they don't do any encryption).

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/signalapp/Signal-Android/issues/9930#issuecomment-825076495, or unsubscribe https://github.com/notifications/unsubscribe-auth/AOCKMFLLI2HOB6CC5PAQCELTKBRQDANCNFSM4QBCELZQ .

Nisc3d commented 3 years ago

Yes, even on faster phones it took like 3 or 4 seconds, which wasn't that big of a deal, but other apps send messages instantly (but they don't do any encryption).

If you compare it to Whatsapp, which uses the same encryption protocol, even Whatsapp is faster. So stronger encryption can not be a excuse here.

suganth215 commented 3 years ago

I'm not comparing whatsapp with signal here. I'm comparing the signal of january to signal of april.

On Thu, Apr 22, 2021, 11:51 PM Nisc3d @.***> wrote:

Yes, even on faster phones it took like 3 or 4 seconds, which wasn't that big of a deal, but other apps send messages instantly (but they don't do any encryption).

If you compare it to Whatsapp, which uses the same encryption protocol, even Whatsapp is faster. So stronger encryption can not be a excuse here.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/signalapp/Signal-Android/issues/9930#issuecomment-825080991, or unsubscribe https://github.com/notifications/unsubscribe-auth/AOCKMFJKIRFYPSGEYS4U7QTTKBSJFANCNFSM4QBCELZQ .

gabrc52 commented 3 years ago

I see, I haven't tested WhatsApp, but I will install it and test to see if it happens there.

From what's been said here, and my own testing, it seems like the time it takes to send a message is proportional to the size of the conversation (this could be quantified to see if this correlation really is true, but it seems so), which means that for some reason sending a message is O(N) where N is the number of messages on the mobile app 😬. It should be O(1) and not depend on the size of the conversation.

gabrc52 commented 3 years ago

I'm not comparing whatsapp with signal here. I'm comparing the signal of january to signal of april.

Ah, then it's a regression (a recent-ish change introduced the bug).

suganth215 commented 3 years ago

The actual problem has to do something with the servers. The amount of people using signal has been significantly increased. That's the issue here. They have to buy more servers.

On Thu, Apr 22, 2021, 11:54 PM Gabriel Rodríguez @.***> wrote:

I see, I haven't tested WhatsApp, but I will install it and test to see if it happens there.

From what's been said here, and my own testing, it seems like the time it takes to send a message is proportional to the size of the conversation (this could be quantified to see if this correlation really is true, but it seems so), which means that for some reason sending a message is O(N) where N is the number of messages on the mobile app 😬. It should be O(1) and not depend on the size of the conversation.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/signalapp/Signal-Android/issues/9930#issuecomment-825083188, or unsubscribe https://github.com/notifications/unsubscribe-auth/AOCKMFOAW75DIEOFHILAOFLTKBSV7ANCNFSM4QBCELZQ .

Nisc3d commented 3 years ago

Ah, then it's a regression (a recent-ish change introduced the bug).

But this GitHub issue is from August 17 2020. I think the issue was introduced some months earlier.

suganth215 commented 3 years ago

That makes sense. Maybe it is some sort of a bug that a cluster of people has

On Thu, Apr 22, 2021, 11:57 PM Nisc3d @.***> wrote:

Ah, then it's a regression (a recent-ish change introduced the bug).

But this GitHub issue is from August 17 2020. I think the issue was introduced some months earlier.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/signalapp/Signal-Android/issues/9930#issuecomment-825084824, or unsubscribe https://github.com/notifications/unsubscribe-auth/AOCKMFO6DVO23TXK3AXFIPLTKBS75ANCNFSM4QBCELZQ .

gabrc52 commented 3 years ago

But this GitHub issue is from August 17 2020

Ah, yes, true.

The actual problem has to do something with the servers

I don't think it's a server issue.

But it's at least Android-specific, because on Signal desktop the messages send pretty fast (pretty much instantly).

And if a more powerful phone means less time to send messages, it also points to the bug probably being in the client side.

Nisc3d commented 3 years ago

Yes, it's an Android Client issue. The iOS App and the Desktop App don't have this Problem as far as I know.

And I think we shouldn't discuss this here further, unless we can add something useful to the issue because everytime someone replies, everyone on this isssue get's an email.

suganth215 commented 3 years ago

Speaking on signal desktop, the signal desktop takes eternity to load

On Thu, Apr 22, 2021, 11:58 PM Gabriel Rodríguez @.***> wrote:

But this GitHub issue is from August 17 2020

Ah, yes, true.

The actual problem has to do something with the servers

I don't think it's a server issue.

But it's at least Android-specific, because on Signal desktop the messages send pretty fast (pretty much instantly).

And if a more powerful phone means less time to send messages, it also points to the bug probably being in the client side.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/signalapp/Signal-Android/issues/9930#issuecomment-825086043, or unsubscribe https://github.com/notifications/unsubscribe-auth/AOCKMFJJA24KOWCQZBDJKBLTKBTGNANCNFSM4QBCELZQ .

suganth215 commented 3 years ago

I mean the initial loading

On Fri, Apr 23, 2021, 12:00 AM suganth @.***> wrote:

Speaking on signal desktop, the signal desktop takes eternity to load

On Thu, Apr 22, 2021, 11:58 PM Gabriel Rodríguez @.***> wrote:

But this GitHub issue is from August 17 2020

Ah, yes, true.

The actual problem has to do something with the servers

I don't think it's a server issue.

But it's at least Android-specific, because on Signal desktop the messages send pretty fast (pretty much instantly).

And if a more powerful phone means less time to send messages, it also points to the bug probably being in the client side.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/signalapp/Signal-Android/issues/9930#issuecomment-825086043, or unsubscribe https://github.com/notifications/unsubscribe-auth/AOCKMFJJA24KOWCQZBDJKBLTKBTGNANCNFSM4QBCELZQ .

Nisc3d commented 3 years ago

Please don't discuss Desktop issues here. Here is the right place for this specific issue: https://github.com/signalapp/Signal-Desktop/issues/5030

And just as a general reminder: if you want to have general conversation about signal or about feature requests go to the Signal Forum: https://community.signalusers.org/

Anti-ctrl commented 3 years ago

But it's at least Android-specific, because on Signal desktop the messages send pretty fast (pretty much instantly).

And if a more powerful phone means less time to send messages, it also points to the bug probably being in the client side.

I can assure you that this is not only a Problem on the Mobile App. I noticed slower sending Messages also on the Desktop, as the Chat Size increases. Also the Desktop App gets really sluggish as long as a Message sends and short after sending (a few seconds)

I'm assuming newer phones have it too, they're just fast enough to cover it up

Yes, this is true and i already talked about that further up. I switched from a Galaxy S5 to a OnePlus 6T. Messages send faster now, but as the Messages in the Chat increase, the sending times gets longer and longer.

Attach Debuglogs if yall can and please take the Discussion to the Forums if Possible, thanks.

ultrajae commented 3 years ago

I want to jump in on this-

I have NOT read this whole thread, other than the OP, but I think my issue is the same

My chat has over 250K messages in it going back 4 years.

I'm using an Essential PH-1.

It's gotten slower and slower to send messages (after the first one I send it seems) Can be 30 seconds or more.

Since the desktop version updated to v5, it has ALSO become impossibly slow when sending in THIS concersation- 1 to 3 (three!) minutes per line in the same conversation.. And the desktop client was NOT "attached" from the beginning, so it probably has about 180K messages if I had to guess (maybe less)

It's Windows 7 Corei5 with 8GB of RAM, and I know some ppl will complain to upgrade, and "that's your problem", but at least on the desktop id definitely ISN'T.. because I didn't have this issue on desktop until it updated to V5.

AND, I do NOT have the issue on the phone OR the desktop on EITHER platform in SHORT conversations I have going. They work pretty normally.

If there was a way that I could archive the super long conversation, and have it somehow "detached" from ongoing conversation (but still be accessibly and searchable in the app), that would be ideal.

I honestly don't know what to do because I DON'T want to delete my history but it's getting impossible to simply, "chat", on either platform (desktop is worse now since V5, fwiw)

Thanks

*I would be happy to provide logs if it would help in any way

niktss commented 3 years ago

If there was a way that I could archive the super long conversation, and have it somehow "detached" from ongoing conversation (but still be accessibly and searchable in the app), that would be ideal.

I honestly don't know what to do because I DON'T want to delete my history but it's getting impossible to simply, "chat", on either platform (desktop is worse now since V5, fwiw)

You can archive it. It will remain accessible, although a bit hidden from the main screen. https://support.signal.org/hc/en-us/articles/360007321231-Archiving-or-unarchiving-chats

ultrajae commented 3 years ago

You can archive it. It will remain accessible, although a bit hidden from the main screen. Yeah but once someone sends a text it's automatically "un-archived", so it becomes active again, and thus the same problem.

I wish it would archive and "detach" from the active chat.

That would solve the issue I think.

Salmon-Bard commented 3 years ago

To solve this issue forever developers must implement active window loading which lets the app only load a preset number of conversations to the active chat window screen based on where your scroll location is within a long conversation. As the user scrolls through the chat window the out of visible screen area gets unloaded and new conversions will be loaded at the location you reach after scrolling stops.

This will lower the processing, memory, GPU resource needed to render and display the app UI area making it very responsive. I feel that their android team needs to be improved in terms of skills and experience .

On Sat, Apr 24, 2021 at 10:58 AM ultrajae @.***> wrote:

You can archive it. It will remain accessible, although a bit hidden from the main screen. Yeah but once someone sends a text it's automatically "un-archived", so it becomes active again, and thus the same problem.

I wish it would archive and "detach" from the active chat.

That would solve the issue I think.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/signalapp/Signal-Android/issues/9930#issuecomment-826053716, or unsubscribe https://github.com/notifications/unsubscribe-auth/ADAYFYUY54XACMEV37NZAS3TKJ23HANCNFSM4QBCELZQ .

niktss commented 3 years ago

To solve this issue forever developers must implement active window loading which lets the app only load a preset number of conversations to the active chat window screen based on where your scroll location is within a long conversation.

Check greyson-signal's comment on this issue from the 4th of December. As far as I understand it, they already do this optimisation.

Also, I'm sure it's a competent team, though limited by resources.

Salmon-Bard commented 3 years ago

Thanks for pointing that out. I'm not referring to competence but rather pointing out what could be the cause. My next suggestion if the already have active window loading not fixing the problem is making use of CPU, GPU, RAM monitoring tools to define resources intensive issues. Google have you covered in their studio and play store to track events resources mapp.

Another advice for our friends at signal is to redesign the UI with flat: no components transitions, effects, and multilayer layouts. This will definitely improve performance on old devices with limited resources.

I just wish they are more open to contributions from the community to get more free resources on their hands.

On Sat, Apr 24, 2021 at 12:55 PM Frivolous2 @.***> wrote:

To solve this issue forever developers must implement active window loading which lets the app only load a preset number of conversations to the active chat window screen based on where your scroll location is within a long conversation.

Check greyson-signal's comment on this issue from the 4th of December. As far as I understand it, they already do this optimisation.

Also, I'm sure it's a competent team, though limited by resources.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/signalapp/Signal-Android/issues/9930#issuecomment-826067311, or unsubscribe https://github.com/notifications/unsubscribe-auth/ADAYFYWK3HA4BSCH5TTT4JDTKKIQHANCNFSM4QBCELZQ .

ProactiveServices commented 3 years ago

@cody-signal would you lock this issue, please? I need to stay subscribed to it as it rules out my using larger groups, but am sick of the lack of netiquette degenerating the conversation.

Salmon-Bard commented 3 years ago

If you are feeling sick of people complaining about your app issues then I think you should take some pells and get some rest off the team. Lock the damn thing we just need more donations to get it fixed!!!

On Sat, Apr 24, 2021 at 3:04 PM Adam Piggott @.***> wrote:

@cody-signal https://github.com/cody-signal would you lock this issue, please? I need to stay subscribed to it as it rules out my using larger groups, but am sick of the lack of netiquette degenerating the conversation.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/signalapp/Signal-Android/issues/9930#issuecomment-826082812, or unsubscribe https://github.com/notifications/unsubscribe-auth/ADAYFYVIDGYFW3Z6JT3BA4TTKKXUVANCNFSM4QBCELZQ .

ultrajae commented 3 years ago

To solve this issue forever developers must implement active window loading which lets the app only load a preset number of conversations to the active chat window screen based on where your scroll location is within a long conversation.

Honestly I'm not sure how this would remedy the issue--

It doesn't seem to have anything to do with the number of conversations one has going (I only have a few)--

The problem (for me anyway), is clearly that Signal can't handle large conversations-

250K message history (only 3 members) over the past 4+ years, makes this group chat molasses when I try to send a text (other members don't keep all messages so it's snappy for them)--

On Android, and NOW on desktop too (especially since v5.. It was pretty "okay" on the previous version, even with the large history).

At the same time, if I go into other groups or conversations with only a short history (hundreds of msgs), my texts appear instantly (like normal).

Also, desktop is WORSE than Android now.. 20-30 secs on Android vs 1-3 minutes on desktop for my texts to appear, ESPECIALLY if I try to send more than two texts in a row. It's unbearable.

hiqua commented 3 years ago

For performance issues please always attach debug logs, otherwise you're not helping.

Signal-Desktop has improved recently performance-wise, so if you still encounter big slowdowns your debug logs would definitely be appreciated.

gabrc52 commented 3 years ago

We have sent multiple debug logs in this issue's thread. Here is a compilation of them:

hiqua commented 3 years ago

We have sent multiple debug logs in this issue's thread. Here is a compilation of them:

Old debug logs are way less relevant. They contain some issues that have been fixed. They might contains clues about other issues for which more logging has been added since then.

If you still have problems with the latest version and want to help out, post a new debug log. That's the most helpful thing you can do really, short of debugging the issue yourself and coming with a small nice fix yourself.

I was mostly answering to the comment above mine by the way.

gabrc52 commented 3 years ago

Okay

I'm submitting a debug log from the latest version 5.9.7

https://debuglogs.org/9e7111ed7d3a1742e97034d61dc52880380a2795e95018098c498b9dba0b2a9c

On Sun, May 9, 2021, 3:39 PM Quentin Hibon @.***> wrote:

We have sent multiple debug logs in this issue's thread. Here is a compilation of them:

Old debug logs are way less relevant. If you still have problems with the latest version and want to help out, post a new debug log. That's the most helpful thing you can do really, short of debugging the issue yourself and coming with a small nice fix yourself.

I was mostly answering to the comment above mine by the way.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/signalapp/Signal-Android/issues/9930#issuecomment-835883571, or unsubscribe https://github.com/notifications/unsubscribe-auth/AFZ4HIWXVKDCBXHKHUC3HHTTM3XINANCNFSM4QBCELZQ .

sjlua commented 3 years ago

https://debuglogs.org/0b791c6320948dbf64677f25bdad1b5c33da3e9b6f541f09ef70d40a0617a05d

5.10.7 - Redmi Note 8 Pro - Android 10 - Custom ROM - 6GB RAM

https://community.signalusers.org/t/sending-a-message-takes-a-long-time/29057?u=sirsean

Referenced the issue there.

ultrajae commented 3 years ago

Sorry just want to explicitly ask- Is there anything "sensitive" in a debug log that one might be concerned about posting publicly?

I'd like to post one too

gabrc52 commented 3 years ago

Probably metadata like the time you spend on Signal and how many people you talk to. But phone numbers, names, etc, they're all censored.

ProactiveServices commented 3 years ago

Sorry just want to explicitly ask- Is there anything "sensitive" in a debug log that one might be concerned about posting publicly?

Take a look through those posted here and you'll see they're well-redacted.

ultrajae commented 3 years ago

Here's my log.

https://debuglogs.org/c423abc580f56c7aab5048a1c71e3c20e70ff477313fd96117d7551a83c67db8

It's almost impossible to have a conversation in the long chat. It can take 60 seconds or more for multiple messages to go through and my cpu pins (the fans kick on to full speed)

It was decidedly NOT like this prior to updating to v5 (this is desktop).

Also, here's the log from the same instance from my phone I just captured. https://debuglogs.org/5e935294682fc7a3a2fcbb9c0db6076607dd18b3e3ce38c6bf699acf3a2ad0ee

Sending messages is also painfully slow (similarly on multiple messages consecutively) but not AS slow as the desktop.

Nisc3d commented 3 years ago

Here's my log.

https://debuglogs.org/c423abc580f56c7aab5048a1c71e3c20e70ff477313fd96117d7551a83c67db8

It's almost impossible to have a conversation in the long chat. It can take 60 seconds or more for multiple messages to go through and my cpu pins (the fans kick on to full speed)

It was decidedly NOT like this prior to updating to v5 (this is desktop).

This issue is reserved for the Android Version of Signal. You can post your log to a new or existing Desktop issue here: https://github.com/signalapp/Signal-Desktop/issues

sunflowerspeed commented 3 years ago

I'm suffering from this issue as well as of a few days ago.

https://debuglogs.org/1469dfbd8afb9f06fe09f62c83fb65d5c853e61a0a2953267c259956975f6153

Galaxy S10 (Exynos), Android 11.

ultrajae commented 3 years ago

Here's my log. https://debuglogs.org/c423abc580f56c7aab5048a1c71e3c20e70ff477313fd96117d7551a83c67db8 It's almost impossible to have a conversation in the long chat. It can take 60 seconds or more for multiple messages to go through and my cpu pins (the fans kick on to full speed) It was decidedly NOT like this prior to updating to v5 (this is desktop).

This issue is reserved for the Android Version of Signal. You can post your log to a new or existing Desktop issue here: https://github.com/signalapp/Signal-Desktop/issues

Thank you, and done: https://github.com/signalapp/Signal-Desktop/issues/5263

Note I updated my above comment here with my Android log since these issues seems to be related if not the same.

Anti-ctrl commented 3 years ago

The New Version of the Desktop App fixed the Issue i had, with the Long sending times within a long chat, at least on the Desktop. Underneath is a Debuglog from the Desktop App, while spamming some messages. Underneath that is a Log from my Phone. Both taken a few minutes apart from each other.

Debuglog Desktop App: https://debuglogs.org/9568ebe309602e793d50fe51d2e5acdc82ab15749b78d4ecb84d439ca29bf184 Debuglog Phone: https://debuglogs.org/cd7961d2653cd7f3730e5f99d1b543c65fcafddeb9552ecba225fb800b71ca87

I tried to get a third Logfile from my Chatpartner, from the same time, but their Version of Signal is still older, so i advised to do an Update and will try it again tomorrow or so and Post probably another few Logfiles. I hope that helps to solve the Problem. Maybe someone can spot differences in both Logfiles. Spamming occurred at around 20:13 o'clock.

ultrajae commented 3 years ago

The New Version of the Desktop App fixed the Issue i had, with the Long sending times within a long chat, at least on the Desktop. Underneath is a Debuglog from the Desktop App, while spamming some messages. Underneath that is a Log from my Phone. Both taken a few minutes apart from each other.

Debuglog Desktop App: https://debuglogs.org/9568ebe309602e793d50fe51d2e5acdc82ab15749b78d4ecb84d439ca29bf184 Debuglog Phone: https://debuglogs.org/cd7961d2653cd7f3730e5f99d1b543c65fcafddeb9552ecba225fb800b71ca87

I tried to get a third Logfile from my Chatpartner, from the same time, but their Version of Signal is still older, so i advised to do an Update and will try it again tomorrow or so and Post probably another few Logfiles. I hope that helps to solve the Problem. Maybe someone can spot differences in both Logfiles. Spamming occurred at around 20:13 o'clock.

Same exact events occurred here too, only it was something on the backend that happened to "fix" the desktop issues (I have a thread where this was acknowledged here: https://github.com/signalapp/Signal-Desktop/issues/5263)

It would be great if the desktop development team could get together with the mobile app team on this as the symptoms are identical, and the desktop client is perfect once again.

It truly seems like the exact same issue that is (was) afflicting both applications

Anti-ctrl commented 3 years ago

Same exact events occurred here too, only it was something on the backend that happened to "fix" the desktop issues (I have a thread where this was acknowledged here: signalapp/Signal-Desktop#5263)

Yeah i saw your Thread and that lead me to including a Desktop Log too.

Promised Logfiles:

My Phone: https://debuglogs.org/c31d11194156c94717fbf5b95b35b85aaa6bd41904c8c793cb96536e8c9cda91 Chat Partner: https://debuglogs.org/cbe9c93a74cd012daafa890765d6a1301e9362ae4be529c972dbaaad69e49851

Taken at the same time, with maybe 2 Seconds difference. Both phones where still sending and receiving Messages from each other. One on 4G, one on Wifi, just to ensure its not the Network.

It would be great if the desktop development team could get together with the mobile app team on this as the symptoms are identical, and the desktop client is perfect once again.

^ This.

mrliuws commented 3 years ago

Messages taking >10s, up to 30s to send.

Hope the logfile helps.

Logfile: https://debuglogs.org/0e20cc32eb6789149df6c8c921177384ec7f31ee36febc908042b2ed859e1ff6

hwinnemoe commented 3 years ago

I tried creating a backup and restoring from it, but it did not improve the issue. In long chats, sending a message still can take up to 25 seconds depending on the method. I can always send messages in these slow chats faster by sending them and returning to the conversation list. There seems to be some added cost when keeping the conversation open. Completely new chats send instantly with any method.

Debug log and details

https://debuglogs.org/f386a3601431b25c016196c808eb464004ccb425af997fa0ae44f4b23ccc1543
Message ID 1622894558220 was sent while keeping the conversation open and took 25 seconds to send
Message ID 1622894621742 was sent and I immediately closed the conversation, it took 13 seconds to send
Device: Sony Xperia Z2, Android version: 6.0.1
Signal version: 5.12.3

gabrc52 commented 3 years ago

@hwinnemoe Thanks for your log! I think this is the first time in this thread someone has done more than submitting the debug log (including me), since you've pinpointed the message IDs that take long to send.

It seems that the calls to size() function, which seems to count the number of messages in the thread, seem to add up a lot, at least 7.9 seconds (!) in this fragment:

I'll paste the part that seems relevant

``` 06-05 14:02:44.800 24342 24412 I PushTextSendJob: [JOB::830dec3a-477b-42fc-9d3c-6470d5edc933][PushTextSendJob][1622894558220] Sending message: 358164, Recipient: RecipientId::131, Thread: 51 (Time Since Submission: 4292 ms, Lifespan: 86400000 ms, Run Attempt: 1/Unlimited) 06-05 14:02:44.806 24342 8461 D ConversationDataSource: size() for thread 51: 64 ms 06-05 14:02:44.815 24342 24408 I JobRunner: [JOB::26648f5f-1a93-4ef2-b97c-3a11ef6c4c4e][TrimThreadJob][1] Running job. (Time Since Submission: 4325 ms, Lifespan: Immortal, Run Attempt: 1/1) 06-05 14:02:44.816 24342 24408 I JobRunner: [JOB::26648f5f-1a93-4ef2-b97c-3a11ef6c4c4e][TrimThreadJob][1] Job finished with result SUCCESS in 2 ms. (Time Since Submission: 4327 ms, Lifespan: Immortal, Run Attempt: 1/1) 06-05 14:02:44.828 24342 24342 D SnapToTopDataObserver: Scrolling to top. 06-05 14:02:48.087 24342 8609 D ConversationListDataSou: [load(0, 41), UnarchivedConversationListDataSource] cursor: 3287 cache-recipients: 1 total: 3288 06-05 14:02:48.087 24342 8609 W FixedSizePagingController: onDataNeededAroundIndex(2) Invalidated! Just after data was loaded. 06-05 14:02:48.097 24342 24395 D MarkReadHelper: Marking 0 messages as read. 06-05 14:02:50.375 24342 24412 I PushSendJob: Ensuring we have these certificates [UUID_AND_E164] 06-05 14:02:50.375 24342 24412 D PushSendJob: Certificate UUID_AND_E164 is valid 06-05 14:02:50.375 24342 24412 D PushSendJob: All certificates are valid. 06-05 14:02:50.378 24342 24412 I UnidentifiedAccessUtil: Unidentified: 1, Other: 0. Types: {UUID_AND_E164=1} 06-05 14:02:50.379 24342 24412 I PushTextSendJob: [JOB::830dec3a-477b-42fc-9d3c-6470d5edc933][PushTextSendJob][1622894558220] Have access key to use: true (Time Since Submission: 9870 ms, Lifespan: 86400000 ms, Run Attempt: 1/Unlimited) 06-05 14:02:50.379 24342 24412 W SignalServiceMessageSender: No attachments present... 06-05 14:02:50.419 24342 24385 I MessageNotifierV2: State is empty, cancelling all notifications 06-05 14:02:50.419 24342 24385 D NotificationCancellatio: cancelLegacy() called with: notificationId = [1338] 06-05 14:02:50.429 24342 8609 D ConversationDataSource: [load(0, 100), thread 51] messages: 2328 mentions: 14 conversion: 0 total: 2342 06-05 14:02:50.429 24342 8609 W FixedSizePagingController: onDataNeededAroundIndex(0) Invalidated! Just after data was loaded. 06-05 14:02:50.446 24342 31237 D ConversationListDataSou: [size(), UnarchivedConversationListDataSource] 5192 ms 06-05 14:02:50.446 24342 8609 W FixedSizePagingController: onDataNeededAroundIndex(2) Invalidated! At beginning of load task. 06-05 14:02:50.447 24342 8461 D ConversationDataSource: size() for thread 51: 2355 ms 06-05 14:02:50.452 24342 31237 D ConversationListDataSou: [size(), UnarchivedConversationListDataSource] 6 ms 06-05 14:02:50.541 24342 8461 D ConversationDataSource: size() for thread 51: 88 ms 06-05 14:02:50.583 24342 8609 D ConversationListDataSou: [load(0, 41), UnarchivedConversationListDataSource] cursor: 125 cache-recipients: 5 total: 130 06-05 14:02:50.585 24342 8609 W FixedSizePagingController: onDataNeededAroundIndex(0) Invalidated! At beginning of load task. 06-05 14:02:52.593 24342 8609 D ConversationDataSource: [load(0, 100), thread 51] messages: 2007 mentions: 1 conversion: 0 total: 2008 06-05 14:02:52.623 24342 24412 W SignalServiceMessageSender: java.io.IOException: No connection! 06-05 14:02:52.623 24342 24412 W SignalServiceMessageSender: at org.whispersystems.signalservice.internal.websocket.WebSocketConnection.sendRequest(WebSocketConnection.java:185) 06-05 14:02:52.623 24342 24412 W SignalServiceMessageSender: at org.whispersystems.signalservice.api.SignalServiceMessagePipe.send(SignalServiceMessagePipe.java:195) 06-05 14:02:52.623 24342 24412 W SignalServiceMessageSender: at org.whispersystems.signalservice.api.SignalServiceMessageSender.sendMessage(SignalServiceMessageSender.java:1498) 06-05 14:02:52.623 24342 24412 W SignalServiceMessageSender: at org.whispersystems.signalservice.api.SignalServiceMessageSender.sendMessage(SignalServiceMessageSender.java:287) 06-05 14:02:52.623 24342 24412 W SignalServiceMessageSender: at org.thoughtcrime.securesms.jobs.PushTextSendJob.deliver(PushTextSendJob.java:179) 06-05 14:02:52.623 24342 24412 W SignalServiceMessageSender: at org.thoughtcrime.securesms.jobs.PushTextSendJob.onPushSend(PushTextSendJob.java:92) 06-05 14:02:52.623 24342 24412 W SignalServiceMessageSender: at org.thoughtcrime.securesms.jobs.PushSendJob.onSend(PushSendJob.java:112) 06-05 14:02:52.623 24342 24412 W SignalServiceMessageSender: at org.thoughtcrime.securesms.jobs.SendJob.onRun(SendJob.java:42) 06-05 14:02:52.623 24342 24412 W SignalServiceMessageSender: at org.thoughtcrime.securesms.jobs.BaseJob.run(BaseJob.java:32) 06-05 14:02:52.623 24342 24412 W SignalServiceMessageSender: at org.thoughtcrime.securesms.jobmanager.JobRunner.run(JobRunner.java:86) 06-05 14:02:52.623 24342 24412 W SignalServiceMessageSender: at org.thoughtcrime.securesms.jobmanager.JobRunner.run(JobRunner.java:49) 06-05 14:02:52.623 24342 24412 W SignalServiceMessageSender: 06-05 14:02:52.623 24342 24412 W SignalServiceMessageSender: [sendMessage] Unidentified pipe failed, falling back... 06-05 14:02:52.869 24342 24412 I SmsDatabase: Updating ID: 358164 to base type: 10485783 06-05 14:02:53.636 24342 24391 I IncomingMessageObserver: Retrieved envelope! 1622894572770 06-05 14:02:53.660 24342 24391 I Job : [JOB::28643239-09a8-4013-8d26-cbaa1919d41c][PushDecryptMessageJob] onSubmit() (Time Since Submission: 24 ms, Lifespan: Immortal, Run Attempt: 1/Unlimited) 06-05 14:02:53.662 24342 24391 D IncomingMessageObserver: Network: true, Foreground: true, FCM: true, Censored: false, Registered: true, Websocket Registered: true, Proxy: false 06-05 14:02:53.662 24342 24391 D IncomingMessageObserver: Reading message... 06-05 14:02:53.680 24342 24408 I JobRunner: [JOB::28643239-09a8-4013-8d26-cbaa1919d41c][PushDecryptMessageJob][1] Running job. (Time Since Submission: 44 ms, Lifespan: Immortal, Run Attempt: 1/Unlimited) 06-05 14:02:53.682 24342 24408 I libsignal-client: rust/protocol/src/sealed_sender.rs:540: deserializing UnidentifiedSenderMessage with version 1 06-05 14:02:53.698 24342 24408 I libsignal-client: rust/protocol/src/sealed_sender.rs:438: deserialized UnidentifiedSenderMessageContent from ********-****-****-****-**********db.3 with type Whisper 06-05 14:02:53.809 24342 24408 I libsignal-client: rust/protocol/src/session_cipher.rs:527: ********-****-****-****-**********db.3 creating new chains. 06-05 14:02:53.813 24342 24408 I libsignal-client: rust/protocol/src/state/session.rs:228: Trimming excessive receiver_chain for session with base key 89dc2e2b33529225ed0dead90946e15cd6c9c31ecec2a793c324b87c88343b71, chain count: 6 06-05 14:02:53.979 24342 24391 I IncomingMessageObserver: Retrieved envelope! 1622894573347 06-05 14:02:54.017 24342 24391 I Job : [JOB::89372e2d-6d2a-4fd5-b94f-7c0fb5181031][PushDecryptMessageJob] onSubmit() (Time Since Submission: 38 ms, Lifespan: Immortal, Run Attempt: 1/Unlimited) 06-05 14:02:54.021 24342 24391 D IncomingMessageObserver: Network: true, Foreground: true, FCM: true, Censored: false, Registered: true, Websocket Registered: true, Proxy: false 06-05 14:02:54.021 24342 24391 D IncomingMessageObserver: Reading message... 06-05 14:02:55.137 24342 24408 I Job : [JOB::3287e622-3291-4723-a868-7048436ae23f][PushProcessMessageJob] onSubmit() (Time Since Submission: 31 ms, Lifespan: Immortal, Run Attempt: 1/Unlimited) 06-05 14:02:55.142 24342 24408 I JobRunner: [JOB::28643239-09a8-4013-8d26-cbaa1919d41c][PushDecryptMessageJob][1] Job finished with result SUCCESS in 1462 ms. (Time Since Submission: 1506 ms, Lifespan: Immortal, Run Attempt: 1/Unlimited) 06-05 14:02:55.161 24342 24411 I JobRunner: [JOB::3287e622-3291-4723-a868-7048436ae23f][PushProcessMessageJob][4] Running job. (Time Since Submission: 55 ms, Lifespan: Immortal, Run Attempt: 1/Unlimited) 06-05 14:02:55.197 24342 24409 I JobRunner: [JOB::89372e2d-6d2a-4fd5-b94f-7c0fb5181031][PushDecryptMessageJob][2] Running job. (Time Since Submission: 1218 ms, Lifespan: Immortal, Run Attempt: 1/Unlimited) 06-05 14:02:55.206 24342 24409 I libsignal-client: rust/protocol/src/sealed_sender.rs:540: deserializing UnidentifiedSenderMessage with version 1 06-05 14:02:55.213 24342 24409 I libsignal-client: rust/protocol/src/sealed_sender.rs:438: deserialized UnidentifiedSenderMessageContent from ********-****-****-****-**********db.3 with type Whisper 06-05 14:02:55.222 24342 24412 I PushTextSendJob: [JOB::830dec3a-477b-42fc-9d3c-6470d5edc933][PushTextSendJob][1622894558220] Sent message: 358164 (Time Since Submission: 14714 ms, Lifespan: 86400000 ms, Run Attempt: 1/Unlimited) 06-05 14:02:55.222 24342 24412 I SendJob : Message send completed 06-05 14:02:55.223 24342 24412 I JobRunner: [JOB::830dec3a-477b-42fc-9d3c-6470d5edc933][PushTextSendJob][5] Job finished with result SUCCESS in 10449 ms. (Time Since Submission: 14715 ms, Lifespan: 86400000 ms, Run Attempt: 1/Unlimited) 06-05 14:02:55.232 24342 24411 I MessageContentProcessor: [1622894572770] Beginning message processing. 06-05 14:02:55.242 24342 31237 D ConversationListDataSou: [size(), UnarchivedConversationListDataSource] 106 ms 06-05 14:02:55.249 24342 8461 D ConversationDataSource: size() for thread 51: 109 ms 06-05 14:02:55.278 24342 24411 I Job : [JOB::b8e163f5-8898-4e47-927a-7c2c1c1cda24][SendDeliveryReceiptJob] onSubmit() (Time Since Submission: 32 ms, Lifespan: 86400000 ms, Run Attempt: 1/Unlimited) 06-05 14:02:55.311 24342 24411 I JobRunner: [JOB::3287e622-3291-4723-a868-7048436ae23f][PushProcessMessageJob][4] Job finished with result SUCCESS in 148 ms. (Time Since Submission: 203 ms, Lifespan: Immortal, Run Attempt: 1/Unlimited) 06-05 14:02:55.315 24342 24408 I JobRunner: [JOB::b8e163f5-8898-4e47-927a-7c2c1c1cda24][SendDeliveryReceiptJob][1] Running job. (Time Since Submission: 68 ms, Lifespan: 86400000 ms, Run Attempt: 1/Unlimited) 06-05 14:02:55.317 24342 24408 I UnidentifiedAccessUtil: Unidentified: 1, Other: 0. Types: {UUID_AND_E164=1} 06-05 14:02:55.336 24342 8609 D ConversationListDataSou: [load(0, 41), UnarchivedConversationListDataSource] cursor: 82 cache-recipients: 11 total: 93 06-05 14:02:55.354 24342 24409 I Job : [JOB::6810f050-c300-4bde-a5f6-ed5b4c9a2d7a][PushProcessMessageJob] onSubmit() (Time Since Submission: 29 ms, Lifespan: Immortal, Run Attempt: 1/Unlimited) 06-05 14:02:55.356 24342 24409 I JobRunner: [JOB::89372e2d-6d2a-4fd5-b94f-7c0fb5181031][PushDecryptMessageJob][2] Job finished with result SUCCESS in 159 ms. (Time Since Submission: 1377 ms, Lifespan: Immortal, Run Attempt: 1/Unlimited) 06-05 14:02:55.394 24342 24411 I JobRunner: [JOB::6810f050-c300-4bde-a5f6-ed5b4c9a2d7a][PushProcessMessageJob][4] Running job. (Time Since Submission: 59 ms, Lifespan: Immortal, Run Attempt: 1/Unlimited) 06-05 14:02:57.132 24342 24411 I MessageContentProcessor: [1622894573347] Beginning message processing. 06-05 14:02:57.132 24342 24411 I MessageContentProcessor: [MessageContentProcessor] Processing delivery receipts for IDs: 1622894558220 06-05 14:02:57.146 24342 24391 I IncomingMessageObserver: Retrieved envelope! 1622894574680 ```

This may have to do with the bug, since it's directly measuring the size of the conversation. However, tracing what that does, it seems to do a count(*) query to the SQLite database.

On searching "sqlite count linear instead of constant", I get this StackOverflow result which says that count(*) has a runtime of O(n). Some solutions are proposed there, but I think the count calls could be removed or moved, since I don't think they're a prerrequisite in order to send a message. Alternatively, the number of messages could be stored somewhere else and incremented as a new message is sent, or decremented as a message is deleted.

To be honest, I didn't look into it that deeply to see where the size() function is being called in order to send a message (I might try to in the future). I'm not sure at all why to send a message, you have to count the number of previous messages.

Something which would help is to reduce the number of calls to count(*)

Personal note: I bought a new, more powerful, device in part due to this bug; this bug makes me hesitate recommending Signal, since not everyone has the means to do so. So, I'm willing to do my part to solve this bug.

Anti-ctrl commented 3 years ago

@hwinnemoe Thanks for your log! I think this is the first time in this thread someone has done more than submitting the debug log (including me), since you've pinpointed the message IDs that take long to send.

I think the Problem here is, that ALL Messages take long to send, which is why no one pointed it out yet. Well.. And, at least for me, there is the noob factor involved, as i cant pin point a message in the log at all.

Nevertheless its quiet nice to see someone making progress, after almost one YEAR! Thanks alot for having a look and thanks to @hwinnemoe for being so precise! Good Job Guys/Girls! How difficult is it, to fix stuff like that and what Problems may occur if you reduce/(re-)move the count(*) thingy ? May it be possible to just run it while you do a backup or as a nightly Job ? Sorry for the stupid question, but kinda excited to see some Progress (finally!!)

ultrajae commented 3 years ago

Just updating to say I've timed more closely how long to send in my 250K message chat--

25-30 seconds for the first msg 1 min for the second 2 mins for the third- and more for subsequent msgs

Again, this is on consecutive messages sent (IOW, a back and forth active conversation).

It's pretty unusable tbh

As I stated earlier, the problem DID exist on the desktop version to, shortly after I updated to v5, AND further updated to v 5.1.0, but THEN the desktop team did something on their end, which made ALL OF THAT go away, and suddenly, v 5.1.0 was working normally, i.e., instant messaging. (and still working perfectly a.o. v 5.4.0)

My Android log is in my earlier post.

signalapp / Signal-Android

Signal gets really slow on long Conversations #9930

Bug description

Steps to reproduce

Device info

Link to debug log

9881