Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Signal repeatly crash #8519

Closed
4 tasks done
ikino opened this issue Jan 9, 2019 · 7 comments
Closed
4 tasks done

Signal repeatly crash #8519

ikino opened this issue Jan 9, 2019 · 7 comments
Labels

Comments

@ikino
Copy link

ikino commented Jan 9, 2019


Bug description

Repeatly crash

Steps to reproduce

som messages didn't sent, after few hours I delete those messages and it begin crash

Actual result: crash
Expected result: not crash

Device info

Device: Lenovo Moto G5S+
Android version: 8.1.0
Signal version: 4.31.6

Link to debug log

01-09 19:39:55.678 13713 13828 W RetrieveProfileAvatarJob: null 01-09 19:39:55.678 13713 13828 W RetrieveProfileAvatarJob: org.whispersystems.signalservice.api.push.exceptions.NonSuccessfulResponseCodeException: Response: Response{protocol=h2, code=403, message=, url=https://cdn.signal.org/profiles/GoiQP6-7TE6WIHZn-ZT89g} 01-09 19:39:55.678 13713 13828 W RetrieveProfileAvatarJob: at org.whispersystems.signalservice.internal.push.PushServiceSocket.downloadFromCdn(PushServiceSocket.java:692) 01-09 19:39:55.678 13713 13828 W RetrieveProfileAvatarJob: at org.whispersystems.signalservice.internal.push.PushServiceSocket.retrieveProfileAvatar(PushServiceSocket.java:410) 01-09 19:39:55.678 13713 13828 W RetrieveProfileAvatarJob: at org.whispersystems.signalservice.api.SignalServiceMessageReceiver.retrieveProfileAvatar(SignalServiceMessageReceiver.java:114) 01-09 19:39:55.678 13713 13828 W RetrieveProfileAvatarJob: at org.thoughtcrime.securesms.jobs.RetrieveProfileAvatarJob.onRun(RetrieveProfileAvatarJob.java:99) 01-09 19:39:55.678 13713 13828 W RetrieveProfileAvatarJob: at org.thoughtcrime.securesms.jobmanager.Job.doWorkInternal(Job.java:99) 01-09 19:39:55.678 13713 13828 W RetrieveProfileAvatarJob: at org.thoughtcrime.securesms.jobmanager.Job.doWork(Job.java:65) 01-09 19:39:55.678 13713 13828 W RetrieveProfileAvatarJob: at androidx.work.Worker$1.run(Worker.java:57) 01-09 19:39:55.678 13713 13828 W RetrieveProfileAvatarJob: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162) 01-09 19:39:55.678 13713 13828 W RetrieveProfileAvatarJob: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636) 01-09 19:39:55.678 13713 13828 W RetrieveProfileAvatarJob: at java.lang.Thread.run(Thread.java:764) 01-09 19:39:55.679 13713 13828 W Job : [f5d7e892-d34e-424c-87f7-9bd61f99e0ca] RetrieveProfileAvatarJob :: Failing due to an exception. (Time since submission: 860 ms, Run attempt: 0, isStopped: false) 01-09 19:39:55.679 13713 13828 W Job : org.whispersystems.signalservice.api.push.exceptions.NonSuccessfulResponseCodeException: Response: Response{protocol=h2, code=403, message=, url=https://cdn.signal.org/profiles/GoiQP6-7TE6WIHZn-ZT89g} 01-09 19:39:55.679 13713 13828 W Job : at org.whispersystems.signalservice.internal.push.PushServiceSocket.downloadFromCdn(PushServiceSocket.java:692) 01-09 19:39:55.679 13713 13828 W Job : at org.whispersystems.signalservice.internal.push.PushServiceSocket.retrieveProfileAvatar(PushServiceSocket.java:410) 01-09 19:39:55.679 13713 13828 W Job : at org.whispersystems.signalservice.api.SignalServiceMessageReceiver.retrieveProfileAvatar(SignalServiceMessageReceiver.java:114) 01-09 19:39:55.679 13713 13828 W Job : at org.thoughtcrime.securesms.jobs.RetrieveProfileAvatarJob.onRun(RetrieveProfileAvatarJob.java:99) 01-09 19:39:55.679 13713 13828 W Job : at org.thoughtcrime.securesms.jobmanager.Job.doWorkInternal(Job.java:99) 01-09 19:39:55.679 13713 13828 W Job : at org.thoughtcrime.securesms.jobmanager.Job.doWork(Job.java:65) 01-09 19:39:55.679 13713 13828 W Job : at androidx.work.Worker$1.run(Worker.java:57) 01-09 19:39:55.679 13713 13828 W Job : at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162) 01-09 19:39:55.679 13713 13828 W Job : at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636) 01-09 19:39:55.679 13713 13828 W Job : at java.lang.Thread.run(Thread.java:764) 0

@ikino
Copy link
Author

ikino commented Jan 9, 2019

I found another error with logcat:

01-09 19:39:54.438 13713 13729 D Processor: Processor: processing 5c94bc00-dfe1-404c-9a28-6a9aadb27b34 01-09 19:39:54.458 13713 13818 I Job : [5c94bc00-dfe1-404c-9a28-6a9aadb27b34] PushGroupSendJob :: doWork() (Time since submission: 9950578 ms, Run attempt: 52, isStopped: false) 01-09 19:39:54.459 13713 13818 I Job : [5c94bc00-dfe1-404c-9a28-6a9aadb27b34] PushGroupSendJob :: doWorkInternal() (Time since submission: 9950579 ms, Run attempt: 52, isStopped: false) 01-09 19:39:54.501 13713 13818 I SendJob : Starting message send attempt 01-09 19:39:54.504 13713 13818 V Cursor : Filling cursor window with start position:0 required position:0 01-09 19:39:54.508 13713 13818 I chatty : uid=10139(org.thoughtcrime.securesms) pool-1-thread-2 identical 2 lines 01-09 19:39:54.511 13713 13818 V Cursor : Filling cursor window with start position:0 required position:0 01-09 19:39:54.512 13713 13818 I PushGroupSendJob: [5c94bc00-dfe1-404c-9a28-6a9aadb27b34] Sending message: 5076 (Time since submission: 9950632 ms, Run attempt: 52, isStopped: false) 01-09 19:39:54.513 13713 13818 E AndroidRuntime: FATAL EXCEPTION: pool-1-thread-2 01-09 19:39:54.513 13713 13818 E AndroidRuntime: Process: org.thoughtcrime.securesms, PID: 13713 01-09 19:39:54.513 13713 13818 E AndroidRuntime: java.lang.AssertionError: Not group: +421XXXXXXXXX 01-09 19:39:54.513 13713 13818 E AndroidRuntime: at org.thoughtcrime.securesms.database.Address.toGroupString(Address.java:127) 01-09 19:39:54.513 13713 13818 E AndroidRuntime: at org.thoughtcrime.securesms.jobs.PushGroupSendJob.onPushSend(PushGroupSendJob.java:127) 01-09 19:39:54.513 13713 13818 E AndroidRuntime: at org.thoughtcrime.securesms.jobs.PushSendJob.onSend(PushSendJob.java:78) 01-09 19:39:54.513 13713 13818 E AndroidRuntime: at org.thoughtcrime.securesms.jobs.SendJob.onRun(SendJob.java:56) 01-09 19:39:54.513 13713 13818 E AndroidRuntime: at org.thoughtcrime.securesms.jobmanager.Job.doWorkInternal(Job.java:99) 01-09 19:39:54.513 13713 13818 E AndroidRuntime: at org.thoughtcrime.securesms.jobmanager.Job.doWork(Job.java:65) 01-09 19:39:54.513 13713 13818 E AndroidRuntime: at androidx.work.Worker$1.run(Worker.java:57) 01-09 19:39:54.513 13713 13818 E AndroidRuntime: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162) 01-09 19:39:54.513 13713 13818 E AndroidRuntime: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636) 01-09 19:39:54.513 13713 13818 E AndroidRuntime: at java.lang.Thread.run(Thread.java:764) 01-09 19:39:54.513 13713 13818 E UncaughtExceptionLogger: 01-09 19:39:54.513 13713 13818 E UncaughtExceptionLogger: java.lang.AssertionError: Not group: +421XXXXXXXXX 01-09 19:39:54.513 13713 13818 E UncaughtExceptionLogger: at org.thoughtcrime.securesms.database.Address.toGroupString(Address.java:127) 01-09 19:39:54.513 13713 13818 E UncaughtExceptionLogger: at org.thoughtcrime.securesms.jobs.PushGroupSendJob.onPushSend(PushGroupSendJob.java:127) 01-09 19:39:54.513 13713 13818 E UncaughtExceptionLogger: at org.thoughtcrime.securesms.jobs.PushSendJob.onSend(PushSendJob.java:78) 01-09 19:39:54.513 13713 13818 E UncaughtExceptionLogger: at org.thoughtcrime.securesms.jobs.SendJob.onRun(SendJob.java:56) 01-09 19:39:54.513 13713 13818 E UncaughtExceptionLogger: at org.thoughtcrime.securesms.jobmanager.Job.doWorkInternal(Job.java:99) 01-09 19:39:54.513 13713 13818 E UncaughtExceptionLogger: at org.thoughtcrime.securesms.jobmanager.Job.doWork(Job.java:65) 01-09 19:39:54.513 13713 13818 E UncaughtExceptionLogger: at androidx.work.Worker$1.run(Worker.java:57) 01-09 19:39:54.513 13713 13818 E UncaughtExceptionLogger: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162) 01-09 19:39:54.513 13713 13818 E UncaughtExceptionLogger: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636) 01-09 19:39:54.513 13713 13818 E UncaughtExceptionLogger: at java.lang.Thread.run(Thread.java:764) 01-09 19:39:54.516 1965 8261 W ActivityManager: Force finishing activity org.thoughtcrime.securesms/.ConversationActivity 01-09 19:39:54.519 1965 8261 W ActivityManager: Force finishing activity org.thoughtcrime.securesms/.RoutingActivity 01-09 19:39:54.525 1965 2069 I ActivityManager: Showing crash dialog for package org.thoughtcrime.securesms u0 01-09 19:39:54.525 1965 2068 W BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.DROPBOX_ENTRY_ADDED flg=0x10 (has extras) } to com.google.android.gms/.stats.service.DropBoxEntryAddedReceiver 01-09 19:39:54.525 1965 2068 W BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.DROPBOX_ENTRY_ADDED flg=0x10 (has extras) } to com.google.android.gms/.chimera.GmsIntentOperationService$PersistentTrustedReceiver

@ikino
Copy link
Author

ikino commented Jan 9, 2019

after reinstalling signal with restore backup, it work again ok

@five-c-d
Copy link

Looks like a normal phone-number +421XXXXXXXXX was being mis-recognized as a groupchat uuid for some reason?

01-09 19:39:54.513 13713 13818 E UncaughtExceptionLogger: java.lang.AssertionError: Not group: +421XXXXXXXXX 
01-09 19:39:54.513 13713 13818 E UncaughtExceptionLogger: at org.thoughtcrime.securesms.database.Address.toGroupString(Address.java:127) 
01-09 19:39:54.513 13713 13818 E UncaughtExceptionLogger: at org.thoughtcrime.securesms.jobs.PushGroupSendJob.onPushSend(PushGroupSendJob.java:127) 
01-09 19:39:54.513 13713 13818 E UncaughtExceptionLogger: at org.thoughtcrime.securesms.jobs.PushSendJob.onSend(PushSendJob.java:78) 

Here is the java code which was being called...

else target = getGroupMessageRecipients(message.getRecipient().getAddress().toGroupString(), messageId);
... country code is Slovakia +421 methinks.

@jedie
Copy link

jedie commented Jan 28, 2019

Same here:

  • I have searched open and closed issues for duplicates

Bug Description

Signal crashes 2-3 Sec. after app start

Steps to Reproduce

don't know how to reproduce ;)

Platform Info

Device : Sony H3113 (H3113)
Android : 8.1.0 (8ce5ff7b93, lineage_pioneer-userdebug 8.1.0 OPM7.181205.001 8ce5ff7b93)
Memory : 25M (22.42% free, 512M max)
Memclass: 192
OS Host : lineage-runner
App : Signal 4.32.8

Link to Debug Log

01-27 15:36:12.270  3689  3747 E AndroidRuntime: FATAL EXCEPTION: pool-1-thread-1
01-27 15:36:12.270  3689  3747 E AndroidRuntime: Process: org.thoughtcrime.securesms, PID: 3689
01-27 15:36:12.270  3689  3747 E AndroidRuntime: java.lang.AssertionError: Not group: +***********33
01-27 15:36:12.270  3689  3747 E AndroidRuntime: 	at org.thoughtcrime.securesms.database.Address.toGroupString(Address.java:129)
01-27 15:36:12.270  3689  3747 E AndroidRuntime: 	at org.thoughtcrime.securesms.jobs.PushGroupSendJob.onPushSend(PushGroupSendJob.java:162)
01-27 15:36:12.270  3689  3747 E AndroidRuntime: 	at org.thoughtcrime.securesms.jobs.PushSendJob.onSend(PushSendJob.java:84)
01-27 15:36:12.270  3689  3747 E AndroidRuntime: 	at org.thoughtcrime.securesms.jobs.SendJob.onRun(SendJob.java:56)
01-27 15:36:12.270  3689  3747 E AndroidRuntime: 	at org.thoughtcrime.securesms.jobmanager.Job.doWorkInternal(Job.java:111)
01-27 15:36:12.270  3689  3747 E AndroidRuntime: 	at org.thoughtcrime.securesms.jobmanager.Job.doWork(Job.java:64)
01-27 15:36:12.270  3689  3747 E AndroidRuntime: 	at androidx.work.Worker$1.run(Worker.java:84)
01-27 15:36:12.270  3689  3747 E AndroidRuntime: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162)
01-27 15:36:12.270  3689  3747 E AndroidRuntime: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636)
01-27 15:36:12.270  3689  3747 E AndroidRuntime: 	at java.lang.Thread.run(Thread.java:764)

https://debuglogs.org/590f3821eb515fe04875f5399aee7cc712a6ce15b17beccf91764d7fa5e25c24

@jedie
Copy link

jedie commented Jan 28, 2019

Think the important part is: **Not group: +*********33 (in my case)

I have only one persons with this telephone number... I sent several messages via desktop client back and forth. And try "Restart encryption" ... At some point the App crash was gone. But I can't remember exactly when.

@five-c-d
Copy link

From the debuglog posted by @jedie it looks like the "Not group" exception kept re-trying for hours and hours ... 42 retries is a lot when there is an unhandled exception every time:

2019-01-27 15:41:36.936 MEZ I SendJob: Starting message send attempt
2019-01-27 15:41:36.950 MEZ I PushGroupSendJob: [fa48411e-19c9-4bf2-82ac-b284e1bf21f4] Sending message: 6250 (Time since submission: 72191000 ms, Run attempt: 42, isStopped: false)
2019-01-27 15:41:36.952 MEZ E UncaughtExceptionLogger: 
2019-01-27 15:41:36.952 MEZ E UncaughtExceptionLogger: java.lang.AssertionError: Not group: +***********33

There was a string of (probably not directly related) DuplicateMessageException logs ==

2019-01-27 15:36:16.972 MEZ W PushDecryptJob: null
2019-01-27 15:36:16.972 MEZ W PushDecryptJob: org.signal.libsignal.metadata.ProtocolDuplicateMessageException: org.whispersystems.libsignal.DuplicateMessageException: Received message with old counter: 10 , 1
2019-01-27 15:36:16.972 MEZ W PushDecryptJob: 	at org.signal.libsignal.metadata.SealedSessionCipher.decrypt(SealedSessionCipher.java:132)
2019-01-27 15:36:16.972 MEZ W PushDecryptJob: 	at org.whispersystems.signalservice.api.crypto.SignalServiceCipher.decrypt(SignalServiceCipher.java:232)
2019-01-27 15:36:16.972 MEZ W PushDecryptJob: 	at org.whispersystems.signalservice.api.crypto.SignalServiceCipher.decrypt(SignalServiceCipher.java:164)
2019-01-27 15:36:16.972 MEZ W PushDecryptJob: 	at org.thoughtcrime.securesms.jobs.PushDecryptJob.handleMessage(PushDecryptJob.java:221)
2019-01-27 15:36:16.972 MEZ W PushDecryptJob: 	at org.thoughtcrime.securesms.jobs.PushDecryptJob.processMessage(PushDecryptJob.java:192)
2019-01-27 15:36:16.972 MEZ W PushDecryptJob: 	at org.thoughtcrime.securesms.jobs.PushReceivedJob.handleMessage(PushReceivedJob.java:56)
2019-01-27 15:36:16.972 MEZ W PushDecryptJob: 	at org.thoughtcrime.securesms.jobs.PushReceivedJob.processEnvelope(PushReceivedJob.java:48)
2019-01-27 15:36:16.972 MEZ W PushDecryptJob: 	at org.thoughtcrime.securesms.service.IncomingMessageObserver$MessageRetrievalThread.lambda$run$0$IncomingMessageObserver$MessageRetrievalThread(IncomingMessageObserver.java:162)
2019-01-27 15:36:16.972 MEZ W PushDecryptJob: 	at org.thoughtcrime.securesms.service.IncomingMessageObserver$MessageRetrievalThread$$Lambda$0.onMessage(Unknown Source:2)
2019-01-27 15:36:16.972 MEZ W PushDecryptJob: 	at org.whispersystems.signalservice.api.SignalServiceMessagePipe.read(SignalServiceMessagePipe.java:111)
2019-01-27 15:36:16.972 MEZ W PushDecryptJob: 	at org.thoughtcrime.securesms.service.IncomingMessageObserver$MessageRetrievalThread.run(IncomingMessageObserver.java:159)

This error though, 'Receiver not registered' during a keepalive attempt, is one I have never seen in a debuglog thus far ==

2019-01-27 12:20:00.486 MEZ W WebSocketConnection: java.lang.IllegalArgumentException: Receiver not registered: org.whispersystems.signalservice.api.util.RealtimeSleepTimer$AlarmReceiver@ab5dd6e
	at android.app.LoadedApk.forgetReceiverDispatcher(LoadedApk.java:1193)
	at android.app.ContextImpl.unregisterReceiver(ContextImpl.java:1449)
	at android.content.ContextWrapper.unregisterReceiver(ContextWrapper.java:645)
	at org.whispersystems.signalservice.api.util.RealtimeSleepTimer.sleep(RealtimeSleepTimer.java:51)
	at org.whispersystems.signalservice.internal.websocket.WebSocketConnection$KeepAliveSender.run(WebSocketConnection.java:320)

There is an open bug-report about 'Receiver not registered' and non-GApps ROMs over at #8402 ... likely that is what Jedie is experiencing methinks, running LineageOS per their debuglog:

Device  : Sony H3113 (H3113)
Android : 8.1.0 (8ce5ff7b93, lineage_pioneer-userdebug 8.1.0 OPM7.181205.001 8ce5ff7b93)
Memory  : 25M (22.42% free, 512M max)
Memclass: 192
OS Host : lineage-runner
App     : Signal 4.32.8

@stale
Copy link

stale bot commented Jan 28, 2022

Is this still relevant? If so, what is blocking it? Is there anything you can do to help move it forward?

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs.

@stale stale bot added the wontfix label Jan 28, 2022
@stale stale bot closed this as completed Feb 4, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Development

No branches or pull requests

3 participants