PlayAssetDelivery: can't fetch on-demand/fast-forward packs on installed app downloaded from Google Play

[jimmymjing]

I'm so sorry to ask this question all around. I'm just afraid that it simply got ignored somehow. I fight on this for many days but to no avail. I assume it is a bug for the PlayAssetDelivery ANE. The original post is here: airsdk/ANE-PlayAssetDelivery#6

Please shed some light on this. I think most of the apps would exceed 250MB and using PAD should be a must. Can someone please confirm that on-demand Asset Delivery is working? Thanks so much!!!

[jimmymjing]

@ajwfrost I'm sorry to bother you again. I just tested on-demand AssetPackDelivery with the latest AIRSDK_33.1.1.743, and failed again. May I ask if there is any progress on this? Now, this is the only thing preventing us from uploading aab to the Play Store. Thanks in advance!

(As I'm the only one reporting this PAD on-demand issue, it makes me really worried and I start feeling like it might be an issue on my side. If anyone has successfully done this, please let me know.)

[ajwfrost]

Hi

I've just gone through and double-checked this using our test cases, and it's working okay here ...

Looking at the log file from the linked issue, we can see:

01-07 10:33:15.280 I/PlayCore(32521): UID: [10273]  PID: [32521] AssetPackServiceListenerRegistry : registerListener
01-07 10:33:15.284 I/PlayCore(32521): UID: [10273]  PID: [32521] AssetPackServiceImpl : startDownload([ap_assets_one])
01-07 10:33:15.284 I/PlayCore(32521): UID: [10273]  PID: [32521] AssetPackServiceImpl : syncPacks
01-07 10:33:15.285 I/PlayCore(32521): UID: [10273]  PID: [32521] AssetPackServiceImpl : Initiate binding to the service.
01-07 10:33:15.301 I/PlayCore(32521): UID: [10273]  PID: [32521] AssetPackServiceImpl : Waiting to bind to the service.

and then 5s later it looks like it's being killed as an ANE.

So I'm wondering if there's still an issue with the services listed in your app descriptor file, or the Google Play service?
Can you try the getAssetPackStatus() method as the first request, and let us know what the return value is? Or is this blocking?

We can perhaps send you a version of the ANE library that has additional debug information in it, if that doesn't help... I am wondering whether the declaration that some of the APIs are asynchronous may be different from them being multithreaded so it may be that us waiting to get a response from the service is causing it to not actually run properly in this case!

thanks

[ajwfrost]

@jimmymjing please try with the below version of the ANE, which has some extra logging in it.
As I understand it, the best approach would be:

1. add an event listener for PlayAssetDeliveryEvent.PLAY_ASSET_UPDATE and trace out any events that are triggered
2. call getAssetPackLocation -> should return null if the asset pack is not yet downloaded
3. call getAssetPackStatus -> should return a value which indicates the status
4. and check the logcat output, if you post it here we should be able to see what may be going on...

thanks
PlayAssetDelivery.zip

[jimmymjing]

@ajwfrost Thanks so much for the debug version ANE, I will follow the directions pointed out in your post and let you know the results!

[jimmymjing]

@ajwfrost
Hi, I have updated the ANE and here's my code and the catlog output.
I just called getAssetPackStatusand it causes my app to freeze (calling getAssetPackStatus blocks). I have called initAssetDelivery before calling this function. initAssetDelivery didn't freeze the app.

_pad = new PlayAssetDelivery();
_isPADInited = _pad.initAssetDelivery();
if (_isPADInited) {
    _pad.addEventListener(PlayAssetDeliveryEvent.PLAY_ASSET_UPDATE, playAssetDelivery_statusHandler);
    //calling either function (getAssetPackStatus / getAssetPackLocation / fetchAssetPack) freezes the app
    var sta:int = _pad.getAssetPackStatus("ap_assets_one");
    log("ap status:" + sta); // <-------NEVER REACH HERE
   // _pad.getAssetPackLocation("ap_assets_one");

    //_pad.fetchAssetPack("ap_assets_one");
}

//log from OnePlus mobile
play store_2022_1_19_11_49_9.log

//log from XiaoMi mobile
logcat.log

Just in case, here's the description xml.
Main-app.xml.zip

[ajwfrost]

Hi - something's gone wrong with the update here then as we're not seeing the log output that we'd expect .. let me double-check the build (or re-do it with the normal build script) and perhaps add a bit more logging into it. If "getAssetPackLocation" is still blocking then it means you're not executing the updated code as we changed how this function works...

Will provide another updated ANE file shortly...

thanks

[jimmymjing]

Thanks so much! I will test it right away once I get the ANE :D

[ajwfrost]

Hi

Please check with the below ANE file, and if you don't see trace output like the below then please double-check the ANE file is properly updated and rebuild/deploy is working! Below is with local testing but we're pushing out Android log 'warning' level to try to ensure it shows up...

01-19 05:04:23.163 25551 25551 W AdobeAIR: >> InitAssetDelivery
01-19 05:04:23.210 25551 25551 I PlayCore: UID: [10568]  PID: [25551] AssetPackServiceListenerRegistry : registerListener
01-19 05:04:23.216 25551 25551 W AdobeAIR:    InitAssetDelivery SUCCESS
01-19 05:04:23.217 25551 25551 W AdobeAIR: << InitAssetDelivery

01-19 05:04:23.259 25551 25551 W AdobeAIR: >> GetAssetStatus
01-19 05:04:23.259 25551 25551 W AdobeAIR: Requesting pack status for fast_follow_asset_pack
01-19 05:04:23.259 25551 25606 I PlayCore: UID: [10568]  PID: [25551] FakeAssetPackService : syncPacks()
01-19 05:04:23.262 25551 25551 I PlayCore: UID: [10568]  PID: [25551] FakeAssetPackService : getPackStates([fast_follow_asset_pack])
01-19 05:04:23.315 25551 25551 W AdobeAIR: getStatus for fast_follow_asset_pack completed
01-19 05:04:23.315 25551 25551 W AdobeAIR:    GetAssetStatus = 4
01-19 05:04:23.315 25551 25551 W AdobeAIR: << GetAssetStatus

01-19 05:04:23.587 25551 25551 W AdobeAIR: >> GetAssetPackLocation
01-19 05:04:23.594 25551 25551 W AdobeAIR: Asset pack [fast_follow_asset_pack] is already available
01-19 05:04:23.594 25551 25551 W AdobeAIR: Storage method = STORAGE_FILES
01-19 05:04:23.594 25551 25551 W AdobeAIR: Asset pack files at /data/data/air.com.harman.air.TestPAD/files/assetpacks/fast_follow_asset_pack/1/1/assets
01-19 05:04:23.594 25551 25551 W AdobeAIR:    GetAssetPackLocation = /data/data/air.com.harman.air.TestPAD/files/assetpacks/fast_follow_asset_pack/1/1/assets
01-19 05:04:23.595 25551 25551 W AdobeAIR: << GetAssetPackLocation

If you can call it like the below it may be best (and an "aab-debug" build would mean we should see the AS3 trace() output):

_pad = new PlayAssetDelivery();
trace("Created PlayAssetDelivery ANE, about to initialize");
_isPADInited = _pad.initAssetDelivery();
trace("PlayAssetDelivery initialize returned " + _isPADInited);
if (_isPADInited) {
    _pad.addEventListener(PlayAssetDeliveryEvent.PLAY_ASSET_UPDATE, playAssetDelivery_statusHandler);
    trace("PlayAssetDelivery calling getAssetPackLocation");
    var loc : String = _pad.getAssetPackLocation("ap_assets_one");
    trace("PlayAssetDelivery getAssetPackLocation returned " + loc);

    trace("PlayAssetDelivery calling getAssetPackStatus");
    var sta:int = _pad.getAssetPackStatus("ap_assets_one");
    trace("PlayAssetDelivery getAssetPackStatus returned " + sta);
    log("ap status:" + sta); // <-------NEVER REACH HERE
   // _pad.getAssetPackLocation("ap_assets_one");

    //_pad.fetchAssetPack("ap_assets_one");
}

thanks!
PlayAssetDelivery.zip

[jimmymjing]

Will test it right away.

[jimmymjing]

@ajwfrost Hello, now it works! I just copy/pasted the code and then packaged the aab with aab-debug. Here's the catlog output:
play store_2022_1_19_13_22_58.log

Does aab-debug and aab make any difference expect the trace() log?
I will test fetchAssetPack now.

[jimmymjing]

@ajwfrost
Hello, I called fetchAssetPack but the event handler never gets triggered. Here's the log:

play store_2022_1_19_14_1_40.log

p.s. Local test PAD always works. I only have this PAD fetching issue for the app downloaded through Play Store internal testing.

[ajwfrost]

Great, thanks ... so we had slightly updated the code under the "GetAssetStatus" command:

01-19 05:22:46.698 W/AdobeAIR(23670): >> GetAssetStatus
01-19 05:22:46.698 W/AdobeAIR(23670): Requesting pack status for ap_assets_one
01-19 05:22:46.698 I/PlayCore(23670): UID: [10469]  PID: [23670] AssetPackServiceImpl : getPackStates([ap_assets_one])
01-19 05:22:46.719 I/PlayCore(23670): UID: [10469]  PID: [23670] AssetPackServiceImpl : Waiting to bind to the service.
...
01-19 05:22:46.899 W/AdobeAIR(23670): getStatus for ap_assets_one has not yet completed
01-19 05:22:46.899 W/AdobeAIR(23670):    GetAssetStatus = 0
01-19 05:22:46.899 W/AdobeAIR(23670): << GetAssetStatus
...
01-19 05:22:46.952 I/PlayCore(23670): UID: [10469]  PID: [23670] AssetPackServiceImpl : ServiceConnectionImpl.onServiceConnected(ComponentInfo{com.android.vending/com.google.android.finsky.assetmoduleservice.AssetModuleService})
01-19 05:22:46.952 I/PlayCore(23670): UID: [10469]  PID: [23670] AssetPackServiceImpl : linkToDeath
01-19 05:22:46.958 I/PlayCore(23670): UID: [10469]  PID: [23670] AssetPackServiceImpl : onGetSessionStates
01-19 05:22:46.960 I/PlayCore(23670): UID: [10469]  PID: [23670] AssetPackServiceImpl : Unbind from service.
01-19 05:22:46.961 W/PlayAssetDeliveryManager(23670): getPackStates failed
...

Previously, we were waiting for the response from the asset pack service, but you can see these are coming in now after we have returned from the function (with the trace getStatus for ap_assets_one has not yet completed).

The only trouble appears to be, when the task does complete, it has failed...

Let us tweak this a little more and see if we can get it to work in a more asynchronous way. This is going to mean that the getAssetPackStatus method will never provide a response directly, it will always need to trigger a status update event...

thanks

[jimmymjing]

Thanks so much! I will wait for an updated ANE then :)

[ajwfrost]

Here's another version .. not quite sure why the task was saying it's failed but the Android example code just tries to get the task result, so I've changed it so that it's logging the 'success' value but trying to get the result information regardless..

Plus other blocking calls have been removed. There's hopefully some events now being dispatched to the playAssetDelivery_statusHandler method.

thanks
PlayAssetDelivery.zip

[jimmymjing]

Hi, this time the package gets downloaded! Thanks! I will post the log here and maybe you can check to see if things look right. (I do see linktodeath)
May I use it in production or I shall wait a bit?
play store_2022_1_19_14_53_55.log

[ajwfrost]

Awesome, thanks for the log...

So this time we get the results of the "status" task successfully:

01-19 06:53:44.260 W/AdobeAIR(13925): AssetPackStates task has completed
01-19 06:53:44.260 W/AdobeAIR(13925): AssetPackStates task is successful
01-19 06:53:44.260 W/AdobeAIR(13925): AssetPackStates result is available
01-19 06:53:44.260 W/AdobeAIR(13925): status: 8, name: ap_assets_one, errorCode: 0, bytesDownloaded: 0, totalBytesToDownload: 6767, transferProgressPercentage: 0

with status 8 = NOT_INSTALLED. So, that's successful and I think you've got that value being traced out from your event handler..?

The request for "fetch" isn't working though, I'm wondering whether this is because they're overlapping i.e. the fetch request starts before the "status" task has finished:

01-19 06:53:44.271 W/AdobeAIR(13925): Fetch asset pack task has completed
01-19 06:53:44.271 W/AdobeAIR(13925): Fetch asset pack task is not successful
01-19 06:53:44.271 E/AdobeAIR(13925): Exception in fetch asset pack completion handler: android.os.RemoteException: AssetPackService : Binder has died.

But curiously this does seem to have kicked off the request:

01-19 06:53:44.285 I/Finsky  (24466): [2427] fdh.a(59): Starting download of module ap_assets_one

and we then get status events as it is fetched:

01-19 06:53:44.439 W/AdobeAIR(13925): Asset pack onStateUpdate -> ap_assets_one -> 1
01-19 06:53:44.445 D/        (13925): [AssetPackManager]: status: PENDING
01-19 06:53:44.446 W/AdobeAIR(13925): Asset pack onStateUpdate -> ap_assets_one -> 2
01-19 06:53:44.449 D/        (13925): [AssetPackManager]: status: DOWNLOADING
01-19 06:53:51.066 W/AdobeAIR(13925): Asset pack onStateUpdate -> ap_assets_one -> 3
01-19 06:53:51.074 D/        (13925): [AssetPackManager]: status: TRANSFERRING
01-19 06:53:51.133 W/AdobeAIR(13925): Asset pack onStateUpdate -> ap_assets_one -> 4
01-19 06:53:51.137 D/        (13925): [AssetPackManager]: status: COMPLETED

So after it's hit the "completed" status, you should be able to get at the files from it...

I'll just tidy up and remove some of the logging (or switch it back down to debug/info levels); I'm wondering whether we also need to prevent folk from calling one async function when another one is already in progress, but it may just be that this was a fast-follow pack so perhaps it's invalid to request a "fetch" unless the download was interrupted (looking at the Android/Java documentation on it...) -> it can be left to the user here I think! But to let you know there's been a response, we can trigger another update event there and leave the status at 'unknown'...

Best to wait for a proper release with an updated version number in it! but that should be possible to do later today.

thanks

[ajwfrost]

Hi @jimmymjing
Please find below the updated ANE... @marchbold are you able to update this on the PlayAssetDelivery repository please, github is telling me I don't have push access.. thanks!

PlayAssetDelivery.zip

[jimmymjing]

@ajwfrost Thanks so much!

[marchbold]

Yep, will get that up this shortly.

[marchbold]

v1.0.2 is available now, in the repo and apm.