Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Open
MikeDevBeddo opened this issue Mar 15, 2024 · 17 comments · Fixed by #670
Open

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

MikeDevBeddo opened this issue Mar 15, 2024 · 17 comments · Fixed by #670
Assignees

Comments

@MikeDevBeddo
Copy link

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
Copy link

ieatfood commented Mar 19, 2024

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
Copy link

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
Copy link

MAKARD commented May 30, 2024

+1

@yberstad
Copy link

yberstad commented Jun 7, 2024

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
Copy link

We are also facing this issue...

@c-goettert
Copy link

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

@yberstad
Copy link

@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
Copy link

@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
Copy link

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

@ArmaanSinghKlair
Copy link

ArmaanSinghKlair commented Jun 25, 2024

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

@bonnmh
Copy link

bonnmh commented Jul 9, 2024

keystore2::error: In get_security_level: No such security level.
                                                                                                    
                                                                                                    Caused by:
                                                                                                        Error::Km(ErrorCode(-68))
2024-07-09 17:29:33.395  7187-7281  c                       pid-7187                             W  StrongBox security storage is not available.
                                                                                                    android.security.keystore.StrongBoxUnavailableException: Failed to generate key
                                                                                                    	at android.security.keystore2.AndroidKeyStoreKeyGeneratorSpi.engineGenerateKey(AndroidKeyStoreKeyGeneratorSpi.java:411)
                                                                                                    	at javax.crypto.KeyGenerator.generateKey(KeyGenerator.java:612)
                                                                                                    	at mh.i.r(CipherStorageKeystoreAesCbc.java:14)
                                                                                                    	at mh.c.F(CipherStorageBase.java:20)
                                                                                                    	at mh.c.E(CipherStorageBase.java:2)
                                                                                                    	at mh.c.s(CipherStorageBase.java:27)
                                                                                                    	at com.oblador.keychain.KeychainModule.internalWarmingBestCipher(KeychainModule.java:49)
                                                                                                    	at com.oblador.keychain.KeychainModule.a(KeychainModule.java:1)
                                                                                                    	at com.oblador.keychain.b.run(R8$$SyntheticClass:3)
                                                                                                    	at java.lang.Thread.run(Thread.java:1012)
                                                                                                    Caused by: android.security.KeyStoreException: No StrongBox available (public error code: 12 internal Keystore code: -68)

I had this problem, everything worked fine 2 weeks ago, I'm trying to figure out what went wrong
react-native: 0.72.4
react-native-keychain: 8.1.3

@laurens-lamberts
Copy link

We also experience the issue. Took us quite a long time to track it down.
Rolling back to 8.1.2 for now. Hope a fix will come along soon.
Maybe it's a good idea to deprecate the latest two versions so that new installers won't face this ambiguous issue.

@pwltr
Copy link

pwltr commented Oct 21, 2024

Hi, can anyone of you that rolled back (disabled StrongBox) using @git-user-1337 's patch confirm that it is safe to do so for production apps? If a user has saved to keychain using StrongBox will the value still be accessible using TEE after the patch?

@DorianMazur
Copy link
Collaborator

@pwltr I will fix this issue soon and release the official version. I'm working on it ;)

@pwltr
Copy link

pwltr commented Oct 21, 2024

Awesome, thanks @DorianMazur !

@Brma1048
Copy link

@DorianMazur issue still exists with 9.1.0 setGenericPassword takes 9.5 sek on my pixel 7 (Android 14) and in version 8.1.2 it took only 2,4 sek.
RN Version: 0.75.4

@DorianMazur
Copy link
Collaborator

DorianMazur commented Nov 4, 2024

@Brma1048
The issue is caused by StrongBox, which runs very slowly on Android devices that support StrongBox Keymaster. I just got a Pixel device to look into this problem more closely :D I'll do my best to figure out the main cause. In the worst case, I'll add an option to disable StrongBox. If you're using version 8.1.2, things are faster because StrongBox is NOT working in that version.

@DorianMazur DorianMazur reopened this Nov 4, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.