Correct job base heartbeat calculation
The "how many buckets ago did we last run" calculation was wrong, in a
way that was too aggressive about throttling execution. We no longer
use a per-job base runnability milestone; instead, the app as a whole
experiences runnability intervals every so often based on its standby
state.
We also now specifically allow for newly-scheduled jobs within the app's
standby-defined execution slot to run within that slot, rather than
having to wait for the next one.
A small stats bug has been fixed in the job-start code: we would
previously log a job start event in battery stats even when the intended
job turned out to be unlaunchable.
Finally, there's a new 'heartbeat' shell command that allows a tester
to read or advance the standby heartbeat.
Change-Id: Icf03f82e2fde7408095f6d06642d944c3ae10a26
Fixes: 72713333
Test: atest CtsJobSchedulerTestCases
diff --git a/services/core/java/com/android/server/job/JobSchedulerService.java b/services/core/java/com/android/server/job/JobSchedulerService.java
index be48f69..c33d7f4 100644
--- a/services/core/java/com/android/server/job/JobSchedulerService.java
+++ b/services/core/java/com/android/server/job/JobSchedulerService.java
@@ -23,6 +23,7 @@
import android.app.Activity;
import android.app.ActivityManager;
import android.app.ActivityManagerInternal;
+import android.app.AlarmManager;
import android.app.AppGlobals;
import android.app.IUidObserver;
import android.app.job.IJobScheduler;
@@ -184,6 +185,7 @@
IBatteryStats mBatteryStats;
DeviceIdleController.LocalService mLocalDeviceIdleController;
AppStateTracker mAppStateTracker;
+ final UsageStatsManagerInternal mUsageStats;
/**
* Set to true once we are allowed to run third party apps.
@@ -225,7 +227,10 @@
*/
final long[] mNextBucketHeartbeat = { 0, 0, 0, 0, Long.MAX_VALUE };
long mHeartbeat = 0;
- long mLastHeartbeatTime = 0;
+ long mLastHeartbeatTime = sElapsedRealtimeClock.millis();
+
+ static final String HEARTBEAT_TAG = "*job.heartbeat*";
+ final HeartbeatAlarmListener mHeartbeatAlarm = new HeartbeatAlarmListener();
// -- Pre-allocated temporaries only for use in assignJobsToContextsLocked --
@@ -495,6 +500,9 @@
STANDBY_BEATS[3] = mParser.getInt(KEY_STANDBY_RARE_BEATS,
DEFAULT_STANDBY_RARE_BEATS);
}
+
+ // Reset the heartbeat alarm based on the new heartbeat duration
+ setNextHeartbeatAlarm();
}
void dump(PrintWriter pw) {
@@ -1090,9 +1098,9 @@
mJobSchedulerStub = new JobSchedulerStub();
// Set up the app standby bucketing tracker
- UsageStatsManagerInternal usageStats = LocalServices.getService(UsageStatsManagerInternal.class);
- mStandbyTracker = new StandbyTracker(usageStats);
- usageStats.addAppIdleStateChangeListener(mStandbyTracker);
+ mStandbyTracker = new StandbyTracker();
+ mUsageStats = LocalServices.getService(UsageStatsManagerInternal.class);
+ mUsageStats.addAppIdleStateChangeListener(mStandbyTracker);
// The job store needs to call back
publishLocalService(JobSchedulerInternal.class, new LocalService());
@@ -1177,6 +1185,7 @@
mAppStateTracker = Preconditions.checkNotNull(
LocalServices.getService(AppStateTracker.class));
+ setNextHeartbeatAlarm();
// Register br for package removals and user removals.
final IntentFilter filter = new IntentFilter();
@@ -1418,6 +1427,23 @@
periodicToReschedule.getLastFailedRunTime());
}
+ long heartbeatWhenJobsLastRun(String packageName, final @UserIdInt int userId) {
+ final long heartbeat;
+ final long timeSinceLastJob = mUsageStats.getTimeSinceLastJobRun(packageName, userId);
+ synchronized (mLock) {
+ heartbeat = mHeartbeat - (timeSinceLastJob / mConstants.STANDBY_HEARTBEAT_TIME);
+ }
+ if (DEBUG_STANDBY) {
+ Slog.v(TAG, "Last job heartbeat " + heartbeat + " for " + packageName + "/" + userId
+ + " delta=" + timeSinceLastJob);
+ }
+ return heartbeat;
+ }
+
+ long heartbeatWhenJobsLastRun(JobStatus job) {
+ return heartbeatWhenJobsLastRun(job.getSourcePackageName(), job.getSourceUserId());
+ }
+
// JobCompletedListener implementations.
/**
@@ -1560,9 +1586,7 @@
noteJobsNonpending(mPendingJobs);
mPendingJobs.clear();
stopNonReadyActiveJobsLocked();
- boolean updated = updateStandbyHeartbeatLocked();
mJobs.forEachJob(mReadyQueueFunctor);
- if (updated) updateNextStandbyHeartbeatsLocked();
mReadyQueueFunctor.postProcess();
if (DEBUG) {
@@ -1716,36 +1740,78 @@
noteJobsNonpending(mPendingJobs);
mPendingJobs.clear();
stopNonReadyActiveJobsLocked();
- boolean updated = updateStandbyHeartbeatLocked();
mJobs.forEachJob(mMaybeQueueFunctor);
- if (updated) updateNextStandbyHeartbeatsLocked();
mMaybeQueueFunctor.postProcess();
}
- private boolean updateStandbyHeartbeatLocked() {
- final long sinceLast = sElapsedRealtimeClock.millis() - mLastHeartbeatTime;
- final long beatsElapsed = sinceLast / mConstants.STANDBY_HEARTBEAT_TIME;
- if (beatsElapsed > 0) {
- mHeartbeat += beatsElapsed;
- mLastHeartbeatTime += beatsElapsed * mConstants.STANDBY_HEARTBEAT_TIME;
- if (DEBUG_STANDBY) {
- Slog.v(TAG, "Advancing standby heartbeat by " + beatsElapsed + " to " + mHeartbeat);
+ /**
+ * Heartbeat tracking. The heartbeat alarm is intentionally non-wakeup.
+ */
+ class HeartbeatAlarmListener implements AlarmManager.OnAlarmListener {
+
+ @Override
+ public void onAlarm() {
+ synchronized (mLock) {
+ final long sinceLast = sElapsedRealtimeClock.millis() - mLastHeartbeatTime;
+ final long beatsElapsed = sinceLast / mConstants.STANDBY_HEARTBEAT_TIME;
+ if (beatsElapsed > 0) {
+ mLastHeartbeatTime += beatsElapsed * mConstants.STANDBY_HEARTBEAT_TIME;
+ advanceHeartbeatLocked(beatsElapsed);
+ }
}
- return true;
+ setNextHeartbeatAlarm();
}
- return false;
}
- private void updateNextStandbyHeartbeatsLocked() {
- // don't update ACTIVE or NEVER bucket milestones
+ // Intentionally does not touch the alarm timing
+ void advanceHeartbeatLocked(long beatsElapsed) {
+ mHeartbeat += beatsElapsed;
+ if (DEBUG_STANDBY) {
+ Slog.v(TAG, "Advancing standby heartbeat by " + beatsElapsed
+ + " to " + mHeartbeat);
+ }
+ // Don't update ACTIVE or NEVER bucket milestones. Note that mHeartbeat
+ // will be equal to mNextBucketHeartbeat[bucket] for one beat, during which
+ // new jobs scheduled by apps in that bucket will be permitted to run
+ // immediately.
+ boolean didAdvanceBucket = false;
for (int i = 1; i < mNextBucketHeartbeat.length - 1; i++) {
- while (mHeartbeat >= mNextBucketHeartbeat[i]) {
+ // Did we reach or cross a bucket boundary?
+ if (mHeartbeat >= mNextBucketHeartbeat[i]) {
+ didAdvanceBucket = true;
+ }
+ while (mHeartbeat > mNextBucketHeartbeat[i]) {
mNextBucketHeartbeat[i] += mConstants.STANDBY_BEATS[i];
}
if (DEBUG_STANDBY) {
- Slog.v(TAG, " Bucket " + i + " next heartbeat " + mNextBucketHeartbeat[i]);
+ Slog.v(TAG, " Bucket " + i + " next heartbeat "
+ + mNextBucketHeartbeat[i]);
}
}
+
+ if (didAdvanceBucket) {
+ if (DEBUG_STANDBY) {
+ Slog.v(TAG, "Hit bucket boundary; reevaluating job runnability");
+ }
+ mHandler.obtainMessage(MSG_CHECK_JOB).sendToTarget();
+ }
+ }
+
+ void setNextHeartbeatAlarm() {
+ final long heartbeatLength;
+ synchronized (mLock) {
+ heartbeatLength = mConstants.STANDBY_HEARTBEAT_TIME;
+ }
+ final long now = sElapsedRealtimeClock.millis();
+ final long nextBeatOrdinal = (now + heartbeatLength) / heartbeatLength;
+ final long nextHeartbeat = nextBeatOrdinal * heartbeatLength;
+ if (DEBUG_STANDBY) {
+ Slog.i(TAG, "Setting heartbeat alarm for " + nextHeartbeat
+ + " = " + TimeUtils.formatDuration(nextHeartbeat - now));
+ }
+ AlarmManager am = (AlarmManager) getContext().getSystemService(Context.ALARM_SERVICE);
+ am.setExact(AlarmManager.ELAPSED_REALTIME, nextHeartbeat,
+ HEARTBEAT_TAG, mHeartbeatAlarm, mHandler);
}
/**
@@ -1811,17 +1877,20 @@
if (!mInParole && !job.getJob().isExemptedFromAppStandby()) {
final int bucket = job.getStandbyBucket();
if (mHeartbeat < mNextBucketHeartbeat[bucket]) {
- // Only skip this job if it's still waiting for the end of its (initial) nominal
+ // Only skip this job if the app is still waiting for the end of its nominal
// bucket interval. Once it's waited that long, we let it go ahead and clear.
// The final (NEVER) bucket is special; we never age those apps' jobs into
// runnability.
+ final long appLastRan = heartbeatWhenJobsLastRun(job);
if (bucket >= mConstants.STANDBY_BEATS.length
- || (mHeartbeat < job.getBaseHeartbeat() + mConstants.STANDBY_BEATS[bucket])) {
+ || (mHeartbeat > appLastRan
+ && mHeartbeat < appLastRan + mConstants.STANDBY_BEATS[bucket])) {
// TODO: log/trace that we're deferring the job due to bucketing if we hit this
if (job.getWhenStandbyDeferred() == 0) {
if (DEBUG_STANDBY) {
Slog.v(TAG, "Bucket deferral: " + mHeartbeat + " < "
- + mNextBucketHeartbeat[job.getStandbyBucket()] + " for " + job);
+ + (appLastRan + mConstants.STANDBY_BEATS[bucket])
+ + " for " + job);
}
job.setWhenStandbyDeferred(sElapsedRealtimeClock.millis());
}
@@ -2078,18 +2147,19 @@
// ACTIVE => everything can be run right away
// NEVER => we won't run them anyway, so let them go in the future
// as soon as the app enters normal use
+ if (DEBUG_STANDBY) {
+ Slog.v(TAG, "Base heartbeat forced ZERO for new job in "
+ + packageName + "/" + userId);
+ }
return 0;
}
- final long timeSinceLastJob = mStandbyTracker.getTimeSinceLastJobRun(
- packageName, userId);
- final long bucketLength = mConstants.STANDBY_BEATS[appStandbyBucket];
- final long bucketsAgo = timeSinceLastJob / bucketLength;
-
- // If we haven't run any jobs for more than the app's current bucket period, just
- // consider anything new to be immediately runnable. Otherwise, base it on the
- // bucket at which we last ran jobs.
- return (bucketsAgo > bucketLength) ? 0 : (getCurrentHeartbeat() - bucketsAgo);
+ final long baseHeartbeat = heartbeatWhenJobsLastRun(packageName, userId);
+ if (DEBUG_STANDBY) {
+ Slog.v(TAG, "Base heartbeat " + baseHeartbeat + " for new job in "
+ + packageName + "/" + userId);
+ }
+ return baseHeartbeat;
}
/**
@@ -2166,15 +2236,6 @@
* Tracking of app assignments to standby buckets
*/
final class StandbyTracker extends AppIdleStateChangeListener {
- final UsageStatsManagerInternal mUsageStats;
-
- StandbyTracker(UsageStatsManagerInternal usageStats) {
- mUsageStats = usageStats;
- }
-
- public long getTimeSinceLastJobRun(String packageName, final @UserIdInt int userId) {
- return mUsageStats.getTimeSinceLastJobRun(packageName, userId);
- }
// AppIdleStateChangeListener interface for live updates
@@ -2256,6 +2317,7 @@
else return 0;
}
+ // Static to support external callers
public static int standbyBucketForPackage(String packageName, int userId, long elapsedNow) {
UsageStatsManagerInternal usageStats = LocalServices.getService(
UsageStatsManagerInternal.class);
@@ -2682,6 +2744,7 @@
}
}
+ // Shell command infrastructure
int getJobState(PrintWriter pw, String pkgName, int userId, int jobId) {
try {
final int uid = AppGlobals.getPackageManager().getPackageUid(pkgName, 0,
@@ -2759,6 +2822,21 @@
return 0;
}
+ // Shell command infrastructure
+ int executeHeartbeatCommand(PrintWriter pw, int numBeats) {
+ if (numBeats < 1) {
+ pw.println(getCurrentHeartbeat());
+ return 0;
+ }
+
+ pw.print("Advancing standby heartbeat by ");
+ pw.println(numBeats);
+ synchronized (mLock) {
+ advanceHeartbeatLocked(numBeats);
+ }
+ return 0;
+ }
+
private String printContextIdToJobMap(JobStatus[] map, String initial) {
StringBuilder s = new StringBuilder(initial + ": ");
for (int i=0; i<map.length; i++) {
diff --git a/services/core/java/com/android/server/job/JobSchedulerShellCommand.java b/services/core/java/com/android/server/job/JobSchedulerShellCommand.java
index d630aab..63225f3 100644
--- a/services/core/java/com/android/server/job/JobSchedulerShellCommand.java
+++ b/services/core/java/com/android/server/job/JobSchedulerShellCommand.java
@@ -64,6 +64,8 @@
return getStorageNotLow(pw);
case "get-job-state":
return getJobState(pw);
+ case "heartbeat":
+ return doHeartbeat(pw);
default:
return handleDefaultCommands(cmd);
}
@@ -333,6 +335,20 @@
}
}
+ private int doHeartbeat(PrintWriter pw) throws Exception {
+ checkPermission("manipulate scheduler heartbeat");
+
+ final String arg = getNextArg();
+ final int numBeats = (arg != null) ? Integer.parseInt(arg) : 0;
+
+ final long ident = Binder.clearCallingIdentity();
+ try {
+ return mInternal.executeHeartbeatCommand(pw, numBeats);
+ } finally {
+ Binder.restoreCallingIdentity(ident);
+ }
+ }
+
@Override
public void onHelp() {
final PrintWriter pw = getOutPrintWriter();
@@ -359,6 +375,9 @@
pw.println(" Options:");
pw.println(" -u or --user: specify which user's job is to be run; the default is");
pw.println(" the primary or system user");
+ pw.println(" heartbeat [num]");
+ pw.println(" With no argument, prints the current standby heartbeat. With a positive");
+ pw.println(" argument, advances the standby heartbeat by that number.");
pw.println(" monitor-battery [on|off]");
pw.println(" Control monitoring of all battery changes. Off by default. Turning");
pw.println(" on makes get-battery-seq useful.");
diff --git a/services/core/java/com/android/server/job/JobServiceContext.java b/services/core/java/com/android/server/job/JobServiceContext.java
index 4988974..1f8cf76 100644
--- a/services/core/java/com/android/server/job/JobServiceContext.java
+++ b/services/core/java/com/android/server/job/JobServiceContext.java
@@ -240,11 +240,6 @@
}
}
- UsageStatsManagerInternal usageStats =
- LocalServices.getService(UsageStatsManagerInternal.class);
- usageStats.setLastJobRunTime(job.getSourcePackageName(), job.getSourceUserId(),
- mExecutionStartTimeElapsed);
-
// Once we'e begun executing a job, we by definition no longer care whether
// it was inflated from disk with not-yet-coherent delay/deadline bounds.
job.clearPersistedUtcTimes();
@@ -267,12 +262,16 @@
removeOpTimeOutLocked();
return false;
}
+ mJobPackageTracker.noteActive(job);
try {
mBatteryStats.noteJobStart(job.getBatteryName(), job.getSourceUid());
} catch (RemoteException e) {
// Whatever.
}
- mJobPackageTracker.noteActive(job);
+ UsageStatsManagerInternal usageStats =
+ LocalServices.getService(UsageStatsManagerInternal.class);
+ usageStats.setLastJobRunTime(job.getSourcePackageName(), job.getSourceUserId(),
+ mExecutionStartTimeElapsed);
mAvailable = false;
mStoppedReason = null;
mStoppedTime = 0;
diff --git a/services/core/java/com/android/server/job/controllers/JobStatus.java b/services/core/java/com/android/server/job/controllers/JobStatus.java
index 08ff7bd..3867306 100644
--- a/services/core/java/com/android/server/job/controllers/JobStatus.java
+++ b/services/core/java/com/android/server/job/controllers/JobStatus.java
@@ -1346,6 +1346,15 @@
}
pw.print(prefix); pw.print("Standby bucket: ");
pw.println(bucketName(standbyBucket));
+ if (standbyBucket > 0) {
+ pw.print(prefix); pw.print("Base heartbeat: ");
+ pw.println(baseHeartbeat);
+ }
+ if (whenStandbyDeferred != 0) {
+ pw.print(prefix); pw.print(" Deferred since: ");
+ TimeUtils.formatDuration(whenStandbyDeferred, elapsedRealtimeMillis, pw);
+ pw.println();
+ }
pw.print(prefix); pw.print("Enqueue time: ");
TimeUtils.formatDuration(enqueueTime, elapsedRealtimeMillis, pw);
pw.println();