Android WorkManager chained work not running on alpha04

Question

[UPDATE] this has been solved in alpha09

I´ve two works that gets chained by the WorkManager alpha04 beginWith and then api´s.

fun updateData() {
   createWorkRequests()
   runDataDownloadWork()
}

private fun createWorkRequests() {
    dwElementsWork = OneTimeWorkRequestBuilder<DWElementsWork>()
            .addTag(TAG_ELEMENTS_WORK)
            .build()
    dwElementTypesWork = OneTimeWorkRequestBuilder<DWElementTypesWork>()
            .addTag(TAG_ELEMENTS_TYPE_WORK)
            .build()
}

private fun runDataDownloadWorkNoStatus() {
    WorkManager.getInstance()!!
            .beginWith(dwElementTypesWork)
            .then(dwElementsWork)
            .enqueue()
}

They get called on my MainActivity.kt file and somethimes just the first one gets executed dwElementTypesWork some other times both, and just in a few cases none of them. Am I missing some configuration? The documentation is pretty straight forward.

This is the logcat output based on the WorkManager log:

06-28 09:28:20.519 28480-28501/com.myapp.app D/SystemJobScheduler: Scheduling work ID 3e5f8531-aa92-4e28-8533-d180612dab02 Job ID 28
06-28 09:28:20.537 28480-28501/com.myapp.app D/GreedyScheduler: Starting tracking for 3e5f8531-aa92-4e28-8533-d180612dab02
06-28 09:28:20.542 28480-28501/com.myapp.app D/ConstraintTracker: NetworkStateTracker: initial state = [ Connected=true Validated=true Metered=false NotRoaming=true ]
06-28 09:28:20.543 28480-28501/com.myapp.app D/NetworkStateTracker: Registering network callback
06-28 09:28:20.549 28480-28501/com.myapp.app D/WorkConstraintsTracker: Constraints met for 3e5f8531-aa92-4e28-8533-d180612dab02
06-28 09:28:20.550 28480-28501/com.myapp.app D/GreedyScheduler: Constraints met: Scheduling work ID 3e5f8531-aa92-4e28-8533-d180612dab02
06-28 09:28:20.551 28480-28501/com.myapp.app D/WorkConstraintsTracker: Constraints met for 3e5f8531-aa92-4e28-8533-d180612dab02
06-28 09:28:20.551 28480-28501/com.myapp.app D/GreedyScheduler: Constraints met: Scheduling work ID 3e5f8531-aa92-4e28-8533-d180612dab02
06-28 09:28:20.555 28480-28512/com.myapp.app D/NetworkStateTracker: Network capabilities changed: [ Transports: WIFI Capabilities: NOT_METERED&INTERNET&NOT_RESTRICTED&TRUSTED&NOT_VPN&VALIDATED&FOREGROUND LinkUpBandwidth>=1048576Kbps LinkDnBandwidth>=1048576Kbps SignalStrength: -51]
06-28 09:28:20.558 28480-28501/com.myapp.app D/Processor: Processor: processing 3e5f8531-aa92-4e28-8533-d180612dab02 Work 3e5f8531-aa92-4e28-8533-d180612dab02 is already enqueued for processing
06-28 09:28:20.593 28480-28513/com.myapp.app D/dw_element_types_work: doWork dw_element_types_work
06-28 09:28:20.629 28480-28480/com.myapp.app D/SystemJobService: onStartJob for 3e5f8531-aa92-4e28-8533-d180612dab02
06-28 09:28:20.630 28480-28501/com.myapp.app D/Processor: Work 3e5f8531-aa92-4e28-8533-d180612dab02 is already enqueued for processing
06-28 09:28:20.659 28480-28513/com.myapp.app D/OkHttp: --> GET http://myapi.com/elements/types
    --> END GET
06-28 09:28:21.086 28480-28513/com.myapp.app D/OkHttp: <-- 200 OK http://myapi.com/elements/types (426ms)
    Server: nginx/1.13.8
    Content-Type: application/json
    Transfer-Encoding: chunked
    X-Powered-By: PHP/7.2.6
    Cache-Control: no-cache, private
    Date: Thu, 28 Jun 2018 07:28:21 GMT
06-28 09:28:21.088 28480-28513/com.myapp.app D/OkHttp: [] <-- END HTTP (491-byte body)
06-28 09:28:21.291 28480-28513/com.myapp.app D/WorkerWrapper: Worker result SUCCESS for 3e5f8531-aa92-4e28-8533-d180612dab02
06-28 09:28:21.296 28480-28513/com.myapp.app D/WorkerWrapper: Setting status to enqueued for 181346ae-2341-45ad-9e90-a8a5e86fffa6
06-28 09:28:21.305 28480-28513/com.myapp.app D/SystemJobScheduler: Scheduling work ID 181346ae-2341-45ad-9e90-a8a5e86fffa6 Job ID 29
06-28 09:28:21.307 28480-28513/com.myapp.app D/GreedyScheduler: Starting tracking for 181346ae-2341-45ad-9e90-a8a5e86fffa6
06-28 09:28:21.308 28480-28513/com.myapp.app D/WorkConstraintsTracker: Constraints met for 3e5f8531-aa92-4e28-8533-d180612dab02
06-28 09:28:21.309 28480-28513/com.myapp.app D/WorkConstraintsTracker: Constraints met for 181346ae-2341-45ad-9e90-a8a5e86fffa6
06-28 09:28:21.309 28480-28513/com.myapp.app D/GreedyScheduler: Constraints met: Scheduling work ID 3e5f8531-aa92-4e28-8533-d180612dab02
06-28 09:28:21.310 28480-28501/com.myapp.app D/Processor: Work 3e5f8531-aa92-4e28-8533-d180612dab02 is already enqueued for processing
06-28 09:28:21.310 28480-28513/com.myapp.app D/GreedyScheduler: Constraints met: Scheduling work ID 181346ae-2341-45ad-9e90-a8a5e86fffa6
06-28 09:28:21.312 28480-28501/com.myapp.app D/Processor: Processor: processing 181346ae-2341-45ad-9e90-a8a5e86fffa6
06-28 09:28:21.316 28480-28480/com.myapp.app D/Processor: Processor 3e5f8531-aa92-4e28-8533-d180612dab02 executed; isSuccessful = true, reschedule = false
06-28 09:28:21.316 28480-28517/com.myapp.app E/WorkerWrapper: Status for 181346ae-2341-45ad-9e90-a8a5e86fffa6 is BLOCKED; not doing any work
06-28 09:28:21.317 28480-28480/com.myapp.app D/SystemJobService: 3e5f8531-aa92-4e28-8533-d180612dab02 executed on JobScheduler
06-28 09:28:21.319 28480-28480/com.myapp.app D/SystemJobService: onStartJob for 181346ae-2341-45ad-9e90-a8a5e86fffa6
06-28 09:28:21.320 28480-28501/com.myapp.app D/Processor: Work 181346ae-2341-45ad-9e90-a8a5e86fffa6 is already enqueued for processing
06-28 09:28:21.332 28480-28480/com.myapp.app D/Processor: Processor 181346ae-2341-45ad-9e90-a8a5e86fffa6 executed; isSuccessful = false, reschedule = false
06-28 09:28:21.333 28480-28480/com.myapp.app D/SystemJobService: 181346ae-2341-45ad-9e90-a8a5e86fffa6 executed on JobScheduler

Sometimes it throws the following errors for the second job:

E/WorkerWrapper: Status for cfaeae5c-fafd-4b9f-a77b-909625bdb26b is ENQUEUED; not doing any work

E/WorkerWrapper: Status for cfaeae5c-fafd-4b9f-a77b-909625bdb26b is BLOCKED; not doing any work

Answer 1

I had the same issue (I've found your question searching for it).

It seems that it's broken on Google side and they should fix it. I'll try to fire a bug report later on.

For now I've "fixed" it by delaying the work by 1 second. Like following:

OneTimeWorkRequest.Builder(MyWorker::class.java)
// TODO whenever WorkManager is updated, test this again
// it was not working without the delay https://stackoverflow.com/questions/51078090/workmanager-chained-work-not-running#
.setInitialDelay(1, TimeUnit.SECONDS)

I know it's a bad hack, but for now it works.

Answer 2

Would add a comment, but can't comment yet on answers. The above answer by Budius works as a "fix". We had the issue with the last Worker for the chained work never being started, and it stayed forever on ENQUEUED. Setting a delay on the "ending" worker solved it.