Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Slow observeQuery Performance #2730

Open
1 task done
tylerjroach opened this issue Mar 7, 2024 · 2 comments
Open
1 task done

Slow observeQuery Performance #2730

tylerjroach opened this issue Mar 7, 2024 · 2 comments
Assignees
Labels
bug Something isn't working datastore DataStore category/plugins

Comments

@tylerjroach
Copy link
Contributor

Before opening, please confirm:

Language and Async Model

Java

Amplify Categories

DataStore

Gradle script dependencies

DataStore v1.37.3 - v2.14.10

Environment information

DataStore v1.37.3 - v2.14.10

Please include any relevant guides or documentation you're referencing

No response

Describe the bug

Report from customer below....

Observed on all the Android versions from v1.37.3 - v2.14.10

According to the documentation observeQuery first publishes the initial snapshot of the locally available data and then emits the new data whenever there is any update. We have around ~1k results locally available and the observeQuery is taking anywhere between 3 - 30 seconds to post the initial snapshot of the local data. The same behavior is noticed with query (expected as the documentation says the first snapshot of observeQuery is same as Query) as well.

If the same data is available in a standalone sqlite database table, the query returns in few milliseconds and the data is shown on the screen immediately.

When tried to debug it looks like "queryOfflineData()" block of code from SqlQueryProcessor.java is taking up a chunk of time to map the cursor data to actual model class ( cursor item -> Map -> Json string -> actual model). But the load time fluctuating between 3-30seconds is not clear and we are assuming its because of some caching at a different layer.

So is this expected behavior with local datastore db? The local data that is readily available on the device taking around ~20seconds to get published? Is there anything that we are missing here? We can't see any logs to figure out what is happening internally. Anyone else seeing this issue on your end?

One possible solution is to only request a subset of data ( pagination) and implement indefinite scroll type of feature, but we got to show few filters and graphs which would need the entire dataset.

Reproduction steps (if applicable)

No response

Code Snippet

// Put your code below this line.

Log output

// Put your logs below this line


amplifyconfiguration.json

No response

GraphQL Schema

// Put your schema below this line

Additional information and screenshots

Amplify datastore version - 2.14.11

All the results are locally available on the device. 
Turned on the airplane mode before invoking the observeQuery. 


SECTION 1: 1000 results
OBSERVATIONS:
	On a cold start - consistently taking 8seconds 
	On a hot start - Took 4secs 

2024-02-29 10:21:17.734  7011-7011  Testing123              samplepackage         I  fetchResults observeQuery:: Thread[main,5,main]
2024-02-29 10:21:25.448  7011-7664  Testing123              samplepackage         I  Callback: Started observeQuery:: Thread[pool-38-thread-5,5,main]
2024-02-29 10:21:25.449  7011-7664  Testing123              samplepackage         I  Callback:: snapshopSize:: 1004, Thread:: Thread[pool-38-thread-5,5,main]

2024-02-29 10:21:47.780  7011-7011  Testing123              samplepackage         I  fetchResults observeQuery:: Thread[main,5,main]
2024-02-29 10:21:51.663  7011-7690  Testing123              samplepackage         I  Callback: Started observeQuery:: Thread[pool-38-thread-6,5,main]
2024-02-29 10:21:51.663  7011-7690  Testing123              samplepackage         I  Callback:: snapshopSize:: 1004, Thread:: Thread[pool-38-thread-6,5,main]

---------------------------- PROCESS ENDED (7011) for package samplepackage ----------------------------
---------------------------- PROCESS STARTED (7744) for package samplepackage ----------------------------

2024-02-29 10:22:18.577  7744-7744  Testing123              samplepackage         I  fetchResults observeQuery:: Thread[main,5,main]
2024-02-29 10:22:26.764  7744-7969  Testing123              samplepackage         I  Callback: Started observeQuery:: Thread[pool-38-thread-5,5,main]
2024-02-29 10:22:26.764  7744-7969  Testing123              samplepackage         I  Callback:: snapshopSize:: 1004, Thread:: Thread[pool-38-thread-5,5,main]


SECTION 2 : 3000 results
OBSERVATIONS:
	On a cold start - consistently taking ~15 seconds 
	On a hot start - Took ~5secs

---------------------------- PROCESS STARTED (11561) for package samplepackage ----------------------------
2024-02-29 11:30:48.880 11561-11561 Testing123              samplepackage         I  fetchResults observeQuery:: Thread[main,5,main]
2024-02-29 11:31:03.803 11561-12007 Testing123              samplepackage         I  Callback: Started observeQuery:: Thread[pool-38-thread-10,5,main]
2024-02-29 11:31:03.803 11561-12007 Testing123              samplepackage         I  Callback:: snapshopSize:: 3011, Thread:: Thread[pool-38-thread-10,5,main]

2024-02-29 11:31:18.183 11561-11561 Testing123              samplepackage         I  fetchResults observeQuery:: Thread[main,5,main]
2024-02-29 11:31:23.715 11561-12036 Testing123              samplepackage         I  Callback: Started observeQuery:: Thread[pool-38-thread-11,5,main]
2024-02-29 11:31:23.716 11561-12036 Testing123              samplepackage         I  Callback:: snapshopSize:: 3011, Thread:: Thread[pool-38-thread-11,5,main]

---------------------------- PROCESS ENDED (11561) for package samplepackage ----------------------------
---------------------------- PROCESS STARTED (12080) for package samplepackage ----------------------------

2024-02-29 11:31:48.638 12080-12080 Testing123              samplepackage         I  fetchResults observeQuery:: Thread[main,5,main]
2024-02-29 11:32:03.564 12080-12302 Testing123              samplepackage         I  Callback: Started observeQuery:: Thread[pool-37-thread-5,5,main]
2024-02-29 11:32:03.565 12080-12302 Testing123              samplepackage         I  Callback:: snapshopSize:: 3011, Thread:: Thread[pool-37-thread-5,5,main]

NOTE: Even with the airplane mode turned off, we are seeing the same load times.
@github-actions github-actions bot added the pending-triage Issue is pending triage label Mar 7, 2024
@tylerjroach tylerjroach added bug Something isn't working datastore DataStore category/plugins and removed pending-triage Issue is pending triage labels Mar 7, 2024
@tylerjroach
Copy link
Contributor Author

Marking this as a bug while we investigate what expected time should be. If we determine that speed is much slower than expected, we should leave as a bug.

@mattcreaser
Copy link
Contributor

The performance of query/observeQuery has been improved in Amplify 2.17.0. There may be room for additional optimizations but apps should notice some improvement after upgrading to that version. The amount of improvement depends heavily on the actual structure of the data being queried - models with many fields and relationships will see a larger benefit than those with few.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working datastore DataStore category/plugins
Projects
None yet
Development

No branches or pull requests

3 participants