WorkManager Periodic work stops after a period [111469837]

Fixed

Bug

Status Update

No update yet.

Description

da...@gmail.com

created issue #1

Jul 15, 2018 06:15PM

I'm using WorkManager alpha-4 and have converted my app's sync jobs to workers. If the device remains plugged in, the periodic jobs run as expected (approx once an hour as scheduled). However, when taking the device off power, allowing it to go to sleep, after a period of time the workers no longer excecute.

My log contains the following statements at the time when the jobs (there are 4) were supposed to execute:

2018-07-15 13:52:15.456 12947-12947/com.dvtonder.chronus D/SystemJobService: Override deadline expired for id 5caee77a-e9c5-4a99-bc7b-651ad21eb94b. Retry requested
2018-07-15 13:52:15.460 12947-12947/com.dvtonder.chronus D/SystemJobService: Override deadline expired for id e3641a8b-1df8-49b9-8c90-1c893c3afc0f. Retry requested
2018-07-15 13:52:15.464 12947-12947/com.dvtonder.chronus D/SystemJobService: Override deadline expired for id db7c03a2-0fe6-42c4-baf8-0ef6e8220e9b. Retry requested
2018-07-15 13:52:15.465 12947-12947/com.dvtonder.chronus D/SystemJobService: Override deadline expired for id d3efce3a-6aa7-4e10-84af-759f1124ccf5. Retry requested

As you can see from the log entries below, things were running just fine up to that point:

2018-07-15 11:30:02.168 12947-12947/com.dvtonder.chronus D/SystemJobService: 5caee77a-e9c5-4a99-bc7b-651ad21eb94b executed on JobScheduler
2018-07-15 11:30:02.396 12947-12947/com.dvtonder.chronus D/SystemJobService: d3efce3a-6aa7-4e10-84af-759f1124ccf5 executed on JobScheduler
2018-07-15 11:30:03.291 12947-12947/com.dvtonder.chronus D/SystemJobService: e3641a8b-1df8-49b9-8c90-1c893c3afc0f executed on JobScheduler
2018-07-15 11:30:03.292 12947-12947/com.dvtonder.chronus D/SystemJobService: db7c03a2-0fe6-42c4-baf8-0ef6e8220e9b executed on JobScheduler
2018-07-15 11:54:09.377 12947-12947/com.dvtonder.chronus D/SystemJobService: onStartJob for b4303ff7-dd6c-4288-8be2-e859c56cddc5
2018-07-15 11:54:09.383 12947-12947/com.dvtonder.chronus D/SystemJobService: onStartJob for 27c2a27b-4da0-4512-ac60-924fb134addd
2018-07-15 11:54:09.478 12947-12947/com.dvtonder.chronus D/SystemJobService: 27c2a27b-4da0-4512-ac60-924fb134addd executed on JobScheduler
2018-07-15 11:54:10.026 12947-12947/com.dvtonder.chronus D/SystemJobService: b4303ff7-dd6c-4288-8be2-e859c56cddc5 executed on JobScheduler
2018-07-15 12:49:00.838 12947-12947/com.dvtonder.chronus D/SystemJobService: onStartJob for e3641a8b-1df8-49b9-8c90-1c893c3afc0f
2018-07-15 12:49:00.865 12947-12947/com.dvtonder.chronus D/SystemJobService: onStartJob for 5caee77a-e9c5-4a99-bc7b-651ad21eb94b
2018-07-15 12:49:01.136 12947-12947/com.dvtonder.chronus D/SystemJobService: onStartJob for db7c03a2-0fe6-42c4-baf8-0ef6e8220e9b
2018-07-15 12:49:01.548 12947-12947/com.dvtonder.chronus D/SystemJobService: onStartJob for d3efce3a-6aa7-4e10-84af-759f1124ccf5
2018-07-15 12:49:09.589 12947-12947/com.dvtonder.chronus D/SystemJobService: db7c03a2-0fe6-42c4-baf8-0ef6e8220e9b executed on JobScheduler
2018-07-15 12:49:17.334 12947-12947/com.dvtonder.chronus D/SystemJobService: d3efce3a-6aa7-4e10-84af-759f1124ccf5 executed on JobScheduler
2018-07-15 12:49:25.292 12947-12947/com.dvtonder.chronus D/SystemJobService: e3641a8b-1df8-49b9-8c90-1c893c3afc0f executed on JobScheduler
2018-07-15 12:49:42.364 12947-12947/com.dvtonder.chronus D/SystemJobService: 5caee77a-e9c5-4a99-bc7b-651ad21eb94b executed on JobScheduler
2018-07-15 12:50:03.938 12947-12947/com.dvtonder.chronus D/SystemJobService: onStartJob for 7fa7b9d0-4e00-466f-a29d-fcc89d4c5b5d
2018-07-15 12:50:04.015 12947-12947/com.dvtonder.chronus D/SystemJobService: 7fa7b9d0-4e00-466f-a29d-fcc89d4c5b5d executed on JobScheduler
2018-07-15 12:50:32.909 12947-12947/com.dvtonder.chronus D/SystemJobService: onStartJob for 204b2e5e-5e24-466e-bdd7-814ef9a4582b
2018-07-15 12:50:33.329 12947-12947/com.dvtonder.chronus D/SystemJobService: 204b2e5e-5e24-466e-bdd7-814ef9a4582b executed on JobScheduler
2018-07-15 13:52:15.456 12947-12947/com.dvtonder.chronus D/SystemJobService: Override deadline expired for id 5caee77a-e9c5-4a99-bc7b-651ad21eb94b. Retry requested
2018-07-15 13:52:15.460 12947-12947/com.dvtonder.chronus D/SystemJobService: Override deadline expired for id e3641a8b-1df8-49b9-8c90-1c893c3afc0f. Retry requested
2018-07-15 13:52:15.464 12947-12947/com.dvtonder.chronus D/SystemJobService: Override deadline expired for id db7c03a2-0fe6-42c4-baf8-0ef6e8220e9b. Retry requested
2018-07-15 13:52:15.465 12947-12947/com.dvtonder.chronus D/SystemJobService: Override deadline expired for id d3efce3a-6aa7-4e10-84af-759f1124ccf5. Retry requested

Comments

ra...@google.com <ra...@google.com> #2Jul 16, 2018 04:50PM

Status: Won't Fix (Intended Behavior)

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

commit b90079595f33f58fece04026a97faa0d243acdb1
Author: Yuichi Araki <yaraki@google.com>
Date: Wed Sep 18 16:55:49 2019

Change the way to detect mismatch between POJO and query

This fixes cursor mismatch warnings with expandProjection.

Bug: 140759491
Test: QueryMethodProcessorTest
Change-Id: I7659002e5e0d1ef60fc1af2a625c0c36da0664d8

M room/compiler/src/main/kotlin/androidx/room/processor/QueryMethodProcessor.kt
M room/compiler/src/main/kotlin/androidx/room/solver/TypeAdapterStore.kt
M room/compiler/src/main/kotlin/androidx/room/solver/query/result/PojoRowAdapter.kt
M room/compiler/src/test/kotlin/androidx/room/processor/QueryMethodProcessorTest.kt
M room/compiler/src/test/kotlin/androidx/room/testing/TestProcessor.kt

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

https://goto.google.com/android-sha1/b90079595f33f58fece04026a97faa0d243acdb1

da...@gmail.com <da...@gmail.com> #3Jul 16, 2018 06:03PM

The following changes were cherrypicked through Coastguard (

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

https://android-build.googleplex.com/coastguard/dashboard/6093116828680192/#/cherrypickHistory/all)
Created: 2019-10-14 17:23:42.610596+00:00
Changes: aosp/1123258

da...@gmail.com <da...@gmail.com> #4Jul 16, 2018 09:15PM

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

commit bdde5a1a970ddc9007b28de4aa29d60ffa588f08
Author: Yigit Boyar <yboyar@google.com>
Date: Thu Apr 16 16:47:05 2020

Re-factor how errors are dismissed when query is re-written

This CL changes how we handle errors/warnings if query is
re-written.
There was a bug in expandProjection where we would report warnings
for things that Room already fixes automatically (

b/140759491

).
The solution to that problem (I7659002e5e0d1ef60fc1af2a625c0c36da0664d8)
solved it by deferring validating of columns until after re-write
decision is made. Unfortunately, this required changing PojoRowAdapter
to have a dummy mapping until it is validating, make it hard to use
as it does have a non-null mapping which is not useful.

This CL partially reverts that change and instead rely on the log
deferring logic we have in Context. This way, we don't need to break
the stability of PojoRowAdapter while still having the ability to
drop warnings that room fixes. This will also play nicer when we
have different query re-writing options that can use more information
about the query results.

Bug: 153387066
Bug: 140759491
Test: existing tests pass
Change-Id: I2ec967c763d33d7a3ff02c1a13c6953b460d1e5f

M room/compiler/src/main/kotlin/androidx/room/log/RLog.kt
M room/compiler/src/main/kotlin/androidx/room/processor/QueryMethodProcessor.kt
M room/compiler/src/main/kotlin/androidx/room/solver/TypeAdapterStore.kt
M room/compiler/src/main/kotlin/androidx/room/solver/query/result/PojoRowAdapter.kt

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

ra...@google.com <ra...@google.com> #5Jul 16, 2018 09:25PM

The fact that SystemJobService is being invoked means that the jobs are getting rescheduled. Your constraints are not being met.
Which constraints are you using, and can you give us a small reproducible test-case ?

da...@gmail.com <da...@gmail.com> #6Jul 16, 2018 09:42PM

The code snippet that schedules the work is as follows. All the workers in question are all identical and are used for the periodic updating (hourly) of Weather, Stocks, News and Tasks data.

The device is running Oreo 8.1

The only constraint that should be applying is NetworkType.CONNECTED.

@Synchronized
fun schedulePeriodicUpdate(context: Context) {
val interval = Preferences.weatherRefreshIntervalInMs(context)
if (interval == 0L) {
// We are set to manual update, don't schedule a periodic job, cancel any existing ones
WorkManager.getInstance()?.cancelAllWorkByTag(JOB_TAG_PERIODIC)
return
}

val wifiOnly = Preferences.weatherDownloadOverWiFiOnly(context)
val constraints = Constraints.Builder()
.setRequiredNetworkType(if (wifiOnly)
NetworkType.UNMETERED
else
NetworkType.CONNECTED)
.build()

// Create the job definition
val periodicRefresh = PeriodicWorkRequest.Builder(
WeatherUpdateWorker::class.java, interval, TimeUnit.MILLISECONDS, Constants.PERIODIC_FLEX_MILLIS, TimeUnit.MILLISECONDS)
.setConstraints(constraints)
.addTag(JOB_TAG_PERIODIC)
.build()

// Start the job
WorkManager.getInstance()?.enqueueUniquePeriodicWork(JOB_TAG_PERIODIC, ExistingPeriodicWorkPolicy.REPLACE, periodicRefresh)
if (DEBUG) {
val workId = periodicRefresh.id
Log.d(TAG, "Scheduled a periodic Weather update job with id = $workId")
}
}

da...@gmail.com <da...@gmail.com> #7Jul 16, 2018 11:03PM

In my case, interval = 60 * 60 * 1000 millis (1 hour) and PERIODIC_FLEX_MILLIS = 10 * 60 * 1000 millis (10 minutes).

The way I understand that it should work is that the worker will attempt to run at some time in the last 10 minutes of the interval (the Flex period), if the conditions are met, in my case NETWORK_CONNECTED.

Given that the worker's conditions might not be met when the device is in Doze mode, one would expect that the worker will be queued to retry in the next/upcoming Doze "Maintenance Window", otherwise periodic jobs may never run when the device is in Doze since the likelihood of the flex period and the Doze Maintenance window aligning is low.

ra...@google.com <ra...@google.com> #8Jul 18, 2018 06:27PM

Assigned to ra...@google.com.

Investigating further, it looks like WorkManager incorrectly assumes that deadline expiry implies that the constraints may not be met. However, for PeriodicWork, JobScheduler ensures that the Job is run only when the constraints are met.

su...@google.com <su...@google.com> Jul 23, 2018 09:53PM

Marked as fixed.

da...@gmail.com <da...@gmail.com> #9Aug 26, 2018 04:28PM

This seems to have been broken with the alpha07 release.

su...@google.com <su...@google.com> #10Aug 27, 2018 07:36PM

Yes, the fix will be out with alpha08 later today.

sa...@gmail.com <sa...@gmail.com> #11Jun 27, 2019 08:20AM

Hi,

Work manager triggering when it started. But in Background (after killing or in doze mode) it is not triggered in 2.0.1 version. Tested mobile Vivo v11 pro, android version 9.

-------Worker class-------

class LocationTracker(private val mContext: Context, workerParams: WorkerParameters) : Worker(mContext, workerParams) {

private val TAG = "LocationTracker"

override fun doWork(): Result {
Log.d(TAG, "doWork: Done")
// var locationRequestListener: LocationRequestListener
Log.d(TAG, "onStartJob: STARTING JOB..")

try {

GPSLocation(applicationContext)

} catch (ignored: ParseException) {
ignored.printStackTrace()
}

return Result.success()
}
}

------ Work manager --------
private fun startLocationTrackingService() {
val constraints = Constraints.Builder()
.setRequiredNetworkType(NetworkType.CONNECTED)
.build()
val periodicWork = PeriodicWorkRequest.Builder(LocationTracker::class.java, 15, TimeUnit.MINUTES)
.addTag(LOCATION_TAG)
.setConstraints(constraints)
.build()
WorkManager.getInstance().enqueueUniquePeriodicWork(LOCATION_TAG, ExistingPeriodicWorkPolicy.KEEP, periodicWork)

}

ra...@google.com <ra...@google.com> #12Jun 27, 2019 02:21PM

Could you please open a new bug ?

Also could you please enable WorkManager logging as it will give us more insight into what is going on. For more information please look at

https://developer.android.com/topic/libraries/architecture/workmanager/advanced/custom-configuration and make sure you use Log.DEBUG

Also check to see if your device has settings for non-standard battery optimizations. Some OEMs force-stop your app when its in the background which means that all your jobs are gone. An easy way to tell whether this is the case to to try and reproduce this problem on an emulator.