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