Loading apct-tests/perftests/core/src/android/os/BinderCallsStatsPerfTest.java +3 −2 Original line number Diff line number Diff line Loading @@ -22,6 +22,7 @@ import android.support.test.filters.LargeTest; import android.support.test.runner.AndroidJUnit4; import com.android.internal.os.BinderCallsStats; import com.android.internal.os.BinderInternal.CallSession; import java.util.Random; Loading Loading @@ -61,7 +62,7 @@ public class BinderCallsStatsPerfTest { Binder b = new Binder(); int i = 0; while (state.keepRunning()) { BinderCallsStats.CallSession s = mBinderCallsStats.callStarted(b, i % 100); CallSession s = mBinderCallsStats.callStarted(b, i % 100); mBinderCallsStats.callEnded(s, 0, 0); i++; } Loading @@ -73,7 +74,7 @@ public class BinderCallsStatsPerfTest { final BenchmarkState state = mPerfStatusReporter.getBenchmarkState(); Binder b = new Binder(); while (state.keepRunning()) { BinderCallsStats.CallSession s = mBinderCallsStats.callStarted(b, 0); CallSession s = mBinderCallsStats.callStarted(b, 0); mBinderCallsStats.callEnded(s, 0, 0); } } Loading core/java/android/os/Binder.java +26 −6 Original line number Diff line number Diff line Loading @@ -22,8 +22,8 @@ import android.util.ExceptionUtils; import android.util.Log; import android.util.Slog; import com.android.internal.os.BinderCallsStats; import com.android.internal.os.BinderInternal; import com.android.internal.os.BinderInternal.CallSession; import com.android.internal.util.FastPrintWriter; import com.android.internal.util.FunctionalUtils.ThrowingRunnable; import com.android.internal.util.FunctionalUtils.ThrowingSupplier; Loading Loading @@ -92,6 +92,11 @@ public class Binder implements IBinder { */ private static volatile TransactionTracker sTransactionTracker = null; /** * Global observer for this process. */ private static BinderInternal.Observer sObserver = null; /** * Guestimate of native memory associated with a Binder. */ Loading @@ -106,6 +111,7 @@ public class Binder implements IBinder { Binder.class.getClassLoader(), getNativeFinalizer(), NATIVE_ALLOCATION_SIZE); } // Transaction tracking code. /** Loading Loading @@ -151,6 +157,15 @@ public class Binder implements IBinder { return sTransactionTracker; } /** * Get the binder transaction observer for this process. * * @hide */ public static void setObserver(@Nullable BinderInternal.Observer observer) { sObserver = observer; } /** {@hide} */ static volatile boolean sWarnOnBlocking = false; Loading Loading @@ -721,8 +736,10 @@ public class Binder implements IBinder { // Entry point from android_util_Binder.cpp's onTransact private boolean execTransact(int code, long dataObj, long replyObj, int flags) { BinderCallsStats binderCallsStats = BinderCallsStats.getInstance(); BinderCallsStats.CallSession callSession = binderCallsStats.callStarted(this, code); // Make sure the observer won't change while processing a transaction. final BinderInternal.Observer observer = sObserver; final CallSession callSession = observer != null ? observer.callStarted(this, code) : null; Parcel data = Parcel.obtain(dataObj); Parcel reply = Parcel.obtain(replyObj); // theoretically, we should call transact, which will call onTransact, Loading @@ -738,7 +755,9 @@ public class Binder implements IBinder { } res = onTransact(code, data, reply, flags); } catch (RemoteException|RuntimeException e) { binderCallsStats.callThrewException(callSession, e); if (observer != null) { observer.callThrewException(callSession, e); } if (LOG_RUNTIME_EXCEPTION) { Log.w(TAG, "Caught a RuntimeException from the binder stub implementation.", e); } Loading Loading @@ -770,9 +789,10 @@ public class Binder implements IBinder { // to the main transaction loop to wait for another incoming transaction. Either // way, strict mode begone! StrictMode.clearGatheredViolations(); binderCallsStats.callEnded(callSession, requestSizeBytes, replySizeBytes); if (observer != null) { observer.callEnded(callSession, requestSizeBytes, replySizeBytes); } return res; } } core/java/com/android/internal/os/BinderCallsStats.java +49 −76 Original line number Diff line number Diff line Loading @@ -29,6 +29,7 @@ import android.util.SparseArray; import com.android.internal.annotations.GuardedBy; import com.android.internal.annotations.VisibleForTesting; import com.android.internal.os.BinderInternal.CallSession; import com.android.internal.util.Preconditions; import java.io.PrintWriter; Loading @@ -47,7 +48,7 @@ import java.util.function.ToDoubleFunction; * Collects statistics about CPU time spent per binder call across multiple dimensions, e.g. * per thread, uid or call description. */ public class BinderCallsStats { public class BinderCallsStats implements BinderInternal.Observer { public static final boolean ENABLED_DEFAULT = true; public static final boolean DETAILED_TRACKING_DEFAULT = true; public static final int PERIODIC_SAMPLING_INTERVAL_DEFAULT = 10; Loading @@ -57,12 +58,9 @@ public class BinderCallsStats { private static final int PERIODIC_SAMPLING_INTERVAL = 10; private static final int MAX_EXCEPTION_COUNT_SIZE = 50; private static final String EXCEPTION_COUNT_OVERFLOW_NAME = "overflow"; private static final CallSession NOT_ENABLED = new CallSession(); private static final BinderCallsStats sInstance = new BinderCallsStats(new Random()); private volatile boolean mEnabled = ENABLED_DEFAULT; private volatile boolean mDetailedTracking = DETAILED_TRACKING_DEFAULT; private volatile int mPeriodicSamplingInterval = PERIODIC_SAMPLING_INTERVAL_DEFAULT; private boolean mDetailedTracking = DETAILED_TRACKING_DEFAULT; private int mPeriodicSamplingInterval = PERIODIC_SAMPLING_INTERVAL_DEFAULT; @GuardedBy("mLock") private final SparseArray<UidEntry> mUidEntries = new SparseArray<>(); @GuardedBy("mLock") Loading @@ -72,28 +70,24 @@ public class BinderCallsStats { private final Random mRandom; private long mStartTime = System.currentTimeMillis(); @VisibleForTesting // Use getInstance() instead. public BinderCallsStats(Random random) { this.mRandom = random; } @Override public CallSession callStarted(Binder binder, int code) { return callStarted(binder.getClass().getName(), code, binder.getTransactionName(code)); } private CallSession callStarted(String className, int code, @Nullable String methodName) { if (!mEnabled) { return NOT_ENABLED; } CallSession s = mCallSessionsPool.poll(); if (s == null) { s = new CallSession(); } s.callStat.className = className; s.callStat.msg = code; s.callStat.methodName = methodName; s.className = className; s.transactionCode = code; s.methodName = methodName; s.exceptionThrown = false; s.cpuTimeStarted = -1; s.timeStarted = -1; Loading @@ -109,9 +103,9 @@ public class BinderCallsStats { return s; } public void callEnded(CallSession s, int parcelRequestSize, int parcelReplySize) { Preconditions.checkNotNull(s); if (s == NOT_ENABLED) { @Override public void callEnded(@Nullable CallSession s, int parcelRequestSize, int parcelReplySize) { if (s == null) { return; } Loading @@ -124,10 +118,6 @@ public class BinderCallsStats { private void processCallEnded(CallSession s, int parcelRequestSize, int parcelReplySize) { synchronized (mLock) { if (!mEnabled) { return; } final int callingUid = getCallingUid(); UidEntry uidEntry = mUidEntries.get(callingUid); if (uidEntry == null) { Loading @@ -135,7 +125,7 @@ public class BinderCallsStats { mUidEntries.put(callingUid, uidEntry); } uidEntry.callCount++; CallStat callStat = uidEntry.getOrCreate(s.callStat); CallStat callStat = uidEntry.getOrCreate(s.className, s.transactionCode); callStat.callCount++; // Non-negative time signals we need to record data for this call. Loading @@ -147,7 +137,7 @@ public class BinderCallsStats { uidEntry.recordedCallCount++; callStat.recordedCallCount++; callStat.methodName = s.callStat.methodName; callStat.methodName = s.methodName; callStat.cpuTimeMicros += duration; callStat.maxCpuTimeMicros = Math.max(callStat.maxCpuTimeMicros, duration); callStat.latencyMicros += latencyDuration; Loading @@ -164,16 +154,9 @@ public class BinderCallsStats { } } /** * Called if an exception is thrown while executing the binder transaction. * * <li>BinderCallsStats#callEnded will be called afterwards. * <li>Do not throw an exception in this method, it will swallow the original exception thrown * by the binder transaction. */ public void callThrewException(CallSession s, Exception exception) { Preconditions.checkNotNull(s); if (!mEnabled) { @Override public void callThrewException(@Nullable CallSession s, Exception exception) { if (s == null) { return; } s.exceptionThrown = true; Loading Loading @@ -208,7 +191,7 @@ public class BinderCallsStats { exported.uid = entry.uid; exported.className = stat.className; exported.methodName = stat.methodName == null ? String.valueOf(stat.msg) : stat.methodName; ? String.valueOf(stat.transactionCode) : stat.methodName; exported.cpuTimeMicros = stat.cpuTimeMicros; exported.maxCpuTimeMicros = stat.maxCpuTimeMicros; exported.latencyMicros = stat.latencyMicros; Loading @@ -233,11 +216,6 @@ public class BinderCallsStats { } private void dumpLocked(PrintWriter pw, Map<Integer,String> appIdToPkgNameMap, boolean verbose) { if (!mEnabled) { pw.println("Binder calls stats disabled."); return; } long totalCallsCount = 0; long totalRecordedCallsCount = 0; long totalCpuTime = 0; Loading Loading @@ -340,10 +318,6 @@ public class BinderCallsStats { return mRandom.nextInt() % mPeriodicSamplingInterval == 0; } public static BinderCallsStats getInstance() { return sInstance; } public void setDetailedTracking(boolean enabled) { synchronized (mLock) { if (enabled != mDetailedTracking) { Loading @@ -353,15 +327,6 @@ public class BinderCallsStats { } } public void setEnabled(boolean enabled) { synchronized (mLock) { if (enabled != mEnabled) { mEnabled = enabled; reset(); } } } public void setSamplingInterval(int samplingInterval) { synchronized (mLock) { if (samplingInterval != mPeriodicSamplingInterval) { Loading Loading @@ -400,7 +365,7 @@ public class BinderCallsStats { @VisibleForTesting public static class CallStat { public String className; public int msg; public int transactionCode; // Method name might be null when we cannot resolve the transaction code. For instance, if // the binder was not generated by AIDL. public @Nullable String methodName; Loading @@ -427,10 +392,21 @@ public class BinderCallsStats { CallStat() { } CallStat(String className, int msg) { CallStat(String className, int transactionCode) { this.className = className; this.msg = msg; this.transactionCode = transactionCode; } @Override public String toString() { return className + "#" + (methodName == null ? transactionCode : methodName); } } /** Key used to store CallStat object in a Map. */ public static class CallStatKey { public String className; public int transactionCode; @Override public boolean equals(Object o) { Loading @@ -438,29 +414,19 @@ public class BinderCallsStats { return true; } CallStat callStat = (CallStat) o; return msg == callStat.msg && (className.equals(callStat.className)); CallStatKey key = (CallStatKey) o; return transactionCode == key.transactionCode && (className.equals(key.className)); } @Override public int hashCode() { int result = className.hashCode(); result = 31 * result + msg; result = 31 * result + transactionCode; return result; } @Override public String toString() { return className + "#" + (methodName == null ? msg : methodName); } } public static class CallSession { long cpuTimeStarted; long timeStarted; boolean exceptionThrown; final CallStat callStat = new CallStat(); } @VisibleForTesting public static class UidEntry { Loading @@ -480,14 +446,21 @@ public class BinderCallsStats { } // Aggregate time spent per each call name: call_desc -> cpu_time_micros Map<CallStat, CallStat> mCallStats = new ArrayMap<>(); CallStat getOrCreate(CallStat callStat) { CallStat mapCallStat = mCallStats.get(callStat); private Map<CallStatKey, CallStat> mCallStats = new ArrayMap<>(); private CallStatKey mTempKey = new CallStatKey(); CallStat getOrCreate(String className, int transactionCode) { // Use a global temporary key to avoid creating new objects for every lookup. mTempKey.className = className; mTempKey.transactionCode = transactionCode; CallStat mapCallStat = mCallStats.get(mTempKey); // Only create CallStat if it's a new entry, otherwise update existing instance if (mapCallStat == null) { mapCallStat = new CallStat(callStat.className, callStat.msg); mCallStats.put(mapCallStat, mapCallStat); mapCallStat = new CallStat(className, transactionCode); CallStatKey key = new CallStatKey(); key.className = className; key.transactionCode = transactionCode; mCallStats.put(key, mapCallStat); } return mapCallStat; } Loading @@ -496,7 +469,7 @@ public class BinderCallsStats { * Returns list of calls sorted by CPU time */ public List<CallStat> getCallStatsList() { List<CallStat> callStats = new ArrayList<>(mCallStats.keySet()); List<CallStat> callStats = new ArrayList<>(mCallStats.values()); callStats.sort((o1, o2) -> { if (o1.cpuTimeMicros < o2.cpuTimeMicros) { return 1; Loading core/java/com/android/internal/os/BinderInternal.java +54 −7 Original line number Diff line number Diff line Loading @@ -17,6 +17,7 @@ package com.android.internal.os; import android.annotation.NonNull; import android.os.Binder; import android.os.Handler; import android.os.IBinder; import android.os.SystemClock; Loading Loading @@ -69,6 +70,52 @@ public class BinderInternal { } } /** * A session used by {@link Observer} in order to keep track of some data. */ public static class CallSession { // Binder interface descriptor. public String className; // Binder transaction code. public int transactionCode; // Binder transaction method name. public String methodName; // CPU time at the beginning of the call. long cpuTimeStarted; // System time at the beginning of the call. long timeStarted; // Should be set to one when an exception is thrown. boolean exceptionThrown; } /** * Allows to track various steps of an API call. */ public interface Observer { /** * Called when a binder call starts. * * @return a CallSession to pass to the callEnded method. */ CallSession callStarted(Binder binder, int code); /** * Called when a binder call stops. * * <li>This method will be called even when an exception is thrown. */ void callEnded(CallSession s, int parcelRequestSize, int parcelReplySize); /** * Called if an exception is thrown while executing the binder transaction. * * <li>BinderCallsStats#callEnded will be called afterwards. * <li>Do not throw an exception in this method, it will swallow the original exception * thrown by the binder transaction. */ public void callThrewException(CallSession s, Exception exception); } /** * Add the calling thread to the IPC thread pool. This function does * not return until the current process is exiting. Loading core/tests/coretests/src/com/android/internal/os/BinderCallsStatsTest.java +31 −52 Original line number Diff line number Diff line Loading @@ -23,6 +23,8 @@ import android.support.test.runner.AndroidJUnit4; import android.util.ArrayMap; import android.util.SparseArray; import com.android.internal.os.BinderInternal.CallSession; import org.junit.Assert; import org.junit.Test; import org.junit.runner.RunWith; Loading Loading @@ -52,7 +54,7 @@ public class BinderCallsStatsTest { bcs.setSamplingInterval(5); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); CallSession callSession = bcs.callStarted(binder, 1); bcs.time += 10; bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); Loading @@ -65,7 +67,7 @@ public class BinderCallsStatsTest { assertEquals(1, uidEntry.recordedCallCount); assertEquals(10, uidEntry.cpuTimeMicros); assertEquals(binder.getClass().getName(), callStatsList.get(0).className); assertEquals(1, callStatsList.get(0).msg); assertEquals(1, callStatsList.get(0).transactionCode); // CPU usage is sampled, should not be tracked here. callSession = bcs.callStarted(binder, 1); Loading Loading @@ -93,7 +95,7 @@ public class BinderCallsStatsTest { bcs.setDetailedTracking(true); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); CallSession callSession = bcs.callStarted(binder, 1); bcs.time += 10; bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); Loading @@ -109,7 +111,7 @@ public class BinderCallsStatsTest { assertEquals(1, callStatsList.get(0).callCount); assertEquals(10, callStatsList.get(0).cpuTimeMicros); assertEquals(binder.getClass().getName(), callStatsList.get(0).className); assertEquals(1, callStatsList.get(0).msg); assertEquals(1, callStatsList.get(0).transactionCode); callSession = bcs.callStarted(binder, 1); bcs.time += 20; Loading @@ -134,44 +136,21 @@ public class BinderCallsStatsTest { } @Test public void testDisabled() { TestBinderCallsStats bcs = new TestBinderCallsStats(); bcs.setEnabled(false); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); bcs.time += 10; bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); SparseArray<BinderCallsStats.UidEntry> uidEntries = bcs.getUidEntries(); assertEquals(0, uidEntries.size()); } @Test public void testDisableInBetweenCall() { public void testEnableInBetweenCall() { TestBinderCallsStats bcs = new TestBinderCallsStats(); bcs.setEnabled(true); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); bcs.time += 10; bcs.setEnabled(false); bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); bcs.callEnded(null, REQUEST_SIZE, REPLY_SIZE); SparseArray<BinderCallsStats.UidEntry> uidEntries = bcs.getUidEntries(); assertEquals(0, uidEntries.size()); } @Test public void testEnableInBetweenCall() { public void testInBetweenCallWhenExceptionThrown() { TestBinderCallsStats bcs = new TestBinderCallsStats(); bcs.setEnabled(false); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); bcs.time += 10; bcs.setEnabled(true); bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); bcs.callThrewException(null, new IllegalStateException()); bcs.callEnded(null, REQUEST_SIZE, REPLY_SIZE); SparseArray<BinderCallsStats.UidEntry> uidEntries = bcs.getUidEntries(); assertEquals(0, uidEntries.size()); Loading @@ -184,7 +163,7 @@ public class BinderCallsStatsTest { bcs.setSamplingInterval(2); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); CallSession callSession = bcs.callStarted(binder, 1); bcs.time += 10; bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); Loading Loading @@ -221,7 +200,7 @@ public class BinderCallsStatsTest { bcs.setSamplingInterval(2); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); CallSession callSession = bcs.callStarted(binder, 1); bcs.time += 10; bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); Loading Loading @@ -264,13 +243,13 @@ public class BinderCallsStatsTest { return "resolved"; } }; BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); CallSession callSession = bcs.callStarted(binder, 1); bcs.time += 10; bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); List<BinderCallsStats.CallStat> callStatsList = bcs.getUidEntries().get(TEST_UID).getCallStatsList(); assertEquals(1, callStatsList.get(0).msg); assertEquals(1, callStatsList.get(0).transactionCode); assertEquals("resolved", callStatsList.get(0).methodName); } Loading @@ -279,7 +258,7 @@ public class BinderCallsStatsTest { TestBinderCallsStats bcs = new TestBinderCallsStats(); bcs.setDetailedTracking(true); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); CallSession callSession = bcs.callStarted(binder, 1); bcs.time += 10; bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); Loading @@ -295,7 +274,7 @@ public class BinderCallsStatsTest { TestBinderCallsStats bcs = new TestBinderCallsStats(); bcs.setDetailedTracking(true); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); CallSession callSession = bcs.callStarted(binder, 1); bcs.time += 50; bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); Loading @@ -314,7 +293,7 @@ public class BinderCallsStatsTest { TestBinderCallsStats bcs = new TestBinderCallsStats(); bcs.setDetailedTracking(true); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); CallSession callSession = bcs.callStarted(binder, 1); bcs.elapsedTime += 5; bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); Loading @@ -341,7 +320,7 @@ public class BinderCallsStatsTest { TestBinderCallsStats bcs = new TestBinderCallsStats(); bcs.setDetailedTracking(true); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); CallSession callSession = bcs.callStarted(binder, 1); bcs.callThrewException(callSession, new IllegalStateException()); bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); Loading @@ -364,7 +343,7 @@ public class BinderCallsStatsTest { TestBinderCallsStats bcs = new TestBinderCallsStats(); bcs.setDetailedTracking(true); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); CallSession callSession = bcs.callStarted(binder, 1); bcs.callThrewException(callSession, new IllegalStateException()); bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); Loading @@ -377,7 +356,7 @@ public class BinderCallsStatsTest { TestBinderCallsStats bcs = new TestBinderCallsStats(); bcs.setDetailedTracking(false); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); CallSession callSession = bcs.callStarted(binder, 1); bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); assertEquals(0, bcs.getExportedCallStats().size()); Loading @@ -388,7 +367,7 @@ public class BinderCallsStatsTest { TestBinderCallsStats bcs = new TestBinderCallsStats(); bcs.setDetailedTracking(true); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); CallSession callSession = bcs.callStarted(binder, 1); bcs.time += 10; bcs.elapsedTime += 20; bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); Loading Loading
apct-tests/perftests/core/src/android/os/BinderCallsStatsPerfTest.java +3 −2 Original line number Diff line number Diff line Loading @@ -22,6 +22,7 @@ import android.support.test.filters.LargeTest; import android.support.test.runner.AndroidJUnit4; import com.android.internal.os.BinderCallsStats; import com.android.internal.os.BinderInternal.CallSession; import java.util.Random; Loading Loading @@ -61,7 +62,7 @@ public class BinderCallsStatsPerfTest { Binder b = new Binder(); int i = 0; while (state.keepRunning()) { BinderCallsStats.CallSession s = mBinderCallsStats.callStarted(b, i % 100); CallSession s = mBinderCallsStats.callStarted(b, i % 100); mBinderCallsStats.callEnded(s, 0, 0); i++; } Loading @@ -73,7 +74,7 @@ public class BinderCallsStatsPerfTest { final BenchmarkState state = mPerfStatusReporter.getBenchmarkState(); Binder b = new Binder(); while (state.keepRunning()) { BinderCallsStats.CallSession s = mBinderCallsStats.callStarted(b, 0); CallSession s = mBinderCallsStats.callStarted(b, 0); mBinderCallsStats.callEnded(s, 0, 0); } } Loading
core/java/android/os/Binder.java +26 −6 Original line number Diff line number Diff line Loading @@ -22,8 +22,8 @@ import android.util.ExceptionUtils; import android.util.Log; import android.util.Slog; import com.android.internal.os.BinderCallsStats; import com.android.internal.os.BinderInternal; import com.android.internal.os.BinderInternal.CallSession; import com.android.internal.util.FastPrintWriter; import com.android.internal.util.FunctionalUtils.ThrowingRunnable; import com.android.internal.util.FunctionalUtils.ThrowingSupplier; Loading Loading @@ -92,6 +92,11 @@ public class Binder implements IBinder { */ private static volatile TransactionTracker sTransactionTracker = null; /** * Global observer for this process. */ private static BinderInternal.Observer sObserver = null; /** * Guestimate of native memory associated with a Binder. */ Loading @@ -106,6 +111,7 @@ public class Binder implements IBinder { Binder.class.getClassLoader(), getNativeFinalizer(), NATIVE_ALLOCATION_SIZE); } // Transaction tracking code. /** Loading Loading @@ -151,6 +157,15 @@ public class Binder implements IBinder { return sTransactionTracker; } /** * Get the binder transaction observer for this process. * * @hide */ public static void setObserver(@Nullable BinderInternal.Observer observer) { sObserver = observer; } /** {@hide} */ static volatile boolean sWarnOnBlocking = false; Loading Loading @@ -721,8 +736,10 @@ public class Binder implements IBinder { // Entry point from android_util_Binder.cpp's onTransact private boolean execTransact(int code, long dataObj, long replyObj, int flags) { BinderCallsStats binderCallsStats = BinderCallsStats.getInstance(); BinderCallsStats.CallSession callSession = binderCallsStats.callStarted(this, code); // Make sure the observer won't change while processing a transaction. final BinderInternal.Observer observer = sObserver; final CallSession callSession = observer != null ? observer.callStarted(this, code) : null; Parcel data = Parcel.obtain(dataObj); Parcel reply = Parcel.obtain(replyObj); // theoretically, we should call transact, which will call onTransact, Loading @@ -738,7 +755,9 @@ public class Binder implements IBinder { } res = onTransact(code, data, reply, flags); } catch (RemoteException|RuntimeException e) { binderCallsStats.callThrewException(callSession, e); if (observer != null) { observer.callThrewException(callSession, e); } if (LOG_RUNTIME_EXCEPTION) { Log.w(TAG, "Caught a RuntimeException from the binder stub implementation.", e); } Loading Loading @@ -770,9 +789,10 @@ public class Binder implements IBinder { // to the main transaction loop to wait for another incoming transaction. Either // way, strict mode begone! StrictMode.clearGatheredViolations(); binderCallsStats.callEnded(callSession, requestSizeBytes, replySizeBytes); if (observer != null) { observer.callEnded(callSession, requestSizeBytes, replySizeBytes); } return res; } }
core/java/com/android/internal/os/BinderCallsStats.java +49 −76 Original line number Diff line number Diff line Loading @@ -29,6 +29,7 @@ import android.util.SparseArray; import com.android.internal.annotations.GuardedBy; import com.android.internal.annotations.VisibleForTesting; import com.android.internal.os.BinderInternal.CallSession; import com.android.internal.util.Preconditions; import java.io.PrintWriter; Loading @@ -47,7 +48,7 @@ import java.util.function.ToDoubleFunction; * Collects statistics about CPU time spent per binder call across multiple dimensions, e.g. * per thread, uid or call description. */ public class BinderCallsStats { public class BinderCallsStats implements BinderInternal.Observer { public static final boolean ENABLED_DEFAULT = true; public static final boolean DETAILED_TRACKING_DEFAULT = true; public static final int PERIODIC_SAMPLING_INTERVAL_DEFAULT = 10; Loading @@ -57,12 +58,9 @@ public class BinderCallsStats { private static final int PERIODIC_SAMPLING_INTERVAL = 10; private static final int MAX_EXCEPTION_COUNT_SIZE = 50; private static final String EXCEPTION_COUNT_OVERFLOW_NAME = "overflow"; private static final CallSession NOT_ENABLED = new CallSession(); private static final BinderCallsStats sInstance = new BinderCallsStats(new Random()); private volatile boolean mEnabled = ENABLED_DEFAULT; private volatile boolean mDetailedTracking = DETAILED_TRACKING_DEFAULT; private volatile int mPeriodicSamplingInterval = PERIODIC_SAMPLING_INTERVAL_DEFAULT; private boolean mDetailedTracking = DETAILED_TRACKING_DEFAULT; private int mPeriodicSamplingInterval = PERIODIC_SAMPLING_INTERVAL_DEFAULT; @GuardedBy("mLock") private final SparseArray<UidEntry> mUidEntries = new SparseArray<>(); @GuardedBy("mLock") Loading @@ -72,28 +70,24 @@ public class BinderCallsStats { private final Random mRandom; private long mStartTime = System.currentTimeMillis(); @VisibleForTesting // Use getInstance() instead. public BinderCallsStats(Random random) { this.mRandom = random; } @Override public CallSession callStarted(Binder binder, int code) { return callStarted(binder.getClass().getName(), code, binder.getTransactionName(code)); } private CallSession callStarted(String className, int code, @Nullable String methodName) { if (!mEnabled) { return NOT_ENABLED; } CallSession s = mCallSessionsPool.poll(); if (s == null) { s = new CallSession(); } s.callStat.className = className; s.callStat.msg = code; s.callStat.methodName = methodName; s.className = className; s.transactionCode = code; s.methodName = methodName; s.exceptionThrown = false; s.cpuTimeStarted = -1; s.timeStarted = -1; Loading @@ -109,9 +103,9 @@ public class BinderCallsStats { return s; } public void callEnded(CallSession s, int parcelRequestSize, int parcelReplySize) { Preconditions.checkNotNull(s); if (s == NOT_ENABLED) { @Override public void callEnded(@Nullable CallSession s, int parcelRequestSize, int parcelReplySize) { if (s == null) { return; } Loading @@ -124,10 +118,6 @@ public class BinderCallsStats { private void processCallEnded(CallSession s, int parcelRequestSize, int parcelReplySize) { synchronized (mLock) { if (!mEnabled) { return; } final int callingUid = getCallingUid(); UidEntry uidEntry = mUidEntries.get(callingUid); if (uidEntry == null) { Loading @@ -135,7 +125,7 @@ public class BinderCallsStats { mUidEntries.put(callingUid, uidEntry); } uidEntry.callCount++; CallStat callStat = uidEntry.getOrCreate(s.callStat); CallStat callStat = uidEntry.getOrCreate(s.className, s.transactionCode); callStat.callCount++; // Non-negative time signals we need to record data for this call. Loading @@ -147,7 +137,7 @@ public class BinderCallsStats { uidEntry.recordedCallCount++; callStat.recordedCallCount++; callStat.methodName = s.callStat.methodName; callStat.methodName = s.methodName; callStat.cpuTimeMicros += duration; callStat.maxCpuTimeMicros = Math.max(callStat.maxCpuTimeMicros, duration); callStat.latencyMicros += latencyDuration; Loading @@ -164,16 +154,9 @@ public class BinderCallsStats { } } /** * Called if an exception is thrown while executing the binder transaction. * * <li>BinderCallsStats#callEnded will be called afterwards. * <li>Do not throw an exception in this method, it will swallow the original exception thrown * by the binder transaction. */ public void callThrewException(CallSession s, Exception exception) { Preconditions.checkNotNull(s); if (!mEnabled) { @Override public void callThrewException(@Nullable CallSession s, Exception exception) { if (s == null) { return; } s.exceptionThrown = true; Loading Loading @@ -208,7 +191,7 @@ public class BinderCallsStats { exported.uid = entry.uid; exported.className = stat.className; exported.methodName = stat.methodName == null ? String.valueOf(stat.msg) : stat.methodName; ? String.valueOf(stat.transactionCode) : stat.methodName; exported.cpuTimeMicros = stat.cpuTimeMicros; exported.maxCpuTimeMicros = stat.maxCpuTimeMicros; exported.latencyMicros = stat.latencyMicros; Loading @@ -233,11 +216,6 @@ public class BinderCallsStats { } private void dumpLocked(PrintWriter pw, Map<Integer,String> appIdToPkgNameMap, boolean verbose) { if (!mEnabled) { pw.println("Binder calls stats disabled."); return; } long totalCallsCount = 0; long totalRecordedCallsCount = 0; long totalCpuTime = 0; Loading Loading @@ -340,10 +318,6 @@ public class BinderCallsStats { return mRandom.nextInt() % mPeriodicSamplingInterval == 0; } public static BinderCallsStats getInstance() { return sInstance; } public void setDetailedTracking(boolean enabled) { synchronized (mLock) { if (enabled != mDetailedTracking) { Loading @@ -353,15 +327,6 @@ public class BinderCallsStats { } } public void setEnabled(boolean enabled) { synchronized (mLock) { if (enabled != mEnabled) { mEnabled = enabled; reset(); } } } public void setSamplingInterval(int samplingInterval) { synchronized (mLock) { if (samplingInterval != mPeriodicSamplingInterval) { Loading Loading @@ -400,7 +365,7 @@ public class BinderCallsStats { @VisibleForTesting public static class CallStat { public String className; public int msg; public int transactionCode; // Method name might be null when we cannot resolve the transaction code. For instance, if // the binder was not generated by AIDL. public @Nullable String methodName; Loading @@ -427,10 +392,21 @@ public class BinderCallsStats { CallStat() { } CallStat(String className, int msg) { CallStat(String className, int transactionCode) { this.className = className; this.msg = msg; this.transactionCode = transactionCode; } @Override public String toString() { return className + "#" + (methodName == null ? transactionCode : methodName); } } /** Key used to store CallStat object in a Map. */ public static class CallStatKey { public String className; public int transactionCode; @Override public boolean equals(Object o) { Loading @@ -438,29 +414,19 @@ public class BinderCallsStats { return true; } CallStat callStat = (CallStat) o; return msg == callStat.msg && (className.equals(callStat.className)); CallStatKey key = (CallStatKey) o; return transactionCode == key.transactionCode && (className.equals(key.className)); } @Override public int hashCode() { int result = className.hashCode(); result = 31 * result + msg; result = 31 * result + transactionCode; return result; } @Override public String toString() { return className + "#" + (methodName == null ? msg : methodName); } } public static class CallSession { long cpuTimeStarted; long timeStarted; boolean exceptionThrown; final CallStat callStat = new CallStat(); } @VisibleForTesting public static class UidEntry { Loading @@ -480,14 +446,21 @@ public class BinderCallsStats { } // Aggregate time spent per each call name: call_desc -> cpu_time_micros Map<CallStat, CallStat> mCallStats = new ArrayMap<>(); CallStat getOrCreate(CallStat callStat) { CallStat mapCallStat = mCallStats.get(callStat); private Map<CallStatKey, CallStat> mCallStats = new ArrayMap<>(); private CallStatKey mTempKey = new CallStatKey(); CallStat getOrCreate(String className, int transactionCode) { // Use a global temporary key to avoid creating new objects for every lookup. mTempKey.className = className; mTempKey.transactionCode = transactionCode; CallStat mapCallStat = mCallStats.get(mTempKey); // Only create CallStat if it's a new entry, otherwise update existing instance if (mapCallStat == null) { mapCallStat = new CallStat(callStat.className, callStat.msg); mCallStats.put(mapCallStat, mapCallStat); mapCallStat = new CallStat(className, transactionCode); CallStatKey key = new CallStatKey(); key.className = className; key.transactionCode = transactionCode; mCallStats.put(key, mapCallStat); } return mapCallStat; } Loading @@ -496,7 +469,7 @@ public class BinderCallsStats { * Returns list of calls sorted by CPU time */ public List<CallStat> getCallStatsList() { List<CallStat> callStats = new ArrayList<>(mCallStats.keySet()); List<CallStat> callStats = new ArrayList<>(mCallStats.values()); callStats.sort((o1, o2) -> { if (o1.cpuTimeMicros < o2.cpuTimeMicros) { return 1; Loading
core/java/com/android/internal/os/BinderInternal.java +54 −7 Original line number Diff line number Diff line Loading @@ -17,6 +17,7 @@ package com.android.internal.os; import android.annotation.NonNull; import android.os.Binder; import android.os.Handler; import android.os.IBinder; import android.os.SystemClock; Loading Loading @@ -69,6 +70,52 @@ public class BinderInternal { } } /** * A session used by {@link Observer} in order to keep track of some data. */ public static class CallSession { // Binder interface descriptor. public String className; // Binder transaction code. public int transactionCode; // Binder transaction method name. public String methodName; // CPU time at the beginning of the call. long cpuTimeStarted; // System time at the beginning of the call. long timeStarted; // Should be set to one when an exception is thrown. boolean exceptionThrown; } /** * Allows to track various steps of an API call. */ public interface Observer { /** * Called when a binder call starts. * * @return a CallSession to pass to the callEnded method. */ CallSession callStarted(Binder binder, int code); /** * Called when a binder call stops. * * <li>This method will be called even when an exception is thrown. */ void callEnded(CallSession s, int parcelRequestSize, int parcelReplySize); /** * Called if an exception is thrown while executing the binder transaction. * * <li>BinderCallsStats#callEnded will be called afterwards. * <li>Do not throw an exception in this method, it will swallow the original exception * thrown by the binder transaction. */ public void callThrewException(CallSession s, Exception exception); } /** * Add the calling thread to the IPC thread pool. This function does * not return until the current process is exiting. Loading
core/tests/coretests/src/com/android/internal/os/BinderCallsStatsTest.java +31 −52 Original line number Diff line number Diff line Loading @@ -23,6 +23,8 @@ import android.support.test.runner.AndroidJUnit4; import android.util.ArrayMap; import android.util.SparseArray; import com.android.internal.os.BinderInternal.CallSession; import org.junit.Assert; import org.junit.Test; import org.junit.runner.RunWith; Loading Loading @@ -52,7 +54,7 @@ public class BinderCallsStatsTest { bcs.setSamplingInterval(5); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); CallSession callSession = bcs.callStarted(binder, 1); bcs.time += 10; bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); Loading @@ -65,7 +67,7 @@ public class BinderCallsStatsTest { assertEquals(1, uidEntry.recordedCallCount); assertEquals(10, uidEntry.cpuTimeMicros); assertEquals(binder.getClass().getName(), callStatsList.get(0).className); assertEquals(1, callStatsList.get(0).msg); assertEquals(1, callStatsList.get(0).transactionCode); // CPU usage is sampled, should not be tracked here. callSession = bcs.callStarted(binder, 1); Loading Loading @@ -93,7 +95,7 @@ public class BinderCallsStatsTest { bcs.setDetailedTracking(true); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); CallSession callSession = bcs.callStarted(binder, 1); bcs.time += 10; bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); Loading @@ -109,7 +111,7 @@ public class BinderCallsStatsTest { assertEquals(1, callStatsList.get(0).callCount); assertEquals(10, callStatsList.get(0).cpuTimeMicros); assertEquals(binder.getClass().getName(), callStatsList.get(0).className); assertEquals(1, callStatsList.get(0).msg); assertEquals(1, callStatsList.get(0).transactionCode); callSession = bcs.callStarted(binder, 1); bcs.time += 20; Loading @@ -134,44 +136,21 @@ public class BinderCallsStatsTest { } @Test public void testDisabled() { TestBinderCallsStats bcs = new TestBinderCallsStats(); bcs.setEnabled(false); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); bcs.time += 10; bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); SparseArray<BinderCallsStats.UidEntry> uidEntries = bcs.getUidEntries(); assertEquals(0, uidEntries.size()); } @Test public void testDisableInBetweenCall() { public void testEnableInBetweenCall() { TestBinderCallsStats bcs = new TestBinderCallsStats(); bcs.setEnabled(true); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); bcs.time += 10; bcs.setEnabled(false); bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); bcs.callEnded(null, REQUEST_SIZE, REPLY_SIZE); SparseArray<BinderCallsStats.UidEntry> uidEntries = bcs.getUidEntries(); assertEquals(0, uidEntries.size()); } @Test public void testEnableInBetweenCall() { public void testInBetweenCallWhenExceptionThrown() { TestBinderCallsStats bcs = new TestBinderCallsStats(); bcs.setEnabled(false); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); bcs.time += 10; bcs.setEnabled(true); bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); bcs.callThrewException(null, new IllegalStateException()); bcs.callEnded(null, REQUEST_SIZE, REPLY_SIZE); SparseArray<BinderCallsStats.UidEntry> uidEntries = bcs.getUidEntries(); assertEquals(0, uidEntries.size()); Loading @@ -184,7 +163,7 @@ public class BinderCallsStatsTest { bcs.setSamplingInterval(2); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); CallSession callSession = bcs.callStarted(binder, 1); bcs.time += 10; bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); Loading Loading @@ -221,7 +200,7 @@ public class BinderCallsStatsTest { bcs.setSamplingInterval(2); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); CallSession callSession = bcs.callStarted(binder, 1); bcs.time += 10; bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); Loading Loading @@ -264,13 +243,13 @@ public class BinderCallsStatsTest { return "resolved"; } }; BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); CallSession callSession = bcs.callStarted(binder, 1); bcs.time += 10; bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); List<BinderCallsStats.CallStat> callStatsList = bcs.getUidEntries().get(TEST_UID).getCallStatsList(); assertEquals(1, callStatsList.get(0).msg); assertEquals(1, callStatsList.get(0).transactionCode); assertEquals("resolved", callStatsList.get(0).methodName); } Loading @@ -279,7 +258,7 @@ public class BinderCallsStatsTest { TestBinderCallsStats bcs = new TestBinderCallsStats(); bcs.setDetailedTracking(true); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); CallSession callSession = bcs.callStarted(binder, 1); bcs.time += 10; bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); Loading @@ -295,7 +274,7 @@ public class BinderCallsStatsTest { TestBinderCallsStats bcs = new TestBinderCallsStats(); bcs.setDetailedTracking(true); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); CallSession callSession = bcs.callStarted(binder, 1); bcs.time += 50; bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); Loading @@ -314,7 +293,7 @@ public class BinderCallsStatsTest { TestBinderCallsStats bcs = new TestBinderCallsStats(); bcs.setDetailedTracking(true); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); CallSession callSession = bcs.callStarted(binder, 1); bcs.elapsedTime += 5; bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); Loading @@ -341,7 +320,7 @@ public class BinderCallsStatsTest { TestBinderCallsStats bcs = new TestBinderCallsStats(); bcs.setDetailedTracking(true); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); CallSession callSession = bcs.callStarted(binder, 1); bcs.callThrewException(callSession, new IllegalStateException()); bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); Loading @@ -364,7 +343,7 @@ public class BinderCallsStatsTest { TestBinderCallsStats bcs = new TestBinderCallsStats(); bcs.setDetailedTracking(true); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); CallSession callSession = bcs.callStarted(binder, 1); bcs.callThrewException(callSession, new IllegalStateException()); bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); Loading @@ -377,7 +356,7 @@ public class BinderCallsStatsTest { TestBinderCallsStats bcs = new TestBinderCallsStats(); bcs.setDetailedTracking(false); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); CallSession callSession = bcs.callStarted(binder, 1); bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); assertEquals(0, bcs.getExportedCallStats().size()); Loading @@ -388,7 +367,7 @@ public class BinderCallsStatsTest { TestBinderCallsStats bcs = new TestBinderCallsStats(); bcs.setDetailedTracking(true); Binder binder = new Binder(); BinderCallsStats.CallSession callSession = bcs.callStarted(binder, 1); CallSession callSession = bcs.callStarted(binder, 1); bcs.time += 10; bcs.elapsedTime += 20; bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE); Loading