search

Iterable / iterable-android-sdk

Iterable's Android SDK. Receive and track pushes to Iterable from your Android app.
https://iterable.com/
MIT License
30 stars 29 forks source link

Initialize causing ANR when creating encrypted shared prefrences #760

Open lmorda opened 4 months ago

lmorda commented 4 months ago

Our users are experiencing ANR errors when Iterable is being initialized according to BugSnag reports:

ANR:  executing service com.shiftkey.provider/com.shiftkey.invoicing.service.GeofencingLocationService
libc.so +0x5c072               syscall
libart.so +0x2395ab            art::ConditionVariable::TimedWait(art::Thread*, long long, int)
libart.so +0x23de35            art::Monitor::Wait(art::Thread*, long long, int, bool, art::ThreadState)
libart.so +0x23d89b            art::Monitor::Wait(art::Thread*, art::ObjPtr<art::mirror::Object>, long long, int, bool, art::ThreadState)
libart.so +0x458745            art::Thread_sleep(_JNIEnv*, _jclass*, _jobject*, long long, int)
boot.oat +0xa9673              art_jni_trampoline
boot.oat +0x187151             java.lang.Thread.sleep
boot.oat +0x186f5d             java.lang.Thread.sleep
libart.so +0xf17ca             nterp_helper
<unknown>                      <unknown>
boot-framework.oat +0x51e483   android.security.KeyStoreSecurityLevel.createOperation
boot-framework.oat +0x561abd   android.security.keystore2.AndroidKeyStoreCipherSpiBase.ensureKeystoreOperationInitialized
libart.so +0xf1b8a             nterp_helper
<unknown>                      <unknown>
boot.oat +0x11dcb5             javax.crypto.Cipher.tryTransformWithProvider
boot.oat +0x11cf8d             javax.crypto.Cipher.tryCombinations
boot.oat +0x11aca1             javax.crypto.Cipher$SpiAndProviderUpdater.updateAndGetSpiAndProvider
boot.oat +0x11b34d             javax.crypto.Cipher.chooseProvider
boot.oat +0x11e5b3             javax.crypto.Cipher.init
boot.oat +0x11e519             javax.crypto.Cipher.init
base.odex +0xa35bbd            lc.b.d
base.odex +0xa3566f            lc.b.a
base.odex +0xa35e95            lc.c.i
base.odex +0xa36115            lc.c.b
libart.so +0xf1b8a             nterp_helper
<unknown>                      <unknown>
base.odex +0x978839            lc.a$b.f
base.odex +0x397a2d            e7.a.b
base.odex +0x39783f            e7.a.a
base.odex +0x8a15f1            ce.k0.<init>
base.odex +0x92a57f            com.iterable.iterableapi.c.x
base.odex +0x929bd1            com.iterable.iterableapi.c.M
base.odex +0x928c45            com.iterable.iterableapi.c.D
base.odex +0x890929            com.shiftkey.provider.app.ProviderApplication.onCreate
boot-framework.oat +0x247cbf   android.app.Instrumentation.callApplicationOnCreate
boot-framework.oat +0x31326b   android.app.ActivityThread.handleBindApplication
boot-framework.oat +0x30a21d   android.app.ActivityThread$H.handleMessage
boot-framework.oat +0x4f0a5f   android.os.Handler.dispatchMessage
libart.so +0xf1b8a             nterp_helper
<unknown>                      <unknown>
boot-framework.oat +0x4f31a1   android.os.Looper.loop
boot-framework.oat +0x319fc1   android.app.ActivityThread.main
libart.so +0x1795d3            art_quick_invoke_stub_internal
libart.so +0x1abced            void art::quick_invoke_reg_setup<true>(art::ArtMethod*, unsigned int*, unsigned int, art::Thread*, art::JValue*, char const*) [clone .llvm.16767119545644103066]
libart.so +0x1b2ccb            art::ArtMethod::Invoke(art::Thread*, unsigned int*, unsigned int, art::JValue*, char const*)
libart.so +0x2a8b77            _jobject* art::InvokeMethod<(art::PointerSize)4>(art::ScopedObjectAccessAlreadyRunnable const&, _jobject*, _jobject*, _jobject*, unsigned int)
libart.so +0x2a8975            art::Method_invoke(_JNIEnv*, _jobject*, _jobject*, _jobjectArray*)
boot.oat +0xaa045              art_jni_trampoline
boot-framework.oat +0x7bc531   com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run
boot-framework.oat +0x7c3d59   com.android.internal.os.ZygoteInit.main
libart.so +0x1795d3            art_quick_invoke_stub_internal
libart.so +0x1abced            void art::quick_invoke_reg_setup<true>(art::ArtMethod*, unsigned int*, unsigned int, art::Thread*, art::JValue*, char const*) [clone .llvm.16767119545644103066]
libart.so +0x2964f1            art::JValue art::InvokeWithVarArgs<_jmethodID*>(art::ScopedObjectAccessAlreadyRunnable const&, _jobject*, _jmethodID*, std::__va_list)
libart.so +0x415a11            art::JNI<true>::CallStaticVoidMethodV(_JNIEnv*, _jclass*, _jmethodID*, std::__va_list)
libandroid_runtime.so +0x770bb _JNIEnv::CallStaticVoidMethod(_jclass*, _jmethodID*, ...)
libandroid_runtime.so +0x802e9 android::AndroidRuntime::start(char const*, android::Vector<android::String8> const&, bool)
app_process32 +0x2561          main
libc.so +0x5a5db               __libc_init
                               java.lang.Thread.sleep (Thread.java:-2)
                               java.lang.Thread.sleep (Thread.java:451)
                               java.lang.Thread.sleep (Thread.java:356)
                               android.security.KeyStoreSecurityLevel.interruptedPreservingSleep (KeyStoreSecurityLevel.java:206)
                               android.security.KeyStoreSecurityLevel.createOperation (KeyStoreSecurityLevel.java:115)
                               android.security.keystore2.AndroidKeyStoreCipherSpiBase.ensureKeystoreOperationInitialized (AndroidKeyStoreCipherSpiBase.java:334)
                               android.security.keystore2.AndroidKeyStoreCipherSpiBase.engineInit (AndroidKeyStoreCipherSpiBase.java:171)
                               javax.crypto.Cipher.tryTransformWithProvider (Cipher.java:2984)
                               javax.crypto.Cipher.tryCombinations (Cipher.java:2891)
                               javax.crypto.Cipher$SpiAndProviderUpdater.updateAndGetSpiAndProvider (Cipher.java:2796)
                               javax.crypto.Cipher.chooseProvider (Cipher.java:773)
                               javax.crypto.Cipher.init (Cipher.java:1143)
                               javax.crypto.Cipher.init (Cipher.java:1084)
                               com.google.crypto.tink.integration.android.AndroidKeystoreAesGcm.encryptInternal (AndroidKeystoreAesGcm:85)
                               com.google.crypto.tink.integration.android.AndroidKeystoreAesGcm.encrypt (AndroidKeystoreAesGcm:69)
                               com.google.crypto.tink.integration.android.AndroidKeystoreKmsClient.validateAead (AndroidKeystoreKmsClient:298)
                               com.google.crypto.tink.integration.android.AndroidKeystoreKmsClient.getAead (AndroidKeystoreKmsClient:180)
                               com.google.crypto.tink.integration.android.AndroidKeysetManager$Builder.readMasterkeyDecryptAndParseKeyset (AndroidKeysetManager:365)
                               com.google.crypto.tink.integration.android.AndroidKeysetManager$Builder.build (AndroidKeysetManager:297)
                               androidx.security.crypto.EncryptedSharedPreferences.create (EncryptedSharedPreferences:169)
                               androidx.security.crypto.EncryptedSharedPreferences.create (EncryptedSharedPreferences:130)
                               com.iterable.iterableapi.IterableKeychain.<init> (IterableKeychain:38)
                               com.iterable.iterableapi.IterableApi.getKeychain (IterableApi:146)
                               com.iterable.iterableapi.IterableApi.retrieveEmailAndUserId (IterableApi:446)
                               com.iterable.iterableapi.IterableApi.initialize (IterableApi:597)
                               com.shiftkey.provider.app.ProviderApplication.initIterable (ProviderApplication:78)
                               com.shiftkey.provider.app.ProviderApplication.onCreate (ProviderApplication:48)
                               android.app.Instrumentation.callApplicationOnCreate (Instrumentation.java:1213)
                               android.app.ActivityThread.handleBindApplication (ActivityThread.java:6915)
                               android.app.ActivityThread.access$1600 (ActivityThread.java:261)
                               android.app.ActivityThread$H.handleMessage (ActivityThread.java:2154)
                               android.os.Handler.dispatchMessage (Handler.java:111)
                               android.os.Looper.loopOnce (Looper.java:238)
                               android.os.Looper.loop (Looper.java:357)
                               android.app.ActivityThread.main (ActivityThread.java:8098)
                               java.lang.reflect.Method.invoke (Method.java:-2)
                               com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run (RuntimeInit.java:548)
                               com.android.internal.os.ZygoteInit.main (ZygoteInit.java:1026)

The problem appears to be when the Iterable keychain is initialized and a call to androidx.security.crypto.EncryptedSharedPreferences.create is made. This is a bit confusing because we do not store in-app messages in memory, in other words we don't set setUseInMemoryStorageForInApps(true) we are simply just calling initialize with a default config:

class ShiftKeyApplication : Application() {

    override fun onCreate() {
        super.onCreate()
    }

    private fun initIterable() {
        val config = IterableConfig.Builder().build()
        IterableApi.initialize(this, BuildConfig.ITERABLE_API_KEY, config)
    }
}

Should this Iterable keychain initialization be offloaded to a background thread? Also is there a reason why EncryptedSharedPreferences.create is called even though we don't use encrypted messages? Thanks

Ayyanchira commented 4 months ago

Thank you for sharing the logs @lmorda !

SDK stores Email/ UserId Android's Encrypted Shared Preference over Regular shared preference starting 3.4.10 and hence the usage of Encrypted Shared Preferences.

Can you share which version of SDK is being used in the app?

lmorda commented 4 months ago

@Ayyanchira thank you for your quick response and your explanation!

We've been on version 3.5.1 for the two months and we see the issue intermittently (12 users in the last 30 days). This morning we had 31 events which triggered an error notification in our BugSnag Slack channel. But all of these events were from the same user.

Ayyanchira commented 4 months ago

Will you be able to provide device detail on which the crash is occuring. We can try replicating it and see what exactly is happening.

Iterable uses google's crypto library. Crypto has been getting updates over recent years focussing on crashes on the device, however, the issue - still remains open: https://issuetracker.google.com/issues/176215143?pli=1

lmorda commented 4 months ago

@Ayyanchira here are the devices reporting the issue the last 30 days:

moto g play - 2023 REVVL V+ 5G TCL Stylus 5G (T779W) moto g power (2022) K92 (LM-K920) LG G8 ThinQ™ (LM-G820) Nokia 7.2 U668AA moto g stylus 5G motorola one 5G UW ace

and all of these devices are either on Android 11 or Android 12

Hospes commented 1 month ago

Same for me, all 100% of reportings comes from Android 12, SDK version is 3.5.3 device manufacturers are:

randalleastland commented 1 month ago

We are having the same issue. The problem appears to be in the file IterableKeychain.kt. .

In the constructor on line 38, you are calling EncryptedSharedPreferences.create(). The version of create() that you are using is deprecated. The Google documentation clearly says that this method is not thread safe.

I believe that if you switched to this version of create(), then this issue would be resolved.

Can you please comment here that you are aware of this issue and are willing to fix it? We have users where background threads report ANRs and eventually a crashed thread as a result of this.

Thank you.

Ayyanchira commented 1 month ago

Hi @randalleastland thanks for writing in.

This does point out ambiguous variable name problem in SDK. Rest assured, SDK indeed uses the recommended approach which accepts MasterKey instead of String alias. masterKeyAlias variable name may have caused the confusion, suggesting the use of a deprecated method.

And yes, the team is aware of the issue and is actively working towards a solution.