blob: b5966d58372b018bd4219b701ea91c182adfaa03 [file] [log] [blame]
Vishnu Nair7891e962021-11-11 12:07:21 -08001/*
2 * Copyright 2021 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
17#undef LOG_TAG
18#define LOG_TAG "TransactionTracing"
19#define ATRACE_TAG ATRACE_TAG_GRAPHICS
20
21#include <android-base/stringprintf.h>
22#include <log/log.h>
23#include <utils/SystemClock.h>
24#include <utils/Trace.h>
25
26#include "RingBuffer.h"
27#include "TransactionTracing.h"
28
29namespace android {
30
31TransactionTracing::TransactionTracing() {
32 mBuffer = std::make_unique<
33 RingBuffer<proto::TransactionTraceFile, proto::TransactionTraceEntry>>();
34}
35
36TransactionTracing::~TransactionTracing() = default;
37
38bool TransactionTracing::enable() {
39 std::scoped_lock lock(mTraceLock);
40 if (mEnabled) {
41 return false;
42 }
43 mBuffer->setSize(mBufferSizeInBytes);
Vishnu Nair0cc69e12021-11-18 09:05:49 -080044 mStartingTimestamp = systemTime();
Vishnu Nair7891e962021-11-11 12:07:21 -080045 mEnabled = true;
46 {
47 std::scoped_lock lock(mMainThreadLock);
48 mDone = false;
49 mThread = std::thread(&TransactionTracing::loop, this);
50 }
51 return true;
52}
53
54bool TransactionTracing::disable() {
55 std::thread thread;
56 {
57 std::scoped_lock lock(mMainThreadLock);
58 mDone = true;
59 mTransactionsAvailableCv.notify_all();
60 thread = std::move(mThread);
61 }
62 if (thread.joinable()) {
63 thread.join();
64 }
65
66 std::scoped_lock lock(mTraceLock);
67 if (!mEnabled) {
68 return false;
69 }
70 mEnabled = false;
71
Vishnu Nair0cc69e12021-11-18 09:05:49 -080072 writeToFileLocked();
73 mBuffer->reset();
Vishnu Nair7891e962021-11-11 12:07:21 -080074 mQueuedTransactions.clear();
Vishnu Nair0cc69e12021-11-18 09:05:49 -080075 mStartingStates.clear();
76 mLayerHandles.clear();
Vishnu Nair7891e962021-11-11 12:07:21 -080077 return true;
78}
79
80bool TransactionTracing::isEnabled() const {
81 std::scoped_lock lock(mTraceLock);
82 return mEnabled;
83}
84
85status_t TransactionTracing::writeToFile() {
86 std::scoped_lock lock(mTraceLock);
87 if (!mEnabled) {
88 return STATUS_OK;
89 }
Vishnu Nair0cc69e12021-11-18 09:05:49 -080090 return writeToFileLocked();
91}
92
93status_t TransactionTracing::writeToFileLocked() {
Vishnu Nair7891e962021-11-11 12:07:21 -080094 proto::TransactionTraceFile fileProto = createTraceFileProto();
Vishnu Nair0cc69e12021-11-18 09:05:49 -080095 addStartingStateToProtoLocked(fileProto);
Vishnu Nair7891e962021-11-11 12:07:21 -080096 return mBuffer->writeToFile(fileProto, FILE_NAME);
97}
98
99void TransactionTracing::setBufferSize(size_t bufferSizeInBytes) {
100 std::scoped_lock lock(mTraceLock);
101 mBufferSizeInBytes = bufferSizeInBytes;
102 mBuffer->setSize(mBufferSizeInBytes);
103}
104
105proto::TransactionTraceFile TransactionTracing::createTraceFileProto() const {
106 proto::TransactionTraceFile proto;
107 proto.set_magic_number(uint64_t(proto::TransactionTraceFile_MagicNumber_MAGIC_NUMBER_H) << 32 |
108 proto::TransactionTraceFile_MagicNumber_MAGIC_NUMBER_L);
109 return proto;
110}
111
112void TransactionTracing::dump(std::string& result) const {
113 std::scoped_lock lock(mTraceLock);
114 base::StringAppendF(&result, "Transaction tracing state: %s\n",
115 mEnabled ? "enabled" : "disabled");
Vishnu Nair0cc69e12021-11-18 09:05:49 -0800116 base::StringAppendF(&result,
117 " queued transactions=%zu created layers=%zu handles=%zu states=%zu\n",
118 mQueuedTransactions.size(), mCreatedLayers.size(), mLayerHandles.size(),
119 mStartingStates.size());
Vishnu Nair7891e962021-11-11 12:07:21 -0800120 mBuffer->dump(result);
121}
122
123void TransactionTracing::addQueuedTransaction(const TransactionState& transaction) {
124 std::scoped_lock lock(mTraceLock);
125 ATRACE_CALL();
126 if (!mEnabled) {
127 return;
128 }
129 mQueuedTransactions[transaction.id] =
Vishnu Nair0cc69e12021-11-18 09:05:49 -0800130 TransactionProtoParser::toProto(transaction,
131 std::bind(&TransactionTracing::getLayerIdLocked, this,
132 std::placeholders::_1),
133 nullptr);
Vishnu Nair7891e962021-11-11 12:07:21 -0800134}
135
136void TransactionTracing::addCommittedTransactions(std::vector<TransactionState>& transactions,
137 int64_t vsyncId) {
138 CommittedTransactions committedTransactions;
139 committedTransactions.vsyncId = vsyncId;
140 committedTransactions.timestamp = systemTime();
141 committedTransactions.transactionIds.reserve(transactions.size());
142 for (const auto& transaction : transactions) {
143 committedTransactions.transactionIds.emplace_back(transaction.id);
144 }
145
Vishnu Nair0cc69e12021-11-18 09:05:49 -0800146 mPendingTransactions.emplace_back(committedTransactions);
147 tryPushToTracingThread();
Vishnu Nair7891e962021-11-11 12:07:21 -0800148}
149
150void TransactionTracing::loop() {
151 while (true) {
152 std::vector<CommittedTransactions> committedTransactions;
Vishnu Nair0cc69e12021-11-18 09:05:49 -0800153 std::vector<int32_t> removedLayers;
Vishnu Nair7891e962021-11-11 12:07:21 -0800154 {
155 std::unique_lock<std::mutex> lock(mMainThreadLock);
156 base::ScopedLockAssertion assumeLocked(mMainThreadLock);
157 mTransactionsAvailableCv.wait(lock, [&]() REQUIRES(mMainThreadLock) {
158 return mDone || !mCommittedTransactions.empty();
159 });
160 if (mDone) {
161 mCommittedTransactions.clear();
Vishnu Nair0cc69e12021-11-18 09:05:49 -0800162 mRemovedLayers.clear();
Vishnu Nair7891e962021-11-11 12:07:21 -0800163 break;
164 }
Vishnu Nair0cc69e12021-11-18 09:05:49 -0800165
166 removedLayers = std::move(mRemovedLayers);
167 mRemovedLayers.clear();
Vishnu Nair7891e962021-11-11 12:07:21 -0800168 committedTransactions = std::move(mCommittedTransactions);
169 mCommittedTransactions.clear();
170 } // unlock mMainThreadLock
171
Vishnu Nair0cc69e12021-11-18 09:05:49 -0800172 addEntry(committedTransactions, removedLayers);
Vishnu Nair7891e962021-11-11 12:07:21 -0800173 }
174}
175
Vishnu Nair0cc69e12021-11-18 09:05:49 -0800176void TransactionTracing::addEntry(const std::vector<CommittedTransactions>& committedTransactions,
177 const std::vector<int32_t>& removedLayers) {
Vishnu Nair7891e962021-11-11 12:07:21 -0800178 ATRACE_CALL();
179 std::scoped_lock lock(mTraceLock);
Vishnu Nair62863552021-12-10 13:34:48 -0800180 std::vector<std::string> removedEntries;
181 proto::TransactionTraceEntry entryProto;
Vishnu Nair7891e962021-11-11 12:07:21 -0800182 for (const CommittedTransactions& entry : committedTransactions) {
Vishnu Nair7891e962021-11-11 12:07:21 -0800183 entryProto.set_elapsed_realtime_nanos(entry.timestamp);
184 entryProto.set_vsync_id(entry.vsyncId);
Vishnu Nair0cc69e12021-11-18 09:05:49 -0800185 entryProto.mutable_added_layers()->Reserve(static_cast<int32_t>(mCreatedLayers.size()));
186 for (auto& newLayer : mCreatedLayers) {
187 entryProto.mutable_added_layers()->Add(std::move(newLayer));
188 }
189 entryProto.mutable_removed_layers()->Reserve(static_cast<int32_t>(removedLayers.size()));
190 for (auto& removedLayer : removedLayers) {
191 entryProto.mutable_removed_layers()->Add(removedLayer);
192 }
193 mCreatedLayers.clear();
Vishnu Nair7891e962021-11-11 12:07:21 -0800194 entryProto.mutable_transactions()->Reserve(
195 static_cast<int32_t>(entry.transactionIds.size()));
196 for (const uint64_t& id : entry.transactionIds) {
197 auto it = mQueuedTransactions.find(id);
198 if (it != mQueuedTransactions.end()) {
199 entryProto.mutable_transactions()->Add(std::move(it->second));
200 mQueuedTransactions.erase(it);
201 } else {
Vishnu Nair047fb332021-12-09 09:54:36 -0800202 ALOGW("Could not find transaction id %" PRIu64, id);
Vishnu Nair7891e962021-11-11 12:07:21 -0800203 }
204 }
Vishnu Nair62863552021-12-10 13:34:48 -0800205
206 std::string serializedProto;
207 entryProto.SerializeToString(&serializedProto);
208 entryProto.Clear();
209 std::vector<std::string> entries = mBuffer->emplace(std::move(serializedProto));
210 removedEntries.reserve(removedEntries.size() + entries.size());
Vishnu Nair0cc69e12021-11-18 09:05:49 -0800211 removedEntries.insert(removedEntries.end(), std::make_move_iterator(entries.begin()),
212 std::make_move_iterator(entries.end()));
213 }
214
Vishnu Nair62863552021-12-10 13:34:48 -0800215 proto::TransactionTraceEntry removedEntryProto;
216 for (const std::string& removedEntry : removedEntries) {
217 removedEntryProto.ParseFromString(removedEntry);
218 updateStartingStateLocked(removedEntryProto);
219 removedEntryProto.Clear();
Vishnu Nair0cc69e12021-11-18 09:05:49 -0800220 }
221 mTransactionsAddedToBufferCv.notify_one();
222}
223
224void TransactionTracing::flush(int64_t vsyncId) {
225 while (!mPendingTransactions.empty() || !mPendingRemovedLayers.empty()) {
226 tryPushToTracingThread();
227 }
228 std::unique_lock<std::mutex> lock(mTraceLock);
229 base::ScopedLockAssertion assumeLocked(mTraceLock);
230 mTransactionsAddedToBufferCv.wait(lock, [&]() REQUIRES(mTraceLock) {
Vishnu Nair62863552021-12-10 13:34:48 -0800231 proto::TransactionTraceEntry entry;
232 if (mBuffer->used() > 0) {
233 entry.ParseFromString(mBuffer->back());
234 }
235 return mBuffer->used() > 0 && entry.vsync_id() >= vsyncId;
Vishnu Nair0cc69e12021-11-18 09:05:49 -0800236 });
237}
238
239void TransactionTracing::onLayerAdded(BBinder* layerHandle, int layerId, const std::string& name,
240 uint32_t flags, int parentId) {
241 std::scoped_lock lock(mTraceLock);
Vishnu Nair84125ac2021-12-02 08:47:48 -0800242 TracingLayerCreationArgs args{layerId, name, flags, parentId, -1 /* mirrorFromId */};
Vishnu Nair047fb332021-12-09 09:54:36 -0800243 if (mLayerHandles.find(layerHandle) != mLayerHandles.end()) {
244 ALOGW("Duplicate handles found. %p", layerHandle);
245 }
Vishnu Nair84125ac2021-12-02 08:47:48 -0800246 mLayerHandles[layerHandle] = layerId;
247 proto::LayerCreationArgs protoArgs = TransactionProtoParser::toProto(args);
248 proto::LayerCreationArgs protoArgsCopy = protoArgs;
249 mCreatedLayers.push_back(protoArgs);
250}
251
252void TransactionTracing::onMirrorLayerAdded(BBinder* layerHandle, int layerId,
253 const std::string& name, int mirrorFromId) {
254 std::scoped_lock lock(mTraceLock);
255 TracingLayerCreationArgs args{layerId, name, 0 /* flags */, -1 /* parentId */, mirrorFromId};
Vishnu Nair047fb332021-12-09 09:54:36 -0800256 if (mLayerHandles.find(layerHandle) != mLayerHandles.end()) {
257 ALOGW("Duplicate handles found. %p", layerHandle);
258 }
Vishnu Nair0cc69e12021-11-18 09:05:49 -0800259 mLayerHandles[layerHandle] = layerId;
260 mCreatedLayers.emplace_back(TransactionProtoParser::toProto(args));
261}
262
263void TransactionTracing::onLayerRemoved(int32_t layerId) {
264 mPendingRemovedLayers.emplace_back(layerId);
265 tryPushToTracingThread();
266}
267
Vishnu Nair047fb332021-12-09 09:54:36 -0800268void TransactionTracing::onHandleRemoved(BBinder* layerHandle) {
269 std::scoped_lock lock(mTraceLock);
270 mLayerHandles.erase(layerHandle);
271}
272
Vishnu Nair0cc69e12021-11-18 09:05:49 -0800273void TransactionTracing::tryPushToTracingThread() {
274 // Try to acquire the lock from main thread.
275 if (mMainThreadLock.try_lock()) {
276 // We got the lock! Collect any pending transactions and continue.
277 mCommittedTransactions.insert(mCommittedTransactions.end(),
278 std::make_move_iterator(mPendingTransactions.begin()),
279 std::make_move_iterator(mPendingTransactions.end()));
280 mPendingTransactions.clear();
281 mRemovedLayers.insert(mRemovedLayers.end(), mPendingRemovedLayers.begin(),
282 mPendingRemovedLayers.end());
283 mPendingRemovedLayers.clear();
284 mTransactionsAvailableCv.notify_one();
285 mMainThreadLock.unlock();
286 } else {
287 ALOGV("Couldn't get lock");
Vishnu Nair7891e962021-11-11 12:07:21 -0800288 }
289}
290
Vishnu Nair0cc69e12021-11-18 09:05:49 -0800291int32_t TransactionTracing::getLayerIdLocked(const sp<IBinder>& layerHandle) {
292 if (layerHandle == nullptr) {
293 return -1;
294 }
295 auto it = mLayerHandles.find(layerHandle->localBinder());
Vishnu Nair047fb332021-12-09 09:54:36 -0800296 if (it == mLayerHandles.end()) {
297 ALOGW("Could not find layer handle %p", layerHandle->localBinder());
298 return -1;
299 }
300 return it->second;
Vishnu Nair0cc69e12021-11-18 09:05:49 -0800301}
302
303void TransactionTracing::updateStartingStateLocked(
304 const proto::TransactionTraceEntry& removedEntry) {
305 // Keep track of layer starting state so we can reconstruct the layer state as we purge
306 // transactions from the buffer.
307 for (const proto::LayerCreationArgs& addedLayer : removedEntry.added_layers()) {
308 TracingLayerState& startingState = mStartingStates[addedLayer.layer_id()];
309 startingState.layerId = addedLayer.layer_id();
Vishnu Nair84125ac2021-12-02 08:47:48 -0800310 TransactionProtoParser::fromProto(addedLayer, startingState.args);
Vishnu Nair0cc69e12021-11-18 09:05:49 -0800311 }
312
313 // Merge layer states to starting transaction state.
314 for (const proto::TransactionState& transaction : removedEntry.transactions()) {
315 for (const proto::LayerState& layerState : transaction.layer_changes()) {
316 auto it = mStartingStates.find(layerState.layer_id());
317 if (it == mStartingStates.end()) {
Vishnu Nair047fb332021-12-09 09:54:36 -0800318 ALOGW("Could not find layer id %d", layerState.layer_id());
Vishnu Nair0cc69e12021-11-18 09:05:49 -0800319 continue;
320 }
321 TransactionProtoParser::fromProto(layerState, nullptr, it->second);
322 }
323 }
324
325 // Clean up stale starting states since the layer has been removed and the buffer does not
326 // contain any references to the layer.
327 for (const int32_t removedLayerId : removedEntry.removed_layers()) {
Vishnu Nair0cc69e12021-11-18 09:05:49 -0800328 mStartingStates.erase(removedLayerId);
329 }
330}
331
332void TransactionTracing::addStartingStateToProtoLocked(proto::TransactionTraceFile& proto) {
333 proto::TransactionTraceEntry* entryProto = proto.add_entry();
334 entryProto->set_elapsed_realtime_nanos(mStartingTimestamp);
335 entryProto->set_vsync_id(0);
Vishnu Nair84125ac2021-12-02 08:47:48 -0800336 if (mStartingStates.size() == 0) {
337 return;
338 }
339
Vishnu Nair0cc69e12021-11-18 09:05:49 -0800340 entryProto->mutable_added_layers()->Reserve(static_cast<int32_t>(mStartingStates.size()));
341 for (auto& [layerId, state] : mStartingStates) {
Vishnu Nair84125ac2021-12-02 08:47:48 -0800342 entryProto->mutable_added_layers()->Add(TransactionProtoParser::toProto(state.args));
Vishnu Nair0cc69e12021-11-18 09:05:49 -0800343 }
344
345 proto::TransactionState transactionProto = TransactionProtoParser::toProto(mStartingStates);
346 transactionProto.set_vsync_id(0);
347 transactionProto.set_post_time(mStartingTimestamp);
348 entryProto->mutable_transactions()->Add(std::move(transactionProto));
349}
350
351proto::TransactionTraceFile TransactionTracing::writeToProto() {
352 std::scoped_lock<std::mutex> lock(mTraceLock);
353 proto::TransactionTraceFile proto = createTraceFileProto();
354 addStartingStateToProtoLocked(proto);
355 mBuffer->writeToProto(proto);
356 return proto;
Vishnu Nair7891e962021-11-11 12:07:21 -0800357}
358
359} // namespace android