TimeStats: fix a racing case

setPostTime is plumbed without BufferQueue lock, and it's called at the
end of queueBuffer. If the addAndGetFrameTimestamps is delayed by
queueBuffer back pressure (this could happen on special SF/BQ configs),
setAcquireFence will be called with a out-of-bound index internally.

So this change will tweak the order of the back Pressure logic to make
the post time correct when queueBuffer back pressure happens as well as
guarding the TimeStats more strictly.

Bug: 130515827
Test: all SurfaceFlinger tests
Change-Id: I2eace6d8693cc647284de0f33e7b58a6bf79eaaf
Merged-In: I2eace6d8693cc647284de0f33e7b58a6bf79eaaf

2 files changed, 26 insertions, 8 deletions

diff --git a/libs/gui/BufferQueueProducer.cpp b/libs/gui/BufferQueueProducer.cpp
index c96a2dd6a3..9d7f14cb6e 100644
--- a/libs/gui/BufferQueueProducer.cpp
+++ b/libs/gui/BufferQueueProducer.cpp
@@ -989,14 +989,6 @@ status_t BufferQueueProducer::queueBuffer(int slot,
         mCallbackCondition.broadcast();
     }
 
-    // Wait without lock held
-    if (connectedApi == NATIVE_WINDOW_API_EGL) {
-        // Waiting here allows for two full buffers to be queued but not a
-        // third. In the event that frames take varying time, this makes a
-        // small trade-off in favor of latency rather than throughput.
-        lastQueuedFence->waitForever("Throttling EGL Production");
-    }
-
     // Update and get FrameEventHistory.
     nsecs_t postedTime = systemTime(SYSTEM_TIME_MONOTONIC);
     NewFrameEventsEntry newFrameEventsEntry = {
@@ -1008,6 +1000,14 @@ status_t BufferQueueProducer::queueBuffer(int slot,
     addAndGetFrameTimestamps(&newFrameEventsEntry,
             getFrameTimestamps ? &output->frameTimestamps : nullptr);
 
+    // Wait without lock held
+    if (connectedApi == NATIVE_WINDOW_API_EGL) {
+        // Waiting here allows for two full buffers to be queued but not a
+        // third. In the event that frames take varying time, this makes a
+        // small trade-off in favor of latency rather than throughput.
+        lastQueuedFence->waitForever("Throttling EGL Production");
+    }
+
     return NO_ERROR;
 }
 
diff --git a/services/surfaceflinger/TimeStats/TimeStats.cpp b/services/surfaceflinger/TimeStats/TimeStats.cpp
index d4f1e29042..9c34aa726b 100644
--- a/services/surfaceflinger/TimeStats/TimeStats.cpp
+++ b/services/surfaceflinger/TimeStats/TimeStats.cpp
@@ -277,6 +277,9 @@ void TimeStats::setLatchTime(const std::string& layerName, uint64_t frameNumber,
     std::lock_guard<std::mutex> lock(mMutex);
     if (!timeStatsTracker.count(layerName)) return;
     LayerRecord& layerRecord = timeStatsTracker[layerName];
+    if (layerRecord.waitData < 0 ||
+        layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
+        return;
     TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
     if (timeRecord.frameNumber == frameNumber) {
         timeRecord.latchTime = latchTime;
@@ -294,6 +297,9 @@ void TimeStats::setDesiredTime(const std::string& layerName, uint64_t frameNumbe
     std::lock_guard<std::mutex> lock(mMutex);
     if (!timeStatsTracker.count(layerName)) return;
     LayerRecord& layerRecord = timeStatsTracker[layerName];
+    if (layerRecord.waitData < 0 ||
+        layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
+        return;
     TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
     if (timeRecord.frameNumber == frameNumber) {
         timeRecord.desiredTime = desiredTime;
@@ -311,6 +317,9 @@ void TimeStats::setAcquireTime(const std::string& layerName, uint64_t frameNumbe
     std::lock_guard<std::mutex> lock(mMutex);
     if (!timeStatsTracker.count(layerName)) return;
     LayerRecord& layerRecord = timeStatsTracker[layerName];
+    if (layerRecord.waitData < 0 ||
+        layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
+        return;
     TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
     if (timeRecord.frameNumber == frameNumber) {
         timeRecord.acquireTime = acquireTime;
@@ -328,6 +337,9 @@ void TimeStats::setAcquireFence(const std::string& layerName, uint64_t frameNumb
     std::lock_guard<std::mutex> lock(mMutex);
     if (!timeStatsTracker.count(layerName)) return;
     LayerRecord& layerRecord = timeStatsTracker[layerName];
+    if (layerRecord.waitData < 0 ||
+        layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
+        return;
     TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
     if (timeRecord.frameNumber == frameNumber) {
         timeRecord.acquireFence = acquireFence;
@@ -345,6 +357,9 @@ void TimeStats::setPresentTime(const std::string& layerName, uint64_t frameNumbe
     std::lock_guard<std::mutex> lock(mMutex);
     if (!timeStatsTracker.count(layerName)) return;
     LayerRecord& layerRecord = timeStatsTracker[layerName];
+    if (layerRecord.waitData < 0 ||
+        layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
+        return;
     TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
     if (timeRecord.frameNumber == frameNumber) {
         timeRecord.presentTime = presentTime;
@@ -366,6 +381,9 @@ void TimeStats::setPresentFence(const std::string& layerName, uint64_t frameNumb
     std::lock_guard<std::mutex> lock(mMutex);
     if (!timeStatsTracker.count(layerName)) return;
     LayerRecord& layerRecord = timeStatsTracker[layerName];
+    if (layerRecord.waitData < 0 ||
+        layerRecord.waitData >= static_cast<int32_t>(layerRecord.timeRecords.size()))
+        return;
     TimeRecord& timeRecord = layerRecord.timeRecords[layerRecord.waitData];
     if (timeRecord.frameNumber == frameNumber) {
         timeRecord.presentFence = presentFence;