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

Commit d2ae04c0 authored by Treehugger Robot's avatar Treehugger Robot Committed by Android (Google) Code Review
Browse files

Merge "WindowTracing: fix deadlock" into main

parents 589cc034 88ef7620

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

+35 −6
Original line number Diff line number Diff line
@@ -18,6 +18,7 @@ package com.android.server.wm; 


import static android.tracing.perfetto.DataSourceParams.PERFETTO_DS_BUFFER_EXHAUSTED_POLICY_STALL_AND_ABORT;



import android.annotation.IntDef;

import android.annotation.NonNull;

import android.internal.perfetto.protos.DataSourceConfigOuterClass.DataSourceConfig;

import android.internal.perfetto.protos.WindowmanagerConfig.WindowManagerConfig;
@@ -34,19 +35,42 @@ import android.util.proto.ProtoInputStream; 


import java.io.IOException;

import java.lang.ref.WeakReference;

import java.util.concurrent.atomic.AtomicBoolean;

import java.util.concurrent.atomic.AtomicInteger;



public final class WindowTracingDataSource extends DataSource<WindowTracingDataSource.Instance,

        WindowTracingDataSource.TlsState, Void> {



    @IntDef({

            com.android.server.wm.WindowTracingDataSource.Status.WAITING_START_EVENT,

            com.android.server.wm.WindowTracingDataSource.Status

                    .WAITING_START_EVENT_WITH_DEFERRED_STOP,

            com.android.server.wm.WindowTracingDataSource.Status.WRITING_START_EVENT,

            com.android.server.wm.WindowTracingDataSource.Status

                    .WRITING_START_EVENT_WITH_DEFERRED_STOP,

            com.android.server.wm.WindowTracingDataSource.Status.STARTED,

            com.android.server.wm.WindowTracingDataSource.Status.STOPPED,

    })

    @interface Status {

        int WAITING_START_EVENT = 0;

        int WAITING_START_EVENT_WITH_DEFERRED_STOP = 1;

        int WRITING_START_EVENT = 2;

        int WRITING_START_EVENT_WITH_DEFERRED_STOP = 3;

        int STARTED_WITH_DEFERRED_STOP = 4;

        int STARTED = 5;

        int STOPPED = 6;

    }



    public static class TlsState {

        public final Config mConfig;

        public final AtomicBoolean mIsStarting = new AtomicBoolean(true);

        public final AtomicInteger mStatus;



        private TlsState(Config config) {

        private TlsState(Config config, AtomicInteger status) {

            mConfig = config;

            mStatus = status;

        }

    }





    public static class Config {

        public final @WindowTracingLogLevel int mLogLevel;

        public final @WindowTracingLogFrequency int mLogFrequency;
@@ -61,10 +85,12 @@ public final class WindowTracingDataSource extends DataSource<WindowTracingDataS 


    public abstract static class Instance extends DataSourceInstance {

        public final Config mConfig;

        public final AtomicInteger mStatus;



        public Instance(DataSource dataSource, int instanceIndex, Config config) {

            super(dataSource, instanceIndex);

            mConfig = config;

            mStatus = new AtomicInteger(Status.WAITING_START_EVENT);

        }

    }
@@ -85,6 +111,7 @@ public final class WindowTracingDataSource extends DataSource<WindowTracingDataS 
                new DataSourceParams.Builder()

                        .setBufferExhaustedPolicy(

                                PERFETTO_DS_BUFFER_EXHAUSTED_POLICY_STALL_AND_ABORT)

                        .setPostponeStop(true)

                        .build();

        register(params);

        Log.i(TAG, "Registered with perfetto service");
@@ -101,13 +128,15 @@ public final class WindowTracingDataSource extends DataSource<WindowTracingDataS 
                if (windowTracing != null) {

                    windowTracing.onStart(mConfig);

                }





            }



            @Override

            protected void onStop(StopCallbackArguments args) {

                WindowTracingPerfetto windowTracing = mWindowTracing.get();

                if (windowTracing != null) {

                    windowTracing.onStop(mConfig);

                    windowTracing.onStop(this);

                }

            }

        };
@@ -119,9 +148,9 @@ public final class WindowTracingDataSource extends DataSource<WindowTracingDataS 
        try (Instance dsInstance = args.getDataSourceInstanceLocked()) {

            if (dsInstance == null) {

                // Datasource instance has been removed

                return new TlsState(CONFIG_DEFAULT);

                return new TlsState(CONFIG_DEFAULT,  new AtomicInteger(Status.WAITING_START_EVENT));

            }

            return new TlsState(dsInstance.mConfig);

            return new TlsState(dsInstance.mConfig, dsInstance.mStatus);

        }

    }

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

+68 −12
Original line number Diff line number Diff line
@@ -19,6 +19,8 @@ package com.android.server.wm; 
import android.annotation.Nullable;

import android.internal.perfetto.protos.TracePacketOuterClass.TracePacket;

import android.internal.perfetto.protos.WinscopeExtensionsImplOuterClass.WinscopeExtensionsImpl;

import android.os.Handler;

import android.os.Looper;

import android.os.ShellCommand;

import android.os.SystemClock;

import android.util.Log;
@@ -30,6 +32,7 @@ import com.android.internal.annotations.VisibleForTesting; 
import android.os.Trace;



import java.io.PrintWriter;

import java.util.ArrayList;

import java.util.concurrent.atomic.AtomicInteger;



class WindowTracingPerfetto extends WindowTracing {
@@ -112,14 +115,25 @@ class WindowTracingPerfetto extends WindowTracing { 
            boolean isStartLogEvent = where == WHERE_START_TRACING;

            boolean isOnFrameLogEvent = where == WHERE_ON_FRAME;



            ArrayList<Runnable> pendingStopDones = new ArrayList<Runnable>();



            mDataSource.trace((context) -> {

                WindowTracingDataSource.Config dataSourceConfig =

                        context.getCustomTlsState().mConfig;



                AtomicInteger dataSourceStatus =

                        context.getCustomTlsState().mStatus;



                if (isStartLogEvent) {

                    boolean isDataSourceStarting = context.getCustomTlsState()

                            .mIsStarting.compareAndSet(true, false);

                    if (!isDataSourceStarting) {

                    boolean isWaitingStartEvent = dataSourceStatus.compareAndSet(

                            WindowTracingDataSource.Status.WAITING_START_EVENT,

                            WindowTracingDataSource.Status.WRITING_START_EVENT);



                    boolean isWaitingStartEventWithDeferredStop = dataSourceStatus.compareAndSet(

                            WindowTracingDataSource.Status.WAITING_START_EVENT_WITH_DEFERRED_STOP,

                            WindowTracingDataSource.Status.WRITING_START_EVENT_WITH_DEFERRED_STOP);



                    if (!isWaitingStartEvent && !isWaitingStartEventWithDeferredStop) {

                        return;

                    }

                } else if (isOnFrameLogEvent) {
@@ -144,7 +158,26 @@ class WindowTracingPerfetto extends WindowTracing { 
                dumpToProto(os, dataSourceConfig.mLogLevel, where, timestamp);

                os.end(tokenExtensionsField);

                os.end(tokenWinscopeExtensions);



                dataSourceStatus.compareAndSet(WindowTracingDataSource.Status.WRITING_START_EVENT,

                        WindowTracingDataSource.Status.STARTED);



                dataSourceStatus.compareAndSet(

                        WindowTracingDataSource.Status.WRITING_START_EVENT_WITH_DEFERRED_STOP,

                        WindowTracingDataSource.Status.STARTED_WITH_DEFERRED_STOP);



                if (dataSourceStatus.compareAndSet(

                        WindowTracingDataSource.Status.STARTED_WITH_DEFERRED_STOP,

                        WindowTracingDataSource.Status.STOPPED

                )) {

                    pendingStopDones.add(context::stopDone);

                }

            });



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

                pendingStopDones.get(i).run();

                Log.i(TAG, "Stopped session (postponed)");

            }

        } catch (Exception e) {

            Log.wtf(TAG, "Exception while tracing state", e);

        } finally {
@@ -170,22 +203,45 @@ class WindowTracingPerfetto extends WindowTracing { 
            Log.i(TAG, "Started session (frequency=TRANSACTION, log level="

                    + config.mLogFrequency + ")");

            mCountSessionsOnTransaction.incrementAndGet();

        } else if (config.mLogFrequency == WindowTracingLogFrequency.SINGLE_DUMP) {

            Log.i(TAG, "Started session (frequency=SINGLE_DUMP, log level="

                    + config.mLogFrequency + ")");

        }



        Log.i(TAG, getStatus());

        Handler handler = new Handler(Looper.getMainLooper());

        handler.post(() -> log(WHERE_START_TRACING));

    }



        log(WHERE_START_TRACING);

    void onStop(WindowTracingDataSource.Instance instance) {

        if (instance.mStatus.compareAndSet(

                WindowTracingDataSource.Status.WAITING_START_EVENT,

                WindowTracingDataSource.Status.WAITING_START_EVENT_WITH_DEFERRED_STOP)) {

            Log.i(TAG, "Postponed session stop (start event not written yet)");

            return;

        }



    void onStop(WindowTracingDataSource.Config config) {

        if (config.mLogFrequency == WindowTracingLogFrequency.FRAME) {

        if (instance.mStatus.compareAndSet(

                WindowTracingDataSource.Status.WRITING_START_EVENT,

                WindowTracingDataSource.Status.WRITING_START_EVENT_WITH_DEFERRED_STOP)) {

            Log.i(TAG, "Postponed session stop (start event not written yet)");

            return;

        }



        if (!instance.mStatus.compareAndSet(WindowTracingDataSource.Status.STARTED,

                WindowTracingDataSource.Status.STOPPED)) {

            return;

        }



        instance.stopDone();



        if (instance.mConfig.mLogFrequency == WindowTracingLogFrequency.FRAME) {

            Log.i(TAG, "Stopped session (frequency=FRAME)");

            mCountSessionsOnFrame.decrementAndGet();

            Log.i(TAG, "Stopped session (frequency=TRANSACTION)");

        } else if (config.mLogFrequency == WindowTracingLogFrequency.TRANSACTION) {

        } else if (instance.mConfig.mLogFrequency == WindowTracingLogFrequency.TRANSACTION) {

            mCountSessionsOnTransaction.decrementAndGet();

            Log.i(TAG, "Stopped session (frequency=TRANSACTION)");

        } else if (instance.mConfig.mLogFrequency == WindowTracingLogFrequency.SINGLE_DUMP) {

            Log.i(TAG, "Stopped session (frequency=SINGLE_DUMP)");

        }



        Log.i(TAG, getStatus());

    }

}

services/tests/wmtests/src/com/android/server/wm/WindowTracingPerfettoTest.java

+13 −2
Original line number Diff line number Diff line
@@ -30,6 +30,7 @@ import static org.junit.Assert.fail; 
import static org.junit.Assume.assumeTrue;

import static org.mockito.ArgumentMatchers.any;

import static org.mockito.ArgumentMatchers.eq;

import static org.mockito.Mockito.timeout;



import static java.io.File.createTempFile;

import static java.nio.file.Files.createTempDirectory;
@@ -67,6 +68,11 @@ import java.io.IOException; 
public class WindowTracingPerfettoTest {

    private static final String TEST_DATA_SOURCE_NAME = "android.windowmanager.test";



    // The initial snapshot is written to perfetto asynchronously (not by the perfetto onStart

    // thread). The timeout is used after the perfetto onStart returns (i.e. after the tracing

    // session has started) to wait till the initial snapshot is actually written.

    private static final int INITIAL_SNAPSHOT_TIMEOUT_MS = 5000;



    private static WindowManagerService sWmMock;

    private static Choreographer sChoreographerMock;

    @Captor
@@ -141,12 +147,16 @@ public class WindowTracingPerfettoTest { 
    @Test

    public void trace_writesInitialStateSnapshot_whenTracingStarts() {

        startTracing(LogFrequency.LOG_FREQUENCY_TRANSACTION);

        verify(sWmMock, times(1)).dumpDebugLocked(any(), eq(WindowTracingLogLevel.ALL));

        verify(sWmMock, timeout(INITIAL_SNAPSHOT_TIMEOUT_MS)

                .times(1)).dumpDebugLocked(any(), eq(WindowTracingLogLevel.ALL));

    }



    @Test

    public void trace_writesStateSnapshot_onLogStateCall() {

        startTracing(LogFrequency.LOG_FREQUENCY_TRANSACTION);

        verify(sWmMock, timeout(INITIAL_SNAPSHOT_TIMEOUT_MS)

                .times(1)).dumpDebugLocked(any(), eq(WindowTracingLogLevel.ALL));



        sWindowTracing.logState("where");

        verify(sWmMock, times(2)).dumpDebugLocked(any(), eq(WindowTracingLogLevel.ALL));

    }
@@ -182,7 +192,8 @@ public class WindowTracingPerfettoTest { 
    public void dump_writesOneSingleStateSnapshot() {

        startTracing(LogFrequency.LOG_FREQUENCY_SINGLE_DUMP);

        sWindowTracing.logState("where");

        verify(sWmMock, times(1)).dumpDebugLocked(any(), eq(WindowTracingLogLevel.ALL));

        verify(sWmMock, timeout(INITIAL_SNAPSHOT_TIMEOUT_MS)

                .times(1)).dumpDebugLocked(any(), eq(WindowTracingLogLevel.ALL));

    }



    private void startTracing(LogFrequency logFrequency) {