1 // Copyright 2012 The Chromium Authors
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
7 #include "base/win/event_trace_consumer.h"
8
9 #include <objbase.h>
10
11 #include <initguid.h>
12
13 #include <iterator>
14 #include <list>
15
16 #include "base/files/file_path.h"
17 #include "base/files/file_util.h"
18 #include "base/files/scoped_temp_dir.h"
19 #include "base/logging.h"
20 #include "base/process/process_handle.h"
21 #include "base/strings/string_number_conversions_win.h"
22 #include "base/strings/string_util.h"
23 #include "base/win/event_trace_controller.h"
24 #include "base/win/event_trace_provider.h"
25 #include "base/win/scoped_handle.h"
26 #include "testing/gtest/include/gtest/gtest.h"
27
28 namespace base {
29 namespace win {
30
31 namespace {
32
33 using EventQueue = std::list<EVENT_TRACE>;
34
35 class TestConsumer : public EtwTraceConsumerBase<TestConsumer> {
36 public:
TestConsumer()37 TestConsumer() {
38 sank_event_.Set(::CreateEvent(nullptr, TRUE, FALSE, nullptr));
39 ClearQueue();
40 }
41
42 TestConsumer(const TestConsumer&) = delete;
43 TestConsumer& operator=(const TestConsumer&) = delete;
44
~TestConsumer()45 ~TestConsumer() {
46 ClearQueue();
47 sank_event_.Close();
48 }
49
ClearQueue()50 void ClearQueue() {
51 for (EventQueue::const_iterator it(events_.begin()), end(events_.end());
52 it != end; ++it) {
53 delete[] reinterpret_cast<char*>(it->MofData);
54 }
55
56 events_.clear();
57 }
58
EnqueueEvent(EVENT_TRACE * event)59 static void EnqueueEvent(EVENT_TRACE* event) {
60 events_.push_back(*event);
61 EVENT_TRACE& back = events_.back();
62
63 if (event->MofData != nullptr && event->MofLength != 0) {
64 back.MofData = new char[event->MofLength];
65 memcpy(back.MofData, event->MofData, event->MofLength);
66 }
67 }
68
ProcessEvent(EVENT_TRACE * event)69 static void ProcessEvent(EVENT_TRACE* event) {
70 EnqueueEvent(event);
71 ::SetEvent(sank_event_.get());
72 }
73
74 static ScopedHandle sank_event_;
75 static EventQueue events_;
76 };
77
78 ScopedHandle TestConsumer::sank_event_;
79 EventQueue TestConsumer::events_;
80
81 class EtwTraceConsumerBaseTest : public testing::Test {
82 public:
EtwTraceConsumerBaseTest()83 EtwTraceConsumerBaseTest()
84 : session_name_(L"TestSession-" + NumberToWString(GetCurrentProcId())) {}
85
SetUp()86 void SetUp() override {
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
TearDown()95 void TearDown() override {
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
TEST_F(EtwTraceConsumerBaseTest,Initialize)108 TEST_F(EtwTraceConsumerBaseTest, Initialize) {
109 TestConsumer consumer_;
110 }
111
TEST_F(EtwTraceConsumerBaseTest,OpenRealtimeSucceedsWhenNoSession)112 TEST_F(EtwTraceConsumerBaseTest, OpenRealtimeSucceedsWhenNoSession) {
113 TestConsumer consumer_;
114 ASSERT_HRESULT_SUCCEEDED(
115 consumer_.OpenRealtimeSession(session_name_.c_str()));
116 }
117
TEST_F(EtwTraceConsumerBaseTest,ConsumerImmediateFailureWhenNoSession)118 TEST_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
125 namespace {
126
127 class EtwTraceConsumerRealtimeTest : public EtwTraceConsumerBaseTest {
128 public:
SetUp()129 void SetUp() override {
130 EtwTraceConsumerBaseTest::SetUp();
131 ASSERT_HRESULT_SUCCEEDED(
132 consumer_.OpenRealtimeSession(session_name_.c_str()));
133 }
134
TearDown()135 void TearDown() override {
136 consumer_.Close();
137 EtwTraceConsumerBaseTest::TearDown();
138 }
139
ConsumerThread()140 DWORD ConsumerThread() {
141 ::SetEvent(consumer_ready_.get());
142 return consumer_.Consume();
143 }
144
ConsumerThreadMainProc(void * arg)145 static DWORD WINAPI ConsumerThreadMainProc(void* arg) {
146 return reinterpret_cast<EtwTraceConsumerRealtimeTest*>(arg)
147 ->ConsumerThread();
148 }
149
StartConsumerThread()150 HRESULT StartConsumerThread() {
151 consumer_ready_.Set(::CreateEvent(nullptr, TRUE, FALSE, nullptr));
152 EXPECT_TRUE(consumer_ready_.is_valid());
153 consumer_thread_.Set(
154 ::CreateThread(nullptr, 0, ConsumerThreadMainProc, this, 0, nullptr));
155 if (consumer_thread_.get() == nullptr)
156 return HRESULT_FROM_WIN32(::GetLastError());
157
158 HANDLE events[] = {consumer_ready_.get(), consumer_thread_.get()};
159 DWORD result =
160 ::WaitForMultipleObjects(std::size(events), events, 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.
JoinConsumerThread()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
TEST_F(EtwTraceConsumerRealtimeTest,ConsumerReturnsWhenSessionClosed)201 TEST_F(EtwTraceConsumerRealtimeTest, ConsumerReturnsWhenSessionClosed) {
202 EtwTraceController controller;
203 if (controller.StartRealtimeSession(session_name_.c_str(), 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. This is inherently racy because
213 // the consumer thread says that it is ready and then calls Consume() which
214 // calls ::ProcessTrace. We need to call WaitForSingleObject after the call to
215 // ::ProcessTrace but there is no way to know when that call has been made.
216 // With a timeout of 50 ms this test was failing frequently when the system
217 // was under load. It is hoped that 500 ms will be enough.
218 ASSERT_EQ(static_cast<DWORD>(WAIT_TIMEOUT),
219 ::WaitForSingleObject(consumer_thread_.get(), 500));
220 ASSERT_HRESULT_SUCCEEDED(controller.Stop(nullptr));
221
222 // The consumer_ returns success on session stop.
223 ASSERT_HRESULT_SUCCEEDED(JoinConsumerThread());
224 }
225
226 namespace {
227
228 // clang-format off
229 // {57E47923-A549-476f-86CA-503D57F59E62}
230 DEFINE_GUID(
231 kTestEventType,
232 0x57e47923, 0xa549, 0x476f, 0x86, 0xca, 0x50, 0x3d, 0x57, 0xf5, 0x9e, 0x62);
233 // clang-format on
234
235 } // namespace
236
TEST_F(EtwTraceConsumerRealtimeTest,ConsumeEvent)237 TEST_F(EtwTraceConsumerRealtimeTest, ConsumeEvent) {
238 EtwTraceController controller;
239 if (controller.StartRealtimeSession(session_name_.c_str(), 1024) ==
240 E_ACCESSDENIED) {
241 VLOG(1) << "You must be an administrator to run this test on Vista";
242 return;
243 }
244
245 ASSERT_HRESULT_SUCCEEDED(controller.EnableProvider(
246 test_provider_, TRACE_LEVEL_VERBOSE, 0xFFFFFFFF));
247
248 EtwTraceProvider provider(test_provider_);
249 ASSERT_EQ(static_cast<DWORD>(ERROR_SUCCESS), provider.Register());
250
251 // Start the consumer_.
252 ASSERT_HRESULT_SUCCEEDED(StartConsumerThread());
253 ASSERT_EQ(0u, TestConsumer::events_.size());
254
255 EtwMofEvent<1> event(kTestEventType, 1, TRACE_LEVEL_ERROR);
256 EXPECT_EQ(static_cast<DWORD>(ERROR_SUCCESS), provider.Log(&event.header));
257 EXPECT_EQ(WAIT_OBJECT_0,
258 ::WaitForSingleObject(TestConsumer::sank_event_.get(), INFINITE));
259 ASSERT_HRESULT_SUCCEEDED(controller.Stop(nullptr));
260 ASSERT_HRESULT_SUCCEEDED(JoinConsumerThread());
261 ASSERT_NE(0u, TestConsumer::events_.size());
262 }
263
264 namespace {
265
266 // We run events through a file session to assert that
267 // the content comes through.
268 class EtwTraceConsumerDataTest : public EtwTraceConsumerBaseTest {
269 public:
270 EtwTraceConsumerDataTest() = default;
271
SetUp()272 void SetUp() override {
273 EtwTraceConsumerBaseTest::SetUp();
274
275 EtwTraceProperties prop;
276 EtwTraceController::Stop(session_name_.c_str(), &prop);
277
278 // Create a temp dir for this test.
279 ASSERT_TRUE(temp_dir_.CreateUniqueTempDir());
280 // Construct a temp file name in our dir.
281 temp_file_ = temp_dir_.GetPath().Append(FILE_PATH_LITERAL("test.etl"));
282 }
283
TearDown()284 void TearDown() override {
285 EXPECT_TRUE(DeleteFile(temp_file_));
286
287 EtwTraceConsumerBaseTest::TearDown();
288 }
289
LogEventToTempSession(PEVENT_TRACE_HEADER header)290 HRESULT LogEventToTempSession(PEVENT_TRACE_HEADER header) {
291 EtwTraceController controller;
292
293 // Set up a file session.
294 HRESULT hr = controller.StartFileSession(session_name_.c_str(),
295 temp_file_.value().c_str());
296 if (FAILED(hr))
297 return hr;
298
299 // Enable our provider.
300 EXPECT_HRESULT_SUCCEEDED(controller.EnableProvider(
301 test_provider_, TRACE_LEVEL_VERBOSE, 0xFFFFFFFF));
302
303 EtwTraceProvider provider(test_provider_);
304 // Then register our provider, means we get a session handle immediately.
305 EXPECT_EQ(static_cast<DWORD>(ERROR_SUCCESS), provider.Register());
306 // Trace the event, it goes to the temp file.
307 EXPECT_EQ(static_cast<DWORD>(ERROR_SUCCESS), provider.Log(header));
308 EXPECT_HRESULT_SUCCEEDED(controller.DisableProvider(test_provider_));
309 EXPECT_HRESULT_SUCCEEDED(provider.Unregister());
310 EXPECT_HRESULT_SUCCEEDED(controller.Flush(nullptr));
311 EXPECT_HRESULT_SUCCEEDED(controller.Stop(nullptr));
312
313 return S_OK;
314 }
315
ConsumeEventFromTempSession()316 HRESULT ConsumeEventFromTempSession() {
317 // Now consume the event(s).
318 TestConsumer consumer_;
319 HRESULT hr = consumer_.OpenFileSession(temp_file_.value().c_str());
320 if (SUCCEEDED(hr))
321 hr = consumer_.Consume();
322 consumer_.Close();
323 // And nab the result.
324 events_.swap(TestConsumer::events_);
325 return hr;
326 }
327
RoundTripEvent(PEVENT_TRACE_HEADER header,PEVENT_TRACE * trace)328 HRESULT RoundTripEvent(PEVENT_TRACE_HEADER header, PEVENT_TRACE* trace) {
329 DeleteFile(temp_file_);
330
331 HRESULT hr = LogEventToTempSession(header);
332 if (SUCCEEDED(hr))
333 hr = ConsumeEventFromTempSession();
334
335 if (FAILED(hr))
336 return hr;
337
338 // We should now have the event in the queue.
339 if (events_.empty())
340 return E_FAIL;
341
342 *trace = &events_.back();
343 return S_OK;
344 }
345
346 EventQueue events_;
347 ScopedTempDir temp_dir_;
348 FilePath temp_file_;
349 };
350
351 } // namespace
352
TEST_F(EtwTraceConsumerDataTest,RoundTrip)353 TEST_F(EtwTraceConsumerDataTest, RoundTrip) {
354 EtwMofEvent<1> event(kTestEventType, 1, TRACE_LEVEL_ERROR);
355
356 static const char kData[] = "This is but test data";
357 event.fields[0].DataPtr = reinterpret_cast<ULONG64>(kData);
358 event.fields[0].Length = sizeof(kData);
359
360 PEVENT_TRACE trace = nullptr;
361 HRESULT hr = RoundTripEvent(&event.header, &trace);
362 if (hr == E_ACCESSDENIED) {
363 VLOG(1) << "You must be an administrator to run this test on Vista";
364 return;
365 }
366 ASSERT_HRESULT_SUCCEEDED(hr) << "RoundTripEvent failed";
367 ASSERT_TRUE(trace != nullptr);
368 ASSERT_EQ(sizeof(kData), trace->MofLength);
369 ASSERT_STREQ(kData, reinterpret_cast<const char*>(trace->MofData));
370 }
371
372 } // namespace win
373 } // namespace base
374