Amplify-android: DataStore @auth error: "Not Authorized to access [...] on type Subscription"

Created on 14 Oct 2020 · 6Comments · Source: aws-amplify/amplify-android

Hi, I found an error in my application, and I would like some help fixing it.

I am using Sentry to save log crashes. The error described below has been
reported more than 700 times during development. I am not sure if this is an
error with my code. If so, I would like some guidance on how to make it work
or what could be going on.

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 onCreateRespuestaCovid 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.}

Specifically, the error has this cause:

Bad subscription data for RespuestaCovid: [GraphQLResponse.Error{message='Not Authorized to access onCreateRespuestaCovid on type Subscription', locations='null', path='null', extensions='{errorType=Unauthorized}'}]

Current behavior:

The application is crashing on start only when the user is logged in. (Some
times the crash occurs a few seconds after start.)
Subscriptions are not woking.
Constantly getting these logs:

D/amplify:aws-api: Subscription attempt was canceled.
D/amplify:aws-datastore: Releasing latch due to an error.

Libraries information:

Cognito 1.4.1
Datastore 1.4.1
API 1.4.1
Storage 1.4.1

Device information

Battery Level | 89%
Brand | samsung
Connection Type | wifi
Family | SM-A530F
Free Memory | 1.4 GB
Free Storage | 1.3 GB
Low Memory | False
Name | Galaxy A8 (2018)
Online | True

Amplify initialization

class Application : MultiDexApplication() {
    …
    override fun onCreate() {
        super.onCreate()
        try {
            Amplify.addPlugin(AndroidLoggingPlugin(LogLevel.VERBOSE))
            Amplify.addPlugin(AWSCognitoAuthPlugin())
            Amplify.addPlugin(AWSDataStorePlugin())
            Amplify.addPlugin(AWSApiPlugin())
            Amplify.addPlugin(AWSS3StoragePlugin())
            //Amplify.addPlugin(AWSPredictionsPlugin())
            Amplify.configure(applicationContext)

            Log.i(TAG, "Initialized Amplify")
        } catch (error: AmplifyException) {
            Log.e(TAG, "Could not initialize Amplify", error)
        }
    }
}

amplifyconfigutration.json

{
    "UserAgent": "aws-amplify-cli/2.0",
    "Version": "1.0",
    "api": {
        "plugins": {
            "awsAPIPlugin": {
                "ilandroidappcheckin": {
                    "endpointType": "GraphQL",
                    "endpoint": "<ENDPOINT>.<REGION>",
                    "region": "us-east-1",
                    "authorizationType": "AMAZON_COGNITO_USER_POOLS",
                    "apiKey": "<REMOVED>"
                }
            }
        }
    },
    "auth": {
        "plugins": {
            "awsCognitoAuthPlugin": {
                "UserAgent": "aws-amplify-cli/0.1.0",
                "Version": "0.1.0",
                "IdentityManager": {
                    "Default": {}
                },
                "CredentialsProvider": {
                    "CognitoIdentity": {
                        "Default": {
                            "PoolId": "<REMOVED>",
                            "Region": "us-east-1"
                        }
                    }
                },
                "CognitoUserPool": {
                    "Default": {
                        "PoolId": "<REMOVED>",
                        "AppClientId": "<REMOVED>",
                        "AppClientSecret": "<REMOVED>",
                        "Region": "us-east-1"
                    }
                },
                "Auth": {
                    "Default": {
                        "authenticationFlowType": "USER_SRP_AUTH"
                    }
                },
                "AppSync": {
                    "Default": {
                        "ApiUrl": "",
                        "Region": "us-east-1",
                        "AuthMode": "AMAZON_COGNITO_USER_POOLS",
                        "ClientDatabasePrefix": "ilandroidappcheckin_AMAZON_COGNITO_USER_POOLS"
                    },
                    "ilandroidappcheckin_API_KEY": {
                        "ApiUrl": "<REMOVED>",
                        "Region": "us-east-1",
                        "AuthMode": "API_KEY",
                        "ApiKey": "<REMOVED>",
                        "ClientDatabasePrefix": "ilandroidappcheckin_API_KEY"
                    }
                },
                "S3TransferUtility": {
                    "Default": {
                        "Bucket": "<REMOVED>",
                        "Region": "us-east-1"
                    }
                }
            }
        }
    },
    "storage": {
        "plugins": {
            "awsS3StoragePlugin": {
                "bucket": "<>",
                "region": "us-east-1",
                "defaultAccessLevel": "guest"
            }
        }
    }
}

Error related GraphQL schema:
(Please let me know wether you need to see the full schema)

...

type RespuestaCovid #Conocer la ubicación del empleado mientras se encuentre en horario laboral
@model
@key(name: "fechaRespuesta", fields: ["createdAt"], queryField: "fechaRespuesta")
@auth(rules: [
    { allow: owner, ownerField: "asignado", operations: [read, create, update, delete] }
    { allow: groups, groups: ["admin"], operations: [read, create, update, delete] }
]) {
    id: ID!
    respuesta: [String!]! #Ej: [0,1,1,0,1,0,0,0,0,1, "Detalle de medicamentos"]
    createdAt: AWSDateTime!
    asignado: String!
}

...

Error Logs:

D/amplify:aws-api: Subscription attempt was canceled.
D/amplify:aws-datastore: Releasing latch due to an error.
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 RespuestaCovid: [GraphQLResponse.Error{message='Not Authorized to access onCreateRespuestaCovid 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)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
W/System.err:     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 onCreateRespuestaCovid 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 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)
D/amplify:aws-datastore: Releasing latch due to an error.
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)
        at okhttp3.internal.ws.WebSocketReader.readMessageFrame(WebSocketReader.kt:245)
D/amplify:aws-api: Current endpoint status: CONNECTED
W/System.err:     at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.kt:106)
        at okhttp3.internal.ws.RealWebSocket.loopReader(RealWebSocket.kt:293)
W/System.err:     at okhttp3.internal.ws.RealWebSocket$connect$1.onResponse(RealWebSocket.kt:195)
        at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:519)
        ... 3 more
D/amplify:aws-datastore: Invoking subscription onError emitter.
W/amplify:aws-datastore: An error occurred on the remote Localizacion subscription for model ON_CREATE.
    AmplifyException {message=Bad subscription data for Localizacion: [GraphQLResponse.Error{message='Not Authorized to access onCreateLocalizacion 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)
D/amplify:aws-datastore: Releasing latch due to an error.
D/amplify:aws-api: Subscription attempt was canceled.
D/amplify:aws-datastore: Releasing latch due to an error.
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 Localizacion: [GraphQLResponse.Error{message='Not Authorized to access onCreateLocalizacion 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.}
D/amplify:aws-api: Current endpoint status: CONNECTED
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)
        at io.reactivex.rxjava3.internal.observers.BasicFuseableObserver.onError(BasicFuseableObserver.java:100)
        at io.reactivex.rxjava3.internal.observers.BasicFuseableObserver.onError(BasicFuseableObserver.java:100)
W/System.err:     at io.reactivex.rxjava3.internal.operators.observable.ObservableObserveOn$ObserveOnObserver.checkTerminated(ObservableObserveOn.java:281)
W/System.err:     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)
W/System.err:     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)
        at java.lang.Thread.run(Thread.java:764)
W/System.err: Caused by: AmplifyException {message=Bad subscription data for Localizacion: [GraphQLResponse.Error{message='Not Authorized to access onCreateLocalizacion 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)
W/System.err:     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)
W/System.err:     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)
W/System.err:     at okhttp3.internal.ws.RealWebSocket$connect$1.onResponse(RealWebSocket.kt:195)
        at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:519)
        ... 3 more
D/amplify:aws-datastore: Invoking subscription onError emitter.
W/amplify:aws-datastore: An error occurred on the remote Localizacion subscription for model ON_UPDATE.
    AmplifyException {message=Bad subscription data for Localizacion: [GraphQLResponse.Error{message='Not Authorized to access onUpdateLocalizacion 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)
D/amplify:aws-datastore: Releasing latch due to an error.
D/amplify:aws-api: Subscription attempt was canceled.
D/amplify:aws-datastore: Releasing latch due to an error.
D/amplify:aws-api: Current endpoint status: CONNECTED
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 Localizacion: [GraphQLResponse.Error{message='Not Authorized to access onUpdateLocalizacion 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)
        at io.reactivex.rxjava3.internal.observers.BasicFuseableObserver.onError(BasicFuseableObserver.java:100)
W/System.err:     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)
W/System.err:     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)
W/System.err: Caused by: AmplifyException {message=Bad subscription data for Localizacion: [GraphQLResponse.Error{message='Not Authorized to access onUpdateLocalizacion 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)
W/System.err:     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)
W/System.err:     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
D/amplify:aws-datastore: Invoking subscription onError emitter.
W/amplify:aws-datastore: An error occurred on the remote Actividad subscription for model ON_CREATE.
    AmplifyException {message=Bad subscription data for Actividad: [GraphQLResponse.Error{message='Not Authorized to access onCreateActividad 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)
E/AndroidRuntime: FATAL EXCEPTION: RxCachedThreadScheduler-2
    Process: com.invernaderolabs.checkin, PID: 29628
    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 onCreateRespuestaCovid 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 onCreateRespuestaCovid 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 Actividad: [GraphQLResponse.Error{message='Not Authorized to access onCreateActividad 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.}
D/amplify:aws-api: Subscription attempt was canceled.
D/amplify:aws-datastore: Releasing latch due to an error.
W/System.err:     at io.reactivex.rxjava3.plugins.RxJavaPlugins.onError(RxJavaPlugins.java:367)
        at io.reactivex.rxjava3.internal.util.AtomicThrowable.tryAddThrowableOrReport(AtomicThrowable.java:52)
W/System.err:     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)
W/System.err:     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 Actividad: [GraphQLResponse.Error{message='Not Authorized to access onCreateActividad 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 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)
W/System.err:     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)
        ... 3 more
D/amplify:aws-datastore: Releasing latch due to an error.
D/amplify:aws-api: Current endpoint status: CONNECTED
I/System.out: (HTTPLog)-Static: isSBSettingEnabled false
I/System.out: (HTTPLog)-Static: isSBSettingEnabled false
I/Process: Sending signal. PID: 29628 SIG: 9

Part that is causing the crash:

E/AndroidRuntime: FATAL EXCEPTION: RxCachedThreadScheduler-2
    Process: com.invernaderolabs.checkin, PID: 29628
    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 onCreateRespuestaCovid 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 onCreateRespuestaCovid 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)

Full log is attached. It begins at app start when user is not logged in, and goes until the crash after login.
full-log.log

Bug DataStore

Source

upachecog

👍1

Most helpful comment

We were doing some tests and finally found what was the issue.

Our problem was that our models had not changed since the first time the issue appeared so we had not run the command _amplify codegen model_ again since the previous version of the CLI when this issue #186 was present and our generated models had the@AuthRule headers missing.

Thank you for your help, you gave us meaningful clues to track down what was going on, hope this helps some else who face this issue.

upachecog on 31 Oct 2020

🎉1 😄1

All 6 comments

@jamesonwilliams, @upachecog we add context like you tell us in issue #831, if you need more information please let us know.

cmllamosas on 14 Oct 2020

@upachecog: thanks for the detailed report.

The three salient components I see here are:

This message:

Not Authorized to access onCreateRespuestaCovid on type Subscription

This @auth rule:

@auth(rules: [
    { allow: owner, ownerField: "asignado", operations: [read, create, update, delete] }
    { allow: groups, groups: ["admin"], operations: [read, create, update, delete] }
])

and the fact that there is no user signed in, at the time the DataStore starts.

@richardmcclellan is currently working on a more explicit mechanism to start/stop synchronization, until _after_ a user has signed-in. That may alleviate some of the issue, here. @TrekSoft & @changxu0306 do you know if this combination of @auth rules is currently working?

jamesonwilliams on 15 Oct 2020

👍1

Yes as of 1.4.1 that combination should work no problem.

TrekSoft on 15 Oct 2020

👍1

@upachecog: thanks for the detailed report.

The three salient components I see here are:

This message:

Not Authorized to access onCreateRespuestaCovid on type Subscription

This @auth rule:
@auth(rules: [
    { allow: owner, ownerField: "asignado", operations: [read, create, update, delete] }
    { allow: groups, groups: ["admin"], operations: [read, create, update, delete] }
]) 
and the fact that there is no user signed in, at the time the DataStore starts.

@richardmcclellan is currently working on a more explicit mechanism to start/stop synchronization, until _after_ a user has signed-in. That may alleviate some of the issue, here. @TrekSoft & @changxu0306 do you know if this combination of @auth rules is currently working?

@jamesonwilliams: thank you for your quick response.

I can see other models involved in the logs, with similar messages:

Not Authorized to access onCreateRespuestaCovid on type Subscription

Not Authorized to access onCreateNuevaUbicacion on type Subscription

Not Authorized to access onDeleteActividad on type Subscription

@TrekSoft as of your answer, do this rules should be working? If so, do you know what could be going on? If not, could you suggest us a combination of auth rules that may fix our issue or refer us to the correct documentation?
I was able to replicate this problem starting the application while logged in, here's the log file: Amplify-error-signed-in.log

upachecog on 16 Oct 2020

Yes that's a rules combination we support so it appears to be a bug.

TrekSoft on 16 Oct 2020

We were doing some tests and finally found what was the issue.

Thank you for your help, you gave us meaningful clues to track down what was going on, hope this helps some else who face this issue.

upachecog on 31 Oct 2020

🎉1 😄1

Was this page helpful?

0 / 5 - 0 ratings

Related issues

The request signature we calculated does not match the signature you provided. Check your AWS Secret Access Key and signing method. Consult the service documentation for details.

tendynewbies · 5Comments

REST API converts PUT and POST with no body into GET request in-flight

jpignata · 5Comments

Temporal date types don't work with DataStore category

tomasfelder · 5Comments

"createdAt: AWSDateTime" in schema causes Datastore query failure

btdo · 4Comments

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

kjones · 7Comments