Signal-android: Signal gets unresponsive over time and ultimately crashes

[piratenpanda]

• [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

My Signal installation has become quite large over time (over 16GB) and with the most recent version starts to lag after a while, message threads sometimes take 20s to load, keyboard opens after a few seconds etc. I don't know if this is a stock android 10 bug or related to signal. I attached a log.

Steps to reproduce

• use signal

Actual result:

Signal becomes very unresponsive over time and I need to restart my phone to return it to normal

Expected result:

Signal should stay responsive

Device info

Device: Google Pixel 2 XL
Android version: 10.0
Signal version: 4.50.6

Link to debug log

https://debuglogs.org/2087f1943a113227fd1944cfd6ee3488893cd7320ba5e11e312a1de8eee253ad

[EukalyptusX]

Same here. If you need any logs or something, let me know.

Deleting cache or erase old messages (500 max. each conversation) doesn't help. Only a restart fixes the problem for some time.

Device info:

OnePlus 5T
Lineage 16.0 (Android 9)
Signal version: 4.49.18

[greyson-signal]

It's not clear from the log what's happening. I'm at least going to add some more metrics to the log in 4.51. Is there a backup running during this time?

@EukalyptusX Logs would be helpful.

[EukalyptusX]

No, there's no backup running.
I try to get the logs asap.

[piratenpanda]

Also no backup here

[EukalyptusX]

Hi, i faced the issue again at about 12:35-12:40 and it's getting worse now. If I won't restart now, the conversations activity will stay blank for minutes until it's finally loaded. Here's the log file:

https://debuglogs.org/169d7e8e641ee15456af64e7834b6653a1c897e1c85d114688fb24f70868dcde

I don't know if this has to do something, but I found this in the log. Maybe it has something to do with allocated space?

12-05 12:47:17.737 5503 5665 I crime.securesm: Alloc concurrent copying GC freed 291(23KB) AllocSpace objects, 1(700KB) LOS objects, 0% free, 511MB/512MB, paused 83us total 5.420s

0% free seems bad somehow :D

[greyson-signal]

@EukalyptusX If you're using the web release, can you update to 4.50.x?

For everyone, if you're using the play store release, can you join the beta and post a new log? I added some FPS tracking metrics that logs when there's big frame drops, which should help us correlate stuff in the logs better. Thanks!

[piratenpanda]

@greyson-signal some log with the beta version https://debuglogs.org/48c92d1163586317049051247009d2270b7a2188810760002640650d74e22376

[greyson-signal]

@piratenpanda

Hmm... possible garbage collection issues? Pasting logs for reference.

12-08 12:20:33.727  4076 17925 I crime.securesm: Waiting for a blocking GC Alloc
12-08 12:20:33.728  4076 17924 I crime.securesm: Waiting for a blocking GC Alloc
12-08 12:20:34.245  4076 20397 I crime.securesm: Waiting for a blocking GC Alloc
12-08 12:20:34.780  4076  5029 I crime.securesm: Waiting for a blocking GC Alloc
12-08 12:20:35.372  4076  4125 I crime.securesm: Clamp target GC heap from 530MB to 512MB
12-08 12:20:35.372  4076  4125 I crime.securesm: Background concurrent copying GC freed 101481(5091KB) AllocSpace objects, 7(344KB) LOS objects, 1% free, 506MB/512MB, paused 68us total 3.364s
12-08 12:20:35.373  4076  4076 I crime.securesm: WaitForGcToComplete blocked Alloc on HeapTrim for 3.350s
12-08 12:20:35.373  4076  4076 I crime.securesm: Starting a blocking GC Alloc
12-08 12:20:35.373  4076  4356 I crime.securesm: WaitForGcToComplete blocked Alloc on HeapTrim for 3.263s
12-08 12:20:35.373  4076  4356 I crime.securesm: Starting a blocking GC Alloc
12-08 12:20:35.373  4076 20776 I crime.securesm: WaitForGcToComplete blocked Alloc on HeapTrim for 1.647s
12-08 12:20:35.373  4076 20776 I crime.securesm: Starting a blocking GC Alloc
12-08 12:20:35.373  4076 17925 I crime.securesm: WaitForGcToComplete blocked Alloc on HeapTrim for 1.646s
12-08 12:20:35.373  4076 17925 I crime.securesm: Starting a blocking GC Alloc
12-08 12:20:35.374  4076 17924 I crime.securesm: WaitForGcToComplete blocked Alloc on HeapTrim for 1.645s
12-08 12:20:35.374  4076 17924 I crime.securesm: Starting a blocking GC Alloc
12-08 12:20:35.374  4076 20397 I crime.securesm: WaitForGcToComplete blocked Alloc on HeapTrim for 1.129s
12-08 12:20:35.374  4076 20397 I crime.securesm: Starting a blocking GC Alloc
12-08 12:20:35.374  4076 20397 W WebSocketConnection: WSC onMessage()
12-08 12:20:35.374  4076  5029 I crime.securesm: WaitForGcToComplete blocked Alloc on HeapTrim for 594.580ms
12-08 12:20:35.374  4076  5029 I crime.securesm: Starting a blocking GC Alloc
12-08 12:20:35.374  4076 20397 W WebSocketConnection: Message Type: 1
12-08 12:20:35.375  4076  4266 I IncomingMessageObserver: Retrieved envelope! 
12-08 12:20:35.380  4076  4266 D IncomingMessageProcesso: Lock acquired by thread 282 (MessageRetrievalService)
12-08 12:20:35.380  4076  4266 I IncomingMessageProcesso: Received message. Inserting in PushDatabase.
12-08 12:20:35.380  4076  4266 V Cursor  : Filling cursor window with start position:0 required position:0
12-08 12:20:35.388  4076  4266 D IncomingMessageProcesso: Lock about to be released by thread 282 (MessageRetrievalService)
12-08 12:20:35.389  4076  4266 D IncomingMessageObserver: Network requirement: true, app visible: true, gcm disabled: false
12-08 12:20:35.390  4076  4266 I IncomingMessageObserver: Reading message...
12-08 12:20:35.396  4076  4264 I JobSchedulerScheduler: Scheduling a run in 0 ms.
12-08 12:20:35.398  4076  4264 I Job     : [JOB::7dd192b2-66ea-4515-b369-e758772a33f9][PushDecryptJob] onSubmit() (Time Since Submission: 10 ms, Lifespan: Immortal, Run Attempt: 1/Unlimited)
12-08 12:20:35.404  4076  4514 I JobRunner: [JOB::7dd192b2-66ea-4515-b369-e758772a33f9][PushDecryptJob][1] Running job. (Time Since Submission: 16 ms, Lifespan: Immortal, Run Attempt: 1/Unlimited)
12-08 12:20:35.405  4076  4514 D WakeLockUtil: Acquired wakelock with tag: signal:********-****-****-****-**********f9
12-08 12:20:35.405  4076  4514 V Cursor  : Filling cursor window with start position:0 required position:0
12-08 12:20:35.421  4076  4076 I Choreographer: Skipped 203 frames!  The application may be doing too much work on its main thread.
12-08 12:20:35.421  4076  4076 W FrameRateTracker: Bad frame! Took 3400 ms (204 dropped frames, or 0.29 FPS)

And again:

12-08 12:20:38.725  4076  4076 I crime.securesm: Waiting for a blocking GC Alloc
12-08 12:20:40.069  4076  4125 I crime.securesm: Background young concurrent copying GC freed 56435(3507KB) AllocSpace objects, 3(124KB) LOS objects, 0% free, 508MB/512MB, paused 125us total 1.357s
12-08 12:20:40.070  4076  4076 I crime.securesm: WaitForGcToComplete blocked Alloc on HeapTrim for 1.344s
12-08 12:20:40.070  4076  4076 I crime.securesm: Starting a blocking GC Alloc
12-08 12:20:40.094  4076  4286 I OpenGLRenderer: Davey! duration=1444ms; Flags=1, IntendedVsync=36819491874344, Vsync=36819525207676, OldestInputEvent=9223372036854775807, NewestInputEvent=0, HandleInputStart=36819534856032, AnimationStart=36819534887699, PerformTraversalsStart=36819535005876, DrawStart=36820922735493, SyncQueued=36820927004869, SyncStart=36820927273931, IssueDrawCommandsStart=36820927446379, SwapBuffers=36820935449349, FrameCompleted=36820936685807, DequeueBufferDuration=181000, QueueBufferDuration=763000, 
12-08 12:20:40.098  4076  4076 I Choreographer: Skipped 83 frames!  The application may be doing too much work on its main thread.
12-08 12:20:40.098  4076  4076 W FrameRateTracker: Bad frame! Took 1400 ms (84 dropped frames, or 0.71 FPS)

[EukalyptusX]

New logs with version 4.50.5:
https://debuglogs.org/8889a6abab9fbd8d122220a2c76d6a2c0b56d431027e99aafb6a241b3cd50c9e

The issue started at about 10:43

Here's a snippet:

12-11 10:43:21.406 6891 6891 I KeyboardAwareLinearLayout: onKeyboardOpen(670) 12-11 10:43:21.406 6891 6891 I MediaKeyboard: hide() 12-11 10:43:21.423 6891 6891 I crime.securesm: Waiting for a blocking GC Alloc 12-11 10:43:22.139 6891 6904 I crime.securesm: Clamp target GC heap from 534MB to 512MB 12-11 10:43:22.139 6891 6904 I crime.securesm: Background concurrent copying GC freed 44200(1776KB) AllocSpace objects, 5(224KB) LOS objects, 0% free, 510MB/512MB, paused 176us total 1.961s 12-11 10:43:22.140 6891 6891 I crime.securesm: WaitForGcToComplete blocked Alloc on HeapTrim for 717.422ms 12-11 10:43:22.140 6891 6891 I crime.securesm: Starting a blocking GC Alloc 12-11 10:43:22.142 6891 6891 I Choreographer: Skipped 43 frames! The application may be doing too much work on its main thread. 12-11 10:43:22.145 6891 11460 I OpenGLRenderer: Davey! duration=740ms; Flags=1, IntendedVsync=174764640202656, Vsync=174764640202656, OldestInputEvent=9223372036854775807, NewestInputEvent=0, HandleInputStart=174764640507722, AnimationStart=174764640525275, PerformTraversalsStart=174764640526420, DrawStart=174764656948453, SyncQueued=174765376996025, SyncStart=174765377076598, IssueDrawCommandsStart=174765377763161, SwapBuffers=174765379815296, FrameCompleted=174765380522952, DequeueBufferDuration=176000, QueueBufferDuration=306000, 12-11 10:43:22.268 6891 9739 V Cursor : Filling cursor window with start position:0 required position:0 12-11 10:43:22.296 6891 9737 V Cursor : Filling cursor window with start position:0 required position:0

[1337haXXor]

I'm having this same issue. I'm not sure if it's this one or the other report related to not having Google Play Services. I recently restarted my phone, but after I have it running for a couple days, I'll submit a log.

[1337haXXor]

Okay, program running for 16 hours and I'm at 1.1GB RAM usage...

Looking at each of the individual processes, the culprit is WebRtcCallServices; when I stopped that RAM dropped completely. It seems to be a process related to Signal phone calls?

Which is also of not, as my Signal will do video calls, but I receive no audio.. That's just a separate issue I have been having for a couple weeks.

[EukalyptusX]

I'm having this same issue. I'm not sure if it's this one or the other report related to not having Google Play Services. I recently restarted my phone, but after I have it running for a couple days, I'll submit a log.

If it's of interest, I don't have Google Play Services installed either.

[piratenpanda]

Stock pixel 2xl with Google play services here

[piratenpanda]

Signal was using 1,4 GB of RAM it happened the last time here so #9251 might really be related

[piratenpanda]

Definitely RAM related. Maybe this could help? https://github.com/signalapp/Signal-Android/pull/9221

[piratenpanda]

Still happening with latest stable

[piratenpanda]

Sorry for spamming the bug tracker but it really gets annoying having to kill signal to make it usable again. Any plans to reduce ram usage?

[gfs]

https://debuglogs.org/a587faffa5264b7f82ef3b3563b10955b6c05c1d06b651b2ab4c3e0d4cf6c6df

Encountered this issue and had to restart my phone to make it usable again. Log taken after restart.

[jeremymasters]

Getting a lot of lag here as well on 4.57.2 with galaxy s10+. Restart cures it.
https://debuglogs.org/c38c275d5d19f4c9326c4059bab78652a01f9e669c46081bc99bc1e1f8e6f571