Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 399465a9 authored by Ray Ye's avatar Ray Ye
Browse files

Added async trace functions with a track name argument

Bug: 221119585
Test: atest TraceDevTest
Change-Id: I48d9e858ce588e3735ddbbe14b1bd7c8f264cd83
parent 8461ca59
Loading
Loading
Loading
Loading
+35 −3
Original line number Original line Diff line number Diff line
@@ -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.
 * 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.
 * 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
 * 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).
 * in the timeline (rather than a span, in the case of begin/end events).
 */
 */
#define ATRACE_INSTANT_FOR_TRACK(trackName, name) \
#define ATRACE_INSTANT_FOR_TRACK(trackName, name) \
    atrace_instant_for_track(ATRACE_TAG, 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))) {
    if (CC_UNLIKELY(atrace_is_tag_enabled(tag))) {
        void atrace_instant_for_track_body(const char*, const char*);
        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 −0
Original line number Original line Diff line number Diff line
@@ -229,6 +229,28 @@ 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_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) {
void atrace_instant_body(const char* name) {
    if (CC_LIKELY(atrace_use_container_sock)) {
    if (CC_LIKELY(atrace_use_container_sock)) {
        WRITE_MSG_IN_CONTAINER("I", "|", "%s", "", name, "");
        WRITE_MSG_IN_CONTAINER("I", "|", "%s", "", name, "");
+8 −0
Original line number Original line Diff line number Diff line
@@ -89,6 +89,14 @@ 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_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) {
void atrace_instant_body(const char* name) {
    WRITE_MSG("I|%d|", "%s", "", name, "");
    WRITE_MSG("I|%d|", "%s", "", name, "");
}
}
+220 −0
Original line number Original line Diff line number Diff line
@@ -195,6 +195,226 @@ TEST_F(TraceDevTest, atrace_async_end_body_truncated) {
  ASSERT_STREQ(expected.c_str(), actual.c_str());
  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) {
TEST_F(TraceDevTest, atrace_instant_body_normal) {
    atrace_instant_body("fake_name");
    atrace_instant_body("fake_name");


+5 −2
Original line number Original line Diff line number Diff line
@@ -28,9 +28,12 @@ void atrace_begin_body(const char* /*name*/) {}
void atrace_end_body() { }
void atrace_end_body() { }
void atrace_async_begin_body(const char* /*name*/, int32_t /*cookie*/) {}
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_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_body(const char* /*name*/) {}
void atrace_instant_for_track_body(const char* /*trackName*/,
void atrace_instant_for_track_body(const char* /*track_name*/, const char* /*name*/) {}
                                   const char* /*name*/) {}
void atrace_int_body(const char* /*name*/, int32_t /*value*/) {}
void atrace_int_body(const char* /*name*/, int32_t /*value*/) {}
void atrace_int64_body(const char* /*name*/, int64_t /*value*/) {}
void atrace_int64_body(const char* /*name*/, int64_t /*value*/) {}
void atrace_init() {}
void atrace_init() {}