SF: Move DispSync systrace logging to shell variable.
screenshot: https://screenshot.googleplex.com/Jo0r6yus6HL
Test: SF tests pass.
Change-Id: I0703507b32648a7afc840811cebf994cc528d9a5
diff --git a/services/surfaceflinger/Scheduler/DispSync.cpp b/services/surfaceflinger/Scheduler/DispSync.cpp
index a12ae83..cba9181 100644
--- a/services/surfaceflinger/Scheduler/DispSync.cpp
+++ b/services/surfaceflinger/Scheduler/DispSync.cpp
@@ -44,10 +44,6 @@
namespace impl {
-// Setting this to true enables verbose tracing that can be used to debug
-// vsync event model or phase issues.
-static const bool kTraceDetailedInfo = false;
-
// Setting this to true adds a zero-phase tracer for correlating with hardware
// vsync events
static const bool kEnableZeroPhaseTracer = false;
@@ -62,19 +58,20 @@
#define LOG_TAG "DispSyncThread"
class DispSyncThread : public Thread {
public:
- explicit DispSyncThread(const char* name)
+ DispSyncThread(const char* name, bool showTraceDetailedInfo)
: mName(name),
mStop(false),
mPeriod(0),
mPhase(0),
mReferenceTime(0),
mWakeupLatency(0),
- mFrameNumber(0) {}
+ mFrameNumber(0),
+ mTraceDetailedInfo(showTraceDetailedInfo) {}
virtual ~DispSyncThread() {}
void updateModel(nsecs_t period, nsecs_t phase, nsecs_t referenceTime) {
- if (kTraceDetailedInfo) ATRACE_CALL();
+ if (mTraceDetailedInfo) ATRACE_CALL();
Mutex::Autolock lock(mMutex);
mPeriod = period;
mPhase = phase;
@@ -86,7 +83,7 @@
}
void stop() {
- if (kTraceDetailedInfo) ATRACE_CALL();
+ if (mTraceDetailedInfo) ATRACE_CALL();
Mutex::Autolock lock(mMutex);
mStop = true;
mCond.signal();
@@ -104,7 +101,7 @@
{ // Scope for lock
Mutex::Autolock lock(mMutex);
- if (kTraceDetailedInfo) {
+ if (mTraceDetailedInfo) {
ATRACE_INT64("DispSync:Frame", mFrameNumber);
}
ALOGV("[%s] Frame %" PRId64, mName, mFrameNumber);
@@ -128,7 +125,7 @@
bool isWakeup = false;
if (now < targetTime) {
- if (kTraceDetailedInfo) ATRACE_NAME("DispSync waiting");
+ if (mTraceDetailedInfo) ATRACE_NAME("DispSync waiting");
if (targetTime == INT64_MAX) {
ALOGV("[%s] Waiting forever", mName);
@@ -154,7 +151,7 @@
if (isWakeup) {
mWakeupLatency = ((mWakeupLatency * 63) + (now - targetTime)) / 64;
mWakeupLatency = min(mWakeupLatency, kMaxWakeupLatency);
- if (kTraceDetailedInfo) {
+ if (mTraceDetailedInfo) {
ATRACE_INT64("DispSync:WakeupLat", now - targetTime);
ATRACE_INT64("DispSync:AvgWakeupLat", mWakeupLatency);
}
@@ -172,7 +169,7 @@
}
status_t addEventListener(const char* name, nsecs_t phase, DispSync::Callback* callback) {
- if (kTraceDetailedInfo) ATRACE_CALL();
+ if (mTraceDetailedInfo) ATRACE_CALL();
Mutex::Autolock lock(mMutex);
for (size_t i = 0; i < mEventListeners.size(); i++) {
@@ -198,7 +195,7 @@
}
status_t removeEventListener(DispSync::Callback* callback) {
- if (kTraceDetailedInfo) ATRACE_CALL();
+ if (mTraceDetailedInfo) ATRACE_CALL();
Mutex::Autolock lock(mMutex);
for (std::vector<EventListener>::iterator it = mEventListeners.begin();
@@ -214,7 +211,7 @@
}
status_t changePhaseOffset(DispSync::Callback* callback, nsecs_t phase) {
- if (kTraceDetailedInfo) ATRACE_CALL();
+ if (mTraceDetailedInfo) ATRACE_CALL();
Mutex::Autolock lock(mMutex);
for (auto& eventListener : mEventListeners) {
@@ -254,7 +251,7 @@
};
nsecs_t computeNextEventTimeLocked(nsecs_t now) {
- if (kTraceDetailedInfo) ATRACE_CALL();
+ if (mTraceDetailedInfo) ATRACE_CALL();
ALOGV("[%s] computeNextEventTimeLocked", mName);
nsecs_t nextEventTime = INT64_MAX;
for (size_t i = 0; i < mEventListeners.size(); i++) {
@@ -270,7 +267,7 @@
}
std::vector<CallbackInvocation> gatherCallbackInvocationsLocked(nsecs_t now) {
- if (kTraceDetailedInfo) ATRACE_CALL();
+ if (mTraceDetailedInfo) ATRACE_CALL();
ALOGV("[%s] gatherCallbackInvocationsLocked @ %" PRId64, mName, ns2us(now));
std::vector<CallbackInvocation> callbackInvocations;
@@ -293,7 +290,7 @@
}
nsecs_t computeListenerNextEventTimeLocked(const EventListener& listener, nsecs_t baseTime) {
- if (kTraceDetailedInfo) ATRACE_CALL();
+ if (mTraceDetailedInfo) ATRACE_CALL();
ALOGV("[%s] [%s] computeListenerNextEventTimeLocked(%" PRId64 ")", mName, listener.mName,
ns2us(baseTime));
@@ -344,7 +341,7 @@
}
void fireCallbackInvocations(const std::vector<CallbackInvocation>& callbacks) {
- if (kTraceDetailedInfo) ATRACE_CALL();
+ if (mTraceDetailedInfo) ATRACE_CALL();
for (size_t i = 0; i < callbacks.size(); i++) {
callbacks[i].mCallback->onDispSyncEvent(callbacks[i].mEventTime);
}
@@ -365,6 +362,9 @@
Mutex mMutex;
Condition mCond;
+
+ // Flag to turn on logging in systrace.
+ const bool mTraceDetailedInfo;
};
#undef LOG_TAG
@@ -383,8 +383,13 @@
bool mParity;
};
-DispSync::DispSync(const char* name)
- : mName(name), mRefreshSkipCount(0), mThread(new DispSyncThread(name)) {}
+DispSync::DispSync(const char* name) : mName(name), mRefreshSkipCount(0) {
+ // This flag offers the ability to turn on systrace logging from the shell.
+ char value[PROPERTY_VALUE_MAX];
+ property_get("debug.sf.dispsync_trace_detailed_info", value, "0");
+ mTraceDetailedInfo = atoi(value);
+ mThread = new DispSyncThread(name, mTraceDetailedInfo);
+}
DispSync::~DispSync() {}
@@ -403,7 +408,7 @@
reset();
beginResync();
- if (kTraceDetailedInfo && kEnableZeroPhaseTracer) {
+ if (mTraceDetailedInfo && kEnableZeroPhaseTracer) {
mZeroPhaseTracer = std::make_unique<ZeroPhaseTracer>();
addEventListener("ZeroPhaseTracer", 0, mZeroPhaseTracer.get());
}
@@ -588,7 +593,7 @@
ALOGV("[%s] Adjusting mPhase -> %" PRId64, mName, ns2us(mPhase));
}
- if (kTraceDetailedInfo) {
+ if (mTraceDetailedInfo) {
ATRACE_INT64("DispSync:Period", mPeriod);
ATRACE_INT64("DispSync:Phase", mPhase + mPeriod / 2);
}
@@ -647,7 +652,7 @@
"No present times for model error.");
}
- if (kTraceDetailedInfo) {
+ if (mTraceDetailedInfo) {
ATRACE_INT64("DispSync:Error", mError);
}
}
diff --git a/services/surfaceflinger/Scheduler/DispSync.h b/services/surfaceflinger/Scheduler/DispSync.h
index 89f5cdb..5b511f4 100644
--- a/services/surfaceflinger/Scheduler/DispSync.h
+++ b/services/surfaceflinger/Scheduler/DispSync.h
@@ -241,6 +241,9 @@
bool mIgnorePresentFences;
std::unique_ptr<Callback> mZeroPhaseTracer;
+
+ // Flag to turn on logging in systrace.
+ bool mTraceDetailedInfo = false;
};
} // namespace impl