Status Update
Comments
ar...@gmail.com <ar...@gmail.com> #3
Sure thing!
Here we go:
D/WM-PackageManagerHelper: androidx.work.impl.background.systemjob.SystemJobService enabled
D/WM-Schedulers: Created SystemJobScheduler and enabled SystemJobService
D/WM-ForceStopRunnable: Performing cleanup operations.
D/WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver enabled
D/WM-SystemJobScheduler: Scheduling work ID 2d2cab8b-beb4-45c4-8d04-9d85e5aa4ecd Job ID 74
D/WM-GreedyScheduler: Starting work for 2d2cab8b-beb4-45c4-8d04-9d85e5aa4ecd
D/WM-Processor: Processor: processing 2d2cab8b-beb4-45c4-8d04-9d85e5aa4ecd
D/WM-WorkerWrapper: Starting work for REDACTED.Application$ForegroundWorker
I/WM-Processor: Moving WorkSpec (2d2cab8b-beb4-45c4-8d04-9d85e5aa4ecd) to the foreground
D/WM-WorkerWrapper: REDACTED.Application$ForegroundWorker returned a Success {mOutputData=Data {}} result.
I/WM-WorkerWrapper: Worker result SUCCESS for Work [ id=2d2cab8b-beb4-45c4-8d04-9d85e5aa4ecd, tags={ REDACTED.Application$ForegroundWorker } ]
D/WM-Processor: No more foreground work. SystemForegroundService is already stopped
D/WM-GreedyScheduler: Cancelling work ID 2d2cab8b-beb4-45c4-8d04-9d85e5aa4ecd
D/WM-Processor: Processor stopping background work 2d2cab8b-beb4-45c4-8d04-9d85e5aa4ecd
D/WM-Processor: WorkerWrapper could not be found for 2d2cab8b-beb4-45c4-8d04-9d85e5aa4ecd
D/WM-StopWorkRunnable: StopWorkRunnable for 2d2cab8b-beb4-45c4-8d04-9d85e5aa4ecd; Processor.stopWork = false
D/WM-SystemJobService: onStartJob for 2d2cab8b-beb4-45c4-8d04-9d85e5aa4ecd
D/WM-Processor: Processor: processing 2d2cab8b-beb4-45c4-8d04-9d85e5aa4ecd
D/WM-WorkerWrapper: Status for 2d2cab8b-beb4-45c4-8d04-9d85e5aa4ecd is SUCCEEDED; not doing any work
D/WM-WorkerWrapper: REDACTED.Application$ForegroundWorker is not in ENQUEUED state. Nothing more to do.
I/WM-SystemFgDispatcher: Started foreground service Intent { act=ACTION_START_FOREGROUND cmp=REDACTED/androidx.work.impl.foreground.SystemForegroundService (has extras) }
D/WM-SystemFgDispatcher: Notifying with (id: 42, workSpecId: 2d2cab8b-beb4-45c4-8d04-9d85e5aa4ecd, notificationType: 0)
D/WM-SystemFgDispatcher: Notifying with (id: 42, workSpecId: 2d2cab8b-beb4-45c4-8d04-9d85e5aa4ecd, notificationType: 0)
D/WM-Processor: Processor 2d2cab8b-beb4-45c4-8d04-9d85e5aa4ecd executed; reschedule = false
D/WM-SystemJobService: 2d2cab8b-beb4-45c4-8d04-9d85e5aa4ecd executed on JobScheduler
D/WM-SystemJobService: onStopJob for 2d2cab8b-beb4-45c4-8d04-9d85e5aa4ecd
D/WM-Processor: Processor 2d2cab8b-beb4-45c4-8d04-9d85e5aa4ecd executed; reschedule = false
D/WM-SystemJobService: 2d2cab8b-beb4-45c4-8d04-9d85e5aa4ecd executed on JobScheduler
D/WM-Processor: Processor stopping background work 2d2cab8b-beb4-45c4-8d04-9d85e5aa4ecd
D/WM-Processor: WorkerWrapper could not be found for 2d2cab8b-beb4-45c4-8d04-9d85e5aa4ecd
D/WM-StopWorkRunnable: StopWorkRunnable for 2d2cab8b-beb4-45c4-8d04-9d85e5aa4ecd; Processor.stopWork = false
ar...@gmail.com <ar...@gmail.com> #4
Just tried 2.3.4 which claims to resolve the
Logs:
D/WM-PackageManagerHelper: androidx.work.impl.background.systemjob.SystemJobService enabled
D/WM-Schedulers: Created SystemJobScheduler and enabled SystemJobService
D/WM-ForceStopRunnable: Performing cleanup operations.
D/WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver enabled
D/WM-SystemJobScheduler: Scheduling work ID 2d44c9de-0e3c-4518-b960-c282ba924638 Job ID 299
D/WM-GreedyScheduler: Starting work for 2d44c9de-0e3c-4518-b960-c282ba924638
D/WM-Processor: Processor: processing 2d44c9de-0e3c-4518-b960-c282ba924638
D/WM-WorkerWrapper: Starting work for REDACTED.Application$ForegroundWorker
I/WM-Processor: Moving WorkSpec (2d44c9de-0e3c-4518-b960-c282ba924638) to the foreground
D/WM-WorkerWrapper: REDACTED.Application$ForegroundWorker returned a Success {mOutputData=Data {}} result.
I/WM-WorkerWrapper: Worker result SUCCESS for Work [ id=2d44c9de-0e3c-4518-b960-c282ba924638, tags={ REDACTED.Application$ForegroundWorker } ]
D/WM-Processor: No more foreground work. SystemForegroundService is already stopped
D/WM-GreedyScheduler: Cancelling work ID 2d44c9de-0e3c-4518-b960-c282ba924638
D/WM-Processor: Processor stopping background work 2d44c9de-0e3c-4518-b960-c282ba924638
D/WM-Processor: WorkerWrapper could not be found for 2d44c9de-0e3c-4518-b960-c282ba924638
D/WM-StopWorkRunnable: StopWorkRunnable for 2d44c9de-0e3c-4518-b960-c282ba924638; Processor.stopWork = false
D/WM-SystemJobService: onStartJob for 2d44c9de-0e3c-4518-b960-c282ba924638
D/WM-Processor: Processor: processing 2d44c9de-0e3c-4518-b960-c282ba924638
I/WM-SystemFgDispatcher: Started foreground service Intent { act=ACTION_START_FOREGROUND cmp=REDACTED/androidx.work.impl.foreground.SystemForegroundService (has extras) }
D/WM-SystemFgDispatcher: Notifying with (id: 42, workSpecId: 2d44c9de-0e3c-4518-b960-c282ba924638, notificationType: 0)
D/WM-SystemFgDispatcher: Notifying with (id: 42, workSpecId: 2d44c9de-0e3c-4518-b960-c282ba924638, notificationType: 0)
D/WM-WorkerWrapper: Status for 2d44c9de-0e3c-4518-b960-c282ba924638 is SUCCEEDED; not doing any work
D/WM-WorkerWrapper: REDACTED.Application$ForegroundWorker is not in ENQUEUED state. Nothing more to do.
D/WM-Processor: Processor 2d44c9de-0e3c-4518-b960-c282ba924638 executed; reschedule = false
D/WM-SystemJobService: 2d44c9de-0e3c-4518-b960-c282ba924638 executed on JobScheduler
D/WM-SystemJobService: onStopJob for 2d44c9de-0e3c-4518-b960-c282ba924638
D/WM-Processor: Processor stopping background work 2d44c9de-0e3c-4518-b960-c282ba924638
D/WM-Processor: WorkerWrapper could not be found for 2d44c9de-0e3c-4518-b960-c282ba924638
D/WM-StopWorkRunnable: StopWorkRunnable for 2d44c9de-0e3c-4518-b960-c282ba924638; Processor.stopWork = false
D/WM-Processor: Processor 2d44c9de-0e3c-4518-b960-c282ba924638 executed; reschedule = false
D/WM-SystemJobService: 2d44c9de-0e3c-4518-b960-c282ba924638 executed on JobScheduler
ra...@google.com <ra...@google.com> #5
We marked it duplicate because if your Worker
ran long enough, it would trigger the other bug which had a similar sticky Notification
. However, you have a combination of problems one of which we fixed in 2.3.4
.
Your RxWorker implementation has a bug. You are calling setForegroundAsync(...)
, but you are not waiting for completion.
setForegroundAsync(...)
returns a ListenableFuture
that you should be waiting for.
What happens is that your Worker
running on a dedicated Executor
is racing against setForegroundAsync()
and in some cases it ends up being called after your Worker
returns a Result.success()
.
ar...@gmail.com <ar...@gmail.com> #6
Yep, the call does return the Future
but get
is called on it. I was under an impression that it blocks the execution until the Future
delivers a result. Isn’t that the case here?
ra...@google.com <ra...@google.com> #7
Yes, that is how you should be blocking on the ListenableFuture
. When I last looked at your code, you were not doing it correctly.
ar...@gmail.com <ar...@gmail.com> #8
Sorry, I’m confused. The sample in the opening comment has this:
Single
.fromCallable {
setForegroundAsync(ForegroundInfo(42, createNotification())).get().toOptional()
}
.map { Result.success() }
What it does (from my POV):
- changes the worker to be foregrounded using
setForegroundAsync
; - blocks until the
setForegroundAsync
ListenableFuture
provides it; - emits a successful worker result.
Is there a bug in this implementation? I’m confused because #5 states that there is a bug in the sample but #7 confirms that blocking via get()
should work.
ra...@google.com <ra...@google.com> #9
Are you calling setForegroundAsync()
in your constructor ?
ra...@google.com <ra...@google.com> #11
WorkManager has multiple schedulers (in-process, JobScheduler
, the AlarmManager
based scheduler etc.).
What's happening in your case, is that the in-process Scheduler is picking up the RxWorker
implementation and your Worker
completes successfully by returning an instance of Result
.
However, around the same time JobScheduler
also wants to execute the same WorkRequest
. For us to be able to de-dupe the execution, we create an instance of the Worker
and check to see if it needs to be scheduled. As your logs point out, we correctly identify that the Worker
is done.
D/WM-WorkerWrapper: Status for 2d44c9de-0e3c-4518-b960-c282ba924638 is SUCCEEDED; not doing any work
D/WM-WorkerWrapper: REDACTED.Application$ForegroundWorker is not in ENQUEUED state. Nothing more to do.
However in your RxWorker
implementation the side-effect of calling setForegroundAsync()
in createWork()
is that a call to notify()
happens despite your Worker
not having to run at all. The reason this happens is because there is no easy way for you to be able to tell that the Worker
actually started running (because that happens only when an underlying subscription is created).
We made this a lot more ergonomic in 2.4.0-alpha02
(soon to be released). Attempts to notify are ignored
when a Worker
is done.
--
In your RxWorker
for a workaround around the notifications, you could do something like:
Single
.fromCallable {
val workInfo = WorkManager.getInstance(context).getWorkInfoById(getId()).get()
if (workInfo != null && !workInfo.getState().isFinished()) {
setForegroundAsync(ForegroundInfo(42, createNotification())).get().toOptional()
}
}
.map { Result.success() }
Going forward, we automatically handle this for you.
ar...@gmail.com <ar...@gmail.com> #12
Awesome, thanks for the detailed explanation! I’ll look forward to the 2.4.0.
Sorry for bothering you with this. It was a bit weird to follow the documentation and still having an issue.
ra...@google.com <ra...@google.com> #13
No problem. In 2.4.0-alpha02
you can just call setForegroundAsync()
and not have to worry about calling get()
.
We do the rest :)
Description
* Android version: 10
* Device: emulator API level 29, x86
Put the following code in the `Application` subclass and call the `scheduleForegroundWork` method in the `onCreate` one. Run the application.
```kotlin
private fun scheduleForegroundWork() {
val workRequest = OneTimeWorkRequest.Builder(ForegroundWorker::class.java).build()
WorkManager
.getInstance(this)
.enqueueUniqueWork("foreground-work", ExistingWorkPolicy.REPLACE, workRequest)
}
class ForegroundWorker(private val context: Context, parameters: WorkerParameters) : RxWorker(context, parameters) {
companion object {
private const val NOTIFICATION_CHANNEL_ID = "foreground-work"
}
override fun createWork() = Single
.fromCallable {
createNotificationChannel()
setForegroundAsync(ForegroundInfo(42, createNotification())).get().toOptional()
}
.map { Result.success() }
private fun createNotificationChannel() {
val channel = NotificationChannel(
NOTIFICATION_CHANNEL_ID,
"Foreground work",
NotificationManager.IMPORTANCE_LOW
)
context.getSystemService<NotificationManager>()?.createNotificationChannel(channel)
}
private fun createNotification() = Notification.Builder(context, NOTIFICATION_CHANNEL_ID)
.setSmallIcon(R.drawable.ic_notification_upload)
.setContentText("Hello there from the foreground work")
.build()
}
```
* Actual behavior: the notification is shown but is never dismissed — not that the `Result` is provided immediately.
* Expected behavior: the notification is hidden.
The issue can be mitigated via adding a delay before producing a result:
```diff
}
+ .delay(1, TimeUnit.SECONDS)
.map { Result.success() }
```
I suspect that the foreground service is cancelled all the time when a result is provided, maybe there is a race somewhere.