Persisted jobs versus incorrect boot-time RTC (616541d7) · Commits · e / os / android_frameworks_base

core/java/android/util/AtomicFile.java

+3 −3

Original line number	Diff line number	Diff line
		@@ -214,10 +214,10 @@ public class AtomicFile {
		* Gets the last modified time of the atomic file.
		* {@hide}
		*
		* @return last modified time in milliseconds since epoch.
		* @throws IOException
		* @return last modified time in milliseconds since epoch. Returns zero if
		* the file does not exist or an I/O error is encountered.
		*/
		public long getLastModifiedTime() throws IOException {
		public long getLastModifiedTime() {
		if (mBackupName.exists()) {
		return mBackupName.lastModified();
		}

services/core/java/com/android/server/job/JobSchedulerService.java

+50 −0

Original line number	Diff line number	Diff line
		@@ -76,6 +76,7 @@ import com.android.internal.app.procstats.ProcessStats;
		import com.android.internal.util.ArrayUtils;
		import com.android.internal.util.DumpUtils;
		import com.android.server.DeviceIdleController;
		import com.android.server.FgThread;
		import com.android.server.LocalServices;
		import com.android.server.job.JobStore.JobStatusFunctor;
		import com.android.server.job.controllers.AppIdleController;
		@@ -919,7 +920,56 @@ public final class JobSchedulerService extends com.android.server.SystemService
		mControllers.add(AppIdleController.get(this));
		mControllers.add(ContentObserverController.get(this));
		mControllers.add(DeviceIdleJobsController.get(this));

		// If the job store determined that it can't yet reschedule persisted jobs,
		// we need to start watching the clock.
		if (!mJobs.jobTimesInflatedValid()) {
		Slog.w(TAG, "!!! RTC not yet good; tracking time updates for job scheduling");
		context.registerReceiver(mTimeSetReceiver, new IntentFilter(Intent.ACTION_TIME_CHANGED));
		}
		}

		private final BroadcastReceiver mTimeSetReceiver = new BroadcastReceiver() {
		@Override
		public void onReceive(Context context, Intent intent) {
		if (Intent.ACTION_TIME_CHANGED.equals(intent.getAction())) {
		// When we reach clock sanity, recalculate the temporal windows
		// of all affected jobs.
		if (mJobs.clockNowValidToInflate(System.currentTimeMillis())) {
		Slog.i(TAG, "RTC now valid; recalculating persisted job windows");

		// We've done our job now, so stop watching the time.
		context.unregisterReceiver(this);

		// And kick off the work to update the affected jobs, using a secondary
		// thread instead of chugging away here on the main looper thread.
		FgThread.getHandler().post(mJobTimeUpdater);
		}
		}
		}
		};

		private final Runnable mJobTimeUpdater = () -> {
		final ArrayList<JobStatus> toRemove = new ArrayList<>();
		final ArrayList<JobStatus> toAdd = new ArrayList<>();
		synchronized (mLock) {
		// Note: we intentionally both look up the existing affected jobs and replace them
		// with recalculated ones inside the same lock lifetime.
		getJobStore().getRtcCorrectedJobsLocked(toAdd, toRemove);

		// Now, at each position [i], we have both the existing JobStatus
		// and the one that replaces it.
		final int N = toAdd.size();
		for (int i = 0; i < N; i++) {
		final JobStatus oldJob = toRemove.get(i);
		final JobStatus newJob = toAdd.get(i);
		if (DEBUG) {
		Slog.v(TAG, " replacing " + oldJob + " with " + newJob);
		}
		cancelJobImplLocked(oldJob, newJob, "deferred rtc calculation");
		}
		}
		};

		@Override
		public void onStart() {

services/core/java/com/android/server/job/JobServiceContext.java

+4 −0

Original line number	Diff line number	Diff line
		@@ -219,6 +219,10 @@ public final class JobServiceContext implements ServiceConnection {
		isDeadlineExpired, triggeredUris, triggeredAuthorities);
		mExecutionStartTimeElapsed = SystemClock.elapsedRealtime();

		// 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();

		mVerb = VERB_BINDING;
		scheduleOpTimeOutLocked();
		final Intent intent = new Intent().setComponent(job.getServiceComponent());

services/core/java/com/android/server/job/JobStore.java

+137 −26

Original line number	Diff line number	Diff line
		@@ -72,10 +72,15 @@ public final class JobStore {

		/** Threshold to adjust how often we want to write to the db. */
		private static final int MAX_OPS_BEFORE_WRITE = 1;

		final Object mLock;
		final JobSet mJobSet; // per-caller-uid tracking
		final Context mContext;

		// Bookkeeping around incorrect boot-time system clock
		private final long mXmlTimestamp;
		private boolean mRtcGood;

		private int mDirtyOperations;

		private static final Object sSingletonLock = new Object();
		@@ -120,7 +125,52 @@ public final class JobStore {

		mJobSet = new JobSet();

		readJobMapFromDisk(mJobSet);
		// If the current RTC is earlier than the timestamp on our persisted jobs file,
		// we suspect that the RTC is uninitialized and so we cannot draw conclusions
		// about persisted job scheduling.
		//
		// Note that if the persisted jobs file does not exist, we proceed with the
		// assumption that the RTC is good. This is less work and is safe: if the
		// clock updates to sanity then we'll be saving the persisted jobs file in that
		// correct state, which is normal; or we'll wind up writing the jobs file with
		// an incorrect historical timestamp. That's fine; at worst we'll reboot with
		// a correct timestamp, see a bunch of overdue jobs, and run them; then
		// settle into normal operation.
		mXmlTimestamp = mJobsFile.getLastModifiedTime();
		mRtcGood = (System.currentTimeMillis() > mXmlTimestamp);

		readJobMapFromDisk(mJobSet, mRtcGood);
		}

		public boolean jobTimesInflatedValid() {
		return mRtcGood;
		}

		public boolean clockNowValidToInflate(long now) {
		return now >= mXmlTimestamp;
		}

		/**
		* Find all the jobs that were affected by RTC clock uncertainty at boot time. Returns
		* parallel lists of the existing JobStatus objects and of new, equivalent JobStatus instances
		* with now-corrected time bounds.
		*/
		public void getRtcCorrectedJobsLocked(final ArrayList<JobStatus> toAdd,
		final ArrayList<JobStatus> toRemove) {
		final long elapsedNow = SystemClock.elapsedRealtime();

		// Find the jobs that need to be fixed up, collecting them for post-iteration
		// replacement with their new versions
		forEachJob(job -> {
		final Pair<Long, Long> utcTimes = job.getPersistedUtcTimes();
		if (utcTimes != null) {
		Pair<Long, Long> elapsedRuntimes =
		convertRtcBoundsToElapsed(utcTimes, elapsedNow);
		toAdd.add(new JobStatus(job, elapsedRuntimes.first, elapsedRuntimes.second,
		0, job.getLastSuccessfulRunTime(), job.getLastFailedRunTime()));
		toRemove.add(job);
		}
		});
		}

		/**
		@@ -241,8 +291,6 @@ public final class JobStore {
		/**
		* Every time the state changes we write all the jobs in one swath, instead of trying to
		* track incremental changes.
		* @return Whether the operation was successful. This will only fail for e.g. if the system is
		* low on storage. If this happens, we continue as normal
		*/
		private void maybeWriteStatusToDiskAsync() {
		mDirtyOperations++;
		@@ -250,20 +298,21 @@ public final class JobStore {
		if (DEBUG) {
		Slog.v(TAG, "Writing jobs to disk.");
		}
		mIoHandler.post(new WriteJobsMapToDiskRunnable());
		mIoHandler.removeCallbacks(mWriteRunnable);
		mIoHandler.post(mWriteRunnable);
		}
		}

		@VisibleForTesting
		public void readJobMapFromDisk(JobSet jobSet) {
		new ReadJobMapFromDiskRunnable(jobSet).run();
		public void readJobMapFromDisk(JobSet jobSet, boolean rtcGood) {
		new ReadJobMapFromDiskRunnable(jobSet, rtcGood).run();
		}

		/**
		* Runnable that writes {@link #mJobSet} out to xml.
		* NOTE: This Runnable locks on mLock
		*/
		private final class WriteJobsMapToDiskRunnable implements Runnable {
		private final Runnable mWriteRunnable = new Runnable() {
		@Override
		public void run() {
		final long startElapsed = SystemClock.elapsedRealtime();
		@@ -280,7 +329,7 @@ public final class JobStore {
		});
		}
		writeJobsMapImpl(storeCopy);
		if (JobSchedulerService.DEBUG) {
		if (DEBUG) {
		Slog.v(TAG, "Finished writing, took " + (SystemClock.elapsedRealtime()
		- startElapsed) + "ms");
		}
		@@ -311,7 +360,7 @@ public final class JobStore {
		out.endTag(null, "job-info");
		out.endDocument();

		// Write out to disk in one fell sweep.
		// Write out to disk in one fell swoop.
		FileOutputStream fos = mJobsFile.startWrite();
		fos.write(baos.toByteArray());
		mJobsFile.finishWrite(fos);
		@@ -417,15 +466,27 @@ public final class JobStore {
		out.startTag(null, XML_TAG_ONEOFF);
		}

		// If we still have the persisted times, we need to record those directly because
		// we haven't yet been able to calculate the usual elapsed-timebase bounds
		// correctly due to wall-clock uncertainty.
		Pair <Long, Long> utcJobTimes = jobStatus.getPersistedUtcTimes();
		if (DEBUG && utcJobTimes != null) {
		Slog.i(TAG, "storing original UTC timestamps for " + jobStatus);
		}

		final long nowRTC = System.currentTimeMillis();
		final long nowElapsed = SystemClock.elapsedRealtime();
		if (jobStatus.hasDeadlineConstraint()) {
		// Wall clock deadline.
		final long deadlineWallclock = System.currentTimeMillis() +
		(jobStatus.getLatestRunTimeElapsed() - SystemClock.elapsedRealtime());
		final long deadlineWallclock = (utcJobTimes == null)
		? nowRTC + (jobStatus.getLatestRunTimeElapsed() - nowElapsed)
		: utcJobTimes.second;
		out.attribute(null, "deadline", Long.toString(deadlineWallclock));
		}
		if (jobStatus.hasTimingDelayConstraint()) {
		final long delayWallclock = System.currentTimeMillis() +
		(jobStatus.getEarliestRunTime() - SystemClock.elapsedRealtime());
		final long delayWallclock = (utcJobTimes == null)
		? nowRTC + (jobStatus.getEarliestRunTime() - nowElapsed)
		: utcJobTimes.first;
		out.attribute(null, "delay", Long.toString(delayWallclock));
		}

		@@ -443,6 +504,25 @@ public final class JobStore {
		out.endTag(null, XML_TAG_ONEOFF);
		}
		}
		};

		/**
		* Translate the supplied RTC times to the elapsed timebase, with clamping appropriate
		* to interpreting them as a job's delay + deadline times for alarm-setting purposes.
		* @param rtcTimes a Pair<Long, Long> in which {@code first} is the "delay" earliest
		* allowable runtime for the job, and {@code second} is the "deadline" time at which
		* the job becomes overdue.
		*/
		private static Pair<Long, Long> convertRtcBoundsToElapsed(Pair<Long, Long> rtcTimes,
		long nowElapsed) {
		final long nowWallclock = System.currentTimeMillis();
		final long earliest = (rtcTimes.first > JobStatus.NO_EARLIEST_RUNTIME)
		? nowElapsed + Math.max(rtcTimes.first - nowWallclock, 0)
		: JobStatus.NO_EARLIEST_RUNTIME;
		final long latest = (rtcTimes.second < JobStatus.NO_LATEST_RUNTIME)
		? nowElapsed + Math.max(rtcTimes.second - nowWallclock, 0)
		: JobStatus.NO_LATEST_RUNTIME;
		return Pair.create(earliest, latest);
		}

		/**
		@@ -451,13 +531,15 @@ public final class JobStore {
		*/
		private final class ReadJobMapFromDiskRunnable implements Runnable {
		private final JobSet jobSet;
		private final boolean rtcGood;

		/**
		* @param jobSet Reference to the (empty) set of JobStatus objects that back the JobStore,
		* so that after disk read we can populate it directly.
		*/
		ReadJobMapFromDiskRunnable(JobSet jobSet) {
		ReadJobMapFromDiskRunnable(JobSet jobSet, boolean rtcIsGood) {
		this.jobSet = jobSet;
		this.rtcGood = rtcIsGood;
		}

		@Override
		@@ -466,7 +548,7 @@ public final class JobStore {
		List<JobStatus> jobs;
		FileInputStream fis = mJobsFile.openRead();
		synchronized (mLock) {
		jobs = readJobMapImpl(fis);
		jobs = readJobMapImpl(fis, rtcGood);
		if (jobs != null) {
		long now = SystemClock.elapsedRealtime();
		IActivityManager am = ActivityManager.getService();
		@@ -480,21 +562,21 @@ public final class JobStore {
		}
		fis.close();
		} catch (FileNotFoundException e) {
		if (JobSchedulerService.DEBUG) {
		if (DEBUG) {
		Slog.d(TAG, "Could not find jobs file, probably there was nothing to load.");
		}
		} catch (XmlPullParserException e) {
		if (JobSchedulerService.DEBUG) {
		if (DEBUG) {
		Slog.d(TAG, "Error parsing xml.", e);
		}
		} catch (IOException e) {
		if (JobSchedulerService.DEBUG) {
		if (DEBUG) {
		Slog.d(TAG, "Error parsing xml.", e);
		}
		}
		}

		private List<JobStatus> readJobMapImpl(FileInputStream fis)
		private List<JobStatus> readJobMapImpl(FileInputStream fis, boolean rtcIsGood)
		throws XmlPullParserException, IOException {
		XmlPullParser parser = Xml.newPullParser();
		parser.setInput(fis, StandardCharsets.UTF_8.name());
		@@ -533,7 +615,7 @@ public final class JobStore {
		tagName = parser.getName();
		// Start reading job.
		if ("job".equals(tagName)) {
		JobStatus persistedJob = restoreJobFromXml(parser);
		JobStatus persistedJob = restoreJobFromXml(rtcIsGood, parser);
		if (persistedJob != null) {
		if (DEBUG) {
		Slog.d(TAG, "Read out " + persistedJob);
		@@ -556,8 +638,8 @@ public final class JobStore {
		* will take the parser into the body of the job tag.
		* @return Newly instantiated job holding all the information we just read out of the xml tag.
		*/
		private JobStatus restoreJobFromXml(XmlPullParser parser) throws XmlPullParserException,
		IOException {
		private JobStatus restoreJobFromXml(boolean rtcIsGood, XmlPullParser parser)
		throws XmlPullParserException, IOException {
		JobInfo.Builder jobBuilder;
		int uid, sourceUserId;
		long lastSuccessfulRunTime;
		@@ -621,10 +703,10 @@ public final class JobStore {
		return null;
		}

		// Tuple of (earliest runtime, latest runtime) in elapsed realtime after disk load.
		Pair<Long, Long> elapsedRuntimes;
		// Tuple of (earliest runtime, latest runtime) in UTC.
		final Pair<Long, Long> rtcRuntimes;
		try {
		elapsedRuntimes = buildExecutionTimesFromXml(parser);
		rtcRuntimes = buildRtcExecutionTimesFromXml(parser);
		} catch (NumberFormatException e) {
		if (DEBUG) {
		Slog.d(TAG, "Error parsing execution time parameters, skipping.");
		@@ -633,6 +715,8 @@ public final class JobStore {
		}

		final long elapsedNow = SystemClock.elapsedRealtime();
		Pair<Long, Long> elapsedRuntimes = convertRtcBoundsToElapsed(rtcRuntimes, elapsedNow);

		if (XML_TAG_PERIODIC.equals(parser.getName())) {
		try {
		String val = parser.getAttributeValue(null, "period");
		@@ -722,7 +806,8 @@ public final class JobStore {
		JobStatus js = new JobStatus(
		jobBuilder.build(), uid, sourcePackageName, sourceUserId, sourceTag,
		elapsedRuntimes.first, elapsedRuntimes.second,
		lastSuccessfulRunTime, lastFailedRunTime);
		lastSuccessfulRunTime, lastFailedRunTime,
		(rtcIsGood) ? null : rtcRuntimes);
		return js;
		}

		@@ -777,6 +862,32 @@ public final class JobStore {
		}
		}

		/**
		* Extract a job's earliest/latest run time data from XML. These are returned in
		* unadjusted UTC wall clock time, because we do not yet know whether the system
		* clock is reliable for purposes of calculating deltas from 'now'.
		*
		* @param parser
		* @return A Pair of timestamps in UTC wall-clock time. The first is the earliest
		* time at which the job is to become runnable, and the second is the deadline at
		* which it becomes overdue to execute.
		* @throws NumberFormatException
		*/
		private Pair<Long, Long> buildRtcExecutionTimesFromXml(XmlPullParser parser)
		throws NumberFormatException {
		String val;
		// Pull out execution time data.
		val = parser.getAttributeValue(null, "delay");
		final long earliestRunTimeRtc = (val != null)
		? Long.parseLong(val)
		: JobStatus.NO_EARLIEST_RUNTIME;
		val = parser.getAttributeValue(null, "deadline");
		final long latestRunTimeRtc = (val != null)
		? Long.parseLong(val)
		: JobStatus.NO_LATEST_RUNTIME;
		return Pair.create(earliestRunTimeRtc, latestRunTimeRtc);
		}

		/**
		* Convenience function to read out and convert deadline and delay from xml into elapsed real
		* time.

services/core/java/com/android/server/job/controllers/JobStatus.java

+47 −2

Original line number	Diff line number	Diff line
		@@ -28,10 +28,12 @@ import android.os.SystemClock;
		import android.os.UserHandle;
		import android.text.format.Time;
		import android.util.ArraySet;
		import android.util.Pair;
		import android.util.Slog;
		import android.util.TimeUtils;

		import com.android.server.job.GrantedUriPermissions;
		import com.android.server.job.JobSchedulerService;

		import java.io.PrintWriter;
		import java.util.ArrayList;
		@@ -50,6 +52,7 @@ import java.util.Arrays;
		*/
		public final class JobStatus {
		static final String TAG = "JobSchedulerService";
		static final boolean DEBUG = JobSchedulerService.DEBUG;

		public static final long NO_LATEST_RUNTIME = Long.MAX_VALUE;
		public static final long NO_EARLIEST_RUNTIME = 0L;
		@@ -195,6 +198,18 @@ public final class JobStatus {
		*/
		private long mLastFailedRunTime;

		/**
		* Transient: when a job is inflated from disk before we have a reliable RTC clock time,
		* we retain the canonical (delay, deadline) scheduling tuple read out of the persistent
		* store in UTC so that we can fix up the job's scheduling criteria once we get a good
		* wall-clock time. If we have to persist the job again before the clock has been updated,
		* we record these times again rather than calculating based on the earliest/latest elapsed
		* time base figures.
		*
		* 'first' is the earliest/delay time, and 'second' is the latest/deadline time.
		*/
		private Pair<Long, Long> mPersistedUtcTimes;

		/**
		* For use only by ContentObserverController: state it is maintaining about content URIs
		* being observed.
		@@ -280,13 +295,20 @@ public final class JobStatus {
		mLastFailedRunTime = lastFailedRunTime;
		}

		/** Copy constructor. */
		/** Copy constructor: used specifically when cloning JobStatus objects for persistence,
		* so we preserve RTC window bounds if the source object has them. */
		public JobStatus(JobStatus jobStatus) {
		this(jobStatus.getJob(), jobStatus.getUid(),
		jobStatus.getSourcePackageName(), jobStatus.getSourceUserId(),
		jobStatus.getSourceTag(), jobStatus.getNumFailures(),
		jobStatus.getEarliestRunTime(), jobStatus.getLatestRunTimeElapsed(),
		jobStatus.getLastSuccessfulRunTime(), jobStatus.getLastFailedRunTime());
		mPersistedUtcTimes = jobStatus.mPersistedUtcTimes;
		if (jobStatus.mPersistedUtcTimes != null) {
		if (DEBUG) {
		Slog.i(TAG, "Cloning job with persisted run times", new RuntimeException("here"));
		}
		}
		}

		/**
		@@ -298,10 +320,22 @@ public final class JobStatus {
		*/
		public JobStatus(JobInfo job, int callingUid, String sourcePackageName, int sourceUserId,
		String sourceTag, long earliestRunTimeElapsedMillis, long latestRunTimeElapsedMillis,
		long lastSuccessfulRunTime, long lastFailedRunTime) {
		long lastSuccessfulRunTime, long lastFailedRunTime,
		Pair<Long, Long> persistedExecutionTimesUTC) {
		this(job, callingUid, sourcePackageName, sourceUserId, sourceTag, 0,
		earliestRunTimeElapsedMillis, latestRunTimeElapsedMillis,
		lastSuccessfulRunTime, lastFailedRunTime);

		// Only during initial inflation do we record the UTC-timebase execution bounds
		// read from the persistent store. If we ever have to recreate the JobStatus on
		// the fly, it means we're rescheduling the job; and this means that the calculated
		// elapsed timebase bounds intrinsically become correct.
		this.mPersistedUtcTimes = persistedExecutionTimesUTC;
		if (persistedExecutionTimesUTC != null) {
		if (DEBUG) {
		Slog.i(TAG, "+ restored job with RTC times because of bad boot clock");
		}
		}
		}

		/** Create a new job to be rescheduled with the provided parameters. */
		@@ -612,6 +646,14 @@ public final class JobStatus {
		return latestRunTimeElapsedMillis;
		}

		public Pair<Long, Long> getPersistedUtcTimes() {
		return mPersistedUtcTimes;
		}

		public void clearPersistedUtcTimes() {
		mPersistedUtcTimes = null;
		}

		boolean setChargingConstraintSatisfied(boolean state) {
		return setConstraintSatisfied(CONSTRAINT_CHARGING, state);
		}
		@@ -799,6 +841,9 @@ public final class JobStatus {
		if (job.isRequireDeviceIdle()) {
		sb.append(" IDLE");
		}
		if (job.isPeriodic()) {
		sb.append(" PERIODIC");
		}
		if (job.isPersisted()) {
		sb.append(" PERSISTED");
		}