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 android.app.job.JobInfo.getPriorityString; 20 21 import static com.android.server.job.JobConcurrencyManager.WORK_TYPE_NONE; 22 import static com.android.server.job.JobSchedulerService.sElapsedRealtimeClock; 23 import static com.android.server.job.JobSchedulerService.safelyScaleBytesToKBForHistogram; 24 25 import android.Manifest; 26 import android.annotation.BytesLong; 27 import android.annotation.NonNull; 28 import android.annotation.Nullable; 29 import android.app.ActivityManager; 30 import android.app.ActivityManagerInternal; 31 import android.app.Notification; 32 import android.app.compat.CompatChanges; 33 import android.app.job.IJobCallback; 34 import android.app.job.IJobService; 35 import android.app.job.JobInfo; 36 import android.app.job.JobParameters; 37 import android.app.job.JobProtoEnums; 38 import android.app.job.JobWorkItem; 39 import android.app.usage.UsageStatsManagerInternal; 40 import android.compat.annotation.ChangeId; 41 import android.compat.annotation.EnabledAfter; 42 import android.content.ComponentName; 43 import android.content.Context; 44 import android.content.Intent; 45 import android.content.PermissionChecker; 46 import android.content.ServiceConnection; 47 import android.net.Network; 48 import android.net.Uri; 49 import android.os.Binder; 50 import android.os.Build; 51 import android.os.Handler; 52 import android.os.IBinder; 53 import android.os.Looper; 54 import android.os.Message; 55 import android.os.PowerManager; 56 import android.os.RemoteException; 57 import android.os.Trace; 58 import android.os.UserHandle; 59 import android.util.EventLog; 60 import android.util.IndentingPrintWriter; 61 import android.util.Pair; 62 import android.util.Slog; 63 import android.util.TimeUtils; 64 65 import com.android.internal.annotations.GuardedBy; 66 import com.android.internal.annotations.VisibleForTesting; 67 import com.android.internal.app.IBatteryStats; 68 import com.android.internal.os.TimeoutRecord; 69 import com.android.internal.util.FrameworkStatsLog; 70 import com.android.modules.expresslog.Counter; 71 import com.android.modules.expresslog.Histogram; 72 import com.android.server.EventLogTags; 73 import com.android.server.LocalServices; 74 import com.android.server.job.controllers.JobStatus; 75 import com.android.server.tare.EconomicPolicy; 76 import com.android.server.tare.EconomyManagerInternal; 77 import com.android.server.tare.JobSchedulerEconomicPolicy; 78 79 import java.util.Objects; 80 81 /** 82 * Handles client binding and lifecycle of a job. Jobs execute one at a time on an instance of this 83 * class. 84 * 85 * There are two important interactions into this class from the 86 * {@link com.android.server.job.JobSchedulerService}. To execute a job and to cancel a job. 87 * - Execution of a new job is handled by the {@link #mAvailable}. This bit is flipped once when a 88 * job lands, and again when it is complete. 89 * - Cancelling is trickier, because there are also interactions from the client. It's possible 90 * the {@link com.android.server.job.JobServiceContext.JobServiceHandler} tries to process a 91 * {@link #doCancelLocked} after the client has already finished. This is handled by having 92 * {@link com.android.server.job.JobServiceContext.JobServiceHandler#handleCancelLocked} check whether 93 * the context is still valid. 94 * To mitigate this, we avoid sending duplicate onStopJob() 95 * calls to the client after they've specified jobFinished(). 96 */ 97 public final class JobServiceContext implements ServiceConnection { 98 private static final boolean DEBUG = JobSchedulerService.DEBUG; 99 private static final boolean DEBUG_STANDBY = JobSchedulerService.DEBUG_STANDBY; 100 101 /** 102 * Whether to trigger an ANR when apps are slow to respond on pre-UDC APIs and functionality. 103 */ 104 @ChangeId 105 @EnabledAfter(targetSdkVersion = Build.VERSION_CODES.TIRAMISU) 106 private static final long ANR_PRE_UDC_APIS_ON_SLOW_RESPONSES = 258236856L; 107 108 private static final String TAG = "JobServiceContext"; 109 /** Amount of time the JobScheduler waits for the initial service launch+bind. */ 110 private static final long OP_BIND_TIMEOUT_MILLIS = 18 * 1000 * Build.HW_TIMEOUT_MULTIPLIER; 111 /** Amount of time the JobScheduler will wait for a response from an app for a message. */ 112 private static final long OP_TIMEOUT_MILLIS = 8 * 1000 * Build.HW_TIMEOUT_MULTIPLIER; 113 /** Amount of time the JobScheduler will wait for a job to provide a required notification. */ 114 private static final long NOTIFICATION_TIMEOUT_MILLIS = 10_000L * Build.HW_TIMEOUT_MULTIPLIER; 115 private static final long EXECUTION_DURATION_STAMP_PERIOD_MILLIS = 5 * 60_000L; 116 117 private static final Histogram sEnqueuedJwiAtJobStart = new Histogram( 118 "job_scheduler.value_hist_w_uid_enqueued_work_items_at_job_start", 119 new Histogram.ScaledRangeOptions(20, 1, 3, 1.4f)); 120 private static final Histogram sTransferredNetworkDownloadKBHighWaterMarkLogger = new Histogram( 121 "job_scheduler.value_hist_transferred_network_download_kilobytes_high_water_mark", 122 new Histogram.ScaledRangeOptions(50, 0, 32 /* 32 KB */, 1.31f)); 123 private static final Histogram sTransferredNetworkUploadKBHighWaterMarkLogger = new Histogram( 124 "job_scheduler.value_hist_transferred_network_upload_kilobytes_high_water_mark", 125 new Histogram.ScaledRangeOptions(50, 0, 32 /* 32 KB */, 1.31f)); 126 private static final Histogram sUpdatedEstimatedNetworkDownloadKBLogger = new Histogram( 127 "job_scheduler.value_hist_updated_estimated_network_download_kilobytes", 128 new Histogram.ScaledRangeOptions(50, 0, 32 /* 32 KB */, 1.31f)); 129 private static final Histogram sUpdatedEstimatedNetworkUploadKBLogger = new Histogram( 130 "job_scheduler.value_hist_updated_estimated_network_upload_kilobytes", 131 new Histogram.ScaledRangeOptions(50, 0, 32 /* 32 KB */, 1.31f)); 132 133 private static final String[] VERB_STRINGS = { 134 "VERB_BINDING", "VERB_STARTING", "VERB_EXECUTING", "VERB_STOPPING", "VERB_FINISHED" 135 }; 136 137 // States that a job occupies while interacting with the client. 138 static final int VERB_BINDING = 0; 139 static final int VERB_STARTING = 1; 140 static final int VERB_EXECUTING = 2; 141 static final int VERB_STOPPING = 3; 142 static final int VERB_FINISHED = 4; 143 144 // Messages that result from interactions with the client service. 145 /** System timed out waiting for a response. */ 146 private static final int MSG_TIMEOUT = 0; 147 148 public static final int NO_PREFERRED_UID = -1; 149 150 private final Handler mCallbackHandler; 151 /** Make callbacks to {@link JobSchedulerService} to inform on job completion status. */ 152 private final JobCompletedListener mCompletedListener; 153 private final JobConcurrencyManager mJobConcurrencyManager; 154 private final JobNotificationCoordinator mNotificationCoordinator; 155 private final JobSchedulerService mService; 156 /** Used for service binding, etc. */ 157 private final Context mContext; 158 private final Object mLock; 159 private final ActivityManagerInternal mActivityManagerInternal; 160 private final IBatteryStats mBatteryStats; 161 private final EconomyManagerInternal mEconomyManagerInternal; 162 private final JobPackageTracker mJobPackageTracker; 163 private final PowerManager mPowerManager; 164 private PowerManager.WakeLock mWakeLock; 165 166 // Execution state. 167 private JobParameters mParams; 168 @VisibleForTesting 169 int mVerb; 170 private boolean mCancelled; 171 /** 172 * True if the previous job on this context successfully finished (ie. called jobFinished or 173 * dequeueWork with no work left). 174 */ 175 private boolean mPreviousJobHadSuccessfulFinish; 176 /** 177 * The last time a job on this context didn't finish successfully, in the elapsed realtime 178 * timebase. 179 */ 180 private long mLastUnsuccessfulFinishElapsed; 181 182 /** 183 * All the information maintained about the job currently being executed. 184 * 185 * Any reads (dereferences) not done from the handler thread must be synchronized on 186 * {@link #mLock}. 187 * Writes can only be done from the handler thread, 188 * or {@link #executeRunnableJob(JobStatus, int)}. 189 */ 190 private JobStatus mRunningJob; 191 @JobConcurrencyManager.WorkType 192 private int mRunningJobWorkType; 193 private JobCallback mRunningCallback; 194 /** Used to store next job to run when current job is to be preempted. */ 195 private int mPreferredUid; 196 IJobService service; 197 198 /** 199 * Whether this context is free. This is set to false at the start of execution, and reset to 200 * true when execution is complete. 201 */ 202 @GuardedBy("mLock") 203 private boolean mAvailable; 204 /** Track start time. */ 205 private long mExecutionStartTimeElapsed; 206 /** Track when job will timeout. */ 207 private long mTimeoutElapsed; 208 /** 209 * The minimum amount of time the context will allow the job to run before checking whether to 210 * stop it or not. 211 */ 212 private long mMinExecutionGuaranteeMillis; 213 /** The absolute maximum amount of time the job can run */ 214 private long mMaxExecutionTimeMillis; 215 /** Whether this job is required to provide a notification and we're still waiting for it. */ 216 private boolean mAwaitingNotification; 217 /** The last time we updated the job's execution duration, in the elapsed realtime timebase. */ 218 private long mLastExecutionDurationStampTimeElapsed; 219 220 private long mEstimatedDownloadBytes; 221 private long mEstimatedUploadBytes; 222 private long mTransferredDownloadBytes; 223 private long mTransferredUploadBytes; 224 225 /** 226 * The stop reason for a pending cancel. If there's not pending cancel, then the value should be 227 * {@link JobParameters#STOP_REASON_UNDEFINED}. 228 */ 229 private int mPendingStopReason = JobParameters.STOP_REASON_UNDEFINED; 230 private int mPendingInternalStopReason; 231 private String mPendingDebugStopReason; 232 233 private Network mPendingNetworkChange; 234 235 /** 236 * The reason this job is marked for death. If it's not marked for death, 237 * then the value should be {@link JobParameters#STOP_REASON_UNDEFINED}. 238 */ 239 private int mDeathMarkStopReason = JobParameters.STOP_REASON_UNDEFINED; 240 private int mDeathMarkInternalStopReason; 241 private String mDeathMarkDebugReason; 242 243 // Debugging: reason this job was last stopped. 244 public String mStoppedReason; 245 246 // Debugging: time this job was last stopped. 247 public long mStoppedTime; 248 249 final class JobCallback extends IJobCallback.Stub { 250 public String mStoppedReason; 251 public long mStoppedTime; 252 253 @Override acknowledgeGetTransferredDownloadBytesMessage(int jobId, int workId, @BytesLong long transferredBytes)254 public void acknowledgeGetTransferredDownloadBytesMessage(int jobId, int workId, 255 @BytesLong long transferredBytes) { 256 doAcknowledgeGetTransferredDownloadBytesMessage(this, jobId, workId, transferredBytes); 257 } 258 259 @Override acknowledgeGetTransferredUploadBytesMessage(int jobId, int workId, @BytesLong long transferredBytes)260 public void acknowledgeGetTransferredUploadBytesMessage(int jobId, int workId, 261 @BytesLong long transferredBytes) { 262 doAcknowledgeGetTransferredUploadBytesMessage(this, jobId, workId, transferredBytes); 263 } 264 265 @Override acknowledgeStartMessage(int jobId, boolean ongoing)266 public void acknowledgeStartMessage(int jobId, boolean ongoing) { 267 doAcknowledgeStartMessage(this, jobId, ongoing); 268 } 269 270 @Override acknowledgeStopMessage(int jobId, boolean reschedule)271 public void acknowledgeStopMessage(int jobId, boolean reschedule) { 272 doAcknowledgeStopMessage(this, jobId, reschedule); 273 } 274 275 @Override dequeueWork(int jobId)276 public JobWorkItem dequeueWork(int jobId) { 277 return doDequeueWork(this, jobId); 278 } 279 280 @Override completeWork(int jobId, int workId)281 public boolean completeWork(int jobId, int workId) { 282 return doCompleteWork(this, jobId, workId); 283 } 284 285 @Override jobFinished(int jobId, boolean reschedule)286 public void jobFinished(int jobId, boolean reschedule) { 287 doJobFinished(this, jobId, reschedule); 288 } 289 290 @Override updateEstimatedNetworkBytes(int jobId, JobWorkItem item, long downloadBytes, long uploadBytes)291 public void updateEstimatedNetworkBytes(int jobId, JobWorkItem item, 292 long downloadBytes, long uploadBytes) { 293 doUpdateEstimatedNetworkBytes(this, jobId, item, downloadBytes, uploadBytes); 294 } 295 296 @Override updateTransferredNetworkBytes(int jobId, JobWorkItem item, long downloadBytes, long uploadBytes)297 public void updateTransferredNetworkBytes(int jobId, JobWorkItem item, 298 long downloadBytes, long uploadBytes) { 299 doUpdateTransferredNetworkBytes(this, jobId, item, downloadBytes, uploadBytes); 300 } 301 302 @Override setNotification(int jobId, int notificationId, Notification notification, int jobEndNotificationPolicy)303 public void setNotification(int jobId, int notificationId, 304 Notification notification, int jobEndNotificationPolicy) { 305 doSetNotification(this, jobId, notificationId, notification, jobEndNotificationPolicy); 306 } 307 } 308 JobServiceContext(JobSchedulerService service, JobConcurrencyManager concurrencyManager, JobNotificationCoordinator notificationCoordinator, IBatteryStats batteryStats, JobPackageTracker tracker, Looper looper)309 JobServiceContext(JobSchedulerService service, JobConcurrencyManager concurrencyManager, 310 JobNotificationCoordinator notificationCoordinator, 311 IBatteryStats batteryStats, JobPackageTracker tracker, Looper looper) { 312 mContext = service.getContext(); 313 mLock = service.getLock(); 314 mService = service; 315 mActivityManagerInternal = LocalServices.getService(ActivityManagerInternal.class); 316 mBatteryStats = batteryStats; 317 mEconomyManagerInternal = LocalServices.getService(EconomyManagerInternal.class); 318 mJobPackageTracker = tracker; 319 mCallbackHandler = new JobServiceHandler(looper); 320 mJobConcurrencyManager = concurrencyManager; 321 mNotificationCoordinator = notificationCoordinator; 322 mCompletedListener = service; 323 mPowerManager = mContext.getSystemService(PowerManager.class); 324 mAvailable = true; 325 mVerb = VERB_FINISHED; 326 mPreferredUid = NO_PREFERRED_UID; 327 } 328 329 /** 330 * Give a job to this context for execution. Callers must first check {@link 331 * #getRunningJobLocked()} 332 * and ensure it is null to make sure this is a valid context. 333 * 334 * @param job The status of the job that we are going to run. 335 * @return True if the job is valid and is running. False if the job cannot be executed. 336 */ executeRunnableJob(JobStatus job, @JobConcurrencyManager.WorkType int workType)337 boolean executeRunnableJob(JobStatus job, @JobConcurrencyManager.WorkType int workType) { 338 synchronized (mLock) { 339 if (!mAvailable) { 340 Slog.e(TAG, "Starting new runnable but context is unavailable > Error."); 341 return false; 342 } 343 344 mPreferredUid = NO_PREFERRED_UID; 345 346 mRunningJob = job; 347 mRunningJobWorkType = workType; 348 mRunningCallback = new JobCallback(); 349 mPendingNetworkChange = null; 350 final boolean isDeadlineExpired = 351 job.hasDeadlineConstraint() && 352 (job.getLatestRunTimeElapsed() < sElapsedRealtimeClock.millis()); 353 Uri[] triggeredUris = null; 354 if (job.changedUris != null) { 355 triggeredUris = new Uri[job.changedUris.size()]; 356 job.changedUris.toArray(triggeredUris); 357 } 358 String[] triggeredAuthorities = null; 359 if (job.changedAuthorities != null) { 360 triggeredAuthorities = new String[job.changedAuthorities.size()]; 361 job.changedAuthorities.toArray(triggeredAuthorities); 362 } 363 final JobInfo ji = job.getJob(); 364 final Network passedNetwork = canGetNetworkInformation(job) ? job.network : null; 365 mParams = new JobParameters(mRunningCallback, job.getNamespace(), job.getJobId(), 366 ji.getExtras(), 367 ji.getTransientExtras(), ji.getClipData(), ji.getClipGrantFlags(), 368 isDeadlineExpired, job.shouldTreatAsExpeditedJob(), 369 job.shouldTreatAsUserInitiatedJob(), triggeredUris, triggeredAuthorities, 370 passedNetwork); 371 mExecutionStartTimeElapsed = sElapsedRealtimeClock.millis(); 372 mLastExecutionDurationStampTimeElapsed = mExecutionStartTimeElapsed; 373 mMinExecutionGuaranteeMillis = mService.getMinJobExecutionGuaranteeMs(job); 374 mMaxExecutionTimeMillis = 375 Math.max(mService.getMaxJobExecutionTimeMs(job), mMinExecutionGuaranteeMillis); 376 mEstimatedDownloadBytes = job.getEstimatedNetworkDownloadBytes(); 377 mEstimatedUploadBytes = job.getEstimatedNetworkUploadBytes(); 378 mTransferredDownloadBytes = mTransferredUploadBytes = 0; 379 mAwaitingNotification = job.isUserVisibleJob(); 380 381 final long whenDeferred = job.getWhenStandbyDeferred(); 382 if (whenDeferred > 0) { 383 final long deferral = mExecutionStartTimeElapsed - whenDeferred; 384 EventLog.writeEvent(EventLogTags.JOB_DEFERRED_EXECUTION, deferral); 385 if (DEBUG_STANDBY) { 386 StringBuilder sb = new StringBuilder(128); 387 sb.append("Starting job deferred for standby by "); 388 TimeUtils.formatDuration(deferral, sb); 389 sb.append(" ms : "); 390 sb.append(job.toShortString()); 391 Slog.v(TAG, sb.toString()); 392 } 393 } 394 395 // Once we'e begun executing a job, we by definition no longer care whether 396 // it was inflated from disk with not-yet-coherent delay/deadline bounds. 397 job.clearPersistedUtcTimes(); 398 399 mWakeLock = mPowerManager.newWakeLock(PowerManager.PARTIAL_WAKE_LOCK, job.getTag()); 400 mWakeLock.setWorkSource( 401 mService.deriveWorkSource(job.getSourceUid(), job.getSourcePackageName())); 402 mWakeLock.setReferenceCounted(false); 403 mWakeLock.acquire(); 404 405 // Note the start when we try to bind so that the app is charged for some processing 406 // even if binding fails. 407 mEconomyManagerInternal.noteInstantaneousEvent( 408 job.getSourceUserId(), job.getSourcePackageName(), 409 getStartActionId(job), String.valueOf(job.getJobId())); 410 mVerb = VERB_BINDING; 411 scheduleOpTimeOutLocked(); 412 // Use FLAG_FROM_BACKGROUND to avoid resetting the bad-app tracking. 413 final Intent intent = new Intent().setComponent(job.getServiceComponent()) 414 .setFlags(Intent.FLAG_FROM_BACKGROUND); 415 boolean binding = false; 416 boolean startedWithForegroundFlag = false; 417 try { 418 final Context.BindServiceFlags bindFlags; 419 if (job.shouldTreatAsUserInitiatedJob() && !job.isUserBgRestricted()) { 420 // If the user has bg restricted the app, don't give the job FG privileges 421 // such as bypassing data saver or getting the higher foreground proc state. 422 // If we've gotten to this point, the app is most likely in the foreground, 423 // so the job will run just fine while the user keeps the app in the foreground. 424 bindFlags = Context.BindServiceFlags.of( 425 Context.BIND_AUTO_CREATE 426 | Context.BIND_ALMOST_PERCEPTIBLE 427 | Context.BIND_BYPASS_POWER_NETWORK_RESTRICTIONS 428 | Context.BIND_BYPASS_USER_NETWORK_RESTRICTIONS 429 | Context.BIND_NOT_APP_COMPONENT_USAGE); 430 startedWithForegroundFlag = true; 431 } else if (job.shouldTreatAsExpeditedJob() || job.shouldTreatAsUserInitiatedJob()) { 432 bindFlags = Context.BindServiceFlags.of( 433 Context.BIND_AUTO_CREATE 434 | Context.BIND_NOT_FOREGROUND 435 | Context.BIND_ALMOST_PERCEPTIBLE 436 | Context.BIND_BYPASS_POWER_NETWORK_RESTRICTIONS 437 | Context.BIND_NOT_APP_COMPONENT_USAGE); 438 } else { 439 bindFlags = Context.BindServiceFlags.of( 440 Context.BIND_AUTO_CREATE 441 | Context.BIND_NOT_FOREGROUND 442 | Context.BIND_NOT_PERCEPTIBLE 443 | Context.BIND_NOT_APP_COMPONENT_USAGE); 444 } 445 binding = mContext.bindServiceAsUser(intent, this, bindFlags, 446 UserHandle.of(job.getUserId())); 447 } catch (SecurityException e) { 448 // Some permission policy, for example INTERACT_ACROSS_USERS and 449 // android:singleUser, can result in a SecurityException being thrown from 450 // bindServiceAsUser(). If this happens, catch it and fail gracefully. 451 Slog.w(TAG, "Job service " + job.getServiceComponent().getShortClassName() 452 + " cannot be executed: " + e.getMessage()); 453 binding = false; 454 } 455 if (!binding) { 456 if (DEBUG) { 457 Slog.d(TAG, job.getServiceComponent().getShortClassName() + " unavailable."); 458 } 459 mRunningJob = null; 460 mRunningJobWorkType = WORK_TYPE_NONE; 461 mRunningCallback = null; 462 mParams = null; 463 mExecutionStartTimeElapsed = 0L; 464 mWakeLock.release(); 465 mVerb = VERB_FINISHED; 466 removeOpTimeOutLocked(); 467 return false; 468 } 469 mJobPackageTracker.noteActive(job); 470 FrameworkStatsLog.write_non_chained(FrameworkStatsLog.SCHEDULED_JOB_STATE_CHANGED, 471 job.getSourceUid(), null, job.getBatteryName(), 472 FrameworkStatsLog.SCHEDULED_JOB_STATE_CHANGED__STATE__STARTED, 473 JobProtoEnums.INTERNAL_STOP_REASON_UNKNOWN, 474 job.getStandbyBucket(), 475 job.getLoggingJobId(), 476 job.hasChargingConstraint(), 477 job.hasBatteryNotLowConstraint(), 478 job.hasStorageNotLowConstraint(), 479 job.hasTimingDelayConstraint(), 480 job.hasDeadlineConstraint(), 481 job.hasIdleConstraint(), 482 job.hasConnectivityConstraint(), 483 job.hasContentTriggerConstraint(), 484 job.isRequestedExpeditedJob(), 485 job.shouldTreatAsExpeditedJob(), 486 JobProtoEnums.STOP_REASON_UNDEFINED, 487 job.getJob().isPrefetch(), 488 job.getJob().getPriority(), 489 job.getEffectivePriority(), 490 job.getNumPreviousAttempts(), 491 job.getJob().getMaxExecutionDelayMillis(), 492 isDeadlineExpired, 493 job.isConstraintSatisfied(JobInfo.CONSTRAINT_FLAG_CHARGING), 494 job.isConstraintSatisfied(JobInfo.CONSTRAINT_FLAG_BATTERY_NOT_LOW), 495 job.isConstraintSatisfied(JobInfo.CONSTRAINT_FLAG_STORAGE_NOT_LOW), 496 job.isConstraintSatisfied(JobStatus.CONSTRAINT_TIMING_DELAY), 497 job.isConstraintSatisfied(JobInfo.CONSTRAINT_FLAG_DEVICE_IDLE), 498 job.isConstraintSatisfied(JobStatus.CONSTRAINT_CONNECTIVITY), 499 job.isConstraintSatisfied(JobStatus.CONSTRAINT_CONTENT_TRIGGER), 500 mExecutionStartTimeElapsed - job.enqueueTime, 501 job.getJob().isUserInitiated(), 502 job.shouldTreatAsUserInitiatedJob(), 503 job.getJob().isPeriodic(), 504 job.getJob().getMinLatencyMillis(), 505 job.getEstimatedNetworkDownloadBytes(), 506 job.getEstimatedNetworkUploadBytes(), 507 job.getWorkCount(), 508 ActivityManager.processStateAmToProto(mService.getUidProcState(job.getUid())), 509 job.getNamespaceHash()); 510 sEnqueuedJwiAtJobStart.logSampleWithUid(job.getUid(), job.getWorkCount()); 511 final String sourcePackage = job.getSourcePackageName(); 512 if (Trace.isTagEnabled(Trace.TRACE_TAG_SYSTEM_SERVER)) { 513 final String componentPackage = job.getServiceComponent().getPackageName(); 514 String traceTag = "*job*<" + job.getSourceUid() + ">" + sourcePackage; 515 if (!sourcePackage.equals(componentPackage)) { 516 traceTag += ":" + componentPackage; 517 } 518 traceTag += "/" + job.getServiceComponent().getShortClassName(); 519 if (!componentPackage.equals(job.serviceProcessName)) { 520 traceTag += "$" + job.serviceProcessName; 521 } 522 if (job.getNamespace() != null) { 523 traceTag += "@" + job.getNamespace(); 524 } 525 traceTag += "#" + job.getJobId(); 526 527 // Use the context's ID to distinguish traces since there'll only be one job 528 // running per context. 529 Trace.asyncTraceForTrackBegin(Trace.TRACE_TAG_SYSTEM_SERVER, "JobScheduler", 530 traceTag, getId()); 531 } 532 try { 533 mBatteryStats.noteJobStart(job.getBatteryName(), job.getSourceUid()); 534 } catch (RemoteException e) { 535 // Whatever. 536 } 537 final int jobUserId = job.getSourceUserId(); 538 UsageStatsManagerInternal usageStats = 539 LocalServices.getService(UsageStatsManagerInternal.class); 540 usageStats.setLastJobRunTime(sourcePackage, jobUserId, mExecutionStartTimeElapsed); 541 mAvailable = false; 542 mStoppedReason = null; 543 mStoppedTime = 0; 544 // Wait until after bindService() returns a success value to set these so we don't 545 // have JobStatus objects that aren't running but have these set to true. 546 job.startedAsExpeditedJob = job.shouldTreatAsExpeditedJob(); 547 job.startedAsUserInitiatedJob = job.shouldTreatAsUserInitiatedJob(); 548 job.startedWithForegroundFlag = startedWithForegroundFlag; 549 return true; 550 } 551 } 552 canGetNetworkInformation(@onNull JobStatus job)553 private boolean canGetNetworkInformation(@NonNull JobStatus job) { 554 if (job.getJob().getRequiredNetwork() == null) { 555 // The job never had a network constraint, so we're not going to give it a network 556 // object. Add this check as an early return to avoid wasting cycles doing permission 557 // checks for this job. 558 return false; 559 } 560 // The calling app is doing the work, so use its UID, not the source UID. 561 final int uid = job.getUid(); 562 if (CompatChanges.isChangeEnabled( 563 JobSchedulerService.REQUIRE_NETWORK_PERMISSIONS_FOR_CONNECTIVITY_JOBS, uid)) { 564 final String pkgName = job.getServiceComponent().getPackageName(); 565 if (!hasPermissionForDelivery(uid, pkgName, Manifest.permission.ACCESS_NETWORK_STATE)) { 566 return false; 567 } 568 } 569 570 return true; 571 } 572 hasPermissionForDelivery(int uid, @NonNull String pkgName, @NonNull String permission)573 private boolean hasPermissionForDelivery(int uid, @NonNull String pkgName, 574 @NonNull String permission) { 575 final int result = PermissionChecker.checkPermissionForDataDelivery(mContext, permission, 576 PermissionChecker.PID_UNKNOWN, uid, pkgName, /* attributionTag */ null, 577 "network info via JS"); 578 return result == PermissionChecker.PERMISSION_GRANTED; 579 } 580 581 @EconomicPolicy.AppAction getStartActionId(@onNull JobStatus job)582 private static int getStartActionId(@NonNull JobStatus job) { 583 switch (job.getEffectivePriority()) { 584 case JobInfo.PRIORITY_MAX: 585 return JobSchedulerEconomicPolicy.ACTION_JOB_MAX_START; 586 case JobInfo.PRIORITY_HIGH: 587 return JobSchedulerEconomicPolicy.ACTION_JOB_HIGH_START; 588 case JobInfo.PRIORITY_LOW: 589 return JobSchedulerEconomicPolicy.ACTION_JOB_LOW_START; 590 case JobInfo.PRIORITY_MIN: 591 return JobSchedulerEconomicPolicy.ACTION_JOB_MIN_START; 592 default: 593 Slog.wtf(TAG, "Unknown priority: " + getPriorityString(job.getEffectivePriority())); 594 // Intentional fallthrough 595 case JobInfo.PRIORITY_DEFAULT: 596 return JobSchedulerEconomicPolicy.ACTION_JOB_DEFAULT_START; 597 } 598 } 599 600 /** 601 * Used externally to query the running job. Will return null if there is no job running. 602 */ 603 @Nullable getRunningJobLocked()604 JobStatus getRunningJobLocked() { 605 return mRunningJob; 606 } 607 608 @JobConcurrencyManager.WorkType getRunningJobWorkType()609 int getRunningJobWorkType() { 610 return mRunningJobWorkType; 611 } 612 613 /** 614 * Used only for debugging. Will return <code>"<null>"</code> if there is no job running. 615 */ getRunningJobNameLocked()616 private String getRunningJobNameLocked() { 617 return mRunningJob != null ? mRunningJob.toShortString() : "<null>"; 618 } 619 620 /** Called externally when a job that was scheduled for execution should be cancelled. */ 621 @GuardedBy("mLock") cancelExecutingJobLocked(@obParameters.StopReason int reason, int internalStopReason, @NonNull String debugReason)622 void cancelExecutingJobLocked(@JobParameters.StopReason int reason, 623 int internalStopReason, @NonNull String debugReason) { 624 doCancelLocked(reason, internalStopReason, debugReason); 625 } 626 627 /** 628 * Called when an app's process is about to be killed and we want to update the job's stop 629 * reasons without telling the job it's going to be stopped. 630 */ 631 @GuardedBy("mLock") markForProcessDeathLocked(@obParameters.StopReason int reason, int internalStopReason, @NonNull String debugReason)632 void markForProcessDeathLocked(@JobParameters.StopReason int reason, 633 int internalStopReason, @NonNull String debugReason) { 634 if (mVerb == VERB_FINISHED) { 635 if (DEBUG) { 636 Slog.d(TAG, "Too late to mark for death (verb=" + mVerb + "), ignoring."); 637 } 638 return; 639 } 640 if (DEBUG) { 641 Slog.d(TAG, 642 "Marking " + mRunningJob.toShortString() + " for death because " 643 + reason + ":" + debugReason); 644 } 645 mDeathMarkStopReason = reason; 646 mDeathMarkInternalStopReason = internalStopReason; 647 mDeathMarkDebugReason = debugReason; 648 if (mParams.getStopReason() == JobParameters.STOP_REASON_UNDEFINED) { 649 // Only set the stop reason if we're not already trying to stop the job for some 650 // other reason in case that other stop is successful before the process dies. 651 mParams.setStopReason(reason, internalStopReason, debugReason); 652 } 653 } 654 getPreferredUid()655 int getPreferredUid() { 656 return mPreferredUid; 657 } 658 clearPreferredUid()659 void clearPreferredUid() { 660 mPreferredUid = NO_PREFERRED_UID; 661 } 662 getId()663 int getId() { 664 return hashCode(); 665 } 666 getExecutionStartTimeElapsed()667 long getExecutionStartTimeElapsed() { 668 return mExecutionStartTimeElapsed; 669 } 670 getTimeoutElapsed()671 long getTimeoutElapsed() { 672 return mTimeoutElapsed; 673 } 674 getRemainingGuaranteedTimeMs(long nowElapsed)675 long getRemainingGuaranteedTimeMs(long nowElapsed) { 676 return Math.max(0, mExecutionStartTimeElapsed + mMinExecutionGuaranteeMillis - nowElapsed); 677 } 678 informOfNetworkChangeLocked(Network newNetwork)679 void informOfNetworkChangeLocked(Network newNetwork) { 680 if (newNetwork != null && mRunningJob != null && !canGetNetworkInformation(mRunningJob)) { 681 // The app can't get network information, so there's no point informing it of network 682 // changes. This case may happen if an app had scheduled network job and then 683 // started targeting U+ without requesting the required network permissions. 684 if (DEBUG) { 685 Slog.d(TAG, "Skipping network change call because of missing permissions"); 686 } 687 return; 688 } 689 if (mVerb != VERB_EXECUTING) { 690 Slog.w(TAG, "Sending onNetworkChanged for a job that isn't started. " + mRunningJob); 691 if (mVerb == VERB_BINDING || mVerb == VERB_STARTING) { 692 // The network changed before the job has fully started. Hold the change push 693 // until the job has started executing. 694 mPendingNetworkChange = newNetwork; 695 } 696 return; 697 } 698 try { 699 mParams.setNetwork(newNetwork); 700 mPendingNetworkChange = null; 701 service.onNetworkChanged(mParams); 702 } catch (RemoteException e) { 703 Slog.e(TAG, "Error sending onNetworkChanged to client.", e); 704 // The job's host app apparently crashed during the job, so we should reschedule. 705 closeAndCleanupJobLocked(/* reschedule */ true, 706 "host crashed when trying to inform of network change"); 707 } 708 } 709 isWithinExecutionGuaranteeTime()710 boolean isWithinExecutionGuaranteeTime() { 711 return sElapsedRealtimeClock.millis() 712 < mExecutionStartTimeElapsed + mMinExecutionGuaranteeMillis; 713 } 714 715 @GuardedBy("mLock") stopIfExecutingLocked(String pkgName, int userId, @Nullable String namespace, boolean matchJobId, int jobId, int stopReason, int internalStopReason)716 boolean stopIfExecutingLocked(String pkgName, int userId, @Nullable String namespace, 717 boolean matchJobId, int jobId, int stopReason, int internalStopReason) { 718 final JobStatus executing = getRunningJobLocked(); 719 if (executing != null && (userId == UserHandle.USER_ALL || userId == executing.getUserId()) 720 && (pkgName == null || pkgName.equals(executing.getSourcePackageName())) 721 && Objects.equals(namespace, executing.getNamespace()) 722 && (!matchJobId || jobId == executing.getJobId())) { 723 if (mVerb == VERB_EXECUTING) { 724 mParams.setStopReason(stopReason, internalStopReason, "stop from shell"); 725 sendStopMessageLocked("stop from shell"); 726 return true; 727 } 728 } 729 return false; 730 } 731 732 @GuardedBy("mLock") getEstimatedNetworkBytes()733 Pair<Long, Long> getEstimatedNetworkBytes() { 734 return Pair.create(mEstimatedDownloadBytes, mEstimatedUploadBytes); 735 } 736 737 @GuardedBy("mLock") getTransferredNetworkBytes()738 Pair<Long, Long> getTransferredNetworkBytes() { 739 return Pair.create(mTransferredDownloadBytes, mTransferredUploadBytes); 740 } 741 doJobFinished(JobCallback cb, int jobId, boolean reschedule)742 void doJobFinished(JobCallback cb, int jobId, boolean reschedule) { 743 final long ident = Binder.clearCallingIdentity(); 744 try { 745 synchronized (mLock) { 746 if (!verifyCallerLocked(cb)) { 747 return; 748 } 749 mParams.setStopReason(JobParameters.STOP_REASON_UNDEFINED, 750 JobParameters.INTERNAL_STOP_REASON_SUCCESSFUL_FINISH, 751 "app called jobFinished"); 752 doCallbackLocked(reschedule, "app called jobFinished"); 753 } 754 } finally { 755 Binder.restoreCallingIdentity(ident); 756 } 757 } 758 doAcknowledgeGetTransferredDownloadBytesMessage(JobCallback cb, int jobId, int workId, @BytesLong long transferredBytes)759 private void doAcknowledgeGetTransferredDownloadBytesMessage(JobCallback cb, int jobId, 760 int workId, @BytesLong long transferredBytes) { 761 // TODO(255393346): Make sure apps call this appropriately and monitor for abuse 762 synchronized (mLock) { 763 if (!verifyCallerLocked(cb)) { 764 return; 765 } 766 mTransferredDownloadBytes = transferredBytes; 767 } 768 } 769 doAcknowledgeGetTransferredUploadBytesMessage(JobCallback cb, int jobId, int workId, @BytesLong long transferredBytes)770 private void doAcknowledgeGetTransferredUploadBytesMessage(JobCallback cb, int jobId, 771 int workId, @BytesLong long transferredBytes) { 772 // TODO(255393346): Make sure apps call this appropriately and monitor for abuse 773 synchronized (mLock) { 774 if (!verifyCallerLocked(cb)) { 775 return; 776 } 777 mTransferredUploadBytes = transferredBytes; 778 } 779 } 780 doAcknowledgeStopMessage(JobCallback cb, int jobId, boolean reschedule)781 void doAcknowledgeStopMessage(JobCallback cb, int jobId, boolean reschedule) { 782 doCallback(cb, reschedule, null); 783 } 784 doAcknowledgeStartMessage(JobCallback cb, int jobId, boolean ongoing)785 void doAcknowledgeStartMessage(JobCallback cb, int jobId, boolean ongoing) { 786 doCallback(cb, ongoing, "finished start"); 787 } 788 doDequeueWork(JobCallback cb, int jobId)789 JobWorkItem doDequeueWork(JobCallback cb, int jobId) { 790 final long ident = Binder.clearCallingIdentity(); 791 try { 792 synchronized (mLock) { 793 if (!assertCallerLocked(cb)) { 794 return null; 795 } 796 if (mVerb == VERB_STOPPING || mVerb == VERB_FINISHED) { 797 // This job is either all done, or on its way out. Either way, it 798 // should not dispatch any more work. We will pick up any remaining 799 // work the next time we start the job again. 800 return null; 801 } 802 final JobWorkItem work = mRunningJob.dequeueWorkLocked(); 803 if (work == null && !mRunningJob.hasExecutingWorkLocked()) { 804 mParams.setStopReason(JobParameters.STOP_REASON_UNDEFINED, 805 JobParameters.INTERNAL_STOP_REASON_SUCCESSFUL_FINISH, 806 "last work dequeued"); 807 // This will finish the job. 808 doCallbackLocked(false, "last work dequeued"); 809 } else if (work != null) { 810 // Delivery count has been updated, so persist JobWorkItem change. 811 mService.mJobs.touchJob(mRunningJob); 812 } 813 return work; 814 } 815 } finally { 816 Binder.restoreCallingIdentity(ident); 817 } 818 } 819 doCompleteWork(JobCallback cb, int jobId, int workId)820 boolean doCompleteWork(JobCallback cb, int jobId, int workId) { 821 final long ident = Binder.clearCallingIdentity(); 822 try { 823 synchronized (mLock) { 824 if (!assertCallerLocked(cb)) { 825 // Return true instead of false here so we don't just kick the 826 // Exception-throwing-can down the road to JobParameters.completeWork >:( 827 return true; 828 } 829 if (mRunningJob.completeWorkLocked(workId)) { 830 mService.mJobs.touchJob(mRunningJob); 831 return true; 832 } 833 return false; 834 } 835 } finally { 836 Binder.restoreCallingIdentity(ident); 837 } 838 } 839 doUpdateEstimatedNetworkBytes(JobCallback cb, int jobId, @Nullable JobWorkItem item, long downloadBytes, long uploadBytes)840 private void doUpdateEstimatedNetworkBytes(JobCallback cb, int jobId, 841 @Nullable JobWorkItem item, long downloadBytes, long uploadBytes) { 842 // TODO(255393346): Make sure apps call this appropriately and monitor for abuse 843 synchronized (mLock) { 844 if (!verifyCallerLocked(cb)) { 845 return; 846 } 847 Counter.logIncrementWithUid( 848 "job_scheduler.value_cntr_w_uid_estimated_network_bytes_updated", 849 mRunningJob.getUid()); 850 sUpdatedEstimatedNetworkDownloadKBLogger.logSample( 851 safelyScaleBytesToKBForHistogram(downloadBytes)); 852 sUpdatedEstimatedNetworkUploadKBLogger.logSample( 853 safelyScaleBytesToKBForHistogram(uploadBytes)); 854 if (mEstimatedDownloadBytes != JobInfo.NETWORK_BYTES_UNKNOWN 855 && downloadBytes != JobInfo.NETWORK_BYTES_UNKNOWN) { 856 if (mEstimatedDownloadBytes < downloadBytes) { 857 Counter.logIncrementWithUid( 858 "job_scheduler." 859 + "value_cntr_w_uid_estimated_network_download_bytes_increased", 860 mRunningJob.getUid()); 861 } else if (mEstimatedDownloadBytes > downloadBytes) { 862 Counter.logIncrementWithUid( 863 "job_scheduler." 864 + "value_cntr_w_uid_estimated_network_download_bytes_decreased", 865 mRunningJob.getUid()); 866 } 867 } 868 if (mEstimatedUploadBytes != JobInfo.NETWORK_BYTES_UNKNOWN 869 && uploadBytes != JobInfo.NETWORK_BYTES_UNKNOWN) { 870 if (mEstimatedUploadBytes < uploadBytes) { 871 Counter.logIncrementWithUid( 872 "job_scheduler" 873 + ".value_cntr_w_uid_estimated_network_upload_bytes_increased", 874 mRunningJob.getUid()); 875 } else if (mEstimatedUploadBytes > uploadBytes) { 876 Counter.logIncrementWithUid( 877 "job_scheduler" 878 + ".value_cntr_w_uid_estimated_network_upload_bytes_decreased", 879 mRunningJob.getUid()); 880 } 881 } 882 mEstimatedDownloadBytes = downloadBytes; 883 mEstimatedUploadBytes = uploadBytes; 884 } 885 } 886 doUpdateTransferredNetworkBytes(JobCallback cb, int jobId, @Nullable JobWorkItem item, long downloadBytes, long uploadBytes)887 private void doUpdateTransferredNetworkBytes(JobCallback cb, int jobId, 888 @Nullable JobWorkItem item, long downloadBytes, long uploadBytes) { 889 // TODO(255393346): Make sure apps call this appropriately and monitor for abuse 890 synchronized (mLock) { 891 if (!verifyCallerLocked(cb)) { 892 return; 893 } 894 Counter.logIncrementWithUid( 895 "job_scheduler.value_cntr_w_uid_transferred_network_bytes_updated", 896 mRunningJob.getUid()); 897 sTransferredNetworkDownloadKBHighWaterMarkLogger.logSample( 898 safelyScaleBytesToKBForHistogram(downloadBytes)); 899 sTransferredNetworkUploadKBHighWaterMarkLogger.logSample( 900 safelyScaleBytesToKBForHistogram(uploadBytes)); 901 if (mTransferredDownloadBytes != JobInfo.NETWORK_BYTES_UNKNOWN 902 && downloadBytes != JobInfo.NETWORK_BYTES_UNKNOWN) { 903 if (mTransferredDownloadBytes < downloadBytes) { 904 Counter.logIncrementWithUid( 905 "job_scheduler." 906 + "value_cntr_w_uid_transferred_network_download_bytes_increased", 907 mRunningJob.getUid()); 908 } else if (mTransferredDownloadBytes > downloadBytes) { 909 Counter.logIncrementWithUid( 910 "job_scheduler." 911 + "value_cntr_w_uid_transferred_network_download_bytes_decreased", 912 mRunningJob.getUid()); 913 } 914 } 915 if (mTransferredUploadBytes != JobInfo.NETWORK_BYTES_UNKNOWN 916 && uploadBytes != JobInfo.NETWORK_BYTES_UNKNOWN) { 917 if (mTransferredUploadBytes < uploadBytes) { 918 Counter.logIncrementWithUid( 919 "job_scheduler." 920 + "value_cntr_w_uid_transferred_network_upload_bytes_increased", 921 mRunningJob.getUid()); 922 } else if (mTransferredUploadBytes > uploadBytes) { 923 Counter.logIncrementWithUid( 924 "job_scheduler." 925 + "value_cntr_w_uid_transferred_network_upload_bytes_decreased", 926 mRunningJob.getUid()); 927 } 928 } 929 mTransferredDownloadBytes = downloadBytes; 930 mTransferredUploadBytes = uploadBytes; 931 } 932 } 933 doSetNotification(JobCallback cb, int jodId, int notificationId, Notification notification, int jobEndNotificationPolicy)934 private void doSetNotification(JobCallback cb, int jodId, int notificationId, 935 Notification notification, int jobEndNotificationPolicy) { 936 final int callingPid = Binder.getCallingPid(); 937 final int callingUid = Binder.getCallingUid(); 938 final long ident = Binder.clearCallingIdentity(); 939 try { 940 synchronized (mLock) { 941 if (!verifyCallerLocked(cb)) { 942 return; 943 } 944 if (callingUid != mRunningJob.getUid()) { 945 Slog.wtfStack(TAG, "Calling UID isn't the same as running job's UID..."); 946 throw new SecurityException("Can't post notification on behalf of another app"); 947 } 948 final String callingPkgName = mRunningJob.getServiceComponent().getPackageName(); 949 mNotificationCoordinator.enqueueNotification(this, callingPkgName, 950 callingPid, callingUid, notificationId, 951 notification, jobEndNotificationPolicy); 952 if (mAwaitingNotification) { 953 mAwaitingNotification = false; 954 if (mVerb == VERB_EXECUTING) { 955 scheduleOpTimeOutLocked(); 956 } 957 } 958 } 959 } finally { 960 Binder.restoreCallingIdentity(ident); 961 } 962 } 963 964 /** 965 * We acquire/release a wakelock on onServiceConnected/unbindService. This mirrors the work 966 * we intend to send to the client - we stop sending work when the service is unbound so until 967 * then we keep the wakelock. 968 * @param name The concrete component name of the service that has been connected. 969 * @param service The IBinder of the Service's communication channel, 970 */ 971 @Override onServiceConnected(ComponentName name, IBinder service)972 public void onServiceConnected(ComponentName name, IBinder service) { 973 JobStatus runningJob; 974 synchronized (mLock) { 975 // This isn't strictly necessary b/c the JobServiceHandler is running on the main 976 // looper and at this point we can't get any binder callbacks from the client. Better 977 // safe than sorry. 978 runningJob = mRunningJob; 979 980 if (runningJob == null || !name.equals(runningJob.getServiceComponent())) { 981 closeAndCleanupJobLocked(true /* needsReschedule */, 982 "connected for different component"); 983 return; 984 } 985 this.service = IJobService.Stub.asInterface(service); 986 doServiceBoundLocked(); 987 } 988 } 989 990 /** If the client service crashes we reschedule this job and clean up. */ 991 @Override onServiceDisconnected(ComponentName name)992 public void onServiceDisconnected(ComponentName name) { 993 synchronized (mLock) { 994 if (mDeathMarkStopReason != JobParameters.STOP_REASON_UNDEFINED) { 995 // Service "unexpectedly" disconnected, but we knew the process was going to die. 996 // Use that as the stop reason for logging/debugging purposes. 997 mParams.setStopReason( 998 mDeathMarkStopReason, mDeathMarkInternalStopReason, mDeathMarkDebugReason); 999 } else if (mRunningJob != null) { 1000 Counter.logIncrementWithUid( 1001 "job_scheduler.value_cntr_w_uid_unexpected_service_disconnects", 1002 // Use the calling UID since that's the one this context was connected to. 1003 mRunningJob.getUid()); 1004 } 1005 closeAndCleanupJobLocked(true /* needsReschedule */, "unexpectedly disconnected"); 1006 } 1007 } 1008 1009 @Override onBindingDied(ComponentName name)1010 public void onBindingDied(ComponentName name) { 1011 synchronized (mLock) { 1012 if (mRunningJob == null) { 1013 Slog.e(TAG, "Binding died for " + name.getPackageName() 1014 + " but no running job on this context"); 1015 } else if (mRunningJob.getServiceComponent().equals(name)) { 1016 Slog.e(TAG, "Binding died for " 1017 + mRunningJob.getSourceUserId() + ":" + name.getPackageName()); 1018 } else { 1019 Slog.e(TAG, "Binding died for " + name.getPackageName() 1020 + " but context is running a different job"); 1021 } 1022 closeAndCleanupJobLocked(true /* needsReschedule */, "binding died"); 1023 } 1024 } 1025 1026 @Override onNullBinding(ComponentName name)1027 public void onNullBinding(ComponentName name) { 1028 synchronized (mLock) { 1029 if (mRunningJob == null) { 1030 Slog.wtf(TAG, "Got null binding for " + name.getPackageName() 1031 + " but no running job on this context"); 1032 } else if (mRunningJob.getServiceComponent().equals(name)) { 1033 Slog.wtf(TAG, "Got null binding for " 1034 + mRunningJob.getSourceUserId() + ":" + name.getPackageName()); 1035 } else { 1036 Slog.wtf(TAG, "Got null binding for " + name.getPackageName() 1037 + " but context is running a different job"); 1038 } 1039 // Don't reschedule the job since returning a null binding is an explicit choice by the 1040 // app which breaks things. 1041 closeAndCleanupJobLocked(false /* needsReschedule */, "null binding"); 1042 } 1043 } 1044 1045 /** 1046 * This class is reused across different clients, and passes itself in as a callback. Check 1047 * whether the client exercising the callback is the client we expect. 1048 * @return True if the binder calling is coming from the client we expect. 1049 */ verifyCallerLocked(JobCallback cb)1050 private boolean verifyCallerLocked(JobCallback cb) { 1051 if (mRunningCallback != cb) { 1052 if (DEBUG) { 1053 Slog.d(TAG, "Stale callback received, ignoring."); 1054 } 1055 return false; 1056 } 1057 return true; 1058 } 1059 1060 /** 1061 * Will throw a {@link SecurityException} if the callback is not for the currently running job, 1062 * but may decide not to throw an exception if the call from the previous job appears to be an 1063 * accident. 1064 * 1065 * @return true if the callback is for the current job, false otherwise 1066 */ assertCallerLocked(JobCallback cb)1067 private boolean assertCallerLocked(JobCallback cb) { 1068 if (!verifyCallerLocked(cb)) { 1069 final long nowElapsed = sElapsedRealtimeClock.millis(); 1070 if (!mPreviousJobHadSuccessfulFinish 1071 && (nowElapsed - mLastUnsuccessfulFinishElapsed) < 15_000L) { 1072 // Don't punish apps for race conditions 1073 return false; 1074 } 1075 // It's been long enough that the app should really not be calling into JS for the 1076 // stopped job. 1077 StringBuilder sb = new StringBuilder(128); 1078 sb.append("Caller no longer running"); 1079 if (cb.mStoppedReason != null) { 1080 sb.append(", last stopped "); 1081 TimeUtils.formatDuration(nowElapsed - cb.mStoppedTime, sb); 1082 sb.append(" because: "); 1083 sb.append(cb.mStoppedReason); 1084 } 1085 throw new SecurityException(sb.toString()); 1086 } 1087 return true; 1088 } 1089 1090 /** 1091 * Scheduling of async messages (basically timeouts at this point). 1092 */ 1093 private class JobServiceHandler extends Handler { JobServiceHandler(Looper looper)1094 JobServiceHandler(Looper looper) { 1095 super(looper); 1096 } 1097 1098 @Override handleMessage(Message message)1099 public void handleMessage(Message message) { 1100 switch (message.what) { 1101 case MSG_TIMEOUT: 1102 synchronized (mLock) { 1103 if (message.obj == mRunningCallback) { 1104 handleOpTimeoutLocked(); 1105 } else { 1106 JobCallback jc = (JobCallback)message.obj; 1107 StringBuilder sb = new StringBuilder(128); 1108 sb.append("Ignoring timeout of no longer active job"); 1109 if (jc.mStoppedReason != null) { 1110 sb.append(", stopped "); 1111 TimeUtils.formatDuration(sElapsedRealtimeClock.millis() 1112 - jc.mStoppedTime, sb); 1113 sb.append(" because: "); 1114 sb.append(jc.mStoppedReason); 1115 } 1116 Slog.w(TAG, sb.toString()); 1117 } 1118 } 1119 break; 1120 default: 1121 Slog.e(TAG, "Unrecognised message: " + message); 1122 } 1123 } 1124 } 1125 1126 @GuardedBy("mLock") doServiceBoundLocked()1127 void doServiceBoundLocked() { 1128 removeOpTimeOutLocked(); 1129 handleServiceBoundLocked(); 1130 } 1131 doCallback(JobCallback cb, boolean reschedule, String reason)1132 void doCallback(JobCallback cb, boolean reschedule, String reason) { 1133 final long ident = Binder.clearCallingIdentity(); 1134 try { 1135 synchronized (mLock) { 1136 if (!verifyCallerLocked(cb)) { 1137 return; 1138 } 1139 doCallbackLocked(reschedule, reason); 1140 } 1141 } finally { 1142 Binder.restoreCallingIdentity(ident); 1143 } 1144 } 1145 1146 @GuardedBy("mLock") doCallbackLocked(boolean reschedule, String reason)1147 void doCallbackLocked(boolean reschedule, String reason) { 1148 if (DEBUG) { 1149 Slog.d(TAG, "doCallback of : " + mRunningJob 1150 + " v:" + VERB_STRINGS[mVerb]); 1151 } 1152 removeOpTimeOutLocked(); 1153 1154 if (mVerb == VERB_STARTING) { 1155 handleStartedLocked(reschedule); 1156 } else if (mVerb == VERB_EXECUTING || 1157 mVerb == VERB_STOPPING) { 1158 handleFinishedLocked(reschedule, reason); 1159 } else { 1160 if (DEBUG) { 1161 Slog.d(TAG, "Unrecognised callback: " + mRunningJob); 1162 } 1163 } 1164 } 1165 1166 @GuardedBy("mLock") doCancelLocked(@obParameters.StopReason int stopReasonCode, int internalStopReasonCode, @Nullable String debugReason)1167 private void doCancelLocked(@JobParameters.StopReason int stopReasonCode, 1168 int internalStopReasonCode, @Nullable String debugReason) { 1169 if (mVerb == VERB_FINISHED || mVerb == VERB_STOPPING) { 1170 if (DEBUG) { 1171 Slog.d(TAG, 1172 "Too late to process cancel for context (verb=" + mVerb + "), ignoring."); 1173 } 1174 return; 1175 } 1176 if (mRunningJob.startedAsExpeditedJob 1177 && stopReasonCode == JobParameters.STOP_REASON_QUOTA) { 1178 // EJs should be able to run for at least the min upper limit regardless of quota. 1179 final long earliestStopTimeElapsed = 1180 mExecutionStartTimeElapsed + mMinExecutionGuaranteeMillis; 1181 final long nowElapsed = sElapsedRealtimeClock.millis(); 1182 if (nowElapsed < earliestStopTimeElapsed) { 1183 mPendingStopReason = stopReasonCode; 1184 mPendingInternalStopReason = internalStopReasonCode; 1185 mPendingDebugStopReason = debugReason; 1186 return; 1187 } 1188 } 1189 mParams.setStopReason(stopReasonCode, internalStopReasonCode, debugReason); 1190 if (stopReasonCode == JobParameters.STOP_REASON_PREEMPT) { 1191 // Only preserve the UID when we're preempting the job for another one of the same UID. 1192 mPreferredUid = mRunningJob != null ? mRunningJob.getUid() : NO_PREFERRED_UID; 1193 } 1194 handleCancelLocked(debugReason); 1195 } 1196 1197 /** Start the job on the service. */ 1198 @GuardedBy("mLock") handleServiceBoundLocked()1199 private void handleServiceBoundLocked() { 1200 if (DEBUG) { 1201 Slog.d(TAG, "handleServiceBound for " + getRunningJobNameLocked()); 1202 } 1203 if (mVerb != VERB_BINDING) { 1204 Slog.e(TAG, "Sending onStartJob for a job that isn't pending. " 1205 + VERB_STRINGS[mVerb]); 1206 closeAndCleanupJobLocked(false /* reschedule */, "started job not pending"); 1207 return; 1208 } 1209 if (mCancelled) { 1210 if (DEBUG) { 1211 Slog.d(TAG, "Job cancelled while waiting for bind to complete. " 1212 + mRunningJob); 1213 } 1214 closeAndCleanupJobLocked(true /* reschedule */, "cancelled while waiting for bind"); 1215 return; 1216 } 1217 try { 1218 mVerb = VERB_STARTING; 1219 scheduleOpTimeOutLocked(); 1220 service.startJob(mParams); 1221 } catch (Exception e) { 1222 // We catch 'Exception' because client-app malice or bugs might induce a wide 1223 // range of possible exception-throw outcomes from startJob() and its handling 1224 // of the client's ParcelableBundle extras. 1225 Slog.e(TAG, "Error sending onStart message to '" + 1226 mRunningJob.getServiceComponent().getShortClassName() + "' ", e); 1227 } 1228 } 1229 1230 /** 1231 * State behaviours. 1232 * VERB_STARTING -> Successful start, change job to VERB_EXECUTING and post timeout. 1233 * _PENDING -> Error 1234 * _EXECUTING -> Error 1235 * _STOPPING -> Error 1236 */ 1237 @GuardedBy("mLock") handleStartedLocked(boolean workOngoing)1238 private void handleStartedLocked(boolean workOngoing) { 1239 switch (mVerb) { 1240 case VERB_STARTING: 1241 mVerb = VERB_EXECUTING; 1242 if (!workOngoing) { 1243 // Job is finished already so fast-forward to handleFinished. 1244 handleFinishedLocked(false, "onStartJob returned false"); 1245 return; 1246 } 1247 if (mCancelled) { 1248 if (DEBUG) { 1249 Slog.d(TAG, "Job cancelled while waiting for onStartJob to complete."); 1250 } 1251 // Cancelled *while* waiting for acknowledgeStartMessage from client. 1252 handleCancelLocked(null); 1253 return; 1254 } 1255 scheduleOpTimeOutLocked(); 1256 if (mPendingNetworkChange != null 1257 && !Objects.equals(mParams.getNetwork(), mPendingNetworkChange)) { 1258 informOfNetworkChangeLocked(mPendingNetworkChange); 1259 } 1260 if (mRunningJob.isUserVisibleJob()) { 1261 mService.informObserversOfUserVisibleJobChange(this, mRunningJob, true); 1262 } 1263 break; 1264 default: 1265 Slog.e(TAG, "Handling started job but job wasn't starting! Was " 1266 + VERB_STRINGS[mVerb] + "."); 1267 return; 1268 } 1269 } 1270 1271 /** 1272 * VERB_EXECUTING -> Client called jobFinished(), clean up and notify done. 1273 * _STOPPING -> Successful finish, clean up and notify done. 1274 * _STARTING -> Error 1275 * _PENDING -> Error 1276 */ 1277 @GuardedBy("mLock") handleFinishedLocked(boolean reschedule, String reason)1278 private void handleFinishedLocked(boolean reschedule, String reason) { 1279 switch (mVerb) { 1280 case VERB_EXECUTING: 1281 case VERB_STOPPING: 1282 closeAndCleanupJobLocked(reschedule, reason); 1283 break; 1284 default: 1285 Slog.e(TAG, "Got an execution complete message for a job that wasn't being" + 1286 "executed. Was " + VERB_STRINGS[mVerb] + "."); 1287 } 1288 } 1289 1290 /** 1291 * A job can be in various states when a cancel request comes in: 1292 * VERB_BINDING -> Cancelled before bind completed. Mark as cancelled and wait for 1293 * {@link #onServiceConnected(android.content.ComponentName, android.os.IBinder)} 1294 * _STARTING -> Mark as cancelled and wait for 1295 * {@link JobServiceContext#doAcknowledgeStartMessage} 1296 * _EXECUTING -> call {@link #sendStopMessageLocked}}, but only if there are no callbacks 1297 * in the message queue. 1298 * _ENDING -> No point in doing anything here, so we ignore. 1299 */ 1300 @GuardedBy("mLock") handleCancelLocked(@ullable String reason)1301 private void handleCancelLocked(@Nullable String reason) { 1302 if (JobSchedulerService.DEBUG) { 1303 Slog.d(TAG, "Handling cancel for: " + mRunningJob.getJobId() + " " 1304 + VERB_STRINGS[mVerb]); 1305 } 1306 switch (mVerb) { 1307 case VERB_BINDING: 1308 case VERB_STARTING: 1309 mCancelled = true; 1310 applyStoppedReasonLocked(reason); 1311 break; 1312 case VERB_EXECUTING: 1313 sendStopMessageLocked(reason); 1314 break; 1315 case VERB_STOPPING: 1316 // Nada. 1317 break; 1318 default: 1319 Slog.e(TAG, "Cancelling a job without a valid verb: " + mVerb); 1320 break; 1321 } 1322 } 1323 1324 /** Process MSG_TIMEOUT here. */ 1325 @GuardedBy("mLock") handleOpTimeoutLocked()1326 private void handleOpTimeoutLocked() { 1327 switch (mVerb) { 1328 case VERB_BINDING: 1329 onSlowAppResponseLocked(/* reschedule */ false, /* updateStopReasons */ true, 1330 /* texCounterMetricId */ 1331 "job_scheduler.value_cntr_w_uid_slow_app_response_binding", 1332 /* debugReason */ "timed out while binding", 1333 /* anrMessage */ "Timed out while trying to bind", 1334 CompatChanges.isChangeEnabled(ANR_PRE_UDC_APIS_ON_SLOW_RESPONSES, 1335 mRunningJob.getUid())); 1336 break; 1337 case VERB_STARTING: 1338 // Client unresponsive - wedged or failed to respond in time. We don't really 1339 // know what happened so let's log it and notify the JobScheduler 1340 // FINISHED/NO-RETRY. 1341 onSlowAppResponseLocked(/* reschedule */ false, /* updateStopReasons */ true, 1342 /* texCounterMetricId */ 1343 "job_scheduler.value_cntr_w_uid_slow_app_response_on_start_job", 1344 /* debugReason */ "timed out while starting", 1345 /* anrMessage */ "No response to onStartJob", 1346 CompatChanges.isChangeEnabled(ANR_PRE_UDC_APIS_ON_SLOW_RESPONSES, 1347 mRunningJob.getUid())); 1348 break; 1349 case VERB_STOPPING: 1350 // At least we got somewhere, so fail but ask the JobScheduler to reschedule. 1351 // Don't update the stop reasons since we were already stopping the job for some 1352 // other reason. 1353 onSlowAppResponseLocked(/* reschedule */ true, /* updateStopReasons */ false, 1354 /* texCounterMetricId */ 1355 "job_scheduler.value_cntr_w_uid_slow_app_response_on_stop_job", 1356 /* debugReason */ "timed out while stopping", 1357 /* anrMessage */ "No response to onStopJob", 1358 CompatChanges.isChangeEnabled(ANR_PRE_UDC_APIS_ON_SLOW_RESPONSES, 1359 mRunningJob.getUid())); 1360 break; 1361 case VERB_EXECUTING: 1362 if (mPendingStopReason != JobParameters.STOP_REASON_UNDEFINED) { 1363 if (mService.isReadyToBeExecutedLocked(mRunningJob, false)) { 1364 // Job became ready again while we were waiting to stop it (for example, 1365 // the device was temporarily taken off the charger). Ignore the pending 1366 // stop and see what the manager says. 1367 mPendingStopReason = JobParameters.STOP_REASON_UNDEFINED; 1368 mPendingInternalStopReason = 0; 1369 mPendingDebugStopReason = null; 1370 } else { 1371 Slog.i(TAG, "JS was waiting to stop this job." 1372 + " Sending onStop: " + getRunningJobNameLocked()); 1373 mParams.setStopReason(mPendingStopReason, mPendingInternalStopReason, 1374 mPendingDebugStopReason); 1375 sendStopMessageLocked(mPendingDebugStopReason); 1376 break; 1377 } 1378 } 1379 final long latestStopTimeElapsed = 1380 mExecutionStartTimeElapsed + mMaxExecutionTimeMillis; 1381 final long earliestStopTimeElapsed = 1382 mExecutionStartTimeElapsed + mMinExecutionGuaranteeMillis; 1383 final long nowElapsed = sElapsedRealtimeClock.millis(); 1384 if (nowElapsed >= latestStopTimeElapsed) { 1385 // Not an error - client ran out of time. 1386 Slog.i(TAG, "Client timed out while executing (no jobFinished received)." 1387 + " Sending onStop: " + getRunningJobNameLocked()); 1388 mParams.setStopReason(JobParameters.STOP_REASON_TIMEOUT, 1389 JobParameters.INTERNAL_STOP_REASON_TIMEOUT, "client timed out"); 1390 sendStopMessageLocked("timeout while executing"); 1391 } else if (nowElapsed >= earliestStopTimeElapsed) { 1392 // We've given the app the minimum execution time. See if we should stop it or 1393 // let it continue running 1394 final String reason = mJobConcurrencyManager.shouldStopRunningJobLocked(this); 1395 if (reason != null) { 1396 Slog.i(TAG, "Stopping client after min execution time: " 1397 + getRunningJobNameLocked() + " because " + reason); 1398 // Tell the developer we're stopping the job due to device state instead 1399 // of timeout since all of the reasons could equate to "the system needs 1400 // the resources the app is currently using." 1401 mParams.setStopReason(JobParameters.STOP_REASON_DEVICE_STATE, 1402 JobParameters.INTERNAL_STOP_REASON_TIMEOUT, reason); 1403 sendStopMessageLocked(reason); 1404 } else { 1405 Slog.i(TAG, "Letting " + getRunningJobNameLocked() 1406 + " continue to run past min execution time"); 1407 scheduleOpTimeOutLocked(); 1408 } 1409 } else if (mAwaitingNotification) { 1410 onSlowAppResponseLocked(/* reschedule */ true, /* updateStopReasons */ true, 1411 /* texCounterMetricId */ 1412 "job_scheduler.value_cntr_w_uid_slow_app_response_set_notification", 1413 /* debugReason */ "timed out while stopping", 1414 /* anrMessage */ "required notification not provided", 1415 /* triggerAnr */ true); 1416 } else { 1417 final long timeSinceDurationStampTimeMs = 1418 nowElapsed - mLastExecutionDurationStampTimeElapsed; 1419 if (timeSinceDurationStampTimeMs < EXECUTION_DURATION_STAMP_PERIOD_MILLIS) { 1420 Slog.e(TAG, "Unexpected op timeout while EXECUTING"); 1421 } 1422 // Update the execution time even if this wasn't the pre-set time. 1423 mRunningJob.incrementCumulativeExecutionTime(timeSinceDurationStampTimeMs); 1424 mService.mJobs.touchJob(mRunningJob); 1425 mLastExecutionDurationStampTimeElapsed = nowElapsed; 1426 scheduleOpTimeOutLocked(); 1427 } 1428 break; 1429 default: 1430 Slog.e(TAG, "Handling timeout for an invalid job state: " 1431 + getRunningJobNameLocked() + ", dropping."); 1432 closeAndCleanupJobLocked(false /* needsReschedule */, "invalid timeout"); 1433 } 1434 } 1435 1436 /** 1437 * Already running, need to stop. Will switch {@link #mVerb} from VERB_EXECUTING -> 1438 * VERB_STOPPING. 1439 */ 1440 @GuardedBy("mLock") sendStopMessageLocked(@ullable String reason)1441 private void sendStopMessageLocked(@Nullable String reason) { 1442 removeOpTimeOutLocked(); 1443 if (mVerb != VERB_EXECUTING) { 1444 Slog.e(TAG, "Sending onStopJob for a job that isn't started. " + mRunningJob); 1445 closeAndCleanupJobLocked(false /* reschedule */, reason); 1446 return; 1447 } 1448 try { 1449 applyStoppedReasonLocked(reason); 1450 mVerb = VERB_STOPPING; 1451 scheduleOpTimeOutLocked(); 1452 service.stopJob(mParams); 1453 } catch (RemoteException e) { 1454 Slog.e(TAG, "Error sending onStopJob to client.", e); 1455 // The job's host app apparently crashed during the job, so we should reschedule. 1456 closeAndCleanupJobLocked(true /* reschedule */, "host crashed when trying to stop"); 1457 } 1458 } 1459 1460 @GuardedBy("mLock") onSlowAppResponseLocked(boolean reschedule, boolean updateStopReasons, @NonNull String texCounterMetricId, @NonNull String debugReason, @NonNull String anrMessage, boolean triggerAnr)1461 private void onSlowAppResponseLocked(boolean reschedule, boolean updateStopReasons, 1462 @NonNull String texCounterMetricId, 1463 @NonNull String debugReason, @NonNull String anrMessage, boolean triggerAnr) { 1464 Slog.w(TAG, anrMessage + " for " + getRunningJobNameLocked()); 1465 // Use the calling UID since that's the one this context was connected to. 1466 Counter.logIncrementWithUid(texCounterMetricId, mRunningJob.getUid()); 1467 if (updateStopReasons) { 1468 mParams.setStopReason( 1469 JobParameters.STOP_REASON_UNDEFINED, 1470 JobParameters.INTERNAL_STOP_REASON_ANR, 1471 debugReason); 1472 } 1473 if (triggerAnr) { 1474 mActivityManagerInternal.appNotResponding( 1475 mRunningJob.serviceProcessName, mRunningJob.getUid(), 1476 TimeoutRecord.forJobService(anrMessage)); 1477 } 1478 closeAndCleanupJobLocked(reschedule, debugReason); 1479 } 1480 1481 /** 1482 * The provided job has finished, either by calling 1483 * {@link android.app.job.JobService#jobFinished(android.app.job.JobParameters, boolean)} 1484 * or from acknowledging the stop message we sent. Either way, we're done tracking it and 1485 * we want to clean up internally. 1486 */ 1487 @GuardedBy("mLock") closeAndCleanupJobLocked(boolean reschedule, @Nullable String loggingDebugReason)1488 private void closeAndCleanupJobLocked(boolean reschedule, @Nullable String loggingDebugReason) { 1489 final JobStatus completedJob; 1490 if (mVerb == VERB_FINISHED) { 1491 return; 1492 } 1493 if (DEBUG) { 1494 Slog.d(TAG, "Cleaning up " + mRunningJob.toShortString() 1495 + " reschedule=" + reschedule + " reason=" + loggingDebugReason); 1496 } 1497 final long nowElapsed = sElapsedRealtimeClock.millis(); 1498 applyStoppedReasonLocked(loggingDebugReason); 1499 completedJob = mRunningJob; 1500 completedJob.incrementCumulativeExecutionTime( 1501 nowElapsed - mLastExecutionDurationStampTimeElapsed); 1502 // Use the JobParameters stop reasons for logging and metric purposes, 1503 // but if the job was marked for death, use that reason for rescheduling purposes. 1504 // The discrepancy could happen if a job ends up stopping for some reason 1505 // in the time between the job being marked and the process actually dying. 1506 // Since the job stopped for another reason, we want to log the actual stop reason 1507 // for the sake of accurate metrics and debugging, 1508 // but we should use the death mark reasons when determining reschedule policy. 1509 final int loggingStopReason = mParams.getStopReason(); 1510 final int loggingInternalStopReason = mParams.getInternalStopReasonCode(); 1511 final int reschedulingStopReason, reschedulingInternalStopReason; 1512 if (mDeathMarkStopReason != JobParameters.STOP_REASON_UNDEFINED) { 1513 if (DEBUG) { 1514 Slog.d(TAG, "Job marked for death because of " 1515 + JobParameters.getInternalReasonCodeDescription( 1516 mDeathMarkInternalStopReason) 1517 + ": " + mDeathMarkDebugReason); 1518 } 1519 reschedulingStopReason = mDeathMarkStopReason; 1520 reschedulingInternalStopReason = mDeathMarkInternalStopReason; 1521 } else { 1522 reschedulingStopReason = loggingStopReason; 1523 reschedulingInternalStopReason = loggingInternalStopReason; 1524 } 1525 mPreviousJobHadSuccessfulFinish = 1526 (loggingInternalStopReason == JobParameters.INTERNAL_STOP_REASON_SUCCESSFUL_FINISH); 1527 if (!mPreviousJobHadSuccessfulFinish) { 1528 mLastUnsuccessfulFinishElapsed = nowElapsed; 1529 } 1530 mJobPackageTracker.noteInactive(completedJob, 1531 loggingInternalStopReason, loggingDebugReason); 1532 FrameworkStatsLog.write_non_chained(FrameworkStatsLog.SCHEDULED_JOB_STATE_CHANGED, 1533 completedJob.getSourceUid(), null, completedJob.getBatteryName(), 1534 FrameworkStatsLog.SCHEDULED_JOB_STATE_CHANGED__STATE__FINISHED, 1535 loggingInternalStopReason, completedJob.getStandbyBucket(), 1536 completedJob.getLoggingJobId(), 1537 completedJob.hasChargingConstraint(), 1538 completedJob.hasBatteryNotLowConstraint(), 1539 completedJob.hasStorageNotLowConstraint(), 1540 completedJob.hasTimingDelayConstraint(), 1541 completedJob.hasDeadlineConstraint(), 1542 completedJob.hasIdleConstraint(), 1543 completedJob.hasConnectivityConstraint(), 1544 completedJob.hasContentTriggerConstraint(), 1545 completedJob.isRequestedExpeditedJob(), 1546 completedJob.startedAsExpeditedJob, 1547 loggingStopReason, 1548 completedJob.getJob().isPrefetch(), 1549 completedJob.getJob().getPriority(), 1550 completedJob.getEffectivePriority(), 1551 completedJob.getNumPreviousAttempts(), 1552 completedJob.getJob().getMaxExecutionDelayMillis(), 1553 mParams.isOverrideDeadlineExpired(), 1554 completedJob.isConstraintSatisfied(JobInfo.CONSTRAINT_FLAG_CHARGING), 1555 completedJob.isConstraintSatisfied(JobInfo.CONSTRAINT_FLAG_BATTERY_NOT_LOW), 1556 completedJob.isConstraintSatisfied(JobInfo.CONSTRAINT_FLAG_STORAGE_NOT_LOW), 1557 completedJob.isConstraintSatisfied(JobStatus.CONSTRAINT_TIMING_DELAY), 1558 completedJob.isConstraintSatisfied(JobInfo.CONSTRAINT_FLAG_DEVICE_IDLE), 1559 completedJob.isConstraintSatisfied(JobStatus.CONSTRAINT_CONNECTIVITY), 1560 completedJob.isConstraintSatisfied(JobStatus.CONSTRAINT_CONTENT_TRIGGER), 1561 mExecutionStartTimeElapsed - completedJob.enqueueTime, 1562 completedJob.getJob().isUserInitiated(), 1563 completedJob.startedAsUserInitiatedJob, 1564 completedJob.getJob().isPeriodic(), 1565 completedJob.getJob().getMinLatencyMillis(), 1566 completedJob.getEstimatedNetworkDownloadBytes(), 1567 completedJob.getEstimatedNetworkUploadBytes(), 1568 completedJob.getWorkCount(), 1569 ActivityManager 1570 .processStateAmToProto(mService.getUidProcState(completedJob.getUid())), 1571 completedJob.getNamespaceHash()); 1572 if (Trace.isTagEnabled(Trace.TRACE_TAG_SYSTEM_SERVER)) { 1573 Trace.asyncTraceForTrackEnd(Trace.TRACE_TAG_SYSTEM_SERVER, "JobScheduler", 1574 getId()); 1575 } 1576 try { 1577 mBatteryStats.noteJobFinish(mRunningJob.getBatteryName(), mRunningJob.getSourceUid(), 1578 loggingInternalStopReason); 1579 } catch (RemoteException e) { 1580 // Whatever. 1581 } 1582 if (loggingStopReason == JobParameters.STOP_REASON_TIMEOUT) { 1583 mEconomyManagerInternal.noteInstantaneousEvent( 1584 mRunningJob.getSourceUserId(), mRunningJob.getSourcePackageName(), 1585 JobSchedulerEconomicPolicy.ACTION_JOB_TIMEOUT, 1586 String.valueOf(mRunningJob.getJobId())); 1587 } 1588 mNotificationCoordinator.removeNotificationAssociation(this, 1589 reschedulingStopReason, completedJob); 1590 if (mWakeLock != null) { 1591 mWakeLock.release(); 1592 } 1593 final int workType = mRunningJobWorkType; 1594 mContext.unbindService(JobServiceContext.this); 1595 mWakeLock = null; 1596 mRunningJob = null; 1597 mRunningJobWorkType = WORK_TYPE_NONE; 1598 mRunningCallback = null; 1599 mParams = null; 1600 mVerb = VERB_FINISHED; 1601 mCancelled = false; 1602 service = null; 1603 mAvailable = true; 1604 mDeathMarkStopReason = JobParameters.STOP_REASON_UNDEFINED; 1605 mDeathMarkInternalStopReason = 0; 1606 mDeathMarkDebugReason = null; 1607 mLastExecutionDurationStampTimeElapsed = 0; 1608 mPendingStopReason = JobParameters.STOP_REASON_UNDEFINED; 1609 mPendingInternalStopReason = 0; 1610 mPendingDebugStopReason = null; 1611 mPendingNetworkChange = null; 1612 removeOpTimeOutLocked(); 1613 if (completedJob.isUserVisibleJob()) { 1614 mService.informObserversOfUserVisibleJobChange(this, completedJob, false); 1615 } 1616 mCompletedListener.onJobCompletedLocked(completedJob, 1617 reschedulingStopReason, reschedulingInternalStopReason, reschedule); 1618 mJobConcurrencyManager.onJobCompletedLocked(this, completedJob, workType); 1619 } 1620 applyStoppedReasonLocked(@ullable String reason)1621 private void applyStoppedReasonLocked(@Nullable String reason) { 1622 if (reason != null && mStoppedReason == null) { 1623 mStoppedReason = reason; 1624 mStoppedTime = sElapsedRealtimeClock.millis(); 1625 if (mRunningCallback != null) { 1626 mRunningCallback.mStoppedReason = mStoppedReason; 1627 mRunningCallback.mStoppedTime = mStoppedTime; 1628 } 1629 } 1630 } 1631 1632 /** 1633 * Called when sending a message to the client, over whose execution we have no control. If 1634 * we haven't received a response in a certain amount of time, we want to give up and carry 1635 * on with life. 1636 */ scheduleOpTimeOutLocked()1637 private void scheduleOpTimeOutLocked() { 1638 removeOpTimeOutLocked(); 1639 1640 final long timeoutMillis; 1641 switch (mVerb) { 1642 case VERB_EXECUTING: 1643 long minTimeout; 1644 final long earliestStopTimeElapsed = 1645 mExecutionStartTimeElapsed + mMinExecutionGuaranteeMillis; 1646 final long latestStopTimeElapsed = 1647 mExecutionStartTimeElapsed + mMaxExecutionTimeMillis; 1648 final long nowElapsed = sElapsedRealtimeClock.millis(); 1649 if (nowElapsed < earliestStopTimeElapsed) { 1650 minTimeout = earliestStopTimeElapsed - nowElapsed; 1651 } else { 1652 minTimeout = latestStopTimeElapsed - nowElapsed; 1653 } 1654 if (mAwaitingNotification) { 1655 minTimeout = Math.min(minTimeout, NOTIFICATION_TIMEOUT_MILLIS); 1656 } 1657 minTimeout = Math.min(minTimeout, EXECUTION_DURATION_STAMP_PERIOD_MILLIS); 1658 timeoutMillis = minTimeout; 1659 break; 1660 1661 case VERB_BINDING: 1662 timeoutMillis = OP_BIND_TIMEOUT_MILLIS; 1663 break; 1664 1665 default: 1666 timeoutMillis = OP_TIMEOUT_MILLIS; 1667 break; 1668 } 1669 if (DEBUG) { 1670 Slog.d(TAG, "Scheduling time out for '" + 1671 mRunningJob.getServiceComponent().getShortClassName() + "' jId: " + 1672 mParams.getJobId() + ", in " + (timeoutMillis / 1000) + " s"); 1673 } 1674 Message m = mCallbackHandler.obtainMessage(MSG_TIMEOUT, mRunningCallback); 1675 mCallbackHandler.sendMessageDelayed(m, timeoutMillis); 1676 mTimeoutElapsed = sElapsedRealtimeClock.millis() + timeoutMillis; 1677 } 1678 removeOpTimeOutLocked()1679 private void removeOpTimeOutLocked() { 1680 mCallbackHandler.removeMessages(MSG_TIMEOUT); 1681 } 1682 dumpLocked(IndentingPrintWriter pw, final long nowElapsed)1683 void dumpLocked(IndentingPrintWriter pw, final long nowElapsed) { 1684 if (mRunningJob == null) { 1685 if (mStoppedReason != null) { 1686 pw.print("inactive since "); 1687 TimeUtils.formatDuration(mStoppedTime, nowElapsed, pw); 1688 pw.print(", stopped because: "); 1689 pw.println(mStoppedReason); 1690 } else { 1691 pw.println("inactive"); 1692 } 1693 } else { 1694 pw.println(mRunningJob.toShortString()); 1695 1696 pw.increaseIndent(); 1697 pw.print("Running for: "); 1698 TimeUtils.formatDuration(nowElapsed - mExecutionStartTimeElapsed, pw); 1699 pw.print(", timeout at: "); 1700 TimeUtils.formatDuration(mTimeoutElapsed - nowElapsed, pw); 1701 pw.println(); 1702 pw.print("Remaining execution limits: ["); 1703 TimeUtils.formatDuration( 1704 (mExecutionStartTimeElapsed + mMinExecutionGuaranteeMillis) - nowElapsed, pw); 1705 pw.print(", "); 1706 TimeUtils.formatDuration( 1707 (mExecutionStartTimeElapsed + mMaxExecutionTimeMillis) - nowElapsed, pw); 1708 pw.print("]"); 1709 if (mPendingStopReason != JobParameters.STOP_REASON_UNDEFINED) { 1710 pw.print(" Pending stop because "); 1711 pw.print(mPendingStopReason); 1712 pw.print("/"); 1713 pw.print(mPendingInternalStopReason); 1714 pw.print("/"); 1715 pw.print(mPendingDebugStopReason); 1716 } 1717 pw.println(); 1718 pw.decreaseIndent(); 1719 } 1720 } 1721 } 1722