SurfaceFlinger: Trace pending BufferStateLayer buffers.

In BufferQueueLayer the BufferQueueConsumer lives inside the server
process, and ATRACE's an integer indicating the current number of
queued buffers. This makes it possible from systrace to observe
three useful points:
	1. When a buffer arrives at the server
	2. When the buffer is latched
	3. If any buffers are dropped
In BLAST this trace point has of course been moved to the client
process. In this CL we introduce some new machinery to ATRACE and
increment an integer when transactions containing a buffer arrive
at the server. We then decrement this integer when dropping a frame or
latching a buffer.

Bug: 171232941
Test: Existing tests pass
Change-Id: I2672018e4f20d683e3249141438d0716b5af9d11
diff --git a/services/surfaceflinger/BufferStateLayer.cpp b/services/surfaceflinger/BufferStateLayer.cpp
index b6c59cd..0b9caba 100644
--- a/services/surfaceflinger/BufferStateLayer.cpp
+++ b/services/surfaceflinger/BufferStateLayer.cpp
@@ -347,6 +347,12 @@
 
     if (mCurrentState.buffer) {
         mReleasePreviousBuffer = true;
+        if (mCurrentState.buffer != mDrawingState.buffer) {
+            // If mCurrentState has a buffer, and we are about to update again
+            // before swapping to drawing state, then the first buffer will be
+            // dropped and we should decrement the pending buffer count.
+            decrementPendingBufferCount();
+        }
     }
 
     mCurrentState.frameNumber = frameNumber;
@@ -629,6 +635,7 @@
     if (s.buffer == nullptr) {
         return BAD_VALUE;
     }
+    decrementPendingBufferCount();
 
     mPreviousBufferId = getCurrentBufferId();
     mBufferInfo.mBuffer = s.buffer;
@@ -826,6 +833,32 @@
     const Rect layerSize{getBounds()};
     return layerSize.width() != bufferWidth || layerSize.height() != bufferHeight;
 }
+
+void BufferStateLayer::incrementPendingBufferCount() {
+    mPendingBufferTransactions++;
+    tracePendingBufferCount();
+}
+
+void BufferStateLayer::decrementPendingBufferCount() {
+    mPendingBufferTransactions--;
+    tracePendingBufferCount();
+}
+
+void BufferStateLayer::tracePendingBufferCount() {
+    ATRACE_INT(mBlastTransactionName.c_str(), mPendingBufferTransactions);
+}
+
+uint32_t BufferStateLayer::doTransaction(uint32_t flags) {
+    if (mDrawingState.buffer != nullptr && mDrawingState.buffer != mBufferInfo.mBuffer) {
+        // If we are about to update mDrawingState.buffer but it has not yet latched
+        // then we will drop a buffer and should decrement the pending buffer count.
+        // This logic may not work perfectly in the face of a BufferStateLayer being the
+        // deferred side of a deferred transaction, but we don't expect this use case.
+        decrementPendingBufferCount();
+    }
+    return Layer::doTransaction(flags);
+}
+
 } // namespace android
 
 // TODO(b/129481165): remove the #pragma below and fix conversion issues
diff --git a/services/surfaceflinger/BufferStateLayer.h b/services/surfaceflinger/BufferStateLayer.h
index 69b27e4..ad00c65 100644
--- a/services/surfaceflinger/BufferStateLayer.h
+++ b/services/surfaceflinger/BufferStateLayer.h
@@ -112,6 +112,11 @@
     bool onPreComposition(nsecs_t refreshStartTime) override;
     uint32_t getEffectiveScalingMode() const override;
 
+    // See mPendingBufferTransactions
+    void incrementPendingBufferCount() override;
+    void decrementPendingBufferCount();
+    uint32_t doTransaction(uint32_t flags) override;
+
 protected:
     void gatherBufferInfo() override;
     uint64_t getHeadFrameNumber(nsecs_t expectedPresentTime) const;
@@ -119,6 +124,7 @@
 
 private:
     friend class SlotGenerationTest;
+    inline void tracePendingBufferCount();
 
     bool updateFrameEventHistory(const sp<Fence>& acquireFence, nsecs_t postedTime,
                                  nsecs_t requestedPresentTime);
@@ -163,6 +169,18 @@
 
     std::deque<std::shared_ptr<android::frametimeline::SurfaceFrame>> mPendingJankClassifications;
 
+    const std::string mBlastTransactionName{"BufferTX - " + mName};
+    // This integer is incremented everytime a buffer arrives at the server for this layer,
+    // and decremented when a buffer is dropped or latched. When changed the integer is exported
+    // to systrace with ATRACE_INT and mBlastTransactionName. This way when debugging perf it is
+    // possible to see when a buffer arrived at the server, and in which frame it latched.
+    //
+    // You can understand the trace this way:
+    //     - If the integer increases, a buffer arrived at the server.
+    //     - If the integer decreases in latchBuffer, that buffer was latched
+    //     - If the integer decreases in setBuffer or doTransaction, a buffer was dropped
+    uint64_t mPendingBufferTransactions{0};
+
     // TODO(marissaw): support sticky transform for LEGACY camera mode
 
     class HwcSlotGenerator : public ClientCache::ErasedRecipient {
diff --git a/services/surfaceflinger/Layer.h b/services/surfaceflinger/Layer.h
index ac0eb90..95bf510 100644
--- a/services/surfaceflinger/Layer.h
+++ b/services/surfaceflinger/Layer.h
@@ -480,6 +480,8 @@
     virtual void useSurfaceDamage() {}
     virtual void useEmptyDamage() {}
 
+    virtual void incrementPendingBufferCount() {}
+
     /*
      * isOpaque - true if this surface is opaque
      *
@@ -744,7 +746,7 @@
      * doTransaction - process the transaction. This is a good place to figure
      * out which attributes of the surface have changed.
      */
-    uint32_t doTransaction(uint32_t transactionFlags);
+    virtual uint32_t doTransaction(uint32_t transactionFlags);
 
     /*
      * Remove relative z for the layer if its relative parent is not part of the
diff --git a/services/surfaceflinger/SurfaceFlinger.cpp b/services/surfaceflinger/SurfaceFlinger.cpp
index e9416d6..d54cac2 100644
--- a/services/surfaceflinger/SurfaceFlinger.cpp
+++ b/services/surfaceflinger/SurfaceFlinger.cpp
@@ -3268,14 +3268,16 @@
 
 
 bool SurfaceFlinger::transactionIsReadyToBeApplied(int64_t desiredPresentTime,
-                                                   const Vector<ComposerState>& states) {
+                                                   const Vector<ComposerState>& states,
+                                                   bool updateTransactionCounters) {
 
     const nsecs_t expectedPresentTime = mExpectedPresentTime.load();
+    bool ready = true;
     // Do not present if the desiredPresentTime has not passed unless it is more than one second
     // in the future. We ignore timestamps more than 1 second in the future for stability reasons.
     if (desiredPresentTime >= 0 && desiredPresentTime >= expectedPresentTime &&
         desiredPresentTime < expectedPresentTime + s2ns(1)) {
-        return false;
+        ready = false;
     }
 
     for (const ComposerState& state : states) {
@@ -3284,10 +3286,22 @@
             continue;
         }
         if (s.acquireFence && s.acquireFence->getStatus() == Fence::Status::Unsignaled) {
-            return false;
+          ready = false;
+        }
+        if (updateTransactionCounters) {
+              sp<Layer> layer = nullptr;
+              if (s.surface) {
+                layer = fromHandleLocked(s.surface).promote();
+              } else {
+                ALOGW("Transaction with buffer, but no Layer?");
+                continue;
+              }
+              // See BufferStateLayer::mPendingBufferTransactions
+              if (layer) layer->incrementPendingBufferCount();
+
         }
     }
-    return true;
+    return ready;
 }
 
 status_t SurfaceFlinger::setTransactionState(
@@ -3331,7 +3345,7 @@
     const int originPid = ipc->getCallingPid();
     const int originUid = ipc->getCallingUid();
 
-    if (pendingTransactions || !transactionIsReadyToBeApplied(desiredPresentTime, states)) {
+    if (pendingTransactions || !transactionIsReadyToBeApplied(desiredPresentTime, states, true)) {
         mTransactionQueues[applyToken].emplace(frameTimelineVsyncId, states, displays, flags,
                                                desiredPresentTime, uncacheBuffer, postTime,
                                                privileged, hasListenerCallbacks, listenerCallbacks,
diff --git a/services/surfaceflinger/SurfaceFlinger.h b/services/surfaceflinger/SurfaceFlinger.h
index 0509247..96d0499 100644
--- a/services/surfaceflinger/SurfaceFlinger.h
+++ b/services/surfaceflinger/SurfaceFlinger.h
@@ -743,7 +743,8 @@
     void commitTransaction() REQUIRES(mStateLock);
     void commitOffscreenLayers();
     bool transactionIsReadyToBeApplied(int64_t desiredPresentTime,
-                                       const Vector<ComposerState>& states);
+                                       const Vector<ComposerState>& states,
+                                       bool updateTransactionCounters = false) REQUIRES(mStateLock);
     uint32_t setDisplayStateLocked(const DisplayState& s) REQUIRES(mStateLock);
     uint32_t addInputWindowCommands(const InputWindowCommands& inputWindowCommands)
             REQUIRES(mStateLock);