SF: Add continuous transaction tracing
Add the ability to capture all incoming transactions into a ring
buffer. Capture transactions as the come in through the binder
thread. On the main thread push committed transactions to the
tracing thread which will then add to the buffer and purge
older entries as the buffer gets filled.
Also introduce a new flag to enable transaction tracing (disabled
by default).
Test: presubmit
Bug: 200284593
Change-Id: I90dd0fa4f89f68cfc7b7922ecd0bba4adab8d7a4
diff --git a/services/surfaceflinger/Tracing/RingBuffer.h b/services/surfaceflinger/Tracing/RingBuffer.h
index d0fb3f2..63a2786 100644
--- a/services/surfaceflinger/Tracing/RingBuffer.h
+++ b/services/surfaceflinger/Tracing/RingBuffer.h
@@ -21,8 +21,9 @@
#include <log/log.h>
#include <utils/Errors.h>
-#include <utils/SystemClock.h>
+#include <utils/Timers.h>
#include <utils/Trace.h>
+#include <chrono>
#include <queue>
namespace android {
@@ -57,9 +58,7 @@
status_t writeToFile(FileProto& fileProto, std::string filename) {
ATRACE_CALL();
std::string output;
- flush(fileProto);
- reset(mSizeInBytes);
- if (!fileProto.SerializeToString(&output)) {
+ if (!writeToString(fileProto, &output)) {
ALOGE("Could not serialize proto.");
return UNKNOWN_ERROR;
}
@@ -73,6 +72,13 @@
return NO_ERROR;
}
+ bool writeToString(FileProto& fileProto, std::string* outString) {
+ ATRACE_CALL();
+ flush(fileProto);
+ reset(mSizeInBytes);
+ return fileProto.SerializeToString(outString);
+ }
+
std::vector<EntryProto> emplace(EntryProto&& proto) {
std::vector<EntryProto> replacedEntries;
size_t protoSize = static_cast<size_t>(proto.ByteSize());
@@ -99,8 +105,8 @@
const int64_t durationCount = duration.count();
base::StringAppendF(&result,
" number of entries: %zu (%.2fMB / %.2fMB) duration: %" PRIi64 "ms\n",
- frameCount(), float(used()) / 1024.f * 1024.f,
- float(size()) / 1024.f * 1024.f, durationCount);
+ frameCount(), float(used()) / (1024.f * 1024.f),
+ float(size()) / (1024.f * 1024.f), durationCount);
}
private:
diff --git a/services/surfaceflinger/Tracing/TransactionTracing.cpp b/services/surfaceflinger/Tracing/TransactionTracing.cpp
new file mode 100644
index 0000000..758bd31
--- /dev/null
+++ b/services/surfaceflinger/Tracing/TransactionTracing.cpp
@@ -0,0 +1,203 @@
+/*
+ * Copyright 2021 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#undef LOG_TAG
+#define LOG_TAG "TransactionTracing"
+#define ATRACE_TAG ATRACE_TAG_GRAPHICS
+
+#include <android-base/stringprintf.h>
+#include <log/log.h>
+#include <utils/SystemClock.h>
+#include <utils/Trace.h>
+
+#include "RingBuffer.h"
+#include "TransactionTracing.h"
+
+namespace android {
+
+TransactionTracing::TransactionTracing() {
+ mBuffer = std::make_unique<
+ RingBuffer<proto::TransactionTraceFile, proto::TransactionTraceEntry>>();
+}
+
+TransactionTracing::~TransactionTracing() = default;
+
+bool TransactionTracing::enable() {
+ std::scoped_lock lock(mTraceLock);
+ if (mEnabled) {
+ return false;
+ }
+ mBuffer->setSize(mBufferSizeInBytes);
+ mEnabled = true;
+ {
+ std::scoped_lock lock(mMainThreadLock);
+ mDone = false;
+ mThread = std::thread(&TransactionTracing::loop, this);
+ }
+ return true;
+}
+
+bool TransactionTracing::disable() {
+ std::thread thread;
+ {
+ std::scoped_lock lock(mMainThreadLock);
+ mDone = true;
+ mTransactionsAvailableCv.notify_all();
+ thread = std::move(mThread);
+ }
+ if (thread.joinable()) {
+ thread.join();
+ }
+
+ std::scoped_lock lock(mTraceLock);
+ if (!mEnabled) {
+ return false;
+ }
+ mEnabled = false;
+
+ proto::TransactionTraceFile fileProto = createTraceFileProto();
+ mBuffer->writeToFile(fileProto, FILE_NAME);
+ mQueuedTransactions.clear();
+ return true;
+}
+
+bool TransactionTracing::isEnabled() const {
+ std::scoped_lock lock(mTraceLock);
+ return mEnabled;
+}
+
+status_t TransactionTracing::writeToFile() {
+ std::scoped_lock lock(mTraceLock);
+ if (!mEnabled) {
+ return STATUS_OK;
+ }
+ proto::TransactionTraceFile fileProto = createTraceFileProto();
+ return mBuffer->writeToFile(fileProto, FILE_NAME);
+}
+
+void TransactionTracing::setBufferSize(size_t bufferSizeInBytes) {
+ std::scoped_lock lock(mTraceLock);
+ mBufferSizeInBytes = bufferSizeInBytes;
+ mBuffer->setSize(mBufferSizeInBytes);
+}
+
+proto::TransactionTraceFile TransactionTracing::createTraceFileProto() const {
+ proto::TransactionTraceFile proto;
+ proto.set_magic_number(uint64_t(proto::TransactionTraceFile_MagicNumber_MAGIC_NUMBER_H) << 32 |
+ proto::TransactionTraceFile_MagicNumber_MAGIC_NUMBER_L);
+ return proto;
+}
+
+void TransactionTracing::dump(std::string& result) const {
+ std::scoped_lock lock(mTraceLock);
+ base::StringAppendF(&result, "Transaction tracing state: %s\n",
+ mEnabled ? "enabled" : "disabled");
+ base::StringAppendF(&result, " queued transactions: %d\n",
+ static_cast<uint32_t>(mQueuedTransactions.size()));
+ mBuffer->dump(result);
+}
+
+void TransactionTracing::addQueuedTransaction(const TransactionState& transaction) {
+ std::scoped_lock lock(mTraceLock);
+ ATRACE_CALL();
+ if (!mEnabled) {
+ return;
+ }
+ mQueuedTransactions[transaction.id] =
+ TransactionProtoParser::toProto(transaction, nullptr, nullptr);
+}
+
+void TransactionTracing::addCommittedTransactions(std::vector<TransactionState>& transactions,
+ int64_t vsyncId) {
+ CommittedTransactions committedTransactions;
+ committedTransactions.vsyncId = vsyncId;
+ committedTransactions.timestamp = systemTime();
+ committedTransactions.transactionIds.reserve(transactions.size());
+ for (const auto& transaction : transactions) {
+ committedTransactions.transactionIds.emplace_back(transaction.id);
+ }
+
+ // Try to acquire the lock from main thread, but don't block if we cannot acquire the lock. Add
+ // it to pending transactions that we can collect later.
+ if (mMainThreadLock.try_lock()) {
+ // We got the lock! Collect any pending transactions and continue.
+ mCommittedTransactions.insert(mCommittedTransactions.end(),
+ std::make_move_iterator(mPendingTransactions.begin()),
+ std::make_move_iterator(mPendingTransactions.end()));
+ mPendingTransactions.clear();
+ mCommittedTransactions.emplace_back(committedTransactions);
+ mTransactionsAvailableCv.notify_one();
+ mMainThreadLock.unlock();
+ } else {
+ mPendingTransactions.emplace_back(committedTransactions);
+ }
+}
+
+void TransactionTracing::loop() {
+ while (true) {
+ std::vector<CommittedTransactions> committedTransactions;
+ {
+ std::unique_lock<std::mutex> lock(mMainThreadLock);
+ base::ScopedLockAssertion assumeLocked(mMainThreadLock);
+ mTransactionsAvailableCv.wait(lock, [&]() REQUIRES(mMainThreadLock) {
+ return mDone || !mCommittedTransactions.empty();
+ });
+ if (mDone) {
+ mCommittedTransactions.clear();
+ break;
+ }
+ committedTransactions = std::move(mCommittedTransactions);
+ mCommittedTransactions.clear();
+ } // unlock mMainThreadLock
+
+ addEntry(committedTransactions);
+
+ mTransactionsAddedToBufferCv.notify_one();
+ }
+}
+
+void TransactionTracing::addEntry(const std::vector<CommittedTransactions>& committedTransactions) {
+ ATRACE_CALL();
+ std::scoped_lock lock(mTraceLock);
+ std::vector<proto::TransactionTraceEntry> removedEntries;
+ for (const CommittedTransactions& entry : committedTransactions) {
+ proto::TransactionTraceEntry entryProto;
+ entryProto.set_elapsed_realtime_nanos(entry.timestamp);
+ entryProto.set_vsync_id(entry.vsyncId);
+ entryProto.mutable_transactions()->Reserve(
+ static_cast<int32_t>(entry.transactionIds.size()));
+ for (const uint64_t& id : entry.transactionIds) {
+ auto it = mQueuedTransactions.find(id);
+ if (it != mQueuedTransactions.end()) {
+ entryProto.mutable_transactions()->Add(std::move(it->second));
+ mQueuedTransactions.erase(it);
+ } else {
+ ALOGE("Could not find transaction id %" PRIu64, id);
+ }
+ }
+ mBuffer->emplace(std::move(entryProto));
+ }
+}
+
+void TransactionTracing::flush() {
+ std::unique_lock<std::mutex> lock(mMainThreadLock);
+ base::ScopedLockAssertion assumeLocked(mMainThreadLock);
+ mTransactionsAddedToBufferCv.wait(lock, [&]() REQUIRES(mMainThreadLock) {
+ return mCommittedTransactions.empty();
+ });
+}
+
+} // namespace android
diff --git a/services/surfaceflinger/Tracing/TransactionTracing.h b/services/surfaceflinger/Tracing/TransactionTracing.h
new file mode 100644
index 0000000..d92ab01
--- /dev/null
+++ b/services/surfaceflinger/Tracing/TransactionTracing.h
@@ -0,0 +1,107 @@
+/*
+ * Copyright 2021 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#pragma once
+
+#include <android-base/thread_annotations.h>
+#include <layerproto/TransactionProto.h>
+#include <utils/Errors.h>
+#include <utils/Timers.h>
+
+#include <memory>
+#include <mutex>
+#include <thread>
+
+#include "TransactionProtoParser.h"
+
+using namespace android::surfaceflinger;
+
+namespace android {
+
+template <typename FileProto, typename EntryProto>
+class RingBuffer;
+
+class SurfaceFlinger;
+class TransactionTracingTest;
+/*
+ * Records all committed transactions into a ring bufffer.
+ *
+ * Transactions come in via the binder thread. They are serialized to proto
+ * and stored in a map using the transaction id as key. Main thread will
+ * pass the list of transaction ids that are committed every vsync and notify
+ * the tracing thread. The tracing thread will then wake up and add the
+ * committed transactions to the ring buffer.
+ *
+ * When generating SF dump state, we will flush the buffer to a file which
+ * will then be included in the bugreport.
+ *
+ */
+class TransactionTracing {
+public:
+ TransactionTracing();
+ ~TransactionTracing();
+
+ bool enable();
+ bool disable();
+ bool isEnabled() const;
+
+ void addQueuedTransaction(const TransactionState&);
+ void addCommittedTransactions(std::vector<TransactionState>& transactions, int64_t vsyncId);
+ status_t writeToFile();
+ void setBufferSize(size_t bufferSizeInBytes);
+ void dump(std::string&) const;
+ static constexpr auto CONTINUOUS_TRACING_BUFFER_SIZE = 512 * 1024;
+ static constexpr auto ACTIVE_TRACING_BUFFER_SIZE = 100 * 1024 * 1024;
+
+private:
+ friend class TransactionTracingTest;
+
+ static constexpr auto FILE_NAME = "/data/misc/wmtrace/transactions_trace.winscope";
+
+ mutable std::mutex mTraceLock;
+ bool mEnabled GUARDED_BY(mTraceLock) = false;
+ std::unique_ptr<RingBuffer<proto::TransactionTraceFile, proto::TransactionTraceEntry>> mBuffer
+ GUARDED_BY(mTraceLock);
+ size_t mBufferSizeInBytes GUARDED_BY(mTraceLock) = CONTINUOUS_TRACING_BUFFER_SIZE;
+ std::unordered_map<uint64_t, proto::TransactionState> mQueuedTransactions
+ GUARDED_BY(mTraceLock);
+
+ // We do not want main thread to block so main thread will try to acquire mMainThreadLock,
+ // otherwise will push data to temporary container.
+ std::mutex mMainThreadLock;
+ std::thread mThread GUARDED_BY(mMainThreadLock);
+ bool mDone GUARDED_BY(mMainThreadLock) = false;
+ std::condition_variable mTransactionsAvailableCv;
+ std::condition_variable mTransactionsAddedToBufferCv;
+ struct CommittedTransactions {
+ std::vector<uint64_t> transactionIds;
+ int64_t vsyncId;
+ int64_t timestamp;
+ };
+ std::vector<CommittedTransactions> mCommittedTransactions GUARDED_BY(mMainThreadLock);
+ std::vector<CommittedTransactions> mPendingTransactions; // only accessed by main thread
+ proto::TransactionTraceFile createTraceFileProto() const;
+
+ void loop();
+ void addEntry(const std::vector<CommittedTransactions>& committedTransactions)
+ EXCLUDES(mTraceLock);
+
+ // TEST
+ // Wait until all the committed transactions are added to the buffer.
+ void flush() EXCLUDES(mMainThreadLock);
+};
+
+} // namespace android