IssueTracker

I was able to reproduce this issue. We should have a fix in rc02.

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

commit f1d3eabbb463486932b3f31bfb1bbc49aff8e5e3
Author: Rahul Ravikumar <rahulrav@google.com>
Date:   Tue Feb 19 11:34:51 2019

    Fixes a case where WorkManager needs to reschedule Workers after an unexpected application crash.
   
    * This is different from a traditional force stop scenario. The app crashes while WorkManager is
      managing a WorkRequest. This `Worker` should be retried after the app starts up.
   
    Test: Added unit tests. Ran integration tests.
   
    02-19 11:34:18.142  6344  6344 D WM-PackageManagerHelper: androidx.work.impl.background.systemjob.SystemJobService enabled
    02-19 11:34:18.142  6344  6344 D WM-Schedulers: Created SystemJobScheduler and enabled SystemJobService
    02-19 11:34:18.142  6344  6344 D WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.SystemAlarmService disabled
    02-19 11:34:18.163  6344  6365 D WM-ForceStopRunnable: Found unfinished work, rescheduling.
    02-19 11:34:18.170  6344  6365 D WM-SystemJobScheduler: Skipping scheduling b4d48f2b-e712-4585-8aae-80eed11e0618 because JobScheduler is aware of it already.
    02-19 11:34:18.170  6344  6365 D WM-ForceStopRunnable: Unfinished Workers exist, rescheduling.
    02-19 11:34:18.332  6344  6344 D WM-SystemJobService: onStartJob for b4d48f2b-e712-4585-8aae-80eed11e0618
    02-19 11:34:18.337  6344  6365 D WM-Processor: Processor: processing b4d48f2b-e712-4585-8aae-80eed11e0618
    02-19 11:34:18.338  6344  6365 D WM-WorkerWrapper: Delaying execution for com.perracolabs.workmanagerbug.WorkerTest because it is being executed before schedule.
    02-19 11:34:18.486  6344  6344 D WM-Processor: Processor b4d48f2b-e712-4585-8aae-80eed11e0618 executed; reschedule = true
    02-19 11:34:18.486  6344  6344 D WM-SystemJobService: b4d48f2b-e712-4585-8aae-80eed11e0618 executed on JobScheduler
   
    02-19 11:34:28.514  6344  6344 D WM-SystemJobService: onStartJob for b4d48f2b-e712-4585-8aae-80eed11e0618
    02-19 11:34:28.514  6344  6365 D WM-Processor: Processor: processing b4d48f2b-e712-4585-8aae-80eed11e0618
    02-19 11:34:28.522  6344  6344 D WM-WorkerWrapper: Starting work for com.perracolabs.workmanagerbug.WorkerTest
    02-19 11:34:28.528  6344  6365 D WM-WorkerWrapper: com.perracolabs.workmanagerbug.WorkerTest returned a Success {mOutputData=androidx.work.Data@0} result.
    02-19 11:34:28.529  6344  6365 I WM-WorkerWrapper: Worker result SUCCESS for Work [ id=b4d48f2b-e712-4585-8aae-80eed11e0618, tags={ com.perracolabs.workmanagerbug.WorkerTest } ]
    02-19 11:34:28.530  6344  6365 D WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver disabled
    02-19 11:34:28.534  6344  6344 D WM-Processor: Processor b4d48f2b-e712-4585-8aae-80eed11e0618 executed; reschedule = false
    02-19 11:34:28.534  6344  6344 D WM-SystemJobService: b4d48f2b-e712-4585-8aae-80eed11e0618 executed on JobScheduler
    02-19 11:34:28.535  6344  6365 D WM-GreedyScheduler: Cancelling work ID b4d48f2b-e712-4585-8aae-80eed11e0618
    02-19 11:34:28.537  6344  6365 D WM-Processor: Processor stopping b4d48f2b-e712-4585-8aae-80eed11e0618
    02-19 11:34:28.537  6344  6365 D WM-Processor: WorkerWrapper could not be found for b4d48f2b-e712-4585-8aae-80eed11e0618
    02-19 11:34:28.537  6344  6365 D WM-StopWorkRunnable: StopWorkRunnable for b4d48f2b-e712-4585-8aae-80eed11e0618; Processor.stopWork = false
   
    Fixes: b/124546316
   
    Change-Id: I41cf0b113f4667bcd67efbf62bcbc110ad80103d

M       work/workmanager/src/androidTest/java/androidx/work/impl/utils/ForceStopRunnableTest.java
M       work/workmanager/src/main/java/androidx/work/impl/model/WorkSpecDao.java
M       work/workmanager/src/main/java/androidx/work/impl/utils/ForceStopRunnable.java

https://android-review.googlesource.com/906605
https://goto.google.com/android-sha1/f1d3eabbb463486932b3f31bfb1bbc49aff8e5e3

Thanks for the Rc02 update. I’m still able to reproduce the issue, though the behavior has slightly changed and with this update I must point out that it doesn’t happen all the time yet is still reproducible.

I’ve done the test in a Nexus 5X API 27, and Nexus 6 API 25.

Taking as reference the test project I’ve supplied in the initial report but updated to 1.0.0-rc02, after a first crash I’ve found that sometimes when there is a 1 enqueued worker this one is processed only after submitting new workers into the chain.

After the new workers are submitted everything seems to work fine, besides the fact that I had to submit new ones to force the chain to be processed.

Then, if forcing a second crash the problem reappears and no more workers get processed. Only by killing the app through the launcher the issue disappears once the app is re-opened.

Please find attached a video recording to clarify my explanation. In it I don’t wait too long between the actions just illustrate the issue.

I’ve repeated the test a few times with longer space periods between the actions, just to ensure it isn't some type of delay imposed by the WorkManager. The problem reappears randomly, in some forced crashes everything seems to be fine, and other times the issue reappears.

After the application crashes, and you relaunch it - you will need to wait for the Worker to go into a RUNNING state.
This is because a crash meant that your Worker got backed off and it's only eligible to run after the back off window..

So, I've I understood well, because the worker crashed, in order to get it into a RUNNING state I need to submit new workers into the chain, right?
This would explain that on the first crash only after I submit the new workers everything starts again to correctly be processed.
But, if I force a second crash, then after reopening the app the chain is no longer processed at all, not even submitting new workers into the chain.

OK, I misunderstood your final explanation. I will do a few test more waiting for the back-off period.