[sf] Add traces with log fatals
If we have to abort flinger, capture a transaction trace to
disk as well. This will help us understand what lead to the
unexpected state.
Test: presubmit
Bug: 238781169
Change-Id: I3ba9004ef8fc3cc2b9f7f431f9ceefafda858db7
diff --git a/services/surfaceflinger/FrontEnd/LayerHierarchy.cpp b/services/surfaceflinger/FrontEnd/LayerHierarchy.cpp
index ab4c15d..962dc09 100644
--- a/services/surfaceflinger/FrontEnd/LayerHierarchy.cpp
+++ b/services/surfaceflinger/FrontEnd/LayerHierarchy.cpp
@@ -60,9 +60,9 @@
return;
}
}
- if (traversalPath.hasRelZLoop()) {
- LOG_ALWAYS_FATAL("Found relative z loop layerId:%d", traversalPath.invalidRelativeRootId);
- }
+
+ LLOG_ALWAYS_FATAL_WITH_TRACE_IF(traversalPath.hasRelZLoop(), "Found relative z loop layerId:%d",
+ traversalPath.invalidRelativeRootId);
for (auto& [child, childVariant] : mChildren) {
ScopedAddToTraversalPath addChildToTraversalPath(traversalPath, child->mLayer->id,
childVariant);
@@ -104,9 +104,7 @@
[child](const std::pair<LayerHierarchy*, Variant>& x) {
return x.first == child;
});
- if (it == mChildren.end()) {
- LOG_ALWAYS_FATAL("Could not find child!");
- }
+ LLOG_ALWAYS_FATAL_WITH_TRACE_IF(it == mChildren.end(), "Could not find child!");
mChildren.erase(it);
}
@@ -119,11 +117,8 @@
[hierarchy](std::pair<LayerHierarchy*, Variant>& child) {
return child.first == hierarchy;
});
- if (it == mChildren.end()) {
- LOG_ALWAYS_FATAL("Could not find child!");
- } else {
- it->second = variant;
- }
+ LLOG_ALWAYS_FATAL_WITH_TRACE_IF(it == mChildren.end(), "Could not find child!");
+ it->second = variant;
}
const RequestedLayerState* LayerHierarchy::getLayer() const {
@@ -422,9 +417,8 @@
LayerHierarchy* LayerHierarchyBuilder::getHierarchyFromId(uint32_t layerId, bool crashOnFailure) {
auto it = mLayerIdToHierarchy.find(layerId);
if (it == mLayerIdToHierarchy.end()) {
- if (crashOnFailure) {
- LOG_ALWAYS_FATAL("Could not find hierarchy for layer id %d", layerId);
- }
+ LLOG_ALWAYS_FATAL_WITH_TRACE_IF(crashOnFailure, "Could not find hierarchy for layer id %d",
+ layerId);
return nullptr;
};
@@ -460,7 +454,7 @@
}
LayerHierarchy::TraversalPath LayerHierarchy::TraversalPath::getMirrorRoot() const {
- LOG_ALWAYS_FATAL_IF(!isClone(), "Cannot get mirror root of a non cloned node");
+ LLOG_ALWAYS_FATAL_WITH_TRACE_IF(!isClone(), "Cannot get mirror root of a non cloned node");
TraversalPath mirrorRootPath = *this;
mirrorRootPath.id = mirrorRootId;
return mirrorRootPath;
diff --git a/services/surfaceflinger/FrontEnd/LayerLifecycleManager.cpp b/services/surfaceflinger/FrontEnd/LayerLifecycleManager.cpp
index 1712137..a826ec1 100644
--- a/services/surfaceflinger/FrontEnd/LayerLifecycleManager.cpp
+++ b/services/surfaceflinger/FrontEnd/LayerLifecycleManager.cpp
@@ -45,11 +45,11 @@
for (auto& newLayer : newLayers) {
RequestedLayerState& layer = *newLayer.get();
auto [it, inserted] = mIdToLayer.try_emplace(layer.id, References{.owner = layer});
- if (!inserted) {
- LOG_ALWAYS_FATAL("Duplicate layer id found. New layer: %s Existing layer: %s",
- layer.getDebugString().c_str(),
- it->second.owner.getDebugString().c_str());
- }
+ LLOG_ALWAYS_FATAL_WITH_TRACE_IF(!inserted,
+ "Duplicate layer id found. New layer: %s Existing layer: "
+ "%s",
+ layer.getDebugString().c_str(),
+ it->second.owner.getDebugString().c_str());
mAddedLayers.push_back(newLayer.get());
mChangedLayers.push_back(newLayer.get());
layer.parentId = linkLayer(layer.parentId, layer.id);
@@ -85,14 +85,15 @@
}
}
-void LayerLifecycleManager::onHandlesDestroyed(const std::vector<uint32_t>& destroyedHandles,
- bool ignoreUnknownHandles) {
+void LayerLifecycleManager::onHandlesDestroyed(
+ const std::vector<std::pair<uint32_t, std::string /* debugName */>>& destroyedHandles,
+ bool ignoreUnknownHandles) {
std::vector<uint32_t> layersToBeDestroyed;
- for (const auto& layerId : destroyedHandles) {
+ for (const auto& [layerId, name] : destroyedHandles) {
auto it = mIdToLayer.find(layerId);
if (it == mIdToLayer.end()) {
- LOG_ALWAYS_FATAL_IF(!ignoreUnknownHandles, "%s Layerid not found %d", __func__,
- layerId);
+ LLOG_ALWAYS_FATAL_WITH_TRACE_IF(!ignoreUnknownHandles, "%s Layerid not found %s[%d]",
+ __func__, name.c_str(), layerId);
continue;
}
RequestedLayerState& layer = it->second.owner;
@@ -113,10 +114,8 @@
for (size_t i = 0; i < layersToBeDestroyed.size(); i++) {
uint32_t layerId = layersToBeDestroyed[i];
auto it = mIdToLayer.find(layerId);
- if (it == mIdToLayer.end()) {
- LOG_ALWAYS_FATAL("%s Layer with id %d not found", __func__, layerId);
- continue;
- }
+ LLOG_ALWAYS_FATAL_WITH_TRACE_IF(it == mIdToLayer.end(), "%s Layer with id %d not found",
+ __func__, layerId);
RequestedLayerState& layer = it->second.owner;
@@ -135,11 +134,9 @@
auto& references = it->second.references;
for (uint32_t linkedLayerId : references) {
RequestedLayerState* linkedLayer = getLayerFromId(linkedLayerId);
- if (!linkedLayer) {
- LOG_ALWAYS_FATAL("%s Layerid reference %d not found for %d", __func__,
- linkedLayerId, layer.id);
- continue;
- };
+ LLOG_ALWAYS_FATAL_WITH_TRACE_IF(!linkedLayer,
+ "%s Layerid reference %d not found for %d", __func__,
+ linkedLayerId, layer.id);
if (linkedLayer->parentId == layer.id) {
linkedLayer->parentId = UNASSIGNED_LAYER_ID;
if (linkedLayer->canBeDestroyed()) {
@@ -191,17 +188,17 @@
RequestedLayerState* layer = getLayerFromId(layerId);
if (layer == nullptr) {
- LOG_ALWAYS_FATAL_IF(!ignoreUnknownLayers, "%s Layer with layerid=%d not found",
- __func__, layerId);
+ LLOG_ALWAYS_FATAL_WITH_TRACE_IF(!ignoreUnknownLayers,
+ "%s Layer with layerid=%d not found", __func__,
+ layerId);
continue;
}
- if (!layer->handleAlive) {
- LOG_ALWAYS_FATAL("%s Layer's with layerid=%d) is not alive. Possible out of "
- "order LayerLifecycleManager updates",
- __func__, layerId);
- continue;
- }
+ LLOG_ALWAYS_FATAL_WITH_TRACE_IF(!layer->handleAlive,
+ "%s Layer's with layerid=%d) is not alive. Possible "
+ "out of "
+ "order LayerLifecycleManager updates",
+ __func__, layerId);
if (layer->changes.get() == 0) {
mChangedLayers.push_back(layer);
@@ -241,7 +238,7 @@
RequestedLayerState* bgColorLayer = getLayerFromId(layer->bgColorLayerId);
layer->bgColorLayerId = UNASSIGNED_LAYER_ID;
bgColorLayer->parentId = unlinkLayer(bgColorLayer->parentId, bgColorLayer->id);
- onHandlesDestroyed({bgColorLayer->id});
+ onHandlesDestroyed({{bgColorLayer->id, bgColorLayer->debugName}});
} else if (layer->bgColorLayerId != UNASSIGNED_LAYER_ID) {
RequestedLayerState* bgColorLayer = getLayerFromId(layer->bgColorLayerId);
bgColorLayer->color = layer->bgColor;
diff --git a/services/surfaceflinger/FrontEnd/LayerLifecycleManager.h b/services/surfaceflinger/FrontEnd/LayerLifecycleManager.h
index 48571bf..9aff78e 100644
--- a/services/surfaceflinger/FrontEnd/LayerLifecycleManager.h
+++ b/services/surfaceflinger/FrontEnd/LayerLifecycleManager.h
@@ -47,7 +47,8 @@
// Ignore unknown handles when iteroping with legacy front end. In the old world, we
// would create child layers which are not necessary with the new front end. This means
// we will get notified for handle changes that don't exist in the new front end.
- void onHandlesDestroyed(const std::vector<uint32_t>&, bool ignoreUnknownHandles = false);
+ void onHandlesDestroyed(const std::vector<std::pair<uint32_t, std::string /* debugName */>>&,
+ bool ignoreUnknownHandles = false);
// Detaches the layer from its relative parent to prevent a loop in the
// layer hierarchy. This overrides the RequestedLayerState and leaves
diff --git a/services/surfaceflinger/FrontEnd/LayerLog.h b/services/surfaceflinger/FrontEnd/LayerLog.h
index 4943483..3845dfe 100644
--- a/services/surfaceflinger/FrontEnd/LayerLog.h
+++ b/services/surfaceflinger/FrontEnd/LayerLog.h
@@ -16,6 +16,8 @@
#pragma once
+#include "Tracing/TransactionTracing.h"
+
// Uncomment to trace layer updates for a single layer
// #define LOG_LAYER 1
@@ -27,3 +29,17 @@
#endif
#define LLOGD(LAYER_ID, x, ...) ALOGD("[%d] %s " x, (LAYER_ID), __func__, ##__VA_ARGS__);
+
+#define LLOG_ALWAYS_FATAL_WITH_TRACE(...) \
+ do { \
+ TransactionTraceWriter::getInstance().invoke(__func__, /* overwrite= */ false); \
+ LOG_ALWAYS_FATAL(##__VA_ARGS__); \
+ } while (false)
+
+#define LLOG_ALWAYS_FATAL_WITH_TRACE_IF(cond, ...) \
+ do { \
+ if (__predict_false(cond)) { \
+ TransactionTraceWriter::getInstance().invoke(__func__, /* overwrite= */ false); \
+ } \
+ LOG_ALWAYS_FATAL_IF(cond, ##__VA_ARGS__); \
+ } while (false)
\ No newline at end of file
diff --git a/services/surfaceflinger/FrontEnd/LayerSnapshotBuilder.cpp b/services/surfaceflinger/FrontEnd/LayerSnapshotBuilder.cpp
index 159d0f0..21f1a4a 100644
--- a/services/surfaceflinger/FrontEnd/LayerSnapshotBuilder.cpp
+++ b/services/surfaceflinger/FrontEnd/LayerSnapshotBuilder.cpp
@@ -523,12 +523,9 @@
const Args& args, const LayerHierarchy& hierarchy,
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");
- }
+ LLOG_ALWAYS_FATAL_WITH_TRACE_IF(depth > 50,
+ "Cycle detected in LayerSnapshotBuilder. See "
+ "builder_stack_overflow_transactions.winscope");
const RequestedLayerState* layer = hierarchy.getLayer();
LayerSnapshot* snapshot = getSnapshot(traversalPath);
diff --git a/services/surfaceflinger/FrontEnd/TransactionHandler.cpp b/services/surfaceflinger/FrontEnd/TransactionHandler.cpp
index ca7c3c2..d3d9509 100644
--- a/services/surfaceflinger/FrontEnd/TransactionHandler.cpp
+++ b/services/surfaceflinger/FrontEnd/TransactionHandler.cpp
@@ -22,6 +22,7 @@
#include <cutils/trace.h>
#include <utils/Log.h>
#include <utils/Trace.h>
+#include "FrontEnd/LayerLog.h"
#include "TransactionHandler.h"
@@ -87,8 +88,8 @@
}
auto it = mPendingTransactionQueues.find(flushState.queueWithUnsignaledBuffer);
- LOG_ALWAYS_FATAL_IF(it == mPendingTransactionQueues.end(),
- "Could not find queue with unsignaled buffer!");
+ LLOG_ALWAYS_FATAL_WITH_TRACE_IF(it == mPendingTransactionQueues.end(),
+ "Could not find queue with unsignaled buffer!");
auto& queue = it->second;
popTransactionFromPending(transactions, flushState, queue);
diff --git a/services/surfaceflinger/FrontEnd/Update.h b/services/surfaceflinger/FrontEnd/Update.h
index e1449b6..e5cca8f 100644
--- a/services/surfaceflinger/FrontEnd/Update.h
+++ b/services/surfaceflinger/FrontEnd/Update.h
@@ -46,7 +46,7 @@
std::vector<LayerCreatedState> layerCreatedStates;
std::vector<std::unique_ptr<frontend::RequestedLayerState>> newLayers;
std::vector<LayerCreationArgs> layerCreationArgs;
- std::vector<uint32_t> destroyedHandles;
+ std::vector<std::pair<uint32_t, std::string /* debugName */>> destroyedHandles;
};
} // namespace android::surfaceflinger::frontend