Fix issue #29006049: Add logging for implicit broadcasts

am: bc02a3901d

* commit 'bc02a3901dea52d236dd855722191155156cb856':
  Fix issue #29006049: Add logging for implicit broadcasts

Change-Id: Ifd88a4ce68bd9c2853d085bb10f74df682ae8ee6
This commit is contained in:
Dianne Hackborn
2016-06-05 18:17:01 +00:00
committed by android-build-merger
6 changed files with 307 additions and 8 deletions

View File

@@ -41,7 +41,6 @@ import com.android.internal.util.FastPrintWriter;
import com.android.internal.util.FastXmlSerializer;
import com.android.internal.util.MemInfoReader;
import com.android.internal.util.Preconditions;
import com.android.internal.util.ProgressReporter;
import com.android.server.AppOpsService;
import com.android.server.AttributeCache;
import com.android.server.DeviceIdleController;
@@ -98,7 +97,6 @@ import android.app.IUiAutomationConnection;
import android.app.IUidObserver;
import android.app.IUserSwitchObserver;
import android.app.Instrumentation;
import android.app.KeyguardManager;
import android.app.Notification;
import android.app.NotificationManager;
import android.app.PendingIntent;
@@ -259,12 +257,10 @@ import static android.Manifest.permission.START_TASKS_FROM_RECENTS;
import static android.app.ActivityManager.DOCKED_STACK_CREATE_MODE_TOP_OR_LEFT;
import static android.app.ActivityManager.RESIZE_MODE_PRESERVE_WINDOW;
import static android.app.ActivityManager.StackId.DOCKED_STACK_ID;
import static android.app.ActivityManager.StackId.FIRST_STATIC_STACK_ID;
import static android.app.ActivityManager.StackId.FREEFORM_WORKSPACE_STACK_ID;
import static android.app.ActivityManager.StackId.FULLSCREEN_WORKSPACE_STACK_ID;
import static android.app.ActivityManager.StackId.HOME_STACK_ID;
import static android.app.ActivityManager.StackId.INVALID_STACK_ID;
import static android.app.ActivityManager.StackId.LAST_STATIC_STACK_ID;
import static android.app.ActivityManager.StackId.PINNED_STACK_ID;
import static android.content.pm.PackageManager.FEATURE_FREEFORM_WINDOW_MANAGEMENT;
import static android.content.pm.PackageManager.FEATURE_LEANBACK_ONLY;
@@ -570,6 +566,9 @@ public final class ActivityManagerService extends ActivityManagerNative
// so that dispatch of foreground broadcasts gets precedence.
final BroadcastQueue[] mBroadcastQueues = new BroadcastQueue[2];
BroadcastStats mLastBroadcastStats;
BroadcastStats mCurBroadcastStats;
BroadcastQueue broadcastQueueForIntent(Intent intent) {
final boolean isFg = (intent.getFlags() & Intent.FLAG_RECEIVER_FOREGROUND) != 0;
if (DEBUG_BROADCAST_BACKGROUND) Slog.i(TAG_BROADCAST,
@@ -13771,6 +13770,8 @@ public final class ActivityManagerService extends ActivityManagerNative
boolean dumpAll = false;
boolean dumpClient = false;
boolean dumpCheckin = false;
boolean dumpCheckinFormat = false;
String dumpPackage = null;
int opti = 0;
@@ -13793,6 +13794,10 @@ public final class ActivityManagerService extends ActivityManagerNative
return;
}
dumpClient = true;
} else if ("--checkin".equals(opt)) {
dumpCheckin = dumpCheckinFormat = true;
} else if ("-C".equals(opt)) {
dumpCheckinFormat = true;
} else if ("-h".equals(opt)) {
ActivityManagerShellCommand.dumpHelp(pw, true);
return;
@@ -13831,6 +13836,22 @@ public final class ActivityManagerService extends ActivityManagerNative
synchronized (this) {
dumpBroadcastsLocked(fd, pw, args, opti, true, dumpPackage);
}
} else if ("broadcast-stats".equals(cmd)) {
String[] newArgs;
String name;
if (opti >= args.length) {
name = null;
newArgs = EMPTY_STRING_ARRAY;
} else {
dumpPackage = args[opti];
opti++;
newArgs = new String[args.length - opti];
if (args.length > 2) System.arraycopy(args, opti, newArgs, 0,
args.length - opti);
}
synchronized (this) {
dumpBroadcastStatsLocked(fd, pw, args, opti, true, dumpPackage);
}
} else if ("intents".equals(cmd) || "i".equals(cmd)) {
String[] newArgs;
String name;
@@ -13961,7 +13982,9 @@ public final class ActivityManagerService extends ActivityManagerNative
}
// No piece of data specified, dump everything.
if (dumpClient) {
if (dumpCheckinFormat) {
dumpBroadcastStatsCheckinLocked(fd, pw, args, opti, dumpCheckin, dumpPackage);
} else if (dumpClient) {
ActiveServices.ServiceDumper sdumper;
synchronized (this) {
dumpPendingIntentsLocked(fd, pw, args, opti, dumpAll, dumpPackage);
@@ -13974,6 +13997,13 @@ public final class ActivityManagerService extends ActivityManagerNative
if (dumpAll) {
pw.println("-------------------------------------------------------------------------------");
}
if (dumpAll || dumpPackage != null) {
dumpBroadcastStatsLocked(fd, pw, args, opti, dumpAll, dumpPackage);
pw.println();
if (dumpAll) {
pw.println("-------------------------------------------------------------------------------");
}
}
dumpProvidersLocked(fd, pw, args, opti, dumpAll, dumpPackage);
pw.println();
if (dumpAll) {
@@ -14025,6 +14055,13 @@ public final class ActivityManagerService extends ActivityManagerNative
if (dumpAll) {
pw.println("-------------------------------------------------------------------------------");
}
if (dumpAll || dumpPackage != null) {
dumpBroadcastStatsLocked(fd, pw, args, opti, dumpAll, dumpPackage);
pw.println();
if (dumpAll) {
pw.println("-------------------------------------------------------------------------------");
}
}
dumpProvidersLocked(fd, pw, args, opti, dumpAll, dumpPackage);
pw.println();
if (dumpAll) {
@@ -14975,6 +15012,58 @@ public final class ActivityManagerService extends ActivityManagerNative
}
}
void dumpBroadcastStatsLocked(FileDescriptor fd, PrintWriter pw, String[] args,
int opti, boolean dumpAll, String dumpPackage) {
if (mCurBroadcastStats == null) {
return;
}
pw.println("ACTIVITY MANAGER BROADCAST STATS STATE (dumpsys activity broadcast-stats)");
final long now = SystemClock.elapsedRealtime();
if (mLastBroadcastStats != null) {
pw.print(" Last stats (from ");
TimeUtils.formatDuration(mLastBroadcastStats.mStartRealtime, now, pw);
pw.print(" to ");
TimeUtils.formatDuration(mLastBroadcastStats.mEndRealtime, now, pw);
pw.print(", ");
TimeUtils.formatDuration(mLastBroadcastStats.mEndUptime
- mLastBroadcastStats.mStartUptime, pw);
pw.println(" uptime):");
if (!mLastBroadcastStats.dumpStats(pw, " ", dumpPackage)) {
pw.println(" (nothing)");
}
pw.println();
}
pw.print(" Current stats (from ");
TimeUtils.formatDuration(mCurBroadcastStats.mStartRealtime, now, pw);
pw.print(" to now, ");
TimeUtils.formatDuration(SystemClock.uptimeMillis()
- mCurBroadcastStats.mStartUptime, pw);
pw.println(" uptime):");
if (!mCurBroadcastStats.dumpStats(pw, " ", dumpPackage)) {
pw.println(" (nothing)");
}
}
void dumpBroadcastStatsCheckinLocked(FileDescriptor fd, PrintWriter pw, String[] args,
int opti, boolean fullCheckin, String dumpPackage) {
if (mCurBroadcastStats == null) {
return;
}
if (mLastBroadcastStats != null) {
mLastBroadcastStats.dumpCheckinStats(pw, dumpPackage);
if (fullCheckin) {
mLastBroadcastStats = null;
return;
}
}
mCurBroadcastStats.dumpCheckinStats(pw, dumpPackage);
if (fullCheckin) {
mCurBroadcastStats = null;
}
}
void dumpProvidersLocked(FileDescriptor fd, PrintWriter pw, String[] args,
int opti, boolean dumpAll, String dumpPackage) {
boolean needSep;
@@ -17943,11 +18032,34 @@ public final class ActivityManagerService extends ActivityManagerNative
queue.enqueueOrderedBroadcastLocked(r);
queue.scheduleBroadcastsLocked();
}
} else {
// There was nobody interested in the broadcast, but we still want to record
// that it happened.
if (intent.getComponent() == null && intent.getPackage() == null
&& (intent.getFlags()&Intent.FLAG_RECEIVER_REGISTERED_ONLY) == 0) {
// This was an implicit broadcast... let's record it for posterity.
addBroadcastStatLocked(intent.getAction(), callerPackage, 0, 0, 0);
}
}
return ActivityManager.BROADCAST_SUCCESS;
}
final void addBroadcastStatLocked(String action, String srcPackage, int receiveCount,
int skipCount, long dispatchTime) {
final long now = SystemClock.elapsedRealtime();
if (mCurBroadcastStats == null ||
(mCurBroadcastStats.mStartRealtime +(24*60*60*1000) < now)) {
mLastBroadcastStats = mCurBroadcastStats;
if (mLastBroadcastStats != null) {
mLastBroadcastStats.mEndRealtime = SystemClock.elapsedRealtime();
mLastBroadcastStats.mEndUptime = SystemClock.uptimeMillis();
}
mCurBroadcastStats = new BroadcastStats();
}
mCurBroadcastStats.addBroadcast(action, srcPackage, receiveCount, skipCount, dispatchTime);
}
final Intent verifyBroadcastLocked(Intent intent) {
// Refuse possible leaked file descriptors
if (intent != null && intent.hasFileDescriptors() == true) {

View File

@@ -197,6 +197,7 @@ class ActivityManagerShellCommand extends ShellCommand {
pw.println(" a[ctivities]: activity stack state");
pw.println(" r[recents]: recent activities state");
pw.println(" b[roadcasts] [PACKAGE_NAME] [history [-s]]: broadcast state");
pw.println(" broadcast-stats [PACKAGE_NAME]: aggregated broadcast statistics");
pw.println(" i[ntents] [PACKAGE_NAME]: pending intent state");
pw.println(" p[rocesses] [PACKAGE_NAME]: process state");
pw.println(" o[om]: out of memory management");
@@ -216,12 +217,14 @@ class ActivityManagerShellCommand extends ShellCommand {
pw.println(" -a: include all available server state.");
pw.println(" -c: include client state.");
pw.println(" -p: limit output to given package.");
pw.println(" --checkin: output checkin format, resetting data.");
pw.println(" --C: output checkin format, not resetting data.");
} else {
pw.println("Activity manager (activity) commands:");
pw.println(" help");
pw.println(" Print this help text.");
pw.println(" force-stop [--user <USER_ID> | all | current] <PACKAGE>");
pw.println(" Complete stop the given application package.");
pw.println(" Completely stop the given application package.");
pw.println(" kill [--user <USER_ID> | all | current] <PACKAGE>");
pw.println(" Kill all processes associated with the given application.");
pw.println(" kill-all");

View File

@@ -898,6 +898,12 @@ public final class BroadcastQueue {
// ... and on to the next...
addBroadcastToHistoryLocked(r);
if (r.intent.getComponent() == null && r.intent.getPackage() == null
&& (r.intent.getFlags()&Intent.FLAG_RECEIVER_REGISTERED_ONLY) == 0) {
// This was an implicit broadcast... let's record it for posterity.
mService.addBroadcastStatLocked(r.intent.getAction(), r.callerPackage,
r.manifestCount, r.manifestSkipCount, r.finishTime-r.dispatchTime);
}
mOrderedBroadcasts.remove(0);
r = null;
looped = true;
@@ -1083,6 +1089,11 @@ public final class BroadcastQueue {
skip = true;
}
}
if (!skip) {
r.manifestCount++;
} else {
r.manifestSkipCount++;
}
if (r.curApp != null && r.curApp.crashing) {
// If the target process is crashing, just skip it.
Slog.w(TAG, "Skipping deliver ordered [" + mQueueName + "] " + r

View File

@@ -72,6 +72,8 @@ final class BroadcastRecord extends Binder {
IBinder receiver; // who is currently running, null if none.
int state;
int anrCount; // has this broadcast record hit any ANRs?
int manifestCount; // number of manifest receivers dispatched.
int manifestSkipCount; // number of manifest receivers skipped.
BroadcastQueue queue; // the outbound queue handling this broadcast
static final int IDLE = 0;

View File

@@ -0,0 +1,163 @@
/*
* Copyright (C) 2016 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.server.am;
import android.os.SystemClock;
import android.util.ArrayMap;
import android.util.TimeUtils;
import java.io.PrintWriter;
import java.util.ArrayList;
import java.util.Collections;
import java.util.Comparator;
public final class BroadcastStats {
final long mStartRealtime;
final long mStartUptime;
long mEndRealtime;
long mEndUptime;
final ArrayMap<String, ActionEntry> mActions = new ArrayMap<>();
static final Comparator<ActionEntry> ACTIONS_COMPARATOR = new Comparator<ActionEntry>() {
@Override public int compare(ActionEntry o1, ActionEntry o2) {
if (o1.mTotalDispatchTime < o2.mTotalDispatchTime) {
return -1;
}
if (o1.mTotalDispatchTime > o2.mTotalDispatchTime) {
return 1;
}
return 0;
}
};
static final class ActionEntry {
final String mAction;
final ArrayMap<String, PackageEntry> mPackages = new ArrayMap<>();
int mReceiveCount;
int mSkipCount;
long mTotalDispatchTime;
long mMaxDispatchTime;
ActionEntry(String action) {
mAction = action;
}
}
static final class PackageEntry {
int mSendCount;
}
public BroadcastStats() {
mStartRealtime = SystemClock.elapsedRealtime();
mStartUptime = SystemClock.uptimeMillis();
}
public void addBroadcast(String action, String srcPackage, int receiveCount,
int skipCount, long dispatchTime) {
ActionEntry ae = mActions.get(action);
if (ae == null) {
ae = new ActionEntry(action);
mActions.put(action, ae);
}
ae.mReceiveCount += receiveCount;
ae.mSkipCount += skipCount;
ae.mTotalDispatchTime += dispatchTime;
if (ae.mMaxDispatchTime < dispatchTime) {
ae.mMaxDispatchTime = dispatchTime;
}
PackageEntry pe = ae.mPackages.get(srcPackage);
if (pe == null) {
pe = new PackageEntry();
ae.mPackages.put(srcPackage, pe);
}
pe.mSendCount++;
}
public boolean dumpStats(PrintWriter pw, String prefix, String dumpPackage) {
boolean printedSomething = false;
ArrayList<ActionEntry> actions = new ArrayList<>(mActions.size());
for (int i=mActions.size()-1; i>=0; i--) {
actions.add(mActions.valueAt(i));
}
Collections.sort(actions, ACTIONS_COMPARATOR);
for (int i=actions.size()-1; i>=0; i--) {
ActionEntry ae = actions.get(i);
if (dumpPackage != null && !ae.mPackages.containsKey(dumpPackage)) {
continue;
}
printedSomething = true;
pw.print(prefix);
pw.print(ae.mAction);
pw.println(":");
pw.print(prefix);
pw.print(" Number received: ");
pw.print(ae.mReceiveCount);
pw.print(", skipped: ");
pw.println(ae.mSkipCount);
pw.print(prefix);
pw.print(" Total dispatch time: ");
TimeUtils.formatDuration(ae.mTotalDispatchTime, pw);
pw.print(", max: ");
TimeUtils.formatDuration(ae.mMaxDispatchTime, pw);
pw.println();
for (int j=ae.mPackages.size()-1; j>=0; j--) {
pw.print(prefix);
pw.print(" Package ");
pw.print(ae.mPackages.keyAt(j));
pw.print(": ");
PackageEntry pe = ae.mPackages.valueAt(j);
pw.print(pe.mSendCount);
pw.println(" times");
}
}
return printedSomething;
}
public void dumpCheckinStats(PrintWriter pw, String dumpPackage) {
pw.print("broadcast-stats,1,");
pw.print(mStartRealtime);
pw.print(",");
pw.print(mEndRealtime == 0 ? SystemClock.elapsedRealtime() : mEndRealtime);
pw.print(",");
pw.println((mEndUptime == 0 ? SystemClock.uptimeMillis() : mEndUptime) - mStartUptime);
for (int i=mActions.size()-1; i>=0; i--) {
ActionEntry ae = mActions.valueAt(i);
if (dumpPackage != null && !ae.mPackages.containsKey(dumpPackage)) {
continue;
}
pw.print("a,");
pw.print(mActions.keyAt(i));
pw.print(",");
pw.print(ae.mReceiveCount);
pw.print(",");
pw.print(ae.mSkipCount);
pw.print(",");
pw.print(ae.mTotalDispatchTime);
pw.print(",");
pw.print(ae.mMaxDispatchTime);
pw.println();
for (int j=ae.mPackages.size()-1; j>=0; j--) {
pw.print("p,");
pw.print(ae.mPackages.keyAt(j));
PackageEntry pe = ae.mPackages.valueAt(j);
pw.print(",");
pw.print(pe.mSendCount);
pw.println();
}
}
}
}

View File

@@ -32,6 +32,7 @@ import android.os.RemoteException;
import android.os.TransactionTooLargeException;
import android.os.UserHandle;
import android.util.Slog;
import android.util.TimeUtils;
import com.android.server.am.ActivityStackSupervisor.ActivityContainer;
@@ -397,7 +398,12 @@ final class PendingIntentRecord extends IIntentSender.Stub {
pw.print(prefix); pw.print("sent="); pw.print(sent);
pw.print(" canceled="); pw.println(canceled);
}
pw.print(prefix); pw.println("whitelistDuration="); pw.println(whitelistDuration);
if (whitelistDuration != 0) {
pw.print(prefix);
pw.print("whitelistDuration=");
TimeUtils.formatDuration(whitelistDuration, pw);
pw.println();
}
}
public String toString() {
@@ -412,7 +418,9 @@ final class PendingIntentRecord extends IIntentSender.Stub {
sb.append(' ');
sb.append(key.typeName());
if (whitelistDuration > 0) {
sb.append( " (whitelistDuration: ").append(whitelistDuration).append("ms)");
sb.append( " (whitelist: ");
TimeUtils.formatDuration(whitelistDuration, sb);
sb.append(")");
}
sb.append('}');
return stringName = sb.toString();