Push the latency histograms to statsd

Cherry pick from master with no changes

Test: unit tests, verified atom logging with statsd_testdrive
Bug: 180584913

Change-Id: I0b8db72c0cb3b285177bbe402ce37639c468dbf3
Merged-In: I0b8db72c0cb3b285177bbe402ce37639c468dbf3
(cherry picked from commit a28ccaf3736c0cfb755b81f904d25c8563a36e11)

1 files changed, 143 insertions, 1 deletions

diff --git a/core/java/com/android/internal/os/BinderLatencyObserver.java b/core/java/com/android/internal/os/BinderLatencyObserver.java
index 59cc66d79bce..4ca59be4877a 100644
--- a/core/java/com/android/internal/os/BinderLatencyObserver.java
+++ b/core/java/com/android/internal/os/BinderLatencyObserver.java
@@ -16,22 +16,37 @@
 
 package com.android.internal.os;
 
+import static com.android.internal.os.BinderLatencyProto.Dims.SYSTEM_SERVER;
+
 import android.annotation.Nullable;
 import android.os.Binder;
+import android.os.Handler;
+import android.os.Looper;
 import android.os.SystemClock;
 import android.util.ArrayMap;
 import android.util.Slog;
+import android.util.proto.ProtoOutputStream;
 
 import com.android.internal.annotations.GuardedBy;
 import com.android.internal.annotations.VisibleForTesting;
 import com.android.internal.os.BinderInternal.CallSession;
+import com.android.internal.os.BinderLatencyProto.ApiStats;
+import com.android.internal.os.BinderLatencyProto.Dims;
+import com.android.internal.os.BinderLatencyProto.RepeatedApiStats;
+import com.android.internal.util.FrameworkStatsLog;
 
 import java.util.Random;
 
 /** Collects statistics about Binder call latency per calling API and method. */
 public class BinderLatencyObserver {
     private static final String TAG = "BinderLatencyObserver";
+    private static final int MAX_ATOM_SIZE_BYTES = 4064;
+    // Be conservative and leave 1K space for the last histogram so we don't go over the size limit.
+    private static final int LAST_HISTOGRAM_BUFFER_SIZE_BYTES = 1000;
+
+    // Latency observer parameters.
     public static final int PERIODIC_SAMPLING_INTERVAL_DEFAULT = 10;
+    public static final int STATSD_PUSH_INTERVAL_MINUTES_DEFAULT = 360;
 
     // Histogram buckets parameters.
     public static final int BUCKET_COUNT_DEFAULT = 100;
@@ -50,20 +65,124 @@ public class BinderLatencyObserver {
     private int mFirstBucketSize = FIRST_BUCKET_SIZE_DEFAULT;
     private float mBucketScaleFactor = BUCKET_SCALE_FACTOR_DEFAULT;
 
+    private int mStatsdPushIntervalMinutes = STATSD_PUSH_INTERVAL_MINUTES_DEFAULT;
+
     private final Random mRandom;
     private BinderLatencyBuckets mLatencyBuckets;
 
+    private final Handler mLatencyObserverHandler;
+
+    private Runnable mLatencyObserverRunnable = new Runnable() {
+        @Override
+        public void run() {
+            // Schedule the next push.
+            noteLatencyDelayed();
+
+            ArrayMap<LatencyDims, int[]> histogramMap;
+            synchronized (mLock) {
+                // Copy the histograms map so we don't use the lock for longer than needed.
+                histogramMap = new ArrayMap<>(mLatencyHistograms);
+                mLatencyHistograms.clear();
+            }
+
+            BinderTransactionNameResolver resolver = new BinderTransactionNameResolver();
+            ProtoOutputStream proto = new ProtoOutputStream();
+            int histogramsWritten = 0;
+
+            for (LatencyDims dims : histogramMap.keySet()) {
+                // Start a new atom if the next histogram risks going over the atom size limit.
+                if (proto.getRawSize() + LAST_HISTOGRAM_BUFFER_SIZE_BYTES > getMaxAtomSizeBytes()) {
+                    if (histogramsWritten > 0) {
+                        writeAtomToStatsd(proto);
+                    }
+                    proto = new ProtoOutputStream();
+                    histogramsWritten = 0;
+                }
+
+                String transactionName = resolver.getMethodName(
+                        dims.getBinderClass(), dims.getTransactionCode());
+                fillApiStatsProto(proto, dims, transactionName, histogramMap.get(dims));
+                histogramsWritten++;
+            }
+            // Push the final atom.
+            if (histogramsWritten > 0) {
+                writeAtomToStatsd(proto);
+            }
+        }
+    };
+
+    private void fillApiStatsProto(
+            ProtoOutputStream proto, LatencyDims dims, String transactionName, int[] histogram) {
+        // Find the part of the histogram to write.
+        int firstNonEmptyBucket = 0;
+        for (int i = 0; i < mBucketCount; i++) {
+            if (histogram[i] != 0) {
+                firstNonEmptyBucket = i;
+                break;
+            }
+        }
+        int lastNonEmptyBucket = mBucketCount - 1;
+        for (int i = mBucketCount - 1; i >= 0; i--) {
+            if (histogram[i] != 0) {
+                lastNonEmptyBucket = i;
+                break;
+            }
+        }
+
+        // Start a new ApiStats proto.
+        long apiStatsToken = proto.start(RepeatedApiStats.API_STATS);
+
+        // Write the dims.
+        long dimsToken = proto.start(ApiStats.DIMS);
+        proto.write(Dims.PROCESS_SOURCE, SYSTEM_SERVER);
+        proto.write(Dims.SERVICE_CLASS_NAME, dims.getBinderClass().getName());
+        proto.write(Dims.SERVICE_METHOD_NAME, transactionName);
+        proto.end(dimsToken);
+
+        // Write the histogram.
+        proto.write(ApiStats.FIRST_BUCKET_INDEX, firstNonEmptyBucket);
+        for (int i = firstNonEmptyBucket; i <= lastNonEmptyBucket; i++) {
+            proto.write(ApiStats.BUCKETS, histogram[i]);
+        }
+
+        proto.end(apiStatsToken);
+    }
+
+    protected int getMaxAtomSizeBytes() {
+        return MAX_ATOM_SIZE_BYTES;
+    }
+
+    protected void writeAtomToStatsd(ProtoOutputStream atom) {
+        FrameworkStatsLog.write(
+                FrameworkStatsLog.BINDER_LATENCY_REPORTED,
+                atom.getBytes(),
+                mPeriodicSamplingInterval,
+                1);
+    }
+
+    private void noteLatencyDelayed() {
+        mLatencyObserverHandler.removeCallbacks(mLatencyObserverRunnable);
+        mLatencyObserverHandler.postDelayed(mLatencyObserverRunnable,
+                mStatsdPushIntervalMinutes * 60 * 1000);
+    }
+
     /** Injector for {@link BinderLatencyObserver}. */
     public static class Injector {
         public Random getRandomGenerator() {
             return new Random();
         }
+
+        public Handler getHandler() {
+            return new Handler(Looper.getMainLooper());
+        }
     }
 
     public BinderLatencyObserver(Injector injector) {
         mRandom = injector.getRandomGenerator();
+        mLatencyObserverHandler = injector.getHandler();
         mLatencyBuckets = new BinderLatencyBuckets(
             mBucketCount, mFirstBucketSize, mBucketScaleFactor);
+        noteLatencyDelayed();
     }
 
     /** Should be called when a Binder call completes, will store latency data. */
@@ -73,7 +192,8 @@ public class BinderLatencyObserver {
         }
 
         LatencyDims dims = new LatencyDims(s.binderClass, s.transactionCode);
-        long callDuration = getElapsedRealtimeMicro() - s.timeStarted;
+        long elapsedTimeMicro = getElapsedRealtimeMicro();
+        long callDuration = elapsedTimeMicro - s.timeStarted;
 
         // Find the bucket this sample should go to.
         int bucketIdx = mLatencyBuckets.sampleToBucket(
@@ -117,6 +237,22 @@ public class BinderLatencyObserver {
         }
     }
 
+    /** Updates the statsd push interval. */
+    public void setPushInterval(int pushIntervalMinutes) {
+        if (pushIntervalMinutes <= 0) {
+            Slog.w(TAG, "Ignored invalid push interval (value must be positive): "
+                    + pushIntervalMinutes);
+            return;
+        }
+
+        synchronized (mLock) {
+            if (pushIntervalMinutes != mStatsdPushIntervalMinutes) {
+                mStatsdPushIntervalMinutes = pushIntervalMinutes;
+                reset();
+            }
+        }
+    }
+
     /** Updates the histogram buckets parameters. */
     public void setHistogramBucketsParams(
             int bucketCount, int firstBucketSize, float bucketScaleFactor) {
@@ -138,6 +274,7 @@ public class BinderLatencyObserver {
         synchronized (mLock) {
             mLatencyHistograms.clear();
         }
+        noteLatencyDelayed();
     }
 
     /** Container for binder latency information. */
@@ -187,4 +324,9 @@ public class BinderLatencyObserver {
     public ArrayMap<LatencyDims, int[]> getLatencyHistograms() {
         return mLatencyHistograms;
     }
+
+    @VisibleForTesting
+    public Runnable getStatsdPushRunnable() {
+        return mLatencyObserverRunnable;
+    }
 }