IssueTracker

Component used: Workmanager Version used: 2.4.0 Devices/Android versions reproduced on: Multiple devices, Nokia 8.1 Android 10, Huawei P30 lite (Android 9), Xaomi Redmi 9 (Android 10)

In our app we run 3 jobs through WorkManager and we are observing that sometimes a periodic job that runs the most often is sometimes not added in the system job scheduler after it ran. This can be verified by looking at adb shell dumpsys jobscheduler. The devices in question have been left alone for a while over a couple of hours.

WorkManager.initialize() will also not restore these missing jobs.

One reason for this could be that the system job scheduler implementation isn't checking the return code from JobScheduler.schedule(), especially since this issue doesn't happen every single time the job has run.

Logs from the app indicate WorkManager scheduling job id 7, but this id is not showing up for the nl.rijksoverheid.en package. Only id 3 & 4, that have been scheduled at the same time as the initial periodic job, are shown in the output:

  JOB #u0a127/3: eacc6d4 nl.rijksoverheid.en/androidx.work.impl.background.systemjob.SystemJobService
    u0a127 tag=*job*/nl.rijksoverheid.en/androidx.work.impl.background.systemjob.SystemJobService
    Source: uid=u0a127 user=0 pkg=nl.rijksoverheid.en
    JobInfo:
      Service: nl.rijksoverheid.en/androidx.work.impl.background.systemjob.SystemJobService
      Requires: charging=false batteryNotLow=false deviceIdle=false
      Extras: {EXTRA_WORK_SPEC_ID=5943826e-4cd3-4bda-b42a-e41454b089e2, EXTRA_IS_PERIODIC=true}
      Minimum latency: +23h59m59s971ms
      Backoff: policy=1 initial=+30s0ms
      Has early constraint
    Required constraints: TIMING_DELAY [0x80000000]
    Satisfied constraints: DEVICE_NOT_DOZING BACKGROUND_NOT_RESTRICTED [0x2400000]
    Unsatisfied constraints: TIMING_DELAY [0x80000000]
    Doze whitelisted: true
    Tracking: TIME
    Standby bucket: ACTIVE
    Enqueue time: -20h0m41s814ms
    Run time: earliest=+3h59m18s157ms, latest=none
    Last run heartbeat: 54
    Ready: false (job=false user=true !pending=true !active=true !backingup=true comp=true)
  JOB #u0a127/4: 8276672 nl.rijksoverheid.en/androidx.work.impl.background.systemjob.SystemJobService
    u0a127 tag=*job*/nl.rijksoverheid.en/androidx.work.impl.background.systemjob.SystemJobService
    Source: uid=u0a127 user=0 pkg=nl.rijksoverheid.en
    JobInfo:
      Service: nl.rijksoverheid.en/androidx.work.impl.background.systemjob.SystemJobService
      Requires: charging=false batteryNotLow=false deviceIdle=false
      Extras: {EXTRA_WORK_SPEC_ID=7f85d14a-7379-4aba-be7b-4bc04aea697f, EXTRA_IS_PERIODIC=true}
      Minimum latency: +23h59m59s965ms
      Backoff: policy=1 initial=+30s0ms
      Has early constraint
    Required constraints: TIMING_DELAY [0x80000000]
    Satisfied constraints: DEVICE_NOT_DOZING BACKGROUND_NOT_RESTRICTED [0x2400000]
    Unsatisfied constraints: TIMING_DELAY [0x80000000]
    Doze whitelisted: true
    Tracking: TIME
    Standby bucket: ACTIVE
    Enqueue time: -19h59m40s975ms
    Run time: earliest=+4h0m18s990ms, latest=none
    Last run heartbeat: 54
    Ready: false (job=false user=true !pending=true !active=true !backingup=true comp=true)

Here's the WorkManager log output after the job has been run:

2020-08-25 21:48:13.631/WM-WorkerWrapper: nl.rijksoverheid.en.job.ProcessManifestWorker returned a Success {mOutputData=Data {}} result.
2020-08-25 21:48:13.639/WM-WorkerWrapper: Worker result SUCCESS for Work [ id=b41f4e98-0266-49a6-8251-ebe6340cfdd2, tags={ nl.rijksoverheid.en.job.ProcessManifestWorker } ]
2020-08-25 21:48:13.646/WM-Processor: No more foreground work. Stopping SystemForegroundService
2020-08-25 21:48:13.648/WM-SystemFgDispatcher: Stopping foreground service
2020-08-25 21:48:13.649/WM-SystemFgService: All commands completed.
2020-08-25 21:48:13.657/WM-GreedyScheduler: Cancelling work ID b41f4e98-0266-49a6-8251-ebe6340cfdd2
2020-08-25 21:48:13.657/WM-Processor: Processor b41f4e98-0266-49a6-8251-ebe6340cfdd2 executed; reschedule = false
2020-08-25 21:48:13.659/WM-SystemJobService: b41f4e98-0266-49a6-8251-ebe6340cfdd2 executed on JobScheduler
2020-08-25 21:48:13.665/WM-NetworkStateTracker: Unregistering network callback
2020-08-25 21:48:13.669/WM-SystemJobService: onStopJob for b41f4e98-0266-49a6-8251-ebe6340cfdd2
2020-08-25 21:48:13.698/WM-SystemJobScheduler: Scheduling work ID b41f4e98-0266-49a6-8251-ebe6340cfdd2 Job ID 7
2020-08-25 21:48:13.708/WM-Processor: Processor stopping background work b41f4e98-0266-49a6-8251-ebe6340cfdd2
2020-08-25 21:48:13.709/WM-Processor: WorkerWrapper could not be found for b41f4e98-0266-49a6-8251-ebe6340cfdd2
2020-08-25 21:48:13.710/WM-StopWorkRunnable: StopWorkRunnable for b41f4e98-0266-49a6-8251-ebe6340cfdd2; Processor.stopWork = false
2020-08-25 21:48:13.712/WM-Processor: Processor stopping background work b41f4e98-0266-49a6-8251-ebe6340cfdd2
2020-08-25 21:48:13.713/WM-Processor: WorkerWrapper could not be found for b41f4e98-0266-49a6-8251-ebe6340cfdd2
2020-08-25 21:48:13.714/WM-StopWorkRunnable: StopWorkRunnable for b41f4e98-0266-49a6-8251-ebe6340cfdd2; Processor.stopWork = false