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.

Sign up for GitHub

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

Jump to bottom

Crash due CursorWindow exception which results in a OutOfMemoryError #140

Closed
gyurme-accedo opened this issue Apr 3, 2019 · 5 comments
Closed

Crash due CursorWindow exception which results in a OutOfMemoryError #140

gyurme-accedo opened this issue Apr 3, 2019 · 5 comments
Assignees
@minbi
Labels
bug Something isn't working

Comments

@gyurme-accedo
Copy link

gyurme-accedo commented Apr 3, 2019 •
edited
Loading

Overview
We've noticed a sporadic bug where our app crashes with the following stack trace when the app is in the middle of a download (from CDN links we receive after user pool authentication with AWS appsync)

To Reproduce
Steps to reproduce the behavior:

  1. The app authenticates via Appsync with a specific user pool
  2. A graphql query is run to retrieve CDN links which have an expiry date on them
  3. A download tries to kick off
  4. A crash occurs
  5. note: this is an app designed for kiosk like behaviour so it is running in the foreground most of the time for hours, memory analysis does not show significantly increasing memory usage

Stack Trace

04-03 11:06:06.102 24396-24646/*redacted*.debug E/CursorWindow: Could not allocate CursorWindow '/data/data/*redacted*.debug/databases/appsyncstore' of size 2097152 due to error -12.
04-03 11:06:06.103 24396-24396/*redacted*.debug D/ContentUpdateLogger: Content Update Manifest Retrieved Successfully. Details are: 
04-03 11:06:06.105 24396-24396/*redacted*.debug D/ContentUpdateLogger: Content Update Started. Details are: 
04-03 11:06:06.482 24396-24396/*redacted*.debug D/ContentUpdateLogger: Program Update Started. Details are: Currently updating *redacted*
04-03 11:06:06.484 24396-24396/*redacted*.debug D/ContentUpdateLogger: Releases Update Started. Details are: Currently updating releases for *redacted*
04-03 11:06:06.497 24396-24396/*redacted*.debug D/ContentUpdateLogger: Release Update Started. Details are: Currently updating *redacted*
04-03 11:06:06.499 24396-24396/*redacted*.debug D/ContentUpdateLogger: Trailer And Gif Update Started. Details are: 
04-03 11:06:06.504 24396-24396/*redacted*.debug D/ContentUpdateLogger: Asset Download Started. Details are: 
04-03 11:06:06.521 24396-24396/*redacted*.debug D/AssetDownloader: started https://cdn.*redacted*.gif
04-03 11:06:07.719 24396-24396/*redacted*.debug D/AssetDownloader: connected https://cdn.*redacted*.gif
04-03 11:06:07.899 24396-24396/*redacted*.debug D/AssetDownloader: onProgress https://cdn.*redacted*.gif
04-03 11:06:07.900 24396-24396/*redacted*.debug D/AssetDownloader: Total downloaded 0/21 mb - 0 %
04-03 11:06:07.931 24396-24396/*redacted*.debug D/AssetDownloader: connected https://cdn.*redacted*.gif
04-03 11:06:08.768 24396-24396/*redacted*.debug D/AssetDownloader: connected https://cdn.*redacted*.gif
04-03 11:06:10.914 24396-24396/*redacted*.debug D/AssetDownloader: onProgress https://cdn.*redacted*.gif
04-03 11:06:10.914 24396-24396/*redacted*.debug D/AssetDownloader: Total downloaded 2/21 mb - 13 %
04-03 11:06:12.228 24396-24661/*redacted*.debug D/MetadataUtil: Skipped unknown metadata entry: hdvd
04-03 11:06:12.228 24396-24661/*redacted*.debug D/MetadataUtil: Skipped unknown metadata entry: stik
04-03 11:06:12.661 24396-24662/*redacted*.debug D/MetadataUtil: Skipped unknown metadata entry: hdvd
04-03 11:06:12.661 24396-24662/*redacted*.debug D/MetadataUtil: Skipped unknown metadata entry: stik
04-03 11:06:13.708 24396-24605/*redacted*.debug W/libc: pthread_create failed: couldn't allocate 1064960-byte stack: Out of memory
04-03 11:06:13.708 24396-24605/*redacted*.debug E/art: Throwing OutOfMemoryError "pthread_create (1040KB stack) failed: Try again"
04-03 11:06:13.739 24396-24437/*redacted*.debug D/SensorManager: aidl getSensorManager:null
04-03 11:06:13.883 24396-24437/*redacted*.debug W/libc: pthread_create failed: couldn't allocate 1064960-byte stack: Out of memory
04-03 11:06:13.883 24396-24437/*redacted*.debug E/art: Throwing OutOfMemoryError "pthread_create (1040KB stack) failed: Try again"
04-03 11:06:13.904 24396-24605/*redacted*.debug E/AndroidRuntime: FATAL EXCEPTION: ExoPlayerImplInternal:Handler
    Process: *redacted*.debug, PID: 24396
    java.lang.OutOfMemoryError: pthread_create (1040KB stack) failed: Try again
        at java.lang.Thread.nativeCreate(Native Method)
        at java.lang.Thread.start(Thread.java:1063)
        at java.util.concurrent.ThreadPoolExecutor.addWorker(ThreadPoolExecutor.java:920)
        at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1327)
        at java.util.concurrent.Executors$DelegatedExecutorService.execute(Executors.java:583)
        at com.google.android.exoplayer2.upstream.Loader$LoadTask.execute(Loader.java:414)
        at com.google.android.exoplayer2.upstream.Loader$LoadTask.start(Loader.java:282)
        at com.google.android.exoplayer2.upstream.Loader.startLoading(Loader.java:175)
        at com.google.android.exoplayer2.source.ExtractorMediaPeriod.startLoading(ExtractorMediaPeriod.java:658)
        at com.google.android.exoplayer2.source.ExtractorMediaPeriod.prepare(ExtractorMediaPeriod.java:210)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.maybeUpdateLoadingPeriod(ExoPlayerImplInternal.java:1495)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.updatePeriods(ExoPlayerImplInternal.java:1367)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.doSomeWork(ExoPlayerImplInternal.java:495)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:301)
        at android.os.Handler.dispatchMessage(Handler.java:98)
        at android.os.Looper.loop(Looper.java:135)
        at android.os.HandlerThread.run(HandlerThread.java:61)
04-03 11:06:13.929 24396-24396/*redacted*.debug D/AssetDownloader: onProgress https://cdn.*redacted*.gif
04-03 11:06:13.929 24396-24396/*redacted*.debug D/AssetDownloader: Total downloaded 7/21 mb - 37 %
04-03 11:06:14.051 24396-24396/*redacted*.debug D/ViewRootImpl: 1920<<<<<< BACK FROM relayoutWM.LayoutParams{(0,0)(fillxfill)mPosX=0mPosY=0mHScale=1.0mVScale=1.0 align=UNDEFINE taskId=75 sim=#20 ty=1 fl=#81810100 fmt=-3 wanim=0x1030469 vsysui=0x1300 surfaceInsets=Rect(0, 0 - 0, 0) needsMenuKey=2packageName=*redacted*.debugtoken=android.os.BinderProxy@21f74b12}
04-03 11:06:15.479 24396-24437/*redacted*.debug I/CrashlyticsCore: Crashlytics report upload complete: 5CA3D8AB003A-0001-5F4C-FA3C80AB05B6
04-03 11:06:16.774 24396-24658/*redacted*.debug W/libc: pthread_create failed: couldn't allocate 1064960-byte stack: Out of memory
04-03 11:06:16.775 24396-24658/*redacted*.debug E/art: Throwing OutOfMemoryError "pthread_create (1040KB stack) failed: Try again"
04-03 11:06:16.780 24396-24657/*redacted*.debug W/libc: pthread_create failed: couldn't allocate 1064960-byte stack: Out of memory
04-03 11:06:16.781 24396-24657/*redacted*.debug E/art: Throwing OutOfMemoryError "pthread_create (1040KB stack) failed: Try again"
04-03 11:06:18.639 24396-24659/*redacted*.debug W/libc: pthread_create failed: couldn't allocate 1064960-byte stack: Out of memory
04-03 11:06:18.639 24396-24659/*redacted*.debug E/art: Throwing OutOfMemoryError "pthread_create (1040KB stack) failed: Try again"

Environment(please complete the following information):

  • AppSync SDK Version: 2.6.21 , testing with 2.7.8 now

Device Information (please complete the following information):

  • Device: GloryStar Nebula Tablet
  • Android Version: 5.1.1

Additional context
We ran the app in strict mode for analysis and saw multiple warnings

Code
We instantiate a new instance of the aws client whenever we need to authenicate or make a query

fun generateAWSClient(context: Context, serverRegion: String, serverUrl: String, userPool: CognitoUserPool): AWSAppSyncClient {
        val basicCognitoUserPoolsAuthProvider = BasicCognitoUserPoolsAuthProvider(userPool)
        val client = AWSAppSyncClient.builder()
                .context(context)
                .region(Regions.fromName(serverRegion))
                .serverUrl(serverUrl)
                .cognitoUserPoolsAuthProvider(basicCognitoUserPoolsAuthProvider)
                .build()
        return client

run a query for the content manifest which gives us our cdn links to download and thats about it, are we meant to be running a cleanup step for the client?

appSyncClient?.query(query)
                ?.responseFetcher(AppSyncResponseFetchers.NETWORK_ONLY)
                ?.enqueue(object : GraphQLCall.Callback<ContentManifestQuery.Data>() {
                    override fun onResponse(response: Response<ContentManifestQuery.Data>) {

                        uiThreadHandler.post {
                            if (!response.hasErrors()) {
                                onSuccess(response.data()?.console)
                            } else {
                                val error = response.errors().toString()
                                Timber.e(error)
                                onFailure(error)
                            }
                        }
                    }

                    override fun onFailure(e: ApolloException) {
                        uiThreadHandler.post {
                            onFailure(e.message)
                            Timber.e(e)
                        }
                    }
                })
@gyurme-accedo
Copy link
Author

When running our app in strict mode we receive the following warnings:

04-03 15:23:24.901 28329-28341/*redacted*.dev.debug E/StrictMode: A resource was acquired at attached stack trace but never released. See java.io.Closeable for information on avoiding resource leaks.
    java.lang.Throwable: Explicit termination method 'close' not called
        at dalvik.system.CloseGuard.open(CloseGuard.java:184)
        at android.database.CursorWindow.<init>(CursorWindow.java:111)
        at android.database.AbstractWindowedCursor.clearOrCreateWindow(AbstractWindowedCursor.java:198)
        at android.database.sqlite.SQLiteCursor.fillWindow(SQLiteCursor.java:139)
        at android.database.sqlite.SQLiteCursor.getCount(SQLiteCursor.java:133)
        at android.database.AbstractCursor.moveToPosition(AbstractCursor.java:197)
        at android.database.AbstractCursor.moveToFirst(AbstractCursor.java:237)
        at com.amazonaws.mobileconnectors.appsync.AppSyncMutationSqlCacheOperations.fetchAllRecords(AppSyncMutationSqlCacheOperations.java:102)
        at com.amazonaws.mobileconnectors.appsync.PersistentOfflineMutationManager.fetchPersistentMutationsList(PersistentOfflineMutationManager.java:74)
        at com.amazonaws.mobileconnectors.appsync.PersistentOfflineMutationManager.<init>(PersistentOfflineMutationManager.java:42)
        at com.amazonaws.mobileconnectors.appsync.AppSyncOfflineMutationManager.<init>(AppSyncOfflineMutationManager.java:181)
        at com.amazonaws.mobileconnectors.appsync.AWSAppSyncClient.<init>(AWSAppSyncClient.java:112)
        at com.amazonaws.mobileconnectors.appsync.AWSAppSyncClient.<init>(AWSAppSyncClient.java:60)
        at com.amazonaws.mobileconnectors.appsync.AWSAppSyncClient$Builder.build(AWSAppSyncClient.java:300)
        at *redacted*.utils.AWSUtil.generateAWSClient(AWSUtil.kt:23)
        at *redacted*.networking.NetworkClient.onUserAuthenticated(NetworkClient.kt:83)
        at *redacted*.networking.NetworkClient$authenticate$authHandler$1$onSuccess$1.run(NetworkClient.kt:41)
        at android.os.Handler.handleCallback(Handler.java:739)
        at android.os.Handler.dispatchMessage(Handler.java:95)
        at android.os.Looper.loop(Looper.java:135)
        at android.app.ActivityThread.main(ActivityThread.java:5280)
        at java.lang.reflect.Method.invoke(Native Method)
        at java.lang.reflect.Method.invoke(Method.java:372)
        at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:963)
        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:758)
04-03 15:23:24.902 28329-28341/*redacted*.dev.debug E/StrictMode: Finalizing a Cursor that has not been deactivated or closed. database = /data/data/*redacted*.dev.debug/databases/appsyncstore_mutation, table = mutation_records, query = SELECT _id, record_id, record, response_class, client_state, bucket, key, region, local_uri, mime_type FROM mutation_records ORDER BY _id
    android.database.sqlite.DatabaseObjectNotClosedException: Application did not close the cursor or database object that was opened here
        at android.database.sqlite.SQLiteCursor.<init>(SQLiteCursor.java:98)
        at android.database.sqlite.SQLiteDirectCursorDriver.query(SQLiteDirectCursorDriver.java:50)
        at android.database.sqlite.SQLiteDatabase.rawQueryWithFactory(SQLiteDatabase.java:1316)
        at android.database.sqlite.SQLiteDatabase.queryWithFactory(SQLiteDatabase.java:1163)
        at android.database.sqlite.SQLiteDatabase.query(SQLiteDatabase.java:1034)
        at android.database.sqlite.SQLiteDatabase.query(SQLiteDatabase.java:1202)
        at com.amazonaws.mobileconnectors.appsync.AppSyncMutationSqlCacheOperations.fetchAllRecords(AppSyncMutationSqlCacheOperations.java:99)
        at com.amazonaws.mobileconnectors.appsync.PersistentOfflineMutationManager.fetchPersistentMutationsList(PersistentOfflineMutationManager.java:74)
        at com.amazonaws.mobileconnectors.appsync.PersistentOfflineMutationManager.<init>(PersistentOfflineMutationManager.java:42)
        at com.amazonaws.mobileconnectors.appsync.AppSyncOfflineMutationManager.<init>(AppSyncOfflineMutationManager.java:181)
        at com.amazonaws.mobileconnectors.appsync.AWSAppSyncClient.<init>(AWSAppSyncClient.java:112)
        at com.amazonaws.mobileconnectors.appsync.AWSAppSyncClient.<init>(AWSAppSyncClient.java:60)
        at com.amazonaws.mobileconnectors.appsync.AWSAppSyncClient$Builder.build(AWSAppSyncClient.java:300)
        at *redacted*.utils.AWSUtil.generateAWSClient(AWSUtil.kt:23)
        at *redacted*.networking.NetworkClient.onUserAuthenticated(NetworkClient.kt:83)
        at *redacted*.networking.NetworkClient$authenticate$authHandler$1$onSuccess$1.run(NetworkClient.kt:41)
        at android.os.Handler.handleCallback(Handler.java:739)
        at android.os.Handler.dispatchMessage(Handler.java:95)
        at android.os.Looper.loop(Looper.java:135)
        at android.app.ActivityThread.main(ActivityThread.java:5280)
        at java.lang.reflect.Method.invoke(Native Method)
        at java.lang.reflect.Method.invoke(Method.java:372)
        at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:963)
        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:758)

@alanvan0502 alanvan0502 mentioned this issue Apr 3, 2019
Merged
@gyurme-accedo
Copy link
Author

Awesome thanks for the quick fix guys, any chance we can get a ETA on the next release that has this fix? We have a release of our own that needs it :)

@minbi minbi self-assigned this Apr 4, 2019
@minbi minbi added AppSync bug Something isn't working labels Apr 4, 2019
@minbi
Copy link
Contributor

minbi commented Apr 6, 2019

Hi,

Please see if SDK release 2.7.9 fixes this issue for you. We have added the following:

Fixed a bug that caused cursors to remain open in certain scenarios.

You may see all changes in the changelog

@minbi minbi added the pending-response Issue is pending response from the issue requestor label Apr 6, 2019
@gyurme-accedo
Copy link
Author

Thanks guys, we did some stress testing over multiple devices and it looks good to us.

@stale stale bot removed the closing-soon label Apr 9, 2019
@minbi
Copy link
Contributor

minbi commented Apr 9, 2019

Thanks for verifying, closing. Please feel free to open a new issue if the problem persists. We ask this because closed issues are not actively monitored.

Thanks

@minbi minbi closed this as completed Apr 9, 2019
@minbi minbi removed the pending-response Issue is pending response from the issue requestor label Apr 9, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@minbi minbi

Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@minbi @rohandubal @gyurme-accedo