Added async trace functions with a track name argument
Bug: 221119585
Test: atest TraceDevTest
Change-Id: I48d9e858ce588e3735ddbbe14b1bd7c8f264cd83
diff --git a/libcutils/include/cutils/trace.h b/libcutils/include/cutils/trace.h
index 17a0070..98ae0d4 100644
--- a/libcutils/include/cutils/trace.h
+++ b/libcutils/include/cutils/trace.h
@@ -209,6 +209,37 @@
}
/**
+ * Trace the beginning of an asynchronous event. In addition to the name and a
+ * cookie as in ATRACE_ASYNC_BEGIN/ATRACE_ASYNC_END, a track name argument is
+ * provided, which is the name of the row where this async event should be
+ * recorded. The track name, name, and cookie used to begin an event must be
+ * used to end it.
+ */
+#define ATRACE_ASYNC_FOR_TRACK_BEGIN(track_name, name, cookie) \
+ atrace_async_for_track_begin(ATRACE_TAG, track_name, name, cookie)
+static inline void atrace_async_for_track_begin(uint64_t tag, const char* track_name,
+ const char* name, int32_t cookie) {
+ if (CC_UNLIKELY(atrace_is_tag_enabled(tag))) {
+ void atrace_async_for_track_begin_body(const char*, const char*, int32_t);
+ atrace_async_for_track_begin_body(track_name, name, cookie);
+ }
+}
+
+/**
+ * Trace the end of an asynchronous event.
+ * This should correspond to a previous ATRACE_ASYNC_FOR_TRACK_BEGIN.
+ */
+#define ATRACE_ASYNC_FOR_TRACK_END(track_name, name, cookie) \
+ atrace_async_for_track_end(ATRACE_TAG, track_name, name, cookie)
+static inline void atrace_async_for_track_end(uint64_t tag, const char* track_name,
+ const char* name, int32_t cookie) {
+ if (CC_UNLIKELY(atrace_is_tag_enabled(tag))) {
+ void atrace_async_for_track_end_body(const char*, const char*, int32_t);
+ atrace_async_for_track_end_body(track_name, name, cookie);
+ }
+}
+
+/**
* Trace an instantaneous context. name is used to identify the context.
*
* An "instant" is an event with no defined duration. Visually is displayed like a single marker
@@ -227,17 +258,18 @@
/**
* Trace an instantaneous context. name is used to identify the context.
- * trackName is the name of the row where the event should be recorded.
+ * track_name is the name of the row where the event should be recorded.
*
* An "instant" is an event with no defined duration. Visually is displayed like a single marker
* in the timeline (rather than a span, in the case of begin/end events).
*/
#define ATRACE_INSTANT_FOR_TRACK(trackName, name) \
atrace_instant_for_track(ATRACE_TAG, trackName, name)
-static inline void atrace_instant_for_track(uint64_t tag, const char* trackName, const char* name) {
+static inline void atrace_instant_for_track(uint64_t tag, const char* track_name,
+ const char* name) {
if (CC_UNLIKELY(atrace_is_tag_enabled(tag))) {
void atrace_instant_for_track_body(const char*, const char*);
- atrace_instant_for_track_body(trackName, name);
+ atrace_instant_for_track_body(track_name, name);
}
}
diff --git a/libcutils/trace-container.cpp b/libcutils/trace-container.cpp
index f3fdda4..8901e4a 100644
--- a/libcutils/trace-container.cpp
+++ b/libcutils/trace-container.cpp
@@ -229,6 +229,28 @@
WRITE_MSG("F|%d|", "|%" PRId32, "", name, cookie);
}
+void atrace_async_for_track_begin_body(const char* track_name, const char* name, int32_t cookie) {
+ if (CC_LIKELY(atrace_use_container_sock)) {
+ WRITE_MSG_IN_CONTAINER("T", "|", "|%d", track_name, name, cookie);
+ return;
+ }
+
+ if (atrace_marker_fd < 0) return;
+
+ WRITE_MSG("T|%d|", "|%" PRId32, track_name, name, cookie);
+}
+
+void atrace_async_for_track_end_body(const char* track_name, const char* name, int32_t cookie) {
+ if (CC_LIKELY(atrace_use_container_sock)) {
+ WRITE_MSG_IN_CONTAINER("U", "|", "|%d", track_name, name, cookie);
+ return;
+ }
+
+ if (atrace_marker_fd < 0) return;
+
+ WRITE_MSG("U|%d|", "|%" PRId32, track_name, name, cookie);
+}
+
void atrace_instant_body(const char* name) {
if (CC_LIKELY(atrace_use_container_sock)) {
WRITE_MSG_IN_CONTAINER("I", "|", "%s", "", name, "");
diff --git a/libcutils/trace-dev.cpp b/libcutils/trace-dev.cpp
index 8bdeac5..eacc8ee 100644
--- a/libcutils/trace-dev.cpp
+++ b/libcutils/trace-dev.cpp
@@ -89,6 +89,14 @@
WRITE_MSG("F|%d|", "|%" PRId32, "", name, cookie);
}
+void atrace_async_for_track_begin_body(const char* track_name, const char* name, int32_t cookie) {
+ WRITE_MSG("T|%d|", "|%" PRId32, track_name, name, cookie);
+}
+
+void atrace_async_for_track_end_body(const char* track_name, const char* name, int32_t cookie) {
+ WRITE_MSG("U|%d|", "|%" PRId32, track_name, name, cookie);
+}
+
void atrace_instant_body(const char* name) {
WRITE_MSG("I|%d|", "%s", "", name, "");
}
diff --git a/libcutils/trace-dev_test.cpp b/libcutils/trace-dev_test.cpp
index 29a5590..841674a 100644
--- a/libcutils/trace-dev_test.cpp
+++ b/libcutils/trace-dev_test.cpp
@@ -195,6 +195,226 @@
ASSERT_STREQ(expected.c_str(), actual.c_str());
}
+TEST_F(TraceDevTest, atrace_async_for_track_begin_body_normal) {
+ atrace_async_for_track_begin_body("fake_track", "fake_name", 12345);
+
+ ASSERT_EQ(0, lseek(atrace_marker_fd, 0, SEEK_SET));
+
+ std::string actual;
+ ASSERT_TRUE(android::base::ReadFdToString(atrace_marker_fd, &actual));
+ std::string expected = android::base::StringPrintf("T|%d|fake_track|fake_name|12345", getpid());
+ ASSERT_STREQ(expected.c_str(), actual.c_str());
+}
+
+TEST_F(TraceDevTest, atrace_async_for_track_begin_body_exact_track_name) {
+ const int name_size = 5;
+ std::string expected = android::base::StringPrintf("T|%d|", getpid());
+ std::string track_name =
+ MakeName(ATRACE_MESSAGE_LENGTH - expected.length() - 1 - name_size - 6);
+ atrace_async_for_track_begin_body(track_name.c_str(), "name", 12345);
+
+ ASSERT_EQ(ATRACE_MESSAGE_LENGTH - 1, lseek(atrace_marker_fd, 0, SEEK_CUR));
+ ASSERT_EQ(0, lseek(atrace_marker_fd, 0, SEEK_SET));
+
+ std::string actual;
+ ASSERT_TRUE(android::base::ReadFdToString(atrace_marker_fd, &actual));
+ expected += track_name + "|name|12345";
+ ASSERT_STREQ(expected.c_str(), actual.c_str());
+
+ // Add a single character and verify name truncation
+ ASSERT_EQ(0, lseek(atrace_marker_fd, 0, SEEK_SET));
+ track_name += '*';
+ expected = android::base::StringPrintf("T|%d|", getpid());
+ expected += track_name + "|nam|12345";
+ atrace_async_for_track_begin_body(track_name.c_str(), "name", 12345);
+ EXPECT_EQ(ATRACE_MESSAGE_LENGTH - 1, lseek(atrace_marker_fd, 0, SEEK_CUR));
+ ASSERT_EQ(0, lseek(atrace_marker_fd, 0, SEEK_SET));
+ ASSERT_TRUE(android::base::ReadFdToString(atrace_marker_fd, &actual));
+ ASSERT_STREQ(expected.c_str(), actual.c_str());
+}
+
+TEST_F(TraceDevTest, atrace_async_for_track_begin_body_truncated_track_name) {
+ std::string expected = android::base::StringPrintf("T|%d|", getpid());
+ std::string track_name = MakeName(2 * ATRACE_MESSAGE_LENGTH);
+ atrace_async_for_track_begin_body(track_name.c_str(), "name", 12345);
+
+ ASSERT_EQ(ATRACE_MESSAGE_LENGTH - 1, lseek(atrace_marker_fd, 0, SEEK_CUR));
+ ASSERT_EQ(0, lseek(atrace_marker_fd, 0, SEEK_SET));
+
+ std::string actual;
+ ASSERT_TRUE(android::base::ReadFdToString(atrace_marker_fd, &actual));
+ int expected_len = ATRACE_MESSAGE_LENGTH - expected.length() - 9;
+ expected += android::base::StringPrintf("%.*s|n|12345", expected_len, track_name.c_str());
+ ASSERT_STREQ(expected.c_str(), actual.c_str());
+}
+
+TEST_F(TraceDevTest, atrace_async_for_track_begin_body_exact_name) {
+ const int track_name_size = 11;
+ std::string expected = android::base::StringPrintf("T|%d|", getpid());
+ std::string name =
+ MakeName(ATRACE_MESSAGE_LENGTH - expected.length() - 1 - track_name_size - 6);
+ atrace_async_for_track_begin_body("track_name", name.c_str(), 12345);
+
+ ASSERT_EQ(ATRACE_MESSAGE_LENGTH - 1, lseek(atrace_marker_fd, 0, SEEK_CUR));
+ ASSERT_EQ(0, lseek(atrace_marker_fd, 0, SEEK_SET));
+
+ std::string actual;
+ ASSERT_TRUE(android::base::ReadFdToString(atrace_marker_fd, &actual));
+ expected += "track_name|" + name + "|12345";
+ ASSERT_STREQ(expected.c_str(), actual.c_str());
+
+ // Add a single character and verify we get the same value as before.
+ ASSERT_EQ(0, lseek(atrace_marker_fd, 0, SEEK_SET));
+ name += '*';
+ atrace_async_for_track_begin_body("track_name", name.c_str(), 12345);
+ EXPECT_EQ(ATRACE_MESSAGE_LENGTH - 1, lseek(atrace_marker_fd, 0, SEEK_CUR));
+ ASSERT_EQ(0, lseek(atrace_marker_fd, 0, SEEK_SET));
+ ASSERT_TRUE(android::base::ReadFdToString(atrace_marker_fd, &actual));
+ ASSERT_STREQ(expected.c_str(), actual.c_str());
+}
+
+TEST_F(TraceDevTest, atrace_async_for_track_begin_body_truncated_name) {
+ std::string expected = android::base::StringPrintf("T|%d|track_name|", getpid());
+ std::string name = MakeName(2 * ATRACE_MESSAGE_LENGTH);
+ atrace_async_for_track_begin_body("track_name", name.c_str(), 12345);
+
+ ASSERT_EQ(ATRACE_MESSAGE_LENGTH - 1, lseek(atrace_marker_fd, 0, SEEK_CUR));
+ ASSERT_EQ(0, lseek(atrace_marker_fd, 0, SEEK_SET));
+
+ std::string actual;
+ ASSERT_TRUE(android::base::ReadFdToString(atrace_marker_fd, &actual));
+ int expected_len = ATRACE_MESSAGE_LENGTH - expected.length() - 1 - 6;
+ expected += android::base::StringPrintf("%.*s|12345", expected_len, name.c_str());
+ ASSERT_STREQ(expected.c_str(), actual.c_str());
+}
+
+TEST_F(TraceDevTest, atrace_async_for_track_begin_body_truncated_both) {
+ std::string expected = android::base::StringPrintf("T|%d|", getpid());
+ std::string name = MakeName(2 * ATRACE_MESSAGE_LENGTH);
+ std::string track_name = MakeName(2 * ATRACE_MESSAGE_LENGTH);
+ atrace_async_for_track_begin_body(track_name.c_str(), name.c_str(), 12345);
+
+ ASSERT_EQ(ATRACE_MESSAGE_LENGTH - 1, lseek(atrace_marker_fd, 0, SEEK_CUR));
+ ASSERT_EQ(0, lseek(atrace_marker_fd, 0, SEEK_SET));
+
+ std::string actual;
+ ASSERT_TRUE(android::base::ReadFdToString(atrace_marker_fd, &actual));
+ int expected_len = ATRACE_MESSAGE_LENGTH - expected.length() - 3 - 6;
+ expected += android::base::StringPrintf("%.*s|%.1s|12345", expected_len, track_name.c_str(),
+ name.c_str());
+ ASSERT_STREQ(expected.c_str(), actual.c_str());
+}
+
+TEST_F(TraceDevTest, atrace_async_for_track_end_body_normal) {
+ atrace_async_for_track_end_body("fake_track", "fake_name", 12345);
+
+ ASSERT_EQ(0, lseek(atrace_marker_fd, 0, SEEK_SET));
+
+ std::string actual;
+ ASSERT_TRUE(android::base::ReadFdToString(atrace_marker_fd, &actual));
+ std::string expected = android::base::StringPrintf("U|%d|fake_track|fake_name|12345", getpid());
+ ASSERT_STREQ(expected.c_str(), actual.c_str());
+}
+
+TEST_F(TraceDevTest, atrace_async_for_track_end_body_exact_track_name) {
+ const int name_size = 5;
+ std::string expected = android::base::StringPrintf("U|%d|", getpid());
+ std::string track_name =
+ MakeName(ATRACE_MESSAGE_LENGTH - expected.length() - 1 - name_size - 6);
+ atrace_async_for_track_end_body(track_name.c_str(), "name", 12345);
+
+ ASSERT_EQ(ATRACE_MESSAGE_LENGTH - 1, lseek(atrace_marker_fd, 0, SEEK_CUR));
+ ASSERT_EQ(0, lseek(atrace_marker_fd, 0, SEEK_SET));
+
+ std::string actual;
+ ASSERT_TRUE(android::base::ReadFdToString(atrace_marker_fd, &actual));
+ expected += track_name + "|name|12345";
+ ASSERT_STREQ(expected.c_str(), actual.c_str());
+
+ // Add a single character and verify name truncation
+ ASSERT_EQ(0, lseek(atrace_marker_fd, 0, SEEK_SET));
+ track_name += '*';
+ expected = android::base::StringPrintf("U|%d|", getpid());
+ expected += track_name + "|nam|12345";
+ atrace_async_for_track_end_body(track_name.c_str(), "name", 12345);
+ EXPECT_EQ(ATRACE_MESSAGE_LENGTH - 1, lseek(atrace_marker_fd, 0, SEEK_CUR));
+ ASSERT_EQ(0, lseek(atrace_marker_fd, 0, SEEK_SET));
+ ASSERT_TRUE(android::base::ReadFdToString(atrace_marker_fd, &actual));
+ ASSERT_STREQ(expected.c_str(), actual.c_str());
+}
+
+TEST_F(TraceDevTest, atrace_async_for_track_end_body_truncated_track_name) {
+ std::string expected = android::base::StringPrintf("U|%d|", getpid());
+ std::string track_name = MakeName(2 * ATRACE_MESSAGE_LENGTH);
+ atrace_async_for_track_end_body(track_name.c_str(), "name", 12345);
+
+ ASSERT_EQ(ATRACE_MESSAGE_LENGTH - 1, lseek(atrace_marker_fd, 0, SEEK_CUR));
+ ASSERT_EQ(0, lseek(atrace_marker_fd, 0, SEEK_SET));
+
+ std::string actual;
+ ASSERT_TRUE(android::base::ReadFdToString(atrace_marker_fd, &actual));
+ int expected_len = ATRACE_MESSAGE_LENGTH - expected.length() - 9;
+ expected += android::base::StringPrintf("%.*s|n|12345", expected_len, track_name.c_str());
+ ASSERT_STREQ(expected.c_str(), actual.c_str());
+}
+
+TEST_F(TraceDevTest, atrace_async_for_track_end_body_exact_name) {
+ const int track_name_size = 11;
+ std::string expected = android::base::StringPrintf("U|%d|", getpid());
+ std::string name =
+ MakeName(ATRACE_MESSAGE_LENGTH - expected.length() - 1 - track_name_size - 6);
+ atrace_async_for_track_end_body("track_name", name.c_str(), 12345);
+
+ ASSERT_EQ(ATRACE_MESSAGE_LENGTH - 1, lseek(atrace_marker_fd, 0, SEEK_CUR));
+ ASSERT_EQ(0, lseek(atrace_marker_fd, 0, SEEK_SET));
+
+ std::string actual;
+ ASSERT_TRUE(android::base::ReadFdToString(atrace_marker_fd, &actual));
+ expected += "track_name|" + name + "|12345";
+ ASSERT_STREQ(expected.c_str(), actual.c_str());
+
+ // Add a single character and verify we get the same value as before.
+ ASSERT_EQ(0, lseek(atrace_marker_fd, 0, SEEK_SET));
+ name += '*';
+ atrace_async_for_track_end_body("track_name", name.c_str(), 12345);
+ EXPECT_EQ(ATRACE_MESSAGE_LENGTH - 1, lseek(atrace_marker_fd, 0, SEEK_CUR));
+ ASSERT_EQ(0, lseek(atrace_marker_fd, 0, SEEK_SET));
+ ASSERT_TRUE(android::base::ReadFdToString(atrace_marker_fd, &actual));
+ ASSERT_STREQ(expected.c_str(), actual.c_str());
+}
+
+TEST_F(TraceDevTest, atrace_async_for_track_end_body_truncated_name) {
+ std::string expected = android::base::StringPrintf("U|%d|track_name|", getpid());
+ std::string name = MakeName(2 * ATRACE_MESSAGE_LENGTH);
+ atrace_async_for_track_end_body("track_name", name.c_str(), 12345);
+
+ ASSERT_EQ(ATRACE_MESSAGE_LENGTH - 1, lseek(atrace_marker_fd, 0, SEEK_CUR));
+ ASSERT_EQ(0, lseek(atrace_marker_fd, 0, SEEK_SET));
+
+ std::string actual;
+ ASSERT_TRUE(android::base::ReadFdToString(atrace_marker_fd, &actual));
+ int expected_len = ATRACE_MESSAGE_LENGTH - expected.length() - 1 - 6;
+ expected += android::base::StringPrintf("%.*s|12345", expected_len, name.c_str());
+ ASSERT_STREQ(expected.c_str(), actual.c_str());
+}
+
+TEST_F(TraceDevTest, atrace_async_for_track_end_body_truncated_both) {
+ std::string expected = android::base::StringPrintf("U|%d|", getpid());
+ std::string name = MakeName(2 * ATRACE_MESSAGE_LENGTH);
+ std::string track_name = MakeName(2 * ATRACE_MESSAGE_LENGTH);
+ atrace_async_for_track_end_body(track_name.c_str(), name.c_str(), 12345);
+
+ ASSERT_EQ(ATRACE_MESSAGE_LENGTH - 1, lseek(atrace_marker_fd, 0, SEEK_CUR));
+ ASSERT_EQ(0, lseek(atrace_marker_fd, 0, SEEK_SET));
+
+ std::string actual;
+ ASSERT_TRUE(android::base::ReadFdToString(atrace_marker_fd, &actual));
+ int expected_len = ATRACE_MESSAGE_LENGTH - expected.length() - 3 - 6;
+ expected += android::base::StringPrintf("%.*s|%.1s|12345", expected_len, track_name.c_str(),
+ name.c_str());
+ ASSERT_STREQ(expected.c_str(), actual.c_str());
+}
+
TEST_F(TraceDevTest, atrace_instant_body_normal) {
atrace_instant_body("fake_name");
diff --git a/libcutils/trace-host.cpp b/libcutils/trace-host.cpp
index b01a0ec..c2a379b 100644
--- a/libcutils/trace-host.cpp
+++ b/libcutils/trace-host.cpp
@@ -28,9 +28,12 @@
void atrace_end_body() { }
void atrace_async_begin_body(const char* /*name*/, int32_t /*cookie*/) {}
void atrace_async_end_body(const char* /*name*/, int32_t /*cookie*/) {}
+void atrace_async_for_track_begin_body(const char* /*track_name*/, const char* /*name*/,
+ int32_t /*cookie*/) {}
+void atrace_async_for_track_end_body(const char* /*track_name*/, const char* /*name*/,
+ int32_t /*cookie*/) {}
void atrace_instant_body(const char* /*name*/) {}
-void atrace_instant_for_track_body(const char* /*trackName*/,
- const char* /*name*/) {}
+void atrace_instant_for_track_body(const char* /*track_name*/, const char* /*name*/) {}
void atrace_int_body(const char* /*name*/, int32_t /*value*/) {}
void atrace_int64_body(const char* /*name*/, int64_t /*value*/) {}
void atrace_init() {}