Status Update
Comments
ra...@google.com <ra...@google.com> #2
When you disable WiFi, your Worker should have been interrupted. Can you please send us a sample app, and I can take a look.
ar...@gmail.com <ar...@gmail.com> #3
Sure thing. Attaching the sample with the same code as in the initial comment. Please follow steps from it, I was able to reproduce it on the described emulator.
ra...@google.com <ra...@google.com> #4
I followed your instructions and this is what I see:
I turned off WiFi and enqueued the WorkRequest
:
2020-05-12 10:52:04.484 6827-6869/com.sample D/WM-Processor: Processor cancelling 068731ec-1829-4d1e-80ab-336be38e51c7
2020-05-12 10:52:04.487 6827-6869/com.sample D/WM-Processor: WorkerWrapper could not be found for 068731ec-1829-4d1e-80ab-336be38e51c7
2020-05-12 10:52:04.497 6827-6869/com.sample D/WM-GreedyScheduler: Cancelling work ID 068731ec-1829-4d1e-80ab-336be38e51c7
2020-05-12 10:52:04.552 6827-6869/com.sample D/WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver enabled
2020-05-12 10:52:04.674 6827-6869/com.sample D/WM-SystemJobScheduler: Scheduling work ID 6ac118f4-5af8-4fce-93f8-dec44f97d584 Job ID 2
2020-05-12 10:52:04.685 6827-6869/com.sample D/WM-GreedyScheduler: Starting tracking for [6ac118f4-5af8-4fce-93f8-dec44f97d584]
2020-05-12 10:52:04.713 6827-6869/com.sample D/WM-ConstraintTracker: NetworkStateTracker: initial state = [ Connected=true Validated=true Metered=true NotRoaming=true ]
2020-05-12 10:52:04.713 6827-6869/com.sample D/WM-NetworkStateTracker: Registering network callback
2020-05-12 10:52:04.748 6827-6869/com.sample D/WM-GreedyScheduler: Constraints not met: Cancelling work ID 6ac118f4-5af8-4fce-93f8-dec44f97d584
2020-05-12 10:52:04.805 6827-6864/com.sample D/WM-Processor: Processor stopping background work 068731ec-1829-4d1e-80ab-336be38e51c7
2020-05-12 10:52:04.811 6827-6864/com.sample D/WM-Processor: WorkerWrapper could not be found for 068731ec-1829-4d1e-80ab-336be38e51c7
2020-05-12 10:52:04.812 6827-6880/com.sample D/WM-NetworkStateTracker: Network capabilities changed: [ Transports: CELLULAR Capabilities: MMS&SUPL&DUN&FOTA&IMS&CBS&INTERNET&NOT_RESTRICTED&TRUSTED&NOT_VPN&VALIDATED&NOT_ROAMING&FOREGROUND&NOT_CONGESTED&NOT_SUSPENDED LinkUpBandwidth>=51200Kbps LinkDnBandwidth>=102400Kbps Specifier: <1>]
2020-05-12 10:52:04.815 6827-6864/com.sample D/WM-StopWorkRunnable: StopWorkRunnable for 068731ec-1829-4d1e-80ab-336be38e51c7; Processor.stopWork = false
2020-05-12 10:52:04.841 6827-6869/com.sample D/WM-Processor: Processor stopping background work 6ac118f4-5af8-4fce-93f8-dec44f97d584
2020-05-12 10:52:04.843 6827-6869/com.sample D/WM-Processor: WorkerWrapper could not be found for 6ac118f4-5af8-4fce-93f8-dec44f97d584
2020-05-12 10:52:04.850 6827-6869/com.sample D/WM-StopWorkRunnable: StopWorkRunnable for 6ac118f4-5af8-4fce-93f8-dec44f97d584; Processor.stopWork = false
You can see that the log states that the constraints were not met.
I then enabled WiFi.
2020-05-12 10:52:25.374 6827-6880/com.sample D/WM-NetworkStateTracker: Network capabilities changed: [ Transports: WIFI Capabilities: NOT_METERED&INTERNET&NOT_RESTRICTED&TRUSTED&NOT_VPN&VALIDATED&NOT_ROAMING&FOREGROUND&NOT_CONGESTED&NOT_SUSPENDED LinkUpBandwidth>=1048576Kbps LinkDnBandwidth>=1048576Kbps SignalStrength: -30]
2020-05-12 10:52:25.409 6827-6827/com.sample D/WM-WorkConstraintsTrack: Constraints met for 6ac118f4-5af8-4fce-93f8-dec44f97d584
2020-05-12 10:52:25.411 6827-6827/com.sample D/WM-GreedyScheduler: Constraints met: Scheduling work ID 6ac118f4-5af8-4fce-93f8-dec44f97d584
2020-05-12 10:52:25.416 6827-6827/com.sample D/WM-SystemJobService: onStartJob for 6ac118f4-5af8-4fce-93f8-dec44f97d584
2020-05-12 10:52:25.425 6827-6880/com.sample D/WM-NetworkStateTracker: Network capabilities changed: [ Transports: WIFI Capabilities: NOT_METERED&INTERNET&NOT_RESTRICTED&TRUSTED&NOT_VPN&VALIDATED&NOT_ROAMING&FOREGROUND&NOT_CONGESTED&NOT_SUSPENDED LinkUpBandwidth>=1048576Kbps LinkDnBandwidth>=1048576Kbps SignalStrength: -30]
2020-05-12 10:52:25.443 6827-6864/com.sample D/WM-Processor: Processor: processing 6ac118f4-5af8-4fce-93f8-dec44f97d584
2020-05-12 10:52:25.444 6827-6864/com.sample D/WM-Processor: Work 6ac118f4-5af8-4fce-93f8-dec44f97d584 is already enqueued for processing
2020-05-12 10:52:25.497 6827-6827/com.sample D/WM-WorkerWrapper: Starting work for com.sample.WorkApplication$ForegroundWorker
2020-05-12 10:52:25.738 6827-6881/com.sample I/WM-Processor: Moving WorkSpec (6ac118f4-5af8-4fce-93f8-dec44f97d584) to the foreground
2020-05-12 10:52:25.775 6827-6827/com.sample I/WM-SystemFgDispatcher: Started foreground service Intent { act=ACTION_START_FOREGROUND cmp=com.sample/androidx.work.impl.foreground.SystemForegroundService (has extras) }
2020-05-12 10:52:25.783 6827-6827/com.sample D/WM-SystemFgDispatcher: Notifying with (id: 42, workSpecId: 6ac118f4-5af8-4fce-93f8-dec44f97d584, notificationType: 0)
2020-05-12 10:52:25.821 6827-6864/com.sample D/WM-WorkConstraintsTrack: Constraints met for 6ac118f4-5af8-4fce-93f8-dec44f97d584
2020-05-12 10:52:25.826 6827-6827/com.sample D/WM-SystemFgDispatcher: Notifying with (id: 42, workSpecId: 6ac118f4-5af8-4fce-93f8-dec44f97d584, notificationType: 0)
2020-05-12 10:52:25.834 6827-6917/com.sample I/System.out: Worker interval 0
2020-05-12 10:52:26.812 6827-6917/com.sample I/System.out: Worker interval 1
2020-05-12 10:52:27.814 6827-6917/com.sample I/System.out: Worker interval 2
2020-05-12 10:52:28.813 6827-6917/com.sample I/System.out: Worker interval 3
2020-05-12 10:52:29.812 6827-6917/com.sample I/System.out: Worker interval 4
2020-05-12 10:52:30.812 6827-6917/com.sample I/System.out: Worker interval 5
....
Your Worker
now started running.
I subsequently waited for a couple of seconds and disabled the WiFi.
2020-05-12 10:52:38.351 6827-6880/com.sample D/WM-NetworkStateTracker: Network connection lost
2020-05-12 10:52:38.356 6827-6869/com.sample D/WM-Processor: Processor stopping background work 6ac118f4-5af8-4fce-93f8-dec44f97d584
2020-05-12 10:52:38.357 6827-6869/com.sample D/WM-Processor: WorkerWrapper could not be found for 6ac118f4-5af8-4fce-93f8-dec44f97d584
2020-05-12 10:52:38.360 6827-6869/com.sample D/WM-StopWorkRunnable: StopWorkRunnable for 6ac118f4-5af8-4fce-93f8-dec44f97d584; Processor.stopWork = false
2020-05-12 10:52:38.381 6827-6827/com.sample D/WM-GreedyScheduler: Constraints not met: Cancelling work ID 6ac118f4-5af8-4fce-93f8-dec44f97d584
2020-05-12 10:52:38.382 6827-6827/com.sample D/WM-SystemFgDispatcher: Constraints unmet for WorkSpec 6ac118f4-5af8-4fce-93f8-dec44f97d584
2020-05-12 10:52:38.383 6827-6864/com.sample D/WM-Processor: Processor stopping background work 6ac118f4-5af8-4fce-93f8-dec44f97d584
2020-05-12 10:52:38.384 6827-6864/com.sample D/WM-Processor: WorkerWrapper could not be found for 6ac118f4-5af8-4fce-93f8-dec44f97d584
2020-05-12 10:52:38.385 6827-6864/com.sample D/WM-StopWorkRunnable: StopWorkRunnable for 6ac118f4-5af8-4fce-93f8-dec44f97d584; Processor.stopWork = false
2020-05-12 10:52:38.391 6827-6881/com.sample D/WM-Processor: Processor stopping foreground work 6ac118f4-5af8-4fce-93f8-dec44f97d584
2020-05-12 10:52:38.392 6827-6881/com.sample D/WM-WorkerWrapper: Work interrupted for Work [ id=6ac118f4-5af8-4fce-93f8-dec44f97d584, tags={ com.sample.WorkApplication$ForegroundWorker } ]
2020-05-12 10:52:38.405 6827-6881/com.sample D/WM-Processor: No more foreground work. Stopping SystemForegroundService
2020-05-12 10:52:38.406 6827-6827/com.sample I/WM-SystemFgDispatcher: Stopping foreground service
2020-05-12 10:52:38.406 6827-6827/com.sample D/WM-SystemFgService: All commands completed.
2020-05-12 10:52:38.409 6827-6881/com.sample D/WM-Processor: WorkerWrapper interrupted for 6ac118f4-5af8-4fce-93f8-dec44f97d584
2020-05-12 10:52:38.411 6827-6881/com.sample D/WM-StopWorkRunnable: StopWorkRunnable for 6ac118f4-5af8-4fce-93f8-dec44f97d584; Processor.stopWork = true
2020-05-12 10:52:38.413 6827-6827/com.sample D/WM-Processor: Processor 6ac118f4-5af8-4fce-93f8-dec44f97d584 executed; reschedule = true
2020-05-12 10:52:38.413 6827-6827/com.sample D/WM-GreedyScheduler: Stopping tracking for 6ac118f4-5af8-4fce-93f8-dec44f97d584
2020-05-12 10:52:38.416 6827-6827/com.sample D/WM-NetworkStateTracker: Unregistering network callback
2020-05-12 10:52:38.428 6827-6869/com.sample I/WM-WorkerWrapper: Work [ id=6ac118f4-5af8-4fce-93f8-dec44f97d584, tags={ com.sample.WorkApplication$ForegroundWorker } ] was cancelled
java.util.concurrent.CancellationException: Task was cancelled.
at androidx.work.impl.utils.futures.AbstractFuture.cancellationExceptionWithCause(AbstractFuture.java:1184)
at androidx.work.impl.utils.futures.AbstractFuture.getDoneValue(AbstractFuture.java:514)
at androidx.work.impl.utils.futures.AbstractFuture.get(AbstractFuture.java:475)
at androidx.work.impl.WorkerWrapper$2.run(WorkerWrapper.java:298)
at androidx.work.impl.utils.SerialExecutor$Task.run(SerialExecutor.java:91)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
at java.lang.Thread.run(Thread.java:919)
2020-05-12 10:52:38.429 6827-6869/com.sample D/WM-WorkerWrapper: Work interrupted for Work [ id=6ac118f4-5af8-4fce-93f8-dec44f97d584, tags={ com.sample.WorkApplication$ForegroundWorker } ]
2020-05-12 10:52:38.436 6827-6869/com.sample D/WM-Processor: No more foreground work. SystemForegroundService is already stopped
The foreground service is correctly stopped.
ra...@google.com <ra...@google.com> #5
ra...@google.com <ra...@google.com> #6
If you have more information, I can reopen the bug.
ar...@gmail.com <ar...@gmail.com> #7
Yep, the verbose logging was enabled to produce logs in the initial comment.
ra...@google.com <ra...@google.com> #8
Okay, I think I know what might be going on. Thanks for the logs, that really helped.
ap...@google.com <ap...@google.com> #9
Branch: androidx-master-dev
commit 889cad12d1cadf8ee1ec3e031b204cb94e498233
Author: Rahul Ravikumar <rahulrav@google.com>
Date: Tue May 12 11:35:53 2020
Processor needs to check for both foreground and background work.
* Processor needs to check for enqueued foreground and background work,
so there is only ever 1 `WorkerWrapper` per work request.
Fixes:
Test: Existing unit tests pass.
Change-Id: Ib4223565beeb983001bc51d8d45ee417ebf53d62
M work/workmanager/src/main/java/androidx/work/impl/Processor.java
ar...@gmail.com <ar...@gmail.com> #10
Thanks for the quick fix! Is it possible to check a snapshot of some sort with the included change?
ra...@google.com <ra...@google.com> #11
Yeah we publish our snapshots via
Add this snippet to your build.gradle
file.
allprojects {
repositories {
google()
jcenter()
maven { url 'https://androidx.dev/snapshots/builds/6490637/artifacts/repository' }
}
}
Add this to your dependencies
block:
dependencies {
def work_version = '2.4.0-SNAPSHOT'
implementation "androidx.work:work-runtime:$work_version"
}
ar...@gmail.com <ar...@gmail.com> #12
Just checked the snapshot — works as expected. Thanks again!
ra...@google.com <ra...@google.com> #13
Thanks for confirming !
Description
Put the following code in the
Application
subclass and call thescheduleForegroundWork
method in theonCreate
one.Single
keeps working, the notification remains in place.Single
is disposed, the notification is hidden.Debug logs (2.4.0-alpha03):