DO NOT MERGE Sanity check loaded periodics and cap runtime.

BUG: 24900376
We've seen an issue where periodic run times can be massively
inflated after loading from disk.
As a safeguard, cap the period's loaded runtime to be [p, 2p]
from the time of loading.

Change-Id: Ie4464490c8d6702fee8efe9190c3da5dc5f013f6
(cherry picked from commit fa8e5084ee)
This commit is contained in:
Matthew Williams
2015-10-15 15:59:12 -07:00
parent 5362f273e9
commit 1f0ec16b6d
4 changed files with 78 additions and 11 deletions

View File

@@ -62,7 +62,7 @@ import java.util.concurrent.atomic.AtomicBoolean;
*
*/
public class JobServiceContext extends IJobCallback.Stub implements ServiceConnection {
private static final boolean DEBUG = false;
private static final boolean DEBUG = JobSchedulerService.DEBUG;
private static final String TAG = "JobServiceContext";
/** Define the maximum # of jobs allowed to run on a service at once. */
private static final int defaultMaxActiveJobsPerService =

View File

@@ -24,6 +24,7 @@ import android.os.Handler;
import android.os.PersistableBundle;
import android.os.SystemClock;
import android.os.UserHandle;
import android.text.format.DateUtils;
import android.util.AtomicFile;
import android.util.ArraySet;
import android.util.Pair;
@@ -552,9 +553,10 @@ public class JobStore {
return null;
}
Pair<Long, Long> runtimes;
// Tuple of (earliest runtime, latest runtime) in elapsed realtime after disk load.
Pair<Long, Long> elapsedRuntimes;
try {
runtimes = buildExecutionTimesFromXml(parser);
elapsedRuntimes = buildExecutionTimesFromXml(parser);
} catch (NumberFormatException e) {
if (DEBUG) {
Slog.d(TAG, "Error parsing execution time parameters, skipping.");
@@ -562,22 +564,45 @@ public class JobStore {
return null;
}
final long elapsedNow = SystemClock.elapsedRealtime();
if (XML_TAG_PERIODIC.equals(parser.getName())) {
try {
String val = parser.getAttributeValue(null, "period");
jobBuilder.setPeriodic(Long.valueOf(val));
final long periodMillis = Long.valueOf(val);
jobBuilder.setPeriodic(periodMillis);
// As a sanity check, cap the recreated run time to be no later than 2 periods
// from now. This is the latest the periodic could be pushed out. This could
// happen if the periodic ran early (at the start of its period), and then the
// device rebooted.
if (elapsedRuntimes.second > elapsedNow + 2 * periodMillis) {
final long clampedEarlyRuntimeElapsed = elapsedNow + periodMillis;
final long clampedLateRuntimeElapsed = elapsedNow + 2 * periodMillis;
Slog.w(TAG,
String.format("Periodic job for uid='%d' persisted run-time is" +
" too big [%s, %s]. Clamping to [%s,%s]",
uid,
DateUtils.formatElapsedTime(elapsedRuntimes.first / 1000),
DateUtils.formatElapsedTime(elapsedRuntimes.second / 1000),
DateUtils.formatElapsedTime(
clampedEarlyRuntimeElapsed / 1000),
DateUtils.formatElapsedTime(
clampedLateRuntimeElapsed / 1000))
);
elapsedRuntimes =
Pair.create(clampedEarlyRuntimeElapsed, clampedLateRuntimeElapsed);
}
} catch (NumberFormatException e) {
Slog.d(TAG, "Error reading periodic execution criteria, skipping.");
return null;
}
} else if (XML_TAG_ONEOFF.equals(parser.getName())) {
try {
if (runtimes.first != JobStatus.NO_EARLIEST_RUNTIME) {
jobBuilder.setMinimumLatency(runtimes.first - SystemClock.elapsedRealtime());
if (elapsedRuntimes.first != JobStatus.NO_EARLIEST_RUNTIME) {
jobBuilder.setMinimumLatency(elapsedRuntimes.first - elapsedNow);
}
if (runtimes.second != JobStatus.NO_LATEST_RUNTIME) {
if (elapsedRuntimes.second != JobStatus.NO_LATEST_RUNTIME) {
jobBuilder.setOverrideDeadline(
runtimes.second - SystemClock.elapsedRealtime());
elapsedRuntimes.second - elapsedNow);
}
} catch (NumberFormatException e) {
Slog.d(TAG, "Error reading job execution criteria, skipping.");
@@ -598,7 +623,8 @@ public class JobStore {
do {
eventType = parser.next();
} while (eventType == XmlPullParser.TEXT);
if (!(eventType == XmlPullParser.START_TAG && XML_TAG_EXTRAS.equals(parser.getName()))) {
if (!(eventType == XmlPullParser.START_TAG
&& XML_TAG_EXTRAS.equals(parser.getName()))) {
if (DEBUG) {
Slog.d(TAG, "Error reading extras, skipping.");
}
@@ -609,7 +635,8 @@ public class JobStore {
jobBuilder.setExtras(extras);
parser.nextTag(); // Consume </extras>
return new JobStatus(jobBuilder.build(), uid, runtimes.first, runtimes.second);
return new JobStatus(
jobBuilder.build(), uid, elapsedRuntimes.first, elapsedRuntimes.second);
}
private JobInfo.Builder buildBuilderFromXml(XmlPullParser parser) throws NumberFormatException {

View File

@@ -18,6 +18,7 @@ package com.android.server.job.controllers;
import android.content.Context;
import com.android.server.job.JobSchedulerService;
import com.android.server.job.StateChangedListener;
import java.io.PrintWriter;
@@ -28,7 +29,7 @@ import java.io.PrintWriter;
* are ready to run, or whether they must be stopped.
*/
public abstract class StateController {
protected static final boolean DEBUG = false;
protected static final boolean DEBUG = JobSchedulerService.DEBUG;
protected Context mContext;
protected StateChangedListener mStateChangedListener;
protected boolean mDeviceIdleMode;

View File

@@ -6,6 +6,7 @@ import android.content.Context;
import android.app.job.JobInfo;
import android.app.job.JobInfo.Builder;
import android.os.PersistableBundle;
import android.os.SystemClock;
import android.test.AndroidTestCase;
import android.test.RenamingDelegatingContext;
import android.util.Log;
@@ -102,6 +103,14 @@ public class JobStoreTest extends AndroidTestCase {
Iterator<JobStatus> it = jobStatusSet.iterator();
JobStatus loaded1 = it.next();
JobStatus loaded2 = it.next();
// Reverse them so we know which comparison to make.
if (loaded1.getJobId() != 8) {
JobStatus tmp = loaded1;
loaded1 = loaded2;
loaded2 = tmp;
}
assertTasksEqual(task1, loaded1.getJob());
assertTasksEqual(task2, loaded2.getJob());
assertTrue("JobStore#contains invalid.", mTaskStoreUnderTest.containsJob(taskStatus1));
@@ -143,6 +152,36 @@ public class JobStoreTest extends AndroidTestCase {
assertTasksEqual(task, loaded.getJob());
}
public void testMassivePeriodClampedOnRead() throws Exception {
final long TEN_SECONDS = 10000L;
JobInfo.Builder b = new Builder(8, mComponent)
.setPeriodic(TEN_SECONDS)
.setPersisted(true);
final long invalidLateRuntimeElapsedMillis =
SystemClock.elapsedRealtime() + (TEN_SECONDS * 2) + 5000; // >2P from now.
final long invalidEarlyRuntimeElapsedMillis =
invalidLateRuntimeElapsedMillis - TEN_SECONDS; // Early is (late - period).
final JobStatus js = new JobStatus(b.build(), SOME_UID,
invalidEarlyRuntimeElapsedMillis, invalidLateRuntimeElapsedMillis);
mTaskStoreUnderTest.add(js);
Thread.sleep(IO_WAIT);
final ArraySet<JobStatus> jobStatusSet = new ArraySet<JobStatus>();
mTaskStoreUnderTest.readJobMapFromDisk(jobStatusSet);
assertEquals("Incorrect # of persisted tasks.", 1, jobStatusSet.size());
JobStatus loaded = jobStatusSet.iterator().next();
// Assert early runtime was clamped to be under now + period. We can do <= here b/c we'll
// call SystemClock.elapsedRealtime after doing the disk i/o.
final long newNowElapsed = SystemClock.elapsedRealtime();
assertTrue("Early runtime wasn't correctly clamped.",
loaded.getEarliestRunTime() <= newNowElapsed + TEN_SECONDS);
// Assert late runtime was clamped to be now + period*2.
assertTrue("Early runtime wasn't correctly clamped.",
loaded.getEarliestRunTime() <= newNowElapsed + TEN_SECONDS*2);
}
/**
* Helper function to throw an error if the provided task and TaskStatus objects are not equal.
*/