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