Fix a long standing locking issue with tracing thread

If winscope tracing is enabled, the tracing thread will read the drawing
state if the visible region changes and writes the state it to a proto.
This has a few issues: layer drawing state was being committed without
holding the tracing lock, layers could be destroyed when
finalizePendingOutputLayers (without holding the tracing lock) making
access to offscreenlayers invalid, finally we could get miss a trace
entry or have invalid entries.

This fix takes the tracing lock while committing the layer drawing
states and removes accessing the drawing states which are modified
later. It also identifies any missed entries.

In S, we will look at simplifying the tracing model to store a delta
of changes per layer.

Fixes: b/152010382, b/144918813, b/140854698

Test: w/ hwasan build and winscope enabled atest SurfaceFlinger_test libgui_test
Test: w/ hwasan build and winscope enabled go/wm-tests

Change-Id: I71c7b8e6567767ef97d82c5ea2e06a82ecc3c17a

6 files changed, 65 insertions, 23 deletions

diff --git a/services/surfaceflinger/Layer.cpp b/services/surfaceflinger/Layer.cpp
index 3d67a6b9ad..5039761a6a 100644
--- a/services/surfaceflinger/Layer.cpp
+++ b/services/surfaceflinger/Layer.cpp
@@ -2134,10 +2134,12 @@ LayerProto* Layer::writeToProto(LayersProto& layersProto, uint32_t traceFlags,
     writeToProtoDrawingState(layerProto, traceFlags);
     writeToProtoCommonState(layerProto, LayerVector::StateSet::Drawing, traceFlags);
 
-    // Only populate for the primary display.
-    if (device) {
-        const Hwc2::IComposerClient::Composition compositionType = getCompositionType(device);
-        layerProto->set_hwc_composition_type(static_cast<HwcCompositionType>(compositionType));
+    if (traceFlags & SurfaceTracing::TRACE_COMPOSITION) {
+        // Only populate for the primary display.
+        if (device) {
+            const Hwc2::IComposerClient::Composition compositionType = getCompositionType(device);
+            layerProto->set_hwc_composition_type(static_cast<HwcCompositionType>(compositionType));
+        }
     }
 
     for (const sp<Layer>& layer : mDrawingChildren) {
@@ -2180,8 +2182,10 @@ void Layer::writeToProtoDrawingState(LayerProto* layerInfo, uint32_t traceFlags)
         LayerProtoHelper::writePositionToProto(transform.tx(), transform.ty(),
                                                [&]() { return layerInfo->mutable_position(); });
         LayerProtoHelper::writeToProto(mBounds, [&]() { return layerInfo->mutable_bounds(); });
-        LayerProtoHelper::writeToProto(debugGetVisibleRegionOnDefaultDisplay(),
-                                       [&]() { return layerInfo->mutable_visible_region(); });
+        if (traceFlags & SurfaceTracing::TRACE_COMPOSITION) {
+            LayerProtoHelper::writeToProto(debugGetVisibleRegionOnDefaultDisplay(),
+                                           [&]() { return layerInfo->mutable_visible_region(); });
+        }
         LayerProtoHelper::writeToProto(surfaceDamageRegion,
                                        [&]() { return layerInfo->mutable_damage_region(); });
 
@@ -2191,15 +2195,13 @@ void Layer::writeToProtoDrawingState(LayerProto* layerInfo, uint32_t traceFlags)
         }
     }
 
-    if (traceFlags & SurfaceTracing::TRACE_EXTRA) {
-        LayerProtoHelper::writeToProto(mSourceBounds,
-                                       [&]() { return layerInfo->mutable_source_bounds(); });
-        LayerProtoHelper::writeToProto(mScreenBounds,
-                                       [&]() { return layerInfo->mutable_screen_bounds(); });
-        LayerProtoHelper::writeToProto(getRoundedCornerState().cropRect,
-                                       [&]() { return layerInfo->mutable_corner_radius_crop(); });
-        layerInfo->set_shadow_radius(mEffectiveShadowRadius);
-    }
+    LayerProtoHelper::writeToProto(mSourceBounds,
+                                   [&]() { return layerInfo->mutable_source_bounds(); });
+    LayerProtoHelper::writeToProto(mScreenBounds,
+                                   [&]() { return layerInfo->mutable_screen_bounds(); });
+    LayerProtoHelper::writeToProto(getRoundedCornerState().cropRect,
+                                   [&]() { return layerInfo->mutable_corner_radius_crop(); });
+    layerInfo->set_shadow_radius(mEffectiveShadowRadius);
 }
 
 void Layer::writeToProtoCommonState(LayerProto* layerInfo, LayerVector::StateSet stateSet,
diff --git a/services/surfaceflinger/SurfaceFlinger.cpp b/services/surfaceflinger/SurfaceFlinger.cpp
index 2da92b3145..53b23bc799 100644
--- a/services/surfaceflinger/SurfaceFlinger.cpp
+++ b/services/surfaceflinger/SurfaceFlinger.cpp
@@ -1929,8 +1929,18 @@ void SurfaceFlinger::onMessageReceived(int32_t what) NO_THREAD_SAFETY_ANALYSIS {
             // potentially trigger a display handoff.
             updateVrFlinger();
 
-            bool refreshNeeded = handleMessageTransaction();
-            refreshNeeded |= handleMessageInvalidate();
+            bool refreshNeeded;
+            withTracingLock([&]() {
+                refreshNeeded = handleMessageTransaction();
+                refreshNeeded |= handleMessageInvalidate();
+                if (mTracingEnabled) {
+                    mAddCompositionStateToTrace =
+                            mTracing.flagIsSetLocked(SurfaceTracing::TRACE_COMPOSITION);
+                    if (mVisibleRegionsDirty && !mAddCompositionStateToTrace) {
+                        mTracing.notifyLocked("visibleRegionsDirty");
+                    }
+                }
+            });
 
             // Layers need to get updated (in the previous line) before we can use them for
             // choosing the refresh rate.
@@ -2074,7 +2084,7 @@ void SurfaceFlinger::handleMessageRefresh() {
     mLayersWithQueuedFrames.clear();
     if (mVisibleRegionsDirty) {
         mVisibleRegionsDirty = false;
-        if (mTracingEnabled) {
+        if (mTracingEnabled && mAddCompositionStateToTrace) {
             mTracing.notify("visibleRegionsDirty");
         }
     }
@@ -2946,8 +2956,7 @@ void SurfaceFlinger::initScheduler(DisplayId primaryDisplayId) {
 
 void SurfaceFlinger::commitTransaction()
 {
-    withTracingLock([this]() { commitTransactionLocked(); });
-
+    commitTransactionLocked();
     mTransactionPending = false;
     mAnimTransactionPending = false;
     mTransactionCV.broadcast();
diff --git a/services/surfaceflinger/SurfaceFlinger.h b/services/surfaceflinger/SurfaceFlinger.h
index 6ab1fcf9d5..6aaa0a85ca 100644
--- a/services/surfaceflinger/SurfaceFlinger.h
+++ b/services/surfaceflinger/SurfaceFlinger.h
@@ -1070,6 +1070,7 @@ private:
     std::unique_ptr<SurfaceInterceptor> mInterceptor;
     SurfaceTracing mTracing{*this};
     bool mTracingEnabled = false;
+    bool mAddCompositionStateToTrace = false;
     bool mTracingEnabledChanged GUARDED_BY(mStateLock) = false;
     const std::shared_ptr<TimeStats> mTimeStats;
     const std::unique_ptr<FrameTracer> mFrameTracer;
diff --git a/services/surfaceflinger/SurfaceTracing.cpp b/services/surfaceflinger/SurfaceTracing.cpp
index a9c33327c8..0b1251eac6 100644
--- a/services/surfaceflinger/SurfaceTracing.cpp
+++ b/services/surfaceflinger/SurfaceTracing.cpp
@@ -60,6 +60,8 @@ LayersTraceProto SurfaceTracing::traceWhenNotified() {
     mCanStartTrace.wait(lock);
     android::base::ScopedLockAssertion assumeLock(mSfLock);
     LayersTraceProto entry = traceLayersLocked(mWhere, displayDevice);
+    mTracingInProgress = false;
+    mMissedTraceEntries = 0;
     lock.unlock();
     return entry;
 }
@@ -76,7 +78,15 @@ bool SurfaceTracing::addTraceToBuffer(LayersTraceProto& entry) {
 
 void SurfaceTracing::notify(const char* where) {
     std::scoped_lock lock(mSfLock);
+    notifyLocked(where);
+}
+
+void SurfaceTracing::notifyLocked(const char* where) {
     mWhere = where;
+    if (mTracingInProgress) {
+        mMissedTraceEntries++;
+    }
+    mTracingInProgress = true;
     mCanStartTrace.notify_one();
 }
 
@@ -175,7 +185,10 @@ LayersTraceProto SurfaceTracing::traceLayersLocked(const char* where,
     entry.set_elapsed_realtime_nanos(elapsedRealtimeNano());
     entry.set_where(where);
     LayersProto layers(mFlinger.dumpDrawingStateProto(mTraceFlags, displayDevice));
-    mFlinger.dumpOffscreenLayersProto(layers);
+
+    if (flagIsSetLocked(SurfaceTracing::TRACE_EXTRA)) {
+        mFlinger.dumpOffscreenLayersProto(layers);
+    }
     entry.mutable_layers()->Swap(&layers);
 
     if (mTraceFlags & SurfaceTracing::TRACE_HWC) {
@@ -183,6 +196,10 @@ LayersTraceProto SurfaceTracing::traceLayersLocked(const char* where,
         mFlinger.dumpHwc(hwcDump);
         entry.set_hwc_blob(hwcDump);
     }
+    if (!flagIsSetLocked(SurfaceTracing::TRACE_COMPOSITION)) {
+        entry.set_excludes_composition_state(true);
+    }
+    entry.set_missed_entries(mMissedTraceEntries);
 
     return entry;
 }
diff --git a/services/surfaceflinger/SurfaceTracing.h b/services/surfaceflinger/SurfaceTracing.h
index 83872ed3ae..a00e5d64af 100644
--- a/services/surfaceflinger/SurfaceTracing.h
+++ b/services/surfaceflinger/SurfaceTracing.h
@@ -49,6 +49,7 @@ public:
     status_t writeToFile();
     bool isEnabled() const;
     void notify(const char* where);
+    void notifyLocked(const char* where) NO_THREAD_SAFETY_ANALYSIS /* REQUIRES(mSfLock) */;
 
     void setBufferSize(size_t bufferSizeInByte);
     void writeToFileAsync();
@@ -57,11 +58,15 @@ public:
     enum : uint32_t {
         TRACE_CRITICAL = 1 << 0,
         TRACE_INPUT = 1 << 1,
-        TRACE_EXTRA = 1 << 2,
-        TRACE_HWC = 1 << 3,
+        TRACE_COMPOSITION = 1 << 2,
+        TRACE_EXTRA = 1 << 3,
+        TRACE_HWC = 1 << 4,
         TRACE_ALL = 0xffffffff
     };
     void setTraceFlags(uint32_t flags);
+    bool flagIsSetLocked(uint32_t flags) NO_THREAD_SAFETY_ANALYSIS /* REQUIRES(mSfLock) */ {
+        return (mTraceFlags & flags) == flags;
+    }
 
 private:
     static constexpr auto kDefaultBufferCapInByte = 5_MB;
@@ -103,6 +108,8 @@ private:
     std::mutex& mSfLock;
     uint32_t mTraceFlags GUARDED_BY(mSfLock) = TRACE_CRITICAL | TRACE_INPUT;
     const char* mWhere GUARDED_BY(mSfLock) = "";
+    uint32_t mMissedTraceEntries GUARDED_BY(mSfLock) = 0;
+    bool mTracingInProgress GUARDED_BY(mSfLock) = false;
 
     mutable std::mutex mTraceLock;
     LayersTraceBuffer mBuffer GUARDED_BY(mTraceLock);
diff --git a/services/surfaceflinger/layerproto/layerstrace.proto b/services/surfaceflinger/layerproto/layerstrace.proto
index ac33a0ef9c..acf621e16c 100644
--- a/services/surfaceflinger/layerproto/layerstrace.proto
+++ b/services/surfaceflinger/layerproto/layerstrace.proto
@@ -51,4 +51,10 @@ message LayersTraceProto {
 
     // Blob for the current HWC information for all layers, reported by dumpsys.
     optional string hwc_blob = 4;
+
+    /* Includes state sent during composition like visible region and composition type. */
+    optional bool excludes_composition_state = 5;
+
+    /* Number of missed entries since the last entry was recorded. */
+    optional int32 missed_entries = 6;
 }