Create BinderLatencyObserver to collect binder call latency stats. (8d0ecde2) · Commits · e / os / android_frameworks_base

core/java/com/android/internal/os/BinderCallsStats.java

+32 −0

Original line number	Diff line number	Diff line
		@@ -57,6 +57,7 @@ public class BinderCallsStats implements BinderInternal.Observer {
		public static final boolean DEFAULT_TRACK_SCREEN_INTERACTIVE = false;
		public static final boolean DEFAULT_TRACK_DIRECT_CALLING_UID = true;
		public static final boolean DEFAULT_IGNORE_BATTERY_STATUS = false;
		public static final boolean DEFAULT_COLLECT_LATENCY_DATA = false;
		public static final int MAX_BINDER_CALL_STATS_COUNT_DEFAULT = 1500;
		private static final String DEBUG_ENTRY_PREFIX = "__DEBUG_";

		@@ -97,11 +98,13 @@ public class BinderCallsStats implements BinderInternal.Observer {
		private boolean mTrackDirectCallingUid = DEFAULT_TRACK_DIRECT_CALLING_UID;
		private boolean mTrackScreenInteractive = DEFAULT_TRACK_SCREEN_INTERACTIVE;
		private boolean mIgnoreBatteryStatus = DEFAULT_IGNORE_BATTERY_STATUS;
		private boolean mCollectLatencyData = DEFAULT_COLLECT_LATENCY_DATA;

		private CachedDeviceState.Readonly mDeviceState;
		private CachedDeviceState.TimeInStateStopwatch mBatteryStopwatch;

		private static final int CALL_STATS_OBSERVER_DEBOUNCE_MILLIS = 5000;
		private BinderLatencyObserver mLatencyObserver;
		private BinderInternal.CallStatsObserver mCallStatsObserver;
		private ArraySet<Integer> mSendUidsToObserver = new ArraySet<>(32);
		private final Handler mCallStatsObserverHandler;
		@@ -148,11 +151,16 @@ public class BinderCallsStats implements BinderInternal.Observer {
		public Handler getHandler() {
		return new Handler(Looper.getMainLooper());
		}

		public BinderLatencyObserver getLatencyObserver() {
		return new BinderLatencyObserver(new BinderLatencyObserver.Injector());
		}
		}

		public BinderCallsStats(Injector injector) {
		this.mRandom = injector.getRandomGenerator();
		this.mCallStatsObserverHandler = injector.getHandler();
		this.mLatencyObserver = injector.getLatencyObserver();
		}

		public void setDeviceState(@NonNull CachedDeviceState.Readonly deviceState) {
		@@ -202,7 +210,10 @@ public class BinderCallsStats implements BinderInternal.Observer {
		if (mRecordingAllTransactionsForUid \|\| s.recordedCall) {
		s.cpuTimeStarted = getThreadTimeMicro();
		s.timeStarted = getElapsedRealtimeMicro();
		} else if (mCollectLatencyData) {
		s.timeStarted = getElapsedRealtimeMicro();
		}

		return s;
		}

		@@ -227,6 +238,10 @@ public class BinderCallsStats implements BinderInternal.Observer {

		private void processCallEnded(CallSession s,
		int parcelRequestSize, int parcelReplySize, int workSourceUid) {
		if (mCollectLatencyData) {
		mLatencyObserver.callEnded(s);
		}

		UidEntry uidEntry = null;
		final boolean recordCall;
		if (s.recordedCall) {
		@@ -752,6 +767,17 @@ public class BinderCallsStats implements BinderInternal.Observer {
		}
		}

		/** Whether to collect latency histograms. */
		public void setCollectLatencyData(boolean collectLatencyData) {
		mCollectLatencyData = collectLatencyData;
		}

		/** Whether to collect latency histograms. */
		@VisibleForTesting
		public boolean getCollectLatencyData() {
		return mCollectLatencyData;
		}

		public void reset() {
		synchronized (mLock) {
		mCallStatsCount = 0;
		@@ -763,6 +789,8 @@ public class BinderCallsStats implements BinderInternal.Observer {
		mBatteryStopwatch.reset();
		}
		mRecordingAllTransactionsForUid = false;
		// Do not reset the latency observer as binder stats and latency will be pushed to WW
		// at different intervals so the resets should not be coupled.
		}
		}

		@@ -987,6 +1015,10 @@ public class BinderCallsStats implements BinderInternal.Observer {
		return mExceptionCounts;
		}

		public BinderLatencyObserver getLatencyObserver() {
		return mLatencyObserver;
		}

		@VisibleForTesting
		public static <T> List<T> getHighestValues(List<T> list, ToDoubleFunction<T> toDouble,
		double percentile) {

core/java/com/android/internal/os/BinderLatencyObserver.java

0 → 100644

+157 −0

Original line number	Diff line number	Diff line
		/*
		* Copyright (C) 2017 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.internal.os;

		import android.annotation.Nullable;
		import android.os.Binder;
		import android.os.SystemClock;
		import android.util.ArrayMap;
		import android.util.Slog;

		import com.android.internal.annotations.GuardedBy;
		import com.android.internal.annotations.VisibleForTesting;
		import com.android.internal.os.BinderInternal.CallSession;

		import java.util.ArrayList;
		import java.util.Random;

		/** Collects statistics about Binder call latency per calling API and method. */
		public class BinderLatencyObserver {
		private static final String TAG = "BinderLatencyObserver";
		public static final int PERIODIC_SAMPLING_INTERVAL_DEFAULT = 10;

		// This is not the final data structure - we will eventually store latency histograms instead of
		// raw samples as it is much more memory / disk space efficient.
		// TODO(b/179999191): change this to store the histogram.
		// TODO(b/179999191): pre allocate the array size so we would not have to resize this.
		@GuardedBy("mLock")
		private final ArrayMap<LatencyDims, ArrayList<Long>> mLatencySamples = new ArrayMap<>();
		private final Object mLock = new Object();

		// Sampling period to control how often to track CPU usage. 1 means all calls, 100 means ~1 out
		// of 100 requests.
		private int mPeriodicSamplingInterval = PERIODIC_SAMPLING_INTERVAL_DEFAULT;
		private final Random mRandom;

		/** Injector for {@link BinderLatencyObserver}. */
		public static class Injector {
		public Random getRandomGenerator() {
		return new Random();
		}
		}

		public BinderLatencyObserver(Injector injector) {
		mRandom = injector.getRandomGenerator();
		}

		/** Should be called when a Binder call completes, will store latency data. */
		public void callEnded(@Nullable CallSession s) {
		if (s == null \|\| s.exceptionThrown \|\| !shouldKeepSample()) {
		return;
		}

		LatencyDims dims = new LatencyDims(s.binderClass, s.transactionCode);
		long callDuration = getElapsedRealtimeMicro() - s.timeStarted;

		synchronized (mLock) {
		if (!mLatencySamples.containsKey(dims)) {
		mLatencySamples.put(dims, new ArrayList<Long>());
		}

		mLatencySamples.get(dims).add(callDuration);
		}
		}

		protected long getElapsedRealtimeMicro() {
		return SystemClock.elapsedRealtimeNanos() / 1000;
		}

		protected boolean shouldKeepSample() {
		return mRandom.nextInt() % mPeriodicSamplingInterval == 0;
		}

		/** Updates the sampling interval. */
		public void setSamplingInterval(int samplingInterval) {
		if (samplingInterval <= 0) {
		Slog.w(TAG, "Ignored invalid sampling interval (value must be positive): "
		+ samplingInterval);
		return;
		}

		synchronized (mLock) {
		if (samplingInterval != mPeriodicSamplingInterval) {
		mPeriodicSamplingInterval = samplingInterval;
		reset();
		}
		}
		}

		/** Resets the sample collection. */
		public void reset() {
		synchronized (mLock) {
		mLatencySamples.clear();
		}
		}

		/** Container for binder latency information. */
		public static class LatencyDims {
		// Binder interface descriptor.
		private Class<? extends Binder> mBinderClass;
		// Binder transaction code.
		private int mTransactionCode;
		// Cached hash code, 0 if not set yet.
		private int mHashCode = 0;

		public LatencyDims(Class<? extends Binder> binderClass, int transactionCode) {
		this.mBinderClass = binderClass;
		this.mTransactionCode = transactionCode;
		}

		public Class<? extends Binder> getBinderClass() {
		return mBinderClass;
		}

		public int getTransactionCode() {
		return mTransactionCode;
		}

		@Override
		public boolean equals(final Object other) {
		if (other == null \|\| !(other instanceof LatencyDims)) {
		return false;
		}
		LatencyDims o = (LatencyDims) other;
		return mTransactionCode == o.getTransactionCode() && mBinderClass == o.getBinderClass();
		}

		@Override
		public int hashCode() {
		if (mHashCode != 0) {
		return mHashCode;
		}
		int hash = mTransactionCode;
		hash = 31 * hash + mBinderClass.hashCode();
		mHashCode = hash;
		return hash;
		}
		}

		@VisibleForTesting
		public ArrayMap<LatencyDims, ArrayList<Long>> getLatencySamples() {
		return mLatencySamples;
		}
		}

core/tests/coretests/src/com/android/internal/os/BinderCallsStatsTest.java

+32 −0

Original line number	Diff line number	Diff line
		@@ -923,6 +923,34 @@ public class BinderCallsStatsTest {
		}
		}

		@Test
		public void testLatencyCollectionEnabled() {
		TestBinderCallsStats bcs = new TestBinderCallsStats();
		bcs.setCollectLatencyData(true);

		Binder binder = new Binder();
		CallSession callSession = bcs.callStarted(binder, 1, WORKSOURCE_UID);
		bcs.time += 10;
		bcs.elapsedTime += 20;
		bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE, WORKSOURCE_UID);

		assertEquals(1, bcs.getLatencyObserver().getLatencySamples().size());
		}

		@Test
		public void testLatencyCollectionDisabledByDefault() {
		TestBinderCallsStats bcs = new TestBinderCallsStats();
		assertEquals(false, bcs.getCollectLatencyData());

		Binder binder = new Binder();
		CallSession callSession = bcs.callStarted(binder, 1, WORKSOURCE_UID);
		bcs.time += 10;
		bcs.elapsedTime += 20;
		bcs.callEnded(callSession, REQUEST_SIZE, REPLY_SIZE, WORKSOURCE_UID);

		assertEquals(0, bcs.getLatencyObserver().getLatencySamples().size());
		}

		private static class TestHandler extends Handler {
		ArrayList<Runnable> mRunnables = new ArrayList<>();

		@@ -963,6 +991,10 @@ public class BinderCallsStatsTest {
		public Handler getHandler() {
		return mHandler;
		}

		public BinderLatencyObserver getLatencyObserver() {
		return new BinderLatencyObserverTest.TestBinderLatencyObserver();
		}
		});
		setSamplingInterval(1);
		setAddDebugEntries(false);

core/tests/coretests/src/com/android/internal/os/BinderLatencyObserverTest.java

0 → 100644

+110 −0

Original line number	Diff line number	Diff line
		/*
		* Copyright (C) 2018 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.internal.os;

		import static com.google.common.truth.Truth.assertThat;

		import static org.junit.Assert.assertEquals;

		import android.os.Binder;
		import android.platform.test.annotations.Presubmit;
		import android.util.ArrayMap;

		import androidx.test.filters.SmallTest;
		import androidx.test.runner.AndroidJUnit4;

		import com.android.internal.os.BinderInternal.CallSession;
		import com.android.internal.os.BinderLatencyObserver.LatencyDims;

		import org.junit.Test;
		import org.junit.runner.RunWith;

		import java.util.ArrayList;
		import java.util.Arrays;
		import java.util.Random;

		@SmallTest
		@RunWith(AndroidJUnit4.class)
		@Presubmit
		public class BinderLatencyObserverTest {
		@Test
		public void testLatencyCollectionWithMultipleClasses() {
		TestBinderLatencyObserver blo = new TestBinderLatencyObserver();

		Binder binder = new Binder();
		CallSession callSession = new CallSession();
		callSession.binderClass = binder.getClass();
		callSession.transactionCode = 1;
		blo.callEnded(callSession);
		blo.callEnded(callSession);
		callSession.transactionCode = 2;
		blo.callEnded(callSession);

		ArrayMap<LatencyDims, ArrayList<Long>> latencySamples = blo.getLatencySamples();
		assertEquals(2, latencySamples.keySet().size());
		assertThat(latencySamples.get(new LatencyDims(binder.getClass(), 1)))
		.containsExactlyElementsIn(Arrays.asList(1L, 2L));
		assertThat(latencySamples.get(new LatencyDims(binder.getClass(), 2))).containsExactly(3L);
		}

		@Test
		public void testSampling() {
		TestBinderLatencyObserver blo = new TestBinderLatencyObserver();
		blo.setSamplingInterval(2);

		Binder binder = new Binder();
		CallSession callSession = new CallSession();
		callSession.binderClass = binder.getClass();
		callSession.transactionCode = 1;
		blo.callEnded(callSession);
		callSession.transactionCode = 2;
		blo.callEnded(callSession);

		ArrayMap<LatencyDims, ArrayList<Long>> latencySamples = blo.getLatencySamples();
		assertEquals(1, latencySamples.size());
		LatencyDims dims = latencySamples.keySet().iterator().next();
		assertEquals(binder.getClass(), dims.getBinderClass());
		assertEquals(1, dims.getTransactionCode());
		ArrayList<Long> values = latencySamples.get(dims);
		assertThat(values).containsExactly(1L);
		}

		public static class TestBinderLatencyObserver extends BinderLatencyObserver {
		private long mElapsedTimeCallCount = 0;

		TestBinderLatencyObserver() {
		// Make random generator not random.
		super(new Injector() {
		public Random getRandomGenerator() {
		return new Random() {
		int mCallCount = 0;

		public int nextInt() {
		return mCallCount++;
		}
		};
		}
		});
		setSamplingInterval(1);
		}

		@Override
		protected long getElapsedRealtimeMicro() {
		return ++mElapsedTimeCallCount;
		}
		}
		}

services/core/java/com/android/server/BinderCallsStatsService.java

+14 −0

Original line number	Diff line number	Diff line
		@@ -43,6 +43,7 @@ import com.android.internal.os.AppIdToPackageMap;
		import com.android.internal.os.BackgroundThread;
		import com.android.internal.os.BinderCallsStats;
		import com.android.internal.os.BinderInternal;
		import com.android.internal.os.BinderLatencyObserver;
		import com.android.internal.os.CachedDeviceState;
		import com.android.internal.util.DumpUtils;

		@@ -124,6 +125,7 @@ public class BinderCallsStatsService extends Binder {

		/** Listens for flag changes. */
		private static class SettingsObserver extends ContentObserver {
		// Settings for BinderCallsStats.
		private static final String SETTINGS_ENABLED_KEY = "enabled";
		private static final String SETTINGS_DETAILED_TRACKING_KEY = "detailed_tracking";
		private static final String SETTINGS_UPLOAD_DATA_KEY = "upload_data";
		@@ -132,6 +134,10 @@ public class BinderCallsStatsService extends Binder {
		private static final String SETTINGS_TRACK_DIRECT_CALLING_UID_KEY = "track_calling_uid";
		private static final String SETTINGS_MAX_CALL_STATS_KEY = "max_call_stats_count";
		private static final String SETTINGS_IGNORE_BATTERY_STATUS_KEY = "ignore_battery_status";
		// Settings for BinderLatencyObserver.
		private static final String SETTINGS_COLLECT_LATENCY_DATA_KEY = "collect_Latency_data";
		private static final String SETTINGS_LATENCY_OBSERVER_SAMPLING_INTERVAL_KEY =
		"latency_observer_sampling_interval";

		private boolean mEnabled;
		private final Uri mUri = Settings.Global.getUriFor(Settings.Global.BINDER_CALLS_STATS);
		@@ -188,6 +194,13 @@ public class BinderCallsStatsService extends Binder {
		mBinderCallsStats.setIgnoreBatteryStatus(
		mParser.getBoolean(SETTINGS_IGNORE_BATTERY_STATUS_KEY,
		BinderCallsStats.DEFAULT_IGNORE_BATTERY_STATUS));
		mBinderCallsStats.setCollectLatencyData(
		mParser.getBoolean(SETTINGS_COLLECT_LATENCY_DATA_KEY,
		BinderCallsStats.DEFAULT_COLLECT_LATENCY_DATA));
		// Binder latency observer settings.
		mBinderCallsStats.getLatencyObserver().setSamplingInterval(mParser.getInt(
		SETTINGS_LATENCY_OBSERVER_SAMPLING_INTERVAL_KEY,
		BinderLatencyObserver.PERIODIC_SAMPLING_INTERVAL_DEFAULT));


		final boolean enabled =
		@@ -206,6 +219,7 @@ public class BinderCallsStatsService extends Binder {
		mEnabled = enabled;
		mBinderCallsStats.reset();
		mBinderCallsStats.setAddDebugEntries(enabled);
		mBinderCallsStats.getLatencyObserver().reset();
		}
		}
		}