ACPR/android_system_core
1
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions

Merge "Added async trace functions with a track name argument" am: 9f6770e6a6

Browse source 
Original change: https://android-review.googlesource.com/c/platform/system/core/+/2037685

Change-Id: I3d12094d4885d247289dda09011680ce25a8a350
Signed-off-by: Automerger Merge Worker <android-build-automerger-merge-worker@system.gserviceaccount.com>
This commit is contained in:
Ray Ye 2022-03-25 20:50:50 +00:00 • committed by Automerger Merge Worker
commit d2d203337f
5 changed files with 290 additions and 5 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

38
libcutils/include/cutils/trace.h
View file

@ -208,6 +208,37 @@ static inline void atrace_async_end(uint64_t tag, const char* name, int32_t cook
}
}
/**
* 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.
*
@ -227,17 +258,18 @@ static inline void atrace_instant(uint64_t tag, const char* name) {
/**
* 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);
}
}

22
libcutils/trace-container.cpp
View file

@ -229,6 +229,28 @@ void atrace_async_end_body(const char* name, int32_t cookie)
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, "");

8
libcutils/trace-dev.cpp
View file

@ -89,6 +89,14 @@ void atrace_async_end_body(const char* name, int32_t cookie)
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, "");
}

220
libcutils/trace-dev_test.cpp
View file

@ -195,6 +195,226 @@ TEST_F(TraceDevTest, atrace_async_end_body_truncated) {
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");

7
libcutils/trace-host.cpp
View file

@ -28,9 +28,12 @@ void atrace_begin_body(const char* /*name*/) {}
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() {}