From 4b1ad93f7b7e7db3472316bdee86089e601f3f6f Mon Sep 17 00:00:00 2001 From: skiazyk Date: Tue, 7 Mar 2017 10:08:16 -0800 Subject: Add some changes to TraceAnalyzer to improve analysis * Tests which rely on being able to query for the end event in a pair were not possible, partly because end events tend to be missing information, and also because they did not reference their start events * Async event association can optionally be allowed for events which span across process boundaries BUG=None Review-Url: https://codereview.chromium.org/2716023002 Cr-Commit-Position: refs/heads/master@{#455132} (cherry picked from commit 83621ef58f633413145bd7093f16d56eb2c88103) --- base/test/trace_event_analyzer.cc | 50 ++++++++++++---- base/test/trace_event_analyzer.h | 95 +++++++++++++++++++++++++++++- base/test/trace_event_analyzer_unittest.cc | 6 ++ 3 files changed, 139 insertions(+), 12 deletions(-) diff --git a/base/test/trace_event_analyzer.cc b/base/test/trace_event_analyzer.cc index 64436dc144..55a349acf2 100644 --- a/base/test/trace_event_analyzer.cc +++ b/base/test/trace_event_analyzer.cc @@ -449,14 +449,24 @@ bool Query::GetAsString(const TraceEvent& event, std::string* str) const { } } +const TraceEvent* Query::SelectTargetEvent(const TraceEvent* event, + TraceEventMember member) { + if (member >= OTHER_FIRST_MEMBER && member <= OTHER_LAST_MEMBER) { + return event->other_event; + } else if (member >= PREV_FIRST_MEMBER && member <= PREV_LAST_MEMBER) { + return event->prev_event; + } else { + return event; + } +} + bool Query::GetMemberValueAsDouble(const TraceEvent& event, double* num) const { DCHECK_EQ(QUERY_EVENT_MEMBER, type_); // This could be a request for a member of |event| or a member of |event|'s - // associated event. Store the target event in the_event: - const TraceEvent* the_event = (member_ < OTHER_PID) ? - &event : event.other_event; + // associated previous or next event. Store the target event in the_event: + const TraceEvent* the_event = SelectTargetEvent(&event, member_); // Request for member of associated event, but there is no associated event. if (!the_event) @@ -465,14 +475,17 @@ bool Query::GetMemberValueAsDouble(const TraceEvent& event, switch (member_) { case EVENT_PID: case OTHER_PID: + case PREV_PID: *num = static_cast(the_event->thread.process_id); return true; case EVENT_TID: case OTHER_TID: + case PREV_TID: *num = static_cast(the_event->thread.thread_id); return true; case EVENT_TIME: case OTHER_TIME: + case PREV_TIME: *num = the_event->timestamp; return true; case EVENT_DURATION: @@ -487,18 +500,22 @@ bool Query::GetMemberValueAsDouble(const TraceEvent& event, return true; case EVENT_PHASE: case OTHER_PHASE: + case PREV_PHASE: *num = static_cast(the_event->phase); return true; case EVENT_HAS_STRING_ARG: case OTHER_HAS_STRING_ARG: + case PREV_HAS_STRING_ARG: *num = (the_event->HasStringArg(string_) ? 1.0 : 0.0); return true; case EVENT_HAS_NUMBER_ARG: case OTHER_HAS_NUMBER_ARG: + case PREV_HAS_NUMBER_ARG: *num = (the_event->HasNumberArg(string_) ? 1.0 : 0.0); return true; case EVENT_ARG: - case OTHER_ARG: { + case OTHER_ARG: + case PREV_ARG: { // Search for the argument name and return its value if found. std::map::const_iterator num_i = the_event->arg_numbers.find(string_); @@ -511,6 +528,9 @@ bool Query::GetMemberValueAsDouble(const TraceEvent& event, // return 1.0 (true) if the other event exists *num = event.other_event ? 1.0 : 0.0; return true; + case EVENT_HAS_PREV: + *num = event.prev_event ? 1.0 : 0.0; + return true; default: return false; } @@ -521,9 +541,8 @@ bool Query::GetMemberValueAsString(const TraceEvent& event, DCHECK_EQ(QUERY_EVENT_MEMBER, type_); // This could be a request for a member of |event| or a member of |event|'s - // associated event. Store the target event in the_event: - const TraceEvent* the_event = (member_ < OTHER_PID) ? - &event : event.other_event; + // associated previous or next event. Store the target event in the_event: + const TraceEvent* the_event = SelectTargetEvent(&event, member_); // Request for member of associated event, but there is no associated event. if (!the_event) @@ -532,18 +551,22 @@ bool Query::GetMemberValueAsString(const TraceEvent& event, switch (member_) { case EVENT_CATEGORY: case OTHER_CATEGORY: + case PREV_CATEGORY: *str = the_event->category; return true; case EVENT_NAME: case OTHER_NAME: + case PREV_NAME: *str = the_event->name; return true; case EVENT_ID: case OTHER_ID: + case PREV_ID: *str = the_event->id; return true; case EVENT_ARG: - case OTHER_ARG: { + case OTHER_ARG: + case PREV_ARG: { // Search for the argument name and return its value if found. std::map::const_iterator str_i = the_event->arg_strings.find(string_); @@ -740,7 +763,7 @@ void TraceAnalyzer::AssociateBeginEndEvents() { AssociateEvents(begin, end, match); } -void TraceAnalyzer::AssociateAsyncBeginEndEvents() { +void TraceAnalyzer::AssociateAsyncBeginEndEvents(bool match_pid) { using trace_analyzer::Query; Query begin( @@ -750,10 +773,13 @@ void TraceAnalyzer::AssociateAsyncBeginEndEvents() { Query end(Query::EventPhaseIs(TRACE_EVENT_PHASE_ASYNC_END) || Query::EventPhaseIs(TRACE_EVENT_PHASE_ASYNC_STEP_INTO) || Query::EventPhaseIs(TRACE_EVENT_PHASE_ASYNC_STEP_PAST)); - Query match(Query::EventName() == Query::OtherName() && - Query::EventCategory() == Query::OtherCategory() && + Query match(Query::EventCategory() == Query::OtherCategory() && Query::EventId() == Query::OtherId()); + if (match_pid) { + match = match && Query::EventPid() == Query::OtherPid(); + } + AssociateEvents(begin, end, match); } @@ -782,6 +808,8 @@ void TraceAnalyzer::AssociateEvents(const Query& first, begin_event.other_event = &this_event; if (match.Evaluate(begin_event)) { // Found a matching begin/end pair. + // Set the associated previous event + this_event.prev_event = &begin_event; // Erase the matching begin event index from the stack. begin_stack.erase(begin_stack.begin() + stack_index); break; diff --git a/base/test/trace_event_analyzer.h b/base/test/trace_event_analyzer.h index 0e2366bbb1..054964304f 100644 --- a/base/test/trace_event_analyzer.h +++ b/base/test/trace_event_analyzer.h @@ -174,6 +174,10 @@ struct TraceEvent { // The other event associated with this event (or NULL). const TraceEvent* other_event; + + // A back-link for |other_event|. That is, if other_event is not null, then + // |event->other_event->prev_event == event| is always true. + const TraceEvent* prev_event; }; typedef std::vector TraceEventVector; @@ -351,6 +355,70 @@ class Query { return Query(OTHER_ARG, arg_name); } + // Access the associated prev_event's members: + + static Query PrevPid() { return Query(PREV_PID); } + + static Query PrevTid() { return Query(PREV_TID); } + + static Query PrevTime() { return Query(PREV_TIME); } + + static Query PrevPhase() { return Query(PREV_PHASE); } + + static Query PrevCategory() { return Query(PREV_CATEGORY); } + + static Query PrevName() { return Query(PREV_NAME); } + + static Query PrevId() { return Query(PREV_ID); } + + static Query PrevPidIs(int process_id) { + return Query(PREV_PID) == Query::Int(process_id); + } + + static Query PrevTidIs(int thread_id) { + return Query(PREV_TID) == Query::Int(thread_id); + } + + static Query PrevThreadIs(const TraceEvent::ProcessThreadID& thread) { + return PrevPidIs(thread.process_id) && PrevTidIs(thread.thread_id); + } + + static Query PrevTimeIs(double timestamp) { + return Query(PREV_TIME) == Query::Double(timestamp); + } + + static Query PrevPhaseIs(char phase) { + return Query(PREV_PHASE) == Query::Phase(phase); + } + + static Query PrevCategoryIs(const std::string& category) { + return Query(PREV_CATEGORY) == Query::String(category); + } + + static Query PrevNameIs(const std::string& name) { + return Query(PREV_NAME) == Query::String(name); + } + + static Query PrevIdIs(const std::string& id) { + return Query(PREV_ID) == Query::String(id); + } + + // Evaluates to true if arg exists and is a string. + static Query PrevHasStringArg(const std::string& arg_name) { + return Query(PREV_HAS_STRING_ARG, arg_name); + } + + // Evaluates to true if arg exists and is a number. + // Number arguments include types double, int and bool. + static Query PrevHasNumberArg(const std::string& arg_name) { + return Query(PREV_HAS_NUMBER_ARG, arg_name); + } + + // Evaluates to arg value (string or number). + static Query PrevArg(const std::string& arg_name) { + return Query(PREV_ARG, arg_name); + } + //////////////////////////////////////////////////////////////// // Common queries: @@ -438,6 +506,8 @@ class Query { EVENT_HAS_NUMBER_ARG, EVENT_ARG, EVENT_HAS_OTHER, + EVENT_HAS_PREV, + OTHER_PID, OTHER_TID, OTHER_TIME, @@ -448,6 +518,23 @@ class Query { OTHER_HAS_STRING_ARG, OTHER_HAS_NUMBER_ARG, OTHER_ARG, + + PREV_PID, + PREV_TID, + PREV_TIME, + PREV_PHASE, + PREV_CATEGORY, + PREV_NAME, + PREV_ID, + PREV_HAS_STRING_ARG, + PREV_HAS_NUMBER_ARG, + PREV_ARG, + + OTHER_FIRST_MEMBER = OTHER_PID, + OTHER_LAST_MEMBER = OTHER_ARG, + + PREV_FIRST_MEMBER = PREV_PID, + PREV_LAST_MEMBER = PREV_ARG, }; enum Operator { @@ -536,6 +623,9 @@ class Query { return operator_ != OP_INVALID && operator_ < OP_AND; } + static const TraceEvent* SelectTargetEvent(const TraceEvent* ev, + TraceEventMember member); + const Query& left() const; const Query& right() const; @@ -587,7 +677,10 @@ class TraceAnalyzer { // An ASYNC_END event will match the most recent ASYNC_BEGIN or ASYNC_STEP // event with the same name, category, and ID. This creates a singly linked // list of ASYNC_BEGIN->ASYNC_STEP...->ASYNC_END. - void AssociateAsyncBeginEndEvents(); + // |match_pid| - If true, will only match async events which are running + // under the same process ID, otherwise will allow linking + // async events from different processes. + void AssociateAsyncBeginEndEvents(bool match_pid = true); // AssociateEvents can be used to customize event associations by setting the // other_event member of TraceEvent. This should be used to associate two diff --git a/base/test/trace_event_analyzer_unittest.cc b/base/test/trace_event_analyzer_unittest.cc index 086cfc97d3..b4f0950793 100644 --- a/base/test/trace_event_analyzer_unittest.cc +++ b/base/test/trace_event_analyzer_unittest.cc @@ -608,15 +608,21 @@ TEST_F(TraceEventAnalyzerTest, AsyncBeginEndAssocationsWithSteps) { EXPECT_STRCASEEQ("0xb", found[0]->id.c_str()); EXPECT_EQ(TRACE_EVENT_PHASE_ASYNC_STEP_PAST, found[0]->other_event->phase); + EXPECT_EQ(found[0], found[0]->other_event->prev_event); EXPECT_TRUE(found[0]->other_event->other_event); EXPECT_EQ(TRACE_EVENT_PHASE_ASYNC_END, found[0]->other_event->other_event->phase); + EXPECT_EQ(found[0]->other_event, + found[0]->other_event->other_event->prev_event); EXPECT_STRCASEEQ("0xc", found[1]->id.c_str()); EXPECT_EQ(TRACE_EVENT_PHASE_ASYNC_STEP_INTO, found[1]->other_event->phase); + EXPECT_EQ(found[1], found[1]->other_event->prev_event); EXPECT_TRUE(found[1]->other_event->other_event); EXPECT_EQ(TRACE_EVENT_PHASE_ASYNC_STEP_INTO, found[1]->other_event->other_event->phase); + EXPECT_EQ(found[1]->other_event, + found[1]->other_event->other_event->prev_event); double arg_actual = 0; EXPECT_TRUE(found[1]->other_event->other_event->GetArgAsNumber( "a", &arg_actual)); -- cgit v1.2.3