add classes trace_analyzer::Query and TraceAnalyzer to make it easy to search through trace data

base/test/trace_event_analyzer.cc

+// 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 <algorithm>
+#include <math.h>
+
+#include "base/test/trace_event_analyzer.h"

[jar (doing other things), 2011/10/26 19:35:20]

nit: alphabetize

[jbates, 2011/10/26 21:51:54]

Done.

+#include "base/json/json_reader.h"
+#include "base/memory/scoped_ptr.h"
+#include "base/values.h"
+
+namespace trace_analyzer {
+
+// TraceEvent
+
+TraceEvent::TraceEvent()
+    : pid_tid(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", &pid_tid.pid) &&
+      dictionary->GetInteger("tid", &pid_tid.tid) &&
+      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();
+
+  CHECK(type_ == QUERY_BOOLEAN_OPERATOR)

[jar (doing other things), 2011/10/26 19:35:20]

Checks in production code like this are bad. Brett is working to trim down the
500K of comments currently affiliated with CHECKs.  Please use DCHECKs, and
handle the cases (rather than crashing).

[jbates, 2011/10/26 21:51:54]

Done. This is base/test, so shouldn't end up in prod code. My main goal is to
assert here for both debug and release test builds. Since DCHECK also works for
Release, it works also.

[jar (doing other things), 2011/10/28 20:47:53]

DCHECK is debug only (I think)
CHECK is Release and Official (as well as DEBUG).

Do you need something different here?

On 2011/10/26 21:51:54, jbates wrote:

[jbates, 2011/10/28 21:54:28]

Since --enable-dcheck works for Release builds, DCHECK should be OK.

+      << "Invalid query: missing boolean expression";
+  CHECK(left_.get() && (right_.get() || is_unary_operator()));
+
+  if (operator_ < OP_AND) {

[jar (doing other things), 2011/10/26 19:35:20]

This was hard to read, as I had to go back to the header file to see the list. 
Perhaps it would be nice to have:
IsUnaryLogicalOperator(operator)
This way I'd at least see the intent here.

[jbates, 2011/10/26 21:51:54]

Done.

+    CHECK(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 {
+  CHECK(type_ == QUERY_ARITHMETIC_OPERATOR);
+  CHECK(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;
+      break;

[jar (doing other things), 2011/10/26 19:35:20]

personal style nit: Early return is nicer, so that the reader doesn't have to
look down and see what else you are doing.

Suggest replace:
break;
with
return true;

[jbates, 2011/10/26 21:51:54]

Done.

+    case OP_SUB:
+      *num = lhs - rhs;
+      break;
+    case OP_MUL:
+      *num = lhs * rhs;
+      break;
+    case OP_DIV:
+      *num = lhs / rhs;
+      break;
+    case OP_MOD:
+      *num = static_cast<double>(static_cast<int64>(lhs) %
+                                 static_cast<int64>(rhs));
+      break;
+    case OP_NEGATE:
+      *num = -lhs;
+      break;
+    default:
+      NOTREACHED();
+      return false;
+  }
+
+  return true;
+}
+
+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 {
+  CHECK(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->pid_tid.pid);
+    case EVENT_TID:
+    case OTHER_TID:
+      return static_cast<double>(the_event->pid_tid.tid);
+    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) {
+  CHECK(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 input_i = 0; input_i < raw_events_.size(); ++input_i) {

[jar (doing other things), 2011/10/26 19:35:20]

nit: please use either i and j for integer index, or a full blown name such as
"index" or "input_index".
When I read "input_i" I misunderstood it to be the i'th input, when it is really
an index.

[jbates, 2011/10/26 21:51:54]

Done.

+
+    TraceEvent& this_event = raw_events_[input_i];
+
+    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 si = static_cast<int>(begin_stack.size()) - 1; si >= 0; --si) {

[jar (doing other things), 2011/10/26 19:35:20]

nit: variable name |si| had me looking all over.  Better is to use things like i
and j for integer iteration, or else use a full blows name.

[jbates, 2011/10/26 21:51:54]

Done.

+        TraceEvent& begin_event = *begin_stack[si];
+
+        // 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() + si);
+          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::PidTid& pid_tid) {
+  // If pid_tid is not found, just add and return empty string.
+  return thread_names_[pid_tid];
+}
+
+void TraceAnalyzer::ParseMetadata() {
+  for (size_t i = 0; i < raw_events_.size(); ++i) {
+    TraceEvent& this_event = raw_events_[i];
+    if (this_event.phase == base::debug::TRACE_EVENT_PHASE_METADATA) {

[jar (doing other things), 2011/10/26 19:35:20]

nit: for readability, nested ifs are hard to grok.  This is a case where use of
"continue" can make things much easier to read (no curlies, no indent, and less
wrapping).
Example:
if  (this_event.phase != base::debug::TRACE_EVENT_PHASE_METADATA)
  continue;
etc.

[jbates, 2011/10/26 21:51:54]

Done.

+      // Check for thread name metadata.
+      if (this_event.name == "thread_name") {
+        std::map<std::string, std::string>::const_iterator string_i =
+            this_event.arg_strings.find("name");
+        if (string_i != this_event.arg_strings.end())

[jar (doing other things), 2011/10/26 19:35:20]

How do you deal with naming of worker threads?

[jbates, 2011/10/26 21:51:54]

They show as "WorkerPool/3478" in about:tracing with unique numbers. The thread
names are set in base/debug/trace_event.cc.

+          thread_names_[this_event.pid_tid] = string_i->second;
+      }
+    }
+  }
+}
+
+}  // namespace trace_analyzer
+