amplify-android: [DataStore] Not getting results on the first query after a fresh login

Before opening, please confirm:

Language and Async Model

Kotlin - Coroutines

Amplify Categories

DataStore

Gradle script dependencies

// Put output below this line

    // Amplify
    implementation 'com.amplifyframework:core-kotlin:0.15.1'
    implementation 'com.amplifyframework:aws-api:1.31.1'
    // Datastore
    implementation 'com.amplifyframework:aws-datastore:1.31.3'
    // Support for Java 8 features
    coreLibraryDesugaring 'com.android.tools:desugar_jdk_libs:1.1.5'
    // Cognito
    implementation 'com.amplifyframework:aws-auth-cognito:1.31.1'

Environment information

# Put output below this line

Welcome to Gradle 7.2!

Here are the highlights of this release:
 - Toolchain support for Scala
 - More cache hits when Java source files have platform-specific line endings
 - More resilient remote HTTP build cache behavior

For more details see https://docs.gradle.org/7.2/release-notes.html


------------------------------------------------------------
Gradle 7.2
------------------------------------------------------------

Build time:   2021-08-17 09:59:03 UTC
Revision:     a773786b58bb28710e3dc96c4d1a7063628952ad

Kotlin:       1.5.21
Groovy:       3.0.8
Ant:          Apache Ant(TM) version 1.10.9 compiled on September 27 2020
JVM:          17.0.1 (Oracle Corporation 17.0.1+12-39)
OS:           Mac OS X 12.1 aarch64


Please include any relevant guides or documentation you’re referencing

https://github.com/aws-amplify/amplify-android/issues/802#issuecomment-728280343

Describe the bug

I am trying to use DataStore on my Kotlin based Android App. I am facing an issue where the first query after a fresh login doesn’t show results for even a simple query. I am trying to Query a Customer with a given ID. It should be a trivial case but I am unable to access the results until I re-launch the app or re-launch the query. On the first launch, I can see multiple “Sync Failed” messages in the logs.

I checked the AmplifyDatastore.db file that is created on the local storage and it seems like it gets all the values even on the first try but my code does not display it after the query. I found an issue on GitHub which shows a similar problem: https://github.com/aws-amplify/amplify-android/issues/802#issuecomment-721895666

As suggested by the solution on the GitHub link, I am trying to start a Subscription for the SYNC_QUERIES_READY event but when I do that, although I am successfully getting the data, my app seems to get stuck on the Subscription event code (attached to this issue) for about 10 seconds. Waiting for so long is an extremely bad experience for my end user. I think this wait is because DataStore gets all the related data at once. For example, when I query 1 customer, I get about 100 entries from multiple tables which are related to the queried customer.

Another issue: The attached code is sitting on my LoginFragment.kt file. Inside the Event Subscription, after I get the SYNC_QUERIES_READY event, I am running the query and once I “collect” data, I am proceeding to the Dashboard Activity. However, on my first login after a fresh launch, even though the query inside the Subscription (as shown in the attached code) is able to display values, when I proceed to the Dashboard activity and run the same query again, I don’t get any data again. This time I don’t get any errors or feedback of any sort. And the same query still gives no data on the Dashboard activity even on consecutive launches. The only way I was able to get the query on my Dashboard to work was to Sign Out and Sign In again (without re-launching the app) and go through the entire process of waiting for SYNC_QUERIES_READY event and then proceeding to the Dashboard activity and querying again and this time it works.

Note that I am using DataStore.clear() followed by Amplify.Auth.signOut() calls inside my SignOut() function which means that my local db is cleared on sign out.

I am just wondering if there is another way of doing this, preferably without waiting for 10 seconds and ideally without Subscribing to the SYNC_QUERIES_READY event on DataStore. I would also be open to selective queries to get just the queried data and not everything related to it at the same time.

Reproduction steps (if applicable)

  1. Create a relational schema and populate each table with multiple entries
  2. Run a simple query on an object which is related to multiple other objects.
  3. On your first ever query, you won’t be able to see any of your queried data. However, if you check your device’s local database, it will be fully populated.
  4. Now, run the query again. You’ll be able to see data this time.
  5. To solve the previous issue: clear your local database. In your code, start an event subscription and wait for the SYNC_QUERIES_READY event call. Inside the event call, try running the query again. This time you’ll still see the same errors but also be able to see results. However, it takes very very very long.
  6. You can see the attached code for subscription event.

Code Snippet

// Put your code below this line.

suspend fun firstQuery() {
        val uid: String = UserInfo.getInstance().getUID()

        // Ignore results from this query as instructed in https://github.com/aws-amplify/amplify-android/issues/802#issuecomment-728280343
        Amplify.DataStore.query(
            Customer::class,
            Where.matches(Customer.ID.eq(uid))
        )
            .catch { Log.e("DataStore", "Error in query: ", it) }
            .collect {
                Log.d("DataStore", "IGNORE RESULTS - Query: id: ${it.id} name: ${it.customerFirstName}")
            }

        // Start Subscription to DataStore events
        Amplify.Hub.subscribe(HubChannel.DATASTORE).collect { hubEvent ->
            when (hubEvent.name) {
                DataStoreChannelEventName.SYNC_QUERIES_READY.toString() -> {
                    Amplify.DataStore.query(
                        Customer::class,
                        Where.matches(Customer.ID.eq(uid))
                    )
                        .catch { Log.e("DataStore", "Error in query: ", it) }
                        .collect {
                            Log.d("DataStore", "Query completed successfully.: id: ${it.id} name: ${it.customerFirstName}")
                            launchDashboard()
                        }
                }
            }
        }
    }

Log output

// Put your logs below this line

> Before event subscription

> On First login (local db empty):

I/amplify:aws-datastore: Orchestrator lock acquired.
I/amplify:aws-datastore: Orchestrator transitioning from STOPPED to SYNC_VIA_API
I/amplify:aws-datastore: Starting to observe local storage changes.
I/amplify:aws-datastore: Now observing local storage. Local changes will be enqueued to mutation outbox.
I/amplify:aws-datastore: Setting currentState to LOCAL_ONLY
I/amplify:aws-datastore: Setting currentState to SYNC_VIA_API
I/amplify:aws-datastore: Orchestrator lock released.
I/AmplifyService: DataStore started
I/amplify:aws-datastore: Starting API synchronization mode.
I/amplify:aws-datastore: Orchestrator lock acquired.
I/amplify:aws-datastore: Orchestrator lock released.
I/amplify:aws-datastore: Starting processing subscription events.
I/amplify:aws-datastore: Started subscription processor for models: [Site, Customer,  Animal] of types [ON_CREATE, ON_UPDATE, ON_DELETE].
W/amplify:aws-datastore: Sync failed: foreign key constraint violation: ModelWithMetadata{model=Site {id=34567890, owner=1234561, ……, customer=Customer {id=12345, owner=13243, ….’}, syncMetadata=ModelMetadata{id='Site|12345916b', _deleted=null, _version=2, _lastChangedAt=Temporal.Timestamp{timestamp=1644537738124}}}

    DataStoreException{message=Invalid SQL statement: INSERT INTO `Site` (`id`, `createdAt`, `owner`, …………, `updatedAt`, `customer_id`) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?), cause=android.database.sqlite.SQLiteConstraintException: FOREIGN KEY constraint failed (code 787 SQLITE_CONSTRAINT_FOREIGNKEY), recoverySuggestion=There is a possibility that there is a bug if this error persists. Please take a look at 
    https://github.com/aws-amplify/amplify-android/issues to see if there are any existing issues that 
    match your scenario, and file an issue with the details of the bug if there isn't.}
        at com.amplifyframework.datastore.storage.sqlite.SQLCommandProcessor.dataStoreException(SQLCommandProcessor.java:86)
        at com.amplifyframework.datastore.storage.sqlite.SQLCommandProcessor.execute(SQLCommandProcessor.java:81)
        at com.amplifyframework.datastore.storage.sqlite.SQLiteStorageAdapter.writeData(SQLiteStorageAdapter.java:759)
2022-02-15 13:46:36.923 20291-20700/com.example.onecupai W/amplify:aws-datastore:     at com.amplifyframework.datastore.storage.sqlite.SQLiteStorageAdapter.lambda$save$3$com-amplifyframework-datastore-storage-sqlite-SQLiteStorageAdapter(SQLiteStorageAdapter.java:364)
        at com.amplifyframework.datastore.storage.sqlite.SQLiteStorageAdapter$$ExternalSyntheticLambda5.run(Unknown Source:12)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:458)
        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:764)
     Caused by: android.database.sqlite.SQLiteConstraintException: FOREIGN KEY constraint failed (code 787 SQLITE_CONSTRAINT_FOREIGNKEY)
        at android.database.sqlite.SQLiteConnection.nativeExecute(Native Method)
        at android.database.sqlite.SQLiteConnection.execute(SQLiteConnection.java:569)
        at android.database.sqlite.SQLiteSession.execute(SQLiteSession.java:619)
        at android.database.sqlite.SQLiteStatement.execute(SQLiteStatement.java:44)
        at com.amplifyframework.datastore.storage.sqlite.SQLCommandProcessor.execute(SQLCommandProcessor.java:77)
        	... 8 more
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
W/amplify:aws-datastore: Sync failed: foreign key constraint violation: ModelWithMetadata{model=Animal …………..




> On Second Login (local db already populated on first login:

I/amplify:aws-datastore: Orchestrator lock acquired.
I/amplify:aws-datastore: Orchestrator transitioning from STOPPED to SYNC_VIA_API
I/amplify:aws-datastore: Starting to observe local storage changes.
I/amplify:aws-datastore: Now observing local storage. Local changes will be enqueued to mutation outbox.
I/amplify:aws-datastore: Setting currentState to LOCAL_ONLY
I/amplify:aws-datastore: Setting currentState to SYNC_VIA_API
I/amplify:aws-datastore: Orchestrator lock released.
I/AmplifyService: DataStore started
I/amplify:aws-datastore: Starting API synchronization mode.
I/amplify:aws-datastore: Starting processing subscription events.
I/amplify:aws-datastore: Orchestrator lock acquired.
I/amplify:aws-datastore: Orchestrator lock released.
D/DataStore: Query completed successfully.: id: 12345 name:  Firstname Lastname
I/amplify:aws-datastore: Started subscription processor for models: [Site, Customer, Animal] of types [ON_CREATE, ON_UPDATE, ON_DELETE].
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Starting processing subscription data buffer.
I/amplify:aws-datastore: Started the orchestrator in API sync mode.
I/amplify:aws-datastore: Started processing the mutation outbox. Pending mutations will be published to the cloud.





> With Subscription event: (1 query followed by nested query inside Subscription event)

> First login:

I/amplify:aws-datastore: Orchestrator lock acquired.
I/amplify:aws-datastore: Orchestrator transitioning from STOPPED to SYNC_VIA_API
I/amplify:aws-datastore: Starting to observe local storage changes.
I/amplify:aws-datastore: Now observing local storage. Local changes will be enqueued to mutation outbox.
I/amplify:aws-datastore: Setting currentState to LOCAL_ONLY
I/amplify:aws-datastore: Setting currentState to SYNC_VIA_API
I/amplify:aws-datastore: Orchestrator lock released.
I/AmplifyService: DataStore started
I/amplify:aws-datastore: Starting API synchronization mode.
I/amplify:aws-datastore: Orchestrator lock acquired.
I/amplify:aws-datastore: Orchestrator lock released.
I/amplify:aws-datastore: Starting processing subscription events.
I/amplify:aws-datastore: Started subscription processor for models: [Site, Customer, Animal] of types [ON_CREATE, ON_UPDATE, ON_DELETE].
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
W/amplify:aws-datastore: Sync failed: foreign key constraint violation: ModelWithMetadata{model=Animal {......
W/amplify:aws-datastore: DataStoreException{message=Invalid SQL statement: INSERT INTO `Animal` (`id`, ..... `customer_id`, `herd_id`, `site_id`) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?), cause=android.database.sqlite.SQLiteConstraintException: FOREIGN KEY constraint failed (code 787 SQLITE_CONSTRAINT_FOREIGNKEY), recoverySuggestion=There is a possibility that there is a bug if this error persists. Please take a look at 
    https://github.com/aws-amplify/amplify-android/issues to see if there are any existing issues that 
    match your scenario, and file an issue with the details of the bug if there isn't.}
    at com.amplifyframework.datastore.storage.sqlite.SQLCommandProcessor.dataStoreException(SQLCommandProcessor.java:86)
        at com.amplifyframework.datastore.storage.sqlite.SQLCommandProcessor.execute(SQLCommandProcessor.java:81)
        at com.amplifyframework.datastore.storage.sqlite.SQLiteStorageAdapter.writeData(SQLiteStorageAdapter.java:759)
        at com.amplifyframework.datastore.storage.sqlite.SQLiteStorageAdapter.lambda$save$3$com-amplifyframework-datastore-storage-sqlite-SQLiteStorageAdapter(SQLiteStorageAdapter.java:364)
        at com.amplifyframework.datastore.storage.sqlite.SQLiteStorageAdapter$$ExternalSyntheticLambda5.run(Unknown Source:12)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:458)
        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:764)
     Caused by: android.database.sqlite.SQLiteConstraintException: FOREIGN KEY constraint failed (code 787 SQLITE_CONSTRAINT_FOREIGNKEY)
        at android.database.sqlite.SQLiteConnection.nativeExecute(Native Method)
        at android.database.sqlite.SQLiteConnection.execute(SQLiteConnection.java:569)
        at android.database.sqlite.SQLiteSession.execute(SQLiteSession.java:619)
        at android.database.sqlite.SQLiteStatement.execute(SQLiteStatement.java:44)
        at com.amplifyframework.datastore.storage.sqlite.SQLCommandProcessor.execute(SQLCommandProcessor.java:77)
        at com.amplifyframework.datastore.storage.sqlite.SQLiteStorageAdapter.writeData(SQLiteStorageAdapter.java:759) 
        at com.amplifyframework.datastore.storage.sqlite.SQLiteStorageAdapter.lambda$save$3$com-amplifyframework-datastore-storage-sqlite-SQLiteStorageAdapter(SQLiteStorageAdapter.java:364) 
        at com.amplifyframework.datastore.storage.sqlite.SQLiteStorageAdapter$$ExternalSyntheticLambda5.run(Unknown Source:12) 
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:458) 
        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:764) 
W/amplify:aws-datastore: Sync failed: foreign key constraint violation: ModelWithMetadata{model=Animal ........
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Orchestrator lock acquired.
I/amplify:aws-datastore: Orchestrator lock released.
I/amplify:aws-datastore: Starting processing subscription data buffer.
I/amplify:aws-datastore: Started the orchestrator in API sync mode.
I/amplify:aws-datastore: Started processing the mutation outbox. Pending mutations will be published to the cloud.
D/DataStore: Query completed successfully.: id: 123456 name:  Firstname Lastname


> On second/consecutive logins:

I/amplify:aws-datastore: Orchestrator lock acquired.
I/amplify:aws-datastore: Orchestrator transitioning from STOPPED to SYNC_VIA_API
I/amplify:aws-datastore: Starting to observe local storage changes.
I/amplify:aws-datastore: Now observing local storage. Local changes will be enqueued to mutation outbox.
I/amplify:aws-datastore: Setting currentState to LOCAL_ONLY
I/amplify:aws-datastore: Setting currentState to SYNC_VIA_API
I/amplify:aws-datastore: Orchestrator lock released.
I/AmplifyService: DataStore started
I/amplify:aws-datastore: Starting API synchronization mode.
I/amplify:aws-datastore: Starting processing subscription events.
I/amplify:aws-datastore: Orchestrator lock acquired.
I/amplify:aws-datastore: Orchestrator lock released.
D/DataStore: IGNORE RESULTS Query completed successfully.: id: 12345 name:  Firstname Lastname
I/amplify:aws-datastore: Started subscription processor for models: [Site, Customer, Animal] of types [ON_CREATE, ON_UPDATE, ON_DELETE].
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Successfully sync'd down model state from cloud.
I/amplify:aws-datastore: Starting processing subscription data buffer.
I/amplify:aws-datastore: Started the orchestrator in API sync mode.
I/amplify:aws-datastore: Started processing the mutation outbox. Pending mutations will be published to the cloud.
D/DataStore: Query completed successfully.: id: 123456 name:  Firstname Lastname

amplifyconfiguration.json

{ “UserAgent”: “aws-amplify-cli/2.0”, “Version”: “1.0”, “api”: { “plugins”: { “awsAPIPlugin”: { “portal”: { “endpointType”: “GraphQL”, “endpoint”: “https://[id].appsync-api.us-west-2.amazonaws.com/graphql”, “region”: “us-west-2”, “authorizationType”: “AMAZON_COGNITO_USER_POOLS” } } } }, “auth”: { “plugins”: { “awsCognitoAuthPlugin”: { “UserAgent”: “aws-amplify-cli/0.1.0”, “Version”: “0.1.0”, “IdentityManager”: { “Default”: {} }, “CredentialsProvider”: { “CognitoIdentity”: { “Default”: { “PoolId”: “”, “Region”: “us-west-2” } } }, “CognitoUserPool”: { “Default”: { “PoolId”: “”, “AppClientId”: “”, “Region”: “us-west-2” } }, “Auth”: { “Default”: { “authenticationFlowType”: “USER_SRP_AUTH”, “socialProviders”: [], “usernameAttributes”: [ “EMAIL” ], “signupAttributes”: [ “EMAIL” ], “passwordProtectionSettings”: { “passwordPolicyMinLength”: 8, “passwordPolicyCharacters”: [ “REQUIRES_LOWERCASE”, “REQUIRES_UPPERCASE”, “REQUIRES_NUMBERS”, “REQUIRES_SYMBOLS” ] }, “mfaConfiguration”: “OFF”, “mfaTypes”: [], “verificationMechanisms”: [ “EMAIL” ] } }, “AppSync”: { “Default”: { “ApiUrl”: “https://[id].appsync-api.us-west-2.amazonaws.com/graphql”, “Region”: “us-west-2”, “AuthMode”: “AMAZON_COGNITO_USER_POOLS”, “ClientDatabasePrefix”: “portal_AMAZON_COGNITO_USER_POOLS” }, “portal_AWS_IAM”: { “ApiUrl”: “https://[id].appsync-api.us-west-2.amazonaws.com/graphql”, “Region”: “us-west-2”, “AuthMode”: “AWS_IAM”, “ClientDatabasePrefix”: “portal_AWS_IAM” } } } } } }

GraphQL Schema

// Put your schema below this line


Additional information and screenshots

No response

About this issue

  • Original URL
  • State: closed
  • Created 2 years ago
  • Reactions: 1
  • Comments: 49 (9 by maintainers)

Most upvoted comments

I have same issue on flutter as well, after closing app and reopen it loads data. First load after login it is not updating.