BackgroundFetch on Android with startOnBoot: true crashes on restart #6290
Description
🐛 Bug Report
Environment
Expo CLI 3.7.1 environment info:
System:
OS: macOS 10.14.6
Shell: 3.2.57 - /bin/bash
Binaries:
Node: 12.6.0 - /usr/local/bin/node
Yarn: 1.17.3 - /usr/local/bin/yarn
npm: 6.11.3 - /usr/local/bin/npm
IDEs:
Android Studio: 3.5 AI-191.8026.42.35.5977832
Xcode: 11.2.1/11B500 - /usr/bin/xcodebuild
npmPackages:
expo: ^35.0.0 => 35.0.1
react: 16.8.3 => 16.8.3
react-native: https://github.com/expo/react-native/archive/sdk-35.0.0.tar.gz => 0.59.8
npmGlobalPackages:
expo-cli: 3.7.1
I'm building an android app using the managed workflow.
The logs come from Pixel emulator running android 9, but I've reproduced the problem on a real Pixel device running android 10.
Steps to Reproduce
In an expo app, create a BackgroundFetch task, and register it with startOnBoot: true
build an android app with the managed workflow, install the app on the phone
Run the app, make sure that the background task works as expected
( in the example below adb logcat | grep ReactNative should show running background task )
For example in the https://github.com/jeromecornet/expo-android-backgroundfetch/raw/master/first_run.log, you will see:
11-15 14:02:57.200 4386 4473 I ReactNativeJS: running background task
Restart the phone
the app registers the task again, and starts the timer
for example in https://github.com/jeromecornet/expo-android-backgroundfetch/raw/master/after_reboot.log you will see
11-15 14:07:39.732 3987 3987 I TaskService: Registered task with name 'background-fetch-restart-test' for app with ID '@jerome.cornet/expo-android-backgroundfetch'.
11-15 14:07:39.732 3987 3987 I TaskService: Handling intent with action 'android.intent.action.BOOT_COMPLETED'.
11-15 14:07:39.736 3987 3987 I BackgroundFetchTaskConsumer: Starting an alarm for task 'background-fetch-restart-test'.
Wait 1 minute or so for the task to be executed
Expected Behavior
The task should run, showing the expected console.log line
Actual Behavior
Instead, the standalone app crashes and the background task gets unregistered, the following message appears in the logs instead
TaskService: Cannot execute background task because application loader can't be found.
From there the task gets unregistered and no longer works until the app is manually started again.
here's a relevant snippet of adb logcat (full log at https://github.com/jeromecornet/expo-android-backgroundfetch/raw/master/after_reboot.log)
11-15 14:09:10.998 1865 1882 I ActivityManager: Start proc 4461:com.jeromecornet.expobackgroundfetch/u0a85 for broadcast com.jeromecornet.expobackgroundfetch/expo.modules.taskManager.TaskBroadcastReceiv
er
11-15 14:09:11.001 4461 4461 W backgroundfetc: Unexpected CPU variant for X86 using defaults: x86
11-15 14:09:11.002 4461 4461 E backgroundfetc: Not starting debugger since process cannot load the jdwp agent.
11-15 14:09:11.023 4461 4461 I backgroundfetc: The ClassLoaderContext is a special shared library.
11-15 14:09:11.031 4461 4461 I MultiDex: VM with version 2.1.0 has multidex support
11-15 14:09:11.031 4461 4461 I MultiDex: Installing application
11-15 14:09:11.031 4461 4461 I MultiDex: VM has multidex support, MultiDex support library is disabled.
11-15 14:09:11.054 4461 4476 V FA : Deferring to Google Analytics for Firebase for event data collection. https://goo.gl/J1sWQy
11-15 14:09:11.060 4461 4476 W backgroundfetc: Unsupported class loader
11-15 14:09:11.067 4461 4461 D FirebaseApp: com.google.firebase.auth.FirebaseAuth is not linked. Skipping initialization.
11-15 14:09:11.069 4461 4461 D FirebaseApp: com.google.firebase.crash.FirebaseCrash is not linked. Skipping initialization.
11-15 14:09:11.069 4461 4461 I FirebaseInitProvider: FirebaseApp initialization successful
11-15 14:09:11.072 4461 4476 W backgroundfetc: Skipping duplicate class check due to unsupported classloader
11-15 14:09:11.072 4461 4476 I DynamiteModule: Considering local module com.google.android.gms.ads.dynamite:0 and remote module com.google.android.gms.ads.dynamite:21001
11-15 14:09:11.072 4461 4476 I DynamiteModule: Selected remote version of com.google.android.gms.ads.dynamite, version >= 21001
11-15 14:09:11.073 4461 4476 V DynamiteModule: Dynamite loader version >= 2, using loadModule2NoCrashUtils
11-15 14:09:11.083 4461 4476 W backgroundfetc: Unsupported class loader
11-15 14:09:11.085 4461 4461 W com.facebook.UserSettingsManager: Please set a value for AutoLogAppEventsEnabled. Set the flag to TRUE if you want to collect app install, app launch and in-app purchase e
vents automatically. To request user consent before collecting data, set the flag value to FALSE, then change to TRUE once user consent is received. Learn more: https://developers.facebook.com/docs/app-ev
ents/getting-started-app-events-android#disable-auto-events.
11-15 14:09:11.085 4461 4461 W com.facebook.UserSettingsManager: You haven't set a value for AdvertiserIDCollectionEnabled. Set the flag to TRUE if you want to collect Advertiser ID for better advertisi
ng and analytics results. To request user consent before collecting data, set the flag value to FALSE, then change to TRUE once user consent is received. Learn more: https://developers.facebook.com/docs/a
pp-events/getting-started-app-events-android#disable-auto-events.
11-15 14:09:11.099 4461 4476 W backgroundfetc: Skipping duplicate class check due to unsupported classloader
11-15 14:09:11.110 4461 4485 D NetworkSecurityConfig: No Network Security Config specified, using platform default
11-15 14:09:11.133 1865 1884 E BatteryExternalStatsWorker: no controller energy info supplied for wifi
11-15 14:09:11.174 4461 4481 I FA : App measurement is starting up, version: 16250
11-15 14:09:11.174 4461 4481 I FA : To enable debug logging run: adb shell setprop log.tag.FA VERBOSE
11-15 14:09:11.174 4461 4481 I FA : To enable faster debug mode event logging run:
11-15 14:09:11.174 4461 4481 I FA : adb shell setprop debug.firebase.analytics.app com.jeromecornet.expobackgroundfetch
11-15 14:09:11.188 4461 4461 D SoLoader: init start
11-15 14:09:11.188 4461 4461 D SoLoader: adding system library source: /vendor/lib
11-15 14:09:11.188 4461 4461 D SoLoader: adding system library source: /system/lib
11-15 14:09:11.188 4461 4461 D SoLoader: adding application source: com.facebook.soloader.DirectorySoSource[root = /data/app/com.jeromecornet.expobackgroundfetch-A0PwZZDTIP-cwTsS3PjhoA==/lib/x86 flags =
0]
11-15 14:09:11.189 4461 4461 D SoLoader: adding backup source from : com.facebook.soloader.ApkSoSource[root = /data/data/com.jeromecornet.expobackgroundfetch/lib-main flags = 1]
11-15 14:09:11.189 4461 4461 D SoLoader: Preparing SO source: com.facebook.soloader.DirectorySoSource[root = /system/lib flags = 2]
11-15 14:09:11.189 4461 4461 D SoLoader: Preparing SO source: com.facebook.soloader.DirectorySoSource[root = /vendor/lib flags = 2]
11-15 14:09:11.190 4461 4461 D SoLoader: Preparing SO source: com.facebook.soloader.DirectorySoSource[root = /data/app/com.jeromecornet.expobackgroundfetch-A0PwZZDTIP-cwTsS3PjhoA==/lib/x86 flags = 0]
11-15 14:09:11.190 4461 4461 D SoLoader: Preparing SO source: com.facebook.soloader.ApkSoSource[root = /data/data/com.jeromecornet.expobackgroundfetch/lib-main flags = 1]
11-15 14:09:11.191 4461 4461 V fb-UnpackingSoSource: locked dso store /data/user/0/com.jeromecornet.expobackgroundfetch/lib-main
11-15 14:09:11.192 4461 4461 I fb-UnpackingSoSource: dso store is up-to-date: /data/user/0/com.jeromecornet.expobackgroundfetch/lib-main
11-15 14:09:11.193 4461 4461 V fb-UnpackingSoSource: releasing dso store lock for /data/user/0/com.jeromecornet.expobackgroundfetch/lib-main
11-15 14:09:11.193 4461 4461 D SoLoader: init finish: 4 SO sources prepared
11-15 14:09:11.193 4461 4461 D SoLoader: init exiting
11-15 14:09:11.188 4461 4461 D SoLoader: init start
11-15 14:09:11.188 4461 4461 D SoLoader: adding system library source: /vendor/lib
11-15 14:09:11.188 4461 4461 D SoLoader: adding system library source: /system/lib
11-15 14:09:11.188 4461 4461 D SoLoader: adding application source: com.facebook.soloader.DirectorySoSource[root = /data/app/com.jeromecornet.expobackgroundfetch-A0PwZZDTIP-cwTsS3PjhoA==/lib/x86 flags = 0]
11-15 14:09:11.189 4461 4461 D SoLoader: adding backup source from : com.facebook.soloader.ApkSoSource[root = /data/data/com.jeromecornet.expobackgroundfetch/lib-main flags = 1]
11-15 14:09:11.189 4461 4461 D SoLoader: Preparing SO source: com.facebook.soloader.DirectorySoSource[root = /system/lib flags = 2]
11-15 14:09:11.189 4461 4461 D SoLoader: Preparing SO source: com.facebook.soloader.DirectorySoSource[root = /vendor/lib flags = 2]
11-15 14:09:11.190 4461 4461 D SoLoader: Preparing SO source: com.facebook.soloader.DirectorySoSource[root = /data/app/com.jeromecornet.expobackgroundfetch-A0PwZZDTIP-cwTsS3PjhoA==/lib/x86 flags = 0]
11-15 14:09:11.190 4461 4461 D SoLoader: Preparing SO source: com.facebook.soloader.ApkSoSource[root = /data/data/com.jeromecornet.expobackgroundfetch/lib-main flags = 1]
11-15 14:09:11.191 4461 4461 V fb-UnpackingSoSource: locked dso store /data/user/0/com.jeromecornet.expobackgroundfetch/lib-main
11-15 14:09:11.192 4461 4461 I fb-UnpackingSoSource: dso store is up-to-date: /data/user/0/com.jeromecornet.expobackgroundfetch/lib-main
11-15 14:09:11.193 4461 4461 V fb-UnpackingSoSource: releasing dso store lock for /data/user/0/com.jeromecornet.expobackgroundfetch/lib-main
11-15 14:09:11.193 4461 4461 D SoLoader: init finish: 4 SO sources prepared
11-15 14:09:11.263 4461 4461 D SoLoader: init exiting
11-15 14:09:11.282 4461 4461 I TaskService: Registered task with name 'background-fetch-restart-test' for app with ID '@jerome.cornet/expo-android-backgroundfetch'.
11-15 14:09:11.283 4461 4461 I TaskService: Handling intent with task name 'background-fetch-restart-test' and appId '@jerome.cornet/expo-android-backgroundfetch'.
11-15 14:09:11.299 4461 4461 I TaskService: Handling job with task name 'background-fetch-restart-test' for app with ID '@jerome.cornet/expo-android-backgroundfetch'.
11-15 14:09:11.300 4461 4461 E Expo : Cannot initialize app loader. <init> [class android.content.Context]
11-15 14:09:11.300 4461 4461 E TaskService: Cannot execute background task because application loader can't be found.
11-15 14:09:11.300 4461 4461 I TaskService: Unregistering task 'background-fetch-restart-test' for app '@jerome.cornet/expo-android-backgroundfetch'.
11-15 14:09:11.432 4461 4497 D b : Loaded exp.host status page.
11-15 14:09:11.455 4461 4486 E GraphResponse: {HttpStatus: 400, errorCode: 100, subErrorCode: 33, errorType: GraphMethodException, errorMessage: Unsupported get request. Please read the Graph API documentation at https://developers.facebook.com/docs/graph-api}
11-15 14:09:11.460 4461 4485 E GraphResponse: {HttpStatus: 400, errorCode: 100, subErrorCode: 33, errorType: GraphMethodException, errorMessage: Unsupported get request. Please read the Graph API documentation at https://developers.facebook.com/docs/graph-api}
11-15 14:09:11.473 4461 4469 W System : A resource failed to call close.
11-15 14:09:11.522 4461 4486 E GraphResponse: {HttpStatus: 400, errorCode: 100, subErrorCode: 33, errorType: GraphMethodException, errorMessage: Unsupported get request. Please read the Graph API documentation at https://developers.facebook.com/docs/graph-api}
11-15 14:09:11.663 4461 4504 E Fabric : Failed to retrieve settings from https://settings.crashlytics.com/spi/v2/platforms/android/apps/com.jeromecornet.expobackgroundfetch/settings
11-15 14:09:11.665 4461 4504 E Answers : Failed to retrieve settings
Reproducible Demo
I have put a minimal sample app here https://github.com/jeromecornet/expo-android-backgroundfetch. I set the minimumInterval to 1mn for debugging, but I've had the problem with a 15mn interval so I don't believe it's related.
The matching apk (built with expo build:android) is here: https://github.com/jeromecornet/expo-android-backgroundfetch/raw/master/app.apk
the full adb logcat output of the app working when executed is at https://github.com/jeromecornet/expo-android-backgroundfetch/raw/master/first_run.log
the full adb logcat output of of the app crashing upon reboot is at https://github.com/jeromecornet/expo-android-backgroundfetch/raw/master/after_reboot.log