1 /* 2 * Copyright (C) 2018 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.NonNull; 20 import android.annotation.Nullable; 21 import android.os.Handler; 22 import android.os.Looper; 23 import android.os.Message; 24 import android.os.SystemClock; 25 import android.util.SparseArray; 26 27 import com.android.internal.annotations.GuardedBy; 28 29 import java.util.ArrayList; 30 import java.util.List; 31 import java.util.concurrent.ConcurrentLinkedQueue; 32 import java.util.concurrent.ThreadLocalRandom; 33 34 /** 35 * Collects aggregated telemetry data about Looper message dispatching. 36 * 37 * @hide Only for use within the system server. 38 */ 39 @android.ravenwood.annotation.RavenwoodKeepWholeClass 40 public class LooperStats implements Looper.Observer { 41 public static final String DEBUG_ENTRY_PREFIX = "__DEBUG_"; 42 private static final int SESSION_POOL_SIZE = 50; 43 private static final boolean DISABLED_SCREEN_STATE_TRACKING_VALUE = false; 44 public static final boolean DEFAULT_IGNORE_BATTERY_STATUS = false; 45 46 @GuardedBy("mLock") 47 private final SparseArray<Entry> mEntries = new SparseArray<>(512); 48 private final Object mLock = new Object(); 49 private final Entry mOverflowEntry = new Entry("OVERFLOW"); 50 private final Entry mHashCollisionEntry = new Entry("HASH_COLLISION"); 51 private final ConcurrentLinkedQueue<DispatchSession> mSessionPool = 52 new ConcurrentLinkedQueue<>(); 53 private final int mEntriesSizeCap; 54 private int mSamplingInterval; 55 private CachedDeviceState.Readonly mDeviceState; 56 private CachedDeviceState.TimeInStateStopwatch mBatteryStopwatch; 57 private long mStartCurrentTime = System.currentTimeMillis(); 58 private long mStartElapsedTime = SystemClock.elapsedRealtime(); 59 private boolean mAddDebugEntries = false; 60 private boolean mTrackScreenInteractive = false; 61 private boolean mIgnoreBatteryStatus = DEFAULT_IGNORE_BATTERY_STATUS; 62 LooperStats(int samplingInterval, int entriesSizeCap)63 public LooperStats(int samplingInterval, int entriesSizeCap) { 64 this.mSamplingInterval = samplingInterval; 65 this.mEntriesSizeCap = entriesSizeCap; 66 } 67 setDeviceState(@onNull CachedDeviceState.Readonly deviceState)68 public void setDeviceState(@NonNull CachedDeviceState.Readonly deviceState) { 69 if (mBatteryStopwatch != null) { 70 mBatteryStopwatch.close(); 71 } 72 73 mDeviceState = deviceState; 74 mBatteryStopwatch = deviceState.createTimeOnBatteryStopwatch(); 75 } 76 setAddDebugEntries(boolean addDebugEntries)77 public void setAddDebugEntries(boolean addDebugEntries) { 78 mAddDebugEntries = addDebugEntries; 79 } 80 81 @Override messageDispatchStarting()82 public Object messageDispatchStarting() { 83 if (deviceStateAllowsCollection() && shouldCollectDetailedData()) { 84 DispatchSession session = mSessionPool.poll(); 85 session = session == null ? new DispatchSession() : session; 86 session.startTimeMicro = getElapsedRealtimeMicro(); 87 session.cpuStartMicro = getThreadTimeMicro(); 88 session.systemUptimeMillis = getSystemUptimeMillis(); 89 return session; 90 } 91 92 return DispatchSession.NOT_SAMPLED; 93 } 94 95 @Override messageDispatched(Object token, Message msg)96 public void messageDispatched(Object token, Message msg) { 97 if (!deviceStateAllowsCollection()) { 98 return; 99 } 100 101 DispatchSession session = (DispatchSession) token; 102 Entry entry = findEntry(msg, /* allowCreateNew= */session != DispatchSession.NOT_SAMPLED); 103 if (entry != null) { 104 synchronized (entry) { 105 entry.messageCount++; 106 if (session != DispatchSession.NOT_SAMPLED) { 107 entry.recordedMessageCount++; 108 final long latency = getElapsedRealtimeMicro() - session.startTimeMicro; 109 final long cpuUsage = getThreadTimeMicro() - session.cpuStartMicro; 110 entry.totalLatencyMicro += latency; 111 entry.maxLatencyMicro = Math.max(entry.maxLatencyMicro, latency); 112 entry.cpuUsageMicro += cpuUsage; 113 entry.maxCpuUsageMicro = Math.max(entry.maxCpuUsageMicro, cpuUsage); 114 if (msg.getWhen() > 0) { 115 final long delay = Math.max(0L, session.systemUptimeMillis - msg.getWhen()); 116 entry.delayMillis += delay; 117 entry.maxDelayMillis = Math.max(entry.maxDelayMillis, delay); 118 entry.recordedDelayMessageCount++; 119 } 120 } 121 } 122 } 123 124 recycleSession(session); 125 } 126 127 @Override dispatchingThrewException(Object token, Message msg, Exception exception)128 public void dispatchingThrewException(Object token, Message msg, Exception exception) { 129 if (!deviceStateAllowsCollection()) { 130 return; 131 } 132 133 DispatchSession session = (DispatchSession) token; 134 Entry entry = findEntry(msg, /* allowCreateNew= */session != DispatchSession.NOT_SAMPLED); 135 if (entry != null) { 136 synchronized (entry) { 137 entry.exceptionCount++; 138 } 139 } 140 141 recycleSession(session); 142 } 143 deviceStateAllowsCollection()144 private boolean deviceStateAllowsCollection() { 145 if (mIgnoreBatteryStatus) { 146 return true; 147 } 148 if (mDeviceState == null) { 149 return false; 150 } 151 if (mDeviceState.isCharging()) { 152 return false; 153 } 154 return true; 155 } 156 157 /** Returns an array of {@link ExportedEntry entries} with the aggregated statistics. */ getEntries()158 public List<ExportedEntry> getEntries() { 159 final ArrayList<ExportedEntry> exportedEntries; 160 synchronized (mLock) { 161 final int size = mEntries.size(); 162 exportedEntries = new ArrayList<>(size); 163 for (int i = 0; i < size; i++) { 164 Entry entry = mEntries.valueAt(i); 165 synchronized (entry) { 166 exportedEntries.add(new ExportedEntry(entry)); 167 } 168 } 169 } 170 // Add the overflow and collision entries only if they have any data. 171 maybeAddSpecialEntry(exportedEntries, mOverflowEntry); 172 maybeAddSpecialEntry(exportedEntries, mHashCollisionEntry); 173 // Debug entries added to help validate the data. 174 if (mAddDebugEntries && mBatteryStopwatch != null) { 175 exportedEntries.add(createDebugEntry("start_time_millis", mStartElapsedTime)); 176 exportedEntries.add(createDebugEntry("end_time_millis", SystemClock.elapsedRealtime())); 177 exportedEntries.add( 178 createDebugEntry("battery_time_millis", mBatteryStopwatch.getMillis())); 179 exportedEntries.add(createDebugEntry("sampling_interval", mSamplingInterval)); 180 } 181 return exportedEntries; 182 } 183 createDebugEntry(String variableName, long value)184 private ExportedEntry createDebugEntry(String variableName, long value) { 185 final Entry entry = new Entry(DEBUG_ENTRY_PREFIX + variableName); 186 entry.messageCount = 1; 187 entry.recordedMessageCount = 1; 188 entry.totalLatencyMicro = value; 189 return new ExportedEntry(entry); 190 } 191 192 /** Returns a timestamp indicating when the statistics were last reset. */ getStartTimeMillis()193 public long getStartTimeMillis() { 194 return mStartCurrentTime; 195 } 196 getStartElapsedTimeMillis()197 public long getStartElapsedTimeMillis() { 198 return mStartElapsedTime; 199 } 200 getBatteryTimeMillis()201 public long getBatteryTimeMillis() { 202 return mBatteryStopwatch != null ? mBatteryStopwatch.getMillis() : 0; 203 } 204 maybeAddSpecialEntry(List<ExportedEntry> exportedEntries, Entry specialEntry)205 private void maybeAddSpecialEntry(List<ExportedEntry> exportedEntries, Entry specialEntry) { 206 synchronized (specialEntry) { 207 if (specialEntry.messageCount > 0 || specialEntry.exceptionCount > 0) { 208 exportedEntries.add(new ExportedEntry(specialEntry)); 209 } 210 } 211 } 212 213 /** Removes all collected data. */ reset()214 public void reset() { 215 synchronized (mLock) { 216 mEntries.clear(); 217 } 218 synchronized (mHashCollisionEntry) { 219 mHashCollisionEntry.reset(); 220 } 221 synchronized (mOverflowEntry) { 222 mOverflowEntry.reset(); 223 } 224 mStartCurrentTime = System.currentTimeMillis(); 225 mStartElapsedTime = SystemClock.elapsedRealtime(); 226 if (mBatteryStopwatch != null) { 227 mBatteryStopwatch.reset(); 228 } 229 } 230 setSamplingInterval(int samplingInterval)231 public void setSamplingInterval(int samplingInterval) { 232 mSamplingInterval = samplingInterval; 233 } 234 setTrackScreenInteractive(boolean enabled)235 public void setTrackScreenInteractive(boolean enabled) { 236 mTrackScreenInteractive = enabled; 237 } 238 setIgnoreBatteryStatus(boolean ignore)239 public void setIgnoreBatteryStatus(boolean ignore) { 240 mIgnoreBatteryStatus = ignore; 241 } 242 243 @Nullable findEntry(Message msg, boolean allowCreateNew)244 private Entry findEntry(Message msg, boolean allowCreateNew) { 245 final boolean isInteractive = mTrackScreenInteractive 246 ? mDeviceState.isScreenInteractive() 247 : DISABLED_SCREEN_STATE_TRACKING_VALUE; 248 final int id = Entry.idFor(msg, isInteractive); 249 Entry entry; 250 synchronized (mLock) { 251 entry = mEntries.get(id); 252 if (entry == null) { 253 if (!allowCreateNew) { 254 return null; 255 } else if (mEntries.size() >= mEntriesSizeCap) { 256 // If over the size cap track totals under OVERFLOW entry. 257 return mOverflowEntry; 258 } else { 259 entry = new Entry(msg, isInteractive); 260 mEntries.put(id, entry); 261 } 262 } 263 } 264 265 if (entry.workSourceUid != msg.workSourceUid 266 || entry.handler.getClass() != msg.getTarget().getClass() 267 || entry.handler.getLooper().getThread() != msg.getTarget().getLooper().getThread() 268 || entry.isInteractive != isInteractive) { 269 // If a hash collision happened, track totals under a single entry. 270 return mHashCollisionEntry; 271 } 272 return entry; 273 } 274 recycleSession(DispatchSession session)275 private void recycleSession(DispatchSession session) { 276 if (session != DispatchSession.NOT_SAMPLED && mSessionPool.size() < SESSION_POOL_SIZE) { 277 mSessionPool.add(session); 278 } 279 } 280 getThreadTimeMicro()281 protected long getThreadTimeMicro() { 282 return SystemClock.currentThreadTimeMicro(); 283 } 284 getElapsedRealtimeMicro()285 protected long getElapsedRealtimeMicro() { 286 return SystemClock.elapsedRealtimeNanos() / 1000; 287 } 288 getSystemUptimeMillis()289 protected long getSystemUptimeMillis() { 290 return SystemClock.uptimeMillis(); 291 } 292 shouldCollectDetailedData()293 protected boolean shouldCollectDetailedData() { 294 return ThreadLocalRandom.current().nextInt(mSamplingInterval) == 0; 295 } 296 297 private static class DispatchSession { 298 static final DispatchSession NOT_SAMPLED = new DispatchSession(); 299 public long startTimeMicro; 300 public long cpuStartMicro; 301 public long systemUptimeMillis; 302 } 303 304 private static class Entry { 305 public final int workSourceUid; 306 public final Handler handler; 307 public final String messageName; 308 public final boolean isInteractive; 309 public long messageCount; 310 public long recordedMessageCount; 311 public long exceptionCount; 312 public long totalLatencyMicro; 313 public long maxLatencyMicro; 314 public long cpuUsageMicro; 315 public long maxCpuUsageMicro; 316 public long recordedDelayMessageCount; 317 public long delayMillis; 318 public long maxDelayMillis; 319 Entry(Message msg, boolean isInteractive)320 Entry(Message msg, boolean isInteractive) { 321 this.workSourceUid = msg.workSourceUid; 322 this.handler = msg.getTarget(); 323 this.messageName = handler.getMessageName(msg); 324 this.isInteractive = isInteractive; 325 } 326 Entry(String specialEntryName)327 Entry(String specialEntryName) { 328 this.workSourceUid = Message.UID_NONE; 329 this.messageName = specialEntryName; 330 this.handler = null; 331 this.isInteractive = false; 332 } 333 reset()334 void reset() { 335 messageCount = 0; 336 recordedMessageCount = 0; 337 exceptionCount = 0; 338 totalLatencyMicro = 0; 339 maxLatencyMicro = 0; 340 cpuUsageMicro = 0; 341 maxCpuUsageMicro = 0; 342 delayMillis = 0; 343 maxDelayMillis = 0; 344 recordedDelayMessageCount = 0; 345 } 346 idFor(Message msg, boolean isInteractive)347 static int idFor(Message msg, boolean isInteractive) { 348 int result = 7; 349 result = 31 * result + msg.workSourceUid; 350 result = 31 * result + msg.getTarget().getLooper().getThread().hashCode(); 351 result = 31 * result + msg.getTarget().getClass().hashCode(); 352 result = 31 * result + (isInteractive ? 1231 : 1237); 353 if (msg.getCallback() != null) { 354 return 31 * result + msg.getCallback().getClass().hashCode(); 355 } else { 356 return 31 * result + msg.what; 357 } 358 } 359 } 360 361 /** Aggregated data of Looper message dispatching in the in the current process. */ 362 public static class ExportedEntry { 363 public final int workSourceUid; 364 public final String handlerClassName; 365 public final String threadName; 366 public final String messageName; 367 public final boolean isInteractive; 368 public final long messageCount; 369 public final long recordedMessageCount; 370 public final long exceptionCount; 371 public final long totalLatencyMicros; 372 public final long maxLatencyMicros; 373 public final long cpuUsageMicros; 374 public final long maxCpuUsageMicros; 375 public final long maxDelayMillis; 376 public final long delayMillis; 377 public final long recordedDelayMessageCount; 378 ExportedEntry(Entry entry)379 ExportedEntry(Entry entry) { 380 this.workSourceUid = entry.workSourceUid; 381 if (entry.handler != null) { 382 this.handlerClassName = entry.handler.getClass().getName(); 383 this.threadName = entry.handler.getLooper().getThread().getName(); 384 } else { 385 // Overflow/collision entries do not have a handler set. 386 this.handlerClassName = ""; 387 this.threadName = ""; 388 } 389 this.isInteractive = entry.isInteractive; 390 this.messageName = entry.messageName; 391 this.messageCount = entry.messageCount; 392 this.recordedMessageCount = entry.recordedMessageCount; 393 this.exceptionCount = entry.exceptionCount; 394 this.totalLatencyMicros = entry.totalLatencyMicro; 395 this.maxLatencyMicros = entry.maxLatencyMicro; 396 this.cpuUsageMicros = entry.cpuUsageMicro; 397 this.maxCpuUsageMicros = entry.maxCpuUsageMicro; 398 this.delayMillis = entry.delayMillis; 399 this.maxDelayMillis = entry.maxDelayMillis; 400 this.recordedDelayMessageCount = entry.recordedDelayMessageCount; 401 } 402 } 403 } 404