Fix issue #38210653: Few more tweaks of job scheduler

- Now keep track of the time a job was enqueued, and order
  the pending list by that.
- Added configuration constants for rescheduling: maximum
  times to reschedule, minimum backoff times.
- Fixed printing of active jobs -- the method to get the current
  JobStatus was old and didn't require the caller to hold a
  lock, so made a copy, which didn't contain all the data we were
  interested in.  Now with our simple locking, we can just make
  that require the caller hold a lock and return the real
  JobStatus object.
- Include oom_adj and procstate when printing information about
  processes being killed.
- Expanded documentation of BroadcastReceiver.goAsync().

Test: bit CtsJobSchedulerTestCases:*

Change-Id: I2e45f181e45be9836c74cbff1b844ffdf6e93019
diff --git a/core/java/android/app/job/JobInfo.java b/core/java/android/app/job/JobInfo.java
index 007ea88..3cb59f2 100644
--- a/core/java/android/app/job/JobInfo.java
+++ b/core/java/android/app/job/JobInfo.java
@@ -111,8 +111,11 @@
     /* Minimum flex for a periodic job, in milliseconds. */
     private static final long MIN_FLEX_MILLIS = 5 * 60 * 1000L; // 5 minutes
 
-    /* Minimum backoff interval for a job, in milliseconds */
-    private static final long MIN_BACKOFF_MILLIS = 10 * 1000L;      // 10 seconds
+    /**
+     * Minimum backoff interval for a job, in milliseconds
+     * @hide
+     */
+    public static final long MIN_BACKOFF_MILLIS = 10 * 1000L;      // 10 seconds
 
     /**
      * Query the minimum interval allowed for periodic scheduled jobs.  Attempting
@@ -431,7 +434,7 @@
     /**
      * The amount of time the JobScheduler will wait before rescheduling a failed job. This value
      * will be increased depending on the backoff policy specified at job creation time. Defaults
-     * to 5 seconds.
+     * to 30 seconds, minimum is currently 10 seconds.
      */
     public long getInitialBackoffMillis() {
         final long minBackoff = getMinBackoffMillis();
diff --git a/core/java/android/content/BroadcastReceiver.java b/core/java/android/content/BroadcastReceiver.java
index c3d6606..f907721 100644
--- a/core/java/android/content/BroadcastReceiver.java
+++ b/core/java/android/content/BroadcastReceiver.java
@@ -330,10 +330,32 @@
      * This can be called by an application in {@link #onReceive} to allow
      * it to keep the broadcast active after returning from that function.
      * This does <em>not</em> change the expectation of being relatively
-     * responsive to the broadcast (finishing it within 10s), but does allow
+     * responsive to the broadcast, but does allow
      * the implementation to move work related to it over to another thread
      * to avoid glitching the main UI thread due to disk IO.
      *
+     * <p>As a general rule, broadcast receivers are allowed to run for up to 10 seconds
+     * before they system will consider them non-responsive and ANR the app.  Since these usually
+     * execute on the app's main thread, they are already bound by the ~5 second time limit
+     * of various operations that can happen there (not to mention just avoiding UI jank), so
+     * the receive limit is generally not of concern.  However, once you use {@goAsync}, though
+     * able to be off the main thread, the broadcast execution limit still applies, and that
+     * includes the time spent between calling this method and ultimately
+     * {@link PendingResult#finish() PendingResult.finish()}.</p>
+     *
+     * <p>If you are taking advantage of this method to have more time to execute, it is useful
+     * to know that the available time can be longer in certain situations.  In particular, if
+     * the broadcast you are receiving is not a foreground broadcast (that is, the sender has not
+     * used {@link Intent#FLAG_RECEIVER_FOREGROUND}), then more time is allowed for the receivers
+     * to run, allowing them to execute for 30 seconds or even a bit more.  This is something that
+     * receivers should rarely take advantage of (long work should be punted to another system
+     * facility such as {@link android.app.job.JobScheduler}, {@link android.app.Service}, or
+     * see especially {@link android.support.v4.app.JobIntentService}), but can be useful in
+     * certain rare cases where it is necessary to do some work as soon as the broadcast is
+     * delivered.  Keep in mind that the work you do here will block further broadcasts until
+     * it completes, so taking advantage of this at all excessively can be counter-productive
+     * and cause later events to be received more slowly.</p>
+     *
      * @return Returns a {@link PendingResult} representing the result of
      * the active broadcast.  The BroadcastRecord itself is no longer active;
      * all data and other interaction must go through {@link PendingResult}
diff --git a/services/core/java/com/android/server/am/ActivityManagerService.java b/services/core/java/com/android/server/am/ActivityManagerService.java
index ee57952..652a3c4 100644
--- a/services/core/java/com/android/server/am/ActivityManagerService.java
+++ b/services/core/java/com/android/server/am/ActivityManagerService.java
@@ -5376,8 +5376,9 @@
             boolean doLowMem = app.instr == null;
             boolean doOomAdj = doLowMem;
             if (!app.killedByAm) {
-                Slog.i(TAG, "Process " + app.processName + " (pid " + pid
-                        + ") has died");
+                Slog.i(TAG, "Process " + app.processName + " (pid " + pid + ") has died: "
+                        + ProcessList.makeOomAdjString(app.setAdj)
+                        + ProcessList.makeProcStateString(app.setProcState));
                 mAllowLowerMemLevel = true;
             } else {
                 // Note that we always want to do oom adj to update our state with the
@@ -5385,7 +5386,8 @@
                 mAllowLowerMemLevel = false;
                 doLowMem = false;
             }
-            EventLog.writeEvent(EventLogTags.AM_PROC_DIED, app.userId, app.pid, app.processName);
+            EventLog.writeEvent(EventLogTags.AM_PROC_DIED, app.userId, app.pid, app.processName,
+                    app.setAdj, app.setProcState);
             if (DEBUG_CLEANUP) Slog.v(TAG_CLEANUP,
                 "Dying app: " + app + ", pid: " + pid + ", thread: " + thread.asBinder());
             handleAppDiedLocked(app, false, true);
diff --git a/services/core/java/com/android/server/am/EventLogTags.logtags b/services/core/java/com/android/server/am/EventLogTags.logtags
index 372ab6b..b2d3137 100644
--- a/services/core/java/com/android/server/am/EventLogTags.logtags
+++ b/services/core/java/com/android/server/am/EventLogTags.logtags
@@ -34,7 +34,7 @@
 # Application process bound to work
 30010 am_proc_bound (User|1|5),(PID|1|5),(Process Name|3)
 # Application process died
-30011 am_proc_died (User|1|5),(PID|1|5),(Process Name|3)
+30011 am_proc_died (User|1|5),(PID|1|5),(Process Name|3),(OomAdj|1|5),(ProcState|1|5)
 # The Activity Manager failed to pause the given activity.
 30012 am_failed_to_pause (User|1|5),(Token|1|5),(Wanting to pause|3),(Currently pausing|3)
 # Attempting to pause the current activity
diff --git a/services/core/java/com/android/server/job/JobSchedulerService.java b/services/core/java/com/android/server/job/JobSchedulerService.java
index e2c1274..c08f866 100644
--- a/services/core/java/com/android/server/job/JobSchedulerService.java
+++ b/services/core/java/com/android/server/job/JobSchedulerService.java
@@ -218,6 +218,11 @@
         private static final String KEY_BG_MODERATE_JOB_COUNT = "bg_moderate_job_count";
         private static final String KEY_BG_LOW_JOB_COUNT = "bg_low_job_count";
         private static final String KEY_BG_CRITICAL_JOB_COUNT = "bg_critical_job_count";
+        private static final String KEY_MAX_STANDARD_RESCHEDULE_COUNT
+                = "max_standard_reschedule_count";
+        private static final String KEY_MAX_WORK_RESCHEDULE_COUNT = "max_work_reschedule_count";
+        private static final String KEY_MIN_LINEAR_BACKOFF_TIME = "min_linear_backoff_time";
+        private static final String KEY_MIN_EXP_BACKOFF_TIME = "min_exp_backoff_time";
 
         private static final int DEFAULT_MIN_IDLE_COUNT = 1;
         private static final int DEFAULT_MIN_CHARGING_COUNT = 1;
@@ -233,6 +238,10 @@
         private static final int DEFAULT_BG_MODERATE_JOB_COUNT = 4;
         private static final int DEFAULT_BG_LOW_JOB_COUNT = 1;
         private static final int DEFAULT_BG_CRITICAL_JOB_COUNT = 1;
+        private static final int DEFAULT_MAX_STANDARD_RESCHEDULE_COUNT = Integer.MAX_VALUE;
+        private static final int DEFAULT_MAX_WORK_RESCHEDULE_COUNT = Integer.MAX_VALUE;
+        private static final long DEFAULT_MIN_LINEAR_BACKOFF_TIME = JobInfo.MIN_BACKOFF_MILLIS;
+        private static final long DEFAULT_MIN_EXP_BACKOFF_TIME = JobInfo.MIN_BACKOFF_MILLIS;
 
         /**
          * Minimum # of idle jobs that must be ready in order to force the JMS to schedule things
@@ -303,6 +312,24 @@
          * memory state.
          */
         int BG_CRITICAL_JOB_COUNT = DEFAULT_BG_CRITICAL_JOB_COUNT;
+        /**
+         * The maximum number of times we allow a job to have itself rescheduled before
+         * giving up on it, for standard jobs.
+         */
+        int MAX_STANDARD_RESCHEDULE_COUNT = DEFAULT_MAX_STANDARD_RESCHEDULE_COUNT;
+        /**
+         * The maximum number of times we allow a job to have itself rescheduled before
+         * giving up on it, for jobs that are executing work.
+         */
+        int MAX_WORK_RESCHEDULE_COUNT = DEFAULT_MAX_WORK_RESCHEDULE_COUNT;
+        /**
+         * The minimum backoff time to allow for linear backoff.
+         */
+        long MIN_LINEAR_BACKOFF_TIME = DEFAULT_MIN_LINEAR_BACKOFF_TIME;
+        /**
+         * The minimum backoff time to allow for exponential backoff.
+         */
+        long MIN_EXP_BACKOFF_TIME = DEFAULT_MIN_EXP_BACKOFF_TIME;
 
         private ContentResolver mResolver;
         private final KeyValueListParser mParser = new KeyValueListParser(',');
@@ -374,6 +401,14 @@
                 if ((FG_JOB_COUNT+BG_CRITICAL_JOB_COUNT) > MAX_JOB_CONTEXTS_COUNT) {
                     BG_CRITICAL_JOB_COUNT = MAX_JOB_CONTEXTS_COUNT - FG_JOB_COUNT;
                 }
+                MAX_STANDARD_RESCHEDULE_COUNT = mParser.getInt(KEY_MAX_STANDARD_RESCHEDULE_COUNT,
+                        DEFAULT_MAX_STANDARD_RESCHEDULE_COUNT);
+                MAX_WORK_RESCHEDULE_COUNT = mParser.getInt(KEY_MAX_WORK_RESCHEDULE_COUNT,
+                        DEFAULT_MAX_WORK_RESCHEDULE_COUNT);
+                MIN_LINEAR_BACKOFF_TIME = mParser.getLong(KEY_MIN_LINEAR_BACKOFF_TIME,
+                        DEFAULT_MIN_LINEAR_BACKOFF_TIME);
+                MIN_EXP_BACKOFF_TIME = mParser.getLong(KEY_MIN_EXP_BACKOFF_TIME,
+                        DEFAULT_MIN_EXP_BACKOFF_TIME);
             }
         }
 
@@ -421,11 +456,38 @@
 
             pw.print("    "); pw.print(KEY_BG_CRITICAL_JOB_COUNT); pw.print("=");
             pw.print(BG_CRITICAL_JOB_COUNT); pw.println();
+
+            pw.print("    "); pw.print(KEY_MAX_STANDARD_RESCHEDULE_COUNT); pw.print("=");
+            pw.print(MAX_STANDARD_RESCHEDULE_COUNT); pw.println();
+
+            pw.print("    "); pw.print(KEY_MAX_WORK_RESCHEDULE_COUNT); pw.print("=");
+            pw.print(MAX_WORK_RESCHEDULE_COUNT); pw.println();
+
+            pw.print("    "); pw.print(KEY_MIN_LINEAR_BACKOFF_TIME); pw.print("=");
+            pw.print(MIN_LINEAR_BACKOFF_TIME); pw.println();
+
+            pw.print("    "); pw.print(KEY_MIN_EXP_BACKOFF_TIME); pw.print("=");
+            pw.print(MIN_EXP_BACKOFF_TIME); pw.println();
         }
     }
 
     final Constants mConstants;
 
+    static final Comparator<JobStatus> mEnqueueTimeComparator = (o1, o2) -> {
+        if (o1.enqueueTime < o2.enqueueTime) {
+            return -1;
+        }
+        return o1.enqueueTime > o2.enqueueTime ? 1 : 0;
+    };
+
+    static <T> void addOrderedItem(ArrayList<T> array, T newItem, Comparator<T> comparator) {
+        int where = Collections.binarySearch(array, newItem, comparator);
+        if (where < 0) {
+            where = ~where;
+        }
+        array.add(where, newItem);
+    }
+
     /**
      * Cleans up outstanding jobs when a package is removed. Even if it's being replaced later we
      * still clean up. On reinstall the package will have a new uid.
@@ -647,7 +709,7 @@
                 // This is a new job, we can just immediately put it on the pending
                 // list and try to run it.
                 mJobPackageTracker.notePending(jobStatus);
-                mPendingJobs.add(jobStatus);
+                addOrderedItem(mPendingJobs, jobStatus, mEnqueueTimeComparator);
                 maybeRunPendingJobsLocked();
             }
         }
@@ -771,7 +833,7 @@
                 // except those using the idle exemption flag.
                 for (int i=0; i<mActiveServices.size(); i++) {
                     JobServiceContext jsc = mActiveServices.get(i);
-                    final JobStatus executing = jsc.getRunningJob();
+                    final JobStatus executing = jsc.getRunningJobLocked();
                     if (executing != null
                             && (executing.getFlags() & JobInfo.FLAG_WILL_BE_FOREGROUND) == 0) {
                         jsc.cancelExecutingJobLocked(JobParameters.REASON_DEVICE_IDLE);
@@ -798,7 +860,7 @@
         if (mPendingJobs.size() <= 0) {
             for (int i=0; i<mActiveServices.size(); i++) {
                 final JobServiceContext jsc = mActiveServices.get(i);
-                final JobStatus job = jsc.getRunningJob();
+                final JobStatus job = jsc.getRunningJobLocked();
                 if (job != null
                         && (job.getJob().getFlags() & JobInfo.FLAG_WILL_BE_FOREGROUND) == 0
                         && !job.dozeWhitelisted) {
@@ -918,6 +980,7 @@
         if (!jobStatus.isPreparedLocked()) {
             Slog.wtf(TAG, "Not yet prepared when started tracking: " + jobStatus);
         }
+        jobStatus.enqueueTime = SystemClock.elapsedRealtime();
         final boolean update = mJobs.add(jobStatus);
         if (mReadyToRock) {
             for (int i = 0; i < mControllers.size(); i++) {
@@ -953,7 +1016,7 @@
     private boolean stopJobOnServiceContextLocked(JobStatus job, int reason) {
         for (int i=0; i<mActiveServices.size(); i++) {
             JobServiceContext jsc = mActiveServices.get(i);
-            final JobStatus executing = jsc.getRunningJob();
+            final JobStatus executing = jsc.getRunningJobLocked();
             if (executing != null && executing.matches(job.getUid(), job.getJobId())) {
                 jsc.cancelExecutingJobLocked(reason);
                 return true;
@@ -970,11 +1033,7 @@
     private boolean isCurrentlyActiveLocked(JobStatus job) {
         for (int i=0; i<mActiveServices.size(); i++) {
             JobServiceContext serviceContext = mActiveServices.get(i);
-            // The 'unsafe' direct-internal-reference running-job inspector is okay to
-            // use here because we are already holding the necessary lock *and* we
-            // immediately discard the returned object reference, if any; we return
-            // only a boolean state indicator to the caller.
-            final JobStatus running = serviceContext.getRunningJobUnsafeLocked();
+            final JobStatus running = serviceContext.getRunningJobLocked();
             if (running != null && running.matches(job.getUid(), job.getJobId())) {
                 return true;
             }
@@ -1016,18 +1075,38 @@
         final int backoffAttempts = failureToReschedule.getNumFailures() + 1;
         long delayMillis;
 
+        if (failureToReschedule.hasWorkLocked()) {
+            if (backoffAttempts > mConstants.MAX_WORK_RESCHEDULE_COUNT) {
+                Slog.w(TAG, "Not rescheduling " + failureToReschedule + ": attempt #"
+                        + backoffAttempts + " > work limit "
+                        + mConstants.MAX_STANDARD_RESCHEDULE_COUNT);
+                return null;
+            }
+        } else if (backoffAttempts > mConstants.MAX_STANDARD_RESCHEDULE_COUNT) {
+            Slog.w(TAG, "Not rescheduling " + failureToReschedule + ": attempt #"
+                    + backoffAttempts + " > std limit " + mConstants.MAX_STANDARD_RESCHEDULE_COUNT);
+            return null;
+        }
+
         switch (job.getBackoffPolicy()) {
-            case JobInfo.BACKOFF_POLICY_LINEAR:
-                delayMillis = initialBackoffMillis * backoffAttempts;
-                break;
+            case JobInfo.BACKOFF_POLICY_LINEAR: {
+                long backoff = initialBackoffMillis;
+                if (backoff < mConstants.MIN_LINEAR_BACKOFF_TIME) {
+                    backoff = mConstants.MIN_LINEAR_BACKOFF_TIME;
+                }
+                delayMillis = backoff * backoffAttempts;
+            } break;
             default:
                 if (DEBUG) {
                     Slog.v(TAG, "Unrecognised back-off policy, defaulting to exponential.");
                 }
-            case JobInfo.BACKOFF_POLICY_EXPONENTIAL:
-                delayMillis =
-                        (long) Math.scalb(initialBackoffMillis, backoffAttempts - 1);
-                break;
+            case JobInfo.BACKOFF_POLICY_EXPONENTIAL: {
+                long backoff = initialBackoffMillis;
+                if (backoff < mConstants.MIN_EXP_BACKOFF_TIME) {
+                    backoff = mConstants.MIN_EXP_BACKOFF_TIME;
+                }
+                delayMillis = (long) Math.scalb(backoff, backoffAttempts - 1);
+            } break;
         }
         delayMillis =
                 Math.min(delayMillis, JobInfo.MAX_BACKOFF_DELAY_MILLIS);
@@ -1163,7 +1242,7 @@
                         // state is such that all ready jobs should be run immediately.
                         if (runNow != null && isReadyToBeExecutedLocked(runNow)) {
                             mJobPackageTracker.notePending(runNow);
-                            mPendingJobs.add(runNow);
+                            addOrderedItem(mPendingJobs, runNow, mEnqueueTimeComparator);
                         } else {
                             queueReadyJobsForExecutionLocked();
                         }
@@ -1237,6 +1316,9 @@
             if (newReadyJobs != null) {
                 noteJobsPending(newReadyJobs);
                 mPendingJobs.addAll(newReadyJobs);
+                if (mPendingJobs.size() > 1) {
+                    mPendingJobs.sort(mEnqueueTimeComparator);
+                }
             }
             newReadyJobs = null;
         }
@@ -1326,6 +1408,9 @@
                 }
                 noteJobsPending(runnableJobs);
                 mPendingJobs.addAll(runnableJobs);
+                if (mPendingJobs.size() > 1) {
+                    mPendingJobs.sort(mEnqueueTimeComparator);
+                }
             } else {
                 if (DEBUG) {
                     Slog.d(TAG, "maybeQueueReadyJobsForExecutionLocked: Not running anything.");
@@ -1515,7 +1600,7 @@
         int numForeground = 0;
         for (int i=0; i<MAX_JOB_CONTEXTS_COUNT; i++) {
             final JobServiceContext js = mActiveServices.get(i);
-            final JobStatus status = js.getRunningJob();
+            final JobStatus status = js.getRunningJobLocked();
             if ((contextIdToJobMap[i] = status) != null) {
                 numActive++;
                 if (status.lastEvaluatedPriority >= JobInfo.PRIORITY_TOP_APP) {
@@ -1591,10 +1676,10 @@
         for (int i=0; i<MAX_JOB_CONTEXTS_COUNT; i++) {
             boolean preservePreferredUid = false;
             if (act[i]) {
-                JobStatus js = mActiveServices.get(i).getRunningJob();
+                JobStatus js = mActiveServices.get(i).getRunningJobLocked();
                 if (js != null) {
                     if (DEBUG) {
-                        Slog.d(TAG, "preempting job: " + mActiveServices.get(i).getRunningJob());
+                        Slog.d(TAG, "preempting job: " + mActiveServices.get(i).getRunningJobLocked());
                     }
                     // preferredUid will be set to uid of currently running job.
                     mActiveServices.get(i).preemptExecutingJobLocked();
@@ -2099,7 +2184,7 @@
                         continue;
                     }
 
-                    job.dump(pw, "    ", true);
+                    job.dump(pw, "    ", true, now);
                     pw.print("    Ready: ");
                     pw.print(isReadyToBeExecutedLocked(job));
                     pw.print(" (job=");
@@ -2169,22 +2254,22 @@
                 JobStatus job = mPendingJobs.get(i);
                 pw.print("  Pending #"); pw.print(i); pw.print(": ");
                 pw.println(job.toShortString());
-                job.dump(pw, "    ", false);
+                job.dump(pw, "    ", false, now);
                 int priority = evaluateJobPriorityLocked(job);
                 if (priority != JobInfo.PRIORITY_DEFAULT) {
                     pw.print("    Evaluated priority: "); pw.println(priority);
                 }
                 pw.print("    Tag: "); pw.println(job.getTag());
                 pw.print("    Enq: ");
-                TimeUtils.formatDuration(now - job.madePending, pw);
-                pw.println(" ago");
+                TimeUtils.formatDuration(job.madePending - now, pw);
+                pw.println();
             }
             pw.println();
             pw.println("Active jobs:");
             for (int i=0; i<mActiveServices.size(); i++) {
                 JobServiceContext jsc = mActiveServices.get(i);
                 pw.print("  Slot #"); pw.print(i); pw.print(": ");
-                final JobStatus job = jsc.getRunningJob();
+                final JobStatus job = jsc.getRunningJobLocked();
                 if (job == null) {
                     pw.println("inactive");
                     continue;
@@ -2195,13 +2280,14 @@
                     pw.print(", timeout at: ");
                     TimeUtils.formatDuration(jsc.getTimeoutElapsed() - now, pw);
                     pw.println();
-                    job.dump(pw, "    ", false);
-                    int priority = evaluateJobPriorityLocked(jsc.getRunningJob());
+                    job.dump(pw, "    ", false, now);
+                    int priority = evaluateJobPriorityLocked(jsc.getRunningJobLocked());
                     if (priority != JobInfo.PRIORITY_DEFAULT) {
                         pw.print("    Evaluated priority: "); pw.println(priority);
                     }
-                    pw.print("    Active at "); pw.println(job.madeActive);
-                    pw.print("    Pending for ");
+                    pw.print("    Active at ");
+                    TimeUtils.formatDuration(job.madeActive - now, pw);
+                    pw.print(", pending for ");
                     TimeUtils.formatDuration(job.madeActive - job.madePending, pw);
                     pw.println();
                 }
diff --git a/services/core/java/com/android/server/job/JobServiceContext.java b/services/core/java/com/android/server/job/JobServiceContext.java
index bdcf642..ff39baf 100644
--- a/services/core/java/com/android/server/job/JobServiceContext.java
+++ b/services/core/java/com/android/server/job/JobServiceContext.java
@@ -146,7 +146,7 @@
     }
 
     /**
-     * Give a job to this context for execution. Callers must first check {@link #getRunningJob()}
+     * Give a job to this context for execution. Callers must first check {@link #getRunningJobLocked()}
      * and ensure it is null to make sure this is a valid context.
      * @param job The status of the job that we are going to run.
      * @return True if the job is valid and is running. False if the job cannot be executed.
@@ -210,23 +210,8 @@
 
     /**
      * Used externally to query the running job. Will return null if there is no job running.
-     * Be careful when using this function, at any moment it's possible that the job returned may
-     * stop executing.
      */
-    JobStatus getRunningJob() {
-        final JobStatus job;
-        synchronized (mLock) {
-            job = mRunningJob;
-        }
-        return job == null ? null : new JobStatus(job);
-    }
-
-    /**
-     * Internal non-cloning inspection of the currently running job, if any.  The lock
-     * must be held when calling this *and* for the entire lifetime of using its returned
-     * JobStatus object!
-     */
-    JobStatus getRunningJobUnsafeLocked() {
+    JobStatus getRunningJobLocked() {
         return mRunningJob;
     }
 
@@ -256,7 +241,7 @@
     }
 
     boolean timeoutIfExecutingLocked(String pkgName, int userId, boolean matchJobId, int jobId) {
-        final JobStatus executing = getRunningJob();
+        final JobStatus executing = getRunningJobLocked();
         if (executing != null && (userId == UserHandle.USER_ALL || userId == executing.getUserId())
                 && (pkgName == null || pkgName.equals(executing.getSourcePackageName()))
                 && (!matchJobId || jobId == executing.getJobId())) {
diff --git a/services/core/java/com/android/server/job/JobStore.java b/services/core/java/com/android/server/job/JobStore.java
index 2e6cd3f..e7ece2c 100644
--- a/services/core/java/com/android/server/job/JobStore.java
+++ b/services/core/java/com/android/server/job/JobStore.java
@@ -454,10 +454,12 @@
                 synchronized (mLock) {
                     jobs = readJobMapImpl(fis);
                     if (jobs != null) {
+                        long now = SystemClock.elapsedRealtime();
                         IActivityManager am = ActivityManager.getService();
                         for (int i=0; i<jobs.size(); i++) {
                             JobStatus js = jobs.get(i);
                             js.prepareLocked(am);
+                            js.enqueueTime = now;
                             this.jobSet.add(js);
                         }
                     }
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 4d507d6..53bf402 100644
--- a/services/core/java/com/android/server/job/controllers/JobStatus.java
+++ b/services/core/java/com/android/server/job/controllers/JobStatus.java
@@ -22,14 +22,10 @@
 import android.app.job.JobWorkItem;
 import android.content.ClipData;
 import android.content.ComponentName;
-import android.content.ContentProvider;
-import android.content.Intent;
 import android.net.Uri;
-import android.os.Binder;
 import android.os.RemoteException;
 import android.os.SystemClock;
 import android.os.UserHandle;
-import android.text.format.DateUtils;
 import android.util.ArraySet;
 import android.util.Slog;
 import android.util.TimeUtils;
@@ -180,7 +176,10 @@
     // Used by shell commands
     public int overrideState = 0;
 
-    // Metrics about queue latency
+    // When this job was enqueued, for ordering.  (in elapsedRealtimeMillis)
+    public long enqueueTime;
+
+    // Metrics about queue latency.  (in uptimeMillis)
     public long madePending;
     public long madeActive;
 
@@ -349,6 +348,10 @@
         return null;
     }
 
+    public boolean hasWorkLocked() {
+        return (pendingWork != null && pendingWork.size() > 0) || hasExecutingWorkLocked();
+    }
+
     public boolean hasExecutingWorkLocked() {
         return executingWork != null && executingWork.size() > 0;
     }
@@ -744,10 +747,11 @@
         sb.append(getSourceUid());
         if (earliestRunTimeElapsedMillis != NO_EARLIEST_RUNTIME
                 || latestRunTimeElapsedMillis != NO_LATEST_RUNTIME) {
+            long now = SystemClock.elapsedRealtime();
             sb.append(" TIME=");
-            sb.append(formatRunTime(earliestRunTimeElapsedMillis, NO_EARLIEST_RUNTIME));
-            sb.append("-");
-            sb.append(formatRunTime(latestRunTimeElapsedMillis, NO_EARLIEST_RUNTIME));
+            formatRunTime(sb, earliestRunTimeElapsedMillis, NO_EARLIEST_RUNTIME, now);
+            sb.append(":");
+            formatRunTime(sb, latestRunTimeElapsedMillis, NO_LATEST_RUNTIME, now);
         }
         if (job.getNetworkType() != JobInfo.NETWORK_TYPE_NONE) {
             sb.append(" NET=");
@@ -789,17 +793,19 @@
         return sb.toString();
     }
 
-    private String formatRunTime(long runtime, long  defaultValue) {
+    private void formatRunTime(PrintWriter pw, long runtime, long  defaultValue, long now) {
         if (runtime == defaultValue) {
-            return "none";
+            pw.print("none");
         } else {
-            long elapsedNow = SystemClock.elapsedRealtime();
-            long nextRuntime = runtime - elapsedNow;
-            if (nextRuntime > 0) {
-                return DateUtils.formatElapsedTime(nextRuntime / 1000);
-            } else {
-                return "-" + DateUtils.formatElapsedTime(nextRuntime / -1000);
-            }
+            TimeUtils.formatDuration(runtime - now, pw);
+        }
+    }
+
+    private void formatRunTime(StringBuilder sb, long runtime, long  defaultValue, long now) {
+        if (runtime == defaultValue) {
+            sb.append("none");
+        } else {
+            TimeUtils.formatDuration(runtime - now, sb);
         }
     }
 
@@ -881,7 +887,7 @@
     }
 
     // Dumpsys infrastructure
-    public void dump(PrintWriter pw, String prefix, boolean full) {
+    public void dump(PrintWriter pw, String prefix, boolean full, long elapsedRealtimeMillis) {
         pw.print(prefix); UserHandle.formatUid(pw, callingUid);
         pw.print(" tag="); pw.println(tag);
         pw.print(prefix);
@@ -1020,10 +1026,14 @@
                 dumpJobWorkItem(pw, prefix, executingWork.get(i), i);
             }
         }
-        pw.print(prefix); pw.print("Earliest run time: ");
-        pw.println(formatRunTime(earliestRunTimeElapsedMillis, NO_EARLIEST_RUNTIME));
-        pw.print(prefix); pw.print("Latest run time: ");
-        pw.println(formatRunTime(latestRunTimeElapsedMillis, NO_LATEST_RUNTIME));
+        pw.print(prefix); pw.print("Enqueue time: ");
+        TimeUtils.formatDuration(enqueueTime, elapsedRealtimeMillis, pw);
+        pw.println();
+        pw.print(prefix); pw.print("Run time: earliest=");
+        formatRunTime(pw, earliestRunTimeElapsedMillis, NO_EARLIEST_RUNTIME, elapsedRealtimeMillis);
+        pw.print(", latest=");
+        formatRunTime(pw, latestRunTimeElapsedMillis, NO_LATEST_RUNTIME, elapsedRealtimeMillis);
+        pw.println();
         if (numFailures != 0) {
             pw.print(prefix); pw.print("Num failures: "); pw.println(numFailures);
         }