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 <cutils/log.h>
26
27 #include <ui/Fence.h>
28
29 #include <utils/String8.h>
30 #include <utils/Thread.h>
31 #include <utils/Trace.h>
32 #include <utils/Vector.h>
33
34 #include "DispSync.h"
35 #include "EventLog/EventLog.h"
36
37 #include <algorithm>
38
39 using std::max;
40 using std::min;
41
42 namespace android {
43
44 // Setting this to true enables verbose tracing that can be used to debug
45 // vsync event model or phase issues.
46 static const bool kTraceDetailedInfo = false;
47
48 // Setting this to true adds a zero-phase tracer for correlating with hardware
49 // vsync events
50 static const bool kEnableZeroPhaseTracer = false;
51
52 // This is the threshold used to determine when hardware vsync events are
53 // needed to re-synchronize the software vsync model with the hardware. The
54 // error metric used is the mean of the squared difference between each
55 // present time and the nearest software-predicted vsync.
56 static const nsecs_t kErrorThreshold = 160000000000; // 400 usec squared
57
58 // This is the offset from the present fence timestamps to the corresponding
59 // vsync event.
60 static const int64_t kPresentTimeOffset = PRESENT_TIME_OFFSET_FROM_VSYNC_NS;
61
62 #undef LOG_TAG
63 #define LOG_TAG "DispSyncThread"
64 class DispSyncThread: public Thread {
65 public:
66
DispSyncThread(const char * name)67 DispSyncThread(const char* name):
68 mName(name),
69 mStop(false),
70 mPeriod(0),
71 mPhase(0),
72 mReferenceTime(0),
73 mWakeupLatency(0),
74 mFrameNumber(0) {}
75
~DispSyncThread()76 virtual ~DispSyncThread() {}
77
updateModel(nsecs_t period,nsecs_t phase,nsecs_t referenceTime)78 void updateModel(nsecs_t period, nsecs_t phase, nsecs_t referenceTime) {
79 if (kTraceDetailedInfo) ATRACE_CALL();
80 Mutex::Autolock lock(mMutex);
81 mPeriod = period;
82 mPhase = phase;
83 mReferenceTime = referenceTime;
84 ALOGV("[%s] updateModel: mPeriod = %" PRId64 ", mPhase = %" PRId64
85 " mReferenceTime = %" PRId64, mName, ns2us(mPeriod),
86 ns2us(mPhase), ns2us(mReferenceTime));
87 mCond.signal();
88 }
89
stop()90 void stop() {
91 if (kTraceDetailedInfo) ATRACE_CALL();
92 Mutex::Autolock lock(mMutex);
93 mStop = true;
94 mCond.signal();
95 }
96
threadLoop()97 virtual bool threadLoop() {
98 status_t err;
99 nsecs_t now = systemTime(SYSTEM_TIME_MONOTONIC);
100
101 while (true) {
102 Vector<CallbackInvocation> callbackInvocations;
103
104 nsecs_t targetTime = 0;
105
106 { // Scope for lock
107 Mutex::Autolock lock(mMutex);
108
109 if (kTraceDetailedInfo) {
110 ATRACE_INT64("DispSync:Frame", mFrameNumber);
111 }
112 ALOGV("[%s] Frame %" PRId64, mName, mFrameNumber);
113 ++mFrameNumber;
114
115 if (mStop) {
116 return false;
117 }
118
119 if (mPeriod == 0) {
120 err = mCond.wait(mMutex);
121 if (err != NO_ERROR) {
122 ALOGE("error waiting for new events: %s (%d)",
123 strerror(-err), err);
124 return false;
125 }
126 continue;
127 }
128
129 targetTime = computeNextEventTimeLocked(now);
130
131 bool isWakeup = false;
132
133 if (now < targetTime) {
134 if (kTraceDetailedInfo) ATRACE_NAME("DispSync waiting");
135
136 if (targetTime == INT64_MAX) {
137 ALOGV("[%s] Waiting forever", mName);
138 err = mCond.wait(mMutex);
139 } else {
140 ALOGV("[%s] Waiting until %" PRId64, mName,
141 ns2us(targetTime));
142 err = mCond.waitRelative(mMutex, targetTime - now);
143 }
144
145 if (err == TIMED_OUT) {
146 isWakeup = true;
147 } else if (err != NO_ERROR) {
148 ALOGE("error waiting for next event: %s (%d)",
149 strerror(-err), err);
150 return false;
151 }
152 }
153
154 now = systemTime(SYSTEM_TIME_MONOTONIC);
155
156 // Don't correct by more than 1.5 ms
157 static const nsecs_t kMaxWakeupLatency = us2ns(1500);
158
159 if (isWakeup) {
160 mWakeupLatency = ((mWakeupLatency * 63) +
161 (now - targetTime)) / 64;
162 mWakeupLatency = min(mWakeupLatency, kMaxWakeupLatency);
163 if (kTraceDetailedInfo) {
164 ATRACE_INT64("DispSync:WakeupLat", now - targetTime);
165 ATRACE_INT64("DispSync:AvgWakeupLat", mWakeupLatency);
166 }
167 }
168
169 callbackInvocations = gatherCallbackInvocationsLocked(now);
170 }
171
172 if (callbackInvocations.size() > 0) {
173 fireCallbackInvocations(callbackInvocations);
174 }
175 }
176
177 return false;
178 }
179
addEventListener(const char * name,nsecs_t phase,const sp<DispSync::Callback> & callback)180 status_t addEventListener(const char* name, nsecs_t phase,
181 const sp<DispSync::Callback>& callback) {
182 if (kTraceDetailedInfo) ATRACE_CALL();
183 Mutex::Autolock lock(mMutex);
184
185 for (size_t i = 0; i < mEventListeners.size(); i++) {
186 if (mEventListeners[i].mCallback == callback) {
187 return BAD_VALUE;
188 }
189 }
190
191 EventListener listener;
192 listener.mName = name;
193 listener.mPhase = phase;
194 listener.mCallback = callback;
195
196 // We want to allow the firstmost future event to fire without
197 // allowing any past events to fire
198 listener.mLastEventTime = systemTime() - mPeriod / 2 + mPhase -
199 mWakeupLatency;
200
201 mEventListeners.push(listener);
202
203 mCond.signal();
204
205 return NO_ERROR;
206 }
207
removeEventListener(const sp<DispSync::Callback> & callback)208 status_t removeEventListener(const sp<DispSync::Callback>& callback) {
209 if (kTraceDetailedInfo) ATRACE_CALL();
210 Mutex::Autolock lock(mMutex);
211
212 for (size_t i = 0; i < mEventListeners.size(); i++) {
213 if (mEventListeners[i].mCallback == callback) {
214 mEventListeners.removeAt(i);
215 mCond.signal();
216 return NO_ERROR;
217 }
218 }
219
220 return BAD_VALUE;
221 }
222
223 // This method is only here to handle the kIgnorePresentFences case.
hasAnyEventListeners()224 bool hasAnyEventListeners() {
225 if (kTraceDetailedInfo) ATRACE_CALL();
226 Mutex::Autolock lock(mMutex);
227 return !mEventListeners.empty();
228 }
229
230 private:
231
232 struct EventListener {
233 const char* mName;
234 nsecs_t mPhase;
235 nsecs_t mLastEventTime;
236 sp<DispSync::Callback> mCallback;
237 };
238
239 struct CallbackInvocation {
240 sp<DispSync::Callback> mCallback;
241 nsecs_t mEventTime;
242 };
243
computeNextEventTimeLocked(nsecs_t now)244 nsecs_t computeNextEventTimeLocked(nsecs_t now) {
245 if (kTraceDetailedInfo) ATRACE_CALL();
246 ALOGV("[%s] computeNextEventTimeLocked", mName);
247 nsecs_t nextEventTime = INT64_MAX;
248 for (size_t i = 0; i < mEventListeners.size(); i++) {
249 nsecs_t t = computeListenerNextEventTimeLocked(mEventListeners[i],
250 now);
251
252 if (t < nextEventTime) {
253 nextEventTime = t;
254 }
255 }
256
257 ALOGV("[%s] nextEventTime = %" PRId64, mName, ns2us(nextEventTime));
258 return nextEventTime;
259 }
260
gatherCallbackInvocationsLocked(nsecs_t now)261 Vector<CallbackInvocation> gatherCallbackInvocationsLocked(nsecs_t now) {
262 if (kTraceDetailedInfo) ATRACE_CALL();
263 ALOGV("[%s] gatherCallbackInvocationsLocked @ %" PRId64, mName,
264 ns2us(now));
265
266 Vector<CallbackInvocation> callbackInvocations;
267 nsecs_t onePeriodAgo = now - mPeriod;
268
269 for (size_t i = 0; i < mEventListeners.size(); i++) {
270 nsecs_t t = computeListenerNextEventTimeLocked(mEventListeners[i],
271 onePeriodAgo);
272
273 if (t < now) {
274 CallbackInvocation ci;
275 ci.mCallback = mEventListeners[i].mCallback;
276 ci.mEventTime = t;
277 ALOGV("[%s] [%s] Preparing to fire", mName,
278 mEventListeners[i].mName);
279 callbackInvocations.push(ci);
280 mEventListeners.editItemAt(i).mLastEventTime = t;
281 }
282 }
283
284 return callbackInvocations;
285 }
286
computeListenerNextEventTimeLocked(const EventListener & listener,nsecs_t baseTime)287 nsecs_t computeListenerNextEventTimeLocked(const EventListener& listener,
288 nsecs_t baseTime) {
289 if (kTraceDetailedInfo) ATRACE_CALL();
290 ALOGV("[%s] [%s] computeListenerNextEventTimeLocked(%" PRId64 ")",
291 mName, listener.mName, ns2us(baseTime));
292
293 nsecs_t lastEventTime = listener.mLastEventTime + mWakeupLatency;
294 ALOGV("[%s] lastEventTime: %" PRId64, mName, ns2us(lastEventTime));
295 if (baseTime < lastEventTime) {
296 baseTime = lastEventTime;
297 ALOGV("[%s] Clamping baseTime to lastEventTime -> %" PRId64, mName,
298 ns2us(baseTime));
299 }
300
301 baseTime -= mReferenceTime;
302 ALOGV("[%s] Relative baseTime = %" PRId64, mName, ns2us(baseTime));
303 nsecs_t phase = mPhase + listener.mPhase;
304 ALOGV("[%s] Phase = %" PRId64, mName, ns2us(phase));
305 baseTime -= phase;
306 ALOGV("[%s] baseTime - phase = %" PRId64, mName, ns2us(baseTime));
307
308 // If our previous time is before the reference (because the reference
309 // has since been updated), the division by mPeriod will truncate
310 // towards zero instead of computing the floor. Since in all cases
311 // before the reference we want the next time to be effectively now, we
312 // set baseTime to -mPeriod so that numPeriods will be -1.
313 // When we add 1 and the phase, we will be at the correct event time for
314 // this period.
315 if (baseTime < 0) {
316 ALOGV("[%s] Correcting negative baseTime", mName);
317 baseTime = -mPeriod;
318 }
319
320 nsecs_t numPeriods = baseTime / mPeriod;
321 ALOGV("[%s] numPeriods = %" PRId64, mName, numPeriods);
322 nsecs_t t = (numPeriods + 1) * mPeriod + phase;
323 ALOGV("[%s] t = %" PRId64, mName, ns2us(t));
324 t += mReferenceTime;
325 ALOGV("[%s] Absolute t = %" PRId64, mName, ns2us(t));
326
327 // Check that it's been slightly more than half a period since the last
328 // event so that we don't accidentally fall into double-rate vsyncs
329 if (t - listener.mLastEventTime < (3 * mPeriod / 5)) {
330 t += mPeriod;
331 ALOGV("[%s] Modifying t -> %" PRId64, mName, ns2us(t));
332 }
333
334 t -= mWakeupLatency;
335 ALOGV("[%s] Corrected for wakeup latency -> %" PRId64, mName, ns2us(t));
336
337 return t;
338 }
339
fireCallbackInvocations(const Vector<CallbackInvocation> & callbacks)340 void fireCallbackInvocations(const Vector<CallbackInvocation>& callbacks) {
341 if (kTraceDetailedInfo) ATRACE_CALL();
342 for (size_t i = 0; i < callbacks.size(); i++) {
343 callbacks[i].mCallback->onDispSyncEvent(callbacks[i].mEventTime);
344 }
345 }
346
347 const char* const mName;
348
349 bool mStop;
350
351 nsecs_t mPeriod;
352 nsecs_t mPhase;
353 nsecs_t mReferenceTime;
354 nsecs_t mWakeupLatency;
355
356 int64_t mFrameNumber;
357
358 Vector<EventListener> mEventListeners;
359
360 Mutex mMutex;
361 Condition mCond;
362 };
363
364 #undef LOG_TAG
365 #define LOG_TAG "DispSync"
366
367 class ZeroPhaseTracer : public DispSync::Callback {
368 public:
ZeroPhaseTracer()369 ZeroPhaseTracer() : mParity(false) {}
370
onDispSyncEvent(nsecs_t)371 virtual void onDispSyncEvent(nsecs_t /*when*/) {
372 mParity = !mParity;
373 ATRACE_INT("ZERO_PHASE_VSYNC", mParity ? 1 : 0);
374 }
375
376 private:
377 bool mParity;
378 };
379
DispSync(const char * name)380 DispSync::DispSync(const char* name) :
381 mName(name),
382 mRefreshSkipCount(0),
383 mThread(new DispSyncThread(name)) {
384
385 mThread->run("DispSync", PRIORITY_URGENT_DISPLAY + PRIORITY_MORE_FAVORABLE);
386 // set DispSync to SCHED_FIFO to minimize jitter
387 struct sched_param param = {0};
388 param.sched_priority = 2;
389 if (sched_setscheduler(mThread->getTid(), SCHED_FIFO, ¶m) != 0) {
390 ALOGE("Couldn't set SCHED_FIFO for DispSyncThread");
391 }
392
393
394 reset();
395 beginResync();
396
397 if (kTraceDetailedInfo) {
398 // If we're not getting present fences then the ZeroPhaseTracer
399 // would prevent HW vsync event from ever being turned off.
400 // Even if we're just ignoring the fences, the zero-phase tracing is
401 // not needed because any time there is an event registered we will
402 // turn on the HW vsync events.
403 if (!kIgnorePresentFences && kEnableZeroPhaseTracer) {
404 addEventListener("ZeroPhaseTracer", 0, new ZeroPhaseTracer());
405 }
406 }
407 }
408
~DispSync()409 DispSync::~DispSync() {}
410
reset()411 void DispSync::reset() {
412 Mutex::Autolock lock(mMutex);
413
414 mPhase = 0;
415 mReferenceTime = 0;
416 mModelUpdated = false;
417 mNumResyncSamples = 0;
418 mFirstResyncSample = 0;
419 mNumResyncSamplesSincePresent = 0;
420 resetErrorLocked();
421 }
422
addPresentFence(const sp<Fence> & fence)423 bool DispSync::addPresentFence(const sp<Fence>& fence) {
424 Mutex::Autolock lock(mMutex);
425
426 mPresentFences[mPresentSampleOffset] = fence;
427 mPresentTimes[mPresentSampleOffset] = 0;
428 mPresentSampleOffset = (mPresentSampleOffset + 1) % NUM_PRESENT_SAMPLES;
429 mNumResyncSamplesSincePresent = 0;
430
431 for (size_t i = 0; i < NUM_PRESENT_SAMPLES; i++) {
432 const sp<Fence>& f(mPresentFences[i]);
433 if (f != NULL) {
434 nsecs_t t = f->getSignalTime();
435 if (t < INT64_MAX) {
436 mPresentFences[i].clear();
437 mPresentTimes[i] = t + kPresentTimeOffset;
438 }
439 }
440 }
441
442 updateErrorLocked();
443
444 return !mModelUpdated || mError > kErrorThreshold;
445 }
446
beginResync()447 void DispSync::beginResync() {
448 Mutex::Autolock lock(mMutex);
449 ALOGV("[%s] beginResync", mName);
450 mModelUpdated = false;
451 mNumResyncSamples = 0;
452 }
453
addResyncSample(nsecs_t timestamp)454 bool DispSync::addResyncSample(nsecs_t timestamp) {
455 Mutex::Autolock lock(mMutex);
456
457 ALOGV("[%s] addResyncSample(%" PRId64 ")", mName, ns2us(timestamp));
458
459 size_t idx = (mFirstResyncSample + mNumResyncSamples) % MAX_RESYNC_SAMPLES;
460 mResyncSamples[idx] = timestamp;
461 if (mNumResyncSamples == 0) {
462 mPhase = 0;
463 mReferenceTime = timestamp;
464 ALOGV("[%s] First resync sample: mPeriod = %" PRId64 ", mPhase = 0, "
465 "mReferenceTime = %" PRId64, mName, ns2us(mPeriod),
466 ns2us(mReferenceTime));
467 mThread->updateModel(mPeriod, mPhase, mReferenceTime);
468 }
469
470 if (mNumResyncSamples < MAX_RESYNC_SAMPLES) {
471 mNumResyncSamples++;
472 } else {
473 mFirstResyncSample = (mFirstResyncSample + 1) % MAX_RESYNC_SAMPLES;
474 }
475
476 updateModelLocked();
477
478 if (mNumResyncSamplesSincePresent++ > MAX_RESYNC_SAMPLES_WITHOUT_PRESENT) {
479 resetErrorLocked();
480 }
481
482 if (kIgnorePresentFences) {
483 // If we don't have the sync framework we will never have
484 // addPresentFence called. This means we have no way to know whether
485 // or not we're synchronized with the HW vsyncs, so we just request
486 // that the HW vsync events be turned on whenever we need to generate
487 // SW vsync events.
488 return mThread->hasAnyEventListeners();
489 }
490
491 // Check against kErrorThreshold / 2 to add some hysteresis before having to
492 // resync again
493 bool modelLocked = mModelUpdated && mError < (kErrorThreshold / 2);
494 ALOGV("[%s] addResyncSample returning %s", mName,
495 modelLocked ? "locked" : "unlocked");
496 return !modelLocked;
497 }
498
endResync()499 void DispSync::endResync() {
500 }
501
addEventListener(const char * name,nsecs_t phase,const sp<Callback> & callback)502 status_t DispSync::addEventListener(const char* name, nsecs_t phase,
503 const sp<Callback>& callback) {
504 Mutex::Autolock lock(mMutex);
505 return mThread->addEventListener(name, phase, callback);
506 }
507
setRefreshSkipCount(int count)508 void DispSync::setRefreshSkipCount(int count) {
509 Mutex::Autolock lock(mMutex);
510 ALOGD("setRefreshSkipCount(%d)", count);
511 mRefreshSkipCount = count;
512 updateModelLocked();
513 }
514
removeEventListener(const sp<Callback> & callback)515 status_t DispSync::removeEventListener(const sp<Callback>& callback) {
516 Mutex::Autolock lock(mMutex);
517 return mThread->removeEventListener(callback);
518 }
519
setPeriod(nsecs_t period)520 void DispSync::setPeriod(nsecs_t period) {
521 Mutex::Autolock lock(mMutex);
522 mPeriod = period;
523 mPhase = 0;
524 mReferenceTime = 0;
525 mThread->updateModel(mPeriod, mPhase, mReferenceTime);
526 }
527
getPeriod()528 nsecs_t DispSync::getPeriod() {
529 // lock mutex as mPeriod changes multiple times in updateModelLocked
530 Mutex::Autolock lock(mMutex);
531 return mPeriod;
532 }
533
updateModelLocked()534 void DispSync::updateModelLocked() {
535 ALOGV("[%s] updateModelLocked %zu", mName, mNumResyncSamples);
536 if (mNumResyncSamples >= MIN_RESYNC_SAMPLES_FOR_UPDATE) {
537 ALOGV("[%s] Computing...", mName);
538 nsecs_t durationSum = 0;
539 nsecs_t minDuration = INT64_MAX;
540 nsecs_t maxDuration = 0;
541 for (size_t i = 1; i < mNumResyncSamples; i++) {
542 size_t idx = (mFirstResyncSample + i) % MAX_RESYNC_SAMPLES;
543 size_t prev = (idx + MAX_RESYNC_SAMPLES - 1) % MAX_RESYNC_SAMPLES;
544 nsecs_t duration = mResyncSamples[idx] - mResyncSamples[prev];
545 durationSum += duration;
546 minDuration = min(minDuration, duration);
547 maxDuration = max(maxDuration, duration);
548 }
549
550 // Exclude the min and max from the average
551 durationSum -= minDuration + maxDuration;
552 mPeriod = durationSum / (mNumResyncSamples - 3);
553
554 ALOGV("[%s] mPeriod = %" PRId64, mName, ns2us(mPeriod));
555
556 double sampleAvgX = 0;
557 double sampleAvgY = 0;
558 double scale = 2.0 * M_PI / double(mPeriod);
559 // Intentionally skip the first sample
560 for (size_t i = 1; i < mNumResyncSamples; i++) {
561 size_t idx = (mFirstResyncSample + i) % MAX_RESYNC_SAMPLES;
562 nsecs_t sample = mResyncSamples[idx] - mReferenceTime;
563 double samplePhase = double(sample % mPeriod) * scale;
564 sampleAvgX += cos(samplePhase);
565 sampleAvgY += sin(samplePhase);
566 }
567
568 sampleAvgX /= double(mNumResyncSamples - 1);
569 sampleAvgY /= double(mNumResyncSamples - 1);
570
571 mPhase = nsecs_t(atan2(sampleAvgY, sampleAvgX) / scale);
572
573 ALOGV("[%s] mPhase = %" PRId64, mName, ns2us(mPhase));
574
575 if (mPhase < -(mPeriod / 2)) {
576 mPhase += mPeriod;
577 ALOGV("[%s] Adjusting mPhase -> %" PRId64, mName, ns2us(mPhase));
578 }
579
580 if (kTraceDetailedInfo) {
581 ATRACE_INT64("DispSync:Period", mPeriod);
582 ATRACE_INT64("DispSync:Phase", mPhase + mPeriod / 2);
583 }
584
585 // Artificially inflate the period if requested.
586 mPeriod += mPeriod * mRefreshSkipCount;
587
588 mThread->updateModel(mPeriod, mPhase, mReferenceTime);
589 mModelUpdated = true;
590 }
591 }
592
updateErrorLocked()593 void DispSync::updateErrorLocked() {
594 if (!mModelUpdated) {
595 return;
596 }
597
598 // Need to compare present fences against the un-adjusted refresh period,
599 // since they might arrive between two events.
600 nsecs_t period = mPeriod / (1 + mRefreshSkipCount);
601
602 int numErrSamples = 0;
603 nsecs_t sqErrSum = 0;
604
605 for (size_t i = 0; i < NUM_PRESENT_SAMPLES; i++) {
606 nsecs_t sample = mPresentTimes[i] - mReferenceTime;
607 if (sample > mPhase) {
608 nsecs_t sampleErr = (sample - mPhase) % period;
609 if (sampleErr > period / 2) {
610 sampleErr -= period;
611 }
612 sqErrSum += sampleErr * sampleErr;
613 numErrSamples++;
614 }
615 }
616
617 if (numErrSamples > 0) {
618 mError = sqErrSum / numErrSamples;
619 } else {
620 mError = 0;
621 }
622
623 if (kTraceDetailedInfo) {
624 ATRACE_INT64("DispSync:Error", mError);
625 }
626 }
627
resetErrorLocked()628 void DispSync::resetErrorLocked() {
629 mPresentSampleOffset = 0;
630 mError = 0;
631 for (size_t i = 0; i < NUM_PRESENT_SAMPLES; i++) {
632 mPresentFences[i].clear();
633 mPresentTimes[i] = 0;
634 }
635 }
636
computeNextRefresh(int periodOffset) const637 nsecs_t DispSync::computeNextRefresh(int periodOffset) const {
638 Mutex::Autolock lock(mMutex);
639 nsecs_t now = systemTime(SYSTEM_TIME_MONOTONIC);
640 nsecs_t phase = mReferenceTime + mPhase;
641 return (((now - phase) / mPeriod) + periodOffset + 1) * mPeriod + phase;
642 }
643
dump(String8 & result) const644 void DispSync::dump(String8& result) const {
645 Mutex::Autolock lock(mMutex);
646 result.appendFormat("present fences are %s\n",
647 kIgnorePresentFences ? "ignored" : "used");
648 result.appendFormat("mPeriod: %" PRId64 " ns (%.3f fps; skipCount=%d)\n",
649 mPeriod, 1000000000.0 / mPeriod, mRefreshSkipCount);
650 result.appendFormat("mPhase: %" PRId64 " ns\n", mPhase);
651 result.appendFormat("mError: %" PRId64 " ns (sqrt=%.1f)\n",
652 mError, sqrt(mError));
653 result.appendFormat("mNumResyncSamplesSincePresent: %d (limit %d)\n",
654 mNumResyncSamplesSincePresent, MAX_RESYNC_SAMPLES_WITHOUT_PRESENT);
655 result.appendFormat("mNumResyncSamples: %zd (max %d)\n",
656 mNumResyncSamples, MAX_RESYNC_SAMPLES);
657
658 result.appendFormat("mResyncSamples:\n");
659 nsecs_t previous = -1;
660 for (size_t i = 0; i < mNumResyncSamples; i++) {
661 size_t idx = (mFirstResyncSample + i) % MAX_RESYNC_SAMPLES;
662 nsecs_t sampleTime = mResyncSamples[idx];
663 if (i == 0) {
664 result.appendFormat(" %" PRId64 "\n", sampleTime);
665 } else {
666 result.appendFormat(" %" PRId64 " (+%" PRId64 ")\n",
667 sampleTime, sampleTime - previous);
668 }
669 previous = sampleTime;
670 }
671
672 result.appendFormat("mPresentFences / mPresentTimes [%d]:\n",
673 NUM_PRESENT_SAMPLES);
674 nsecs_t now = systemTime(SYSTEM_TIME_MONOTONIC);
675 previous = 0;
676 for (size_t i = 0; i < NUM_PRESENT_SAMPLES; i++) {
677 size_t idx = (i + mPresentSampleOffset) % NUM_PRESENT_SAMPLES;
678 bool signaled = mPresentFences[idx] == NULL;
679 nsecs_t presentTime = mPresentTimes[idx];
680 if (!signaled) {
681 result.appendFormat(" [unsignaled fence]\n");
682 } else if (presentTime == 0) {
683 result.appendFormat(" 0\n");
684 } else if (previous == 0) {
685 result.appendFormat(" %" PRId64 " (%.3f ms ago)\n", presentTime,
686 (now - presentTime) / 1000000.0);
687 } else {
688 result.appendFormat(" %" PRId64 " (+%" PRId64 " / %.3f) (%.3f ms ago)\n",
689 presentTime, presentTime - previous,
690 (presentTime - previous) / (double) mPeriod,
691 (now - presentTime) / 1000000.0);
692 }
693 previous = presentTime;
694 }
695
696 result.appendFormat("current monotonic time: %" PRId64 "\n", now);
697 }
698
699 } // namespace android
700