1 /*
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 "ClientCache.h"
27 #include "TransactionTracing.h"
28 #include "renderengine/ExternalTexture.h"
29
30 namespace android {
31
32 // Keeps the binder address as the layer id so we can avoid holding the tracing lock in the
33 // binder thread.
34 class FlatDataMapper : public TransactionProtoParser::FlingerDataMapper {
35 public:
getLayerId(const sp<IBinder> & layerHandle) const36 virtual int64_t getLayerId(const sp<IBinder>& layerHandle) const {
37 if (layerHandle == nullptr) {
38 return -1;
39 }
40
41 return reinterpret_cast<int64_t>(layerHandle->localBinder());
42 }
43
getGraphicBufferPropertiesFromCache(client_cache_t cachedBuffer,uint64_t * outBufferId,uint32_t * outWidth,uint32_t * outHeight,int32_t * outPixelFormat,uint64_t * outUsage) const44 void getGraphicBufferPropertiesFromCache(client_cache_t cachedBuffer, uint64_t* outBufferId,
45 uint32_t* outWidth, uint32_t* outHeight,
46 int32_t* outPixelFormat,
47 uint64_t* outUsage) const override {
48 std::shared_ptr<renderengine::ExternalTexture> buffer =
49 ClientCache::getInstance().get(cachedBuffer);
50 if (!buffer || !buffer->getBuffer()) {
51 *outBufferId = 0;
52 *outWidth = 0;
53 *outHeight = 0;
54 *outPixelFormat = 0;
55 *outUsage = 0;
56 return;
57 }
58
59 *outBufferId = buffer->getId();
60 *outWidth = buffer->getWidth();
61 *outHeight = buffer->getHeight();
62 *outPixelFormat = buffer->getPixelFormat();
63 *outUsage = buffer->getUsage();
64 return;
65 }
66 };
67
68 class FlingerDataMapper : public FlatDataMapper {
69 std::unordered_map<BBinder* /* layerHandle */, int32_t /* layerId */>& mLayerHandles;
70
71 public:
FlingerDataMapper(std::unordered_map<BBinder *,int32_t> & layerHandles)72 FlingerDataMapper(std::unordered_map<BBinder* /* handle */, int32_t /* id */>& layerHandles)
73 : mLayerHandles(layerHandles) {}
74
getLayerId(const sp<IBinder> & layerHandle) const75 int64_t getLayerId(const sp<IBinder>& layerHandle) const override {
76 if (layerHandle == nullptr) {
77 return -1;
78 }
79 return getLayerId(layerHandle->localBinder());
80 }
81
getLayerId(BBinder * localBinder) const82 int64_t getLayerId(BBinder* localBinder) const {
83 auto it = mLayerHandles.find(localBinder);
84 if (it == mLayerHandles.end()) {
85 ALOGW("Could not find layer handle %p", localBinder);
86 return -1;
87 }
88 return it->second;
89 }
90 };
91
TransactionTracing()92 TransactionTracing::TransactionTracing()
93 : mProtoParser(std::make_unique<FlingerDataMapper>(mLayerHandles)),
94 mLockfreeProtoParser(std::make_unique<FlatDataMapper>()) {
95 std::scoped_lock lock(mTraceLock);
96
97 mBuffer.setSize(mBufferSizeInBytes);
98 mStartingTimestamp = systemTime();
99 {
100 std::scoped_lock lock(mMainThreadLock);
101 mThread = std::thread(&TransactionTracing::loop, this);
102 }
103 }
104
~TransactionTracing()105 TransactionTracing::~TransactionTracing() {
106 std::thread thread;
107 {
108 std::scoped_lock lock(mMainThreadLock);
109 mDone = true;
110 mTransactionsAvailableCv.notify_all();
111 thread = std::move(mThread);
112 }
113 if (thread.joinable()) {
114 thread.join();
115 }
116
117 writeToFile();
118 }
119
writeToFile(std::string filename)120 status_t TransactionTracing::writeToFile(std::string filename) {
121 std::scoped_lock lock(mTraceLock);
122 proto::TransactionTraceFile fileProto = createTraceFileProto();
123 addStartingStateToProtoLocked(fileProto);
124 return mBuffer.writeToFile(fileProto, filename);
125 }
126
setBufferSize(size_t bufferSizeInBytes)127 void TransactionTracing::setBufferSize(size_t bufferSizeInBytes) {
128 std::scoped_lock lock(mTraceLock);
129 mBufferSizeInBytes = bufferSizeInBytes;
130 mBuffer.setSize(mBufferSizeInBytes);
131 }
132
createTraceFileProto() const133 proto::TransactionTraceFile TransactionTracing::createTraceFileProto() const {
134 proto::TransactionTraceFile proto;
135 proto.set_magic_number(uint64_t(proto::TransactionTraceFile_MagicNumber_MAGIC_NUMBER_H) << 32 |
136 proto::TransactionTraceFile_MagicNumber_MAGIC_NUMBER_L);
137 return proto;
138 }
139
dump(std::string & result) const140 void TransactionTracing::dump(std::string& result) const {
141 std::scoped_lock lock(mTraceLock);
142 base::StringAppendF(&result,
143 " queued transactions=%zu created layers=%zu handles=%zu states=%zu\n",
144 mQueuedTransactions.size(), mCreatedLayers.size(), mLayerHandles.size(),
145 mStartingStates.size());
146 mBuffer.dump(result);
147 }
148
addQueuedTransaction(const TransactionState & transaction)149 void TransactionTracing::addQueuedTransaction(const TransactionState& transaction) {
150 proto::TransactionState* state =
151 new proto::TransactionState(mLockfreeProtoParser.toProto(transaction));
152 mTransactionQueue.push(state);
153 }
154
addCommittedTransactions(std::vector<TransactionState> & transactions,int64_t vsyncId)155 void TransactionTracing::addCommittedTransactions(std::vector<TransactionState>& transactions,
156 int64_t vsyncId) {
157 CommittedTransactions committedTransactions;
158 committedTransactions.vsyncId = vsyncId;
159 committedTransactions.timestamp = systemTime();
160 committedTransactions.transactionIds.reserve(transactions.size());
161 for (const auto& transaction : transactions) {
162 committedTransactions.transactionIds.emplace_back(transaction.id);
163 }
164
165 mPendingTransactions.emplace_back(committedTransactions);
166 tryPushToTracingThread();
167 }
168
loop()169 void TransactionTracing::loop() {
170 while (true) {
171 std::vector<CommittedTransactions> committedTransactions;
172 std::vector<int32_t> removedLayers;
173 {
174 std::unique_lock<std::mutex> lock(mMainThreadLock);
175 base::ScopedLockAssertion assumeLocked(mMainThreadLock);
176 mTransactionsAvailableCv.wait(lock, [&]() REQUIRES(mMainThreadLock) {
177 return mDone || !mCommittedTransactions.empty();
178 });
179 if (mDone) {
180 mCommittedTransactions.clear();
181 mRemovedLayers.clear();
182 break;
183 }
184
185 removedLayers = std::move(mRemovedLayers);
186 mRemovedLayers.clear();
187 committedTransactions = std::move(mCommittedTransactions);
188 mCommittedTransactions.clear();
189 } // unlock mMainThreadLock
190
191 if (!committedTransactions.empty() || !removedLayers.empty()) {
192 addEntry(committedTransactions, removedLayers);
193 }
194 }
195 }
196
addEntry(const std::vector<CommittedTransactions> & committedTransactions,const std::vector<int32_t> & removedLayers)197 void TransactionTracing::addEntry(const std::vector<CommittedTransactions>& committedTransactions,
198 const std::vector<int32_t>& removedLayers) {
199 ATRACE_CALL();
200 std::scoped_lock lock(mTraceLock);
201 std::vector<std::string> removedEntries;
202 proto::TransactionTraceEntry entryProto;
203
204 while (auto incomingTransaction = mTransactionQueue.pop()) {
205 auto transaction = *incomingTransaction;
206 int32_t layerCount = transaction.layer_changes_size();
207 for (int i = 0; i < layerCount; i++) {
208 auto layer = transaction.mutable_layer_changes(i);
209 layer->set_layer_id(
210 mProtoParser.mMapper->getLayerId(reinterpret_cast<BBinder*>(layer->layer_id())));
211 if ((layer->what() & layer_state_t::eReparent) && layer->parent_id() != -1) {
212 layer->set_parent_id(
213 mProtoParser.mMapper->getLayerId(reinterpret_cast<BBinder*>(
214 layer->parent_id())));
215 }
216
217 if ((layer->what() & layer_state_t::eRelativeLayerChanged) &&
218 layer->relative_parent_id() != -1) {
219 layer->set_relative_parent_id(
220 mProtoParser.mMapper->getLayerId(reinterpret_cast<BBinder*>(
221 layer->relative_parent_id())));
222 }
223
224 if (layer->has_window_info_handle() &&
225 layer->window_info_handle().crop_layer_id() != -1) {
226 auto input = layer->mutable_window_info_handle();
227 input->set_crop_layer_id(
228 mProtoParser.mMapper->getLayerId(reinterpret_cast<BBinder*>(
229 input->crop_layer_id())));
230 }
231 }
232 mQueuedTransactions[incomingTransaction->transaction_id()] = transaction;
233 delete incomingTransaction;
234 }
235 for (const CommittedTransactions& entry : committedTransactions) {
236 entryProto.set_elapsed_realtime_nanos(entry.timestamp);
237 entryProto.set_vsync_id(entry.vsyncId);
238 entryProto.mutable_added_layers()->Reserve(static_cast<int32_t>(mCreatedLayers.size()));
239 for (auto& newLayer : mCreatedLayers) {
240 entryProto.mutable_added_layers()->Add(std::move(newLayer));
241 }
242 entryProto.mutable_removed_layers()->Reserve(static_cast<int32_t>(removedLayers.size()));
243 for (auto& removedLayer : removedLayers) {
244 entryProto.mutable_removed_layers()->Add(removedLayer);
245 }
246 mCreatedLayers.clear();
247 entryProto.mutable_transactions()->Reserve(
248 static_cast<int32_t>(entry.transactionIds.size()));
249 for (const uint64_t& id : entry.transactionIds) {
250 auto it = mQueuedTransactions.find(id);
251 if (it != mQueuedTransactions.end()) {
252 entryProto.mutable_transactions()->Add(std::move(it->second));
253 mQueuedTransactions.erase(it);
254 } else {
255 ALOGW("Could not find transaction id %" PRIu64, id);
256 }
257 }
258
259 std::string serializedProto;
260 entryProto.SerializeToString(&serializedProto);
261 entryProto.Clear();
262 std::vector<std::string> entries = mBuffer.emplace(std::move(serializedProto));
263 removedEntries.reserve(removedEntries.size() + entries.size());
264 removedEntries.insert(removedEntries.end(), std::make_move_iterator(entries.begin()),
265 std::make_move_iterator(entries.end()));
266
267 entryProto.mutable_removed_layer_handles()->Reserve(
268 static_cast<int32_t>(mRemovedLayerHandles.size()));
269 for (auto& handle : mRemovedLayerHandles) {
270 entryProto.mutable_removed_layer_handles()->Add(handle);
271 }
272 mRemovedLayerHandles.clear();
273 }
274
275 proto::TransactionTraceEntry removedEntryProto;
276 for (const std::string& removedEntry : removedEntries) {
277 removedEntryProto.ParseFromString(removedEntry);
278 updateStartingStateLocked(removedEntryProto);
279 removedEntryProto.Clear();
280 }
281 mTransactionsAddedToBufferCv.notify_one();
282 }
283
flush(int64_t vsyncId)284 void TransactionTracing::flush(int64_t vsyncId) {
285 while (!mPendingTransactions.empty() || !mPendingRemovedLayers.empty()) {
286 tryPushToTracingThread();
287 }
288 std::unique_lock<std::mutex> lock(mTraceLock);
289 base::ScopedLockAssertion assumeLocked(mTraceLock);
290 mTransactionsAddedToBufferCv.wait(lock, [&]() REQUIRES(mTraceLock) {
291 proto::TransactionTraceEntry entry;
292 if (mBuffer.used() > 0) {
293 entry.ParseFromString(mBuffer.back());
294 }
295 return mBuffer.used() > 0 && entry.vsync_id() >= vsyncId;
296 });
297 }
298
onLayerAdded(BBinder * layerHandle,int layerId,const std::string & name,uint32_t flags,int parentId)299 void TransactionTracing::onLayerAdded(BBinder* layerHandle, int layerId, const std::string& name,
300 uint32_t flags, int parentId) {
301 std::scoped_lock lock(mTraceLock);
302 TracingLayerCreationArgs args{layerId, name, flags, parentId, -1 /* mirrorFromId */};
303 if (mLayerHandles.find(layerHandle) != mLayerHandles.end()) {
304 ALOGW("Duplicate handles found. %p", layerHandle);
305 }
306 mLayerHandles[layerHandle] = layerId;
307 mCreatedLayers.push_back(mProtoParser.toProto(args));
308 }
309
onMirrorLayerAdded(BBinder * layerHandle,int layerId,const std::string & name,int mirrorFromId)310 void TransactionTracing::onMirrorLayerAdded(BBinder* layerHandle, int layerId,
311 const std::string& name, int mirrorFromId) {
312 std::scoped_lock lock(mTraceLock);
313 TracingLayerCreationArgs args{layerId, name, 0 /* flags */, -1 /* parentId */, mirrorFromId};
314 if (mLayerHandles.find(layerHandle) != mLayerHandles.end()) {
315 ALOGW("Duplicate handles found. %p", layerHandle);
316 }
317 mLayerHandles[layerHandle] = layerId;
318 mCreatedLayers.emplace_back(mProtoParser.toProto(args));
319 }
320
onLayerRemoved(int32_t layerId)321 void TransactionTracing::onLayerRemoved(int32_t layerId) {
322 mPendingRemovedLayers.emplace_back(layerId);
323 tryPushToTracingThread();
324 }
325
onHandleRemoved(BBinder * layerHandle)326 void TransactionTracing::onHandleRemoved(BBinder* layerHandle) {
327 std::scoped_lock lock(mTraceLock);
328 auto it = mLayerHandles.find(layerHandle);
329 if (it == mLayerHandles.end()) {
330 ALOGW("handle not found. %p", layerHandle);
331 return;
332 }
333
334 mRemovedLayerHandles.push_back(it->second);
335 mLayerHandles.erase(it);
336 }
337
tryPushToTracingThread()338 void TransactionTracing::tryPushToTracingThread() {
339 // Try to acquire the lock from main thread.
340 if (mMainThreadLock.try_lock()) {
341 // We got the lock! Collect any pending transactions and continue.
342 mCommittedTransactions.insert(mCommittedTransactions.end(),
343 std::make_move_iterator(mPendingTransactions.begin()),
344 std::make_move_iterator(mPendingTransactions.end()));
345 mPendingTransactions.clear();
346 mRemovedLayers.insert(mRemovedLayers.end(), mPendingRemovedLayers.begin(),
347 mPendingRemovedLayers.end());
348 mPendingRemovedLayers.clear();
349 mTransactionsAvailableCv.notify_one();
350 mMainThreadLock.unlock();
351 } else {
352 ALOGV("Couldn't get lock");
353 }
354 }
355
updateStartingStateLocked(const proto::TransactionTraceEntry & removedEntry)356 void TransactionTracing::updateStartingStateLocked(
357 const proto::TransactionTraceEntry& removedEntry) {
358 mStartingTimestamp = removedEntry.elapsed_realtime_nanos();
359 // Keep track of layer starting state so we can reconstruct the layer state as we purge
360 // transactions from the buffer.
361 for (const proto::LayerCreationArgs& addedLayer : removedEntry.added_layers()) {
362 TracingLayerState& startingState = mStartingStates[addedLayer.layer_id()];
363 startingState.layerId = addedLayer.layer_id();
364 mProtoParser.fromProto(addedLayer, startingState.args);
365 }
366
367 // Merge layer states to starting transaction state.
368 for (const proto::TransactionState& transaction : removedEntry.transactions()) {
369 for (const proto::LayerState& layerState : transaction.layer_changes()) {
370 auto it = mStartingStates.find((int32_t)layerState.layer_id());
371 if (it == mStartingStates.end()) {
372 ALOGW("Could not find layer id %d", (int32_t)layerState.layer_id());
373 continue;
374 }
375 mProtoParser.mergeFromProto(layerState, it->second);
376 }
377 }
378
379 // Clean up stale starting states since the layer has been removed and the buffer does not
380 // contain any references to the layer.
381 for (const int32_t removedLayerId : removedEntry.removed_layers()) {
382 mStartingStates.erase(removedLayerId);
383 }
384 }
385
addStartingStateToProtoLocked(proto::TransactionTraceFile & proto)386 void TransactionTracing::addStartingStateToProtoLocked(proto::TransactionTraceFile& proto) {
387 if (mStartingStates.size() == 0) {
388 return;
389 }
390
391 proto::TransactionTraceEntry* entryProto = proto.add_entry();
392 entryProto->set_elapsed_realtime_nanos(mStartingTimestamp);
393 entryProto->set_vsync_id(0);
394
395 entryProto->mutable_added_layers()->Reserve(static_cast<int32_t>(mStartingStates.size()));
396 for (auto& [layerId, state] : mStartingStates) {
397 entryProto->mutable_added_layers()->Add(mProtoParser.toProto(state.args));
398 }
399
400 proto::TransactionState transactionProto = mProtoParser.toProto(mStartingStates);
401 transactionProto.set_vsync_id(0);
402 transactionProto.set_post_time(mStartingTimestamp);
403 entryProto->mutable_transactions()->Add(std::move(transactionProto));
404 }
405
writeToProto()406 proto::TransactionTraceFile TransactionTracing::writeToProto() {
407 std::scoped_lock<std::mutex> lock(mTraceLock);
408 proto::TransactionTraceFile proto = createTraceFileProto();
409 addStartingStateToProtoLocked(proto);
410 mBuffer.writeToProto(proto);
411 return proto;
412 }
413
414 } // namespace android
415