• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1 /*
2  * Copyright (C) 2017 The Android Open Source Project
3  *
4  * Licensed under the Apache License, Version 2.0 (the "License");
5  * you may not use this file except in compliance with the License.
6  * You may obtain a copy of the License at
7  *
8  *      http://www.apache.org/licenses/LICENSE-2.0
9  *
10  * Unless required by applicable law or agreed to in writing, software
11  * distributed under the License is distributed on an "AS IS" BASIS,
12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13  * See the License for the specific language governing permissions and
14  * limitations under the License.
15  */
16 
17 package com.android.internal.os;
18 
19 import android.annotation.Nullable;
20 import android.os.Binder;
21 import android.os.Handler;
22 import android.os.Looper;
23 import android.os.SystemClock;
24 import android.util.ArrayMap;
25 import android.util.Slog;
26 import android.util.proto.ProtoOutputStream;
27 
28 import com.android.internal.annotations.GuardedBy;
29 import com.android.internal.annotations.VisibleForTesting;
30 import com.android.internal.os.BinderInternal.CallSession;
31 import com.android.internal.os.BinderLatencyProto.ApiStats;
32 import com.android.internal.os.BinderLatencyProto.Dims;
33 import com.android.internal.os.BinderLatencyProto.RepeatedApiStats;
34 import com.android.internal.util.FrameworkStatsLog;
35 
36 import java.util.Random;
37 
38 /** Collects statistics about Binder call latency per calling API and method. */
39 public class BinderLatencyObserver {
40     private static final String TAG = "BinderLatencyObserver";
41     private static final int MAX_ATOM_SIZE_BYTES = 4064;
42     // Be conservative and leave 1K space for the last histogram so we don't go over the size limit.
43     private static final int LAST_HISTOGRAM_BUFFER_SIZE_BYTES = 1000;
44 
45     // Latency observer parameters.
46     public static final int PERIODIC_SAMPLING_INTERVAL_DEFAULT = 10;
47     public static final int SHARDING_MODULO_DEFAULT = 1;
48     public static final int STATSD_PUSH_INTERVAL_MINUTES_DEFAULT = 360;
49 
50     // Histogram buckets parameters.
51     public static final int BUCKET_COUNT_DEFAULT = 100;
52     public static final int FIRST_BUCKET_SIZE_DEFAULT = 5;
53     public static final float BUCKET_SCALE_FACTOR_DEFAULT = 1.125f;
54 
55     @GuardedBy("mLock")
56     private final ArrayMap<LatencyDims, int[]> mLatencyHistograms = new ArrayMap<>();
57     private final Object mLock = new Object();
58 
59     // Sampling period to control how often to track CPU usage. 1 means all calls, 100 means ~1 out
60     // of 100 requests.
61     private int mPeriodicSamplingInterval = PERIODIC_SAMPLING_INTERVAL_DEFAULT;
62     // Controls how many APIs will be collected per device. 1 means all APIs, 10 means every 10th
63     // API will be collected.
64     private int mShardingModulo = SHARDING_MODULO_DEFAULT;
65     // Controls which shards will be collected on this device.
66     private int mShardingOffset;
67 
68     private int mBucketCount = BUCKET_COUNT_DEFAULT;
69     private int mFirstBucketSize = FIRST_BUCKET_SIZE_DEFAULT;
70     private float mBucketScaleFactor = BUCKET_SCALE_FACTOR_DEFAULT;
71 
72     private int mStatsdPushIntervalMinutes = STATSD_PUSH_INTERVAL_MINUTES_DEFAULT;
73 
74     private final Random mRandom;
75     private final Handler mLatencyObserverHandler;
76     private final int mProcessSource;
77 
78     private BinderLatencyBuckets mLatencyBuckets;
79 
80     private Runnable mLatencyObserverRunnable = new Runnable() {
81         @Override
82         public void run() {
83             // Schedule the next push.
84             noteLatencyDelayed();
85 
86             ArrayMap<LatencyDims, int[]> histogramMap;
87             synchronized (mLock) {
88                 // Copy the histograms map so we don't use the lock for longer than needed.
89                 histogramMap = new ArrayMap<>(mLatencyHistograms);
90                 mLatencyHistograms.clear();
91             }
92 
93             BinderTransactionNameResolver resolver = new BinderTransactionNameResolver();
94             ProtoOutputStream proto = new ProtoOutputStream();
95             int histogramsWritten = 0;
96 
97             for (LatencyDims dims : histogramMap.keySet()) {
98                 // Start a new atom if the next histogram risks going over the atom size limit.
99                 if (proto.getRawSize() + LAST_HISTOGRAM_BUFFER_SIZE_BYTES > getMaxAtomSizeBytes()) {
100                     if (histogramsWritten > 0) {
101                         writeAtomToStatsd(proto);
102                     }
103                     proto = new ProtoOutputStream();
104                     histogramsWritten = 0;
105                 }
106 
107                 String transactionName = resolver.getMethodName(
108                         dims.getBinderClass(), dims.getTransactionCode());
109                 fillApiStatsProto(proto, dims, transactionName, histogramMap.get(dims));
110                 histogramsWritten++;
111             }
112             // Push the final atom.
113             if (histogramsWritten > 0) {
114                 writeAtomToStatsd(proto);
115             }
116         }
117     };
118 
fillApiStatsProto( ProtoOutputStream proto, LatencyDims dims, String transactionName, int[] histogram)119     private void fillApiStatsProto(
120             ProtoOutputStream proto, LatencyDims dims, String transactionName, int[] histogram) {
121         // Find the part of the histogram to write.
122         int firstNonEmptyBucket = 0;
123         for (int i = 0; i < mBucketCount; i++) {
124             if (histogram[i] != 0) {
125                 firstNonEmptyBucket = i;
126                 break;
127             }
128         }
129         int lastNonEmptyBucket = mBucketCount - 1;
130         for (int i = mBucketCount - 1; i >= 0; i--) {
131             if (histogram[i] != 0) {
132                 lastNonEmptyBucket = i;
133                 break;
134             }
135         }
136 
137         // Start a new ApiStats proto.
138         long apiStatsToken = proto.start(RepeatedApiStats.API_STATS);
139 
140         // Write the dims.
141         long dimsToken = proto.start(ApiStats.DIMS);
142         proto.write(Dims.PROCESS_SOURCE, mProcessSource);
143         proto.write(Dims.SERVICE_CLASS_NAME, dims.getBinderClass().getName());
144         proto.write(Dims.SERVICE_METHOD_NAME, transactionName);
145         proto.end(dimsToken);
146 
147         // Write the histogram.
148         proto.write(ApiStats.FIRST_BUCKET_INDEX, firstNonEmptyBucket);
149         for (int i = firstNonEmptyBucket; i <= lastNonEmptyBucket; i++) {
150             proto.write(ApiStats.BUCKETS, histogram[i]);
151         }
152 
153         proto.end(apiStatsToken);
154     }
155 
getMaxAtomSizeBytes()156     protected int getMaxAtomSizeBytes() {
157         return MAX_ATOM_SIZE_BYTES;
158     }
159 
writeAtomToStatsd(ProtoOutputStream atom)160     protected void writeAtomToStatsd(ProtoOutputStream atom) {
161         FrameworkStatsLog.write(
162                 FrameworkStatsLog.BINDER_LATENCY_REPORTED,
163                 atom.getBytes(),
164                 mPeriodicSamplingInterval,
165                 mShardingModulo,
166                 mBucketCount,
167                 mFirstBucketSize,
168                 mBucketScaleFactor);
169     }
170 
noteLatencyDelayed()171     private void noteLatencyDelayed() {
172         mLatencyObserverHandler.removeCallbacks(mLatencyObserverRunnable);
173         mLatencyObserverHandler.postDelayed(mLatencyObserverRunnable,
174                 mStatsdPushIntervalMinutes * 60 * 1000);
175     }
176 
177     /** Injector for {@link BinderLatencyObserver}. */
178     public static class Injector {
getRandomGenerator()179         public Random getRandomGenerator() {
180             return new Random();
181         }
182 
getHandler()183         public Handler getHandler() {
184             return new Handler(Looper.getMainLooper());
185         }
186     }
187 
BinderLatencyObserver(Injector injector, int processSource)188     public BinderLatencyObserver(Injector injector, int processSource) {
189         mRandom = injector.getRandomGenerator();
190         mLatencyObserverHandler = injector.getHandler();
191         mLatencyBuckets = new BinderLatencyBuckets(
192             mBucketCount, mFirstBucketSize, mBucketScaleFactor);
193         mProcessSource = processSource;
194         mShardingOffset = mRandom.nextInt(mShardingModulo);
195         noteLatencyDelayed();
196     }
197 
198     /** Should be called when a Binder call completes, will store latency data. */
callEnded(@ullable CallSession s)199     public void callEnded(@Nullable CallSession s) {
200         if (s == null || s.exceptionThrown || !shouldKeepSample()) {
201             return;
202         }
203 
204         LatencyDims dims = LatencyDims.create(s.binderClass, s.transactionCode);
205 
206         if (!shouldCollect(dims)) {
207             return;
208         }
209 
210         long elapsedTimeMicro = getElapsedRealtimeMicro();
211         long callDuration = elapsedTimeMicro - s.timeStarted;
212 
213         // Find the bucket this sample should go to.
214         int bucketIdx = mLatencyBuckets.sampleToBucket(
215                 callDuration > Integer.MAX_VALUE ? Integer.MAX_VALUE : (int) callDuration);
216 
217         synchronized (mLock) {
218             int[] buckets = mLatencyHistograms.get(dims);
219             if (buckets == null) {
220                 buckets = new int[mBucketCount];
221                 mLatencyHistograms.put(dims, buckets);
222             }
223 
224             // Increment the correct bucket.
225             if (buckets[bucketIdx] < Integer.MAX_VALUE) {
226                 buckets[bucketIdx] += 1;
227             }
228         }
229     }
230 
getElapsedRealtimeMicro()231     protected long getElapsedRealtimeMicro() {
232         return SystemClock.elapsedRealtimeNanos() / 1000;
233     }
234 
shouldCollect(LatencyDims dims)235     protected boolean shouldCollect(LatencyDims dims) {
236         return (dims.hashCode() + mShardingOffset) % mShardingModulo == 0;
237     }
238 
shouldKeepSample()239     protected boolean shouldKeepSample() {
240         return mRandom.nextInt() % mPeriodicSamplingInterval == 0;
241     }
242 
243     /** Updates the sampling interval. */
setSamplingInterval(int samplingInterval)244     public void setSamplingInterval(int samplingInterval) {
245         if (samplingInterval <= 0) {
246             Slog.w(TAG, "Ignored invalid sampling interval (value must be positive): "
247                     + samplingInterval);
248             return;
249         }
250 
251         synchronized (mLock) {
252             if (samplingInterval != mPeriodicSamplingInterval) {
253                 mPeriodicSamplingInterval = samplingInterval;
254                 reset();
255             }
256         }
257     }
258 
259     /** Updates the sharding modulo. */
setShardingModulo(int shardingModulo)260     public void setShardingModulo(int shardingModulo) {
261         if (shardingModulo <= 0) {
262             Slog.w(TAG, "Ignored invalid sharding modulo (value must be positive): "
263                     + shardingModulo);
264             return;
265         }
266 
267         synchronized (mLock) {
268             if (shardingModulo != mShardingModulo) {
269                 mShardingModulo = shardingModulo;
270                 mShardingOffset = mRandom.nextInt(shardingModulo);
271                 reset();
272             }
273         }
274     }
275 
276     /** Updates the statsd push interval. */
setPushInterval(int pushIntervalMinutes)277     public void setPushInterval(int pushIntervalMinutes) {
278         if (pushIntervalMinutes <= 0) {
279             Slog.w(TAG, "Ignored invalid push interval (value must be positive): "
280                     + pushIntervalMinutes);
281             return;
282         }
283 
284         synchronized (mLock) {
285             if (pushIntervalMinutes != mStatsdPushIntervalMinutes) {
286                 mStatsdPushIntervalMinutes = pushIntervalMinutes;
287                 reset();
288             }
289         }
290     }
291 
292     /** Updates the histogram buckets parameters. */
setHistogramBucketsParams( int bucketCount, int firstBucketSize, float bucketScaleFactor)293     public void setHistogramBucketsParams(
294             int bucketCount, int firstBucketSize, float bucketScaleFactor) {
295         synchronized (mLock) {
296             if (bucketCount != mBucketCount || firstBucketSize != mFirstBucketSize
297                     || bucketScaleFactor != mBucketScaleFactor) {
298                 mBucketCount = bucketCount;
299                 mFirstBucketSize = firstBucketSize;
300                 mBucketScaleFactor = bucketScaleFactor;
301                 mLatencyBuckets = new BinderLatencyBuckets(
302                     mBucketCount, mFirstBucketSize, mBucketScaleFactor);
303                 reset();
304             }
305         }
306     }
307 
308     /** Resets the sample collection. */
reset()309     public void reset() {
310         synchronized (mLock) {
311             mLatencyHistograms.clear();
312         }
313         noteLatencyDelayed();
314     }
315 
316     /** Container for binder latency information. */
317     public static class LatencyDims {
318         // Binder interface descriptor.
319         private Class<? extends Binder> mBinderClass;
320         // Binder transaction code.
321         private int mTransactionCode;
322         // Cached hash code, 0 if not set yet.
323         private int mHashCode = 0;
324 
325         /** Creates a new instance of LatencyDims. */
create(Class<? extends Binder> binderClass, int transactionCode)326         public static LatencyDims create(Class<? extends Binder> binderClass, int transactionCode) {
327             return new LatencyDims(binderClass, transactionCode);
328         }
329 
LatencyDims(Class<? extends Binder> binderClass, int transactionCode)330         private LatencyDims(Class<? extends Binder> binderClass, int transactionCode) {
331             this.mBinderClass = binderClass;
332             this.mTransactionCode = transactionCode;
333         }
334 
getBinderClass()335         public Class<? extends Binder> getBinderClass() {
336             return mBinderClass;
337         }
338 
getTransactionCode()339         public int getTransactionCode() {
340             return mTransactionCode;
341         }
342 
343         @Override
equals(final Object other)344         public boolean equals(final Object other) {
345             if (other == null || !(other instanceof LatencyDims)) {
346                 return false;
347             }
348             LatencyDims o = (LatencyDims) other;
349             return mTransactionCode == o.getTransactionCode() && mBinderClass == o.getBinderClass();
350         }
351 
352         @Override
hashCode()353         public int hashCode() {
354             if (mHashCode != 0) {
355                 return mHashCode;
356             }
357             int hash = mTransactionCode;
358             hash = 31 * hash + mBinderClass.getName().hashCode();
359             mHashCode = hash;
360             return hash;
361         }
362     }
363 
364     @VisibleForTesting
getLatencyHistograms()365     public ArrayMap<LatencyDims, int[]> getLatencyHistograms() {
366         return mLatencyHistograms;
367     }
368 
369     @VisibleForTesting
getStatsdPushRunnable()370     public Runnable getStatsdPushRunnable() {
371         return mLatencyObserverRunnable;
372     }
373 
374     @VisibleForTesting
getProcessSource()375     public int getProcessSource() {
376         return mProcessSource;
377     }
378 }
379