aws-amplify / amplify-android

The fastest and easiest way to use AWS from your Android app.
https://docs.amplify.aws/lib/q/platform/android/
Apache License 2.0
245 stars 114 forks source link

Timed out while starting to observe storage changes #1359

Closed oras closed 3 years ago

oras commented 3 years ago

Before opening, please confirm:

Language and Async Model

Java

Amplify Categories

DataStore

Gradle script dependencies

```groovy dependencies { implementation fileTree(dir: 'libs', include: ['*.jar']) implementation 'androidx.appcompat:appcompat:1.3.0' implementation 'androidx.constraintlayout:constraintlayout:2.0.4' testImplementation 'junit:junit:4.12' androidTestImplementation 'androidx.test.ext:junit:1.1.2' androidTestImplementation 'androidx.test.espresso:espresso-core:3.3.0' implementation 'com.google.android.material:material:1.3.0' implementation 'com.amplifyframework:aws-analytics-pinpoint:1.17.6' implementation 'com.amplifyframework:aws-api:1.17.6' implementation 'com.amplifyframework:aws-auth-cognito:1.17.6' implementation 'com.amplifyframework:aws-datastore:1.17.6' implementation 'com.amplifyframework:aws-predictions:1.17.6' implementation 'com.amazonaws:aws-android-sdk-apigateway-core:2.15.0' // Support for Java 8 features coreLibraryDesugaring 'com.android.tools:desugar_jdk_libs:1.1.5' } ```

Environment information

``` # Put output below this line Android Studio Arctic Fox | 2020.3.1 Beta 3 Build #AI-203.7717.56.2031.7395685, built on May 25, 2021 Runtime version: 11.0.10+0-b96-7249189 amd64 VM: OpenJDK 64-Bit Server VM by Oracle Corporation Windows 10 10.0 GC: G1 Young Generation, G1 Old Generation Memory: 1280M Cores: 4 Registry: external.system.auto.import.disabled=true Gradle 6.5 ------------------------------------------------------------ Build time: 2020-06-02 20:46:21 UTC Revision: a27f41e4ae5e8a41ab9b19f8dd6d86d7b384dad4 Kotlin: 1.3.72 Groovy: 2.5.11 Ant: Apache Ant(TM) version 1.10.7 compiled on September 1 2019 JVM: 1.8.0_231 (Oracle Corporation 25.231-b11) OS: Windows 10 10.0 amd64 ```

Please include any relevant guides or documentation you're referencing

No response

Describe the bug

Although the authentication was success, I can't save or load any new data from\to cloud (dynamoDB). I am trying to query without loading from local datastore.

Reproduction steps (if applicable)

No response

Code Snippet

 public void saveToDataStore(Vaccine vaccine)
    {
         if(mSaveVaccineLock.tryLock()) {
             try {
                 Executors.newCachedThreadPool().submit(() ->
                 {
                     try
                     {
                         com.amplifyframework.datastore.generated.model.Vaccine vaccineData = com.amplifyframework.
                                 datastore.generated.model.Vaccine.builder()
                                 .name(vaccine.getName())
                                 .vaccine(vaccine.getVaccine())
                                 .provider(vaccine.getProvider())
                                 .bottleVol(Math.round(vaccine.getBottleVol() * 100))
                                 .lowTempC(vaccine.getLowTempC())
                                 .highTempC(vaccine.getHighTempC())
                                 .build();

                         Amplify.DataStore.save(
                                 vaccineData,
                                 success -> onSuccessfulAdd(vaccine),
                                 error -> {
                                     Log.e("DataStore", "Could not save program to DataStore",
                                             error);
                                     if(mListener != null)
                                     {
                                         mListener.onUpdate(UpdateDataStoreCodeEnum.ERROR,
                                                 error.getMessage());
                                     }
                                 }
                         );

                     }
                     catch (Exception e)
                     {

                     }
                 });
             } catch (Exception e) {

             }
             finally
             {
                 mSaveVaccineLock.unlock();
             }
         }
    }

Log output

``` // Put your logs below this line waitForSignIn: userState:SIGNED_IN getCredentials: Validated user is signed-in I/Choreographer: Skipped 52 frames! The application may be doing too much work on its main thread. I/OpenGLRenderer: Davey! duration=1119ms; Flags=1, IntendedVsync=175534886153, Vsync=176401552785, OldestInputEvent=9223372036854775807, NewestInputEvent=0, HandleInputStart=176405272454, AnimationStart=176405319573, PerformTraversalsStart=176407459597, DrawStart=176603502091, SyncQueued=176604145362, SyncStart=176604191174, IssueDrawCommandsStart=176617608312, SwapBuffers=176648932108, FrameCompleted=176654236404, DequeueBufferDuration=59000, QueueBufferDuration=207000, I/com.sysmop.dov: Background concurrent copying GC freed 46817(2MB) AllocSpace objects, 32(1664KB) LOS objects, 49% free, 5MB/10MB, paused 14.159ms total 2.676s W/com.sysmop.dov: Verification of java.lang.Object kotlin.SynchronizedLazyImpl.writeReplace() took 110.727ms D/EGL_emulation: eglMakeCurrent: 0x705604b32000: ver 2 0 (tinfo 0x705604aee960) D/EGL_emulation: eglMakeCurrent: 0x705604b32000: ver 2 0 (tinfo 0x705604aee960) I/Choreographer: Skipped 34 frames! The application may be doing too much work on its main thread. I/OpenGLRenderer: Davey! duration=1010ms; Flags=1, IntendedVsync=177929852482, Vsync=178013185812, OldestInputEvent=9223372036854775807, NewestInputEvent=0, HandleInputStart=178014338236, AnimationStart=178014375601, PerformTraversalsStart=178014574144, DrawStart=178588658416, SyncQueued=178588822781, SyncStart=178590147004, IssueDrawCommandsStart=178590198442, SwapBuffers=178933046054, FrameCompleted=178941620241, DequeueBufferDuration=80000, QueueBufferDuration=286000, D/EGL_emulation: eglMakeCurrent: 0x705604b32000: ver 2 0 (tinfo 0x705604aee960) D/EGL_emulation: eglMakeCurrent: 0x705604b32000: ver 2 0 (tinfo 0x705604aee960) I/OpenGLRenderer: Davey! duration=984ms; Flags=0, IntendedVsync=178021044039, Vsync=178587710683, OldestInputEvent=9223372036854775807, NewestInputEvent=0, HandleInputStart=178599649612, AnimationStart=178599700179, PerformTraversalsStart=178601460844, DrawStart=178944459834, SyncQueued=178944486632, SyncStart=179006133706, IssueDrawCommandsStart=179006182270, SwapBuffers=179060281952, FrameCompleted=179067648699, DequeueBufferDuration=58000, QueueBufferDuration=239000, D/EGL_emulation: eglMakeCurrent: 0x705604b32000: ver 2 0 (tinfo 0x705604aee960) D/EGL_emulation: eglMakeCurrent: 0x705604b32000: ver 2 0 (tinfo 0x705604aee960) D/EGL_emulation: eglMakeCurrent: 0x705604b32000: ver 2 0 (tinfo 0x705604aee960) D/EGL_emulation: eglMakeCurrent: 0x705604b32000: ver 2 0 (tinfo 0x705604aee960) D/OpenGLRenderer: endAllActiveAnimators on 0x7055f06e8b00 (RippleDrawable) with handle 0x7055f48e1c60 D/EGL_emulation: eglMakeCurrent: 0x705604b32000: ver 2 0 (tinfo 0x705604aee960) W/com.sysmop.dov: Accessing hidden method Landroid/widget/PopupWindow;->setEpicenterBounds(Landroid/graphics/Rect;)V (light greylist, linking) W/com.sysmop.dov: Accessing hidden method Landroid/widget/PopupWindow;->setTouchModal(Z)V (light greylist, linking) Accessing hidden method Landroid/widget/PopupWindow;->setClipToScreenEnabled(Z)V (light greylist, reflection) W/com.sysmop.dov: Accessing hidden field Landroid/widget/AbsListView;->mIsChildViewEnabled:Z (light greylist, reflection) D/EGL_emulation: eglMakeCurrent: 0x705604b32000: ver 2 0 (tinfo 0x705604aee960) I/chatty: uid=10069(com.sysmop.dov) RenderThread identical 2 lines D/EGL_emulation: eglMakeCurrent: 0x705604b32000: ver 2 0 (tinfo 0x705604aee960) D/EGL_emulation: eglMakeCurrent: 0x705604b32000: ver 2 0 (tinfo 0x705604aee960) D/EGL_emulation: eglMakeCurrent: 0x705604b32000: ver 2 0 (tinfo 0x705604aee960) I/chatty: uid=10069(com.sysmop.dov) RenderThread identical 2 lines D/EGL_emulation: eglMakeCurrent: 0x705604b32000: ver 2 0 (tinfo 0x705604aee960) D/EGL_emulation: eglMakeCurrent: 0x705604b32000: ver 2 0 (tinfo 0x705604aee960) D/EGL_emulation: eglMakeCurrent: 0x705604b32000: ver 2 0 (tinfo 0x705604aee960) I/Choreographer: Skipped 32 frames! The application may be doing too much work on its main thread. D/EGL_emulation: eglMakeCurrent: 0x705604b32000: ver 2 0 (tinfo 0x705604aee960) D/EGL_emulation: eglMakeCurrent: 0x705604b32000: ver 2 0 (tinfo 0x705604aee960) I/com.sysmop.dov: Background concurrent copying GC freed 85780(3MB) AllocSpace objects, 12(428KB) LOS objects, 49% free, 6MB/12MB, paused 18us total 3.669s I/com.sysmop.dov: Background concurrent copying GC freed 137900(5MB) AllocSpace objects, 0(0B) LOS objects, 45% free, 7MB/13MB, paused 360us total 1.285s W/com.sysmop.dov: Verification of io.reactivex.rxjava3.functions.Action io.reactivex.rxjava3.internal.functions.Functions.notificationOnComplete(io.reactivex.rxjava3.functions.Consumer) took 105.325ms I/amplify:aws-datastore: Orchestrator lock acquired. I/amplify:aws-datastore: Orchestrator transitioning from STOPPED to SYNC_VIA_API Starting to observe local storage changes. E/DataStore: Could not save program to DataStore DataStoreException{message=Failed to start DataStore., cause=DataStoreException{message=Timed out while starting to observe storage changes., cause=java.util.concurrent.TimeoutException: Timed out while preparing local-only mode., 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.}, recoverySuggestion=Retry.} at com.amplifyframework.datastore.AWSDataStorePlugin.lambda$start$11(AWSDataStorePlugin.java:285) at com.amplifyframework.datastore.-$$Lambda$AWSDataStorePlugin$cggRMfd1LBrEzQR62lPbVtwdUwY.accept(Unknown Source:4) at io.reactivex.rxjava3.internal.observers.CallbackCompletableObserver.onError(CallbackCompletableObserver.java:64) at io.reactivex.rxjava3.internal.operators.completable.CompletableSubscribeOn$SubscribeOnObserver.onError(CompletableSubscribeOn.java:74) at io.reactivex.rxjava3.internal.operators.completable.CompletableAndThenCompletable$NextObserver.onError(CompletableAndThenCompletable.java:104) at io.reactivex.rxjava3.internal.operators.completable.CompletableDoFinally$DoFinallyObserver.onError(CompletableDoFinally.java:72) at io.reactivex.rxjava3.internal.operators.completable.CompletableFromAction.subscribeActual(CompletableFromAction.java:40) at io.reactivex.rxjava3.core.Completable.subscribe(Completable.java:2850) at io.reactivex.rxjava3.internal.operators.completable.CompletableDoFinally.subscribeActual(CompletableDoFinally.java:43) at io.reactivex.rxjava3.core.Completable.subscribe(Completable.java:2850) at io.reactivex.rxjava3.internal.operators.completable.CompletableAndThenCompletable$SourceObserver.onComplete(CompletableAndThenCompletable.java:67) at io.reactivex.rxjava3.internal.operators.completable.CompletablePeek$CompletableObserverImplementation.onComplete(CompletablePeek.java:115) at io.reactivex.rxjava3.internal.operators.completable.CompletableSubscribeOn$SubscribeOnObserver.onComplete(CompletableSubscribeOn.java:79) at io.reactivex.rxjava3.internal.operators.completable.CompletableTimeout$TimeOutObserver.onComplete(CompletableTimeout.java:87) at io.reactivex.rxjava3.internal.operators.completable.CompletableFromAction.subscribeActual(CompletableFromAction.java:47) at io.reactivex.rxjava3.core.Completable.subscribe(Completable.java:2850) at io.reactivex.rxjava3.internal.operators.completable.CompletableTimeout.subscribeActual(CompletableTimeout.java:53) at io.reactivex.rxjava3.core.Completable.subscribe(Completable.java:2850) at io.reactivex.rxjava3.internal.operators.completable.CompletableSubscribeOn$SubscribeOnObserver.run(CompletableSubscribeOn.java:64) at io.reactivex.rxjava3.core.Scheduler$DisposeTask.run(Scheduler.java:614) 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:764) Caused by: DataStoreException{message=Timed out while starting to observe storage changes., cause=java.util.concurrent.TimeoutException: Timed out while preparing local-only mode., 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.syncengine.Orchestrator.startObservingStorageChanges(Orchestrator.java:277) at com.amplifyframework.datastore.syncengine.Orchestrator.transitionToApiSync(Orchestrator.java:251) at com.amplifyframework.datastore.syncengine.Orchestrator.lambda$start$0$Orchestrator(Orchestrator.java:158) at com.amplifyframework.datastore.syncengine.-$$Lambda$Orchestrator$qjDvX8bU79JsBLU0hHve6y1vGzc.run(Unknown Source:2) at io.reactivex.rxjava3.internal.operators.completable.CompletableFromAction.subscribeActual(CompletableFromAction.java:36) ... 20 more Caused by: java.util.concurrent.TimeoutException: Timed out while preparing local-only mode. at com.amplifyframework.datastore.syncengine.Orchestrator.startObservingStorageChanges(Orchestrator.java:274) ... 24 more ```

amplifyconfiguration.json

{
    "UserAgent": "aws-amplify-cli/2.0",
    "Version": "1.0",
    "api": {
        "plugins": {
            "awsAPIPlugin": {
                "DOV": {
                    "endpointType": "REST",
                    "endpoint": "https://xxxxxx.execute-api.eu-central-1.amazonaws.com/dev",
                    "region": "eu-central-1",
                    "authorizationType": "AWS_IAM"
                },
                "dovaws": {
                    "endpointType": "GraphQL",
                    "endpoint": "https://xxxxxxxxx.appsync-api.eu-central-1.amazonaws.com/graphql",
                    "region": "eu-central-1",
                    "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": "eu-central-1:eb0a2a31-xxxxxxxx",
                            "Region": "eu-central-1"
                        }
                    }
                },
                "CognitoUserPool": {
                    "Default": {
                        "PoolId": "eu-central-1_xxxxxxx",
                        "AppClientId": "xxxxxxx",
                        "Region": "eu-central-1",
                        "AppClientSecret": "xxxxxxxxxx"
                    }
                },
                "Auth": {
                    "Default": {
                        "authenticationFlowType": "USER_SRP_AUTH"
                    }
                },
                "AppSync": {
                    "Default": {
                        "ApiUrl": "https://xxxxxxx.appsync-api.eu-central-1.amazonaws.com/graphql",
                        "Region": "eu-central-1",
                        "AuthMode": "AMAZON_COGNITO_USER_POOLS",
                        "ClientDatabasePrefix": "dovaws_AMAZON_COGNITO_USER_POOLS"
                    }
                },
                "S3TransferUtility": {
                    "Default": {
                        "Bucket": "app91812-dev",
                        "Region": "eu-central-1"
                    }
                }
            }
        }
    },
    "storage": {
        "plugins": {
            "awsS3StoragePlugin": {
                "bucket": "app91812-dev",
                "region": "eu-central-1",
                "defaultAccessLevel": "guest"
            }
        }
    }
}

GraphQL Schema

```graphql // Put your schema below this line enum DosageType{ RED GREEN WHITE BLUE YELLOW } enum UserType{ BASIC, ADMIN } enum InjectionType{ SINGLE, DOUBULE, TRIPLE } enum InjectionMethod{ STANDARD } enum InjectionMode{ MANUAL, AUTOMATIC } type Program @model { id: ID! program_name : String! vaccine1_id: String! vaccine1_t: DosageType! vaccine1_v: Int! injection1_v: Int! bottle1_v: Int! vaccine2_id: String! vaccine2_t: DosageType! vaccine2_v: Int! injection2_v: Int! bottle2_v: Int! spray_id: String! spray_t: DosageType! spray_v: Int! spray_injection_v: Int! spray_bottle_v: Int! day_counter: Int! batch_counter: Int! replace_param: String! temp_range: String! location: String! } type Vaccine @model { id: ID! name: String! vaccine: String! provider: String! bottle_vol: Int! low_temp_c: Int! high_temp_c: Int! } type Notification @model { id: ID! Machine_ID: String! description: String! } type GlobalVariables @model { id: ID! machine_id: String! firmware_id: String! machine_location: String! vaccine_temp_min_live: Int! vaccine_temp_max_live: Int! vaccine_temp_min_inactive: Int! vaccine_temp_max_inactive: Int! needle_replacement: Int! chicks_per_box_setup: Int! pressure_thresh_min: Int! pressure_thresh_max: Int! temp_format: Boolean! releas_station: Boolean! new_update: Boolean! } type Log @model { id: ID! date_time: String! device_id: Int! injection_count: Int! average_injection_rate: Int! operation_error: Int! operation_success: Int! injection_location: String! dosage_bottle1: Int! batch_number: Int! dosage_bottle2: Int! batch_number2: Int! injection_type_detial: InjectionType! inject_method: InjectionMethod! injection_mode: InjectionMode! top_location_name: String! section_location_name: String! flock_name: String! record_editor: String! elapse_time: Int! } type Device @model { id: ID! device_id: Int! date_time: String! primary_sw_ver: Int! secondary_sw_ver: Int! } type Parameters @model { id: ID! language: String! bottle1_v: Int! vaccine1_id: String! injection1_v: Int! bottle2_v: Int! vaccine2_id: String! injection2_v: Int! bottle_spray_v: Int! spray_id: String! injection_spray_v: Int! location: String! machine_id: Int! date_time: Int! new_update: Boolean! } type Versions @model { id: ID! date_time: String! primary_sw_ver: Int! primary_sw_ver_info: String! secondary_fw_ver: Int! secondary_fw_ver_info: String! dowload_url: String! } ```

Additional information and screenshots

No response

oras commented 3 years ago

The only thing that work for me was doing a small change in the graphQl schema and push it to the cloud. There is a better way to go around it ?

In mode that can be a lot of data on the server it's can be a problem.

sach16795 commented 3 years ago

Hello, can you please share how you were able to resolve this issue? Running into a similar exception.

oras commented 3 years ago

Hi @sach16795, Just do a small change in the local schem and push it to the cloud.