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

Commit ca65618a authored by Sudheer Shanka's avatar Sudheer Shanka
Browse files

Timeout and discard process start requests exceeding a few minutes. 

If AMS doesn't inform BroadcastQueue of process start/cleanup for any
reason, discard the process start request after a while instead of
letting it block the entire queue.

Also, expand the health checks with more logs to identify cases that
could be leading to unfulfilled process start requests.

Bug: 393898613
Test: atest services/tests/mockingservicestests/src/com/android/server/am/BroadcastQueueTest.java
Test: atest services/tests/mockingservicestests/src/com/android/server/am/BroadcastQueueImplTest.java
Flag: EXEMPT bugfix
Change-Id: Ia8d7143a1df7444a3df5255258d1b34e8962c4a2
parent d2a50090

services/core/java/com/android/server/am/BroadcastConstants.java

+18 −0
Original line number Diff line number Diff line
@@ -41,6 +41,7 @@ import dalvik.annotation.optimization.NeverCompile; 


import java.lang.annotation.Retention;

import java.lang.annotation.RetentionPolicy;

import java.util.concurrent.TimeUnit;



/**

 * Tunable parameters for broadcast dispatch policy
@@ -286,6 +287,17 @@ public class BroadcastConstants { 
            "max_frozen_outgoing_broadcasts";

    private static final int DEFAULT_MAX_FROZEN_OUTGOING_BROADCASTS = 32;



    /**

     * For {@link BroadcastQueueImpl}: Indicates how long after a process start was initiated,

     * it should be considered abandoned and discarded.

     */

    public long PENDING_COLD_START_ABANDON_TIMEOUT_MILLIS =

            DEFAULT_PENDING_COLD_START_ABANDON_TIMEOUT_MILLIS * Build.HW_TIMEOUT_MULTIPLIER;

    private static final String KEY_PENDING_COLD_START_ABANDON_TIMEOUT_MILLIS =

            "pending_cold_start_abandon_timeout_millis";

    private static final long DEFAULT_PENDING_COLD_START_ABANDON_TIMEOUT_MILLIS =

            TimeUnit.MINUTES.toMillis(5);



    // Settings override tracking for this instance

    private String mSettingsKey;

    private SettingsObserver mSettingsObserver;
@@ -434,6 +446,10 @@ public class BroadcastConstants { 
            MAX_FROZEN_OUTGOING_BROADCASTS = getDeviceConfigInt(

                    KEY_MAX_FROZEN_OUTGOING_BROADCASTS,

                    DEFAULT_MAX_FROZEN_OUTGOING_BROADCASTS);

            PENDING_COLD_START_ABANDON_TIMEOUT_MILLIS = getDeviceConfigLong(

                    KEY_PENDING_COLD_START_ABANDON_TIMEOUT_MILLIS,

                    DEFAULT_PENDING_COLD_START_ABANDON_TIMEOUT_MILLIS)

                            * Build.HW_TIMEOUT_MULTIPLIER;

        }



        // TODO: migrate BroadcastRecord to accept a BroadcastConstants
@@ -491,6 +507,8 @@ public class BroadcastConstants { 
                    PENDING_COLD_START_CHECK_INTERVAL_MILLIS).println();

            pw.print(KEY_MAX_FROZEN_OUTGOING_BROADCASTS,

                    MAX_FROZEN_OUTGOING_BROADCASTS).println();

            pw.print(KEY_PENDING_COLD_START_ABANDON_TIMEOUT_MILLIS,

                    PENDING_COLD_START_ABANDON_TIMEOUT_MILLIS).println();

            pw.decreaseIndent();

            pw.println();

        }

services/core/java/com/android/server/am/BroadcastProcessQueue.java

+68 −0
Original line number Diff line number Diff line
@@ -245,6 +245,24 @@ class BroadcastProcessQueue { 
     */

    private final ArrayList<BroadcastRecord> mOutgoingBroadcasts = new ArrayList<>();



    /**

     * The timestamp, in {@link SystemClock#uptimeMillis()}, at which a cold start was initiated

     * for the process associated with this queue.

     *

     * Note: We could use the already existing {@link ProcessRecord#getStartUptime()} instead

     * of this, but the need for this timestamp is to identify an issue (b/393898613) where the

     * suspicion is that process is not attached or getting changed. So, we don't want to rely on

     * ProcessRecord directly for this purpose.

     */

    private long mProcessStartInitiatedTimestampMillis;



    /**

     * Indicates whether the number of current receivers has been incremented using

     * {@link ProcessReceiverRecord#incrementCurReceivers()}. This allows to skip decrementing

     * the receivers when it is not required.

     */

    private boolean mCurReceiversIncremented;



    public BroadcastProcessQueue(@NonNull BroadcastConstants constants,

            @NonNull String processName, int uid) {

        this.constants = Objects.requireNonNull(constants);
@@ -652,6 +670,52 @@ class BroadcastProcessQueue { 
        return mActiveFirstLaunch;

    }



    public void incrementCurAppReceivers() {

        app.mReceivers.incrementCurReceivers();

        mCurReceiversIncremented = true;

    }



    public void decrementCurAppReceivers() {

        if (mCurReceiversIncremented) {

            app.mReceivers.decrementCurReceivers();

            mCurReceiversIncremented = false;

        }

    }



    public void setProcessStartInitiatedTimestampMillis(@UptimeMillisLong long timestampMillis) {

        mProcessStartInitiatedTimestampMillis = timestampMillis;

    }



    @UptimeMillisLong

    public long getProcessStartInitiatedTimestampMillis() {

        return mProcessStartInitiatedTimestampMillis;

    }



    public boolean hasProcessStartInitiationTimedout() {

        if (mProcessStartInitiatedTimestampMillis <= 0) {

            return false;

        }

        return (SystemClock.uptimeMillis() - mProcessStartInitiatedTimestampMillis)

                > constants.PENDING_COLD_START_ABANDON_TIMEOUT_MILLIS;

    }



    /**

     * Returns if the process start initiation is expected to be timed out at this point. This

     * allows us to dump necessary state for debugging before the process start is timed out

     * and discarded.

     */

    public boolean isProcessStartInitiationTimeoutExpected() {

        if (mProcessStartInitiatedTimestampMillis <= 0) {

            return false;

        }

        return (SystemClock.uptimeMillis() - mProcessStartInitiatedTimestampMillis)

                > constants.PENDING_COLD_START_ABANDON_TIMEOUT_MILLIS / 2;

    }



    public void clearProcessStartInitiatedTimestampMillis() {

        mProcessStartInitiatedTimestampMillis = 0;

    }



    /**

     * Get package name of the first application loaded into this process.

     */
@@ -1558,6 +1622,10 @@ class BroadcastProcessQueue { 
        if (mActiveReEnqueued) {

            pw.print("activeReEnqueued:"); pw.println(mActiveReEnqueued);

        }

        if (mProcessStartInitiatedTimestampMillis > 0) {

            pw.print("processStartInitiatedTimestamp:"); pw.println(

                    TimeUtils.formatUptime(mProcessStartInitiatedTimestampMillis));

        }

    }



    @NeverCompile

services/core/java/com/android/server/am/BroadcastQueueImpl.java

+36 −3
Original line number Diff line number Diff line
@@ -534,6 +534,7 @@ class BroadcastQueueImpl extends BroadcastQueue { 
                // skip to look for another warm process

                if (mRunningColdStart == null) {

                    mRunningColdStart = queue;

                    mRunningColdStart.clearProcessStartInitiatedTimestampMillis();

                } else if (isPendingColdStartValid()) {

                    // Move to considering next runnable queue

                    queue = nextQueue;
@@ -542,6 +543,7 @@ class BroadcastQueueImpl extends BroadcastQueue { 
                    // Pending cold start is not valid, so clear it and move on.

                    clearInvalidPendingColdStart();

                    mRunningColdStart = queue;

                    mRunningColdStart.clearProcessStartInitiatedTimestampMillis();

                }

            }
@@ -588,7 +590,9 @@ class BroadcastQueueImpl extends BroadcastQueue { 


    @GuardedBy("mService")

    private boolean isPendingColdStartValid() {

        if (mRunningColdStart.app.getPid() > 0) {

        if (mRunningColdStart.hasProcessStartInitiationTimedout()) {

            return false;

        } else if (mRunningColdStart.app.getPid() > 0) {

            // If the process has already started, check if it wasn't killed.

            return !mRunningColdStart.app.isKilled();

        } else {
@@ -672,6 +676,7 @@ class BroadcastQueueImpl extends BroadcastQueue { 
        if ((mRunningColdStart != null) && (mRunningColdStart == queue)) {

            // We've been waiting for this app to cold start, and it's ready

            // now; dispatch its next broadcast and clear the slot

            mRunningColdStart.clearProcessStartInitiatedTimestampMillis();

            mRunningColdStart = null;



            // Now that we're running warm, we can finally request that OOM
@@ -755,6 +760,7 @@ class BroadcastQueueImpl extends BroadcastQueue { 


        // We've been waiting for this app to cold start, and it had

        // trouble; clear the slot and fail delivery below

        mRunningColdStart.clearProcessStartInitiatedTimestampMillis();

        mRunningColdStart = null;



        // We might be willing to kick off another cold start
@@ -1035,6 +1041,7 @@ class BroadcastQueueImpl extends BroadcastQueue { 
                    "startProcessLocked failed");

            return true;

        }

        queue.setProcessStartInitiatedTimestampMillis(SystemClock.uptimeMillis());

        // TODO: b/335420031 - cache receiver intent to avoid multiple calls to getReceiverIntent.

        mService.mProcessList.getAppStartInfoTracker().handleProcessBroadcastStart(

                startTimeNs, queue.app, r.getReceiverIntent(receiver), r.alarm /* isAlarm */);
@@ -1981,6 +1988,32 @@ class BroadcastQueueImpl extends BroadcastQueue { 
        if (mRunningColdStart != null) {

            checkState(getRunningIndexOf(mRunningColdStart) >= 0,

                    "isOrphaned " + mRunningColdStart);



            final BroadcastProcessQueue queue = getProcessQueue(mRunningColdStart.processName,

                    mRunningColdStart.uid);

            checkState(queue == mRunningColdStart, "Conflicting " + mRunningColdStart

                    + " with queue " + queue

                    + ";\n mRunningColdStart.app: " + mRunningColdStart.app.toDetailedString()

                    + ";\n queue.app: " + queue.app.toDetailedString());



            checkState(mRunningColdStart.app != null, "Empty cold start queue "

                    + mRunningColdStart);



            if (mRunningColdStart.isProcessStartInitiationTimeoutExpected()) {

                final StringBuilder sb = new StringBuilder();

                sb.append("Process start timeout expected for app ");

                sb.append(mRunningColdStart.app);

                sb.append(" in queue ");

                sb.append(mRunningColdStart);

                sb.append("; startUpTime: ");

                final long startupTimeMs =

                        mRunningColdStart.getProcessStartInitiatedTimestampMillis();

                sb.append(startupTimeMs == 0 ? "<none>"

                        : TimeUtils.formatDuration(startupTimeMs - SystemClock.uptimeMillis()));

                sb.append(";\n app: ");

                sb.append(mRunningColdStart.app.toDetailedString());

                checkState(false, sb.toString());

            }

        }



        // Verify health of all known process queues
@@ -2080,7 +2113,7 @@ class BroadcastQueueImpl extends BroadcastQueue { 
    @GuardedBy("mService")

    private void notifyStartedRunning(@NonNull BroadcastProcessQueue queue) {

        if (queue.app != null) {

            queue.app.mReceivers.incrementCurReceivers();

            queue.incrementCurAppReceivers();



            // Don't bump its LRU position if it's in the background restricted.

            if (mService.mInternal.getRestrictionLevel(
@@ -2105,7 +2138,7 @@ class BroadcastQueueImpl extends BroadcastQueue { 
    @GuardedBy("mService")

    private void notifyStoppedRunning(@NonNull BroadcastProcessQueue queue) {

        if (queue.app != null) {

            queue.app.mReceivers.decrementCurReceivers();

            queue.decrementCurAppReceivers();



            if (queue.runningOomAdjusted) {

                mService.enqueueOomAdjTargetLocked(queue.app);

services/core/java/com/android/server/am/ProcessRecord.java

+11 −0
Original line number Diff line number Diff line
@@ -70,6 +70,7 @@ import com.android.server.wm.WindowProcessController; 
import com.android.server.wm.WindowProcessListener;



import java.io.PrintWriter;

import java.io.StringWriter;

import java.util.Arrays;

import java.util.List;

import java.util.function.Consumer;
@@ -1414,6 +1415,16 @@ class ProcessRecord implements WindowProcessListener { 
        return mStringName = sb.toString();

    }



    String toDetailedString() {

        final StringBuilder sb = new StringBuilder();

        sb.append(this);

        final StringWriter sw = new StringWriter();

        final PrintWriter pw = new PrintWriter(sw);

        dump(pw, "  ");

        sb.append(sw);

        return sb.toString();

    }



    /*

     *  Return true if package has been added false if not

     */

services/tests/mockingservicestests/src/com/android/server/am/BroadcastQueueTest.java

+37 −1
Original line number Diff line number Diff line
@@ -155,7 +155,6 @@ public class BroadcastQueueTest extends BaseBroadcastQueueTest { 
        doAnswer((invocation) -> {

            Log.v(TAG, "Intercepting startProcessLocked() for "

                    + Arrays.toString(invocation.getArguments()));

            assertHealth();

            final String processName = invocation.getArgument(0);

            final ProcessStartBehavior behavior = mNewProcessStartBehaviors.getOrDefault(

                    processName, mNextProcessStartBehavior.getAndSet(ProcessStartBehavior.SUCCESS));
@@ -206,6 +205,9 @@ public class BroadcastQueueTest extends BaseBroadcastQueueTest { 
                            mActiveProcesses.remove(res);

                            res.setKilled(true);

                            break;

                        case MISSING_RESPONSE:

                            res.setPendingStart(true);

                            break;

                        default:

                            throw new UnsupportedOperationException();

                    }
@@ -244,6 +246,7 @@ public class BroadcastQueueTest extends BaseBroadcastQueueTest { 
        mConstants.ALLOW_BG_ACTIVITY_START_TIMEOUT = 0;

        mConstants.PENDING_COLD_START_CHECK_INTERVAL_MILLIS = 500;

        mConstants.MAX_FROZEN_OUTGOING_BROADCASTS = 10;

        mConstants.PENDING_COLD_START_ABANDON_TIMEOUT_MILLIS = 2000;

    }



    @After
@@ -279,6 +282,8 @@ public class BroadcastQueueTest extends BaseBroadcastQueueTest { 
        FAIL_NULL,

        /** Process is killed without reporting to BroadcastQueue */

        KILLED_WITHOUT_NOTIFY,

        /** Process start fails without no response */

        MISSING_RESPONSE,

    }



    private enum ProcessBehavior {
@@ -1173,6 +1178,37 @@ public class BroadcastQueueTest extends BaseBroadcastQueueTest { 
        verifyScheduleReceiver(times(1), receiverOrangeApp, timezone);

    }



    @Test

    public void testProcessStartWithMissingResponse() throws Exception {

        final ProcessRecord callerApp = makeActiveProcessRecord(PACKAGE_RED);

        final ProcessRecord receiverBlueApp = makeActiveProcessRecord(PACKAGE_BLUE);



        mNewProcessStartBehaviors.put(PACKAGE_GREEN, ProcessStartBehavior.MISSING_RESPONSE);



        final Intent airplane = new Intent(Intent.ACTION_AIRPLANE_MODE_CHANGED);

        enqueueBroadcast(makeBroadcastRecord(airplane, callerApp, List.of(

                withPriority(makeManifestReceiver(PACKAGE_GREEN, CLASS_GREEN), 10),

                withPriority(makeRegisteredReceiver(receiverBlueApp), 5),

                withPriority(makeManifestReceiver(PACKAGE_YELLOW, CLASS_YELLOW), 0))));



        final Intent timezone = new Intent(Intent.ACTION_TIMEZONE_CHANGED);

        enqueueBroadcast(makeBroadcastRecord(timezone, callerApp,

                List.of(makeManifestReceiver(PACKAGE_ORANGE, CLASS_ORANGE))));



        waitForIdle();

        final ProcessRecord receiverGreenApp = mAms.getProcessRecordLocked(PACKAGE_GREEN,

                getUidForPackage(PACKAGE_GREEN));

        final ProcessRecord receiverYellowApp = mAms.getProcessRecordLocked(PACKAGE_YELLOW,

                getUidForPackage(PACKAGE_YELLOW));

        final ProcessRecord receiverOrangeApp = mAms.getProcessRecordLocked(PACKAGE_ORANGE,

                getUidForPackage(PACKAGE_ORANGE));



        verifyScheduleReceiver(times(1), receiverGreenApp, airplane);

        verifyScheduleRegisteredReceiver(times(1), receiverBlueApp, airplane);

        verifyScheduleReceiver(times(1), receiverYellowApp, airplane);

        verifyScheduleReceiver(times(1), receiverOrangeApp, timezone);

    }



    /**

     * Verify that a broadcast sent to a frozen app, which gets killed as part of unfreezing

     * process due to pending sync binder transactions, is delivered as expected.