• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1 /*
2  * Copyright (C) 2013 The Android Open Source Project
3  *
4  * Licensed under the Apache License, Version 2.0 (the "License");
5  * you may not use this file except in compliance with the License.
6  * You may obtain a copy of the License at
7  *
8  *      http://www.apache.org/licenses/LICENSE-2.0
9  *
10  * Unless required by applicable law or agreed to in writing, software
11  * distributed under the License is distributed on an "AS IS" BASIS,
12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13  * See the License for the specific language governing permissions and
14  * limitations under the License.
15  */
16 
17 #define ATRACE_TAG ATRACE_TAG_GRAPHICS
18 //#define LOG_NDEBUG 0
19 
20 // This is needed for stdint.h to define INT64_MAX in C++
21 #define __STDC_LIMIT_MACROS
22 
23 #include <math.h>
24 
25 #include <algorithm>
26 
27 #include <android-base/stringprintf.h>
28 #include <cutils/properties.h>
29 #include <log/log.h>
30 #include <utils/Thread.h>
31 #include <utils/Trace.h>
32 
33 #include <ui/FenceTime.h>
34 
35 #include "DispSync.h"
36 #include "EventLog/EventLog.h"
37 #include "SurfaceFlinger.h"
38 
39 using android::base::StringAppendF;
40 using std::max;
41 using std::min;
42 
43 namespace android {
44 
45 DispSync::~DispSync() = default;
46 DispSync::Callback::~Callback() = default;
47 
48 namespace impl {
49 
50 // Setting this to true adds a zero-phase tracer for correlating with hardware
51 // vsync events
52 static const bool kEnableZeroPhaseTracer = false;
53 
54 // This is the threshold used to determine when hardware vsync events are
55 // needed to re-synchronize the software vsync model with the hardware.  The
56 // error metric used is the mean of the squared difference between each
57 // present time and the nearest software-predicted vsync.
58 static const nsecs_t kErrorThreshold = 160000000000; // 400 usec squared
59 
60 #undef LOG_TAG
61 #define LOG_TAG "DispSyncThread"
62 class DispSyncThread : public Thread {
63 public:
DispSyncThread(const char * name,bool showTraceDetailedInfo)64     DispSyncThread(const char* name, bool showTraceDetailedInfo)
65           : mName(name),
66             mStop(false),
67             mModelLocked(false),
68             mPeriod(0),
69             mPhase(0),
70             mReferenceTime(0),
71             mWakeupLatency(0),
72             mFrameNumber(0),
73             mTraceDetailedInfo(showTraceDetailedInfo) {}
74 
~DispSyncThread()75     virtual ~DispSyncThread() {}
76 
updateModel(nsecs_t period,nsecs_t phase,nsecs_t referenceTime)77     void updateModel(nsecs_t period, nsecs_t phase, nsecs_t referenceTime) {
78         if (mTraceDetailedInfo) ATRACE_CALL();
79         Mutex::Autolock lock(mMutex);
80 
81         mPhase = phase;
82         if (mReferenceTime != referenceTime) {
83             for (auto& eventListener : mEventListeners) {
84                 eventListener.mHasFired = false;
85             }
86         }
87         mReferenceTime = referenceTime;
88         if (mPeriod != 0 && mPeriod != period && mReferenceTime != 0) {
89             // Inflate the reference time to be the most recent predicted
90             // vsync before the current time.
91             const nsecs_t now = systemTime(SYSTEM_TIME_MONOTONIC);
92             const nsecs_t baseTime = now - mReferenceTime;
93             const nsecs_t numOldPeriods = baseTime / mPeriod;
94             mReferenceTime = mReferenceTime + (numOldPeriods)*mPeriod;
95         }
96         mPeriod = period;
97         if (mTraceDetailedInfo) {
98             ATRACE_INT64("DispSync:Period", mPeriod);
99             ATRACE_INT64("DispSync:Phase", mPhase + mPeriod / 2);
100             ATRACE_INT64("DispSync:Reference Time", mReferenceTime);
101         }
102         ALOGV("[%s] updateModel: mPeriod = %" PRId64 ", mPhase = %" PRId64
103               " mReferenceTime = %" PRId64,
104               mName, ns2us(mPeriod), ns2us(mPhase), ns2us(mReferenceTime));
105         mCond.signal();
106     }
107 
stop()108     void stop() {
109         if (mTraceDetailedInfo) ATRACE_CALL();
110         Mutex::Autolock lock(mMutex);
111         mStop = true;
112         mCond.signal();
113     }
114 
lockModel()115     void lockModel() {
116         Mutex::Autolock lock(mMutex);
117         mModelLocked = true;
118     }
119 
unlockModel()120     void unlockModel() {
121         Mutex::Autolock lock(mMutex);
122         mModelLocked = false;
123     }
124 
threadLoop()125     virtual bool threadLoop() {
126         status_t err;
127         nsecs_t now = systemTime(SYSTEM_TIME_MONOTONIC);
128 
129         while (true) {
130             std::vector<CallbackInvocation> callbackInvocations;
131 
132             nsecs_t targetTime = 0;
133 
134             { // Scope for lock
135                 Mutex::Autolock lock(mMutex);
136 
137                 if (mTraceDetailedInfo) {
138                     ATRACE_INT64("DispSync:Frame", mFrameNumber);
139                 }
140                 ALOGV("[%s] Frame %" PRId64, mName, mFrameNumber);
141                 ++mFrameNumber;
142 
143                 if (mStop) {
144                     return false;
145                 }
146 
147                 if (mPeriod == 0) {
148                     err = mCond.wait(mMutex);
149                     if (err != NO_ERROR) {
150                         ALOGE("error waiting for new events: %s (%d)", strerror(-err), err);
151                         return false;
152                     }
153                     continue;
154                 }
155 
156                 targetTime = computeNextEventTimeLocked(now);
157 
158                 bool isWakeup = false;
159 
160                 if (now < targetTime) {
161                     if (mTraceDetailedInfo) ATRACE_NAME("DispSync waiting");
162 
163                     if (targetTime == INT64_MAX) {
164                         ALOGV("[%s] Waiting forever", mName);
165                         err = mCond.wait(mMutex);
166                     } else {
167                         ALOGV("[%s] Waiting until %" PRId64, mName, ns2us(targetTime));
168                         err = mCond.waitRelative(mMutex, targetTime - now);
169                     }
170 
171                     if (err == TIMED_OUT) {
172                         isWakeup = true;
173                     } else if (err != NO_ERROR) {
174                         ALOGE("error waiting for next event: %s (%d)", strerror(-err), err);
175                         return false;
176                     }
177                 }
178 
179                 now = systemTime(SYSTEM_TIME_MONOTONIC);
180 
181                 // Don't correct by more than 1.5 ms
182                 static const nsecs_t kMaxWakeupLatency = us2ns(1500);
183 
184                 if (isWakeup) {
185                     mWakeupLatency = ((mWakeupLatency * 63) + (now - targetTime)) / 64;
186                     mWakeupLatency = min(mWakeupLatency, kMaxWakeupLatency);
187                     if (mTraceDetailedInfo) {
188                         ATRACE_INT64("DispSync:WakeupLat", now - targetTime);
189                         ATRACE_INT64("DispSync:AvgWakeupLat", mWakeupLatency);
190                     }
191                 }
192 
193                 callbackInvocations = gatherCallbackInvocationsLocked(now);
194             }
195 
196             if (callbackInvocations.size() > 0) {
197                 fireCallbackInvocations(callbackInvocations);
198             }
199         }
200 
201         return false;
202     }
203 
addEventListener(const char * name,nsecs_t phase,DispSync::Callback * callback,nsecs_t lastCallbackTime)204     status_t addEventListener(const char* name, nsecs_t phase, DispSync::Callback* callback,
205                               nsecs_t lastCallbackTime) {
206         if (mTraceDetailedInfo) ATRACE_CALL();
207         Mutex::Autolock lock(mMutex);
208 
209         for (size_t i = 0; i < mEventListeners.size(); i++) {
210             if (mEventListeners[i].mCallback == callback) {
211                 return BAD_VALUE;
212             }
213         }
214 
215         EventListener listener;
216         listener.mName = name;
217         listener.mPhase = phase;
218         listener.mCallback = callback;
219 
220         // We want to allow the firstmost future event to fire without
221         // allowing any past events to fire. To do this extrapolate from
222         // mReferenceTime the most recent hardware vsync, and pin the
223         // last event time there.
224         const nsecs_t now = systemTime(SYSTEM_TIME_MONOTONIC);
225         if (mPeriod != 0) {
226             const nsecs_t baseTime = now - mReferenceTime;
227             const nsecs_t numPeriodsSinceReference = baseTime / mPeriod;
228             const nsecs_t predictedReference = mReferenceTime + numPeriodsSinceReference * mPeriod;
229             const nsecs_t phaseCorrection = mPhase + listener.mPhase;
230             const nsecs_t predictedLastEventTime = predictedReference + phaseCorrection;
231             if (predictedLastEventTime >= now) {
232                 // Make sure that the last event time does not exceed the current time.
233                 // If it would, then back the last event time by a period.
234                 listener.mLastEventTime = predictedLastEventTime - mPeriod;
235             } else {
236                 listener.mLastEventTime = predictedLastEventTime;
237             }
238         } else {
239             listener.mLastEventTime = now + mPhase - mWakeupLatency;
240         }
241 
242         if (lastCallbackTime <= 0) {
243             // If there is no prior callback time, try to infer one based on the
244             // logical last event time.
245             listener.mLastCallbackTime = listener.mLastEventTime + mWakeupLatency;
246         } else {
247             listener.mLastCallbackTime = lastCallbackTime;
248         }
249 
250         mEventListeners.push_back(listener);
251 
252         mCond.signal();
253 
254         return NO_ERROR;
255     }
256 
removeEventListener(DispSync::Callback * callback,nsecs_t * outLastCallback)257     status_t removeEventListener(DispSync::Callback* callback, nsecs_t* outLastCallback) {
258         if (mTraceDetailedInfo) ATRACE_CALL();
259         Mutex::Autolock lock(mMutex);
260 
261         for (std::vector<EventListener>::iterator it = mEventListeners.begin();
262              it != mEventListeners.end(); ++it) {
263             if (it->mCallback == callback) {
264                 *outLastCallback = it->mLastCallbackTime;
265                 mEventListeners.erase(it);
266                 mCond.signal();
267                 return NO_ERROR;
268             }
269         }
270 
271         return BAD_VALUE;
272     }
273 
changePhaseOffset(DispSync::Callback * callback,nsecs_t phase)274     status_t changePhaseOffset(DispSync::Callback* callback, nsecs_t phase) {
275         if (mTraceDetailedInfo) ATRACE_CALL();
276         Mutex::Autolock lock(mMutex);
277 
278         for (auto& eventListener : mEventListeners) {
279             if (eventListener.mCallback == callback) {
280                 const nsecs_t oldPhase = eventListener.mPhase;
281                 eventListener.mPhase = phase;
282 
283                 // Pretend that the last time this event was handled at the same frame but with the
284                 // new offset to allow for a seamless offset change without double-firing or
285                 // skipping.
286                 nsecs_t diff = oldPhase - phase;
287                 if (diff > mPeriod / 2) {
288                     diff -= mPeriod;
289                 } else if (diff < -mPeriod / 2) {
290                     diff += mPeriod;
291                 }
292                 eventListener.mLastEventTime -= diff;
293                 mCond.signal();
294                 return NO_ERROR;
295             }
296         }
297         return BAD_VALUE;
298     }
299 
300 private:
301     struct EventListener {
302         const char* mName;
303         nsecs_t mPhase;
304         nsecs_t mLastEventTime;
305         nsecs_t mLastCallbackTime;
306         DispSync::Callback* mCallback;
307         bool mHasFired = false;
308     };
309 
310     struct CallbackInvocation {
311         DispSync::Callback* mCallback;
312         nsecs_t mEventTime;
313     };
314 
computeNextEventTimeLocked(nsecs_t now)315     nsecs_t computeNextEventTimeLocked(nsecs_t now) {
316         if (mTraceDetailedInfo) ATRACE_CALL();
317         ALOGV("[%s] computeNextEventTimeLocked", mName);
318         nsecs_t nextEventTime = INT64_MAX;
319         for (size_t i = 0; i < mEventListeners.size(); i++) {
320             nsecs_t t = computeListenerNextEventTimeLocked(mEventListeners[i], now);
321 
322             if (t < nextEventTime) {
323                 nextEventTime = t;
324             }
325         }
326 
327         ALOGV("[%s] nextEventTime = %" PRId64, mName, ns2us(nextEventTime));
328         return nextEventTime;
329     }
330 
331     // Sanity check that the duration is close enough in length to a period without
332     // falling into double-rate vsyncs.
isCloseToPeriod(nsecs_t duration)333     bool isCloseToPeriod(nsecs_t duration) {
334         // Ratio of 3/5 is arbitrary, but it must be greater than 1/2.
335         return duration < (3 * mPeriod) / 5;
336     }
337 
gatherCallbackInvocationsLocked(nsecs_t now)338     std::vector<CallbackInvocation> gatherCallbackInvocationsLocked(nsecs_t now) {
339         if (mTraceDetailedInfo) ATRACE_CALL();
340         ALOGV("[%s] gatherCallbackInvocationsLocked @ %" PRId64, mName, ns2us(now));
341 
342         std::vector<CallbackInvocation> callbackInvocations;
343         nsecs_t onePeriodAgo = now - mPeriod;
344 
345         for (auto& eventListener : mEventListeners) {
346             nsecs_t t = computeListenerNextEventTimeLocked(eventListener, onePeriodAgo);
347 
348             if (t < now) {
349                 if (isCloseToPeriod(now - eventListener.mLastCallbackTime)) {
350                     eventListener.mLastEventTime = t;
351                     ALOGV("[%s] [%s] Skipping event due to model error", mName,
352                           eventListener.mName);
353                     continue;
354                 }
355                 if (eventListener.mHasFired && !mModelLocked) {
356                     eventListener.mLastEventTime = t;
357                     ALOGV("[%s] [%s] Skipping event due to already firing", mName,
358                           eventListener.mName);
359                     continue;
360                 }
361                 CallbackInvocation ci;
362                 ci.mCallback = eventListener.mCallback;
363                 ci.mEventTime = t;
364                 ALOGV("[%s] [%s] Preparing to fire, latency: %" PRId64, mName, eventListener.mName,
365                       t - eventListener.mLastEventTime);
366                 callbackInvocations.push_back(ci);
367                 eventListener.mLastEventTime = t;
368                 eventListener.mLastCallbackTime = now;
369                 eventListener.mHasFired = true;
370             }
371         }
372 
373         return callbackInvocations;
374     }
375 
computeListenerNextEventTimeLocked(const EventListener & listener,nsecs_t baseTime)376     nsecs_t computeListenerNextEventTimeLocked(const EventListener& listener, nsecs_t baseTime) {
377         if (mTraceDetailedInfo) ATRACE_CALL();
378         ALOGV("[%s] [%s] computeListenerNextEventTimeLocked(%" PRId64 ")", mName, listener.mName,
379               ns2us(baseTime));
380 
381         nsecs_t lastEventTime = listener.mLastEventTime + mWakeupLatency;
382         ALOGV("[%s] lastEventTime: %" PRId64, mName, ns2us(lastEventTime));
383         if (baseTime < lastEventTime) {
384             baseTime = lastEventTime;
385             ALOGV("[%s] Clamping baseTime to lastEventTime -> %" PRId64, mName, ns2us(baseTime));
386         }
387 
388         baseTime -= mReferenceTime;
389         ALOGV("[%s] Relative baseTime = %" PRId64, mName, ns2us(baseTime));
390         nsecs_t phase = mPhase + listener.mPhase;
391         ALOGV("[%s] Phase = %" PRId64, mName, ns2us(phase));
392         baseTime -= phase;
393         ALOGV("[%s] baseTime - phase = %" PRId64, mName, ns2us(baseTime));
394 
395         // If our previous time is before the reference (because the reference
396         // has since been updated), the division by mPeriod will truncate
397         // towards zero instead of computing the floor. Since in all cases
398         // before the reference we want the next time to be effectively now, we
399         // set baseTime to -mPeriod so that numPeriods will be -1.
400         // When we add 1 and the phase, we will be at the correct event time for
401         // this period.
402         if (baseTime < 0) {
403             ALOGV("[%s] Correcting negative baseTime", mName);
404             baseTime = -mPeriod;
405         }
406 
407         nsecs_t numPeriods = baseTime / mPeriod;
408         ALOGV("[%s] numPeriods = %" PRId64, mName, numPeriods);
409         nsecs_t t = (numPeriods + 1) * mPeriod + phase;
410         ALOGV("[%s] t = %" PRId64, mName, ns2us(t));
411         t += mReferenceTime;
412         ALOGV("[%s] Absolute t = %" PRId64, mName, ns2us(t));
413 
414         // Check that it's been slightly more than half a period since the last
415         // event so that we don't accidentally fall into double-rate vsyncs
416         if (isCloseToPeriod(t - listener.mLastEventTime)) {
417             t += mPeriod;
418             ALOGV("[%s] Modifying t -> %" PRId64, mName, ns2us(t));
419         }
420 
421         t -= mWakeupLatency;
422         ALOGV("[%s] Corrected for wakeup latency -> %" PRId64, mName, ns2us(t));
423 
424         return t;
425     }
426 
fireCallbackInvocations(const std::vector<CallbackInvocation> & callbacks)427     void fireCallbackInvocations(const std::vector<CallbackInvocation>& callbacks) {
428         if (mTraceDetailedInfo) ATRACE_CALL();
429         for (size_t i = 0; i < callbacks.size(); i++) {
430             callbacks[i].mCallback->onDispSyncEvent(callbacks[i].mEventTime);
431         }
432     }
433 
434     const char* const mName;
435 
436     bool mStop;
437     bool mModelLocked;
438 
439     nsecs_t mPeriod;
440     nsecs_t mPhase;
441     nsecs_t mReferenceTime;
442     nsecs_t mWakeupLatency;
443 
444     int64_t mFrameNumber;
445 
446     std::vector<EventListener> mEventListeners;
447 
448     Mutex mMutex;
449     Condition mCond;
450 
451     // Flag to turn on logging in systrace.
452     const bool mTraceDetailedInfo;
453 };
454 
455 #undef LOG_TAG
456 #define LOG_TAG "DispSync"
457 
458 class ZeroPhaseTracer : public DispSync::Callback {
459 public:
ZeroPhaseTracer()460     ZeroPhaseTracer() : mParity(false) {}
461 
onDispSyncEvent(nsecs_t)462     virtual void onDispSyncEvent(nsecs_t /*when*/) {
463         mParity = !mParity;
464         ATRACE_INT("ZERO_PHASE_VSYNC", mParity ? 1 : 0);
465     }
466 
467 private:
468     bool mParity;
469 };
470 
DispSync(const char * name)471 DispSync::DispSync(const char* name) : mName(name), mRefreshSkipCount(0) {
472     // This flag offers the ability to turn on systrace logging from the shell.
473     char value[PROPERTY_VALUE_MAX];
474     property_get("debug.sf.dispsync_trace_detailed_info", value, "0");
475     mTraceDetailedInfo = atoi(value);
476     mThread = new DispSyncThread(name, mTraceDetailedInfo);
477 }
478 
~DispSync()479 DispSync::~DispSync() {
480     mThread->stop();
481     mThread->requestExitAndWait();
482 }
483 
init(bool hasSyncFramework,int64_t dispSyncPresentTimeOffset)484 void DispSync::init(bool hasSyncFramework, int64_t dispSyncPresentTimeOffset) {
485     mIgnorePresentFences = !hasSyncFramework;
486     mPresentTimeOffset = dispSyncPresentTimeOffset;
487     mThread->run("DispSync", PRIORITY_URGENT_DISPLAY + PRIORITY_MORE_FAVORABLE);
488 
489     // set DispSync to SCHED_FIFO to minimize jitter
490     struct sched_param param = {0};
491     param.sched_priority = 2;
492     if (sched_setscheduler(mThread->getTid(), SCHED_FIFO, &param) != 0) {
493         ALOGE("Couldn't set SCHED_FIFO for DispSyncThread");
494     }
495 
496     reset();
497     beginResync();
498 
499     if (mTraceDetailedInfo && kEnableZeroPhaseTracer) {
500         mZeroPhaseTracer = std::make_unique<ZeroPhaseTracer>();
501         addEventListener("ZeroPhaseTracer", 0, mZeroPhaseTracer.get(), 0);
502     }
503 }
504 
reset()505 void DispSync::reset() {
506     Mutex::Autolock lock(mMutex);
507     resetLocked();
508 }
509 
resetLocked()510 void DispSync::resetLocked() {
511     mPhase = 0;
512     const size_t lastSampleIdx = (mFirstResyncSample + mNumResyncSamples - 1) % MAX_RESYNC_SAMPLES;
513     // Keep the most recent sample, when we resync to hardware we'll overwrite this
514     // with a more accurate signal
515     if (mResyncSamples[lastSampleIdx] != 0) {
516         mReferenceTime = mResyncSamples[lastSampleIdx];
517     }
518     mModelUpdated = false;
519     for (size_t i = 0; i < MAX_RESYNC_SAMPLES; i++) {
520         mResyncSamples[i] = 0;
521     }
522     mNumResyncSamples = 0;
523     mFirstResyncSample = 0;
524     mNumResyncSamplesSincePresent = 0;
525     mThread->unlockModel();
526     resetErrorLocked();
527 }
528 
addPresentFence(const std::shared_ptr<FenceTime> & fenceTime)529 bool DispSync::addPresentFence(const std::shared_ptr<FenceTime>& fenceTime) {
530     Mutex::Autolock lock(mMutex);
531 
532     if (mIgnorePresentFences) {
533         return true;
534     }
535 
536     mPresentFences[mPresentSampleOffset] = fenceTime;
537     mPresentSampleOffset = (mPresentSampleOffset + 1) % NUM_PRESENT_SAMPLES;
538     mNumResyncSamplesSincePresent = 0;
539 
540     updateErrorLocked();
541 
542     return !mModelUpdated || mError > kErrorThreshold;
543 }
544 
beginResync()545 void DispSync::beginResync() {
546     Mutex::Autolock lock(mMutex);
547     ALOGV("[%s] beginResync", mName);
548     mThread->unlockModel();
549     mModelUpdated = false;
550     mNumResyncSamples = 0;
551 }
552 
addResyncSample(nsecs_t timestamp,bool * periodChanged)553 bool DispSync::addResyncSample(nsecs_t timestamp, bool* periodChanged) {
554     Mutex::Autolock lock(mMutex);
555 
556     ALOGV("[%s] addResyncSample(%" PRId64 ")", mName, ns2us(timestamp));
557 
558     *periodChanged = false;
559     const size_t idx = (mFirstResyncSample + mNumResyncSamples) % MAX_RESYNC_SAMPLES;
560     mResyncSamples[idx] = timestamp;
561     if (mNumResyncSamples == 0) {
562         mPhase = 0;
563         ALOGV("[%s] First resync sample: mPeriod = %" PRId64 ", mPhase = 0, "
564               "mReferenceTime = %" PRId64,
565               mName, ns2us(mPeriod), ns2us(timestamp));
566     } else if (mPendingPeriod > 0) {
567         // mNumResyncSamples > 0, so priorIdx won't overflow
568         const size_t priorIdx = (mFirstResyncSample + mNumResyncSamples - 1) % MAX_RESYNC_SAMPLES;
569         const nsecs_t lastTimestamp = mResyncSamples[priorIdx];
570 
571         const nsecs_t observedVsync = std::abs(timestamp - lastTimestamp);
572         if (std::abs(observedVsync - mPendingPeriod) < std::abs(observedVsync - mPeriod)) {
573             // Observed vsync is closer to the pending period, so reset the
574             // model and flush the pending period.
575             resetLocked();
576             mPeriod = mPendingPeriod;
577             mPendingPeriod = 0;
578             if (mTraceDetailedInfo) {
579                 ATRACE_INT("DispSync:PendingPeriod", mPendingPeriod);
580             }
581             *periodChanged = true;
582         }
583     }
584     // Always update the reference time with the most recent timestamp.
585     mReferenceTime = timestamp;
586     mThread->updateModel(mPeriod, mPhase, mReferenceTime);
587 
588     if (mNumResyncSamples < MAX_RESYNC_SAMPLES) {
589         mNumResyncSamples++;
590     } else {
591         mFirstResyncSample = (mFirstResyncSample + 1) % MAX_RESYNC_SAMPLES;
592     }
593 
594     updateModelLocked();
595 
596     if (mNumResyncSamplesSincePresent++ > MAX_RESYNC_SAMPLES_WITHOUT_PRESENT) {
597         resetErrorLocked();
598     }
599 
600     if (mIgnorePresentFences) {
601         // If we're ignoring the present fences we have no way to know whether
602         // or not we're synchronized with the HW vsyncs, so we just request
603         // that the HW vsync events be turned on.
604         return true;
605     }
606 
607     // Check against kErrorThreshold / 2 to add some hysteresis before having to
608     // resync again
609     bool modelLocked = mModelUpdated && mError < (kErrorThreshold / 2) && mPendingPeriod == 0;
610     ALOGV("[%s] addResyncSample returning %s", mName, modelLocked ? "locked" : "unlocked");
611     if (modelLocked) {
612         mThread->lockModel();
613     }
614     return !modelLocked;
615 }
616 
endResync()617 void DispSync::endResync() {
618     mThread->lockModel();
619 }
620 
addEventListener(const char * name,nsecs_t phase,Callback * callback,nsecs_t lastCallbackTime)621 status_t DispSync::addEventListener(const char* name, nsecs_t phase, Callback* callback,
622                                     nsecs_t lastCallbackTime) {
623     Mutex::Autolock lock(mMutex);
624     return mThread->addEventListener(name, phase, callback, lastCallbackTime);
625 }
626 
setRefreshSkipCount(int count)627 void DispSync::setRefreshSkipCount(int count) {
628     Mutex::Autolock lock(mMutex);
629     ALOGD("setRefreshSkipCount(%d)", count);
630     mRefreshSkipCount = count;
631     updateModelLocked();
632 }
633 
removeEventListener(Callback * callback,nsecs_t * outLastCallbackTime)634 status_t DispSync::removeEventListener(Callback* callback, nsecs_t* outLastCallbackTime) {
635     Mutex::Autolock lock(mMutex);
636     return mThread->removeEventListener(callback, outLastCallbackTime);
637 }
638 
changePhaseOffset(Callback * callback,nsecs_t phase)639 status_t DispSync::changePhaseOffset(Callback* callback, nsecs_t phase) {
640     Mutex::Autolock lock(mMutex);
641     return mThread->changePhaseOffset(callback, phase);
642 }
643 
setPeriod(nsecs_t period)644 void DispSync::setPeriod(nsecs_t period) {
645     Mutex::Autolock lock(mMutex);
646     if (mTraceDetailedInfo) {
647         ATRACE_INT("DispSync:PendingPeriod", period);
648     }
649     mPendingPeriod = period;
650 }
651 
getPeriod()652 nsecs_t DispSync::getPeriod() {
653     // lock mutex as mPeriod changes multiple times in updateModelLocked
654     Mutex::Autolock lock(mMutex);
655     return mPeriod;
656 }
657 
updateModelLocked()658 void DispSync::updateModelLocked() {
659     ALOGV("[%s] updateModelLocked %zu", mName, mNumResyncSamples);
660     if (mNumResyncSamples >= MIN_RESYNC_SAMPLES_FOR_UPDATE) {
661         ALOGV("[%s] Computing...", mName);
662         nsecs_t durationSum = 0;
663         nsecs_t minDuration = INT64_MAX;
664         nsecs_t maxDuration = 0;
665         for (size_t i = 1; i < mNumResyncSamples; i++) {
666             size_t idx = (mFirstResyncSample + i) % MAX_RESYNC_SAMPLES;
667             size_t prev = (idx + MAX_RESYNC_SAMPLES - 1) % MAX_RESYNC_SAMPLES;
668             nsecs_t duration = mResyncSamples[idx] - mResyncSamples[prev];
669             durationSum += duration;
670             minDuration = min(minDuration, duration);
671             maxDuration = max(maxDuration, duration);
672         }
673 
674         // Exclude the min and max from the average
675         durationSum -= minDuration + maxDuration;
676         mPeriod = durationSum / (mNumResyncSamples - 3);
677 
678         ALOGV("[%s] mPeriod = %" PRId64, mName, ns2us(mPeriod));
679 
680         double sampleAvgX = 0;
681         double sampleAvgY = 0;
682         double scale = 2.0 * M_PI / double(mPeriod);
683         // Intentionally skip the first sample
684         for (size_t i = 1; i < mNumResyncSamples; i++) {
685             size_t idx = (mFirstResyncSample + i) % MAX_RESYNC_SAMPLES;
686             nsecs_t sample = mResyncSamples[idx] - mReferenceTime;
687             double samplePhase = double(sample % mPeriod) * scale;
688             sampleAvgX += cos(samplePhase);
689             sampleAvgY += sin(samplePhase);
690         }
691 
692         sampleAvgX /= double(mNumResyncSamples - 1);
693         sampleAvgY /= double(mNumResyncSamples - 1);
694 
695         mPhase = nsecs_t(atan2(sampleAvgY, sampleAvgX) / scale);
696 
697         ALOGV("[%s] mPhase = %" PRId64, mName, ns2us(mPhase));
698 
699         if (mPhase < -(mPeriod / 2)) {
700             mPhase += mPeriod;
701             ALOGV("[%s] Adjusting mPhase -> %" PRId64, mName, ns2us(mPhase));
702         }
703 
704         // Artificially inflate the period if requested.
705         mPeriod += mPeriod * mRefreshSkipCount;
706 
707         mThread->updateModel(mPeriod, mPhase, mReferenceTime);
708         mModelUpdated = true;
709     }
710 }
711 
updateErrorLocked()712 void DispSync::updateErrorLocked() {
713     if (!mModelUpdated) {
714         return;
715     }
716 
717     // Need to compare present fences against the un-adjusted refresh period,
718     // since they might arrive between two events.
719     nsecs_t period = mPeriod / (1 + mRefreshSkipCount);
720 
721     int numErrSamples = 0;
722     nsecs_t sqErrSum = 0;
723 
724     for (size_t i = 0; i < NUM_PRESENT_SAMPLES; i++) {
725         // Only check for the cached value of signal time to avoid unecessary
726         // syscalls. It is the responsibility of the DispSync owner to
727         // call getSignalTime() periodically so the cache is updated when the
728         // fence signals.
729         nsecs_t time = mPresentFences[i]->getCachedSignalTime();
730         if (time == Fence::SIGNAL_TIME_PENDING || time == Fence::SIGNAL_TIME_INVALID) {
731             continue;
732         }
733 
734         nsecs_t sample = time - mReferenceTime;
735         if (sample <= mPhase) {
736             continue;
737         }
738 
739         nsecs_t sampleErr = (sample - mPhase) % period;
740         if (sampleErr > period / 2) {
741             sampleErr -= period;
742         }
743         sqErrSum += sampleErr * sampleErr;
744         numErrSamples++;
745     }
746 
747     if (numErrSamples > 0) {
748         mError = sqErrSum / numErrSamples;
749         mZeroErrSamplesCount = 0;
750     } else {
751         mError = 0;
752         // Use mod ACCEPTABLE_ZERO_ERR_SAMPLES_COUNT to avoid log spam.
753         mZeroErrSamplesCount++;
754         ALOGE_IF((mZeroErrSamplesCount % ACCEPTABLE_ZERO_ERR_SAMPLES_COUNT) == 0,
755                  "No present times for model error.");
756     }
757 
758     if (mTraceDetailedInfo) {
759         ATRACE_INT64("DispSync:Error", mError);
760     }
761 }
762 
resetErrorLocked()763 void DispSync::resetErrorLocked() {
764     mPresentSampleOffset = 0;
765     mError = 0;
766     mZeroErrSamplesCount = 0;
767     for (size_t i = 0; i < NUM_PRESENT_SAMPLES; i++) {
768         mPresentFences[i] = FenceTime::NO_FENCE;
769     }
770 }
771 
computeNextRefresh(int periodOffset) const772 nsecs_t DispSync::computeNextRefresh(int periodOffset) const {
773     Mutex::Autolock lock(mMutex);
774     nsecs_t now = systemTime(SYSTEM_TIME_MONOTONIC);
775     nsecs_t phase = mReferenceTime + mPhase;
776     if (mPeriod == 0) {
777         return 0;
778     }
779     return (((now - phase) / mPeriod) + periodOffset + 1) * mPeriod + phase;
780 }
781 
setIgnorePresentFences(bool ignore)782 void DispSync::setIgnorePresentFences(bool ignore) {
783     Mutex::Autolock lock(mMutex);
784     if (mIgnorePresentFences != ignore) {
785         mIgnorePresentFences = ignore;
786         resetLocked();
787     }
788 }
789 
dump(std::string & result) const790 void DispSync::dump(std::string& result) const {
791     Mutex::Autolock lock(mMutex);
792     StringAppendF(&result, "present fences are %s\n", mIgnorePresentFences ? "ignored" : "used");
793     StringAppendF(&result, "mPeriod: %" PRId64 " ns (%.3f fps; skipCount=%d)\n", mPeriod,
794                   1000000000.0 / mPeriod, mRefreshSkipCount);
795     StringAppendF(&result, "mPhase: %" PRId64 " ns\n", mPhase);
796     StringAppendF(&result, "mError: %" PRId64 " ns (sqrt=%.1f)\n", mError, sqrt(mError));
797     StringAppendF(&result, "mNumResyncSamplesSincePresent: %d (limit %d)\n",
798                   mNumResyncSamplesSincePresent, MAX_RESYNC_SAMPLES_WITHOUT_PRESENT);
799     StringAppendF(&result, "mNumResyncSamples: %zd (max %d)\n", mNumResyncSamples,
800                   MAX_RESYNC_SAMPLES);
801 
802     result.append("mResyncSamples:\n");
803     nsecs_t previous = -1;
804     for (size_t i = 0; i < mNumResyncSamples; i++) {
805         size_t idx = (mFirstResyncSample + i) % MAX_RESYNC_SAMPLES;
806         nsecs_t sampleTime = mResyncSamples[idx];
807         if (i == 0) {
808             StringAppendF(&result, "  %" PRId64 "\n", sampleTime);
809         } else {
810             StringAppendF(&result, "  %" PRId64 " (+%" PRId64 ")\n", sampleTime,
811                           sampleTime - previous);
812         }
813         previous = sampleTime;
814     }
815 
816     StringAppendF(&result, "mPresentFences [%d]:\n", NUM_PRESENT_SAMPLES);
817     nsecs_t now = systemTime(SYSTEM_TIME_MONOTONIC);
818     previous = Fence::SIGNAL_TIME_INVALID;
819     for (size_t i = 0; i < NUM_PRESENT_SAMPLES; i++) {
820         size_t idx = (i + mPresentSampleOffset) % NUM_PRESENT_SAMPLES;
821         nsecs_t presentTime = mPresentFences[idx]->getSignalTime();
822         if (presentTime == Fence::SIGNAL_TIME_PENDING) {
823             StringAppendF(&result, "  [unsignaled fence]\n");
824         } else if (presentTime == Fence::SIGNAL_TIME_INVALID) {
825             StringAppendF(&result, "  [invalid fence]\n");
826         } else if (previous == Fence::SIGNAL_TIME_PENDING ||
827                    previous == Fence::SIGNAL_TIME_INVALID) {
828             StringAppendF(&result, "  %" PRId64 "  (%.3f ms ago)\n", presentTime,
829                           (now - presentTime) / 1000000.0);
830         } else {
831             StringAppendF(&result, "  %" PRId64 " (+%" PRId64 " / %.3f)  (%.3f ms ago)\n",
832                           presentTime, presentTime - previous,
833                           (presentTime - previous) / (double)mPeriod,
834                           (now - presentTime) / 1000000.0);
835         }
836         previous = presentTime;
837     }
838 
839     StringAppendF(&result, "current monotonic time: %" PRId64 "\n", now);
840 }
841 
expectedPresentTime()842 nsecs_t DispSync::expectedPresentTime() {
843     // The HWC doesn't currently have a way to report additional latency.
844     // Assume that whatever we submit now will appear right after the flip.
845     // For a smart panel this might be 1.  This is expressed in frames,
846     // rather than time, because we expect to have a constant frame delay
847     // regardless of the refresh rate.
848     const uint32_t hwcLatency = 0;
849 
850     // Ask DispSync when the next refresh will be (CLOCK_MONOTONIC).
851     return computeNextRefresh(hwcLatency);
852 }
853 
854 } // namespace impl
855 
856 } // namespace android
857