ANR on Android 12 devices

[alvindizon]

Hello, first off great work in building and maintaining this library. I'd like to report ANRs that showed up on Crashlytics lately. We use the library with Hilt, so we have a module that looks like this:

@Module
@InstallIn(SingletonComponent::class)
class DataStoreModule {

    private val encryptedPrefsFileName = "encrypted-someapp-settings"

    private val Context.encryptedDataStore: DataStore<Preferences> by
        encryptedPreferencesDataStore(name = encryptedPrefsFileName)

    @Provides
    @Singleton
    fun provideDataStore(@ApplicationContext context: Context): DataStore<Preferences> =
        context.encryptedDataStore

    @Provides
    @Singleton
    fun provideCommonDataStore(dataStore: DataStore<Preferences>): CommonDataStore =
        CommonDataStoreImpl(dataStore)
}

However, we noticed ANRs coming from Android 12 users, and based on the logs provided by Crashlytics seems it happen when the property delegate for a single process DataStore is invoked. The portion of the stack trace can be found below:

main (timed waiting):tid=1 systid=10495 
       at java.lang.Thread.sleep(Native method)
       at java.lang.Thread.sleep(Thread.java:450)
       at java.lang.Thread.sleep(Thread.java:355)
       at android.security.KeyStoreSecurityLevel.interruptedPreservingSleep(KeyStoreSecurityLevel.java:206)
       at android.security.KeyStoreSecurityLevel.createOperation(KeyStoreSecurityLevel.java:115)
       at android.security.keystore2.AndroidKeyStoreCipherSpiBase.ensureKeystoreOperationInitialized(AndroidKeyStoreCipherSpiBase.java:334)
       at android.security.keystore2.AndroidKeyStoreCipherSpiBase.engineInit(AndroidKeyStoreCipherSpiBase.java:171)
       at javax.crypto.Cipher.tryTransformWithProvider(Cipher.java:2985)
       at javax.crypto.Cipher.tryCombinations(Cipher.java:2892)
       at javax.crypto.Cipher$SpiAndProviderUpdater.updateAndGetSpiAndProvider(Cipher.java:2797)
       at javax.crypto.Cipher.chooseProvider(Cipher.java:774)
       at javax.crypto.Cipher.init(Cipher.java:1144)
       at javax.crypto.Cipher.init(Cipher.java:1085)
       at com.google.crypto.tink.integration.android.AndroidKeystoreAesGcm.encryptInternal(AndroidKeystoreAesGcm.java:77)
       at com.google.crypto.tink.integration.android.AndroidKeystoreAesGcm.encrypt(AndroidKeystoreAesGcm.java:61)
       at com.google.crypto.tink.integration.android.AndroidKeystoreKmsClient.validateAead(AndroidKeystoreKmsClient.java:289)
       at com.google.crypto.tink.integration.android.AndroidKeystoreKmsClient.getAead(AndroidKeystoreKmsClient.java:157)
       at com.google.crypto.tink.integration.android.AndroidKeysetManager$Builder.readMasterkeyDecryptAndParseKeyset(AndroidKeysetManager.java:367)
       at com.google.crypto.tink.integration.android.AndroidKeysetManager$Builder.build(AndroidKeysetManager.java:303)
       at androidx.security.crypto.EncryptedFile$Builder.build(EncryptedFile.java:172)
       at io.github.osipxd.security.crypto.EncryptedPreferenceDataStoreSingletonDelegate$getValue$1$1.invoke(EncryptedPreferencesDataStoreDelegate.kt:121)
       at io.github.osipxd.security.crypto.EncryptedPreferenceDataStoreSingletonDelegate$getValue$1$1.invoke(EncryptedPreferencesDataStoreDelegate.kt:110)
       at io.github.osipxd.security.crypto.EncryptedPreferenceDataStoreFactoryKt.createEncrypted(EncryptedPreferenceDataStoreFactory.kt:76)
       at io.github.osipxd.security.crypto.EncryptedPreferenceDataStoreSingletonDelegate.getValue(EncryptedPreferencesDataStoreDelegate.kt:110)
       at io.github.osipxd.security.crypto.EncryptedPreferenceDataStoreSingletonDelegate.getValue(EncryptedPreferencesDataStoreDelegate.kt:83)
       at com.someapp.common.preferences.di.DataStoreModule.getEncryptedDataStore(DataStoreModule.kt:23)
       at com.someapp.common.preferences.di.DataStoreModule.provideDataStore(DataStoreModule.kt:28)
       at com.someapp.common.preferences.di.DataStoreModule_ProvideDataStoreFactory.provideDataStore(DataStoreModule_ProvideDataStoreFactory.java:50)
       at com.someapp.DaggerSomeApp_HiltComponents_SingletonC$SingletonCImpl$SwitchingProvider.get(DaggerSomeApp_HiltComponents_SingletonC.java:1320)
       at dagger.internal.DoubleCheck.get(DoubleCheck.java:47)
       at com.someapp.SomeApp_HiltComponents_SingletonC$SingletonCImpl$SwitchingProvider.get(DaggerSomeApp_HiltComponents_SingletonC.java:1317)
       at dagger.internal.DoubleCheck.get(DoubleCheck.java:47)
       at com.someapp.DaggerSomeApp_HiltComponents_SingletonC$SingletonCImpl.injectSomeApp2(DaggerSomeApp_HiltComponents_SingletonC.java:1264)
       at com.someapp.DaggerSomeApp_HiltComponents_SingletonC$SingletonCImpl.injectSomeApp(DaggerSomeApp_HiltComponents_SingletonC.java:1240)
       at com.someapp.Hilt_SomeApp.hiltInternalInject(Hilt_SomeApp.java:51)
       at com.someapp.Hilt_SomeApp.onCreate(Hilt_SomeApp.java:42)
       at com.someapp.SomeApp.onCreate(SomeApp.java:76)
       at android.app.Instrumentation.callApplicationOnCreate(Instrumentation.java:1211)
       at android.app.ActivityThread.handleBindApplication(ActivityThread.java:6765)
       at android.app.ActivityThread.access$1600(ActivityThread.java:253)
       at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2090)
       at android.os.Handler.dispatchMessage(Handler.java:106)
       at android.os.Looper.loopOnce(Looper.java:201)
       at android.os.Looper.loop(Looper.java:288)
       at android.app.ActivityThread.main(ActivityThread.java:7881)
       at java.lang.reflect.Method.invoke(Native method)
       at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:568)
       at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1045)

Would you have any insight as to why this is happening? It has happened to two Android 12 users so far so this is not so serious. Thanks

EDIT: found a similar reported issue with androidx.security:security-crypto 1.1.0-alpha06 here

[osipxd]

Hello, thank you for the report.

Here is the line from the stacktrace, before Thread.sleep is called. According to the code, there was ServiceSpecificException thrown with code BACKEND_BUSY which has the following description:

BACKEND_BUSY: Maybe returned by IKeystoreSecurityLevel.create if all Keymint operation slots are currently in use and none can be pruned.

It seems like system capacity for handling cryptographic operations is temporarily maxed out. Are you able to reproduce it yourself? Or, do you have more information about devices where the issue has happened?

[osipxd]

Found the comment to issue in Tink repository proving my guess.

It looks like Android infinitely retries key generation, but always gets BACKEND_BUSY error for some reason and this leads to ANR. I'm not sure if something could be done on the library side.

[alvindizon]

Thanks @osipxd for the update. I could not replicate the issue myself, with just an emulator running Android 12. It has happened on two different devices (Samsung and Ulefone). It looks like it is an issue with the underlying libraries. Will probably just add my stack trace to the Tink issue to add more information.