Home | History | Annotate | Download | only in job
      1 /*
      2  * Copyright (C) 2014 The Android Open Source Project
      3  *
      4  * Licensed under the Apache License, Version 2.0 (the "License");
      5  * you may not use this file except in compliance with the License.
      6  * You may obtain a copy of the License at
      7  *
      8  *      http://www.apache.org/licenses/LICENSE-2.0
      9  *
     10  * Unless required by applicable law or agreed to in writing, software
     11  * distributed under the License is distributed on an "AS IS" BASIS,
     12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
     13  * See the License for the specific language governing permissions and
     14  * limitations under the License
     15  */
     16 
     17 package com.android.server.job;
     18 
     19 import static com.android.server.job.JobSchedulerService.sElapsedRealtimeClock;
     20 
     21 import android.app.ActivityManager;
     22 import android.app.job.IJobCallback;
     23 import android.app.job.IJobService;
     24 import android.app.job.JobInfo;
     25 import android.app.job.JobParameters;
     26 import android.app.job.JobWorkItem;
     27 import android.app.usage.UsageStatsManagerInternal;
     28 import android.content.ComponentName;
     29 import android.content.Context;
     30 import android.content.Intent;
     31 import android.content.ServiceConnection;
     32 import android.net.Uri;
     33 import android.os.Binder;
     34 import android.os.Handler;
     35 import android.os.IBinder;
     36 import android.os.Looper;
     37 import android.os.Message;
     38 import android.os.PowerManager;
     39 import android.os.RemoteException;
     40 import android.os.UserHandle;
     41 import android.os.WorkSource;
     42 import android.util.EventLog;
     43 import android.util.Slog;
     44 import android.util.TimeUtils;
     45 
     46 import com.android.internal.annotations.GuardedBy;
     47 import com.android.internal.annotations.VisibleForTesting;
     48 import com.android.internal.app.IBatteryStats;
     49 import com.android.server.EventLogTags;
     50 import com.android.server.LocalServices;
     51 import com.android.server.job.controllers.JobStatus;
     52 
     53 /**
     54  * Handles client binding and lifecycle of a job. Jobs execute one at a time on an instance of this
     55  * class.
     56  *
     57  * There are two important interactions into this class from the
     58  * {@link com.android.server.job.JobSchedulerService}. To execute a job and to cancel a job.
     59  * - Execution of a new job is handled by the {@link #mAvailable}. This bit is flipped once when a
     60  * job lands, and again when it is complete.
     61  * - Cancelling is trickier, because there are also interactions from the client. It's possible
     62  * the {@link com.android.server.job.JobServiceContext.JobServiceHandler} tries to process a
     63  * {@link #doCancelLocked} after the client has already finished. This is handled by having
     64  * {@link com.android.server.job.JobServiceContext.JobServiceHandler#handleCancelLocked} check whether
     65  * the context is still valid.
     66  * To mitigate this, we avoid sending duplicate onStopJob()
     67  * calls to the client after they've specified jobFinished().
     68  */
     69 public final class JobServiceContext implements ServiceConnection {
     70     private static final boolean DEBUG = JobSchedulerService.DEBUG;
     71     private static final boolean DEBUG_STANDBY = JobSchedulerService.DEBUG_STANDBY;
     72 
     73     private static final String TAG = "JobServiceContext";
     74     /** Amount of time a job is allowed to execute for before being considered timed-out. */
     75     public static final long EXECUTING_TIMESLICE_MILLIS = 10 * 60 * 1000;  // 10mins.
     76     /** Amount of time the JobScheduler waits for the initial service launch+bind. */
     77     private static final long OP_BIND_TIMEOUT_MILLIS = 18 * 1000;
     78     /** Amount of time the JobScheduler will wait for a response from an app for a message. */
     79     private static final long OP_TIMEOUT_MILLIS = 8 * 1000;
     80 
     81     private static final String[] VERB_STRINGS = {
     82             "VERB_BINDING", "VERB_STARTING", "VERB_EXECUTING", "VERB_STOPPING", "VERB_FINISHED"
     83     };
     84 
     85     // States that a job occupies while interacting with the client.
     86     static final int VERB_BINDING = 0;
     87     static final int VERB_STARTING = 1;
     88     static final int VERB_EXECUTING = 2;
     89     static final int VERB_STOPPING = 3;
     90     static final int VERB_FINISHED = 4;
     91 
     92     // Messages that result from interactions with the client service.
     93     /** System timed out waiting for a response. */
     94     private static final int MSG_TIMEOUT = 0;
     95 
     96     public static final int NO_PREFERRED_UID = -1;
     97 
     98     private final Handler mCallbackHandler;
     99     /** Make callbacks to {@link JobSchedulerService} to inform on job completion status. */
    100     private final JobCompletedListener mCompletedListener;
    101     /** Used for service binding, etc. */
    102     private final Context mContext;
    103     private final Object mLock;
    104     private final IBatteryStats mBatteryStats;
    105     private final JobPackageTracker mJobPackageTracker;
    106     private PowerManager.WakeLock mWakeLock;
    107 
    108     // Execution state.
    109     private JobParameters mParams;
    110     @VisibleForTesting
    111     int mVerb;
    112     private boolean mCancelled;
    113 
    114     /**
    115      * All the information maintained about the job currently being executed.
    116      *
    117      * Any reads (dereferences) not done from the handler thread must be synchronized on
    118      * {@link #mLock}.
    119      * Writes can only be done from the handler thread, or {@link #executeRunnableJob(JobStatus)}.
    120      */
    121     private JobStatus mRunningJob;
    122     private JobCallback mRunningCallback;
    123     /** Used to store next job to run when current job is to be preempted. */
    124     private int mPreferredUid;
    125     IJobService service;
    126 
    127     /**
    128      * Whether this context is free. This is set to false at the start of execution, and reset to
    129      * true when execution is complete.
    130      */
    131     @GuardedBy("mLock")
    132     private boolean mAvailable;
    133     /** Track start time. */
    134     private long mExecutionStartTimeElapsed;
    135     /** Track when job will timeout. */
    136     private long mTimeoutElapsed;
    137 
    138     // Debugging: reason this job was last stopped.
    139     public String mStoppedReason;
    140 
    141     // Debugging: time this job was last stopped.
    142     public long mStoppedTime;
    143 
    144     final class JobCallback extends IJobCallback.Stub {
    145         public String mStoppedReason;
    146         public long mStoppedTime;
    147 
    148         @Override
    149         public void acknowledgeStartMessage(int jobId, boolean ongoing) {
    150             doAcknowledgeStartMessage(this, jobId, ongoing);
    151         }
    152 
    153         @Override
    154         public void acknowledgeStopMessage(int jobId, boolean reschedule) {
    155             doAcknowledgeStopMessage(this, jobId, reschedule);
    156         }
    157 
    158         @Override
    159         public JobWorkItem dequeueWork(int jobId) {
    160             return doDequeueWork(this, jobId);
    161         }
    162 
    163         @Override
    164         public boolean completeWork(int jobId, int workId) {
    165             return doCompleteWork(this, jobId, workId);
    166         }
    167 
    168         @Override
    169         public void jobFinished(int jobId, boolean reschedule) {
    170             doJobFinished(this, jobId, reschedule);
    171         }
    172     }
    173 
    174     JobServiceContext(JobSchedulerService service, IBatteryStats batteryStats,
    175             JobPackageTracker tracker, Looper looper) {
    176         this(service.getContext(), service.getLock(), batteryStats, tracker, service, looper);
    177     }
    178 
    179     @VisibleForTesting
    180     JobServiceContext(Context context, Object lock, IBatteryStats batteryStats,
    181             JobPackageTracker tracker, JobCompletedListener completedListener, Looper looper) {
    182         mContext = context;
    183         mLock = lock;
    184         mBatteryStats = batteryStats;
    185         mJobPackageTracker = tracker;
    186         mCallbackHandler = new JobServiceHandler(looper);
    187         mCompletedListener = completedListener;
    188         mAvailable = true;
    189         mVerb = VERB_FINISHED;
    190         mPreferredUid = NO_PREFERRED_UID;
    191     }
    192 
    193     /**
    194      * Give a job to this context for execution. Callers must first check {@link #getRunningJobLocked()}
    195      * and ensure it is null to make sure this is a valid context.
    196      * @param job The status of the job that we are going to run.
    197      * @return True if the job is valid and is running. False if the job cannot be executed.
    198      */
    199     boolean executeRunnableJob(JobStatus job) {
    200         synchronized (mLock) {
    201             if (!mAvailable) {
    202                 Slog.e(TAG, "Starting new runnable but context is unavailable > Error.");
    203                 return false;
    204             }
    205 
    206             mPreferredUid = NO_PREFERRED_UID;
    207 
    208             mRunningJob = job;
    209             mRunningCallback = new JobCallback();
    210             final boolean isDeadlineExpired =
    211                     job.hasDeadlineConstraint() &&
    212                             (job.getLatestRunTimeElapsed() < sElapsedRealtimeClock.millis());
    213             Uri[] triggeredUris = null;
    214             if (job.changedUris != null) {
    215                 triggeredUris = new Uri[job.changedUris.size()];
    216                 job.changedUris.toArray(triggeredUris);
    217             }
    218             String[] triggeredAuthorities = null;
    219             if (job.changedAuthorities != null) {
    220                 triggeredAuthorities = new String[job.changedAuthorities.size()];
    221                 job.changedAuthorities.toArray(triggeredAuthorities);
    222             }
    223             final JobInfo ji = job.getJob();
    224             mParams = new JobParameters(mRunningCallback, job.getJobId(), ji.getExtras(),
    225                     ji.getTransientExtras(), ji.getClipData(), ji.getClipGrantFlags(),
    226                     isDeadlineExpired, triggeredUris, triggeredAuthorities, job.network);
    227             mExecutionStartTimeElapsed = sElapsedRealtimeClock.millis();
    228 
    229             final long whenDeferred = job.getWhenStandbyDeferred();
    230             if (whenDeferred > 0) {
    231                 final long deferral = mExecutionStartTimeElapsed - whenDeferred;
    232                 EventLog.writeEvent(EventLogTags.JOB_DEFERRED_EXECUTION, deferral);
    233                 if (DEBUG_STANDBY) {
    234                     StringBuilder sb = new StringBuilder(128);
    235                     sb.append("Starting job deferred for standby by ");
    236                     TimeUtils.formatDuration(deferral, sb);
    237                     sb.append(" ms : ");
    238                     sb.append(job.toShortString());
    239                     Slog.v(TAG, sb.toString());
    240                 }
    241             }
    242 
    243             // Once we'e begun executing a job, we by definition no longer care whether
    244             // it was inflated from disk with not-yet-coherent delay/deadline bounds.
    245             job.clearPersistedUtcTimes();
    246 
    247             mVerb = VERB_BINDING;
    248             scheduleOpTimeOutLocked();
    249             final Intent intent = new Intent().setComponent(job.getServiceComponent());
    250             boolean binding = mContext.bindServiceAsUser(intent, this,
    251                     Context.BIND_AUTO_CREATE | Context.BIND_NOT_FOREGROUND,
    252                     new UserHandle(job.getUserId()));
    253             if (!binding) {
    254                 if (DEBUG) {
    255                     Slog.d(TAG, job.getServiceComponent().getShortClassName() + " unavailable.");
    256                 }
    257                 mRunningJob = null;
    258                 mRunningCallback = null;
    259                 mParams = null;
    260                 mExecutionStartTimeElapsed = 0L;
    261                 mVerb = VERB_FINISHED;
    262                 removeOpTimeOutLocked();
    263                 return false;
    264             }
    265             mJobPackageTracker.noteActive(job);
    266             try {
    267                 mBatteryStats.noteJobStart(job.getBatteryName(), job.getSourceUid());
    268             } catch (RemoteException e) {
    269                 // Whatever.
    270             }
    271             final String jobPackage = job.getSourcePackageName();
    272             final int jobUserId = job.getSourceUserId();
    273             UsageStatsManagerInternal usageStats =
    274                     LocalServices.getService(UsageStatsManagerInternal.class);
    275             usageStats.setLastJobRunTime(jobPackage, jobUserId, mExecutionStartTimeElapsed);
    276             JobSchedulerInternal jobScheduler =
    277                     LocalServices.getService(JobSchedulerInternal.class);
    278             jobScheduler.noteJobStart(jobPackage, jobUserId);
    279             mAvailable = false;
    280             mStoppedReason = null;
    281             mStoppedTime = 0;
    282             return true;
    283         }
    284     }
    285 
    286     /**
    287      * Used externally to query the running job. Will return null if there is no job running.
    288      */
    289     JobStatus getRunningJobLocked() {
    290         return mRunningJob;
    291     }
    292 
    293     /**
    294      * Used only for debugging. Will return <code>"&lt;null&gt;"</code> if there is no job running.
    295      */
    296     private String getRunningJobNameLocked() {
    297         return mRunningJob != null ? mRunningJob.toShortString() : "<null>";
    298     }
    299 
    300     /** Called externally when a job that was scheduled for execution should be cancelled. */
    301     @GuardedBy("mLock")
    302     void cancelExecutingJobLocked(int reason, String debugReason) {
    303         doCancelLocked(reason, debugReason);
    304     }
    305 
    306     @GuardedBy("mLock")
    307     void preemptExecutingJobLocked() {
    308         doCancelLocked(JobParameters.REASON_PREEMPT, "cancelled due to preemption");
    309     }
    310 
    311     int getPreferredUid() {
    312         return mPreferredUid;
    313     }
    314 
    315     void clearPreferredUid() {
    316         mPreferredUid = NO_PREFERRED_UID;
    317     }
    318 
    319     long getExecutionStartTimeElapsed() {
    320         return mExecutionStartTimeElapsed;
    321     }
    322 
    323     long getTimeoutElapsed() {
    324         return mTimeoutElapsed;
    325     }
    326 
    327     @GuardedBy("mLock")
    328     boolean timeoutIfExecutingLocked(String pkgName, int userId, boolean matchJobId, int jobId,
    329             String reason) {
    330         final JobStatus executing = getRunningJobLocked();
    331         if (executing != null && (userId == UserHandle.USER_ALL || userId == executing.getUserId())
    332                 && (pkgName == null || pkgName.equals(executing.getSourcePackageName()))
    333                 && (!matchJobId || jobId == executing.getJobId())) {
    334             if (mVerb == VERB_EXECUTING) {
    335                 mParams.setStopReason(JobParameters.REASON_TIMEOUT, reason);
    336                 sendStopMessageLocked("force timeout from shell");
    337                 return true;
    338             }
    339         }
    340         return false;
    341     }
    342 
    343     void doJobFinished(JobCallback cb, int jobId, boolean reschedule) {
    344         doCallback(cb, reschedule, "app called jobFinished");
    345     }
    346 
    347     void doAcknowledgeStopMessage(JobCallback cb, int jobId, boolean reschedule) {
    348         doCallback(cb, reschedule, null);
    349     }
    350 
    351     void doAcknowledgeStartMessage(JobCallback cb, int jobId, boolean ongoing) {
    352         doCallback(cb, ongoing, "finished start");
    353     }
    354 
    355     JobWorkItem doDequeueWork(JobCallback cb, int jobId) {
    356         final long ident = Binder.clearCallingIdentity();
    357         try {
    358             synchronized (mLock) {
    359                 assertCallerLocked(cb);
    360                 if (mVerb == VERB_STOPPING || mVerb == VERB_FINISHED) {
    361                     // This job is either all done, or on its way out.  Either way, it
    362                     // should not dispatch any more work.  We will pick up any remaining
    363                     // work the next time we start the job again.
    364                     return null;
    365                 }
    366                 final JobWorkItem work = mRunningJob.dequeueWorkLocked();
    367                 if (work == null && !mRunningJob.hasExecutingWorkLocked()) {
    368                     // This will finish the job.
    369                     doCallbackLocked(false, "last work dequeued");
    370                 }
    371                 return work;
    372             }
    373         } finally {
    374             Binder.restoreCallingIdentity(ident);
    375         }
    376     }
    377 
    378     boolean doCompleteWork(JobCallback cb, int jobId, int workId) {
    379         final long ident = Binder.clearCallingIdentity();
    380         try {
    381             synchronized (mLock) {
    382                 assertCallerLocked(cb);
    383                 return mRunningJob.completeWorkLocked(ActivityManager.getService(), workId);
    384             }
    385         } finally {
    386             Binder.restoreCallingIdentity(ident);
    387         }
    388     }
    389 
    390     /**
    391      * We acquire/release a wakelock on onServiceConnected/unbindService. This mirrors the work
    392      * we intend to send to the client - we stop sending work when the service is unbound so until
    393      * then we keep the wakelock.
    394      * @param name The concrete component name of the service that has been connected.
    395      * @param service The IBinder of the Service's communication channel,
    396      */
    397     @Override
    398     public void onServiceConnected(ComponentName name, IBinder service) {
    399         JobStatus runningJob;
    400         synchronized (mLock) {
    401             // This isn't strictly necessary b/c the JobServiceHandler is running on the main
    402             // looper and at this point we can't get any binder callbacks from the client. Better
    403             // safe than sorry.
    404             runningJob = mRunningJob;
    405 
    406             if (runningJob == null || !name.equals(runningJob.getServiceComponent())) {
    407                 closeAndCleanupJobLocked(true /* needsReschedule */,
    408                         "connected for different component");
    409                 return;
    410             }
    411             this.service = IJobService.Stub.asInterface(service);
    412             final PowerManager pm =
    413                     (PowerManager) mContext.getSystemService(Context.POWER_SERVICE);
    414             PowerManager.WakeLock wl = pm.newWakeLock(PowerManager.PARTIAL_WAKE_LOCK,
    415                     runningJob.getTag());
    416             wl.setWorkSource(deriveWorkSource(runningJob));
    417             wl.setReferenceCounted(false);
    418             wl.acquire();
    419 
    420             // We use a new wakelock instance per job.  In rare cases there is a race between
    421             // teardown following job completion/cancellation and new job service spin-up
    422             // such that if we simply assign mWakeLock to be the new instance, we orphan
    423             // the currently-live lock instead of cleanly replacing it.  Watch for this and
    424             // explicitly fast-forward the release if we're in that situation.
    425             if (mWakeLock != null) {
    426                 Slog.w(TAG, "Bound new job " + runningJob + " but live wakelock " + mWakeLock
    427                         + " tag=" + mWakeLock.getTag());
    428                 mWakeLock.release();
    429             }
    430             mWakeLock = wl;
    431             doServiceBoundLocked();
    432         }
    433     }
    434 
    435     private WorkSource deriveWorkSource(JobStatus runningJob) {
    436         final int jobUid = runningJob.getSourceUid();
    437         if (WorkSource.isChainedBatteryAttributionEnabled(mContext)) {
    438             WorkSource workSource = new WorkSource();
    439             workSource.createWorkChain()
    440                     .addNode(jobUid, null)
    441                     .addNode(android.os.Process.SYSTEM_UID, "JobScheduler");
    442             return workSource;
    443         } else {
    444             return new WorkSource(jobUid);
    445         }
    446     }
    447 
    448     /** If the client service crashes we reschedule this job and clean up. */
    449     @Override
    450     public void onServiceDisconnected(ComponentName name) {
    451         synchronized (mLock) {
    452             closeAndCleanupJobLocked(true /* needsReschedule */, "unexpectedly disconnected");
    453         }
    454     }
    455 
    456     /**
    457      * This class is reused across different clients, and passes itself in as a callback. Check
    458      * whether the client exercising the callback is the client we expect.
    459      * @return True if the binder calling is coming from the client we expect.
    460      */
    461     private boolean verifyCallerLocked(JobCallback cb) {
    462         if (mRunningCallback != cb) {
    463             if (DEBUG) {
    464                 Slog.d(TAG, "Stale callback received, ignoring.");
    465             }
    466             return false;
    467         }
    468         return true;
    469     }
    470 
    471     private void assertCallerLocked(JobCallback cb) {
    472         if (!verifyCallerLocked(cb)) {
    473             StringBuilder sb = new StringBuilder(128);
    474             sb.append("Caller no longer running");
    475             if (cb.mStoppedReason != null) {
    476                 sb.append(", last stopped ");
    477                 TimeUtils.formatDuration(sElapsedRealtimeClock.millis() - cb.mStoppedTime, sb);
    478                 sb.append(" because: ");
    479                 sb.append(cb.mStoppedReason);
    480             }
    481             throw new SecurityException(sb.toString());
    482         }
    483     }
    484 
    485     /**
    486      * Scheduling of async messages (basically timeouts at this point).
    487      */
    488     private class JobServiceHandler extends Handler {
    489         JobServiceHandler(Looper looper) {
    490             super(looper);
    491         }
    492 
    493         @Override
    494         public void handleMessage(Message message) {
    495             switch (message.what) {
    496                 case MSG_TIMEOUT:
    497                     synchronized (mLock) {
    498                         if (message.obj == mRunningCallback) {
    499                             handleOpTimeoutLocked();
    500                         } else {
    501                             JobCallback jc = (JobCallback)message.obj;
    502                             StringBuilder sb = new StringBuilder(128);
    503                             sb.append("Ignoring timeout of no longer active job");
    504                             if (jc.mStoppedReason != null) {
    505                                 sb.append(", stopped ");
    506                                 TimeUtils.formatDuration(sElapsedRealtimeClock.millis()
    507                                         - jc.mStoppedTime, sb);
    508                                 sb.append(" because: ");
    509                                 sb.append(jc.mStoppedReason);
    510                             }
    511                             Slog.w(TAG, sb.toString());
    512                         }
    513                     }
    514                     break;
    515                 default:
    516                     Slog.e(TAG, "Unrecognised message: " + message);
    517             }
    518         }
    519     }
    520 
    521     @GuardedBy("mLock")
    522     void doServiceBoundLocked() {
    523         removeOpTimeOutLocked();
    524         handleServiceBoundLocked();
    525     }
    526 
    527     void doCallback(JobCallback cb, boolean reschedule, String reason) {
    528         final long ident = Binder.clearCallingIdentity();
    529         try {
    530             synchronized (mLock) {
    531                 if (!verifyCallerLocked(cb)) {
    532                     return;
    533                 }
    534                 doCallbackLocked(reschedule, reason);
    535             }
    536         } finally {
    537             Binder.restoreCallingIdentity(ident);
    538         }
    539     }
    540 
    541     @GuardedBy("mLock")
    542     void doCallbackLocked(boolean reschedule, String reason) {
    543         if (DEBUG) {
    544             Slog.d(TAG, "doCallback of : " + mRunningJob
    545                     + " v:" + VERB_STRINGS[mVerb]);
    546         }
    547         removeOpTimeOutLocked();
    548 
    549         if (mVerb == VERB_STARTING) {
    550             handleStartedLocked(reschedule);
    551         } else if (mVerb == VERB_EXECUTING ||
    552                 mVerb == VERB_STOPPING) {
    553             handleFinishedLocked(reschedule, reason);
    554         } else {
    555             if (DEBUG) {
    556                 Slog.d(TAG, "Unrecognised callback: " + mRunningJob);
    557             }
    558         }
    559     }
    560 
    561     @GuardedBy("mLock")
    562     void doCancelLocked(int arg1, String debugReason) {
    563         if (mVerb == VERB_FINISHED) {
    564             if (DEBUG) {
    565                 Slog.d(TAG,
    566                         "Trying to process cancel for torn-down context, ignoring.");
    567             }
    568             return;
    569         }
    570         mParams.setStopReason(arg1, debugReason);
    571         if (arg1 == JobParameters.REASON_PREEMPT) {
    572             mPreferredUid = mRunningJob != null ? mRunningJob.getUid() :
    573                     NO_PREFERRED_UID;
    574         }
    575         handleCancelLocked(debugReason);
    576     }
    577 
    578     /** Start the job on the service. */
    579     @GuardedBy("mLock")
    580     private void handleServiceBoundLocked() {
    581         if (DEBUG) {
    582             Slog.d(TAG, "handleServiceBound for " + getRunningJobNameLocked());
    583         }
    584         if (mVerb != VERB_BINDING) {
    585             Slog.e(TAG, "Sending onStartJob for a job that isn't pending. "
    586                     + VERB_STRINGS[mVerb]);
    587             closeAndCleanupJobLocked(false /* reschedule */, "started job not pending");
    588             return;
    589         }
    590         if (mCancelled) {
    591             if (DEBUG) {
    592                 Slog.d(TAG, "Job cancelled while waiting for bind to complete. "
    593                         + mRunningJob);
    594             }
    595             closeAndCleanupJobLocked(true /* reschedule */, "cancelled while waiting for bind");
    596             return;
    597         }
    598         try {
    599             mVerb = VERB_STARTING;
    600             scheduleOpTimeOutLocked();
    601             service.startJob(mParams);
    602         } catch (Exception e) {
    603             // We catch 'Exception' because client-app malice or bugs might induce a wide
    604             // range of possible exception-throw outcomes from startJob() and its handling
    605             // of the client's ParcelableBundle extras.
    606             Slog.e(TAG, "Error sending onStart message to '" +
    607                     mRunningJob.getServiceComponent().getShortClassName() + "' ", e);
    608         }
    609     }
    610 
    611     /**
    612      * State behaviours.
    613      * VERB_STARTING   -> Successful start, change job to VERB_EXECUTING and post timeout.
    614      *     _PENDING    -> Error
    615      *     _EXECUTING  -> Error
    616      *     _STOPPING   -> Error
    617      */
    618     @GuardedBy("mLock")
    619     private void handleStartedLocked(boolean workOngoing) {
    620         switch (mVerb) {
    621             case VERB_STARTING:
    622                 mVerb = VERB_EXECUTING;
    623                 if (!workOngoing) {
    624                     // Job is finished already so fast-forward to handleFinished.
    625                     handleFinishedLocked(false, "onStartJob returned false");
    626                     return;
    627                 }
    628                 if (mCancelled) {
    629                     if (DEBUG) {
    630                         Slog.d(TAG, "Job cancelled while waiting for onStartJob to complete.");
    631                     }
    632                     // Cancelled *while* waiting for acknowledgeStartMessage from client.
    633                     handleCancelLocked(null);
    634                     return;
    635                 }
    636                 scheduleOpTimeOutLocked();
    637                 break;
    638             default:
    639                 Slog.e(TAG, "Handling started job but job wasn't starting! Was "
    640                         + VERB_STRINGS[mVerb] + ".");
    641                 return;
    642         }
    643     }
    644 
    645     /**
    646      * VERB_EXECUTING  -> Client called jobFinished(), clean up and notify done.
    647      *     _STOPPING   -> Successful finish, clean up and notify done.
    648      *     _STARTING   -> Error
    649      *     _PENDING    -> Error
    650      */
    651     @GuardedBy("mLock")
    652     private void handleFinishedLocked(boolean reschedule, String reason) {
    653         switch (mVerb) {
    654             case VERB_EXECUTING:
    655             case VERB_STOPPING:
    656                 closeAndCleanupJobLocked(reschedule, reason);
    657                 break;
    658             default:
    659                 Slog.e(TAG, "Got an execution complete message for a job that wasn't being" +
    660                         "executed. Was " + VERB_STRINGS[mVerb] + ".");
    661         }
    662     }
    663 
    664     /**
    665      * A job can be in various states when a cancel request comes in:
    666      * VERB_BINDING    -> Cancelled before bind completed. Mark as cancelled and wait for
    667      *                    {@link #onServiceConnected(android.content.ComponentName, android.os.IBinder)}
    668      *     _STARTING   -> Mark as cancelled and wait for
    669      *                    {@link JobServiceContext#doAcknowledgeStartMessage}
    670      *     _EXECUTING  -> call {@link #sendStopMessageLocked}}, but only if there are no callbacks
    671      *                      in the message queue.
    672      *     _ENDING     -> No point in doing anything here, so we ignore.
    673      */
    674     @GuardedBy("mLock")
    675     private void handleCancelLocked(String reason) {
    676         if (JobSchedulerService.DEBUG) {
    677             Slog.d(TAG, "Handling cancel for: " + mRunningJob.getJobId() + " "
    678                     + VERB_STRINGS[mVerb]);
    679         }
    680         switch (mVerb) {
    681             case VERB_BINDING:
    682             case VERB_STARTING:
    683                 mCancelled = true;
    684                 applyStoppedReasonLocked(reason);
    685                 break;
    686             case VERB_EXECUTING:
    687                 sendStopMessageLocked(reason);
    688                 break;
    689             case VERB_STOPPING:
    690                 // Nada.
    691                 break;
    692             default:
    693                 Slog.e(TAG, "Cancelling a job without a valid verb: " + mVerb);
    694                 break;
    695         }
    696     }
    697 
    698     /** Process MSG_TIMEOUT here. */
    699     @GuardedBy("mLock")
    700     private void handleOpTimeoutLocked() {
    701         switch (mVerb) {
    702             case VERB_BINDING:
    703                 Slog.w(TAG, "Time-out while trying to bind " + getRunningJobNameLocked()
    704                         + ", dropping.");
    705                 closeAndCleanupJobLocked(false /* needsReschedule */, "timed out while binding");
    706                 break;
    707             case VERB_STARTING:
    708                 // Client unresponsive - wedged or failed to respond in time. We don't really
    709                 // know what happened so let's log it and notify the JobScheduler
    710                 // FINISHED/NO-RETRY.
    711                 Slog.w(TAG, "No response from client for onStartJob "
    712                         + getRunningJobNameLocked());
    713                 closeAndCleanupJobLocked(false /* needsReschedule */, "timed out while starting");
    714                 break;
    715             case VERB_STOPPING:
    716                 // At least we got somewhere, so fail but ask the JobScheduler to reschedule.
    717                 Slog.w(TAG, "No response from client for onStopJob "
    718                         + getRunningJobNameLocked());
    719                 closeAndCleanupJobLocked(true /* needsReschedule */, "timed out while stopping");
    720                 break;
    721             case VERB_EXECUTING:
    722                 // Not an error - client ran out of time.
    723                 Slog.i(TAG, "Client timed out while executing (no jobFinished received), " +
    724                         "sending onStop: " + getRunningJobNameLocked());
    725                 mParams.setStopReason(JobParameters.REASON_TIMEOUT, "client timed out");
    726                 sendStopMessageLocked("timeout while executing");
    727                 break;
    728             default:
    729                 Slog.e(TAG, "Handling timeout for an invalid job state: "
    730                         + getRunningJobNameLocked() + ", dropping.");
    731                 closeAndCleanupJobLocked(false /* needsReschedule */, "invalid timeout");
    732         }
    733     }
    734 
    735     /**
    736      * Already running, need to stop. Will switch {@link #mVerb} from VERB_EXECUTING ->
    737      * VERB_STOPPING.
    738      */
    739     @GuardedBy("mLock")
    740     private void sendStopMessageLocked(String reason) {
    741         removeOpTimeOutLocked();
    742         if (mVerb != VERB_EXECUTING) {
    743             Slog.e(TAG, "Sending onStopJob for a job that isn't started. " + mRunningJob);
    744             closeAndCleanupJobLocked(false /* reschedule */, reason);
    745             return;
    746         }
    747         try {
    748             applyStoppedReasonLocked(reason);
    749             mVerb = VERB_STOPPING;
    750             scheduleOpTimeOutLocked();
    751             service.stopJob(mParams);
    752         } catch (RemoteException e) {
    753             Slog.e(TAG, "Error sending onStopJob to client.", e);
    754             // The job's host app apparently crashed during the job, so we should reschedule.
    755             closeAndCleanupJobLocked(true /* reschedule */, "host crashed when trying to stop");
    756         }
    757     }
    758 
    759     /**
    760      * The provided job has finished, either by calling
    761      * {@link android.app.job.JobService#jobFinished(android.app.job.JobParameters, boolean)}
    762      * or from acknowledging the stop message we sent. Either way, we're done tracking it and
    763      * we want to clean up internally.
    764      */
    765     @GuardedBy("mLock")
    766     private void closeAndCleanupJobLocked(boolean reschedule, String reason) {
    767         final JobStatus completedJob;
    768         if (mVerb == VERB_FINISHED) {
    769             return;
    770         }
    771         applyStoppedReasonLocked(reason);
    772         completedJob = mRunningJob;
    773         mJobPackageTracker.noteInactive(completedJob, mParams.getStopReason(), reason);
    774         try {
    775             mBatteryStats.noteJobFinish(mRunningJob.getBatteryName(),
    776                     mRunningJob.getSourceUid(), mParams.getStopReason());
    777         } catch (RemoteException e) {
    778             // Whatever.
    779         }
    780         if (mWakeLock != null) {
    781             mWakeLock.release();
    782         }
    783         mContext.unbindService(JobServiceContext.this);
    784         mWakeLock = null;
    785         mRunningJob = null;
    786         mRunningCallback = null;
    787         mParams = null;
    788         mVerb = VERB_FINISHED;
    789         mCancelled = false;
    790         service = null;
    791         mAvailable = true;
    792         removeOpTimeOutLocked();
    793         mCompletedListener.onJobCompletedLocked(completedJob, reschedule);
    794     }
    795 
    796     private void applyStoppedReasonLocked(String reason) {
    797         if (reason != null && mStoppedReason == null) {
    798             mStoppedReason = reason;
    799             mStoppedTime = sElapsedRealtimeClock.millis();
    800             if (mRunningCallback != null) {
    801                 mRunningCallback.mStoppedReason = mStoppedReason;
    802                 mRunningCallback.mStoppedTime = mStoppedTime;
    803             }
    804         }
    805     }
    806 
    807     /**
    808      * Called when sending a message to the client, over whose execution we have no control. If
    809      * we haven't received a response in a certain amount of time, we want to give up and carry
    810      * on with life.
    811      */
    812     private void scheduleOpTimeOutLocked() {
    813         removeOpTimeOutLocked();
    814 
    815         final long timeoutMillis;
    816         switch (mVerb) {
    817             case VERB_EXECUTING:
    818                 timeoutMillis = EXECUTING_TIMESLICE_MILLIS;
    819                 break;
    820 
    821             case VERB_BINDING:
    822                 timeoutMillis = OP_BIND_TIMEOUT_MILLIS;
    823                 break;
    824 
    825             default:
    826                 timeoutMillis = OP_TIMEOUT_MILLIS;
    827                 break;
    828         }
    829         if (DEBUG) {
    830             Slog.d(TAG, "Scheduling time out for '" +
    831                     mRunningJob.getServiceComponent().getShortClassName() + "' jId: " +
    832                     mParams.getJobId() + ", in " + (timeoutMillis / 1000) + " s");
    833         }
    834         Message m = mCallbackHandler.obtainMessage(MSG_TIMEOUT, mRunningCallback);
    835         mCallbackHandler.sendMessageDelayed(m, timeoutMillis);
    836         mTimeoutElapsed = sElapsedRealtimeClock.millis() + timeoutMillis;
    837     }
    838 
    839 
    840     private void removeOpTimeOutLocked() {
    841         mCallbackHandler.removeMessages(MSG_TIMEOUT);
    842     }
    843 }
    844