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

Commit 7a61c7a8 authored by TreeHugger Robot's avatar TreeHugger Robot Committed by Automerger Merge Worker
Browse files

Merge "Log the duration of executing all receivers of LOCKED_BOOT_COMPLETED or...

Merge "Log the duration of executing all receivers of LOCKED_BOOT_COMPLETED or BOOT_COMPLETED broadcast." into tm-dev am: fc40aa79

Original change: https://googleplex-android-review.googlesource.com/c/platform/frameworks/base/+/17143804

Change-Id: I1704b91fa5fc5c19fb39c81ad9f661944a62cf85
parents 822294ec fc40aa79
Loading
Loading
Loading
Loading
+67 −0
Original line number Diff line number Diff line
@@ -21,6 +21,9 @@ import static android.os.Process.ZYGOTE_POLICY_FLAG_EMPTY;
import static android.os.Process.ZYGOTE_POLICY_FLAG_LATENCY_SENSITIVE;
import static android.text.TextUtils.formatSimple;

import static com.android.internal.util.FrameworkStatsLog.BOOT_COMPLETED_BROADCAST_COMPLETION_LATENCY_REPORTED;
import static com.android.internal.util.FrameworkStatsLog.BOOT_COMPLETED_BROADCAST_COMPLETION_LATENCY_REPORTED__EVENT__BOOT_COMPLETED;
import static com.android.internal.util.FrameworkStatsLog.BOOT_COMPLETED_BROADCAST_COMPLETION_LATENCY_REPORTED__EVENT__LOCKED_BOOT_COMPLETED;
import static com.android.server.am.ActivityManagerDebugConfig.DEBUG_BROADCAST;
import static com.android.server.am.ActivityManagerDebugConfig.DEBUG_BROADCAST_DEFERRAL;
import static com.android.server.am.ActivityManagerDebugConfig.DEBUG_BROADCAST_LIGHT;
@@ -29,6 +32,7 @@ import static com.android.server.am.ActivityManagerDebugConfig.DEBUG_PERMISSIONS
import static com.android.server.am.ActivityManagerDebugConfig.POSTFIX_BROADCAST;
import static com.android.server.am.ActivityManagerDebugConfig.POSTFIX_MU;


import android.annotation.NonNull;
import android.annotation.Nullable;
import android.app.ActivityManager;
@@ -51,6 +55,7 @@ import android.content.pm.ApplicationInfo;
import android.content.pm.PackageManager;
import android.content.pm.PermissionInfo;
import android.content.pm.ResolveInfo;
import android.content.pm.UserInfo;
import android.os.Bundle;
import android.os.Handler;
import android.os.IBinder;
@@ -64,6 +69,7 @@ import android.os.RemoteException;
import android.os.SystemClock;
import android.os.Trace;
import android.os.UserHandle;
import android.os.UserManager;
import android.permission.IPermissionManager;
import android.text.TextUtils;
import android.util.EventLog;
@@ -75,6 +81,7 @@ import android.util.proto.ProtoOutputStream;
import com.android.internal.util.ArrayUtils;
import com.android.internal.util.FrameworkStatsLog;
import com.android.server.LocalServices;
import com.android.server.pm.UserManagerInternal;

import java.io.FileDescriptor;
import java.io.PrintWriter;
@@ -250,12 +257,16 @@ public final class BroadcastQueue {

    public void enqueueParallelBroadcastLocked(BroadcastRecord r) {
        r.enqueueClockTime = System.currentTimeMillis();
        r.enqueueTime = SystemClock.uptimeMillis();
        r.enqueueRealTime = SystemClock.elapsedRealtime();
        mParallelBroadcasts.add(r);
        enqueueBroadcastHelper(r);
    }

    public void enqueueOrderedBroadcastLocked(BroadcastRecord r) {
        r.enqueueClockTime = System.currentTimeMillis();
        r.enqueueTime = SystemClock.uptimeMillis();
        r.enqueueRealTime = SystemClock.elapsedRealtime();
        mDispatcher.enqueueOrderedBroadcastLocked(r);
        enqueueBroadcastHelper(r);
    }
@@ -1121,6 +1132,7 @@ public final class BroadcastQueue {
        while (mParallelBroadcasts.size() > 0) {
            r = mParallelBroadcasts.remove(0);
            r.dispatchTime = SystemClock.uptimeMillis();
            r.dispatchRealTime = SystemClock.elapsedRealtime();
            r.dispatchClockTime = System.currentTimeMillis();

            if (Trace.isTagEnabled(Trace.TRACE_TAG_ACTIVITY_MANAGER)) {
@@ -1292,6 +1304,7 @@ public final class BroadcastQueue {
                            performReceiveLocked(r.callerApp, r.resultTo,
                                    new Intent(r.intent), r.resultCode,
                                    r.resultData, r.resultExtras, false, false, r.userId);
                            logBootCompletedBroadcastCompletionLatencyIfPossible(r);
                            // Set this to null so that the reference
                            // (local and remote) isn't kept in the mBroadcastHistory.
                            r.resultTo = null;
@@ -1408,6 +1421,7 @@ public final class BroadcastQueue {
        r.receiverTime = SystemClock.uptimeMillis();
        if (recIdx == 0) {
            r.dispatchTime = r.receiverTime;
            r.dispatchRealTime = SystemClock.elapsedRealtime();
            r.dispatchClockTime = System.currentTimeMillis();

            if (mLogLatencyMetrics) {
@@ -1866,6 +1880,59 @@ public final class BroadcastQueue {
        return null;
    }

    private void logBootCompletedBroadcastCompletionLatencyIfPossible(BroadcastRecord r) {
        // Only log after last receiver.
        // In case of split BOOT_COMPLETED broadcast, make sure only call this method on the
        // last BroadcastRecord of the split broadcast which has non-null resultTo.
        final int numReceivers = (r.receivers != null) ? r.receivers.size() : 0;
        if (r.nextReceiver < numReceivers) {
            return;
        }
        final String action = r.intent.getAction();
        int event = 0;
        if (Intent.ACTION_LOCKED_BOOT_COMPLETED.equals(action)) {
            event = BOOT_COMPLETED_BROADCAST_COMPLETION_LATENCY_REPORTED__EVENT__LOCKED_BOOT_COMPLETED;
        } else if (Intent.ACTION_BOOT_COMPLETED.equals(action)) {
            event = BOOT_COMPLETED_BROADCAST_COMPLETION_LATENCY_REPORTED__EVENT__BOOT_COMPLETED;
        }
        if (event != 0) {
            final int dispatchLatency = (int)(r.dispatchTime - r.enqueueTime);
            final int completeLatency = (int)
                    (SystemClock.uptimeMillis() - r.enqueueTime);
            final int dispatchRealLatency = (int)(r.dispatchRealTime - r.enqueueRealTime);
            final int completeRealLatency = (int)
                    (SystemClock.elapsedRealtime() - r.enqueueRealTime);
            int userType = FrameworkStatsLog.USER_LIFECYCLE_JOURNEY_REPORTED__USER_TYPE__TYPE_UNKNOWN;
            // This method is called very infrequently, no performance issue we call
            // LocalServices.getService() here.
            final UserManagerInternal umInternal = LocalServices.getService(
                    UserManagerInternal.class);
            final UserInfo userInfo = umInternal.getUserInfo(r.userId);
            if (userInfo != null) {
                userType = UserManager.getUserTypeForStatsd(userInfo.userType);
            }
            Slog.i(TAG_BROADCAST,
                    "BOOT_COMPLETED_BROADCAST_COMPLETION_LATENCY_REPORTED action:"
                            + action
                            + " dispatchLatency:" + dispatchLatency
                            + " completeLatency:" + completeLatency
                            + " dispatchRealLatency:" + dispatchRealLatency
                            + " completeRealLatency:" + completeRealLatency
                            + " receiversSize:" + r.receivers.size()
                            + " userId:" + r.userId
                            + " userType:" + (userInfo != null? userInfo.userType : null));
            FrameworkStatsLog.write(
                    BOOT_COMPLETED_BROADCAST_COMPLETION_LATENCY_REPORTED,
                    event,
                    dispatchLatency,
                    completeLatency,
                    dispatchRealLatency,
                    completeRealLatency,
                    r.userId,
                    userType);
        }
    }

    private void maybeReportBroadcastDispatchedEventLocked(BroadcastRecord r, int targetUid) {
        // STOPSHIP (217251579): Temporarily use temp-allowlist reason to identify
        // push messages and record response events.
+14 −4
Original line number Diff line number Diff line
@@ -84,11 +84,14 @@ final class BroadcastRecord extends Binder {
    boolean deferred;
    int splitCount;         // refcount for result callback, when split
    int splitToken;         // identifier for cross-BroadcastRecord refcount
    long enqueueTime;       // uptimeMillis when the broadcast was enqueued
    long enqueueRealTime;   // elapsedRealtime when the broadcast was enqueued
    long enqueueClockTime;  // the clock time the broadcast was enqueued
    long dispatchTime;      // when dispatch started on this set of receivers
    long dispatchRealTime;  // elapsedRealtime when the broadcast was dispatched
    long dispatchClockTime; // the clock time the dispatch started
    long receiverTime;      // when current receiver started for timeouts.
    long finishTime;        // when we finished the broadcast.
    long finishTime;        // when we finished the current receiver.
    boolean timeoutExempt;  // true if this broadcast is not subject to receiver timeouts
    int resultCode;         // current result code value.
    String resultData;      // current result data value.
@@ -169,7 +172,7 @@ final class BroadcastRecord extends Binder {
        pw.print(prefix); pw.print("dispatchTime=");
                TimeUtils.formatDuration(dispatchTime, now, pw);
                pw.print(" (");
                TimeUtils.formatDuration(dispatchClockTime-enqueueClockTime, pw);
                TimeUtils.formatDuration(dispatchTime - enqueueTime, pw);
                pw.print(" since enq)");
        if (finishTime != 0) {
            pw.print(" finishTime="); TimeUtils.formatDuration(finishTime, now, pw);
@@ -324,8 +327,11 @@ final class BroadcastRecord extends Binder {
        delivery = from.delivery;
        duration = from.duration;
        resultTo = from.resultTo;
        enqueueTime = from.enqueueTime;
        enqueueRealTime = from.enqueueRealTime;
        enqueueClockTime = from.enqueueClockTime;
        dispatchTime = from.dispatchTime;
        dispatchRealTime = from.dispatchRealTime;
        dispatchClockTime = from.dispatchClockTime;
        receiverTime = from.receiverTime;
        finishTime = from.finishTime;
@@ -378,7 +384,9 @@ final class BroadcastRecord extends Binder {
                requiredPermissions, excludedPermissions, appOp, options, splitReceivers, resultTo,
                resultCode, resultData, resultExtras, ordered, sticky, initialSticky, userId,
                allowBackgroundActivityStarts, mBackgroundActivityStartsToken, timeoutExempt);

        split.enqueueTime = this.enqueueTime;
        split.enqueueRealTime = this.enqueueRealTime;
        split.enqueueClockTime = this.enqueueClockTime;
        split.splitToken = this.splitToken;
        return split;
    }
@@ -448,9 +456,11 @@ final class BroadcastRecord extends Binder {
            final BroadcastRecord br = new BroadcastRecord(queue, intent, callerApp, callerPackage,
                    callerFeatureId, callingPid, callingUid, callerInstantApp, resolvedType,
                    requiredPermissions, excludedPermissions, appOp, options,
                    uid2receiverList.valueAt(i), resultTo,
                    uid2receiverList.valueAt(i), null /* _resultTo */,
                    resultCode, resultData, resultExtras, ordered, sticky, initialSticky, userId,
                    allowBackgroundActivityStarts, mBackgroundActivityStartsToken, timeoutExempt);
            br.enqueueTime = this.enqueueTime;
            br.enqueueRealTime = this.enqueueRealTime;
            br.enqueueClockTime = this.enqueueClockTime;
            ret.put(uid2receiverList.keyAt(i), br);
        }