From 62292daa208d007a8c57b073303e8bb6169a2016 Mon Sep 17 00:00:00 2001
From: Dianne Hackborn <hackbod@google.com>
Date: Mon, 19 Jun 2017 14:24:51 -0700
Subject: [PATCH] Fix issue #62787070: restart due to NPE in
 JobServiceContext...

...handleOpTimeoutLocked

Don't try to print the running job if it is null.

Also, the timeout message should be scheduled with the actually
running job it is for, so we can ignore it if we happen to
dispatch one after the job is over.

Test: bit CtsJobSchedulerTestCases:*

Change-Id: I7bc55f55da645a9e116d3f0ee02f2ee115383ea9
---
 .../android/server/job/JobServiceContext.java | 36 +++++++++++++------
 1 file changed, 26 insertions(+), 10 deletions(-)

diff --git a/services/core/java/com/android/server/job/JobServiceContext.java b/services/core/java/com/android/server/job/JobServiceContext.java
index 5d3f6f7b804b6..107475f36c734 100644
--- a/services/core/java/com/android/server/job/JobServiceContext.java
+++ b/services/core/java/com/android/server/job/JobServiceContext.java
@@ -438,7 +438,21 @@ public final class JobServiceContext implements ServiceConnection {
             switch (message.what) {
                 case MSG_TIMEOUT:
                     synchronized (mLock) {
-                        handleOpTimeoutLocked();
+                        if (message.obj == mRunningCallback) {
+                            handleOpTimeoutLocked();
+                        } else {
+                            JobCallback jc = (JobCallback)message.obj;
+                            StringBuilder sb = new StringBuilder(128);
+                            sb.append("Ignoring timeout of no longer active job");
+                            if (jc.mStoppedReason != null) {
+                                sb.append(", stopped ");
+                                TimeUtils.formatDuration(SystemClock.elapsedRealtime()
+                                        - jc.mStoppedTime, sb);
+                                sb.append(" because: ");
+                                sb.append(jc.mStoppedReason);
+                            }
+                            Slog.w(TAG, sb.toString());
+                        }
                     }
                     break;
                 default:
@@ -621,7 +635,7 @@ public final class JobServiceContext implements ServiceConnection {
     private void handleOpTimeoutLocked() {
         switch (mVerb) {
             case VERB_BINDING:
-                Slog.e(TAG, "Time-out while trying to bind " + mRunningJob.toShortString() +
+                Slog.w(TAG, "Time-out while trying to bind " + mRunningJob.toShortString() +
                         ", dropping.");
                 closeAndCleanupJobLocked(false /* needsReschedule */, "timed out while binding");
                 break;
@@ -629,26 +643,28 @@ public final class JobServiceContext implements ServiceConnection {
                 // Client unresponsive - wedged or failed to respond in time. We don't really
                 // know what happened so let's log it and notify the JobScheduler
                 // FINISHED/NO-RETRY.
-                Slog.e(TAG, "No response from client for onStartJob '" +
-                        mRunningJob.toShortString());
+                Slog.w(TAG, "No response from client for onStartJob " +
+                        mRunningJob != null ? mRunningJob.toShortString() : "<null>");
                 closeAndCleanupJobLocked(false /* needsReschedule */, "timed out while starting");
                 break;
             case VERB_STOPPING:
                 // At least we got somewhere, so fail but ask the JobScheduler to reschedule.
-                Slog.e(TAG, "No response from client for onStopJob, '" +
-                        mRunningJob.toShortString());
+                Slog.w(TAG, "No response from client for onStopJob " +
+                        mRunningJob != null ? mRunningJob.toShortString() : "<null>");
                 closeAndCleanupJobLocked(true /* needsReschedule */, "timed out while stopping");
                 break;
             case VERB_EXECUTING:
                 // Not an error - client ran out of time.
-                Slog.i(TAG, "Client timed out while executing (no jobFinished received)." +
-                        " sending onStop. "  + mRunningJob.toShortString());
+                Slog.i(TAG, "Client timed out while executing (no jobFinished received), " +
+                        "sending onStop: "  +
+                        mRunningJob != null ? mRunningJob.toShortString() : "<null>");
                 mParams.setStopReason(JobParameters.REASON_TIMEOUT);
                 sendStopMessageLocked("timeout while executing");
                 break;
             default:
                 Slog.e(TAG, "Handling timeout for an invalid job state: " +
-                        mRunningJob.toShortString() + ", dropping.");
+                        mRunningJob != null ? mRunningJob.toShortString() : "<null>"
+                        + ", dropping.");
                 closeAndCleanupJobLocked(false /* needsReschedule */, "invalid timeout");
         }
     }
@@ -749,7 +765,7 @@ public final class JobServiceContext implements ServiceConnection {
                     mRunningJob.getServiceComponent().getShortClassName() + "' jId: " +
                     mParams.getJobId() + ", in " + (timeoutMillis / 1000) + " s");
         }
-        Message m = mCallbackHandler.obtainMessage(MSG_TIMEOUT);
+        Message m = mCallbackHandler.obtainMessage(MSG_TIMEOUT, mRunningCallback);
         mCallbackHandler.sendMessageDelayed(m, timeoutMillis);
         mTimeoutElapsed = SystemClock.elapsedRealtime() + timeoutMillis;
     }