amplify-js
amplify-js copied to clipboard
aws-amplify
DataStore saves inconsistent data to dynamoDB on a poor connection
Before opening, please confirm:
- [X] I have searched for duplicate or closed issues and discussions.
- [X] I have read the guide for submitting bug reports.
- [X] I have done my best to include a minimal, self-contained set of instructions for consistently reproducing the issue.
JavaScript Framework
React
Amplify APIs
GraphQL API, DataStore
Amplify Categories
api
Environment information
System:
OS: Linux 5.18 Arch Linux
CPU: (16) x64 AMD Ryzen 7 3700X 8-Core Processor
Memory: 17.56 GB / 31.26 GB
Container: Yes
Shell: 5.9 - /bin/zsh
Binaries:
Node: 16.13.2 - ~/.nvm/versions/node/v16.13.2/bin/node
Yarn: 1.22.19 - /usr/bin/yarn
npm: 8.1.2 - ~/.nvm/versions/node/v16.13.2/bin/npm
Browsers:
Firefox: 101.0.1
npmPackages:
@aws-amplify/ui-react: ^2.19.1 => 2.19.1
@aws-amplify/ui-react-internal: undefined ()
@aws-amplify/ui-react-legacy: undefined ()
@peculiar/webcrypto: ^1.3.2 => 1.3.2
@testing-library/jest-dom: ^5.16.2 => 5.16.2
@testing-library/react: ^12.1.4 => 12.1.4
@testing-library/user-event: ^13.5.0 => 13.5.0
aws-amplify: ^4.3.24 => 4.3.24
graphql: ^16.3.0 => 16.3.0 (15.8.0)
react: ^17.0.2 => 17.0.2
react-dom: ^17.0.2 => 17.0.2
react-scripts: 5.0.0 => 5.0.0
web-vitals: ^2.1.4 => 2.1.4
npmGlobalPackages:
@aws-amplify/cli: 8.4.0
corepack: 0.10.0
npm: 8.1.2
Describe the bug
When making changes too fast to a record, mutations to the API are missed or send incorrect data.
An observer will also react and return the UI into an old state that reflects the out of date mutation.
The problem is more obvious when on a slow network connection, and in real world testing has caused data to be saved incorrectly with normal usage. When offline, data is synced correctly once a connection is re-established.
I also find the problem occurs when testing with Cypress at full network speed.
I use an observer to make sure that the record has one field set before enabling a button to set the next field. However I have observed this issue when changing a single field repeatedly.
One workaround is to check that _version has incremented before allowing further mutations. However this prevents it from working offline as that value is never incremented until data is sent to the API.
In my example I'm setting two fields: status and a time stamp. But it does seem to happen when setting one field too.
Expected behavior
DataStore should always sync changes to the record and not miss changes. The observer should not update with incorrect data.
Reproduction steps
- open the example in Chrome
- open dev tools and in the console:
await DataStore.save(new models.Task({})) - copy the new ID to taskId
- (if console says task not found, refresh the page)
- go to Network tab. Change No throttling to Slow 3G
- update the record by clicking the check boxes multiple times. previous check box should be disabled until the observer updates
- the status should appear at the top
- buttons that are enabled appear under the checkboxes
- observe mutations in the Network tab
- observe changes in the UI
Code Snippet
enum TaskStatus {
ACTIVE
PICKED_UP
DROPPED_OFF
COMPLETED
}
type Task @model @auth(rules: [{ allow: public }]) {
id: ID!
status: TaskStatus
timePickedUp: AWSDateTime
timeDroppedOff: AWSDateTime
timeRiderHome: AWSDateTime
}
src/App.js
import "./App.css";
import React, { useRef, useState } from "react";
import { Amplify, DataStore } from "aws-amplify";
import awsconfig from "./aws-exports";
import { useEffect } from "react";
import * as models from "./models";
window.DataStore = DataStore;
window.models = models;
Amplify.configure(awsconfig);
const fields = {
timePickedUp: "Picked up",
timeDroppedOff: "Delivered",
timeRiderHome: "Rider home",
};
export const tasksStatus = {
active: "ACTIVE",
pickedUp: "PICKED_UP",
droppedOff: "DROPPED_OFF",
completed: "COMPLETED",
};
export function determineTaskStatus(task) {
if (!!!task.timePickedUp) {
return tasksStatus.active;
} else if (!!task.timePickedUp && !!!task.timeDroppedOff) {
return tasksStatus.pickedUp;
} else if (
!!task.timePickedUp &&
!!task.timeDroppedOff &&
!!!task.timeRiderHome
) {
return tasksStatus.droppedOff;
} else if (
!!task.timePickedUp &&
!!task.timeDroppedOff &&
!!task.timeRiderHome
) {
return tasksStatus.completed;
}
}
async function saveTaskTimeWithKey(key, value, taskId) {
let isoString = null;
if (value) {
isoString = new Date(value).toISOString();
}
const existingTask = await DataStore.query(models.Task, taskId);
if (!existingTask) throw new Error("Task doesn't exist");
const status = await determineTaskStatus({
...existingTask,
[key]: isoString,
});
return DataStore.save(
models.Task.copyOf(existingTask, (updated) => {
updated[key] = value ? isoString : null;
updated.status = status;
})
);
}
function App() {
const [state, setState] = useState([]);
const [task, setTask] = useState(null);
const [isPosting, setIsPosting] = useState(false);
const taskObserver = useRef({ unsubscribe: () => {} });
const timeSet = useRef(null);
const taskId = "38b35b73-2b4a-406a-bcf0-de0bc56ee8d0";
const prevVersion = useRef(null);
function checkDisabled(key) {
const stopped =
state.includes("timeCancelled") || state.includes("timeRejected");
if (key === "timeDroppedOff")
return (
state.includes("timeRiderHome") ||
!state.includes("timePickedUp") ||
stopped
);
else if (key === "timePickedUp") {
return state.includes("timeDroppedOff") || stopped;
} else if (key === "timeRiderHome") {
if (task && task.status === tasksStatus.new) return true;
return !state.includes("timeDroppedOff");
} else if (key === "timeRejected") {
if (state.includes("timeRejected")) return false;
return (
(state.includes("timePickedUp") && state.includes("timeDroppedOff")) ||
stopped
);
} else if (key === "timeCancelled") {
if (state.includes("timeCancelled")) return false;
return (
(state.includes("timePickedUp") && state.includes("timeDroppedOff")) ||
stopped
);
} else return false;
}
async function setTimeWithKey(key, value) {
try {
setIsPosting(true);
await saveTaskTimeWithKey(key, value, taskId);
setIsPosting(false);
} catch (error) {
console.log(error);
}
}
async function getTaskAndUpdateState() {
try {
const task = await DataStore.query(models.Task, taskId);
if (!task) throw new Error("Task not found");
setTask(task);
taskObserver.current.unsubscribe();
taskObserver.current = DataStore.observe(models.Task, taskId).subscribe(
async ({ opType, element }) => {
if (
["INSERT", "UPDATE"].includes(opType)
// uncomment for a fix that only works while online
//&& element._version > prevVersion.current
) {
console.log(element);
setTask(element);
prevVersion.current = element._version;
}
}
);
} catch (e) {
console.log(e);
}
}
useEffect(() => getTaskAndUpdateState(), []);
function calculateState() {
if (!task) return;
const result = Object.keys(fields).filter((key) => {
return !!task[key];
});
setState(result);
}
useEffect(calculateState, [task]);
function onClickToggle(key, checked) {
timeSet.current = new Date();
setTimeWithKey(key, !checked ? null : new Date());
}
return (
<div>
{task ? task.status : ""}
<div>
<form class="form">
{Object.entries(fields).map(([key, label]) => {
return (
<label>
{label}
<input
type="checkbox"
disabled={isPosting || checkDisabled(key)}
onChange={(e) => onClickToggle(key, e.target.checked)}
checked={state.includes(key)}
/>
</label>
);
})}
</form>
</div>
<div sx={{ width: "100%" }} direction="column">
{Object.entries(fields).map(([key, value]) => {
const disabled = isPosting || checkDisabled(key);
return (
!disabled && (
<div>
{value.toUpperCase()}
</div>
)
);
})}
</div>
</div>
);
}
export default App;
src/App.css
.form {
display: flex;
flex-direction: column;
justify-content: center;
align-items: flex-end;
max-width: 120px;
}
Log output
ConsoleLogger.ts:125 [DEBUG] 01:01.814 DataStore - params ready {predicate: {…}, pagination: {…}, modelConstructor: ƒ}
App.js:126 Model {id: '38b35b73-2b4a-406a-bcf0-de0bc56ee8d0', status: 'DROPPED_OFF', timePickedUp: '2022-06-10T01:52:35.587Z', timeDroppedOff: '2022-06-10T02:00:34.696Z', timeCancelled: null, …}
ConsoleLogger.ts:115 [DEBUG] 01:01.852 DataStore - Attempting mutation with authMode: API_KEY
ConsoleLogger.ts:115 [DEBUG] 01:01.852 Util - attempt #1 with this vars: ["Task","Update","{\"timeRiderHome\":null,\"status\":\"DROPPED_OFF\",\"id\":\"38b35b73-2b4a-406a-bcf0-de0bc56ee8d0\",\"_version\":316,\"_lastChangedAt\":1654826451258,\"_deleted\":null}","{}",null,null,{"data":"{\"timeRiderHome\":null,\"status\":\"DROPPED_OFF\",\"id\":\"38b35b73-2b4a-406a-bcf0-de0bc56ee8d0\",\"_version\":316,\"_lastChangedAt\":1654826451258,\"_deleted\":null}","modelId":"38b35b73-2b4a-406a-bcf0-de0bc56ee8d0","model":"Task","operation":"Update","condition":"{}","id":"01G55M7Q5TB189H8P2QFKV0F35"}]
ConsoleLogger.ts:125 [DEBUG] 01:01.853 RestClient - POST https://xpbl3vag25afng2n6ishxbo74y.appsync-api.eu-west-1.amazonaws.com/graphql
ConsoleLogger.ts:125 [DEBUG] 01:02.110 DataStore - params ready {predicate: {…}, pagination: {…}, modelConstructor: ƒ}
App.js:126 Model {id: '38b35b73-2b4a-406a-bcf0-de0bc56ee8d0', status: 'PICKED_UP', timePickedUp: '2022-06-10T01:52:35.587Z', timeDroppedOff: null, timeCancelled: null, …}
ConsoleLogger.ts:115 [DEBUG] 01:02.145 AWSAppSyncRealTimeProvider - subscription message from AWS AppSync RealTime: {"id":"55de9349-e5e3-4391-9ff0-daa8235c61a2","type":"data","payload":{"data":{"onUpdateTask":{"id":"38b35b73-2b4a-406a-bcf0-de0bc56ee8d0","status":"DROPPED_OFF","timePickedUp":"2022-06-10T01:52:35.587Z","timeDroppedOff":"2022-06-10T02:00:34.696Z","timeCancelled":null,"timeRejected":null,"timeRiderHome":null,"createdAt":"2022-06-09T18:38:06.466Z","updatedAt":"2022-06-10T02:01:01.912Z","_version":317,"_lastChangedAt":1654826461927,"_deleted":null}}}}
ConsoleLogger.ts:118 [DEBUG] 01:02.145 AWSAppSyncRealTimeProvider {id: '55de9349-e5e3-4391-9ff0-daa8235c61a2', observer: SubscriptionObserver, query: 'subscription operation {\n onUpdateTask {\n id\n … _version\n _lastChangedAt\n _deleted\n }\n}\n', variables: {…}}
ConsoleLogger.ts:125 [DEBUG] 01:02.384 DataStore - params ready {predicate: {…}, pagination: {…}, modelConstructor: ƒ}
App.js:126 Model {id: '38b35b73-2b4a-406a-bcf0-de0bc56ee8d0', status: 'ACTIVE', timePickedUp: null, timeDroppedOff: null, timeCancelled: null, …}
ConsoleLogger.ts:115 [DEBUG] 01:03.886 DataStore - Mutation sent successfully with authMode: API_KEY
ConsoleLogger.ts:115 [DEBUG] 01:03.909 DataStore - Attempting mutation with authMode: API_KEY
ConsoleLogger.ts:115 [DEBUG] 01:03.909 Util - attempt #1 with this vars: ["Task","Update","{\"id\":\"38b35b73-2b4a-406a-bcf0-de0bc56ee8d0\",\"_version\":316,\"_lastChangedAt\":1654826451258,\"_deleted\":null,\"timeDroppedOff\":null,\"status\":\"ACTIVE\",\"timePickedUp\":null}","{}",null,null,{"data":"{\"id\":\"38b35b73-2b4a-406a-bcf0-de0bc56ee8d0\",\"_version\":316,\"_lastChangedAt\":1654826451258,\"_deleted\":null,\"timeDroppedOff\":null,\"status\":\"ACTIVE\",\"timePickedUp\":null}","modelId":"38b35b73-2b4a-406a-bcf0-de0bc56ee8d0","model":"Task","operation":"Update","condition":"{}","id":"01G55M7Q5TB189H8P2QFKV0F37"}]
ConsoleLogger.ts:125 [DEBUG] 01:03.910 RestClient - POST https://xpbl3vag25afng2n6ishxbo74y.appsync-api.eu-west-1.amazonaws.com/graphql
ConsoleLogger.ts:115 [DEBUG] 01:04.214 AWSAppSyncRealTimeProvider - subscription message from AWS AppSync RealTime: {"id":"55de9349-e5e3-4391-9ff0-daa8235c61a2","type":"data","payload":{"data":{"onUpdateTask":{"id":"38b35b73-2b4a-406a-bcf0-de0bc56ee8d0","status":"DROPPED_OFF","timePickedUp":"2022-06-10T01:52:35.587Z","timeDroppedOff":"2022-06-10T02:00:34.696Z","timeCancelled":null,"timeRejected":null,"timeRiderHome":null,"createdAt":"2022-06-09T18:38:06.466Z","updatedAt":"2022-06-10T02:01:01.912Z","_version":318,"_lastChangedAt":1654826464061,"_deleted":null}}}}
ConsoleLogger.ts:118 [DEBUG] 01:04.214 AWSAppSyncRealTimeProvider {id: '55de9349-e5e3-4391-9ff0-daa8235c61a2', observer: SubscriptionObserver, query: 'subscription operation {\n onUpdateTask {\n id\n … _version\n _lastChangedAt\n _deleted\n }\n}\n', variables: {…}}
ConsoleLogger.ts:115 [DEBUG] 01:05.927 DataStore - Mutation sent successfully with authMode: API_KEY
App.js:126 Model {id: '38b35b73-2b4a-406a-bcf0-de0bc56ee8d0', status: 'DROPPED_OFF', timePickedUp: '2022-06-10T01:52:35.587Z', timeDroppedOff: '2022-06-10T02:00:34.696Z', timeCancelled: null, …}
ConsoleLogger.ts:115 [DEBUG] 01:10.215 AWSAppSyncRealTimeProvider - subscription message from AWS AppSync RealTime: {"type":"ka"}
ConsoleLogger.ts:118 [DEBUG] 01:10.228 AWSAppSyncRealTimeProvider {id: '', observer: null, query: '', variables: {…}}
ConsoleLogger.ts:125 [DEBUG] 02:04.837 DataStore - params ready {predicate: {…}, pagination: {…}, modelConstructor: ƒ}
App.js:126 Model {id: '38b35b73-2b4a-406a-bcf0-de0bc56ee8d0', status: 'COMPLETED', timePickedUp: '2022-06-10T01:52:35.587Z', timeDroppedOff: '2022-06-10T02:00:34.696Z', timeCancelled: null, …}
ConsoleLogger.ts:115 [DEBUG] 02:04.895 DataStore - Attempting mutation with authMode: API_KEY
ConsoleLogger.ts:115 [DEBUG] 02:04.896 Util - attempt #1 with this vars: ["Task","Update","{\"timeRiderHome\":\"2022-06-10T02:02:04.836Z\",\"status\":\"COMPLETED\",\"id\":\"38b35b73-2b4a-406a-bcf0-de0bc56ee8d0\",\"_version\":318,\"_lastChangedAt\":1654826464061,\"_deleted\":null}","{}",null,null,{"data":"{\"timeRiderHome\":\"2022-06-10T02:02:04.836Z\",\"status\":\"COMPLETED\",\"id\":\"38b35b73-2b4a-406a-bcf0-de0bc56ee8d0\",\"_version\":318,\"_lastChangedAt\":1654826464061,\"_deleted\":null}","modelId":"38b35b73-2b4a-406a-bcf0-de0bc56ee8d0","model":"Task","operation":"Update","condition":"{}","id":"01G55M7Q5TB189H8P2QFKV0F38"}]
ConsoleLogger.ts:125 [DEBUG] 02:04.896 RestClient - POST https://xpbl3vag25afng2n6ishxbo74y.appsync-api.eu-west-1.amazonaws.com/graphql
ConsoleLogger.ts:115 [DEBUG] 02:05.204 AWSAppSyncRealTimeProvider - subscription message from AWS AppSync RealTime: {"id":"55de9349-e5e3-4391-9ff0-daa8235c61a2","type":"data","payload":{"data":{"onUpdateTask":{"id":"38b35b73-2b4a-406a-bcf0-de0bc56ee8d0","status":"COMPLETED","timePickedUp":"2022-06-10T01:52:35.587Z","timeDroppedOff":"2022-06-10T02:00:34.696Z","timeCancelled":null,"timeRejected":null,"timeRiderHome":"2022-06-10T02:02:04.836Z","createdAt":"2022-06-09T18:38:06.466Z","updatedAt":"2022-06-10T02:02:04.971Z","_version":319,"_lastChangedAt":1654826525012,"_deleted":null}}}}
ConsoleLogger.ts:118 [DEBUG] 02:05.204 AWSAppSyncRealTimeProvider {id: '55de9349-e5e3-4391-9ff0-daa8235c61a2', observer: SubscriptionObserver, query: 'subscription operation {\n onUpdateTask {\n id\n … _version\n _lastChangedAt\n _deleted\n }\n}\n', variables: {…}}
ConsoleLogger.ts:115 [DEBUG] 02:06.917 DataStore - Mutation sent successfully with authMode: API_KEY
App.js:126 Model {id: '38b35b73-2b4a-406a-bcf0-de0bc56ee8d0', status: 'COMPLETED', timePickedUp: '2022-06-10T01:52:35.587Z', timeDroppedOff: '2022-06-10T02:00:34.696Z', timeCancelled: null, …}
ConsoleLogger.ts:125 [DEBUG] 02:09.126 DataStore - params ready {predicate: {…}, pagination: {…}, modelConstructor: ƒ}
App.js:126 Model {id: '38b35b73-2b4a-406a-bcf0-de0bc56ee8d0', status: 'DROPPED_OFF', timePickedUp: '2022-06-10T01:52:35.587Z', timeDroppedOff: '2022-06-10T02:00:34.696Z', timeCancelled: null, …}
ConsoleLogger.ts:115 [DEBUG] 02:09.162 DataStore - Attempting mutation with authMode: API_KEY
ConsoleLogger.ts:115 [DEBUG] 02:09.162 Util - attempt #1 with this vars: ["Task","Update","{\"timeRiderHome\":null,\"status\":\"DROPPED_OFF\",\"id\":\"38b35b73-2b4a-406a-bcf0-de0bc56ee8d0\",\"_version\":319,\"_lastChangedAt\":1654826525012,\"_deleted\":null}","{}",null,null,{"data":"{\"timeRiderHome\":null,\"status\":\"DROPPED_OFF\",\"id\":\"38b35b73-2b4a-406a-bcf0-de0bc56ee8d0\",\"_version\":319,\"_lastChangedAt\":1654826525012,\"_deleted\":null}","modelId":"38b35b73-2b4a-406a-bcf0-de0bc56ee8d0","model":"Task","operation":"Update","condition":"{}","id":"01G55M7Q5TB189H8P2QFKV0F39"}]
ConsoleLogger.ts:125 [DEBUG] 02:09.163 RestClient - POST https://xpbl3vag25afng2n6ishxbo74y.appsync-api.eu-west-1.amazonaws.com/graphql
ConsoleLogger.ts:115 [DEBUG] 02:09.494 AWSAppSyncRealTimeProvider - subscription message from AWS AppSync RealTime: {"id":"55de9349-e5e3-4391-9ff0-daa8235c61a2","type":"data","payload":{"data":{"onUpdateTask":{"id":"38b35b73-2b4a-406a-bcf0-de0bc56ee8d0","status":"DROPPED_OFF","timePickedUp":"2022-06-10T01:52:35.587Z","timeDroppedOff":"2022-06-10T02:00:34.696Z","timeCancelled":null,"timeRejected":null,"timeRiderHome":null,"createdAt":"2022-06-09T18:38:06.466Z","updatedAt":"2022-06-10T02:02:09.217Z","_version":320,"_lastChangedAt":1654826529232,"_deleted":null}}}}
ConsoleLogger.ts:118 [DEBUG] 02:09.494 AWSAppSyncRealTimeProvider {id: '55de9349-e5e3-4391-9ff0-daa8235c61a2', observer: SubscriptionObserver, query: 'subscription operation {\n onUpdateTask {\n id\n … _version\n _lastChangedAt\n _deleted\n }\n}\n', variables: {…}}
ConsoleLogger.ts:125 [DEBUG] 02:09.694 DataStore - params ready {predicate: {…}, pagination: {…}, modelConstructor: ƒ}
App.js:126 Model {id: '38b35b73-2b4a-406a-bcf0-de0bc56ee8d0', status: 'COMPLETED', timePickedUp: '2022-06-10T01:52:35.587Z', timeDroppedOff: '2022-06-10T02:00:34.696Z', timeCancelled: null, …}
ConsoleLogger.ts:115 [DEBUG] 02:10.214 AWSAppSyncRealTimeProvider - subscription message from AWS AppSync RealTime: {"type":"ka"}
ConsoleLogger.ts:118 [DEBUG] 02:10.214 AWSAppSyncRealTimeProvider {id: '', observer: null, query: '', variables: {…}}
ConsoleLogger.ts:115 [DEBUG] 02:11.206 DataStore - Mutation sent successfully with authMode: API_KEY
ConsoleLogger.ts:115 [DEBUG] 02:11.227 DataStore - Attempting mutation with authMode: API_KEY
ConsoleLogger.ts:115 [DEBUG] 02:11.227 Util - attempt #1 with this vars: ["Task","Update","{\"timeRiderHome\":\"2022-06-10T02:02:09.692Z\",\"status\":\"COMPLETED\",\"id\":\"38b35b73-2b4a-406a-bcf0-de0bc56ee8d0\",\"_version\":319,\"_lastChangedAt\":1654826525012,\"_deleted\":null}","{}",null,null,{"data":"{\"timeRiderHome\":\"2022-06-10T02:02:09.692Z\",\"status\":\"COMPLETED\",\"id\":\"38b35b73-2b4a-406a-bcf0-de0bc56ee8d0\",\"_version\":319,\"_lastChangedAt\":1654826525012,\"_deleted\":null}","modelId":"38b35b73-2b4a-406a-bcf0-de0bc56ee8d0","model":"Task","operation":"Update","condition":"{}","id":"01G55M7Q5TB189H8P2QFKV0F3A"}]
ConsoleLogger.ts:125 [DEBUG] 02:11.228 RestClient - POST https://xpbl3vag25afng2n6ishxbo74y.appsync-api.eu-west-1.amazonaws.com/graphql
ConsoleLogger.ts:115 [DEBUG] 02:11.535 AWSAppSyncRealTimeProvider - subscription message from AWS AppSync RealTime: {"id":"55de9349-e5e3-4391-9ff0-daa8235c61a2","type":"data","payload":{"data":{"onUpdateTask":{"id":"38b35b73-2b4a-406a-bcf0-de0bc56ee8d0","status":"DROPPED_OFF","timePickedUp":"2022-06-10T01:52:35.587Z","timeDroppedOff":"2022-06-10T02:00:34.696Z","timeCancelled":null,"timeRejected":null,"timeRiderHome":"2022-06-10T02:02:09.692Z","createdAt":"2022-06-09T18:38:06.466Z","updatedAt":"2022-06-10T02:02:09.217Z","_version":321,"_lastChangedAt":1654826531350,"_deleted":null}}}}
ConsoleLogger.ts:118 [DEBUG] 02:11.535 AWSAppSyncRealTimeProvider {id: '55de9349-e5e3-4391-9ff0-daa8235c61a2', observer: SubscriptionObserver, query: 'subscription operation {\n onUpdateTask {\n id\n … _version\n _lastChangedAt\n _deleted\n }\n}\n', variables: {…}}
ConsoleLogger.ts:115 [DEBUG] 02:13.248 DataStore - Mutation sent successfully with authMode: API_KEY
App.js:126 Model {id: '38b35b73-2b4a-406a-bcf0-de0bc56ee8d0', status: 'DROPPED_OFF', timePickedUp: '2022-06-10T01:52:35.587Z', timeDroppedOff: '2022-06-10T02:00:34.696Z', timeCancelled: null, …}
aws-exports.js
const awsmobile = {
"aws_project_region": "eu-west-1",
"aws_appsync_graphqlEndpoint": "https://xpbl3vag25afng2n6ishxbo74y.appsync-api.eu-west-1.amazonaws.com/graphql",
"aws_appsync_region": "eu-west-1",
"aws_appsync_authenticationType": "API_KEY",
"aws_appsync_apiKey": "da2-vs6oo7xssvdn7lnqbpene4fmla",
"aws_cognito_identity_pool_id": "eu-west-1:7bbed19f-d205-4101-9829-ebfa833ec06d",
"aws_cognito_region": "eu-west-1",
"aws_user_pools_id": "eu-west-1_VD0AQtRSn",
"aws_user_pools_web_client_id": "63l0hbdlt41u10th59cnfom53c",
"oauth": {},
"aws_cognito_username_attributes": [],
"aws_cognito_social_providers": [],
"aws_cognito_signup_attributes": [
"EMAIL"
],
"aws_cognito_mfa_configuration": "OFF",
"aws_cognito_mfa_types": [
"SMS"
],
"aws_cognito_password_protection_settings": {
"passwordPolicyMinLength": 8,
"passwordPolicyCharacters": []
},
"aws_cognito_verification_mechanisms": [
"EMAIL"
]
};
export default awsmobile;
Manual configuration
No response
Additional configuration
No response
Mobile Device
No response
Mobile Operating System
No response
Mobile Browser
No response
Mobile Browser Version
No response
Additional information and screenshots
A video demonstration (sorry for quality, the webm looked much better but github won't attach it):
https://user-images.githubusercontent.com/32309223/172974634-359942aa-2387-45a1-8f2d-88797ef15353.mp4
An example of where the status field mismatches what was sent to the API (timeRiderHome, timeDroppedOff and timePickedUp all being set means the status should be COMPLETED). This doesn't always happen, but does often.
The entry in dynamoDB where the status doesn't match:
@duckbytes We reviewed this yesterday and can reproduce, it looks to be a specific race condition as you've identified during in-flight network requests. In order to address this though it would be helpful to see the Cypress tests as well. Can you share those?
Hey @undefobj. Thanks for looking into it.
Cypress.Commands.add("addSingleTask", () => {
cy.get("[data-cy=NEW-title-skeleton]", { timeout: 10000 }).should(
"not.exist"
);
cy.get(".MuiPaper-root").should("be.visible");
cy.get("[data-cy=create-task-button]").click();
cy.get("[data-cy=save-to-dash-button]").click();
});
Cypress.Commands.add("loginByCognitoApi", (username, password) => {
const log = Cypress.log({
displayName: "COGNITO LOGIN",
message: [`🔐 Authenticating | ${username}`],
// @ts-ignore
autoEnd: false,
});
log.snapshot("before");
const signIn = Auth.signIn({ username, password });
cy.wrap(signIn, { log: false }).then((cognitoResponse) => {
const keyPrefixWithUsername = `${cognitoResponse.keyPrefix}.${cognitoResponse.username}`;
window.localStorage.setItem(
`${keyPrefixWithUsername}.idToken`,
cognitoResponse.signInUserSession.idToken.jwtToken
);
window.localStorage.setItem(
`${keyPrefixWithUsername}.accessToken`,
cognitoResponse.signInUserSession.accessToken.jwtToken
);
window.localStorage.setItem(
`${keyPrefixWithUsername}.refreshToken`,
cognitoResponse.signInUserSession.refreshToken.token
);
window.localStorage.setItem(
`${keyPrefixWithUsername}.clockDrift`,
cognitoResponse.signInUserSession.clockDrift
);
window.localStorage.setItem(
`${cognitoResponse.keyPrefix}.LastAuthUser`,
cognitoResponse.username
);
window.localStorage.setItem(
"amplify-authenticator-authState",
"signedIn"
);
log.snapshot("after");
log.end();
});
cy.visit("/");
});
describe("task actions", () => {
beforeEach(() => {
cy.loginByCognitoApi(Cypress.env("username"), Cypress.env("password"));
});
it("picked up, delivered, rider home", () => {
cy.visit("/");
cy.addSingleTask();
cy.get("[data-cy=tasks-kanban-column-NEW]").children().first().click();
cy.get("[data-cy=combo-box-riders]").click().type("Test Rider");
cy.get('[id*="option-0"]').should("exist");
cy.get('[id*="option-0"]').click();
cy.get("[data-cy=task-status]").should("have.text", "ACTIVE");
cy.get("[data-cy=task-RIDER-assignees]").contains("Test Rider");
cy.get("[data-cy=task-timePickedUp-button]").should("be.enabled");
cy.get("[data-cy=task-timePickedUp-button]").click();
cy.get("[data-cy=confirmation-ok-button]").click();
cy.get("[data-cy=task-status]").should("have.text", "PICKED UP");
cy.get("[data-cy=task-timeDroppedOff-button]").should("be.enabled");
cy.get("[data-cy=task-timeDroppedOff-button]").click();
cy.get("[data-cy=confirmation-ok-button]").click();
cy.get("[data-cy=task-status]").should("have.text", "DELIVERED");
cy.get("[data-cy=task-timeRiderHome-button]").should("be.enabled");
cy.get("[data-cy=task-timeRiderHome-button]").click();
cy.get("[data-cy=confirmation-ok-button]").click();
cy.get("[data-cy=task-status]").should("have.text", "COMPLETED");
});
});
This is the Cypress code. A lot of it applies to my app and not the example I made, but it might be helpful anyway.
The Cypress test is interesting because in this case the network tab shows what looks like a correct mutation, but the observer returns the status in the top bar back to delivered:
The test also passes because the UI does show completed for a moment before the observer catches up and puts it back to delivered.
But the dynamodb record has the incorrect status again:
This mismatch of recorded data seems to be reproducible for every run of the test.
Edit to add: not sure if it's helpful too but these are the the unit tests that demonstrate exactly what I'm doing with DataStore underneath https://github.com/platelet-app/platelet/blob/master/src/scenes/Task/components/TaskActions.test.js
@duckbytes thank you for this. We have determined the issue is due to a comparison problem between changed fields on the clients and the network response when using AutoMerge. We have a plan to solve this but it will take some care on our side for this scenario with testing. In the meantime if you are blocked on this particular behavior we would suggest switching your Conflict Resolution strategy to Optimistic Concurrency rather than AutoMerge if possible.
Thanks @undefobj switching to optimistic concurrency looks to have fixed it.
Hello, allow me to join this discussion to say that indeed we were facing a problem without understanding the cause. Eventually I stumbled across this thread and came to the same conclusion. We are developing a stock management application and unfortunately the inconsistencies that have arisen affect the satisfaction of our customers. Amplify is a wonderful tool and we appreciate the efforts made so far to resolve the issues we are having. We are still waiting for a definitive solution. Regards
@frankarnaud thank you! We are currently focused on completing and releasing support for Custom Primary & Composite Keys in DataStore. However, the work for this fix is already up for review and will be scheduled for released afterwards. Please stay tuned for more updates!
We too have an issue with DataStore thinking that all of the records have been synced to cloud (sending outboxStatus event with empty payload), but in reality these records are not persisted in DynamoDB. This often happens when we use our application in an area with poor network connectivity. Everything works when the app is completely online or completely offline. Things start breaking when the network connection varies in strength (e.g. good connection - bad connection - no connection - etc). Most of our users use the app in these network conditions. We tried following the suggestion in this thread and switched to Optimistic Concurrency conflict resolution strategy, but it seems to have little effect.
Steps to reproduce: drive out of town until you get 3G cell signal with 0-2 bars. Create 100 entities in DataStore while walking in a line between two spots where signal strength varies. Return to the area with good Internet connection and observe up to 10% of the records missing in DynamoDB. Even after returning to good Internet connection, DataStore will not attempt to sync the remaining records as it thinks that there is nothing left to sync.
Since this was a critical blocker for us, we ended up writing custom logic that listens for DataStore event that claims all records are synced. It then queries all model types and iterates over the results to find records with _version === undefined. For each such record, we submit a worker that calls AppSync API to create the record, then DataStore.query with that record ID predicate to force refresh it with the latest values. This is using AUTO_MERGE conflict resolution strategy. We are also using a token-based retry strategy in case we go offline and the worker is not able to complete its job.
We also found an easier way to achieve the described end result. In Chrome:
- Go offline in Network profiles
- Clear cookies in Application tab
- Create a model via DataStore
- Go online (no throttling)
- Refresh the page
- Login
DataStore will send an event indicating that there is nothing to sync, but the un-synced model record will remain stored in the local IndexedDB table with undefined _version etc. attributes.
The PR with the fix for this issue has been reviewed and approved, soon to be released in the coming weeks. I would keep an eye on that PR, we will later comment here when the fix is officially available.
@chrisbonifacio Sorry if this was miscommunicated, but that PR doesn't doesn't solve this problem. It solves a problem with .clear() and .stop() that was interfering with the reproduction of this problem in the test suite.
But, @iartemiev is starting work on the fix today, which we may initially release under a tag for testing.
Are there downsides or considerations to take when using optimistic concurrency until this is fixed?
I found documentation here about writing a conflict resolution function https://docs.amplify.aws/lib/datastore/conflict/q/platform/js/#custom-configuration
Is there any recommended logic to use there until we can go back to using auto-merge?
@svidgen Just to confirm, will @iartemiev work address the issue with the DataStore missing propagation of local updates to AppSync on spotty Internet connection? Have you been able to reproduce it? The fact that switching conflict resolution to optimistic concurrency helped some users but not others makes me wonder if there are two different issues.
Are there downsides or considerations to take when using optimistic concurrency until this is fixed?
I found documentation here about writing a conflict resolution function https://docs.amplify.aws/lib/datastore/conflict/q/platform/js/#custom-configuration
Is there any recommended logic to use there until we can go back to using auto-merge?
@duckbytes Not sure if this helps, but switching to optimistic concurrency broke our auto-increment logic where we issue an empty GraphQL update to atomically increment the Counter model _version attribute. To make it work with optimistic concurrency, we would have to query the record first for the latest _version, then make an update with the latest _version value known to client. This could fail if there are many concurrent updates on the same record as it is prone to race conditions.
Optimistic concurrency didn't resolve the DataStore issue for us, so we simply switched back to auto-merge.
Has there been any progress or new information on this issue? Or potential workarounds?
I'm having some difficulty with optimistic concurrency and trying to resolve conflicts manually, as well as coming up against bugs (https://github.com/aws-amplify/amplify-js/issues/11708). I'd like to try auto-merge again if possible.
@duckbytes - We have a plan to improve the experience with Auto Merge but it is still work in progress due to the underlying complexity of the fix. Our recommendation in general, is to use Optimistic Concurrency. I understand that you're facing bug #11708 and we'll investigate that in parallel to unblock you from continuing to use optimistic concurrency.
Hello @duckbytes,
We really appreciate the time and detail you've put into this issue. A fix was merged this week and is now available on "aws-amplify": "unstable" which resolves the sequencing bug for several of my sample apps; constructed based on your notes.
This fix will be published to latest with the next release, currently scheduled for today. I'll be doing more testing around this on my end. If you have the opportunity to test against unstable today or latest for any aws-amplify version > 6.0.11, it would be good to get your confirmation that the problem is fixed for your app as well.
Thanks! Aaron
Thanks very much @stocaaro for your work on this!
My web version is still on Amplify V4 because of the breaking changes in DataStore, so I won't be able to switch over to automerge and test until I can do the work to migrate everything over. The smartphone app is on Amplify V5 though, so I will get that up to date soon.
Sounds good @duckbytes,
From the testing I’ve done, I believe this problem is solved in the current V6 release. I’m going to close this issue. If you get your applications updated and are seeing issues that look related in any way, please comment here (or on a new issue linked back to this one) with details.
Thanks, Aaron