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

Original change: https://android-review.googlesource.com/c/platform/frameworks/base/+/1697178

Change-Id: I025d7728e7cc5dd6a3491d254013f7832ea4b01d

2 files changed, 190 insertions, 0 deletions

diff --git a/core/java/com/android/internal/os/BinderCallsStats.java b/core/java/com/android/internal/os/BinderCallsStats.java
index 0fb2728aed73..dbba469dda1a 100644
--- a/core/java/com/android/internal/os/BinderCallsStats.java
+++ b/core/java/com/android/internal/os/BinderCallsStats.java
@@ -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) {
diff --git a/core/java/com/android/internal/os/BinderLatencyObserver.java b/core/java/com/android/internal/os/BinderLatencyObserver.java
new file mode 100644
index 000000000000..92b495284de2
--- /dev/null
+++ b/core/java/com/android/internal/os/BinderLatencyObserver.java
@@ -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;
+    }
+}