Foreground RxJava work is never cancelled [156310133]

Fixed

Bug

Status Update

No update yet.

Description

ar...@gmail.com

created issue #1

May 12, 2020 06:55AM

WorkManager versions: 2.3.4, 2.4.0-alpha03
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.

Disable Wi-Fi.
Run the application.
Enable Wi-Fi.
Wait 5 seconds or so.
Disable Wi-Fi.
Results:
- Actual: work is not cancelled, the Single keeps working, the notification remains in place.
- Expected: work is cancelled, the Single is disposed, the notification is hidden.

private fun scheduleForegroundWork() {
    val workConstraints = Constraints.Builder()
        .setRequiredNetworkType(NetworkType.UNMETERED)
        .build()

    val workRequest = OneTimeWorkRequest.Builder(ForegroundWorker::class.java)
        .setConstraints(workConstraints)
        .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()
        }
        .flatMapObservable {
            Observable
                .interval(0, 1, TimeUnit.SECONDS)
                .switchMap {
                    println("Worker interval $it")
         
                    if (it > 60) {
                        Observable.just(Unit)
                    } else {
                        Observable.never()
                    }
                }
        }
        .firstOrError()
        .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)
        .setContentText("Hello there from the foreground work")
        .build()
}

Debug logs (2.4.0-alpha03):

// Open the application

WM-PackageManagerHelper: androidx.work.impl.background.systemjob.SystemJobService enabled
WM-Schedulers: Created SystemJobScheduler and enabled SystemJobService
WM-ForceStopRunnable: Performing cleanup operations.
WM-ForceStopRunnable: Application was force-stopped, rescheduling.
WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver enabled
WM-SystemJobScheduler: Scheduling work ID 8f1237eb-ea6c-415c-a512-c431c6ee985c Job ID 0
WM-GreedyScheduler: Starting tracking for [8f1237eb-ea6c-415c-a512-c431c6ee985c]
WM-ConstraintTracker: NetworkStateTracker: initial state = [ Connected=false Validated=false Metered=true NotRoaming=false ]
WM-NetworkStateTracker: Registering network callback
WM-GreedyScheduler: Constraints not met: Cancelling work ID 8f1237eb-ea6c-415c-a512-c431c6ee985c
WM-Processor: Processor stopping background work 8f1237eb-ea6c-415c-a512-c431c6ee985c
WM-Processor: WorkerWrapper could not be found for 8f1237eb-ea6c-415c-a512-c431c6ee985c
WM-StopWorkRunnable: StopWorkRunnable for 8f1237eb-ea6c-415c-a512-c431c6ee985c; Processor.stopWork = false

// Enable Wi-Fi

WM-NetworkStateTracker: Network capabilities changed: [ Transports: WIFI Capabilities: NOT_METERED&INTERNET&NOT_RESTRICTED&TRUSTED&NOT_VPN&NOT_ROAMING&FOREGROUND&NOT_CONGESTED&NOT_SUSPENDED LinkUpBandwidth>=1048576Kbps LinkDnBandwidth>=1048576Kbps SignalStrength: -30]
WM-WorkConstraintsTrack: Constraints met for 8f1237eb-ea6c-415c-a512-c431c6ee985c
WM-GreedyScheduler: Constraints met: Scheduling work ID 8f1237eb-ea6c-415c-a512-c431c6ee985c
WM-Processor: Processor: processing 8f1237eb-ea6c-415c-a512-c431c6ee985c
WM-WorkerWrapper: Starting work for PACKAGE.Application$ForegroundWorker
WM-Processor: Moving WorkSpec (8f1237eb-ea6c-415c-a512-c431c6ee985c) to the foreground
WM-SystemFgDispatcher: Started foreground service Intent { act=ACTION_START_FOREGROUND cmp=PACKAGE/androidx.work.impl.foreground.SystemForegroundService (has extras) }
WM-SystemFgDispatcher: Notifying with (id: 42, workSpecId: 8f1237eb-ea6c-415c-a512-c431c6ee985c, notificationType: 0)
WM-SystemFgDispatcher: Notifying with (id: 42, workSpecId: 8f1237eb-ea6c-415c-a512-c431c6ee985c, notificationType: 0)
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]
WM-WorkConstraintsTrack: Constraints met for 8f1237eb-ea6c-415c-a512-c431c6ee985c
WM-SystemJobService: onStartJob for 8f1237eb-ea6c-415c-a512-c431c6ee985c
WM-Processor: Processor: processing 8f1237eb-ea6c-415c-a512-c431c6ee985c
WM-WorkConstraintsTrack: Constraints met for 8f1237eb-ea6c-415c-a512-c431c6ee985c
WM-GreedyScheduler: Constraints met: Scheduling work ID 8f1237eb-ea6c-415c-a512-c431c6ee985c
WM-WorkConstraintsTrack: Constraints met for 8f1237eb-ea6c-415c-a512-c431c6ee985c
WM-WorkerWrapper: Status for 8f1237eb-ea6c-415c-a512-c431c6ee985c is RUNNING;not doing any work and rescheduling for later execution
WM-WorkerWrapper: PACKAGE.Application$ForegroundWorker is not in ENQUEUED state. Nothing more to do.
WM-Processor: Processor 8f1237eb-ea6c-415c-a512-c431c6ee985c executed; reschedule = true
WM-GreedyScheduler: Stopping tracking for 8f1237eb-ea6c-415c-a512-c431c6ee985c
WM-NetworkStateTracker: Unregistering network callback
WM-SystemJobService: 8f1237eb-ea6c-415c-a512-c431c6ee985c executed on JobScheduler
WM-Processor: Processor: processing 8f1237eb-ea6c-415c-a512-c431c6ee985c
WM-WorkerWrapper: Status for 8f1237eb-ea6c-415c-a512-c431c6ee985c is RUNNING;not doing any work and rescheduling for later execution
WM-Processor: Processor 8f1237eb-ea6c-415c-a512-c431c6ee985c executed; reschedule = true
WM-WorkerWrapper: PACKAGE.Application$ForegroundWorker is not in ENQUEUED state. Nothing more to do.

// Disable Wi-Fi (nothing is printed)

// Pass 60 seconds for Single to complete

WM-WorkerWrapper: PACKAGE.Application$ForegroundWorker returned a Success {mOutputData=Data {}} result.
WM-WorkerWrapper: Worker result SUCCESS for Work [ id=8f1237eb-ea6c-415c-a512-c431c6ee985c, tags={ PACKAGE.Application$ForegroundWorker } ]
WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver disabled
WM-Processor: No more foreground work. Stopping SystemForegroundService
WM-SystemFgDispatcher: Stopping foreground service
WM-SystemFgService: All commands completed.
WM-Processor: Processor 8f1237eb-ea6c-415c-a512-c431c6ee985c executed; reschedule = false
WM-GreedyScheduler: Cancelling work ID 8f1237eb-ea6c-415c-a512-c431c6ee985c
WM-Processor: Processor stopping background work 8f1237eb-ea6c-415c-a512-c431c6ee985c
WM-Processor: WorkerWrapper could not be found for 8f1237eb-ea6c-415c-a512-c431c6ee985c
WM-StopWorkRunnable: StopWorkRunnable for 8f1237eb-ea6c-415c-a512-c431c6ee985c; Processor.stopWork = false

Comments

ra...@google.com <ra...@google.com> #2May 12, 2020 04:34PM

https://android-review.googlesource.com/c/platform/frameworks/support/+/1092870

ar...@gmail.com <ar...@gmail.com> #3May 12, 2020 05:08PM

Thank you for the quick fix.
Is there an ETA for the next release?

work-manager-observable.zip

251 KB

Download

ra...@google.com <ra...@google.com> #4May 12, 2020 05:55PM

2.2.0-rc01 should be out this week.

ra...@google.com <ra...@google.com> #5May 12, 2020 05:57PM

Status: Won't Fix (Not Reproducible)

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

commit a1957df3709a06f4e6482fb0e4d39ded4f230a70
Author: Rahul Ravikumar <rahulrav@google.com>
Date: Mon Jul 29 09:48:05 2019

Workaround NPE in PersistableBundle.getExtras().

Test: Existing unit tests pass. Ran integration test app.
Fixes:

b/138441699

Change-Id: I0b48e0009a7d83c343a3d26112b94c057470c281

M work/workmanager/src/main/java/androidx/work/impl/background/systemjob/SystemJobService.java

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

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

ra...@google.com <ra...@google.com> #6May 12, 2020 05:57PM

The following changes were cherrypicked through Coastguard (

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

https://android-build.googleplex.com/coastguard/dashboard/6206758647365632/#/cherrypickHistory/all)
Created: 2019-07-29 19:41:55.445144+00:00
Changes: aosp/1092870

ar...@gmail.com <ar...@gmail.com> #7May 12, 2020 06:12PM

Yep, the verbose logging was enabled to produce logs in the initial comment.

Video with the reproducible scenario using the sample above.
Made new logs, attaching.

worker.txt

15 KB

View

Download

ra...@google.com <ra...@google.com> #8May 12, 2020 06:29PM

Assigned to ra...@google.com.

Okay, I think I know what might be going on. Thanks for the logs, that really helped.

ap...@google.com <ap...@google.com> #9May 12, 2020 08:04PM

Marked as fixed.

Project: platform/frameworks/support
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:

b/156310133

Test: Existing unit tests pass.
Change-Id: Ib4223565beeb983001bc51d8d45ee417ebf53d62

M work/workmanager/src/main/java/androidx/work/impl/Processor.java

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

ar...@gmail.com <ar...@gmail.com> #10May 13, 2020 05:40AM

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> #11May 13, 2020 02:55PM

Yeah we publish our snapshots via https://androidx.dev now. You can try using this:

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> #12May 13, 2020 03:16PM

Just checked the snapshot — works as expected. Thanks again!

ra...@google.com <ra...@google.com> #13May 13, 2020 03:43PM

Thanks for confirming !