Amplify-android: DataStore owner based auth Subscribe fails when Cognito sign-in method is email based

[kjones]

Amplify Android: 1.2.0
Related work: #596 and #635

When adding Cognito auth to a project, if email based sign-in is chosen (might apply to phone number also)

then DataStore fails when subscribing to AppSync for GraphQL models with owner based auth. Exception message is similar to the following:

AmplifyException - Bad subscription data for Athlete
GraphQLResponse.Error - Not Authorized to access onUpdateAthlete on type Subscription

This only happens when using email/password as the method of sign-in. Subscriptions succeed when signed-in via Social Provider (Federated).

I've traced this to an error in what the owner variable is set to when building the subscription request. It should be using the Cognito sub value for the owner variable instead of username. sub can be obtained from the ID token claim.

String sub = AWSMobileClient.getInstance().getTokens().getIdToken().getClaim("sub");

[upachecog]

I am facing the same issue with:

• DataStore version: 1.3.1
• Api version: 1.3.1
• Cognito version: 1.3.1

And some times it is causing the app to crash.

I confirm that I am using email-based authentication with Cognito. Please let me know whether you require more information to replicate the error.

W/amplify:aws-datastore: An error occurred on the remote Empresa subscription for model ON_UPDATE.
    AmplifyException {message=Bad subscription data for Empresa: [GraphQLResponse.Error{message='Not Authorized to access onUpdateEmpresa on type Subscription', locations='null', path='null', extensions='{errorType=Unauthorized}'}], cause=null, recoverySuggestion=Sorry, we don't have a suggested fix for this error yet.}
        at com.amplifyframework.datastore.appsync.AppSyncClient.lambda$subscription$2(AppSyncClient.java:285)
        at com.amplifyframework.datastore.appsync.-$$Lambda$AppSyncClient$JcXWwhRqFFN0mthuNQf2Zjf5Scw.accept(Unknown Source:8)
        at com.amplifyframework.api.aws.SubscriptionEndpoint$Subscription.dispatchNextMessage(SubscriptionEndpoint.java:370)
        at com.amplifyframework.api.aws.SubscriptionEndpoint.notifySubscriptionData(SubscriptionEndpoint.java:220)
        at com.amplifyframework.api.aws.SubscriptionEndpoint.access$600(SubscriptionEndpoint.java:60)
        at com.amplifyframework.api.aws.SubscriptionEndpoint$AmplifyWebSocketListener.processJsonMessage(SubscriptionEndpoint.java:546)
        at com.amplifyframework.api.aws.SubscriptionEndpoint$AmplifyWebSocketListener.onMessage(SubscriptionEndpoint.java:454)
        at okhttp3.internal.ws.RealWebSocket.onReadMessage(RealWebSocket.kt:333)
        at okhttp3.internal.ws.WebSocketReader.readMessageFrame(WebSocketReader.kt:245)
        at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.kt:106)
        at okhttp3.internal.ws.RealWebSocket.loopReader(RealWebSocket.kt:293)
        at okhttp3.internal.ws.RealWebSocket$connect$1.onResponse(RealWebSocket.kt:195)
        at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:519)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
        at java.lang.Thread.run(Thread.java:764)
W/System.err: io.reactivex.rxjava3.exceptions.UndeliverableException: The exception could not be delivered to the consumer because it has already canceled/disposed the flow or the exception has nowhere to go to begin with. Further reading: https://github.com/ReactiveX/RxJava/wiki/What's-different-in-2.0#error-handling | AmplifyException {message=Bad subscription data for Empresa: [GraphQLResponse.Error{message='Not Authorized to access onUpdateEmpresa on type Subscription', locations='null', path='null', extensions='{errorType=Unauthorized}'}], cause=null, recoverySuggestion=Sorry, we don't have a suggested fix for this error yet.}
W/System.err:     at io.reactivex.rxjava3.plugins.RxJavaPlugins.onError(RxJavaPlugins.java:367)
        at io.reactivex.rxjava3.internal.util.AtomicThrowable.tryAddThrowableOrReport(AtomicThrowable.java:52)
        at io.reactivex.rxjava3.internal.operators.observable.ObservableFlatMap$InnerObserver.onError(ObservableFlatMap.java:531)
W/System.err:     at io.reactivex.rxjava3.internal.observers.BasicFuseableObserver.onError(BasicFuseableObserver.java:100)
        at io.reactivex.rxjava3.internal.observers.BasicFuseableObserver.onError(BasicFuseableObserver.java:100)
        at io.reactivex.rxjava3.internal.operators.observable.ObservableObserveOn$ObserveOnObserver.checkTerminated(ObservableObserveOn.java:281)
        at io.reactivex.rxjava3.internal.operators.observable.ObservableObserveOn$ObserveOnObserver.drainNormal(ObservableObserveOn.java:172)
W/System.err:     at io.reactivex.rxjava3.internal.operators.observable.ObservableObserveOn$ObserveOnObserver.run(ObservableObserveOn.java:255)
        at io.reactivex.rxjava3.internal.schedulers.ScheduledRunnable.run(ScheduledRunnable.java:65)
        at io.reactivex.rxjava3.internal.schedulers.ScheduledRunnable.call(ScheduledRunnable.java:56)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:301)
W/System.err:     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
W/ActivityThread: handleWindowVisibility: no activity for token android.os.BinderProxy@12e029a
W/System.err:     at java.lang.Thread.run(Thread.java:764)
W/System.err: Caused by: AmplifyException {message=Bad subscription data for Empresa: [GraphQLResponse.Error{message='Not Authorized to access onUpdateEmpresa on type Subscription', locations='null', path='null', extensions='{errorType=Unauthorized}'}], cause=null, recoverySuggestion=Sorry, we don't have a suggested fix for this error yet.}
        at com.amplifyframework.datastore.appsync.AppSyncClient.lambda$subscription$2(AppSyncClient.java:285)
        at com.amplifyframework.datastore.appsync.-$$Lambda$AppSyncClient$JcXWwhRqFFN0mthuNQf2Zjf5Scw.accept(Unknown Source:8)
        at com.amplifyframework.api.aws.SubscriptionEndpoint$Subscription.dispatchNextMessage(SubscriptionEndpoint.java:370)
        at com.amplifyframework.api.aws.SubscriptionEndpoint.notifySubscriptionData(SubscriptionEndpoint.java:220)
W/System.err:     at com.amplifyframework.api.aws.SubscriptionEndpoint.access$600(SubscriptionEndpoint.java:60)
        at com.amplifyframework.api.aws.SubscriptionEndpoint$AmplifyWebSocketListener.processJsonMessage(SubscriptionEndpoint.java:546)
W/System.err:     at com.amplifyframework.api.aws.SubscriptionEndpoint$AmplifyWebSocketListener.onMessage(SubscriptionEndpoint.java:454)
        at okhttp3.internal.ws.RealWebSocket.onReadMessage(RealWebSocket.kt:333)
W/System.err:     at okhttp3.internal.ws.WebSocketReader.readMessageFrame(WebSocketReader.kt:245)
        at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.kt:106)
        at okhttp3.internal.ws.RealWebSocket.loopReader(RealWebSocket.kt:293)
        at okhttp3.internal.ws.RealWebSocket$connect$1.onResponse(RealWebSocket.kt:195)
        at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:519)
        ... 3 more
E/AndroidRuntime: FATAL EXCEPTION: RxCachedThreadScheduler-26
    Process: com.invernaderolabs.checkin, PID: 2175
    io.reactivex.rxjava3.exceptions.UndeliverableException: The exception could not be delivered to the consumer because it has already canceled/disposed the flow or the exception has nowhere to go to begin with. Further reading: https://github.com/ReactiveX/RxJava/wiki/What's-different-in-2.0#error-handling | AmplifyException {message=Bad subscription data for RespuestaCovid: [GraphQLResponse.Error{message='Not Authorized to access onDeleteRespuestaCovid on type Subscription', locations='null', path='null', extensions='{errorType=Unauthorized}'}], cause=null, recoverySuggestion=Sorry, we don't have a suggested fix for this error yet.}
        at io.reactivex.rxjava3.plugins.RxJavaPlugins.onError(RxJavaPlugins.java:367)
        at io.reactivex.rxjava3.internal.util.AtomicThrowable.tryAddThrowableOrReport(AtomicThrowable.java:52)
        at io.reactivex.rxjava3.internal.operators.observable.ObservableFlatMap$InnerObserver.onError(ObservableFlatMap.java:531)
        at io.reactivex.rxjava3.internal.observers.BasicFuseableObserver.onError(BasicFuseableObserver.java:100)
        at io.reactivex.rxjava3.internal.observers.BasicFuseableObserver.onError(BasicFuseableObserver.java:100)
        at io.reactivex.rxjava3.internal.operators.observable.ObservableObserveOn$ObserveOnObserver.checkTerminated(ObservableObserveOn.java:281)
        at io.reactivex.rxjava3.internal.operators.observable.ObservableObserveOn$ObserveOnObserver.drainNormal(ObservableObserveOn.java:172)
        at io.reactivex.rxjava3.internal.operators.observable.ObservableObserveOn$ObserveOnObserver.run(ObservableObserveOn.java:255)
        at io.reactivex.rxjava3.internal.schedulers.ScheduledRunnable.run(ScheduledRunnable.java:65)
        at io.reactivex.rxjava3.internal.schedulers.ScheduledRunnable.call(ScheduledRunnable.java:56)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:301)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
        at java.lang.Thread.run(Thread.java:764)
     Caused by: AmplifyException {message=Bad subscription data for RespuestaCovid: [GraphQLResponse.Error{message='Not Authorized to access onDeleteRespuestaCovid on type Subscription', locations='null', path='null', extensions='{errorType=Unauthorized}'}], cause=null, recoverySuggestion=Sorry, we don't have a suggested fix for this error yet.}
        at com.amplifyframework.datastore.appsync.AppSyncClient.lambda$subscription$2(AppSyncClient.java:285)
        at com.amplifyframework.datastore.appsync.-$$Lambda$AppSyncClient$JcXWwhRqFFN0mthuNQf2Zjf5Scw.accept(Unknown Source:8)
        at com.amplifyframework.api.aws.SubscriptionEndpoint$Subscription.dispatchNextMessage(SubscriptionEndpoint.java:370)
        at com.amplifyframework.api.aws.SubscriptionEndpoint.notifySubscriptionData(SubscriptionEndpoint.java:220)
        at com.amplifyframework.api.aws.SubscriptionEndpoint.access$600(SubscriptionEndpoint.java:60)
        at com.amplifyframework.api.aws.SubscriptionEndpoint$AmplifyWebSocketListener.processJsonMessage(SubscriptionEndpoint.java:546)
        at com.amplifyframework.api.aws.SubscriptionEndpoint$AmplifyWebSocketListener.onMessage(SubscriptionEndpoint.java:454)
        at okhttp3.internal.ws.RealWebSocket.onReadMessage(RealWebSocket.kt:333)
        at okhttp3.internal.ws.WebSocketReader.readMessageFrame(WebSocketReader.kt:245)
        at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.kt:106)
        at okhttp3.internal.ws.RealWebSocket.loopReader(RealWebSocket.kt:293)
        at okhttp3.internal.ws.RealWebSocket$connect$1.onResponse(RealWebSocket.kt:195)
        at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:519)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167) 
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641) 
        at java.lang.Thread.run(Thread.java:764) 

[kjones]

Not sure if this is the right approach (AWS devs???) but I've hacked together something that allows me to work around this issue. Note that I simply deleted all the tests that I broke with this change due to not wanting to devote time if this isn't the way to go. I can turn this into an official PR with valid tests if someone can give me the thumbs up or point me in the right direction.

[TrekSoft]

Hey, actually just about to submit a PR for the solution here - the issue with that is that username based sign in uses the username value instead of the user sub. There's some weirdness going on here where AppSync is checking the value of username from the access token which in the case of email/phone based sign in is the user sub. So I'm updating the getUsername method used here to simply pull username from that value which will guarantee it's what AppSync is looking for.

[kjones]

Excellent news @TrekSoft! I'll be happy to abandon my hack when your real fix is available. Thanks!

[kjones]

@TrekSoft I cherry-picked your changes into a local build and it works great. Thanks again.

[TrekSoft]

That's awesome to hear! It's merged now so will go out with the next release - most likely Thursday of next week.

[jamesonwilliams]

@kjones #818 went out in 1.3.2. Please give this latest version a try, and let us know if the issue persists. cc: @TrekSoft