Added trackName as additional argument to WRITE_MSG to handle trace
messages with a track name
Bug: 220499650
Test: atest TraceDevTest
Change-Id: I3f6be6b693fb6f906b90655d5d553e853c4d4411
diff --git a/libcutils/trace-container.cpp b/libcutils/trace-container.cpp
index ef7c72d..f3fdda4 100644
--- a/libcutils/trace-container.cpp
+++ b/libcutils/trace-container.cpp
@@ -131,29 +131,41 @@
// Write trace events to container trace file. Note that we need to amend tid and time information
// here comparing to normal ftrace, where those informations are added by kernel.
-#define WRITE_MSG_IN_CONTAINER_LOCKED(ph, sep_before_name, value_format, name, value) { \
+#define WRITE_MSG_IN_CONTAINER_LOCKED(ph, sep_before_name, value_format, \
+ track_name, name, value) { \
char buf[CONTAINER_ATRACE_MESSAGE_LENGTH]; \
+ const char* track_name_sep = track_name[0] != '\0' ? "|" : ""; \
int pid = getpid(); \
int tid = gettid(); \
uint64_t ts = gettime(CLOCK_MONOTONIC); \
uint64_t tts = gettime(CLOCK_THREAD_CPUTIME_ID); \
int len = snprintf( \
buf, sizeof(buf), \
- ph "|%d|%d|%" PRIu64 "|%" PRIu64 sep_before_name "%s" value_format, \
- pid, tid, ts, tts, name, value); \
+ ph "|%d|%d|%" PRIu64 "|%" PRIu64 sep_before_name "%s%s%s" value_format, \
+ pid, tid, ts, tts, track_name, track_name_sep, name, value); \
if (len >= (int) sizeof(buf)) { \
int name_len = strlen(name) - (len - sizeof(buf)) - 1; \
/* Truncate the name to make the message fit. */ \
if (name_len > 0) { \
- ALOGW("Truncated name in %s: %s\n", __FUNCTION__, name); \
len = snprintf( \
- buf, sizeof(buf), \
- ph "|%d|%d|%" PRIu64 "|%" PRIu64 sep_before_name "%.*s" value_format, \
- pid, tid, ts, tts, name_len, name, value); \
+ buf, sizeof(buf), \
+ ph "|%d|%d|%" PRIu64 "|%" PRIu64 sep_before_name "%s%s%.*s" value_format, \
+ pid, tid, ts, tts, track_name, track_name_sep, name_len, name, value); \
} else { \
- /* Data is still too long. Drop it. */ \
- ALOGW("Data is too long in %s: %s\n", __FUNCTION__, name); \
- len = 0; \
+ int track_name_len = 0; \
+ if (track_name[0] != '\0') { \
+ track_name_len = strlen(track_name) - (len - strlen(name) - sizeof(buf)) - 2; \
+ } \
+ if (track_name_len <= 0){ \
+ /* Data is still too long. Drop it. */ \
+ len = 0; \
+ } else { \
+ /* Truncate the trackName and name to make the message fit. */ \
+ len = snprintf( \
+ buf, sizeof(buf), \
+ ph "|%d|%d|%" PRIu64 "|%" PRIu64 sep_before_name "%.*s|%.1s" value_format, \
+ pid, tid, ts, tts, track_name_len, track_name, name, value); \
+ } \
} \
} \
if (len > 0) { \
@@ -161,10 +173,10 @@
} \
}
-#define WRITE_MSG_IN_CONTAINER(ph, sep_before_name, value_format, name, value) { \
+#define WRITE_MSG_IN_CONTAINER(ph, sep_before_name, value_format, track_name, name, value) { \
pthread_rwlock_rdlock(&atrace_container_sock_rwlock); \
if (atrace_container_sock_fd != -1) { \
- WRITE_MSG_IN_CONTAINER_LOCKED(ph, sep_before_name, value_format, name, value); \
+ WRITE_MSG_IN_CONTAINER_LOCKED(ph, sep_before_name, value_format, track_name, name, value); \
} \
pthread_rwlock_unlock(&atrace_container_sock_rwlock); \
}
@@ -172,93 +184,93 @@
void atrace_begin_body(const char* name)
{
if (CC_LIKELY(atrace_use_container_sock)) {
- WRITE_MSG_IN_CONTAINER("B", "|", "%s", name, "");
+ WRITE_MSG_IN_CONTAINER("B", "|", "%s", "", name, "");
return;
}
if (atrace_marker_fd < 0) return;
- WRITE_MSG("B|%d|", "%s", name, "");
+ WRITE_MSG("B|%d|", "%s", "", name, "");
}
void atrace_end_body()
{
if (CC_LIKELY(atrace_use_container_sock)) {
- WRITE_MSG_IN_CONTAINER("E", "", "%s", "", "");
+ WRITE_MSG_IN_CONTAINER("E", "", "%s", "", "", "");
return;
}
if (atrace_marker_fd < 0) return;
- WRITE_MSG("E|%d", "%s", "", "");
+ WRITE_MSG("E|%d", "%s", "", "", "");
}
void atrace_async_begin_body(const char* name, int32_t cookie)
{
if (CC_LIKELY(atrace_use_container_sock)) {
- WRITE_MSG_IN_CONTAINER("S", "|", "|%d", name, cookie);
+ WRITE_MSG_IN_CONTAINER("S", "|", "|%d", "", name, cookie);
return;
}
if (atrace_marker_fd < 0) return;
- WRITE_MSG("S|%d|", "|%" PRId32, name, cookie);
+ WRITE_MSG("S|%d|", "|%" PRId32, "", name, cookie);
}
void atrace_async_end_body(const char* name, int32_t cookie)
{
if (CC_LIKELY(atrace_use_container_sock)) {
- WRITE_MSG_IN_CONTAINER("F", "|", "|%d", name, cookie);
+ WRITE_MSG_IN_CONTAINER("F", "|", "|%d", "", name, cookie);
return;
}
if (atrace_marker_fd < 0) return;
- WRITE_MSG("F|%d|", "|%" PRId32, name, cookie);
+ WRITE_MSG("F|%d|", "|%" PRId32, "", name, cookie);
}
void atrace_instant_body(const char* name) {
if (CC_LIKELY(atrace_use_container_sock)) {
- WRITE_MSG_IN_CONTAINER("I", "|", "%s", name, "");
+ WRITE_MSG_IN_CONTAINER("I", "|", "%s", "", name, "");
return;
}
if (atrace_marker_fd < 0) return;
- WRITE_MSG("I|%d|", "%s", name, "");
+ WRITE_MSG("I|%d|", "%s", "", 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) {
if (CC_LIKELY(atrace_use_container_sock)) {
- WRITE_MSG_IN_CONTAINER("N", "|", "|%s", trackName, name);
+ WRITE_MSG_IN_CONTAINER("N", "|", "%s", track_name, name, "");
return;
}
if (atrace_marker_fd < 0) return;
- WRITE_MSG("N|%d|", "|%s", name, trackName);
+ WRITE_MSG("N|%d|", "%s", track_name, name, "");
}
void atrace_int_body(const char* name, int32_t value)
{
if (CC_LIKELY(atrace_use_container_sock)) {
- WRITE_MSG_IN_CONTAINER("C", "|", "|%" PRId32, name, value);
+ WRITE_MSG_IN_CONTAINER("C", "|", "|%" PRId32, "", name, value);
return;
}
if (atrace_marker_fd < 0) return;
- WRITE_MSG("C|%d|", "|%" PRId32, name, value);
+ WRITE_MSG("C|%d|", "|%" PRId32, "", name, value);
}
void atrace_int64_body(const char* name, int64_t value)
{
if (CC_LIKELY(atrace_use_container_sock)) {
- WRITE_MSG_IN_CONTAINER("C", "|", "|%" PRId64, name, value);
+ WRITE_MSG_IN_CONTAINER("C", "|", "|%" PRId64, "", name, value);
return;
}
if (atrace_marker_fd < 0) return;
- WRITE_MSG("C|%d|", "|%" PRId64, name, value);
+ WRITE_MSG("C|%d|", "|%" PRId64, "", name, value);
}
diff --git a/libcutils/trace-dev.cpp b/libcutils/trace-dev.cpp
index 25c86f4..8bdeac5 100644
--- a/libcutils/trace-dev.cpp
+++ b/libcutils/trace-dev.cpp
@@ -71,38 +71,38 @@
void atrace_begin_body(const char* name)
{
- WRITE_MSG("B|%d|", "%s", name, "");
+ WRITE_MSG("B|%d|", "%s", "", name, "");
}
void atrace_end_body()
{
- WRITE_MSG("E|%d", "%s", "", "");
+ WRITE_MSG("E|%d", "%s", "", "", "");
}
void atrace_async_begin_body(const char* name, int32_t cookie)
{
- WRITE_MSG("S|%d|", "|%" PRId32, name, cookie);
+ WRITE_MSG("S|%d|", "|%" PRId32, "", name, cookie);
}
void atrace_async_end_body(const char* name, int32_t cookie)
{
- WRITE_MSG("F|%d|", "|%" PRId32, name, cookie);
+ WRITE_MSG("F|%d|", "|%" PRId32, "", name, cookie);
}
void atrace_instant_body(const char* name) {
- WRITE_MSG("I|%d|", "%s", name, "");
+ WRITE_MSG("I|%d|", "%s", "", name, "");
}
-void atrace_instant_for_track_body(const char* trackName, const char* name) {
- WRITE_MSG("N|%d|", "|%s", trackName, name);
+void atrace_instant_for_track_body(const char* track_name, const char* name) {
+ WRITE_MSG("N|%d|", "%s", track_name, name, "");
}
void atrace_int_body(const char* name, int32_t value)
{
- WRITE_MSG("C|%d|", "|%" PRId32, name, value);
+ WRITE_MSG("C|%d|", "|%" PRId32, "", name, value);
}
void atrace_int64_body(const char* name, int64_t value)
{
- WRITE_MSG("C|%d|", "|%" PRId64, name, value);
+ WRITE_MSG("C|%d|", "|%" PRId64, "", name, value);
}
diff --git a/libcutils/trace-dev.inc b/libcutils/trace-dev.inc
index 3b459e0..94945ec 100644
--- a/libcutils/trace-dev.inc
+++ b/libcutils/trace-dev.inc
@@ -185,21 +185,36 @@
}
}
-#define WRITE_MSG(format_begin, format_end, name, value) { \
+#define WRITE_MSG(format_begin, format_end, track_name, name, value) { \
char buf[ATRACE_MESSAGE_LENGTH] __attribute__((uninitialized)); \
+ const char* track_name_sep = track_name[0] != '\0' ? "|" : ""; \
int pid = getpid(); \
- int len = snprintf(buf, sizeof(buf), format_begin "%s" format_end, pid, \
- name, value); \
+ int len = snprintf(buf, sizeof(buf), format_begin "%s%s%s" format_end, pid, \
+ track_name, track_name_sep, name, value); \
if (len >= (int) sizeof(buf)) { \
- /* Given the sizeof(buf), and all of the current format buffers, \
- * it is impossible for name_len to be < 0 if len >= sizeof(buf). */ \
int name_len = strlen(name) - (len - sizeof(buf)) - 1; \
/* Truncate the name to make the message fit. */ \
- ALOGW("Truncated name in %s: %s\n", __FUNCTION__, name); \
- len = snprintf(buf, sizeof(buf), format_begin "%.*s" format_end, pid, \
- name_len, name, value); \
+ if (name_len > 0) { \
+ len = snprintf(buf, sizeof(buf), format_begin "%s%s%.*s" format_end, pid, \
+ track_name, track_name_sep, name_len, name, value); \
+ } else { \
+ int track_name_len = 0; \
+ if (track_name[0] != '\0') { \
+ track_name_len = strlen(track_name) - (len - strlen(name) - sizeof(buf)) - 2; \
+ } \
+ if (track_name_len <= 0) { \
+ /* Data is still too long. Drop it. */ \
+ len = 0; \
+ } else { \
+ /* Truncate the trackName and name to make the message fit */ \
+ len = snprintf(buf, sizeof(buf), format_begin "%.*s|%.1s" format_end, pid, \
+ track_name_len, track_name, name, value); \
+ } \
+ } \
} \
- write(atrace_marker_fd, buf, len); \
+ if (len > 0) { \
+ write(atrace_marker_fd, buf, len); \
+ } \
}
#endif // __TRACE_DEV_INC
diff --git a/libcutils/trace-dev_test.cpp b/libcutils/trace-dev_test.cpp
index ff6d202..29a5590 100644
--- a/libcutils/trace-dev_test.cpp
+++ b/libcutils/trace-dev_test.cpp
@@ -255,43 +255,100 @@
ASSERT_STREQ(expected.c_str(), actual.c_str());
}
-TEST_F(TraceDevTest, atrace_instant_for_track_body_exact) {
- const int nameSize = 5;
+TEST_F(TraceDevTest, atrace_instant_for_track_body_exact_track_name) {
+ const int name_size = 5;
std::string expected = android::base::StringPrintf("N|%d|", getpid());
- std::string trackName = MakeName(ATRACE_MESSAGE_LENGTH - expected.length() - 1 - nameSize);
- atrace_instant_for_track_body(trackName.c_str(), "name");
+ std::string track_name = MakeName(ATRACE_MESSAGE_LENGTH - expected.length() - 1 - name_size);
+ atrace_instant_for_track_body(track_name.c_str(), "name");
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 += trackName + "|name";
+ expected += track_name + "|name";
ASSERT_STREQ(expected.c_str(), actual.c_str());
- // Add a single character and verify we get the exact same value as before.
+ // Add a single character and verify name truncation
ASSERT_EQ(0, lseek(atrace_marker_fd, 0, SEEK_SET));
- trackName += '*';
- atrace_instant_for_track_body(trackName.c_str(), "name");
+ track_name += '*';
+ expected = android::base::StringPrintf("N|%d|", getpid());
+ expected += track_name + "|nam";
+ atrace_instant_for_track_body(track_name.c_str(), "name");
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_instant_for_track_body_truncated) {
- const int nameSize = 5;
+TEST_F(TraceDevTest, atrace_instant_for_track_body_truncated_track_name) {
std::string expected = android::base::StringPrintf("N|%d|", getpid());
- std::string trackName = MakeName(2 * ATRACE_MESSAGE_LENGTH);
- atrace_instant_for_track_body(trackName.c_str(), "name");
+ std::string track_name = MakeName(2 * ATRACE_MESSAGE_LENGTH);
+ atrace_instant_for_track_body(track_name.c_str(), "name");
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 - nameSize;
- expected += android::base::StringPrintf("%.*s|name", expected_len, trackName.c_str());
+ int expected_len = ATRACE_MESSAGE_LENGTH - expected.length() - 3;
+ expected += android::base::StringPrintf("%.*s|n", expected_len, track_name.c_str());
+ ASSERT_STREQ(expected.c_str(), actual.c_str());
+}
+
+TEST_F(TraceDevTest, atrace_instant_for_track_body_exact_name) {
+ const int track_name_size = 11;
+ std::string expected = android::base::StringPrintf("N|%d|", getpid());
+ std::string name = MakeName(ATRACE_MESSAGE_LENGTH - expected.length() - 1 - track_name_size);
+ atrace_instant_for_track_body("track_name", name.c_str());
+
+ 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;
+ 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_instant_for_track_body("track_name", name.c_str());
+ 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_instant_for_track_body_truncated_name) {
+ std::string expected = android::base::StringPrintf("N|%d|track_name|", getpid());
+ std::string name = MakeName(2 * ATRACE_MESSAGE_LENGTH);
+ atrace_instant_for_track_body("track_name", name.c_str());
+
+ 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;
+ expected += android::base::StringPrintf("%.*s", expected_len, name.c_str());
+ ASSERT_STREQ(expected.c_str(), actual.c_str());
+}
+
+TEST_F(TraceDevTest, atrace_instant_for_track_body_truncated_both) {
+ std::string expected = android::base::StringPrintf("N|%d|", getpid());
+ std::string name = MakeName(2 * ATRACE_MESSAGE_LENGTH);
+ std::string track_name = MakeName(2 * ATRACE_MESSAGE_LENGTH);
+ atrace_instant_for_track_body(track_name.c_str(), name.c_str());
+
+ 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;
+ expected +=
+ android::base::StringPrintf("%.*s|%.1s", expected_len, track_name.c_str(), name.c_str());
ASSERT_STREQ(expected.c_str(), actual.c_str());
}