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

Commit dddea62e authored by Jeff Sharkey's avatar Jeff Sharkey
Browse files

Layer "locked" methods for better locking logs. 

When reporting either deadlocks or lock contention, the OS logs the
line at which the lock was acquired, and our LocalHandler makes this
tricky to track across builds as line numbers change.

This change pivots to adding a call stack frame to give ourselves
clearer information about what operation is working with the lock.

Also restore missing code coverage for health checks that was
accidentally deleted.

Bug: 274681945
Test: atest FrameworksMockingServicesTests:BroadcastQueueTest
Test: atest FrameworksMockingServicesTests:BroadcastQueueModernImplTest
Test: atest FrameworksMockingServicesTests:BroadcastRecordTest
Change-Id: Ic6de76f9a7e1ae7b9d1bd6358f556072eaf3ac7c
parent d3a95bbc

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

+5 −5
Original line number Diff line number Diff line
@@ -1050,13 +1050,13 @@ class BroadcastProcessQueue { 
     * Check overall health, confirming things are in a reasonable state and

     * that we're not wedged.

     */

    public void checkHealthLocked() {

        checkHealthLocked(mPending);

        checkHealthLocked(mPendingUrgent);

        checkHealthLocked(mPendingOffload);

    public void assertHealthLocked() {

        assertHealthLocked(mPending);

        assertHealthLocked(mPendingUrgent);

        assertHealthLocked(mPendingOffload);

    }



    private void checkHealthLocked(@NonNull ArrayDeque<SomeArgs> queue) {

    private void assertHealthLocked(@NonNull ArrayDeque<SomeArgs> queue) {

        if (queue.isEmpty()) return;



        final Iterator<SomeArgs> it = queue.descendingIterator();

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

+74 −52
Original line number Diff line number Diff line
@@ -246,21 +246,15 @@ class BroadcastQueueModernImpl extends BroadcastQueue { 
    private final Handler.Callback mLocalCallback = (msg) -> {

        switch (msg.what) {

            case MSG_UPDATE_RUNNING_LIST: {

                synchronized (mService) {

                    updateRunningListLocked();

                }

                updateRunningList();

                return true;

            }

            case MSG_DELIVERY_TIMEOUT_SOFT: {

                synchronized (mService) {

                    deliveryTimeoutSoftLocked((BroadcastProcessQueue) msg.obj, msg.arg1);

                }

                deliveryTimeoutSoft((BroadcastProcessQueue) msg.obj, msg.arg1);

                return true;

            }

            case MSG_DELIVERY_TIMEOUT_HARD: {

                synchronized (mService) {

                    deliveryTimeoutHardLocked((BroadcastProcessQueue) msg.obj);

                }

                deliveryTimeoutHard((BroadcastProcessQueue) msg.obj);

                return true;

            }

            case MSG_BG_ACTIVITY_START_TIMEOUT: {
@@ -274,9 +268,7 @@ class BroadcastQueueModernImpl extends BroadcastQueue { 
                return true;

            }

            case MSG_CHECK_HEALTH: {

                synchronized (mService) {

                    checkHealthLocked();

                }

                checkHealth();

                return true;

            }

        }
@@ -365,6 +357,12 @@ class BroadcastQueueModernImpl extends BroadcastQueue { 
        }

    }



    private void updateRunningList() {

        synchronized (mService) {

            updateRunningListLocked();

        }

    }



    /**

     * Consider updating the list of "running" queues.

     * <p>
@@ -965,6 +963,13 @@ class BroadcastQueueModernImpl extends BroadcastQueue { 
        r.resultTo = null;

    }



    private void deliveryTimeoutSoft(@NonNull BroadcastProcessQueue queue,

            int softTimeoutMillis) {

        synchronized (mService) {

            deliveryTimeoutSoftLocked(queue, softTimeoutMillis);

        }

    }



    private void deliveryTimeoutSoftLocked(@NonNull BroadcastProcessQueue queue,

            int softTimeoutMillis) {

        if (queue.app != null) {
@@ -981,6 +986,12 @@ class BroadcastQueueModernImpl extends BroadcastQueue { 
        }

    }



    private void deliveryTimeoutHard(@NonNull BroadcastProcessQueue queue) {

        synchronized (mService) {

            deliveryTimeoutHardLocked(queue);

        }

    }



    private void deliveryTimeoutHardLocked(@NonNull BroadcastProcessQueue queue) {

        finishReceiverActiveLocked(queue, BroadcastRecord.DELIVERY_TIMEOUT,

                "deliveryTimeoutHardLocked");
@@ -1458,14 +1469,35 @@ class BroadcastQueueModernImpl extends BroadcastQueue { 
        // TODO: implement

    }



    private void checkHealth() {

        synchronized (mService) {

            checkHealthLocked();

        }

    }



    private void checkHealthLocked() {

        try {

            assertHealthLocked();



            // If no health issues found above, check again in the future

            mLocalHandler.sendEmptyMessageDelayed(MSG_CHECK_HEALTH,

                    DateUtils.MINUTE_IN_MILLIS);



        } catch (Exception e) {

            // Throw up a message to indicate that something went wrong, and

            // dump current state for later inspection

            Slog.wtf(TAG, e);

            dumpToDropBoxLocked(e.toString());

        }

    }



    /**

     * Check overall health, confirming things are in a reasonable state and

     * that we're not wedged. If we determine we're in an unhealthy state, dump

     * current state once and stop future health checks to avoid spamming.

     */

    @VisibleForTesting

    void checkHealthLocked() {

        try {

    void assertHealthLocked() {

        // Verify all runnable queues are sorted

        BroadcastProcessQueue prev = null;

        BroadcastProcessQueue next = mRunnableHead;
@@ -1497,20 +1529,10 @@ class BroadcastQueueModernImpl extends BroadcastQueue { 
        for (int i = 0; i < mProcessQueues.size(); i++) {

            BroadcastProcessQueue leaf = mProcessQueues.valueAt(i);

            while (leaf != null) {

                    leaf.checkHealthLocked();

                leaf.assertHealthLocked();

                leaf = leaf.processNameNext;

            }

        }



            // If no health issues found above, check again in the future

            mLocalHandler.sendEmptyMessageDelayed(MSG_CHECK_HEALTH, DateUtils.MINUTE_IN_MILLIS);



        } catch (Exception e) {

            // Throw up a message to indicate that something went wrong, and

            // dump current state for later inspection

            Slog.wtf(TAG, e);

            dumpToDropBoxLocked(e.toString());

        }

    }



    private void updateWarmProcess(@NonNull BroadcastProcessQueue queue) {

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

+7 −2
Original line number Diff line number Diff line
@@ -91,8 +91,8 @@ import org.junit.Rule; 
import org.junit.Test;

import org.mockito.Mock;



import java.io.ByteArrayOutputStream;

import java.io.PrintWriter;

import java.io.Writer;

import java.lang.reflect.Array;

import java.util.ArrayList;

import java.util.List;
@@ -596,7 +596,7 @@ public final class BroadcastQueueModernImplTest { 
        // about the actual output, just that we don't crash

        queue.getActive().setDeliveryState(0, BroadcastRecord.DELIVERY_SCHEDULED, "Test-driven");

        queue.dumpLocked(SystemClock.uptimeMillis(),

                new IndentingPrintWriter(new PrintWriter(new ByteArrayOutputStream())));

                new IndentingPrintWriter(new PrintWriter(Writer.nullWriter())));



        queue.makeActiveNextPending();

        assertEquals(Intent.ACTION_LOCALE_CHANGED, queue.getActive().intent.getAction());
@@ -1166,6 +1166,11 @@ public final class BroadcastQueueModernImplTest { 
            List<Intent> intents) {

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

            queue.makeActiveNextPending();



            // While we're here, give our health check some test coverage

            queue.assertHealthLocked();

            queue.dumpLocked(0L, new IndentingPrintWriter(Writer.nullWriter()));



            final Intent actualIntent = queue.getActive().intent;

            final Intent expectedIntent = intents.get(i);

            final String errMsg = "actual=" + actualIntent + ", expected=" + expectedIntent

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

+14 −3
Original line number Diff line number Diff line
@@ -39,6 +39,7 @@ import static org.mockito.Mockito.atLeastOnce; 
import static org.mockito.Mockito.doAnswer;

import static org.mockito.Mockito.doNothing;

import static org.mockito.Mockito.doReturn;

import static org.mockito.Mockito.doThrow;

import static org.mockito.Mockito.inOrder;

import static org.mockito.Mockito.mock;

import static org.mockito.Mockito.never;
@@ -106,10 +107,10 @@ import org.mockito.Mock; 
import org.mockito.MockitoAnnotations;

import org.mockito.verification.VerificationMode;



import java.io.ByteArrayOutputStream;

import java.io.File;

import java.io.FileDescriptor;

import java.io.PrintWriter;

import java.io.Writer;

import java.util.ArrayList;

import java.util.Arrays;

import java.util.Collection;
@@ -231,6 +232,7 @@ public class BroadcastQueueTest { 
        doAnswer((invocation) -> {

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

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

            assertHealth();

            final ProcessStartBehavior behavior = mNextProcessStartBehavior

                    .getAndSet(ProcessStartBehavior.SUCCESS);

            if (behavior == ProcessStartBehavior.FAIL_NULL) {
@@ -462,6 +464,7 @@ public class BroadcastQueueTest { 
        doAnswer((invocation) -> {

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

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

            assertHealth();

            final Intent intent = invocation.getArgument(0);

            final Bundle extras = invocation.getArgument(5);

            mScheduledBroadcasts.add(makeScheduledBroadcast(r, intent));
@@ -483,6 +486,7 @@ public class BroadcastQueueTest { 
        doAnswer((invocation) -> {

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

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

            assertHealth();

            final Intent intent = invocation.getArgument(1);

            final Bundle extras = invocation.getArgument(4);

            final boolean ordered = invocation.getArgument(5);
@@ -600,6 +604,13 @@ public class BroadcastQueueTest { 
                BackgroundStartPrivileges.NONE, false, null);

    }



    private void assertHealth() {

        if (mImpl == Impl.MODERN) {

            // If this fails, it'll throw a clear reason message

            ((BroadcastQueueModernImpl) mQueue).assertHealthLocked();

        }

    }



    private static Map<String, Object> asMap(Bundle bundle) {

        final Map<String, Object> map = new HashMap<>();

        if (bundle != null) {
@@ -769,7 +780,7 @@ public class BroadcastQueueTest { 
        // about the actual output, just that we don't crash

        mQueue.dumpDebug(new ProtoOutputStream(),

                ActivityManagerServiceDumpBroadcastsProto.BROADCAST_QUEUE);

        mQueue.dumpLocked(FileDescriptor.err, new PrintWriter(new ByteArrayOutputStream()),

        mQueue.dumpLocked(FileDescriptor.err, new PrintWriter(Writer.nullWriter()),

                null, 0, true, true, true, null, false);

        mQueue.dumpToDropBoxLocked(TAG);
@@ -1166,7 +1177,7 @@ public class BroadcastQueueTest { 
            // about the actual output, just that we don't crash

            mQueue.dumpDebug(new ProtoOutputStream(),

                    ActivityManagerServiceDumpBroadcastsProto.BROADCAST_QUEUE);

            mQueue.dumpLocked(FileDescriptor.err, new PrintWriter(new ByteArrayOutputStream()),

            mQueue.dumpLocked(FileDescriptor.err, new PrintWriter(Writer.nullWriter()),

                    null, 0, true, true, true, null, false);

        }