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

Commit 22d80bdd authored by Mohamad Mahmoud's avatar Mohamad Mahmoud
Browse files

Integrate the Debug store into frameworks

Introduce debug store to frameworks, and collect data from various events in ActivityThread
for more information, see b/314735374 and b/314735374#comment5

Flag: debug_store_enabled
Bug: 314735374
Test: atest && m && manual testing
Change-Id: I2b3481ae949ef78414dc213c3e1579039791ed31
parent 037392f3
Loading
Loading
Loading
Loading
+80 −8
Original line number Diff line number Diff line
@@ -232,6 +232,7 @@ import com.android.internal.app.IVoiceInteractor;
import com.android.internal.content.ReferrerIntent;
import com.android.internal.os.BinderCallsStats;
import com.android.internal.os.BinderInternal;
import com.android.internal.os.DebugStore;
import com.android.internal.os.RuntimeInit;
import com.android.internal.os.SafeZipPathValidatorCallback;
import com.android.internal.os.SomeArgs;
@@ -358,6 +359,15 @@ public final class ActivityThread extends ClientTransactionHandler
    private static final long BINDER_CALLBACK_THROTTLE = 10_100L;
    private long mBinderCallbackLast = -1;

    private static final boolean DEBUG_STORE_ENABLED =
            com.android.internal.os.Flags.debugStoreEnabled();

    /**
    * Threshold for identifying long-running looper messages (in milliseconds).
    * Calculated as 2 seconds multiplied by the hardware timeout multiplier.
    */
    private static final long LONG_MESSAGE_THRESHOLD_MS = 2000 * Build.HW_TIMEOUT_MULTIPLIER;

    /**
     * Denotes the sequence number of the process state change for which the main thread needs
     * to block until the network rules are updated for it.
@@ -2409,6 +2419,12 @@ public final class ActivityThread extends ClientTransactionHandler
        }
        public void handleMessage(Message msg) {
            if (DEBUG_MESSAGES) Slog.v(TAG, ">>> handling: " + codeToString(msg.what));
            long debugStoreId = -1;
            // By default, log all long messages when the debug store is enabled,
            // unless this is overridden for certain message types, for which we have
            // more granular debug store logging.
            boolean shouldLogLongMessage = DEBUG_STORE_ENABLED;
            final long messageStartUptimeMs = SystemClock.uptimeMillis();
            switch (msg.what) {
                case BIND_APPLICATION:
                    Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "bindApplication");
@@ -2433,24 +2449,61 @@ public final class ActivityThread extends ClientTransactionHandler
                                    "broadcastReceiveComp");
                        }
                    }
                    handleReceiver((ReceiverData)msg.obj);
                    ReceiverData receiverData = (ReceiverData) msg.obj;
                    if (DEBUG_STORE_ENABLED) {
                        debugStoreId =
                                DebugStore.recordBroadcastHandleReceiver(receiverData.intent);
                    }

                    try {
                        handleReceiver(receiverData);
                    } finally {
                        Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
                        if (DEBUG_STORE_ENABLED) {
                            DebugStore.recordEventEnd(debugStoreId);
                            shouldLogLongMessage = false;
                        }
                    }
                    break;
                case CREATE_SERVICE:
                    if (Trace.isTagEnabled(Trace.TRACE_TAG_ACTIVITY_MANAGER)) {
                        Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
                                ("serviceCreate: " + String.valueOf(msg.obj)));
                    }
                    handleCreateService((CreateServiceData)msg.obj);
                    CreateServiceData createServiceData = (CreateServiceData) msg.obj;
                    if (DEBUG_STORE_ENABLED) {
                        debugStoreId = DebugStore.recordServiceCreate(createServiceData.info);
                    }

                    try {
                        handleCreateService(createServiceData);
                    } finally {
                        Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
                        if (DEBUG_STORE_ENABLED) {
                            DebugStore.recordEventEnd(debugStoreId);
                            shouldLogLongMessage = false;
                        }
                    }
                    break;
                case BIND_SERVICE:
                    if (Trace.isTagEnabled(Trace.TRACE_TAG_ACTIVITY_MANAGER)) {
                        Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "serviceBind: "
                                + String.valueOf(msg.obj));
                    }
                    handleBindService((BindServiceData)msg.obj);
                    BindServiceData bindData = (BindServiceData) msg.obj;
                    if (DEBUG_STORE_ENABLED) {
                        debugStoreId =
                                DebugStore.recordServiceBind(bindData.rebind, bindData.intent);
                    }
                    try {
                        handleBindService(bindData);
                    } finally {
                        Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
                        if (DEBUG_STORE_ENABLED) {
                            DebugStore.recordEventEnd(debugStoreId);
                            shouldLogLongMessage = false;
                        }
                    }
                    break;
                case UNBIND_SERVICE:
                    if (Trace.isTagEnabled(Trace.TRACE_TAG_ACTIVITY_MANAGER)) {
@@ -2466,8 +2519,21 @@ public final class ActivityThread extends ClientTransactionHandler
                        Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
                                ("serviceStart: " + String.valueOf(msg.obj)));
                    }
                    handleServiceArgs((ServiceArgsData)msg.obj);
                    ServiceArgsData serviceData = (ServiceArgsData) msg.obj;
                    if (DEBUG_STORE_ENABLED) {
                        debugStoreId = DebugStore.recordServiceOnStart(serviceData.startId,
                                serviceData.flags, serviceData.args);
                    }

                    try {
                        handleServiceArgs(serviceData);
                    } finally {
                        Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
                        if (DEBUG_STORE_ENABLED) {
                            DebugStore.recordEventEnd(debugStoreId);
                            shouldLogLongMessage = false;
                        }
                    }
                    break;
                case STOP_SERVICE:
                    if (Trace.isTagEnabled(Trace.TRACE_TAG_ACTIVITY_MANAGER)) {
@@ -2670,11 +2736,17 @@ public final class ActivityThread extends ClientTransactionHandler
                    handleFinishInstrumentationWithoutRestart();
                    break;
            }
            long messageElapsedTimeMs = SystemClock.uptimeMillis() - messageStartUptimeMs;
            Object obj = msg.obj;
            if (obj instanceof SomeArgs) {
                ((SomeArgs) obj).recycle();
            }
            if (DEBUG_MESSAGES) Slog.v(TAG, "<<< done: " + codeToString(msg.what));
            if (shouldLogLongMessage
                    && messageElapsedTimeMs > LONG_MESSAGE_THRESHOLD_MS) {
                DebugStore.recordLongLooperMessage(msg.what, msg.getTarget().getClass().getName(),
                        messageElapsedTimeMs);
            }
        }
    }

+11 −1
Original line number Diff line number Diff line
@@ -34,6 +34,8 @@ import android.os.UserHandle;
import android.util.Log;
import android.util.Slog;

import com.android.internal.os.DebugStore;

/**
 * Base class for code that receives and handles broadcast intents sent by
 * {@link android.content.Context#sendBroadcast(Intent)}.
@@ -55,6 +57,9 @@ public abstract class BroadcastReceiver {
    private PendingResult mPendingResult;
    private boolean mDebugUnregister;

    private static final boolean DEBUG_STORE_ENABLED =
            com.android.internal.os.Flags.debugStoreEnabled();

    /**
     * State for a result that is pending for a broadcast receiver.  Returned
     * by {@link BroadcastReceiver#goAsync() goAsync()}
@@ -255,6 +260,9 @@ public abstract class BroadcastReceiver {
                        "PendingResult#finish#ClassName:" + mReceiverClassName,
                        1);
            }
            if (DEBUG_STORE_ENABLED) {
                DebugStore.recordFinish(mReceiverClassName);
            }

            if (mType == TYPE_COMPONENT) {
                final IActivityManager mgr = ActivityManager.getService();
@@ -433,7 +441,9 @@ public abstract class BroadcastReceiver {
    public final PendingResult goAsync() {
        PendingResult res = mPendingResult;
        mPendingResult = null;

        if (DEBUG_STORE_ENABLED) {
            DebugStore.recordGoAsync(getClass().getName());
        }
        if (res != null && Trace.isTagEnabled(Trace.TRACE_TAG_ACTIVITY_MANAGER)) {
            res.mReceiverClassName = getClass().getName();
            Trace.traceCounter(Trace.TRACE_TAG_ACTIVITY_MANAGER,
+247 −0
Original line number Diff line number Diff line
/*
 * Copyright (C) 2024 The Android Open Source Project
 *
 * Licensed under the Apache License, Version 2.0 (the "License");
 * you may not use this file except in compliance with the License.
 * You may obtain a copy of the License at
 *
 *      http://www.apache.org/licenses/LICENSE-2.0
 *
 * Unless required by applicable law or agreed to in writing, software
 * distributed under the License is distributed on an "AS IS" BASIS,
 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 * See the License for the specific language governing permissions and
 * limitations under the License.
 */

package com.android.internal.os;

import android.annotation.Nullable;
import android.compat.annotation.UnsupportedAppUsage;
import android.content.Intent;
import android.content.pm.ServiceInfo;

import com.android.internal.annotations.VisibleForTesting;

import java.util.Collections;
import java.util.List;
import java.util.Objects;


/**
 * The DebugStore class provides methods for recording various debug events related to service
 * lifecycle, broadcast receivers and others.
 * The DebugStore class facilitates debugging ANR issues by recording time-stamped events
 * related to service lifecycles, broadcast receivers, and other framework operations. It logs
 * the start and end times of operations within the ANR timer scope called  by framework,
 * enabling pinpointing of methods and events contributing to ANRs.
 *
 * Usage currently includes recording service starts, binds, and asynchronous operations initiated
 * by broadcast receivers, providing a granular view of system behavior that facilitates
 * identifying performance bottlenecks and optimizing issue resolution.
 *
 * @hide
 */
public class DebugStore {
    private static DebugStoreNative sDebugStoreNative = new DebugStoreNativeImpl();

    @UnsupportedAppUsage
    @VisibleForTesting
    public static void setDebugStoreNative(DebugStoreNative nativeImpl) {
        sDebugStoreNative = nativeImpl;
    }
    /**
     * Records the start of a service.
     *
     * @param startId The start ID of the service.
     * @param flags Additional flags for the service start.
     * @param intent The Intent associated with the service start.
     * @return A unique ID for the recorded event.
     */
    @UnsupportedAppUsage
    public static long recordServiceOnStart(int startId, int flags, @Nullable Intent intent) {
        return sDebugStoreNative.beginEvent(
                "SvcStart",
                List.of(
                        "stId",
                        String.valueOf(startId),
                        "flg",
                        Integer.toHexString(flags),
                        "act",
                        Objects.toString(intent != null ? intent.getAction() : null),
                        "comp",
                        Objects.toString(intent != null ? intent.getComponent() : null),
                        "pkg",
                        Objects.toString(intent != null ? intent.getPackage() : null)));
    }

    /**
     * Records the creation of a service.
     *
     * @param serviceInfo Information about the service being created.
     * @return A unique ID for the recorded event.
     */
    @UnsupportedAppUsage
    public static long recordServiceCreate(@Nullable ServiceInfo serviceInfo) {
        return sDebugStoreNative.beginEvent(
                "SvcCreate",
                List.of(
                        "name",
                        Objects.toString(serviceInfo != null ? serviceInfo.name : null),
                        "pkg",
                        Objects.toString(serviceInfo != null ? serviceInfo.packageName : null)));
    }

    /**
     * Records the binding of a service.
     *
     * @param isRebind Indicates whether the service is being rebound.
     * @param intent The Intent associated with the service binding.
     * @return A unique identifier for the recorded event.
     */
    @UnsupportedAppUsage
    public static long recordServiceBind(boolean isRebind, @Nullable Intent intent) {
        return sDebugStoreNative.beginEvent(
                "SvcBind",
                List.of(
                        "rebind",
                        String.valueOf(isRebind),
                        "act",
                        Objects.toString(intent != null ? intent.getAction() : null),
                        "cmp",
                        Objects.toString(intent != null ? intent.getComponent() : null),
                        "pkg",
                        Objects.toString(intent != null ? intent.getPackage() : null)));
    }

    /**
     * Records an asynchronous operation initiated by a broadcast receiver through calling GoAsync.
     *
     * @param receiverClassName The class name of the broadcast receiver.
     */
    @UnsupportedAppUsage
    public static void recordGoAsync(String receiverClassName) {
        sDebugStoreNative.recordEvent(
                "GoAsync",
                List.of(
                        "tname",
                        Thread.currentThread().getName(),
                        "tid",
                        String.valueOf(Thread.currentThread().getId()),
                        "rcv",
                        Objects.toString(receiverClassName)));
    }

    /**
     * Records the completion of a broadcast operation through calling Finish.
     *
     * @param receiverClassName The class of the broadcast receiver that completed the operation.
     */
    @UnsupportedAppUsage
    public static void recordFinish(String receiverClassName) {
        sDebugStoreNative.recordEvent(
                "Finish",
                List.of(
                        "tname",
                        Thread.currentThread().getName(),
                        "tid",
                        String.valueOf(Thread.currentThread().getId()),
                        "rcv",
                        Objects.toString(receiverClassName)));
    }
    /**
     * Records the completion of a long-running looper message.
     *
     * @param messageCode The code representing the type of the message.
     * @param targetClass The FQN of the class that handled the message.
     * @param elapsedTimeMs The time that was taken to process the message, in milliseconds.
     */
    @UnsupportedAppUsage
    public static void recordLongLooperMessage(int messageCode, String targetClass,
            long elapsedTimeMs) {
        sDebugStoreNative.recordEvent(
                "LooperMsg",
                List.of(
                        "code",
                        String.valueOf(messageCode),
                        "trgt",
                        Objects.toString(targetClass),
                        "elapsed",
                        String.valueOf(elapsedTimeMs)));
    }


    /**
     * Records the reception of a broadcast.
     *
     * @param intent The Intent associated with the broadcast.
     * @return A unique ID for the recorded event.
     */
    @UnsupportedAppUsage
    public static long recordBroadcastHandleReceiver(@Nullable Intent intent) {
        return sDebugStoreNative.beginEvent(
                "HandleReceiver",
                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)));
    }

    /**
     * Ends a previously recorded event.
     *
     * @param id The unique ID of the event to be ended.
     */
    @UnsupportedAppUsage
    public static void recordEventEnd(long id) {
        sDebugStoreNative.endEvent(id, Collections.emptyList());
    }

    /**
     * An interface for a class that acts as a wrapper for the static native methods
     * of the Debug Store.
     *
     * It allows us to mock static native methods in our tests and should be removed
     * once mocking static methods becomes easier.
     */
    @VisibleForTesting
    public interface DebugStoreNative {
        /**
         * Begins an event with the given name and attributes.
         */
        long beginEvent(String eventName, List<String> attributes);
        /**
         * Ends an event with the given ID and attributes.
         */
        void endEvent(long id, List<String> attributes);
        /**
         * Records an event with the given name and attributes.
         */
        void recordEvent(String eventName, List<String> attributes);
    }

    private static class DebugStoreNativeImpl implements DebugStoreNative {
        @Override
        public long beginEvent(String eventName, List<String> attributes) {
            return DebugStore.beginEventNative(eventName, attributes);
        }

        @Override
        public void endEvent(long id, List<String> attributes) {
            DebugStore.endEventNative(id, attributes);
        }

        @Override
        public void recordEvent(String eventName, List<String> attributes) {
            DebugStore.recordEventNative(eventName, attributes);
        }
    }

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

    private static native void endEventNative(long id, List<String> attributes);

    private static native void recordEventNative(String eventName, List<String> attributes);
}
+8 −0
Original line number Diff line number Diff line
@@ -20,3 +20,11 @@ flag {
        purpose: PURPOSE_BUGFIX
    }
}

flag {
    name: "debug_store_enabled"
    namespace: "stability"
    description: "If the debug store is enabled."
    bug: "314735374"
    is_fixed_read_only: true
}
 No newline at end of file
+2 −0
Original line number Diff line number Diff line
@@ -259,6 +259,7 @@ cc_library_shared_for_libandroid_runtime {
                "com_android_internal_content_om_OverlayManagerImpl.cpp",
                "com_android_internal_net_NetworkUtilsInternal.cpp",
                "com_android_internal_os_ClassLoaderFactory.cpp",
                "com_android_internal_os_DebugStore.cpp",
                "com_android_internal_os_FuseAppLoop.cpp",
                "com_android_internal_os_KernelAllocationStats.cpp",
                "com_android_internal_os_KernelCpuBpfTracking.cpp",
@@ -315,6 +316,7 @@ cc_library_shared_for_libandroid_runtime {
                "libcrypto",
                "libcutils",
                "libdebuggerd_client",
                "libdebugstore_cxx",
                "libutils",
                "libbinder",
                "libbinderdebug",
Loading