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

AWSMobileClient getTokens is slow to return cached tokens #1722

Closed
michatch opened this issue May 11, 2020 · 32 comments
Closed

AWSMobileClient getTokens is slow to return cached tokens #1722

michatch opened this issue May 11, 2020 · 32 comments
Labels
mobile client Issues with AWS Mobile's client-side Cognito wrapper

Comments

@michatch
Copy link

michatch commented May 11, 2020

Describe the bug
When calling AWSMobileClient.getInstance().getTokens() On an initilized AWSMobileClient with a signed in user, it takes about 500ms to return the token.
I'm using this call to retrieve the JWT token with AWSMobileClient.getInstance().getTokens().getIdToken().getTokenString() to be able to make an authenticated API call. This adds already a lot of time to have an API response.
Is there a better way to retrieve the token?

To Reproduce

Using following dependencies:

  • com.amazonaws:aws-android-sdk-mobile-client:2.16.12
  • com.amazonaws:aws-android-sdk-cognitoauth:2.16.12@aar) { transitive = true }

Steps:

  • AWSMobileClient.getInstance().initialize()
  • AWSMobileClient.getInstance().signIn()
  • AWSMobileClient.getInstance().getTokens()

Which AWS service(s) are affected?
AWS Cognito
Android SDK 2.16.12

Environment Information (please complete the following information):

  • AWS Android SDK Version: 2.16.12
  • Device: Samsung Galaxy Tab A
  • Android Version: 9
  • Specific to simulators: No

Logs
Log start when call to getTokens() is made.
Log ends when token was received.

2020-05-11 14:44:27.172 15474-15671/com.example.aws D/KeyProvider23: AndroidKeyStore contains keyAlias com.amazonaws.mobile.client.aesKeyStoreAlias
2020-05-11 14:44:27.172 15474-15671/com.example.aws D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-05-11 14:44:27.183 15474-15474/com.example.aws D/InputTransport: Input channel constructed: fd=92
2020-05-11 14:44:27.183 15474-15474/com.example.aws D/InputTransport: Input channel destroyed: fd=94
2020-05-11 14:44:27.200 15474-15671/com.example.aws D/KeyProvider23: AndroidKeyStore contains keyAlias com.amazonaws.mobile.client.aesKeyStoreAlias
2020-05-11 14:44:27.200 15474-15671/com.example.aws D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-05-11 14:44:27.225 15474-15474/com.example.aws E/ViewRootImpl: sendUserActionEvent() returned.
2020-05-11 14:44:27.229 15474-15671/com.example.aws D/KeyProvider23: AndroidKeyStore contains keyAlias com.amazonaws.mobile.client.aesKeyStoreAlias
2020-05-11 14:44:27.229 15474-15671/com.example.aws D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-05-11 14:44:27.257 15474-15671/com.example.aws D/KeyProvider23: AndroidKeyStore contains keyAlias com.amazonaws.mobile.client.aesKeyStoreAlias
2020-05-11 14:44:27.257 15474-15671/com.example.aws D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-05-11 14:44:27.280 15474-15671/com.example.aws D/KeyProvider23: AndroidKeyStore contains keyAlias com.amazonaws.mobile.client.aesKeyStoreAlias
2020-05-11 14:44:27.280 15474-15671/com.example.aws D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-05-11 14:44:27.307 15474-15671/com.example.aws D/KeyProvider23: AndroidKeyStore contains keyAlias com.amazonaws.mobile.client.aesKeyStoreAlias
2020-05-11 14:44:27.307 15474-15671/com.example.aws D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-05-11 14:44:27.328 15474-15671/com.example.aws D/AWSMobileClient: Inspecting user state details
2020-05-11 14:44:27.335 15474-15671/com.example.aws D/KeyProvider23: AndroidKeyStore contains keyAlias com.amazonaws.mobile.client.aesKeyStoreAlias
2020-05-11 14:44:27.335 15474-15671/com.example.aws D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-05-11 14:44:27.360 15474-15671/com.example.aws D/KeyProvider23: AndroidKeyStore contains keyAlias com.amazonaws.mobile.client.aesKeyStoreAlias
2020-05-11 14:44:27.360 15474-15671/com.example.aws D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-05-11 14:44:27.384 15474-15671/com.example.aws D/KeyProvider23: AndroidKeyStore contains keyAlias com.amazonaws.mobile.client.aesKeyStoreAlias
2020-05-11 14:44:27.384 15474-15671/com.example.aws D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-05-11 14:44:27.407 15474-15671/com.example.aws D/KeyProvider23: AndroidKeyStore contains keyAlias com.amazonaws.mobile.client.aesKeyStoreAlias
2020-05-11 14:44:27.407 15474-15671/com.example.aws D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-05-11 14:44:27.414 15474-15671/com.example.aws D/KeyProvider23: AndroidKeyStore contains keyAlias com.amazonaws.mobile.client.aesKeyStoreAlias
2020-05-11 14:44:27.414 15474-15671/com.example.aws D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-05-11 14:44:27.422 15474-15671/com.example.aws D/KeyProvider23: AndroidKeyStore contains keyAlias CognitoIdentityProviderCache.aesKeyStoreAlias
2020-05-11 14:44:27.422 15474-15671/com.example.aws D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-05-11 14:44:27.445 15474-15671/com.example.aws D/KeyProvider23: AndroidKeyStore contains keyAlias CognitoIdentityProviderCache.aesKeyStoreAlias
2020-05-11 14:44:27.445 15474-15671/com.example.aws D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-05-11 14:44:27.471 15474-15671/com.example.aws D/KeyProvider23: AndroidKeyStore contains keyAlias CognitoIdentityProviderCache.aesKeyStoreAlias
2020-05-11 14:44:27.471 15474-15671/com.example.aws D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-05-11 14:44:27.492 15474-15671/com.example.aws D/KeyProvider23: AndroidKeyStore contains keyAlias CognitoIdentityProviderCache.aesKeyStoreAlias
2020-05-11 14:44:27.492 15474-15671/com.example.aws D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-05-11 14:44:27.515 15474-15671/com.example.aws D/AWSMobileClient: hasFederatedToken: true provider: cognito-idp.eu-west-1.amazonaws.com/eu-west-1_p*******
2020-05-11 14:44:27.516 15474-15671/com.example.aws D/AWSMobileClient: waitForSignIn: userState:SIGNED_IN
2020-05-11 14:44:27.518 15474-15671/com.example.aws D/KeyProvider23: AndroidKeyStore contains keyAlias com.amazonaws.mobile.client.aesKeyStoreAlias
2020-05-11 14:44:27.519 15474-15671/com.example.aws D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-05-11 14:44:27.541 15474-15671/com.example.aws D/KeyProvider23: AndroidKeyStore contains keyAlias com.amazonaws.mobile.client.aesKeyStoreAlias
2020-05-11 14:44:27.541 15474-15671/com.example.aws D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-05-11 14:44:27.548 15474-15671/com.example.aws D/KeyProvider23: AndroidKeyStore contains keyAlias com.amazonaws.mobile.client.aesKeyStoreAlias
2020-05-11 14:44:27.548 15474-15671/com.example.aws D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-05-11 14:44:27.556 15474-15671/com.example.aws D/KeyProvider23: AndroidKeyStore contains keyAlias CognitoIdentityProviderCache.aesKeyStoreAlias
2020-05-11 14:44:27.556 15474-15671/com.example.aws D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-05-11 14:44:27.578 15474-15671/com.example.aws D/KeyProvider23: AndroidKeyStore contains keyAlias CognitoIdentityProviderCache.aesKeyStoreAlias
2020-05-11 14:44:27.578 15474-15671/com.example.aws D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-05-11 14:44:27.601 15474-15671/com.example.aws D/KeyProvider23: AndroidKeyStore contains keyAlias CognitoIdentityProviderCache.aesKeyStoreAlias
2020-05-11 14:44:27.601 15474-15671/com.example.aws D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-05-11 14:44:27.624 15474-15671/com.example.aws D/KeyProvider23: AndroidKeyStore contains keyAlias CognitoIdentityProviderCache.aesKeyStoreAlias
2020-05-11 14:44:27.624 15474-15671/com.example.aws D/KeyProvider23: Loading the encryption key from Android KeyStore.
@patrickkempff
Copy link

patrickkempff commented May 18, 2020

We have the same issue with receiving the cached AccessToken. On a Samsung s9 it can take sometimes around 1000ms. Calling currentUserState() takes more than 300ms. A isSignedIn call also takes between 50 and 500ms, which also feels quite long.

We are using the latest version of the SDK, but also had the same issues with the previous versions of the SDK.

@CameliaTripon
Copy link

CameliaTripon commented May 19, 2020

Same for us. We did some kind of local caching for the token using somehow the same rule as in the SDK. The first time we call getTokens, we save the token in our in-memory cache (together with the validity date). Next time we want the token, we are asking the local cache if it has a valid token (with 55 mins default validity). If we have a valid token, we return it from our cache (takes about 1 ms), otherwise we ask the SDK (which of course can take longer since the token is expired and they need to make a request).

It's not ideal but is better then waiting for about 500ms for each request since the token is cached in their SDK anyway

@desokroshan desokroshan added the mobile client Issues with AWS Mobile's client-side Cognito wrapper label May 29, 2020
@tyjaon
Copy link

tyjaon commented Jun 3, 2020

@CameliaTripon but still it should be optimized on the AWSMobileClient side, because on some older phones like my samsung s8 + i don't know why is taking around 1s also I don't know about you guys but sometimes retrieving fresh new token is taking about 10s.

I have implemented similar solution to refresh token with tokenRefreshWorker that use AwsMobileClient.getInstance().getTokens().getIdToken().getTokenString() and save it to my app preferences. My first approach was to run a job every 45-55 min, because token is valid only for 1 hour, but the problem was when I was calling AwsMobIleClient before token have expired I was receiving old token. So I have change my approach to increase time gap between token refresh job to 1 h 1-60s. Most time it's working fine, but still sometimes you can enter gap when there is no token refreshed and you have to wait until it would be fetched.

@Dachmian
Copy link

Dachmian commented Jun 17, 2020

We are also experiencing this issue.
It is really a big issue for us that this process can take up to 10s.

@tyjaon
Copy link

tyjaon commented Jul 3, 2020

So guys from AWS could you comment it ? or respond to it? It's 2 months since the ticket was posted. The proposed solution above it's not the solution only a bypass.

@patrickkempff
Copy link

Communication from the AWS team is really poor, there are multiple issues which affect a large user base but those tickets are just ignored it seems. Not a really good motivation to work with these services from a developer perspective...

@TrekSoft
Copy link
Contributor

TrekSoft commented Aug 3, 2020

Sorry for the delay on this - looks like this is recently impacting a significant number of users so we'll be prioritizing it here.

For those experiencing this issue can you post:

  • the version of Android you are experiencing it on
  • the version of the AWS SDK
  • the sign in method you are using (HostedUI, Federated, or normal)

@tyjaon
Copy link

tyjaon commented Aug 4, 2020

ok so i'm experiencing it on:

  • Samsung Galaxy s8 + Android 9.0
  • build tools version 29.0.2, SDK 29
  • login method HostedUI for Facebook/Google and normal for user registered via email (situations looks the same in the booth mentioned methods)

@TrekSoft
Copy link
Contributor

TrekSoft commented Aug 4, 2020

Thanks - sorry I wasn't clear - by version of SDK I meant the version of the AWS SDK you're using. What you gave is useful too.

@TrekSoft
Copy link
Contributor

TrekSoft commented Aug 5, 2020

Also @tyjaon I tried replicating it with those same parameters in the emulator and was getting response times in less than 300ms for fresh and less than 200ms cached with the latest SDK. Does that happen for you on the emulator or only on the device? Also could you post the specific steps to replicate the latency you're seeing?

@tyjaon
Copy link

tyjaon commented Aug 6, 2020

@TrekSoft I didn't tried It on emulator. It have happened on couple of different devices.
Cached Token:
I was just calling the method mentioned below on initialized AWSMobileClient and user signed in via HostedUI via facebook. But in cached token probably sign in method shouldn’t matter.
AWSMobileClient.getInstance().getTokens().getIdToken();
I have tried couple times calling it and for cached tokens It's takes at least 500ms or more. Here are the logs (from samsung galaxy s8+ mentioned by me above) .

2020-08-06 15:58:40.306 16585-17163/app.betify.betify D/KeyProvider23: AndroidKeyStore contains keyAlias com.amazonaws.mobile.client.aesKeyStoreAlias
2020-08-06 15:58:40.306 16585-17163/app.betify.betify D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-08-06 15:58:40.341 16585-17163/app.betify.betify D/KeyProvider23: AndroidKeyStore contains keyAlias com.amazonaws.mobile.client.aesKeyStoreAlias
2020-08-06 15:58:40.341 16585-17163/app.betify.betify D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-08-06 15:58:40.361 16585-17163/app.betify.betify D/KeyProvider23: AndroidKeyStore contains keyAlias com.amazonaws.mobile.client.aesKeyStoreAlias
2020-08-06 15:58:40.361 16585-17163/app.betify.betify D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-08-06 15:58:40.385 16585-17163/app.betify.betify D/KeyProvider23: AndroidKeyStore contains keyAlias com.amazonaws.mobile.client.aesKeyStoreAlias
2020-08-06 15:58:40.385 16585-17163/app.betify.betify D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-08-06 15:58:40.411 16585-17163/app.betify.betify D/KeyProvider23: AndroidKeyStore contains keyAlias com.amazonaws.mobile.client.aesKeyStoreAlias
2020-08-06 15:58:40.411 16585-17163/app.betify.betify D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-08-06 15:58:40.436 16585-17163/app.betify.betify D/KeyProvider23: AndroidKeyStore contains keyAlias com.amazonaws.mobile.client.aesKeyStoreAlias
2020-08-06 15:58:40.436 16585-17163/app.betify.betify D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-08-06 15:58:40.457 16585-17163/app.betify.betify D/AWSMobileClient: Inspecting user state details
2020-08-06 15:58:40.463 16585-17163/app.betify.betify D/KeyProvider23: AndroidKeyStore contains keyAlias com.amazonaws.mobile.client.aesKeyStoreAlias
2020-08-06 15:58:40.463 16585-17163/app.betify.betify D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-08-06 15:58:40.488 16585-17163/app.betify.betify D/KeyProvider23: AndroidKeyStore contains keyAlias com.amazonaws.mobile.client.aesKeyStoreAlias
2020-08-06 15:58:40.488 16585-17163/app.betify.betify D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-08-06 15:58:40.511 16585-17163/app.betify.betify D/KeyProvider23: AndroidKeyStore contains keyAlias com.amazonaws.mobile.client.aesKeyStoreAlias
2020-08-06 15:58:40.511 16585-17163/app.betify.betify D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-08-06 15:58:40.535 16585-17163/app.betify.betify D/KeyProvider23: AndroidKeyStore contains keyAlias com.amazonaws.mobile.client.aesKeyStoreAlias
2020-08-06 15:58:40.535 16585-17163/app.betify.betify D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-08-06 15:58:40.561 16585-17163/app.betify.betify D/KeyProvider23: AndroidKeyStore contains keyAlias CognitoIdentityProviderCache.aesKeyStoreAlias
2020-08-06 15:58:40.561 16585-17163/app.betify.betify D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-08-06 15:58:40.591 16585-17163/app.betify.betify D/KeyProvider23: AndroidKeyStore contains keyAlias CognitoIdentityProviderCache.aesKeyStoreAlias
2020-08-06 15:58:40.591 16585-17163/app.betify.betify D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-08-06 15:58:40.616 16585-17163/app.betify.betify D/KeyProvider23: AndroidKeyStore contains keyAlias CognitoIdentityProviderCache.aesKeyStoreAlias
2020-08-06 15:58:40.616 16585-17163/app.betify.betify D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-08-06 15:58:40.640 16585-17163/app.betify.betify D/KeyProvider23: AndroidKeyStore contains keyAlias CognitoIdentityProviderCache.aesKeyStoreAlias
2020-08-06 15:58:40.640 16585-17163/app.betify.betify D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-08-06 15:58:40.664 16585-17163/app.betify.betify D/KeyProvider23: AndroidKeyStore contains keyAlias CognitoIdentityProviderCache.aesKeyStoreAlias
2020-08-06 15:58:40.664 16585-17163/app.betify.betify D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-08-06 15:58:40.689 16585-17163/app.betify.betify D/AWSMobileClient: hasFederatedToken: true provider: cognito-idp.eu-west-1.amazonaws.com/eu-west-1_8At4CGQbx
2020-08-06 15:58:40.689 16585-17163/app.betify.betify D/AWSMobileClient: waitForSignIn: userState:SIGNED_IN
2020-08-06 15:58:40.691 16585-17163/app.betify.betify D/KeyProvider23: AndroidKeyStore contains keyAlias com.amazonaws.mobile.client.aesKeyStoreAlias
2020-08-06 15:58:40.691 16585-17163/app.betify.betify D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-08-06 15:58:40.715 16585-17163/app.betify.betify D/KeyProvider23: AndroidKeyStore contains keyAlias com.amazonaws.mobile.client.aesKeyStoreAlias
2020-08-06 15:58:40.715 16585-17163/app.betify.betify D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-08-06 15:58:40.736 16585-17163/app.betify.betify D/KeyProvider23: AndroidKeyStore contains keyAlias CognitoIdentityProviderCache.aesKeyStoreAlias
2020-08-06 15:58:40.736 16585-17163/app.betify.betify D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-08-06 15:58:40.762 16585-17163/app.betify.betify D/KeyProvider23: AndroidKeyStore contains keyAlias CognitoIdentityProviderCache.aesKeyStoreAlias
2020-08-06 15:58:40.762 16585-17163/app.betify.betify D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-08-06 15:58:40.800 16585-17163/app.betify.betify D/KeyProvider23: AndroidKeyStore contains keyAlias CognitoIdentityProviderCache.aesKeyStoreAlias
2020-08-06 15:58:40.800 16585-17163/app.betify.betify D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-08-06 15:58:40.842 16585-17163/app.betify.betify D/KeyProvider23: AndroidKeyStore contains keyAlias CognitoIdentityProviderCache.aesKeyStoreAlias
2020-08-06 15:58:40.843 16585-17163/app.betify.betify D/KeyProvider23: Loading the encryption key from Android KeyStore.
2020-08-06 15:58:40.875 16585-17163/app.betify.betify D/KeyProvider23: AndroidKeyStore contains keyAlias CognitoIdentityProviderCache.aesKeyStoreAlias
2020-08-06 15:58:40.875 16585-17163/app.betify.betify D/KeyProvider23: Loading the encryption key from Android KeyStore.
.txt

For refresh I will provide you logs and statistics on the weekend

@TrekSoft
Copy link
Contributor

TrekSoft commented Aug 6, 2020

Ok and what version of our SDK are you using? Also was that the same command you were calling to get the fresh token that took 10 seconds?

@tyjaon
Copy link

tyjaon commented Aug 6, 2020

2.16.6 , I'm using exactly the same command :

AWSMobileClient.getInstance().getTokens().getIdToken();

@TrekSoft
Copy link
Contributor

TrekSoft commented Aug 6, 2020

Just to make sure it isn't something we've already fixed could you try it on the latest version 2.17.0? If it is device dependent it'll take me a bit to get an old device to replicate it on so want to eliminate any obvious possibilities first.

@tyjaon
Copy link

tyjaon commented Aug 9, 2020

@TrekSoft I have upgraded lib version to the latest version 2.17.0 and I gave it to couple people to test it in order to check if it there is any improvements. The speed of retrieving new token didn't improve at all (when I personally have checked couple times it was 4s 5s 12s, my friends have obtained similar results ), but I must say that probably the situation with the retrieving cached token has partially improved from (500 ms + ) to around 100-400, but still if this operation is based on reading from cache and decryption it should be faster.

@TrekSoft
Copy link
Contributor

100-400ms sounds about right - it's retrieving it from device storage so it's not going to be instantaneous. The concern is the multiple seconds taken to retrieve new tokens. What type of internet connection were you on when you were seeing these times?

@tyjaon
Copy link

tyjaon commented Aug 11, 2020

4G +(LTE) with almost full signal. Everything after and before this initial token generating connection is running smoothly with normal pings to the server. If you want I can check also on WiFi connection.

@TrekSoft
Copy link
Contributor

That's fine - thanks. If I could get input from other users here especially if anyone is getting this with a more modern device that would be great so I can replicate it.

@reku47
Copy link

reku47 commented Aug 11, 2020

i have similar times like @tyjaon

  • Oneplus 7t pro (android 10)
  • build tools version 29.0.3, SDK 30
  • normal for user registered via email (situations looks the same in the booth mentioned methods)
  • aws-mobile-client 2.17.0
  • I have tested it on mobile network with 4G+ with good signal (the other request after token refresh are going without any hude delay, so I think that it's not a network related problem, but in same cases could stack some small additional delay)

@shivaanshi
Copy link

Hi, I am also facing same issue, fetching id token from session taking longer than usual, it's taking more than 10 seconds.
Device specification -
Honor Play, android 9

@TrekSoft
Copy link
Contributor

Thanks @reku47 - @shivaanshi could you please fill out the requested information?

  • the version of Android you are experiencing it on
  • the version of the AWS SDK
  • the sign in method you are using (HostedUI, Federated, or normal)

@tyjaon
Copy link

tyjaon commented Aug 12, 2020

@TrekSoft btw also 100ms-400 ms reading from internal storage is huge waste of time I don't know exactly what you guys are doing there but normally on the shared preferences with some encryption you should waste max 10-20ms, maybe max 100ms on older phones (by older I mean phones from the really low price range like 100-200$, that are 2-4 years old).

@shivaanshi
Copy link

@TrekSoft Android version is 9
'com.amplifyframework:core:1.0.0'
'com.amplifyframework:aws-auth-cognito:1.0.0'
Federate

@WillBarden
Copy link

@TrekSoft Also ran into the issue. It seems that AWSKeyValueStore is only caching the tokens when persistence is disabled. However, if internal storage takes this long to read, always checking the cache could result in a large performance increase. Perhaps line 204 and 181 of the AWSKeyValueStore class could be modified to be
if (cache.contains(dataKey) || !isPersistenceEnabled) { return cache.get(dataKey); }

@TrekSoft
Copy link
Contributor

Thanks for that tip @WillBarden - it does seem like attempting to black box replicate this is not the answer so once I wrap up my other task for this sprint, I'll dig into the code there and see if some obvious improvements like that can be made.

Also thanks @shivaanshi and @tyjaon for the additional input.

@tomrapadmi
Copy link

One thing that I've noticed is that the _getTokens Runnable calls getCurrentUser which always returns a new instance of a CognitoUser, meaning that its memory cache of private CognitoUserSession cipSession; is always null when checked in getCachedSession line 961.

@TrekSoft
Copy link
Contributor

TrekSoft commented Aug 14, 2020

Btw @WillBarden I just checked into your proposal here and it makes a ton of sense so I've already added that to my fix and will see what other improvements can be made along with it.

Also, I'm now replicating the issue myself with lag time of up to 1 second getting cached tokens which I agree is unacceptable so digging into what's going on.

One thing I've noticed is that if you call getTokens() twice in a row, the second time completes in under 200ms. This obviously isn't a helpful workaround but it will help in the investigation.

@TrekSoft
Copy link
Contributor

TrekSoft commented Aug 14, 2020

Alright, I found the root cause - it's the waitForSignIn() method calling getUserStateDetails() with offlineCheck set to false: https://github.com/aws-amplify/aws-sdk-android/blob/main/aws-android-sdk-mobile-client/src/main/java/com/amazonaws/mobile/client/AWSMobileClient.java#L923

Actual key store retrieval is lightning fast as we'd expect but because we first check that method, it adds hundreds of milliseconds of latency to the getTokens calls. Will keep this ticket updated as I address this.

@TrekSoft
Copy link
Contributor

TrekSoft commented Aug 17, 2020

Turns out there was a very simple fix to the lag time for the cached tokens - the code was always enabling a waitForSignIn block so that if you happened to call getTokens while it was in the middle of signing in it would wait until the sign in process completed. This check was written very badly and included a network call leading to the lag time. So I disabled this waitForSignIn block and it will throw an error if getTokens is attempted to be called while you were signed out (regardless of whether you are in the middle of signing in or not).

This lowered latency for me retrieving cached tokens from 900ms+ to 77ms.

It's getting released today and once it's out, would appreciate if those of you experiencing long latencies with getting a fresh, non-cached token could try it as well and see if this has resolved that issue as a side effect or if you're still having it.

@tyjaon
Copy link

tyjaon commented Aug 17, 2020

@TrekSoft Nice improvement :) When it will be available i will try it.

@tyjaon
Copy link

tyjaon commented Aug 19, 2020

@TrekSoft I have checked the situation with cached token has improved, now the retrieving time is unnoticeable from the user perspective, but the request for fresh token are still too long I have tested it couple times on different devices and It took 5s, 8s , 9s, 10s.

@TrekSoft
Copy link
Contributor

Alright, thanks - given the original issue here is about cached tokens, I'll close this issue and if you don't mind creating a new issue with the steps to reproduce, that'd be great and I'll look into that. For everyone else's information, upgrade to 2.18.0 to resolve the issue with retrieving cached tokens taking too long.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
mobile client Issues with AWS Mobile's client-side Cognito wrapper
Projects
None yet
Development

No branches or pull requests