Improve existing InputDispatcher traces
Previously, we traced using ATRACE_NAME inside an
if condition after checking if atrace was enabled. This was so that we
could avoid the addtional overhead of formatting the trace string when
there's no ongoing trace.
Since ATRACE_NAME is expected to be scoped trace of the call, doing it
inside an if condition means the scope of the trace ends immediately
once we leave the inner scope of the conditional. This essentially makes
all of our scoped traces point traces.
We get around this by adding a new helper macro ATRACE_NAME_IF that
takes a lambda that formats the message. This way, we can avoid the
formatting overhead and ensure the entire scope of the method is traced.
Bug: 210460522
Test: manual: take a trace with Perfetto
Change-Id: Ibee1e7dc5021296bdb5871dec59d8d4978fcf0c9
diff --git a/services/inputflinger/dispatcher/InputDispatcher.cpp b/services/inputflinger/dispatcher/InputDispatcher.cpp
index 630542f..b427c73 100644
--- a/services/inputflinger/dispatcher/InputDispatcher.cpp
+++ b/services/inputflinger/dispatcher/InputDispatcher.cpp
@@ -32,6 +32,7 @@
#endif
#include <input/InputDevice.h>
#include <input/PrintTools.h>
+#include <input/TraceTools.h>
#include <openssl/mem.h>
#include <powermanager/PowerManager.h>
#include <unistd.h>
@@ -3161,12 +3162,10 @@
const std::shared_ptr<Connection>& connection,
std::shared_ptr<EventEntry> eventEntry,
const InputTarget& inputTarget) {
- if (ATRACE_ENABLED()) {
- std::string message =
- StringPrintf("prepareDispatchCycleLocked(inputChannel=%s, id=0x%" PRIx32 ")",
- connection->getInputChannelName().c_str(), eventEntry->id);
- ATRACE_NAME(message.c_str());
- }
+ ATRACE_NAME_IF(ATRACE_ENABLED(), [&]() {
+ return StringPrintf("prepareDispatchCycleLocked(inputChannel=%s, id=0x%" PRIx32 ")",
+ connection->getInputChannelName().c_str(), eventEntry->id);
+ });
if (DEBUG_DISPATCH_CYCLE) {
ALOGD("channel '%s' ~ prepareDispatchCycle - flags=%s, "
"globalScaleFactor=%f, pointerIds=%s %s",
@@ -3231,12 +3230,10 @@
const std::shared_ptr<Connection>& connection,
std::shared_ptr<EventEntry> eventEntry,
const InputTarget& inputTarget) {
- if (ATRACE_ENABLED()) {
- std::string message =
- StringPrintf("enqueueDispatchEntriesLocked(inputChannel=%s, id=0x%" PRIx32 ")",
- connection->getInputChannelName().c_str(), eventEntry->id);
- ATRACE_NAME(message.c_str());
- }
+ ATRACE_NAME_IF(ATRACE_ENABLED(), [&]() {
+ return StringPrintf("enqueueDispatchEntriesLocked(inputChannel=%s, id=0x%" PRIx32 ")",
+ connection->getInputChannelName().c_str(), eventEntry->id);
+ });
LOG_ALWAYS_FATAL_IF(!inputTarget.flags.any(InputTarget::DISPATCH_MASK),
"No dispatch flags are set for %s", eventEntry->getDescription().c_str());
@@ -3266,12 +3263,11 @@
std::shared_ptr<EventEntry> eventEntry,
const InputTarget& inputTarget,
ftl::Flags<InputTarget::Flags> dispatchMode) {
- if (ATRACE_ENABLED()) {
- std::string message = StringPrintf("enqueueDispatchEntry(inputChannel=%s, dispatchMode=%s)",
- connection->getInputChannelName().c_str(),
- dispatchMode.string().c_str());
- ATRACE_NAME(message.c_str());
- }
+ ATRACE_NAME_IF(ATRACE_ENABLED(), [&]() {
+ return StringPrintf("enqueueDispatchEntry(inputChannel=%s, dispatchMode=%s)",
+ connection->getInputChannelName().c_str(),
+ dispatchMode.string().c_str());
+ });
ftl::Flags<InputTarget::Flags> inputTargetFlags = inputTarget.flags;
if (!inputTargetFlags.any(dispatchMode)) {
return;
@@ -3558,11 +3554,10 @@
void InputDispatcher::startDispatchCycleLocked(nsecs_t currentTime,
const std::shared_ptr<Connection>& connection) {
- if (ATRACE_ENABLED()) {
- std::string message = StringPrintf("startDispatchCycleLocked(inputChannel=%s)",
- connection->getInputChannelName().c_str());
- ATRACE_NAME(message.c_str());
- }
+ ATRACE_NAME_IF(ATRACE_ENABLED(), [&]() {
+ return StringPrintf("startDispatchCycleLocked(inputChannel=%s)",
+ connection->getInputChannelName().c_str());
+ });
if (DEBUG_DISPATCH_CYCLE) {
ALOGD("channel '%s' ~ startDispatchCycle", connection->getInputChannelName().c_str());
}
@@ -4136,12 +4131,10 @@
}
int32_t newId = mIdGenerator.nextId();
- if (ATRACE_ENABLED()) {
- std::string message = StringPrintf("Split MotionEvent(id=0x%" PRIx32
- ") to MotionEvent(id=0x%" PRIx32 ").",
- originalMotionEntry.id, newId);
- ATRACE_NAME(message.c_str());
- }
+ ATRACE_NAME_IF(ATRACE_ENABLED(), [&]() {
+ return StringPrintf("Split MotionEvent(id=0x%" PRIx32 ") to MotionEvent(id=0x%" PRIx32 ").",
+ originalMotionEntry.id, newId);
+ });
std::unique_ptr<MotionEntry> splitMotionEntry =
std::make_unique<MotionEntry>(newId, originalMotionEntry.eventTime,
originalMotionEntry.deviceId, originalMotionEntry.source,