Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 4a672625 authored by Pablo Gamito's avatar Pablo Gamito Committed by Automerger Merge Worker
Browse files

Dump finish time of transitions in transitions trace am: 61aaf12c 

Original change: https://googleplex-android-review.googlesource.com/c/platform/frameworks/base/+/21609946



Change-Id: Id3487f6589ccddc4f885180b94aa7dea6311a51f
Signed-off-by: default avatarAutomerger Merge Worker <android-build-automerger-merge-worker@system.gserviceaccount.com>
parents c3ed2dba 61aaf12c

core/proto/android/server/windowmanagertransitiontrace.proto

+6 −3
Original line number Diff line number Diff line
@@ -36,8 +36,10 @@ message TransitionTraceProto { 
    MAGIC_NUMBER_H = 0x45434152;  /* RACE (little-endian ASCII) */

  }



  required fixed64 magic_number = 1;  /* Must be the first field, set to value in MagicNumber */

  repeated Transition sent_transitions = 2;

  // 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;
@@ -50,7 +52,8 @@ message Transition { 
  required uint64 finish_transaction_id = 3;

  required int64 create_time_ns = 4;

  required int64 send_time_ns = 5;

  repeated Target targets = 6;

  optional int64 finish_time_ns = 6; // consider aborted if not provided

  repeated Target targets = 7;

}



message Target {

services/core/java/com/android/server/wm/Transition.java

+3 −2
Original line number Diff line number Diff line
@@ -829,6 +829,7 @@ class Transition implements BLASTSyncEngine.TransactionReadyListener { 
        }

        mLogger.mFinishTimeNs = SystemClock.elapsedRealtimeNanos();

        mController.mLoggerHandler.post(mLogger::logOnFinish);

        mController.mTransitionTracer.logFinishedTransition(this);

        // Close the transactions now. They were originally copied to Shell in case we needed to

        // apply them due to a remote failure. Since we don't need to apply them anymore, free them

        // immediately.
@@ -1045,6 +1046,7 @@ class Transition implements BLASTSyncEngine.TransactionReadyListener { 
        }

        ProtoLog.v(ProtoLogGroup.WM_DEBUG_WINDOW_TRANSITIONS, "Aborting Transition: %d", mSyncId);

        mState = STATE_ABORT;

        mController.mTransitionTracer.logAbortedTransition(this);

        // Syncengine abort will call through to onTransactionReady()

        mSyncEngine.abort(mSyncId);

        mController.dispatchLegacyAppTransitionCancelled();
@@ -1249,8 +1251,7 @@ class Transition implements BLASTSyncEngine.TransactionReadyListener { 
                        "Calling onTransitionReady: %s", info);

                mLogger.mSendTimeNs = SystemClock.elapsedRealtimeNanos();

                mLogger.mInfo = info;

                mController.mTransitionTracer.logSentTransition(

                        this, mTargets, mLogger.mCreateTimeNs, mLogger.mSendTimeNs, info);

                mController.mTransitionTracer.logSentTransition(this, mTargets, info);

                mController.getTransitionPlayer().onTransitionReady(

                        mToken, info, transaction, mFinishTransaction);

                if (Trace.isTagEnabled(TRACE_TAG_WINDOW_MANAGER)) {

services/core/java/com/android/server/wm/TransitionController.java

+2 −0
Original line number Diff line number Diff line
@@ -976,6 +976,8 @@ class TransitionController { 
        WindowContainerTransaction mStartWCT;

        int mSyncId;

        TransitionInfo mInfo;

        ProtoOutputStream mProtoOutputStream = new ProtoOutputStream();

        long mProtoToken;



        private String buildOnSendLog() {

            StringBuilder sb = new StringBuilder("Sent Transition #").append(mSyncId)

services/core/java/com/android/server/wm/TransitionTracer.java

+190 −148
Original line number Diff line number Diff line
@@ -18,14 +18,6 @@ package com.android.server.wm; 


import static android.os.Build.IS_USER;



import static com.android.server.wm.shell.ChangeInfo.CHANGE_FLAGS;

import static com.android.server.wm.shell.ChangeInfo.HAS_CHANGED;

import static com.android.server.wm.shell.ChangeInfo.TRANSIT_MODE;

import static com.android.server.wm.shell.ChangeInfo.WINDOWING_MODE;

import static com.android.server.wm.shell.ChangeInfo.WINDOW_IDENTIFIER;

import static com.android.server.wm.shell.TransitionInfoChange.LAYER_ID;

import static com.android.server.wm.shell.TransitionInfoChange.MODE;

import static com.android.server.wm.shell.TransitionState.CHANGE;

import static com.android.server.wm.shell.TransitionTraceProto.MAGIC_NUMBER;

import static com.android.server.wm.shell.TransitionTraceProto.MAGIC_NUMBER_H;

import static com.android.server.wm.shell.TransitionTraceProto.MAGIC_NUMBER_L;
@@ -66,19 +58,59 @@ public class TransitionTracer { 


    /**

     * Records key information about a transition that has been sent to Shell to be played.

     * More information will be appended to the same proto object once the transition is finished or

     * aborted.

     * Transition information won't be added to the trace buffer until

     * {@link #logFinishedTransition} or {@link #logAbortedTransition} is called for this

     * transition.

     *

     * @param transition The transition that has been sent to Shell.

     * @param targets Information about the target windows of the transition.

     * @param createTimeNs System elapsed time (nanoseconds since boot including sleep time) at

 *                     which the transition to be recorded was created.

     * @param sendTimeNs System elapsed time (nanoseconds since boot including sleep time) at which

     * @param info

     * @param info The TransitionInfo send over to Shell to execute the transition.

     */

    public void logSentTransition(Transition transition, ArrayList<ChangeInfo> targets,

            long createTimeNs, long sendTimeNs, TransitionInfo info) {

        mTraceBuffer.pushSentTransition(transition, targets, createTimeNs, sendTimeNs);

            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);

        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);



        logTransitionInfo(transition, info);

    }



    /**

     * Completes the information dumped in {@link #logSentTransition} for a transition

     * that has finished or aborted, and add the proto object to the trace buffer.

     *

     * @param transition The transition that has finished.

     */

    public void logFinishedTransition(Transition transition) {

        // 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);

    }



    /**

     * Same as {@link #logFinishedTransition} but don't add the transition to the trace buffer

     * unless actively tracing.

     *

     * @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.
@@ -87,7 +119,9 @@ public class TransitionTracer { 
        if (!mActiveTracingEnabled) {

            return;

        }

        mTraceBuffer.pushTransitionState(transition);

        final ProtoOutputStream outputStream = new ProtoOutputStream();

        dumpTransitionStateToProto(outputStream, transition);

        mTraceBuffer.pushTransitionState(outputStream);

    }



    /**
@@ -99,39 +133,19 @@ public class TransitionTracer { 
        if (!mActiveTracingEnabled) {

            return;

        }

        mTraceBuffer.pushTransitionInfo(transition, info);

    }



    private class TransitionTraceBuffer {

        private final TraceBuffer mBuffer = 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);



        public void pushSentTransition(

                Transition transition,

                ArrayList<ChangeInfo> targets,

                long createTimeNs,

                long sendTimeNs

        ) {

            Trace.beginSection("TransitionTraceBuffer#pushSentTransition");

        final ProtoOutputStream outputStream = new ProtoOutputStream();

            final long transitionToken = outputStream

                    .start(com.android.server.wm.shell.TransitionTraceProto.SENT_TRANSITIONS);

        dumpTransitionInfoToProto(outputStream, transition, info);

        mTraceBuffer.pushTransitionInfo(outputStream);

    }



    private void dumpTransitionTargetsToProto(ProtoOutputStream outputStream,

            Transition transition, ArrayList<ChangeInfo> targets) {

        Trace.beginSection("TransitionTracer#dumpTransitionTargetsToProto");

        if (mActiveTracingEnabled) {

            outputStream.write(com.android.server.wm.shell.Transition.ID,

                    transition.getSyncId());

        }



            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());



            outputStream.write(com.android.server.wm.shell.Transition.CREATE_TIME_NS, createTimeNs);

            outputStream.write(com.android.server.wm.shell.Transition.SEND_TIME_NS, sendTimeNs);



        for (int i = 0; i < targets.size(); ++i) {

            final long changeToken = outputStream

                    .start(com.android.server.wm.shell.Transition.TARGETS);
@@ -158,15 +172,28 @@ public class TransitionTracer { 
            outputStream.end(changeToken);

        }



            outputStream.end(transitionToken);

            mBuffer.add(outputStream);

        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 pushTransitionState(Transition transition) {

            Trace.beginSection("TransitionTraceBuffer#pushTransitionState");

            final ProtoOutputStream outputStream = new ProtoOutputStream();

    private void dumpTransitionStateToProto(ProtoOutputStream outputStream, Transition transition) {

        Trace.beginSection("TransitionTracer#dumpTransitionStateToProto");



        final long stateToken = outputStream

                .start(com.android.server.wm.shell.TransitionTraceProto.TRANSITION_STATES);
@@ -184,13 +211,7 @@ public class TransitionTracer { 
        for (int i = 0; i < transition.mChanges.size(); ++i) {

            final WindowContainer window = transition.mChanges.keyAt(i);

            final ChangeInfo changeInfo = transition.mChanges.valueAt(i);

                writeChange(outputStream, window, changeInfo);

            }



            for (int i = 0; i < transition.mChanges.size(); ++i) {

                final WindowContainer window = transition.mChanges.keyAt(i);

                final ChangeInfo changeInfo = transition.mChanges.valueAt(i);

                writeChange(outputStream, window, changeInfo);

            dumpChangeInfoToProto(outputStream, window, changeInfo);

        }



        for (int i = 0; i < transition.mParticipants.size(); ++i) {
@@ -200,14 +221,34 @@ public class TransitionTracer { 
        }



        outputStream.end(stateToken);

        Trace.endSection();

    }



            mStateBuffer.add(outputStream);

    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 pushTransitionInfo(Transition transition, TransitionInfo info) {

            Trace.beginSection("TransitionTraceBuffer#pushTransitionInfo");

            final ProtoOutputStream outputStream = new ProtoOutputStream();

    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);
@@ -215,55 +256,55 @@ public class TransitionTracer { 
                transition.getSyncId());

        for (int i = 0; i < info.getChanges().size(); ++i) {

            TransitionInfo.Change change = info.getChanges().get(i);

                writeTransitionInfoChange(outputStream, change);

            dumpTransitionInfoChangeToProto(outputStream, change);

        }



        outputStream.end(transitionInfoToken);

            mTransitionInfoBuffer.add(outputStream);

        Trace.endSection();

    }



        private void writeChange(ProtoOutputStream outputStream, WindowContainer window,

                ChangeInfo changeInfo) {

            Trace.beginSection("TransitionTraceBuffer#writeChange");

            final long changeEntryToken = outputStream.start(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(TRANSIT_MODE, transitMode);

            outputStream.write(HAS_CHANGED, hasChanged);

            outputStream.write(CHANGE_FLAGS, changeFlags);

            outputStream.write(WINDOWING_MODE, windowingMode);

            window.writeIdentifierToProto(outputStream, WINDOW_IDENTIFIER);



            outputStream.end(changeEntryToken);

            Trace.endSection();

        }



        private void writeTransitionInfoChange(

    private void dumpTransitionInfoChangeToProto(

            ProtoOutputStream outputStream,

            TransitionInfo.Change change

    ) {

            Trace.beginSection("TransitionTraceBuffer#writeTransitionInfoChange");

        Trace.beginSection("TransitionTracer#dumpTransitionInfoChangeToProto");

        final long changeEntryToken = outputStream

                .start(com.android.server.wm.shell.TransitionInfo.CHANGE);



            outputStream.write(LAYER_ID, change.getLeash().getLayerId());

            outputStream.write(MODE, change.getMode());

        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 {

            mBuffer.writeTraceToFile(file, proto);

            mTransitionBuffer.writeTraceToFile(file, proto);

        }



        public void reset() {

            mBuffer.resetBuffer();

            mTransitionBuffer.resetBuffer();

            mStateBuffer.resetBuffer();

            mTransitionInfoBuffer.resetBuffer();

        }

    }
@@ -280,7 +321,7 @@ public class TransitionTracer { 
        LogAndPrintln.i(pw, "Starting shell transition trace.");

        synchronized (mEnabledLock) {

            mActiveTracingEnabled = true;

            mTraceBuffer.mBuffer.setCapacity(ACTIVE_TRACING_BUFFER_CAPACITY);

            mTraceBuffer.mTransitionBuffer.setCapacity(ACTIVE_TRACING_BUFFER_CAPACITY);

            mTraceBuffer.reset();

        }

        Trace.endSection();
@@ -309,7 +350,8 @@ public class TransitionTracer { 
        synchronized (mEnabledLock) {

            mActiveTracingEnabled = false;

            writeTraceToFileLocked(pw, outputFile);

            mTraceBuffer.mBuffer.setCapacity(ALWAYS_ON_TRACING_CAPACITY);

            mTraceBuffer.reset();

            mTraceBuffer.mTransitionBuffer.setCapacity(ALWAYS_ON_TRACING_CAPACITY);

        }

        Trace.endSection();

    }