Android/frameworks_base
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Merge "Collect telemetry data for System Server Loopers."

Browse Source
This commit is contained in:
Marcin Oczeretko
2018-09-05 19:12:45 +00:00
committed by Android (Google) Code Review
parent 8ef645daa2 d8cc8593c0
commit f1d4563acd
8 changed files with 883 additions and 3 deletions
Download Patch File Download Diff File Expand all files Collapse all files

50
cmds/statsd/src/atoms.proto
View File

@@ -133,7 +133,7 @@ message Atom {
}
// Pulled events will start at field 10000.
// Next: 10024
// Next: 10025
oneof pulled {
WifiBytesTransfer wifi_bytes_transfer = 10000;
WifiBytesTransferByFgBg wifi_bytes_transfer_by_fg_bg = 10001;
@@ -159,6 +159,7 @@ message Atom {
Temperature temperature = 10021;
BinderCalls binder_calls = 10022;
BinderCallsExceptions binder_calls_exceptions = 10023;
LooperStats looper_stats = 10024;
}
// DO NOT USE field numbers above 100,000 in AOSP. Field numbers above
@@ -2203,3 +2204,50 @@ message BinderCallsExceptions {
// Total number of exceptions.
optional int64 exception_count = 2;
}
message LooperStats {
// Currently not collected and always set to 0.
optional int32 uid = 1 [(is_uid) = true];
// Fully qualified class name of the handler target class.
//
// This field does not contain PII. This is a system server class name.
optional string handler_class_name = 2;
// The name of the thread that runs the Looper.
//
// This field does not contain PII. This is a system server thread name.
optional string looper_thread_name = 3;
// The name of the dispatched message.
//
// This field does not contain PII. This is a system server constant or class
// name.
optional string message_name = 4;
// Total number of successfully dispatched messages.
optional int64 message_count = 5;
// Total number of messages that failed dispatching.
optional int64 exception_count = 6;
// Total number of processed messages we have data recorded for. If we
// collected data for all the messages, message_count will be equal to
// recorded_message_count.
//
// If recorded_message_count is different than message_count, it means data
// collection has been sampled. All the fields below will be sampled in this
// case.
optional int64 recorded_message_count = 7;
// Total latency of all processed messages.
// Average can be computed using recorded_total_latency_micros /
// recorded_message_count.
optional int64 recorded_total_latency_micros = 8;
// Total CPU usage of all processed message.
// Average can be computed using recorded_total_cpu_micros /
// recorded_message_count. Total can be computed using
// recorded_total_cpu_micros / recorded_message_count * call_count.
optional int64 recorded_total_cpu_micros = 9;
}

8
cmds/statsd/src/external/StatsPullerManager.cpp vendored
View File

@@ -183,7 +183,13 @@ const std::map<int, PullAtomInfo> StatsPullerManager::kAllPullAtomInfo = {
{{},
{},
1 * NS_PER_SEC,
new StatsCompanionServicePuller(android::util::BINDER_CALLS_EXCEPTIONS)}}
new StatsCompanionServicePuller(android::util::BINDER_CALLS_EXCEPTIONS)}},
// looper_stats
{android::util::LOOPER_STATS,
{{5, 6, 7, 8, 9},
{2, 3, 4},
1 * NS_PER_SEC,
new StatsCompanionServicePuller(android::util::LOOPER_STATS)}}
};
StatsPullerManager::StatsPullerManager() : mNextPullTimeNs(NO_ALARM_UPDATE) {

60
core/java/android/os/Looper.java
View File

@@ -18,7 +18,6 @@ package android.os;
import android.annotation.NonNull;
import android.annotation.Nullable;
import android.os.LooperProto;
import android.util.Log;
import android.util.Printer;
import android.util.Slog;
@@ -70,6 +69,7 @@ public final class Looper {
// sThreadLocal.get() will return null unless you've called prepare().
static final ThreadLocal<Looper> sThreadLocal = new ThreadLocal<Looper>();
private static Looper sMainLooper; // guarded by Looper.class
private static Observer sObserver;
final MessageQueue mQueue;
final Thread mThread;
@@ -130,6 +130,15 @@ public final class Looper {
}
}
/**
* Set the transaction observer for all Loopers in this process.
*
* @hide
*/
public static void setObserver(@Nullable Observer observer) {
sObserver = observer;
}
/**
* Run the message queue in this thread. Be sure to call
* {@link #quit()} to end the loop.
@@ -169,6 +178,8 @@ public final class Looper {
logging.println(">>>>> Dispatching to " + msg.target + " " +
msg.callback + ": " + msg.what);
}
// Make sure the observer won't change while processing a transaction.
final Observer observer = sObserver;
final long traceTag = me.mTraceTag;
long slowDispatchThresholdMs = me.mSlowDispatchThresholdMs;
@@ -189,9 +200,21 @@ public final class Looper {
final long dispatchStart = needStartTime ? SystemClock.uptimeMillis() : 0;
final long dispatchEnd;
Object token = null;
if (observer != null) {
token = observer.messageDispatchStarting();
}
try {
msg.target.dispatchMessage(msg);
if (observer != null) {
observer.messageDispatched(token, msg);
}
dispatchEnd = needEndTime ? SystemClock.uptimeMillis() : 0;
} catch (Exception exception) {
if (observer != null) {
observer.dispatchingThrewException(token, msg, exception);
}
throw exception;
} finally {
if (traceTag != 0) {
Trace.traceEnd(traceTag);
@@ -397,4 +420,39 @@ public final class Looper {
return "Looper (" + mThread.getName() + ", tid " + mThread.getId()
+ ") {" + Integer.toHexString(System.identityHashCode(this)) + "}";
}
/** {@hide} */
public interface Observer {
/**
* Called right before a message is dispatched.
*
* <p> The token type is not specified to allow the implementation to specify its own type.
*
* @return a token used for collecting telemetry when dispatching a single message.
* The token token must be passed back exactly once to either
* {@link Observer#messageDispatched} or {@link Observer#dispatchingThrewException}
* and must not be reused again.
*
*/
Object messageDispatchStarting();
/**
* Called when a message was processed by a Handler.
*
* @param token Token obtained by previously calling
* {@link Observer#messageDispatchStarting} on the same Observer instance.
* @param msg The message that was dispatched.
*/
void messageDispatched(Object token, Message msg);
/**
* Called when an exception was thrown while processing a message.
*
* @param token Token obtained by previously calling
* {@link Observer#messageDispatchStarting} on the same Observer instance.
* @param msg The message that was dispatched and caused an exception.
* @param exception The exception that was thrown.
*/
void dispatchingThrewException(Object token, Message msg, Exception exception);
}
}

269
core/java/com/android/internal/os/LooperStats.java Normal file
View File

@@ -0,0 +1,269 @@
/*
* Copyright (C) 2018 The Android Open Source Project
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package com.android.internal.os;
import android.annotation.NonNull;
import android.os.Handler;
import android.os.Looper;
import android.os.Message;
import android.os.SystemClock;
import android.util.SparseArray;
import com.android.internal.annotations.GuardedBy;
import java.util.ArrayList;
import java.util.List;
import java.util.concurrent.ConcurrentLinkedQueue;
import java.util.concurrent.ThreadLocalRandom;
/**
* Collects aggregated telemetry data about Looper message dispatching.
*
* @hide Only for use within the system server.
*/
public class LooperStats implements Looper.Observer {
private static final int TOKEN_POOL_SIZE = 50;
private static final int DEFAULT_ENTRIES_SIZE_CAP = 2000;
private static final int DEFAULT_SAMPLING_INTERVAL = 100;
@GuardedBy("mLock")
private final SparseArray<Entry> mEntries = new SparseArray<>(256);
private final Object mLock = new Object();
private final Entry mOverflowEntry = new Entry("OVERFLOW");
private final Entry mHashCollisionEntry = new Entry("HASH_COLLISION");
private final ConcurrentLinkedQueue<DispatchSession> mSessionPool =
new ConcurrentLinkedQueue<>();
private final int mSamplingInterval;
private final int mEntriesSizeCap;
public LooperStats() {
this(DEFAULT_SAMPLING_INTERVAL, DEFAULT_ENTRIES_SIZE_CAP);
}
public LooperStats(int samplingInterval, int entriesSizeCap) {
this.mSamplingInterval = samplingInterval;
this.mEntriesSizeCap = entriesSizeCap;
}
@Override
public Object messageDispatchStarting() {
if (shouldCollectDetailedData()) {
DispatchSession session = mSessionPool.poll();
session = session == null ? new DispatchSession() : session;
session.startTimeMicro = getElapsedRealtimeMicro();
session.cpuStartMicro = getThreadTimeMicro();
return session;
}
return DispatchSession.NOT_SAMPLED;
}
@Override
public void messageDispatched(Object token, Message msg) {
DispatchSession session = (DispatchSession) token;
Entry entry = getOrCreateEntry(msg);
synchronized (entry) {
entry.messageCount++;
if (session != DispatchSession.NOT_SAMPLED) {
entry.recordedMessageCount++;
long latency = getElapsedRealtimeMicro() - session.startTimeMicro;
long cpuUsage = getThreadTimeMicro() - session.cpuStartMicro;
entry.totalLatencyMicro += latency;
entry.maxLatencyMicro = Math.max(entry.maxLatencyMicro, latency);
entry.cpuUsageMicro += cpuUsage;
entry.maxCpuUsageMicro = Math.max(entry.maxCpuUsageMicro, cpuUsage);
}
}
recycleSession(session);
}
@Override
public void dispatchingThrewException(Object token, Message msg, Exception exception) {
DispatchSession session = (DispatchSession) token;
Entry entry = getOrCreateEntry(msg);
synchronized (entry) {
entry.exceptionCount++;
}
recycleSession(session);
}
/** Returns an array of {@link ExportedEntry entries} with the aggregated statistics. */
public List<ExportedEntry> getEntries() {
final ArrayList<ExportedEntry> entries;
synchronized (mLock) {
final int size = mEntries.size();
entries = new ArrayList<>(size);
for (int i = 0; i < size; i++) {
Entry entry = mEntries.valueAt(i);
synchronized (entry) {
entries.add(new ExportedEntry(entry));
}
}
}
// Add the overflow and collision entries only if they have any data.
if (mOverflowEntry.messageCount > 0 || mOverflowEntry.exceptionCount > 0) {
synchronized (mOverflowEntry) {
entries.add(new ExportedEntry(mOverflowEntry));
}
}
if (mHashCollisionEntry.messageCount > 0 || mHashCollisionEntry.exceptionCount > 0) {
synchronized (mHashCollisionEntry) {
entries.add(new ExportedEntry(mHashCollisionEntry));
}
}
return entries;
}
/** Removes all collected data. */
public void reset() {
synchronized (mLock) {
mEntries.clear();
}
synchronized (mHashCollisionEntry) {
mHashCollisionEntry.reset();
}
synchronized (mOverflowEntry) {
mOverflowEntry.reset();
}
}
@NonNull
private Entry getOrCreateEntry(Message msg) {
final int id = Entry.idFor(msg);
Entry entry;
synchronized (mLock) {
entry = mEntries.get(id);
if (entry == null) {
if (mEntries.size() >= mEntriesSizeCap) {
// If over the size cap, track totals under a single entry.
return mOverflowEntry;
}
entry = new Entry(msg);
mEntries.put(id, entry);
}
}
if (entry.handler.getClass() != msg.getTarget().getClass()
|| entry.handler.getLooper().getThread()
!= msg.getTarget().getLooper().getThread()) {
// If a hash collision happened, track totals under a single entry.
return mHashCollisionEntry;
}
return entry;
}
private void recycleSession(DispatchSession session) {
if (session != DispatchSession.NOT_SAMPLED && mSessionPool.size() < TOKEN_POOL_SIZE) {
mSessionPool.add(session);
}
}
protected long getThreadTimeMicro() {
return SystemClock.currentThreadTimeMicro();
}
protected long getElapsedRealtimeMicro() {
return SystemClock.elapsedRealtimeNanos() / 1000;
}
protected boolean shouldCollectDetailedData() {
return ThreadLocalRandom.current().nextInt() % mSamplingInterval == 0;
}
private static class DispatchSession {
static final DispatchSession NOT_SAMPLED = new DispatchSession();
public long startTimeMicro;
public long cpuStartMicro;
}
private static class Entry {
public final Handler handler;
public final String messageName;
public long messageCount;
public long recordedMessageCount;
public long exceptionCount;
public long totalLatencyMicro;
public long maxLatencyMicro;
public long cpuUsageMicro;
public long maxCpuUsageMicro;
Entry(Message msg) {
handler = msg.getTarget();
messageName = handler.getMessageName(msg);
}
Entry(String specialEntryName) {
handler = null;
messageName = specialEntryName;
}
void reset() {
messageCount = 0;
recordedMessageCount = 0;
exceptionCount = 0;
totalLatencyMicro = 0;
maxLatencyMicro = 0;
cpuUsageMicro = 0;
maxCpuUsageMicro = 0;
}
static int idFor(Message msg) {
int result = 7;
result = 31 * result + msg.getTarget().getLooper().getThread().hashCode();
result = 31 * result + msg.getTarget().getClass().hashCode();
if (msg.getCallback() != null) {
return 31 * result + msg.getCallback().getClass().hashCode();
} else {
return 31 * result + msg.what;
}
}
}
/** Aggregated data of Looper message dispatching in the in the current process. */
public static class ExportedEntry {
public final String handlerClassName;
public final String threadName;
public final String messageName;
public final long messageCount;
public final long recordedMessageCount;
public final long exceptionCount;
public final long totalLatencyMicros;
public final long maxLatencyMicros;
public final long cpuUsageMicros;
public final long maxCpuUsageMicros;
ExportedEntry(Entry entry) {
if (entry.handler != null) {
this.handlerClassName = entry.handler.getClass().getName();
this.threadName = entry.handler.getLooper().getThread().getName();
} else {
// Overflow/collision entries do not have a handler set.
this.handlerClassName = "";
this.threadName = "";
}
this.messageName = entry.messageName;
this.messageCount = entry.messageCount;
this.recordedMessageCount = entry.recordedMessageCount;
this.exceptionCount = entry.exceptionCount;
this.totalLatencyMicros = entry.totalLatencyMicro;
this.maxLatencyMicros = entry.maxLatencyMicro;
this.cpuUsageMicros = entry.cpuUsageMicro;
this.maxCpuUsageMicros = entry.maxCpuUsageMicro;
}
}
}

331
core/tests/coretests/src/com/android/internal/os/LooperStatsTest.java Normal file
View File

@@ -0,0 +1,331 @@
/*
* Copyright (C) 2018 The Android Open Source Project
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package com.android.internal.os;
import static com.google.common.truth.Truth.assertThat;
import android.os.Handler;
import android.os.HandlerThread;
import android.os.Looper;
import android.platform.test.annotations.Presubmit;
import android.support.test.filters.SmallTest;
import android.support.test.runner.AndroidJUnit4;
import org.junit.After;
import org.junit.Assert;
import org.junit.Before;
import org.junit.Test;
import org.junit.runner.RunWith;
import java.util.Comparator;
import java.util.List;
@SmallTest
@RunWith(AndroidJUnit4.class)
@Presubmit
public final class LooperStatsTest {
private HandlerThread mThreadFirst;
private HandlerThread mThreadSecond;
private Handler mHandlerFirst;
private Handler mHandlerSecond;
private Handler mHandlerAnonymous;
@Before
public void setUp() {
// The tests are all single-threaded. HandlerThreads are created to allow creating Handlers
// and to test Thread name collection.
mThreadFirst = new HandlerThread("TestThread1");
mThreadSecond = new HandlerThread("TestThread2");
mThreadFirst.start();
mThreadSecond.start();
mHandlerFirst = new TestHandlerFirst(mThreadFirst.getLooper());
mHandlerSecond = new TestHandlerSecond(mThreadSecond.getLooper());
mHandlerAnonymous = new Handler(mThreadFirst.getLooper()) {
/* To create an anonymous subclass. */
};
}
@After
public void tearDown() {
mThreadFirst.quit();
mThreadSecond.quit();
}
@Test
public void testSingleMessageDispatched() {
TestableLooperStats looperStats = new TestableLooperStats(1, 100);
Object token = looperStats.messageDispatchStarting();
looperStats.tickRealtime(100);
looperStats.tickThreadTime(10);
looperStats.messageDispatched(token, mHandlerFirst.obtainMessage(1000));
List<LooperStats.ExportedEntry> entries = looperStats.getEntries();
assertThat(entries).hasSize(1);
LooperStats.ExportedEntry entry = entries.get(0);
assertThat(entry.threadName).isEqualTo("TestThread1");
assertThat(entry.handlerClassName).isEqualTo(
"com.android.internal.os.LooperStatsTest$TestHandlerFirst");
assertThat(entry.messageName).isEqualTo("0x3e8" /* 1000 in hex */);
assertThat(entry.messageCount).isEqualTo(1);
assertThat(entry.recordedMessageCount).isEqualTo(1);
assertThat(entry.exceptionCount).isEqualTo(0);
assertThat(entry.totalLatencyMicros).isEqualTo(100);
assertThat(entry.maxLatencyMicros).isEqualTo(100);
assertThat(entry.cpuUsageMicros).isEqualTo(10);
assertThat(entry.maxCpuUsageMicros).isEqualTo(10);
}
@Test
public void testThrewException() {
TestableLooperStats looperStats = new TestableLooperStats(1, 100);
Object token = looperStats.messageDispatchStarting();
looperStats.tickRealtime(100);
looperStats.tickThreadTime(10);
looperStats.dispatchingThrewException(token, mHandlerFirst.obtainMessage(7),
new ArithmeticException());
List<LooperStats.ExportedEntry> entries = looperStats.getEntries();
assertThat(entries).hasSize(1);
LooperStats.ExportedEntry entry = entries.get(0);
assertThat(entry.threadName).isEqualTo("TestThread1");
assertThat(entry.handlerClassName).isEqualTo(
"com.android.internal.os.LooperStatsTest$TestHandlerFirst");
assertThat(entry.messageName).isEqualTo("0x7" /* 7 in hex */);
assertThat(entry.messageCount).isEqualTo(0);
assertThat(entry.recordedMessageCount).isEqualTo(0);
assertThat(entry.exceptionCount).isEqualTo(1);
assertThat(entry.totalLatencyMicros).isEqualTo(0);
assertThat(entry.maxLatencyMicros).isEqualTo(0);
assertThat(entry.cpuUsageMicros).isEqualTo(0);
assertThat(entry.maxCpuUsageMicros).isEqualTo(0);
}
@Test
public void testMultipleMessagesDispatched() {
TestableLooperStats looperStats = new TestableLooperStats(2, 100);
// Contributes to entry2.
Object token1 = looperStats.messageDispatchStarting();
looperStats.tickRealtime(100);
looperStats.tickThreadTime(10);
looperStats.messageDispatched(token1, mHandlerFirst.obtainMessage(1000));
// Contributes to entry2.
Object token2 = looperStats.messageDispatchStarting();
looperStats.tickRealtime(50);
looperStats.tickThreadTime(20);
looperStats.messageDispatched(token2, mHandlerFirst.obtainMessage(1000));
// Contributes to entry3.
Object token3 = looperStats.messageDispatchStarting();
looperStats.tickRealtime(10);
looperStats.tickThreadTime(10);
looperStats.messageDispatched(token3, mHandlerSecond.obtainMessage().setCallback(() -> {
}));
// Contributes to entry1.
Object token4 = looperStats.messageDispatchStarting();
looperStats.tickRealtime(100);
looperStats.tickThreadTime(100);
looperStats.messageDispatched(token4, mHandlerAnonymous.obtainMessage(1));
List<LooperStats.ExportedEntry> entries = looperStats.getEntries();
assertThat(entries).hasSize(3);
entries.sort(Comparator.comparing(e -> e.handlerClassName));
// Captures data for token4 call.
LooperStats.ExportedEntry entry1 = entries.get(0);
assertThat(entry1.threadName).isEqualTo("TestThread1");
assertThat(entry1.handlerClassName).isEqualTo("com.android.internal.os.LooperStatsTest$1");
assertThat(entry1.messageName).isEqualTo("0x1" /* 1 in hex */);
assertThat(entry1.messageCount).isEqualTo(1);
assertThat(entry1.recordedMessageCount).isEqualTo(0);
assertThat(entry1.exceptionCount).isEqualTo(0);
assertThat(entry1.totalLatencyMicros).isEqualTo(0);
assertThat(entry1.maxLatencyMicros).isEqualTo(0);
assertThat(entry1.cpuUsageMicros).isEqualTo(0);
assertThat(entry1.maxCpuUsageMicros).isEqualTo(0);
// Captures data for token1 and token2 calls.
LooperStats.ExportedEntry entry2 = entries.get(1);
assertThat(entry2.threadName).isEqualTo("TestThread1");
assertThat(entry2.handlerClassName).isEqualTo(
"com.android.internal.os.LooperStatsTest$TestHandlerFirst");
assertThat(entry2.messageName).isEqualTo("0x3e8" /* 1000 in hex */);
assertThat(entry2.messageCount).isEqualTo(2);
assertThat(entry2.recordedMessageCount).isEqualTo(1);
assertThat(entry2.exceptionCount).isEqualTo(0);
assertThat(entry2.totalLatencyMicros).isEqualTo(100);
assertThat(entry2.maxLatencyMicros).isEqualTo(100);
assertThat(entry2.cpuUsageMicros).isEqualTo(10);
assertThat(entry2.maxCpuUsageMicros).isEqualTo(10);
// Captures data for token3 call.
LooperStats.ExportedEntry entry3 = entries.get(2);
assertThat(entry3.threadName).isEqualTo("TestThread2");
assertThat(entry3.handlerClassName).isEqualTo(
"com.android.internal.os.LooperStatsTest$TestHandlerSecond");
assertThat(entry3.messageName).startsWith(
"com.android.internal.os.-$$Lambda$LooperStatsTest$");
assertThat(entry3.messageCount).isEqualTo(1);
assertThat(entry3.recordedMessageCount).isEqualTo(1);
assertThat(entry3.exceptionCount).isEqualTo(0);
assertThat(entry3.totalLatencyMicros).isEqualTo(10);
assertThat(entry3.maxLatencyMicros).isEqualTo(10);
assertThat(entry3.cpuUsageMicros).isEqualTo(10);
assertThat(entry3.maxCpuUsageMicros).isEqualTo(10);
}
@Test
public void testMessagesOverSizeCap() {
TestableLooperStats looperStats = new TestableLooperStats(2, 1 /* sizeCap */);
Object token1 = looperStats.messageDispatchStarting();
looperStats.tickRealtime(100);
looperStats.tickThreadTime(10);
looperStats.messageDispatched(token1, mHandlerFirst.obtainMessage(1000));
Object token2 = looperStats.messageDispatchStarting();
looperStats.tickRealtime(50);
looperStats.tickThreadTime(20);
looperStats.messageDispatched(token2, mHandlerFirst.obtainMessage(1001));
Object token3 = looperStats.messageDispatchStarting();
looperStats.tickRealtime(10);
looperStats.tickThreadTime(10);
looperStats.messageDispatched(token3, mHandlerFirst.obtainMessage(1002));
Object token4 = looperStats.messageDispatchStarting();
looperStats.tickRealtime(10);
looperStats.tickThreadTime(10);
looperStats.messageDispatched(token4, mHandlerSecond.obtainMessage(1003));
List<LooperStats.ExportedEntry> entries = looperStats.getEntries();
assertThat(entries).hasSize(2);
entries.sort(Comparator.comparing(e -> e.handlerClassName));
LooperStats.ExportedEntry entry1 = entries.get(0);
assertThat(entry1.threadName).isEqualTo("");
assertThat(entry1.handlerClassName).isEqualTo("");
assertThat(entry1.messageName).isEqualTo("OVERFLOW");
assertThat(entry1.messageCount).isEqualTo(3);
assertThat(entry1.recordedMessageCount).isEqualTo(1);
assertThat(entry1.exceptionCount).isEqualTo(0);
assertThat(entry1.totalLatencyMicros).isEqualTo(10);
assertThat(entry1.maxLatencyMicros).isEqualTo(10);
assertThat(entry1.cpuUsageMicros).isEqualTo(10);
assertThat(entry1.maxCpuUsageMicros).isEqualTo(10);
LooperStats.ExportedEntry entry2 = entries.get(1);
assertThat(entry2.threadName).isEqualTo("TestThread1");
assertThat(entry2.handlerClassName).isEqualTo(
"com.android.internal.os.LooperStatsTest$TestHandlerFirst");
}
@Test
public void testInvalidTokensCauseException() {
TestableLooperStats looperStats = new TestableLooperStats(1, 100);
assertThrows(ClassCastException.class,
() -> looperStats.dispatchingThrewException(new Object(),
mHandlerFirst.obtainMessage(),
new ArithmeticException()));
assertThrows(ClassCastException.class,
() -> looperStats.messageDispatched(new Object(), mHandlerFirst.obtainMessage()));
assertThrows(ClassCastException.class,
() -> looperStats.messageDispatched(123, mHandlerFirst.obtainMessage()));
assertThrows(ClassCastException.class,
() -> looperStats.messageDispatched(mHandlerFirst.obtainMessage(),
mHandlerFirst.obtainMessage()));
assertThat(looperStats.getEntries()).hasSize(0);
}
@Test
public void testTracksMultipleHandlerInstancesIfSameClass() {
TestableLooperStats looperStats = new TestableLooperStats(1, 100);
Handler handlerFirstAnother = new TestHandlerFirst(mHandlerFirst.getLooper());
Object token1 = looperStats.messageDispatchStarting();
looperStats.messageDispatched(token1, mHandlerFirst.obtainMessage(1000));
Object token2 = looperStats.messageDispatchStarting();
looperStats.messageDispatched(token2, handlerFirstAnother.obtainMessage(1000));
assertThat(looperStats.getEntries()).hasSize(1);
assertThat(looperStats.getEntries().get(0).messageCount).isEqualTo(2);
}
private static void assertThrows(Class<? extends Exception> exceptionClass, Runnable r) {
try {
r.run();
Assert.fail("Expected " + exceptionClass + " to be thrown.");
} catch (Exception exception) {
assertThat(exception).isInstanceOf(exceptionClass);
}
}
private static final class TestableLooperStats extends LooperStats {
private static final long INITIAL_MICROS = 10001000123L;
private int mCount;
private long mRealtimeMicros;
private long mThreadTimeMicros;
private int mSamplingInterval;
TestableLooperStats(int samplingInterval, int sizeCap) {
super(samplingInterval, sizeCap);
this.mSamplingInterval = samplingInterval;
}
void tickRealtime(long micros) {
mRealtimeMicros += micros;
}
void tickThreadTime(long micros) {
mThreadTimeMicros += micros;
}
@Override
protected long getElapsedRealtimeMicro() {
return INITIAL_MICROS + mRealtimeMicros;
}
@Override
protected long getThreadTimeMicro() {
return INITIAL_MICROS + mThreadTimeMicros;
}
@Override
protected boolean shouldCollectDetailedData() {
return mCount++ % mSamplingInterval == 0;
}
}
private static final class TestHandlerFirst extends Handler {
TestHandlerFirst(Looper looper) {
super(looper);
}
}
private static final class TestHandlerSecond extends Handler {
TestHandlerSecond(Looper looper) {
super(looper);
}
}
}

135
services/core/java/com/android/server/LooperStatsService.java Normal file
View File

@@ -0,0 +1,135 @@
/*
* Copyright (C) 2018 The Android Open Source Project
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package com.android.server;
import android.content.Context;
import android.os.Binder;
import android.os.Looper;
import android.os.ResultReceiver;
import android.os.ShellCallback;
import android.os.ShellCommand;
import com.android.internal.os.LooperStats;
import com.android.internal.util.DumpUtils;
import java.io.FileDescriptor;
import java.io.PrintWriter;
import java.util.Arrays;
import java.util.Comparator;
import java.util.List;
/**
* @hide Only for use within the system server.
*/
public class LooperStatsService extends Binder {
private static final String TAG = "LooperStatsService";
private static final String LOOPER_STATS_SERVICE_NAME = "looper_stats";
private final Context mContext;
private final LooperStats mStats;
private boolean mEnabled = false;
private LooperStatsService(Context context, LooperStats stats) {
this.mContext = context;
this.mStats = stats;
}
@Override
public void onShellCommand(FileDescriptor in, FileDescriptor out, FileDescriptor err,
String[] args, ShellCallback callback, ResultReceiver resultReceiver) {
(new LooperShellCommand()).exec(this, in, out, err, args, callback, resultReceiver);
}
@Override
protected void dump(FileDescriptor fd, PrintWriter pw, String[] args) {
if (!DumpUtils.checkDumpPermission(mContext, TAG, pw)) return;
List<LooperStats.ExportedEntry> entries = mStats.getEntries();
entries.sort(Comparator
.comparing((LooperStats.ExportedEntry entry) -> entry.threadName)
.thenComparing(entry -> entry.handlerClassName)
.thenComparing(entry -> entry.messageName));
String header = String.join(",", Arrays.asList(
"thread_name",
"handler_class",
"message_name",
"message_count",
"recorded_message_count",
"total_latency_micros",
"max_latency_micros",
"total_cpu_micros",
"max_cpu_micros",
"exception_count"));
pw.println(header);
for (LooperStats.ExportedEntry entry : entries) {
pw.printf("%s,%s,%s,%s,%s,%s,%s,%s,%s,%s\n", entry.threadName, entry.handlerClassName,
entry.messageName, entry.messageCount, entry.recordedMessageCount,
entry.totalLatencyMicros, entry.maxLatencyMicros, entry.cpuUsageMicros,
entry.maxCpuUsageMicros, entry.exceptionCount);
}
}
private void setEnabled(boolean enabled) {
if (mEnabled != enabled) {
mEnabled = enabled;
mStats.reset();
Looper.setObserver(enabled ? mStats : null);
}
}
/**
* Manages the lifecycle of LooperStatsService within System Server.
*/
public static class Lifecycle extends SystemService {
public Lifecycle(Context context) {
super(context);
}
@Override
public void onStart() {
LooperStats stats = new LooperStats();
publishLocalService(LooperStats.class, stats);
// TODO: publish LooperStatsService as a binder service when the SE Policy is changed.
}
}
private class LooperShellCommand extends ShellCommand {
@Override
public int onCommand(String cmd) {
if ("enable".equals(cmd)) {
setEnabled(true);
return 0;
} else if ("disable".equals(cmd)) {
setEnabled(false);
return 0;
} else if ("reset".equals(cmd)) {
mStats.reset();
return 0;
} else {
return handleDefaultCommands(cmd);
}
}
@Override
public void onHelp() {
final PrintWriter pw = getOutPrintWriter();
pw.println(LOOPER_STATS_SERVICE_NAME + " commands:");
pw.println(" enable: Enable collecting stats");
pw.println(" disable: Disable collecting stats");
pw.println(" reset: Reset stats");
}
}
}

28
services/core/java/com/android/server/stats/StatsCompanionService.java
View File

@@ -70,6 +70,7 @@ import com.android.internal.os.KernelUidCpuFreqTimeReader;
import com.android.internal.os.KernelUidCpuTimeReader;
import com.android.internal.os.KernelWakelockReader;
import com.android.internal.os.KernelWakelockStats;
import com.android.internal.os.LooperStats;
import com.android.internal.os.PowerProfile;
import com.android.internal.util.DumpUtils;
import com.android.server.BinderCallsStatsService;
@@ -938,6 +939,29 @@ public class StatsCompanionService extends IStatsCompanionService.Stub {
}
}
private void pullLooperStats(int tagId, List<StatsLogEventWrapper> pulledData) {
LooperStats looperStats = LocalServices.getService(LooperStats.class);
if (looperStats == null) {
return;
}
List<LooperStats.ExportedEntry> entries = looperStats.getEntries();
long elapsedNanos = SystemClock.elapsedRealtimeNanos();
for (LooperStats.ExportedEntry entry : entries) {
StatsLogEventWrapper e = new StatsLogEventWrapper(elapsedNanos, tagId, 9 /* fields */);
e.writeLong(0); // uid collection not implemented yet
e.writeString(entry.handlerClassName);
e.writeString(entry.threadName);
e.writeString(entry.messageName);
e.writeLong(entry.messageCount);
e.writeLong(entry.exceptionCount);
e.writeLong(entry.recordedMessageCount);
e.writeLong(entry.totalLatencyMicros);
e.writeLong(entry.cpuUsageMicros);
pulledData.add(e);
}
}
/**
* Pulls various data.
*/
@@ -1028,6 +1052,10 @@ public class StatsCompanionService extends IStatsCompanionService.Stub {
pullBinderCallsStatsExceptions(tagId, ret);
break;
}
case StatsLog.LOOPER_STATS: {
pullLooperStats(tagId, ret);
break;
}
default:
Slog.w(TAG, "No such tagId data as " + tagId);
return null;

5
services/java/com/android/server/SystemServer.java
View File

@@ -747,6 +747,11 @@ public final class SystemServer {
traceBeginAndSlog("StartBinderCallsStatsService");
mSystemServiceManager.startService(BinderCallsStatsService.LifeCycle.class);
traceEnd();
// Tracks time spent in handling messages in handlers.
traceBeginAndSlog("StartLooperStatsService");
mSystemServiceManager.startService(LooperStatsService.Lifecycle.class);
traceEnd();
}
/**