1// Copyright (c) 2012 The Chromium Authors. All rights reserved.
2// Use of this source code is governed by a BSD-style license that can be
3// found in the LICENSE file.
4//
5// Unit tests for event trace consumer base class.
6#include "base/win/event_trace_consumer.h"
7
8#include <list>
9
10#include <objbase.h>
11
12#include "base/basictypes.h"
13#include "base/files/file_path.h"
14#include "base/files/file_util.h"
15#include "base/files/scoped_temp_dir.h"
16#include "base/logging.h"
17#include "base/process/process.h"
18#include "base/strings/stringprintf.h"
19#include "base/win/event_trace_controller.h"
20#include "base/win/event_trace_provider.h"
21#include "base/win/scoped_handle.h"
22#include "testing/gtest/include/gtest/gtest.h"
23
24#include <initguid.h>  // NOLINT - has to be last
25
26namespace base {
27namespace win {
28
29namespace {
30
31typedef std::list<EVENT_TRACE> EventQueue;
32
33class TestConsumer: public EtwTraceConsumerBase<TestConsumer> {
34 public:
35  TestConsumer() {
36    sank_event_.Set(::CreateEvent(NULL, TRUE, FALSE, NULL));
37    ClearQueue();
38  }
39
40  ~TestConsumer() {
41    ClearQueue();
42    sank_event_.Close();
43  }
44
45  void ClearQueue() {
46    for (EventQueue::const_iterator it(events_.begin()), end(events_.end());
47         it != end; ++it) {
48      delete[] reinterpret_cast<char*>(it->MofData);
49    }
50
51    events_.clear();
52  }
53
54  static void EnqueueEvent(EVENT_TRACE* event) {
55    events_.push_back(*event);
56    EVENT_TRACE& back = events_.back();
57
58    if (event->MofData != NULL && event->MofLength != 0) {
59      back.MofData = new char[event->MofLength];
60      memcpy(back.MofData, event->MofData, event->MofLength);
61    }
62  }
63
64  static void ProcessEvent(EVENT_TRACE* event) {
65    EnqueueEvent(event);
66    ::SetEvent(sank_event_.Get());
67  }
68
69  static ScopedHandle sank_event_;
70  static EventQueue events_;
71
72 private:
73  DISALLOW_COPY_AND_ASSIGN(TestConsumer);
74};
75
76ScopedHandle TestConsumer::sank_event_;
77EventQueue TestConsumer::events_;
78
79class EtwTraceConsumerBaseTest: public testing::Test {
80 public:
81  EtwTraceConsumerBaseTest()
82      : session_name_(StringPrintf(L"TestSession-%d",
83                                   Process::Current().pid())) {
84  }
85
86  virtual void SetUp() {
87    // Cleanup any potentially dangling sessions.
88    EtwTraceProperties ignore;
89    EtwTraceController::Stop(session_name_.c_str(), &ignore);
90
91    // Allocate a new GUID for each provider test.
92    ASSERT_HRESULT_SUCCEEDED(::CoCreateGuid(&test_provider_));
93  }
94
95  virtual void TearDown() {
96    // Cleanup any potentially dangling sessions.
97    EtwTraceProperties ignore;
98    EtwTraceController::Stop(session_name_.c_str(), &ignore);
99  }
100
101 protected:
102  GUID test_provider_;
103  std::wstring session_name_;
104};
105
106}  // namespace
107
108TEST_F(EtwTraceConsumerBaseTest, Initialize) {
109  TestConsumer consumer_;
110}
111
112TEST_F(EtwTraceConsumerBaseTest, OpenRealtimeSucceedsWhenNoSession) {
113  TestConsumer consumer_;
114  ASSERT_HRESULT_SUCCEEDED(
115      consumer_.OpenRealtimeSession(session_name_.c_str()));
116}
117
118TEST_F(EtwTraceConsumerBaseTest, ConsumerImmediateFailureWhenNoSession) {
119  TestConsumer consumer_;
120  ASSERT_HRESULT_SUCCEEDED(
121      consumer_.OpenRealtimeSession(session_name_.c_str()));
122  ASSERT_HRESULT_FAILED(consumer_.Consume());
123}
124
125namespace {
126
127class EtwTraceConsumerRealtimeTest: public EtwTraceConsumerBaseTest {
128 public:
129  virtual void SetUp() {
130    EtwTraceConsumerBaseTest::SetUp();
131    ASSERT_HRESULT_SUCCEEDED(
132        consumer_.OpenRealtimeSession(session_name_.c_str()));
133  }
134
135  virtual void TearDown() {
136    consumer_.Close();
137    EtwTraceConsumerBaseTest::TearDown();
138  }
139
140  DWORD ConsumerThread() {
141    ::SetEvent(consumer_ready_.Get());
142    return consumer_.Consume();
143  }
144
145  static DWORD WINAPI ConsumerThreadMainProc(void* arg) {
146    return reinterpret_cast<EtwTraceConsumerRealtimeTest*>(arg)->
147        ConsumerThread();
148  }
149
150  HRESULT StartConsumerThread() {
151    consumer_ready_.Set(::CreateEvent(NULL, TRUE, FALSE, NULL));
152    EXPECT_TRUE(consumer_ready_.IsValid());
153    consumer_thread_.Set(::CreateThread(NULL, 0, ConsumerThreadMainProc, this,
154                                        0, NULL));
155    if (consumer_thread_.Get() == NULL)
156      return HRESULT_FROM_WIN32(::GetLastError());
157
158    HANDLE events[] = { consumer_ready_.Get(), consumer_thread_.Get() };
159    DWORD result = ::WaitForMultipleObjects(arraysize(events), events,
160                                            FALSE, INFINITE);
161    switch (result) {
162      case WAIT_OBJECT_0:
163        // The event was set, the consumer_ is ready.
164        return S_OK;
165      case WAIT_OBJECT_0 + 1: {
166          // The thread finished. This may race with the event, so check
167          // explicitly for the event here, before concluding there's trouble.
168          if (::WaitForSingleObject(consumer_ready_.Get(), 0) == WAIT_OBJECT_0)
169            return S_OK;
170          DWORD exit_code = 0;
171          if (::GetExitCodeThread(consumer_thread_.Get(), &exit_code))
172            return exit_code;
173          return HRESULT_FROM_WIN32(::GetLastError());
174        }
175      default:
176        return E_UNEXPECTED;
177    }
178  }
179
180  // Waits for consumer_ thread to exit, and returns its exit code.
181  HRESULT JoinConsumerThread() {
182    if (::WaitForSingleObject(consumer_thread_.Get(), INFINITE) !=
183        WAIT_OBJECT_0) {
184      return HRESULT_FROM_WIN32(::GetLastError());
185    }
186
187    DWORD exit_code = 0;
188    if (::GetExitCodeThread(consumer_thread_.Get(), &exit_code))
189      return exit_code;
190
191    return HRESULT_FROM_WIN32(::GetLastError());
192  }
193
194  TestConsumer consumer_;
195  ScopedHandle consumer_ready_;
196  ScopedHandle consumer_thread_;
197};
198
199}  // namespace
200
201TEST_F(EtwTraceConsumerRealtimeTest, ConsumerReturnsWhenSessionClosed) {
202  EtwTraceController controller;
203  if (controller.StartRealtimeSession(session_name_.c_str(), 100 * 1024) ==
204      E_ACCESSDENIED) {
205    VLOG(1) << "You must be an administrator to run this test on Vista";
206    return;
207  }
208
209  // Start the consumer_.
210  ASSERT_HRESULT_SUCCEEDED(StartConsumerThread());
211
212  // Wait around for the consumer_ thread a bit.
213  ASSERT_EQ(WAIT_TIMEOUT, ::WaitForSingleObject(consumer_thread_.Get(), 50));
214  ASSERT_HRESULT_SUCCEEDED(controller.Stop(NULL));
215
216  // The consumer_ returns success on session stop.
217  ASSERT_HRESULT_SUCCEEDED(JoinConsumerThread());
218}
219
220namespace {
221
222// {57E47923-A549-476f-86CA-503D57F59E62}
223DEFINE_GUID(
224    kTestEventType,
225    0x57e47923, 0xa549, 0x476f, 0x86, 0xca, 0x50, 0x3d, 0x57, 0xf5, 0x9e, 0x62);
226
227}  // namespace
228
229TEST_F(EtwTraceConsumerRealtimeTest, ConsumeEvent) {
230  EtwTraceController controller;
231  if (controller.StartRealtimeSession(session_name_.c_str(), 100 * 1024) ==
232      E_ACCESSDENIED) {
233    VLOG(1) << "You must be an administrator to run this test on Vista";
234    return;
235  }
236
237  ASSERT_HRESULT_SUCCEEDED(controller.EnableProvider(
238      test_provider_, TRACE_LEVEL_VERBOSE, 0xFFFFFFFF));
239
240  EtwTraceProvider provider(test_provider_);
241  ASSERT_EQ(ERROR_SUCCESS, provider.Register());
242
243  // Start the consumer_.
244  ASSERT_HRESULT_SUCCEEDED(StartConsumerThread());
245  ASSERT_EQ(0, TestConsumer::events_.size());
246
247  EtwMofEvent<1> event(kTestEventType, 1, TRACE_LEVEL_ERROR);
248  EXPECT_EQ(ERROR_SUCCESS, provider.Log(&event.header));
249  EXPECT_EQ(WAIT_OBJECT_0,
250            ::WaitForSingleObject(TestConsumer::sank_event_.Get(), INFINITE));
251  ASSERT_HRESULT_SUCCEEDED(controller.Stop(NULL));
252  ASSERT_HRESULT_SUCCEEDED(JoinConsumerThread());
253  ASSERT_NE(0u, TestConsumer::events_.size());
254}
255
256namespace {
257
258// We run events through a file session to assert that
259// the content comes through.
260class EtwTraceConsumerDataTest: public EtwTraceConsumerBaseTest {
261 public:
262  EtwTraceConsumerDataTest() {
263  }
264
265  virtual void SetUp() {
266    EtwTraceConsumerBaseTest::SetUp();
267
268    EtwTraceProperties prop;
269    EtwTraceController::Stop(session_name_.c_str(), &prop);
270
271    // Create a temp dir for this test.
272    ASSERT_TRUE(temp_dir_.CreateUniqueTempDir());
273    // Construct a temp file name in our dir.
274    temp_file_ = temp_dir_.path().Append(L"test.etl");
275  }
276
277  virtual void TearDown() {
278    EXPECT_TRUE(base::DeleteFile(temp_file_, false));
279
280    EtwTraceConsumerBaseTest::TearDown();
281  }
282
283  HRESULT LogEventToTempSession(PEVENT_TRACE_HEADER header) {
284    EtwTraceController controller;
285
286    // Set up a file session.
287    HRESULT hr = controller.StartFileSession(session_name_.c_str(),
288                                             temp_file_.value().c_str());
289    if (FAILED(hr))
290      return hr;
291
292    // Enable our provider.
293    EXPECT_HRESULT_SUCCEEDED(controller.EnableProvider(
294        test_provider_, TRACE_LEVEL_VERBOSE, 0xFFFFFFFF));
295
296    EtwTraceProvider provider(test_provider_);
297    // Then register our provider, means we get a session handle immediately.
298    EXPECT_EQ(ERROR_SUCCESS, provider.Register());
299    // Trace the event, it goes to the temp file.
300    EXPECT_EQ(ERROR_SUCCESS, provider.Log(header));
301    EXPECT_HRESULT_SUCCEEDED(controller.DisableProvider(test_provider_));
302    EXPECT_HRESULT_SUCCEEDED(provider.Unregister());
303    EXPECT_HRESULT_SUCCEEDED(controller.Flush(NULL));
304    EXPECT_HRESULT_SUCCEEDED(controller.Stop(NULL));
305
306    return S_OK;
307  }
308
309  HRESULT ConsumeEventFromTempSession() {
310    // Now consume the event(s).
311    TestConsumer consumer_;
312    HRESULT hr = consumer_.OpenFileSession(temp_file_.value().c_str());
313    if (SUCCEEDED(hr))
314      hr = consumer_.Consume();
315    consumer_.Close();
316    // And nab the result.
317    events_.swap(TestConsumer::events_);
318    return hr;
319  }
320
321  HRESULT RoundTripEvent(PEVENT_TRACE_HEADER header, PEVENT_TRACE* trace) {
322    base::DeleteFile(temp_file_, false);
323
324    HRESULT hr = LogEventToTempSession(header);
325    if (SUCCEEDED(hr))
326      hr = ConsumeEventFromTempSession();
327
328    if (FAILED(hr))
329      return hr;
330
331    // We should now have the event in the queue.
332    if (events_.empty())
333      return E_FAIL;
334
335    *trace = &events_.back();
336    return S_OK;
337  }
338
339  EventQueue events_;
340  ScopedTempDir temp_dir_;
341  FilePath temp_file_;
342};
343
344}  // namespace
345
346
347TEST_F(EtwTraceConsumerDataTest, RoundTrip) {
348  EtwMofEvent<1> event(kTestEventType, 1, TRACE_LEVEL_ERROR);
349
350  static const char kData[] = "This is but test data";
351  event.fields[0].DataPtr = reinterpret_cast<ULONG64>(kData);
352  event.fields[0].Length = sizeof(kData);
353
354  PEVENT_TRACE trace = NULL;
355  HRESULT hr = RoundTripEvent(&event.header, &trace);
356  if (hr == E_ACCESSDENIED) {
357    VLOG(1) << "You must be an administrator to run this test on Vista";
358    return;
359  }
360  ASSERT_HRESULT_SUCCEEDED(hr) << "RoundTripEvent failed";
361  ASSERT_TRUE(trace != NULL);
362  ASSERT_EQ(sizeof(kData), trace->MofLength);
363  ASSERT_STREQ(kData, reinterpret_cast<const char*>(trace->MofData));
364}
365
366}  // namespace win
367}  // namespace base
368