RxJava foreground worker does not hide notification on success [168502234]

Fixed

Bug

Status Update

No update yet.

Description

ar...@gmail.com

created issue #1

Sep 15, 2020 05:46AM

WorkManager: 2.4.0
Device: Google Pixel 3a (Android 11), Google Pixel 1 (Android 10)

Don’t think the Android version matters here. The device might — we’ve observed that Google Pixel 4 (Android 10) does not suffer from this as often.

The sample application is attached. Steps to reproduce using it:

Run from Android Studio.
Observe system notification.
Results:
- Actual: sometimes notification is not hidden and remains shown forever. Multiple reruns might be required. Happens once per 3—5 attempts for me. Almost never happens on clean install.
- Expected: notification is hidden immediately.

Logs captured using custom configuration (level is set to DEBUG):

Fine behavior (notification is hidden eventually):

2020-09-15 08:37:48.462 7255-7255/com.sample D/WM-PackageManagerHelper: androidx.work.impl.background.systemjob.SystemJobService enabled
2020-09-15 08:37:48.462 7255-7255/com.sample D/WM-Schedulers: Created SystemJobScheduler and enabled SystemJobService
2020-09-15 08:37:48.475 7255-7292/com.sample D/WM-ForceStopRunnable: Performing cleanup operations.
2020-09-15 08:37:48.583 7255-7292/com.sample D/WM-ForceStopRunnable: Application was force-stopped, rescheduling.
2020-09-15 08:37:48.897 7255-7303/com.sample D/WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver enabled
2020-09-15 08:37:48.909 7255-7303/com.sample D/WM-SystemJobScheduler: Scheduling work ID 7aaf9d71-bd63-4ee9-9cef-54e6b8f7a556 Job ID 0
2020-09-15 08:37:48.989 7255-7303/com.sample D/WM-GreedyScheduler: Starting work for 7aaf9d71-bd63-4ee9-9cef-54e6b8f7a556
2020-09-15 08:37:48.996 7255-7306/com.sample D/WM-Processor: Processor: processing 7aaf9d71-bd63-4ee9-9cef-54e6b8f7a556
2020-09-15 08:37:49.005 7255-7255/com.sample D/WM-WorkerWrapper: Starting work for com.sample.WorkApplication$ForegroundWorker
2020-09-15 08:37:49.029 7255-7305/com.sample I/WM-Processor: Moving WorkSpec (7aaf9d71-bd63-4ee9-9cef-54e6b8f7a556) to the foreground
2020-09-15 08:37:49.044 7255-7255/com.sample I/WM-SystemFgDispatcher: Started foreground service Intent { act=ACTION_START_FOREGROUND cmp=com.sample/androidx.work.impl.foreground.SystemForegroundService (has extras) }
2020-09-15 08:37:49.045 7255-7309/com.sample D/WM-Foreground-Worker: I AM DONE!
2020-09-15 08:37:49.046 7255-7255/com.sample D/WM-SystemFgDispatcher: Notifying with (id: 42, workSpecId: 7aaf9d71-bd63-4ee9-9cef-54e6b8f7a556, notificationType: 0)
2020-09-15 08:37:49.046 7255-7306/com.sample D/WM-WorkerWrapper: com.sample.WorkApplication$ForegroundWorker returned a Success {mOutputData=Data {}} result.
2020-09-15 08:37:49.049 7255-7255/com.sample D/WM-SystemFgDispatcher: Notifying with (id: 42, workSpecId: 7aaf9d71-bd63-4ee9-9cef-54e6b8f7a556, notificationType: 0)
2020-09-15 08:37:49.050 7255-7306/com.sample I/WM-WorkerWrapper: Worker result SUCCESS for Work [ id=7aaf9d71-bd63-4ee9-9cef-54e6b8f7a556, tags={ com.sample.WorkApplication$ForegroundWorker } ]
2020-09-15 08:37:49.060 7255-7306/com.sample D/WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver disabled
2020-09-15 08:37:49.060 7255-7306/com.sample D/WM-Processor: No more foreground work. Stopping SystemForegroundService
2020-09-15 08:37:49.060 7255-7255/com.sample I/WM-SystemFgDispatcher: Stopping foreground service
2020-09-15 08:37:49.060 7255-7255/com.sample D/WM-SystemFgService: All commands completed.
2020-09-15 08:37:49.063 7255-7255/com.sample D/WM-Processor: Processor 7aaf9d71-bd63-4ee9-9cef-54e6b8f7a556 executed; reschedule = false
2020-09-15 08:37:49.063 7255-7255/com.sample D/WM-SystemJobService: 7aaf9d71-bd63-4ee9-9cef-54e6b8f7a556 executed on JobScheduler
2020-09-15 08:37:49.077 7255-7306/com.sample D/WM-GreedyScheduler: Cancelling work ID 7aaf9d71-bd63-4ee9-9cef-54e6b8f7a556
2020-09-15 08:37:49.089 7255-7306/com.sample D/WM-Processor: Processor stopping background work 7aaf9d71-bd63-4ee9-9cef-54e6b8f7a556
2020-09-15 08:37:49.089 7255-7306/com.sample D/WM-Processor: WorkerWrapper could not be found for 7aaf9d71-bd63-4ee9-9cef-54e6b8f7a556
2020-09-15 08:37:49.090 7255-7306/com.sample D/WM-StopWorkRunnable: StopWorkRunnable for 7aaf9d71-bd63-4ee9-9cef-54e6b8f7a556; Processor.stopWork = false

Diagnostics:

2020-09-15 08:38:37.896 7255-7255/com.sample D/WM-DiagnosticsRcvr: Requesting diagnostics
2020-09-15 08:38:37.905 7255-7305/com.sample D/WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver enabled
2020-09-15 08:38:37.917 7255-7305/com.sample D/WM-SystemJobScheduler: Scheduling work ID 2daaf311-db13-4f1d-ba96-f7e5af3070a4 Job ID 1
2020-09-15 08:38:37.924 7255-7305/com.sample D/WM-GreedyScheduler: Starting work for 2daaf311-db13-4f1d-ba96-f7e5af3070a4
2020-09-15 08:38:37.928 7255-7305/com.sample D/WM-Processor: Processor: processing 2daaf311-db13-4f1d-ba96-f7e5af3070a4
2020-09-15 08:38:37.931 7255-7255/com.sample D/WM-SystemJobService: onStartJob for 2daaf311-db13-4f1d-ba96-f7e5af3070a4
2020-09-15 08:38:37.940 7255-7305/com.sample D/WM-Processor: Work 2daaf311-db13-4f1d-ba96-f7e5af3070a4 is already enqueued for processing
2020-09-15 08:38:37.941 7255-7255/com.sample D/WM-WorkerWrapper: Starting work for androidx.work.impl.workers.DiagnosticsWorker
2020-09-15 08:38:37.946 7255-7338/com.sample I/WM-DiagnosticsWrkr: Recently completed work:
2020-09-15 08:38:37.949 7255-7338/com.sample I/WM-DiagnosticsWrkr:  Id 	 Class Name	 Job Id	 State	 Unique Name	 Tags	
    7aaf9d71-bd63-4ee9-9cef-54e6b8f7a556	 com.sample.WorkApplication$ForegroundWorker	 null	 SUCCEEDED	 foreground-work	 com.sample.WorkApplication$ForegroundWorker	
2020-09-15 08:38:37.949 7255-7338/com.sample I/WM-DiagnosticsWrkr: Running work:
2020-09-15 08:38:37.951 7255-7338/com.sample I/WM-DiagnosticsWrkr:  Id 	 Class Name	 Job Id	 State	 Unique Name	 Tags	
    2daaf311-db13-4f1d-ba96-f7e5af3070a4	 androidx.work.impl.workers.DiagnosticsWorker	 1	 RUNNING	 	 androidx.work.impl.workers.DiagnosticsWorker	
2020-09-15 08:38:37.952 7255-7306/com.sample D/WM-WorkerWrapper: androidx.work.impl.workers.DiagnosticsWorker returned a Success {mOutputData=Data {}} result.
2020-09-15 08:38:37.953 7255-7306/com.sample I/WM-WorkerWrapper: Worker result SUCCESS for Work [ id=2daaf311-db13-4f1d-ba96-f7e5af3070a4, tags={ androidx.work.impl.workers.DiagnosticsWorker } ]
2020-09-15 08:38:37.956 7255-7306/com.sample D/WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver disabled
2020-09-15 08:38:37.957 7255-7255/com.sample D/WM-Processor: Processor 2daaf311-db13-4f1d-ba96-f7e5af3070a4 executed; reschedule = false
2020-09-15 08:38:37.957 7255-7255/com.sample D/WM-SystemJobService: 2daaf311-db13-4f1d-ba96-f7e5af3070a4 executed on JobScheduler
2020-09-15 08:38:37.959 7255-7306/com.sample D/WM-GreedyScheduler: Cancelling work ID 2daaf311-db13-4f1d-ba96-f7e5af3070a4
2020-09-15 08:38:37.961 7255-7255/com.sample D/WM-SystemJobService: onStopJob for 2daaf311-db13-4f1d-ba96-f7e5af3070a4
2020-09-15 08:38:37.963 7255-7306/com.sample D/WM-Processor: Processor stopping background work 2daaf311-db13-4f1d-ba96-f7e5af3070a4
2020-09-15 08:38:37.964 7255-7306/com.sample D/WM-Processor: WorkerWrapper could not be found for 2daaf311-db13-4f1d-ba96-f7e5af3070a4
2020-09-15 08:38:37.964 7255-7306/com.sample D/WM-StopWorkRunnable: StopWorkRunnable for 2daaf311-db13-4f1d-ba96-f7e5af3070a4; Processor.stopWork = false
2020-09-15 08:38:37.965 7255-7305/com.sample D/WM-Processor: Processor stopping background work 2daaf311-db13-4f1d-ba96-f7e5af3070a4
2020-09-15 08:38:37.965 7255-7305/com.sample D/WM-Processor: WorkerWrapper could not be found for 2daaf311-db13-4f1d-ba96-f7e5af3070a4
2020-09-15 08:38:37.965 7255-7305/com.sample D/WM-StopWorkRunnable: StopWorkRunnable for 2daaf311-db13-4f1d-ba96-f7e5af3070a4; Processor.stopWork = false

Issue behavior (notification is not hidden):

2020-09-15 08:42:01.792 8542-8542/com.sample D/WM-PackageManagerHelper: androidx.work.impl.background.systemjob.SystemJobService enabled
2020-09-15 08:42:01.793 8542-8542/com.sample D/WM-Schedulers: Created SystemJobScheduler and enabled SystemJobService
2020-09-15 08:42:01.800 8542-8564/com.sample D/WM-ForceStopRunnable: Performing cleanup operations.
2020-09-15 08:42:01.846 8542-8568/com.sample D/WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver enabled
2020-09-15 08:42:01.859 8542-8568/com.sample D/WM-SystemJobScheduler: Scheduling work ID 543e6b41-9099-42d0-9330-1be877dfed5c Job ID 2
2020-09-15 08:42:01.864 8542-8568/com.sample D/WM-GreedyScheduler: Starting work for 543e6b41-9099-42d0-9330-1be877dfed5c
2020-09-15 08:42:01.871 8542-8570/com.sample D/WM-Processor: Processor: processing 543e6b41-9099-42d0-9330-1be877dfed5c
2020-09-15 08:42:01.932 8542-8542/com.sample D/WM-WorkerWrapper: Starting work for com.sample.WorkApplication$ForegroundWorker
2020-09-15 08:42:01.953 8542-8542/com.sample D/WM-SystemJobService: onStartJob for 543e6b41-9099-42d0-9330-1be877dfed5c
2020-09-15 08:42:01.954 8542-8569/com.sample D/WM-Processor: Work 543e6b41-9099-42d0-9330-1be877dfed5c is already enqueued for processing
2020-09-15 08:42:01.956 8542-8569/com.sample I/WM-Processor: Moving WorkSpec (543e6b41-9099-42d0-9330-1be877dfed5c) to the foreground
2020-09-15 08:42:01.966 8542-8573/com.sample D/WM-Foreground-Worker: I AM DONE!
2020-09-15 08:42:01.967 8542-8570/com.sample D/WM-WorkerWrapper: com.sample.WorkApplication$ForegroundWorker returned a Success {mOutputData=Data {}} result.
2020-09-15 08:42:01.968 8542-8570/com.sample I/WM-WorkerWrapper: Worker result SUCCESS for Work [ id=543e6b41-9099-42d0-9330-1be877dfed5c, tags={ com.sample.WorkApplication$ForegroundWorker } ]
2020-09-15 08:42:01.974 8542-8570/com.sample D/WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver disabled
2020-09-15 08:42:01.974 8542-8570/com.sample D/WM-Processor: No more foreground work. Stopping SystemForegroundService
2020-09-15 08:42:01.976 8542-8542/com.sample I/WM-SystemFgDispatcher: Started foreground service Intent { act=ACTION_START_FOREGROUND cmp=com.sample/androidx.work.impl.foreground.SystemForegroundService (has extras) }
2020-09-15 08:42:01.977 8542-8542/com.sample D/WM-SystemFgDispatcher: Notifying with (id: 42, workSpecId: 543e6b41-9099-42d0-9330-1be877dfed5c, notificationType: 0)
2020-09-15 08:42:01.979 8542-8542/com.sample D/WM-SystemFgDispatcher: Notifying with (id: 42, workSpecId: 543e6b41-9099-42d0-9330-1be877dfed5c, notificationType: 0)
2020-09-15 08:42:01.980 8542-8570/com.sample D/WM-GreedyScheduler: Cancelling work ID 543e6b41-9099-42d0-9330-1be877dfed5c
2020-09-15 08:42:01.981 8542-8542/com.sample I/WM-SystemFgDispatcher: Stopping foreground service
2020-09-15 08:42:01.981 8542-8542/com.sample D/WM-SystemFgService: All commands completed.
2020-09-15 08:42:01.982 8542-8542/com.sample D/WM-Processor: Processor 543e6b41-9099-42d0-9330-1be877dfed5c executed; reschedule = false
2020-09-15 08:42:01.982 8542-8542/com.sample D/WM-SystemJobService: 543e6b41-9099-42d0-9330-1be877dfed5c executed on JobScheduler
2020-09-15 08:42:01.983 8542-8542/com.sample D/WM-SystemJobService: onStopJob for 543e6b41-9099-42d0-9330-1be877dfed5c
2020-09-15 08:42:01.990 8542-8564/com.sample D/WM-Processor: Processor stopping background work 543e6b41-9099-42d0-9330-1be877dfed5c
2020-09-15 08:42:01.990 8542-8564/com.sample D/WM-Processor: WorkerWrapper could not be found for 543e6b41-9099-42d0-9330-1be877dfed5c
2020-09-15 08:42:01.990 8542-8564/com.sample D/WM-StopWorkRunnable: StopWorkRunnable for 543e6b41-9099-42d0-9330-1be877dfed5c; Processor.stopWork = false
2020-09-15 08:42:01.992 8542-8564/com.sample D/WM-Processor: Processor stopping background work 543e6b41-9099-42d0-9330-1be877dfed5c
2020-09-15 08:42:01.992 8542-8564/com.sample D/WM-Processor: WorkerWrapper could not be found for 543e6b41-9099-42d0-9330-1be877dfed5c
2020-09-15 08:42:01.992 8542-8564/com.sample D/WM-StopWorkRunnable: StopWorkRunnable for 543e6b41-9099-42d0-9330-1be877dfed5c; Processor.stopWork = false

Diagnostics:

2020-09-15 08:42:46.313 8542-8542/com.sample D/WM-DiagnosticsRcvr: Requesting diagnostics
2020-09-15 08:42:46.325 8542-8568/com.sample D/WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver enabled
2020-09-15 08:42:46.337 8542-8568/com.sample D/WM-SystemJobScheduler: Scheduling work ID a13fe29d-e9cf-4444-ba4d-98c7d31e3308 Job ID 3
2020-09-15 08:42:46.351 8542-8542/com.sample D/WM-SystemJobService: onStartJob for a13fe29d-e9cf-4444-ba4d-98c7d31e3308
2020-09-15 08:42:46.357 8542-8568/com.sample D/WM-GreedyScheduler: Starting work for a13fe29d-e9cf-4444-ba4d-98c7d31e3308
2020-09-15 08:42:46.361 8542-8570/com.sample D/WM-Processor: Processor: processing a13fe29d-e9cf-4444-ba4d-98c7d31e3308
2020-09-15 08:42:46.361 8542-8570/com.sample D/WM-Processor: Work a13fe29d-e9cf-4444-ba4d-98c7d31e3308 is already enqueued for processing
2020-09-15 08:42:46.372 8542-8542/com.sample D/WM-WorkerWrapper: Starting work for androidx.work.impl.workers.DiagnosticsWorker
2020-09-15 08:42:46.387 8542-8601/com.sample I/WM-DiagnosticsWrkr: Recently completed work:
2020-09-15 08:42:46.397 8542-8601/com.sample I/WM-DiagnosticsWrkr:  Id 	 Class Name	 Job Id	 State	 Unique Name	 Tags	
    543e6b41-9099-42d0-9330-1be877dfed5c	 com.sample.WorkApplication$ForegroundWorker	 null	 SUCCEEDED	 foreground-work	 com.sample.WorkApplication$ForegroundWorker	
2020-09-15 08:42:46.397 8542-8601/com.sample I/WM-DiagnosticsWrkr: Running work:
2020-09-15 08:42:46.401 8542-8601/com.sample I/WM-DiagnosticsWrkr:  Id 	 Class Name	 Job Id	 State	 Unique Name	 Tags	
    a13fe29d-e9cf-4444-ba4d-98c7d31e3308	 androidx.work.impl.workers.DiagnosticsWorker	 3	 RUNNING	 	 androidx.work.impl.workers.DiagnosticsWorker	
2020-09-15 08:42:46.403 8542-8564/com.sample D/WM-WorkerWrapper: androidx.work.impl.workers.DiagnosticsWorker returned a Success {mOutputData=Data {}} result.
2020-09-15 08:42:46.405 8542-8564/com.sample I/WM-WorkerWrapper: Worker result SUCCESS for Work [ id=a13fe29d-e9cf-4444-ba4d-98c7d31e3308, tags={ androidx.work.impl.workers.DiagnosticsWorker } ]
2020-09-15 08:42:46.410 8542-8564/com.sample D/WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver disabled
2020-09-15 08:42:46.412 8542-8542/com.sample D/WM-Processor: Processor a13fe29d-e9cf-4444-ba4d-98c7d31e3308 executed; reschedule = false
2020-09-15 08:42:46.412 8542-8542/com.sample D/WM-SystemJobService: a13fe29d-e9cf-4444-ba4d-98c7d31e3308 executed on JobScheduler
2020-09-15 08:42:46.419 8542-8564/com.sample D/WM-GreedyScheduler: Cancelling work ID a13fe29d-e9cf-4444-ba4d-98c7d31e3308
2020-09-15 08:42:46.428 8542-8564/com.sample D/WM-Processor: Processor stopping background work a13fe29d-e9cf-4444-ba4d-98c7d31e3308
2020-09-15 08:42:46.428 8542-8564/com.sample D/WM-Processor: WorkerWrapper could not be found for a13fe29d-e9cf-4444-ba4d-98c7d31e3308
2020-09-15 08:42:46.429 8542-8564/com.sample D/WM-StopWorkRunnable: StopWorkRunnable for a13fe29d-e9cf-4444-ba4d-98c7d31e3308; Processor.stopWork = false

work-manager-notification.zip

68 KB

Download

Comments

ra...@google.com <ra...@google.com> #2Sep 16, 2020 08:08PM

Yigit, do you have time to fix it?

reemission of the same liveData is racy

ar...@gmail.com <ar...@gmail.com> #3Sep 16, 2020 08:13PM

yea i'll take it.

ra...@google.com <ra...@google.com> #4Sep 16, 2020 08:26PM

Thanks for the detailed analysis. This may not be an issue anymore since we've started using Main.immediate there but I' not sure; I'll try to create a test case.

ar...@gmail.com <ar...@gmail.com> #5Sep 17, 2020 05:57AM

just emitting same live data reproduces the issue.

@Test
fun raceTest() {
val subLiveData = MutableLiveData(1)
val subject = liveData(testScope.coroutineContext) {
emitSource(subLiveData)
emitSource(subLiveData) //crashes
}
subject.addObserver().apply {
testScope.advanceUntilIdle()
}
}

ra...@google.com <ra...@google.com> Sep 17, 2020 06:56PM

Assigned to ra...@google.com.

ap...@google.com <ap...@google.com> #6Sep 18, 2020 05:21AM

Marked as fixed.

With 2.2.0-alpha04 (that use Main.immediate), the issue seems to be still there (I tested it by calling emitSource() twice, like your test case)

ap...@google.com <ap...@google.com> #7Sep 18, 2020 05:22AM

yea sorry immediate does not fix it.
I actually have a WIP fix for it:

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

if your case is the one i found (emitting same LiveData multiple times, as shown in #5) you can work around it by adding a dummy transformation.

val subLiveData = MutableLiveData(1)
val subject = liveData(testScope.coroutineContext) {
emitSource(subLiveData.map {it })
emitSource(subLiveData.map {it} )
}

ar...@gmail.com <ar...@gmail.com> #8Sep 18, 2020 08:57AM

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

commit af12e75e6b4110f48e44ca121466943909de8f06
Author: Yigit Boyar <yboyar@google.com>
Date: Tue Sep 03 12:58:11 2019

Fix coroutine livedata race condition

This CL fixes a bug in liveData builder where emitting same
LiveData source twice would make it crash because the second
emission registry could possibly happen before first one is
removed as source.

We fix it by using a suspending dispose function. It does feel
a bit hacky but we cannot make DisposableHandle.dispose async
and we do not want to block there. This does not mean that there
is a problem if developer disposes it manually since our emit
functions take care of making sure it disposes (and there is
no other way to add source to the underlying MediatorLiveData)

Bug: 140249349
Test: BuildLiveDataTest#raceTest_*

Change-Id: I0b464c242a583da4669af195cf2504e2adc4de40

M lifecycle/lifecycle-livedata-ktx/api/2.2.0-alpha05.txt
M lifecycle/lifecycle-livedata-ktx/api/current.txt
M lifecycle/lifecycle-livedata-ktx/api/public_plus_experimental_2.2.0-alpha05.txt
M lifecycle/lifecycle-livedata-ktx/api/public_plus_experimental_current.txt
M lifecycle/lifecycle-livedata-ktx/api/restricted_2.2.0-alpha05.txt
M lifecycle/lifecycle-livedata-ktx/api/restricted_current.txt
M lifecycle/lifecycle-livedata-ktx/src/main/java/androidx/lifecycle/CoroutineLiveData.kt
M lifecycle/lifecycle-livedata-ktx/src/test/java/androidx/lifecycle/BuildLiveDataTest.kt

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

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

ra...@google.com <ra...@google.com> #9Sep 18, 2020 05:05PM

Yes, you can use the latest snapshot from here: https://androidx.dev/

Pick the latest buildId from here: https://androidx.dev/snapshots/builds

ar...@gmail.com <ar...@gmail.com> #10Sep 21, 2020 05:49AM

Unfortunately still happens using 6850853 and 2.5.0-SNAPSHOT.

Logs when notification wasn’t hidden:

2020-09-21 08:43:11.098 17842-17842/com.sample D/WM-PackageManagerHelper: androidx.work.impl.background.systemjob.SystemJobService enabled
2020-09-21 08:43:11.099 17842-17842/com.sample D/WM-Schedulers: Created SystemJobScheduler and enabled SystemJobService
2020-09-21 08:43:11.112 17842-17864/com.sample D/WM-WorkManagerImpl: Unable to initialize multi-process support
    java.lang.ClassNotFoundException: androidx.work.multiprocess.RemoteWorkManagerClient
        at java.lang.Class.classForName(Native Method)
        at java.lang.Class.forName(Class.java:454)
        at java.lang.Class.forName(Class.java:379)
        at androidx.work.impl.WorkManagerImpl.tryInitializeMultiProcessSupport(WorkManagerImpl.java:789)
        at androidx.work.impl.WorkManagerImpl.getRemoteWorkManager(WorkManagerImpl.java:620)
        at androidx.work.impl.utils.ForceStopRunnable.multiProcessChecks(ForceStopRunnable.java:215)
        at androidx.work.impl.utils.ForceStopRunnable.run(ForceStopRunnable.java:85)
        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:923)
     Caused by: java.lang.ClassNotFoundException: Didn't find class "androidx.work.multiprocess.RemoteWorkManagerClient" on path: DexPathList[[zip file "/data/app/~~pznhiTJaz8mu2OlB1YnkvQ==/com.sample-a0bfoO8aHcj3liE7R1MTLw==/base.apk"],nativeLibraryDirectories=[/data/app/~~pznhiTJaz8mu2OlB1YnkvQ==/com.sample-a0bfoO8aHcj3liE7R1MTLw==/lib/arm64, /system/lib64, /system_ext/lib64, /product/lib64]]
        at dalvik.system.BaseDexClassLoader.findClass(BaseDexClassLoader.java:207)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:379)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:312)
        at java.lang.Class.classForName(Native Method) 
        at java.lang.Class.forName(Class.java:454) 
        at java.lang.Class.forName(Class.java:379) 
        at androidx.work.impl.WorkManagerImpl.tryInitializeMultiProcessSupport(WorkManagerImpl.java:789) 
        at androidx.work.impl.WorkManagerImpl.getRemoteWorkManager(WorkManagerImpl.java:620) 
        at androidx.work.impl.utils.ForceStopRunnable.multiProcessChecks(ForceStopRunnable.java:215) 
        at androidx.work.impl.utils.ForceStopRunnable.run(ForceStopRunnable.java:85) 
        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:923) 
2020-09-21 08:43:11.113 17842-17864/com.sample D/WM-ForceStopRunnable: Performing cleanup operations.
2020-09-21 08:43:11.160 17842-17868/com.sample D/WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver enabled
2020-09-21 08:43:11.175 17842-17868/com.sample D/WM-SystemJobScheduler: Scheduling work ID 4424568b-8425-4f4b-bfc9-07660a579b9d Job ID 7
2020-09-21 08:43:11.179 17842-17868/com.sample D/WM-GreedyScheduler: Starting work for 4424568b-8425-4f4b-bfc9-07660a579b9d
2020-09-21 08:43:11.186 17842-17870/com.sample D/WM-Processor: Processor: processing 4424568b-8425-4f4b-bfc9-07660a579b9d
2020-09-21 08:43:11.254 17842-17842/com.sample D/WM-WorkerWrapper: Starting work for com.sample.WorkApplication$ForegroundWorker
2020-09-21 08:43:11.273 17842-17842/com.sample D/WM-SystemJobService: onStartJob for 4424568b-8425-4f4b-bfc9-07660a579b9d
2020-09-21 08:43:11.274 17842-17869/com.sample D/WM-Processor: Work 4424568b-8425-4f4b-bfc9-07660a579b9d is already enqueued for processing
2020-09-21 08:43:11.276 17842-17869/com.sample I/WM-Processor: Moving WorkSpec (4424568b-8425-4f4b-bfc9-07660a579b9d) to the foreground
2020-09-21 08:43:11.295 17842-17873/com.sample D/WM-Foreground-Worker: I AM DONE!
2020-09-21 08:43:11.295 17842-17842/com.sample I/WM-SystemFgDispatcher: Started foreground service Intent { act=ACTION_START_FOREGROUND cmp=com.sample/androidx.work.impl.foreground.SystemForegroundService (has extras) }
2020-09-21 08:43:11.296 17842-17868/com.sample D/WM-WorkerWrapper: com.sample.WorkApplication$ForegroundWorker returned a Success {mOutputData=Data {}} result.
2020-09-21 08:43:11.298 17842-17868/com.sample I/WM-WorkerWrapper: Worker result SUCCESS for Work [ id=4424568b-8425-4f4b-bfc9-07660a579b9d, tags={ com.sample.WorkApplication$ForegroundWorker } ]
2020-09-21 08:43:11.301 17842-17868/com.sample D/WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver disabled
2020-09-21 08:43:11.301 17842-17842/com.sample D/WM-SystemFgDispatcher: Notifying with (id: 42, workSpecId: 4424568b-8425-4f4b-bfc9-07660a579b9d, notificationType: 0)
2020-09-21 08:43:11.305 17842-17842/com.sample D/WM-SystemFgDispatcher: Notifying with (id: 42, workSpecId: 4424568b-8425-4f4b-bfc9-07660a579b9d, notificationType: 0)
2020-09-21 08:43:11.309 17842-17842/com.sample I/WM-SystemFgDispatcher: Stopping foreground service
2020-09-21 08:43:11.309 17842-17868/com.sample D/WM-GreedyScheduler: Cancelling work ID 4424568b-8425-4f4b-bfc9-07660a579b9d
2020-09-21 08:43:11.309 17842-17842/com.sample D/WM-SystemFgService: All commands completed.
2020-09-21 08:43:11.312 17842-17842/com.sample D/WM-Processor: Processor 4424568b-8425-4f4b-bfc9-07660a579b9d executed; reschedule = false
2020-09-21 08:43:11.313 17842-17842/com.sample D/WM-SystemJobService: 4424568b-8425-4f4b-bfc9-07660a579b9d executed on JobScheduler
2020-09-21 08:43:11.313 17842-17842/com.sample D/WM-SystemFgDispatcher: Removing Notification (id: 42, workSpecId: 4424568b-8425-4f4b-bfc9-07660a579b9d ,notificationType: 0)
2020-09-21 08:43:11.315 17842-17842/com.sample D/WM-SystemJobService: onStopJob for 4424568b-8425-4f4b-bfc9-07660a579b9d
2020-09-21 08:43:11.320 17842-17868/com.sample D/WM-Processor: Processor stopping background work 4424568b-8425-4f4b-bfc9-07660a579b9d
2020-09-21 08:43:11.321 17842-17868/com.sample D/WM-Processor: WorkerWrapper could not be found for 4424568b-8425-4f4b-bfc9-07660a579b9d
2020-09-21 08:43:11.321 17842-17868/com.sample D/WM-StopWorkRunnable: StopWorkRunnable for 4424568b-8425-4f4b-bfc9-07660a579b9d; Processor.stopWork = false
2020-09-21 08:43:11.322 17842-17868/com.sample D/WM-Processor: Processor stopping background work 4424568b-8425-4f4b-bfc9-07660a579b9d
2020-09-21 08:43:11.322 17842-17868/com.sample D/WM-Processor: WorkerWrapper could not be found for 4424568b-8425-4f4b-bfc9-07660a579b9d
2020-09-21 08:43:11.322 17842-17868/com.sample D/WM-StopWorkRunnable: StopWorkRunnable for 4424568b-8425-4f4b-bfc9-07660a579b9d; Processor.stopWork = false

Corresponding diagnostics:

2020-09-21 08:47:19.149 17842-17842/com.sample D/WM-DiagnosticsRcvr: Requesting diagnostics
2020-09-21 08:47:19.161 17842-17864/com.sample D/WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver enabled
2020-09-21 08:47:19.178 17842-17864/com.sample D/WM-SystemJobScheduler: Scheduling work ID 81c3ccd7-43fa-411e-b319-00572086249b Job ID 8
2020-09-21 08:47:19.188 17842-17864/com.sample D/WM-GreedyScheduler: Starting work for 81c3ccd7-43fa-411e-b319-00572086249b
2020-09-21 08:47:19.192 17842-17870/com.sample D/WM-Processor: Processor: processing 81c3ccd7-43fa-411e-b319-00572086249b
2020-09-21 08:47:19.195 17842-17842/com.sample D/WM-SystemJobService: onStartJob for 81c3ccd7-43fa-411e-b319-00572086249b
2020-09-21 08:47:19.211 17842-17870/com.sample D/WM-Processor: Work 81c3ccd7-43fa-411e-b319-00572086249b is already enqueued for processing
2020-09-21 08:47:19.211 17842-17842/com.sample D/WM-WorkerWrapper: Starting work for androidx.work.impl.workers.DiagnosticsWorker
2020-09-21 08:47:19.224 17842-18039/com.sample I/WM-DiagnosticsWrkr: Recently completed work:
2020-09-21 08:47:19.231 17842-18039/com.sample I/WM-DiagnosticsWrkr:  Id 	 Class Name	 Job Id	 State	 Unique Name	 Tags	
    4424568b-8425-4f4b-bfc9-07660a579b9d	 com.sample.WorkApplication$ForegroundWorker	 null	 SUCCEEDED	 foreground-work	 com.sample.WorkApplication$ForegroundWorker	
2020-09-21 08:47:19.231 17842-18039/com.sample I/WM-DiagnosticsWrkr: Running work:
2020-09-21 08:47:19.236 17842-18039/com.sample I/WM-DiagnosticsWrkr:  Id 	 Class Name	 Job Id	 State	 Unique Name	 Tags	
    81c3ccd7-43fa-411e-b319-00572086249b	 androidx.work.impl.workers.DiagnosticsWorker	 8	 RUNNING	 	 androidx.work.impl.workers.DiagnosticsWorker	
2020-09-21 08:47:19.237 17842-17868/com.sample D/WM-WorkerWrapper: androidx.work.impl.workers.DiagnosticsWorker returned a Success {mOutputData=Data {}} result.
2020-09-21 08:47:19.240 17842-17868/com.sample I/WM-WorkerWrapper: Worker result SUCCESS for Work [ id=81c3ccd7-43fa-411e-b319-00572086249b, tags={ androidx.work.impl.workers.DiagnosticsWorker } ]
2020-09-21 08:47:19.246 17842-17868/com.sample D/WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver disabled
2020-09-21 08:47:19.248 17842-17842/com.sample D/WM-Processor: Processor 81c3ccd7-43fa-411e-b319-00572086249b executed; reschedule = false
2020-09-21 08:47:19.248 17842-17842/com.sample D/WM-SystemJobService: 81c3ccd7-43fa-411e-b319-00572086249b executed on JobScheduler
2020-09-21 08:47:19.272 17842-17868/com.sample D/WM-GreedyScheduler: Cancelling work ID 81c3ccd7-43fa-411e-b319-00572086249b
2020-09-21 08:47:19.279 17842-17868/com.sample D/WM-Processor: Processor stopping background work 81c3ccd7-43fa-411e-b319-00572086249b
2020-09-21 08:47:19.280 17842-17868/com.sample D/WM-Processor: WorkerWrapper could not be found for 81c3ccd7-43fa-411e-b319-00572086249b
2020-09-21 08:47:19.280 17842-17868/com.sample D/WM-StopWorkRunnable: StopWorkRunnable for 81c3ccd7-43fa-411e-b319-00572086249b; Processor.stopWork = false

Logs when notification was hidden (hides with 5 second timeout visually if this matters):

2020-09-21 08:48:14.677 18220-18220/com.sample D/WM-PackageManagerHelper: androidx.work.impl.background.systemjob.SystemJobService enabled
2020-09-21 08:48:14.677 18220-18220/com.sample D/WM-Schedulers: Created SystemJobScheduler and enabled SystemJobService
2020-09-21 08:48:14.686 18220-18242/com.sample D/WM-WorkManagerImpl: Unable to initialize multi-process support
    java.lang.ClassNotFoundException: androidx.work.multiprocess.RemoteWorkManagerClient
        at java.lang.Class.classForName(Native Method)
        at java.lang.Class.forName(Class.java:454)
        at java.lang.Class.forName(Class.java:379)
        at androidx.work.impl.WorkManagerImpl.tryInitializeMultiProcessSupport(WorkManagerImpl.java:789)
        at androidx.work.impl.WorkManagerImpl.getRemoteWorkManager(WorkManagerImpl.java:620)
        at androidx.work.impl.utils.ForceStopRunnable.multiProcessChecks(ForceStopRunnable.java:215)
        at androidx.work.impl.utils.ForceStopRunnable.run(ForceStopRunnable.java:85)
        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:923)
     Caused by: java.lang.ClassNotFoundException: Didn't find class "androidx.work.multiprocess.RemoteWorkManagerClient" on path: DexPathList[[zip file "/data/app/~~pznhiTJaz8mu2OlB1YnkvQ==/com.sample-a0bfoO8aHcj3liE7R1MTLw==/base.apk"],nativeLibraryDirectories=[/data/app/~~pznhiTJaz8mu2OlB1YnkvQ==/com.sample-a0bfoO8aHcj3liE7R1MTLw==/lib/arm64, /system/lib64, /system_ext/lib64, /product/lib64]]
        at dalvik.system.BaseDexClassLoader.findClass(BaseDexClassLoader.java:207)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:379)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:312)
        at java.lang.Class.classForName(Native Method) 
        at java.lang.Class.forName(Class.java:454) 
        at java.lang.Class.forName(Class.java:379) 
        at androidx.work.impl.WorkManagerImpl.tryInitializeMultiProcessSupport(WorkManagerImpl.java:789) 
        at androidx.work.impl.WorkManagerImpl.getRemoteWorkManager(WorkManagerImpl.java:620) 
        at androidx.work.impl.utils.ForceStopRunnable.multiProcessChecks(ForceStopRunnable.java:215) 
        at androidx.work.impl.utils.ForceStopRunnable.run(ForceStopRunnable.java:85) 
        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:923) 
2020-09-21 08:48:14.686 18220-18242/com.sample D/WM-ForceStopRunnable: Performing cleanup operations.
2020-09-21 08:48:14.729 18220-18246/com.sample D/WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver enabled
2020-09-21 08:48:14.739 18220-18246/com.sample D/WM-SystemJobScheduler: Scheduling work ID 2e0eb977-ff9b-4bf3-9c59-2b5c585ee475 Job ID 10
2020-09-21 08:48:14.744 18220-18246/com.sample D/WM-GreedyScheduler: Starting work for 2e0eb977-ff9b-4bf3-9c59-2b5c585ee475
2020-09-21 08:48:14.750 18220-18248/com.sample D/WM-Processor: Processor: processing 2e0eb977-ff9b-4bf3-9c59-2b5c585ee475
2020-09-21 08:48:14.819 18220-18220/com.sample D/WM-WorkerWrapper: Starting work for com.sample.WorkApplication$ForegroundWorker
2020-09-21 08:48:14.838 18220-18220/com.sample D/WM-SystemJobService: onStartJob for 2e0eb977-ff9b-4bf3-9c59-2b5c585ee475
2020-09-21 08:48:14.838 18220-18247/com.sample D/WM-Processor: Work 2e0eb977-ff9b-4bf3-9c59-2b5c585ee475 is already enqueued for processing
2020-09-21 08:48:14.841 18220-18248/com.sample I/WM-Processor: Moving WorkSpec (2e0eb977-ff9b-4bf3-9c59-2b5c585ee475) to the foreground
2020-09-21 08:48:14.854 18220-18251/com.sample D/WM-Foreground-Worker: I AM DONE!
2020-09-21 08:48:14.855 18220-18242/com.sample D/WM-WorkerWrapper: com.sample.WorkApplication$ForegroundWorker returned a Success {mOutputData=Data {}} result.
2020-09-21 08:48:14.856 18220-18220/com.sample I/WM-SystemFgDispatcher: Started foreground service Intent { act=ACTION_START_FOREGROUND cmp=com.sample/androidx.work.impl.foreground.SystemForegroundService (has extras) }
2020-09-21 08:48:14.856 18220-18220/com.sample D/WM-SystemFgDispatcher: Notifying with (id: 42, workSpecId: 2e0eb977-ff9b-4bf3-9c59-2b5c585ee475, notificationType: 0)
2020-09-21 08:48:14.858 18220-18242/com.sample I/WM-WorkerWrapper: Worker result SUCCESS for Work [ id=2e0eb977-ff9b-4bf3-9c59-2b5c585ee475, tags={ com.sample.WorkApplication$ForegroundWorker } ]
2020-09-21 08:48:14.858 18220-18220/com.sample D/WM-SystemFgDispatcher: Notifying with (id: 42, workSpecId: 2e0eb977-ff9b-4bf3-9c59-2b5c585ee475, notificationType: 0)
2020-09-21 08:48:14.861 18220-18242/com.sample D/WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver disabled
2020-09-21 08:48:14.864 18220-18220/com.sample I/WM-SystemFgDispatcher: Stopping foreground service
2020-09-21 08:48:14.864 18220-18220/com.sample D/WM-SystemFgService: All commands completed.
2020-09-21 08:48:14.866 18220-18220/com.sample D/WM-Processor: Processor 2e0eb977-ff9b-4bf3-9c59-2b5c585ee475 executed; reschedule = false
2020-09-21 08:48:14.866 18220-18220/com.sample D/WM-SystemJobService: 2e0eb977-ff9b-4bf3-9c59-2b5c585ee475 executed on JobScheduler
2020-09-21 08:48:14.866 18220-18220/com.sample D/WM-SystemFgDispatcher: Removing Notification (id: 42, workSpecId: 2e0eb977-ff9b-4bf3-9c59-2b5c585ee475 ,notificationType: 0)
2020-09-21 08:48:14.868 18220-18242/com.sample D/WM-GreedyScheduler: Cancelling work ID 2e0eb977-ff9b-4bf3-9c59-2b5c585ee475
2020-09-21 08:48:14.872 18220-18220/com.sample D/WM-SystemJobService: onStopJob for 2e0eb977-ff9b-4bf3-9c59-2b5c585ee475
2020-09-21 08:48:14.874 18220-18246/com.sample D/WM-Processor: Processor stopping background work 2e0eb977-ff9b-4bf3-9c59-2b5c585ee475
2020-09-21 08:48:14.874 18220-18246/com.sample D/WM-Processor: WorkerWrapper could not be found for 2e0eb977-ff9b-4bf3-9c59-2b5c585ee475
2020-09-21 08:48:14.875 18220-18246/com.sample D/WM-StopWorkRunnable: StopWorkRunnable for 2e0eb977-ff9b-4bf3-9c59-2b5c585ee475; Processor.stopWork = false
2020-09-21 08:48:14.876 18220-18246/com.sample D/WM-Processor: Processor stopping background work 2e0eb977-ff9b-4bf3-9c59-2b5c585ee475
2020-09-21 08:48:14.876 18220-18246/com.sample D/WM-Processor: WorkerWrapper could not be found for 2e0eb977-ff9b-4bf3-9c59-2b5c585ee475
2020-09-21 08:48:14.876 18220-18246/com.sample D/WM-StopWorkRunnable: StopWorkRunnable for 2e0eb977-ff9b-4bf3-9c59-2b5c585ee475; Processor.stopWork = false

Corresponding diagnostics:

2020-09-21 08:48:56.601 18220-18220/com.sample D/WM-DiagnosticsRcvr: Requesting diagnostics
2020-09-21 08:48:56.610 18220-18242/com.sample D/WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver enabled
2020-09-21 08:48:56.627 18220-18242/com.sample D/WM-SystemJobScheduler: Scheduling work ID 1c7aaff0-5304-4645-b4a8-35c9511c3df3 Job ID 11
2020-09-21 08:48:56.635 18220-18242/com.sample D/WM-GreedyScheduler: Starting work for 1c7aaff0-5304-4645-b4a8-35c9511c3df3
2020-09-21 08:48:56.640 18220-18248/com.sample D/WM-Processor: Processor: processing 1c7aaff0-5304-4645-b4a8-35c9511c3df3
2020-09-21 08:48:56.649 18220-18220/com.sample D/WM-SystemJobService: onStartJob for 1c7aaff0-5304-4645-b4a8-35c9511c3df3
2020-09-21 08:48:56.657 18220-18220/com.sample D/WM-WorkerWrapper: Starting work for androidx.work.impl.workers.DiagnosticsWorker
2020-09-21 08:48:56.658 18220-18248/com.sample D/WM-Processor: Work 1c7aaff0-5304-4645-b4a8-35c9511c3df3 is already enqueued for processing
2020-09-21 08:48:56.668 18220-18280/com.sample I/WM-DiagnosticsWrkr: Recently completed work:
2020-09-21 08:48:56.676 18220-18280/com.sample I/WM-DiagnosticsWrkr:  Id 	 Class Name	 Job Id	 State	 Unique Name	 Tags	
    2e0eb977-ff9b-4bf3-9c59-2b5c585ee475	 com.sample.WorkApplication$ForegroundWorker	 null	 SUCCEEDED	 foreground-work	 com.sample.WorkApplication$ForegroundWorker	
    81c3ccd7-43fa-411e-b319-00572086249b	 androidx.work.impl.workers.DiagnosticsWorker	 null	 SUCCEEDED	 	 androidx.work.impl.workers.DiagnosticsWorker	
2020-09-21 08:48:56.677 18220-18280/com.sample I/WM-DiagnosticsWrkr: Running work:
2020-09-21 08:48:56.683 18220-18280/com.sample I/WM-DiagnosticsWrkr:  Id 	 Class Name	 Job Id	 State	 Unique Name	 Tags	
    1c7aaff0-5304-4645-b4a8-35c9511c3df3	 androidx.work.impl.workers.DiagnosticsWorker	 11	 RUNNING	 	 androidx.work.impl.workers.DiagnosticsWorker	
2020-09-21 08:48:56.684 18220-18246/com.sample D/WM-WorkerWrapper: androidx.work.impl.workers.DiagnosticsWorker returned a Success {mOutputData=Data {}} result.
2020-09-21 08:48:56.686 18220-18246/com.sample I/WM-WorkerWrapper: Worker result SUCCESS for Work [ id=1c7aaff0-5304-4645-b4a8-35c9511c3df3, tags={ androidx.work.impl.workers.DiagnosticsWorker } ]
2020-09-21 08:48:56.692 18220-18246/com.sample D/WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver disabled
2020-09-21 08:48:56.693 18220-18220/com.sample D/WM-Processor: Processor 1c7aaff0-5304-4645-b4a8-35c9511c3df3 executed; reschedule = false
2020-09-21 08:48:56.693 18220-18220/com.sample D/WM-SystemJobService: 1c7aaff0-5304-4645-b4a8-35c9511c3df3 executed on JobScheduler
2020-09-21 08:48:56.705 18220-18246/com.sample D/WM-GreedyScheduler: Cancelling work ID 1c7aaff0-5304-4645-b4a8-35c9511c3df3
2020-09-21 08:48:56.715 18220-18246/com.sample D/WM-Processor: Processor stopping background work 1c7aaff0-5304-4645-b4a8-35c9511c3df3
2020-09-21 08:48:56.715 18220-18246/com.sample D/WM-Processor: WorkerWrapper could not be found for 1c7aaff0-5304-4645-b4a8-35c9511c3df3
2020-09-21 08:48:56.716 18220-18246/com.sample D/WM-StopWorkRunnable: StopWorkRunnable for 1c7aaff0-5304-4645-b4a8-35c9511c3df3; Processor.stopWork = false

ra...@google.com <ra...@google.com> #11Sep 21, 2020 03:11PM

Let me try and reproduce again. I was unable to reproduce this after I made the fix.

ra...@google.com <ra...@google.com> #12Sep 21, 2020 09:13PM

I looked into this further, and it looks like there is a bug in the platform in Android 11. Will keep this bug updated as i have more information.

ar...@gmail.com <ar...@gmail.com> #13Sep 22, 2020 06:39AM

Checked again with 6853689 and 2.5.0-SNAPSHOT:

Google Pixel 1 with Android 10. Notification is not even showing. Had to add a timeout before producing Result.success() to check that it’s even in place.
Google Pixel 3a with Android 11. 10% of tries the notification is not even showing. 85% it’s shown for 5 seconds or so and then hides. 5% it sticks forever. The "forever" outcome logs and diagnostics are below.

Logs:

2020-09-22 09:36:33.017 13711-13711/com.sample D/WM-PackageManagerHelper: androidx.work.impl.background.systemjob.SystemJobService enabled
2020-09-22 09:36:33.017 13711-13711/com.sample D/WM-Schedulers: Created SystemJobScheduler and enabled SystemJobService
2020-09-22 09:36:33.027 13711-13771/com.sample D/WM-WorkManagerImpl: Unable to initialize multi-process support
    java.lang.ClassNotFoundException: androidx.work.multiprocess.RemoteWorkManagerClient
        at java.lang.Class.classForName(Native Method)
        at java.lang.Class.forName(Class.java:454)
        at java.lang.Class.forName(Class.java:379)
        at androidx.work.impl.WorkManagerImpl.tryInitializeMultiProcessSupport(WorkManagerImpl.java:789)
        at androidx.work.impl.WorkManagerImpl.getRemoteWorkManager(WorkManagerImpl.java:620)
        at androidx.work.impl.utils.ForceStopRunnable.multiProcessChecks(ForceStopRunnable.java:215)
        at androidx.work.impl.utils.ForceStopRunnable.run(ForceStopRunnable.java:85)
        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:923)
     Caused by: java.lang.ClassNotFoundException: Didn't find class "androidx.work.multiprocess.RemoteWorkManagerClient" on path: DexPathList[[zip file "/data/app/~~zyT1LboFg6KO8LnnXW0Bdw==/com.sample-mm1hod8ctb8bzuHrgG2QOw==/base.apk"],nativeLibraryDirectories=[/data/app/~~zyT1LboFg6KO8LnnXW0Bdw==/com.sample-mm1hod8ctb8bzuHrgG2QOw==/lib/arm64, /system/lib64, /system_ext/lib64, /product/lib64]]
        at dalvik.system.BaseDexClassLoader.findClass(BaseDexClassLoader.java:207)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:379)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:312)
        at java.lang.Class.classForName(Native Method) 
        at java.lang.Class.forName(Class.java:454) 
        at java.lang.Class.forName(Class.java:379) 
        at androidx.work.impl.WorkManagerImpl.tryInitializeMultiProcessSupport(WorkManagerImpl.java:789) 
        at androidx.work.impl.WorkManagerImpl.getRemoteWorkManager(WorkManagerImpl.java:620) 
        at androidx.work.impl.utils.ForceStopRunnable.multiProcessChecks(ForceStopRunnable.java:215) 
        at androidx.work.impl.utils.ForceStopRunnable.run(ForceStopRunnable.java:85) 
        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:923) 
2020-09-22 09:36:33.029 13711-13771/com.sample D/WM-ForceStopRunnable: Performing cleanup operations.
2020-09-22 09:36:33.078 13711-13775/com.sample D/WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver enabled
2020-09-22 09:36:33.095 13711-13775/com.sample D/WM-SystemJobScheduler: Scheduling work ID ae315b30-745d-4669-bfe5-20feecac92ec Job ID 28
2020-09-22 09:36:33.105 13711-13775/com.sample D/WM-GreedyScheduler: Starting work for ae315b30-745d-4669-bfe5-20feecac92ec
2020-09-22 09:36:33.112 13711-13777/com.sample D/WM-Processor: Processor: processing ae315b30-745d-4669-bfe5-20feecac92ec
2020-09-22 09:36:33.176 13711-13711/com.sample D/WM-SystemJobService: onStartJob for ae315b30-745d-4669-bfe5-20feecac92ec
2020-09-22 09:36:33.177 13711-13776/com.sample D/WM-Processor: Work ae315b30-745d-4669-bfe5-20feecac92ec is already enqueued for processing
2020-09-22 09:36:33.177 13711-13711/com.sample D/WM-WorkerWrapper: Starting work for com.sample.WorkApplication$ForegroundWorker
2020-09-22 09:36:33.199 13711-13777/com.sample I/WM-Processor: Moving WorkSpec (ae315b30-745d-4669-bfe5-20feecac92ec) to the foreground
2020-09-22 09:36:33.220 13711-13780/com.sample D/WM-Foreground-Worker: I AM DONE!
2020-09-22 09:36:33.221 13711-13775/com.sample D/WM-WorkerWrapper: com.sample.WorkApplication$ForegroundWorker returned a Success {mOutputData=Data {}} result.
2020-09-22 09:36:33.222 13711-13775/com.sample I/WM-WorkerWrapper: Worker result SUCCESS for Work [ id=ae315b30-745d-4669-bfe5-20feecac92ec, tags={ com.sample.WorkApplication$ForegroundWorker } ]
2020-09-22 09:36:33.224 13711-13711/com.sample I/WM-SystemFgDispatcher: Started foreground service Intent { act=ACTION_START_FOREGROUND cmp=com.sample/androidx.work.impl.foreground.SystemForegroundService (has extras) }
2020-09-22 09:36:33.225 13711-13711/com.sample D/WM-SystemFgDispatcher: Notifying with (id: 42, workSpecId: ae315b30-745d-4669-bfe5-20feecac92ec, notificationType: 0)
2020-09-22 09:36:33.226 13711-13775/com.sample D/WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver disabled
2020-09-22 09:36:33.228 13711-13711/com.sample D/WM-SystemFgDispatcher: Notifying with (id: 42, workSpecId: ae315b30-745d-4669-bfe5-20feecac92ec, notificationType: 0)
2020-09-22 09:36:33.229 13711-13711/com.sample I/WM-SystemFgDispatcher: Stopping foreground service
2020-09-22 09:36:33.230 13711-13711/com.sample D/WM-SystemFgService: All commands completed.
2020-09-22 09:36:33.233 13711-13711/com.sample D/WM-Processor: Processor ae315b30-745d-4669-bfe5-20feecac92ec executed; reschedule = false
2020-09-22 09:36:33.234 13711-13711/com.sample D/WM-SystemJobService: ae315b30-745d-4669-bfe5-20feecac92ec executed on JobScheduler
2020-09-22 09:36:33.234 13711-13711/com.sample D/WM-SystemFgDispatcher: Removing Notification (id: 42, workSpecId: ae315b30-745d-4669-bfe5-20feecac92ec ,notificationType: 0)
2020-09-22 09:36:33.235 13711-13775/com.sample D/WM-GreedyScheduler: Cancelling work ID ae315b30-745d-4669-bfe5-20feecac92ec
2020-09-22 09:36:33.237 13711-13711/com.sample D/WM-SystemJobService: onStopJob for ae315b30-745d-4669-bfe5-20feecac92ec
2020-09-22 09:36:33.242 13711-13775/com.sample D/WM-Processor: Processor stopping background work ae315b30-745d-4669-bfe5-20feecac92ec
2020-09-22 09:36:33.242 13711-13775/com.sample D/WM-Processor: WorkerWrapper could not be found for ae315b30-745d-4669-bfe5-20feecac92ec
2020-09-22 09:36:33.242 13711-13775/com.sample D/WM-StopWorkRunnable: StopWorkRunnable for ae315b30-745d-4669-bfe5-20feecac92ec; Processor.stopWork = false
2020-09-22 09:36:33.244 13711-13775/com.sample D/WM-Processor: Processor stopping background work ae315b30-745d-4669-bfe5-20feecac92ec
2020-09-22 09:36:33.244 13711-13775/com.sample D/WM-Processor: WorkerWrapper could not be found for ae315b30-745d-4669-bfe5-20feecac92ec
2020-09-22 09:36:33.244 13711-13775/com.sample D/WM-StopWorkRunnable: StopWorkRunnable for ae315b30-745d-4669-bfe5-20feecac92ec; Processor.stopWork = false

Diagnostics:

2020-09-22 09:39:01.696 13711-13711/com.sample D/WM-DiagnosticsRcvr: Requesting diagnostics
2020-09-22 09:39:01.706 13711-13771/com.sample D/WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver enabled
2020-09-22 09:39:01.720 13711-13771/com.sample D/WM-SystemJobScheduler: Scheduling work ID 67418b7b-a714-4b56-9496-12e05f76b672 Job ID 29
2020-09-22 09:39:01.728 13711-13771/com.sample D/WM-GreedyScheduler: Starting work for 67418b7b-a714-4b56-9496-12e05f76b672
2020-09-22 09:39:01.733 13711-13776/com.sample D/WM-Processor: Processor: processing 67418b7b-a714-4b56-9496-12e05f76b672
2020-09-22 09:39:01.742 13711-13711/com.sample D/WM-SystemJobService: onStartJob for 67418b7b-a714-4b56-9496-12e05f76b672
2020-09-22 09:39:01.749 13711-13711/com.sample D/WM-WorkerWrapper: Starting work for androidx.work.impl.workers.DiagnosticsWorker
2020-09-22 09:39:01.751 13711-13777/com.sample D/WM-Processor: Work 67418b7b-a714-4b56-9496-12e05f76b672 is already enqueued for processing
2020-09-22 09:39:01.762 13711-13841/com.sample I/WM-DiagnosticsWrkr: Recently completed work:
2020-09-22 09:39:01.768 13711-13841/com.sample I/WM-DiagnosticsWrkr:  Id 	 Class Name	 Job Id	 State	 Unique Name	 Tags	
    ae315b30-745d-4669-bfe5-20feecac92ec	 com.sample.WorkApplication$ForegroundWorker	 null	 SUCCEEDED	 foreground-work	 com.sample.WorkApplication$ForegroundWorker	
2020-09-22 09:39:01.768 13711-13841/com.sample I/WM-DiagnosticsWrkr: Running work:
2020-09-22 09:39:01.772 13711-13841/com.sample I/WM-DiagnosticsWrkr:  Id 	 Class Name	 Job Id	 State	 Unique Name	 Tags	
    67418b7b-a714-4b56-9496-12e05f76b672	 androidx.work.impl.workers.DiagnosticsWorker	 29	 RUNNING	 	 androidx.work.impl.workers.DiagnosticsWorker	
2020-09-22 09:39:01.773 13711-13776/com.sample D/WM-WorkerWrapper: androidx.work.impl.workers.DiagnosticsWorker returned a Success {mOutputData=Data {}} result.
2020-09-22 09:39:01.776 13711-13776/com.sample I/WM-WorkerWrapper: Worker result SUCCESS for Work [ id=67418b7b-a714-4b56-9496-12e05f76b672, tags={ androidx.work.impl.workers.DiagnosticsWorker } ]
2020-09-22 09:39:01.782 13711-13776/com.sample D/WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver disabled
2020-09-22 09:39:01.784 13711-13711/com.sample D/WM-Processor: Processor 67418b7b-a714-4b56-9496-12e05f76b672 executed; reschedule = false
2020-09-22 09:39:01.785 13711-13711/com.sample D/WM-SystemJobService: 67418b7b-a714-4b56-9496-12e05f76b672 executed on JobScheduler
2020-09-22 09:39:01.791 13711-13776/com.sample D/WM-GreedyScheduler: Cancelling work ID 67418b7b-a714-4b56-9496-12e05f76b672
2020-09-22 09:39:01.800 13711-13776/com.sample D/WM-Processor: Processor stopping background work 67418b7b-a714-4b56-9496-12e05f76b672
2020-09-22 09:39:01.801 13711-13776/com.sample D/WM-Processor: WorkerWrapper could not be found for 67418b7b-a714-4b56-9496-12e05f76b672
2020-09-22 09:39:01.801 13711-13776/com.sample D/WM-StopWorkRunnable: StopWorkRunnable for 67418b7b-a714-4b56-9496-12e05f76b672; Processor.stopWork = false

ra...@google.com <ra...@google.com> #14Sep 22, 2020 04:58PM

That is correct, and in-line with what I am seeing. There a known bug in R that is being tracked which causes this to happen.

ar...@gmail.com <ar...@gmail.com> #15Oct 1, 2020 07:18AM

Hey, do you have any news on this? Is there a reference to a platform issue? Should this issue be reopened? Is it possible to workaround the platform issue in WM? Is it possible to workaround the platform issue on the client side?

Sorry, a lot of questions but it would be nice to get rid of the issue on our side somehow.

ra...@google.com <ra...@google.com> #16Oct 1, 2020 03:06PM

Sorry, the bug tracking the platform issue is internal.

This has not been fixed in the platform yet. There is a race condition in NotificationManager's implementation. Unfortunately there are no known workarounds for this issue.

Will send out an update once the underlying bug is fixed.

ar...@gmail.com <ar...@gmail.com> #17Oct 1, 2020 03:12PM

All right, thanks for the update!

Just a dumb idea: if we set a minimum work duration (to 3 seconds or so) on our side — will it help to mitigate the issue and avoid the race condition?

ra...@google.com <ra...@google.com> #18Oct 1, 2020 03:15PM

It might alleviate your problem. There is still a race condition so it could still happen, but I am pretty sure it wont happen as often as it is now.

ar...@gmail.com <ar...@gmail.com> #19Oct 1, 2020 03:16PM

Thanks again! We’ll check if it helps IRL.

Issue 168502234

Description

Issue summary

Comments

ra...@google.com <ra...@google.com> #2Sep 16, 2020 08:08PM

ar...@gmail.com <ar...@gmail.com> #3Sep 16, 2020 08:13PM

ra...@google.com <ra...@google.com> #4Sep 16, 2020 08:26PM

ar...@gmail.com <ar...@gmail.com> #5Sep 17, 2020 05:57AM

ra...@google.com <ra...@google.com> Sep 17, 2020 06:56PM

ap...@google.com <ap...@google.com> #6Sep 18, 2020 05:21AM

ap...@google.com <ap...@google.com> #7Sep 18, 2020 05:22AM

ar...@gmail.com <ar...@gmail.com> #8Sep 18, 2020 08:57AM

ra...@google.com <ra...@google.com> #9Sep 18, 2020 05:05PM

ar...@gmail.com <ar...@gmail.com> #10Sep 21, 2020 05:49AM

ra...@google.com <ra...@google.com> #11Sep 21, 2020 03:11PM

ra...@google.com <ra...@google.com> #12Sep 21, 2020 09:13PM

ar...@gmail.com <ar...@gmail.com> #13Sep 22, 2020 06:39AM

ra...@google.com <ra...@google.com> #14Sep 22, 2020 04:58PM

ar...@gmail.com <ar...@gmail.com> #15Oct 1, 2020 07:18AM

ra...@google.com <ra...@google.com> #16Oct 1, 2020 03:06PM

ar...@gmail.com <ar...@gmail.com> #17Oct 1, 2020 03:12PM

ra...@google.com <ra...@google.com> #18Oct 1, 2020 03:15PM

ar...@gmail.com <ar...@gmail.com> #19Oct 1, 2020 03:16PM

Add comment

Issue metadata