Initial attempt at jank-tracking stat collection

Is a bit naive, perhaps overly aggressive, but sorta works

Change-Id: I01a774e00dbe681439c02557d9728ae43c45ce50
diff --git a/libs/hwui/renderthread/CanvasContext.cpp b/libs/hwui/renderthread/CanvasContext.cpp
index 6346479..80c60d9 100644
--- a/libs/hwui/renderthread/CanvasContext.cpp
+++ b/libs/hwui/renderthread/CanvasContext.cpp
@@ -48,7 +48,8 @@
         , mCanvas(nullptr)
         , mHaveNewSurface(false)
         , mAnimationContext(contextFactory->createAnimationContext(mRenderThread.timeLord()))
-        , mRootRenderNode(rootRenderNode) {
+        , mRootRenderNode(rootRenderNode)
+        , mCurrentFrameInfo(nullptr) {
     mRenderThread.renderState().registerCanvasContext(this);
 }
 
@@ -151,9 +152,13 @@
     }
 }
 
-void CanvasContext::prepareTree(TreeInfo& info) {
+void CanvasContext::prepareTree(TreeInfo& info, int64_t* uiFrameInfo) {
     mRenderThread.removeFrameCallback(this);
 
+    mCurrentFrameInfo = &mFrames.next();
+    mCurrentFrameInfo->importUiThreadInfo(uiFrameInfo);
+    mCurrentFrameInfo->markSyncStart();
+
     info.damageAccumulator = &mDamageAccumulator;
     info.renderer = mCanvas;
     if (mPrefetechedLayers.size() && info.mode == TreeInfo::MODE_FULL) {
@@ -203,6 +208,7 @@
             "drawRenderNode called on a context with no canvas or surface!");
 
     profiler().markPlaybackStart();
+    mCurrentFrameInfo->markIssueDrawCommandsStart();
 
     SkRect dirty;
     mDamageAccumulator.finish(&dirty);
@@ -239,12 +245,19 @@
 
     profiler().markPlaybackEnd();
 
+    // Even if we decided to cancel the frame, from the perspective of jank
+    // metrics the frame was swapped at this point
+    mCurrentFrameInfo->markSwapBuffers();
+
     if (drew) {
         swapBuffers();
     } else {
         mEglManager.cancelFrame();
     }
 
+    // TODO: Use a fence for real completion?
+    mCurrentFrameInfo->markFrameCompleted();
+    mRenderThread.jankTracker().addFrame(*mCurrentFrameInfo);
     profiler().finishFrame();
 }
 
@@ -257,9 +270,14 @@
     ATRACE_CALL();
 
     profiler().startFrame();
+    int64_t frameInfo[UI_THREAD_FRAME_INFO_SIZE];
+    UiFrameInfoBuilder(frameInfo)
+        .addFlag(FrameInfoFlags::kRTAnimation)
+        .setVsync(mRenderThread.timeLord().computeFrameTimeNanos(),
+                mRenderThread.timeLord().latestVsync());
 
     TreeInfo info(TreeInfo::MODE_RT_ONLY, mRenderThread.renderState());
-    prepareTree(info);
+    prepareTree(info, frameInfo);
     if (info.out.canDrawThisFrame) {
         draw();
     }
@@ -372,6 +390,28 @@
     thread.eglManager().setTextureAtlas(buffer, map, mapSize);
 }
 
+void CanvasContext::dumpFrames(int fd) {
+    FILE* file = fdopen(fd, "a");
+    fprintf(file, "\n\n---PROFILEDATA---");
+    for (size_t i = 0; i < mFrames.size(); i++) {
+        FrameInfo& frame = mFrames[i];
+        if (frame[FrameInfoIndex::kSyncStart] == 0) {
+            continue;
+        }
+        fprintf(file, "\n");
+        for (int i = 0; i < FrameInfoIndex::kNumIndexes; i++) {
+            fprintf(file, "%" PRId64 ",", frame[i]);
+        }
+    }
+    fprintf(file, "\n---PROFILEDATA---\n\n");
+    fflush(file);
+}
+
+void CanvasContext::resetFrameStats() {
+    mFrames.clear();
+    mRenderThread.jankTracker().reset();
+}
+
 } /* namespace renderthread */
 } /* namespace uirenderer */
 } /* namespace android */
diff --git a/libs/hwui/renderthread/CanvasContext.h b/libs/hwui/renderthread/CanvasContext.h
index d3fbde8..9a60dc7 100644
--- a/libs/hwui/renderthread/CanvasContext.h
+++ b/libs/hwui/renderthread/CanvasContext.h
@@ -17,7 +17,14 @@
 #ifndef CANVASCONTEXT_H_
 #define CANVASCONTEXT_H_
 
-#include <set>
+#include "DamageAccumulator.h"
+#include "DrawProfiler.h"
+#include "IContextFactory.h"
+#include "FrameInfo.h"
+#include "RenderNode.h"
+#include "utils/RingBuffer.h"
+#include "renderthread/RenderTask.h"
+#include "renderthread/RenderThread.h"
 
 #include <cutils/compiler.h>
 #include <EGL/egl.h>
@@ -25,14 +32,7 @@
 #include <utils/Functor.h>
 #include <utils/Vector.h>
 
-#include "../DamageAccumulator.h"
-#include "../DrawProfiler.h"
-#include "../IContextFactory.h"
-#include "../RenderNode.h"
-#include "RenderTask.h"
-#include "RenderThread.h"
-
-#define FUNCTOR_PROCESS_DELAY 4
+#include <set>
 
 namespace android {
 namespace uirenderer {
@@ -75,7 +75,7 @@
     void setOpaque(bool opaque);
     void makeCurrent();
     void processLayerUpdate(DeferredLayerUpdater* layerUpdater);
-    void prepareTree(TreeInfo& info);
+    void prepareTree(TreeInfo& info, int64_t* uiFrameInfo);
     void draw();
     void destroy();
 
@@ -103,6 +103,9 @@
 
     DrawProfiler& profiler() { return mProfiler; }
 
+    void dumpFrames(int fd);
+    void resetFrameStats();
+
 private:
     friend class RegisterFrameCallbackTask;
     // TODO: Replace with something better for layer & other GL object
@@ -133,6 +136,9 @@
     const sp<RenderNode> mRootRenderNode;
 
     DrawProfiler mProfiler;
+    FrameInfo* mCurrentFrameInfo;
+    // Ring buffer large enough for 1 second worth of frames
+    RingBuffer<FrameInfo, 60> mFrames;
 
     std::set<RenderNode*> mPrefetechedLayers;
 };
diff --git a/libs/hwui/renderthread/DrawFrameTask.cpp b/libs/hwui/renderthread/DrawFrameTask.cpp
index 4d8a469..679a00f 100644
--- a/libs/hwui/renderthread/DrawFrameTask.cpp
+++ b/libs/hwui/renderthread/DrawFrameTask.cpp
@@ -34,8 +34,6 @@
 DrawFrameTask::DrawFrameTask()
         : mRenderThread(nullptr)
         , mContext(nullptr)
-        , mFrameTimeNanos(0)
-        , mRecordDurationNanos(0)
         , mDensity(1.0f) // safe enough default
         , mSyncResult(kSync_OK) {
 }
@@ -68,18 +66,12 @@
     }
 }
 
-int DrawFrameTask::drawFrame(nsecs_t frameTimeNanos, nsecs_t recordDurationNanos) {
+int DrawFrameTask::drawFrame() {
     LOG_ALWAYS_FATAL_IF(!mContext, "Cannot drawFrame with no CanvasContext!");
 
     mSyncResult = kSync_OK;
-    mFrameTimeNanos = frameTimeNanos;
-    mRecordDurationNanos = recordDurationNanos;
     postAndWait();
 
-    // Reset the single-frame data
-    mFrameTimeNanos = 0;
-    mRecordDurationNanos = 0;
-
     return mSyncResult;
 }
 
@@ -93,7 +85,7 @@
     ATRACE_NAME("DrawFrame");
 
     mContext->profiler().setDensity(mDensity);
-    mContext->profiler().startFrame(mRecordDurationNanos);
+    mContext->profiler().startFrame();
 
     bool canUnblockUiThread;
     bool canDrawThisFrame;
@@ -122,7 +114,7 @@
 
 bool DrawFrameTask::syncFrameState(TreeInfo& info) {
     ATRACE_CALL();
-    mRenderThread->timeLord().vsyncReceived(mFrameTimeNanos);
+    mRenderThread->timeLord().vsyncReceived(mFrameInfo[FrameInfoIndex::kVsync]);
     mContext->makeCurrent();
     Caches::getInstance().textureCache.resetMarkInUse();
 
@@ -130,7 +122,7 @@
         mContext->processLayerUpdate(mLayers[i].get());
     }
     mLayers.clear();
-    mContext->prepareTree(info);
+    mContext->prepareTree(info, mFrameInfo);
 
     // This is after the prepareTree so that any pending operations
     // (RenderNode tree state, prefetched layers, etc...) will be flushed.
diff --git a/libs/hwui/renderthread/DrawFrameTask.h b/libs/hwui/renderthread/DrawFrameTask.h
index 953f012..0e56bea 100644
--- a/libs/hwui/renderthread/DrawFrameTask.h
+++ b/libs/hwui/renderthread/DrawFrameTask.h
@@ -25,6 +25,7 @@
 #include "RenderTask.h"
 
 #include "../Rect.h"
+#include "../FrameInfo.h"
 #include "../TreeInfo.h"
 
 namespace android {
@@ -62,7 +63,9 @@
     void removeLayerUpdate(DeferredLayerUpdater* layer);
 
     void setDensity(float density) { mDensity = density; }
-    int drawFrame(nsecs_t frameTimeNanos, nsecs_t recordDurationNanos);
+    int drawFrame();
+
+    int64_t* frameInfo() { return mFrameInfo; }
 
     virtual void run() override;
 
@@ -80,12 +83,12 @@
     /*********************************************
      *  Single frame data
      *********************************************/
-    nsecs_t mFrameTimeNanos;
-    nsecs_t mRecordDurationNanos;
     float mDensity;
     std::vector< sp<DeferredLayerUpdater> > mLayers;
 
     int mSyncResult;
+
+    int64_t mFrameInfo[UI_THREAD_FRAME_INFO_SIZE];
 };
 
 } /* namespace renderthread */
diff --git a/libs/hwui/renderthread/RenderProxy.cpp b/libs/hwui/renderthread/RenderProxy.cpp
index 4dc4248..3a31db0 100644
--- a/libs/hwui/renderthread/RenderProxy.cpp
+++ b/libs/hwui/renderthread/RenderProxy.cpp
@@ -16,14 +16,14 @@
 
 #include "RenderProxy.h"
 
-#include "CanvasContext.h"
-#include "RenderTask.h"
-#include "RenderThread.h"
-
-#include "../DeferredLayerUpdater.h"
-#include "../DisplayList.h"
-#include "../LayerRenderer.h"
-#include "../Rect.h"
+#include "DeferredLayerUpdater.h"
+#include "DisplayList.h"
+#include "LayerRenderer.h"
+#include "Rect.h"
+#include "renderthread/CanvasContext.h"
+#include "renderthread/RenderTask.h"
+#include "renderthread/RenderThread.h"
+#include "utils/Macros.h"
 
 namespace android {
 namespace uirenderer {
@@ -52,6 +52,11 @@
     MethodInvokeRenderTask* task = new MethodInvokeRenderTask((RunnableMethod) Bridge_ ## method); \
     ARGS(method) *args = (ARGS(method) *) task->payload()
 
+HWUI_ENUM(DumpFlags,
+        kFrameStats = 1 << 0,
+        kReset      = 1 << 1,
+);
+
 CREATE_BRIDGE4(createContext, RenderThread* thread, bool translucent,
         RenderNode* rootRenderNode, IContextFactory* contextFactory) {
     return new CanvasContext(*args->thread, args->translucent,
@@ -92,7 +97,7 @@
 }
 
 CREATE_BRIDGE2(setFrameInterval, RenderThread* thread, nsecs_t frameIntervalNanos) {
-    args->thread->timeLord().setFrameInterval(args->frameIntervalNanos);
+    args->thread->setFrameInterval(args->frameIntervalNanos);
     return nullptr;
 }
 
@@ -175,7 +180,8 @@
 }
 
 void RenderProxy::setup(int width, int height, const Vector3& lightCenter, float lightRadius,
-        uint8_t ambientShadowAlpha, uint8_t spotShadowAlpha) {
+        uint8_t ambientShadowAlpha, uint8_t spotShadowAlpha, float density) {
+    mDrawFrameTask.setDensity(density);
     SETUP_TASK(setup);
     args->context = mContext;
     args->width = width;
@@ -199,10 +205,12 @@
     post(task);
 }
 
-int RenderProxy::syncAndDrawFrame(nsecs_t frameTimeNanos, nsecs_t recordDurationNanos,
-        float density) {
-    mDrawFrameTask.setDensity(density);
-    return mDrawFrameTask.drawFrame(frameTimeNanos, recordDurationNanos);
+int64_t* RenderProxy::frameInfo() {
+    return mDrawFrameTask.frameInfo();
+}
+
+int RenderProxy::syncAndDrawFrame() {
+    return mDrawFrameTask.drawFrame();
 }
 
 CREATE_BRIDGE1(destroy, CanvasContext* context) {
@@ -375,19 +383,28 @@
     mRenderThread.queueAtFront(task);
 }
 
-CREATE_BRIDGE2(dumpProfileInfo, CanvasContext* context, int fd) {
+CREATE_BRIDGE3(dumpProfileInfo, CanvasContext* context, int fd, int dumpFlags) {
     args->context->profiler().dumpData(args->fd);
+    if (args->dumpFlags & DumpFlags::kFrameStats) {
+        args->context->dumpFrames(args->fd);
+    }
+    if (args->dumpFlags & DumpFlags::kReset) {
+        args->context->resetFrameStats();
+    }
     return nullptr;
 }
 
-void RenderProxy::dumpProfileInfo(int fd) {
+void RenderProxy::dumpProfileInfo(int fd, int dumpFlags) {
     SETUP_TASK(dumpProfileInfo);
     args->context = mContext;
     args->fd = fd;
+    args->dumpFlags = dumpFlags;
     postAndWait(task);
 }
 
-CREATE_BRIDGE1(dumpGraphicsMemory, int fd) {
+CREATE_BRIDGE2(dumpGraphicsMemory, int fd, RenderThread* thread) {
+    args->thread->jankTracker().dump(args->fd);
+
     FILE *file = fdopen(args->fd, "a");
     if (Caches::hasInstance()) {
         String8 cachesLog;
@@ -403,6 +420,7 @@
 void RenderProxy::dumpGraphicsMemory(int fd) {
     SETUP_TASK(dumpGraphicsMemory);
     args->fd = fd;
+    args->thread = &RenderThread::getInstance();
     staticPostAndWait(task);
 }
 
diff --git a/libs/hwui/renderthread/RenderProxy.h b/libs/hwui/renderthread/RenderProxy.h
index d87e777..19e73e5 100644
--- a/libs/hwui/renderthread/RenderProxy.h
+++ b/libs/hwui/renderthread/RenderProxy.h
@@ -71,10 +71,10 @@
     ANDROID_API void updateSurface(const sp<ANativeWindow>& window);
     ANDROID_API bool pauseSurface(const sp<ANativeWindow>& window);
     ANDROID_API void setup(int width, int height, const Vector3& lightCenter, float lightRadius,
-            uint8_t ambientShadowAlpha, uint8_t spotShadowAlpha);
+            uint8_t ambientShadowAlpha, uint8_t spotShadowAlpha, float density);
     ANDROID_API void setOpaque(bool opaque);
-    ANDROID_API int syncAndDrawFrame(nsecs_t frameTimeNanos, nsecs_t recordDurationNanos,
-            float density);
+    ANDROID_API int64_t* frameInfo();
+    ANDROID_API int syncAndDrawFrame();
     ANDROID_API void destroy();
 
     ANDROID_API static void invokeFunctor(Functor* functor, bool waitForCompletion);
@@ -95,7 +95,7 @@
     ANDROID_API void stopDrawing();
     ANDROID_API void notifyFramePending();
 
-    ANDROID_API void dumpProfileInfo(int fd);
+    ANDROID_API void dumpProfileInfo(int fd, int dumpFlags);
     ANDROID_API static void dumpGraphicsMemory(int fd);
 
     ANDROID_API void setTextureAtlas(const sp<GraphicBuffer>& buffer, int64_t* map, size_t size);
diff --git a/libs/hwui/renderthread/RenderThread.cpp b/libs/hwui/renderthread/RenderThread.cpp
index 9a0fbad..2a8baa7 100644
--- a/libs/hwui/renderthread/RenderThread.cpp
+++ b/libs/hwui/renderthread/RenderThread.cpp
@@ -151,6 +151,11 @@
     LOG_ALWAYS_FATAL("Can't destroy the render thread");
 }
 
+void RenderThread::setFrameInterval(nsecs_t frameInterval) {
+    mTimeLord.setFrameInterval(frameInterval);
+    mJankTracker->setFrameInterval(frameInterval);
+}
+
 void RenderThread::initializeDisplayEventReceiver() {
     LOG_ALWAYS_FATAL_IF(mDisplayEventReceiver, "Initializing a second DisplayEventReceiver?");
     mDisplayEventReceiver = new DisplayEventReceiver();
@@ -167,6 +172,7 @@
     initializeDisplayEventReceiver();
     mEglManager = new EglManager(*this);
     mRenderState = new RenderState(*this);
+    mJankTracker = new JankTracker(mTimeLord.frameIntervalNanos());
 }
 
 int RenderThread::displayEventReceiverCallback(int fd, int events, void* data) {
diff --git a/libs/hwui/renderthread/RenderThread.h b/libs/hwui/renderthread/RenderThread.h
index 8fc8ca5..f169424 100644
--- a/libs/hwui/renderthread/RenderThread.h
+++ b/libs/hwui/renderthread/RenderThread.h
@@ -19,8 +19,8 @@
 
 #include "RenderTask.h"
 
-#include <memory>
-#include <set>
+#include "../JankTracker.h"
+#include "TimeLord.h"
 
 #include <cutils/compiler.h>
 #include <utils/Looper.h>
@@ -28,7 +28,8 @@
 #include <utils/Singleton.h>
 #include <utils/Thread.h>
 
-#include "TimeLord.h"
+#include <memory>
+#include <set>
 
 namespace android {
 
@@ -85,9 +86,12 @@
     // the next vsync. If it is not currently registered this does nothing.
     void pushBackFrameCallback(IFrameCallback* callback);
 
+    void setFrameInterval(nsecs_t frameInterval);
+
     TimeLord& timeLord() { return mTimeLord; }
     RenderState& renderState() { return *mRenderState; }
     EglManager& eglManager() { return *mEglManager; }
+    JankTracker& jankTracker() { return *mJankTracker; }
 
 protected:
     virtual bool threadLoop() override;
@@ -132,6 +136,8 @@
     TimeLord mTimeLord;
     RenderState* mRenderState;
     EglManager* mEglManager;
+
+    JankTracker* mJankTracker = nullptr;
 };
 
 } /* namespace renderthread */
diff --git a/libs/hwui/renderthread/TimeLord.cpp b/libs/hwui/renderthread/TimeLord.cpp
index f187493..f846d6a 100644
--- a/libs/hwui/renderthread/TimeLord.cpp
+++ b/libs/hwui/renderthread/TimeLord.cpp
@@ -32,7 +32,7 @@
     return false;
 }
 
-nsecs_t TimeLord::computeFrameTimeMs() {
+nsecs_t TimeLord::computeFrameTimeNanos() {
     // Logic copied from Choreographer.java
     nsecs_t now = systemTime(CLOCK_MONOTONIC);
     nsecs_t jitterNanos = now - mFrameTimeNanos;
@@ -40,7 +40,11 @@
         nsecs_t lastFrameOffset = jitterNanos % mFrameIntervalNanos;
         mFrameTimeNanos = now - lastFrameOffset;
     }
-    return nanoseconds_to_milliseconds(mFrameTimeNanos);
+    return mFrameTimeNanos;
+}
+
+nsecs_t TimeLord::computeFrameTimeMs() {
+    return nanoseconds_to_milliseconds(computeFrameTimeNanos());
 }
 
 } /* namespace renderthread */
diff --git a/libs/hwui/renderthread/TimeLord.h b/libs/hwui/renderthread/TimeLord.h
index 7c155d2..5464399 100644
--- a/libs/hwui/renderthread/TimeLord.h
+++ b/libs/hwui/renderthread/TimeLord.h
@@ -29,9 +29,13 @@
 class TimeLord {
 public:
     void setFrameInterval(nsecs_t intervalNanos) { mFrameIntervalNanos = intervalNanos; }
+    nsecs_t frameIntervalNanos() const { return mFrameIntervalNanos; }
+
     // returns true if the vsync is newer, false if it was rejected for staleness
     bool vsyncReceived(nsecs_t vsync);
+    nsecs_t latestVsync() { return mFrameTimeNanos; }
     nsecs_t computeFrameTimeMs();
+    nsecs_t computeFrameTimeNanos();
 
 private:
     friend class RenderThread;