AAssetManager_open freezing

[dan-ryan]

I’m using this c file to read files on the native side:
https://github.com/googlesamples/android-ndk/blob/master/native-media/app/src/main/cpp/android_fopen.c

Now we are getting plenty of ANRs in our app from this code - ~1700 ANRs a month.
Looks like the trouble is in “AAssetManager_open”.

This is the stack trace:

"main" prio=5 tid=1 Native
| group="main" sCount=1 dsCount=0 flags=1 obj=0x736a2b58 self=0x7c5f0c0a00
| sysTid=4920 nice=-4 cgrp=default sched=0/0 handle=0x7c642d49c8
| state=S schedstat=( 5768577463 291181617 2662 ) utm=518 stm=58 core=4 HZ=100
| stack=0x7fed7dc000-0x7fed7de000 stackSize=8MB
| held mutexes=
kernel: __switch_to+0x8c/0x98
kernel: futex_wait_queue_me+0xd8/0x130
kernel: futex_wait+0xe4/0x1d8
kernel: do_futex+0xcc/0x898
kernel: SyS_futex+0xf0/0x168
kernel: __sys_trace_return+0x0/0x4
native: #00 pc 000000000001db2c /system/lib64/libc.so (syscall+28)
native: #1 pc 0000000000068a20 /system/lib64/libc.so (_ZL33__pthread_mutex_lock_with_timeoutP24pthread_mutex_internal_tbPK8timespec+744)
native: #2 pc 000000000001ed7c /system/lib64/libandroidfw.so (_ZN7android12AssetManager4openEPKcNS_5Asset10AccessModeE+60)
native: #3 pc 0000000000012680 /system/lib64/libandroid.so (AAssetManager_open+20)
native: #4 pc 0000000000230064 /data/app/nz.co.nuffie.android.crichq.debug-gCivRXbhKxFuy6RJFelbkQ==/lib/arm64/libCricEngine.so (Z13android_fopenPKcS0+44)
native: #5 pc 00000000002306c8 /data/app/nz.co.nuffie.android.crichq.debug-gCivRXbhKxFuy6RJFelbkQ==/lib/arm64/libCricEngine.so (_ZN12CEFileHelper14isFileReadableENSt6__ndk117basic_string_viewIcNS0_11char_traitsIcEEEE+16)
native: #6 pc 0000000000230218 /data/app/nz.co.nuffie.android.crichq.debug-gCivRXbhKxFuy6RJFelbkQ==/lib/arm64/libCricEngine.so (_ZN12CEFileHelper15getAbsolutePathENSt6__ndk117basic_string_viewIcNS0_11char_traitsIcEEEE+308)
native: #7 pc 00000000002f5e74 /data/app/nz.co.nuffie.android.crichq.debug-gCivRXbhKxFuy6RJFelbkQ==/lib/arm64/libCricEngine.so (_ZN24CEPerformanceDiagnostics13loadDataFilesEv+184)
native: #8 pc 00000000002f60fc /data/app/nz.co.nuffie.android.crichq.debug-gCivRXbhKxFuy6RJFelbkQ==/lib/arm64/libCricEngine.so (_ZN24CEPerformanceDiagnostics31calculatePerformanceDiagnosticsERKNSt6__ndk110shared_ptrIK7CEMatchEE+56)
native: #9 pc 00000000002445a8 /data/app/nz.co.nuffie.android.crichq.debug-gCivRXbhKxFuy6RJFelbkQ==/lib/arm64/libCricEngine.so (_ZNK7CEMatch12getPdResultsEv+72)
native: #10 pc 0000000000245f48 /data/app/nz.co.nuffie.android.crichq.debug-gCivRXbhKxFuy6RJFelbkQ==/lib/arm64/libCricEngine.so (_ZNK7CEMatch18generateTickerTapeENSt6__ndk117basic_string_viewIcNS0_11char_traitsIcEEEEb+836)
native: #11 pc 00000000002125e8 /data/app/nz.co.nuffie.android.crichq.debug-gCivRXbhKxFuy6RJFelbkQ==/lib/arm64/libCricEngine.so (getTickerTape+40)
native: #12 pc 00000000002e4adc /data/app/nz.co.nuffie.android.crichq.debug-gCivRXbhKxFuy6RJFelbkQ==/lib/arm64/libCricEngine.so (Java_nz_co_nuffie_android_crichq_engine_CricEngine_getTickerTape+16)
native: #13 pc 0000000000511300 /system/lib64/libart.so (art_quick_generic_jni_trampoline+144)
native: #14 pc 0000000000507f84 /system/lib64/libart.so (art_quick_invoke_stub+580)
native: #15 pc 00000000000d84f4 /system/lib64/libart.so (_ZN3art9ArtMethod6InvokeEPNS_6ThreadEPjjPNS_6JValueEPKc+200)
native: #16 pc 0000000000282158 /system/lib64/libart.so (_ZN3art11interpreter34ArtInterpreterToCompiledCodeBridgeEPNS_6ThreadEPNS_9ArtMethodEPKNS_7DexFile8CodeItemEPNS_11ShadowFrameEPNS_6JValueE+352)
native: #17 pc 000000000027c820 /system/lib64/libart.so (_ZN3art11interpreter6DoCallILb0ELb0EEEbPNS_9ArtMethodEPNS_6ThreadERNS_11ShadowFrameEPKNS_11InstructionEtPNS_6JValueE+672)
native: #18 pc 00000000004ef6e4 /system/lib64/libart.so (MterpInvokeVirtual+612)
native: #19 pc 00000000004f9914 /system/lib64/libart.so (ExecuteMterpImpl+14228)
native: #20 pc 000000000025d59c /system/lib64/libart.so (_ZN3art11interpreterL7ExecuteEPNS_6ThreadEPKNS_7DexFile8CodeItemERNS_11ShadowFrameENS_6JValueEb+444)
native: #21 pc 0000000000263c9c /system/lib64/libart.so (_ZN3art11interpreter33ArtInterpreterToInterpreterBridgeEPNS_6ThreadEPKNS_7DexFile8CodeItemEPNS_11ShadowFrameEPNS_6JValueE+212)
native: #22 pc 000000000027c800 /system/lib64/libart.so (_ZN3art11interpreter6DoCallILb0ELb0EEEbPNS_9ArtMethodEPNS_6ThreadERNS_11ShadowFrameEPKNS_11InstructionEtPNS_6JValueE+640)
native: #23 pc 00000000004ef6e4 /system/lib64/libart.so (MterpInvokeVirtual+612)
native: #24 pc 00000000004f9914 /system/lib64/libart.so (ExecuteMterpImpl+14228)
native: #25 pc 000000000025d59c /system/lib64/libart.so (_ZN3art11interpreterL7ExecuteEPNS_6ThreadEPKNS_7DexFile8CodeItemERNS_11ShadowFrameENS_6JValueEb+444)
native: #26 pc 0000000000263c9c /system/lib64/libart.so (_ZN3art11interpreter33ArtInterpreterToInterpreterBridgeEPNS_6ThreadEPKNS_7DexFile8CodeItemEPNS_11ShadowFrameEPNS_6JValueE+212)
native: #27 pc 000000000027c800 /system/lib64/libart.so (_ZN3art11interpreter6DoCallILb0ELb0EEEbPNS_9ArtMethodEPNS_6ThreadERNS_11ShadowFrameEPKNS_11InstructionEtPNS_6JValueE+640)
native: #28 pc 00000000004ef6e4 /system/lib64/libart.so (MterpInvokeVirtual+612)
native: #29 pc 00000000004f9914 /system/lib64/libart.so (ExecuteMterpImpl+14228)
native: #30 pc 000000000025d59c /system/lib64/libart.so (_ZN3art11interpreterL7ExecuteEPNS_6ThreadEPKNS_7DexFile8CodeItemERNS_11ShadowFrameENS_6JValueEb+444)
native: #31 pc 0000000000263c9c /system/lib64/libart.so (_ZN3art11interpreter33ArtInterpreterToInterpreterBridgeEPNS_6ThreadEPKNS_7DexFile8CodeItemEPNS_11ShadowFrameEPNS_6JValueE+212)
native: #32 pc 000000000027c800 /system/lib64/libart.so (_ZN3art11interpreter6DoCallILb0ELb0EEEbPNS_9ArtMethodEPNS_6ThreadERNS_11ShadowFrameEPKNS_11InstructionEtPNS_6JValueE+640)
native: #33 pc 00000000004f0a50 /system/lib64/libart.so (MterpInvokeDirect+504)
native: #34 pc 00000000004f9a14 /system/lib64/libart.so (ExecuteMterpImpl+14484)
native: #35 pc 000000000025d59c /system/lib64/libart.so (_ZN3art11interpreterL7ExecuteEPNS_6ThreadEPKNS_7DexFile8CodeItemERNS_11ShadowFrameENS_6JValueEb+444)
native: #36 pc 0000000000263c9c /system/lib64/libart.so (_ZN3art11interpreter33ArtInterpreterToInterpreterBridgeEPNS_6ThreadEPKNS_7DexFile8CodeItemEPNS_11ShadowFrameEPNS_6JValueE+212)
native: #37 pc 000000000027c800 /system/lib64/libart.so (_ZN3art11interpreter6DoCallILb0ELb0EEEbPNS_9ArtMethodEPNS_6ThreadERNS_11ShadowFrameEPKNS_11InstructionEtPNS_6JValueE+640)
native: #38 pc 00000000004f0a50 /system/lib64/libart.so (MterpInvokeDirect+504)
native: #39 pc 00000000004f9a14 /system/lib64/libart.so (ExecuteMterpImpl+14484)
native: #40 pc 000000000025d59c /system/lib64/libart.so (_ZN3art11interpreterL7ExecuteEPNS_6ThreadEPKNS_7DexFile8CodeItemERNS_11ShadowFrameENS_6JValueEb+444)
native: #41 pc 0000000000263c9c /system/lib64/libart.so (_ZN3art11interpreter33ArtInterpreterToInterpreterBridgeEPNS_6ThreadEPKNS_7DexFile8CodeItemEPNS_11ShadowFrameEPNS_6JValueE+212)
native: #42 pc 000000000027c800 /system/lib64/libart.so (_ZN3art11interpreter6DoCallILb0ELb0EEEbPNS_9ArtMethodEPNS_6ThreadERNS_11ShadowFrameEPKNS_11InstructionEtPNS_6JValueE+640)
native: #43 pc 00000000004f0730 /system/lib64/libart.so (MterpInvokeInterface+1732)
native: #44 pc 00000000004f9b14 /system/lib64/libart.so (ExecuteMterpImpl+14740)
native: #45 pc 000000000025d59c /system/lib64/libart.so (_ZN3art11interpreterL7ExecuteEPNS_6ThreadEPKNS_7DexFile8CodeItemERNS_11ShadowFrameENS_6JValueEb+444)
native: #46 pc 0000000000263c9c /system/lib64/libart.so (_ZN3art11interpreter33ArtInterpreterToInterpreterBridgeEPNS_6ThreadEPKNS_7DexFile8CodeItemEPNS_11ShadowFrameEPNS_6JValueE+212)
native: #47 pc 000000000027c800 /system/lib64/libart.so (_ZN3art11interpreter6DoCallILb0ELb0EEEbPNS_9ArtMethodEPNS_6ThreadERNS_11ShadowFrameEPKNS_11InstructionEtPNS_6JValueE+640)
native: #48 pc 00000000004ef6e4 /system/lib64/libart.so (MterpInvokeVirtual+612)
native: #49 pc 00000000004f9914 /system/lib64/libart.so (ExecuteMterpImpl+14228)
native: #50 pc 000000000025d59c /system/lib64/libart.so (_ZN3art11interpreterL7ExecuteEPNS_6ThreadEPKNS_7DexFile8CodeItemERNS_11ShadowFrameENS_6JValueEb+444)
native: #51 pc 0000000000263c9c /system/lib64/libart.so (_ZN3art11interpreter33ArtInterpreterToInterpreterBridgeEPNS_6ThreadEPKNS_7DexFile8CodeItemEPNS_11ShadowFrameEPNS_6JValueE+212)
native: #52 pc 000000000027c800 /system/lib64/libart.so (_ZN3art11interpreter6DoCallILb0ELb0EEEbPNS_9ArtMethodEPNS_6ThreadERNS_11ShadowFrameEPKNS_11InstructionEtPNS_6JValueE+640)
native: #53 pc 00000000004f0730 /system/lib64/libart.so (MterpInvokeInterface+1732)
native: #54 pc 00000000004f9b14 /system/lib64/libart.so (ExecuteMterpImpl+14740)
native: #55 pc 000000000025d59c /system/lib64/libart.so (_ZN3art11interpreterL7ExecuteEPNS_6ThreadEPKNS_7DexFile8CodeItemERNS_11ShadowFrameENS_6JValueEb+444)
native: #56 pc 0000000000263c9c /system/lib64/libart.so (_ZN3art11interpreter33ArtInterpreterToInterpreterBridgeEPNS_6ThreadEPKNS_7DexFile8CodeItemEPNS_11ShadowFrameEPNS_6JValueE+212)
native: #57 pc 000000000027c800 /system/lib64/libart.so (_ZN3art11interpreter6DoCallILb0ELb0EEEbPNS_9ArtMethodEPNS_6ThreadERNS_11ShadowFrameEPKNS_11InstructionEtPNS_6JValueE+640)
native: #58 pc 00000000004ef6e4 /system/lib64/libart.so (MterpInvokeVirtual+612)
native: #59 pc 00000000004f9914 /system/lib64/libart.so (ExecuteMterpImpl+14228)
native: #60 pc 000000000025d59c /system/lib64/libart.so (_ZN3art11interpreterL7ExecuteEPNS_6ThreadEPKNS_7DexFile8CodeItemERNS_11ShadowFrameENS_6JValueEb+444)
native: #61 pc 0000000000263c9c /system/lib64/libart.so (_ZN3art11interpreter33ArtInterpreterToInterpreterBridgeEPNS_6ThreadEPKNS_7DexFile8CodeItemEPNS_11ShadowFrameEPNS_6JValueE+212)
native: #62 pc 000000000027c800 /system/lib64/libart.so (_ZN3art11interpreter6DoCallILb0ELb0EEEbPNS_9ArtMethodEPNS_6ThreadERNS_11ShadowFrameEPKNS_11InstructionEtPNS_6JValueE+640)
native: #63 pc 00000000004f0730 /system/lib64/libart.so (MterpInvokeInterface+1732)
at nz.co.nuffie.android.crichq.engine.CricEngine.getTickerTape(Native method)
at nz.co.nuffie.android.crichq.match.score.TickerTapeView.update(TickerTapeView.java:49)
at nz.co.nuffie.android.crichq.match.score.MatchScoreboard.update(MatchScoreboard.kt:61)
at nz.co.nuffie.android.crichq.matchcentre.MatchActivity.updateUi(MatchActivity.java:751)
at nz.co.nuffie.android.crichq.matchcentre.MatchActivity.handleDownloadResponse(MatchActivity.java:1116)
at nz.co.nuffie.android.crichq.matchcentre.MatchActivity.success(MatchActivity.java:1104)
at nz.co.nuffie.android.crichq.util.SyncableEntityManager$12.onResponse(SyncableEntityManager.java:704)
at nz.co.nuffie.android.crichq.util.SyncableEntityManager$12.onResponse(SyncableEntityManager.java:696)
at com.android.volley.toolbox.JsonRequest.deliverResponse(JsonRequest.java:83)
at com.android.volley.ExecutorDelivery$ResponseDeliveryRunnable.run(ExecutorDelivery.java:106)
at android.os.Handler.handleCallback(Handler.java:789)
at android.os.Handler.dispatchMessage(Handler.java:98)
at android.os.Looper.loop(Looper.java:164)
at android.app.ActivityThread.main(ActivityThread.java:6944)
at java.lang.reflect.Method.invoke(Native method)
at com.android.internal.os.Zygote$MethodAndArgsCaller.run(Zygote.java:327)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1374)

Using NDK r17c and Clang.

Does anyone know any possible fixes or other things I could try to narrow the problem down?

[TsvetanBogoev]

We also hit this bug a couple of months ago. So we are not using AAssetManager anymore, instead all assets are extracted to the internal memory (one the app starts) and native code access them as regular files.

[rprichard]

Looks like this is a duplicate of android/ndk-samples#571, which is closed now.

[dan-ryan]

@rprichard while this might be a duplicate, is it a bug in the NDK? Using this code worked fine for many years:

    AAssetManager *mgr = AAssetManager_fromJava(env, assetManager);
    android_fopen_set_asset_manager(mgr);

If it is how it should be then shouldn't it be made to always fail, or at least have a better error message when it does fail? It just froze up our app for like 1 minute + then crashed.

[rprichard]

I think the sample needed to register a global reference to keep the AssetManager from being collected (or moved?) after the createStreamingMediaPlayer JNI function had returned. When it worked in the past, I would guess it was just getting lucky.

I'm not sure what the NDK can do about this.

We do have a warning on the AAssetManager_fromJava docs:

Note that the caller is responsible for obtaining and holding a VM reference to the jobject to prevent its being garbage collected while the native object is in use.

[eddielong]

This happened to me before, cause was calling it on a non UI thread.

[dan-ryan]

"We do have a warning on the AAssetManager_fromJava docs"
Ah ok, I missed this.