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