Amplify-js: Auth: Delay of Hub events using federatedSignIn (part 2)

[tinymarsracing]

My original issue #3214 has been closed, but I believe the problem has not been fixed by the linked PR. I cannot re-open my old issue, so I open this new issue. If it is based on a misunderstanding on my side, I would appreciate an explanation in the original issue.

[bhill9270]

It looks like version 1.1.36 of aws-amplify. But the fix is only for React it appears. I'm getting the same error situation in Angular.

[jordanranz]

Hey @tinymarsracing, sorry that the PR did not fix your issue. Can you post which version of aws-amplify-react you are using for a bit more context?

[bhill9270]

For anyone else out there having this issue, my workaround is testing the localstorage for the right tokens before initializing the Auth.currentAuthenticatedUser() method.

[ErickMwazonga]

My original issue #3214 has been closed, but I believe the problem has not been fixed by the linked PR. I cannot re-open my old issue, so I open this new issue. If it is based on a misunderstanding on my side, I would appreciate an explanation in the original issue.

++

[bhill9270]

I've implemented this timeout loop to wait for the token to populate:

private getAuthToken() { let i = 0; setTimeout(() => { const ampToken = localStorage.getItem('amplify-signin-with-hostedUI'); if (!ampToken) { i++ this.getAuthToken(); } return ampToken; }, 50); }

Then pass that boolean value to whatever functions need it. Would really like to see this resolved within Amplify though.

[ericclemmons]

I was able to reproduce this when going through the following flow:

1. Visit http://localhost:3000/ unauthenticated.
2. Enable debugging: window.LOG_LEVEL = 'DEBUG';. (I also added debugging to a custom useAuth hook I have).
3. "Sign in", which redirects to the federated hosted UI.
4. Get redirected back to http://localhost:3000/?code=....
5. URL gets replaced with http://localhost:3000/

When redirected back to http://localhost:3000/, I captured the following logs:

The development server has disconnected.
Refresh the page if necessary. webpackHotDevClient.js:65
[DEBUG] 36:34.304 Amplify - amplify config 
Object { ...SNIP... }
ConsoleLogger.js:111
[DEBUG] 36:34.320 I18n - configure I18n ConsoleLogger.js:101
[DEBUG] 36:34.321 I18n - create I18n instance ConsoleLogger.js:101
[DEBUG] 36:34.321 I18n - en-US ConsoleLogger.js:101
[DEBUG] 36:34.321 AnalyticsClass - configure Analytics 
Object { ...SNIP... }
ConsoleLogger.js:111
[DEBUG] 36:34.324 Parser - parse config 
Array(3) [ {…}, "to amplifyconfig", {…} ]
ConsoleLogger.js:111
[DEBUG] 36:34.326 AWSPinpointProvider - configure Analytics 
Object { ...SNIP... }
ConsoleLogger.js:111
[DEBUG] 36:34.327 Hub - Dispatching to analytics with  
Object { event: "configured", data: null, message: "The Analytics category has been configured successfully" }
ConsoleLogger.js:111
[DEBUG] 36:34.327 Analytics - on hub capsule analytics 
Object { event: "configured", data: null, message: "The Analytics category has been configured successfully" }
ConsoleLogger.js:111
[DEBUG] 36:34.329 AnalyticsClass - current configuration 
Object { ...SNIP... }
ConsoleLogger.js:111
[DEBUG] 36:34.330 AuthClass - configure Auth ConsoleLogger.js:101
[DEBUG] 36:34.331 Parser - parse config 
Array(3) [ {…}, "to amplifyconfig", {…} ]
ConsoleLogger.js:111
[DEBUG] 36:34.332 Hub - Dispatching to auth with  
Object { event: "parsingCallbackUrl", data: {…}, message: "The callback url is being parsed" }
ConsoleLogger.js:111
[DEBUG] 36:34.333 Analytics - on hub capsule auth 
Object { event: "parsingCallbackUrl", data: {…}, message: "The callback url is being parsed" }
ConsoleLogger.js:111
[DEBUG] 36:34.333 Hub - Dispatching to auth with  
Object { event: "parsingCallbackUrl", data: {…}, message: "The callback url is being parsed" }
ConsoleLogger.js:111
[DEBUG] 36:34.336 OAuth - Starting code flow with http://localhost:3000/?code=SNIP&state=SNIP ConsoleLogger.js:101
[DEBUG] 36:34.336 Hub - Dispatching to auth with  
Object { event: "codeFlow", data: {}, message: "Retrieving tokens from https://SNIP.auth.us-east-1.amazoncognito.com/oauth2/token" }
ConsoleLogger.js:111
[DEBUG] 36:34.337 Analytics - on hub capsule auth 
Object { event: "codeFlow", data: {}, message: "Retrieving tokens from https://SNIP.auth.us-east-1.amazoncognito.com/oauth2/token" }
ConsoleLogger.js:111
[DEBUG] 36:34.338 Hub - Dispatching to auth with  
Object { event: "codeFlow", data: {}, message: "Retrieving tokens from https://SNIP.auth.us-east-1.amazoncognito.com/oauth2/token" }
ConsoleLogger.js:111
[DEBUG] 36:34.339 OAuth - Calling token endpoint: https://SNIP.auth.us-east-1.amazoncognito.com/oauth2/token with 
Object { ...SNIP... }
ConsoleLogger.js:111
[DEBUG] 36:34.339 Hub - Dispatching to auth with  
Object { event: "configured", data: null, message: "The Auth category has been configured successfully" }
ConsoleLogger.js:111
[DEBUG] 36:34.340 Analytics - on hub capsule auth 
Object { event: "configured", data: null, message: "The Auth category has been configured successfully" }
ConsoleLogger.js:111
[DEBUG] 36:34.341 Hub - Dispatching to auth with  
Object { event: "configured", data: null, message: "The Auth category has been configured successfully" }
ConsoleLogger.js:111
[DEBUG] 36:34.341 Storage - storage configure called ConsoleLogger.js:101
[DEBUG] 36:34.341 StorageClass - configure Storage ConsoleLogger.js:101
[DEBUG] 36:34.342 Parser - parse config 
Array(3) [ {…}, "to amplifyconfig", {…} ]
ConsoleLogger.js:111
[DEBUG] 36:34.343 AWSS3Provider - Storage Options 
Object {  }
ConsoleLogger.js:111
[DEBUG] 36:34.343 AWSS3Provider - configure Storage 
Object { bucket: "SNIP", region: "us-east-1", dangerouslyConnectToHttpEndpointForTesting: undefined }
ConsoleLogger.js:111
[DEBUG] 36:34.343 Parser - parse config 
Array(3) [ {…}, "to amplifyconfig", {…} ]
ConsoleLogger.js:111
[DEBUG] 36:34.344 Storage - storage vault configure called ConsoleLogger.js:101
[DEBUG] 36:34.344 StorageClass - configure Storage ConsoleLogger.js:101
[DEBUG] 36:34.344 Parser - parse config 
Array(3) [ {…}, "to amplifyconfig", {…} ]
ConsoleLogger.js:111
[DEBUG] 36:34.345 AWSS3Provider - Storage Options 
Object {  }
ConsoleLogger.js:111
[DEBUG] 36:34.346 AWSS3Provider - configure Storage 
Object { bucket: "SNIP", region: "us-east-1", dangerouslyConnectToHttpEndpointForTesting: undefined, level: "private" }
ConsoleLogger.js:111
[DEBUG] 36:34.347 Parser - parse config 
Array(3) [ {…}, "to amplifyconfig", {…} ]
ConsoleLogger.js:111
[DEBUG] 36:34.348 API - configure API 
Object { opt: {…} }
ConsoleLogger.js:111
[DEBUG] 36:34.348 API - create API instance ConsoleLogger.js:101
[DEBUG] 36:34.349 RestClient - API Options 
Object { ...SNIP... }
ConsoleLogger.js:111
[DEBUG] 36:34.350 PubSub - configure PubSub 
Object { opt: {…} }
ConsoleLogger.js:111
[DEBUG] 36:34.351 Interactions - configure Interactions 
Object { opt: {…} }
ConsoleLogger.js:111
[DEBUG] 36:34.351 XR - configure XR 
Object { opt: {…} }
ConsoleLogger.js:111
[DEBUG] 36:34.352 AbstractXRProvider - configure SumerianProvider 
Object { ...SNIP... }
ConsoleLogger.js:111
[DEBUG] 36:34.352 Predictions - configure Predictions 
Object { identify: {…}, aws_project_region: "us-east-1", aws_cognito_identity_pool_id: "us-east-1:SNIP", aws_cognito_region: "us-east-1", aws_user_pools_id: "us-east-1_H7VKUsI03", aws_user_pools_web_client_id: "SNIP", oauth: {…}, federationTarget: "COGNITO_USER_POOLS", aws_appsync_graphqlEndpoint: "https://SNIP.appsync-api.us-east-1.amazonaws.com/graphql", aws_appsync_region: "us-east-1", … }
ConsoleLogger.js:111
[DEBUG] 36:34.354 Predictions - No plugin found with providerName=> AmazonAIPredictionsProvider ConsoleLogger.js:111
[DEBUG] 36:34.354 Amplify - configure AbstractPredictionsProvider 
Object { config: undefined }
ConsoleLogger.js:111
[DEBUG] 36:34.355 Amplify - configure AbstractPredictionsProvider 
Object { config: {…} }
ConsoleLogger.js:111
[DEBUG] 36:34.355 Amplify - configure AbstractPredictionsProvider 
Object { config: undefined }
ConsoleLogger.js:111
[useAuth] Mounted useAuth.js:22
[useAuth] Auth.currentAuthenticatedUser() useAuth.js:23
[DEBUG] 36:34.412 AuthClass - getting current authenticated user ConsoleLogger.js:101
[DEBUG] 36:34.414 AuthClass - cannot load federated user from auth storage ConsoleLogger.js:101
[DEBUG] 36:34.414 AuthClass - get current authenticated userpool user ConsoleLogger.js:101
[DEBUG] 36:34.415 AuthClass - Failed to get user from user pool ConsoleLogger.js:101
[DEBUG] 36:34.415 AuthClass - The user is not authenticated by the error No current user ConsoleLogger.js:111
[useAuth] Auth.currentAuthenticatedUser().catch not authenticated useAuth.js:34
not authenticated index.js:1375
[useAuth] setIsLoading false useAuth.js:42
[DEBUG] 36:34.739 Credentials - set credentials from session ConsoleLogger.js:101
[DEBUG] 36:35.342 Credentials - Load credentials successfully 
Object { ...SNIP... }
ConsoleLogger.js:111
[DEBUG] 36:35.342 AuthClass - AWS credentials 
Object { ...SNIP... }
ConsoleLogger.js:111
[DEBUG] 36:35.344 Hub - Dispatching to auth with  
Object { event: "signIn", data: {…}, message: "A user Google_110029493523186990292 has been signed in" }
ConsoleLogger.js:111
[DEBUG] 36:35.344 Analytics - on hub capsule auth 
Object { event: "signIn", data: {…}, message: "A user Google_110029493523186990292 has been signed in" }
ConsoleLogger.js:111
[DEBUG] 36:35.346 Hub - Dispatching to auth with  
Object { event: "signIn", data: {…}, message: "A user Google_110029493523186990292 has been signed in" }
ConsoleLogger.js:111
[DEBUG] 36:35.346 Hub - Dispatching to auth with  
Object { event: "signIn", data: {…}, message: "A user Google_110029493523186990292 has been signed in" }
ConsoleLogger.js:111
[useAuth] Hub 
Object { event: "signIn", data: {…}, message: "A user Google_110029493523186990292 has been signed in" }
useAuth.js:10
[DEBUG] 36:35.355 Hub - Dispatching to auth with  
Object { event: "cognitoHostedUI", data: {…}, message: "A user Google_110029493523186990292 has been signed in via Cognito Hosted UI" }
ConsoleLogger.js:111
[DEBUG] 36:35.357 Analytics - on hub capsule auth 
Object { event: "cognitoHostedUI", data: {…}, message: "A user Google_110029493523186990292 has been signed in via Cognito Hosted UI" }
ConsoleLogger.js:111
[DEBUG] 36:35.357 Hub - Dispatching to auth with  
Object { event: "cognitoHostedUI", data: {…}, message: "A user Google_110029493523186990292 has been signed in via Cognito Hosted UI" }
ConsoleLogger.js:111
[DEBUG] 36:35.357 Hub - Dispatching to auth with  
Object { event: "cognitoHostedUI", data: {…}, message: "A user Google_110029493523186990292 has been signed in via Cognito Hosted UI" }
ConsoleLogger.js:111
[useAuth] Hub 
Object { event: "cognitoHostedUI", data: {…}, message: "A user Google_110029493523186990292 has been signed in via Cognito Hosted UI" }
useAuth.js:10

There's a race-condition between Auth.getCurrentUser() and Auth.configure, as indicated by these logs:

...
[useAuth] Mounted useAuth.js:22
[useAuth] Auth.currentAuthenticatedUser() useAuth.js:23
[DEBUG] 36:34.412 AuthClass - getting current authenticated user ConsoleLogger.js:101
[DEBUG] 36:34.414 AuthClass - cannot load federated user from auth storage ConsoleLogger.js:101
[DEBUG] 36:34.414 AuthClass - get current authenticated userpool user ConsoleLogger.js:101
[DEBUG] 36:34.415 AuthClass - Failed to get user from user pool ConsoleLogger.js:101
[DEBUG] 36:34.415 AuthClass - The user is not authenticated by the error No current user ConsoleLogger.js:111
[useAuth] Auth.currentAuthenticatedUser().catch not authenticated useAuth.js:34
not authenticated index.js:1375
[useAuth] setIsLoading false useAuth.js:42
[DEBUG] 36:34.739 Credentials - set credentials from session ConsoleLogger.js:101
[DEBUG] 36:35.342 Credentials - Load credentials successfully 
Object { ...SNIP... }
ConsoleLogger.js:111
[DEBUG] 36:35.342 AuthClass - AWS credentials 
Object { ...SNIP... }
ConsoleLogger.js:111
[DEBUG] 36:35.344 Hub - Dispatching to auth with  
Object { event: "signIn", data: {…}, message: "A user Google_110029493523186990292 has been signed in" }
ConsoleLogger.js:111
...

Tracing things backwards:

1. set credentials from session is called via:

https://github.com/aws-amplify/amplify-js/blob/master/packages/core/src/Credentials.ts#L289

1. ...which traces back to:

   https://github.com/aws-amplify/amplify-js/blob/master/packages/auth/src/Auth.ts#L1770

2. ...which comes from Auth.configure asynchronously listening to the URL:

   https://github.com/aws-amplify/amplify-js/blob/10d747041c476e4dc75288bca417bd76e51773bd/packages/auth/src/Auth.ts#L226-L228

For now, it may be possible for Auth.getAuthenticatedUser() to awaits the URL callback:

• From the hosted UI, the redirect will be the current URL, so there isn't a need to listen.
• Awaiting it can be a one-time fallback operation, if the URL matches a certain structure.
• Cases where the location history matters, the UI is already accounting for the interstitial states (e.g. a PWA).

(Ideally, Auth would go through a state machine to prevent race-conditions like these.)

[ericclemmons]

This may not be as low of a lift as expected. Because the credentials go through a dispatcher flow, the underlying operations cannot be awaited.

[kevintechie]

Would this issue cause data.signInUserSession of the "signIn" event to be null unless I put in a timeout before trying to access it?

[ItayKatzCC]

Any updates?

[ericclemmons]

@ItayKatzCC Nothing in the form of a PR yet, but we have been reviewing the code since this bug came up and finding ways to solve it without introducing breaking changes.

In the meantime, the best way to handle this is to await Auth.currentAuthenticatedUser() and listen to the Hub events to know when the user is signed in for this flow.

[Antoine-C]

Hi @ericclemmons, do you have any update on this issue ?

[ericclemmons]

We're still working on it. Auth is both critical & complex, so eliminating this race-condition is more than a simple PR, unfortunately.

Thanks for the check-ins here on progress @Antoine-C! These comments bubble up into our planning & metrics, so it helps us focus on the most meaningful issues (like this one).

[sopranolinist]

@ericclemmons has there been any progress on this front? I see a PR was merged on Mar 31, did that fix this race condition and if so, is that PR part of the current package release?

[ericclemmons]

@sopranolinist #5244 and a few other PRs improved the handling of this race-condition in @aws-amplify/ui-react, but customers using Auth.currentAuthenticatedUser() and Auth.federatedSignIn() are still affected by the race-condition.

We're actively working on Auth across all platforms, and this is isn't being overlooked.

Keep an eye on this issue and https://github.com/aws-amplify/amplify-js/milestone/23 for resolution.

[sopranolinist]

@ericclemmons thank you very much for the update. My React project is currently using both of the methods you mentioned by name. It sounds like to avoid this race condition as things currently stand, we would have to switch from using the Auth class directly to using the React components, is that correct?

[ericclemmons]

@sopranolinist You can still use the Auth class! I recommend listening to Hub's auth events so you can setState(user) when they signIn or signout:

https://docs.amplify.aws/lib/utilities/hub/q/platform/js#authentication-events

The race-condition means that, after authenticating, Auth.currentAuthenticatedUser() may throw one time (because authentication is still completing), but listening to the signIn event is a sure-fire way to get user no matter what.

[elorzafe]

@tinymarsracing

I merged a fix for this, currently is published to unstable tag on npm if you can try out. We will publish to latest soon.