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