search

airsdk / ANE-PlayAssetDelivery

Play Asset Delivery ANE
MIT License
2 stars 2 forks source link

Crash From Google Play Store Installation #11

Closed braintrain727 closed 2 years ago

braintrain727 commented 2 years ago
Expected behaviour

The app should not crash if initializing PlayAssetDelivery or calling its functions fetchAssetPack() or getAssetPackStatus().

Actual behaviour

I made a demo to test PlayAssetDelivery and am experiencing crashes the first several times I open the app and try to initialize PlayAssetDelivery. Usually the first time I start the app, I can call initAssetDelivery(). Then if I call fetchAssetPack(), the app will crash and close a few seconds later. I then restart the app and it will usually crash and close after I all initAssetDelivery(). After a few more crashes, the crashes stop, and PlayAssetDelivery is working as it should (I can access my asset packs).

This only seems to occur if I install from the Google Play Store internal testing. It does not occur if I install it directly on the device using bundletool. I have tested it on a Galaxy Tab A (8.0", 2019) Android version 11 and Galaxy S8 Android version 9.

I am only using fast-follow.

Environment
Logs

Here is my logcat log: 05-23 13:45:27.907 854 26118 I DropBoxManagerService: add tag=data_app_crash isTagEnabled=true flags=0x2 05-23 13:45:27.908 854 2033 D Debug : low && ship && 3rd party app crash, so skip dump 05-23 13:45:27.908 854 2033 W ActivityManager: crash : [APP ID],10347 05-23 13:45:27.921 854 2033 W ContextImpl: Calling a method in the system process without a qualified user: android.app.ContextImpl.sendBroadcast:1162 com.android.server.am.AppErrors.crashApplicationInner:579 com.android.server.am.AppErrors.crashApplication:443 com.android.server.am.ActivityManagerService.handleApplicationCrashInner:12392 com.android.server.am.ActivityManagerService.handleApplicationCrash:12327 05-23 13:45:27.922 854 2033 W ActivityTaskManager: Force finishing activity [APP ID]/.AIRAppEntry 05-23 13:45:27.927 854 2033 V WindowManager: Prepare app transition: transit=TRANSIT_CRASHING_ACTIVITY_CLOSE mNextAppTransition=TRANSIT_UNSET alwaysKeepCurrent=false displayId=0 Callers=com.android.server.wm.DisplayContent.prepareAppTransition:5809 com.android.server.wm.DisplayContent.prepareAppTransition:5803 com.android.server.wm.ActivityStack.finishTopCrashedActivityLocked:2733 com.android.server.wm.RootWindowContainer.finishTopCrashedActivities:2654 com.android.server.wm.ActivityTaskManagerService$LocalService.finishTopCrashedActivities:8921 05-23 13:45:27.930 854 2033 V WindowManager: Prepare app transition: transit=TRANSIT_TASK_CLOSE mNextAppTransition=TRANSIT_CRASHING_ACTIVITY_CLOSE alwaysKeepCurrent=false displayId=0 Callers=com.android.server.wm.DisplayContent.prepareAppTransition:5809 com.android.server.wm.DisplayContent.prepareAppTransition:5803 com.android.server.wm.ActivityRecord.finishIfPossible:3181 com.android.server.wm.ActivityRecord.finishIfPossible:3053 com.android.server.wm.ActivityStack.finishTopCrashedActivityLocked:2735 05-23 13:45:27.930 854 2033 D WindowManager: isScreenshotDisabledLocked - win: Window{7bfc5fe u0 InputMethod} 05-23 13:45:27.930 854 2033 D WindowManager: isScreenshotDisabledLocked: userId = 0, disabled =false 05-23 13:45:27.930 854 2033 D WindowManager: isScreenshotDisabledLocked - win: Window{b13ed63 u0 [APP ID]/[APP ID].AIRAppEntry} 05-23 13:45:27.930 854 2033 D WindowManager: isScreenshotDisabledLocked: userId = 0, disabled =false 05-23 13:45:27.942 517 523 E statsd : Predicate 5980654721335871649 dropping data for dimension key (10)0x2010101->10347[I] (10)0x30000->launch[S] 05-23 13:45:27.943 517 523 E statsd : Predicate -7037417284711607308 dropping data for dimension key (10)0x2010101->10347[I] (10)0x30000->launch[S] 05-23 13:45:27.950 854 2033 V WindowManager: Setting visibility of Window{8596e19 u0 com.android.vending/com.google.android.finsky.activities.MainActivity}: true, caller=com.android.server.wm.WindowContainer.sendAppVisibilityToClients:1004 com.android.server.wm.ActivityRecord.setClientVisible:6391 com.android.server.wm.ActivityRecord.setVisibility:4866 com.android.server.wm.ActivityRecord.setVisibility:4764 com.android.server.wm.ActivityRecord.makeVisibleIfNeeded:5409 05-23 13:45:27.951 854 2033 D MARsPolicyManager: onPackageResumedFG pkgName = com.android.vending, userId = 0

Here is my manifest.

]]>

The anes in my project are:

These are bundletool commands I am using. java -jar bundletool-all.jar build-apks --bundle=[BUNDLE NAME].aab --output=output.apks --ks=[KEYSTORE NAME].jks --ks-key-alias=[ALIAS] --local-testing --connected-device --adb=[ADB PATH]

java -jar bundletool-all.jar install-apks --apks=output.apks --adb=[ADB PATH]

ajwfrost commented 2 years ago

Hi

I don't suppose we can get the logcat output from a little earlier in the process, where the AIR app first starts up?

The fast-follow asset type seems a little odd, as the documentation states that (a) the download is automatic as soon as the app is installed - before even running it; but (b) when you run the app, you can request the download to start. These seem a little contradictory to me...

In terms of the error here, I suspect it's related to the download status and potentially some poor error handling. Not sure why any of that would cause the app to crash, mostly we should be protecting this with exception handling, but we can investigate: if you do have a full logcat output then it may help narrow things down a little more swiftly.

thanks

Andrew

braintrain727 commented 2 years ago

I have attached the full logcat output. Ihave also tested install-time, which I have no problems with.

logcat.txt

ajwfrost commented 2 years ago

Thanks - so it looks like here's the error:

05-24 08:37:55.195  9024  9024 I PlayCore: UID: [10355]  PID: [9024] ExtractionForegroundService : Starting foreground installation service.
05-24 08:37:55.200   854  4560 W ActivityManager: Permission Denial: startForeground from pid=9024, uid=10355 requires android.permission.FOREGROUND_SERVICE
05-24 08:37:55.201   854  1146 D SettingsProvider: isChangeAllowed() : name = enabled_notification_listeners
05-24 08:37:55.201   854  1146 D SettingsProvider: isChangeAllowed() : name = enabled_notification_assistant
05-24 08:37:55.201   854  1146 D SettingsProvider: isChangeAllowed() : name = enabled_notification_policy_access_packages
05-24 08:37:55.223  9024  9024 D AndroidRuntime: Shutting down VM
05-24 08:37:55.227  9024  9024 E AndroidRuntime: FATAL EXCEPTION: main
05-24 08:37:55.227  9024  9024 E AndroidRuntime: Process: [APP ID], PID: 9024
05-24 08:37:55.227  9024  9024 E AndroidRuntime: java.lang.RuntimeException: Unable to start service com.google.android.play.core.assetpacks.ExtractionForegroundService@15bb2e3 with Intent { cmp=[APP ID]/com.google.android.play.core.assetpacks.ExtractionForegroundService (has extras) }: java.lang.SecurityException: Permission Denial: startForeground from pid=9024, uid=10355 requires android.permission.FOREGROUND_SERVICE
05-24 08:37:55.227  9024  9024 E AndroidRuntime:        at android.app.ActivityThread.handleServiceArgs(ActivityThread.java:4813)
05-24 08:37:55.227  9024  9024 E AndroidRuntime:        at android.app.ActivityThread.access$2000(ActivityThread.java:301)
05-24 08:37:55.227  9024  9024 E AndroidRuntime:        at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2215)
05-24 08:37:55.227  9024  9024 E AndroidRuntime:        at android.os.Handler.dispatchMessage(Handler.java:106)
05-24 08:37:55.227  9024  9024 E AndroidRuntime:        at android.os.Looper.loop(Looper.java:246)
05-24 08:37:55.227  9024  9024 E AndroidRuntime:        at android.app.ActivityThread.main(ActivityThread.java:8653)
05-24 08:37:55.227  9024  9024 E AndroidRuntime:        at java.lang.reflect.Method.invoke(Native Method)
05-24 08:37:55.227  9024  9024 E AndroidRuntime:        at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:602)
05-24 08:37:55.227  9024  9024 E AndroidRuntime:        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1130)
05-24 08:37:55.227  9024  9024 E AndroidRuntime: Caused by: java.lang.SecurityException: Permission Denial: startForeground from pid=9024, uid=10355 requires android.permission.FOREGROUND_SERVICE
05-24 08:37:55.227  9024  9024 E AndroidRuntime:        at android.os.Parcel.createExceptionOrNull(Parcel.java:2385)
05-24 08:37:55.227  9024  9024 E AndroidRuntime:        at android.os.Parcel.createException(Parcel.java:2369)
05-24 08:37:55.227  9024  9024 E AndroidRuntime:        at android.os.Parcel.readException(Parcel.java:2352)
05-24 08:37:55.227  9024  9024 E AndroidRuntime:        at android.os.Parcel.readException(Parcel.java:2294)
05-24 08:37:55.227  9024  9024 E AndroidRuntime:        at android.app.IActivityManager$Stub$Proxy.setServiceForeground(IActivityManager.java:7835)
05-24 08:37:55.227  9024  9024 E AndroidRuntime:        at android.app.Service.startForeground(Service.java:709)
05-24 08:37:55.227  9024  9024 E AndroidRuntime:        at com.google.android.play.core.assetpacks.ExtractionForegroundService.zzb(com.google.android.play:core@@1.10.1:21)
05-24 08:37:55.227  9024  9024 E AndroidRuntime:        at com.google.android.play.core.assetpacks.ExtractionForegroundService.onStartCommand(com.google.android.play:core@@1.10.1:1)
05-24 08:37:55.227  9024  9024 E AndroidRuntime:        at android.app.ActivityThread.handleServiceArgs(ActivityThread.java:4795)
05-24 08:37:55.227  9024  9024 E AndroidRuntime:        ... 8 more
05-24 08:37:55.227  9024  9024 E AndroidRuntime: Caused by: android.os.RemoteException: Remote stack trace:
05-24 08:37:55.227  9024  9024 E AndroidRuntime:        at com.android.server.am.ActivityManagerService.enforcePermission(ActivityManagerService.java:7921)
05-24 08:37:55.227  9024  9024 E AndroidRuntime:        at com.android.server.am.ActiveServices.setServiceForegroundInnerLocked(ActiveServices.java:1537)
05-24 08:37:55.227  9024  9024 E AndroidRuntime:        at com.android.server.am.ActiveServices.setServiceForegroundLocked(ActiveServices.java:1167)
05-24 08:37:55.227  9024  9024 E AndroidRuntime:        at com.android.server.am.ActivityManagerService.setServiceForeground(ActivityManagerService.java:18000)
05-24 08:37:55.227  9024  9024 E AndroidRuntime:        at android.app.IActivityManager$Stub.onTransact(IActivityManager.java:3598)
05-24 08:37:55.227  9024  9024 E AndroidRuntime:
05-24 08:37:55.241   854  9150 I DropBoxManagerService: add tag=data_app_crash isTagEnabled=true flags=0x2
05-24 08:37:55.242   854  4560 D Debug   : low && ship && 3rd party app crash, so skip dump
05-24 08:37:55.244   854  4560 W ActivityManager: crash : [APP ID],10355

I'm not sure then whether this can be fixed just by changing the service - I just noticed it's not set to enabled?:

                <service
                    android:name="com.google.android.play.core.assetpacks.ExtractionForegroundService"
                    android:enabled="false"
                    android:exported="false" />

should be

                    android:enabled="true"

or maybe it also needs a new permission:

 <uses-permission android:name="android.permission.FOREGROUND_SERVICE"/>

thanks

braintrain727 commented 2 years ago

Adding the permission and/or enabling the service seems to have fixed the issue.

Thank you.

ajwfrost commented 2 years ago

Great, thanks for confirming!