Add per-buffer perfetto trace points for SurfaceFlinger frame events

In order to track how buffers move through the system, we add per-buffer perfetto trace points for SurfaceFlinger.
The majority of these were already tracked through TimeStats, so the new tracing was built on top of TimeStats.

Test: atest libsurfaceflinger_unittest

Run trace with:
{ adb shell perfetto   -c - --txt   -o /data/misc/perfetto-traces/trace <<EOF
buffers: {
    size_kb: 1280
}
data_sources: {
    config {
        name: "android.surfaceflinger.timestats"
    }
}
duration_ms: 3000
EOF
} && adb pull /data/misc/perfetto-traces/trace ~/Desktop/trace

Change-Id: Ifb38c64a9966fece735f0ad72438c7c9c5e07baa
diff --git a/services/surfaceflinger/Android.bp b/services/surfaceflinger/Android.bp
index afb9cec..438f8f3 100644
--- a/services/surfaceflinger/Android.bp
+++ b/services/surfaceflinger/Android.bp
@@ -60,11 +60,14 @@
     ],
     static_libs: [
         "libcompositionengine",
+        "libperfetto_client_experimental",
         "librenderengine",
         "libserviceutils",
+        "libtimestats",
         "libtrace_proto",
         "libvr_manager",
         "libvrflinger",
+        "perfetto_src_tracing_ipc",
     ],
     header_libs: [
         "android.hardware.graphics.composer@2.1-command-buffer",
@@ -73,8 +76,10 @@
     ],
     export_static_lib_headers: [
         "libcompositionengine",
+        "libperfetto_client_experimental",
         "librenderengine",
         "libserviceutils",
+        "libtimestats",
     ],
     export_shared_lib_headers: [
         "android.hardware.graphics.allocator@2.0",
@@ -160,7 +165,6 @@
         "SurfaceFlinger.cpp",
         "SurfaceInterceptor.cpp",
         "SurfaceTracing.cpp",
-        "TimeStats/TimeStats.cpp",
         "TransactionCompletedThread.cpp",
     ],
 }
@@ -230,7 +234,6 @@
 
 subdirs = [
     "layerproto",
-    "TimeStats/timestatsproto",
     "tests",
 ]
 
diff --git a/services/surfaceflinger/BufferLayer.cpp b/services/surfaceflinger/BufferLayer.cpp
index e9af9e2..a8bdb79 100644
--- a/services/surfaceflinger/BufferLayer.cpp
+++ b/services/surfaceflinger/BufferLayer.cpp
@@ -314,12 +314,17 @@
 
     if (presentFence->isValid()) {
         mFlinger->mTimeStats->setPresentFence(layerID, mCurrentFrameNumber, presentFence);
+        mFlinger->mTimeStats->traceFence(layerID, getCurrentBufferId(), mCurrentFrameNumber,
+                                         presentFence, TimeStats::FrameEvent::PRESENT_FENCE);
         mFrameTracker.setActualPresentFence(std::shared_ptr<FenceTime>(presentFence));
     } else if (displayId && mFlinger->getHwComposer().isConnected(*displayId)) {
         // The HWC doesn't support present fences, so use the refresh
         // timestamp instead.
         const nsecs_t actualPresentTime = mFlinger->getHwComposer().getRefreshTimestamp(*displayId);
         mFlinger->mTimeStats->setPresentTime(layerID, mCurrentFrameNumber, actualPresentTime);
+        mFlinger->mTimeStats->traceTimestamp(layerID, getCurrentBufferId(), mCurrentFrameNumber,
+                                             actualPresentTime,
+                                             TimeStats::FrameEvent::PRESENT_FENCE);
         mFrameTracker.setActualPresentTime(actualPresentTime);
     }
 
diff --git a/services/surfaceflinger/BufferQueueLayer.cpp b/services/surfaceflinger/BufferQueueLayer.cpp
index 5f494ff..6cad3c7 100644
--- a/services/surfaceflinger/BufferQueueLayer.cpp
+++ b/services/surfaceflinger/BufferQueueLayer.cpp
@@ -45,6 +45,14 @@
 
 void BufferQueueLayer::onLayerDisplayed(const sp<Fence>& releaseFence) {
     mConsumer->setReleaseFence(releaseFence);
+
+    // Prevent tracing the same release multiple times.
+    if (mPreviousFrameNumber != mPreviousReleasedFrameNumber) {
+        mFlinger->mTimeStats->traceFence(getSequence(), mPreviousBufferId, mPreviousFrameNumber,
+                                         std::make_shared<FenceTime>(releaseFence),
+                                         TimeStats::FrameEvent::RELEASE_FENCE);
+        mPreviousReleasedFrameNumber = mPreviousFrameNumber;
+    }
 }
 
 void BufferQueueLayer::setTransformHint(uint32_t orientation) const {
@@ -355,9 +363,15 @@
             mQueuedFrames--;
         }
 
+        uint64_t bufferID = mQueueItems[0].mGraphicBuffer->getId();
         mFlinger->mTimeStats->setAcquireFence(layerID, currentFrameNumber,
                                               mQueueItems[0].mFenceTime);
+        mFlinger->mTimeStats->traceFence(layerID, bufferID, currentFrameNumber,
+                                         mQueueItems[0].mFenceTime,
+                                         TimeStats::FrameEvent::ACQUIRE_FENCE);
         mFlinger->mTimeStats->setLatchTime(layerID, currentFrameNumber, latchTime);
+        mFlinger->mTimeStats->traceTimestamp(layerID, bufferID, currentFrameNumber, latchTime,
+                                             TimeStats::FrameEvent::LATCH);
 
         mQueueItems.removeAt(0);
     }
@@ -373,6 +387,7 @@
 
 status_t BufferQueueLayer::updateActiveBuffer() {
     // update the active buffer
+    mPreviousBufferId = getCurrentBufferId();
     mActiveBuffer = mConsumer->getCurrentBuffer(&mActiveBufferSlot, &mActiveBufferFence);
     auto& layerCompositionState = getCompositionLayer()->editState().frontEnd;
     layerCompositionState.buffer = mActiveBuffer;
@@ -413,6 +428,11 @@
 // -----------------------------------------------------------------------
 
 void BufferQueueLayer::onFrameAvailable(const BufferItem& item) {
+    const int32_t layerID = getSequence();
+    mFlinger->mTimeStats->traceNewLayer(layerID, getName().c_str());
+    mFlinger->mTimeStats->traceTimestamp(layerID, item.mGraphicBuffer->getId(), item.mFrameNumber,
+                                         systemTime(), TimeStats::FrameEvent::POST);
+
     ATRACE_CALL();
     // Add this buffer from our internal queue tracker
     { // Autolock scope
diff --git a/services/surfaceflinger/BufferQueueLayer.h b/services/surfaceflinger/BufferQueueLayer.h
index 3bc625e..bf3f917 100644
--- a/services/surfaceflinger/BufferQueueLayer.h
+++ b/services/surfaceflinger/BufferQueueLayer.h
@@ -128,6 +128,9 @@
     uint64_t mPreviousFrameNumber{0};
     bool mUpdateTexImageFailed{false};
 
+    uint64_t mPreviousBufferId = 0;
+    uint64_t mPreviousReleasedFrameNumber = 0;
+
     // Local copy of the queued contents of the incoming BufferQueue
     mutable Mutex mQueueItemLock;
     Condition mQueueItemCondition;
diff --git a/services/surfaceflinger/BufferStateLayer.cpp b/services/surfaceflinger/BufferStateLayer.cpp
index e0804ff..4a8261d 100644
--- a/services/surfaceflinger/BufferStateLayer.cpp
+++ b/services/surfaceflinger/BufferStateLayer.cpp
@@ -87,6 +87,14 @@
             break;
         }
     }
+
+    // Prevent tracing the same release multiple times.
+    if (mPreviousFrameNumber != mPreviousReleasedFrameNumber) {
+        mFlinger->mTimeStats->traceFence(getSequence(), mPreviousBufferId, mPreviousFrameNumber,
+                                         std::make_shared<FenceTime>(releaseFence),
+                                         TimeStats::FrameEvent::RELEASE_FENCE);
+        mPreviousReleasedFrameNumber = mPreviousFrameNumber;
+    }
 }
 
 void BufferStateLayer::setTransformHint(uint32_t /*orientation*/) const {
@@ -226,7 +234,11 @@
     mCurrentState.modified = true;
     setTransactionFlags(eTransactionNeeded);
 
-    mFlinger->mTimeStats->setPostTime(getSequence(), mFrameNumber, getName().c_str(), postTime);
+    const int32_t layerID = getSequence();
+    mFlinger->mTimeStats->setPostTime(layerID, mFrameNumber, getName().c_str(), postTime);
+    mFlinger->mTimeStats->traceNewLayer(layerID, getName().c_str());
+    mFlinger->mTimeStats->traceTimestamp(layerID, buffer->getId(), mFrameNumber, postTime,
+                                         TimeStats::FrameEvent::POST);
     mCurrentState.desiredPresentTime = desiredPresentTime;
 
     if (mFlinger->mUseSmart90ForVideo) {
@@ -561,8 +573,13 @@
         }
     }
 
+    const uint64_t bufferID = getCurrentBufferId();
     mFlinger->mTimeStats->setAcquireFence(layerID, mFrameNumber, getCurrentFenceTime());
+    mFlinger->mTimeStats->traceFence(layerID, bufferID, mFrameNumber, getCurrentFenceTime(),
+                                     TimeStats::FrameEvent::ACQUIRE_FENCE);
     mFlinger->mTimeStats->setLatchTime(layerID, mFrameNumber, latchTime);
+    mFlinger->mTimeStats->traceTimestamp(layerID, bufferID, mFrameNumber, latchTime,
+                                         TimeStats::FrameEvent::LATCH);
 
     mCurrentStateModified = false;
 
@@ -576,6 +593,7 @@
         return BAD_VALUE;
     }
 
+    mPreviousBufferId = getCurrentBufferId();
     mActiveBuffer = s.buffer;
     mActiveBufferFence = s.acquireFence;
     auto& layerCompositionState = getCompositionLayer()->editState().frontEnd;
@@ -586,6 +604,7 @@
 
 status_t BufferStateLayer::updateFrameNumber(nsecs_t /*latchTime*/) {
     // TODO(marissaw): support frame history events
+    mPreviousFrameNumber = mCurrentFrameNumber;
     mCurrentFrameNumber = mFrameNumber;
     return NO_ERROR;
 }
diff --git a/services/surfaceflinger/BufferStateLayer.h b/services/surfaceflinger/BufferStateLayer.h
index cc67008..c060ca8 100644
--- a/services/surfaceflinger/BufferStateLayer.h
+++ b/services/surfaceflinger/BufferStateLayer.h
@@ -156,6 +156,9 @@
     mutable uint32_t mFrameNumber{0};
 
     sp<Fence> mPreviousReleaseFence;
+    uint64_t mPreviousBufferId = 0;
+    uint64_t mPreviousFrameNumber = 0;
+    uint64_t mPreviousReleasedFrameNumber = 0;
 
     mutable bool mCurrentStateModified = false;
     bool mReleasePreviousBuffer = false;
diff --git a/services/surfaceflinger/Layer.h b/services/surfaceflinger/Layer.h
index 9107189..aa3970e 100644
--- a/services/surfaceflinger/Layer.h
+++ b/services/surfaceflinger/Layer.h
@@ -376,6 +376,14 @@
 
     int32_t getSequence() const { return sequence; }
 
+    // For tracing.
+    // TODO: Replace with raw buffer id from buffer metadata when that becomes available.
+    // GraphicBuffer::getId() does not provide a reliable global identifier. Since the traces
+    // creates its tracks by buffer id and has no way of associating a buffer back to the process
+    // that created it, the current implementation is only sufficient for cases where a buffer is
+    // only used within a single layer.
+    uint64_t getCurrentBufferId() const { return mActiveBuffer ? mActiveBuffer->getId() : 0; }
+
     // -----------------------------------------------------------------------
     // Virtuals
 
diff --git a/services/surfaceflinger/SurfaceFlinger.cpp b/services/surfaceflinger/SurfaceFlinger.cpp
index e804923..6543089 100644
--- a/services/surfaceflinger/SurfaceFlinger.cpp
+++ b/services/surfaceflinger/SurfaceFlinger.cpp
@@ -513,6 +513,8 @@
     const nsecs_t duration = now - mBootTime;
     ALOGI("Boot is finished (%ld ms)", long(ns2ms(duration)) );
 
+    mTimeStats->initializeTracing();
+
     // wait patiently for the window manager death
     const String16 name("window");
     mWindowManager = defaultServiceManager()->getService(name);
diff --git a/services/surfaceflinger/TimeStats/Android.bp b/services/surfaceflinger/TimeStats/Android.bp
new file mode 100644
index 0000000..9e1d503
--- /dev/null
+++ b/services/surfaceflinger/TimeStats/Android.bp
@@ -0,0 +1,15 @@
+cc_library_static {
+    name: "libtimestats",
+    defaults: ["surfaceflinger_defaults"],
+    srcs: [
+      "TimeStats.cpp"
+    ],
+    export_include_dirs: ["."],
+    static_libs: [
+      "libperfetto_client_experimental",
+    ],
+    shared_libs: [
+      "libtimestats_proto",
+      "libui",
+    ],
+}
diff --git a/services/surfaceflinger/TimeStats/TimeStats.cpp b/services/surfaceflinger/TimeStats/TimeStats.cpp
index 3e3ab18..b66e4cf 100644
--- a/services/surfaceflinger/TimeStats/TimeStats.cpp
+++ b/services/surfaceflinger/TimeStats/TimeStats.cpp
@@ -30,10 +30,141 @@
 #include <algorithm>
 #include <regex>
 
+PERFETTO_DEFINE_DATA_SOURCE_STATIC_MEMBERS(android::impl::TimeStats::TimeStatsDataSource);
+
 namespace android {
 
 namespace impl {
 
+void TimeStats::initializeTracing() {
+    perfetto::TracingInitArgs args;
+    args.backends = perfetto::kSystemBackend;
+    perfetto::Tracing::Initialize(args);
+    registerTracingDataSource();
+}
+
+void TimeStats::registerTracingDataSource() {
+    perfetto::DataSourceDescriptor dsd;
+    dsd.set_name(kTimeStatsDataSource);
+    TimeStatsDataSource::Register(dsd);
+}
+
+void TimeStats::traceNewLayer(int32_t layerID, const std::string& layerName) {
+    TimeStatsDataSource::Trace([this, layerID, &layerName](TimeStatsDataSource::TraceContext) {
+        if (mTraceTracker.find(layerID) == mTraceTracker.end()) {
+            std::lock_guard<std::mutex> lock(mTraceMutex);
+            mTraceTracker[layerID].layerName = layerName;
+        }
+    });
+}
+
+void TimeStats::traceTimestamp(int32_t layerID, uint64_t bufferID, uint64_t frameNumber,
+                               nsecs_t timestamp, FrameEvent::BufferEventType type,
+                               nsecs_t duration) {
+    TimeStatsDataSource::Trace([this, layerID, bufferID, frameNumber, timestamp, type,
+                                duration](TimeStatsDataSource::TraceContext ctx) {
+        std::lock_guard<std::mutex> lock(mTraceMutex);
+        if (mTraceTracker.find(layerID) == mTraceTracker.end()) {
+            return;
+        }
+
+        // Handle any pending fences for this buffer.
+        tracePendingFencesLocked(ctx, layerID, bufferID);
+
+        // Complete current trace.
+        traceLocked(ctx, layerID, bufferID, frameNumber, timestamp, type, duration);
+    });
+}
+
+void TimeStats::traceFence(int32_t layerID, uint64_t bufferID, uint64_t frameNumber,
+                           const std::shared_ptr<FenceTime>& fence,
+                           FrameEvent::BufferEventType type, nsecs_t startTime) {
+    TimeStatsDataSource::Trace([this, layerID, bufferID, frameNumber, &fence, type,
+                                startTime](TimeStatsDataSource::TraceContext ctx) {
+        const nsecs_t signalTime = fence->getSignalTime();
+        if (signalTime != Fence::SIGNAL_TIME_INVALID) {
+            std::lock_guard<std::mutex> lock(mTraceMutex);
+            if (mTraceTracker.find(layerID) == mTraceTracker.end()) {
+                return;
+            }
+
+            // Handle any pending fences for this buffer.
+            tracePendingFencesLocked(ctx, layerID, bufferID);
+
+            if (signalTime != Fence::SIGNAL_TIME_PENDING) {
+                traceSpanLocked(ctx, layerID, bufferID, frameNumber, type, startTime, signalTime);
+            } else {
+                mTraceTracker[layerID].pendingFences[bufferID].push_back(
+                        {.frameNumber = frameNumber,
+                         .type = type,
+                         .fence = fence,
+                         .startTime = startTime});
+            }
+        }
+    });
+}
+
+void TimeStats::tracePendingFencesLocked(TimeStatsDataSource::TraceContext& ctx, int32_t layerID,
+                                         uint64_t bufferID) {
+    if (mTraceTracker[layerID].pendingFences.count(bufferID)) {
+        auto& pendingFences = mTraceTracker[layerID].pendingFences[bufferID];
+        for (size_t i = 0; i < pendingFences.size(); ++i) {
+            auto& pendingFence = pendingFences[i];
+
+            nsecs_t signalTime = Fence::SIGNAL_TIME_INVALID;
+            if (pendingFence.fence && pendingFence.fence->isValid()) {
+                signalTime = pendingFence.fence->getSignalTime();
+                if (signalTime == Fence::SIGNAL_TIME_PENDING) {
+                    continue;
+                }
+            }
+
+            if (signalTime != Fence::SIGNAL_TIME_INVALID &&
+                systemTime() - signalTime < kFenceSignallingDeadline) {
+                traceSpanLocked(ctx, layerID, bufferID, pendingFence.frameNumber, pendingFence.type,
+                                pendingFence.startTime, signalTime);
+            }
+
+            pendingFences.erase(pendingFences.begin() + i);
+            --i;
+        }
+    }
+}
+
+void TimeStats::traceLocked(TimeStatsDataSource::TraceContext& ctx, int32_t layerID,
+                            uint64_t bufferID, uint64_t frameNumber, nsecs_t timestamp,
+                            FrameEvent::BufferEventType type, nsecs_t duration) {
+    auto packet = ctx.NewTracePacket();
+    packet->set_timestamp(timestamp);
+    auto* event = packet->set_graphics_frame_event()->set_buffer_event();
+    event->set_buffer_id(static_cast<uint32_t>(bufferID));
+    event->set_frame_number(frameNumber);
+    event->set_type(type);
+
+    if (mTraceTracker.find(layerID) != mTraceTracker.end() &&
+        !mTraceTracker[layerID].layerName.empty()) {
+        const std::string& layerName = mTraceTracker[layerID].layerName;
+        event->set_layer_name(layerName.c_str(), layerName.size());
+    }
+
+    if (duration > 0) {
+        event->set_duration_ns(duration);
+    }
+}
+
+void TimeStats::traceSpanLocked(TimeStatsDataSource::TraceContext& ctx, int32_t layerID,
+                                uint64_t bufferID, uint64_t frameNumber,
+                                FrameEvent::BufferEventType type, nsecs_t startTime,
+                                nsecs_t endTime) {
+    nsecs_t timestamp = endTime;
+    nsecs_t duration = 0;
+    if (startTime > 0 && startTime < endTime) {
+        timestamp = startTime;
+        duration = endTime - startTime;
+    }
+    traceLocked(ctx, layerID, bufferID, frameNumber, timestamp, type, duration);
+}
+
 void TimeStats::parseArgs(bool asProto, const Vector<String16>& args, std::string& result) {
     ATRACE_CALL();
 
@@ -76,6 +207,8 @@
                                  mTimeStatsTracker.size());
     android::base::StringAppendF(&result, "Number of layers in the stats pool is %zu\n",
                                  mTimeStats.stats.size());
+    android::base::StringAppendF(&result, "Number of layers currently being traced is %zu\n",
+                                 mTraceTracker.size());
     return result;
 }
 
@@ -407,14 +540,17 @@
 }
 
 void TimeStats::onDestroy(int32_t layerID) {
-    if (!mEnabled.load()) return;
-
     ATRACE_CALL();
     ALOGV("[%d]-onDestroy", layerID);
+    {
+        std::lock_guard<std::mutex> lock(mMutex);
+        mTimeStatsTracker.erase(layerID);
+    }
 
-    std::lock_guard<std::mutex> lock(mMutex);
-    if (!mTimeStatsTracker.count(layerID)) return;
-    mTimeStatsTracker.erase(layerID);
+    {
+        std::lock_guard<std::mutex> traceLock(mTraceMutex);
+        mTraceTracker.erase(layerID);
+    }
 }
 
 void TimeStats::removeTimeRecord(int32_t layerID, uint64_t frameNumber) {
diff --git a/services/surfaceflinger/TimeStats/TimeStats.h b/services/surfaceflinger/TimeStats/TimeStats.h
index eed7111..470137a 100644
--- a/services/surfaceflinger/TimeStats/TimeStats.h
+++ b/services/surfaceflinger/TimeStats/TimeStats.h
@@ -16,13 +16,12 @@
 
 #pragma once
 
+#include <hardware/hwcomposer_defs.h>
+#include <perfetto/trace/android/graphics_frame_event.pbzero.h>
+#include <perfetto/tracing.h>
 #include <timestatsproto/TimeStatsHelper.h>
 #include <timestatsproto/TimeStatsProtoHeader.h>
-
-#include <hardware/hwcomposer_defs.h>
-
 #include <ui/FenceTime.h>
-
 #include <utils/String16.h>
 #include <utils/Vector.h>
 
@@ -37,8 +36,32 @@
 
 class TimeStats {
 public:
+    using FrameEvent = perfetto::protos::pbzero::GraphicsFrameEvent;
+
     virtual ~TimeStats() = default;
 
+    // Sets up the perfetto tracing backend and data source.
+    virtual void initializeTracing() = 0;
+    // Registers the data source with the perfetto backend. Called as part of initializeTracing()
+    // and should not be called manually outside of tests. Public to allow for substituting a
+    // perfetto::kInProcessBackend in tests.
+    virtual void registerTracingDataSource() = 0;
+    // Starts tracking a new layer for tracing. Needs to be called once before traceTimestamp() or
+    // traceFence() for each layer.
+    virtual void traceNewLayer(int32_t layerID, const std::string& layerName) = 0;
+    // Creates a trace point at the timestamp provided.
+    virtual void traceTimestamp(int32_t layerID, uint64_t bufferID, uint64_t frameNumber,
+                                nsecs_t timestamp, FrameEvent::BufferEventType type,
+                                nsecs_t duration = 0) = 0;
+    // Creates a trace point after the provided fence has been signalled. If a startTime is provided
+    // the trace will have be timestamped from startTime until fence signalling time. If no
+    // startTime is provided, a durationless trace point will be created timestamped at fence
+    // signalling time. If the fence hasn't signalled yet, the trace point will be created the next
+    // time after signalling a trace call for this buffer occurs.
+    virtual void traceFence(int32_t layerID, uint64_t bufferID, uint64_t frameNumber,
+                            const std::shared_ptr<FenceTime>& fence,
+                            FrameEvent::BufferEventType type, nsecs_t startTime = 0) = 0;
+
     virtual void parseArgs(bool asProto, const Vector<String16>& args, std::string& result) = 0;
     virtual bool isEnabled() = 0;
     virtual std::string miniDump() = 0;
@@ -66,6 +89,13 @@
     // Source of truth is RefrehRateStats.
     virtual void recordRefreshRate(uint32_t fps, nsecs_t duration) = 0;
     virtual void setPresentFenceGlobal(const std::shared_ptr<FenceTime>& presentFence) = 0;
+
+    static constexpr char kTimeStatsDataSource[] = "android.surfaceflinger.timestats";
+
+    // The maximum amount of time a fence has to signal before it is discarded.
+    // Used to avoid fence's from previous traces generating new trace points in later ones.
+    // Public for testing.
+    static constexpr nsecs_t kFenceSignallingDeadline = 60'000'000'000; // 60 seconds
 };
 
 namespace impl {
@@ -87,6 +117,13 @@
         std::shared_ptr<FenceTime> presentFence;
     };
 
+    struct PendingFence {
+        uint64_t frameNumber;
+        FrameEvent::BufferEventType type;
+        std::shared_ptr<FenceTime> fence;
+        nsecs_t startTime;
+    };
+
     struct LayerRecord {
         std::string layerName;
         // This is the index in timeRecords, at which the timestamps for that
@@ -98,6 +135,12 @@
         std::deque<TimeRecord> timeRecords;
     };
 
+    struct TraceRecord {
+        std::string layerName;
+        using BufferID = uint64_t;
+        std::unordered_map<BufferID, std::vector<PendingFence>> pendingFences;
+    };
+
     struct PowerTime {
         int32_t powerMode = HWC_POWER_MODE_OFF;
         nsecs_t prevTime = 0;
@@ -109,8 +152,23 @@
     };
 
 public:
+    class TimeStatsDataSource : public perfetto::DataSource<TimeStatsDataSource> {
+        virtual void OnSetup(const SetupArgs&) override{};
+        virtual void OnStart(const StartArgs&) override { ALOGV("TimeStats trace started"); };
+        virtual void OnStop(const StopArgs&) override { ALOGV("TimeStats trace stopped"); };
+    };
+
     TimeStats() = default;
 
+    void initializeTracing() override;
+    void registerTracingDataSource() override;
+    void traceNewLayer(int32_t layerID, const std::string& layerName) override;
+    void traceTimestamp(int32_t layerID, uint64_t bufferID, uint64_t frameNumber, nsecs_t timestamp,
+                        FrameEvent::BufferEventType type, nsecs_t duration = 0) override;
+    void traceFence(int32_t layerID, uint64_t bufferID, uint64_t frameNumber,
+                    const std::shared_ptr<FenceTime>& fence, FrameEvent::BufferEventType type,
+                    nsecs_t startTime = 0) override;
+
     void parseArgs(bool asProto, const Vector<String16>& args, std::string& result) override;
     bool isEnabled() override;
     std::string miniDump() override;
@@ -142,6 +200,20 @@
     static const size_t MAX_NUM_TIME_RECORDS = 64;
 
 private:
+    // Checks if any pending fences for a layer and buffer have signalled and, if they have, creates
+    // trace points for them.
+    void tracePendingFencesLocked(TimeStatsDataSource::TraceContext& ctx, int32_t layerID,
+                                  uint64_t bufferID);
+    // Creates a trace point by translating a start time and an end time to a timestamp and
+    // duration. If startTime is later than end time it sets end time as the timestamp and the
+    // duration to 0. Used by traceFence().
+    void traceSpanLocked(TimeStatsDataSource::TraceContext& ctx, int32_t layerID, uint64_t bufferID,
+                         uint64_t frameNumber, FrameEvent::BufferEventType type, nsecs_t startTime,
+                         nsecs_t endTime);
+    void traceLocked(TimeStatsDataSource::TraceContext& ctx, int32_t layerID, uint64_t bufferID,
+                     uint64_t frameNumber, nsecs_t timestamp, FrameEvent::BufferEventType type,
+                     nsecs_t duration = 0);
+
     bool recordReadyLocked(int32_t layerID, TimeRecord* timeRecord);
     void flushAvailableRecordsToStatsLocked(int32_t layerID);
     void flushPowerTimeLocked();
@@ -160,6 +232,9 @@
     PowerTime mPowerTime;
     GlobalRecord mGlobalRecord;
 
+    std::mutex mTraceMutex;
+    std::unordered_map<int32_t, TraceRecord> mTraceTracker;
+
     static const size_t MAX_NUM_LAYER_RECORDS = 200;
     static const size_t MAX_NUM_LAYER_STATS = 200;
 };
diff --git a/services/surfaceflinger/tests/fakehwc/Android.bp b/services/surfaceflinger/tests/fakehwc/Android.bp
index 644cd7e..57851bc 100644
--- a/services/surfaceflinger/tests/fakehwc/Android.bp
+++ b/services/surfaceflinger/tests/fakehwc/Android.bp
@@ -34,7 +34,9 @@
     ],
     static_libs: [
         "libgmock",
+        "libperfetto_client_experimental",
         "librenderengine",
+        "libtimestats",
         "libtrace_proto",
     ],
     header_libs: [
diff --git a/services/surfaceflinger/tests/unittests/Android.bp b/services/surfaceflinger/tests/unittests/Android.bp
index 4917bc2..0eedf9b 100644
--- a/services/surfaceflinger/tests/unittests/Android.bp
+++ b/services/surfaceflinger/tests/unittests/Android.bp
@@ -36,7 +36,7 @@
         ":libsurfaceflinger_sources",
         "libsurfaceflinger_unittest_main.cpp",
         "CachingTest.cpp",
-	"CompositionTest.cpp",
+        "CompositionTest.cpp",
         "DispSyncSourceTest.cpp",
         "DisplayIdentificationTest.cpp",
         "DisplayTransactionTest.cpp",
@@ -69,7 +69,13 @@
         "libgmock",
         "libcompositionengine",
         "libcompositionengine_mocks",
+        "libperfetto_client_experimental",
         "librenderengine_mocks",
+        "libtimestats",
+        "perfetto_trace_protos",
+    ],
+    shared_libs: [
+        "libsurfaceflinger",
     ],
     header_libs: [
         "libsurfaceflinger_headers",
diff --git a/services/surfaceflinger/tests/unittests/TimeStatsTest.cpp b/services/surfaceflinger/tests/unittests/TimeStatsTest.cpp
index f35758d..f01e603 100644
--- a/services/surfaceflinger/tests/unittests/TimeStatsTest.cpp
+++ b/services/surfaceflinger/tests/unittests/TimeStatsTest.cpp
@@ -17,18 +17,17 @@
 #undef LOG_TAG
 #define LOG_TAG "LibSurfaceFlingerUnittests"
 
+#include <TimeStats/TimeStats.h>
 #include <gmock/gmock.h>
 #include <gtest/gtest.h>
-
 #include <log/log.h>
+#include <perfetto/trace/trace.pb.h>
 #include <utils/String16.h>
 #include <utils/Vector.h>
 
 #include <random>
 #include <unordered_set>
 
-#include "TimeStats/TimeStats.h"
-
 #include "libsurfaceflinger_unittest_main.h"
 
 using namespace android::surfaceflinger;
@@ -110,6 +109,15 @@
         const ::testing::TestInfo* const test_info =
                 ::testing::UnitTest::GetInstance()->current_test_info();
         ALOGD("**** Setting up for %s.%s\n", test_info->test_case_name(), test_info->name());
+
+        // Need to initialize tracing in process for testing, and only once per test suite.
+        static bool wasInitialized = false;
+        if (!wasInitialized) {
+            perfetto::TracingInitArgs args;
+            args.backends = perfetto::kInProcessBackend;
+            perfetto::Tracing::Initialize(args);
+            wasInitialized = true;
+        }
     }
 
     ~TimeStatsTest() {
@@ -118,6 +126,13 @@
         ALOGD("**** Tearing down after %s.%s\n", test_info->test_case_name(), test_info->name());
     }
 
+    void SetUp() override {
+        mTimeStats = std::make_unique<impl::TimeStats>();
+        mTimeStats->registerTracingDataSource();
+    }
+
+    void TearDown() override { mTimeStats.reset(); }
+
     std::string inputCommand(InputCommand cmd, bool useProto);
 
     void setTimeStamp(TimeStamp type, int32_t id, uint64_t frameNumber, nsecs_t ts);
@@ -132,8 +147,22 @@
         }
     }
 
+    // Each tracing session can be used for a single block of Start -> Stop.
+    static std::unique_ptr<perfetto::TracingSession> getTracingSessionForTest() {
+        perfetto::TraceConfig cfg;
+        cfg.set_duration_ms(500);
+        cfg.add_buffers()->set_size_kb(1024);
+        auto* ds_cfg = cfg.add_data_sources()->mutable_config();
+        ds_cfg->set_name(TimeStats::kTimeStatsDataSource);
+
+        auto tracingSession = perfetto::Tracing::NewTrace(perfetto::kInProcessBackend);
+        tracingSession->Setup(cfg);
+        return tracingSession;
+    }
+
     std::mt19937 mRandomEngine = std::mt19937(std::random_device()());
-    std::unique_ptr<TimeStats> mTimeStats = std::make_unique<impl::TimeStats>();
+    std::unique_ptr<TimeStats> mTimeStats;
+    FenceToFenceTimeMap fenceFactory;
 };
 
 std::string TimeStatsTest::inputCommand(InputCommand cmd, bool useProto) {
@@ -210,6 +239,330 @@
     return distr(mRandomEngine);
 }
 
+TEST_F(TimeStatsTest, traceNewLayerStartsTrackingLayerWhenTracing) {
+    EXPECT_EQ(mTimeStats->miniDump(),
+              "TimeStats miniDump:\nNumber of layers currently being tracked is 0\nNumber of "
+              "layers in the stats pool is 0\nNumber of layers currently being traced is 0\n");
+
+    const std::string layerName = "co.layername#0";
+    const int32_t layerID = 5;
+    mTimeStats->traceNewLayer(layerID, layerName);
+
+    EXPECT_EQ(mTimeStats->miniDump(),
+              "TimeStats miniDump:\nNumber of layers currently being tracked is 0\nNumber of "
+              "layers in the stats pool is 0\nNumber of layers currently being traced is 0\n");
+
+    auto tracingSession = getTracingSessionForTest();
+    tracingSession->StartBlocking();
+    EXPECT_EQ(mTimeStats->miniDump(),
+              "TimeStats miniDump:\nNumber of layers currently being tracked is 0\nNumber of "
+              "layers in the stats pool is 0\nNumber of layers currently being traced is 0\n");
+    mTimeStats->traceNewLayer(layerID, layerName);
+    EXPECT_EQ(mTimeStats->miniDump(),
+              "TimeStats miniDump:\nNumber of layers currently being tracked is 0\nNumber of "
+              "layers in the stats pool is 0\nNumber of layers currently being traced is 1\n");
+    tracingSession->StopBlocking();
+}
+
+TEST_F(TimeStatsTest, onDestroyRemovesTheTrackedLayer) {
+    EXPECT_EQ(mTimeStats->miniDump(),
+              "TimeStats miniDump:\nNumber of layers currently being tracked is 0\nNumber of "
+              "layers in the stats pool is 0\nNumber of layers currently being traced is 0\n");
+
+    const std::string layerName = "co.layername#0";
+    const int32_t layerID = 5;
+    const int32_t secondLayerID = 6;
+
+    auto tracingSession = getTracingSessionForTest();
+    tracingSession->StartBlocking();
+    mTimeStats->traceNewLayer(layerID, layerName);
+    mTimeStats->traceNewLayer(secondLayerID, layerName);
+    EXPECT_EQ(mTimeStats->miniDump(),
+              "TimeStats miniDump:\nNumber of layers currently being tracked is 0\nNumber of "
+              "layers in the stats pool is 0\nNumber of layers currently being traced is 2\n");
+    tracingSession->StopBlocking();
+
+    mTimeStats->onDestroy(layerID);
+    EXPECT_EQ(mTimeStats->miniDump(),
+              "TimeStats miniDump:\nNumber of layers currently being tracked is 0\nNumber of "
+              "layers in the stats pool is 0\nNumber of layers currently being traced is 1\n");
+    mTimeStats->onDestroy(layerID);
+    EXPECT_EQ(mTimeStats->miniDump(),
+              "TimeStats miniDump:\nNumber of layers currently being tracked is 0\nNumber of "
+              "layers in the stats pool is 0\nNumber of layers currently being traced is 1\n");
+    mTimeStats->onDestroy(secondLayerID);
+    EXPECT_EQ(mTimeStats->miniDump(),
+              "TimeStats miniDump:\nNumber of layers currently being tracked is 0\nNumber of "
+              "layers in the stats pool is 0\nNumber of layers currently being traced is 0\n");
+}
+
+TEST_F(TimeStatsTest, canTraceAfterAddingLayer) {
+    const std::string layerName = "co.layername#0";
+    const int32_t layerID = 1;
+    const uint32_t bufferID = 2;
+    const uint64_t frameNumber = 3;
+    const nsecs_t timestamp = 4;
+    const nsecs_t duration = 5;
+    const auto type = TimeStats::FrameEvent::POST;
+
+    {
+        auto tracingSession = getTracingSessionForTest();
+
+        tracingSession->StartBlocking();
+        // Clean up irrelevant traces.
+        tracingSession->ReadTraceBlocking();
+
+        mTimeStats->traceTimestamp(layerID, bufferID, frameNumber, timestamp, type, duration);
+        // Create second trace packet to finalize the previous one.
+        mTimeStats->traceTimestamp(layerID, 0, 0, 0, TimeStats::FrameEvent::UNSPECIFIED);
+        tracingSession->StopBlocking();
+
+        std::vector<char> raw_trace = tracingSession->ReadTraceBlocking();
+        EXPECT_EQ(raw_trace.size(), 0);
+    }
+
+    {
+        auto tracingSession = getTracingSessionForTest();
+
+        tracingSession->StartBlocking();
+        // Clean up irrelevant traces.
+        tracingSession->ReadTraceBlocking();
+
+        mTimeStats->traceNewLayer(layerID, layerName);
+        mTimeStats->traceTimestamp(layerID, bufferID, frameNumber, timestamp, type, duration);
+        // Create second trace packet to finalize the previous one.
+        mTimeStats->traceTimestamp(layerID, 0, 0, 0, TimeStats::FrameEvent::UNSPECIFIED);
+        tracingSession->StopBlocking();
+
+        std::vector<char> raw_trace = tracingSession->ReadTraceBlocking();
+        ASSERT_GT(raw_trace.size(), 0);
+
+        perfetto::protos::Trace trace;
+        ASSERT_TRUE(trace.ParseFromArray(raw_trace.data(), int(raw_trace.size())));
+        ASSERT_FALSE(trace.packet().empty());
+        EXPECT_EQ(trace.packet().size(), 1);
+
+        const auto& packet = trace.packet().Get(0);
+        ASSERT_TRUE(packet.has_timestamp());
+        EXPECT_EQ(packet.timestamp(), timestamp);
+        ASSERT_TRUE(packet.has_graphics_frame_event());
+        const auto& frame_event = packet.graphics_frame_event();
+        ASSERT_TRUE(frame_event.has_buffer_event());
+        const auto& buffer_event = frame_event.buffer_event();
+        ASSERT_TRUE(buffer_event.has_buffer_id());
+        EXPECT_EQ(buffer_event.buffer_id(), bufferID);
+        ASSERT_TRUE(buffer_event.has_frame_number());
+        EXPECT_EQ(buffer_event.frame_number(), frameNumber);
+        ASSERT_TRUE(buffer_event.has_type());
+        EXPECT_EQ(buffer_event.type(), perfetto::protos::GraphicsFrameEvent_BufferEventType(type));
+        ASSERT_TRUE(buffer_event.has_duration_ns());
+        EXPECT_EQ(buffer_event.duration_ns(), duration);
+    }
+}
+
+TEST_F(TimeStatsTest, traceFenceTriggersOnNextTraceAfterFenceFired) {
+    const std::string layerName = "co.layername#0";
+    const int32_t layerID = 5;
+    const uint32_t bufferID = 4;
+    const uint64_t frameNumber = 3;
+    const auto type = TimeStats::FrameEvent::ACQUIRE_FENCE;
+
+    {
+        auto fenceTime = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
+        fenceFactory.signalAllForTest(Fence::NO_FENCE, Fence::SIGNAL_TIME_PENDING);
+        auto tracingSession = getTracingSessionForTest();
+        tracingSession->StartBlocking();
+        // Clean up irrelevant traces.
+        tracingSession->ReadTraceBlocking();
+        // Trace.
+        mTimeStats->traceNewLayer(layerID, layerName);
+        mTimeStats->traceFence(layerID, bufferID, frameNumber, fenceTime, type);
+        // Create extra trace packet to (hopefully not) trigger and finalize the fence packet.
+        mTimeStats->traceTimestamp(layerID, bufferID, 0, 0, TimeStats::FrameEvent::UNSPECIFIED);
+        tracingSession->StopBlocking();
+        std::vector<char> raw_trace = tracingSession->ReadTraceBlocking();
+        EXPECT_EQ(raw_trace.size(), 0);
+    }
+
+    {
+        auto fenceTime = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
+        auto tracingSession = getTracingSessionForTest();
+        tracingSession->StartBlocking();
+        // Clean up irrelevant traces.
+        tracingSession->ReadTraceBlocking();
+        mTimeStats->traceNewLayer(layerID, layerName);
+        mTimeStats->traceFence(layerID, bufferID, frameNumber, fenceTime, type);
+        const nsecs_t timestamp = systemTime();
+        fenceFactory.signalAllForTest(Fence::NO_FENCE, timestamp);
+        // Create extra trace packet to trigger and finalize fence trace packets.
+        mTimeStats->traceTimestamp(layerID, bufferID, 0, 0, TimeStats::FrameEvent::UNSPECIFIED);
+        tracingSession->StopBlocking();
+
+        std::vector<char> raw_trace = tracingSession->ReadTraceBlocking();
+        ASSERT_GT(raw_trace.size(), 0);
+
+        perfetto::protos::Trace trace;
+        ASSERT_TRUE(trace.ParseFromArray(raw_trace.data(), int(raw_trace.size())));
+        ASSERT_FALSE(trace.packet().empty());
+        EXPECT_EQ(trace.packet().size(), 2); // Two packets because of the extra trace made above.
+
+        const auto& packet = trace.packet().Get(1);
+        ASSERT_TRUE(packet.has_timestamp());
+        EXPECT_EQ(packet.timestamp(), timestamp);
+        ASSERT_TRUE(packet.has_graphics_frame_event());
+        const auto& frame_event = packet.graphics_frame_event();
+        ASSERT_TRUE(frame_event.has_buffer_event());
+        const auto& buffer_event = frame_event.buffer_event();
+        ASSERT_TRUE(buffer_event.has_buffer_id());
+        EXPECT_EQ(buffer_event.buffer_id(), bufferID);
+        ASSERT_TRUE(buffer_event.has_frame_number());
+        EXPECT_EQ(buffer_event.frame_number(), frameNumber);
+        ASSERT_TRUE(buffer_event.has_type());
+        EXPECT_EQ(buffer_event.type(), perfetto::protos::GraphicsFrameEvent_BufferEventType(type));
+        EXPECT_FALSE(buffer_event.has_duration_ns());
+    }
+}
+
+TEST_F(TimeStatsTest, traceFenceWithStartTimeAfterSignalTime_ShouldHaveNoDuration) {
+    const std::string layerName = "co.layername#0";
+    const int32_t layerID = 5;
+    const uint32_t bufferID = 4;
+    const uint64_t frameNumber = 3;
+    const auto type = TimeStats::FrameEvent::ACQUIRE_FENCE;
+
+    auto tracingSession = getTracingSessionForTest();
+
+    tracingSession->StartBlocking();
+    // Clean up irrelevant traces.
+    tracingSession->ReadTraceBlocking();
+    mTimeStats->traceNewLayer(layerID, layerName);
+
+    // traceFence called after fence signalled.
+    const nsecs_t signalTime1 = systemTime();
+    const nsecs_t startTime1 = signalTime1 + 100000;
+    auto fence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
+    fenceFactory.signalAllForTest(Fence::NO_FENCE, signalTime1);
+    mTimeStats->traceFence(layerID, bufferID, frameNumber, fence1, type, startTime1);
+
+    // traceFence called before fence signalled.
+    const nsecs_t signalTime2 = systemTime();
+    const nsecs_t startTime2 = signalTime2 + 100000;
+    auto fence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
+    mTimeStats->traceFence(layerID, bufferID, frameNumber, fence2, type, startTime2);
+    fenceFactory.signalAllForTest(Fence::NO_FENCE, signalTime2);
+
+    // Create extra trace packet to trigger and finalize fence trace packets.
+    mTimeStats->traceTimestamp(layerID, bufferID, 0, 0, TimeStats::FrameEvent::UNSPECIFIED);
+    tracingSession->StopBlocking();
+
+    std::vector<char> raw_trace = tracingSession->ReadTraceBlocking();
+    ASSERT_GT(raw_trace.size(), 0);
+
+    perfetto::protos::Trace trace;
+    ASSERT_TRUE(trace.ParseFromArray(raw_trace.data(), int(raw_trace.size())));
+    ASSERT_FALSE(trace.packet().empty());
+    EXPECT_EQ(trace.packet().size(), 2);
+
+    const auto& packet1 = trace.packet().Get(0);
+    ASSERT_TRUE(packet1.has_timestamp());
+    EXPECT_EQ(packet1.timestamp(), signalTime1);
+    ASSERT_TRUE(packet1.has_graphics_frame_event());
+    ASSERT_TRUE(packet1.graphics_frame_event().has_buffer_event());
+    ASSERT_FALSE(packet1.graphics_frame_event().buffer_event().has_duration_ns());
+
+    const auto& packet2 = trace.packet().Get(1);
+    ASSERT_TRUE(packet2.has_timestamp());
+    EXPECT_EQ(packet2.timestamp(), signalTime2);
+    ASSERT_TRUE(packet2.has_graphics_frame_event());
+    ASSERT_TRUE(packet2.graphics_frame_event().has_buffer_event());
+    ASSERT_FALSE(packet2.graphics_frame_event().buffer_event().has_duration_ns());
+}
+
+TEST_F(TimeStatsTest, traceFenceOlderThanDeadline_ShouldBeIgnored) {
+    const std::string layerName = "co.layername#0";
+    const int32_t layerID = 5;
+    const uint32_t bufferID = 4;
+    const uint64_t frameNumber = 3;
+    const auto type = TimeStats::FrameEvent::ACQUIRE_FENCE;
+    const nsecs_t signalTime = systemTime() - TimeStats::kFenceSignallingDeadline;
+
+    auto tracingSession = getTracingSessionForTest();
+    auto fence = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
+
+    tracingSession->StartBlocking();
+    // Clean up irrelevant traces.
+    tracingSession->ReadTraceBlocking();
+    mTimeStats->traceNewLayer(layerID, layerName);
+    mTimeStats->traceFence(layerID, bufferID, frameNumber, fence, type);
+    fenceFactory.signalAllForTest(Fence::NO_FENCE, signalTime);
+    // Create extra trace packet to trigger and finalize any previous fence packets.
+    mTimeStats->traceTimestamp(layerID, bufferID, 0, 0, TimeStats::FrameEvent::UNSPECIFIED);
+    tracingSession->StopBlocking();
+
+    std::vector<char> raw_trace = tracingSession->ReadTraceBlocking();
+    EXPECT_EQ(raw_trace.size(), 0);
+}
+
+TEST_F(TimeStatsTest, traceFenceWithValidStartTime_ShouldHaveCorrectDuration) {
+    const std::string layerName = "co.layername#0";
+    const int32_t layerID = 5;
+    const uint32_t bufferID = 4;
+    const uint64_t frameNumber = 3;
+    const auto type = TimeStats::FrameEvent::ACQUIRE_FENCE;
+    const nsecs_t duration = 1234;
+
+    auto tracingSession = getTracingSessionForTest();
+
+    tracingSession->StartBlocking();
+    // Clean up irrelevant traces.
+    tracingSession->ReadTraceBlocking();
+    mTimeStats->traceNewLayer(layerID, layerName);
+
+    // traceFence called after fence signalled.
+    const nsecs_t signalTime1 = systemTime();
+    const nsecs_t startTime1 = signalTime1 - duration;
+    auto fence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
+    fenceFactory.signalAllForTest(Fence::NO_FENCE, signalTime1);
+    mTimeStats->traceFence(layerID, bufferID, frameNumber, fence1, type, startTime1);
+
+    // traceFence called before fence signalled.
+    const nsecs_t signalTime2 = systemTime();
+    const nsecs_t startTime2 = signalTime2 - duration;
+    auto fence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE);
+    mTimeStats->traceFence(layerID, bufferID, frameNumber, fence2, type, startTime2);
+    fenceFactory.signalAllForTest(Fence::NO_FENCE, signalTime2);
+
+    // Create extra trace packet to trigger and finalize fence trace packets.
+    mTimeStats->traceTimestamp(layerID, bufferID, 0, 0, TimeStats::FrameEvent::UNSPECIFIED);
+    tracingSession->StopBlocking();
+
+    std::vector<char> raw_trace = tracingSession->ReadTraceBlocking();
+    ASSERT_GT(raw_trace.size(), 0);
+
+    perfetto::protos::Trace trace;
+    ASSERT_TRUE(trace.ParseFromArray(raw_trace.data(), int(raw_trace.size())));
+    ASSERT_FALSE(trace.packet().empty());
+    EXPECT_EQ(trace.packet().size(), 2);
+
+    const auto& packet1 = trace.packet().Get(0);
+    ASSERT_TRUE(packet1.has_timestamp());
+    EXPECT_EQ(packet1.timestamp(), startTime1);
+    ASSERT_TRUE(packet1.has_graphics_frame_event());
+    ASSERT_TRUE(packet1.graphics_frame_event().has_buffer_event());
+    ASSERT_TRUE(packet1.graphics_frame_event().buffer_event().has_duration_ns());
+    const auto& buffer_event1 = packet1.graphics_frame_event().buffer_event();
+    EXPECT_EQ(buffer_event1.duration_ns(), duration);
+
+    const auto& packet2 = trace.packet().Get(1);
+    ASSERT_TRUE(packet2.has_timestamp());
+    EXPECT_EQ(packet2.timestamp(), startTime2);
+    ASSERT_TRUE(packet2.has_graphics_frame_event());
+    ASSERT_TRUE(packet2.graphics_frame_event().has_buffer_event());
+    ASSERT_TRUE(packet2.graphics_frame_event().buffer_event().has_duration_ns());
+    const auto& buffer_event2 = packet2.graphics_frame_event().buffer_event();
+    EXPECT_EQ(buffer_event2.duration_ns(), duration);
+}
+
 TEST_F(TimeStatsTest, canEnableAndDisableTimeStats) {
     EXPECT_TRUE(inputCommand(InputCommand::ENABLE, FMT_STRING).empty());
     ASSERT_TRUE(mTimeStats->isEnabled());
diff --git a/services/surfaceflinger/tests/unittests/mock/MockTimeStats.h b/services/surfaceflinger/tests/unittests/mock/MockTimeStats.h
index b1634a8..542c70a 100644
--- a/services/surfaceflinger/tests/unittests/mock/MockTimeStats.h
+++ b/services/surfaceflinger/tests/unittests/mock/MockTimeStats.h
@@ -28,6 +28,14 @@
     TimeStats();
     ~TimeStats() override;
 
+    MOCK_METHOD0(initializeTracing, void());
+    MOCK_METHOD0(registerTracingDataSource, void());
+    MOCK_METHOD2(traceNewLayer, void(int32_t, const std::string&));
+    MOCK_METHOD6(traceTimestamp,
+                 void(int32_t, uint64_t, uint64_t, nsecs_t, FrameEvent::BufferEventType, nsecs_t));
+    MOCK_METHOD6(traceFence,
+                 void(int32_t, uint64_t, uint64_t, const std::shared_ptr<FenceTime>&,
+                      FrameEvent::BufferEventType, nsecs_t));
     MOCK_METHOD3(parseArgs, void(bool, const Vector<String16>&, std::string&));
     MOCK_METHOD0(isEnabled, bool());
     MOCK_METHOD0(miniDump, std::string());