optimizely/android-sdk

Unable to create/stop/unbind ScheduledJobService

senlsy opened this issue · 15 comments

Library version: 3.5.0
Android API: 29
Code for Android SDK initialization:
try {
OptimizelyManager manager = OptimizelyManager.builder()
.withSDKKey(BuildConfig.ABTEST_KEY)
.withDatafileDownloadInterval(TimeUnit.MINUTES.toSeconds(60))
.build(application);
mSyncOptyClient = manager.initialize(application, R.raw.datafile, true, true);
} catch (Exception e) {
e.printStackTrace();
}

Fatal Exception: java.lang.RuntimeException: Unable to create service com.optimizely.ab.android.shared.ScheduledJobService: java.lang.RuntimeException: android.os.DeadSystemException
at android.app.ActivityThread.handleCreateService(ActivityThread.java:4081)
at android.app.ActivityThread.access$1500(ActivityThread.java:226)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1914)
at android.os.Handler.dispatchMessage(Handler.java:107)
at android.os.Looper.loop(Looper.java:214)
at android.app.ActivityThread.main(ActivityThread.java:7615)
at java.lang.reflect.Method.invoke(Method.java)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:492)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:964)

=====
Fatal Exception: java.lang.RuntimeException: Unable to stop service com.optimizely.ab.android.shared.ScheduledJobService@711222b: java.lang.RuntimeException: android.os.DeadSystemException
at android.app.ActivityThread.handleStopService(ActivityThread.java:4252)
at android.app.ActivityThread.access$1900(ActivityThread.java:226)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1935)
at android.os.Handler.dispatchMessage(Handler.java:107)
at android.os.Looper.loop(Looper.java:214)
at android.app.ActivityThread.main(ActivityThread.java:7615)
at java.lang.reflect.Method.invoke(Method.java)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:492)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:964)

======
Fatal Exception: java.lang.RuntimeException: Unable to unbind to service com.optimizely.ab.android.shared.ScheduledJobService@b07dc23 with Intent { cmp=com.verifly.smb/com.optimizely.ab.android.shared.ScheduledJobService }: java.lang.RuntimeException: android.os.DeadSystemException
at android.app.ActivityThread.handleUnbindService(ActivityThread.java:4139)
at android.app.ActivityThread.access$1700(ActivityThread.java:226)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1924)
at android.os.Handler.dispatchMessage(Handler.java:107)
at android.os.Looper.loop(Looper.java:214)
at android.app.ActivityThread.main(ActivityThread.java:7615)
at java.lang.reflect.Method.invoke(Method.java)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:492)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:964)

@senlsy Can you tell me how you are running? Are you running multiple instances?

How do you have this setup? It seems weird that you are trying to unbind a scheduled service.

Are you stopping and starting services? Do you know when this happens?
Thanks!

Hi,
I never called the stopping or starting service method in initialization code. AButils is single instance of utils class, it will be created and init on application onCreate() method. This is AButils code click here.

Application onCreate method:
public void onCreate(){
tyr{
ABUtils.getInstance().init(this);// “this” is application instance
}catch(Exception e){
e.printStackTree();
}
}

After initialization, I will call ABUtils.getInstance().isFeatureEnable( key) wherever needed A/B Test. For example:

I accorded to "email_wall_v2" variables show dialog v1 or v2.

if (ABUtils.getInstance().isFeatureEnable("email_wall_v2")) {
showDialog(EmailWallDialogV2.getInstance());
} else {
showDialog(EmailWallDialogV1.getInstance());
}

Please help, thanks!

https://developer.android.com/reference/android/os/DeadSystemException

@senlsy Can we verify that this is being caused by us? It seems that the unbinding is not the cause but the action that was stopped because of a dead system exception. There could have been a reboot or some other issue happening at that time. Your code seems fine. It makes sense that this is happening during a shutdown as the system tries to unbind but we are running scheduled services which should continue to run.

FYI. We are also seeing a huge spike in similar crash reporting recently so I came looking here. We did update to the latest SDK recently but similar crash was reported in small number previously though. Recent crash is mostly from LG K31, K51 and moto g(7) running Android 10. For LG K51 it 283 instances of the crashes from just 4 users.
@senlsy which devices are you seeing this from?

Also in our case it is from DatafileService but caused by similar DeadSystemException.

Fatal Exception: java.lang.RuntimeException
Unable to create service com.optimizely.ab.android.datafile_handler.DatafileService: java.lang.RuntimeException: android.os.DeadSystemException
android.app.ActivityThread.handleCreateService (ActivityThread.java:4081)
android.app.ActivityThread.access$1500 (ActivityThread.java:226)
android.app.ActivityThread$H.handleMessage (ActivityThread.java:1914)
android.os.Handler.dispatchMessage (Handler.java:107)
android.os.Looper.loop (Looper.java:214)
android.app.ActivityThread.main (ActivityThread.java:7615)
java.lang.reflect.Method.invoke (Method.java)
com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run (RuntimeInit.java:492)
com.android.internal.os.ZygoteInit.main (ZygoteInit.java:964)

Anyway, looking at the Exception it may not be related to Optimizely but wanted to provided additional info if anyone is facing similar crash reports.

Hi,
The crash from Android 10, LG K30. android.os.DeadSystemException: Android runtime restart and all running apps will be promptly killed. Causing Optimizely stop/create service failed. @byunlee

@senlsy This is becoming a serious problem for us. The crash counts from Crashlytics are spiking after we updated the Optimizely SDK from 3.5.1 to 3.7.0. And it is mostly coming from LG K31, K51 and moto g(7) play. The numbers do not seem to add up as we are seeing over 1K crashes from just 50~70 users which is hard to believe if DeadSystemException really means that device is trying to reboot. Are you able to reproduce this problem?

Not sure if this related but I'm also seeing lots of ANR (Application Not Responding) in Google Play Console which it says it is happening while executing service com.venmo/com.optimizely.ab.android.shared.ScheduledJobService and the stack trace on the main thread doing something from OptimizelyManager.initialize().

  #00  pc 000000000009b624  /apex/com.android.runtime/lib64/bionic/libc.so (__ioctl+4)
  #00  pc 0000000000057d38  /apex/com.android.runtime/lib64/bionic/libc.so (ioctl+160)
  #00  pc 0000000000050c6c  /system/lib64/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+300)
  #00  pc 0000000000051c7c  /system/lib64/libbinder.so (android::IPCThreadState::waitForResponse(android::Parcel*, int*)+60)
  #00  pc 00000000000519e4  /system/lib64/libbinder.so (android::IPCThreadState::transact(int, unsigned int, android::Parcel const&, android::Parcel*, unsigned int)+188)
  #00  pc 000000000004a0b0  /system/lib64/libbinder.so (android::BpBinder::transact(unsigned int, android::Parcel const&, android::Parcel*, unsigned int)+152)
  #00  pc 0000000000125220  /system/lib64/libandroid_runtime.so (android_os_BinderProxy_transact(_JNIEnv*, _jobject*, int, _jobject*, _jobject*, int)+152)
  at android.os.BinderProxy.transactNative (BinderProxy.java)
  at android.os.BinderProxy.transact (BinderProxy.java:540)
  at android.app.job.IJobScheduler$Stub$Proxy.getAllPendingJobs (IJobScheduler.java:425)
  at android.app.JobSchedulerImpl.getAllPendingJobs (JobSchedulerImpl.java:90)
  at com.optimizely.ab.android.shared.ServiceScheduler.isScheduled (ServiceScheduler.java:305)
  at com.optimizely.ab.android.shared.ServiceScheduler.setRepeating (ServiceScheduler.java:99)
  at com.optimizely.ab.android.shared.ServiceScheduler.schedule (ServiceScheduler.java:86)
  at com.optimizely.ab.android.datafile_handler.DefaultDatafileHandler.startBackgroundUpdates (DefaultDatafileHandler.java:135)
  at com.optimizely.ab.android.sdk.OptimizelyManager.startDatafileHandler (OptimizelyManager.java:504)
  at com.optimizely.ab.android.sdk.OptimizelyManager.initialize (OptimizelyManager.java:218)
  at com.optimizely.ab.android.sdk.OptimizelyManager.initialize (OptimizelyManager.java:261)
  at com.optimizely.ab.android.sdk.OptimizelyManager.initialize (OptimizelyManager.java:288)
...called from Application.onCreate()

I guess it could be that we are doing too many things on Appplication.onStart() and it just happened to be executing OptimizelyManager.initialize() when ANR has happened.

@thomaszurkan-optimizely We integrated optimizely and rolled out very recently and we're noticing similar crashes to the ones reported above in our logs as well.

At least the top 10 crashes for our latest release in which we rolled out Optimizely SDK for the first time are the below crashes.

Here's a list of crashes within the optimizely SDK

Fatal Exception: java.lang.RuntimeException: Unable to create service com.optimizely.ab.android.shared.ScheduledJobService: java.lang.RuntimeException: android.os.DeadSystemException
at android.app.ActivityThread.handleCreateService(ActivityThread.java:4081)
at android.app.ActivityThread.access$1500(ActivityThread.java:226)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1914)
at android.os.Handler.dispatchMessage(Handler.java:107)
at android.os.Looper.loop(Looper.java:214)
at android.app.ActivityThread.main(ActivityThread.java:7615)
at java.lang.reflect.Method.invoke(Method.java)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:492)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:964)
Caused by java.lang.RuntimeException: android.os.DeadSystemException
at android.app.ActivityThread.handleCreateService(ActivityThread.java:4075)
at android.app.ActivityThread.access$1500(ActivityThread.java:226)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1914)
at android.os.Handler.dispatchMessage(Handler.java:107)
at android.os.Looper.loop(Looper.java:214)
at android.app.ActivityThread.main(ActivityThread.java:7615)
at java.lang.reflect.Method.invoke(Method.java)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:492)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:964)

  1. Fatal Exception: java.lang.RuntimeException: Unable to stop service com.optimizely.ab.android.datafile_handler.DatafileService@c78a3c4: java.lang.RuntimeException: android.os.DeadSystemException
    at android.app.ActivityThread.handleStopService(ActivityThread.java:4252)
    at android.app.ActivityThread.access$1900(ActivityThread.java:226)
    at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1935)
    at android.os.Handler.dispatchMessage(Handler.java:107)
    at android.os.Looper.loop(Looper.java:214)
    at android.app.ActivityThread.main(ActivityThread.java:7615)
    at java.lang.reflect.Method.invoke(Method.java)
    at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:492)
    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:964)
    Caused by java.lang.RuntimeException: android.os.DeadSystemException
    at android.app.ActivityThread.handleStopService(ActivityThread.java:4246)
    at android.app.ActivityThread.access$1900(ActivityThread.java:226)
    at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1935)
    at android.os.Handler.dispatchMessage(Handler.java:107)
    at android.os.Looper.loop(Looper.java:214)
    at android.app.ActivityThread.main(ActivityThread.java:7615)
    at java.lang.reflect.Method.invoke(Method.java)
    at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:492)
    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:964)

  2. Fatal Exception: java.lang.RuntimeException: Unable to unbind to service com.optimizely.ab.android.shared.ScheduledJobService@e8c0d1a with Intent { cmp=com.docusign.ink/com.optimizely.ab.android.shared.ScheduledJobService }: java.lang.RuntimeException: android.os.DeadSystemException
    at android.app.ActivityThread.handleUnbindService(ActivityThread.java:4238)
    at android.app.ActivityThread.access$1800(ActivityThread.java:232)
    at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2046)
    at android.os.Handler.dispatchMessage(Handler.java:107)
    at android.os.Looper.loop(Looper.java:241)
    at android.app.ActivityThread.main(ActivityThread.java:7604)
    at java.lang.reflect.Method.invoke(Method.java)
    at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:492)
    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:941)
    Caused by java.lang.RuntimeException: android.os.DeadSystemException
    at android.app.ActivityThread.handleUnbindService(ActivityThread.java:4232)
    at android.app.ActivityThread.access$1800(ActivityThread.java:232)
    at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2046)
    at android.os.Handler.dispatchMessage(Handler.java:107)
    at android.os.Looper.loop(Looper.java:241)
    at android.app.ActivityThread.main(ActivityThread.java:7604)
    at java.lang.reflect.Method.invoke(Method.java)
    at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:492)
    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:941)

The devices in which this crash occurs happens for our app are on on LG k31 (Android OS 10), Samsung Galaxy S7(Android OS 8), LG Stylo 4 (Android 8.1), Motorola G7 (Android 10). The numbers are going up on a daily basis.

@thomaszurkan-optimizely We only have one instance of Optimizely client which we reuse.

@thomaszurkan-optimizely when can we expect a fix?

@prasannarupan we have updated to androidx and I am in the process of deprecating our job scheduler for the androidx work manager. Along with the job scheduler, I am deprecating the intents to also just use the work manager. The PR is mentioned above if you care to comment. Thanks!

This is also causing issues for our production app as well. This crash is our top crash and are getting dozens a day. We only utilize once instance of the Optimizely.

Thank you @thomaszurkan-optimizely for the update