Assign previous release fence to previous frame ID
...as otherwise the release timestamps for EGL/Vk timing apis are
shifted by one frame.
Bug: 295456126
Bug: 301055892
Bug: 303385401
Bug: 310927247
Test: Log and inspect timestamps
Change-Id: If1d8a525053591f15b95aeec8dc0bad8a13e6833
diff --git a/libs/gui/BLASTBufferQueue.cpp b/libs/gui/BLASTBufferQueue.cpp
index 8d0331e..f317a2e 100644
--- a/libs/gui/BLASTBufferQueue.cpp
+++ b/libs/gui/BLASTBufferQueue.cpp
@@ -41,6 +41,8 @@
#include <android-base/thread_annotations.h>
#include <chrono>
+#include <com_android_graphics_libgui_flags.h>
+
using namespace com::android::graphics::libgui;
using namespace std::chrono_literals;
@@ -102,12 +104,11 @@
}
}
-void BLASTBufferItemConsumer::updateFrameTimestamps(uint64_t frameNumber, nsecs_t refreshStartTime,
- const sp<Fence>& glDoneFence,
- const sp<Fence>& presentFence,
- const sp<Fence>& prevReleaseFence,
- CompositorTiming compositorTiming,
- nsecs_t latchTime, nsecs_t dequeueReadyTime) {
+void BLASTBufferItemConsumer::updateFrameTimestamps(
+ uint64_t frameNumber, uint64_t previousFrameNumber, nsecs_t refreshStartTime,
+ const sp<Fence>& glDoneFence, const sp<Fence>& presentFence,
+ const sp<Fence>& prevReleaseFence, CompositorTiming compositorTiming, nsecs_t latchTime,
+ nsecs_t dequeueReadyTime) {
Mutex::Autolock lock(mMutex);
// if the producer is not connected, don't bother updating,
@@ -118,7 +119,15 @@
std::shared_ptr<FenceTime> releaseFenceTime = std::make_shared<FenceTime>(prevReleaseFence);
mFrameEventHistory.addLatch(frameNumber, latchTime);
- mFrameEventHistory.addRelease(frameNumber, dequeueReadyTime, std::move(releaseFenceTime));
+ if (flags::frametimestamps_previousrelease()) {
+ if (previousFrameNumber > 0) {
+ mFrameEventHistory.addRelease(previousFrameNumber, dequeueReadyTime,
+ std::move(releaseFenceTime));
+ }
+ } else {
+ mFrameEventHistory.addRelease(frameNumber, dequeueReadyTime, std::move(releaseFenceTime));
+ }
+
mFrameEventHistory.addPreComposition(frameNumber, refreshStartTime);
mFrameEventHistory.addPostComposition(frameNumber, glDoneFenceTime, presentFenceTime,
compositorTiming);
@@ -364,6 +373,7 @@
if (stat.latchTime > 0) {
mBufferItemConsumer
->updateFrameTimestamps(stat.frameEventStats.frameNumber,
+ stat.frameEventStats.previousFrameNumber,
stat.frameEventStats.refreshStartTime,
stat.frameEventStats.gpuCompositionDoneFence,
stat.presentFence, stat.previousReleaseFence,
diff --git a/libs/gui/ITransactionCompletedListener.cpp b/libs/gui/ITransactionCompletedListener.cpp
index 29d64af..f5d19aa 100644
--- a/libs/gui/ITransactionCompletedListener.cpp
+++ b/libs/gui/ITransactionCompletedListener.cpp
@@ -25,6 +25,10 @@
#include <gui/LayerState.h>
#include <private/gui/ParcelUtils.h>
+#include <com_android_graphics_libgui_flags.h>
+
+using namespace com::android::graphics::libgui;
+
namespace android {
namespace { // Anonymous
@@ -49,6 +53,11 @@
status_t err = output->writeUint64(frameNumber);
if (err != NO_ERROR) return err;
+ if (flags::frametimestamps_previousrelease()) {
+ err = output->writeUint64(previousFrameNumber);
+ if (err != NO_ERROR) return err;
+ }
+
if (gpuCompositionDoneFence) {
err = output->writeBool(true);
if (err != NO_ERROR) return err;
@@ -79,6 +88,11 @@
status_t err = input->readUint64(&frameNumber);
if (err != NO_ERROR) return err;
+ if (flags::frametimestamps_previousrelease()) {
+ err = input->readUint64(&previousFrameNumber);
+ if (err != NO_ERROR) return err;
+ }
+
bool hasFence = false;
err = input->readBool(&hasFence);
if (err != NO_ERROR) return err;
diff --git a/libs/gui/fuzzer/libgui_bufferQueue_fuzzer.cpp b/libs/gui/fuzzer/libgui_bufferQueue_fuzzer.cpp
index 17f4c63..2e270b7 100644
--- a/libs/gui/fuzzer/libgui_bufferQueue_fuzzer.cpp
+++ b/libs/gui/fuzzer/libgui_bufferQueue_fuzzer.cpp
@@ -141,8 +141,8 @@
CompositorTiming compTiming;
sp<Fence> previousFence = new Fence(memfd_create("pfd", MFD_ALLOW_SEALING));
sp<Fence> gpuFence = new Fence(memfd_create("gfd", MFD_ALLOW_SEALING));
- FrameEventHistoryStats frameStats(frameNumber, gpuFence, compTiming,
- mFdp.ConsumeIntegral<int64_t>(),
+ FrameEventHistoryStats frameStats(frameNumber, mFdp.ConsumeIntegral<uint64_t>(), gpuFence,
+ compTiming, mFdp.ConsumeIntegral<int64_t>(),
mFdp.ConsumeIntegral<int64_t>());
std::vector<SurfaceControlStats> stats;
sp<Fence> presentFence = new Fence(memfd_create("fd", MFD_ALLOW_SEALING));
diff --git a/libs/gui/include/gui/BLASTBufferQueue.h b/libs/gui/include/gui/BLASTBufferQueue.h
index 892215e..0e1a505 100644
--- a/libs/gui/include/gui/BLASTBufferQueue.h
+++ b/libs/gui/include/gui/BLASTBufferQueue.h
@@ -50,8 +50,8 @@
void onDisconnect() override EXCLUDES(mMutex);
void addAndGetFrameTimestamps(const NewFrameEventsEntry* newTimestamps,
FrameEventHistoryDelta* outDelta) override EXCLUDES(mMutex);
- void updateFrameTimestamps(uint64_t frameNumber, nsecs_t refreshStartTime,
- const sp<Fence>& gpuCompositionDoneFence,
+ void updateFrameTimestamps(uint64_t frameNumber, uint64_t previousFrameNumber,
+ nsecs_t refreshStartTime, const sp<Fence>& gpuCompositionDoneFence,
const sp<Fence>& presentFence, const sp<Fence>& prevReleaseFence,
CompositorTiming compositorTiming, nsecs_t latchTime,
nsecs_t dequeueReadyTime) EXCLUDES(mMutex);
diff --git a/libs/gui/include/gui/ITransactionCompletedListener.h b/libs/gui/include/gui/ITransactionCompletedListener.h
index 364a57b..bc97cd0 100644
--- a/libs/gui/include/gui/ITransactionCompletedListener.h
+++ b/libs/gui/include/gui/ITransactionCompletedListener.h
@@ -95,15 +95,18 @@
status_t readFromParcel(const Parcel* input) override;
FrameEventHistoryStats() = default;
- FrameEventHistoryStats(uint64_t fn, const sp<Fence>& gpuCompFence, CompositorTiming compTiming,
+ FrameEventHistoryStats(uint64_t frameNumber, uint64_t previousFrameNumber,
+ const sp<Fence>& gpuCompFence, CompositorTiming compTiming,
nsecs_t refreshTime, nsecs_t dequeueReadyTime)
- : frameNumber(fn),
+ : frameNumber(frameNumber),
+ previousFrameNumber(previousFrameNumber),
gpuCompositionDoneFence(gpuCompFence),
compositorTiming(compTiming),
refreshStartTime(refreshTime),
dequeueReadyTime(dequeueReadyTime) {}
uint64_t frameNumber;
+ uint64_t previousFrameNumber;
sp<Fence> gpuCompositionDoneFence;
CompositorTiming compositorTiming;
nsecs_t refreshStartTime;
diff --git a/libs/gui/libgui_flags.aconfig b/libs/gui/libgui_flags.aconfig
index a16be78..b081030 100644
--- a/libs/gui/libgui_flags.aconfig
+++ b/libs/gui/libgui_flags.aconfig
@@ -8,3 +8,10 @@
is_fixed_read_only: true
}
+flag {
+ name: "frametimestamps_previousrelease"
+ namespace: "core_graphics"
+ description: "Controls a fence fixup for timestamp apis"
+ bug: "310927247"
+ is_fixed_read_only: true
+}
diff --git a/libs/gui/tests/BLASTBufferQueue_test.cpp b/libs/gui/tests/BLASTBufferQueue_test.cpp
index 9893c71..ea7078d 100644
--- a/libs/gui/tests/BLASTBufferQueue_test.cpp
+++ b/libs/gui/tests/BLASTBufferQueue_test.cpp
@@ -42,9 +42,12 @@
#include <gtest/gtest.h>
+#include <com_android_graphics_libgui_flags.h>
+
using namespace std::chrono_literals;
namespace android {
+using namespace com::android::graphics::libgui;
using Transaction = SurfaceComposerClient::Transaction;
using android::hardware::graphics::common::V1_2::BufferUsage;
@@ -1581,6 +1584,9 @@
nsecs_t postedTimeB = 0;
setUpAndQueueBuffer(igbProducer, &requestedPresentTimeB, &postedTimeB, &qbOutput, true);
history.applyDelta(qbOutput.frameTimestamps);
+
+ adapter.waitForCallback(2);
+
events = history.getFrame(1);
ASSERT_NE(nullptr, events);
@@ -1590,7 +1596,9 @@
ASSERT_GE(events->postedTime, postedTimeA);
ASSERT_GE(events->latchTime, postedTimeA);
- ASSERT_GE(events->dequeueReadyTime, events->latchTime);
+ if (flags::frametimestamps_previousrelease()) {
+ ASSERT_EQ(events->dequeueReadyTime, FrameEvents::TIMESTAMP_PENDING);
+ }
ASSERT_NE(nullptr, events->gpuCompositionDoneFence);
ASSERT_NE(nullptr, events->displayPresentFence);
ASSERT_NE(nullptr, events->releaseFence);
@@ -1602,6 +1610,50 @@
ASSERT_EQ(requestedPresentTimeB, events->requestedPresentTime);
ASSERT_GE(events->postedTime, postedTimeB);
+ // Now do the same as above with a third buffer, so that timings related to
+ // buffer releases make it back to the first frame.
+ nsecs_t requestedPresentTimeC = 0;
+ nsecs_t postedTimeC = 0;
+ setUpAndQueueBuffer(igbProducer, &requestedPresentTimeC, &postedTimeC, &qbOutput, true);
+ history.applyDelta(qbOutput.frameTimestamps);
+
+ adapter.waitForCallback(3);
+
+ // Check the first frame...
+ events = history.getFrame(1);
+ ASSERT_NE(nullptr, events);
+ ASSERT_EQ(1, events->frameNumber);
+ ASSERT_EQ(requestedPresentTimeA, events->requestedPresentTime);
+ ASSERT_GE(events->postedTime, postedTimeA);
+ ASSERT_GE(events->latchTime, postedTimeA);
+ // Now dequeueReadyTime is valid, because the release timings finally
+ // propaged to queueBuffer()
+ ASSERT_GE(events->dequeueReadyTime, events->latchTime);
+ ASSERT_NE(nullptr, events->gpuCompositionDoneFence);
+ ASSERT_NE(nullptr, events->displayPresentFence);
+ ASSERT_NE(nullptr, events->releaseFence);
+
+ // ...and the second
+ events = history.getFrame(2);
+ ASSERT_NE(nullptr, events);
+ ASSERT_EQ(2, events->frameNumber);
+ ASSERT_EQ(requestedPresentTimeB, events->requestedPresentTime);
+ ASSERT_GE(events->postedTime, postedTimeB);
+ ASSERT_GE(events->latchTime, postedTimeB);
+ if (flags::frametimestamps_previousrelease()) {
+ ASSERT_EQ(events->dequeueReadyTime, FrameEvents::TIMESTAMP_PENDING);
+ }
+ ASSERT_NE(nullptr, events->gpuCompositionDoneFence);
+ ASSERT_NE(nullptr, events->displayPresentFence);
+ ASSERT_NE(nullptr, events->releaseFence);
+
+ // ...and finally the third!
+ events = history.getFrame(3);
+ ASSERT_NE(nullptr, events);
+ ASSERT_EQ(3, events->frameNumber);
+ ASSERT_EQ(requestedPresentTimeC, events->requestedPresentTime);
+ ASSERT_GE(events->postedTime, postedTimeC);
+
// wait for any callbacks that have not been received
adapter.waitForCallbacks();
}
@@ -1660,6 +1712,8 @@
setUpAndQueueBuffer(igbProducer, &requestedPresentTimeC, &postedTimeC, &qbOutput, true);
history.applyDelta(qbOutput.frameTimestamps);
+ adapter.waitForCallback(3);
+
// frame number, requestedPresentTime, and postTime should not have changed
ASSERT_EQ(1, events->frameNumber);
ASSERT_EQ(requestedPresentTimeA, events->requestedPresentTime);
@@ -1679,6 +1733,42 @@
ASSERT_EQ(requestedPresentTimeB, events->requestedPresentTime);
ASSERT_GE(events->postedTime, postedTimeB);
ASSERT_GE(events->latchTime, postedTimeB);
+
+ if (flags::frametimestamps_previousrelease()) {
+ ASSERT_EQ(events->dequeueReadyTime, FrameEvents::TIMESTAMP_PENDING);
+ }
+ ASSERT_NE(nullptr, events->gpuCompositionDoneFence);
+ ASSERT_NE(nullptr, events->displayPresentFence);
+ ASSERT_NE(nullptr, events->releaseFence);
+
+ // Queue another buffer to check for timestamps that came late
+ nsecs_t requestedPresentTimeD = 0;
+ nsecs_t postedTimeD = 0;
+ setUpAndQueueBuffer(igbProducer, &requestedPresentTimeD, &postedTimeD, &qbOutput, true);
+ history.applyDelta(qbOutput.frameTimestamps);
+
+ adapter.waitForCallback(4);
+
+ // frame number, requestedPresentTime, and postTime should not have changed
+ events = history.getFrame(1);
+ ASSERT_EQ(1, events->frameNumber);
+ ASSERT_EQ(requestedPresentTimeA, events->requestedPresentTime);
+ ASSERT_GE(events->postedTime, postedTimeA);
+
+ // a valid latchtime and pre and post composition info should not be set for the dropped frame
+ ASSERT_FALSE(events->hasLatchInfo());
+ ASSERT_FALSE(events->hasDequeueReadyInfo());
+ ASSERT_FALSE(events->hasGpuCompositionDoneInfo());
+ ASSERT_FALSE(events->hasDisplayPresentInfo());
+ ASSERT_FALSE(events->hasReleaseInfo());
+
+ // we should also have gotten values for the presented frame
+ events = history.getFrame(2);
+ ASSERT_NE(nullptr, events);
+ ASSERT_EQ(2, events->frameNumber);
+ ASSERT_EQ(requestedPresentTimeB, events->requestedPresentTime);
+ ASSERT_GE(events->postedTime, postedTimeB);
+ ASSERT_GE(events->latchTime, postedTimeB);
ASSERT_GE(events->dequeueReadyTime, events->latchTime);
ASSERT_NE(nullptr, events->gpuCompositionDoneFence);
ASSERT_NE(nullptr, events->displayPresentFence);