diff --git a/core/java/com/android/internal/util/TraceBuffer.java b/core/java/com/android/internal/util/TraceBuffer.java index bfcd65d4f2778..fcc77bd4f043b 100644 --- a/core/java/com/android/internal/util/TraceBuffer.java +++ b/core/java/com/android/internal/util/TraceBuffer.java @@ -103,6 +103,10 @@ public class TraceBuffer { this(bufferCapacity, new ProtoOutputStreamProvider(), null); } + public TraceBuffer(int bufferCapacity, Consumer protoDequeuedCallback) { + this(bufferCapacity, new ProtoOutputStreamProvider(), protoDequeuedCallback); + } + public TraceBuffer(int bufferCapacity, ProtoProvider protoProvider, Consumer protoDequeuedCallback) { mBufferCapacity = bufferCapacity; diff --git a/libs/WindowManager/Shell/Android.bp b/libs/WindowManager/Shell/Android.bp index 54978bd4496df..6a79bc1f46c2c 100644 --- a/libs/WindowManager/Shell/Android.bp +++ b/libs/WindowManager/Shell/Android.bp @@ -125,6 +125,34 @@ prebuilt_etc { // End ProtoLog +gensrcs { + name: "wm-shell-protos", + + tools: [ + "aprotoc", + "protoc-gen-javastream", + "soong_zip", + ], + + tool_files: [ + ":libprotobuf-internal-protos", + ], + + cmd: "mkdir -p $(genDir)/$(in) " + + "&& $(location aprotoc) " + + " --plugin=$(location protoc-gen-javastream) " + + " --javastream_out=$(genDir)/$(in) " + + " -Iexternal/protobuf/src " + + " -I . " + + " $(in) " + + "&& $(location soong_zip) -jar -o $(out) -C $(genDir)/$(in) -D $(genDir)/$(in)", + + srcs: [ + "proto/**/*.proto", + ], + output_extension: "srcjar", +} + java_library { name: "WindowManager-Shell-proto", @@ -142,6 +170,7 @@ android_library { // TODO(b/168581922) protologtool do not support kotlin(*.kt) ":wm_shell-sources-kt", ":wm_shell-aidls", + ":wm-shell-protos", ], resource_dirs: [ "res", diff --git a/libs/WindowManager/Shell/proto/wm_shell_transition_trace.proto b/libs/WindowManager/Shell/proto/wm_shell_transition_trace.proto new file mode 100644 index 0000000000000..6e0110193a057 --- /dev/null +++ b/libs/WindowManager/Shell/proto/wm_shell_transition_trace.proto @@ -0,0 +1,55 @@ +/* + * Copyright (C) 2020 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. + */ + +syntax = "proto2"; + +package com.android.wm.shell; + +option java_multiple_files = true; + +/* Represents a file full of transition entries. + Encoded, it should start with 0x09 0x57 0x4D 0x53 0x54 0x52 0x41 0x43 0x45 (.WMSTRACE), such + that it can be easily identified. */ +message WmShellTransitionTraceProto { + /* constant; MAGIC_NUMBER = (long) MAGIC_NUMBER_H << 32 | MagicNumber.MAGIC_NUMBER_L + (this is needed because enums have to be 32 bits and there's no nice way to put 64bit + constants into .proto files. */ + enum MagicNumber { + INVALID = 0; + MAGIC_NUMBER_L = 0x54534D57; /* WMST (little-endian ASCII) */ + MAGIC_NUMBER_H = 0x45434152; /* RACE (little-endian ASCII) */ + } + + // Must be the first field, set to value in MagicNumber + required fixed64 magic_number = 1; + repeated Transition transitions = 2; + repeated HandlerMapping handlerMappings = 3; +} + +message Transition { + required int32 id = 1; + optional int64 dispatch_time_ns = 2; + optional int32 handler = 3; + optional int64 merge_time_ns = 4; + optional int64 merge_request_time_ns = 5; + optional int32 merged_into = 6; + optional int64 abort_time_ns = 7; +} + +message HandlerMapping { + required int32 id = 1; + required string name = 2; +} diff --git a/libs/WindowManager/Shell/src/com/android/wm/shell/transition/Tracer.java b/libs/WindowManager/Shell/src/com/android/wm/shell/transition/Tracer.java new file mode 100644 index 0000000000000..7753d174e68c9 --- /dev/null +++ b/libs/WindowManager/Shell/src/com/android/wm/shell/transition/Tracer.java @@ -0,0 +1,243 @@ +/* + * Copyright (C) 2023 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.wm.shell.transition; + +import static android.os.Build.IS_USER; + +import static com.android.wm.shell.WmShellTransitionTraceProto.MAGIC_NUMBER; +import static com.android.wm.shell.WmShellTransitionTraceProto.MAGIC_NUMBER_H; +import static com.android.wm.shell.WmShellTransitionTraceProto.MAGIC_NUMBER_L; + +import android.annotation.NonNull; +import android.annotation.Nullable; +import android.os.SystemClock; +import android.os.Trace; +import android.util.Log; +import android.util.proto.ProtoOutputStream; + +import com.android.internal.util.TraceBuffer; + +import java.io.File; +import java.io.IOException; +import java.io.PrintWriter; +import java.util.HashMap; +import java.util.Map; + +/** + * Helper class to collect and dump transition traces. + */ +public class Tracer { + private static final int ALWAYS_ON_TRACING_CAPACITY = 15 * 1024; // 15 KB + + private static final long MAGIC_NUMBER_VALUE = ((long) MAGIC_NUMBER_H << 32) | MAGIC_NUMBER_L; + + static final String WINSCOPE_EXT = ".winscope"; + private static final String TRACE_FILE = + "/data/misc/wmtrace/shell_transition_trace" + WINSCOPE_EXT; + + private final Object mEnabledLock = new Object(); + + private final TraceBuffer mTraceBuffer = new TraceBuffer(ALWAYS_ON_TRACING_CAPACITY, + (proto) -> handleOnEntryRemovedFromTrace(proto)); + private final Map mRemovedFromTraceCallbacks = new HashMap<>(); + + private final Map mHandlerIds = new HashMap<>(); + private final Map mHandlerUseCountInTrace = + new HashMap<>(); + + /** + * Adds an entry in the trace to log that a transition has been dispatched to a handler. + * + * @param transitionId The id of the transition being dispatched. + * @param handler The handler the transition is being dispatched to. + */ + public void logDispatched(int transitionId, Transitions.TransitionHandler handler) { + final int handlerId; + if (mHandlerIds.containsKey(handler)) { + handlerId = mHandlerIds.get(handler); + } else { + handlerId = mHandlerIds.size(); + mHandlerIds.put(handler, handlerId); + } + + ProtoOutputStream outputStream = new ProtoOutputStream(); + final long protoToken = + outputStream.start(com.android.wm.shell.WmShellTransitionTraceProto.TRANSITIONS); + + outputStream.write(com.android.wm.shell.Transition.ID, transitionId); + outputStream.write(com.android.wm.shell.Transition.DISPATCH_TIME_NS, + SystemClock.elapsedRealtimeNanos()); + outputStream.write(com.android.wm.shell.Transition.HANDLER, handlerId); + + outputStream.end(protoToken); + + final int useCountAfterAdd = mHandlerUseCountInTrace.getOrDefault(handler, 0) + 1; + mHandlerUseCountInTrace.put(handler, useCountAfterAdd); + + mRemovedFromTraceCallbacks.put(outputStream, () -> { + final int useCountAfterRemove = mHandlerUseCountInTrace.get(handler) - 1; + mHandlerUseCountInTrace.put(handler, useCountAfterRemove); + }); + + mTraceBuffer.add(outputStream); + } + + /** + * Adds an entry in the trace to log that a request to merge a transition was made. + * + * @param mergeRequestedTransitionId The id of the transition we are requesting to be merged. + * @param playingTransitionId The id of the transition we was to merge the transition into. + */ + public void logMergeRequested(int mergeRequestedTransitionId, int playingTransitionId) { + ProtoOutputStream outputStream = new ProtoOutputStream(); + final long protoToken = + outputStream.start(com.android.wm.shell.WmShellTransitionTraceProto.TRANSITIONS); + + outputStream.write(com.android.wm.shell.Transition.ID, mergeRequestedTransitionId); + outputStream.write(com.android.wm.shell.Transition.MERGE_REQUEST_TIME_NS, + SystemClock.elapsedRealtimeNanos()); + outputStream.write(com.android.wm.shell.Transition.MERGED_INTO, playingTransitionId); + + outputStream.end(protoToken); + + mTraceBuffer.add(outputStream); + } + + /** + * Adds an entry in the trace to log that a transition was merged by the handler. + * + * @param mergedTransitionId The id of the transition that was merged. + * @param playingTransitionId The id of the transition the transition was merged into. + */ + public void logMerged(int mergedTransitionId, int playingTransitionId) { + ProtoOutputStream outputStream = new ProtoOutputStream(); + final long protoToken = + outputStream.start(com.android.wm.shell.WmShellTransitionTraceProto.TRANSITIONS); + + outputStream.write(com.android.wm.shell.Transition.ID, mergedTransitionId); + outputStream.write( + com.android.wm.shell.Transition.MERGE_TIME_NS, SystemClock.elapsedRealtimeNanos()); + outputStream.write(com.android.wm.shell.Transition.MERGED_INTO, playingTransitionId); + + outputStream.end(protoToken); + + mTraceBuffer.add(outputStream); + } + + /** + * Adds an entry in the trace to log that a transition was aborted. + * + * @param transitionId The id of the transition that was aborted. + */ + public void logAborted(int transitionId) { + ProtoOutputStream outputStream = new ProtoOutputStream(); + final long protoToken = + outputStream.start(com.android.wm.shell.WmShellTransitionTraceProto.TRANSITIONS); + + outputStream.write(com.android.wm.shell.Transition.ID, transitionId); + outputStream.write( + com.android.wm.shell.Transition.ABORT_TIME_NS, SystemClock.elapsedRealtimeNanos()); + + outputStream.end(protoToken); + + mTraceBuffer.add(outputStream); + } + + /** + * Being called while taking a bugreport so that tracing files can be included in the bugreport. + * + * @param pw Print writer + */ + public void saveForBugreport(@Nullable PrintWriter pw) { + if (IS_USER) { + LogAndPrintln.e(pw, "Tracing is not supported on user builds."); + return; + } + Trace.beginSection("TransitionTracer#saveForBugreport"); + synchronized (mEnabledLock) { + final File outputFile = new File(TRACE_FILE); + writeTraceToFileLocked(pw, outputFile); + } + Trace.endSection(); + } + + private void writeTraceToFileLocked(@Nullable PrintWriter pw, File file) { + Trace.beginSection("TransitionTracer#writeTraceToFileLocked"); + try { + ProtoOutputStream proto = new ProtoOutputStream(); + proto.write(MAGIC_NUMBER, MAGIC_NUMBER_VALUE); + writeHandlerMappingToProto(proto); + int pid = android.os.Process.myPid(); + LogAndPrintln.i(pw, "Writing file to " + file.getAbsolutePath() + + " from process " + pid); + mTraceBuffer.writeTraceToFile(file, proto); + } catch (IOException e) { + LogAndPrintln.e(pw, "Unable to write buffer to file", e); + } + Trace.endSection(); + } + + private void writeHandlerMappingToProto(ProtoOutputStream outputStream) { + for (Transitions.TransitionHandler handler : mHandlerUseCountInTrace.keySet()) { + final int count = mHandlerUseCountInTrace.get(handler); + if (count > 0) { + final long protoToken = outputStream.start( + com.android.wm.shell.WmShellTransitionTraceProto.HANDLER_MAPPINGS); + outputStream.write(com.android.wm.shell.HandlerMapping.ID, + mHandlerIds.get(handler)); + outputStream.write(com.android.wm.shell.HandlerMapping.NAME, + handler.getClass().getName()); + outputStream.end(protoToken); + } + } + } + + private void handleOnEntryRemovedFromTrace(Object proto) { + if (mRemovedFromTraceCallbacks.containsKey(proto)) { + mRemovedFromTraceCallbacks.get(proto).run(); + mRemovedFromTraceCallbacks.remove(proto); + } + } + + private static class LogAndPrintln { + private static final String LOG_TAG = "ShellTransitionTracer"; + + private static void i(@Nullable PrintWriter pw, String msg) { + Log.i(LOG_TAG, msg); + if (pw != null) { + pw.println(msg); + pw.flush(); + } + } + + private static void e(@Nullable PrintWriter pw, String msg) { + Log.e(LOG_TAG, msg); + if (pw != null) { + pw.println("ERROR: " + msg); + pw.flush(); + } + } + + private static void e(@Nullable PrintWriter pw, String msg, @NonNull Exception e) { + Log.e(LOG_TAG, msg, e); + if (pw != null) { + pw.println("ERROR: " + msg + " ::\n " + e); + pw.flush(); + } + } + } +} diff --git a/libs/WindowManager/Shell/src/com/android/wm/shell/transition/Transitions.java b/libs/WindowManager/Shell/src/com/android/wm/shell/transition/Transitions.java index 5c8791effe18e..c0a6c7bf95e52 100644 --- a/libs/WindowManager/Shell/src/com/android/wm/shell/transition/Transitions.java +++ b/libs/WindowManager/Shell/src/com/android/wm/shell/transition/Transitions.java @@ -165,7 +165,7 @@ public class Transitions implements RemoteCallable { private final ShellController mShellController; private final ShellTransitionImpl mImpl = new ShellTransitionImpl(); private final SleepHandler mSleepHandler = new SleepHandler(); - + private final Tracer mTracer = new Tracer(); private boolean mIsRegistered = false; /** List of possible handlers. Ordered by specificity (eg. tapped back to front). */ @@ -783,6 +783,7 @@ public class Transitions implements RemoteCallable { ProtoLog.v(ShellProtoLogGroup.WM_SHELL_TRANSITIONS, "Transition %s ready while" + " %s is still animating. Notify the animating transition" + " in case they can be merged", ready, playing); + mTracer.logMergeRequested(ready.mInfo.getDebugId(), playing.mInfo.getDebugId()); playing.mHandler.mergeAnimation(ready.mToken, ready.mInfo, ready.mStartT, playing.mToken, (wct, cb) -> onMerged(playing, ready)); } @@ -816,6 +817,7 @@ public class Transitions implements RemoteCallable { for (int i = 0; i < mObservers.size(); ++i) { mObservers.get(i).onTransitionMerged(merged.mToken, playing.mToken); } + mTracer.logMerged(merged.mInfo.getDebugId(), playing.mInfo.getDebugId()); // See if we should merge another transition. processReadyQueue(track); } @@ -842,6 +844,8 @@ public class Transitions implements RemoteCallable { // Otherwise give every other handler a chance active.mHandler = dispatchTransition(active.mToken, active.mInfo, active.mStartT, active.mFinishT, (wct, cb) -> onFinish(active, wct, cb), active.mHandler); + + mTracer.logDispatched(active.mInfo.getDebugId(), active.mHandler); } /** @@ -893,6 +897,8 @@ public class Transitions implements RemoteCallable { transition.mFinishT.apply(); transition.mAborted = true; + mTracer.logAborted(transition.mInfo.getDebugId()); + if (transition.mHandler != null) { // Notifies to clean-up the aborted transition. transition.mHandler.onTransitionConsumed(