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

ANR in expo-updates in android on start up with large number of assets #19918

Open
celandro opened this issue Nov 8, 2022 · 9 comments
Open

Comments

@celandro
Copy link

celandro commented Nov 8, 2022

Summary

Receiving a large number of ANRs that look like:

com.pokebattler.raidParty.MainApplication.onCreate
Broadcast of Intent { act=android.intent.action.MY_PACKAGE_REPLACED cmp=com.pokebattler.raidParty/expo.modules.notifications.service.NotificationsService }
Native method - android.os.MessageQueue.nativePollOnce
Broadcast of Intent { act=android.intent.action.MY_PACKAGE_REPLACED cmp=com.pokebattler.raidParty/expo.modules.notifications.service.NotificationsService }
com.pokebattler.raidParty.MainApplication.onCreate
Broadcast of Intent { act=android.intent.action.BOOT_COMPLETED cmp=com.pokebattler.raidParty/expo.modules.notifications.service.NotificationsService }
[libart.so] art::DumpNativeStack(std::__1::basic_ostream<char, std::__1::char_traits<char> >&, int, BacktraceMap*, char const*, art::ArtMethod*, void*, bool)
Broadcast of Intent { act=android.intent.action.MY_PACKAGE_REPLACED cmp=com.pokebattler.raidParty/expo.modules.notifications.service.NotificationsService }

This has my app sitting dangerously close to the 0.47% ANR bad behavior cutoff. It spikes to almost 3% when a new release is pushed to the play store.

What platform(s) does this occur on?

Android

Environment

expo-env-info 1.0.5 environment info:

System:

  OS: macOS 12.5.1

  Shell: 3.2.57 - /bin/bash

Binaries:

  Node: 17.4.0 - /usr/local/bin/node

  npm: 8.3.1 - /usr/local/bin/npm

  Watchman: 4.9.0 - /usr/local/bin/watchman

Managers:

  CocoaPods: 1.11.2 - /usr/local/bin/pod

SDKs:

  iOS SDK:

    Platforms: DriverKit 22.1, iOS 16.1, macOS 13.0, tvOS 16.1, watchOS 9.1

  Android SDK:

    API Levels: 28, 29, 30, 31, 32

    Build Tools: 28.0.3, 29.0.2, 30.0.3, 31.0.0, 32.0.0

IDEs:

  Android Studio: 2020.3 AI-203.7717.56.2031.7935034

  Xcode: 14.1/14B47b - /usr/bin/xcodebuild

npmPackages:

  expo: ^46.0.8 => 46.0.10 

  react: 18.0.0 => 18.0.0 

  react-dom: 18.0.0 => 18.0.0 

  react-native: 0.69.5 => 0.69.5 

  react-native-web: ~0.18.7 => 0.18.9 

npmGlobalPackages:

  expo-cli: 6.0.2

Expo Workflow: bare

Minimal reproducible example

This is a bare app that is a fairly heavy user of push notifications

@celandro celandro added the needs validation Issue needs to be validated label Nov 8, 2022
@Kudo Kudo added incomplete issue: missing or invalid repro A minimal reproducible example is required for most issues and removed needs validation Issue needs to be validated labels Nov 15, 2022
@expo-bot
Copy link
Collaborator

Hi there! It looks like your issue requires a minimal reproducible example, but it is invalid or absent. Please prepare such an example and share it in a new issue.

The best way to get attention to your issue is to provide a clean and easy way for a developer to reproduce the issue on their own machine. Please do not provide your entire project, or a project with more code than is necessary to reproduce the issue.

A side benefit of going through the process of narrowing down the minimal amount of code needed to reproduce the issue is that you may get lucky and discover that the bug is due to a mistake in your application code that you can quickly fix on your own.

Resources

Common concerns

"I've only been able to reproduce it in private, proprietary code"

You may not have spent enough time narrowing down the root cause of the issue. Try out the techniques discussed in this manual debugging guide to learn how to isolate the problem from the rest of your codebase.

"I didn't have time to create one"

That's understandable, it can take some time to prepare. We ask that you hold off on filing an issue until you are able to fully complete the required fields in the issue template.

"You can reproduce it by yourself by creating a project and following these steps"

This is useful knowledge, but it's still valuable to have the resulting project that is produced from running the steps, where you have verified you can reproduce the issue.

@Kudo
Copy link
Contributor

Kudo commented Nov 15, 2022

hi there! it's hard for us to help with the issue which we cannot reproduce. could you please create a minimal reproducible project and upload it to some git repositories? i'm happy to reopen and help then.

btw, google play console should have an ANR report to show the stacktrace which causing the ANR. you could try to dig and share more information from it.

@celandro
Copy link
Author

celandro commented Nov 15, 2022 via email

@Kudo
Copy link
Contributor

Kudo commented Nov 15, 2022

i could understand it's hard to create an example or investigate issues that you cannot reproduce, and so do we.

please share the ANR report details with us. the ANR report on google play should indicate the stacktrace of each thread. that's something we could further take a look. let's see if you we find something in the reports together.

@celandro
Copy link
Author

celandro commented Nov 15, 2022

Unfortunately there is no ANR report download anymore. The original ANR messages are in the original bug report.

My guess is it is actually not expo notifications but expo updates

"main" tid=1 Native

  #00  pc 0x000000000004b38c  /apex/com.android.runtime/lib64/bionic/libc.so (syscall+28)
  #01  pc 0x00000000001af92c  /apex/com.android.art/lib64/libart.so (art::ConditionVariable::WaitHoldingLocks(art::Thread*)+148)
  #02  pc 0x000000000066b4b4  /apex/com.android.art/lib64/libart.so (art::GoToRunnable(art::Thread*)+460)
  #03  pc 0x000000000066b2a4  /apex/com.android.art/lib64/libart.so (art::JniMethodEnd(unsigned int, art::Thread*)+28)
  at android.database.sqlite.SQLiteConnection.nativeBindLong (Native method)
  at android.database.sqlite.SQLiteConnection.bindArguments (SQLiteConnection.java:1154)
  at android.database.sqlite.SQLiteConnection.executeForLastInsertedRowId (SQLiteConnection.java:934)
  at android.database.sqlite.SQLiteSession.executeForLastInsertedRowId (SQLiteSession.java:790)
  at android.database.sqlite.SQLiteStatement.executeInsert (SQLiteStatement.java:88)
  at androidx.sqlite.db.framework.FrameworkSQLiteStatement.executeInsert (FrameworkSQLiteStatement.java:51)
  at androidx.room.EntityInsertionAdapter.insert (EntityInsertionAdapter.java:64)
  at expo.modules.updates.db.dao.AssetDao_Impl._insertUpdateAsset (AssetDao_Impl.java:269)
  at expo.modules.updates.db.dao.AssetDao.addExistingAssetToUpdate (AssetDao.kt:128)
  at expo.modules.updates.db.dao.AssetDao_Impl.access$101 (AssetDao_Impl.java:33)
  at expo.modules.updates.db.dao.AssetDao_Impl.addExistingAssetToUpdate (AssetDao_Impl.java:304)
  at expo.modules.updates.loader.Loader.handleAssetDownloadCompleted (Loader.kt:269)
  at expo.modules.updates.loader.Loader.downloadAllAssets (Loader.kt:222)
  at expo.modules.updates.loader.Loader.processUpdateManifest (Loader.kt:189)
  at expo.modules.updates.loader.Loader.access$processUpdateManifest (Loader.kt:18)
  at expo.modules.updates.loader.Loader$start$1.onSuccess (Loader.kt:101)
  at expo.modules.updates.loader.EmbeddedLoader.loadManifest (EmbeddedLoader.kt:58)
  at expo.modules.updates.loader.Loader.start (Loader.kt:91)
  at expo.modules.updates.loader.LoaderTask.launchFallbackUpdateFromDisk (LoaderTask.kt:242)
  at expo.modules.updates.loader.LoaderTask.start (LoaderTask.kt:99)
  at expo.modules.updates.UpdatesController.start (UpdatesController.kt:290)
  at expo.modules.updates.UpdatesController$Companion.initialize (UpdatesController.kt:464)
  at expo.modules.updates.UpdatesPackage$createReactNativeHostHandlers$handler$1.onWillCreateReactInstanceManager (UpdatesPackage.kt:41)
  at expo.modules.ReactNativeHostWrapperBase.createReactInstanceManager (ReactNativeHostWrapperBase.kt:27)
  at com.facebook.react.ReactNativeHost.getReactInstanceManager (ReactNativeHost.java:42)
  at com.pokebattler.raidParty.MainApplication.onCreate (MainApplication.java:76)
  at android.app.Instrumentation.callApplicationOnCreate (Instrumentation.java:1192)
  at android.app.ActivityThread.handleBindApplication (ActivityThread.java:6808)
  at android.app.ActivityThread.access$1400 (ActivityThread.java:250)
  at android.app.ActivityThread$H.handleMessage (ActivityThread.java:1973)
  at android.os.Handler.dispatchMessage (Handler.java:106)
  at android.os.Looper.loop (Looper.java:250)
  at android.app.ActivityThread.main (ActivityThread.java:7766)
  at java.lang.reflect.Method.invoke (Native method)
  at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run (RuntimeInit.java:604)
  at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:958)

The most likely culprit looking into this is my very large number of icons. My assets folder has 9,844 files in it, the vast majority being pngs with 2x and 3x versions. (64x64 128x128 192x192)

@celandro
Copy link
Author

@Kudo Ive looked through the code base in details and have a summary of what the issues are. If there is someone who works on expo-updates who I could speak with on Discord or via email that would be great,

The core issue is the startup time for expo updates has a large number of synchronous calls that must complete before the app is loaded. If these calls take too long, this causes an ANR. I see most of the ANRs are on low end devices and also in background processing which makes sense.

There exists a checkOnLaunch option, it does not avoid enough of the synchronous calls to avoid the ANRs.

The first ANR is the above stack trace with the EmbeddedLoader.loadManifest when there is an update to be downloaded. Part of this is local and part of this can be skipped using checkOnLaunch flag.

The second ANR is the alternative branch that uses DatabaseLoader.initialize lines 86-96 which is used when initializing from the local disk This is a loop of file system calls on application start that causes an ANR with the number of assets I have.
Looking at the diff from sdk-46 to sdk-47 there is an additional continue that skips the expensive check

patch-package expo-updates+0.14.5.patch:

diff --git a/node_modules/expo-updates/android/src/main/java/expo/modules/updates/launcher/DatabaseLauncher.kt b/node_modules/expo-updates/android/src/main/java/expo/modules/updates/launcher/DatabaseLauncher.kt
index 9c62461..91756e1 100644
--- a/node_modules/expo-updates/android/src/main/java/expo/modules/updates/launcher/DatabaseLauncher.kt
+++ b/node_modules/expo-updates/android/src/main/java/expo/modules/updates/launcher/DatabaseLauncher.kt
@@ -85,6 +85,11 @@ class DatabaseLauncher(

     localAssetFiles = mutableMapOf<AssetEntity, String>().apply {
       for (asset in assetEntities) {
+        //patch from sdk-47
+        if (asset.id == launchAsset.id) {
+          // we took care of this one above
+          continue
+        }
         val filename = asset.relativePath
         if (filename != null) {
           val assetFile = ensureAssetExists(asset, database, context)

So my action item for now is

  1. patch in the continue block
  2. add in checkOnLaunch = NEVER
  3. use Updates.checkForUpdateAsync and Updates.fetchUpdateAsync to do updates.

Improving expo-updates to improve performance when using checkOnLaunch=NEVER or maybe even making this check always async to improve performance for all users is something I might be willing to contribute if there is interest. I realize my 10,000 pngs case is not the norm but its a good test case

@Kudo
Copy link
Contributor

Kudo commented Nov 21, 2022

hi @celandro thanks for further investigating the diff. i can confirm the problem exist and i would like to reopen this issue and follow up with team.

@Kudo Kudo reopened this Nov 21, 2022
@Kudo Kudo added Updates Issue accepted and removed incomplete issue: missing or invalid repro A minimal reproducible example is required for most issues labels Nov 21, 2022
@expo-bot
Copy link
Collaborator

Thank you for filing this issue!
This comment acknowledges we believe this may be a bug and there’s enough information to investigate it.
However, we can’t promise any sort of timeline for resolution. We prioritize issues based on severity, breadth of impact, and alignment with our roadmap. If you’d like to help move it more quickly, you can continue to investigate it more deeply and/or you can open a pull request that fixes the cause.

@celandro celandro changed the title ANR in Notifications service in android on MY_PACKAGE_REPLACED ANR in expo-updates in android on start up with large number of assets Dec 3, 2022
@douglowder douglowder self-assigned this Feb 23, 2023
@douglowder
Copy link
Contributor

Tracked in ENG-7652

@douglowder douglowder assigned Kudo and unassigned douglowder Feb 23, 2023
Kudo added a commit that referenced this issue May 17, 2023
# Why

experimenting solution for expo-updates ANR mentioned in #19918
close ENG-7652

# How

in #19918 case, the app has a large number of assets. when the app is updated from google play store, expo-updates will copy these assets from app internal storage (apk/aab) to file system and also doing database updates / asset checksums. that may take longer time.

there is a main thread lock in [`UpdatesController.launchAssetFile`](https://github.com/expo/expo/blob/c0e29be13c8d012256bdd6fd2ec751f78a8ab7c6/packages/expo-updates/android/src/main/java/expo/modules/updates/UpdatesController.kt#L148) to wait for loading finish. it is the root cause of ANR.

after visiting several ways toward the problem, this pr is my last attempt - to delay the call to react-native's `loadApp`. at this point, we can initialize expo-updates and do some heavy work in the background thread. since we don't call `setContentView(ReactRootView)`, expo-splash-screen will keep the splash screen showing. at this result, even splash screen is there, we can still send touch events and back key without ANR.

## Note
the solution is getting a little tricky and is still experimenting. to disable this feature, please add `EX_UPDATES_ANDROID_DELAY_LOAD_APP=false` to gradle.properties.

# Test Plan

- ci passed
- test eas update from the build geneated through `./gradlew :app:assembleRelease`
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

4 participants