Pay attention to buffer timestamps

When acquiring a buffer, SurfaceFlinger now computes the expected
presentation time and passes it to the BufferQueue acquireBuffer()
method.  If it's not yet time to display the buffer, acquireBuffer()
returns PRESENT_LATER instead of a buffer.

The current implementation of the expected-present-time computation
uses approximations and guesswork.

Bug 7900302

Change-Id: If9345611c5983a11a811935aaf27d6388a5036f1
diff --git a/include/gui/BufferItemConsumer.h b/include/gui/BufferItemConsumer.h
index 98b450c..5bf9acb 100644
--- a/include/gui/BufferItemConsumer.h
+++ b/include/gui/BufferItemConsumer.h
@@ -71,7 +71,8 @@
     //
     // If waitForFence is true, and the acquired BufferItem has a valid fence object,
     // acquireBuffer will wait on the fence with no timeout before returning.
-    status_t acquireBuffer(BufferItem *item, bool waitForFence = true);
+    status_t acquireBuffer(BufferItem *item, nsecs_t presentWhen,
+        bool waitForFence = true);
 
     // Returns an acquired buffer to the queue, allowing it to be reused. Since
     // only a fixed number of buffers may be acquired at a time, old buffers
diff --git a/include/gui/BufferQueue.h b/include/gui/BufferQueue.h
index 766fa0f..0143be3 100644
--- a/include/gui/BufferQueue.h
+++ b/include/gui/BufferQueue.h
@@ -39,7 +39,7 @@
     enum { NUM_BUFFER_SLOTS = 32 };
     enum { NO_CONNECTED_API = 0 };
     enum { INVALID_BUFFER_SLOT = -1 };
-    enum { STALE_BUFFER_SLOT = 1, NO_BUFFER_AVAILABLE };
+    enum { STALE_BUFFER_SLOT = 1, NO_BUFFER_AVAILABLE, PRESENT_LATER };
 
     // When in async mode we reserve two slots in order to guarantee that the
     // producer and consumer can run asynchronously.
@@ -284,7 +284,13 @@
     // acquired then the BufferItem::mGraphicBuffer field of buffer is set to
     // NULL and it is assumed that the consumer still holds a reference to the
     // buffer.
-    status_t acquireBuffer(BufferItem *buffer);
+    //
+    // If presentWhen is nonzero, it indicates the time when the buffer will
+    // be displayed on screen.  If the buffer's timestamp is farther in the
+    // future, the buffer won't be acquired, and PRESENT_LATER will be
+    // returned.  The presentation time is in nanoseconds, and the time base
+    // is CLOCK_MONOTONIC.
+    status_t acquireBuffer(BufferItem *buffer, nsecs_t presentWhen);
 
     // releaseBuffer releases a buffer slot from the consumer back to the
     // BufferQueue.  This may be done while the buffer's contents are still
diff --git a/include/gui/ConsumerBase.h b/include/gui/ConsumerBase.h
index 1d51bc9..42b84cc 100644
--- a/include/gui/ConsumerBase.h
+++ b/include/gui/ConsumerBase.h
@@ -152,7 +152,8 @@
     // initialization that must take place the first time a buffer is assigned
     // to a slot.  If it is overridden the derived class's implementation must
     // call ConsumerBase::acquireBufferLocked.
-    virtual status_t acquireBufferLocked(BufferQueue::BufferItem *item);
+    virtual status_t acquireBufferLocked(BufferQueue::BufferItem *item,
+        nsecs_t presentWhen);
 
     // releaseBufferLocked relinquishes control over a buffer, returning that
     // control to the BufferQueue.
diff --git a/include/gui/GLConsumer.h b/include/gui/GLConsumer.h
index 031684e..fbc8840 100644
--- a/include/gui/GLConsumer.h
+++ b/include/gui/GLConsumer.h
@@ -237,7 +237,8 @@
 
     // acquireBufferLocked overrides the ConsumerBase method to update the
     // mEglSlots array in addition to the ConsumerBase behavior.
-    virtual status_t acquireBufferLocked(BufferQueue::BufferItem *item);
+    virtual status_t acquireBufferLocked(BufferQueue::BufferItem *item,
+        nsecs_t presentWhen);
 
     // releaseBufferLocked overrides the ConsumerBase method to update the
     // mEglSlots array in addition to the ConsumerBase.
diff --git a/libs/gui/BufferItemConsumer.cpp b/libs/gui/BufferItemConsumer.cpp
index ba04bdf..8d86c59 100644
--- a/libs/gui/BufferItemConsumer.cpp
+++ b/libs/gui/BufferItemConsumer.cpp
@@ -47,14 +47,15 @@
     mBufferQueue->setConsumerName(name);
 }
 
-status_t BufferItemConsumer::acquireBuffer(BufferItem *item, bool waitForFence) {
+status_t BufferItemConsumer::acquireBuffer(BufferItem *item,
+        nsecs_t presentWhen, bool waitForFence) {
     status_t err;
 
     if (!item) return BAD_VALUE;
 
     Mutex::Autolock _l(mMutex);
 
-    err = acquireBufferLocked(item);
+    err = acquireBufferLocked(item, presentWhen);
     if (err != OK) {
         if (err != NO_BUFFER_AVAILABLE) {
             BI_LOGE("Error acquiring buffer: %s (%d)", strerror(err), err);
diff --git a/libs/gui/BufferQueue.cpp b/libs/gui/BufferQueue.cpp
index 0dab864..8d4b174 100644
--- a/libs/gui/BufferQueue.cpp
+++ b/libs/gui/BufferQueue.cpp
@@ -807,7 +807,7 @@
     }
 }
 
-status_t BufferQueue::acquireBuffer(BufferItem *buffer) {
+status_t BufferQueue::acquireBuffer(BufferItem *buffer, nsecs_t presentWhen) {
     ATRACE_CALL();
     Mutex::Autolock _l(mMutex);
 
@@ -830,38 +830,68 @@
     // check if queue is empty
     // In asynchronous mode the list is guaranteed to be one buffer
     // deep, while in synchronous mode we use the oldest buffer.
-    if (!mQueue.empty()) {
-        Fifo::iterator front(mQueue.begin());
-        int buf = front->mBuf;
-        *buffer = *front;
-        ATRACE_BUFFER_INDEX(buf);
-
-        ST_LOGV("acquireBuffer: acquiring { slot=%d/%llu, buffer=%p }",
-                front->mBuf, front->mFrameNumber,
-                front->mGraphicBuffer->handle);
-        // if front buffer still being tracked update slot state
-        if (stillTracking(front)) {
-            mSlots[buf].mAcquireCalled = true;
-            mSlots[buf].mNeedsCleanupOnRelease = false;
-            mSlots[buf].mBufferState = BufferSlot::ACQUIRED;
-            mSlots[buf].mFence = Fence::NO_FENCE;
-        }
-
-        // If the buffer has previously been acquired by the consumer, set
-        // mGraphicBuffer to NULL to avoid unnecessarily remapping this
-        // buffer on the consumer side.
-        if (buffer->mAcquireCalled) {
-            buffer->mGraphicBuffer = NULL;
-        }
-
-        mQueue.erase(front);
-        mDequeueCondition.broadcast();
-
-        ATRACE_INT(mConsumerName.string(), mQueue.size());
-    } else {
+    if (mQueue.empty()) {
         return NO_BUFFER_AVAILABLE;
     }
 
+    Fifo::iterator front(mQueue.begin());
+    int buf = front->mBuf;
+
+    // Compare the buffer's desired presentation time to the predicted
+    // actual display time.
+    //
+    // The "presentWhen" argument indicates when the buffer is expected
+    // to be presented on-screen.  If the buffer's desired-present time
+    // is earlier (less) than presentWhen, meaning it'll be displayed
+    // on time or possibly late, we acquire and return it.  If we don't want
+    // to display it until after the presentWhen time, we return PRESENT_LATER
+    // without acquiring it.
+    //
+    // To be safe, we don't refuse to acquire the buffer if presentWhen is
+    // more than one second in the future beyond the desired present time
+    // (i.e. we'd be holding the buffer for a really long time).
+    const int MAX_FUTURE_NSEC = 1000000000ULL;
+    nsecs_t desiredPresent = front->mTimestamp;
+    if (presentWhen != 0 && desiredPresent > presentWhen &&
+            desiredPresent - presentWhen < MAX_FUTURE_NSEC)
+    {
+        ALOGV("pts defer: des=%lld when=%lld (%lld) now=%lld",
+                desiredPresent, presentWhen, desiredPresent - presentWhen,
+                systemTime(CLOCK_MONOTONIC));
+        return PRESENT_LATER;
+    }
+    if (presentWhen != 0) {
+        ALOGV("pts accept: %p[%d] sig=%lld des=%lld when=%lld (%lld)",
+                mSlots, buf, mSlots[buf].mFence->getSignalTime(),
+                desiredPresent, presentWhen, desiredPresent - presentWhen);
+    }
+
+    *buffer = *front;
+    ATRACE_BUFFER_INDEX(buf);
+
+    ST_LOGV("acquireBuffer: acquiring { slot=%d/%llu, buffer=%p }",
+            front->mBuf, front->mFrameNumber,
+            front->mGraphicBuffer->handle);
+    // if front buffer still being tracked update slot state
+    if (stillTracking(front)) {
+        mSlots[buf].mAcquireCalled = true;
+        mSlots[buf].mNeedsCleanupOnRelease = false;
+        mSlots[buf].mBufferState = BufferSlot::ACQUIRED;
+        mSlots[buf].mFence = Fence::NO_FENCE;
+    }
+
+    // If the buffer has previously been acquired by the consumer, set
+    // mGraphicBuffer to NULL to avoid unnecessarily remapping this
+    // buffer on the consumer side.
+    if (buffer->mAcquireCalled) {
+        buffer->mGraphicBuffer = NULL;
+    }
+
+    mQueue.erase(front);
+    mDequeueCondition.broadcast();
+
+    ATRACE_INT(mConsumerName.string(), mQueue.size());
+
     return NO_ERROR;
 }
 
diff --git a/libs/gui/ConsumerBase.cpp b/libs/gui/ConsumerBase.cpp
index fd9d153..deb2646 100644
--- a/libs/gui/ConsumerBase.cpp
+++ b/libs/gui/ConsumerBase.cpp
@@ -182,8 +182,9 @@
     }
 }
 
-status_t ConsumerBase::acquireBufferLocked(BufferQueue::BufferItem *item) {
-    status_t err = mBufferQueue->acquireBuffer(item);
+status_t ConsumerBase::acquireBufferLocked(BufferQueue::BufferItem *item,
+        nsecs_t presentWhen) {
+    status_t err = mBufferQueue->acquireBuffer(item, presentWhen);
     if (err != NO_ERROR) {
         return err;
     }
diff --git a/libs/gui/CpuConsumer.cpp b/libs/gui/CpuConsumer.cpp
index 123b470..56bc7c6 100644
--- a/libs/gui/CpuConsumer.cpp
+++ b/libs/gui/CpuConsumer.cpp
@@ -79,7 +79,7 @@
 
     Mutex::Autolock _l(mMutex);
 
-    err = acquireBufferLocked(&b);
+    err = acquireBufferLocked(&b, 0);
     if (err != OK) {
         if (err == BufferQueue::NO_BUFFER_AVAILABLE) {
             return BAD_VALUE;
diff --git a/libs/gui/GLConsumer.cpp b/libs/gui/GLConsumer.cpp
index 6d29edc..d12083f 100644
--- a/libs/gui/GLConsumer.cpp
+++ b/libs/gui/GLConsumer.cpp
@@ -139,7 +139,7 @@
     // Acquire the next buffer.
     // In asynchronous mode the list is guaranteed to be one buffer
     // deep, while in synchronous mode we use the oldest buffer.
-    err = acquireBufferLocked(&item);
+    err = acquireBufferLocked(&item, 0);
     if (err != NO_ERROR) {
         if (err == BufferQueue::NO_BUFFER_AVAILABLE) {
             // We always bind the texture even if we don't update its contents.
@@ -165,8 +165,9 @@
     return bindTextureImageLocked();
 }
 
-status_t GLConsumer::acquireBufferLocked(BufferQueue::BufferItem *item) {
-    status_t err = ConsumerBase::acquireBufferLocked(item);
+status_t GLConsumer::acquireBufferLocked(BufferQueue::BufferItem *item,
+        nsecs_t presentWhen) {
+    status_t err = ConsumerBase::acquireBufferLocked(item, presentWhen);
     if (err != NO_ERROR) {
         return err;
     }
diff --git a/libs/gui/tests/BufferQueue_test.cpp b/libs/gui/tests/BufferQueue_test.cpp
index 62d215b..9682987 100644
--- a/libs/gui/tests/BufferQueue_test.cpp
+++ b/libs/gui/tests/BufferQueue_test.cpp
@@ -80,7 +80,7 @@
                     GRALLOC_USAGE_SW_READ_OFTEN));
         ASSERT_EQ(OK, mBQ->requestBuffer(slot, &buf));
         ASSERT_EQ(OK, mBQ->queueBuffer(slot, qbi, &qbo));
-        ASSERT_EQ(OK, mBQ->acquireBuffer(&item));
+        ASSERT_EQ(OK, mBQ->acquireBuffer(&item, 0));
     }
 
     ASSERT_EQ(IGraphicBufferProducer::BUFFER_NEEDS_REALLOCATION,
@@ -90,7 +90,7 @@
     ASSERT_EQ(OK, mBQ->queueBuffer(slot, qbi, &qbo));
 
     // Acquire the third buffer, which should fail.
-    ASSERT_EQ(INVALID_OPERATION, mBQ->acquireBuffer(&item));
+    ASSERT_EQ(INVALID_OPERATION, mBQ->acquireBuffer(&item, 0));
 }
 
 TEST_F(BufferQueueTest, SetMaxAcquiredBufferCountWithIllegalValues_ReturnsError) {
diff --git a/services/surfaceflinger/DisplayHardware/FramebufferSurface.cpp b/services/surfaceflinger/DisplayHardware/FramebufferSurface.cpp
index 10bca38..938459e 100644
--- a/services/surfaceflinger/DisplayHardware/FramebufferSurface.cpp
+++ b/services/surfaceflinger/DisplayHardware/FramebufferSurface.cpp
@@ -83,7 +83,7 @@
     Mutex::Autolock lock(mMutex);
 
     BufferQueue::BufferItem item;
-    status_t err = acquireBufferLocked(&item);
+    status_t err = acquireBufferLocked(&item, 0);
     if (err == BufferQueue::NO_BUFFER_AVAILABLE) {
         outBuffer = mCurrentBuffer;
         return NO_ERROR;
diff --git a/services/surfaceflinger/Layer.cpp b/services/surfaceflinger/Layer.cpp
index b08b8d1..31a11ce 100644
--- a/services/surfaceflinger/Layer.cpp
+++ b/services/surfaceflinger/Layer.cpp
@@ -1051,11 +1051,6 @@
         const bool oldOpacity = isOpaque();
         sp<GraphicBuffer> oldActiveBuffer = mActiveBuffer;
 
-        // signal another event if we have more frames pending
-        if (android_atomic_dec(&mQueuedFrames) > 1) {
-            mFlinger->signalLayerUpdate();
-        }
-
         struct Reject : public SurfaceFlingerConsumer::BufferRejecter {
             Layer::State& front;
             Layer::State& current;
@@ -1161,7 +1156,21 @@
 
         Reject r(mDrawingState, getCurrentState(), recomputeVisibleRegions);
 
-        if (mSurfaceFlingerConsumer->updateTexImage(&r) != NO_ERROR) {
+        status_t updateResult = mSurfaceFlingerConsumer->updateTexImage(&r);
+        if (updateResult == BufferQueue::PRESENT_LATER) {
+            // Producer doesn't want buffer to be displayed yet.  Signal a
+            // layer update so we check again at the next opportunity.
+            mFlinger->signalLayerUpdate();
+            return outDirtyRegion;
+        }
+
+        // Decrement the queued-frames count.  Signal another event if we
+        // have more frames pending.
+        if (android_atomic_dec(&mQueuedFrames) > 1) {
+            mFlinger->signalLayerUpdate();
+        }
+
+        if (updateResult != NO_ERROR) {
             // something happened!
             recomputeVisibleRegions = true;
             return outDirtyRegion;
diff --git a/services/surfaceflinger/SurfaceFlingerConsumer.cpp b/services/surfaceflinger/SurfaceFlingerConsumer.cpp
index 7ac5c60..b181b60 100644
--- a/services/surfaceflinger/SurfaceFlingerConsumer.cpp
+++ b/services/surfaceflinger/SurfaceFlingerConsumer.cpp
@@ -50,12 +50,14 @@
     // Acquire the next buffer.
     // In asynchronous mode the list is guaranteed to be one buffer
     // deep, while in synchronous mode we use the oldest buffer.
-    err = acquireBufferLocked(&item);
+    err = acquireBufferLocked(&item, computeExpectedPresent());
     if (err != NO_ERROR) {
         if (err == BufferQueue::NO_BUFFER_AVAILABLE) {
             // This variant of updateTexImage does not guarantee that the
             // texture is bound, so no need to call glBindTexture.
             err = NO_ERROR;
+        } else if (err == BufferQueue::PRESENT_LATER) {
+            // return the error, without logging
         } else {
             ALOGE("updateTexImage: acquire failed: %s (%d)",
                 strerror(-err), err);
@@ -99,6 +101,48 @@
     return bindTextureImageLocked();
 }
 
+// We need to determine the time when a buffer acquired now will be
+// displayed.  This can be calculated:
+//   time when previous buffer's actual-present fence was signaled
+//    + current display refresh rate * HWC latency
+//    + a little extra padding
+//
+// Buffer producers are expected to set their desired presentation time
+// based on choreographer time stamps, which (coming from vsync events)
+// will be slightly later then the actual-present timing.  If we get a
+// desired-present time that is unintentionally a hair after the next
+// vsync, we'll hold the frame when we really want to display it.  We
+// want to use an expected-presentation time that is slightly late to
+// avoid this sort of edge case.
+nsecs_t SurfaceFlingerConsumer::computeExpectedPresent()
+{
+    // Don't yet have an easy way to get actual buffer flip time for
+    // the specific display, so use the current time.  This is typically
+    // 1.3ms past the vsync event time.
+    const nsecs_t prevVsync = systemTime(CLOCK_MONOTONIC);
+
+    // Given a SurfaceFlinger reference, and information about what display
+    // we're destined for, we could query the HWC for the refresh rate.  This
+    // could change over time, e.g. we could switch to 24fps for a movie.
+    // For now, assume 60fps.
+    //const nsecs_t vsyncPeriod =
+    //        getHwComposer().getRefreshPeriod(HWC_DISPLAY_PRIMARY);
+    const nsecs_t vsyncPeriod = 16700000;
+
+    // The HWC doesn't currently have a way to report additional latency.
+    // Assume that whatever we submit now will appear on the next flip,
+    // i.e. 1 frame of latency w.r.t. the previous flip.
+    const uint32_t hwcLatency = 1;
+
+    // A little extra padding to compensate for slack between actual vsync
+    // time and vsync event receipt.  Currently not needed since we're
+    // using "now" instead of a vsync time.
+    const nsecs_t extraPadding = 0;
+
+    // Total it up.
+    return prevVsync + hwcLatency * vsyncPeriod + extraPadding;
+}
+
 // ---------------------------------------------------------------------------
 }; // namespace android
 
diff --git a/services/surfaceflinger/SurfaceFlingerConsumer.h b/services/surfaceflinger/SurfaceFlingerConsumer.h
index 22eec81..d774c33 100644
--- a/services/surfaceflinger/SurfaceFlingerConsumer.h
+++ b/services/surfaceflinger/SurfaceFlingerConsumer.h
@@ -51,6 +51,9 @@
 
     // See GLConsumer::bindTextureImageLocked().
     status_t bindTextureImage();
+
+private:
+    nsecs_t computeExpectedPresent();
 };
 
 // ----------------------------------------------------------------------------