summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
-rw-r--r--services/core/java/com/android/server/am/BroadcastQueue.java67
-rw-r--r--services/core/java/com/android/server/am/BroadcastRecord.java18
2 files changed, 81 insertions, 4 deletions
diff --git a/services/core/java/com/android/server/am/BroadcastQueue.java b/services/core/java/com/android/server/am/BroadcastQueue.java
index ea63c080cf68..ade44eac4583 100644
--- a/services/core/java/com/android/server/am/BroadcastQueue.java
+++ b/services/core/java/com/android/server/am/BroadcastQueue.java
@@ -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.
diff --git a/services/core/java/com/android/server/am/BroadcastRecord.java b/services/core/java/com/android/server/am/BroadcastRecord.java
index 8b1e829ad836..2ee32b6abe96 100644
--- a/services/core/java/com/android/server/am/BroadcastRecord.java
+++ b/services/core/java/com/android/server/am/BroadcastRecord.java
@@ -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);
}