Initial GraphQL API sync fails (using Amazon Cognito User Pools authentication) when user not logged

[Perniciosius]

Describe the bug
When using private auth using Amazon Cognito User Pools for authentication of graphql API. During first app startup, Datastore tries to sync to cloud even if currently no user is logged in, which causes the sync to fail.

To Reproduce
Steps to reproduce the behavior:

1. Setup graphql API with private auth using Amazon Cognito UserPool.
2. Start the app first time(user not logged in).

Expected behavior
Initial sync should wait till user login. Only after logging in user, the initial sync should start.

Platform
Amplify Flutter current supports iOS and Android. This issue is reproducible in (check all that apply):
[✔️] Android
[✔️] iOS

Debug Log

I/amplify:flutter:auth_cognito(13780): Added Auth plugin
I/AmplifyFlutter(13780): Added StorageS3 plugin
I/amplify:flutter:api(13780): Added API plugin
I/iosius.feedbac(13780): ProcessProfilingInfo new_methods=37 is saved saved_to_disk=1 resolve_classes_delay=8000
D/AWSMobileClient(13780): Using the SignInProviderConfig from `awsconfiguration.json`.
D/AWSMobileClient(13780): Inspecting user state details
I/TetheringManager(13780): registerTetheringEventCallback:com.perniciosius.feedback
I/amplify:aws-datastore(13780): Orchestrator lock acquired.
I/amplify:aws-datastore(13780): Orchestrator transitioning from STOPPED to SYNC_VIA_API
I/amplify:aws-datastore(13780): Starting to observe local storage changes.
D/AWSMobileClient(13780): Inspecting user state details
I/amplify:aws-datastore(13780): Now observing local storage. Local changes will be enqueued to mutation outbox.
I/amplify:aws-datastore(13780): Setting currentState to LOCAL_ONLY
D/AWSMobileClient(13780): Inspecting user state details
I/amplify:aws-datastore(13780): Setting currentState to SYNC_VIA_API
D/AWSMobileClient(13780): waitForSignIn: userState:SIGNED_OUT
I/amplify:flutter:datastore(13780): Established a new stream form flutter com.amplifyframework.datastore.storage.sqlite.-$$Lambda$coxN3FV0myAqN-gpZfZvj7bzSOI@5fd3391
I/amplify:aws-datastore(13780): Orchestrator lock released.
I/amplify:aws-datastore(13780): Starting API synchronization mode.
I/amplify:aws-datastore(13780): Starting processing subscription events.
E/amplify:aws-datastore(13780): Failure encountered while attempting to start API sync.
E/amplify:aws-datastore(13780): DataStoreException{message=Error during subscription., cause=ApiException{message=You must be signed-in with Cognito Userpools to be able to use getTokens, cause=null, recoverySuggestion=Sorry, we don't have a suggested fix for this error yet.}, recoverySuggestion=Evaluate details.}
E/amplify:aws-datastore(13780): 	at com.amplifyframework.datastore.appsync.AppSyncClient.lambda$subscription$3(AppSyncClient.java:329)
E/amplify:aws-datastore(13780): 	at com.amplifyframework.datastore.appsync.-$$Lambda$AppSyncClient$797ziDK0io-qXODzROLOA77stS8.accept(Unknown Source:4)
E/amplify:aws-datastore(13780): 	at com.amplifyframework.api.aws.SubscriptionOperation.lambda$null$1$SubscriptionOperation(SubscriptionOperation.java:83)
E/amplify:aws-datastore(13780): 	at com.amplifyframework.api.aws.-$$Lambda$SubscriptionOperation$l9lC7Ew6niNmyszMXQSUKS6YhwE.accept(Unknown Source:4)
E/amplify:aws-datastore(13780): 	at com.amplifyframework.api.aws.SubscriptionEndpoint.requestSubscription(SubscriptionEndpoint.java:114)
E/amplify:aws-datastore(13780): 	at com.amplifyframework.api.aws.SubscriptionOperation.lambda$start$2$SubscriptionOperation(SubscriptionOperation.java:74)
E/amplify:aws-datastore(13780): 	at com.amplifyframework.api.aws.-$$Lambda$SubscriptionOperation$dV6kPdbE8Z12Qd0_rE-16cujgUk.run(Unknown Source:2)
E/amplify:aws-datastore(13780): 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:462)
E/amplify:aws-datastore(13780): 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
E/amplify:aws-datastore(13780): 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
E/amplify:aws-datastore(13780): 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
E/amplify:aws-datastore(13780): 	at java.lang.Thread.run(Thread.java:923)
E/amplify:aws-datastore(13780): Caused by: ApiException{message=You must be signed-in with Cognito Userpools to be able to use getTokens, cause=null, recoverySuggestion=Sorry, we don't have a suggested fix for this error yet.}

E/amplify:aws-datastore(13780): 	at com.amplifyframework.api.aws.sigv4.DefaultCognitoUserPoolsAuthProvider.fetchToken(DefaultCognitoUserPoolsAuthProvider.java:97)
E/amplify:aws-datastore(13780): 	at com.amplifyframework.api.aws.sigv4.DefaultCognitoUserPoolsAuthProvider.getLatestAuthToken(DefaultCognitoUserPoolsAuthProvider.java:103)
E/amplify:aws-datastore(13780): 	at com.amplifyframework.api.aws.SubscriptionAuthorizer.forCognitoUserPools(SubscriptionAuthorizer.java:133)
E/amplify:aws-datastore(13780): 	at com.amplifyframework.api.aws.SubscriptionAuthorizer.createHeaders(SubscriptionAuthorizer.java:95)
E/amplify:aws-datastore(13780): 	at com.amplifyframework.api.aws.SubscriptionAuthorizer.createHeadersForConnection(SubscriptionAuthorizer.java:68)
E/amplify:aws-datastore(13780): 	at com.amplifyframework.api.aws.SubscriptionEndpoint.buildConnectionRequestUrl(SubscriptionEndpoint.java:278)
E/amplify:aws-datastore(13780): 	at com.amplifyframework.api.aws.SubscriptionEndpoint.requestSubscription(SubscriptionEndpoint.java:110)
E/amplify:aws-datastore(13780): 	... 7 more
W/amplify:aws-datastore(13780): API sync failed - transitioning to LOCAL_ONLY.
W/amplify:aws-datastore(13780): DataStoreException{message=Error during subscription., cause=ApiException{message=You must be signed-in with Cognito Userpools to be able to use getTokens, cause=null, recoverySuggestion=Sorry, we don't have a suggested fix for this error yet.}, recoverySuggestion=Evaluate details.}
W/amplify:aws-datastore(13780): 	at com.amplifyframework.datastore.appsync.AppSyncClient.lambda$subscription$3(AppSyncClient.java:329)
W/amplify:aws-datastore(13780): 	at com.amplifyframework.datastore.appsync.-$$Lambda$AppSyncClient$797ziDK0io-qXODzROLOA77stS8.accept(Unknown Source:4)
W/amplify:aws-datastore(13780): 	at com.amplifyframework.api.aws.SubscriptionOperation.lambda$null$1$SubscriptionOperation(SubscriptionOperation.java:83)
W/amplify:aws-datastore(13780): 	at com.amplifyframework.api.aws.-$$Lambda$SubscriptionOperation$l9lC7Ew6niNmyszMXQSUKS6YhwE.accept(Unknown Source:4)
W/amplify:aws-datastore(13780): 	at com.amplifyframework.api.aws.SubscriptionEndpoint.requestSubscription(SubscriptionEndpoint.java:114)
W/amplify:aws-datastore(13780): 	at com.amplifyframework.api.aws.SubscriptionOperation.lambda$start$2$SubscriptionOperation(SubscriptionOperation.java:74)
W/amplify:aws-datastore(13780): 	at com.amplifyframework.api.aws.-$$Lambda$SubscriptionOperation$dV6kPdbE8Z12Qd0_rE-16cujgUk.run(Unknown Source:2)
W/amplify:aws-datastore(13780): 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:462)
W/amplify:aws-datastore(13780): 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
W/amplify:aws-datastore(13780): 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
W/amplify:aws-datastore(13780): 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
W/amplify:aws-datastore(13780): 	at java.lang.Thread.run(Thread.java:923)
W/amplify:aws-datastore(13780): Caused by: ApiException{message=You must be signed-in with Cognito Userpools to be able to use getTokens, cause=null, recoverySuggestion=Sorry, we don't have a suggested fix for this error yet.}
W/amplify:aws-datastore(13780): 	at com.amplifyframework.api.aws.sigv4.DefaultCognitoUserPoolsAuthProvider.fetchToken(DefaultCognitoUserPoolsAuthProvider.java:97)
W/amplify:aws-datastore(13780): 	at com.amplifyframework.api.aws.sigv4.DefaultCognitoUserPoolsAuthProvider.getLatestAuthToken(DefaultCognitoUserPoolsAuthProvider.java:103)
W/amplify:aws-datastore(13780): 	at com.amplifyframework.api.aws.SubscriptionAuthorizer.forCognitoUserPools(SubscriptionAuthorizer.java:133)
W/amplify:aws-datastore(13780): 	at com.amplifyframework.api.aws.SubscriptionAuthorizer.createHeaders(SubscriptionAuthorizer.java:95)
W/amplify:aws-datastore(13780): 	at com.amplifyframework.api.aws.SubscriptionAuthorizer.createHeadersForConnection(SubscriptionAuthorizer.java:68)
W/amplify:aws-datastore(13780): 	at com.amplifyframework.api.aws.SubscriptionEndpoint.buildConnectionRequestUrl(SubscriptionEndpoint.java:278)
W/amplify:aws-datastore(13780): 	at com.amplifyframework.api.aws.SubscriptionEndpoint.requestSubscription(SubscriptionEndpoint.java:110)
W/amplify:aws-datastore(13780): 	... 7 more
I/amplify:aws-datastore(13780): Orchestrator transitioning from SYNC_VIA_API to LOCAL_ONLY
I/amplify:aws-datastore(13780): Setting currentState to LOCAL_ONLY
I/amplify:aws-datastore(13780): Stopping subscription processor.
I/amplify:aws-datastore(13780): Stopped subscription processor.

Additional context
The issue can be fixed if sync can wait till user login.

[ragingsquirrel3]

Thanks for raising this issue, will investigate as soon as possible.

[b-cancel]

This is a bug report I just filed that includes a couple of bugs I found and the workarounds to each
after reading your bug report I think it could help
#822

[bugthedebugger]

Any updates on this? I am working on a project that requires access to DataStore before the user logs in. Adding the cognito user pool authentication gives the error:

An error occurred while configuring Amplify:
AmplifyException(
  message: Failed to retrieve auth token from Cognito provider., 
  recoverySuggestion: Check the application logs for details., 
  underlyingException: ApiAuthException{
       message=You must be signed-in with Cognito Userpools to be able to use getTokens, 
       cause=null, recoverySuggestion=Sorry, we don't have a suggested fix for this error yet.
 }
)

[jsw-davidhuang]

i face the relate problem, too. in the app, different use login and get the data from cloud, it seems to get the same data. it would not be different even the account is different

[HuiSF]

As this comment pointed out, amplify-flutter triggers initial sync regardless auth rule settings and if there is a valid user signed in. This behavior will be fixed.

The dependencies of amplify-flutter, amplify-ios and amplify-android both silently handle exceptions happening within API sync, when this happens, both libraries fall back to local mode, and try to resume when invoking DataStore query, save, update, delete and start APIs.

Before the the initial sync issue gets fixed, a workaround can be used here to mitigate:

After user signs in successfully, can invoke start API to ensure DataStore starts API sync with correct authentication information.

await Amplify.DataStore.start()

[HuiSF]

Hi @jsw-davidhuang I'm not sure the issue you describe in the comment is related to issue describe in the main thread. Could you please elaborate?

[jsw-davidhuang]

Hi @jsw-davidhuang I'm not sure the issue you describe in the comment is related to issue describe in the main thread. Could you please elaborate?

i think what @Perniciosius faced is relate to how to design the schema file, he can use rules like:

@auth(rules: [{ allow: owner }]) 

to make the data only for the login users instead of a public data.

[HuiSF]

i face the relate problem, too. in the app, different use login and get the data from cloud, it seems to get the same data. it would not be different even the account is different

Hi @jsw-davidhuang a quick follow up :)
Did you invoke Amplify.DataStore.clear() on user signing out in the App? (Please refer to this document)

[jsw-davidhuang]

i face the relate problem, too. in the app, different use login and get the data from cloud, it seems to get the same data. it would not be different even the account is different

Hi @jsw-davidhuang a quick follow up :) Did you invoke Amplify.DataStore.clear() on user signing out in the App? (Please refer to this document)

i solve it by adding @auth(rules: [{ allow: owner }]) , thanks

[dnys1]

@Perniciosius are you still experiencing this issue?

[HuiSF]

This unexpected behavior now is fixed with version 0.3.0.

[charlieforward9]

Unrelated, but how do I enable the debug log in my console for finer tuned debugging? I am emulating on an iOS simulator and running the app through VS code run & debug console