Merge "Create BinderLatencyObserver to collect binder call latency stats. Pushing these as a metric will come in a future change."

This commit is contained in:
Siim Sammul
2021-05-10 18:10:58 +00:00
committed by Gerrit Code Review
5 changed files with 346 additions and 0 deletions

View File

@@ -54,6 +54,7 @@ public class BinderCallsStats implements BinderInternal.Observer {
public static final int PERIODIC_SAMPLING_INTERVAL_DEFAULT = 1000;
public static final boolean DEFAULT_TRACK_SCREEN_INTERACTIVE = false;
public static final boolean DEFAULT_TRACK_DIRECT_CALLING_UID = true;
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_";
@@ -89,19 +90,27 @@ public class BinderCallsStats implements BinderInternal.Observer {
private boolean mAddDebugEntries = false;
private boolean mTrackDirectCallingUid = DEFAULT_TRACK_DIRECT_CALLING_UID;
private boolean mTrackScreenInteractive = DEFAULT_TRACK_SCREEN_INTERACTIVE;
private boolean mCollectLatencyData = DEFAULT_COLLECT_LATENCY_DATA;
private CachedDeviceState.Readonly mDeviceState;
private CachedDeviceState.TimeInStateStopwatch mBatteryStopwatch;
private BinderLatencyObserver mLatencyObserver;
/** Injector for {@link BinderCallsStats}. */
public static class Injector {
public Random getRandomGenerator() {
return new Random();
}
public BinderLatencyObserver getLatencyObserver() {
return new BinderLatencyObserver(new BinderLatencyObserver.Injector());
}
}
public BinderCallsStats(Injector injector) {
this.mRandom = injector.getRandomGenerator();
this.mLatencyObserver = injector.getLatencyObserver();
}
public void setDeviceState(@NonNull CachedDeviceState.Readonly deviceState) {
@@ -128,7 +137,10 @@ public class BinderCallsStats implements BinderInternal.Observer {
if (shouldRecordDetailedData()) {
s.cpuTimeStarted = getThreadTimeMicro();
s.timeStarted = getElapsedRealtimeMicro();
} else if (mCollectLatencyData) {
s.timeStarted = getElapsedRealtimeMicro();
}
return s;
}
@@ -153,6 +165,10 @@ public class BinderCallsStats implements BinderInternal.Observer {
private void processCallEnded(CallSession s,
int parcelRequestSize, int parcelReplySize, int workSourceUid) {
if (mCollectLatencyData) {
mLatencyObserver.callEnded(s);
}
// Non-negative time signals we need to record data for this call.
final boolean recordCall = s.cpuTimeStarted >= 0;
final long duration;
@@ -555,6 +571,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;
@@ -565,6 +592,8 @@ public class BinderCallsStats implements BinderInternal.Observer {
if (mBatteryStopwatch != null) {
mBatteryStopwatch.reset();
}
// Do not reset the latency observer as binder stats and latency will be pushed to
// statsd at different intervals so the resets should not be coupled.
}
}
@@ -767,6 +796,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) {

View File

@@ -0,0 +1,157 @@
/*
* 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;
}
}

View File

@@ -753,6 +753,34 @@ public class BinderCallsStatsTest {
assertEquals(1, callStats.recordedCallCount);
}
@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());
}
class TestBinderCallsStats extends BinderCallsStats {
public int callingUid = CALLING_UID;
public long time = 1234;
@@ -774,6 +802,10 @@ public class BinderCallsStatsTest {
}
};
}
public BinderLatencyObserver getLatencyObserver() {
return new BinderLatencyObserverTest.TestBinderLatencyObserver();
}
});
setSamplingInterval(1);
setAddDebugEntries(false);

View File

@@ -0,0 +1,110 @@
/*
* 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;
}
}
}

View File

@@ -40,6 +40,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;
@@ -120,6 +121,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";
@@ -127,6 +129,10 @@ public class BinderCallsStatsService extends Binder {
private static final String SETTINGS_TRACK_SCREEN_INTERACTIVE_KEY = "track_screen_state";
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";
// 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);
@@ -180,6 +186,13 @@ public class BinderCallsStatsService extends Binder {
mBinderCallsStats.setTrackDirectCallerUid(
mParser.getBoolean(SETTINGS_TRACK_DIRECT_CALLING_UID_KEY,
BinderCallsStats.DEFAULT_TRACK_DIRECT_CALLING_UID));
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 =
@@ -198,6 +211,7 @@ public class BinderCallsStatsService extends Binder {
mEnabled = enabled;
mBinderCallsStats.reset();
mBinderCallsStats.setAddDebugEntries(enabled);
mBinderCallsStats.getLatencyObserver().reset();
}
}
}