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

Commit 90f899e1 authored by Ben Miles's avatar Ben Miles
Browse files

Improve ANR debug store logging with more app lifecycle events 

New debug store events:
* BindApp = bind application
* SchRcv = schedule receiver
* SchRcvReg = schedule registered receiver
* BcRcvReg = broadcast receive (registered receiver)

Also changed the semantics of some existing debug store events:
* GoAsync / Finish now include the pending result id (so readers can see which finish is for which goAsync)
* Finish no longer includes the receiver name (redundant)
* HandleReceiver is renamed to BcRcv for consistency with BcRcvReg

Also:
* Added some debug logging for the debug store

The rationale for adding these events is to make broadcast_of_intent and
bind_application ANRs more debuggable.

Change-Id: I28166f10a51db728cbdd177704263486d12c7ef8
Test: atest FrameworksCoreTests:com.android.internal.os.DebugStoreTest
Test: Manual testing
Flag: debug_store_enabled
parent a25530f9

core/java/android/app/ActivityThread.java

+23 −1
Original line number Diff line number Diff line
@@ -1130,12 +1130,19 @@ public final class ActivityThread extends ClientTransactionHandler 
                CompatibilityInfo compatInfo, int resultCode, String data, Bundle extras,

                boolean ordered, boolean assumeDelivered, int sendingUser, int processState,

                int sendingUid, String sendingPackage) {

            long debugStoreId = -1;

            if (DEBUG_STORE_ENABLED) {

                debugStoreId = DebugStore.recordScheduleReceiver();

            }

            updateProcessState(processState, false);

            ReceiverData r = new ReceiverData(intent, resultCode, data, extras,

                    ordered, false, assumeDelivered, mAppThread.asBinder(), sendingUser,

                    sendingUid, sendingPackage);

            r.info = info;

            sendMessage(H.RECEIVER, r);

            if (DEBUG_STORE_ENABLED) {

                DebugStore.recordEventEnd(debugStoreId);

            }

        }



        public final void scheduleReceiverList(List<ReceiverInfo> info) throws RemoteException {
@@ -1458,6 +1465,10 @@ public final class ActivityThread extends ClientTransactionHandler 
                boolean sticky, boolean assumeDelivered, int sendingUser, int processState,

                int sendingUid, String sendingPackage)

                throws RemoteException {

            long debugStoreId = -1;

            if (DEBUG_STORE_ENABLED) {

                debugStoreId = DebugStore.recordScheduleRegisteredReceiver();

            }

            updateProcessState(processState, false);



            // We can't modify IIntentReceiver due to UnsupportedAppUsage, so
@@ -1482,6 +1493,9 @@ public final class ActivityThread extends ClientTransactionHandler 
                receiver.performReceive(intent, resultCode, dataStr, extras, ordered, sticky,

                        sendingUser);

            }

            if (DEBUG_STORE_ENABLED) {

                DebugStore.recordEventEnd(debugStoreId);

            }

        }



        @Override
@@ -2445,8 +2459,15 @@ public final class ActivityThread extends ClientTransactionHandler 
            switch (msg.what) {

                case BIND_APPLICATION:

                    Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "bindApplication");

                    if (DEBUG_STORE_ENABLED) {

                        debugStoreId =

                                DebugStore.recordHandleBindApplication();

                    }

                    AppBindData data = (AppBindData)msg.obj;

                    handleBindApplication(data);

                    if (DEBUG_STORE_ENABLED) {

                        DebugStore.recordEventEnd(debugStoreId);

                    }

                    Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);

                    break;

                case EXIT_APPLICATION:
@@ -2469,7 +2490,8 @@ public final class ActivityThread extends ClientTransactionHandler 
                    ReceiverData receiverData = (ReceiverData) msg.obj;

                    if (DEBUG_STORE_ENABLED) {

                        debugStoreId =

                                DebugStore.recordBroadcastHandleReceiver(receiverData.intent);

                            DebugStore.recordBroadcastReceive(

                                receiverData.intent, System.identityHashCode(receiverData));

                    }



                    try {

core/java/android/app/LoadedApk.java

+14 −0
Original line number Diff line number Diff line
@@ -61,6 +61,7 @@ import android.view.DisplayAdjustments; 


import com.android.internal.R;

import com.android.internal.annotations.GuardedBy;

import com.android.internal.os.DebugStore;

import com.android.internal.util.ArrayUtils;



import dalvik.system.BaseDexClassLoader;
@@ -107,6 +108,9 @@ public final class LoadedApk { 
    static final String TAG = "LoadedApk";

    static final boolean DEBUG = false;



    private static final boolean DEBUG_STORE_ENABLED =

            com.android.internal.os.Flags.debugStoreEnabled();



    @UnsupportedAppUsage

    private final ActivityThread mActivityThread;

    @UnsupportedAppUsage
@@ -1805,6 +1809,12 @@ public final class LoadedApk { 
                        Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,

                                "broadcastReceiveReg: " + intent.getAction());

                    }

                    long debugStoreId = -1;

                    if (DEBUG_STORE_ENABLED) {

                        debugStoreId =

                                DebugStore.recordBroadcastReceiveReg(

                                        intent, System.identityHashCode(this));

                    }



                    try {

                        ClassLoader cl = mReceiver.getClass().getClassLoader();
@@ -1827,6 +1837,10 @@ public final class LoadedApk { 
                                    "Error receiving broadcast " + intent

                                            + " in " + mReceiver, e);

                        }

                    } finally {

                        if (DEBUG_STORE_ENABLED) {

                            DebugStore.recordEventEnd(debugStoreId);

                        }

                    }



                    if (receiver.getPendingResult() != null) {

core/java/android/content/BroadcastReceiver.java

+2 −2
Original line number Diff line number Diff line
@@ -263,7 +263,7 @@ public abstract class BroadcastReceiver { 
                        1);

            }

            if (DEBUG_STORE_ENABLED) {

                DebugStore.recordFinish(mReceiverClassName);

                DebugStore.recordFinish(System.identityHashCode(this));

            }



            if (mType == TYPE_COMPONENT) {
@@ -445,7 +445,7 @@ public abstract class BroadcastReceiver { 
        PendingResult res = mPendingResult;

        mPendingResult = null;

        if (DEBUG_STORE_ENABLED) {

            DebugStore.recordGoAsync(getClass().getName());

            DebugStore.recordGoAsync(System.identityHashCode(res));

        }

        if (res != null && Trace.isTagEnabled(Trace.TRACE_TAG_ACTIVITY_MANAGER)) {

            res.mReceiverClassName = getClass().getName();

core/java/com/android/internal/os/DebugStore.java

+120 −14
Original line number Diff line number Diff line
@@ -20,6 +20,7 @@ import android.annotation.Nullable; 
import android.compat.annotation.UnsupportedAppUsage;

import android.content.Intent;

import android.content.pm.ServiceInfo;

import android.util.Log;



import com.android.internal.annotations.VisibleForTesting;
@@ -43,6 +44,9 @@ import java.util.Objects; 
 * @hide

 */

public class DebugStore {

    private static final boolean DEBUG_EVENTS = false;

    private static final String TAG = "DebugStore";



    private static DebugStoreNative sDebugStoreNative = new DebugStoreNativeImpl();



    @UnsupportedAppUsage
@@ -120,7 +124,7 @@ public class DebugStore { 
     * @param receiverClassName The class name of the broadcast receiver.

     */

    @UnsupportedAppUsage

    public static void recordGoAsync(String receiverClassName) {

    public static void recordGoAsync(int pendingResultId) {

        sDebugStoreNative.recordEvent(

                "GoAsync",

                List.of(
@@ -128,8 +132,8 @@ public class DebugStore { 
                        Thread.currentThread().getName(),

                        "tid",

                        String.valueOf(Thread.currentThread().getId()),

                        "rcv",

                        Objects.toString(receiverClassName)));

                        "prid",

                        Integer.toHexString(pendingResultId)));

    }



    /**
@@ -138,7 +142,7 @@ public class DebugStore { 
     * @param receiverClassName The class of the broadcast receiver that completed the operation.

     */

    @UnsupportedAppUsage

    public static void recordFinish(String receiverClassName) {

    public static void recordFinish(int pendingResultId) {

        sDebugStoreNative.recordEvent(

                "Finish",

                List.of(
@@ -146,9 +150,10 @@ public class DebugStore { 
                        Thread.currentThread().getName(),

                        "tid",

                        String.valueOf(Thread.currentThread().getId()),

                        "rcv",

                        Objects.toString(receiverClassName)));

                        "prid",

                        Integer.toHexString(pendingResultId)));

    }



    /**

     * Records the completion of a long-running looper message.

     *
@@ -172,21 +177,92 @@ public class DebugStore { 




    /**

     * Records the reception of a broadcast.

     * Records the reception of a broadcast by a manifest-declared receiver.

     *

     * @param intent The Intent associated with the broadcast.

     * @return A unique ID for the recorded event.

     */

    @UnsupportedAppUsage

    public static long recordBroadcastReceive(@Nullable Intent intent, int pendingResultId) {

        return sDebugStoreNative.beginEvent(

                "BcRcv",

                List.of(

                        "tname",

                        Thread.currentThread().getName(),

                        "tid",

                        String.valueOf(Thread.currentThread().getId()),

                        "act",

                        Objects.toString(intent != null ? intent.getAction() : null),

                        "cmp",

                        Objects.toString(intent != null ? intent.getComponent() : null),

                        "pkg",

                        Objects.toString(intent != null ? intent.getPackage() : null),

                        "prid",

                        Integer.toHexString(pendingResultId)));

    }



    /**

     * Records the reception of a broadcast by a context-registered receiver.

     *

     * @param intent The Intent associated with the broadcast.

     * @param pendingResultId The object ID of the PendingResult associated with the broadcast.

     * @return A unique ID for the recorded event.

     */

    @UnsupportedAppUsage

    public static long recordBroadcastHandleReceiver(@Nullable Intent intent) {

    public static long recordBroadcastReceiveReg(@Nullable Intent intent, int pendingResultId) {

        return sDebugStoreNative.beginEvent(

                "HandleReceiver",

                "BcRcvReg",

                List.of(

                        "tname",

                        Thread.currentThread().getName(),

                        "tid",

                        String.valueOf(Thread.currentThread().getId()),

                        "act",

                        Objects.toString(intent != null ? intent.getAction() : null),

                        "cmp",

                        Objects.toString(intent != null ? intent.getComponent() : null),

                        "pkg",

                        Objects.toString(intent != null ? intent.getPackage() : null),

                        "prid",

                        Integer.toHexString(pendingResultId)));

    }



    /**

     * Records the binding of an application.

     *

     * @return A unique ID for the recorded event.

     */

    @UnsupportedAppUsage

    public static long recordHandleBindApplication() {

        return sDebugStoreNative.beginEvent("BindApp", List.of());

    }



    /**

     * Records the scheduling of a receiver.

     *

     * @return A unique ID for the recorded event.

     */

    @UnsupportedAppUsage

    public static long recordScheduleReceiver() {

        return sDebugStoreNative.beginEvent(

                "SchRcv",

                List.of(

                        "tname", Thread.currentThread().getName(),

                        "tid", String.valueOf(Thread.currentThread().getId()),

                        "act", Objects.toString(intent != null ? intent.getAction() : null),

                        "cmp", Objects.toString(intent != null ? intent.getComponent() : null),

                        "pkg", Objects.toString(intent != null ? intent.getPackage() : null)));

                        "tid", String.valueOf(Thread.currentThread().getId())));

    }



    /**

     * Records the scheduling of a registered receiver.

     *

     * @return A unique ID for the recorded event.

     */

    @UnsupportedAppUsage

    public static long recordScheduleRegisteredReceiver() {

        return sDebugStoreNative.beginEvent(

                "SchRcvReg",

                List.of(

                        "tname", Thread.currentThread().getName(),

                        "tid", String.valueOf(Thread.currentThread().getId())));

    }



    /**
@@ -225,18 +301,48 @@ public class DebugStore { 
    private static class DebugStoreNativeImpl implements DebugStoreNative {

        @Override

        public long beginEvent(String eventName, List<String> attributes) {

            return DebugStore.beginEventNative(eventName, attributes);

            long id = DebugStore.beginEventNative(eventName, attributes);

            if (DEBUG_EVENTS) {

                Log.i(

                        TAG,

                        "beginEvent: " + id + " " + eventName + " " + attributeString(attributes));

            }

            return id;

        }



        @Override

        public void endEvent(long id, List<String> attributes) {

            if (DEBUG_EVENTS) {

                Log.i(TAG, "endEvent: " + id + " " + attributeString(attributes));

            }

            DebugStore.endEventNative(id, attributes);

        }



        @Override

        public void recordEvent(String eventName, List<String> attributes) {

            if (DEBUG_EVENTS) {

                Log.i(TAG, "recordEvent: " + eventName + " " + attributeString(attributes));

            }

            DebugStore.recordEventNative(eventName, attributes);

        }



        /**

         * Returns a string like "[key1=foo, key2=bar]"

         */

        private String attributeString(List<String> attributes) {

            StringBuilder sb = new StringBuilder().append("[");



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

                sb.append(attributes.get(i));



                if (i % 2 == 0) {

                    sb.append("=");

                } else if (i < attributes.size() - 1) {

                    sb.append(", ");

                }

            }

            return sb.append("]").toString();

        }

    }



    private static native long beginEventNative(String eventName, List<String> attributes);

core/tests/coretests/src/com/android/internal/os/DebugStoreTest.java

+214 −140

File changed.

Preview size limit exceeded, changes collapsed.