Merge changes If217a9a8,I35af3a9c

* changes:
  LooperStats - don't create entries for unsampled sessions
  Add work source uid collection to LooperStats
This commit is contained in:
Marcin Oczeretko
2018-09-20 19:43:07 +00:00
committed by Android (Google) Code Review
10 changed files with 147 additions and 49 deletions

View File

@@ -2339,7 +2339,7 @@ message BinderCallsExceptions {
* Next tag: 11
*/
message LooperStats {
// Currently not collected and always set to 0.
// The uid that made a call to the System Server and caused the message to be enqueued.
optional int32 uid = 1 [(is_uid) = true];
// Fully qualified class name of the handler target class.

View File

@@ -773,6 +773,7 @@ public class Binder implements IBinder {
if (tracingEnabled) {
Trace.traceBegin(Trace.TRACE_TAG_ALWAYS, getClass().getName() + ":" + code);
}
ThreadLocalWorkSourceUid.set(Binder.getCallingUid());
res = onTransact(code, data, reply, flags);
} catch (RemoteException|RuntimeException e) {
if (observer != null) {
@@ -793,6 +794,7 @@ public class Binder implements IBinder {
}
res = true;
} finally {
ThreadLocalWorkSourceUid.clear();
if (tracingEnabled) {
Trace.traceEnd(Trace.TRACE_TAG_ALWAYS);
}

View File

@@ -739,6 +739,8 @@ public class Handler {
private boolean enqueueMessage(MessageQueue queue, Message msg, long uptimeMillis) {
msg.target = this;
msg.workSourceUid = ThreadLocalWorkSourceUid.get();
if (mAsynchronous) {
msg.setAsynchronous(true);
}

View File

@@ -205,6 +205,7 @@ public final class Looper {
token = observer.messageDispatchStarting();
}
try {
ThreadLocalWorkSourceUid.set(msg.workSourceUid);
msg.target.dispatchMessage(msg);
if (observer != null) {
observer.messageDispatched(token, msg);
@@ -216,6 +217,7 @@ public final class Looper {
}
throw exception;
} finally {
ThreadLocalWorkSourceUid.clear();
if (traceTag != 0) {
Trace.traceEnd(traceTag);
}

View File

@@ -16,7 +16,6 @@
package android.os;
import android.os.MessageProto;
import android.util.TimeUtils;
import android.util.proto.ProtoOutputStream;
@@ -73,12 +72,26 @@ public final class Message implements Parcelable {
*/
public Messenger replyTo;
/**
* Indicates that the uid is not set;
*
* @hide Only for use within the system server.
*/
public static final int UID_NONE = -1;
/**
* Optional field indicating the uid that sent the message. This is
* only valid for messages posted by a {@link Messenger}; otherwise,
* it will be -1.
*/
public int sendingUid = -1;
public int sendingUid = UID_NONE;
/**
* Optional field indicating the uid that caused this message to be enqueued.
*
* @hide Only for use within the system server.
*/
public int workSourceUid = UID_NONE;
/** If set message is in use.
* This flag is set when the message is enqueued and remains set while it
@@ -151,6 +164,7 @@ public final class Message implements Parcelable {
m.obj = orig.obj;
m.replyTo = orig.replyTo;
m.sendingUid = orig.sendingUid;
m.workSourceUid = orig.workSourceUid;
if (orig.data != null) {
m.data = new Bundle(orig.data);
}
@@ -301,7 +315,8 @@ public final class Message implements Parcelable {
arg2 = 0;
obj = null;
replyTo = null;
sendingUid = -1;
sendingUid = UID_NONE;
workSourceUid = UID_NONE;
when = 0;
target = null;
callback = null;
@@ -329,6 +344,7 @@ public final class Message implements Parcelable {
this.obj = o.obj;
this.replyTo = o.replyTo;
this.sendingUid = o.sendingUid;
this.workSourceUid = o.workSourceUid;
if (o.data != null) {
this.data = (Bundle) o.data.clone();
@@ -612,6 +628,7 @@ public final class Message implements Parcelable {
dest.writeBundle(data);
Messenger.writeMessengerOrNullToParcel(replyTo, dest);
dest.writeInt(sendingUid);
dest.writeInt(workSourceUid);
}
private void readFromParcel(Parcel source) {
@@ -625,5 +642,6 @@ public final class Message implements Parcelable {
data = source.readBundle();
replyTo = Messenger.readMessengerOrNullFromParcel(source);
sendingUid = source.readInt();
workSourceUid = source.readInt();
}
}

View File

@@ -0,0 +1,44 @@
/*
* 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 android.os;
/**
* @hide Only for use within system server.
*/
public final class ThreadLocalWorkSourceUid {
public static final int UID_NONE = Message.UID_NONE;
private static final ThreadLocal<Integer> sWorkSourceUid =
ThreadLocal.withInitial(() -> UID_NONE);
/** Returns the original work source uid. */
public static int get() {
return sWorkSourceUid.get();
}
/** Sets the original work source uid. */
public static void set(int uid) {
sWorkSourceUid.set(uid);
}
/** Clears the stored work source uid. */
public static void clear() {
sWorkSourceUid.set(UID_NONE);
}
private ThreadLocalWorkSourceUid() {
}
}

View File

@@ -17,6 +17,7 @@
package com.android.internal.os;
import android.annotation.NonNull;
import android.annotation.Nullable;
import android.os.Handler;
import android.os.Looper;
import android.os.Message;
@@ -36,7 +37,7 @@ import java.util.concurrent.ThreadLocalRandom;
* @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 SESSION_POOL_SIZE = 50;
@GuardedBy("mLock")
private final SparseArray<Entry> mEntries = new SparseArray<>(512);
@@ -78,17 +79,19 @@ public class LooperStats implements Looper.Observer {
}
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);
Entry entry = findEntry(msg, /* allowCreateNew= */session != DispatchSession.NOT_SAMPLED);
if (entry != null) {
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);
}
}
}
@@ -102,7 +105,7 @@ public class LooperStats implements Looper.Observer {
}
DispatchSession session = (DispatchSession) token;
Entry entry = getOrCreateEntry(msg);
Entry entry = findEntry(msg, /* allowCreateNew= */true);
synchronized (entry) {
entry.exceptionCount++;
}
@@ -159,24 +162,28 @@ public class LooperStats implements Looper.Observer {
mSamplingInterval = samplingInterval;
}
@NonNull
private Entry getOrCreateEntry(Message msg) {
@Nullable
private Entry findEntry(Message msg, boolean allowCreateNew) {
final boolean isInteractive = mDeviceState.isScreenInteractive();
final int id = Entry.idFor(msg, isInteractive);
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.
if (!allowCreateNew) {
return null;
} else if (mEntries.size() >= mEntriesSizeCap) {
// If over the size cap track totals under OVERFLOW entry.
return mOverflowEntry;
} else {
entry = new Entry(msg, isInteractive);
mEntries.put(id, entry);
}
entry = new Entry(msg, isInteractive);
mEntries.put(id, entry);
}
}
if (entry.handler.getClass() != msg.getTarget().getClass()
if (entry.workSourceUid != msg.workSourceUid
|| entry.handler.getClass() != msg.getTarget().getClass()
|| entry.handler.getLooper().getThread() != msg.getTarget().getLooper().getThread()
|| entry.isInteractive != isInteractive) {
// If a hash collision happened, track totals under a single entry.
@@ -186,7 +193,7 @@ public class LooperStats implements Looper.Observer {
}
private void recycleSession(DispatchSession session) {
if (session != DispatchSession.NOT_SAMPLED && mSessionPool.size() < TOKEN_POOL_SIZE) {
if (session != DispatchSession.NOT_SAMPLED && mSessionPool.size() < SESSION_POOL_SIZE) {
mSessionPool.add(session);
}
}
@@ -210,6 +217,7 @@ public class LooperStats implements Looper.Observer {
}
private static class Entry {
public final int workSourceUid;
public final Handler handler;
public final String messageName;
public final boolean isInteractive;
@@ -222,12 +230,14 @@ public class LooperStats implements Looper.Observer {
public long maxCpuUsageMicro;
Entry(Message msg, boolean isInteractive) {
this.workSourceUid = msg.workSourceUid;
this.handler = msg.getTarget();
this.messageName = handler.getMessageName(msg);
this.isInteractive = isInteractive;
}
Entry(String specialEntryName) {
this.workSourceUid = Message.UID_NONE;
this.messageName = specialEntryName;
this.handler = null;
this.isInteractive = false;
@@ -245,6 +255,7 @@ public class LooperStats implements Looper.Observer {
static int idFor(Message msg, boolean isInteractive) {
int result = 7;
result = 31 * result + msg.workSourceUid;
result = 31 * result + msg.getTarget().getLooper().getThread().hashCode();
result = 31 * result + msg.getTarget().getClass().hashCode();
result = 31 * result + (isInteractive ? 1231 : 1237);
@@ -258,6 +269,7 @@ public class LooperStats implements Looper.Observer {
/** Aggregated data of Looper message dispatching in the in the current process. */
public static class ExportedEntry {
public final int workSourceUid;
public final String handlerClassName;
public final String threadName;
public final String messageName;
@@ -271,6 +283,7 @@ public class LooperStats implements Looper.Observer {
public final long maxCpuUsageMicros;
ExportedEntry(Entry entry) {
this.workSourceUid = entry.workSourceUid;
if (entry.handler != null) {
this.handlerClassName = entry.handler.getClass().getName();
this.threadName = entry.handler.getLooper().getThread().getName();

View File

@@ -21,6 +21,7 @@ import static com.google.common.truth.Truth.assertThat;
import android.os.Handler;
import android.os.HandlerThread;
import android.os.Looper;
import android.os.Message;
import android.platform.test.annotations.Presubmit;
import android.support.test.filters.SmallTest;
import android.support.test.runner.AndroidJUnit4;
@@ -74,14 +75,17 @@ public final class LooperStatsTest {
public void testSingleMessageDispatched() {
TestableLooperStats looperStats = new TestableLooperStats(1, 100);
Message message = mHandlerFirst.obtainMessage(1000);
message.workSourceUid = 1000;
Object token = looperStats.messageDispatchStarting();
looperStats.tickRealtime(100);
looperStats.tickThreadTime(10);
looperStats.messageDispatched(token, mHandlerFirst.obtainMessage(1000));
looperStats.messageDispatched(token, message);
List<LooperStats.ExportedEntry> entries = looperStats.getEntries();
assertThat(entries).hasSize(1);
LooperStats.ExportedEntry entry = entries.get(0);
assertThat(entry.workSourceUid).isEqualTo(1000);
assertThat(entry.threadName).isEqualTo("TestThread1");
assertThat(entry.handlerClassName).isEqualTo(
"com.android.internal.os.LooperStatsTest$TestHandlerFirst");
@@ -100,15 +104,17 @@ public final class LooperStatsTest {
public void testThrewException() {
TestableLooperStats looperStats = new TestableLooperStats(1, 100);
Message message = mHandlerFirst.obtainMessage(7);
message.workSourceUid = 123;
Object token = looperStats.messageDispatchStarting();
looperStats.tickRealtime(100);
looperStats.tickThreadTime(10);
looperStats.dispatchingThrewException(token, mHandlerFirst.obtainMessage(7),
new ArithmeticException());
looperStats.dispatchingThrewException(token, message, new ArithmeticException());
List<LooperStats.ExportedEntry> entries = looperStats.getEntries();
assertThat(entries).hasSize(1);
LooperStats.ExportedEntry entry = entries.get(0);
assertThat(entry.workSourceUid).isEqualTo(123);
assertThat(entry.threadName).isEqualTo("TestThread1");
assertThat(entry.handlerClassName).isEqualTo(
"com.android.internal.os.LooperStatsTest$TestHandlerFirst");
@@ -146,31 +152,39 @@ public final class LooperStatsTest {
looperStats.messageDispatched(token3, mHandlerSecond.obtainMessage().setCallback(() -> {
}));
// Contributes to entry1.
// Will not be sampled so does not contribute to any entries.
Object token4 = looperStats.messageDispatchStarting();
looperStats.tickRealtime(10);
looperStats.tickThreadTime(10);
looperStats.messageDispatched(token4, mHandlerSecond.obtainMessage(0));
// Contributes to entry1.
Object token5 = looperStats.messageDispatchStarting();
looperStats.tickRealtime(100);
looperStats.tickThreadTime(100);
looperStats.messageDispatched(token4, mHandlerAnonymous.obtainMessage(1));
looperStats.messageDispatched(token5, 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.
// Captures data for token5 call.
LooperStats.ExportedEntry entry1 = entries.get(0);
assertThat(entry1.workSourceUid).isEqualTo(-1);
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.recordedMessageCount).isEqualTo(1);
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);
assertThat(entry1.totalLatencyMicros).isEqualTo(100);
assertThat(entry1.maxLatencyMicros).isEqualTo(100);
assertThat(entry1.cpuUsageMicros).isEqualTo(100);
assertThat(entry1.maxCpuUsageMicros).isEqualTo(100);
// Captures data for token1 and token2 calls.
LooperStats.ExportedEntry entry2 = entries.get(1);
assertThat(entry2.workSourceUid).isEqualTo(-1);
assertThat(entry2.threadName).isEqualTo("TestThread1");
assertThat(entry2.handlerClassName).isEqualTo(
"com.android.internal.os.LooperStatsTest$TestHandlerFirst");
@@ -185,6 +199,7 @@ public final class LooperStatsTest {
// Captures data for token3 call.
LooperStats.ExportedEntry entry3 = entries.get(2);
assertThat(entry3.workSourceUid).isEqualTo(-1);
assertThat(entry3.threadName).isEqualTo("TestThread2");
assertThat(entry3.handlerClassName).isEqualTo(
"com.android.internal.os.LooperStatsTest$TestHandlerSecond");
@@ -265,7 +280,7 @@ public final class LooperStatsTest {
@Test
public void testMessagesOverSizeCap() {
TestableLooperStats looperStats = new TestableLooperStats(2, 1 /* sizeCap */);
TestableLooperStats looperStats = new TestableLooperStats(1, 1 /* sizeCap */);
Object token1 = looperStats.messageDispatchStarting();
looperStats.tickRealtime(100);
@@ -296,12 +311,12 @@ public final class LooperStatsTest {
assertThat(entry1.handlerClassName).isEqualTo("");
assertThat(entry1.messageName).isEqualTo("OVERFLOW");
assertThat(entry1.messageCount).isEqualTo(3);
assertThat(entry1.recordedMessageCount).isEqualTo(1);
assertThat(entry1.recordedMessageCount).isEqualTo(3);
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);
assertThat(entry1.totalLatencyMicros).isEqualTo(70);
assertThat(entry1.maxLatencyMicros).isEqualTo(50);
assertThat(entry1.cpuUsageMicros).isEqualTo(40);
assertThat(entry1.maxCpuUsageMicros).isEqualTo(20);
LooperStats.ExportedEntry entry2 = entries.get(1);
assertThat(entry2.threadName).isEqualTo("TestThread1");

View File

@@ -93,10 +93,12 @@ public class LooperStatsService extends Binder {
if (!DumpUtils.checkDumpPermission(mContext, TAG, pw)) return;
List<LooperStats.ExportedEntry> entries = mStats.getEntries();
entries.sort(Comparator
.comparing((LooperStats.ExportedEntry entry) -> entry.threadName)
.comparing((LooperStats.ExportedEntry entry) -> entry.workSourceUid)
.thenComparing(entry -> entry.threadName)
.thenComparing(entry -> entry.handlerClassName)
.thenComparing(entry -> entry.messageName));
String header = String.join(",", Arrays.asList(
"work_source_uid",
"thread_name",
"handler_class",
"message_name",
@@ -110,11 +112,11 @@ public class LooperStatsService extends Binder {
"exception_count"));
pw.println(header);
for (LooperStats.ExportedEntry entry : entries) {
pw.printf("%s,%s,%s,%s,%s,%s,%s,%s,%s,%s,%s\n", entry.threadName,
entry.handlerClassName, entry.messageName, entry.isInteractive,
entry.messageCount, entry.recordedMessageCount, entry.totalLatencyMicros,
entry.maxLatencyMicros, entry.cpuUsageMicros, entry.maxCpuUsageMicros,
entry.exceptionCount);
pw.printf("%s,%s,%s,%s,%s,%s,%s,%s,%s,%s,%s,%s\n", entry.workSourceUid,
entry.threadName, entry.handlerClassName, entry.messageName,
entry.isInteractive, entry.messageCount, entry.recordedMessageCount,
entry.totalLatencyMicros, entry.maxLatencyMicros, entry.cpuUsageMicros,
entry.maxCpuUsageMicros, entry.exceptionCount);
}
}

View File

@@ -1031,7 +1031,7 @@ public class StatsCompanionService extends IStatsCompanionService.Stub {
looperStats.reset();
for (LooperStats.ExportedEntry entry : entries) {
StatsLogEventWrapper e = new StatsLogEventWrapper(tagId, elapsedNanos, wallClockNanos);
e.writeInt(1000); // uid collection not implemented yet
e.writeInt(entry.workSourceUid);
e.writeString(entry.handlerClassName);
e.writeString(entry.threadName);
e.writeString(entry.messageName);