GfxFrameStatsMonitorImpl.java

/*
 * Copyright (C) 2016 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 androidx.test.jank.internal;

import android.app.Instrumentation;
import android.os.Bundle;
import android.os.ParcelFileDescriptor;
import androidx.test.jank.GfxFrameStatsMonitor;
import androidx.test.jank.IMonitor;

import java.io.BufferedReader;
import java.io.IOException;
import java.io.InputStream;
import java.io.InputStreamReader;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.Collections;
import java.util.Comparator;
import java.util.List;

/**
 * Monitors dumpsys gfxinfo framestats to compute frame statistics.
 */
class GfxFrameStatsMonitorImpl implements IMonitor {

    private static final String PROFILEDATA_SEPARATOR = "---PROFILEDATA---";
    private final static long FRAME_DURATION_NANO = 16666667;
    private final static long FRAME_VSYNC_MARGIN = FRAME_DURATION_NANO / 2;

    private Instrumentation mInstrumentation;
    private String mProcess;
    private ArrayList<ArrayList<FrameData>> mFrameData = new ArrayList<>();
    private ArrayList<FrameData> mAllFrames = new ArrayList<>();

    private static class FrameData {
        long intendedVsync;
        long vsync;
        long handleInputStart;
        long animationsStart;
        long performTraversalStart;
        long drawStart;
        long syncQueued;
        long syncStart;
        long issueDrawCommandsStart;
        long swapBuffers;
        long completed;
    }

    private interface FrameMeasure {
        long getValue(FrameData frame);
    }

    private static class FrameComparator implements Comparator<FrameData> {

        private final FrameMeasure mMeasure;

        FrameComparator(FrameMeasure measure) {
            mMeasure = measure;
        }

        @Override
        public int compare(FrameData o1, FrameData o2) {
            return Long.compare(mMeasure.getValue(o1), mMeasure.getValue(o2));
        }
    }

    /**
     * Constructs a GfxFrameStatsMonitorImpl instance which can be used to monitor the given
     * {@code process} for frame statistics.
     */
    public GfxFrameStatsMonitorImpl(Instrumentation instrumentation, String process) {
        mInstrumentation = instrumentation;
        mProcess = process;
    }

    /**
     * {@inheritDoc}
     */
    @Override
    public void startIteration() throws IOException {
        // Clear out any previous data
        InputStream stdout = executeShellCommand(
                String.format("dumpsys gfxinfo %s reset", getProcess()));
        BufferedReader reader = new BufferedReader(new InputStreamReader(stdout));

        try {
            // Read the output, but don't do anything with it
            while (reader.readLine() != null) {
            }
        } finally {
            reader.close();
        }
    }

    /**
     * {@inheritDoc}
     */
    @Override
    public Bundle stopIteration() throws IOException {
        int startCount = mAllFrames.size();

        // Dump the latest frames
        InputStream stdout = executeShellCommand(
                String.format("dumpsys gfxinfo %s framestats", getProcess()));
        BufferedReader reader = new BufferedReader(new InputStreamReader(stdout));

        try {
            String line;
            while ((line = reader.readLine()) != null) {
                if (line.startsWith(PROFILEDATA_SEPARATOR)) {
                    line = reader.readLine();
                    if (line == null) {
                        break;
                    }

                    ArrayList<FrameData> frameList = new ArrayList<>();
                    mFrameData.add(frameList);
                    List<String> headers = Arrays.asList(line.split(","));

                    int flagsIndex = headers.indexOf("Flags");
                    int intendedVsyncIndex = headers.indexOf("IntendedVsync");
                    int vsyncIndex = headers.indexOf("Vsync");
                    int inputIndex = headers.indexOf("HandleInputStart");
                    int animationsIndex = headers.indexOf("AnimationStart");
                    int traversalIndex = headers.indexOf("PerformTraversalsStart");
                    int drawStartIndex = headers.indexOf("DrawStart");
                    int syncQueuedIndex = headers.indexOf("SyncQueued");
                    int syncStartIndex = headers.indexOf("SyncStart");
                    int drawCommandsStartIndex = headers.indexOf("IssueDrawCommandsStart");
                    int swapBuffersIndex = headers.indexOf("SwapBuffers");
                    int frameCompletedIndex = headers.indexOf("FrameCompleted");

                    while ((line = reader.readLine()) != null) {
                        if (line.startsWith(PROFILEDATA_SEPARATOR)) {
                            break;
                        }

                        String[] values = line.split(",");

                        // We need to skip any frame with a non-zero flags. From the documentation:
                        // "If this is non-zero the row should be ignored, as the frame has been
                        // determined as being an outlier from normal performance, where it is
                        // expected that layout & draw take longer than 16ms."
                        // In testing I've found that frames with non-zero flags can often have
                        // duplicate, incomplete, or nonsensical timestamps.
                        long flags = Long.parseLong(values[flagsIndex]);
                        if (flags != 0) {
                            continue;
                        }

                        FrameData row = new FrameData();
                        row.intendedVsync = Long.parseLong(values[intendedVsyncIndex]);
                        row.vsync = Long.parseLong(values[vsyncIndex]);
                        row.handleInputStart = Long.parseLong(values[inputIndex]);
                        row.animationsStart = Long.parseLong(values[animationsIndex]);
                        row.performTraversalStart = Long.parseLong(values[traversalIndex]);
                        row.drawStart = Long.parseLong(values[drawStartIndex]);
                        row.syncQueued = Long.parseLong(values[syncQueuedIndex]);
                        row.syncStart = Long.parseLong(values[syncStartIndex]);
                        row.issueDrawCommandsStart = Long.parseLong(values[drawCommandsStartIndex]);
                        row.swapBuffers = Long.parseLong(values[swapBuffersIndex]);
                        row.completed = Long.parseLong(values[frameCompletedIndex]);

                        frameList.add(row);
                        mAllFrames.add(row);
                    }
                }
            }
        } finally {
            reader.close();
        }

        Bundle ret = new Bundle();
        ret.putInt("num-frames", mAllFrames.size() - startCount);
        return ret;
    }

    /**
     * {@inheritDoc}
     */
    public Bundle getMetrics() {
        Bundle ret = new Bundle();
        ret.putInt("num-frames", mAllFrames.size());

        if (mFrameData.isEmpty()) {
            return ret;
        }

        int totalVsyncs = 0;
        int jankyVsyncs = 0;

        // Calculate the number of vsyncs for which we were expecting frames to be drawn,
        // and how many of those we missed.
        for (ArrayList<FrameData> list : mFrameData) {
            if (list.isEmpty()) {
                continue;
            }

            int currentIndex = 0;
            int pendingIndex = 0;

            for (long currentVsync = list.get(0).intendedVsync; currentVsync < list.get(
                    list.size() - 1).completed; currentVsync += FRAME_DURATION_NANO) {

                // Skip this vsync interval if the next frame to display is intended for a future
                // vsync
                FrameData pendingFrame = list.get(pendingIndex);
                if (pendingFrame.intendedVsync - currentVsync > FRAME_VSYNC_MARGIN) {
                    continue;
                }

                // Update our estimate for currentVsync
                if (currentIndex < list.size()) {
                    FrameData currentFrame = list.get(currentIndex);
                    if (currentFrame.intendedVsync - currentVsync < FRAME_VSYNC_MARGIN) {
                        currentVsync = currentFrame.intendedVsync;
                        currentIndex++;
                    }
                }

                // Compute the next vsync time
                long nextVsync = currentVsync + FRAME_DURATION_NANO;
                if (currentIndex < list.size()) {
                    FrameData nextFrame = list.get(currentIndex);
                    if (Math.abs(nextVsync - nextFrame.intendedVsync) < FRAME_VSYNC_MARGIN) {
                        nextVsync = nextFrame.intendedVsync;
                    }
                }

                // Check if we rendered a frame, and advance our pending data if we did.
                // This logic assumes that every frame generated is eventually rendered, and that
                // at most one frame is rendered per vsync.
                if (pendingFrame.completed > nextVsync) {
                    jankyVsyncs++;
                } else {
                    pendingIndex++;
                }
                totalVsyncs++;
            }
        }

        ret.putInt(GfxFrameStatsMonitor.KEY_VSYNC_COUNT, totalVsyncs);
        ret.putInt(GfxFrameStatsMonitor.KEY_FRAME_COUNT, mAllFrames.size());

        double jankRate = (double) jankyVsyncs / (double) totalVsyncs;
        ret.putDouble(GfxFrameStatsMonitor.KEY_AVG_JANK_RATE, jankRate * 100.0);
        ret.putDouble(GfxFrameStatsMonitor.KEY_AVG_FPS, (1.0 - jankRate) * 60.0);

        int slowFrames = 0;
        // Count slow frames.
        for (FrameData data : mAllFrames) {
            if (data.completed - data.vsync > FRAME_DURATION_NANO) {
                slowFrames++;
            }
        }
        ret.putDouble(GfxFrameStatsMonitor.KEY_AVG_SLOW_RATE,
                (double) slowFrames * 100.0 / (double) (mAllFrames.size()));

        recordPercentiles(ret, "framestats-uithread", new FrameMeasure() {
            @Override
            public long getValue(FrameData frame) {
                return frame.syncQueued - frame.vsync;
            }
        });
        recordPercentiles(ret, "framestats-renderthread", new FrameMeasure() {
            @Override
            public long getValue(FrameData frame) {
                return frame.completed - frame.syncStart;
            }
        });
        recordPercentiles(ret, "framestats-totaltime", new FrameMeasure() {
            @Override
            public long getValue(FrameData frame) {
                return frame.completed - frame.vsync;
            }
        });

        return ret;
    }

    private void recordPercentiles(Bundle results, String key, FrameMeasure measure) {
        int size = mAllFrames.size();
        if (size > 0) {
            Collections.sort(mAllFrames, new FrameComparator(measure));
            results.putDouble(key + "-median",
                    (double) measure.getValue(mAllFrames.get((int) (size * 0.50))) / 1000000.0);
            results.putDouble(key + "-90",
                    (double) measure.getValue(mAllFrames.get((int) (size * 0.90))) / 1000000.0);
            results.putDouble(key + "-95",
                    (double) measure.getValue(mAllFrames.get((int) (size * 0.95))) / 1000000.0);
            results.putDouble(key + "-99",
                    (double) measure.getValue(mAllFrames.get((int) (size * 0.99))) / 1000000.0);
        }
    }

    /**
     * Returns the name of the process that this monitor is observing.
     */
    private String getProcess() {
        return mProcess;
    }

    /**
     * Executes the given {@code command} as the shell user and returns an {@link InputStream}
     * containing the command's standard output.
     */
    private InputStream executeShellCommand(String command) {
        ParcelFileDescriptor stdout = mInstrumentation.getUiAutomation()
                .executeShellCommand(command);
        return new ParcelFileDescriptor.AutoCloseInputStream(stdout);
    }
}