search

oblador / react-native-keychain

:key: Keychain Access for React Native
MIT License
3.12k stars 515 forks source link

Cold start on android took 5-10 seconds longer than before the library update #630

Open MikeDevBeddo opened 3 months ago

MikeDevBeddo commented 3 months ago

In library version 8.1.3, where the setUserAuthenticationParameters method was changed using KeyProperties.AUTH_BIOMETRIC_STRONG the application started taking much longer to run

ieatfood commented 3 months ago

I'm also seeing this after upgrading. Downgrading to 8.1.2 fixes the issue for now.

Our users on Google Pixel devices running Android 14 are seeing a delay and the app not responding for 8 to 20 seconds.

Here's the ANR stack trace:

ANR:  Input dispatching timed out (38b8f8a com.example.app/com.example.app.activities.MainActivity (server) is not responding. Waited 5001ms for MotionEvent).
libc.so +0xb6964                __ioctl
libc.so +0x68e78                ioctl
libbinder.so +0x7307c           android::IPCThreadState::transact(int, unsigned int, android::Parcel const&, android::Parcel*, unsigned int)
libbinder.so +0x72894           android::BpBinder::transact(unsigned int, android::Parcel const&, android::Parcel*, unsigned int)
libandroid_runtime.so +0x193da4 android_os_BinderProxy_transact(_JNIEnv*, _jobject*, int, _jobject*, _jobject*, int)
boot.oat +0x331d6c              art_jni_trampoline
                                android.os.BinderProxy.transactNative (BinderProxy.java:-2)
                                android.os.BinderProxy.transact (BinderProxy.java:586)
                                android.system.keystore2.IKeystoreSecurityLevel$Stub$Proxy.createOperation (IKeystoreSecurityLevel.java:276)
                                android.security.KeyStoreSecurityLevel.createOperation (KeyStoreSecurityLevel.java:83)
                                android.security.keystore2.AndroidKeyStoreSignatureSpiBase.ensureKeystoreOperationInitialized (AndroidKeyStoreSignatureSpiBase.java:213)
                                android.security.keystore2.AndroidKeyStoreSignatureSpiBase.engineInitSign (AndroidKeyStoreSignatureSpiBase.java:123)
                                android.security.keystore2.AndroidKeyStoreSignatureSpiBase.engineInitSign (AndroidKeyStoreSignatureSpiBase.java:101)
                                java.security.Signature$Delegate.init (Signature.java:1357)
                                java.security.Signature$Delegate.chooseProvider (Signature.java:1310)
                                java.security.Signature$Delegate.engineInitSign (Signature.java:1385)
                                java.security.Signature.initSign (Signature.java:679)

And here are some logs, if that's helpful:

2024-03-19 09:30:04.275   618-21644 keystore2               keystore2                            W  system/security/keystore2/watchdog/src/lib.rs:114 - ### Keystore Watchdog report - BEGIN ###
2024-03-19 09:30:04.275   618-21644 keystore2               keystore2                            W  system/security/keystore2/watchdog/src/lib.rs:123 - When extracting from a bug report, please include this header
2024-03-19 09:30:04.275   618-21644 keystore2               keystore2                            W  system/security/keystore2/watchdog/src/lib.rs:124 - and all 4 records below.
2024-03-19 09:30:04.275   618-21644 keystore2               keystore2                            W  system/security/keystore2/watchdog/src/lib.rs:154 - ThreadId(135) IKeystoreSecurityLevel::generateKey Pending: 17.013374479s Overdue 12.01337684s: SecurityLevel r#STRONGBOX
2024-03-19 09:30:04.275   618-21644 keystore2               keystore2                            W  system/security/keystore2/watchdog/src/lib.rs:154 - ThreadId(135) In KeystoreSecurityLevel::generate_key (No attestation): calling generate_key. Pending: 17.013316211s Overdue 12.013317025s: SecurityLevel r#STRONGBOX
2024-03-19 09:30:04.276   618-21644 keystore2               keystore2                            W  system/security/keystore2/watchdog/src/lib.rs:154 - ThreadId(1) IKeystoreSecurityLevel::createOperation Pending: 16.300914966s Overdue 15.800915617s: SecurityLevel r#TRUSTED_ENVIRONMENT
2024-03-19 09:30:04.276   618-21644 keystore2               keystore2                            W  system/security/keystore2/watchdog/src/lib.rs:154 - ThreadId(1) In KeystoreSecurityLevel::create_operation: calling begin Pending: 16.300666918s Overdue 15.800667285s: SecurityLevel r#TRUSTED_ENVIRONMENT
2024-03-19 09:30:04.276   618-21644 keystore2               keystore2                            W  system/security/keystore2/watchdog/src/lib.rs:175 - ### Keystore Watchdog report - END ###
2024-03-19 09:30:04.428   622-1867  libnos_datagram         citadeld                             D  App 0x02 returning 0x0
2024-03-19 09:30:04.430   621-621   TrustyKeymaster         and...curity.keymint-service.trusty  W  readv for cmd 4 finished after 16454263436 nsecs
2024-03-19 09:30:04.438  1718-4976  BiometricService        system_server                        D  Sensor ID(1), oemStrength: 4095, updatedStrength: 4095, modality 8, state: 0, cookie: 0, sensorId 1, hasEnrollments: false cannot participate in Keystore operations
2024-03-19 09:30:04.443   618-21644 keystore2               keystore2                            W  system/security/keystore2/watchdog/src/lib.rs:114 - ### Keystore Watchdog report - BEGIN ###
2024-03-19 09:30:04.443   618-21644 keystore2               keystore2                            W  system/security/keystore2/watchdog/src/lib.rs:123 - When extracting from a bug report, please include this header
2024-03-19 09:30:04.443   618-21644 keystore2               keystore2                            W  system/security/keystore2/watchdog/src/lib.rs:124 - and all 2 records below.
2024-03-19 09:30:04.443   618-21644 keystore2               keystore2                            W  system/security/keystore2/watchdog/src/lib.rs:154 - ThreadId(135) IKeystoreSecurityLevel::generateKey Pending: 17.181355395s Overdue 12.181357797s: SecurityLevel r#STRONGBOX
2024-03-19 09:30:04.443   618-21644 keystore2               keystore2                            W  system/security/keystore2/watchdog/src/lib.rs:154 - ThreadId(135) In KeystoreSecurityLevel::generate_key (No attestation): calling generate_key. Pending: 17.181218067s Overdue 12.181218881s: SecurityLevel r#STRONGBOX
2024-03-19 09:30:04.443   618-21644 keystore2               keystore2                            W  system/security/keystore2/watchdog/src/lib.rs:175 - ### Keystore Watchdog report - END ###
2024-03-19 09:30:04.457   622-643   libnos_datagram         citadeld                             D  App 0x00 returning 0x0
2024-03-19 09:30:04.459   620-620   android.ha...ce.citadel and...urity.keymint-service.citadel  I  Null signature certificate requested.
2024-03-19 09:30:04.459   622-1867  libnos_datagram         citadeld                             D  Calling App 0x02 with params 0x0005
2024-03-19 09:30:04.471  1718-1718  BiometricS...reAuthInfo system_server                        D  Package: com.example.app Sensor ID: 1 Modality: 8 Status: 4
2024-03-19 09:30:04.473 21651-21651 Choreographer           com.example.app                      I  Skipped 1483 frames!  The application may be doing too much work on its main thread.
2024-03-19 09:30:04.476  1718-1718  BiometricS...reAuthInfo system_server                        D  Package: com.example.app Sensor ID: 0 Modality: 2 Status: 1
2024-03-19 09:30:04.476  1718-1718  BiometricS...reAuthInfo system_server                        D  getCanAuthenticateInternal Modality: 2 AuthenticatorStatus: 1
2024-03-19 09:30:04.476  1718-1718  BiometricService        system_server                        D  handleAuthenticate: modality(2), status(0), preAuthInfo: BiometricRequested: true, StrengthRequested: 15, CredentialRequested: false, Eligible:{0 }, Ineligible:{ID(1), oemStrength: 4095, updatedStrength: 4095, modality 8, state: 0, cookie: 0:4 }, CredentialAvailable: true,  requestId: 21 promptInfo.isIgnoreEnrollmentState: false
2024-03-19 09:30:04.476  1718-1718  BiometricService        system_server                        D  Creating authSession with authRequest: BiometricRequested: true, StrengthRequested: 15, CredentialRequested: false, Eligible:{0 }, Ineligible:{ID(1), oemStrength: 4095, updatedStrength: 4095, modality 8, state: 0, cookie: 0:4 }, CredentialAvailable: true, 
2024-03-19 09:30:04.476   622-1867  libnos_datagram         citadeld                             D  App 0x02 returning 0x0
2024-03-19 09:30:04.476  1718-1718  BiometricS...uthSession system_server                        D  Creating AuthSession with: BiometricRequested: true, StrengthRequested: 15, CredentialRequested: false, Eligible:{0 }, Ineligible:{ID(1), oemStrength: 4095, updatedStrength: 4095, modality 8, state: 0, cookie: 0:4 }, CredentialAvailable: true, 
2024-03-19 09:30:04.477  1718-1718  BiometricS...uthSession system_server                        V  set to unknown state sensor: 0
2024-03-19 09:30:04.477  1718-1718  BiometricS...uthSession system_server                        V  waiting for cooking for sensor: 0
2024-03-19 09:30:04.477   622-1867  libnos_datagram         citadeld                             D  Calling App 0x02 with params 0x001a
2024-03-19 09:30:04.479  1718-1718  BiometricScheduler      system_server                        D  [Added] {[73] com.android.server.biometrics.sensors.fingerprint.aidl.FingerprintAuthenticationClient, proto=3, owner=com.example.app, cookie=1967369152, requestId=21, userId=0}, new queue size: 1
2024-03-19 09:30:04.479  1718-1718  BiometricScheduler      system_server                        D  [Polled] {[73] com.android.server.biometrics.sensors.fingerprint.aidl.FingerprintAuthenticationClient, proto=3, owner=com.example.app, cookie=1967369152, requestId=21, userId=0}, State: 0
2024-03-19 09:30:04.479  1718-1718  BiometricScheduler      system_server                        D  Waiting for cookie before starting: {[73] com.android.server.biometrics.sensors.fingerprint.aidl.FingerprintAuthenticationClient, proto=3, owner=com.example.app, cookie=1967369152, requestId=21, userId=0}, State: 4
2024-03-19 09:30:04.479  1718-1718  BiometricService/Sensor system_server                        D  Sensor(0) matched cookie: 1967369152
2024-03-19 09:30:04.479  1718-1718  BiometricS...uthSession system_server                        D  Remaining cookies: 0
2024-03-19 09:30:04.481  3252-3252  AuthController          com.android.systemui                 D  showAuthenticationDialog, authenticators: 15, sensorIds: 0 , credentialAllowed: false, requireConfirmation: false, operationId: 813442239040123979, requestId: 21
2024-03-19 09:30:04.481   622-1867  libnos_datagram         citadeld                             D  App 0x02 returning 0x0
2024-03-19 09:30:04.487  3252-3252  AuthController          com.android.systemui                 D  userId: 0 mCurrentDialog: null newDialog: com.android.systemui.biometrics.AuthContainerView{e8c798b VFE...... .F....I. 0,0-0,0}
2024-03-19 09:30:04.488   622-622   libnos_datagram         citadeld                             D  Calling App 0x02 with params 0x001b
2024-03-19 09:30:04.492   634-4212  hwc-display             and...e.composer.hwc3-service.pixel  D  setActiveConfigWithConstraints:: PrimaryDisplay config(37) test(0)
2024-03-19 09:30:04.492   634-4212  hwc-display             and...e.composer.hwc3-service.pixel  I  [PrimaryDisplay] setActiveConfigWithConstraints: config(37)
2024-03-19 09:30:04.501   622-622   libnos_datagram         citadeld                             D  App 0x02 returning 0x0
2024-03-19 09:30:04.502   618-21644 keystore2               keystore2                            W  system/security/keystore2/watchdog/src/lib.rs:114 - ### Keystore Watchdog report - BEGIN ###
2024-03-19 09:30:04.502   618-21644 keystore2               keystore2                            W  system/security/keystore2/watchdog/src/lib.rs:123 - When extracting from a bug report, please include this header
2024-03-19 09:30:04.502   618-21644 keystore2               keystore2                            W  system/security/keystore2/watchdog/src/lib.rs:124 - and all 1 records below.
2024-03-19 09:30:04.502   618-21644 keystore2               keystore2                            W  system/security/keystore2/watchdog/src/lib.rs:154 - ThreadId(135) IKeystoreSecurityLevel::generateKey Pending: 17.239935067s Overdue 12.239937794s: SecurityLevel r#STRONGBOX
2024-03-19 09:30:04.502   618-21644 keystore2               keystore2                            W  system/security/keystore2/watchdog/src/lib.rs:175 - ### Keystore Watchdog report - END ###
2024-03-19 09:30:04.506  3252-3252  AuthDialog...onDetector com.android.systemui                 I  Enable detector
2024-03-19 09:30:04.511 21651-21847 RNKeychainManager       com.example.app                      V  warming up takes: 17303 ms
mrbrentkelly commented 1 month ago

Also experiencing this as well... In Android 14 on physical devices there's a noticeable delay when calling await Keychain.getGenericPassword(); or await Keychain.setGenericPassword().

MAKARD commented 4 weeks ago

+1

yberstad commented 3 weeks ago

We are also experiencing this issue. However, rolling back to version 8.1.2, we encountered the following exception during startup, which version 8.1.3 aims to fix:

StrongBox security storage is not available.
android.security.keystore.StrongBoxUnavailableException: Failed to generated key pair.
    at android.security.keystore2.AndroidKeyStoreKeyPairGeneratorSpi.generateKeyPair(AndroidKeyStoreKeyPairGeneratorSpi.java:662)
    at java.security.KeyPairGenerator$Delegate.generateKeyPair(KeyPairGenerator.java:746)
    at ue.i.r(SourceFile:12)
    at ue.b.F(SourceFile:20)
    at ue.b.E(SourceFile:2)
    at ue.b.s(SourceFile:26)
    at com.oblador.keychain.KeychainModule.internalWarmingBestCipher(SourceFile:48)
    at com.oblador.keychain.KeychainModule.a(SourceFile:1)
    at com.oblador.keychain.b.run(SourceFile:1)
    at java.lang.Thread.run(Thread.java:1012)
Caused by: android.security.KeyStoreException: Requested security level (likely Strongbox) is not available. (internal Keystore
Caused by:
    Error::Km(r#HARDWARE_TYPE_UNAVAILABLE)) (public error code: 12 internal Keystore code: -68)
    at android.security.KeyStore2.getKeyStoreException(KeyStore2.java:435)
    at android.security.KeyStore2.handleRemoteExceptionWithRetry(KeyStore2.java:121)
    at android.security.KeyStore2.getSecurityLevel(KeyStore2.java:284)
    at android.security.keystore2.AndroidKeyStoreKeyPairGeneratorSpi.generateKeyPair(AndroidKeyStoreKeyPairGeneratorSpi.java:649)

It seems that the application still works; we have tested it on a Pixel 7a and a Samsung Galaxy A54.

So, we are faced with a choice between a slow startup or an exception during startup.

Does anyone have any thoughts on which option is better?

c-goettert commented 1 week ago

We are also facing this issue...

c-goettert commented 1 week ago

After some testing I think this PR #577 introduced the performance drop.

yberstad commented 1 week ago

@c-goettert, yes I agree. But as I state in my comment above, rolling back the fix you mentioned we get back the exception StrongBox security storage is not available. I don't know what is the best, live with exception and short startup, or no exception and slow startup.

git-user-1337 commented 1 week ago

@c-goettert @yberstad

As you can read in the comment on the PR, StrongBox seems to have a poorer performance:

Although StrongBox is a little slower and resource constrained (meaning that it supports fewer concurrent operations) compared to TEE, StrongBox provides better security guarantees against physical and side-channel attacks. If you want to prioritize higher security guarantees over app resource efficiency, we recommend using StrongBox on the devices where it is available. Wherever StrongBox isn't available, your app can always fall back to TEE to store key materials.

Since we are talking about ~5 seconds more boot time in our case, we have decided against Strongbox. In the old versions, the wrong key-size prevents the use of strongbox and throws the exception. As there is no option to deactivate strongbox, we have modified the CypherStorageBase.java so that strongbox is not used. Here is a patch-file for the current version 8.2.0, which solves the performance problem for us and does not throw an exception: react-native-keychain+8.2.0.patch

yberstad commented 1 week ago

Thanks for your explanation and patch file, much appreciated @git-user-1337

ArmaanSinghKlair commented 3 days ago

I also applied @git-user-1337 fix and it fixed it for us. Upon launching our app on Pixel phones, the biometric prompt appears promptly. However, successful biometric authentication may take a moment or it failed with the error "java.io.IOException: javax.crypto.IllegalBlockSizeException". The cause was 'Key user not authenticated in Keystore'.

What I'm guessing your code fixed was the time for cold bootup for Keystore. The Keystore cold boot time in some cases went upto 13 seconds and overshot the auth validity duration (5 sec) set in (com.oblador.keychain.cipherStorage.CipherStorageKeystoreRsaEcb.java). Because of this, it always expired our Keystore authorization before biometrics could complete successfully.

The other possible fix would be to increase the validity duration, however the slow app startup would still NOT be fixed and if user were to close and re-open the app fast enough, it wouldn't ask for biometrics and automatically log-in user which also would be undesirable and weird to the user.

It works normally and faster now. Thanks