StackOverflowError in WorkManager on KitKat [129091233]

Fixed

Bug

Status Update

No update yet.

Description

ka...@gmail.com

created issue #1

Mar 22, 2019 02:16PM

Component used: android.arch.work:work-runtime
Version used: 1.0.0-rc01
Devices/Android versions reproduced on: We've seen it on 4.4.4 and 4.4.2

We haven't been able to reproduce this ourselves, but we're seeing it show up in our tracking. There's a StackOverflowError caused somewhere inside WorkManager. Here's the stack trace we get:

Fatal Exception: java.lang.StackOverflowError
at java.util.HashMap.secondaryHash(HashMap.java:350)
at java.util.LinkedHashMap.get(LinkedHashMap.java:251)
at android.util.LruCache.get(LruCache.java:118)
at android.database.sqlite.SQLiteConnection.acquirePreparedStatement(SQLiteConnection.java:1100)
at android.database.sqlite.SQLiteConnection.prepare(SQLiteConnection.java:689)
at android.database.sqlite.SQLiteSession.prepare(SQLiteSession.java:588)
at android.database.sqlite.SQLiteProgram.(SQLiteProgram.java:58)
at android.database.sqlite.SQLiteQuery.(SQLiteQuery.java:37)
at android.database.sqlite.SQLiteDirectCursorDriver.query(SQLiteDirectCursorDriver.java:44)
at android.database.sqlite.SQLiteDatabase.rawQueryWithFactory(SQLiteDatabase.java:1433)
at android.database.sqlite.SQLiteDatabase.rawQueryWithFactory(SQLiteDatabase.java:1408)
at android.arch.persistence.db.framework.FrameworkSQLiteDatabase.query(myapp:161)
at android.arch.persistence.room.RoomDatabase.query(myapp:233)
at androidx.work.impl.model.DependencyDao_Impl.getDependentWorkIds(myapp:117)
at androidx.work.impl.WorkerWrapper.recursivelyFailWorkAndDependents(myapp:503)
<snip ~50 recursive frames>
at androidx.work.impl.WorkerWrapper.recursivelyFailWorkAndDependents(myapp:503)
at androidx.work.impl.WorkerWrapper.setFailedAndResolve(myapp:488)
at androidx.work.impl.WorkerWrapper.runWorker(myapp:242)
at androidx.work.impl.WorkerWrapper.run(myapp:127)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
at java.lang.Thread.run(Thread.java:841)

#0. Crashed: WorkManager-WorkManagerTaskExecutor-thread-0
at java.util.HashMap.secondaryHash(HashMap.java:350)
at java.util.LinkedHashMap.get(LinkedHashMap.java:251)
at android.util.LruCache.get(LruCache.java:118)
at android.database.sqlite.SQLiteConnection.acquirePreparedStatement(SQLiteConnection.java:1100)
at android.database.sqlite.SQLiteConnection.prepare(SQLiteConnection.java:689)
at android.database.sqlite.SQLiteSession.prepare(SQLiteSession.java:588)
at android.database.sqlite.SQLiteProgram.(SQLiteProgram.java:58)
at android.database.sqlite.SQLiteQuery.(SQLiteQuery.java:37)
at android.database.sqlite.SQLiteDirectCursorDriver.query(SQLiteDirectCursorDriver.java:44)
at android.database.sqlite.SQLiteDatabase.rawQueryWithFactory(SQLiteDatabase.java:1433)
at android.database.sqlite.SQLiteDatabase.rawQueryWithFactory(SQLiteDatabase.java:1408)
at android.arch.persistence.db.framework.FrameworkSQLiteDatabase.query(myapp:161)
at android.arch.persistence.room.RoomDatabase.query(myapp:233)

Comments

su...@google.com <su...@google.com> #2Mar 22, 2019 06:32PM

Can you please send us a test app which can reproduce this ?

ka...@gmail.com <ka...@gmail.com> #3Mar 22, 2019 07:31PM

Project: platform/frameworks/support
Branch: androidx-master-dev

commit 5975b62cd1f3f170bb82e9761efca40e5e5bfb16
Author: Rahul Ravikumar <rahulrav@google.com>
Date: Wed Jul 24 12:24:17 2019

TaskExecutor's background executor is now SerialExecutor.

* This gives us visibility into the number of pending tasks which will
be important in the next CL.

There is a race condition between the SerialExecutor draining its queue
of pending tasks and SystemAlarmDispatcher's onAllCommandsCompleted() callback.
This is because SystemAlarmDispatcher thinks there are no more things to be
done even though there are pending runnables in the SerialExecutor.
This CL makes this information available. In the next CL, CommandHandler
will check for pending runnables in the SerialExecutor queue.
(

b/138238197

)

* Fixed TestWorkManagerImpl to use Configuration#getTaskExecutor().
* Updated unit tests.

Test: Updated unit tests.
Change-Id: I5f32f1e1ef2563d4598934aed3b61d62a6d6167c

M work/workmanager-gcm/src/androidTest/java/androidx/work/impl/background/gcm/WorkManagerGcmDispatcherTest.kt
M work/workmanager-ktx/src/androidTest/java/androidx/work/CoroutineWorkerTest.kt
M work/workmanager-rxjava2/src/test/java/androidx/work/RxWorkerTest.kt
M work/workmanager-testing/src/androidTest/java/androidx/work/testing/WorkManagerInitHelperTest.java
M work/workmanager-testing/src/main/java/androidx/work/testing/InstantWorkTaskExecutor.java
M work/workmanager-testing/src/main/java/androidx/work/testing/TestWorkManagerImpl.java
M work/workmanager-testing/src/main/java/androidx/work/testing/WorkManagerTestInitHelper.java
M work/workmanager/src/androidTest/java/androidx/work/impl/utils/taskexecutor/InstantWorkTaskExecutor.java
M work/workmanager/src/main/java/androidx/work/impl/utils/SerialExecutor.java
M work/workmanager/src/main/java/androidx/work/impl/utils/taskexecutor/TaskExecutor.java
M work/workmanager/src/main/java/androidx/work/impl/utils/taskexecutor/WorkManagerTaskExecutor.java

https://android-review.googlesource.com/1090749

https://goto.google.com/android-sha1/5975b62cd1f3f170bb82e9761efca40e5e5bfb16

su...@google.com <su...@google.com> #4Mar 22, 2019 08:25PM

There is a 2nd change that fixes the problem.

ka...@gmail.com <ka...@gmail.com> #5Mar 22, 2019 08:40PM

Project: platform/frameworks/support
Branch: androidx-master-dev

commit 7db27318ea09ae3857a7baebe8dd4e6fa9d16fdc
Author: Rahul Ravikumar <rahulrav@google.com>
Date: Wed Jul 24 12:50:34 2019

Ensure SerialExecutor has no more pending tasks.

* We need to ensure this is the case because we might shutdown
SystemAlarmService without actually completing all the tasks.

Test: Existing unit tests pass. Ran integration tests.
Fixes:

b/138238197

Change-Id: I72fe2ddb1607995721eae320ce41accad93fee8f

M work/workmanager/src/main/java/androidx/work/impl/background/systemalarm/SystemAlarmDispatcher.java
M work/workmanager/src/main/java/androidx/work/impl/utils/SerialExecutor.java

https://android-review.googlesource.com/1090758

https://goto.google.com/android-sha1/7db27318ea09ae3857a7baebe8dd4e6fa9d16fdc

[Deleted User] <[Deleted User]> #6Mar 24, 2019 01:23PM

Awesomme! Thanks for the fix

su...@google.com <su...@google.com> #7Mar 28, 2019 08:09PM

Marked as fixed, reassigned to su...@google.com.

The following changes were cherrypicked through Coastguard (

https://android-build.googleplex.com/coastguard/)
Release Track: (

https://android-build.googleplex.com/coastguard/dashboard/6206758647365632/#/cherrypickHistory/all)
Created: 2019-07-26 23:31:17.300138+00:00
Changes: aosp/1092373, aosp/1092374

ka...@gmail.com <ka...@gmail.com> #8Mar 28, 2019 08:38PM

Hi,

I used 2.2.0-RC1 and the issue still persists but not as frequent as before.

08-14 11:38:59.141 975-987/ A/PowerManager: WakeLock finalized while still held: WorkManager: bd0a17b6-e87a-4c44-bb7f-6ae195975b36 (2)
08-14 11:39:02.588 975-1102/com.yantranet.signware.agent.staging E/WM-SystemAlarmDispatche: Unexpected error in onHandleIntent
java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@3b835a4f rejected from java.util.concurrent.ScheduledThreadPoolExecutor@48bb5dc[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0]
at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2011)
at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:793)
at java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:298)
at java.util.concurrent.ScheduledThreadPoolExecutor.schedule(ScheduledThreadPoolExecutor.java:503)
at java.util.concurrent.Executors$DelegatedScheduledExecutorService.schedule(Executors.java:644)
at androidx.work.impl.background.systemalarm.WorkTimer.startTimer(WorkTimer.java:82)
at androidx.work.impl.background.systemalarm.DelayMetCommandHandler.onAllConstraintsMet(DelayMetCommandHandler.java:135)
at androidx.work.impl.background.systemalarm.DelayMetCommandHandler.handleProcessWork(DelayMetCommandHandler.java:211)
at androidx.work.impl.background.systemalarm.CommandHandler.handleDelayMet(CommandHandler.java:272)
at androidx.work.impl.background.systemalarm.CommandHandler.onHandleIntent(CommandHandler.java:171)
at androidx.work.impl.background.systemalarm.SystemAlarmDispatcher$1.run(SystemAlarmDispatcher.java:276)
at androidx.work.impl.utils.SerialExecutor$Task.run(SerialExecutor.java:91)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
at java.lang.Thread.run(Thread.java:818)
08-14 11:39:44.850 975-987/ A/PowerManager: WakeLock finalized while still held: WorkManager: 348bf17e-7aa4-48df-b88e-a2e7e3b5483d (2)

su...@google.com <su...@google.com> #9Mar 28, 2019 09:11PM

Can you please give us a sample app that reproduces this problem?

ka...@gmail.com <ka...@gmail.com> #10Mar 29, 2019 11:44AM

Also, are you sure the app in question was using the recent version of WM ?