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
acknowledgeStartMessage(int jobId, boolean ongoing)149         public void acknowledgeStartMessage(int jobId, boolean ongoing) {
150             doAcknowledgeStartMessage(this, jobId, ongoing);
151         }
152 
153         @Override
acknowledgeStopMessage(int jobId, boolean reschedule)154         public void acknowledgeStopMessage(int jobId, boolean reschedule) {
155             doAcknowledgeStopMessage(this, jobId, reschedule);
156         }
157 
158         @Override
dequeueWork(int jobId)159         public JobWorkItem dequeueWork(int jobId) {
160             return doDequeueWork(this, jobId);
161         }
162 
163         @Override
completeWork(int jobId, int workId)164         public boolean completeWork(int jobId, int workId) {
165             return doCompleteWork(this, jobId, workId);
166         }
167 
168         @Override
jobFinished(int jobId, boolean reschedule)169         public void jobFinished(int jobId, boolean reschedule) {
170             doJobFinished(this, jobId, reschedule);
171         }
172     }
173 
JobServiceContext(JobSchedulerService service, IBatteryStats batteryStats, JobPackageTracker tracker, Looper looper)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
JobServiceContext(Context context, Object lock, IBatteryStats batteryStats, JobPackageTracker tracker, JobCompletedListener completedListener, Looper looper)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      */
executeRunnableJob(JobStatus job)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 = false;
251             try {
252                 binding = mContext.bindServiceAsUser(intent, this,
253                         Context.BIND_AUTO_CREATE | Context.BIND_NOT_FOREGROUND
254                         | Context.BIND_NOT_PERCEPTIBLE,
255                         new UserHandle(job.getUserId()));
256             } catch (SecurityException e) {
257                 // Some permission policy, for example INTERACT_ACROSS_USERS and
258                 // android:singleUser, can result in a SecurityException being thrown from
259                 // bindServiceAsUser().  If this happens, catch it and fail gracefully.
260                 Slog.w(TAG, "Job service " + job.getServiceComponent().getShortClassName()
261                         + " cannot be executed: " + e.getMessage());
262                 binding = false;
263             }
264             if (!binding) {
265                 if (DEBUG) {
266                     Slog.d(TAG, job.getServiceComponent().getShortClassName() + " unavailable.");
267                 }
268                 mRunningJob = null;
269                 mRunningCallback = null;
270                 mParams = null;
271                 mExecutionStartTimeElapsed = 0L;
272                 mVerb = VERB_FINISHED;
273                 removeOpTimeOutLocked();
274                 return false;
275             }
276             mJobPackageTracker.noteActive(job);
277             try {
278                 mBatteryStats.noteJobStart(job.getBatteryName(), job.getSourceUid(),
279                         job.getStandbyBucket(), job.getJobId());
280             } catch (RemoteException e) {
281                 // Whatever.
282             }
283             final String jobPackage = job.getSourcePackageName();
284             final int jobUserId = job.getSourceUserId();
285             UsageStatsManagerInternal usageStats =
286                     LocalServices.getService(UsageStatsManagerInternal.class);
287             usageStats.setLastJobRunTime(jobPackage, jobUserId, mExecutionStartTimeElapsed);
288             JobSchedulerInternal jobScheduler =
289                     LocalServices.getService(JobSchedulerInternal.class);
290             jobScheduler.noteJobStart(jobPackage, jobUserId);
291             mAvailable = false;
292             mStoppedReason = null;
293             mStoppedTime = 0;
294             return true;
295         }
296     }
297 
298     /**
299      * Used externally to query the running job. Will return null if there is no job running.
300      */
getRunningJobLocked()301     JobStatus getRunningJobLocked() {
302         return mRunningJob;
303     }
304 
305     /**
306      * Used only for debugging. Will return <code>"&lt;null&gt;"</code> if there is no job running.
307      */
getRunningJobNameLocked()308     private String getRunningJobNameLocked() {
309         return mRunningJob != null ? mRunningJob.toShortString() : "<null>";
310     }
311 
312     /** Called externally when a job that was scheduled for execution should be cancelled. */
313     @GuardedBy("mLock")
cancelExecutingJobLocked(int reason, String debugReason)314     void cancelExecutingJobLocked(int reason, String debugReason) {
315         doCancelLocked(reason, debugReason);
316     }
317 
318     @GuardedBy("mLock")
preemptExecutingJobLocked()319     void preemptExecutingJobLocked() {
320         doCancelLocked(JobParameters.REASON_PREEMPT, "cancelled due to preemption");
321     }
322 
getPreferredUid()323     int getPreferredUid() {
324         return mPreferredUid;
325     }
326 
clearPreferredUid()327     void clearPreferredUid() {
328         mPreferredUid = NO_PREFERRED_UID;
329     }
330 
getExecutionStartTimeElapsed()331     long getExecutionStartTimeElapsed() {
332         return mExecutionStartTimeElapsed;
333     }
334 
getTimeoutElapsed()335     long getTimeoutElapsed() {
336         return mTimeoutElapsed;
337     }
338 
339     @GuardedBy("mLock")
timeoutIfExecutingLocked(String pkgName, int userId, boolean matchJobId, int jobId, String reason)340     boolean timeoutIfExecutingLocked(String pkgName, int userId, boolean matchJobId, int jobId,
341             String reason) {
342         final JobStatus executing = getRunningJobLocked();
343         if (executing != null && (userId == UserHandle.USER_ALL || userId == executing.getUserId())
344                 && (pkgName == null || pkgName.equals(executing.getSourcePackageName()))
345                 && (!matchJobId || jobId == executing.getJobId())) {
346             if (mVerb == VERB_EXECUTING) {
347                 mParams.setStopReason(JobParameters.REASON_TIMEOUT, reason);
348                 sendStopMessageLocked("force timeout from shell");
349                 return true;
350             }
351         }
352         return false;
353     }
354 
doJobFinished(JobCallback cb, int jobId, boolean reschedule)355     void doJobFinished(JobCallback cb, int jobId, boolean reschedule) {
356         doCallback(cb, reschedule, "app called jobFinished");
357     }
358 
doAcknowledgeStopMessage(JobCallback cb, int jobId, boolean reschedule)359     void doAcknowledgeStopMessage(JobCallback cb, int jobId, boolean reschedule) {
360         doCallback(cb, reschedule, null);
361     }
362 
doAcknowledgeStartMessage(JobCallback cb, int jobId, boolean ongoing)363     void doAcknowledgeStartMessage(JobCallback cb, int jobId, boolean ongoing) {
364         doCallback(cb, ongoing, "finished start");
365     }
366 
doDequeueWork(JobCallback cb, int jobId)367     JobWorkItem doDequeueWork(JobCallback cb, int jobId) {
368         final long ident = Binder.clearCallingIdentity();
369         try {
370             synchronized (mLock) {
371                 assertCallerLocked(cb);
372                 if (mVerb == VERB_STOPPING || mVerb == VERB_FINISHED) {
373                     // This job is either all done, or on its way out.  Either way, it
374                     // should not dispatch any more work.  We will pick up any remaining
375                     // work the next time we start the job again.
376                     return null;
377                 }
378                 final JobWorkItem work = mRunningJob.dequeueWorkLocked();
379                 if (work == null && !mRunningJob.hasExecutingWorkLocked()) {
380                     // This will finish the job.
381                     doCallbackLocked(false, "last work dequeued");
382                 }
383                 return work;
384             }
385         } finally {
386             Binder.restoreCallingIdentity(ident);
387         }
388     }
389 
doCompleteWork(JobCallback cb, int jobId, int workId)390     boolean doCompleteWork(JobCallback cb, int jobId, int workId) {
391         final long ident = Binder.clearCallingIdentity();
392         try {
393             synchronized (mLock) {
394                 assertCallerLocked(cb);
395                 return mRunningJob.completeWorkLocked(ActivityManager.getService(), workId);
396             }
397         } finally {
398             Binder.restoreCallingIdentity(ident);
399         }
400     }
401 
402     /**
403      * We acquire/release a wakelock on onServiceConnected/unbindService. This mirrors the work
404      * we intend to send to the client - we stop sending work when the service is unbound so until
405      * then we keep the wakelock.
406      * @param name The concrete component name of the service that has been connected.
407      * @param service The IBinder of the Service's communication channel,
408      */
409     @Override
onServiceConnected(ComponentName name, IBinder service)410     public void onServiceConnected(ComponentName name, IBinder service) {
411         JobStatus runningJob;
412         synchronized (mLock) {
413             // This isn't strictly necessary b/c the JobServiceHandler is running on the main
414             // looper and at this point we can't get any binder callbacks from the client. Better
415             // safe than sorry.
416             runningJob = mRunningJob;
417 
418             if (runningJob == null || !name.equals(runningJob.getServiceComponent())) {
419                 closeAndCleanupJobLocked(true /* needsReschedule */,
420                         "connected for different component");
421                 return;
422             }
423             this.service = IJobService.Stub.asInterface(service);
424             final PowerManager pm =
425                     (PowerManager) mContext.getSystemService(Context.POWER_SERVICE);
426             PowerManager.WakeLock wl = pm.newWakeLock(PowerManager.PARTIAL_WAKE_LOCK,
427                     runningJob.getTag());
428             wl.setWorkSource(deriveWorkSource(runningJob));
429             wl.setReferenceCounted(false);
430             wl.acquire();
431 
432             // We use a new wakelock instance per job.  In rare cases there is a race between
433             // teardown following job completion/cancellation and new job service spin-up
434             // such that if we simply assign mWakeLock to be the new instance, we orphan
435             // the currently-live lock instead of cleanly replacing it.  Watch for this and
436             // explicitly fast-forward the release if we're in that situation.
437             if (mWakeLock != null) {
438                 Slog.w(TAG, "Bound new job " + runningJob + " but live wakelock " + mWakeLock
439                         + " tag=" + mWakeLock.getTag());
440                 mWakeLock.release();
441             }
442             mWakeLock = wl;
443             doServiceBoundLocked();
444         }
445     }
446 
deriveWorkSource(JobStatus runningJob)447     private WorkSource deriveWorkSource(JobStatus runningJob) {
448         final int jobUid = runningJob.getSourceUid();
449         if (WorkSource.isChainedBatteryAttributionEnabled(mContext)) {
450             WorkSource workSource = new WorkSource();
451             workSource.createWorkChain()
452                     .addNode(jobUid, null)
453                     .addNode(android.os.Process.SYSTEM_UID, "JobScheduler");
454             return workSource;
455         } else {
456             return new WorkSource(jobUid);
457         }
458     }
459 
460     /** If the client service crashes we reschedule this job and clean up. */
461     @Override
onServiceDisconnected(ComponentName name)462     public void onServiceDisconnected(ComponentName name) {
463         synchronized (mLock) {
464             closeAndCleanupJobLocked(true /* needsReschedule */, "unexpectedly disconnected");
465         }
466     }
467 
468     /**
469      * This class is reused across different clients, and passes itself in as a callback. Check
470      * whether the client exercising the callback is the client we expect.
471      * @return True if the binder calling is coming from the client we expect.
472      */
verifyCallerLocked(JobCallback cb)473     private boolean verifyCallerLocked(JobCallback cb) {
474         if (mRunningCallback != cb) {
475             if (DEBUG) {
476                 Slog.d(TAG, "Stale callback received, ignoring.");
477             }
478             return false;
479         }
480         return true;
481     }
482 
assertCallerLocked(JobCallback cb)483     private void assertCallerLocked(JobCallback cb) {
484         if (!verifyCallerLocked(cb)) {
485             StringBuilder sb = new StringBuilder(128);
486             sb.append("Caller no longer running");
487             if (cb.mStoppedReason != null) {
488                 sb.append(", last stopped ");
489                 TimeUtils.formatDuration(sElapsedRealtimeClock.millis() - cb.mStoppedTime, sb);
490                 sb.append(" because: ");
491                 sb.append(cb.mStoppedReason);
492             }
493             throw new SecurityException(sb.toString());
494         }
495     }
496 
497     /**
498      * Scheduling of async messages (basically timeouts at this point).
499      */
500     private class JobServiceHandler extends Handler {
JobServiceHandler(Looper looper)501         JobServiceHandler(Looper looper) {
502             super(looper);
503         }
504 
505         @Override
handleMessage(Message message)506         public void handleMessage(Message message) {
507             switch (message.what) {
508                 case MSG_TIMEOUT:
509                     synchronized (mLock) {
510                         if (message.obj == mRunningCallback) {
511                             handleOpTimeoutLocked();
512                         } else {
513                             JobCallback jc = (JobCallback)message.obj;
514                             StringBuilder sb = new StringBuilder(128);
515                             sb.append("Ignoring timeout of no longer active job");
516                             if (jc.mStoppedReason != null) {
517                                 sb.append(", stopped ");
518                                 TimeUtils.formatDuration(sElapsedRealtimeClock.millis()
519                                         - jc.mStoppedTime, sb);
520                                 sb.append(" because: ");
521                                 sb.append(jc.mStoppedReason);
522                             }
523                             Slog.w(TAG, sb.toString());
524                         }
525                     }
526                     break;
527                 default:
528                     Slog.e(TAG, "Unrecognised message: " + message);
529             }
530         }
531     }
532 
533     @GuardedBy("mLock")
doServiceBoundLocked()534     void doServiceBoundLocked() {
535         removeOpTimeOutLocked();
536         handleServiceBoundLocked();
537     }
538 
doCallback(JobCallback cb, boolean reschedule, String reason)539     void doCallback(JobCallback cb, boolean reschedule, String reason) {
540         final long ident = Binder.clearCallingIdentity();
541         try {
542             synchronized (mLock) {
543                 if (!verifyCallerLocked(cb)) {
544                     return;
545                 }
546                 doCallbackLocked(reschedule, reason);
547             }
548         } finally {
549             Binder.restoreCallingIdentity(ident);
550         }
551     }
552 
553     @GuardedBy("mLock")
doCallbackLocked(boolean reschedule, String reason)554     void doCallbackLocked(boolean reschedule, String reason) {
555         if (DEBUG) {
556             Slog.d(TAG, "doCallback of : " + mRunningJob
557                     + " v:" + VERB_STRINGS[mVerb]);
558         }
559         removeOpTimeOutLocked();
560 
561         if (mVerb == VERB_STARTING) {
562             handleStartedLocked(reschedule);
563         } else if (mVerb == VERB_EXECUTING ||
564                 mVerb == VERB_STOPPING) {
565             handleFinishedLocked(reschedule, reason);
566         } else {
567             if (DEBUG) {
568                 Slog.d(TAG, "Unrecognised callback: " + mRunningJob);
569             }
570         }
571     }
572 
573     @GuardedBy("mLock")
doCancelLocked(int arg1, String debugReason)574     void doCancelLocked(int arg1, String debugReason) {
575         if (mVerb == VERB_FINISHED) {
576             if (DEBUG) {
577                 Slog.d(TAG,
578                         "Trying to process cancel for torn-down context, ignoring.");
579             }
580             return;
581         }
582         mParams.setStopReason(arg1, debugReason);
583         if (arg1 == JobParameters.REASON_PREEMPT) {
584             mPreferredUid = mRunningJob != null ? mRunningJob.getUid() :
585                     NO_PREFERRED_UID;
586         }
587         handleCancelLocked(debugReason);
588     }
589 
590     /** Start the job on the service. */
591     @GuardedBy("mLock")
handleServiceBoundLocked()592     private void handleServiceBoundLocked() {
593         if (DEBUG) {
594             Slog.d(TAG, "handleServiceBound for " + getRunningJobNameLocked());
595         }
596         if (mVerb != VERB_BINDING) {
597             Slog.e(TAG, "Sending onStartJob for a job that isn't pending. "
598                     + VERB_STRINGS[mVerb]);
599             closeAndCleanupJobLocked(false /* reschedule */, "started job not pending");
600             return;
601         }
602         if (mCancelled) {
603             if (DEBUG) {
604                 Slog.d(TAG, "Job cancelled while waiting for bind to complete. "
605                         + mRunningJob);
606             }
607             closeAndCleanupJobLocked(true /* reschedule */, "cancelled while waiting for bind");
608             return;
609         }
610         try {
611             mVerb = VERB_STARTING;
612             scheduleOpTimeOutLocked();
613             service.startJob(mParams);
614         } catch (Exception e) {
615             // We catch 'Exception' because client-app malice or bugs might induce a wide
616             // range of possible exception-throw outcomes from startJob() and its handling
617             // of the client's ParcelableBundle extras.
618             Slog.e(TAG, "Error sending onStart message to '" +
619                     mRunningJob.getServiceComponent().getShortClassName() + "' ", e);
620         }
621     }
622 
623     /**
624      * State behaviours.
625      * VERB_STARTING   -> Successful start, change job to VERB_EXECUTING and post timeout.
626      *     _PENDING    -> Error
627      *     _EXECUTING  -> Error
628      *     _STOPPING   -> Error
629      */
630     @GuardedBy("mLock")
handleStartedLocked(boolean workOngoing)631     private void handleStartedLocked(boolean workOngoing) {
632         switch (mVerb) {
633             case VERB_STARTING:
634                 mVerb = VERB_EXECUTING;
635                 if (!workOngoing) {
636                     // Job is finished already so fast-forward to handleFinished.
637                     handleFinishedLocked(false, "onStartJob returned false");
638                     return;
639                 }
640                 if (mCancelled) {
641                     if (DEBUG) {
642                         Slog.d(TAG, "Job cancelled while waiting for onStartJob to complete.");
643                     }
644                     // Cancelled *while* waiting for acknowledgeStartMessage from client.
645                     handleCancelLocked(null);
646                     return;
647                 }
648                 scheduleOpTimeOutLocked();
649                 break;
650             default:
651                 Slog.e(TAG, "Handling started job but job wasn't starting! Was "
652                         + VERB_STRINGS[mVerb] + ".");
653                 return;
654         }
655     }
656 
657     /**
658      * VERB_EXECUTING  -> Client called jobFinished(), clean up and notify done.
659      *     _STOPPING   -> Successful finish, clean up and notify done.
660      *     _STARTING   -> Error
661      *     _PENDING    -> Error
662      */
663     @GuardedBy("mLock")
handleFinishedLocked(boolean reschedule, String reason)664     private void handleFinishedLocked(boolean reschedule, String reason) {
665         switch (mVerb) {
666             case VERB_EXECUTING:
667             case VERB_STOPPING:
668                 closeAndCleanupJobLocked(reschedule, reason);
669                 break;
670             default:
671                 Slog.e(TAG, "Got an execution complete message for a job that wasn't being" +
672                         "executed. Was " + VERB_STRINGS[mVerb] + ".");
673         }
674     }
675 
676     /**
677      * A job can be in various states when a cancel request comes in:
678      * VERB_BINDING    -> Cancelled before bind completed. Mark as cancelled and wait for
679      *                    {@link #onServiceConnected(android.content.ComponentName, android.os.IBinder)}
680      *     _STARTING   -> Mark as cancelled and wait for
681      *                    {@link JobServiceContext#doAcknowledgeStartMessage}
682      *     _EXECUTING  -> call {@link #sendStopMessageLocked}}, but only if there are no callbacks
683      *                      in the message queue.
684      *     _ENDING     -> No point in doing anything here, so we ignore.
685      */
686     @GuardedBy("mLock")
handleCancelLocked(String reason)687     private void handleCancelLocked(String reason) {
688         if (JobSchedulerService.DEBUG) {
689             Slog.d(TAG, "Handling cancel for: " + mRunningJob.getJobId() + " "
690                     + VERB_STRINGS[mVerb]);
691         }
692         switch (mVerb) {
693             case VERB_BINDING:
694             case VERB_STARTING:
695                 mCancelled = true;
696                 applyStoppedReasonLocked(reason);
697                 break;
698             case VERB_EXECUTING:
699                 sendStopMessageLocked(reason);
700                 break;
701             case VERB_STOPPING:
702                 // Nada.
703                 break;
704             default:
705                 Slog.e(TAG, "Cancelling a job without a valid verb: " + mVerb);
706                 break;
707         }
708     }
709 
710     /** Process MSG_TIMEOUT here. */
711     @GuardedBy("mLock")
handleOpTimeoutLocked()712     private void handleOpTimeoutLocked() {
713         switch (mVerb) {
714             case VERB_BINDING:
715                 Slog.w(TAG, "Time-out while trying to bind " + getRunningJobNameLocked()
716                         + ", dropping.");
717                 closeAndCleanupJobLocked(false /* needsReschedule */, "timed out while binding");
718                 break;
719             case VERB_STARTING:
720                 // Client unresponsive - wedged or failed to respond in time. We don't really
721                 // know what happened so let's log it and notify the JobScheduler
722                 // FINISHED/NO-RETRY.
723                 Slog.w(TAG, "No response from client for onStartJob "
724                         + getRunningJobNameLocked());
725                 closeAndCleanupJobLocked(false /* needsReschedule */, "timed out while starting");
726                 break;
727             case VERB_STOPPING:
728                 // At least we got somewhere, so fail but ask the JobScheduler to reschedule.
729                 Slog.w(TAG, "No response from client for onStopJob "
730                         + getRunningJobNameLocked());
731                 closeAndCleanupJobLocked(true /* needsReschedule */, "timed out while stopping");
732                 break;
733             case VERB_EXECUTING:
734                 // Not an error - client ran out of time.
735                 Slog.i(TAG, "Client timed out while executing (no jobFinished received), " +
736                         "sending onStop: " + getRunningJobNameLocked());
737                 mParams.setStopReason(JobParameters.REASON_TIMEOUT, "client timed out");
738                 sendStopMessageLocked("timeout while executing");
739                 break;
740             default:
741                 Slog.e(TAG, "Handling timeout for an invalid job state: "
742                         + getRunningJobNameLocked() + ", dropping.");
743                 closeAndCleanupJobLocked(false /* needsReschedule */, "invalid timeout");
744         }
745     }
746 
747     /**
748      * Already running, need to stop. Will switch {@link #mVerb} from VERB_EXECUTING ->
749      * VERB_STOPPING.
750      */
751     @GuardedBy("mLock")
sendStopMessageLocked(String reason)752     private void sendStopMessageLocked(String reason) {
753         removeOpTimeOutLocked();
754         if (mVerb != VERB_EXECUTING) {
755             Slog.e(TAG, "Sending onStopJob for a job that isn't started. " + mRunningJob);
756             closeAndCleanupJobLocked(false /* reschedule */, reason);
757             return;
758         }
759         try {
760             applyStoppedReasonLocked(reason);
761             mVerb = VERB_STOPPING;
762             scheduleOpTimeOutLocked();
763             service.stopJob(mParams);
764         } catch (RemoteException e) {
765             Slog.e(TAG, "Error sending onStopJob to client.", e);
766             // The job's host app apparently crashed during the job, so we should reschedule.
767             closeAndCleanupJobLocked(true /* reschedule */, "host crashed when trying to stop");
768         }
769     }
770 
771     /**
772      * The provided job has finished, either by calling
773      * {@link android.app.job.JobService#jobFinished(android.app.job.JobParameters, boolean)}
774      * or from acknowledging the stop message we sent. Either way, we're done tracking it and
775      * we want to clean up internally.
776      */
777     @GuardedBy("mLock")
closeAndCleanupJobLocked(boolean reschedule, String reason)778     private void closeAndCleanupJobLocked(boolean reschedule, String reason) {
779         final JobStatus completedJob;
780         if (mVerb == VERB_FINISHED) {
781             return;
782         }
783         applyStoppedReasonLocked(reason);
784         completedJob = mRunningJob;
785         mJobPackageTracker.noteInactive(completedJob, mParams.getStopReason(), reason);
786         try {
787             mBatteryStats.noteJobFinish(mRunningJob.getBatteryName(),
788                     mRunningJob.getSourceUid(), mParams.getStopReason(),
789                     mRunningJob.getStandbyBucket(), mRunningJob.getJobId());
790         } catch (RemoteException e) {
791             // Whatever.
792         }
793         if (mWakeLock != null) {
794             mWakeLock.release();
795         }
796         mContext.unbindService(JobServiceContext.this);
797         mWakeLock = null;
798         mRunningJob = null;
799         mRunningCallback = null;
800         mParams = null;
801         mVerb = VERB_FINISHED;
802         mCancelled = false;
803         service = null;
804         mAvailable = true;
805         removeOpTimeOutLocked();
806         mCompletedListener.onJobCompletedLocked(completedJob, reschedule);
807     }
808 
applyStoppedReasonLocked(String reason)809     private void applyStoppedReasonLocked(String reason) {
810         if (reason != null && mStoppedReason == null) {
811             mStoppedReason = reason;
812             mStoppedTime = sElapsedRealtimeClock.millis();
813             if (mRunningCallback != null) {
814                 mRunningCallback.mStoppedReason = mStoppedReason;
815                 mRunningCallback.mStoppedTime = mStoppedTime;
816             }
817         }
818     }
819 
820     /**
821      * Called when sending a message to the client, over whose execution we have no control. If
822      * we haven't received a response in a certain amount of time, we want to give up and carry
823      * on with life.
824      */
scheduleOpTimeOutLocked()825     private void scheduleOpTimeOutLocked() {
826         removeOpTimeOutLocked();
827 
828         final long timeoutMillis;
829         switch (mVerb) {
830             case VERB_EXECUTING:
831                 timeoutMillis = EXECUTING_TIMESLICE_MILLIS;
832                 break;
833 
834             case VERB_BINDING:
835                 timeoutMillis = OP_BIND_TIMEOUT_MILLIS;
836                 break;
837 
838             default:
839                 timeoutMillis = OP_TIMEOUT_MILLIS;
840                 break;
841         }
842         if (DEBUG) {
843             Slog.d(TAG, "Scheduling time out for '" +
844                     mRunningJob.getServiceComponent().getShortClassName() + "' jId: " +
845                     mParams.getJobId() + ", in " + (timeoutMillis / 1000) + " s");
846         }
847         Message m = mCallbackHandler.obtainMessage(MSG_TIMEOUT, mRunningCallback);
848         mCallbackHandler.sendMessageDelayed(m, timeoutMillis);
849         mTimeoutElapsed = sElapsedRealtimeClock.millis() + timeoutMillis;
850     }
851 
852 
removeOpTimeOutLocked()853     private void removeOpTimeOutLocked() {
854         mCallbackHandler.removeMessages(MSG_TIMEOUT);
855     }
856 }
857