AWS AppSync Offline mutations are getting updated to the server multiple times when the device is connected to the network

Question

I'm using AWS AppSync Android SDK in my Project and i have noticed an issue that when i run a mutation it was working fine if the device is connected to the network, but if i do an offline mutation and then enabled my network, the same mutation is getting updated to the server multiple times. So i got a lot duplicate entries in my DB.

Tried different scenarios but the offline updations are getting called twice or thrice once the network connection is established.

//AppSyncClient Configuration class

class ClientFactory {

companion object {
    @Volatile
    private var mAWSAppSyncClient: AWSAppSyncClient? = null        
    private var cacheKeyResolver: CacheKeyResolver? = null
    private var appSyncSqlHelper: AppSyncSqlHelper?=null
    private var mNormalizedCacheFactory: SqlNormalizedCacheFactory?=null
    var  client:OkHttpClient?=null

    private lateinit var interceptor: HttpLoggingInterceptor
    @Synchronized
    fun getInstance(context: Context,utoken:String, dbName:String): AWSAppSyncClient? {
        if (cacheKeyResolver == null){
            cacheKeyResolver = object : CacheKeyResolver() {
                override fun fromFieldRecordSet(field: ResponseField, recordSet: Map<String, Any>): CacheKey {
                    val typeName = recordSet["__typename"] as String
                    if ("MessagesResponse" == typeName) {
                        val userKey = typeName + "." + recordSet["login"]
                        return CacheKey.from(userKey)
                    }
                    if (recordSet.containsKey("id")) {
                        val typeNameAndIDKey = recordSet["__typename"].toString() + "." + recordSet["id"]
                        return CacheKey.from(typeNameAndIDKey)
                    }
                    return CacheKey.NO_KEY
                }

                override fun fromFieldArguments(field: ResponseField, variables: Operation.Variables): CacheKey {
                    return CacheKey.NO_KEY
                }
            }
    }

        interceptor = HttpLoggingInterceptor()
        interceptor.level = HttpLoggingInterceptor.Level.BODY
        appSyncSqlHelper = AppSyncSqlHelper.create(context, dbName)
        mNormalizedCacheFactory =  SqlNormalizedCacheFactory(appSyncSqlHelper)

        if(client==null) {
            val cacheSize = 10 * 1024 * 1024 // 10MB
            client =
                OkHttpClient.Builder().cache(Cache(context.cacheDir, cacheSize.toLong())).addInterceptor(interceptor)
                    .addNetworkInterceptor { chain ->
                        val newRequest = chain.request().newBuilder()
                            .addHeader("Authorization", "Bearer ".plus(utoken))
                            .build()
                        chain.proceed(newRequest)
                    }.build()
        }

        val awsConfig = AWSConfiguration(context)
            mAWSAppSyncClient = AWSAppSyncClient.builder()
                .context(context)
                .okHttpClient(client)
                .normalizedCache(mNormalizedCacheFactory)
                .resolver(cacheKeyResolver)
                .persistentMutationsCallback(object : PersistentMutationsCallback {
                    override fun onFailure(error: PersistentMutationsError?)
                    {
                        Log.v("dd","ff")
                    }
                    override fun onResponse(response: PersistentMutationsResponse?)
                    {
                        Log.v("dd","ff")
                    }
                })
                .awsConfiguration(awsConfig)
                .build()
        return mAWSAppSyncClient
    }       
}

}

// Mutation implementation

        val graphqlCallback = object : GraphQLCall.Callback<MessageActivityMutation.Data>() {
            override fun onResponse(response: Response<MessageActivityMutation.Data>) {
                if(response!=null){}                        
            }
            override fun onFailure(e: ApolloException) {
                e.printStackTrace()                   
            }
        }
        ClientFactory.getInstance(thiscontext!!,preferencesHelper!!.userAuthToken,"messageackmutation_db")
            ?.mutate(MessageActivityMutation.builder()
            .id(msg_id)
            .verb(Constants.MESSAGE_ACKNOWLEDGED)
            .actioned_at(timeStamp)
            .build())
            ?.enqueue(graphqlCallback)

LOGCAT DETAILS***

2019-10-25 17:57:35.180 5403-8062/com.envoyer.app D/AppSyncOfflineMutationManager: Thread:[23616]: Internet DISCONNECTED. 2019-10-25 17:57:35.196 5403-5403/com.envoyer.app I/timberLog: Info-->Plain or R&AK with attachments 2019-10-25 17:57:35.218 5403-5403/com.envoyer.app V/PersistentOfflineMutationManager: Thread:[2]:In Constructor 2019-10-25 17:57:35.218 5403-5403/com.envoyer.app V/PersistentOfflineMutationManager: Thread:[2]:Priming the pump - Fetching all the queued mutations from the persistent store 2019-10-25 17:57:35.218 5403-5403/com.envoyer.app V/PersistentOfflineMutationManager: Thread:[2]: Fetching all mutation requests from persistent store 2019-10-25 17:57:35.220 5403-5403/com.envoyer.app V/PersistentOfflineMutationManager: Thread:[2]:Exiting the constructor. There are [0] mutations in the persistent queue 2019-10-25 17:57:35.225 5403-5403/com.envoyer.app V/AppSyncComplexObjectsInterceptor: Thread:[2]: Instantiating Complex Objects Interceptor 2019-10-25 17:57:35.235 5403-5403/com.envoyer.app V/AppSyncOfflineMutationInterceptor: Thread:[2]: Processing mutation. 2019-10-25 17:57:35.235 5403-5403/com.envoyer.app V/AppSyncOfflineMutationInterceptor: Thread:[2]: First, checking if it is a retry of mutation that encountered a conflict. 2019-10-25 17:57:35.235 5403-5403/com.envoyer.app V/AppSyncOfflineMutationInterceptor: Thread:[2]:Nope, hasn't encountered  conflict 2019-10-25 17:57:35.237 5403-5403/com.envoyer.app V/AppSyncOfflineMutationManager: Thread:[2]:  Added mutation[7ce851b7-fb8e-4ec2-ac49-4b603ca13acd] to inMemory Queue 2019-10-25 17:57:35.237 5403-5403/com.envoyer.app V/S3ObjectManagerImplementation: Thread:[2]: Looking at Key [id] of type [Integer] 2019-10-25 17:57:35.239 5403-5403/com.envoyer.app V/S3ObjectManagerImplementation: Thread:[2]: Looking at Key [verb] of type [String] 2019-10-25 17:57:35.242 5403-5403/com.envoyer.app V/S3ObjectManagerImplementation: Thread:[2]: Looking at Key [actioned_at] of type [String] 2019-10-25 17:57:35.247 5403-5403/com.envoyer.app V/PersistentOfflineMutationManager: Thread:[2]:addPersistentMutationObject: Adding mutation[7ce851b7-fb8e-4ec2-ac49-4b603ca13acd]: MessageActivityMutation     {"query":"mutation MessageActivity($id: Int, $verb: String, $actioned_at: String) {  MessageActivity(id: $id, verb: $verb, actioned_at: $actioned_at) {    __typename    status    data    message  }}","variables":{"id":1833,"verb":"message.seen","actioned_at":"2019-10-25 12:27:35"}} 2019-10-25 17:57:35.263 5403-5403/com.envoyer.app V/AppSyncOfflineMutationManager: Thread:[2]: Added mutation[7ce851b7-fb8e-4ec2-ac49-4b603ca13acd] to Persistent Queue. No S3 Objects found 2019-10-25 17:57:35.263 5403-5403/com.envoyer.app V/AppSyncOfflineMutationManager: Thread:[2]: Created both in-memory and persistent records. Now going to signal queue handler. 2019-10-25 17:57:35.263 5403-8068/com.envoyer.app V/QueueUpdateHandler: Thread:[23622]: Got message to take action on the mutation queue. 2019-10-25 17:57:35.263 5403-8068/com.envoyer.app V/QueueUpdateHandler: Thread:[23622]: Got message to process next mutation if one exists. 2019-10-25 17:57:35.264 5403-8068/com.envoyer.app V/AppSyncOfflineMutationManager: Thread:[23622]: Internet wasn't available. Exiting 2019-10-25 17:57:35.281 5403-5403/com.envoyer.app V/PersistentOfflineMutationManager: Thread:[2]:In Constructor 2019-10-25 17:57:35.281 5403-5403/com.envoyer.app V/PersistentOfflineMutationManager: Thread:[2]:Priming the pump - Fetching all the queued mutations from the persistent store 2019-10-25 17:57:35.281 5403-5403/com.envoyer.app V/PersistentOfflineMutationManager: Thread:[2]: Fetching all mutation requests from persistent store 2019-10-25 17:57:35.283 5403-5403/com.envoyer.app V/PersistentOfflineMutationManager: Thread:[2]:Exiting the constructor. There are [1] mutations in the persistent queue 2019-10-25 17:57:35.288 5403-5403/com.envoyer.app V/AppSyncComplexObjectsInterceptor: Thread:[2]: Instantiating Complex Objects Interceptor 2019-10-25 17:57:35.331 5403-5403/com.envoyer.app V/PersistentOfflineMutationManager: Thread:[2]:In Constructor 2019-10-25 17:57:35.331 5403-5403/com.envoyer.app V/PersistentOfflineMutationManager: Thread:[2]:Priming the pump - Fetching all the queued mutations from the persistent store 2019-10-25 17:57:35.331 5403-5403/com.envoyer.app V/PersistentOfflineMutationManager: Thread:[2]: Fetching all mutation requests from persistent store 2019-10-25 17:57:35.333 5403-5403/com.envoyer.app V/PersistentOfflineMutationManager: Thread:[2]:Exiting the constructor. There are [1] mutations in the persistent queue 2019-10-25 17:57:35.337 5403-5403/com.envoyer.app V/AppSyncComplexObjectsInterceptor: Thread:[2]: Instantiating Complex Objects Interceptor 2019-10-25 17:57:35.357 5403-5403/com.envoyer.app V/PersistentOfflineMutationManager: Thread:[2]:In Constructor 2019-10-25 17:57:35.358 5403-5403/com.envoyer.app V/PersistentOfflineMutationManager: Thread:[2]:Priming the pump - Fetching all the queued mutations from the persistent store 2019-10-25 17:57:35.358 5403-5403/com.envoyer.app V/PersistentOfflineMutationManager: Thread:[2]: Fetching all mutation requests from persistent store 2019-10-25 17:57:35.360 5403-5403/com.envoyer.app V/PersistentOfflineMutationManager: Thread:[2]:Exiting the constructor. There are [1] mutations in the persistent queue 2019-10-25 17:57:35.368 5403-5403/com.envoyer.app V/AppSyncComplexObjectsInterceptor: Thread:[2]: Instantiating Complex Objects Interceptor 2019-10-25 17:57:35.415 5403-5403/com.envoyer.app V/PersistentOfflineMutationManager: Thread:[2]:In Constructor 2019-10-25 17:57:35.415 5403-5403/com.envoyer.app V/PersistentOfflineMutationManager: Thread:[2]:Priming the pump - Fetching all the queued mutations from the persistent store 2019-10-25 17:57:35.415 5403-5403/com.envoyer.app V/PersistentOfflineMutationManager: Thread:[2]: Fetching all mutation requests from persistent store 2019-10-25 17:57:35.417 5403-5403/com.envoyer.app V/PersistentOfflineMutationManager: Thread:[2]:Exiting the constructor. There are [1] mutations in the persistent queue 2019-10-25 17:57:35.422 5403-5403/com.envoyer.app V/AppSyncComplexObjectsInterceptor: Thread:[2]: Instantiating Complex Objects Interceptor 2019-10-25 17:57:35.470 5403-8067/com.envoyer.app D/AppSyncOfflineMutationManager: Thread:[23621]: Internet DISCONNECTED. 2019-10-25 17:57:35.472 5403-8069/com.envoyer.app D/AppSyncOfflineMutationManager: Thread:[23623]: Internet DISCONNECTED. 2019-10-25 17:57:35.472 5403-8071/com.envoyer.app D/AppSyncOfflineMutationManager: Thread:[23625]: Internet DISCONNECTED. 2019-10-25 17:57:35.473 5403-8077/com.envoyer.app D/AppSyncOfflineMutationManager: Thread:[23628]: Internet DISCONNECTED. 2019-10-25 17:57:35.474 5403-8080/com.envoyer.app D/AppSyncOfflineMutationManager: Thread:[23630]: Internet DISCONNECTED. 2019-10-25 17:57:36.103 5403-8054/com.envoyer.app E/timberLog: onError-->An exception was thrown by the websocket 2019-10-25 17:57:37.759 5403-7658/com.envoyer.app V/AppSyncOfflineMutationInterceptor: Thread:[23596]: processing Mutations

******AFTER NETWORK ENABLED*******

<-- 200 https://4betrpovsffuhjxad5ouxlm6um.appsync-api.eu-west-1.amazonaws.com/graphql (1824ms) 2019-10-25 17:58:31.140 5403-8282/com.envoyer.app D/OkHttp: content-type: application/json;charset=UTF-8 2019-10-25 17:58:31.140 5403-8282/com.envoyer.app D/OkHttp: content-length: 100 2019-10-25 17:58:31.140 5403-8282/com.envoyer.app D/OkHttp: date: Fri, 25 Oct 2019 12:29:19 GMT 2019-10-25 17:58:31.140 5403-8282/com.envoyer.app D/OkHttp: x-amzn-requestid: e351113d-b8b4-416c-855c-6c28c95f1a98 2019-10-25 17:58:31.140 5403-8282/com.envoyer.app D/OkHttp: x-cache: Miss from cloudfront 2019-10-25 17:58:31.140 5403-8282/com.envoyer.app D/OkHttp: via: 1.1 bae54c9df29d44a26d5e0fd3d2c61c9c.cloudfront.net (CloudFront) 2019-10-25 17:58:31.140 5403-8282/com.envoyer.app D/OkHttp: x-amz-cf-pop: MAA50-C1 2019-10-25 17:58:31.141 5403-8282/com.envoyer.app D/OkHttp: x-amz-cf-id: Pl8OYaRmtJxPinPXFbGwcnfgQxyGlWJo1LE0n9_oQprRKeULGsvkCw== 2019-10-25 17:58:31.141 5403-8282/com.envoyer.app D/OkHttp: {"data":{"MessageActivity":{"__typename":"Response","status":true,"data":"[]","message":"Success"}}} 2019-10-25 17:58:31.141 5403-8282/com.envoyer.app D/OkHttp: <-- END HTTP (100-byte body) 2019-10-25 17:58:31.142 5403-8282/com.envoyer.app V/dd: ff 2019-10-25 17:58:31.142 5403-8282/com.envoyer.app V/PersistentOfflineMutationManager: Thread:[23645]:Removing mutation [7ce851b7-fb8e-4ec2-ac49-4b603ca13acd] from persistent store 2019-10-25 17:58:31.209 5403-8054/com.envoyer.app I/DpmTcmClient: RegisterTcmMonitor from: com.android.okhttp.TcmIdleTimerMonitor 2019-10-25 17:58:31.271 5403-8298/com.envoyer.app I/RetryInterceptor: Returning network response: success 2019-10-25 17:58:31.271 5403-8298/com.envoyer.app D/OkHttp: <-- 200 https://4betrpovsffuhjxad5ouxlm6um.appsync-api.eu-west-1.amazonaws.com/graphql (1900ms) 2019-10-25 17:58:31.271 5403-8298/com.envoyer.app D/OkHttp: content-type: application/json;charset=UTF-8 2019-10-25 17:58:31.272 5403-8298/com.envoyer.app D/OkHttp: content-length: 100 2019-10-25 17:58:31.272 5403-8298/com.envoyer.app D/OkHttp: date: Fri, 25 Oct 2019 12:29:19 GMT 2019-10-25 17:58:31.272 5403-8298/com.envoyer.app D/OkHttp: x-amzn-requestid: d0289bd6-3e31-49a6-815f-a708a1fa2233 2019-10-25 17:58:31.272 5403-8298/com.envoyer.app D/OkHttp: x-cache: Miss from cloudfront 2019-10-25 17:58:31.272 5403-8298/com.envoyer.app D/OkHttp: via: 1.1 bae54c9df29d44a26d5e0fd3d2c61c9c.cloudfront.net (CloudFront) 2019-10-25 17:58:31.272 5403-8298/com.envoyer.app D/OkHttp: x-amz-cf-pop: MAA50-C1 2019-10-25 17:58:31.272 5403-8298/com.envoyer.app D/OkHttp: x-amz-cf-id: 7wqu5JSmQJFT9layGkgpXB1WNpx5qD0-ohHF6TNHbU2l8gcBBUs0AQ== 2019-10-25 17:58:31.274 5403-8298/com.envoyer.app D/OkHttp: {"data":{"MessageActivity":{"__typename":"Response","status":true,"data":"[]","message":"Success"}}} 2019-10-25 17:58:31.274 5403-8298/com.envoyer.app D/OkHttp: <-- END HTTP (100-byte body) 2019-10-25 17:58:31.276 5403-8298/com.envoyer.app V/dd: ff 2019-10-25 17:58:31.276 5403-8298/com.envoyer.app V/PersistentOfflineMutationManager: Thread:[23648]:Removing mutation [7ce851b7-fb8e-4ec2-ac49-4b603ca13acd] from persistent store 2019-10-25 17:58:31.407 5403-8307/com.envoyer.app I/RetryInterceptor: Returning network response: success 2019-10-25 17:58:31.408 5403-8307/com.envoyer.app D/OkHttp: <-- 200 https://4betrpovsffuhjxad5ouxlm6um.appsync-api.eu-west-1.amazonaws.com/graphql (2007ms) 2019-10-25 17:58:31.408 5403-8307/com.envoyer.app D/OkHttp: content-type: application/json;charset=UTF-8 2019-10-25 17:58:31.408 5403-8307/com.envoyer.app D/OkHttp: content-length: 100 2019-10-25 17:58:31.408 5403-8307/com.envoyer.app D/OkHttp: date: Fri, 25 Oct 2019 12:29:19 GMT 2019-10-25 17:58:31.408 5403-8307/com.envoyer.app D/OkHttp: x-amzn-requestid: 6a575625-f4fa-4209-ac5c-e47f88297910 2019-10-25 17:58:31.408 5403-8307/com.envoyer.app D/OkHttp: x-cache: Miss from cloudfront 2019-10-25 17:58:31.409 5403-8307/com.envoyer.app D/OkHttp: via: 1.1 bae54c9df29d44a26d5e0fd3d2c61c9c.cloudfront.net (CloudFront) 2019-10-25 17:58:31.409 5403-8307/com.envoyer.app D/OkHttp: x-amz-cf-pop: MAA50-C1 2019-10-25 17:58:31.409 5403-8307/com.envoyer.app D/OkHttp: x-amz-cf-id: 1RaLA8-nyDTGsreE4QmtMETeslLvw3PmnHHdMZqzTXsYSjg3Y3kVbQ== 2019-10-25 17:58:31.411 5403-8307/com.envoyer.app D/OkHttp: {"data":{"MessageActivity":{"__typename":"Response","status":true,"data":"[]","message":"Success"}}} 2019-10-25 17:58:31.411 5403-8307/com.envoyer.app D/OkHttp: <-- END HTTP (100-byte body) 2019-10-25 17:58:31.469 5403-8281/com.envoyer.app I/RetryInterceptor: Returning network response: success 2019-10-25 17:58:31.469 5403-8281/com.envoyer.app D/OkHttp: <-- 200 https://4betrpovsffuhjxad5ouxlm6um.appsync-api.eu-west-1.amazonaws.com/graphql (2152ms) 2019-10-25 17:58:31.469 5403-8281/com.envoyer.app D/OkHttp: content-type: application/json;charset=UTF-8 2019-10-25 17:58:31.470 5403-8281/com.envoyer.app D/OkHttp: content-length: 100 2019-10-25 17:58:31.470 5403-8281/com.envoyer.app D/OkHttp: date: Fri, 25 Oct 2019 12:29:19 GMT 2019-10-25 17:58:31.470 5403-8281/com.envoyer.app D/OkHttp: x-amzn-requestid: 509dfabd-008d-477b-8e0d-247c2db21ced 2019-10-25 17:58:31.470 5403-8281/com.envoyer.app D/OkHttp: x-cache: Miss from cloudfront 2019-10-25 17:58:31.470 5403-8281/com.envoyer.app D/OkHttp: via: 1.1 bae54c9df29d44a26d5e0fd3d2c61c9c.cloudfront.net (CloudFront) 2019-10-25 17:58:31.470 5403-8281/com.envoyer.app D/OkHttp: x-amz-cf-pop: MAA50-C1 2019-10-25 17:58:31.470 5403-8281/com.envoyer.app D/OkHttp: x-amz-cf-id: -rdF8loaCHAAmZN8-mRIp9EIYOPJ5ngimAwyisRkoLwXnU_VdrmNAw== 2019-10-25 17:58:31.471 5403-8281/com.envoyer.app D/OkHttp: {"data":{"MessageActivity":{"__typename":"Response","status":true,"data":"[]","message":"Success"}}} 2019-10-25 17:58:31.471 5403-8281/com.envoyer.app D/OkHttp: <-- END HTTP (100-byte body) 2019-10-25 17:58:31.473 5403-8281/com.envoyer.app V/dd: ff 2019-10-25 17:58:31.473 5403-8281/com.envoyer.app V/PersistentOfflineMutationManager: Thread:[23644]:Removing mutation [7ce851b7-fb8e-4ec2-ac49-4b603ca13acd] from persistent store 2019-10-25 17:58:31.508 5403-8283/com.envoyer.app I/RetryInterceptor: Returning network response: success 2019-10-25 17:58:31.509 5403-8283/com.envoyer.app D/OkHttp: <-- 200 https://4betrpovsffuhjxad5ouxlm6um.appsync-api.eu-west-1.amazonaws.com/graphql (2182ms) 2019-10-25 17:58:31.509 5403-8283/com.envoyer.app D/OkHttp: content-type: application/json;charset=UTF-8 2019-10-25 17:58:31.509 5403-8283/com.envoyer.app D/OkHttp: content-length: 100 2019-10-25 17:58:31.509 5403-8283/com.envoyer.app D/OkHttp: date: Fri, 25 Oct 2019 12:29:19 GMT 2019-10-25 17:58:31.509 5403-8283/com.envoyer.app D/OkHttp: x-amzn-requestid: be28bb94-2788-449d-bc6f-af722e77e6d0 2019-10-25 17:58:31.509 5403-8283/com.envoyer.app D/OkHttp: x-cache: Miss from cloudfront 2019-10-25 17:58:31.509 5403-8283/com.envoyer.app D/OkHttp: via: 1.1 bae54c9df29d44a26d5e0fd3d2c61c9c.cloudfront.net (CloudFront) 2019-10-25 17:58:31.509 5403-8283/com.envoyer.app D/OkHttp: x-amz-cf-pop: MAA50-C1 2019-10-25 17:58:31.509 5403-8283/com.envoyer.app D/OkHttp: x-amz-cf-id: edvrZI0GEB_1DDoikzUVcFjpwwyIGAXl9elEqbgk-_ShvoKsP86kuw== 2019-10-25 17:58:31.510 5403-8283/com.envoyer.app D/OkHttp: {"data":{"MessageActivity":{"__typename":"Response","status":true,"data":"[]","message":"Success"}}} 2019-10-25 17:58:31.511 5403-8283/com.envoyer.app D/OkHttp: <-- END HTTP (100-byte body) 2019-10-25 17:58:31.512 5403-8283/com.envoyer.app V/dd: ff 2019-10-25 17:58:31.512 5403-8283/com.envoyer.app V/PersistentOfflineMutationManager: Thread:[23647]:Removing mutation [7ce851b7-fb8e-4ec2-ac49-4b603ca13acd] from persistent store 2019-10-25 17:58:31.685 5403-8282/com.envoyer.app V/QueueUpdateHandler: Thread:[23645]: Setting mutationInProgress as false.

Answer 1

I think I have found the answer but not really sure why this is happening. It's that besides overriding onFailure and onSuccess in your mutation you need to override another method i.e. onStatusEvent and clear the mutation queue. I believe that it's getting called twice or thrice sometimes once for scheduling and once for the network.

override fun onStatusEvent(event: GraphQLCall.StatusEvent) {
                    super.onStatusEvent(event)
                    awsAppSyncClient.clearMutationQueue()
                }

Hope it helps.