diff options
| author | 2020-12-03 01:59:48 +0000 | |
|---|---|---|
| committer | 2020-12-03 01:59:48 +0000 | |
| commit | 78b977d4d99092c20b43e01951089fc1401fc1e9 (patch) | |
| tree | d8fc3d5fc7d24595d536d63e4e8373f044448e23 | |
| parent | 7e2bbfa24aa4c88ead367ade153c258a167aed91 (diff) | |
| parent | 011896785509a2beb8ef7238a1572aaedae0c703 (diff) | |
Merge "Frame Timeline Perfetto producer"
12 files changed, 611 insertions, 21 deletions
diff --git a/services/surfaceflinger/FrameTimeline/Android.bp b/services/surfaceflinger/FrameTimeline/Android.bp index e075d3e1a0..1e6d21efe7 100644 --- a/services/surfaceflinger/FrameTimeline/Android.bp +++ b/services/surfaceflinger/FrameTimeline/Android.bp @@ -14,5 +14,8 @@ cc_library_static { "libui", "libutils", ], + static_libs: [ + "libperfetto_client_experimental", + ], export_include_dirs: ["."], } diff --git a/services/surfaceflinger/FrameTimeline/FrameTimeline.cpp b/services/surfaceflinger/FrameTimeline/FrameTimeline.cpp index bd87482dc6..ef5f5ad414 100644 --- a/services/surfaceflinger/FrameTimeline/FrameTimeline.cpp +++ b/services/surfaceflinger/FrameTimeline/FrameTimeline.cpp @@ -29,6 +29,7 @@ namespace android::frametimeline::impl { using base::StringAppendF; +using FrameTimelineEvent = perfetto::protos::pbzero::FrameTimelineEvent; void dumpTable(std::string& result, TimelineItem predictions, TimelineItem actuals, const std::string& indent, PredictionState predictionState, nsecs_t baseTime) { @@ -143,6 +144,32 @@ std::string jankMetadataBitmaskToString(int32_t jankMetadata) { }); } +FrameTimelineEvent::PresentType presentTypeToProto(int32_t jankMetadata) { + if (jankMetadata & EarlyPresent) { + return FrameTimelineEvent::PRESENT_EARLY; + } + if (jankMetadata & LatePresent) { + return FrameTimelineEvent::PRESENT_LATE; + } + return FrameTimelineEvent::PRESENT_ON_TIME; +} + +FrameTimelineEvent::JankType JankTypeToProto(TimeStats::JankType jankType) { + switch (jankType) { + case TimeStats::None: + return FrameTimelineEvent::JANK_NONE; + case TimeStats::Display: + return FrameTimelineEvent::JANK_DISPLAY_HAL; + case TimeStats::SurfaceFlingerDeadlineMissed: + return FrameTimelineEvent::JANK_SF_DEADLINE_MISSED; + case TimeStats::AppDeadlineMissed: + case TimeStats::PredictionExpired: + return FrameTimelineEvent::JANK_APP_DEADLINE_MISSED; + default: + return FrameTimelineEvent::JANK_UNKNOWN; + } +} + int64_t TokenManager::generateTokenForPredictions(TimelineItem&& predictions) { ATRACE_CALL(); std::lock_guard<std::mutex> lock(mMutex); @@ -177,10 +204,11 @@ void TokenManager::flushTokens(nsecs_t flushTime) { } } -SurfaceFrame::SurfaceFrame(pid_t ownerPid, uid_t ownerUid, std::string layerName, +SurfaceFrame::SurfaceFrame(int64_t token, pid_t ownerPid, uid_t ownerUid, std::string layerName, std::string debugName, PredictionState predictionState, frametimeline::TimelineItem&& predictions) - : mOwnerPid(ownerPid), + : mToken(token), + mOwnerPid(ownerPid), mOwnerUid(ownerUid), mLayerName(std::move(layerName)), mDebugName(std::move(debugName)), @@ -291,17 +319,70 @@ void SurfaceFrame::dump(std::string& result, const std::string& indent, nsecs_t dumpTable(result, mPredictions, mActuals, indent, mPredictionState, baseTime); } +void SurfaceFrame::traceSurfaceFrame(int64_t displayFrameToken) { + using FrameTimelineDataSource = FrameTimeline::FrameTimelineDataSource; + FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) { + std::lock_guard<std::mutex> lock(mMutex); + if (mToken == ISurfaceComposer::INVALID_VSYNC_ID) { + ALOGD("Cannot trace SurfaceFrame - %s with invalid token", mLayerName.c_str()); + return; + } else if (displayFrameToken == ISurfaceComposer::INVALID_VSYNC_ID) { + ALOGD("Cannot trace SurfaceFrame - %s with invalid displayFrameToken", + mLayerName.c_str()); + return; + } + auto packet = ctx.NewTracePacket(); + packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC); + packet->set_timestamp(static_cast<uint64_t>(systemTime())); + + auto* event = packet->set_frame_timeline_event(); + auto* surfaceFrameEvent = event->set_surface_frame(); + + surfaceFrameEvent->set_token(mToken); + surfaceFrameEvent->set_display_frame_token(displayFrameToken); + + if (mPresentState == PresentState::Dropped) { + surfaceFrameEvent->set_present_type(FrameTimelineEvent::PRESENT_DROPPED); + } else if (mPresentState == PresentState::Unknown) { + surfaceFrameEvent->set_present_type(FrameTimelineEvent::PRESENT_UNSPECIFIED); + } else { + surfaceFrameEvent->set_present_type(presentTypeToProto(mJankMetadata)); + } + surfaceFrameEvent->set_on_time_finish(!(mJankMetadata & LateFinish)); + surfaceFrameEvent->set_gpu_composition(mJankMetadata & GpuComposition); + surfaceFrameEvent->set_jank_type(JankTypeToProto(mJankType)); + + surfaceFrameEvent->set_expected_start_ns(mPredictions.startTime); + surfaceFrameEvent->set_expected_end_ns(mPredictions.endTime); + + surfaceFrameEvent->set_actual_start_ns(mActuals.startTime); + surfaceFrameEvent->set_actual_end_ns(mActuals.endTime); + + surfaceFrameEvent->set_layer_name(mDebugName); + surfaceFrameEvent->set_pid(mOwnerPid); + }); +} + FrameTimeline::FrameTimeline(std::shared_ptr<TimeStats> timeStats) : mCurrentDisplayFrame(std::make_shared<DisplayFrame>()), mMaxDisplayFrames(kDefaultMaxDisplayFrames), mTimeStats(std::move(timeStats)) {} +void FrameTimeline::onBootFinished() { + perfetto::TracingInitArgs args; + args.backends = perfetto::kSystemBackend; + perfetto::Tracing::Initialize(args); + registerDataSource(); +} + +void FrameTimeline::registerDataSource() { + perfetto::DataSourceDescriptor dsd; + dsd.set_name(kFrameTimelineDataSource); + FrameTimelineDataSource::Register(dsd); +} + FrameTimeline::DisplayFrame::DisplayFrame() - : surfaceFlingerPredictions(TimelineItem()), - surfaceFlingerActuals(TimelineItem()), - predictionState(PredictionState::None), - jankType(TimeStats::JankType::None), - jankMetadata(0) { + : surfaceFlingerPredictions(TimelineItem()), surfaceFlingerActuals(TimelineItem()) { this->surfaceFrames.reserve(kNumSurfaceFramesInitial); } @@ -310,17 +391,19 @@ std::unique_ptr<android::frametimeline::SurfaceFrame> FrameTimeline::createSurfa std::optional<int64_t> token) { ATRACE_CALL(); if (!token) { - return std::make_unique<impl::SurfaceFrame>(ownerPid, ownerUid, std::move(layerName), + return std::make_unique<impl::SurfaceFrame>(ISurfaceComposer::INVALID_VSYNC_ID, ownerPid, + ownerUid, std::move(layerName), std::move(debugName), PredictionState::None, TimelineItem()); } std::optional<TimelineItem> predictions = mTokenManager.getPredictionsForToken(*token); if (predictions) { - return std::make_unique<impl::SurfaceFrame>(ownerPid, ownerUid, std::move(layerName), - std::move(debugName), PredictionState::Valid, + return std::make_unique<impl::SurfaceFrame>(*token, ownerPid, ownerUid, + std::move(layerName), std::move(debugName), + PredictionState::Valid, std::move(*predictions)); } - return std::make_unique<impl::SurfaceFrame>(ownerPid, ownerUid, std::move(layerName), + return std::make_unique<impl::SurfaceFrame>(*token, ownerPid, ownerUid, std::move(layerName), std::move(debugName), PredictionState::Expired, TimelineItem()); } @@ -340,6 +423,7 @@ void FrameTimeline::setSfWakeUp(int64_t token, nsecs_t wakeUpTime) { ATRACE_CALL(); const std::optional<TimelineItem> prediction = mTokenManager.getPredictionsForToken(token); std::lock_guard<std::mutex> lock(mMutex); + mCurrentDisplayFrame->token = token; if (!prediction) { mCurrentDisplayFrame->predictionState = PredictionState::Expired; } else { @@ -408,6 +492,7 @@ void FrameTimeline::flushPendingPresentFences() { } totalJankReasons |= displayFrame->jankType; + traceDisplayFrame(*displayFrame); for (auto& surfaceFrame : displayFrame->surfaceFrames) { if (surfaceFrame->getPresentState() == SurfaceFrame::PresentState::Presented) { @@ -419,7 +504,6 @@ void FrameTimeline::flushPendingPresentFences() { if (predictionState == PredictionState::Expired) { // Jank analysis cannot be done on apps that don't use predictions surfaceFrame->setJankInfo(TimeStats::JankType::PredictionExpired, 0); - continue; } else if (predictionState == PredictionState::Valid) { const auto& actuals = surfaceFrame->getActuals(); const auto& predictions = surfaceFrame->getPredictions(); @@ -453,6 +537,7 @@ void FrameTimeline::flushPendingPresentFences() { surfaceFrame->setJankInfo(jankType, jankMetadata); } } + surfaceFrame->traceSurfaceFrame(displayFrame->token); } mTimeStats->incrementJankyFrames(totalJankReasons); @@ -569,4 +654,31 @@ void FrameTimeline::reset() { setMaxDisplayFrames(kDefaultMaxDisplayFrames); } +void FrameTimeline::traceDisplayFrame(const DisplayFrame& displayFrame) { + FrameTimelineDataSource::Trace([&](FrameTimelineDataSource::TraceContext ctx) { + if (displayFrame.token == ISurfaceComposer::INVALID_VSYNC_ID) { + ALOGD("Cannot trace DisplayFrame with invalid token"); + return; + } + auto packet = ctx.NewTracePacket(); + packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_MONOTONIC); + packet->set_timestamp(static_cast<uint64_t>(systemTime())); + + auto* event = packet->set_frame_timeline_event(); + auto* displayFrameEvent = event->set_display_frame(); + + displayFrameEvent->set_token(displayFrame.token); + displayFrameEvent->set_present_type(presentTypeToProto(displayFrame.jankMetadata)); + displayFrameEvent->set_on_time_finish(!(displayFrame.jankMetadata & LateFinish)); + displayFrameEvent->set_gpu_composition(displayFrame.jankMetadata & GpuComposition); + displayFrameEvent->set_jank_type(JankTypeToProto(displayFrame.jankType)); + + displayFrameEvent->set_expected_start_ns(displayFrame.surfaceFlingerPredictions.startTime); + displayFrameEvent->set_expected_end_ns(displayFrame.surfaceFlingerPredictions.endTime); + + displayFrameEvent->set_actual_start_ns(displayFrame.surfaceFlingerActuals.startTime); + displayFrameEvent->set_actual_end_ns(displayFrame.surfaceFlingerActuals.endTime); + }); +} + } // namespace android::frametimeline::impl diff --git a/services/surfaceflinger/FrameTimeline/FrameTimeline.h b/services/surfaceflinger/FrameTimeline/FrameTimeline.h index e61567ecae..9a74d508ed 100644 --- a/services/surfaceflinger/FrameTimeline/FrameTimeline.h +++ b/services/surfaceflinger/FrameTimeline/FrameTimeline.h @@ -18,6 +18,8 @@ #include <../TimeStats/TimeStats.h> #include <gui/ISurfaceComposer.h> +#include <perfetto/trace/android/frame_timeline_event.pbzero.h> +#include <perfetto/tracing.h> #include <ui/FenceTime.h> #include <utils/RefBase.h> #include <utils/String16.h> @@ -128,6 +130,10 @@ public: virtual ~FrameTimeline() = default; virtual TokenManager* getTokenManager() = 0; + // Initializes the Perfetto DataSource that emits DisplayFrame and SurfaceFrame events. Test + // classes can avoid double registration by mocking this function. + virtual void onBootFinished() = 0; + // Create a new surface frame, set the predictions based on a token and return it to the caller. // Sets the PredictionState of SurfaceFrame. // Debug name is the human-readable debugging string for dumpsys. @@ -191,8 +197,9 @@ private: class SurfaceFrame : public android::frametimeline::SurfaceFrame { public: - SurfaceFrame(pid_t ownerPid, uid_t ownerUid, std::string layerName, std::string debugName, - PredictionState predictionState, TimelineItem&& predictions); + SurfaceFrame(int64_t token, pid_t ownerPid, uid_t ownerUid, std::string layerName, + std::string debugName, PredictionState predictionState, + TimelineItem&& predictions); ~SurfaceFrame() = default; TimelineItem getPredictions() const override { return mPredictions; }; @@ -202,6 +209,7 @@ public: PredictionState getPredictionState() const override { return mPredictionState; }; pid_t getOwnerPid() const override { return mOwnerPid; }; TimeStats::JankType getJankType() const; + int64_t getToken() const { return mToken; }; nsecs_t getBaseTime() const; uid_t getOwnerUid() const { return mOwnerUid; }; const std::string& getName() const { return mLayerName; }; @@ -216,7 +224,13 @@ public: // All the timestamps are dumped relative to the baseTime void dump(std::string& result, const std::string& indent, nsecs_t baseTime); + // Emits a packet for perfetto tracing. The function body will be executed only if tracing is + // enabled. The displayFrameToken is needed to link the SurfaceFrame to the corresponding + // DisplayFrame at the trace processor side. + void traceSurfaceFrame(int64_t displayFrameToken); + private: + const int64_t mToken; const pid_t mOwnerPid; const uid_t mOwnerUid; const std::string mLayerName; @@ -233,6 +247,12 @@ private: class FrameTimeline : public android::frametimeline::FrameTimeline { public: + class FrameTimelineDataSource : public perfetto::DataSource<FrameTimelineDataSource> { + void OnSetup(const SetupArgs&) override{}; + void OnStart(const StartArgs&) override{}; + void OnStop(const StopArgs&) override{}; + }; + FrameTimeline(std::shared_ptr<TimeStats> timeStats); ~FrameTimeline() = default; @@ -249,6 +269,14 @@ public: void setMaxDisplayFrames(uint32_t size) override; void reset() override; + // Sets up the perfetto tracing backend and data source. + void onBootFinished() override; + // Registers the data source with the perfetto backend. Called as part of onBootFinished() + // and should not be called manually outside of tests. + void registerDataSource(); + + static constexpr char kFrameTimelineDataSource[] = "android.surfaceflinger.frametimeline"; + private: // Friend class for testing friend class android::frametimeline::FrameTimelineTest; @@ -259,6 +287,8 @@ private: struct DisplayFrame { DisplayFrame(); + int64_t token = ISurfaceComposer::INVALID_VSYNC_ID; + /* Usage of TimelineItem w.r.t SurfaceFlinger * startTime Time when SurfaceFlinger wakes up to handle transactions and buffer updates * endTime Time when SurfaceFlinger sends a composited frame to Display @@ -270,9 +300,9 @@ private: // Collection of predictions and actual values sent over by Layers std::vector<std::unique_ptr<SurfaceFrame>> surfaceFrames; - PredictionState predictionState; + PredictionState predictionState = PredictionState::None; TimeStats::JankType jankType = TimeStats::JankType::None; // Enum for the type of jank - int32_t jankMetadata = 0x0; // Additional details about the jank + int32_t jankMetadata = 0x0; // Additional details about the jank }; void flushPendingPresentFences() REQUIRES(mMutex); @@ -285,6 +315,10 @@ private: void dumpAll(std::string& result); void dumpJank(std::string& result); + // Emits a packet for perfetto tracing. The function body will be executed only if tracing is + // enabled. + void traceDisplayFrame(const DisplayFrame& displayFrame) REQUIRES(mMutex); + // Sliding window of display frames. TODO(b/168072834): compare perf with fixed size array std::deque<std::shared_ptr<DisplayFrame>> mDisplayFrames GUARDED_BY(mMutex); std::vector<std::pair<std::shared_ptr<FenceTime>, std::shared_ptr<DisplayFrame>>> @@ -295,10 +329,10 @@ private: uint32_t mMaxDisplayFrames; std::shared_ptr<TimeStats> mTimeStats; static constexpr uint32_t kDefaultMaxDisplayFrames = 64; - // The initial container size for the vector<SurfaceFrames> inside display frame. Although this - // number doesn't represent any bounds on the number of surface frames that can go in a display - // frame, this is a good starting size for the vector so that we can avoid the internal vector - // resizing that happens with push_back. + // The initial container size for the vector<SurfaceFrames> inside display frame. Although + // this number doesn't represent any bounds on the number of surface frames that can go in a + // display frame, this is a good starting size for the vector so that we can avoid the + // internal vector resizing that happens with push_back. static constexpr uint32_t kNumSurfaceFramesInitial = 10; // The various thresholds for App and SF. If the actual timestamp falls within the threshold // compared to prediction, we don't treat it as a jank. diff --git a/services/surfaceflinger/SurfaceFlinger.cpp b/services/surfaceflinger/SurfaceFlinger.cpp index 576bd5083f..773b3ab54d 100644 --- a/services/surfaceflinger/SurfaceFlinger.cpp +++ b/services/surfaceflinger/SurfaceFlinger.cpp @@ -331,7 +331,7 @@ SurfaceFlinger::SurfaceFlinger(Factory& factory, SkipInitializationTag) mInterceptor(mFactory.createSurfaceInterceptor()), mTimeStats(std::make_shared<impl::TimeStats>()), mFrameTracer(mFactory.createFrameTracer()), - mFrameTimeline(std::make_unique<frametimeline::impl::FrameTimeline>(mTimeStats)), + mFrameTimeline(mFactory.createFrameTimeline(mTimeStats)), mEventQueue(mFactory.createMessageQueue()), mCompositionEngine(mFactory.createCompositionEngine()), mInternalDisplayDensity(getDensityFromProperty("ro.sf.lcd_density", true)), @@ -621,6 +621,7 @@ void SurfaceFlinger::bootFinished() { mFrameTracer->initialize(); mTimeStats->onBootFinished(); + mFrameTimeline->onBootFinished(); // wait patiently for the window manager death const String16 name("window"); diff --git a/services/surfaceflinger/SurfaceFlingerDefaultFactory.cpp b/services/surfaceflinger/SurfaceFlingerDefaultFactory.cpp index a93f5f631f..bc487ac1fd 100644 --- a/services/surfaceflinger/SurfaceFlingerDefaultFactory.cpp +++ b/services/surfaceflinger/SurfaceFlingerDefaultFactory.cpp @@ -134,6 +134,12 @@ sp<EffectLayer> DefaultFactory::createEffectLayer(const LayerCreationArgs& args) std::unique_ptr<FrameTracer> DefaultFactory::createFrameTracer() { return std::make_unique<FrameTracer>(); } + +std::unique_ptr<frametimeline::FrameTimeline> DefaultFactory::createFrameTimeline( + std::shared_ptr<TimeStats> timeStats) { + return std::make_unique<frametimeline::impl::FrameTimeline>(timeStats); +} + } // namespace android::surfaceflinger // TODO(b/129481165): remove the #pragma below and fix conversion issues diff --git a/services/surfaceflinger/SurfaceFlingerDefaultFactory.h b/services/surfaceflinger/SurfaceFlingerDefaultFactory.h index 90032d48b4..fc45fa9d64 100644 --- a/services/surfaceflinger/SurfaceFlingerDefaultFactory.h +++ b/services/surfaceflinger/SurfaceFlingerDefaultFactory.h @@ -55,6 +55,8 @@ public: sp<EffectLayer> createEffectLayer(const LayerCreationArgs& args) override; sp<ContainerLayer> createContainerLayer(const LayerCreationArgs& args) override; std::unique_ptr<FrameTracer> createFrameTracer() override; + std::unique_ptr<frametimeline::FrameTimeline> createFrameTimeline( + std::shared_ptr<TimeStats> timeStats) override; }; } // namespace android::surfaceflinger diff --git a/services/surfaceflinger/SurfaceFlingerFactory.h b/services/surfaceflinger/SurfaceFlingerFactory.h index 69e9c3ca29..deb1b526a0 100644 --- a/services/surfaceflinger/SurfaceFlingerFactory.h +++ b/services/surfaceflinger/SurfaceFlingerFactory.h @@ -45,6 +45,7 @@ class Scheduler; class StartPropertySetThread; class SurfaceFlinger; class SurfaceInterceptor; +class TimeStats; struct DisplayDeviceCreationArgs; struct ISchedulerCallback; @@ -60,6 +61,10 @@ class VsyncController; class RefreshRateConfigs; } // namespace scheduler +namespace frametimeline { +class FrameTimeline; +} // namespace frametimeline + namespace surfaceflinger { class NativeWindowSurface; @@ -102,6 +107,8 @@ public: virtual sp<EffectLayer> createEffectLayer(const LayerCreationArgs& args) = 0; virtual sp<ContainerLayer> createContainerLayer(const LayerCreationArgs& args) = 0; virtual std::unique_ptr<FrameTracer> createFrameTracer() = 0; + virtual std::unique_ptr<frametimeline::FrameTimeline> createFrameTimeline( + std::shared_ptr<TimeStats> timeStats) = 0; protected: ~Factory() = default; diff --git a/services/surfaceflinger/tests/unittests/Android.bp b/services/surfaceflinger/tests/unittests/Android.bp index 7427e27487..871222c8b0 100644 --- a/services/surfaceflinger/tests/unittests/Android.bp +++ b/services/surfaceflinger/tests/unittests/Android.bp @@ -83,6 +83,7 @@ cc_test { "mock/DisplayHardware/MockDisplay.cpp", "mock/DisplayHardware/MockPowerAdvisor.cpp", "mock/MockEventThread.cpp", + "mock/MockFrameTimeline.cpp", "mock/MockFrameTracer.cpp", "mock/MockMessageQueue.cpp", "mock/MockNativeWindowSurface.cpp", diff --git a/services/surfaceflinger/tests/unittests/FrameTimelineTest.cpp b/services/surfaceflinger/tests/unittests/FrameTimelineTest.cpp index 03c6f70db5..cb617d6e71 100644 --- a/services/surfaceflinger/tests/unittests/FrameTimelineTest.cpp +++ b/services/surfaceflinger/tests/unittests/FrameTimelineTest.cpp @@ -22,10 +22,16 @@ #include <FrameTimeline/FrameTimeline.h> #include <gtest/gtest.h> #include <log/log.h> +#include <perfetto/trace/trace.pb.h> #include <cinttypes> using namespace std::chrono_literals; using testing::Contains; +using FrameTimelineEvent = perfetto::protos::FrameTimelineEvent; +using ProtoDisplayFrame = perfetto::protos::FrameTimelineEvent_DisplayFrame; +using ProtoSurfaceFrame = perfetto::protos::FrameTimelineEvent_SurfaceFrame; +using ProtoPresentType = perfetto::protos::FrameTimelineEvent_PresentType; +using ProtoJankType = perfetto::protos::FrameTimelineEvent_JankType; MATCHER_P(HasBit, bit, "") { return (arg & bit) != 0; @@ -47,14 +53,56 @@ public: ALOGD("**** Tearing down after %s.%s\n", test_info->test_case_name(), test_info->name()); } + static void SetUpTestSuite() { + // Need to initialize tracing in process for testing, and only once per test suite. + perfetto::TracingInitArgs args; + args.backends = perfetto::kInProcessBackend; + perfetto::Tracing::Initialize(args); + } + void SetUp() override { mTimeStats = std::make_shared<mock::TimeStats>(); mFrameTimeline = std::make_unique<impl::FrameTimeline>(mTimeStats); + mFrameTimeline->registerDataSource(); mTokenManager = &mFrameTimeline->mTokenManager; maxDisplayFrames = &mFrameTimeline->mMaxDisplayFrames; maxTokenRetentionTime = mTokenManager->kMaxRetentionTime; } + // 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(impl::FrameTimeline::kFrameTimelineDataSource); + + auto tracingSession = perfetto::Tracing::NewTrace(perfetto::kInProcessBackend); + tracingSession->Setup(cfg); + return tracingSession; + } + + std::vector<perfetto::protos::TracePacket> readFrameTimelinePacketsBlocking( + perfetto::TracingSession* tracingSession) { + std::vector<char> raw_trace = tracingSession->ReadTraceBlocking(); + perfetto::protos::Trace trace; + EXPECT_TRUE(trace.ParseFromArray(raw_trace.data(), int(raw_trace.size()))); + + std::vector<perfetto::protos::TracePacket> packets; + for (const auto& packet : trace.packet()) { + if (!packet.has_frame_timeline_event()) { + continue; + } + packets.emplace_back(packet); + } + return packets; + } + + void addEmptyDisplayFrame() { + auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE); + mFrameTimeline->setSfPresent(2500, presentFence1); + } + void flushTokens(nsecs_t flushTime) { std::lock_guard<std::mutex> lock(mTokenManager->mMutex); mTokenManager->flushTokens(flushTime); @@ -413,4 +461,308 @@ TEST_F(FrameTimelineTest, presentFenceSignaled_reportsAppMiss) { presentFence1); } +/* + * Tracing Tests + * + * Trace packets are flushed all the way only when the next packet is traced. + * For example: trace<Display/Surface>Frame() will create a TracePacket but not flush it. Only when + * another TracePacket is created, the previous one is guaranteed to be flushed. The following tests + * will have additional empty frames created for this reason. + */ +TEST_F(FrameTimelineTest, tracing_noPacketsSentWithoutTraceStart) { + auto tracingSession = getTracingSessionForTest(); + auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE); + auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE); + + int64_t token1 = mTokenManager->generateTokenForPredictions({10, 20, 30}); + int64_t token2 = mTokenManager->generateTokenForPredictions({40, 50, 60}); + auto surfaceFrame1 = mFrameTimeline->createSurfaceFrameForToken(sPidOne, sUidOne, sLayerNameOne, + sLayerNameOne, token1); + + // Set up the display frame + mFrameTimeline->setSfWakeUp(token1, 20); + mFrameTimeline->addSurfaceFrame(std::move(surfaceFrame1), SurfaceFrame::PresentState::Dropped); + mFrameTimeline->setSfPresent(25, presentFence1); + presentFence1->signalForTest(30); + + // Trigger a flushPresentFence (which will call trace function) by calling setSfPresent for the + // next frame + mFrameTimeline->setSfWakeUp(token2, 50); + mFrameTimeline->setSfPresent(55, presentFence2); + + auto packets = readFrameTimelinePacketsBlocking(tracingSession.get()); + EXPECT_EQ(packets.size(), 0); +} + +TEST_F(FrameTimelineTest, tracing_sanityTest) { + auto tracingSession = getTracingSessionForTest(); + auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE); + auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE); + + tracingSession->StartBlocking(); + int64_t token1 = mTokenManager->generateTokenForPredictions({10, 20, 30}); + int64_t token2 = mTokenManager->generateTokenForPredictions({40, 50, 60}); + auto surfaceFrame1 = mFrameTimeline->createSurfaceFrameForToken(sPidOne, sUidOne, sLayerNameOne, + sLayerNameOne, token1); + + // Set up the display frame + mFrameTimeline->setSfWakeUp(token2, 20); + mFrameTimeline->addSurfaceFrame(std::move(surfaceFrame1), + SurfaceFrame::PresentState::Presented); + mFrameTimeline->setSfPresent(25, presentFence1); + presentFence1->signalForTest(30); + + // Trigger a flushPresentFence (which will call trace function) by calling setSfPresent for the + // next frame + mFrameTimeline->setSfWakeUp(token2, 50); + mFrameTimeline->setSfPresent(55, presentFence2); + presentFence2->signalForTest(55); + + // The SurfaceFrame packet from the first frame is emitted, but not flushed yet. Emitting a new + // packet will flush it. To emit a new packet, we'll need to call flushPendingPresentFences() + // again, which is done by setSfPresent(). + addEmptyDisplayFrame(); + tracingSession->StopBlocking(); + + auto packets = readFrameTimelinePacketsBlocking(tracingSession.get()); + // Display Frame 1 has two packets - DisplayFrame and a SurfaceFrame. + // Display Frame 2 has one packet - DisplayFrame. However, this packet has been emitted but not + // flushed through traced, so this is not counted. + EXPECT_EQ(packets.size(), 2); +} + +TEST_F(FrameTimelineTest, traceDisplayFrame_invalidTokenDoesNotEmitTracePacket) { + auto tracingSession = getTracingSessionForTest(); + auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE); + auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE); + + tracingSession->StartBlocking(); + int64_t token1 = mTokenManager->generateTokenForPredictions({10, 20, 30}); + + // Set up the display frame + mFrameTimeline->setSfWakeUp(-1, 20); + mFrameTimeline->setSfPresent(25, presentFence1); + presentFence1->signalForTest(30); + + // Trigger a flushPresentFence (which will call trace function) by calling setSfPresent for the + // next frame + mFrameTimeline->setSfWakeUp(token1, 50); + mFrameTimeline->setSfPresent(55, presentFence2); + presentFence2->signalForTest(60); + + addEmptyDisplayFrame(); + tracingSession->StopBlocking(); + + auto packets = readFrameTimelinePacketsBlocking(tracingSession.get()); + // Display Frame 1 has no packets. + // Display Frame 2 has one packet - DisplayFrame. However, this packet has + // been emitted but not flushed through traced, so this is not counted. + EXPECT_EQ(packets.size(), 0); +} + +TEST_F(FrameTimelineTest, traceSurfaceFrame_invalidTokenDoesNotEmitTracePacket) { + auto tracingSession = getTracingSessionForTest(); + auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE); + auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE); + + tracingSession->StartBlocking(); + int64_t token1 = mTokenManager->generateTokenForPredictions({10, 20, 30}); + int64_t token2 = mTokenManager->generateTokenForPredictions({40, 50, 60}); + auto surfaceFrame1 = mFrameTimeline->createSurfaceFrameForToken(sPidOne, sUidOne, sLayerNameOne, + sLayerNameOne, std::nullopt); + + // Set up the display frame + mFrameTimeline->setSfWakeUp(token1, 20); + mFrameTimeline->addSurfaceFrame(std::move(surfaceFrame1), SurfaceFrame::PresentState::Dropped); + mFrameTimeline->setSfPresent(25, presentFence1); + presentFence1->signalForTest(30); + + // Trigger a flushPresentFence (which will call trace function) by calling setSfPresent for the + // next frame + mFrameTimeline->setSfWakeUp(token2, 50); + mFrameTimeline->setSfPresent(55, presentFence2); + presentFence2->signalForTest(60); + + addEmptyDisplayFrame(); + tracingSession->StopBlocking(); + + auto packets = readFrameTimelinePacketsBlocking(tracingSession.get()); + // Display Frame 1 has one packet - DisplayFrame (SurfaceFrame shouldn't be traced since it has + // an invalid token). + // Display Frame 2 has one packet - DisplayFrame. However, this packet has + // been emitted but not flushed through traced, so this is not counted. + EXPECT_EQ(packets.size(), 1); +} + +void validateDisplayFrameEvent(const ProtoDisplayFrame& received, const ProtoDisplayFrame& source) { + ASSERT_TRUE(received.has_token()); + EXPECT_EQ(received.token(), source.token()); + + ASSERT_TRUE(received.has_present_type()); + EXPECT_EQ(received.present_type(), source.present_type()); + ASSERT_TRUE(received.has_on_time_finish()); + EXPECT_EQ(received.on_time_finish(), source.on_time_finish()); + ASSERT_TRUE(received.has_gpu_composition()); + EXPECT_EQ(received.gpu_composition(), source.gpu_composition()); + ASSERT_TRUE(received.has_jank_type()); + EXPECT_EQ(received.jank_type(), source.jank_type()); + + ASSERT_TRUE(received.has_expected_start_ns()); + EXPECT_EQ(received.expected_start_ns(), source.expected_start_ns()); + ASSERT_TRUE(received.has_expected_end_ns()); + EXPECT_EQ(received.expected_end_ns(), source.expected_end_ns()); + + ASSERT_TRUE(received.has_actual_start_ns()); + EXPECT_EQ(received.actual_start_ns(), source.actual_start_ns()); + ASSERT_TRUE(received.has_actual_end_ns()); + EXPECT_EQ(received.actual_end_ns(), source.actual_end_ns()); +} + +void validateSurfaceFrameEvent(const ProtoSurfaceFrame& received, const ProtoSurfaceFrame& source) { + ASSERT_TRUE(received.has_token()); + EXPECT_EQ(received.token(), source.token()); + + ASSERT_TRUE(received.has_display_frame_token()); + EXPECT_EQ(received.display_frame_token(), source.display_frame_token()); + + ASSERT_TRUE(received.has_present_type()); + EXPECT_EQ(received.present_type(), source.present_type()); + ASSERT_TRUE(received.has_on_time_finish()); + EXPECT_EQ(received.on_time_finish(), source.on_time_finish()); + ASSERT_TRUE(received.has_gpu_composition()); + EXPECT_EQ(received.gpu_composition(), source.gpu_composition()); + ASSERT_TRUE(received.has_jank_type()); + EXPECT_EQ(received.jank_type(), source.jank_type()); + + ASSERT_TRUE(received.has_expected_start_ns()); + EXPECT_EQ(received.expected_start_ns(), source.expected_start_ns()); + ASSERT_TRUE(received.has_expected_end_ns()); + EXPECT_EQ(received.expected_end_ns(), source.expected_end_ns()); + + ASSERT_TRUE(received.has_actual_start_ns()); + EXPECT_EQ(received.actual_start_ns(), source.actual_start_ns()); + ASSERT_TRUE(received.has_actual_end_ns()); + EXPECT_EQ(received.actual_end_ns(), source.actual_end_ns()); + + ASSERT_TRUE(received.has_layer_name()); + EXPECT_EQ(received.layer_name(), source.layer_name()); + ASSERT_TRUE(received.has_pid()); + EXPECT_EQ(received.pid(), source.pid()); +} + +TEST_F(FrameTimelineTest, traceDisplayFrame_emitsValidTracePacket) { + auto tracingSession = getTracingSessionForTest(); + auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE); + auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE); + + tracingSession->StartBlocking(); + int64_t displayFrameToken1 = mTokenManager->generateTokenForPredictions({10, 25, 30}); + int64_t displayFrameToken2 = mTokenManager->generateTokenForPredictions({40, 50, 60}); + + // Set up the display frame + mFrameTimeline->setSfWakeUp(displayFrameToken1, 20); + mFrameTimeline->setSfPresent(26, presentFence1); + presentFence1->signalForTest(31); + + ProtoDisplayFrame protoDisplayFrame; + protoDisplayFrame.set_token(displayFrameToken1); + protoDisplayFrame.set_present_type(ProtoPresentType(FrameTimelineEvent::PRESENT_ON_TIME)); + protoDisplayFrame.set_on_time_finish(true); + protoDisplayFrame.set_gpu_composition(false); + protoDisplayFrame.set_jank_type(ProtoJankType(FrameTimelineEvent::JANK_NONE)); + protoDisplayFrame.set_expected_start_ns(10); + protoDisplayFrame.set_expected_end_ns(25); + protoDisplayFrame.set_actual_start_ns(20); + protoDisplayFrame.set_actual_end_ns(26); + + // Trigger a flushPresentFence (which will call trace function) by calling setSfPresent for the + // next frame + mFrameTimeline->setSfWakeUp(displayFrameToken2, 50); + mFrameTimeline->setSfPresent(55, presentFence2); + presentFence2->signalForTest(55); + + addEmptyDisplayFrame(); + tracingSession->StopBlocking(); + + auto packets = readFrameTimelinePacketsBlocking(tracingSession.get()); + // Display Frame 1 has one packet - DisplayFrame. + // Display Frame 2 has one packet - DisplayFrame. However, this packet has been emitted but not + // flushed through traced, so this is not counted. + EXPECT_EQ(packets.size(), 1); + + const auto& packet = packets[0]; + ASSERT_TRUE(packet.has_timestamp()); + ASSERT_TRUE(packet.has_frame_timeline_event()); + + const auto& event = packet.frame_timeline_event(); + ASSERT_TRUE(event.has_display_frame()); + ASSERT_FALSE(event.has_surface_frame()); + const auto& displayFrameEvent = event.display_frame(); + validateDisplayFrameEvent(displayFrameEvent, protoDisplayFrame); +} + +TEST_F(FrameTimelineTest, traceSurfaceFrame_emitsValidTracePacket) { + auto tracingSession = getTracingSessionForTest(); + auto presentFence1 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE); + auto presentFence2 = fenceFactory.createFenceTimeForTest(Fence::NO_FENCE); + + tracingSession->StartBlocking(); + int64_t surfaceFrameToken = mTokenManager->generateTokenForPredictions({10, 25, 40}); + int64_t displayFrameToken1 = mTokenManager->generateTokenForPredictions({30, 35, 40}); + int64_t displayFrameToken2 = mTokenManager->generateTokenForPredictions({40, 50, 60}); + + auto surfaceFrame1 = + mFrameTimeline->createSurfaceFrameForToken(sPidOne, sUidOne, sLayerNameOne, + sLayerNameOne, surfaceFrameToken); + surfaceFrame1->setActualStartTime(0); + surfaceFrame1->setActualQueueTime(15); + surfaceFrame1->setAcquireFenceTime(20); + + ProtoSurfaceFrame protoSurfaceFrame; + protoSurfaceFrame.set_token(surfaceFrameToken); + protoSurfaceFrame.set_display_frame_token(displayFrameToken1); + protoSurfaceFrame.set_present_type(ProtoPresentType(FrameTimelineEvent::PRESENT_ON_TIME)); + protoSurfaceFrame.set_on_time_finish(true); + protoSurfaceFrame.set_gpu_composition(false); + protoSurfaceFrame.set_jank_type(ProtoJankType(FrameTimelineEvent::JANK_NONE)); + protoSurfaceFrame.set_expected_start_ns(10); + protoSurfaceFrame.set_expected_end_ns(25); + protoSurfaceFrame.set_actual_start_ns(0); + protoSurfaceFrame.set_actual_end_ns(20); + protoSurfaceFrame.set_layer_name(sLayerNameOne); + protoSurfaceFrame.set_pid(sPidOne); + + // Set up the display frame + mFrameTimeline->setSfWakeUp(displayFrameToken1, 20); + mFrameTimeline->addSurfaceFrame(std::move(surfaceFrame1), + SurfaceFrame::PresentState::Presented); + mFrameTimeline->setSfPresent(26, presentFence1); + presentFence1->signalForTest(31); + + // Trigger a flushPresentFence (which will call trace function) by calling setSfPresent for the + // next frame + mFrameTimeline->setSfWakeUp(displayFrameToken2, 50); + mFrameTimeline->setSfPresent(55, presentFence2); + presentFence2->signalForTest(55); + + addEmptyDisplayFrame(); + tracingSession->StopBlocking(); + + auto packets = readFrameTimelinePacketsBlocking(tracingSession.get()); + // Display Frame 1 has one packet - DisplayFrame and a SurfaceFrame. + // Display Frame 2 has one packet - DisplayFrame. However, this packet has been emitted but not + // flushed through traced, so this is not counted. + EXPECT_EQ(packets.size(), 2); + + const auto& packet = packets[1]; + ASSERT_TRUE(packet.has_timestamp()); + ASSERT_TRUE(packet.has_frame_timeline_event()); + + const auto& event = packet.frame_timeline_event(); + ASSERT_TRUE(!event.has_display_frame()); + ASSERT_TRUE(event.has_surface_frame()); + const auto& surfaceFrameEvent = event.surface_frame(); + validateSurfaceFrameEvent(surfaceFrameEvent, protoSurfaceFrame); +} + } // namespace android::frametimeline diff --git a/services/surfaceflinger/tests/unittests/TestableSurfaceFlinger.h b/services/surfaceflinger/tests/unittests/TestableSurfaceFlinger.h index 8a0276ac86..c0de465668 100644 --- a/services/surfaceflinger/tests/unittests/TestableSurfaceFlinger.h +++ b/services/surfaceflinger/tests/unittests/TestableSurfaceFlinger.h @@ -42,6 +42,7 @@ #include "TestableScheduler.h" #include "mock/DisplayHardware/MockDisplay.h" #include "mock/MockDisplayIdGenerator.h" +#include "mock/MockFrameTimeline.h" #include "mock/MockFrameTracer.h" namespace android { @@ -154,6 +155,11 @@ public: return std::make_unique<mock::FrameTracer>(); } + std::unique_ptr<frametimeline::FrameTimeline> createFrameTimeline( + std::shared_ptr<TimeStats> timeStats) override { + return std::make_unique<mock::FrameTimeline>(timeStats); + } + using CreateBufferQueueFunction = std::function<void(sp<IGraphicBufferProducer>* /* outProducer */, sp<IGraphicBufferConsumer>* /* outConsumer */, diff --git a/services/surfaceflinger/tests/unittests/mock/MockFrameTimeline.cpp b/services/surfaceflinger/tests/unittests/mock/MockFrameTimeline.cpp new file mode 100644 index 0000000000..f784df3049 --- /dev/null +++ b/services/surfaceflinger/tests/unittests/mock/MockFrameTimeline.cpp @@ -0,0 +1,26 @@ +/* + * Copyright 2020 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. + */ + +#include "mock/MockFrameTimeline.h" + +namespace android::mock { + +// Explicit default instantiation is recommended. +FrameTimeline::FrameTimeline(std::shared_ptr<TimeStats> timeStats) + : android::frametimeline::impl::FrameTimeline(timeStats) {} +FrameTimeline::~FrameTimeline() = default; + +} // namespace android::mock diff --git a/services/surfaceflinger/tests/unittests/mock/MockFrameTimeline.h b/services/surfaceflinger/tests/unittests/mock/MockFrameTimeline.h new file mode 100644 index 0000000000..81c32fe08a --- /dev/null +++ b/services/surfaceflinger/tests/unittests/mock/MockFrameTimeline.h @@ -0,0 +1,40 @@ +/* + * Copyright 2020 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. + */ + +#pragma once + +#include <gmock/gmock.h> + +#include "FrameTimeline/FrameTimeline.h" + +namespace android::mock { + +class FrameTimeline : public android::frametimeline::impl::FrameTimeline { + // No need to create mocks for SurfaceFrame and TokenManager yet. They are very small components + // and do not have external dependencies like perfetto. +public: + FrameTimeline(std::shared_ptr<TimeStats> timeStats); + ~FrameTimeline(); + + MOCK_METHOD0(onBootFinished, void()); + MOCK_METHOD2(addSurfaceFrame, + void(std::unique_ptr<frametimeline::SurfaceFrame>, + frametimeline::SurfaceFrame::PresentState)); + MOCK_METHOD2(setSfWakeUp, void(int64_t, nsecs_t)); + MOCK_METHOD2(setSfPresent, void(nsecs_t, const std::shared_ptr<FenceTime>&)); +}; + +} // namespace android::mock |