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

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 {
+
+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());
+}
+
+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 that the TraceAnalyzer works.

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

It is much nicer to test components, and verify that they work, starting with
small items, and working your way up. 

For example:
Test1:  see if you can do a BeginTracing and EndTracing and have no data, and
handle this case well.

Test2: See if you can do tracing with just one event.  Perhaps you can JSON-ify
the results, and see if they are as expected.

Test3: Check to see that the accessors can identify elements.

etc.

As it stands now, you mostly just run a big test, and everything supposedly
works.  When this test fails, it will be much harder (in a year) to figure out
what happened.

In addition, I doubt that you get very complete coverage... but I don't know.  I
saw a lot of discussion of various binary and unary operators... and it is not
clear how or why or where this was tested.

bottom line: A series of small, well labeled tests are much easier to read, and
easier to respond to when there is a failure.

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

In hindsight, I agree that would be easier to maintain. Is this a blocker for
you or can that be done as a followup CL? I ask because there are some
dependencies waiting on this API.

[jbates, 2011/10/27 20:36:35]

Done.

+TEST_F(TraceEventAnalyzerTest, TraceAnalyzerBasic) {
+  using namespace trace_analyzer;
+  ManualSetUp();
+
+  BeginTracing();
+  {
+    TRACE_EVENT_END0("cat3", "name7");

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

nit: for readability, it is much nicer to use named values (put in temporaries)
than simply have embedded constants, where the user must decipher the intent. 
For example:
const char* kThreadName = "cat3";
const char* kFunction = "name7"
TRACE_EVENT_END0(kThreadName, kFunction);

Also note that you can re-use these constats later in your test, when doing the
EXPECT.. calls.

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

I agree that would be clearer. These trace events follow the style of
base/debug/trace_event_unittests.cc.

+    TRACE_EVENT2("cat1", "name1", "arg1", 1111, "arg2", "string1");
+    {
+      TRACE_EVENT2("cat2", "name2", "arg1", 2222, "arg2", "string2");
+      TRACE_EVENT_INSTANT1("cat1", "name3", "arg1", 3333);
+      base::PlatformThread::Sleep(200);
+      TRACE_EVENT0("cat2", "name6");
+    }
+    TRACE_EVENT_INSTANT1("cat2", "name4", "arg1", 4444);
+    TRACE_EVENT_INSTANT1("cat2", "name5", "arg1", 1111);
+    TRACE_EVENT_BEGIN0("cat3", "name7");
+    TRACE_EVENT_INSTANT2("cat4", "math1", "a", 10, "b", 5);
+    TRACE_EVENT_INSTANT2("cat4", "math2", "a", 10, "b", 10);
+  }
+  EndTracing();
+
+  const TraceEvent* event = NULL;
+  scoped_ptr<TraceAnalyzer>
+      analyzer(TraceAnalyzer::Create(output_.json_output));
+  ASSERT_TRUE(!!analyzer.get());
+  analyzer->AssociateBeginEndEvents();
+
+  TraceAnalyzer::TraceEventVector found;
+
+  analyzer->FindEvents(Query(EVENT_CATEGORY) == Query::String("cat1"), &found);
+  EXPECT_EQ(3u, found.size());
+
+  analyzer->FindEvents(Query(EVENT_CATEGORY) == Query::String("cat1") &&
+                      Query(EVENT_ARG, "arg1") == Query::Int(1111), &found);
+  ASSERT_EQ(1u, found.size());
+  EXPECT_STREQ("name1", found.front()->name.c_str());
+
+  analyzer->FindEvents(Query(EVENT_ARG, "arg1") == Query::Int(1111) ||
+                      Query(EVENT_ARG, "arg1") == Query::Int(2222), &found);
+  EXPECT_EQ(3u, found.size());
+
+  analyzer->FindEvents(Query(EVENT_ARG, "arg1") == Query::Int(1111) &&
+                      Query(EVENT_NAME) != Query::String("name1"), &found);
+  ASSERT_EQ(1u, found.size());
+  EXPECT_STREQ("name5", found.front()->name.c_str());
+
+  analyzer->FindEvents(Query(EVENT_ARG, "arg1") == Query::Int(1111) &&
+                      !(Query(EVENT_NAME) != Query::String("name1")), &found);
+  ASSERT_EQ(1u, found.size());
+  EXPECT_STREQ("name1", found.front()->name.c_str());
+
+  analyzer->FindEvents(Query::MatchBeginWithEnd() &&
+                      Query(EVENT_DURATION) > Query::Int(180000) &&
+                      (Query(EVENT_CATEGORY) == Query::String("cat1") ||
+                       Query(EVENT_CATEGORY) == Query::String("cat2") ||
+                       Query(EVENT_CATEGORY) == Query::String("cat3")), &found);
+  EXPECT_EQ(2u, found.size());
+
+  analyzer->FindEvents(Query(EVENT_ARG, "arg1") <= Query::Int(3333), &found);
+  EXPECT_EQ(4u, found.size());
+
+  analyzer->FindEvents(Query(EVENT_ARG, "arg1") >= Query::Int(3333), &found);
+  EXPECT_EQ(2u, found.size());
+
+  analyzer->FindEvents(Query(EVENT_HAS_ARG, "arg1"), &found);
+  EXPECT_EQ(5u, found.size());
+
+  analyzer->FindEvents(Query(EVENT_ARG, "arg2") == Query::String("string1"),
+                       &found);
+  ASSERT_EQ(1u, found.size());
+  EXPECT_STREQ("name1", found.front()->name.c_str());
+
+  analyzer->FindEvents(Query(EVENT_ARG, "arg2") == Query::Pattern("string?"),
+                      &found);
+  EXPECT_EQ(2u, found.size());
+
+  analyzer->FindEvents(Query(EVENT_CATEGORY) == Query::Pattern("cat?") &&
+                      Query(EVENT_NAME) != Query::Pattern("*"),
+                      &found);
+  EXPECT_EQ(0u, found.size());
+
+  analyzer->FindEvents(!Query(EVENT_HAS_OTHER) &&
+                      Query(EVENT_CATEGORY) == Query::String("cat2"), &found);
+  EXPECT_EQ(2u, found.size());
+
+  event = analyzer->FindOneEvent(Query(OTHER_ARG, "arg1") == Query::Int(1111));
+  ASSERT_TRUE(event);
+  EXPECT_STREQ("name1", event->name.c_str());
+
+  // Verify that matching END..BEGIN does not get associated.
+  ASSERT_TRUE(!analyzer->FindOneEvent(Query::MatchBeginName("name7")));
+
+  ASSERT_TRUE(!analyzer->FindOneEvent(Query(EVENT_ARG, "arg1") <
+                                      Query::Int(1111)));
+
+  // 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());
+
+  analyzer->FindEvents(-Query(EVENT_ARG, "b") == Query::Int(-10), &found);
+  EXPECT_EQ(1u, found.size());
+  EXPECT_STREQ("math2", found.front()->name.c_str());
+}
+
+// Test that the TraceAnalyzer custom associations work.
+TEST_F(TraceEventAnalyzerTest, TraceAnalyzerAssociations) {
+  using namespace trace_analyzer;
+  ManualSetUp();
+
+  BeginTracing();
+  {
+    TRACE_EVENT_INSTANT1("cat1", "end", "id", 1);
+    TRACE_EVENT_INSTANT1("cat2", "begin", "id", 2);
+    TRACE_EVENT_INSTANT1("cat3", "begin", "id", 3);
+    TRACE_EVENT_INSTANT1("cat4", "end", "id", 2);
+    TRACE_EVENT_INSTANT1("cat5", "end", "id", 3);
+    TRACE_EVENT_INSTANT1("cat6", "begin", "id", 1);
+  }
+  EndTracing();
+
+  scoped_ptr<TraceAnalyzer>
+      analyzer(TraceAnalyzer::Create(output_.json_output));
+  ASSERT_TRUE(!!analyzer.get());
+
+  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;
+  analyzer->FindEvents(Query(EVENT_CATEGORY) == Query::String("cat1") &&
+                      Query(EVENT_HAS_OTHER), &found);
+  EXPECT_EQ(0u, found.size());
+
+  analyzer->FindEvents(Query(EVENT_CATEGORY) == Query::String("cat1") &&
+                      !Query(EVENT_HAS_OTHER), &found);
+  EXPECT_EQ(1u, found.size());
+
+  analyzer->FindEvents(Query(EVENT_CATEGORY) == Query::String("cat6") &&
+                      !Query(EVENT_HAS_OTHER), &found);
+  EXPECT_EQ(1u, found.size());
+
+  analyzer->FindEvents(Query(EVENT_CATEGORY) == Query::String("cat2") &&
+                      Query(OTHER_CATEGORY) == Query::String("cat4"), &found);
+  EXPECT_EQ(1u, found.size());
+
+  analyzer->FindEvents(Query(EVENT_CATEGORY) == Query::String("cat4") &&
+                      Query(OTHER_CATEGORY) == Query::String("cat2"), &found);
+  EXPECT_EQ(1u, found.size());
+
+  analyzer->FindEvents(Query(EVENT_CATEGORY) == Query::String("cat3") &&
+                      Query(OTHER_CATEGORY) == Query::String("cat5"), &found);
+  EXPECT_EQ(1u, found.size());
+
+  analyzer->FindEvents(Query(EVENT_CATEGORY) == Query::String("cat5") &&
+                      Query(OTHER_CATEGORY) == Query::String("cat3"), &found);
+  EXPECT_EQ(1u, found.size());
+
+  // Verify that literals and types are properly casted.
+
+  // 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
+