Divert TRACE_EVENT macros to use Event Tracing for Windows on Windows builds.

This is in preparation for instrumenting Chrome and Chrome Frame for performance measurements with ETW.

BUG=none
TEST=Unittests in this CL.

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

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@46734 0039d316-1c4b-4281-b951-d872f2087c98

1 files changed, 282 insertions, 0 deletions

diff --git a/base/trace_event_win_unittest.cc b/base/trace_event_win_unittest.cc
new file mode 100644
index 0000000..50769c5
--- /dev/null
+++ b/base/trace_event_win_unittest.cc
@@ -0,0 +1,282 @@
+// Copyright (c) 2010 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/trace_event.h"
+#include <strstream>
+#include "base/basictypes.h"
+#include "base/file_util.h"
+#include "base/event_trace_consumer_win.h"
+#include "base/event_trace_controller_win.h"
+#include "base/win_util.h"
+#include "testing/gmock/include/gmock/gmock.h"
+#include "testing/gtest/include/gtest/gtest.h"
+#include <initguid.h>  // NOLINT - must be last include.
+
+namespace {
+using testing::_;
+using testing::AnyNumber;
+using testing::InSequence;
+using testing::Ge;
+using testing::Le;
+using testing::NotNull;
+
+// Data for unittests traces.
+const char kEmpty[] = "";
+const char kName[] = "unittest.trace_name";
+const char kExtra[] = "UnittestDummyExtraString";
+const void* kId = kName;
+
+const wchar_t kTestSessionName[] = L"TraceEvent unittest session";
+
+MATCHER_P(BufferStartsWith, str, "Buffer starts with") {
+  return memcmp(arg, str.c_str(), str.length()) == 0;
+}
+
+// Duplicated from <evntrace.h> to fix link problems.
+DEFINE_GUID( /* 68fdd900-4a3e-11d1-84f4-0000f80464e3 */
+    kEventTraceGuid,
+    0x68fdd900,
+    0x4a3e,
+    0x11d1,
+    0x84, 0xf4, 0x00, 0x00, 0xf8, 0x04, 0x64, 0xe3);
+
+class TestEventConsumer: public EtwTraceConsumerBase<TestEventConsumer> {
+ public:
+  TestEventConsumer() {
+    EXPECT_TRUE(current_ == NULL);
+    current_ = this;
+  }
+
+  ~TestEventConsumer() {
+    EXPECT_TRUE(current_ == this);
+    current_ = NULL;
+  }
+
+  MOCK_METHOD4(Event, void(REFGUID event_class,
+                      EtwEventType event_type,
+                      size_t buf_len,
+                      const void* buf));
+
+  static void ProcessEvent(EVENT_TRACE* event) {
+    ASSERT_TRUE(current_ != NULL);
+    current_->Event(event->Header.Guid,
+                    event->Header.Class.Type,
+                    event->MofLength,
+                    event->MofData);
+  }
+
+ private:
+  static TestEventConsumer* current_;
+};
+
+TestEventConsumer* TestEventConsumer::current_ = NULL;
+
+class TraceEventTest: public testing::Test {
+ public:
+  void SetUp() {
+    bool is_xp = win_util::GetWinVersion() < win_util::WINVERSION_VISTA;
+
+    // Resurrect and initialize the TraceLog singleton instance.
+    // On Vista and better, we need the provider registered before we
+    // start the private, in-proc session, but on XP we need the global
+    // session created and the provider enabled before we register our
+    // provider.
+    if (!is_xp) {
+      base::TraceLog::Resurrect();
+      base::TraceLog* tracelog = base::TraceLog::Get();
+      ASSERT_TRUE(tracelog != NULL);
+    }
+
+    // Create the log file.
+    ASSERT_TRUE(file_util::CreateTemporaryFile(&log_file_));
+
+    // Create a private log session on the file.
+    EtwTraceProperties prop;
+    ASSERT_HRESULT_SUCCEEDED(prop.SetLoggerFileName(log_file_.value().c_str()));
+    EVENT_TRACE_PROPERTIES& p = *prop.get();
+    p.Wnode.ClientContext = 1;  // QPC timer accuracy.
+    p.LogFileMode = EVENT_TRACE_FILE_MODE_SEQUENTIAL;   // Sequential log.
+
+    // On Vista and later, we create a private in-process log session, because
+    // otherwise we'd need administrator privileges. Unfortunately we can't
+    // do the same on XP and better, because the semantics of a private
+    // logger session are different, and the IN_PROC flag is not supported.
+    if (!is_xp) {
+      p.LogFileMode |= EVENT_TRACE_PRIVATE_IN_PROC |  // In-proc for non-admin.
+          EVENT_TRACE_PRIVATE_LOGGER_MODE;  // Process-private log.
+    }
+
+    p.MaximumFileSize = 100;  // 100M file size.
+    p.FlushTimer = 1;  // 1 second flush lag.
+    ASSERT_HRESULT_SUCCEEDED(controller_.Start(kTestSessionName, &prop));
+
+    // Enable the TraceLog provider GUID.
+    ASSERT_HRESULT_SUCCEEDED(
+        controller_.EnableProvider(base::kChromeTraceProviderName,
+                                   TRACE_LEVEL_INFORMATION,
+                                   0));
+
+    if (is_xp) {
+      base::TraceLog::Resurrect();
+      base::TraceLog* tracelog = base::TraceLog::Get();
+      ASSERT_TRUE(tracelog != NULL);
+    }
+  }
+
+  void TearDown() {
+    EtwTraceProperties prop;
+    if (controller_.session() != 0)
+      EXPECT_HRESULT_SUCCEEDED(controller_.Stop(&prop));
+
+    if (!log_file_.value().empty())
+      file_util::Delete(log_file_, false);
+  }
+
+  void ExpectEvent(REFGUID guid,
+                   EtwEventType type,
+                   const char* name,
+                   size_t name_len,
+                   const void* id,
+                   const char* extra,
+                   size_t extra_len) {
+    // Build the trace event buffer we expect will result from this.
+    std::stringbuf str;
+    str.sputn(name, name_len + 1);
+    str.sputn(reinterpret_cast<const char*>(&id), sizeof(id));
+    str.sputn(extra, extra_len + 1);
+
+    // And set up the expectation for the event callback.
+    EXPECT_CALL(consumer_, Event(guid,
+                                 type,
+                                 testing::Ge(str.str().length()),
+                                 BufferStartsWith(str.str())));
+  }
+
+  void ExpectPlayLog() {
+    // Ignore EventTraceGuid events.
+    EXPECT_CALL(consumer_, Event(kEventTraceGuid, _, _, _))
+        .Times(AnyNumber());
+  }
+
+  void PlayLog() {
+    EtwTraceProperties prop;
+    EXPECT_HRESULT_SUCCEEDED(controller_.Stop(&prop));
+    ASSERT_HRESULT_SUCCEEDED(
+        consumer_.OpenFileSession(log_file_.value().c_str()));
+
+    ASSERT_HRESULT_SUCCEEDED(consumer_.Consume());
+  }
+
+ private:
+  EtwTraceController controller_;
+  FilePath log_file_;
+  TestEventConsumer consumer_;
+};
+
+}  // namespace
+
+
+TEST_F(TraceEventTest, TraceLog) {
+  ExpectPlayLog();
+
+  // The events should arrive in the same sequence as the expects.
+  InSequence in_sequence;
+
+  // Full argument version, passing lengths explicitly.
+  base::TraceLog::Trace(kName,
+                        strlen(kName),
+                        base::TraceLog::EVENT_BEGIN,
+                        kId,
+                        kExtra,
+                        strlen(kExtra));
+
+  ExpectEvent(base::kTraceEventClass32,
+              base::kTraceEventTypeBegin,
+              kName, strlen(kName),
+              kId,
+              kExtra, strlen(kExtra));
+
+  // Const char* version.
+  base::TraceLog::Trace(static_cast<const char*>(kName),
+                        base::TraceLog::EVENT_END,
+                        kId,
+                        static_cast<const char*>(kExtra));
+
+  ExpectEvent(base::kTraceEventClass32,
+              base::kTraceEventTypeEnd,
+              kName, strlen(kName),
+              kId,
+              kExtra, strlen(kExtra));
+
+  // std::string extra version.
+  base::TraceLog::Trace(static_cast<const char*>(kName),
+                        base::TraceLog::EVENT_INSTANT,
+                        kId,
+                        std::string(kExtra));
+
+  ExpectEvent(base::kTraceEventClass32,
+              base::kTraceEventTypeInstant,
+              kName, strlen(kName),
+              kId,
+              kExtra, strlen(kExtra));
+
+
+  // Test for sanity on NULL inputs.
+  base::TraceLog::Trace(NULL,
+                        0,
+                        base::TraceLog::EVENT_BEGIN,
+                        kId,
+                        NULL,
+                        0);
+
+  ExpectEvent(base::kTraceEventClass32,
+              base::kTraceEventTypeBegin,
+              kEmpty, 0,
+              kId,
+              kEmpty, 0);
+
+  base::TraceLog::Trace(NULL,
+                        -1,
+                        base::TraceLog::EVENT_END,
+                        kId,
+                        NULL,
+                        -1);
+
+  ExpectEvent(base::kTraceEventClass32,
+              base::kTraceEventTypeEnd,
+              kEmpty, 0,
+              kId,
+              kEmpty, 0);
+
+  PlayLog();
+}
+
+TEST_F(TraceEventTest, Macros) {
+  ExpectPlayLog();
+
+  // The events should arrive in the same sequence as the expects.
+  InSequence in_sequence;
+
+  TRACE_EVENT_BEGIN(kName, kId, kExtra);
+  ExpectEvent(base::kTraceEventClass32,
+              base::kTraceEventTypeBegin,
+              kName, strlen(kName),
+              kId,
+              kExtra, strlen(kExtra));
+
+  TRACE_EVENT_END(kName, kId, kExtra);
+  ExpectEvent(base::kTraceEventClass32,
+              base::kTraceEventTypeEnd,
+              kName, strlen(kName),
+              kId,
+              kExtra, strlen(kExtra));
+
+  TRACE_EVENT_INSTANT(kName, kId, kExtra);
+  ExpectEvent(base::kTraceEventClass32,
+              base::kTraceEventTypeInstant,
+              kName, strlen(kName),
+              kId,
+              kExtra, strlen(kExtra));
+
+  PlayLog();
+}