[sf] write transaction trace to disk on error
Flush always on transaction traces to disk when we detect
errors like: - out of order buffer updates or cycles in
the layer hierarchy so it easier to investigate issues
from dogfood (ref bug b/272189296)
Bug: 282110579, 238781169
Fixes: 277265947
Test: presubmit
Change-Id: I22dbd7cd43d94763ac941f0c3871dc7e4ea8db8d
diff --git a/services/surfaceflinger/FrontEnd/LayerSnapshotBuilder.cpp b/services/surfaceflinger/FrontEnd/LayerSnapshotBuilder.cpp
index 96ff70c..7213ffa 100644
--- a/services/surfaceflinger/FrontEnd/LayerSnapshotBuilder.cpp
+++ b/services/surfaceflinger/FrontEnd/LayerSnapshotBuilder.cpp
@@ -31,6 +31,7 @@
#include "LayerLog.h"
#include "LayerSnapshotBuilder.h"
#include "TimeStats/TimeStats.h"
+#include "Tracing/TransactionTracing.h"
namespace android::surfaceflinger::frontend {
@@ -435,13 +436,13 @@
// multiple children.
LayerHierarchy::ScopedAddToTraversalPath addChildToPath(root, args.root.getLayer()->id,
LayerHierarchy::Variant::Attached);
- updateSnapshotsInHierarchy(args, args.root, root, mRootSnapshot);
+ updateSnapshotsInHierarchy(args, args.root, root, mRootSnapshot, /*depth=*/0);
} else {
for (auto& [childHierarchy, variant] : args.root.mChildren) {
LayerHierarchy::ScopedAddToTraversalPath addChildToPath(root,
childHierarchy->getLayer()->id,
variant);
- updateSnapshotsInHierarchy(args, *childHierarchy, root, mRootSnapshot);
+ updateSnapshotsInHierarchy(args, *childHierarchy, root, mRootSnapshot, /*depth=*/0);
}
}
@@ -494,7 +495,15 @@
const LayerSnapshot& LayerSnapshotBuilder::updateSnapshotsInHierarchy(
const Args& args, const LayerHierarchy& hierarchy,
- LayerHierarchy::TraversalPath& traversalPath, const LayerSnapshot& parentSnapshot) {
+ LayerHierarchy::TraversalPath& traversalPath, const LayerSnapshot& parentSnapshot,
+ int depth) {
+ if (depth > 50) {
+ TransactionTraceWriter::getInstance().invoke("layer_builder_stack_overflow_",
+ /*overwrite=*/false);
+ LOG_ALWAYS_FATAL("Cycle detected in LayerSnapshotBuilder. See "
+ "builder_stack_overflow_transactions.winscope");
+ }
+
const RequestedLayerState* layer = hierarchy.getLayer();
LayerSnapshot* snapshot = getSnapshot(traversalPath);
const bool newSnapshot = snapshot == nullptr;
@@ -517,7 +526,8 @@
childHierarchy->getLayer()->id,
variant);
const LayerSnapshot& childSnapshot =
- updateSnapshotsInHierarchy(args, *childHierarchy, traversalPath, *snapshot);
+ updateSnapshotsInHierarchy(args, *childHierarchy, traversalPath, *snapshot,
+ depth + 1);
updateChildState(*snapshot, childSnapshot, args);
}
diff --git a/services/surfaceflinger/FrontEnd/LayerSnapshotBuilder.h b/services/surfaceflinger/FrontEnd/LayerSnapshotBuilder.h
index 3f33ab8..2e46dc6 100644
--- a/services/surfaceflinger/FrontEnd/LayerSnapshotBuilder.h
+++ b/services/surfaceflinger/FrontEnd/LayerSnapshotBuilder.h
@@ -96,7 +96,7 @@
const LayerSnapshot& updateSnapshotsInHierarchy(const Args&, const LayerHierarchy& hierarchy,
LayerHierarchy::TraversalPath& traversalPath,
- const LayerSnapshot& parentSnapshot);
+ const LayerSnapshot& parentSnapshot, int depth);
void updateSnapshot(LayerSnapshot&, const Args&, const RequestedLayerState&,
const LayerSnapshot& parentSnapshot, const LayerHierarchy::TraversalPath&);
static void updateRelativeState(LayerSnapshot& snapshot, const LayerSnapshot& parentSnapshot,
diff --git a/services/surfaceflinger/FrontEnd/RequestedLayerState.cpp b/services/surfaceflinger/FrontEnd/RequestedLayerState.cpp
index 23bb54c..bde2d05 100644
--- a/services/surfaceflinger/FrontEnd/RequestedLayerState.cpp
+++ b/services/surfaceflinger/FrontEnd/RequestedLayerState.cpp
@@ -131,6 +131,7 @@
const uint32_t oldFlags = flags;
const half oldAlpha = color.a;
const bool hadBuffer = externalTexture != nullptr;
+ uint64_t oldFramenumber = hadBuffer ? bufferData->frameNumber : 0;
const bool hadSideStream = sidebandStream != nullptr;
const layer_state_t& clientState = resolvedComposerState.state;
const bool hadBlur = hasBlur();
@@ -147,12 +148,9 @@
changes |= RequestedLayerState::Changes::Geometry;
}
}
+
if (clientState.what & layer_state_t::eBufferChanged) {
externalTexture = resolvedComposerState.externalTexture;
- barrierProducerId = std::max(bufferData->producerId, barrierProducerId);
- barrierFrameNumber = std::max(bufferData->frameNumber, barrierFrameNumber);
- // TODO(b/277265947) log and flush transaction trace when we detect out of order updates
-
const bool hasBuffer = externalTexture != nullptr;
if (hasBuffer || hasBuffer != hadBuffer) {
changes |= RequestedLayerState::Changes::Buffer;
@@ -163,6 +161,28 @@
RequestedLayerState::Changes::VisibleRegion |
RequestedLayerState::Changes::Visibility | RequestedLayerState::Changes::Input;
}
+
+ if (hasBuffer) {
+ const bool frameNumberChanged =
+ bufferData->flags.test(BufferData::BufferDataChange::frameNumberChanged);
+ const uint64_t frameNumber =
+ frameNumberChanged ? bufferData->frameNumber : oldFramenumber + 1;
+ bufferData->frameNumber = frameNumber;
+
+ if ((barrierProducerId > bufferData->producerId) ||
+ ((barrierProducerId == bufferData->producerId) &&
+ (barrierFrameNumber > bufferData->frameNumber))) {
+ ALOGE("Out of order buffers detected for %s producedId=%d frameNumber=%" PRIu64
+ " -> producedId=%d frameNumber=%" PRIu64,
+ getDebugString().c_str(), bufferData->producerId, bufferData->frameNumber,
+ bufferData->producerId, frameNumber);
+ TransactionTraceWriter::getInstance().invoke("out_of_order_buffers_",
+ /*overwrite=*/false);
+ }
+
+ barrierProducerId = std::max(bufferData->producerId, barrierProducerId);
+ barrierFrameNumber = std::max(bufferData->frameNumber, barrierFrameNumber);
+ }
}
if (clientState.what & layer_state_t::eSidebandStreamChanged) {