为什么Android Worker成功完成并调用onStopped() [英] Why is Android Worker finishing successfully and calling onStopped()

查看:244
本文介绍了为什么Android Worker成功完成并调用onStopped()的处理方法,对大家解决问题具有一定的参考价值,需要的朋友们下面随着小编来一起学习吧!

问题描述

我当前的Android应用使用了androidx.work:work-runtime:2.2.0-rc01

My current Android app employs androidx.work:work-runtime:2.2.0-rc01

我的工作程序代码类似于:-

My Worker code resembles this:-

class SyncWorker(context: Context, workerParams: WorkerParameters) : Worker(context, workerParams) {

    private var syncWorkerResult: Result = Result.success()

    override fun doWork(): Result {

        return syncWorkerResult
    }

    override fun onStopped() {
        Log.i(TAG, "onStopped() $isStopped")

        super.onStopped()

    }
}

据我了解的工作者"文档,我不应该看到以下日志:-

As far as I understand the docs for Worker I shouldnt be seeing the following logs:-

2019-08-21 14:25:55.183 22716-22750/com.my.app I/WM-WorkerWrapper: Worker result SUCCESS for Work [ id=70a5ff81-1b4b-4604-9d2e-a0b3d342a608, tags={ com.my.app.sync.SyncWorker, SYNC-IN-PROGRESS-TAG } ]
2019-08-21 14:25:55.202 22716-22768/com.my.app I/SyncWorker: onStopped() true

我在做什么错了?

当我的工作人员报告结果成功和成功时,其定义如下:-

As my worker is reporting result SUCCESS and success is defined as follows:-

Returns an instance of ListenableWorker.Result that can be used to indicate that the work completed successfully. Any work that depends on this can be executed as long as all of its other dependencies and constraints are met.

这显然是工作程序代码中的缺陷,因为上面的日志显示我的工作程序已成功完成,然后被停止,如果"STOP"已成功完成,该怎么办?

This is obviously a defect in the worker code as the above logs shows my worker has completed successfully and then gets stopped, what is there to "STOP" if its already completed successfully?

我不明白为什么要为成功完成的工作人员调用androidx.work.impl.WorkerWrapper中断方法

I do not understand why androidx.work.impl.WorkerWrapper interrupt method is being called for my worker that has completed successfully

/**
 * @hide
 */
@RestrictTo(RestrictTo.Scope.LIBRARY_GROUP)
public void interrupt(boolean cancelled) {
    mInterrupted = true;
    // Resolve WorkerWrapper's future so we do the right thing and setup a reschedule
    // if necessary. mInterrupted is always true here, we don't really care about the return
    // value.
    tryCheckForInterruptionAndResolve();
    if (mInnerFuture != null) {
        // Propagate the cancellations to the inner future.
        mInnerFuture.cancel(true);
    }
    // Worker can be null if run() hasn't been called yet.
    if (mWorker != null) {
        mWorker.stop();
    }
}

在搜索Android worker源代码时,我已经确定了此方法

Searching through the Android worker source code I have identified this method

/**
 * Stops a unit of work.
 *
 * @param id The work id to stop
 * @return {@code true} if the work was stopped successfully
 */
public boolean stopWork(String id) {
    synchronized (mLock) {
        Logger.get().debug(TAG, String.format("Processor stopping %s", id));
        WorkerWrapper wrapper = mEnqueuedWorkMap.remove(id);
        if (wrapper != null) {
            wrapper.interrupt(false);
            Logger.get().debug(TAG, String.format("WorkerWrapper stopped for %s", id));
            return true;
        }
        Logger.get().debug(TAG, String.format("WorkerWrapper could not be found for %s", id));
        return false;
    }
}

如该调试变量图像所示,当它删除mEnqueuedWorkMap中存在的工作程序ID时,它将调用wrapper.interrupt(false);方法

Which calls the wrapper.interrupt(false); method when it removes a worker ID present in the mEnqueuedWorkMap as shown by this debug variables image

在这里,当我的Worker的onStopped()方法称为

Heres the WorkManager logs for when my Worker has its onStopped() method called

2019-08-23 13:02:32.754 21031-21031/com.my.app D/WM-PackageManagerHelper: androidx.work.impl.background.systemjob.SystemJobService enabled
2019-08-23 13:02:32.754 21031-21031/com.my.app D/WM-Schedulers: Created SystemJobScheduler and enabled SystemJobService
2019-08-23 13:02:32.763 21031-21085/com.my.app D/WM-ForceStopRunnable: Performing cleanup operations.
2019-08-23 13:02:32.884 21031-21085/com.my.app D/WM-ForceStopRunnable: Application was force-stopped, rescheduling.
2019-08-23 13:02:44.219 21031-21098/com.my.app D/WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver enabled
2019-08-23 13:02:44.237 21031-21098/com.my.app D/WM-SystemJobScheduler: Scheduling work ID e6a31ec8-a155-4d15-8cf7-af505c70e323 Job ID 0
2019-08-23 13:02:44.244 21031-21098/com.my.app D/WM-GreedyScheduler: Starting work for e6a31ec8-a155-4d15-8cf7-af505c70e323
2019-08-23 13:02:44.268 21031-21085/com.my.app D/WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver enabled
2019-08-23 13:02:44.302 21031-21085/com.my.app D/WM-SystemJobScheduler: Scheduling work ID 075fb9b3-e19b-463b-89f1-9e737e476d5b Job ID 1
2019-08-23 13:02:44.331 21031-21101/com.my.app D/WM-Processor: Processor: processing e6a31ec8-a155-4d15-8cf7-af505c70e323
2019-08-23 13:02:44.723 21031-21031/com.my.app D/WM-WorkerWrapper: Starting work for com.my.app.sync.SyncWorker
2019-08-23 13:02:44.730 21031-21031/com.my.app D/WM-SystemJobService: onStartJob for e6a31ec8-a155-4d15-8cf7-af505c70e323
2019-08-23 13:02:44.731 21031-21101/com.my.app D/WM-Processor: Work e6a31ec8-a155-4d15-8cf7-af505c70e323 is already enqueued for processing
2019-08-23 13:02:44.795 21031-21098/com.my.app D/WM-WorkerWrapper: com.my.app.sync.SyncWorker returned a Success {mOutputData=androidx.work.Data@0} result.
2019-08-23 13:02:44.797 21031-21098/com.my.app I/WM-WorkerWrapper: Worker result SUCCESS for Work [ id=e6a31ec8-a155-4d15-8cf7-af505c70e323, tags={ com.my.app.sync.SyncWorker, SYNC-IN-PROGRESS-TAG } ]
2019-08-23 13:02:44.808 21031-21031/com.my.app D/WM-Processor: Processor e6a31ec8-a155-4d15-8cf7-af505c70e323 executed; reschedule = false
2019-08-23 13:02:44.808 21031-21031/com.my.app D/WM-SystemJobService: e6a31ec8-a155-4d15-8cf7-af505c70e323 executed on JobScheduler
2019-08-23 13:02:44.814 21031-21098/com.my.app D/WM-GreedyScheduler: Cancelling work ID e6a31ec8-a155-4d15-8cf7-af505c70e323
2019-08-23 13:02:44.828 21031-21085/com.my.app D/WM-Processor: Processor stopping e6a31ec8-a155-4d15-8cf7-af505c70e323
2019-08-23 13:02:44.829 21031-21085/com.my.app D/WM-Processor: WorkerWrapper could not be found for e6a31ec8-a155-4d15-8cf7-af505c70e323
2019-08-23 13:02:44.829 21031-21085/com.my.app D/WM-StopWorkRunnable: StopWorkRunnable for e6a31ec8-a155-4d15-8cf7-af505c70e323; Processor.stopWork = false
2019-08-23 13:02:44.856 21031-21098/com.my.app D/WM-PackageManagerHelper: androidx.work.impl.background.systemalarm.RescheduleReceiver enabled
2019-08-23 13:02:44.874 21031-21098/com.my.app D/WM-SystemJobScheduler: Scheduling work ID ba72423c-5e4b-425c-aaab-a9a14efaf3f8 Job ID 2
2019-08-23 13:02:44.880 21031-21098/com.my.app D/WM-GreedyScheduler: Starting work for ba72423c-5e4b-425c-aaab-a9a14efaf3f8
2019-08-23 13:02:44.882 21031-21101/com.my.app D/WM-Processor: Processor: processing ba72423c-5e4b-425c-aaab-a9a14efaf3f8
2019-08-23 13:02:44.897 21031-21031/com.my.app D/WM-SystemJobService: onStartJob for ba72423c-5e4b-425c-aaab-a9a14efaf3f8
2019-08-23 13:02:44.900 21031-21031/com.my.app D/WM-WorkerWrapper: Starting work for com.my.app.sync.SyncWorker
2019-08-23 13:02:44.908 21031-21101/com.my.app D/WM-Processor: Work ba72423c-5e4b-425c-aaab-a9a14efaf3f8 is already enqueued for processing
2019-08-23 13:02:44.973 21031-21101/com.my.app D/WM-WorkerWrapper: com.my.app.sync.SyncWorker returned a Success {mOutputData=androidx.work.Data@0} result.
2019-08-23 13:02:44.975 21031-21101/com.my.app I/WM-WorkerWrapper: Worker result SUCCESS for Work [ id=ba72423c-5e4b-425c-aaab-a9a14efaf3f8, tags={ com.my.app.sync.SyncWorker, SYNC-IN-PROGRESS-TAG } ]
2019-08-23 13:02:44.989 21031-21101/com.my.app D/WM-GreedyScheduler: Cancelling work ID ba72423c-5e4b-425c-aaab-a9a14efaf3f8
2019-08-23 13:02:44.996 21031-21085/com.my.app D/WM-Processor: Processor stopping ba72423c-5e4b-425c-aaab-a9a14efaf3f8
2019-08-23 13:02:44.997 21031-21085/com.my.app D/WM-WorkerWrapper: Work interrupted for Work [ id=ba72423c-5e4b-425c-aaab-a9a14efaf3f8, tags={ com.my.app.sync.SyncWorker, SYNC-IN-PROGRESS-TAG } ]

2019-08-23 13:02:44.999 21031-21085/com.my.app I/SyncWorker: onStopped() ba72423c-5e4b-425c-aaab-a9a14efaf3f8 Success {mOutputData=androidx.work.Data@0}

2019-08-23 13:02:44.999 21031-21085/com.my.app D/WM-Processor: WorkerWrapper stopped for ba72423c-5e4b-425c-aaab-a9a14efaf3f8
2019-08-23 13:02:44.999 21031-21085/com.my.app D/WM-StopWorkRunnable: StopWorkRunnable for ba72423c-5e4b-425c-aaab-a9a14efaf3f8; Processor.stopWork = true
2019-08-23 13:02:45.045 21031-21031/com.my.app D/WM-Processor: Processor ba72423c-5e4b-425c-aaab-a9a14efaf3f8 executed; reschedule = false
2019-08-23 13:02:45.046 21031-21031/com.my.app D/WM-SystemJobService: ba72423c-5e4b-425c-aaab-a9a14efaf3f8 executed on JobScheduler
2019-08-23 13:02:45.047 21031-21031/com.my.app D/WM-SystemJobService: onStopJob for ba72423c-5e4b-425c-aaab-a9a14efaf3f8
2019-08-23 13:02:45.049 21031-21098/com.my.app D/WM-Processor: Processor stopping ba72423c-5e4b-425c-aaab-a9a14efaf3f8
2019-08-23 13:02:45.049 21031-21098/com.my.app D/WM-Processor: WorkerWrapper could not be found for ba72423c-5e4b-425c-aaab-a9a14efaf3f8
2019-08-23 13:02:45.049 21031-21098/com.my.app D/WM-StopWorkRunnable: StopWorkRunnable for ba72423c-5e4b-425c-aaab-a9a14efaf3f8; Processor.stopWork = false

更新

当第一个实例完成后,我立即启动工作器的第二个实例时,就会发生此问题.第二个实例的行为始终如上所示.当我在doWork()方法中添加Thread.sleep(Xms)时,可以通过增加Xms来控制"它的出现时间,而问题需要很长时间才能出现.

This issue occurs when I start a second instance of my the worker immediately after the first instance completes OK. The second instance consistently behaves as shown above. When I add a Thread.sleep(Xms) within the doWork() method I have "some" control over when it occurs as by increasing Xms the issue takes long to appear.

例如如果我设置了一个循环",每次以前的工作程序完成OK时都在其中启动一个新工作程序,那么我总是会看到此问题,在该问题中,随后的工作程序实例将同时完成SUCCESSonStopped().

e.g. If I set up a "loop" where I start a new worker each time the pervious worker completes OK, I always see this issue where a subsequent worker instance will both complete SUCCESS and onStopped() is called.

UPDATE II

UPDATE II

这里有一个代码片段,显示了我如何启动工作程序

Heres a code snippet showing how I start the Worker

val refreshDatabaseWork: OneTimeWorkRequest = OneTimeWorkRequest.Builder(SyncWorker::class.java)
        .keepResultsForAtLeast(1L, TimeUnit.NANOSECONDS)
        .addTag(WORK_IN_PROGRESS_TAG).build()
WorkManager.getInstance(application).beginUniqueWork(UNIQUE_WORK_NAME, ExistingWorkPolicy.KEEP, refreshDatabaseWork).enqueue()

我已经打开了一个问题 https://issuetracker.google.com/issues/140055777带有重现问题的小型项目

I've opened an Issue https://issuetracker.google.com/issues/140055777 with small project that reproduces the issue

推荐答案

我创建了一个简单的示例:单击按钮时,它会启动您提供的SyncWorker.没有顺序工人开始,只有一个工人,我什至简化了工人的创建:

I've created a simple example: it just starts the SyncWorker you are provided when a button is clicked. No sequential workers are started, just one worker, I even simplified the worker creation:

val refreshDatabaseWork: OneTimeWorkRequest = OneTimeWorkRequest.Builder(SyncWorker::class.java)
    .build()

WorkManager
    .getInstance(application)
    .enqueue(refreshDatabaseWork)

当我按下按钮时,有时会调用onStopped(),有时不会.这很少被称为,大约每20次点击一次.这种不一致的行为确实确实像个错误. Processor实现中有一个onExecuted()回调方法,每次工作人员完成时都会调用该方法:

When I press the button, sometimes the onStopped() is called, sometimes isn't. It's called very rarely, about one time per 20 clicks. Such inconsistent behavior looks like a bug indeed. There is onExecuted() callback method in the Processor implementation that is called each time when the worker finishes:

@Override
public void onExecuted(
    @NonNull final String workSpecId,
    boolean needsReschedule
) {
    synchronized (mLock) {
        mEnqueuedWorkMap.remove(workSpecId);
        Logger.get().debug(TAG, String.format("%s %s executed; reschedule = %s",
                getClass().getSimpleName(), workSpecId, needsReschedule));

        for (ExecutionListener executionListener : mOuterListeners) {
            executionListener.onExecuted(workSpecId, needsReschedule);
        }
    }
}

此方法从mEnqueuedWorkMap中删除工作程序包装器,但是有时stopWork()方法在删除工作程序之前先获取该包装器,结果工作程序停止了,并调用了onStopped()回调.

This method removes the worker wrapper from mEnqueuedWorkMap, but sometimes stopWork() method gets the wrapper before it's removed, and as a result the worker is stopped and onStopped() callback is called.

我还注意到wrapper.interrupt(false)调用接收到cancelled布尔标志,在我们的例子中这是假的,但是该方法从未使用过该标志,它看起来也很奇怪.

Also I've noticed that wrapper.interrupt(false) call receives cancelled boolean flag which is false in our case, but the flag is never used by the method, it also looks strange.

我也尝试过androidx.work:work-runtime:2.2.0,现在可以使用了,但是结果是一样的.我认为最好创建一个Google问题,以从图书馆开发人员那里得到答案.这种行为看起来很奇怪,但是我只能猜测它的意图.

I've also tried androidx.work:work-runtime:2.2.0, which is now available, but the result is the same. I think it's better to create a google issue to get an answer from the library developers. The behavior looks very strange, but I can only guess what it's intended to be.

这篇关于为什么Android Worker成功完成并调用onStopped()的文章就介绍到这了,希望我们推荐的答案对大家有所帮助,也希望大家多多支持IT屋!

查看全文
登录 关闭
扫码关注1秒登录
发送“验证码”获取 | 15天全站免登陆