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