Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 729a328a authored by Dianne Hackborn's avatar Dianne Hackborn
Browse files

Work on issue #62390590: SecurityException in JobIntentService$... 

...JobServiceEngineImpl$WrapperWorkItem.complete

Add more useful information in the security exception message that
is shown -- the reason the last job that was running on the context
was stopped.  This should tell you why when you are calling at that
point your job is no longer running.

Test: bit CtsJobSchedulerTestCases:*

Change-Id: Ia7155248b4b4f032cbf8e8754c5437f658ed192c
parent f574869c

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

+29 −19
Original line number Diff line number Diff line
@@ -524,7 +524,7 @@ public final class JobSchedulerService extends com.android.server.SystemService 
                                            Slog.d(TAG, "Removing jobs for package " + pkgName

                                                    + " in user " + userId);

                                        }

                                        cancelJobsForUid(pkgUid);

                                        cancelJobsForUid(pkgUid, "app package state changed");

                                    }

                                } catch (RemoteException|IllegalArgumentException e) {

                                    /*
@@ -553,7 +553,7 @@ public final class JobSchedulerService extends com.android.server.SystemService 
                    if (DEBUG) {

                        Slog.d(TAG, "Removing jobs for uid: " + uidRemoved);

                    }

                    cancelJobsForUid(uidRemoved);

                    cancelJobsForUid(uidRemoved, "app uninstalled");

                }

            } else if (Intent.ACTION_USER_REMOVED.equals(action)) {

                final int userId = intent.getIntExtra(Intent.EXTRA_USER_HANDLE, 0);
@@ -611,7 +611,7 @@ public final class JobSchedulerService extends com.android.server.SystemService 
        @Override public void onUidGone(int uid, boolean disabled) throws RemoteException {

            updateUidState(uid, ActivityManager.PROCESS_STATE_CACHED_EMPTY);

            if (disabled) {

                cancelJobsForUid(uid);

                cancelJobsForUid(uid, "uid gone");

            }

        }
@@ -620,7 +620,7 @@ public final class JobSchedulerService extends com.android.server.SystemService 


        @Override public void onUidIdle(int uid, boolean disabled) throws RemoteException {

            if (disabled) {

                cancelJobsForUid(uid);

                cancelJobsForUid(uid, "app uid idle");

            }

        }

    };
@@ -689,7 +689,7 @@ public final class JobSchedulerService extends com.android.server.SystemService 
            jobStatus.prepareLocked(ActivityManager.getService());



            if (toCancel != null) {

                cancelJobImplLocked(toCancel, jobStatus);

                cancelJobImplLocked(toCancel, jobStatus, "job rescheduled by app");

            }

            if (work != null) {

                // If work has been supplied, enqueue it into the new job.
@@ -747,7 +747,7 @@ public final class JobSchedulerService extends com.android.server.SystemService 
            final List<JobStatus> jobsForUser = mJobs.getJobsByUser(userHandle);

            for (int i=0; i<jobsForUser.size(); i++) {

                JobStatus toRemove = jobsForUser.get(i);

                cancelJobImplLocked(toRemove, null);

                cancelJobImplLocked(toRemove, null, "user removed");

            }

        }

    }
@@ -765,7 +765,7 @@ public final class JobSchedulerService extends com.android.server.SystemService 
            for (int i = jobsForUid.size() - 1; i >= 0; i--) {

                final JobStatus job = jobsForUid.get(i);

                if (job.getSourcePackageName().equals(pkgName)) {

                    cancelJobImplLocked(job, null);

                    cancelJobImplLocked(job, null, "app force stopped");

                }

            }

        }
@@ -778,12 +778,12 @@ public final class JobSchedulerService extends com.android.server.SystemService 
     * @param uid Uid to check against for removal of a job.

     *

     */

    public void cancelJobsForUid(int uid) {

    public void cancelJobsForUid(int uid, String reason) {

        synchronized (mLock) {

            final List<JobStatus> jobsForUid = mJobs.getJobsByUid(uid);

            for (int i=0; i<jobsForUid.size(); i++) {

                JobStatus toRemove = jobsForUid.get(i);

                cancelJobImplLocked(toRemove, null);

                cancelJobImplLocked(toRemove, null, reason);

            }

        }

    }
@@ -800,12 +800,12 @@ public final class JobSchedulerService extends com.android.server.SystemService 
        synchronized (mLock) {

            toCancel = mJobs.getJobByUidAndJobId(uid, jobId);

            if (toCancel != null) {

                cancelJobImplLocked(toCancel, null);

                cancelJobImplLocked(toCancel, null, "cancel() called by app");

            }

        }

    }



    private void cancelJobImplLocked(JobStatus cancelled, JobStatus incomingJob) {

    private void cancelJobImplLocked(JobStatus cancelled, JobStatus incomingJob, String reason) {

        if (DEBUG) Slog.d(TAG, "CANCEL: " + cancelled.toShortString());

        cancelled.unprepareLocked(ActivityManager.getService());

        stopTrackingJobLocked(cancelled, incomingJob, true /* writeBack */);
@@ -814,7 +814,7 @@ public final class JobSchedulerService extends com.android.server.SystemService 
            mJobPackageTracker.noteNonpending(cancelled);

        }

        // Cancel if running.

        stopJobOnServiceContextLocked(cancelled, JobParameters.REASON_CANCELED);

        stopJobOnServiceContextLocked(cancelled, JobParameters.REASON_CANCELED, reason);

        reportActiveLocked();

    }
@@ -844,7 +844,8 @@ public final class JobSchedulerService extends com.android.server.SystemService 
                    final JobStatus executing = jsc.getRunningJobLocked();

                    if (executing != null

                            && (executing.getFlags() & JobInfo.FLAG_WILL_BE_FOREGROUND) == 0) {

                        jsc.cancelExecutingJobLocked(JobParameters.REASON_DEVICE_IDLE);

                        jsc.cancelExecutingJobLocked(JobParameters.REASON_DEVICE_IDLE,

                                "cancelled due to doze");

                    }

                }

            } else {
@@ -1023,12 +1024,12 @@ public final class JobSchedulerService extends com.android.server.SystemService 
        return removed;

    }



    private boolean stopJobOnServiceContextLocked(JobStatus job, int reason) {

    private boolean stopJobOnServiceContextLocked(JobStatus job, int reason, String debugReason) {

        for (int i=0; i<mActiveServices.size(); i++) {

            JobServiceContext jsc = mActiveServices.get(i);

            final JobStatus executing = jsc.getRunningJobLocked();

            if (executing != null && executing.matches(job.getUid(), job.getJobId())) {

                jsc.cancelExecutingJobLocked(reason);

                jsc.cancelExecutingJobLocked(reason, debugReason);

                return true;

            }

        }
@@ -1270,7 +1271,8 @@ public final class JobSchedulerService extends com.android.server.SystemService 
                        queueReadyJobsForExecutionLocked();

                        break;

                    case MSG_STOP_JOB:

                        cancelJobImplLocked((JobStatus) message.obj, null);

                        cancelJobImplLocked((JobStatus) message.obj, null,

                                "app no longer allowed to run");

                        break;

                }

                maybeRunPendingJobsLocked();
@@ -1286,7 +1288,8 @@ public final class JobSchedulerService extends com.android.server.SystemService 
            final JobStatus running = serviceContext.getRunningJobLocked();

            if (running != null && !running.isReady()) {

                serviceContext.cancelExecutingJobLocked(

                        JobParameters.REASON_CONSTRAINTS_NOT_SATISFIED);

                        JobParameters.REASON_CONSTRAINTS_NOT_SATISFIED,

                        "cancelled due to unsatisfied constraints");

            }

        }

    }
@@ -1960,7 +1963,7 @@ public final class JobSchedulerService extends com.android.server.SystemService 


            long ident = Binder.clearCallingIdentity();

            try {

                JobSchedulerService.this.cancelJobsForUid(uid);

                JobSchedulerService.this.cancelJobsForUid(uid, "cancelAll() called by app");

            } finally {

                Binder.restoreCallingIdentity(ident);

            }
@@ -2357,7 +2360,14 @@ public final class JobSchedulerService extends com.android.server.SystemService 
                pw.print("  Slot #"); pw.print(i); pw.print(": ");

                final JobStatus job = jsc.getRunningJobLocked();

                if (job == null) {

                    if (jsc.mStoppedReason != null) {

                        pw.print("inactive since ");

                        TimeUtils.formatDuration(jsc.mStoppedTime, nowElapsed, pw);

                        pw.print(", stopped because: ");

                        pw.println(jsc.mStoppedReason);

                    } else {

                        pw.println("inactive");

                    }

                    continue;

                } else {

                    pw.println(job.toShortString());

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

+69 −40
Original line number Diff line number Diff line
@@ -38,6 +38,7 @@ import android.os.SystemClock; 
import android.os.UserHandle;

import android.os.WorkSource;

import android.util.Slog;

import android.util.TimeUtils;



import com.android.internal.annotations.GuardedBy;

import com.android.internal.annotations.VisibleForTesting;
@@ -126,6 +127,12 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
    /** Track when job will timeout. */

    private long mTimeoutElapsed;



    // Debugging: reason this job was last stopped.

    public String mStoppedReason;



    // Debugging: time this job was last stopped.

    public long mStoppedTime;



    JobServiceContext(JobSchedulerService service, IBatteryStats batteryStats,

            JobPackageTracker tracker, Looper looper) {

        this(service.getContext(), service.getLock(), batteryStats, tracker, service, looper);
@@ -204,6 +211,8 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
            }

            mJobPackageTracker.noteActive(job);

            mAvailable = false;

            mStoppedReason = null;

            mStoppedTime = 0;

            return true;

        }

    }
@@ -216,12 +225,12 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
    }



    /** Called externally when a job that was scheduled for execution should be cancelled. */

    void cancelExecutingJobLocked(int reason) {

        doCancelLocked(reason);

    void cancelExecutingJobLocked(int reason, String debugReason) {

        doCancelLocked(reason, debugReason);

    }



    void preemptExecutingJobLocked() {

        doCancelLocked(JobParameters.REASON_PREEMPT);

        doCancelLocked(JobParameters.REASON_PREEMPT, "cancelled due to preemption");

    }



    int getPreferredUid() {
@@ -247,7 +256,7 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
                && (!matchJobId || jobId == executing.getJobId())) {

            if (mVerb == VERB_EXECUTING) {

                mParams.setStopReason(JobParameters.REASON_TIMEOUT);

                sendStopMessageLocked();

                sendStopMessageLocked("force timeout from shell");

                return true;

            }

        }
@@ -256,17 +265,17 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 


    @Override

    public void jobFinished(int jobId, boolean reschedule) {

        doCallback(reschedule);

        doCallback(reschedule, "app called jobFinished");

    }



    @Override

    public void acknowledgeStopMessage(int jobId, boolean reschedule) {

        doCallback(reschedule);

        doCallback(reschedule, null);

    }



    @Override

    public void acknowledgeStartMessage(int jobId, boolean ongoing) {

        doCallback(ongoing);

        doCallback(ongoing, "finished start");

    }



    @Override
@@ -275,14 +284,11 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
        final long ident = Binder.clearCallingIdentity();

        try {

            synchronized (mLock) {

                if (!verifyCallingUidLocked(callingUid)) {

                    throw new SecurityException("Bad calling uid: " + callingUid);

                }



                assertCallingUidLocked(callingUid);

                final JobWorkItem work = mRunningJob.dequeueWorkLocked();

                if (work == null && !mRunningJob.hasExecutingWorkLocked()) {

                    // This will finish the job.

                    doCallbackLocked(false);

                    doCallbackLocked(false, "last work dequeued");

                }

                return work;

            }
@@ -297,9 +303,7 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
        final long ident = Binder.clearCallingIdentity();

        try {

            synchronized (mLock) {

                if (!verifyCallingUidLocked(callingUid)) {

                    throw new SecurityException("Bad calling uid: " + callingUid);

                }

                assertCallingUidLocked(callingUid);

                return mRunningJob.completeWorkLocked(ActivityManager.getService(), workId);

            }

        } finally {
@@ -324,7 +328,8 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
            runningJob = mRunningJob;



            if (runningJob == null || !name.equals(runningJob.getServiceComponent())) {

                closeAndCleanupJobLocked(true /* needsReschedule */);

                closeAndCleanupJobLocked(true /* needsReschedule */,

                        "connected for different component");

                return;

            }

            this.service = IJobService.Stub.asInterface(service);
@@ -355,7 +360,7 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
    @Override

    public void onServiceDisconnected(ComponentName name) {

        synchronized (mLock) {

            closeAndCleanupJobLocked(true /* needsReschedule */);

            closeAndCleanupJobLocked(true /* needsReschedule */, "unexpectedly disconnected");

        }

    }
@@ -374,6 +379,21 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
        return true;

    }



    private void assertCallingUidLocked(final int callingUid) {

        if (!verifyCallingUidLocked(callingUid)) {

            StringBuilder sb = new StringBuilder(128);

            sb.append("Bad calling uid ");

            sb.append(callingUid);

            if (mStoppedReason != null) {

                sb.append(", last stopped ");

                TimeUtils.formatDuration(SystemClock.elapsedRealtime() - mStoppedTime, sb);

                sb.append(" because: ");

                sb.append(mStoppedReason);

            }

            throw new SecurityException(sb.toString());

        }

    }



    /**

     * Scheduling of async messages (basically timeouts at this point).

     */
@@ -401,7 +421,7 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
        handleServiceBoundLocked();

    }



    void doCallback(boolean reschedule) {

    void doCallback(boolean reschedule, String reason) {

        final int callingUid = Binder.getCallingUid();

        final long ident = Binder.clearCallingIdentity();

        try {
@@ -409,14 +429,14 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
                if (!verifyCallingUidLocked(callingUid)) {

                    return;

                }

                doCallbackLocked(reschedule);

                doCallbackLocked(reschedule, reason);

            }

        } finally {

            Binder.restoreCallingIdentity(ident);

        }

    }



    void doCallbackLocked(boolean reschedule) {

    void doCallbackLocked(boolean reschedule, String reason) {

        if (DEBUG) {

            Slog.d(TAG, "doCallback of : " + mRunningJob

                    + " v:" + VERB_STRINGS[mVerb]);
@@ -427,7 +447,7 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
            handleStartedLocked(reschedule);

        } else if (mVerb == VERB_EXECUTING ||

                mVerb == VERB_STOPPING) {

            handleFinishedLocked(reschedule);

            handleFinishedLocked(reschedule, reason);

        } else {

            if (DEBUG) {

                Slog.d(TAG, "Unrecognised callback: " + mRunningJob);
@@ -435,7 +455,7 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
        }

    }



    void doCancelLocked(int arg1) {

    void doCancelLocked(int arg1, String debugReason) {

        if (mVerb == VERB_FINISHED) {

            if (DEBUG) {

                Slog.d(TAG,
@@ -448,7 +468,7 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
            mPreferredUid = mRunningJob != null ? mRunningJob.getUid() :

                    NO_PREFERRED_UID;

        }

        handleCancelLocked();

        handleCancelLocked(debugReason);

    }



    /** Start the job on the service. */
@@ -459,7 +479,7 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
        if (mVerb != VERB_BINDING) {

            Slog.e(TAG, "Sending onStartJob for a job that isn't pending. "

                    + VERB_STRINGS[mVerb]);

            closeAndCleanupJobLocked(false /* reschedule */);

            closeAndCleanupJobLocked(false /* reschedule */, "started job not pending");

            return;

        }

        if (mCancelled) {
@@ -467,7 +487,7 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
                Slog.d(TAG, "Job cancelled while waiting for bind to complete. "

                        + mRunningJob);

            }

            closeAndCleanupJobLocked(true /* reschedule */);

            closeAndCleanupJobLocked(true /* reschedule */, "cancelled while waiting for bind");

            return;

        }

        try {
@@ -496,7 +516,7 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
                mVerb = VERB_EXECUTING;

                if (!workOngoing) {

                    // Job is finished already so fast-forward to handleFinished.

                    handleFinishedLocked(false);

                    handleFinishedLocked(false, "onStartJob returned false");

                    return;

                }

                if (mCancelled) {
@@ -504,7 +524,7 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
                        Slog.d(TAG, "Job cancelled while waiting for onStartJob to complete.");

                    }

                    // Cancelled *while* waiting for acknowledgeStartMessage from client.

                    handleCancelLocked();

                    handleCancelLocked(null);

                    return;

                }

                scheduleOpTimeOutLocked();
@@ -522,11 +542,11 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
     *     _STARTING   -> Error

     *     _PENDING    -> Error

     */

    private void handleFinishedLocked(boolean reschedule) {

    private void handleFinishedLocked(boolean reschedule, String reason) {

        switch (mVerb) {

            case VERB_EXECUTING:

            case VERB_STOPPING:

                closeAndCleanupJobLocked(reschedule);

                closeAndCleanupJobLocked(reschedule, reason);

                break;

            default:

                Slog.e(TAG, "Got an execution complete message for a job that wasn't being" +
@@ -544,7 +564,7 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
     *                      in the message queue.

     *     _ENDING     -> No point in doing anything here, so we ignore.

     */

    private void handleCancelLocked() {

    private void handleCancelLocked(String reason) {

        if (JobSchedulerService.DEBUG) {

            Slog.d(TAG, "Handling cancel for: " + mRunningJob.getJobId() + " "

                    + VERB_STRINGS[mVerb]);
@@ -553,9 +573,10 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
            case VERB_BINDING:

            case VERB_STARTING:

                mCancelled = true;

                applyStoppedReasonLocked(reason);

                break;

            case VERB_EXECUTING:

                sendStopMessageLocked();

                sendStopMessageLocked(reason);

                break;

            case VERB_STOPPING:

                // Nada.
@@ -572,7 +593,7 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
            case VERB_BINDING:

                Slog.e(TAG, "Time-out while trying to bind " + mRunningJob.toShortString() +

                        ", dropping.");

                closeAndCleanupJobLocked(false /* needsReschedule */);

                closeAndCleanupJobLocked(false /* needsReschedule */, "timed out while binding");

                break;

            case VERB_STARTING:

                // Client unresponsive - wedged or failed to respond in time. We don't really
@@ -580,25 +601,25 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
                // FINISHED/NO-RETRY.

                Slog.e(TAG, "No response from client for onStartJob '" +

                        mRunningJob.toShortString());

                closeAndCleanupJobLocked(false /* needsReschedule */);

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

                closeAndCleanupJobLocked(true /* needsReschedule */);

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

                mParams.setStopReason(JobParameters.REASON_TIMEOUT);

                sendStopMessageLocked();

                sendStopMessageLocked("timeout while executing");

                break;

            default:

                Slog.e(TAG, "Handling timeout for an invalid job state: " +

                        mRunningJob.toShortString() + ", dropping.");

                closeAndCleanupJobLocked(false /* needsReschedule */);

                closeAndCleanupJobLocked(false /* needsReschedule */, "invalid timeout");

        }

    }
@@ -606,11 +627,11 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
     * Already running, need to stop. Will switch {@link #mVerb} from VERB_EXECUTING ->

     * VERB_STOPPING.

     */

    private void sendStopMessageLocked() {

    private void sendStopMessageLocked(String reason) {

        removeOpTimeOutLocked();

        if (mVerb != VERB_EXECUTING) {

            Slog.e(TAG, "Sending onStopJob for a job that isn't started. " + mRunningJob);

            closeAndCleanupJobLocked(false /* reschedule */);

            closeAndCleanupJobLocked(false /* reschedule */, reason);

            return;

        }

        try {
@@ -620,7 +641,7 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
        } catch (RemoteException e) {

            Slog.e(TAG, "Error sending onStopJob to client.", e);

            // The job's host app apparently crashed during the job, so we should reschedule.

            closeAndCleanupJobLocked(true /* reschedule */);

            closeAndCleanupJobLocked(true /* reschedule */, "host crashed when trying to stop");

        }

    }
@@ -630,11 +651,12 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
     * or from acknowledging the stop message we sent. Either way, we're done tracking it and

     * we want to clean up internally.

     */

    private void closeAndCleanupJobLocked(boolean reschedule) {

    private void closeAndCleanupJobLocked(boolean reschedule, String reason) {

        final JobStatus completedJob;

        if (mVerb == VERB_FINISHED) {

            return;

        }

        applyStoppedReasonLocked(reason);

        completedJob = mRunningJob;

        mJobPackageTracker.noteInactive(completedJob);

        try {
@@ -658,6 +680,13 @@ public class JobServiceContext extends IJobCallback.Stub implements ServiceConne 
        mCompletedListener.onJobCompletedLocked(completedJob, reschedule);

    }



    private void applyStoppedReasonLocked(String reason) {

        if (reason != null && mStoppedReason == null) {

            mStoppedReason = reason;

            mStoppedTime = SystemClock.elapsedRealtime();

        }

    }



    /**

     * Called when sending a message to the client, over whose execution we have no control. If

     * we haven't received a response in a certain amount of time, we want to give up and carry