Commit 439c1b06 authored by jbates@chromium.org's avatar jbates@chromium.org

Revert 107813 - add classes trace_analyzer::Query and TraceAnalyzer to make it...

Revert 107813 - add classes trace_analyzer::Query and TraceAnalyzer to make it easy to search through trace data.

This also adds a trace_analyzer::TraceEvent class that can be constructed from JSON data (via base::Value). TraceEvent mirrors base::debug::TraceEvent in a form that is lower performance and easier to use in test code.

BUG=95714
TEST=base_unittests

Review URL: http://codereview.chromium.org/7981004

TBR=jbates@chromium.org
Review URL: http://codereview.chromium.org/8413063

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@107845 0039d316-1c4b-4281-b951-d872f2087c98
parent 2daab068
......@@ -240,7 +240,6 @@
'task_queue_unittest.cc',
'task_unittest.cc',
'template_util_unittest.cc',
'test/trace_event_analyzer_unittest.cc',
'threading/non_thread_safe_unittest.cc',
'threading/platform_thread_unittest.cc',
'threading/simple_thread_unittest.cc',
......@@ -445,8 +444,6 @@
'test/test_timeouts.h',
'test/thread_test_helper.cc',
'test/thread_test_helper.h',
'test/trace_event_analyzer.cc',
'test/trace_event_analyzer.h',
],
},
{
......
......@@ -11,6 +11,7 @@
#endif
#include "base/bind.h"
#include "base/format_macros.h"
#include "base/memory/ref_counted_memory.h"
#include "base/process_util.h"
#include "base/stringprintf.h"
#include "base/threading/thread_local.h"
......@@ -118,6 +119,22 @@ void TraceValue::AppendAsJSON(std::string* out) const {
namespace {
const char* GetPhaseStr(TraceEventPhase phase) {
switch(phase) {
case TRACE_EVENT_PHASE_BEGIN:
return "B";
case TRACE_EVENT_PHASE_INSTANT:
return "I";
case TRACE_EVENT_PHASE_END:
return "E";
case TRACE_EVENT_PHASE_METADATA:
return "M";
default:
NOTREACHED() << "Invalid phase argument";
return "?";
}
}
size_t GetAllocLength(const char* str) { return str ? strlen(str) + 1 : 0; }
// Copies |*member| into |*buffer|, sets |*member| to point to this new
......@@ -204,38 +221,6 @@ TraceEvent::TraceEvent(unsigned long process_id,
TraceEvent::~TraceEvent() {
}
const char* TraceEvent::GetPhaseString(TraceEventPhase phase) {
switch(phase) {
case TRACE_EVENT_PHASE_BEGIN:
return "B";
case TRACE_EVENT_PHASE_INSTANT:
return "I";
case TRACE_EVENT_PHASE_END:
return "E";
case TRACE_EVENT_PHASE_METADATA:
return "M";
default:
NOTREACHED() << "Invalid phase argument";
return "?";
}
}
TraceEventPhase TraceEvent::GetPhase(const char* phase) {
switch(*phase) {
case 'B':
return TRACE_EVENT_PHASE_BEGIN;
case 'I':
return TRACE_EVENT_PHASE_INSTANT;
case 'E':
return TRACE_EVENT_PHASE_END;
case 'M':
return TRACE_EVENT_PHASE_METADATA;
default:
NOTREACHED() << "Invalid phase name";
return TRACE_EVENT_PHASE_METADATA;
}
}
void TraceEvent::AppendEventsAsJSON(const std::vector<TraceEvent>& events,
size_t start,
size_t count,
......@@ -248,7 +233,7 @@ void TraceEvent::AppendEventsAsJSON(const std::vector<TraceEvent>& events,
}
void TraceEvent::AppendAsJSON(std::string* out) const {
const char* phase_str = GetPhaseString(phase_);
const char* phase_str = GetPhaseStr(phase_);
int64 time_int64 = timestamp_.ToInternalValue();
// Category name checked at category creation time.
DCHECK(!strchr(name_, '"'));
......
......@@ -102,7 +102,6 @@
#include "base/callback.h"
#include "base/hash_tables.h"
#include "base/memory/ref_counted_memory.h"
#include "base/memory/singleton.h"
#include "base/string_util.h"
#include "base/third_party/dynamic_annotations/dynamic_annotations.h"
......@@ -420,10 +419,6 @@ class BASE_EXPORT TraceValue {
return value;
}
bool is_string() const {
return type_ == TRACE_TYPE_STRING || type_ == TRACE_TYPE_STATIC_STRING;
}
void AppendAsJSON(std::string* out) const;
Type type() const {
......@@ -450,7 +445,7 @@ class BASE_EXPORT TraceValue {
return value_.as_pointer;
}
const char* as_string() const {
DCHECK(is_string());
DCHECK(type_ == TRACE_TYPE_STRING || type_ == TRACE_TYPE_STATIC_STRING);
return value_.as_string;
}
const char** as_assignable_string() {
......@@ -476,7 +471,7 @@ class BASE_EXPORT TraceValue {
// OutputCallback whenever the tracing system decides to flush. This
// can happen at any time, on any thread, or you can programatically
// force it to happen.
class BASE_EXPORT TraceEvent {
class TraceEvent {
public:
TraceEvent();
TraceEvent(unsigned long process_id,
......@@ -490,9 +485,6 @@ class BASE_EXPORT TraceEvent {
bool copy);
~TraceEvent();
static const char* GetPhaseString(TraceEventPhase phase);
static TraceEventPhase GetPhase(const char* phase);
// Serialize event data to JSON
static void AppendEventsAsJSON(const std::vector<TraceEvent>& events,
size_t start,
......
// Copyright (c) 2011 The Chromium Authors. All rights reserved.
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
#include "base/test/trace_event_analyzer.h"
#include <algorithm>
#include <math.h>
#include "base/json/json_reader.h"
#include "base/memory/scoped_ptr.h"
#include "base/values.h"
namespace trace_analyzer {
// TraceEvent
TraceEvent::TraceEvent()
: thread(0, 0),
timestamp(0),
phase(base::debug::TRACE_EVENT_PHASE_BEGIN),
other_event(NULL) {
}
TraceEvent::~TraceEvent() {
}
bool TraceEvent::SetFromJSON(const base::Value* event_value) {
if (event_value->GetType() != base::Value::TYPE_DICTIONARY)
return false;
const base::DictionaryValue* dictionary =
static_cast<const base::DictionaryValue*>(event_value);
std::string phase_str;
base::DictionaryValue* args = NULL;
if (dictionary->GetInteger("pid", &thread.process_id) &&
dictionary->GetInteger("tid", &thread.thread_id) &&
dictionary->GetDouble("ts", &timestamp) &&
dictionary->GetString("cat", &category) &&
dictionary->GetString("name", &name) &&
dictionary->GetString("ph", &phase_str) &&
dictionary->GetDictionary("args", &args)) {
phase = base::debug::TraceEvent::GetPhase(phase_str.c_str());
// For each argument, copy the type and create a trace_analyzer::TraceValue.
base::DictionaryValue::key_iterator keyi = args->begin_keys();
for (; keyi != args->end_keys(); ++keyi) {
std::string str;
bool boolean = false;
int int_num = 0;
double double_num = 0.0;
Value* value = NULL;
if (args->GetWithoutPathExpansion(*keyi, &value)) {
if (value->GetAsString(&str))
arg_strings[*keyi] = str;
else if (value->GetAsInteger(&int_num))
arg_numbers[*keyi] = static_cast<double>(int_num);
else if (value->GetAsBoolean(&boolean))
arg_numbers[*keyi] = static_cast<double>(boolean ? 1 : 0);
else if (value->GetAsDouble(&double_num))
arg_numbers[*keyi] = double_num;
else
return false; // Invalid trace event JSON format.
}
}
return true;
}
return false;
}
bool TraceEvent::GetAbsTimeToOtherEvent(double* duration) const {
if (!other_event)
return false;
*duration = fabs(other_event->timestamp - timestamp);
return true;
}
bool TraceEvent::GetArgAsString(const std::string& name,
std::string* arg) const {
std::map<std::string, std::string>::const_iterator i = arg_strings.find(name);
if (i != arg_strings.end()) {
*arg = i->second;
return true;
}
return false;
}
bool TraceEvent::GetArgAsNumber(const std::string& name,
double* arg) const {
std::map<std::string, double>::const_iterator i = arg_numbers.find(name);
if (i != arg_numbers.end()) {
*arg = i->second;
return true;
}
return false;
}
// QueryNode
QueryNode::QueryNode(const Query& query) : query_(query) {
}
QueryNode::~QueryNode() {
}
// Query
Query::Query(TraceEventMember member)
: type_(QUERY_EVENT_MEMBER),
operator_(OP_INVALID),
member_(member),
number_(0),
is_pattern_(false) {
}
Query::Query(TraceEventMember member, const std::string& arg_name)
: type_(QUERY_EVENT_MEMBER),
operator_(OP_INVALID),
member_(member),
number_(0),
string_(arg_name),
is_pattern_(false) {
}
Query::Query(const Query& query)
: type_(query.type_),
operator_(query.operator_),
left_(query.left_),
right_(query.right_),
member_(query.member_),
number_(query.number_),
string_(query.string_),
is_pattern_(query.is_pattern_) {
}
Query::~Query() {
}
Query Query::String(const std::string& str) {
return Query(str);
}
Query Query::Double(double num) {
return Query(num);
}
Query Query::Int(int32 num) {
return Query(static_cast<double>(num));
}
Query Query::Uint(uint32 num) {
return Query(static_cast<double>(num));
}
Query Query::Bool(bool boolean) {
return Query(boolean ? 1.0 : 0.0);
}
Query Query::Phase(base::debug::TraceEventPhase phase) {
return Query(static_cast<double>(phase));
}
Query Query::Pattern(const std::string& pattern) {
Query query(pattern);
query.is_pattern_ = true;
return query;
}
bool Query::Evaluate(const TraceEvent& event) const {
// First check for values that can convert to bool.
// double is true if != 0:
double bool_value = 0.0;
bool is_bool = GetAsDouble(event, &bool_value);
if (is_bool)
return (bool_value != 0.0);
// string is true if it is non-empty:
std::string str_value;
bool is_str = GetAsString(event, &str_value);
if (is_str)
return !str_value.empty();
DCHECK(type_ == QUERY_BOOLEAN_OPERATOR)
<< "Invalid query: missing boolean expression";
DCHECK(left_.get() && (right_.get() || is_unary_operator()));
if (is_comparison_operator()) {
DCHECK(left().is_value() && right().is_value())
<< "Invalid query: comparison operator used between event member and "
"value.";
bool compare_result = false;
if (CompareAsDouble(event, &compare_result))
return compare_result;
else if (CompareAsString(event, &compare_result))
return compare_result;
return false;
} else {
switch (operator_) {
case OP_AND:
return left().Evaluate(event) && right().Evaluate(event);
case OP_OR:
return left().Evaluate(event) || right().Evaluate(event);
case OP_NOT:
return !left().Evaluate(event);
default:
NOTREACHED();
}
}
NOTREACHED();
return false;
}
bool Query::CompareAsDouble(const TraceEvent& event, bool* result) const {
double lhs, rhs;
if (!left().GetAsDouble(event, &lhs) || !right().GetAsDouble(event, &rhs))
return false;
switch (operator_) {
case OP_EQ:
*result = (lhs == rhs);
return true;
case OP_NE:
*result = (lhs != rhs);
return true;
case OP_LT:
*result = (lhs < rhs);
return true;
case OP_LE:
*result = (lhs <= rhs);
return true;
case OP_GT:
*result = (lhs > rhs);
return true;
case OP_GE:
*result = (lhs >= rhs);
return true;
default:
NOTREACHED();
return false;
}
return true;
}
bool Query::CompareAsString(const TraceEvent& event, bool* result) const {
std::string lhs, rhs;
if (!left().GetAsString(event, &lhs) || !right().GetAsString(event, &rhs))
return false;
switch (operator_) {
case OP_EQ:
if (right().is_pattern_)
*result = MatchPattern(lhs, rhs);
else if (left().is_pattern_)
*result = MatchPattern(rhs, lhs);
else
*result = (lhs == rhs);
return true;
case OP_NE:
if (right().is_pattern_)
*result = !MatchPattern(lhs, rhs);
else if (left().is_pattern_)
*result = !MatchPattern(rhs, lhs);
else
*result = (lhs != rhs);
return true;
case OP_LT:
*result = (lhs < rhs);
return true;
case OP_LE:
*result = (lhs <= rhs);
return true;
case OP_GT:
*result = (lhs > rhs);
return true;
case OP_GE:
*result = (lhs >= rhs);
return true;
default:
NOTREACHED();
return false;
}
return true;
}
bool Query::EvaluateArithmeticOperator(const TraceEvent& event,
double* num) const {
DCHECK(type_ == QUERY_ARITHMETIC_OPERATOR);
DCHECK(left_.get() && (right_.get() || is_unary_operator()));
double lhs = 0, rhs = 0;
if (!left().GetAsDouble(event, &lhs))
return false;
if (!is_unary_operator() && !right().GetAsDouble(event, &rhs))
return false;
switch (operator_) {
case OP_ADD:
*num = lhs + rhs;
return true;
case OP_SUB:
*num = lhs - rhs;
return true;
case OP_MUL:
*num = lhs * rhs;
return true;
case OP_DIV:
*num = lhs / rhs;
return true;
case OP_MOD:
*num = static_cast<double>(static_cast<int64>(lhs) %
static_cast<int64>(rhs));
return true;
case OP_NEGATE:
*num = -lhs;
return true;
default:
NOTREACHED();
return false;
}
}
bool Query::GetAsDouble(const TraceEvent& event, double* num) const {
base::debug::TraceValue value;
switch (type_) {
case QUERY_ARITHMETIC_OPERATOR:
return EvaluateArithmeticOperator(event, num);
case QUERY_EVENT_MEMBER:
value = GetMemberValue(event);
if (value.type() == base::debug::TraceValue::TRACE_TYPE_DOUBLE) {
*num = value.as_double();
return true;
}
return false;
case QUERY_NUMBER:
*num = number_;
return true;
default:
return false;
}
}
bool Query::GetAsString(const TraceEvent& event, std::string* str) const {
base::debug::TraceValue value;
switch (type_) {
case QUERY_EVENT_MEMBER:
value = GetMemberValue(event);
if (value.is_string()) {
*str = value.as_string();
return true;
}
return false;
case QUERY_STRING:
*str = string_;
return true;
default:
return false;
}
}
base::debug::TraceValue Query::GetMemberValue(const TraceEvent& event) const {
DCHECK(type_ == QUERY_EVENT_MEMBER);
// 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;
// Request for member of associated event, but there is no associated event.
if (!the_event)
return base::debug::TraceValue();
switch (member_) {
case EVENT_PID:
case OTHER_PID:
return static_cast<double>(the_event->thread.process_id);
case EVENT_TID:
case OTHER_TID:
return static_cast<double>(the_event->thread.thread_id);
case EVENT_TIME:
case OTHER_TIME:
return the_event->timestamp;
case EVENT_DURATION:
{
double duration;
if (the_event->GetAbsTimeToOtherEvent(&duration))
return duration;
else
return base::debug::TraceValue();
}
case EVENT_PHASE:
case OTHER_PHASE:
return static_cast<double>(the_event->phase);
case EVENT_CATEGORY:
case OTHER_CATEGORY:
return the_event->category;
case EVENT_NAME:
case OTHER_NAME:
return the_event->name;
case EVENT_HAS_ARG:
case OTHER_HAS_ARG:
// Search for the argument name and return true if found.
return static_cast<double>((the_event->arg_strings.find(string_) !=
the_event->arg_strings.end()) ||
(the_event->arg_numbers.find(string_) !=
the_event->arg_numbers.end()) ? 1 : 0);
case EVENT_ARG:
case OTHER_ARG:
{
// Search for the argument name and return its value if found.
std::map<std::string, std::string>::const_iterator str_i =
the_event->arg_strings.find(string_);
if (str_i != the_event->arg_strings.end())
return str_i->second;
std::map<std::string, double>::const_iterator num_i =
the_event->arg_numbers.find(string_);
if (num_i != the_event->arg_numbers.end())
return num_i->second;
return base::debug::TraceValue();
}
case EVENT_HAS_OTHER:
{
// return 1.0 (true) if the other event exists
double result = event.other_event ? 1.0 : 0.0;
return result;
}
default:
NOTREACHED();
return base::debug::TraceValue();
}
}
Query::Query(const std::string& str)
: type_(QUERY_STRING),
operator_(OP_INVALID),
member_(EVENT_INVALID),
number_(0),
string_(str),
is_pattern_(false) {
}
Query::Query(double num)
: type_(QUERY_NUMBER),
operator_(OP_INVALID),
member_(EVENT_INVALID),
number_(num),
is_pattern_(false) {
}
const Query& Query::left() const {
return left_->query();
}
const Query& Query::right() const {
return right_->query();
}
Query Query::operator==(const Query& rhs) const {
return Query(*this, rhs, OP_EQ);
}
Query Query::operator!=(const Query& rhs) const {
return Query(*this, rhs, OP_NE);
}
Query Query::operator<(const Query& rhs) const {
return Query(*this, rhs, OP_LT);
}
Query Query::operator<=(const Query& rhs) const {
return Query(*this, rhs, OP_LE);
}
Query Query::operator>(const Query& rhs) const {
return Query(*this, rhs, OP_GT);
}
Query Query::operator>=(const Query& rhs) const {
return Query(*this, rhs, OP_GE);
}
Query Query::operator&&(const Query& rhs) const {
return Query(*this, rhs, OP_AND);
}
Query Query::operator||(const Query& rhs) const {
return Query(*this, rhs, OP_OR);
}
Query Query::operator!() const {
return Query(*this, OP_NOT);
}
Query Query::operator+(const Query& rhs) const {
return Query(*this, rhs, OP_ADD);
}
Query Query::operator-(const Query& rhs) const {
return Query(*this, rhs, OP_SUB);
}
Query Query::operator*(const Query& rhs) const {
return Query(*this, rhs, OP_MUL);
}
Query Query::operator/(const Query& rhs) const {
return Query(*this, rhs, OP_DIV);
}
Query Query::operator%(const Query& rhs) const {
return Query(*this, rhs, OP_MOD);
}
Query Query::operator-() const {
return Query(*this, OP_NEGATE);
}
Query::Query(const Query& left, const Query& right, Operator binary_op)
: operator_(binary_op),
left_(new QueryNode(left)),
right_(new QueryNode(right)),
member_(EVENT_INVALID),
number_(0) {
type_ = (binary_op < OP_ADD ?
QUERY_BOOLEAN_OPERATOR : QUERY_ARITHMETIC_OPERATOR);
}
Query::Query(const Query& left, Operator unary_op)
: operator_(unary_op),
left_(new QueryNode(left)),
member_(EVENT_INVALID),
number_(0) {
type_ = (unary_op < OP_ADD ?
QUERY_BOOLEAN_OPERATOR : QUERY_ARITHMETIC_OPERATOR);
}
namespace {
// Search |events| for |query| and add matches to |output|.
size_t FindMatchingEvents(const std::vector<TraceEvent>& events,
const Query& query,
TraceAnalyzer::TraceEventVector* output) {
for (size_t i = 0; i < events.size(); ++i) {
if (query.Evaluate(events[i]))
output->push_back(&events[i]);
}
return output->size();
}
bool ParseEventsFromJson(const std::string& json,
std::vector<TraceEvent>* output) {
scoped_ptr<base::Value> root;
root.reset(base::JSONReader::Read(json, false));
ListValue* root_list = NULL;
if (!root.get() || !root->GetAsList(&root_list))
return false;
for (size_t i = 0; i < root_list->GetSize(); ++i) {
Value* item = NULL;
if (root_list->Get(i, &item)) {
TraceEvent event;
if (event.SetFromJSON(item))
output->push_back(event);
else
return false;
}
}
return true;
}
} // namespace
// TraceAnalyzer
TraceAnalyzer::TraceAnalyzer() : allow_assocation_changes_(true) {
}
TraceAnalyzer::~TraceAnalyzer() {
}
// static
TraceAnalyzer* TraceAnalyzer::Create(const std::string& json_events) {
scoped_ptr<TraceAnalyzer> analyzer(new TraceAnalyzer());
if (analyzer->SetEvents(json_events))
return analyzer.release();
return NULL;
}
bool TraceAnalyzer::SetEvents(const std::string& json_events) {
raw_events_.clear();
if (!ParseEventsFromJson(json_events, &raw_events_))
return false;
std::stable_sort(raw_events_.begin(), raw_events_.end());
ParseMetadata();
return true;
}
void TraceAnalyzer::AssociateBeginEndEvents() {
using namespace trace_analyzer;
Query begin(Query(EVENT_PHASE) ==
Query::Phase(base::debug::TRACE_EVENT_PHASE_BEGIN));
Query end(Query(EVENT_PHASE) ==
Query::Phase(base::debug::TRACE_EVENT_PHASE_END));
Query match(Query(EVENT_NAME) == Query(OTHER_NAME) &&
Query(EVENT_CATEGORY) == Query(OTHER_CATEGORY) &&
Query(EVENT_TID) == Query(OTHER_TID) &&
Query(EVENT_PID) == Query(OTHER_PID));
AssociateEvents(begin, end, match);
}
void TraceAnalyzer::AssociateEvents(const Query& first,
const Query& second,
const Query& match) {
DCHECK(allow_assocation_changes_) << "AssociateEvents not allowed after "
"FindEvents";
// Search for matching begin/end event pairs. When a matching end is found,
// it is associated with the begin event.
std::vector<TraceEvent*> begin_stack;
for (size_t event_index = 0; event_index < raw_events_.size();
++event_index) {
TraceEvent& this_event = raw_events_[event_index];
if (first.Evaluate(this_event)) {
begin_stack.push_back(&this_event);
} else if (second.Evaluate(this_event)) {
// Search stack for matching begin, starting from end.
for (int stack_index = static_cast<int>(begin_stack.size()) - 1;
stack_index >= 0; --stack_index) {
TraceEvent& begin_event = *begin_stack[stack_index];
// Temporarily set other to test against the match query.
const TraceEvent* other_backup = begin_event.other_event;
begin_event.other_event = &this_event;
if (match.Evaluate(begin_event)) {
// Found a matching begin/end pair.
// Set event association:
this_event.other_event = &begin_event;
// Erase the matching begin event index from the stack.
begin_stack.erase(begin_stack.begin() + stack_index);
break;
}
// Not a match, restore original other and continue.
begin_event.other_event = other_backup;
}
}
}
}
size_t TraceAnalyzer::FindEvents(const Query& query, TraceEventVector* output) {
allow_assocation_changes_ = false;
output->clear();
return FindMatchingEvents(raw_events_, query, output);
}
const TraceEvent* TraceAnalyzer::FindOneEvent(const Query& query) {
TraceEventVector output;
if (FindEvents(query, &output) > 0)
return output.front();
return NULL;
}
const std::string& TraceAnalyzer::GetThreadName(
const TraceEvent::ProcessThreadID& thread) {
// If thread is not found, just add and return empty string.
return thread_names_[thread];
}
void TraceAnalyzer::ParseMetadata() {
for (size_t i = 0; i < raw_events_.size(); ++i) {
TraceEvent& this_event = raw_events_[i];
// Check for thread name metadata.
if (this_event.phase != base::debug::TRACE_EVENT_PHASE_METADATA ||
this_event.name != "thread_name")
continue;
std::map<std::string, std::string>::const_iterator string_it =
this_event.arg_strings.find("name");
if (string_it != this_event.arg_strings.end())
thread_names_[this_event.thread] = string_it->second;
}
}
} // namespace trace_analyzer
// Copyright (c) 2011 The Chromium Authors. All rights reserved.
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
// Use trace_analyzer::Query and trace_analyzer::TraceAnalyzer to search for
// specific trace events that were generated by the trace_event.h API.
//
// Basic procedure:
// - Get trace events JSON string from base::debug::TraceLog.
// - Create TraceAnalyzer with JSON string.
// - Call TraceAnalyzer::AssociateBeginEndEvents (optional).
// - Call TraceAnalyzer::AssociateEvents (zero or more times).
// - Call TraceAnalyzer::FindEvents with queries to find specific events.
//
// A Query is a boolean expression tree that evaluates to true or false for a
// given trace event. Queries can be combined into a tree using boolean,
// arithmetic and comparison operators that refer to data of an individual trace
// event.
//
// The events are returned as trace_analyzer::TraceEvent objects.
// TraceEvent contains a single trace event's data, as well as a pointer to
// a related trace event. The related trace event is typically the matching end
// of a begin event or the matching begin of an end event.
//
// The following examples use this basic setup code to construct TraceAnalyzer
// with the json trace string retrieved from TraceLog and construct an event
// vector for retrieving events:
//
// TraceAnalyzer analyzer(json_events);
// TraceEventVector events;
//
// During construction, TraceAnalyzer::SetDefaultAssociations is called to
// associate all matching begin/end pairs similar to how they are shown in
// about:tracing.
//
// EXAMPLE 1: Find events named "my_event".
//
// analyzer.FindEvents(Query(EVENT_NAME) == "my_event", &events);
//
// EXAMPLE 2: Find begin events named "my_event" with duration > 1 second.
//
// Query q = (Query(EVENT_NAME) == Query::String("my_event") &&
// Query(EVENT_PHASE) == Query::Phase(TRACE_EVENT_PHASE_BEGIN) &&
// Query(EVENT_DURATION) > Query::Double(1000000.0));
// analyzer.FindEvents(q, &events);
//
// EXAMPLE 3: Associating event pairs across threads.
//
// If the test needs to analyze something that starts and ends on different
// threads, the test needs to use INSTANT events. The typical procedure is to
// specify the same unique ID as a TRACE_EVENT argument on both the start and
// finish INSTANT events. Then use the following procedure to associate those
// events.
//
// Step 1: instrument code with custom begin/end trace events.
// [Thread 1 tracing code]
// TRACE_EVENT_INSTANT1("test_latency", "timing1_begin", "id", 3);
// [Thread 2 tracing code]
// TRACE_EVENT_INSTANT1("test_latency", "timing1_end", "id", 3);
//
// Step 2: associate these custom begin/end pairs.
// Query begin(Query(EVENT_NAME) == Query::String("timing1_begin"));
// Query end(Query(EVENT_NAME) == Query::String("timing1_end"));
// Query match(Query(EVENT_ARG, "id") == Query(OTHER_ARG, "id"));
// analyzer.AssociateEvents(begin, end, match);
//
// Step 3: search for "timing1_begin" events with existing other event.
// Query q = (Query(EVENT_NAME) == Query::String("timing1_begin") &&
// Query(EVENT_HAS_OTHER));
// analyzer.FindEvents(q, &events);
//
// Step 4: analyze events, such as checking durations.
// for (size_t i = 0; i < events.size(); ++i) {
// double duration;
// EXPECT_TRUE(events[i].GetAbsTimeToOtherEvent(&duration));
// EXPECT_LT(duration, 1000000.0/60.0); // expect less than 1/60 second.
// }
#ifndef BASE_TEST_TRACE_EVENT_ANALYZER_H_
#define BASE_TEST_TRACE_EVENT_ANALYZER_H_
#pragma once
#include <map>
#include "base/debug/trace_event.h"
#include "base/memory/ref_counted_memory.h"
#include "base/memory/scoped_ptr.h"
namespace base {
class Value;
}
namespace trace_analyzer {
class QueryNode;
// trace_analyzer::TraceEvent is a more convenient form of the
// base::debug::TraceEvent class to make tracing-based tests easier to write.
struct BASE_EXPORT TraceEvent {
// ProcessThreadID contains a Process ID and Thread ID.
struct ProcessThreadID {
ProcessThreadID() : process_id(0), thread_id(0) {}
ProcessThreadID(int process_id, int thread_id)
: process_id(process_id), thread_id(thread_id) {}
bool operator< (const ProcessThreadID& rhs) const {
if (process_id != rhs.process_id)
return process_id < rhs.process_id;
return thread_id < rhs.thread_id;
}
int process_id;
int thread_id;
};
TraceEvent();
~TraceEvent();
bool SetFromJSON(const base::Value* event_value) WARN_UNUSED_RESULT;
bool operator< (const TraceEvent& rhs) const {
return timestamp < rhs.timestamp;
}
bool has_other_event() const { return other_event; }
// Returns absolute duration in microseconds between this event and other
// event. Returns false if has_other_event() is false.
bool GetAbsTimeToOtherEvent(double* duration) const;
// Return the argument value if it exists and it is a string.
bool GetArgAsString(const std::string& name, std::string* arg) const;
// Return the argument value if it exists and it is a number.
bool GetArgAsNumber(const std::string& name, double* arg) const;
// Process ID and Thread ID.
ProcessThreadID thread;
// Time since epoch in microseconds.
// Stored as double to match its JSON representation.
double timestamp;
base::debug::TraceEventPhase phase;
std::string category;
std::string name;
// All numbers and bool values from TraceEvent args are cast to double.
// bool becomes 1.0 (true) or 0.0 (false).
std::map<std::string, double> arg_numbers;
std::map<std::string, std::string> arg_strings;
// The other event associated with this event (or NULL).
const TraceEvent* other_event;
};
// Pass these values to Query to compare with the corresponding member of a
// TraceEvent.
enum TraceEventMember {
EVENT_INVALID,
// Use these to access the event members:
EVENT_PID,
EVENT_TID,
// Return the timestamp of the event in microseconds since epoch.
EVENT_TIME,
// Return the absolute time between event and other event in microseconds.
// Only works for events with associated BEGIN/END: Query(EVENT_HAS_OTHER).
EVENT_DURATION,
EVENT_PHASE,
EVENT_CATEGORY,
EVENT_NAME,
EVENT_HAS_ARG,
EVENT_ARG,
// Return true if associated event exists.
// (Typically BEGIN for END or END for BEGIN).
EVENT_HAS_OTHER,
// Use these to access the associated event's members:
OTHER_PID,
OTHER_TID,
OTHER_TIME,
OTHER_PHASE,
OTHER_CATEGORY,
OTHER_NAME,
OTHER_HAS_ARG,
OTHER_ARG
};
class BASE_EXPORT Query {
public:
// Compare with the given member.
Query(TraceEventMember member);
// Compare with the given member argument value.
Query(TraceEventMember member, const std::string& arg_name);
Query(const Query& query);
~Query();
// Compare with the given string.
static Query String(const std::string& str);
// Compare with the given number.
static Query Double(double num);
static Query Int(int32 num);
static Query Uint(uint32 num);
// Compare with the given bool.
static Query Bool(bool boolean);
// Compare with the given phase.
static Query Phase(base::debug::TraceEventPhase phase);
// Compare with the given string pattern. Only works with == and != operators.
// Example: Query(EVENT_NAME) == Query::Pattern("MyEvent*")
static Query Pattern(const std::string& pattern);
// Common queries:
// Find BEGIN events that have a corresponding END event.
static Query MatchBeginWithEnd() {
return (Query(EVENT_PHASE) ==
Query::Phase(base::debug::TRACE_EVENT_PHASE_BEGIN)) &&
Query(EVENT_HAS_OTHER);
}
// Find BEGIN events of given |name| which also have associated END events.
static Query MatchBeginName(const std::string& name) {
return (Query(EVENT_NAME) == name) && MatchBeginWithEnd();
}
// Match given Process ID and Thread ID.
static Query MatchThread(const TraceEvent::ProcessThreadID& thread) {
return (Query(EVENT_PID) == Query::Int(thread.process_id)) &&
(Query(EVENT_TID) == Query::Int(thread.thread_id));
}
// Match event pair that spans multiple threads.
static Query MatchCrossThread() {
return (Query(EVENT_PID) != Query(OTHER_PID)) ||
(Query(EVENT_TID) != Query(OTHER_TID));
}
// Boolean operators:
Query operator==(const Query& rhs) const;
Query operator!=(const Query& rhs) const;
Query operator< (const Query& rhs) const;
Query operator<=(const Query& rhs) const;
Query operator> (const Query& rhs) const;
Query operator>=(const Query& rhs) const;
Query operator&&(const Query& rhs) const;
Query operator||(const Query& rhs) const;
Query operator!() const;
// Arithmetic operators:
// Following operators are applied to double arguments:
Query operator+(const Query& rhs) const;
Query operator-(const Query& rhs) const;
Query operator*(const Query& rhs) const;
Query operator/(const Query& rhs) const;
Query operator-() const;
// Mod operates on int64 args (doubles are casted to int64 beforehand):
Query operator%(const Query& rhs) const;
// Return true if the given event matches this query tree.
// This is a recursive method that walks the query tree.
bool Evaluate(const TraceEvent& event) const;
private:
enum Operator {
OP_INVALID,
// Boolean operators:
OP_EQ,
OP_NE,
OP_LT,
OP_LE,
OP_GT,
OP_GE,
OP_AND,
OP_OR,
OP_NOT,
// Arithmetic operators:
OP_ADD,
OP_SUB,
OP_MUL,
OP_DIV,
OP_MOD,
OP_NEGATE
};
enum QueryType {
QUERY_BOOLEAN_OPERATOR,
QUERY_ARITHMETIC_OPERATOR,
QUERY_EVENT_MEMBER,
QUERY_NUMBER,
QUERY_STRING
};
// Compare with the given string.
Query(const std::string& str);
// Compare with the given number.
Query(double num);
// Construct a boolean Query that returns (left <binary_op> right).
Query(const Query& left, const Query& right, Operator binary_op);
// Construct a boolean Query that returns (<binary_op> left).
Query(const Query& left, Operator unary_op);
// Try to compare left_ against right_ based on operator_.
// If either left or right does not convert to double, false is returned.
// Otherwise, true is returned and |result| is set to the comparison result.
bool CompareAsDouble(const TraceEvent& event, bool* result) const;
// Try to compare left_ against right_ based on operator_.
// If either left or right does not convert to string, false is returned.
// Otherwise, true is returned and |result| is set to the comparison result.
bool CompareAsString(const TraceEvent& event, bool* result) const;
// Attempt to convert this Query to a double. On success, true is returned
// and the double value is stored in |num|.
bool GetAsDouble(const TraceEvent& event, double* num) const;
// Attempt to convert this Query to a string. On success, true is returned
// and the string value is stored in |str|.
bool GetAsString(const TraceEvent& event, std::string* str) const;
// Evaluate this Query as an arithmetic operator on left_ and right_.
bool EvaluateArithmeticOperator(const TraceEvent& event,
double* num) const;
// For QUERY_EVENT_MEMBER Query: attempt to get the value of the Query.
// The TraceValue will either be TRACE_TYPE_DOUBLE, TRACE_TYPE_STRING,
// or if requested member does not exist, it will be TRACE_TYPE_UNDEFINED.
base::debug::TraceValue GetMemberValue(const TraceEvent& event) const;
// Does this Query represent a value?
bool is_value() const { return type_ != QUERY_BOOLEAN_OPERATOR; }
bool is_unary_operator() const {
return operator_ == OP_NOT || operator_ == OP_NEGATE;
}
bool is_comparison_operator() const {
return operator_ != OP_INVALID && operator_ < OP_AND;
}
const Query& left() const;
const Query& right() const;
QueryType type_;
Operator operator_;
scoped_refptr<QueryNode> left_;
scoped_refptr<QueryNode> right_;
TraceEventMember member_;
double number_;
std::string string_;
bool is_pattern_;
};
// Implementation detail:
// QueryNode allows Query to store a ref-counted query tree.
class QueryNode : public base::RefCounted<QueryNode> {
public:
explicit QueryNode(const Query& query);
const Query& query() const { return query_; }
private:
friend class base::RefCounted<QueryNode>;
~QueryNode();
Query query_;
};
// TraceAnalyzer helps tests search for trace events.
class BASE_EXPORT TraceAnalyzer {
public:
typedef std::vector<const TraceEvent*> TraceEventVector;
~TraceAnalyzer();
// Use trace events from JSON string generated by tracing API.
// Returns non-NULL if the JSON is successfully parsed.
static TraceAnalyzer* Create(const std::string& json_events)
WARN_UNUSED_RESULT;
// Associate BEGIN and END events with each other. This allows Query(OTHER_*)
// to access the associated event and enables Query(EVENT_DURATION).
// An end event will match the most recent begin event with the same name,
// category, process ID and thread ID. This matches what is shown in
// about:tracing.
void AssociateBeginEndEvents();
// AssociateEvents can be used to customize event associations by setting the
// other_event member of TraceEvent. This should be used to associate two
// INSTANT events.
//
// The assumptions are:
// - |first| events occur before |second| events.
// - the closest matching |second| event is the correct match.
//
// |first| - Eligible |first| events match this query.
// |second| - Eligible |second| events match this query.
// |match| - This query is run on the |first| event. The OTHER_* EventMember
// queries will point to an eligible |second| event. The query
// should evaluate to true if the |first|/|second| pair is a match.
//
// When a match is found, the pair will be associated by having their
// other_event member point to each other. AssociateEvents does not clear
// previous associations, so it is possible to associate multiple pairs of
// events by calling AssociateEvents more than once with different queries.
//
// NOTE: AssociateEvents will overwrite existing other_event associations if
// the queries pass for events that already had a previous association.
//
// After calling FindEvents or FindOneEvent, it is not allowed to call
// AssociateEvents again.
void AssociateEvents(const Query& first,
const Query& second,
const Query& match);
// Find all events that match query and replace output vector.
size_t FindEvents(const Query& query, TraceEventVector* output);
// Helper method: find first event that matches query
const TraceEvent* FindOneEvent(const Query& query);
const std::string& GetThreadName(const TraceEvent::ProcessThreadID& thread);
private:
TraceAnalyzer();
bool SetEvents(const std::string& json_events) WARN_UNUSED_RESULT;
// Read metadata (thread names, etc) from events.
void ParseMetadata();
std::map<TraceEvent::ProcessThreadID, std::string> thread_names_;
std::vector<TraceEvent> raw_events_;
bool allow_assocation_changes_;
DISALLOW_COPY_AND_ASSIGN(TraceAnalyzer);
};
} // namespace trace_analyzer
#endif // BASE_TEST_TRACE_EVENT_ANALYZER_H_
// Copyright (c) 2011 The Chromium Authors. All rights reserved.
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
#include "base/bind.h"
#include "base/test/trace_event_analyzer.h"
#include "testing/gmock/include/gmock/gmock.h"
#include "testing/gtest/include/gtest/gtest.h"
namespace trace_analyzer {
namespace {
class TraceEventAnalyzerTest : public testing::Test {
public:
void ManualSetUp();
void OnTraceDataCollected(
scoped_refptr<base::debug::TraceLog::RefCountedString> json_events_str);
void BeginTracing();
void EndTracing();
base::debug::TraceResultBuffer::SimpleOutput output_;
base::debug::TraceResultBuffer buffer_;
};
void TraceEventAnalyzerTest::ManualSetUp() {
base::debug::TraceLog::Resurrect();
base::debug::TraceLog* tracelog = base::debug::TraceLog::GetInstance();
ASSERT_TRUE(tracelog);
tracelog->SetOutputCallback(
base::Bind(&TraceEventAnalyzerTest::OnTraceDataCollected,
base::Unretained(this)));
buffer_.SetOutputCallback(output_.GetCallback());
output_.json_output.clear();
}
void TraceEventAnalyzerTest::OnTraceDataCollected(
scoped_refptr<base::debug::TraceLog::RefCountedString> json_events_str) {
buffer_.AddFragment(json_events_str->data);
}
void TraceEventAnalyzerTest::BeginTracing() {
output_.json_output.clear();
buffer_.Start();
base::debug::TraceLog::GetInstance()->SetEnabled(true);
}
void TraceEventAnalyzerTest::EndTracing() {
base::debug::TraceLog::GetInstance()->SetEnabled(false);
buffer_.Finish();
}
} // namespace
TEST_F(TraceEventAnalyzerTest, NoEvents) {
using namespace trace_analyzer;
ManualSetUp();
// Create an empty JSON event string:
buffer_.Start();
buffer_.Finish();
scoped_ptr<TraceAnalyzer>
analyzer(TraceAnalyzer::Create(output_.json_output));
ASSERT_TRUE(analyzer.get());
// Search for all events and verify that nothing is returned.
TraceAnalyzer::TraceEventVector found;
analyzer->FindEvents(Query::Bool(true), &found);
EXPECT_EQ(0u, found.size());
}
TEST_F(TraceEventAnalyzerTest, QueryEventMember) {
using namespace trace_analyzer;
ManualSetUp();
TraceEvent event;
event.thread.process_id = 3;
event.thread.thread_id = 4;
event.timestamp = 1.5;
event.phase = base::debug::TRACE_EVENT_PHASE_BEGIN;
event.category = "category";
event.name = "name";
event.arg_numbers["num"] = 7.0;
event.arg_strings["str"] = "the string";
// Other event with all different members:
TraceEvent other;
other.thread.process_id = 5;
other.thread.thread_id = 6;
other.timestamp = 2.5;
other.phase = base::debug::TRACE_EVENT_PHASE_END;
other.category = "category2";
other.name = "name2";
other.arg_numbers["num2"] = 8.0;
other.arg_strings["str2"] = "the string 2";
event.other_event = &other;
double duration;
ASSERT_TRUE(event.GetAbsTimeToOtherEvent(&duration));
Query event_pid = (Query(EVENT_PID) == Query::Int(event.thread.process_id));
Query event_tid = (Query(EVENT_TID) == Query::Int(event.thread.thread_id));
Query event_time = (Query(EVENT_TIME) == Query::Double(event.timestamp));
Query event_duration = (Query(EVENT_DURATION) == Query::Double(duration));
Query event_phase = (Query(EVENT_PHASE) == Query::Phase(event.phase));
Query event_category =
(Query(EVENT_CATEGORY) == Query::String(event.category));
Query event_name = (Query(EVENT_NAME) == Query::String(event.name));
Query event_has_arg1 = Query(EVENT_HAS_ARG, "num");
Query event_has_arg2 = Query(EVENT_HAS_ARG, "str");
Query event_arg1 =
(Query(EVENT_ARG, "num") == Query::Double(event.arg_numbers["num"]));
Query event_arg2 =
(Query(EVENT_ARG, "str") == Query::String(event.arg_strings["str"]));
Query event_has_other = Query(EVENT_HAS_OTHER);
Query other_pid = (Query(OTHER_PID) == Query::Int(other.thread.process_id));
Query other_tid = (Query(OTHER_TID) == Query::Int(other.thread.thread_id));
Query other_time = (Query(OTHER_TIME) == Query::Double(other.timestamp));
Query other_phase = (Query(OTHER_PHASE) == Query::Phase(other.phase));
Query other_category =
(Query(OTHER_CATEGORY) == Query::String(other.category));
Query other_name = (Query(OTHER_NAME) == Query::String(other.name));
Query other_has_arg1 = Query(OTHER_HAS_ARG, "num2");
Query other_has_arg2 = Query(OTHER_HAS_ARG, "str2");
Query other_arg1 =
(Query(OTHER_ARG, "num2") == Query::Double(other.arg_numbers["num2"]));
Query other_arg2 =
(Query(OTHER_ARG, "str2") == Query::String(other.arg_strings["str2"]));
EXPECT_TRUE(event_pid.Evaluate(event));
EXPECT_TRUE(event_tid.Evaluate(event));
EXPECT_TRUE(event_time.Evaluate(event));
EXPECT_TRUE(event_duration.Evaluate(event));
EXPECT_TRUE(event_phase.Evaluate(event));
EXPECT_TRUE(event_category.Evaluate(event));
EXPECT_TRUE(event_name.Evaluate(event));
EXPECT_TRUE(event_has_arg1.Evaluate(event));
EXPECT_TRUE(event_has_arg2.Evaluate(event));
EXPECT_TRUE(event_arg1.Evaluate(event));
EXPECT_TRUE(event_arg2.Evaluate(event));
EXPECT_TRUE(event_has_other.Evaluate(event));
EXPECT_TRUE(other_pid.Evaluate(event));
EXPECT_TRUE(other_tid.Evaluate(event));
EXPECT_TRUE(other_time.Evaluate(event));
EXPECT_TRUE(other_phase.Evaluate(event));
EXPECT_TRUE(other_category.Evaluate(event));
EXPECT_TRUE(other_name.Evaluate(event));
EXPECT_TRUE(other_has_arg1.Evaluate(event));
EXPECT_TRUE(other_has_arg2.Evaluate(event));
EXPECT_TRUE(other_arg1.Evaluate(event));
EXPECT_TRUE(other_arg2.Evaluate(event));
// Evaluate event queries against other to verify the queries fail when the
// event members are wrong.
EXPECT_FALSE(event_pid.Evaluate(other));
EXPECT_FALSE(event_tid.Evaluate(other));
EXPECT_FALSE(event_time.Evaluate(other));
EXPECT_FALSE(event_duration.Evaluate(other));
EXPECT_FALSE(event_phase.Evaluate(other));
EXPECT_FALSE(event_category.Evaluate(other));
EXPECT_FALSE(event_name.Evaluate(other));
EXPECT_FALSE(event_has_arg1.Evaluate(other));
EXPECT_FALSE(event_has_arg2.Evaluate(other));
EXPECT_FALSE(event_arg1.Evaluate(other));
EXPECT_FALSE(event_arg2.Evaluate(other));
EXPECT_FALSE(event_has_other.Evaluate(other));
}
TEST_F(TraceEventAnalyzerTest, BooleanOperators) {
using namespace trace_analyzer;
ManualSetUp();
BeginTracing();
{
TRACE_EVENT_INSTANT1("cat1", "name1", "num", 1);
TRACE_EVENT_INSTANT1("cat1", "name2", "num", 2);
TRACE_EVENT_INSTANT1("cat2", "name3", "num", 3);
TRACE_EVENT_INSTANT1("cat2", "name4", "num", 4);
}
EndTracing();
scoped_ptr<TraceAnalyzer>
analyzer(TraceAnalyzer::Create(output_.json_output));
ASSERT_TRUE(!!analyzer.get());
TraceAnalyzer::TraceEventVector found;
// ==
analyzer->FindEvents(Query(EVENT_CATEGORY) == Query::String("cat1"), &found);
ASSERT_EQ(2u, found.size());
EXPECT_STREQ("name1", found[0]->name.c_str());
EXPECT_STREQ("name2", found[1]->name.c_str());
analyzer->FindEvents(Query(EVENT_ARG, "num") == Query::Int(2), &found);
ASSERT_EQ(1u, found.size());
EXPECT_STREQ("name2", found[0]->name.c_str());
// !=
analyzer->FindEvents(Query(EVENT_CATEGORY) != Query::String("cat1"), &found);
ASSERT_EQ(2u, found.size());
EXPECT_STREQ("name3", found[0]->name.c_str());
EXPECT_STREQ("name4", found[1]->name.c_str());
analyzer->FindEvents(Query(EVENT_ARG, "num") != Query::Int(2), &found);
ASSERT_EQ(3u, found.size());
EXPECT_STREQ("name1", found[0]->name.c_str());
EXPECT_STREQ("name3", found[1]->name.c_str());
EXPECT_STREQ("name4", found[2]->name.c_str());
// <
analyzer->FindEvents(Query(EVENT_ARG, "num") < Query::Int(2), &found);
ASSERT_EQ(1u, found.size());
EXPECT_STREQ("name1", found[0]->name.c_str());
// <=
analyzer->FindEvents(Query(EVENT_ARG, "num") <= Query::Int(2), &found);
ASSERT_EQ(2u, found.size());
EXPECT_STREQ("name1", found[0]->name.c_str());
EXPECT_STREQ("name2", found[1]->name.c_str());
// >
analyzer->FindEvents(Query(EVENT_ARG, "num") > Query::Int(3), &found);
ASSERT_EQ(1u, found.size());
EXPECT_STREQ("name4", found[0]->name.c_str());
// >=
analyzer->FindEvents(Query(EVENT_ARG, "num") >= Query::Int(4), &found);
ASSERT_EQ(1u, found.size());
EXPECT_STREQ("name4", found[0]->name.c_str());
// &&
analyzer->FindEvents(Query(EVENT_NAME) != Query::String("name1") &&
Query(EVENT_ARG, "num") < Query::Int(3), &found);
ASSERT_EQ(1u, found.size());
EXPECT_STREQ("name2", found[0]->name.c_str());
// ||
analyzer->FindEvents(Query(EVENT_NAME) == Query::String("name1") ||
Query(EVENT_ARG, "num") == Query::Int(3), &found);
ASSERT_EQ(2u, found.size());
EXPECT_STREQ("name1", found[0]->name.c_str());
EXPECT_STREQ("name3", found[1]->name.c_str());
// !
analyzer->FindEvents(!(Query(EVENT_NAME) == Query::String("name1") ||
Query(EVENT_ARG, "num") == Query::Int(3)), &found);
ASSERT_EQ(2u, found.size());
EXPECT_STREQ("name2", found[0]->name.c_str());
EXPECT_STREQ("name4", found[1]->name.c_str());
}
TEST_F(TraceEventAnalyzerTest, ArithmeticOperators) {
using namespace trace_analyzer;
ManualSetUp();
BeginTracing();
{
// These events are searched for:
TRACE_EVENT_INSTANT2("cat1", "math1", "a", 10, "b", 5);
TRACE_EVENT_INSTANT2("cat1", "math2", "a", 10, "b", 10);
// Extra events that never match, for noise:
TRACE_EVENT_INSTANT2("noise", "math3", "a", 1, "b", 3);
TRACE_EVENT_INSTANT2("noise", "math4", "c", 10, "d", 5);
}
EndTracing();
scoped_ptr<TraceAnalyzer>
analyzer(TraceAnalyzer::Create(output_.json_output));
ASSERT_TRUE(analyzer.get());
TraceAnalyzer::TraceEventVector found;
// Verify that arithmetic operators function:
// +
analyzer->FindEvents(Query(EVENT_ARG, "a") + Query(EVENT_ARG, "b") ==
Query::Int(20), &found);
EXPECT_EQ(1u, found.size());
EXPECT_STREQ("math2", found.front()->name.c_str());
// -
analyzer->FindEvents(Query(EVENT_ARG, "a") - Query(EVENT_ARG, "b") ==
Query::Int(5), &found);
EXPECT_EQ(1u, found.size());
EXPECT_STREQ("math1", found.front()->name.c_str());
// *
analyzer->FindEvents(Query(EVENT_ARG, "a") * Query(EVENT_ARG, "b") ==
Query::Int(50), &found);
EXPECT_EQ(1u, found.size());
EXPECT_STREQ("math1", found.front()->name.c_str());
// /
analyzer->FindEvents(Query(EVENT_ARG, "a") / Query(EVENT_ARG, "b") ==
Query::Int(2), &found);
EXPECT_EQ(1u, found.size());
EXPECT_STREQ("math1", found.front()->name.c_str());
// %
analyzer->FindEvents(Query(EVENT_ARG, "a") % Query(EVENT_ARG, "b") ==
Query::Int(0), &found);
EXPECT_EQ(2u, found.size());
// - (negate)
analyzer->FindEvents(-Query(EVENT_ARG, "b") == Query::Int(-10), &found);
EXPECT_EQ(1u, found.size());
EXPECT_STREQ("math2", found.front()->name.c_str());
}
TEST_F(TraceEventAnalyzerTest, StringPattern) {
using namespace trace_analyzer;
ManualSetUp();
BeginTracing();
{
TRACE_EVENT_INSTANT0("cat1", "name1");
TRACE_EVENT_INSTANT0("cat1", "name2");
TRACE_EVENT_INSTANT0("cat1", "no match");
TRACE_EVENT_INSTANT0("cat1", "name3x");
}
EndTracing();
scoped_ptr<TraceAnalyzer>
analyzer(TraceAnalyzer::Create(output_.json_output));
ASSERT_TRUE(analyzer.get());
TraceAnalyzer::TraceEventVector found;
analyzer->FindEvents(Query(EVENT_NAME) == Query::Pattern("name?"), &found);
ASSERT_EQ(2u, found.size());
EXPECT_STREQ("name1", found[0]->name.c_str());
EXPECT_STREQ("name2", found[1]->name.c_str());
analyzer->FindEvents(Query(EVENT_NAME) == Query::Pattern("name*"), &found);
ASSERT_EQ(3u, found.size());
EXPECT_STREQ("name1", found[0]->name.c_str());
EXPECT_STREQ("name2", found[1]->name.c_str());
EXPECT_STREQ("name3x", found[2]->name.c_str());
analyzer->FindEvents(Query(EVENT_NAME) != Query::Pattern("name*"), &found);
ASSERT_EQ(1u, found.size());
EXPECT_STREQ("no match", found[0]->name.c_str());
}
// Test that duration queries work.
TEST_F(TraceEventAnalyzerTest, Duration) {
using namespace trace_analyzer;
ManualSetUp();
int sleep_time_us = 200000;
// We will search for events that have a duration of greater than 90% of the
// sleep time, so that there is no flakiness.
int duration_cutoff_us = (sleep_time_us * 9) / 10;
BeginTracing();
{
TRACE_EVENT0("cat1", "name1"); // found by duration query
TRACE_EVENT0("noise", "name2"); // not searched for, just noise
{
TRACE_EVENT0("cat2", "name3"); // found by duration query
TRACE_EVENT_INSTANT0("noise", "name4"); // not searched for, just noise
base::PlatformThread::Sleep(sleep_time_us / 1000);
TRACE_EVENT0("cat2", "name5"); // not found (duration too short)
}
}
EndTracing();
scoped_ptr<TraceAnalyzer>
analyzer(TraceAnalyzer::Create(output_.json_output));
ASSERT_TRUE(analyzer.get());
analyzer->AssociateBeginEndEvents();
TraceAnalyzer::TraceEventVector found;
analyzer->FindEvents(Query::MatchBeginWithEnd() &&
Query(EVENT_DURATION) > Query::Int(duration_cutoff_us) &&
(Query(EVENT_CATEGORY) == Query::String("cat1") ||
Query(EVENT_CATEGORY) == Query::String("cat2") ||
Query(EVENT_CATEGORY) == Query::String("cat3")), &found);
ASSERT_EQ(2u, found.size());
EXPECT_STREQ("name1", found[0]->name.c_str());
EXPECT_STREQ("name3", found[1]->name.c_str());
}
// Test that arithmetic operators work.
TEST_F(TraceEventAnalyzerTest, BeginEndAssocations) {
using namespace trace_analyzer;
ManualSetUp();
BeginTracing();
{
TRACE_EVENT_END0("cat1", "name1"); // does not match out of order begin
TRACE_EVENT0("cat1", "name2");
TRACE_EVENT_INSTANT0("cat1", "name3");
TRACE_EVENT_BEGIN0("cat1", "name1");
}
EndTracing();
scoped_ptr<TraceAnalyzer>
analyzer(TraceAnalyzer::Create(output_.json_output));
ASSERT_TRUE(analyzer.get());
analyzer->AssociateBeginEndEvents();
TraceAnalyzer::TraceEventVector found;
analyzer->FindEvents(Query::MatchBeginWithEnd(), &found);
ASSERT_EQ(1u, found.size());
EXPECT_STREQ("name2", found[0]->name.c_str());
}
// Test that the TraceAnalyzer custom associations work.
TEST_F(TraceEventAnalyzerTest, CustomAssociations) {
using namespace trace_analyzer;
ManualSetUp();
// Add events that begin/end in pipelined ordering with unique ID parameter
// to match up the begin/end pairs.
BeginTracing();
{
TRACE_EVENT_INSTANT1("cat1", "end", "id", 1); // no begin match
TRACE_EVENT_INSTANT1("cat2", "begin", "id", 2); // end is cat4
TRACE_EVENT_INSTANT1("cat3", "begin", "id", 3); // end is cat5
TRACE_EVENT_INSTANT1("cat4", "end", "id", 2);
TRACE_EVENT_INSTANT1("cat5", "end", "id", 3);
TRACE_EVENT_INSTANT1("cat6", "begin", "id", 1); // no end match
}
EndTracing();
scoped_ptr<TraceAnalyzer>
analyzer(TraceAnalyzer::Create(output_.json_output));
ASSERT_TRUE(analyzer.get());
// begin, end, and match queries to find proper begin/end pairs.
Query begin(Query(EVENT_NAME) == Query::String("begin"));
Query end(Query(EVENT_NAME) == Query::String("end"));
Query match(Query(EVENT_ARG, "id") == Query(OTHER_ARG, "id"));
analyzer->AssociateEvents(begin, end, match);
TraceAnalyzer::TraceEventVector found;
// cat1 has no other_event.
analyzer->FindEvents(Query(EVENT_CATEGORY) == Query::String("cat1") &&
Query(EVENT_HAS_OTHER), &found);
EXPECT_EQ(0u, found.size());
// cat1 has no other_event.
analyzer->FindEvents(Query(EVENT_CATEGORY) == Query::String("cat1") &&
!Query(EVENT_HAS_OTHER), &found);
EXPECT_EQ(1u, found.size());
// cat6 has no other_event.
analyzer->FindEvents(Query(EVENT_CATEGORY) == Query::String("cat6") &&
!Query(EVENT_HAS_OTHER), &found);
EXPECT_EQ(1u, found.size());
// cat2 and cat4 are a associated.
analyzer->FindEvents(Query(EVENT_CATEGORY) == Query::String("cat2") &&
Query(OTHER_CATEGORY) == Query::String("cat4"), &found);
EXPECT_EQ(1u, found.size());
// cat4 and cat2 are a associated.
analyzer->FindEvents(Query(EVENT_CATEGORY) == Query::String("cat4") &&
Query(OTHER_CATEGORY) == Query::String("cat2"), &found);
EXPECT_EQ(1u, found.size());
// cat3 and cat5 are a associated.
analyzer->FindEvents(Query(EVENT_CATEGORY) == Query::String("cat3") &&
Query(OTHER_CATEGORY) == Query::String("cat5"), &found);
EXPECT_EQ(1u, found.size());
// cat5 and cat3 are a associated.
analyzer->FindEvents(Query(EVENT_CATEGORY) == Query::String("cat5") &&
Query(OTHER_CATEGORY) == Query::String("cat3"), &found);
EXPECT_EQ(1u, found.size());
}
// Verify that Query literals and types are properly casted.
TEST_F(TraceEventAnalyzerTest, Literals) {
using namespace trace_analyzer;
ManualSetUp();
// Since these queries don't refer to the event data, the dummy event below
// will never be accessed.
TraceEvent dummy;
char char_num = 5;
short short_num = -5;
EXPECT_TRUE((Query::Double(5.0) == Query::Int(char_num)).Evaluate(dummy));
EXPECT_TRUE((Query::Double(-5.0) == Query::Int(short_num)).Evaluate(dummy));
EXPECT_TRUE((Query::Double(1.0) == Query::Uint(1u)).Evaluate(dummy));
EXPECT_TRUE((Query::Double(1.0) == Query::Int(1)).Evaluate(dummy));
EXPECT_TRUE((Query::Double(-1.0) == Query::Int(-1)).Evaluate(dummy));
EXPECT_TRUE((Query::Double(1.0) == Query::Double(1.0f)).Evaluate(dummy));
EXPECT_TRUE((Query::Bool(true) == Query::Int(1)).Evaluate(dummy));
EXPECT_TRUE((Query::Bool(false) == Query::Int(0)).Evaluate(dummy));
EXPECT_TRUE((Query::Bool(true) == Query::Double(1.0f)).Evaluate(dummy));
EXPECT_TRUE((Query::Bool(false) == Query::Double(0.0f)).Evaluate(dummy));
}
} // namespace trace_analyzer
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment