Signal crashed multiple times when tried to initiate call

szotsaki commented 2 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

When I tried to initiate a call, Signal crashed. This happened multiple times.

Crashes:

[5.32.14] [main ] 2022-03-20 12:56:39.153 GMT+01:00 E SignalUncaughtException: 
[5.32.14] [main ] 2022-03-20 12:56:39.153 GMT+01:00 E SignalUncaughtException: android.app.RemoteServiceException: Context.startForegroundService() did not then call Service.startForeground()
[5.32.14] [main ] 2022-03-20 12:56:39.153 GMT+01:00 E SignalUncaughtException:  at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1783)
[5.32.14] [main ] 2022-03-20 12:56:39.153 GMT+01:00 E SignalUncaughtException:  at android.os.Handler.dispatchMessage(Handler.java:105)
[5.32.14] [main ] 2022-03-20 12:56:39.153 GMT+01:00 E SignalUncaughtException:  at android.os.Looper.loop(Looper.java:251)
[5.32.14] [main ] 2022-03-20 12:56:39.153 GMT+01:00 E SignalUncaughtException:  at android.app.ActivityThread.main(ActivityThread.java:6589)
[5.32.14] [main ] 2022-03-20 12:56:39.153 GMT+01:00 E SignalUncaughtException:  at java.lang.reflect.Method.invoke(Native Method)
[5.32.14] [main ] 2022-03-20 12:56:39.153 GMT+01:00 E SignalUncaughtException:  at com.android.internal.os.Zygote$MethodAndArgsCaller.run(Zygote.java:240)
[5.32.14] [main ] 2022-03-20 12:56:39.153 GMT+01:00 E SignalUncaughtException:  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:767)
[5.32.14] [main ] 2022-03-20 12:56:39.153 GMT+01:00 E SignalUncaughtException:

and

[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper: Tried to use a released EglBase
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper: java.lang.Exception
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.components.webrtc.EglBaseWrapper.performWithValidEglBase(EglBaseWrapper.kt:35)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.components.webrtc.WebRtcCallView.updateLocalCallParticipant(WebRtcCallView.java:418)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.components.webrtc.WebRtcCallView.updateCallParticipants(WebRtcCallView.java:399)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.WebRtcCallActivity.lambda$initializeViewModel$1(WebRtcCallActivity.java:299)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.WebRtcCallActivity.$r8$lambda$u5LznMbwa_BeoJygqRKhi4HUkQo(Unknown Source:0)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.WebRtcCallActivity$$ExternalSyntheticLambda9.onChanged(Unknown Source:4)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.LiveData.considerNotify(LiveData.java:133)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.LiveData.dispatchingValue(LiveData.java:151)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.LiveData.setValue(LiveData.java:309)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.MutableLiveData.setValue(MutableLiveData.java:50)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.util.livedata.LiveDataUtil$CombineLiveData.lambda$new$2(LiveDataUtil.java:281)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.util.livedata.LiveDataUtil$CombineLiveData.$r8$lambda$R5nz5BGnO3kKET-VWTSLlC8p2ZI(Unknown Source:0)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.util.livedata.LiveDataUtil$CombineLiveData$$ExternalSyntheticLambda1.onChanged(Unknown Source:4)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.MediatorLiveData$Source.onChanged(MediatorLiveData.java:152)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.LiveData.considerNotify(LiveData.java:133)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.LiveData.dispatchingValue(LiveData.java:151)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.LiveData.setValue(LiveData.java:309)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.MutableLiveData.setValue(MutableLiveData.java:50)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.util.livedata.LiveDataUtil$CombineLiveData.lambda$new$1(LiveDataUtil.java:272)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.util.livedata.LiveDataUtil$CombineLiveData.$r8$lambda$wAMU8DeyM3arS5fG3ekR8gX5eK0(Unknown Source:0)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.util.livedata.LiveDataUtil$CombineLiveData$$ExternalSyntheticLambda2.onChanged(Unknown Source:4)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.MediatorLiveData$Source.onChanged(MediatorLiveData.java:152)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.LiveData.considerNotify(LiveData.java:133)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.LiveData.dispatchingValue(LiveData.java:151)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.LiveData.setValue(LiveData.java:309)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.MutableLiveData.setValue(MutableLiveData.java:50)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.Transformations$3.onChanged(Transformations.java:188)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.MediatorLiveData$Source.onChanged(MediatorLiveData.java:152)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.LiveData.considerNotify(LiveData.java:133)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.LiveData.dispatchingValue(LiveData.java:151)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.LiveData.setValue(LiveData.java:309)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.MutableLiveData.setValue(MutableLiveData.java:50)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.components.sensors.DeviceOrientationMonitor.updateOrientationAngles(DeviceOrientationMonitor.java:83)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.components.sensors.DeviceOrientationMonitor.access$300(DeviceOrientationMonitor.java:18)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.components.sensors.DeviceOrientationMonitor$EventListener.onSensorChanged(DeviceOrientationMonitor.java:99)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at android.hardware.SystemSensorManager$SensorEventQueue.dispatchSensorEvent(SystemSensorManager.java:832)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at android.os.MessageQueue.nativePollOnce(Native Method)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at android.os.MessageQueue.next(MessageQueue.java:375)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at android.os.Looper.loop(Looper.java:225)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at android.app.ActivityThread.main(ActivityThread.java:6589)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at java.lang.reflect.Method.invoke(Native Method)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at com.android.internal.os.Zygote$MethodAndArgsCaller.run(Zygote.java:240)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper:   at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:767)
[5.32.14] [main ] 2022-03-20 12:59:15.032 GMT+01:00 D EglBaseWrapper: 
[5.32.14] [155648] 2022-03-20 12:59:15.034 GMT+01:00 V SignalCallManager: Processing action: orientationChanged, handler: IdleActionProcessor
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper: Tried to use a released EglBase
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper: java.lang.Exception
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.components.webrtc.EglBaseWrapper.performWithValidEglBase(EglBaseWrapper.kt:35)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.components.webrtc.WebRtcCallView.updateLocalCallParticipant(WebRtcCallView.java:418)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.components.webrtc.WebRtcCallView.updateCallParticipants(WebRtcCallView.java:399)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.WebRtcCallActivity.lambda$initializeViewModel$1(WebRtcCallActivity.java:299)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.WebRtcCallActivity.$r8$lambda$u5LznMbwa_BeoJygqRKhi4HUkQo(Unknown Source:0)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.WebRtcCallActivity$$ExternalSyntheticLambda9.onChanged(Unknown Source:4)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.LiveData.considerNotify(LiveData.java:133)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.LiveData.dispatchingValue(LiveData.java:151)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.LiveData.setValue(LiveData.java:309)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.MutableLiveData.setValue(MutableLiveData.java:50)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.util.livedata.LiveDataUtil$CombineLiveData.lambda$new$2(LiveDataUtil.java:281)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.util.livedata.LiveDataUtil$CombineLiveData.$r8$lambda$R5nz5BGnO3kKET-VWTSLlC8p2ZI(Unknown Source:0)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.util.livedata.LiveDataUtil$CombineLiveData$$ExternalSyntheticLambda1.onChanged(Unknown Source:4)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.MediatorLiveData$Source.onChanged(MediatorLiveData.java:152)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.LiveData.considerNotify(LiveData.java:133)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.LiveData.dispatchingValue(LiveData.java:151)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.LiveData.setValue(LiveData.java:309)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.MutableLiveData.setValue(MutableLiveData.java:50)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.util.livedata.LiveDataUtil$CombineLiveData.lambda$new$1(LiveDataUtil.java:272)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.util.livedata.LiveDataUtil$CombineLiveData.$r8$lambda$wAMU8DeyM3arS5fG3ekR8gX5eK0(Unknown Source:0)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.util.livedata.LiveDataUtil$CombineLiveData$$ExternalSyntheticLambda2.onChanged(Unknown Source:4)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.MediatorLiveData$Source.onChanged(MediatorLiveData.java:152)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.LiveData.considerNotify(LiveData.java:133)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.LiveData.dispatchingValue(LiveData.java:151)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.LiveData.setValue(LiveData.java:309)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.MutableLiveData.setValue(MutableLiveData.java:50)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.Transformations$3.onChanged(Transformations.java:188)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.MediatorLiveData$Source.onChanged(MediatorLiveData.java:152)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.LiveData.considerNotify(LiveData.java:133)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.LiveData.dispatchingValue(LiveData.java:151)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.LiveData.setValue(LiveData.java:309)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at androidx.lifecycle.MutableLiveData.setValue(MutableLiveData.java:50)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.components.sensors.DeviceOrientationMonitor.updateOrientationAngles(DeviceOrientationMonitor.java:85)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.components.sensors.DeviceOrientationMonitor.access$300(DeviceOrientationMonitor.java:18)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at org.thoughtcrime.securesms.components.sensors.DeviceOrientationMonitor$EventListener.onSensorChanged(DeviceOrientationMonitor.java:99)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at android.hardware.SystemSensorManager$SensorEventQueue.dispatchSensorEvent(SystemSensorManager.java:832)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at android.os.MessageQueue.nativePollOnce(Native Method)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at android.os.MessageQueue.next(MessageQueue.java:375)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at android.os.Looper.loop(Looper.java:225)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at android.app.ActivityThread.main(ActivityThread.java:6589)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at java.lang.reflect.Method.invoke(Native Method)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at com.android.internal.os.Zygote$MethodAndArgsCaller.run(Zygote.java:240)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:   at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:767)
[5.32.14] [main ] 2022-03-20 12:59:15.109 GMT+01:00 D EglBaseWrapper:

For some reason, before I started Signal, my phone didn't turn its screen to normal brightness after unlocking but remained on the dimmest setting (I barely saw the screen).

Device info

Device: Sony Xperia X Android version: 8.0.0 Signal version: 5.32.14

Link to debug log

https://debuglogs.org/android/5.32.14/daa2194ef71419df05aabc0008cbeb1ad352d46564c63eb806f1aca45802ab53

cody-signal commented 2 years ago

Hey there, sorry about this, something weird is going on with our Android service that runs during call setup.

Do you have any of the follows:

A task manager that likes to kill things
Swiping away the app while ringing
Unique audio configuration or headset/bt usage

When it started working again, did you do anything special or did just start working randomly. If you are able to reproduce it, could you tell me anything special you're doing to do that?

woheller69 commented 2 years ago

Sony obviously has some "optimizations"

 https://dontkillmyapp.com/sony

szotsaki commented 2 years ago

No, I don't have anything from these points. It just started working again randomly an hour later.

I don't know what's (if there's) the connection between these crashes and the buggy Android behaviour I described (that the screen sometimes turns on completely dimmed where even the turn-on event can be triggered only by a long-press of the power button). Next time this bug happens, I'll try to initiate a Signal call to see if there's any connection.

If I'll be next to a PC during this time, would you be interested in a complete Android log in PM or don't you think that it'd help too much?

As I observed, Sony doesn't have too strict optimisations during normal working. It has a stamina mode below 15% but I didn't enable it. Nevertheless, I've checked now and I had created an exception for Signal.

cody-signal commented 2 years ago

Thanks for the extra info. There may be more available in a system log but it's unclear as I haven't seen behavior like this. Android can kill our service, but I believe that's usually via killing an entire process, but the rest of the app continues to run fine, it's just the service. And it seems like it tries to restart but there's no call to onCreate, and then the crash happens.

If you get more logs then you can email them to me or DM my on the community forums. Email is my name at signal.org

harimoradiya commented 2 years ago

crash issue found when calling even wifi is good Realme device 8 android 12

szotsaki commented 2 years ago

Please, attach a debug log from Help -> Debug log to see we're talking about the same issue.

stale[bot] commented 2 years ago

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

signalapp / Signal-Android