event_trace_consumer_unittest.cc 11 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373
  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. #include <objbase.h>
  8. #include <iterator>
  9. #include <list>
  10. #include "base/files/file_path.h"
  11. #include "base/files/file_util.h"
  12. #include "base/files/scoped_temp_dir.h"
  13. #include "base/logging.h"
  14. #include "base/process/process_handle.h"
  15. #include "base/strings/string_util.h"
  16. #include "base/strings/stringprintf.h"
  17. #include "base/win/event_trace_controller.h"
  18. #include "base/win/event_trace_provider.h"
  19. #include "base/win/scoped_handle.h"
  20. #include "testing/gtest/include/gtest/gtest.h"
  21. #include <initguid.h> // NOLINT - has to be last
  22. namespace base {
  23. namespace win {
  24. namespace {
  25. using EventQueue = std::list<EVENT_TRACE>;
  26. class TestConsumer : public EtwTraceConsumerBase<TestConsumer> {
  27. public:
  28. TestConsumer() {
  29. sank_event_.Set(::CreateEvent(nullptr, TRUE, FALSE, nullptr));
  30. ClearQueue();
  31. }
  32. TestConsumer(const TestConsumer&) = delete;
  33. TestConsumer& operator=(const TestConsumer&) = delete;
  34. ~TestConsumer() {
  35. ClearQueue();
  36. sank_event_.Close();
  37. }
  38. void ClearQueue() {
  39. for (EventQueue::const_iterator it(events_.begin()), end(events_.end());
  40. it != end; ++it) {
  41. delete[] reinterpret_cast<char*>(it->MofData);
  42. }
  43. events_.clear();
  44. }
  45. static void EnqueueEvent(EVENT_TRACE* event) {
  46. events_.push_back(*event);
  47. EVENT_TRACE& back = events_.back();
  48. if (event->MofData != nullptr && event->MofLength != 0) {
  49. back.MofData = new char[event->MofLength];
  50. memcpy(back.MofData, event->MofData, event->MofLength);
  51. }
  52. }
  53. static void ProcessEvent(EVENT_TRACE* event) {
  54. EnqueueEvent(event);
  55. ::SetEvent(sank_event_.get());
  56. }
  57. static ScopedHandle sank_event_;
  58. static EventQueue events_;
  59. };
  60. ScopedHandle TestConsumer::sank_event_;
  61. EventQueue TestConsumer::events_;
  62. class EtwTraceConsumerBaseTest : public testing::Test {
  63. public:
  64. EtwTraceConsumerBaseTest()
  65. : session_name_(StringPrintf(L"TestSession-%d", GetCurrentProcId())) {}
  66. void SetUp() override {
  67. // Cleanup any potentially dangling sessions.
  68. EtwTraceProperties ignore;
  69. EtwTraceController::Stop(session_name_.c_str(), &ignore);
  70. // Allocate a new GUID for each provider test.
  71. ASSERT_HRESULT_SUCCEEDED(::CoCreateGuid(&test_provider_));
  72. }
  73. void TearDown() override {
  74. // Cleanup any potentially dangling sessions.
  75. EtwTraceProperties ignore;
  76. EtwTraceController::Stop(session_name_.c_str(), &ignore);
  77. }
  78. protected:
  79. GUID test_provider_;
  80. std::wstring session_name_;
  81. };
  82. } // namespace
  83. TEST_F(EtwTraceConsumerBaseTest, Initialize) {
  84. TestConsumer consumer_;
  85. }
  86. TEST_F(EtwTraceConsumerBaseTest, OpenRealtimeSucceedsWhenNoSession) {
  87. TestConsumer consumer_;
  88. ASSERT_HRESULT_SUCCEEDED(
  89. consumer_.OpenRealtimeSession(session_name_.c_str()));
  90. }
  91. TEST_F(EtwTraceConsumerBaseTest, ConsumerImmediateFailureWhenNoSession) {
  92. TestConsumer consumer_;
  93. ASSERT_HRESULT_SUCCEEDED(
  94. consumer_.OpenRealtimeSession(session_name_.c_str()));
  95. ASSERT_HRESULT_FAILED(consumer_.Consume());
  96. }
  97. namespace {
  98. class EtwTraceConsumerRealtimeTest : public EtwTraceConsumerBaseTest {
  99. public:
  100. void SetUp() override {
  101. EtwTraceConsumerBaseTest::SetUp();
  102. ASSERT_HRESULT_SUCCEEDED(
  103. consumer_.OpenRealtimeSession(session_name_.c_str()));
  104. }
  105. void TearDown() override {
  106. consumer_.Close();
  107. EtwTraceConsumerBaseTest::TearDown();
  108. }
  109. DWORD ConsumerThread() {
  110. ::SetEvent(consumer_ready_.get());
  111. return consumer_.Consume();
  112. }
  113. static DWORD WINAPI ConsumerThreadMainProc(void* arg) {
  114. return reinterpret_cast<EtwTraceConsumerRealtimeTest*>(arg)
  115. ->ConsumerThread();
  116. }
  117. HRESULT StartConsumerThread() {
  118. consumer_ready_.Set(::CreateEvent(nullptr, TRUE, FALSE, nullptr));
  119. EXPECT_TRUE(consumer_ready_.is_valid());
  120. consumer_thread_.Set(
  121. ::CreateThread(nullptr, 0, ConsumerThreadMainProc, this, 0, nullptr));
  122. if (consumer_thread_.get() == nullptr)
  123. return HRESULT_FROM_WIN32(::GetLastError());
  124. HANDLE events[] = {consumer_ready_.get(), consumer_thread_.get()};
  125. DWORD result =
  126. ::WaitForMultipleObjects(std::size(events), events, FALSE, INFINITE);
  127. switch (result) {
  128. case WAIT_OBJECT_0:
  129. // The event was set, the consumer_ is ready.
  130. return S_OK;
  131. case WAIT_OBJECT_0 + 1: {
  132. // The thread finished. This may race with the event, so check
  133. // explicitly for the event here, before concluding there's trouble.
  134. if (::WaitForSingleObject(consumer_ready_.get(), 0) == WAIT_OBJECT_0)
  135. return S_OK;
  136. DWORD exit_code = 0;
  137. if (::GetExitCodeThread(consumer_thread_.get(), &exit_code))
  138. return exit_code;
  139. return HRESULT_FROM_WIN32(::GetLastError());
  140. }
  141. default:
  142. return E_UNEXPECTED;
  143. }
  144. }
  145. // Waits for consumer_ thread to exit, and returns its exit code.
  146. HRESULT JoinConsumerThread() {
  147. if (::WaitForSingleObject(consumer_thread_.get(), INFINITE) !=
  148. WAIT_OBJECT_0) {
  149. return HRESULT_FROM_WIN32(::GetLastError());
  150. }
  151. DWORD exit_code = 0;
  152. if (::GetExitCodeThread(consumer_thread_.get(), &exit_code))
  153. return exit_code;
  154. return HRESULT_FROM_WIN32(::GetLastError());
  155. }
  156. TestConsumer consumer_;
  157. ScopedHandle consumer_ready_;
  158. ScopedHandle consumer_thread_;
  159. };
  160. } // namespace
  161. TEST_F(EtwTraceConsumerRealtimeTest, ConsumerReturnsWhenSessionClosed) {
  162. EtwTraceController controller;
  163. if (controller.StartRealtimeSession(session_name_.c_str(), 1024) ==
  164. E_ACCESSDENIED) {
  165. VLOG(1) << "You must be an administrator to run this test on Vista";
  166. return;
  167. }
  168. // Start the consumer_.
  169. ASSERT_HRESULT_SUCCEEDED(StartConsumerThread());
  170. // Wait around for the consumer_ thread a bit. This is inherently racy because
  171. // the consumer thread says that it is ready and then calls Consume() which
  172. // calls ::ProcessTrace. We need to call WaitForSingleObject after the call to
  173. // ::ProcessTrace but there is no way to know when that call has been made.
  174. // With a timeout of 50 ms this test was failing frequently when the system
  175. // was under load. It is hoped that 500 ms will be enough.
  176. ASSERT_EQ(static_cast<DWORD>(WAIT_TIMEOUT),
  177. ::WaitForSingleObject(consumer_thread_.get(), 500));
  178. ASSERT_HRESULT_SUCCEEDED(controller.Stop(nullptr));
  179. // The consumer_ returns success on session stop.
  180. ASSERT_HRESULT_SUCCEEDED(JoinConsumerThread());
  181. }
  182. namespace {
  183. // clang-format off
  184. // {57E47923-A549-476f-86CA-503D57F59E62}
  185. DEFINE_GUID(
  186. kTestEventType,
  187. 0x57e47923, 0xa549, 0x476f, 0x86, 0xca, 0x50, 0x3d, 0x57, 0xf5, 0x9e, 0x62);
  188. // clang-format on
  189. } // namespace
  190. TEST_F(EtwTraceConsumerRealtimeTest, ConsumeEvent) {
  191. EtwTraceController controller;
  192. if (controller.StartRealtimeSession(session_name_.c_str(), 1024) ==
  193. E_ACCESSDENIED) {
  194. VLOG(1) << "You must be an administrator to run this test on Vista";
  195. return;
  196. }
  197. ASSERT_HRESULT_SUCCEEDED(controller.EnableProvider(
  198. test_provider_, TRACE_LEVEL_VERBOSE, 0xFFFFFFFF));
  199. EtwTraceProvider provider(test_provider_);
  200. ASSERT_EQ(static_cast<DWORD>(ERROR_SUCCESS), provider.Register());
  201. // Start the consumer_.
  202. ASSERT_HRESULT_SUCCEEDED(StartConsumerThread());
  203. ASSERT_EQ(0u, TestConsumer::events_.size());
  204. EtwMofEvent<1> event(kTestEventType, 1, TRACE_LEVEL_ERROR);
  205. EXPECT_EQ(static_cast<DWORD>(ERROR_SUCCESS), provider.Log(&event.header));
  206. EXPECT_EQ(WAIT_OBJECT_0,
  207. ::WaitForSingleObject(TestConsumer::sank_event_.get(), INFINITE));
  208. ASSERT_HRESULT_SUCCEEDED(controller.Stop(nullptr));
  209. ASSERT_HRESULT_SUCCEEDED(JoinConsumerThread());
  210. ASSERT_NE(0u, TestConsumer::events_.size());
  211. }
  212. namespace {
  213. // We run events through a file session to assert that
  214. // the content comes through.
  215. class EtwTraceConsumerDataTest : public EtwTraceConsumerBaseTest {
  216. public:
  217. EtwTraceConsumerDataTest() = default;
  218. void SetUp() override {
  219. EtwTraceConsumerBaseTest::SetUp();
  220. EtwTraceProperties prop;
  221. EtwTraceController::Stop(session_name_.c_str(), &prop);
  222. // Create a temp dir for this test.
  223. ASSERT_TRUE(temp_dir_.CreateUniqueTempDir());
  224. // Construct a temp file name in our dir.
  225. temp_file_ = temp_dir_.GetPath().Append(FILE_PATH_LITERAL("test.etl"));
  226. }
  227. void TearDown() override {
  228. EXPECT_TRUE(DeleteFile(temp_file_));
  229. EtwTraceConsumerBaseTest::TearDown();
  230. }
  231. HRESULT LogEventToTempSession(PEVENT_TRACE_HEADER header) {
  232. EtwTraceController controller;
  233. // Set up a file session.
  234. HRESULT hr = controller.StartFileSession(session_name_.c_str(),
  235. temp_file_.value().c_str());
  236. if (FAILED(hr))
  237. return hr;
  238. // Enable our provider.
  239. EXPECT_HRESULT_SUCCEEDED(controller.EnableProvider(
  240. test_provider_, TRACE_LEVEL_VERBOSE, 0xFFFFFFFF));
  241. EtwTraceProvider provider(test_provider_);
  242. // Then register our provider, means we get a session handle immediately.
  243. EXPECT_EQ(static_cast<DWORD>(ERROR_SUCCESS), provider.Register());
  244. // Trace the event, it goes to the temp file.
  245. EXPECT_EQ(static_cast<DWORD>(ERROR_SUCCESS), provider.Log(header));
  246. EXPECT_HRESULT_SUCCEEDED(controller.DisableProvider(test_provider_));
  247. EXPECT_HRESULT_SUCCEEDED(provider.Unregister());
  248. EXPECT_HRESULT_SUCCEEDED(controller.Flush(nullptr));
  249. EXPECT_HRESULT_SUCCEEDED(controller.Stop(nullptr));
  250. return S_OK;
  251. }
  252. HRESULT ConsumeEventFromTempSession() {
  253. // Now consume the event(s).
  254. TestConsumer consumer_;
  255. HRESULT hr = consumer_.OpenFileSession(temp_file_.value().c_str());
  256. if (SUCCEEDED(hr))
  257. hr = consumer_.Consume();
  258. consumer_.Close();
  259. // And nab the result.
  260. events_.swap(TestConsumer::events_);
  261. return hr;
  262. }
  263. HRESULT RoundTripEvent(PEVENT_TRACE_HEADER header, PEVENT_TRACE* trace) {
  264. DeleteFile(temp_file_);
  265. HRESULT hr = LogEventToTempSession(header);
  266. if (SUCCEEDED(hr))
  267. hr = ConsumeEventFromTempSession();
  268. if (FAILED(hr))
  269. return hr;
  270. // We should now have the event in the queue.
  271. if (events_.empty())
  272. return E_FAIL;
  273. *trace = &events_.back();
  274. return S_OK;
  275. }
  276. EventQueue events_;
  277. ScopedTempDir temp_dir_;
  278. FilePath temp_file_;
  279. };
  280. } // namespace
  281. TEST_F(EtwTraceConsumerDataTest, RoundTrip) {
  282. EtwMofEvent<1> event(kTestEventType, 1, TRACE_LEVEL_ERROR);
  283. static const char kData[] = "This is but test data";
  284. event.fields[0].DataPtr = reinterpret_cast<ULONG64>(kData);
  285. event.fields[0].Length = sizeof(kData);
  286. PEVENT_TRACE trace = nullptr;
  287. HRESULT hr = RoundTripEvent(&event.header, &trace);
  288. if (hr == E_ACCESSDENIED) {
  289. VLOG(1) << "You must be an administrator to run this test on Vista";
  290. return;
  291. }
  292. ASSERT_HRESULT_SUCCEEDED(hr) << "RoundTripEvent failed";
  293. ASSERT_TRUE(trace != nullptr);
  294. ASSERT_EQ(sizeof(kData), trace->MofLength);
  295. ASSERT_STREQ(kData, reinterpret_cast<const char*>(trace->MofData));
  296. }
  297. } // namespace win
  298. } // namespace base