Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 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 static com.google.common.truth.Truth.assertThat; |
| 20 | |
| 21 | import android.os.Handler; |
| 22 | import android.os.HandlerThread; |
| 23 | import android.os.Looper; |
Marcin Oczeretko | ec75872 | 2018-09-12 12:53:47 +0100 | [diff] [blame] | 24 | import android.os.Message; |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 25 | import android.platform.test.annotations.Presubmit; |
Tadashi G. Takaoka | b4470f2 | 2019-01-15 18:29:15 +0900 | [diff] [blame] | 26 | |
| 27 | import androidx.test.filters.SmallTest; |
| 28 | import androidx.test.runner.AndroidJUnit4; |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 29 | |
| 30 | import org.junit.After; |
| 31 | import org.junit.Assert; |
| 32 | import org.junit.Before; |
| 33 | import org.junit.Test; |
| 34 | import org.junit.runner.RunWith; |
| 35 | |
| 36 | import java.util.Comparator; |
| 37 | import java.util.List; |
| 38 | |
| 39 | @SmallTest |
| 40 | @RunWith(AndroidJUnit4.class) |
| 41 | @Presubmit |
| 42 | public final class LooperStatsTest { |
| 43 | private HandlerThread mThreadFirst; |
| 44 | private HandlerThread mThreadSecond; |
| 45 | private Handler mHandlerFirst; |
| 46 | private Handler mHandlerSecond; |
| 47 | private Handler mHandlerAnonymous; |
Marcin Oczeretko | c80c81a | 2018-08-30 20:15:52 +0100 | [diff] [blame] | 48 | private CachedDeviceState mDeviceState; |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 49 | |
| 50 | @Before |
| 51 | public void setUp() { |
| 52 | // The tests are all single-threaded. HandlerThreads are created to allow creating Handlers |
| 53 | // and to test Thread name collection. |
| 54 | mThreadFirst = new HandlerThread("TestThread1"); |
| 55 | mThreadSecond = new HandlerThread("TestThread2"); |
| 56 | mThreadFirst.start(); |
| 57 | mThreadSecond.start(); |
| 58 | |
| 59 | mHandlerFirst = new TestHandlerFirst(mThreadFirst.getLooper()); |
| 60 | mHandlerSecond = new TestHandlerSecond(mThreadSecond.getLooper()); |
| 61 | mHandlerAnonymous = new Handler(mThreadFirst.getLooper()) { |
| 62 | /* To create an anonymous subclass. */ |
| 63 | }; |
Marcin Oczeretko | c80c81a | 2018-08-30 20:15:52 +0100 | [diff] [blame] | 64 | mDeviceState = new CachedDeviceState(); |
| 65 | mDeviceState.setCharging(false); |
| 66 | mDeviceState.setScreenInteractive(true); |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 67 | } |
| 68 | |
| 69 | @After |
| 70 | public void tearDown() { |
| 71 | mThreadFirst.quit(); |
| 72 | mThreadSecond.quit(); |
| 73 | } |
| 74 | |
| 75 | @Test |
| 76 | public void testSingleMessageDispatched() { |
| 77 | TestableLooperStats looperStats = new TestableLooperStats(1, 100); |
| 78 | |
Marcin Oczeretko | ec75872 | 2018-09-12 12:53:47 +0100 | [diff] [blame] | 79 | Message message = mHandlerFirst.obtainMessage(1000); |
| 80 | message.workSourceUid = 1000; |
Marcin Oczeretko | 4427272 | 2018-09-19 11:01:32 +0100 | [diff] [blame] | 81 | message.when = looperStats.getSystemUptimeMillis(); |
| 82 | |
| 83 | looperStats.tickUptime(30); |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 84 | Object token = looperStats.messageDispatchStarting(); |
| 85 | looperStats.tickRealtime(100); |
| 86 | looperStats.tickThreadTime(10); |
Marcin Oczeretko | 4427272 | 2018-09-19 11:01:32 +0100 | [diff] [blame] | 87 | looperStats.tickUptime(200); |
Marcin Oczeretko | ec75872 | 2018-09-12 12:53:47 +0100 | [diff] [blame] | 88 | looperStats.messageDispatched(token, message); |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 89 | |
| 90 | List<LooperStats.ExportedEntry> entries = looperStats.getEntries(); |
| 91 | assertThat(entries).hasSize(1); |
| 92 | LooperStats.ExportedEntry entry = entries.get(0); |
Marcin Oczeretko | ec75872 | 2018-09-12 12:53:47 +0100 | [diff] [blame] | 93 | assertThat(entry.workSourceUid).isEqualTo(1000); |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 94 | assertThat(entry.threadName).isEqualTo("TestThread1"); |
| 95 | assertThat(entry.handlerClassName).isEqualTo( |
| 96 | "com.android.internal.os.LooperStatsTest$TestHandlerFirst"); |
| 97 | assertThat(entry.messageName).isEqualTo("0x3e8" /* 1000 in hex */); |
Marcin Oczeretko | c80c81a | 2018-08-30 20:15:52 +0100 | [diff] [blame] | 98 | assertThat(entry.isInteractive).isEqualTo(true); |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 99 | assertThat(entry.messageCount).isEqualTo(1); |
| 100 | assertThat(entry.recordedMessageCount).isEqualTo(1); |
| 101 | assertThat(entry.exceptionCount).isEqualTo(0); |
| 102 | assertThat(entry.totalLatencyMicros).isEqualTo(100); |
| 103 | assertThat(entry.maxLatencyMicros).isEqualTo(100); |
| 104 | assertThat(entry.cpuUsageMicros).isEqualTo(10); |
| 105 | assertThat(entry.maxCpuUsageMicros).isEqualTo(10); |
Marcin Oczeretko | 4427272 | 2018-09-19 11:01:32 +0100 | [diff] [blame] | 106 | assertThat(entry.recordedDelayMessageCount).isEqualTo(1); |
| 107 | assertThat(entry.delayMillis).isEqualTo(30); |
| 108 | assertThat(entry.maxDelayMillis).isEqualTo(30); |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 109 | } |
| 110 | |
| 111 | @Test |
| 112 | public void testThrewException() { |
| 113 | TestableLooperStats looperStats = new TestableLooperStats(1, 100); |
| 114 | |
Marcin Oczeretko | ec75872 | 2018-09-12 12:53:47 +0100 | [diff] [blame] | 115 | Message message = mHandlerFirst.obtainMessage(7); |
| 116 | message.workSourceUid = 123; |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 117 | Object token = looperStats.messageDispatchStarting(); |
| 118 | looperStats.tickRealtime(100); |
| 119 | looperStats.tickThreadTime(10); |
Marcin Oczeretko | ec75872 | 2018-09-12 12:53:47 +0100 | [diff] [blame] | 120 | looperStats.dispatchingThrewException(token, message, new ArithmeticException()); |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 121 | |
| 122 | List<LooperStats.ExportedEntry> entries = looperStats.getEntries(); |
| 123 | assertThat(entries).hasSize(1); |
| 124 | LooperStats.ExportedEntry entry = entries.get(0); |
Marcin Oczeretko | ec75872 | 2018-09-12 12:53:47 +0100 | [diff] [blame] | 125 | assertThat(entry.workSourceUid).isEqualTo(123); |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 126 | assertThat(entry.threadName).isEqualTo("TestThread1"); |
| 127 | assertThat(entry.handlerClassName).isEqualTo( |
| 128 | "com.android.internal.os.LooperStatsTest$TestHandlerFirst"); |
| 129 | assertThat(entry.messageName).isEqualTo("0x7" /* 7 in hex */); |
Marcin Oczeretko | c80c81a | 2018-08-30 20:15:52 +0100 | [diff] [blame] | 130 | assertThat(entry.isInteractive).isEqualTo(true); |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 131 | assertThat(entry.messageCount).isEqualTo(0); |
| 132 | assertThat(entry.recordedMessageCount).isEqualTo(0); |
| 133 | assertThat(entry.exceptionCount).isEqualTo(1); |
| 134 | assertThat(entry.totalLatencyMicros).isEqualTo(0); |
| 135 | assertThat(entry.maxLatencyMicros).isEqualTo(0); |
| 136 | assertThat(entry.cpuUsageMicros).isEqualTo(0); |
| 137 | assertThat(entry.maxCpuUsageMicros).isEqualTo(0); |
| 138 | } |
| 139 | |
| 140 | @Test |
Olivier Gaillard | 99ab953 | 2019-02-04 10:47:48 +0000 | [diff] [blame] | 141 | public void testThrewException_notSampled() { |
| 142 | TestableLooperStats looperStats = new TestableLooperStats(2, 100); |
| 143 | |
| 144 | Object token = looperStats.messageDispatchStarting(); |
| 145 | looperStats.tickRealtime(10); |
| 146 | looperStats.tickThreadTime(10); |
| 147 | looperStats.messageDispatched(token, mHandlerFirst.obtainMessage(0)); |
| 148 | assertThat(looperStats.getEntries()).hasSize(1); |
| 149 | |
| 150 | // Will not be sampled so does not contribute to any entries. |
| 151 | Object token2 = looperStats.messageDispatchStarting(); |
| 152 | looperStats.tickRealtime(100); |
| 153 | looperStats.tickThreadTime(10); |
| 154 | looperStats.dispatchingThrewException( |
| 155 | token2, mHandlerSecond.obtainMessage(7), new ArithmeticException()); |
| 156 | assertThat(looperStats.getEntries()).hasSize(1); |
| 157 | assertThat(looperStats.getEntries().get(0).messageCount).isEqualTo(1); |
| 158 | } |
| 159 | |
| 160 | @Test |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 161 | public void testMultipleMessagesDispatched() { |
| 162 | TestableLooperStats looperStats = new TestableLooperStats(2, 100); |
| 163 | |
| 164 | // Contributes to entry2. |
| 165 | Object token1 = looperStats.messageDispatchStarting(); |
| 166 | looperStats.tickRealtime(100); |
| 167 | looperStats.tickThreadTime(10); |
| 168 | looperStats.messageDispatched(token1, mHandlerFirst.obtainMessage(1000)); |
| 169 | |
| 170 | // Contributes to entry2. |
| 171 | Object token2 = looperStats.messageDispatchStarting(); |
| 172 | looperStats.tickRealtime(50); |
| 173 | looperStats.tickThreadTime(20); |
| 174 | looperStats.messageDispatched(token2, mHandlerFirst.obtainMessage(1000)); |
| 175 | |
| 176 | // Contributes to entry3. |
| 177 | Object token3 = looperStats.messageDispatchStarting(); |
| 178 | looperStats.tickRealtime(10); |
| 179 | looperStats.tickThreadTime(10); |
| 180 | looperStats.messageDispatched(token3, mHandlerSecond.obtainMessage().setCallback(() -> { |
| 181 | })); |
| 182 | |
Marcin Oczeretko | a674bc9 | 2018-09-13 18:20:21 +0100 | [diff] [blame] | 183 | // Will not be sampled so does not contribute to any entries. |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 184 | Object token4 = looperStats.messageDispatchStarting(); |
Marcin Oczeretko | a674bc9 | 2018-09-13 18:20:21 +0100 | [diff] [blame] | 185 | looperStats.tickRealtime(10); |
| 186 | looperStats.tickThreadTime(10); |
| 187 | looperStats.messageDispatched(token4, mHandlerSecond.obtainMessage(0)); |
| 188 | |
| 189 | // Contributes to entry1. |
| 190 | Object token5 = looperStats.messageDispatchStarting(); |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 191 | looperStats.tickRealtime(100); |
| 192 | looperStats.tickThreadTime(100); |
Marcin Oczeretko | a674bc9 | 2018-09-13 18:20:21 +0100 | [diff] [blame] | 193 | looperStats.messageDispatched(token5, mHandlerAnonymous.obtainMessage(1)); |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 194 | |
| 195 | List<LooperStats.ExportedEntry> entries = looperStats.getEntries(); |
| 196 | assertThat(entries).hasSize(3); |
| 197 | entries.sort(Comparator.comparing(e -> e.handlerClassName)); |
| 198 | |
Marcin Oczeretko | a674bc9 | 2018-09-13 18:20:21 +0100 | [diff] [blame] | 199 | // Captures data for token5 call. |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 200 | LooperStats.ExportedEntry entry1 = entries.get(0); |
Marcin Oczeretko | ec75872 | 2018-09-12 12:53:47 +0100 | [diff] [blame] | 201 | assertThat(entry1.workSourceUid).isEqualTo(-1); |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 202 | assertThat(entry1.threadName).isEqualTo("TestThread1"); |
| 203 | assertThat(entry1.handlerClassName).isEqualTo("com.android.internal.os.LooperStatsTest$1"); |
| 204 | assertThat(entry1.messageName).isEqualTo("0x1" /* 1 in hex */); |
| 205 | assertThat(entry1.messageCount).isEqualTo(1); |
Marcin Oczeretko | a674bc9 | 2018-09-13 18:20:21 +0100 | [diff] [blame] | 206 | assertThat(entry1.recordedMessageCount).isEqualTo(1); |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 207 | assertThat(entry1.exceptionCount).isEqualTo(0); |
Marcin Oczeretko | a674bc9 | 2018-09-13 18:20:21 +0100 | [diff] [blame] | 208 | assertThat(entry1.totalLatencyMicros).isEqualTo(100); |
| 209 | assertThat(entry1.maxLatencyMicros).isEqualTo(100); |
| 210 | assertThat(entry1.cpuUsageMicros).isEqualTo(100); |
| 211 | assertThat(entry1.maxCpuUsageMicros).isEqualTo(100); |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 212 | |
| 213 | // Captures data for token1 and token2 calls. |
| 214 | LooperStats.ExportedEntry entry2 = entries.get(1); |
Marcin Oczeretko | ec75872 | 2018-09-12 12:53:47 +0100 | [diff] [blame] | 215 | assertThat(entry2.workSourceUid).isEqualTo(-1); |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 216 | assertThat(entry2.threadName).isEqualTo("TestThread1"); |
| 217 | assertThat(entry2.handlerClassName).isEqualTo( |
| 218 | "com.android.internal.os.LooperStatsTest$TestHandlerFirst"); |
| 219 | assertThat(entry2.messageName).isEqualTo("0x3e8" /* 1000 in hex */); |
| 220 | assertThat(entry2.messageCount).isEqualTo(2); |
| 221 | assertThat(entry2.recordedMessageCount).isEqualTo(1); |
| 222 | assertThat(entry2.exceptionCount).isEqualTo(0); |
| 223 | assertThat(entry2.totalLatencyMicros).isEqualTo(100); |
| 224 | assertThat(entry2.maxLatencyMicros).isEqualTo(100); |
| 225 | assertThat(entry2.cpuUsageMicros).isEqualTo(10); |
| 226 | assertThat(entry2.maxCpuUsageMicros).isEqualTo(10); |
| 227 | |
| 228 | // Captures data for token3 call. |
| 229 | LooperStats.ExportedEntry entry3 = entries.get(2); |
Marcin Oczeretko | ec75872 | 2018-09-12 12:53:47 +0100 | [diff] [blame] | 230 | assertThat(entry3.workSourceUid).isEqualTo(-1); |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 231 | assertThat(entry3.threadName).isEqualTo("TestThread2"); |
| 232 | assertThat(entry3.handlerClassName).isEqualTo( |
| 233 | "com.android.internal.os.LooperStatsTest$TestHandlerSecond"); |
| 234 | assertThat(entry3.messageName).startsWith( |
| 235 | "com.android.internal.os.-$$Lambda$LooperStatsTest$"); |
| 236 | assertThat(entry3.messageCount).isEqualTo(1); |
| 237 | assertThat(entry3.recordedMessageCount).isEqualTo(1); |
| 238 | assertThat(entry3.exceptionCount).isEqualTo(0); |
| 239 | assertThat(entry3.totalLatencyMicros).isEqualTo(10); |
| 240 | assertThat(entry3.maxLatencyMicros).isEqualTo(10); |
| 241 | assertThat(entry3.cpuUsageMicros).isEqualTo(10); |
| 242 | assertThat(entry3.maxCpuUsageMicros).isEqualTo(10); |
| 243 | } |
| 244 | |
| 245 | @Test |
Marcin Oczeretko | 4427272 | 2018-09-19 11:01:32 +0100 | [diff] [blame] | 246 | public void testDispatchDelayIsRecorded() { |
| 247 | TestableLooperStats looperStats = new TestableLooperStats(1, 100); |
| 248 | |
| 249 | // Dispatched right on time. |
| 250 | Message message1 = mHandlerFirst.obtainMessage(1000); |
| 251 | message1.when = looperStats.getSystemUptimeMillis(); |
| 252 | Object token1 = looperStats.messageDispatchStarting(); |
| 253 | looperStats.tickUptime(10); |
| 254 | looperStats.messageDispatched(token1, message1); |
| 255 | |
| 256 | // Dispatched 100ms late. |
| 257 | Message message2 = mHandlerFirst.obtainMessage(1000); |
| 258 | message2.when = looperStats.getSystemUptimeMillis() - 100; |
| 259 | Object token2 = looperStats.messageDispatchStarting(); |
| 260 | looperStats.tickUptime(10); |
| 261 | looperStats.messageDispatched(token2, message2); |
| 262 | |
| 263 | // No target dispatching time. |
| 264 | Message message3 = mHandlerFirst.obtainMessage(1000); |
| 265 | message3.when = 0; |
| 266 | Object token3 = looperStats.messageDispatchStarting(); |
| 267 | looperStats.tickUptime(10); |
| 268 | looperStats.messageDispatched(token3, message3); |
| 269 | |
| 270 | // Dispatched too soon (should never happen). |
| 271 | Message message4 = mHandlerFirst.obtainMessage(1000); |
| 272 | message4.when = looperStats.getSystemUptimeMillis() + 200; |
| 273 | Object token4 = looperStats.messageDispatchStarting(); |
| 274 | looperStats.tickUptime(10); |
| 275 | looperStats.messageDispatched(token4, message4); |
| 276 | |
| 277 | // Dispatched 300ms late. |
| 278 | Message message5 = mHandlerFirst.obtainMessage(1000); |
| 279 | message5.when = looperStats.getSystemUptimeMillis() - 300; |
| 280 | Object token5 = looperStats.messageDispatchStarting(); |
| 281 | looperStats.tickUptime(10); |
| 282 | looperStats.messageDispatched(token5, message5); |
| 283 | |
| 284 | List<LooperStats.ExportedEntry> entries = looperStats.getEntries(); |
| 285 | assertThat(entries).hasSize(1); |
| 286 | |
| 287 | LooperStats.ExportedEntry entry = entries.get(0); |
| 288 | assertThat(entry.messageCount).isEqualTo(5); |
| 289 | assertThat(entry.recordedMessageCount).isEqualTo(5); |
| 290 | assertThat(entry.recordedDelayMessageCount).isEqualTo(4); |
| 291 | assertThat(entry.delayMillis).isEqualTo(400); |
| 292 | assertThat(entry.maxDelayMillis).isEqualTo(300); |
| 293 | } |
| 294 | |
| 295 | @Test |
Marcin Oczeretko | c80c81a | 2018-08-30 20:15:52 +0100 | [diff] [blame] | 296 | public void testDataNotCollectedBeforeDeviceStateSet() { |
Marcin Oczeretko | 6a2e524 | 2018-11-28 11:08:50 +0000 | [diff] [blame] | 297 | TestableLooperStats looperStats = new TestableLooperStats(1, 100, null); |
Marcin Oczeretko | c80c81a | 2018-08-30 20:15:52 +0100 | [diff] [blame] | 298 | |
| 299 | Object token1 = looperStats.messageDispatchStarting(); |
| 300 | looperStats.messageDispatched(token1, mHandlerFirst.obtainMessage(1000)); |
| 301 | Object token2 = looperStats.messageDispatchStarting(); |
| 302 | looperStats.dispatchingThrewException(token2, mHandlerFirst.obtainMessage(1000), |
| 303 | new IllegalArgumentException()); |
| 304 | |
| 305 | List<LooperStats.ExportedEntry> entries = looperStats.getEntries(); |
| 306 | assertThat(entries).hasSize(0); |
| 307 | } |
| 308 | |
| 309 | @Test |
| 310 | public void testDataNotCollectedOnCharger() { |
| 311 | TestableLooperStats looperStats = new TestableLooperStats(1, 100); |
| 312 | mDeviceState.setCharging(true); |
| 313 | |
| 314 | Object token1 = looperStats.messageDispatchStarting(); |
| 315 | looperStats.messageDispatched(token1, mHandlerFirst.obtainMessage(1000)); |
| 316 | Object token2 = looperStats.messageDispatchStarting(); |
| 317 | looperStats.dispatchingThrewException(token2, mHandlerFirst.obtainMessage(1000), |
| 318 | new IllegalArgumentException()); |
| 319 | |
| 320 | List<LooperStats.ExportedEntry> entries = looperStats.getEntries(); |
| 321 | assertThat(entries).hasSize(0); |
| 322 | } |
| 323 | |
| 324 | @Test |
| 325 | public void testScreenStateCollected() { |
| 326 | TestableLooperStats looperStats = new TestableLooperStats(1, 100); |
| 327 | |
| 328 | mDeviceState.setScreenInteractive(true); |
| 329 | Object token1 = looperStats.messageDispatchStarting(); |
| 330 | looperStats.messageDispatched(token1, mHandlerFirst.obtainMessage(1000)); |
| 331 | Object token2 = looperStats.messageDispatchStarting(); |
| 332 | looperStats.dispatchingThrewException(token2, mHandlerFirst.obtainMessage(1000), |
| 333 | new IllegalArgumentException()); |
| 334 | |
| 335 | Object token3 = looperStats.messageDispatchStarting(); |
| 336 | // If screen state changed during the call, we take the final state into account. |
| 337 | mDeviceState.setScreenInteractive(false); |
| 338 | looperStats.messageDispatched(token3, mHandlerFirst.obtainMessage(1000)); |
| 339 | Object token4 = looperStats.messageDispatchStarting(); |
| 340 | looperStats.dispatchingThrewException(token4, mHandlerFirst.obtainMessage(1000), |
| 341 | new IllegalArgumentException()); |
| 342 | |
| 343 | List<LooperStats.ExportedEntry> entries = looperStats.getEntries(); |
| 344 | assertThat(entries).hasSize(2); |
| 345 | entries.sort(Comparator.comparing(e -> e.isInteractive)); |
| 346 | |
| 347 | LooperStats.ExportedEntry entry1 = entries.get(0); |
| 348 | assertThat(entry1.isInteractive).isEqualTo(false); |
| 349 | assertThat(entry1.messageCount).isEqualTo(1); |
| 350 | assertThat(entry1.exceptionCount).isEqualTo(1); |
| 351 | |
| 352 | LooperStats.ExportedEntry entry2 = entries.get(1); |
| 353 | assertThat(entry2.isInteractive).isEqualTo(true); |
| 354 | assertThat(entry2.messageCount).isEqualTo(1); |
| 355 | assertThat(entry2.exceptionCount).isEqualTo(1); |
| 356 | } |
| 357 | |
| 358 | @Test |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 359 | public void testMessagesOverSizeCap() { |
Marcin Oczeretko | a674bc9 | 2018-09-13 18:20:21 +0100 | [diff] [blame] | 360 | TestableLooperStats looperStats = new TestableLooperStats(1, 1 /* sizeCap */); |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 361 | |
| 362 | Object token1 = looperStats.messageDispatchStarting(); |
| 363 | looperStats.tickRealtime(100); |
| 364 | looperStats.tickThreadTime(10); |
| 365 | looperStats.messageDispatched(token1, mHandlerFirst.obtainMessage(1000)); |
| 366 | |
| 367 | Object token2 = looperStats.messageDispatchStarting(); |
| 368 | looperStats.tickRealtime(50); |
| 369 | looperStats.tickThreadTime(20); |
| 370 | looperStats.messageDispatched(token2, mHandlerFirst.obtainMessage(1001)); |
| 371 | |
| 372 | Object token3 = looperStats.messageDispatchStarting(); |
| 373 | looperStats.tickRealtime(10); |
| 374 | looperStats.tickThreadTime(10); |
| 375 | looperStats.messageDispatched(token3, mHandlerFirst.obtainMessage(1002)); |
| 376 | |
| 377 | Object token4 = looperStats.messageDispatchStarting(); |
| 378 | looperStats.tickRealtime(10); |
| 379 | looperStats.tickThreadTime(10); |
| 380 | looperStats.messageDispatched(token4, mHandlerSecond.obtainMessage(1003)); |
| 381 | |
| 382 | List<LooperStats.ExportedEntry> entries = looperStats.getEntries(); |
| 383 | assertThat(entries).hasSize(2); |
| 384 | entries.sort(Comparator.comparing(e -> e.handlerClassName)); |
| 385 | |
| 386 | LooperStats.ExportedEntry entry1 = entries.get(0); |
| 387 | assertThat(entry1.threadName).isEqualTo(""); |
| 388 | assertThat(entry1.handlerClassName).isEqualTo(""); |
| 389 | assertThat(entry1.messageName).isEqualTo("OVERFLOW"); |
| 390 | assertThat(entry1.messageCount).isEqualTo(3); |
Marcin Oczeretko | a674bc9 | 2018-09-13 18:20:21 +0100 | [diff] [blame] | 391 | assertThat(entry1.recordedMessageCount).isEqualTo(3); |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 392 | assertThat(entry1.exceptionCount).isEqualTo(0); |
Marcin Oczeretko | a674bc9 | 2018-09-13 18:20:21 +0100 | [diff] [blame] | 393 | assertThat(entry1.totalLatencyMicros).isEqualTo(70); |
| 394 | assertThat(entry1.maxLatencyMicros).isEqualTo(50); |
| 395 | assertThat(entry1.cpuUsageMicros).isEqualTo(40); |
| 396 | assertThat(entry1.maxCpuUsageMicros).isEqualTo(20); |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 397 | |
| 398 | LooperStats.ExportedEntry entry2 = entries.get(1); |
| 399 | assertThat(entry2.threadName).isEqualTo("TestThread1"); |
| 400 | assertThat(entry2.handlerClassName).isEqualTo( |
| 401 | "com.android.internal.os.LooperStatsTest$TestHandlerFirst"); |
| 402 | } |
| 403 | |
| 404 | @Test |
| 405 | public void testInvalidTokensCauseException() { |
| 406 | TestableLooperStats looperStats = new TestableLooperStats(1, 100); |
| 407 | assertThrows(ClassCastException.class, |
| 408 | () -> looperStats.dispatchingThrewException(new Object(), |
| 409 | mHandlerFirst.obtainMessage(), |
| 410 | new ArithmeticException())); |
| 411 | assertThrows(ClassCastException.class, |
| 412 | () -> looperStats.messageDispatched(new Object(), mHandlerFirst.obtainMessage())); |
| 413 | assertThrows(ClassCastException.class, |
| 414 | () -> looperStats.messageDispatched(123, mHandlerFirst.obtainMessage())); |
| 415 | assertThrows(ClassCastException.class, |
| 416 | () -> looperStats.messageDispatched(mHandlerFirst.obtainMessage(), |
| 417 | mHandlerFirst.obtainMessage())); |
| 418 | |
| 419 | assertThat(looperStats.getEntries()).hasSize(0); |
| 420 | } |
| 421 | |
| 422 | @Test |
| 423 | public void testTracksMultipleHandlerInstancesIfSameClass() { |
| 424 | TestableLooperStats looperStats = new TestableLooperStats(1, 100); |
| 425 | Handler handlerFirstAnother = new TestHandlerFirst(mHandlerFirst.getLooper()); |
| 426 | |
| 427 | Object token1 = looperStats.messageDispatchStarting(); |
| 428 | looperStats.messageDispatched(token1, mHandlerFirst.obtainMessage(1000)); |
| 429 | |
| 430 | Object token2 = looperStats.messageDispatchStarting(); |
| 431 | looperStats.messageDispatched(token2, handlerFirstAnother.obtainMessage(1000)); |
| 432 | |
| 433 | assertThat(looperStats.getEntries()).hasSize(1); |
| 434 | assertThat(looperStats.getEntries().get(0).messageCount).isEqualTo(2); |
| 435 | } |
| 436 | |
Marcin Oczeretko | 3e6494e | 2018-09-10 18:06:52 +0100 | [diff] [blame] | 437 | @Test |
| 438 | public void testReset() { |
| 439 | TestableLooperStats looperStats = new TestableLooperStats(1, 1); |
| 440 | |
| 441 | Object token1 = looperStats.messageDispatchStarting(); |
| 442 | looperStats.messageDispatched(token1, mHandlerFirst.obtainMessage(1000)); |
| 443 | Object token2 = looperStats.messageDispatchStarting(); |
| 444 | looperStats.messageDispatched(token2, mHandlerFirst.obtainMessage(2000)); |
| 445 | looperStats.reset(); |
| 446 | |
| 447 | List<LooperStats.ExportedEntry> entries = looperStats.getEntries(); |
| 448 | assertThat(entries).hasSize(0); |
| 449 | } |
| 450 | |
Marcin Oczeretko | d32a5135 | 2018-11-20 18:11:37 +0000 | [diff] [blame] | 451 | @Test |
| 452 | public void testAddsDebugEntries() { |
| 453 | TestableLooperStats looperStats = new TestableLooperStats(1, 100); |
| 454 | looperStats.setAddDebugEntries(true); |
Olivier Gaillard | 5d339dd | 2019-03-08 11:25:05 +0000 | [diff] [blame] | 455 | looperStats.setSamplingInterval(10); |
Marcin Oczeretko | d32a5135 | 2018-11-20 18:11:37 +0000 | [diff] [blame] | 456 | |
| 457 | Message message = mHandlerFirst.obtainMessage(1000); |
| 458 | message.when = looperStats.getSystemUptimeMillis(); |
| 459 | Object token = looperStats.messageDispatchStarting(); |
| 460 | looperStats.messageDispatched(token, message); |
| 461 | |
| 462 | List<LooperStats.ExportedEntry> entries = looperStats.getEntries(); |
Olivier Gaillard | 5d339dd | 2019-03-08 11:25:05 +0000 | [diff] [blame] | 463 | assertThat(entries).hasSize(5); |
Marcin Oczeretko | d32a5135 | 2018-11-20 18:11:37 +0000 | [diff] [blame] | 464 | LooperStats.ExportedEntry debugEntry1 = entries.get(1); |
| 465 | assertThat(debugEntry1.handlerClassName).isEqualTo(""); |
| 466 | assertThat(debugEntry1.messageName).isEqualTo("__DEBUG_start_time_millis"); |
Olivier Gaillard | 28109b5 | 2018-12-14 15:14:14 +0000 | [diff] [blame] | 467 | assertThat(debugEntry1.totalLatencyMicros).isEqualTo( |
| 468 | looperStats.getStartElapsedTimeMillis()); |
Marcin Oczeretko | d32a5135 | 2018-11-20 18:11:37 +0000 | [diff] [blame] | 469 | LooperStats.ExportedEntry debugEntry2 = entries.get(2); |
| 470 | assertThat(debugEntry2.handlerClassName).isEqualTo(""); |
| 471 | assertThat(debugEntry2.messageName).isEqualTo("__DEBUG_end_time_millis"); |
Olivier Gaillard | 28109b5 | 2018-12-14 15:14:14 +0000 | [diff] [blame] | 472 | assertThat(debugEntry2.totalLatencyMicros).isAtLeast( |
| 473 | looperStats.getStartElapsedTimeMillis()); |
Marcin Oczeretko | 6a2e524 | 2018-11-28 11:08:50 +0000 | [diff] [blame] | 474 | LooperStats.ExportedEntry debugEntry3 = entries.get(3); |
| 475 | assertThat(debugEntry3.handlerClassName).isEqualTo(""); |
| 476 | assertThat(debugEntry3.messageName).isEqualTo("__DEBUG_battery_time_millis"); |
Marcin Oczeretko | 8d86174 | 2018-12-06 11:13:29 +0000 | [diff] [blame] | 477 | assertThat(debugEntry3.totalLatencyMicros).isAtLeast(0L); |
Olivier Gaillard | 5d339dd | 2019-03-08 11:25:05 +0000 | [diff] [blame] | 478 | LooperStats.ExportedEntry debugEntry4 = entries.get(4); |
| 479 | assertThat(debugEntry4.messageName).isEqualTo("__DEBUG_sampling_interval"); |
| 480 | assertThat(debugEntry4.totalLatencyMicros).isEqualTo(10L); |
Marcin Oczeretko | d32a5135 | 2018-11-20 18:11:37 +0000 | [diff] [blame] | 481 | } |
| 482 | |
Olivier Gaillard | 36b80ca | 2019-02-11 11:41:39 +0000 | [diff] [blame] | 483 | @Test |
| 484 | public void testScreenStateTrackingDisabled() { |
| 485 | TestableLooperStats looperStats = new TestableLooperStats(1, 100); |
| 486 | looperStats.setTrackScreenInteractive(false); |
| 487 | |
| 488 | Message message = mHandlerFirst.obtainMessage(1000); |
| 489 | message.workSourceUid = 1000; |
| 490 | message.when = looperStats.getSystemUptimeMillis(); |
| 491 | |
| 492 | looperStats.tickUptime(30); |
| 493 | mDeviceState.setScreenInteractive(false); |
| 494 | Object token = looperStats.messageDispatchStarting(); |
| 495 | looperStats.messageDispatched(token, message); |
| 496 | |
| 497 | looperStats.tickUptime(30); |
| 498 | mDeviceState.setScreenInteractive(true); |
| 499 | token = looperStats.messageDispatchStarting(); |
| 500 | looperStats.messageDispatched(token, message); |
| 501 | |
| 502 | List<LooperStats.ExportedEntry> entries = looperStats.getEntries(); |
| 503 | assertThat(entries).hasSize(1); |
| 504 | LooperStats.ExportedEntry entry = entries.get(0); |
| 505 | assertThat(entry.isInteractive).isEqualTo(false); |
| 506 | assertThat(entry.messageCount).isEqualTo(2); |
| 507 | assertThat(entry.recordedMessageCount).isEqualTo(2); |
| 508 | } |
| 509 | |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 510 | private static void assertThrows(Class<? extends Exception> exceptionClass, Runnable r) { |
| 511 | try { |
| 512 | r.run(); |
| 513 | Assert.fail("Expected " + exceptionClass + " to be thrown."); |
| 514 | } catch (Exception exception) { |
| 515 | assertThat(exception).isInstanceOf(exceptionClass); |
| 516 | } |
| 517 | } |
| 518 | |
Marcin Oczeretko | c80c81a | 2018-08-30 20:15:52 +0100 | [diff] [blame] | 519 | private final class TestableLooperStats extends LooperStats { |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 520 | private static final long INITIAL_MICROS = 10001000123L; |
| 521 | private int mCount; |
| 522 | private long mRealtimeMicros; |
| 523 | private long mThreadTimeMicros; |
Marcin Oczeretko | 4427272 | 2018-09-19 11:01:32 +0100 | [diff] [blame] | 524 | private long mUptimeMillis; |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 525 | private int mSamplingInterval; |
| 526 | |
| 527 | TestableLooperStats(int samplingInterval, int sizeCap) { |
Marcin Oczeretko | 6a2e524 | 2018-11-28 11:08:50 +0000 | [diff] [blame] | 528 | this(samplingInterval, sizeCap, mDeviceState); |
| 529 | } |
| 530 | |
| 531 | TestableLooperStats(int samplingInterval, int sizeCap, CachedDeviceState deviceState) { |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 532 | super(samplingInterval, sizeCap); |
Marcin Oczeretko | 6a2e524 | 2018-11-28 11:08:50 +0000 | [diff] [blame] | 533 | mSamplingInterval = samplingInterval; |
| 534 | setAddDebugEntries(false); |
Olivier Gaillard | 36b80ca | 2019-02-11 11:41:39 +0000 | [diff] [blame] | 535 | setTrackScreenInteractive(true); |
Marcin Oczeretko | 6a2e524 | 2018-11-28 11:08:50 +0000 | [diff] [blame] | 536 | if (deviceState != null) { |
| 537 | setDeviceState(deviceState.getReadonlyClient()); |
| 538 | } |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 539 | } |
| 540 | |
| 541 | void tickRealtime(long micros) { |
| 542 | mRealtimeMicros += micros; |
| 543 | } |
| 544 | |
| 545 | void tickThreadTime(long micros) { |
| 546 | mThreadTimeMicros += micros; |
| 547 | } |
| 548 | |
Marcin Oczeretko | 4427272 | 2018-09-19 11:01:32 +0100 | [diff] [blame] | 549 | void tickUptime(long millis) { |
| 550 | mUptimeMillis += millis; |
| 551 | } |
| 552 | |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 553 | @Override |
| 554 | protected long getElapsedRealtimeMicro() { |
| 555 | return INITIAL_MICROS + mRealtimeMicros; |
| 556 | } |
| 557 | |
| 558 | @Override |
| 559 | protected long getThreadTimeMicro() { |
| 560 | return INITIAL_MICROS + mThreadTimeMicros; |
| 561 | } |
| 562 | |
| 563 | @Override |
Marcin Oczeretko | 4427272 | 2018-09-19 11:01:32 +0100 | [diff] [blame] | 564 | protected long getSystemUptimeMillis() { |
| 565 | return INITIAL_MICROS / 1000 + mUptimeMillis; |
| 566 | } |
| 567 | |
| 568 | @Override |
Marcin Oczeretko | d8cc859 | 2018-08-22 16:07:36 +0100 | [diff] [blame] | 569 | protected boolean shouldCollectDetailedData() { |
| 570 | return mCount++ % mSamplingInterval == 0; |
| 571 | } |
| 572 | } |
| 573 | |
| 574 | private static final class TestHandlerFirst extends Handler { |
| 575 | TestHandlerFirst(Looper looper) { |
| 576 | super(looper); |
| 577 | } |
| 578 | } |
| 579 | |
| 580 | private static final class TestHandlerSecond extends Handler { |
| 581 | TestHandlerSecond(Looper looper) { |
| 582 | super(looper); |
| 583 | } |
| 584 | } |
| 585 | } |