commit 9243bba2e7b770100ea76757ec9843d14cc7d31c
author Ady Abraham <adyabr@google.com> Fri Feb 10 15:31:14 2023 -0800
committer Ady Abraham <adyabr@google.com> Sat Feb 11 00:10:51 2023 +0000
tree 40fdc5c50231e865842923f383182a62ae9efd53
parent 87602ee3571ea617c62053f247027544cddd9c7a

SF: add traces for isVsyncValid

Add more debug information for isVsyncValid

Bug: 267780202
Test: manual
Change-Id: I84bc750cf490a4d04a5d86915367da4bf6681f8c

services/surfaceflinger/Scheduler/VSyncPredictor.cpp

diff --git a/services/surfaceflinger/Scheduler/VSyncPredictor.cpp b/services/surfaceflinger/Scheduler/VSyncPredictor.cpp
index 02e12fd..f8cb323 100644
--- a/services/surfaceflinger/Scheduler/VSyncPredictor.cpp
+++ b/services/surfaceflinger/Scheduler/VSyncPredictor.cpp
@@ -31,8 +31,8 @@
 #include <android-base/stringprintf.h>
 #include <cutils/compiler.h>
 #include <cutils/properties.h>
+#include <gui/TraceUtils.h>
 #include <utils/Log.h>
-#include <utils/Trace.h>
 
 #include "RefreshRateSelector.h"
 #include "VSyncPredictor.h"
@@ -282,6 +282,13 @@
 }
 
 bool VSyncPredictor::isVSyncInPhaseLocked(nsecs_t timePoint, unsigned divisor) const {
+    const TimePoint now = TimePoint::now();
+    const auto getTimePointIn = [](TimePoint now, nsecs_t timePoint) -> float {
+        return ticks<std::milli, float>(TimePoint::fromNs(timePoint) - now);
+    };
+    ATRACE_FORMAT("%s timePoint in: %.2f divisor: %zu", __func__, getTimePointIn(now, timePoint),
+                  divisor);
+
     struct VsyncError {
         nsecs_t vsyncTimestamp;
         float error;
@@ -304,6 +311,7 @@
     if (knownTimestampIter == mRateDivisorKnownTimestampMap.end()) {
         const auto vsync = nextAnticipatedVSyncTimeFromLocked(justBeforeTimePoint);
         mRateDivisorKnownTimestampMap[dividedPeriod] = vsync;
+        ATRACE_FORMAT_INSTANT("(first) knownVsync in: %.2f", getTimePointIn(now, vsync));
         return true;
     }
 
@@ -323,6 +331,8 @@
 
     const auto minVsyncError = std::min_element(vsyncs.begin(), vsyncs.end());
     mRateDivisorKnownTimestampMap[dividedPeriod] = minVsyncError->vsyncTimestamp;
+    ATRACE_FORMAT_INSTANT("knownVsync in: %.2f",
+                          getTimePointIn(now, minVsyncError->vsyncTimestamp));
     return std::abs(minVsyncError->vsyncTimestamp - timePoint) < period / 2;
 }