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

Merge changes from topic "update-transition-trace-dumping-structure" into udc-dev

Browse Source 
* changes:
  Remove transition state tracing
  Update transition dumping structure
  Add real to elapsed offset to shell transition trace
  Update WM side transition trace file name
This commit is contained in:
Pablo Gamito
2023-05-05 12:03:01 +00:00
committed by Android (Google) Code Review
parent 56675d076c 93add0dabe
commit b26be926b0
6 changed files with 54 additions and 247 deletions
Download Patch File Download Diff File Expand all files Collapse all files

63
core/proto/android/server/windowmanagertransitiontrace.proto
View File

@@ -23,7 +23,7 @@ import "frameworks/base/core/proto/android/server/windowmanagerservice.proto";
option java_multiple_files = true;
/* Represents a file full of transition entries.
Encoded, it should start with 0x09 0x54 0x52 0x4E 0x54 0x52 0x41 0x43 0x45 (TRNTRACE), such
Encoded, it should start with 0x09 0x54 0x52 0x4E 0x54 0x52 0x41 0x43 0x45 (.TRNTRACE), such
that it can be easily identified. */
message TransitionTraceProto {
@@ -38,28 +38,24 @@ message TransitionTraceProto {
// Must be the first field, set to value in MagicNumber
required fixed64 magic_number = 1;
// Transitions that don't have a finish time are considered aborted
repeated Transition finished_transitions = 2;
// Additional debugging info only collected and dumped when explicitly requested to trace
repeated TransitionState transition_states = 3;
repeated TransitionInfo transition_info = 4;
repeated Transition transitions = 2;
/* offset between real-time clock and elapsed time clock in nanoseconds.
Calculated as: 1000000 * System.currentTimeMillis() - SystemClock.elapsedRealtimeNanos() */
optional fixed64 real_to_elapsed_time_offset_nanos = 5;
optional fixed64 real_to_elapsed_time_offset_nanos = 3;
}
message Transition {
optional int32 id = 1; // Not dumped in always on tracing
required uint64 start_transaction_id = 2;
required uint64 finish_transaction_id = 3;
required int64 create_time_ns = 4;
required int64 send_time_ns = 5;
optional int64 finish_time_ns = 6; // consider aborted if not provided
required int32 type = 7;
required int32 id = 1;
optional uint64 start_transaction_id = 2;
optional uint64 finish_transaction_id = 3;
optional int64 create_time_ns = 4;
optional int64 send_time_ns = 5;
optional int64 finish_time_ns = 6;
optional int32 type = 7;
repeated Target targets = 8;
optional int32 flags = 9;
optional int64 abort_time_ns = 10;
}
message Target {
@@ -68,40 +64,3 @@ message Target {
optional int32 window_id = 3; // Not dumped in always on tracing
optional int32 flags = 4;
}
message TransitionState {
enum State {
COLLECTING = 0;
PENDING = -1;
STARTED = 1;
PLAYING = 2;
ABORT = 3;
FINISHED = 4;
}
required int64 time_ns = 1;
required int32 transition_id = 2;
required int32 transition_type = 3;
required State state = 4;
required int32 flags = 5;
repeated ChangeInfo change = 6;
repeated com.android.server.wm.IdentifierProto participants = 7;
}
message ChangeInfo {
required com.android.server.wm.IdentifierProto window_identifier = 1;
required int32 transit_mode = 2;
required bool has_changed = 3;
required int32 change_flags = 4;
required int32 windowing_mode = 5;
}
message TransitionInfo {
required int32 transition_id = 1;
repeated TransitionInfoChange change = 2;
}
message TransitionInfoChange {
required int32 layer_id = 1;
required int32 mode = 2;
}

3
libs/WindowManager/Shell/proto/wm_shell_transition_trace.proto
View File

@@ -37,6 +37,9 @@ message WmShellTransitionTraceProto {
required fixed64 magic_number = 1;
repeated Transition transitions = 2;
repeated HandlerMapping handlerMappings = 3;
/* offset between real-time clock and elapsed time clock in nanoseconds.
Calculated as: 1000000 * System.currentTimeMillis() - SystemClock.elapsedRealtimeNanos() */
optional fixed64 real_to_elapsed_time_offset_nanos = 4;
}
message Transition {

6
libs/WindowManager/Shell/src/com/android/wm/shell/transition/Tracer.java
View File

@@ -28,7 +28,6 @@ import android.os.Trace;
import android.util.Log;
import com.android.internal.util.TraceBuffer;
import com.android.wm.shell.nano.HandlerMapping;
import com.android.wm.shell.sysui.ShellCommandHandler;
import com.google.protobuf.nano.MessageNano;
@@ -41,6 +40,7 @@ import java.util.ArrayList;
import java.util.HashMap;
import java.util.Map;
import java.util.Queue;
import java.util.concurrent.TimeUnit;
/**
* Helper class to collect and dump transition traces.
@@ -241,6 +241,10 @@ public class Tracer implements ShellCommandHandler.ShellCommandActionHandler {
new com.android.wm.shell.nano.WmShellTransitionTraceProto();
proto.magicNumber = MAGIC_NUMBER_VALUE;
writeHandlerMappingToProto(proto);
long timeOffsetNs =
TimeUnit.MILLISECONDS.toNanos(System.currentTimeMillis())
- SystemClock.elapsedRealtimeNanos();
proto.realToElapsedTimeOffsetNanos = timeOffsetNs;
int pid = android.os.Process.myPid();
LogAndPrintln.i(pw, "Writing file to " + file.getAbsolutePath()
+ " from process " + pid);

5
services/core/java/com/android/server/wm/Transition.java
View File

@@ -314,7 +314,6 @@ class Transition implements BLASTSyncEngine.TransactionReadyListener {
mLogger.mCreateWallTimeMs = System.currentTimeMillis();
mLogger.mCreateTimeNs = SystemClock.elapsedRealtimeNanos();
controller.mTransitionTracer.logState(this);
}
@Nullable
@@ -532,7 +531,6 @@ class Transition implements BLASTSyncEngine.TransactionReadyListener {
mLogger.mSyncId = mSyncId;
mLogger.mCollectTimeNs = SystemClock.elapsedRealtimeNanos();
mController.mTransitionTracer.logState(this);
}
/**
@@ -555,7 +553,6 @@ class Transition implements BLASTSyncEngine.TransactionReadyListener {
applyReady();
mLogger.mStartTimeNs = SystemClock.elapsedRealtimeNanos();
mController.mTransitionTracer.logState(this);
mController.updateAnimatingState(mTmpTransaction);
// merge into the next-time the global transaction is applied. This is too-early to set
@@ -1232,7 +1229,6 @@ class Transition implements BLASTSyncEngine.TransactionReadyListener {
validateVisibility();
mState = STATE_FINISHED;
mController.mTransitionTracer.logState(this);
// Rotation change may be deferred while there is a display change transition, so check
// again in case there is a new pending change.
if (hasParticipatedDisplay && !mController.useShellTransitionsRotation()) {
@@ -1261,6 +1257,7 @@ class Transition implements BLASTSyncEngine.TransactionReadyListener {
}
ProtoLog.v(ProtoLogGroup.WM_DEBUG_WINDOW_TRANSITIONS, "Aborting Transition: %d", mSyncId);
mState = STATE_ABORT;
mLogger.mAbortTimeNs = SystemClock.elapsedRealtimeNanos();
mController.mTransitionTracer.logAbortedTransition(this);
// Syncengine abort will call through to onTransactionReady()
mSyncEngine.abort(mSyncId);

5
services/core/java/com/android/server/wm/TransitionController.java
View File

@@ -941,7 +941,6 @@ class TransitionController {
}
mPlayingTransitions.add(transition);
updateRunningRemoteAnimation(transition, true /* isPlaying */);
mTransitionTracer.logState(transition);
// Sync engine should become idle after this, so the idle listener will check the queue.
}
@@ -1122,7 +1121,6 @@ class TransitionController {
mLatestOnTopTasksReported.clear();
}
}
mTransitionTracer.logState(transition);
// This is called during Transition.abort whose codepath will eventually check the queue
// via sync-engine idle.
}
@@ -1416,12 +1414,11 @@ class TransitionController {
long mReadyTimeNs;
long mSendTimeNs;
long mFinishTimeNs;
long mAbortTimeNs;
TransitionRequestInfo mRequest;
WindowContainerTransaction mStartWCT;
int mSyncId;
TransitionInfo mInfo;
ProtoOutputStream mProtoOutputStream = new ProtoOutputStream();
long mProtoToken;
private String buildOnSendLog() {
StringBuilder sb = new StringBuilder("Sent Transition #").append(mSyncId)

219
services/core/java/com/android/server/wm/TransitionTracer.java
View File

@@ -50,10 +50,11 @@ public class TransitionTracer {
private static final int ALWAYS_ON_TRACING_CAPACITY = 15 * 1024; // 15 KB
private static final int ACTIVE_TRACING_BUFFER_CAPACITY = 5000 * 1024; // 5 MB
static final String WINSCOPE_EXT = ".winscope";
private static final String TRACE_FILE = "/data/misc/wmtrace/transition_trace" + WINSCOPE_EXT;
private static final String TRACE_FILE =
"/data/misc/wmtrace/wm_transition_trace" + WINSCOPE_EXT;
private static final long MAGIC_NUMBER_VALUE = ((long) MAGIC_NUMBER_H << 32) | MAGIC_NUMBER_L;
private final TransitionTraceBuffer mTraceBuffer = new TransitionTraceBuffer();
private final TraceBuffer mTraceBuffer = new TraceBuffer(ALWAYS_ON_TRACING_CAPACITY);
private final Object mEnabledLock = new Object();
private volatile boolean mActiveTracingEnabled = false;
@@ -72,18 +73,22 @@ public class TransitionTracer {
*/
public void logSentTransition(Transition transition, ArrayList<ChangeInfo> targets,
TransitionInfo info) {
// Dump the info to proto that will not be available when the transition finishes or
// is canceled
final ProtoOutputStream outputStream = transition.mLogger.mProtoOutputStream;
transition.mLogger.mProtoToken = outputStream
.start(com.android.server.wm.shell.TransitionTraceProto.FINISHED_TRANSITIONS);
final ProtoOutputStream outputStream = new ProtoOutputStream();
final long protoToken = outputStream
.start(com.android.server.wm.shell.TransitionTraceProto.TRANSITIONS);
outputStream.write(com.android.server.wm.shell.Transition.ID, transition.getSyncId());
outputStream.write(com.android.server.wm.shell.Transition.CREATE_TIME_NS,
transition.mLogger.mCreateTimeNs);
outputStream.write(com.android.server.wm.shell.Transition.SEND_TIME_NS,
transition.mLogger.mSendTimeNs);
outputStream.write(com.android.server.wm.shell.Transition.START_TRANSACTION_ID,
transition.getStartTransaction().getId());
outputStream.write(com.android.server.wm.shell.Transition.FINISH_TRANSACTION_ID,
transition.getFinishTransaction().getId());
dumpTransitionTargetsToProto(outputStream, transition, targets);
outputStream.end(protoToken);
logTransitionInfo(transition, info);
mTraceBuffer.add(outputStream);
}
/**
@@ -93,17 +98,15 @@ public class TransitionTracer {
* @param transition The transition that has finished.
*/
public void logFinishedTransition(Transition transition) {
if (transition.mLogger.mProtoToken == 0) {
// Transition finished but never sent, so open token never added
final ProtoOutputStream outputStream = transition.mLogger.mProtoOutputStream;
transition.mLogger.mProtoToken = outputStream
.start(com.android.server.wm.shell.TransitionTraceProto.FINISHED_TRANSITIONS);
}
final ProtoOutputStream outputStream = new ProtoOutputStream();
final long protoToken = outputStream
.start(com.android.server.wm.shell.TransitionTraceProto.TRANSITIONS);
outputStream.write(com.android.server.wm.shell.Transition.ID, transition.getSyncId());
outputStream.write(com.android.server.wm.shell.Transition.FINISH_TIME_NS,
transition.mLogger.mFinishTimeNs);
outputStream.end(protoToken);
// Dump the rest of the transition's info that wasn't dumped during logSentTransition
dumpFinishedTransitionToProto(transition.mLogger.mProtoOutputStream, transition);
transition.mLogger.mProtoOutputStream.end(transition.mLogger.mProtoToken);
mTraceBuffer.pushTransitionProto(transition.mLogger.mProtoOutputStream);
mTraceBuffer.add(outputStream);
}
/**
@@ -113,38 +116,15 @@ public class TransitionTracer {
* @param transition The transition that has been aborted
*/
public void logAbortedTransition(Transition transition) {
// We don't care about aborted transitions unless actively tracing
if (!mActiveTracingEnabled) {
return;
}
logFinishedTransition(transition);
}
/**
* Records the current state of a transition in the transition trace (if it is running).
* @param transition the transition that we want to record the state of.
*/
public void logState(com.android.server.wm.Transition transition) {
if (!mActiveTracingEnabled) {
return;
}
final ProtoOutputStream outputStream = new ProtoOutputStream();
dumpTransitionStateToProto(outputStream, transition);
mTraceBuffer.pushTransitionState(outputStream);
}
final long protoToken = outputStream
.start(com.android.server.wm.shell.TransitionTraceProto.TRANSITIONS);
outputStream.write(com.android.server.wm.shell.Transition.ID, transition.getSyncId());
outputStream.write(com.android.server.wm.shell.Transition.ABORT_TIME_NS,
transition.mLogger.mAbortTimeNs);
outputStream.end(protoToken);
/**
* Records the transition info that is being sent over to Shell.
* @param transition The transition the info is associated with.
* @param info The transition info we want to log.
*/
private void logTransitionInfo(Transition transition, TransitionInfo info) {
if (!mActiveTracingEnabled) {
return;
}
final ProtoOutputStream outputStream = new ProtoOutputStream();
dumpTransitionInfoToProto(outputStream, transition, info);
mTraceBuffer.pushTransitionInfo(outputStream);
mTraceBuffer.add(outputStream);
}
private void dumpTransitionTargetsToProto(ProtoOutputStream outputStream,
@@ -189,139 +169,6 @@ public class TransitionTracer {
Trace.endSection();
}
private void dumpFinishedTransitionToProto(
ProtoOutputStream outputStream,
Transition transition
) {
Trace.beginSection("TransitionTracer#dumpFinishedTransitionToProto");
outputStream.write(com.android.server.wm.shell.Transition.CREATE_TIME_NS,
transition.mLogger.mCreateTimeNs);
outputStream.write(com.android.server.wm.shell.Transition.SEND_TIME_NS,
transition.mLogger.mSendTimeNs);
outputStream.write(com.android.server.wm.shell.Transition.FINISH_TIME_NS,
transition.mLogger.mFinishTimeNs);
Trace.endSection();
}
private void dumpTransitionStateToProto(ProtoOutputStream outputStream, Transition transition) {
Trace.beginSection("TransitionTracer#dumpTransitionStateToProto");
final long stateToken = outputStream
.start(com.android.server.wm.shell.TransitionTraceProto.TRANSITION_STATES);
outputStream.write(com.android.server.wm.shell.TransitionState.TIME_NS,
SystemClock.elapsedRealtimeNanos());
outputStream.write(com.android.server.wm.shell.TransitionState.TRANSITION_ID,
transition.getSyncId());
outputStream.write(com.android.server.wm.shell.TransitionState.TRANSITION_TYPE,
transition.mType);
outputStream.write(com.android.server.wm.shell.TransitionState.STATE,
transition.getState());
outputStream.write(com.android.server.wm.shell.TransitionState.FLAGS,
transition.getFlags());
for (int i = 0; i < transition.mChanges.size(); ++i) {
final WindowContainer window = transition.mChanges.keyAt(i);
final ChangeInfo changeInfo = transition.mChanges.valueAt(i);
dumpChangeInfoToProto(outputStream, window, changeInfo);
}
for (int i = 0; i < transition.mParticipants.size(); ++i) {
final WindowContainer window = transition.mParticipants.valueAt(i);
window.writeIdentifierToProto(outputStream,
com.android.server.wm.shell.TransitionState.PARTICIPANTS);
}
outputStream.end(stateToken);
Trace.endSection();
}
private void dumpChangeInfoToProto(ProtoOutputStream outputStream, WindowContainer window,
ChangeInfo changeInfo) {
Trace.beginSection("TransitionTraceBuffer#writeChange");
final long changeEntryToken =
outputStream.start(com.android.server.wm.shell.TransitionState.CHANGE);
final int transitMode = changeInfo.getTransitMode(window);
final boolean hasChanged = changeInfo.hasChanged();
final int changeFlags = changeInfo.getChangeFlags(window);
final int windowingMode = changeInfo.mWindowingMode;
outputStream.write(com.android.server.wm.shell.ChangeInfo.TRANSIT_MODE, transitMode);
outputStream.write(com.android.server.wm.shell.ChangeInfo.HAS_CHANGED, hasChanged);
outputStream.write(com.android.server.wm.shell.ChangeInfo.CHANGE_FLAGS, changeFlags);
outputStream.write(com.android.server.wm.shell.ChangeInfo.WINDOWING_MODE, windowingMode);
window.writeIdentifierToProto(
outputStream, com.android.server.wm.shell.ChangeInfo.WINDOW_IDENTIFIER);
outputStream.end(changeEntryToken);
Trace.endSection();
}
private void dumpTransitionInfoToProto(ProtoOutputStream outputStream,
Transition transition, TransitionInfo info) {
Trace.beginSection("TransitionTracer#dumpTransitionInfoToProto");
final long transitionInfoToken = outputStream
.start(com.android.server.wm.shell.TransitionTraceProto.TRANSITION_INFO);
outputStream.write(com.android.server.wm.shell.TransitionInfo.TRANSITION_ID,
transition.getSyncId());
for (int i = 0; i < info.getChanges().size(); ++i) {
TransitionInfo.Change change = info.getChanges().get(i);
dumpTransitionInfoChangeToProto(outputStream, change);
}
outputStream.end(transitionInfoToken);
Trace.endSection();
}
private void dumpTransitionInfoChangeToProto(
ProtoOutputStream outputStream,
TransitionInfo.Change change
) {
Trace.beginSection("TransitionTracer#dumpTransitionInfoChangeToProto");
final long changeEntryToken = outputStream
.start(com.android.server.wm.shell.TransitionInfo.CHANGE);
outputStream.write(com.android.server.wm.shell.TransitionInfoChange.LAYER_ID,
change.getLeash().getLayerId());
outputStream.write(com.android.server.wm.shell.TransitionInfoChange.MODE, change.getMode());
outputStream.end(changeEntryToken);
Trace.endSection();
}
private class TransitionTraceBuffer {
private final TraceBuffer mTransitionBuffer = new TraceBuffer(ALWAYS_ON_TRACING_CAPACITY);
private final TraceBuffer mStateBuffer = new TraceBuffer(ACTIVE_TRACING_BUFFER_CAPACITY);
private final TraceBuffer mTransitionInfoBuffer =
new TraceBuffer(ACTIVE_TRACING_BUFFER_CAPACITY);
private void pushTransitionProto(ProtoOutputStream outputStream) {
mTransitionBuffer.add(outputStream);
}
private void pushTransitionState(ProtoOutputStream outputStream) {
mStateBuffer.add(outputStream);
}
private void pushTransitionInfo(ProtoOutputStream outputStream) {
mTransitionInfoBuffer.add(outputStream);
}
public void writeToFile(File file, ProtoOutputStream proto) throws IOException {
mTransitionBuffer.writeTraceToFile(file, proto);
}
public void reset() {
mTransitionBuffer.resetBuffer();
mStateBuffer.resetBuffer();
mTransitionInfoBuffer.resetBuffer();
}
}
/**
* Starts collecting transitions for the trace.
* If called while a trace is already running, this will reset the trace.
@@ -335,8 +182,8 @@ public class TransitionTracer {
LogAndPrintln.i(pw, "Starting shell transition trace.");
synchronized (mEnabledLock) {
mActiveTracingEnabled = true;
mTraceBuffer.mTransitionBuffer.setCapacity(ACTIVE_TRACING_BUFFER_CAPACITY);
mTraceBuffer.reset();
mTraceBuffer.resetBuffer();
mTraceBuffer.setCapacity(ACTIVE_TRACING_BUFFER_CAPACITY);
}
Trace.endSection();
}
@@ -364,8 +211,8 @@ public class TransitionTracer {
synchronized (mEnabledLock) {
mActiveTracingEnabled = false;
writeTraceToFileLocked(pw, outputFile);
mTraceBuffer.reset();
mTraceBuffer.mTransitionBuffer.setCapacity(ALWAYS_ON_TRACING_CAPACITY);
mTraceBuffer.resetBuffer();
mTraceBuffer.setCapacity(ALWAYS_ON_TRACING_CAPACITY);
}
Trace.endSection();
}
@@ -404,7 +251,7 @@ public class TransitionTracer {
int pid = android.os.Process.myPid();
LogAndPrintln.i(pw, "Writing file to " + file.getAbsolutePath()
+ " from process " + pid);
mTraceBuffer.writeToFile(file, proto);
mTraceBuffer.writeTraceToFile(file, proto);
} catch (IOException e) {
LogAndPrintln.e(pw, "Unable to write buffer to file", e);
}