Datastore cannot sync new mutations after getting Failed to publish a local change error #1865

shantanu-saha-europcar · 2022-07-29T18:28:59Z

Before opening, please confirm:

I have searched for duplicate or closed issues and discussions.

Language and Async Model

Kotlin

Amplify Categories

DataStore

Gradle script dependencies

// Put output below this line

implementation 'com.amazonaws:aws-android-sdk-core:1.36.1'
implementation 'com.amazonaws:aws-android-sdk-cognito:1.36.1'
implementation 'com.amazonaws:aws-android-sdk-ses:1.36.1'
implementation 'com.sun.mail:android-mail:1.36.1'
implementation 'com.sun.mail:android-activation:1.36.1'

Environment information

# Put output below this line

Gradle 7.3.3

Please include any relevant guides or documentation you're referencing

No response

Describe the bug

I have the following model (dummy) with two keys as a primary key.

type ExampleModel @model @auth(rules: [{allow: public}]) {
    id: ID!
    Key1: String! @primaryKey(sortKeyFields: ["Key2"])
    Key2: String!
    ....
}

If two users use the app in offline mode and each user creates a row of ExampleModel with the same key1 and key2 value then after online 2nd user will get a mutation exception. It's because 1st user already submit the data to Amplify and 2nd user got a conflict (primary key constraints)

amplify:aws-datastore: Failed to publish a local change = PendingMutation{ ....

The problem is that after the exception user2 cannot publish other changes (also other models) to Amplify. Every change got enqueued but never submitted to Amplify. Also, the conflict handlers never trigger. I have tested the conflict handler for both conflict strategies. The only way to fix the issue is to uninstall the app.

Reproduction steps (if applicable)

No response

Code Snippet

// Put your code below this line.

Log output

// Put your logs below this line

Failed to publish a local change = PendingMutation{mutatedItem=SerializedModel{id='58469120-9ea8-40d8-a665-faf7f40b9ef2', serializedData={CustomerSignatureImage=null, NewDamageCount=0, DashboardImage=null, PickupMileage=25872, LateReturnChargeApplied=true, AgentSignatureImage=null, PickupFuelLevel=8, ReturnVehicleStationCode=PMIC07, CustomerLocaleReport=null, InteriorCleanlinessImages=null, vehicleReturnStationId=53aac6b1-640f-4849-82e6-8b85c571940d, RentalAgreementNumber=DEVRA01, createdAt=null, ReturnMileage=0, InteriorCleanliness=null, vehicleReturnAgentId=2a1b3fa6-87fc-470f-9c01-69efce8516aa, ExteriorCleanliness=null, MissingEquipmentCount=0, ReturnDateTime=2022-07-29T13:08:16.903Z, AlternativeEmail=, id=58469120-9ea8-40d8-a665-faf7f40b9ef2, WaiveFuelCharge=null, [email protected], CustomerSignatureNotPossible=false, updatedAt=null, ReturnAncilliaries=[], Status=INCOMPLETE, Comment=, ReturnFuelLevel=0, StationLocaleReport=null, KeyReturn=OTHER, [email protected], TaskStartDateTime=2022-07-29T13:08:16.506Z, TaskStatus=IN_PROGRESS, IntegrationSystemCode=GWY, DashboardLightStatus={Maintenance=false, Engine=false, Other=false, Tire=false}, RentalMileage=3000, vehicleReturnChangeOverReasonId=null, CustomerSignatureMissingReasonCode=null, DropKeyInBox=false, TaskEndDateTime=null, Vin=DEVTEST0000000001, ReturnMileageUnit=MILE, ReturnVehicleStationCountryCode=GB, SyncCountryCode=null}, modelName=VehicleReturn}, mutationType=UPDATE, mutationId=83bf6c12-0f3f-11ed-ac15-739ca718dcd9, predicate=MatchAllQueryPredicate}
    DataStoreException{message=Wanted 1 metadata for item with id = 58469120-9ea8-40d8-a665-faf7f40b9ef2, but had 0., cause=null, recoverySuggestion=This is likely a bug. please report to AWS.}
        at com.amplifyframework.datastore.syncengine.VersionRepository.extractVersion(VersionRepository.java:90)
        at com.amplifyframework.datastore.syncengine.VersionRepository.lambda$null$0$com-amplifyframework-datastore-syncengine-VersionRepository(VersionRepository.java:63)
        at com.amplifyframework.datastore.syncengine.VersionRepository$$ExternalSyntheticLambda0.accept(Unknown Source:8)
        at com.amplifyframework.datastore.storage.sqlite.SQLiteStorageAdapter.lambda$query$4$com-amplifyframework-datastore-storage-sqlite-SQLiteStorageAdapter(SQLiteStorageAdapter.java:405)
        at com.amplifyframework.datastore.storage.sqlite.SQLiteStorageAdapter$$ExternalSyntheticLambda6.run(Unknown Source:10)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:462)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        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:919)
2022-07-30 00:22:48.297 W/amplify:aws-datastore: Error ended observation of mutation outbox: 
    java.lang.RuntimeException: DataStoreException{message=Wanted 1 metadata for item with id = 58469120-9ea8-40d8-a665-faf7f40b9ef2, but had 0., cause=null, recoverySuggestion=This is likely a bug. please report to AWS.}
        at io.reactivex.rxjava3.internal.util.ExceptionHelper.wrapOrThrow(ExceptionHelper.java:46)
        at io.reactivex.rxjava3.internal.observers.BlockingMultiObserver.blockingAwait(BlockingMultiObserver.java:145)
        at io.reactivex.rxjava3.core.Completable.blockingAwait(Completable.java:1490)
        at com.amplifyframework.datastore.syncengine.MutationProcessor.drainMutationOutbox(MutationProcessor.java:117)
        at com.amplifyframework.datastore.syncengine.MutationProcessor.lambda$startDrainingMutationOutbox$1$com-amplifyframework-datastore-syncengine-MutationProcessor(MutationProcessor.java:101)
        at com.amplifyframework.datastore.syncengine.MutationProcessor$$ExternalSyntheticLambda3.apply(Unknown Source:4)
        at io.reactivex.rxjava3.internal.operators.observable.ObservableFlatMapCompletableCompletable$FlatMapCompletableMainObserver.onNext(ObservableFlatMapCompletableCompletable.java:97)
        at io.reactivex.rxjava3.internal.operators.observable.ObservableObserveOn$ObserveOnObserver.drainNormal(ObservableObserveOn.java:201)
        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:919)
     Caused by: DataStoreException{message=Wanted 1 metadata for item with id = 58469120-9ea8-40d8-a665-faf7f40b9ef2, but had 0., cause=null, recoverySuggestion=This is likely a bug. please report to AWS.}
        at com.amplifyframework.datastore.syncengine.VersionRepository.extractVersion(VersionRepository.java:90)
        at com.amplifyframework.datastore.syncengine.VersionRepository.lambda$null$0$com-amplifyframework-datastore-syncengine-VersionRepository(VersionRepository.java:63)
        at com.amplifyframework.datastore.syncengine.VersionRepository$$ExternalSyntheticLambda0.accept(Unknown Source:8)
        at com.amplifyframework.datastore.storage.sqlite.SQLiteStorageAdapter.lambda$query$4$com-amplifyframework-datastore-storage-sqlite-SQLiteStorageAdapter(SQLiteStorageAdapter.java:405)
        at com.amplifyframework.datastore.storage.sqlite.SQLiteStorageAdapter$$ExternalSyntheticLambda6.run(Unknown Source:10)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:462)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        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:919)

amplifyconfiguration.json

No response

GraphQL Schema

// Put your schema below this line

Additional information and screenshots

No response

The text was updated successfully, but these errors were encountered:

joekiller · 2022-08-01T03:47:39Z

yeah the mutation processor basically hangs if an error occurs. #1845 should fix it one way or another.

shantanu-saha-europcar · 2022-08-01T06:56:43Z

Because of primary key constraints Datastore cannot save the mutation and VersionRepository throws an exception from extractVersion method.

Wanted 1 metadata for item with id X, but had 0.

MutationProcessor handles the error in processOutboxItem method but does nothing. It only removes the mutation from the queue when DatastoreException.GraphQLResponseException occurs. Also, it doesn't announce any error so cannot get any callback on the error handler or Amplify.Hub

joekiller · 2022-08-01T11:31:14Z

Ouch yeah that's no good as well. I guess the PR I mentioned would only unlock the mutation engine to fail a again.

So error is, mutation rapidly or just offline for user1. Mutation gets pushed. User2 gets mutation transition only and encounters error.

Seems like the fix would be for rapid or unpublished mutations for the mutation engine on user1 to ensure it's somehow marked as a creation vs mutation bc otherwise user2 is going to get locked with that error of it not finding the metadata for the "existing" item

shantanu-saha-europcar · 2022-08-03T08:59:38Z

The primary key constraint is an unrecoverable error. So I think mutation should be removed from the queue. Also send an Amplify.Hub message about the error.

joekiller · 2022-08-03T12:54:25Z

Woops yes the trace indicates it is in the drainMutationOutbox which is outbound. Did you save the first model to the datastore prior to mutating it? The model id shouldn't have changed. If not, ensure you save the model before doing a copy of operation to mutate it.

If you had saved the model, this sounds buggy. It could be a bug where the first mutation hadn't even been processed for the storage engine, the mutation outbox merged the two models and then deeper down when it tried to find the model id as a mutation instead of really being a merged creation it would throw the error

joekiller · 2022-08-03T13:10:49Z

Hmm I see that you are using Key1 as the primary key, which you stated. But why not use ID! as the primary key? the uuids have a much better chance of no conflict.

If you need special logic to ensure Key1 and Key2 must be unique on all models then you'd need a custom conflict resolution on the backend

joekiller · 2022-08-03T13:13:21Z

Regardless of the intention, the error messages seem to indicate what I stated previously as the id it's working on to merge the model is 58469120-9ea8-40d8-a665-faf7f40b9ef2

joekiller · 2022-08-03T13:18:41Z

Seems related to #869 (comment)

shantanu-saha-europcar · 2022-08-04T05:04:28Z

Hmm I see that you are using Key1 as the primary key, which you stated. But why not use ID! as the primary key? the uuids have a much better chance of no conflict.

If you need special logic to ensure Key1 and Key2 must be unique on all models then you'd need a custom conflict resolution on the backend

Because Amplify doesn't have any option for unique constraints. So I'm using composite primary constraints. Other database systems throw an exception because of primary key constraints. But Amplify doesn't do anything on the error, that's the problem I think.

chrisbonifacio · 2022-09-07T18:28:50Z

@shantanu-saha-europcar apologies for the delay here, the team is currently working on supporting custom primary keys and composite keys in DataStore. Once that feature is released, we will follow up with an update here and ask if this issue is then resolved for you. Thank you for your patience!

AnilMaktala · 2022-10-12T18:20:29Z

@shantanu-saha-europcar we have identified the root cause and working on resolution. we will update once we resolve the issue.

shantanu-saha-europcar · 2022-10-13T08:04:25Z

@AnilMaktala It will be helpful if you can explain the cause here. Thanks

chrisbonifacio · 2022-10-24T19:58:21Z

@AnilMaktala It will be helpful if you can explain the cause here. Thanks

The cause of this issue is as explained in my earlier comment. The use of the @primaryKey directive, resulting in a custom primary key in the DynamoDB table, is not yet supported by DataStore but the feature is planned for release soon. We'll update here again once it is to verify the fix.

github-actions · 2023-02-01T16:42:08Z

⚠️COMMENT VISIBILITY WARNING⚠️

Comments on closed issues are hard for our team to see.
If you need more assistance, please either tag a team member or open a new issue that references this one.
If you wish to keep having a conversation with other community members under this issue feel free to do so.

banji180 added bug Something isn't working datastore DataStore category/plugins labels Aug 2, 2022

chrisbonifacio added the p1 label Aug 15, 2022

chrisbonifacio assigned poojamat Aug 15, 2022

lawmicha unassigned poojamat Nov 7, 2022

manueliglesias mentioned this issue Dec 24, 2022

feat(datastore): Add recoverability improvements #2201

Merged

5 tasks

mattcreaser closed this as completed in #2201 Feb 1, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Datastore cannot sync new mutations after getting Failed to publish a local change error #1865

Datastore cannot sync new mutations after getting Failed to publish a local change error #1865

shantanu-saha-europcar commented Jul 29, 2022

joekiller commented Aug 1, 2022

shantanu-saha-europcar commented Aug 1, 2022 •

edited

Loading

joekiller commented Aug 1, 2022

shantanu-saha-europcar commented Aug 3, 2022

joekiller commented Aug 3, 2022 •

edited

Loading

joekiller commented Aug 3, 2022 •

edited

Loading

joekiller commented Aug 3, 2022 •

edited

Loading

joekiller commented Aug 3, 2022

shantanu-saha-europcar commented Aug 4, 2022

chrisbonifacio commented Sep 7, 2022

AnilMaktala commented Oct 12, 2022

shantanu-saha-europcar commented Oct 13, 2022 •

edited

Loading

chrisbonifacio commented Oct 24, 2022

github-actions bot commented Feb 1, 2023

Datastore cannot sync new mutations after getting Failed to publish a local change error #1865

Datastore cannot sync new mutations after getting Failed to publish a local change error #1865

Comments

shantanu-saha-europcar commented Jul 29, 2022

Before opening, please confirm:

Language and Async Model

Amplify Categories

Gradle script dependencies

Environment information

Please include any relevant guides or documentation you're referencing

Describe the bug

Reproduction steps (if applicable)

Code Snippet

Log output

amplifyconfiguration.json

GraphQL Schema

Additional information and screenshots

joekiller commented Aug 1, 2022

shantanu-saha-europcar commented Aug 1, 2022 • edited Loading

joekiller commented Aug 1, 2022

shantanu-saha-europcar commented Aug 3, 2022

joekiller commented Aug 3, 2022 • edited Loading

joekiller commented Aug 3, 2022 • edited Loading

joekiller commented Aug 3, 2022 • edited Loading

joekiller commented Aug 3, 2022

shantanu-saha-europcar commented Aug 4, 2022

chrisbonifacio commented Sep 7, 2022

AnilMaktala commented Oct 12, 2022

shantanu-saha-europcar commented Oct 13, 2022 • edited Loading

chrisbonifacio commented Oct 24, 2022

github-actions bot commented Feb 1, 2023

⚠️COMMENT VISIBILITY WARNING⚠️

shantanu-saha-europcar commented Aug 1, 2022 •

edited

Loading

joekiller commented Aug 3, 2022 •

edited

Loading

joekiller commented Aug 3, 2022 •

edited

Loading

joekiller commented Aug 3, 2022 •

edited

Loading

shantanu-saha-europcar commented Oct 13, 2022 •

edited

Loading