diff --git a/apct-tests/perftests/core/src/android/os/BinderCallsStatsPerfTest.java b/apct-tests/perftests/core/src/android/os/BinderCallsStatsPerfTest.java index 28d40969aa210..ba072da8071ed 100644 --- a/apct-tests/perftests/core/src/android/os/BinderCallsStatsPerfTest.java +++ b/apct-tests/perftests/core/src/android/os/BinderCallsStatsPerfTest.java @@ -69,7 +69,6 @@ public class BinderCallsStatsPerfTest { final BenchmarkState state = mPerfStatusReporter.getBenchmarkState(); Binder b = new Binder(); mBinderCallsStats = new BinderCallsStats(false); - assertNull(mBinderCallsStats.callStarted(b, 0)); while (state.keepRunning()) { BinderCallsStats.CallSession s = mBinderCallsStats.callStarted(b, 0); mBinderCallsStats.callEnded(s); diff --git a/core/java/com/android/internal/os/BinderCallsStats.java b/core/java/com/android/internal/os/BinderCallsStats.java index 2c48506494bc1..7eefe59d46967 100644 --- a/core/java/com/android/internal/os/BinderCallsStats.java +++ b/core/java/com/android/internal/os/BinderCallsStats.java @@ -21,6 +21,7 @@ import android.os.SystemClock; import android.util.ArrayMap; import android.util.SparseArray; +import com.android.internal.annotations.GuardedBy; import com.android.internal.annotations.VisibleForTesting; import com.android.internal.util.Preconditions; @@ -40,23 +41,21 @@ public class BinderCallsStats { private static final int CALL_SESSIONS_POOL_SIZE = 100; private static final BinderCallsStats sInstance = new BinderCallsStats(); - private volatile boolean mTrackingEnabled = false; + private volatile boolean mDetailedTracking = false; + @GuardedBy("mLock") private final SparseArray mUidEntries = new SparseArray<>(); private final Queue mCallSessionsPool = new ConcurrentLinkedQueue<>(); + private final Object mLock = new Object(); private BinderCallsStats() { } @VisibleForTesting - public BinderCallsStats(boolean trackingEnabled) { - mTrackingEnabled = trackingEnabled; + public BinderCallsStats(boolean detailedTracking) { + mDetailedTracking = detailedTracking; } public CallSession callStarted(Binder binder, int code) { - if (!mTrackingEnabled) { - return null; - } - return callStarted(binder.getClass().getName(), code); } @@ -73,32 +72,31 @@ public class BinderCallsStats { } public void callEnded(CallSession s) { - if (!mTrackingEnabled) { - return; - } Preconditions.checkNotNull(s); - final long cpuTimeNow = getThreadTimeMicro(); - final long duration = cpuTimeNow - s.mStarted; + long duration = mDetailedTracking ? getThreadTimeMicro() - s.mStarted : 1; s.mCallingUId = Binder.getCallingUid(); - synchronized (mUidEntries) { + synchronized (mLock) { UidEntry uidEntry = mUidEntries.get(s.mCallingUId); if (uidEntry == null) { uidEntry = new UidEntry(s.mCallingUId); mUidEntries.put(s.mCallingUId, uidEntry); } - // Find CallDesc entry and update its total time - CallStat callStat = uidEntry.mCallStats.get(s.mCallStat); - // Only create CallStat if it's a new entry, otherwise update existing instance - if (callStat == null) { - callStat = new CallStat(s.mCallStat.className, s.mCallStat.msg); - uidEntry.mCallStats.put(callStat, callStat); + if (mDetailedTracking) { + // Find CallDesc entry and update its total time + CallStat callStat = uidEntry.mCallStats.get(s.mCallStat); + // Only create CallStat if it's a new entry, otherwise update existing instance + if (callStat == null) { + callStat = new CallStat(s.mCallStat.className, s.mCallStat.msg); + uidEntry.mCallStats.put(callStat, callStat); + } + callStat.callCount++; + callStat.time += duration; } + uidEntry.time += duration; uidEntry.callCount++; - callStat.callCount++; - callStat.time += duration; } if (mCallSessionsPool.size() < CALL_SESSIONS_POOL_SIZE) { mCallSessionsPool.add(s); @@ -112,7 +110,7 @@ public class BinderCallsStats { long totalCallsTime = 0; int uidEntriesSize = mUidEntries.size(); List entries = new ArrayList<>(); - synchronized (mUidEntries) { + synchronized (mLock) { for (int i = 0; i < uidEntriesSize; i++) { UidEntry e = mUidEntries.valueAt(i); entries.add(e); @@ -127,20 +125,10 @@ public class BinderCallsStats { totalCallsCount += e.callCount; } } - pw.println("Binder call stats:"); - pw.println(" Raw data (uid,call_desc,time):"); - entries.sort((o1, o2) -> { - if (o1.time < o2.time) { - return 1; - } else if (o1.time > o2.time) { - return -1; - } - return 0; - }); - StringBuilder sb = new StringBuilder(); - for (UidEntry uidEntry : entries) { - List callStats = new ArrayList<>(uidEntry.mCallStats.keySet()); - callStats.sort((o1, o2) -> { + if (mDetailedTracking) { + pw.println("Binder call stats:"); + pw.println(" Raw data (uid,call_desc,time):"); + entries.sort((o1, o2) -> { if (o1.time < o2.time) { return 1; } else if (o1.time > o2.time) { @@ -148,44 +136,72 @@ public class BinderCallsStats { } return 0; }); - for (CallStat e : callStats) { - sb.setLength(0); - sb.append(" ") - .append(uidEntry.uid).append(",").append(e).append(',').append(e.time); - pw.println(sb); + StringBuilder sb = new StringBuilder(); + for (UidEntry uidEntry : entries) { + List callStats = new ArrayList<>(uidEntry.mCallStats.keySet()); + callStats.sort((o1, o2) -> { + if (o1.time < o2.time) { + return 1; + } else if (o1.time > o2.time) { + return -1; + } + return 0; + }); + for (CallStat e : callStats) { + sb.setLength(0); + sb.append(" ") + .append(uidEntry.uid).append(",").append(e).append(',').append(e.time); + pw.println(sb); + } + } + pw.println(); + pw.println(" Per UID Summary(UID: time, % of total_time, calls_count):"); + List> uidTotals = new ArrayList<>(uidTimeMap.entrySet()); + uidTotals.sort((o1, o2) -> o2.getValue().compareTo(o1.getValue())); + for (Map.Entry uidTotal : uidTotals) { + Long callCount = uidCallCountMap.get(uidTotal.getKey()); + pw.println(String.format(" %7d: %11d %3.0f%% %8d", + uidTotal.getKey(), uidTotal.getValue(), + 100d * uidTotal.getValue() / totalCallsTime, callCount)); + } + pw.println(); + pw.println(String.format(" Summary: total_time=%d, " + + "calls_count=%d, avg_call_time=%.0f", + totalCallsTime, totalCallsCount, + (double)totalCallsTime / totalCallsCount)); + } else { + pw.println(" Per UID Summary(UID: calls_count, % of total calls_count):"); + List> uidTotals = new ArrayList<>(uidTimeMap.entrySet()); + uidTotals.sort((o1, o2) -> o2.getValue().compareTo(o1.getValue())); + for (Map.Entry uidTotal : uidTotals) { + Long callCount = uidCallCountMap.get(uidTotal.getKey()); + pw.println(String.format(" %7d: %8d %3.0f%%", + uidTotal.getKey(), callCount, 100d * uidTotal.getValue() / totalCallsTime)); } } - pw.println(); - pw.println(" Per UID Summary(UID: time, total_time_percentage, calls_count):"); - List> uidTotals = new ArrayList<>(uidTimeMap.entrySet()); - uidTotals.sort((o1, o2) -> o2.getValue().compareTo(o1.getValue())); - for (Map.Entry uidTotal : uidTotals) { - Long callCount = uidCallCountMap.get(uidTotal.getKey()); - pw.println(String.format(" %5d: %11d %3.0f%% %8d", - uidTotal.getKey(), uidTotal.getValue(), - 100d * uidTotal.getValue() / totalCallsTime, callCount)); - } - pw.println(); - pw.println(String.format(" Summary: total_time=%d, " - + "calls_count=%d, avg_call_time=%.0f", - totalCallsTime, totalCallsCount, - (double)totalCallsTime / totalCallsCount)); } - private static long getThreadTimeMicro() { - return SystemClock.currentThreadTimeMicro(); + private long getThreadTimeMicro() { + // currentThreadTimeMicro is expensive, so we measure cpu time only if detailed tracking is + // enabled + return mDetailedTracking ? SystemClock.currentThreadTimeMicro() : 0; } public static BinderCallsStats getInstance() { return sInstance; } - public void setTrackingEnabled(boolean enabled) { - mTrackingEnabled = enabled; + public void setDetailedTracking(boolean enabled) { + if (enabled != mDetailedTracking) { + reset(); + mDetailedTracking = enabled; + } } - public boolean isTrackingEnabled() { - return mTrackingEnabled; + public void reset() { + synchronized (mLock) { + mUidEntries.clear(); + } } private static class CallStat { @@ -210,7 +226,7 @@ public class BinderCallsStats { CallStat callStat = (CallStat) o; - return msg == callStat.msg && (className == callStat.className); + return msg == callStat.msg && (className.equals(callStat.className)); } @Override diff --git a/services/core/java/com/android/server/BinderCallsStatsService.java b/services/core/java/com/android/server/BinderCallsStatsService.java index 2ed451610354d..ae14dfaa4db19 100644 --- a/services/core/java/com/android/server/BinderCallsStatsService.java +++ b/services/core/java/com/android/server/BinderCallsStatsService.java @@ -30,26 +30,58 @@ public class BinderCallsStatsService extends Binder { private static final String TAG = "BinderCallsStatsService"; - private static final String PERSIST_SYS_BINDER_CPU_STATS_TRACKING - = "persist.sys.binder_cpu_stats_tracking"; + private static final String PERSIST_SYS_BINDER_CALLS_DETAILED_TRACKING + = "persist.sys.binder_calls_detailed_tracking"; public static void start() { BinderCallsStatsService service = new BinderCallsStatsService(); ServiceManager.addService("binder_calls_stats", service); - // TODO Enable by default on eng/userdebug builds - boolean trackingEnabledDefault = false; - boolean trackingEnabled = SystemProperties.getBoolean(PERSIST_SYS_BINDER_CPU_STATS_TRACKING, - trackingEnabledDefault); + boolean detailedTrackingEnabled = SystemProperties.getBoolean( + PERSIST_SYS_BINDER_CALLS_DETAILED_TRACKING, false); - if (trackingEnabled) { + if (detailedTrackingEnabled) { Slog.i(TAG, "Enabled CPU usage tracking for binder calls. Controlled by " - + PERSIST_SYS_BINDER_CPU_STATS_TRACKING); - BinderCallsStats.getInstance().setTrackingEnabled(true); + + PERSIST_SYS_BINDER_CALLS_DETAILED_TRACKING + + " or via dumpsys binder_calls_stats --enable-detailed-tracking"); + BinderCallsStats.getInstance().setDetailedTracking(true); } } + public static void reset() { + Slog.i(TAG, "Resetting stats"); + BinderCallsStats.getInstance().reset(); + } + @Override protected void dump(FileDescriptor fd, PrintWriter pw, String[] args) { + if (args != null) { + for (final String arg : args) { + if ("--reset".equals(arg)) { + reset(); + pw.println("binder_calls_stats reset."); + return; + } else if ("--enable-detailed-tracking".equals(arg)) { + SystemProperties.set(PERSIST_SYS_BINDER_CALLS_DETAILED_TRACKING, "1"); + BinderCallsStats.getInstance().setDetailedTracking(true); + pw.println("Detailed tracking enabled"); + return; + } else if ("--disable-detailed-tracking".equals(arg)) { + SystemProperties.set(PERSIST_SYS_BINDER_CALLS_DETAILED_TRACKING, ""); + BinderCallsStats.getInstance().setDetailedTracking(false); + pw.println("Detailed tracking disabled"); + return; + } else if ("-h".equals(arg)) { + pw.println("binder_calls_stats commands:"); + pw.println(" --reset: Reset stats"); + pw.println(" --enable-detailed-tracking: Enables detailed tracking"); + pw.println(" --disable-detailed-tracking: Disables detailed tracking"); + return; + } else { + pw.println("Unknown option: " + arg); + return; + } + } + } BinderCallsStats.getInstance().dump(pw); } }