Add TraceAnalyzer support for START/FINISH events and JSON error logging

base/test/trace_event_analyzer_unittest.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 "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 {
@@ skipping 93 matching lines @@
   using namespace trace_analyzer;
   ManualSetUp();
 
   TraceEvent event;
   event.thread.process_id = 3;
   event.thread.thread_id = 4;
   event.timestamp = 1.5;
   event.phase = TRACE_EVENT_PHASE_BEGIN;
   event.category = "category";
   event.name = "name";
+  event.id = "1";
   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 = TRACE_EVENT_PHASE_END;
   other.category = "category2";
   other.name = "name2";
+  other.id = "2";
   other.arg_numbers["num2"] = 8.0;
   other.arg_strings["str2"] = "the string 2";
 
   event.other_event = &other;
   ASSERT_TRUE(event.has_other_event());
   double duration = event.GetAbsTimeToOtherEvent();
 
   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_id = (Query(EVENT_ID) == Query::String(event.id));
   Query event_has_arg1 = Query(EVENT_HAS_NUMBER_ARG, "num");
   Query event_has_arg2 = Query(EVENT_HAS_STRING_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_id = (Query(OTHER_ID) == Query::String(other.id));
   Query other_has_arg1 = Query(OTHER_HAS_NUMBER_ARG, "num2");
   Query other_has_arg2 = Query(OTHER_HAS_STRING_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_id.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_id.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_id.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();
@@ skipping 204 matching lines @@
   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 AssociateBeginEndEvents
 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 AssociateStartFinishEvents
+TEST_F(TraceEventAnalyzerTest, StartFinishAssocations) {
+  using namespace trace_analyzer;
+  ManualSetUp();
+
+  BeginTracing();
+  {
+    TRACE_EVENT_FINISH0("cat1", "name1", 0xA); // does not match / out of order
+    TRACE_EVENT_START0("cat1", "name1", 0xB);
+    TRACE_EVENT_START0("cat1", "name1", 0xC);
+    TRACE_EVENT_INSTANT0("cat1", "name1"); // noise
+    TRACE_EVENT0("cat1", "name1"); // noise
+    TRACE_EVENT_FINISH0("cat1", "name1", 0xB);
+    TRACE_EVENT_FINISH0("cat1", "name1", 0xC);
+    TRACE_EVENT_START0("cat1", "name1", 0xA); // does not match / out of order
+  }
+  EndTracing();
+
+  scoped_ptr<TraceAnalyzer>
+      analyzer(TraceAnalyzer::Create(output_.json_output));
+  ASSERT_TRUE(analyzer.get());
+  analyzer->AssociateStartFinishEvents();
+
+  TraceAnalyzer::TraceEventVector found;
+  analyzer->FindEvents(Query::MatchStartWithFinish(), &found);
+  ASSERT_EQ(2u, found.size());
+  EXPECT_STRCASEEQ("B", found[0]->id.c_str());
+  EXPECT_STRCASEEQ("C", found[1]->id.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
@@ skipping 71 matching lines @@
   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