OLD | NEW |
| (Empty) |
1 // Copyright (c) 2011 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 #include "base/debug/trace_event.h" | |
6 | |
7 #include <strstream> | |
8 | |
9 #include "base/at_exit.h" | |
10 #include "base/basictypes.h" | |
11 #include "base/debug/trace_event.h" | |
12 #include "base/debug/trace_event_win.h" | |
13 #include "base/files/file_util.h" | |
14 #include "base/win/event_trace_consumer.h" | |
15 #include "base/win/event_trace_controller.h" | |
16 #include "base/win/event_trace_provider.h" | |
17 #include "base/win/windows_version.h" | |
18 #include "testing/gmock/include/gmock/gmock.h" | |
19 #include "testing/gtest/include/gtest/gtest.h" | |
20 #include <initguid.h> // NOLINT - must be last include. | |
21 | |
22 namespace base { | |
23 namespace debug { | |
24 | |
25 namespace { | |
26 | |
27 using testing::_; | |
28 using testing::AnyNumber; | |
29 using testing::InSequence; | |
30 using testing::Ge; | |
31 using testing::Le; | |
32 using testing::NotNull; | |
33 | |
34 using base::win::EtwEventType; | |
35 using base::win::EtwTraceConsumerBase; | |
36 using base::win::EtwTraceController; | |
37 using base::win::EtwTraceProperties; | |
38 | |
39 // Data for unittests traces. | |
40 const char kEmpty[] = ""; | |
41 const char kName[] = "unittest.trace_name"; | |
42 const char kExtra[] = "UnittestDummyExtraString"; | |
43 const void* kId = kName; | |
44 | |
45 const wchar_t kTestSessionName[] = L"TraceEvent unittest session"; | |
46 | |
47 MATCHER_P(BufferStartsWith, str, "Buffer starts with") { | |
48 return memcmp(arg, str.c_str(), str.length()) == 0; | |
49 } | |
50 | |
51 // Duplicated from <evntrace.h> to fix link problems. | |
52 DEFINE_GUID( /* 68fdd900-4a3e-11d1-84f4-0000f80464e3 */ | |
53 kEventTraceGuid, | |
54 0x68fdd900, | |
55 0x4a3e, | |
56 0x11d1, | |
57 0x84, 0xf4, 0x00, 0x00, 0xf8, 0x04, 0x64, 0xe3); | |
58 | |
59 class TestEventConsumer: public EtwTraceConsumerBase<TestEventConsumer> { | |
60 public: | |
61 TestEventConsumer() { | |
62 EXPECT_TRUE(current_ == NULL); | |
63 current_ = this; | |
64 } | |
65 | |
66 ~TestEventConsumer() { | |
67 EXPECT_TRUE(current_ == this); | |
68 current_ = NULL; | |
69 } | |
70 | |
71 MOCK_METHOD4(Event, void(REFGUID event_class, | |
72 EtwEventType event_type, | |
73 size_t buf_len, | |
74 const void* buf)); | |
75 | |
76 static void ProcessEvent(EVENT_TRACE* event) { | |
77 ASSERT_TRUE(current_ != NULL); | |
78 current_->Event(event->Header.Guid, | |
79 event->Header.Class.Type, | |
80 event->MofLength, | |
81 event->MofData); | |
82 } | |
83 | |
84 private: | |
85 static TestEventConsumer* current_; | |
86 }; | |
87 | |
88 TestEventConsumer* TestEventConsumer::current_ = NULL; | |
89 | |
90 class TraceEventWinTest: public testing::Test { | |
91 public: | |
92 TraceEventWinTest() { | |
93 } | |
94 | |
95 void SetUp() { | |
96 bool is_xp = win::GetVersion() < base::win::VERSION_VISTA; | |
97 | |
98 if (is_xp) { | |
99 // Tear down any dangling session from an earlier failing test. | |
100 EtwTraceProperties ignore; | |
101 EtwTraceController::Stop(kTestSessionName, &ignore); | |
102 } | |
103 | |
104 // Resurrect and initialize the TraceLog singleton instance. | |
105 // On Vista and better, we need the provider registered before we | |
106 // start the private, in-proc session, but on XP we need the global | |
107 // session created and the provider enabled before we register our | |
108 // provider. | |
109 TraceEventETWProvider* tracelog = NULL; | |
110 if (!is_xp) { | |
111 TraceEventETWProvider::Resurrect(); | |
112 tracelog = TraceEventETWProvider::GetInstance(); | |
113 ASSERT_TRUE(tracelog != NULL); | |
114 ASSERT_FALSE(tracelog->IsTracing()); | |
115 } | |
116 | |
117 // Create the log file. | |
118 ASSERT_TRUE(base::CreateTemporaryFile(&log_file_)); | |
119 | |
120 // Create a private log session on the file. | |
121 EtwTraceProperties prop; | |
122 ASSERT_HRESULT_SUCCEEDED(prop.SetLoggerFileName(log_file_.value().c_str())); | |
123 EVENT_TRACE_PROPERTIES& p = *prop.get(); | |
124 p.Wnode.ClientContext = 1; // QPC timer accuracy. | |
125 p.LogFileMode = EVENT_TRACE_FILE_MODE_SEQUENTIAL; // Sequential log. | |
126 | |
127 // On Vista and later, we create a private in-process log session, because | |
128 // otherwise we'd need administrator privileges. Unfortunately we can't | |
129 // do the same on XP and better, because the semantics of a private | |
130 // logger session are different, and the IN_PROC flag is not supported. | |
131 if (!is_xp) { | |
132 p.LogFileMode |= EVENT_TRACE_PRIVATE_IN_PROC | // In-proc for non-admin. | |
133 EVENT_TRACE_PRIVATE_LOGGER_MODE; // Process-private log. | |
134 } | |
135 | |
136 p.MaximumFileSize = 100; // 100M file size. | |
137 p.FlushTimer = 1; // 1 second flush lag. | |
138 ASSERT_HRESULT_SUCCEEDED(controller_.Start(kTestSessionName, &prop)); | |
139 | |
140 // Enable the TraceLog provider GUID. | |
141 ASSERT_HRESULT_SUCCEEDED( | |
142 controller_.EnableProvider(kChromeTraceProviderName, | |
143 TRACE_LEVEL_INFORMATION, | |
144 0)); | |
145 | |
146 if (is_xp) { | |
147 TraceEventETWProvider::Resurrect(); | |
148 tracelog = TraceEventETWProvider::GetInstance(); | |
149 } | |
150 ASSERT_TRUE(tracelog != NULL); | |
151 EXPECT_TRUE(tracelog->IsTracing()); | |
152 } | |
153 | |
154 void TearDown() { | |
155 EtwTraceProperties prop; | |
156 if (controller_.session() != 0) | |
157 EXPECT_HRESULT_SUCCEEDED(controller_.Stop(&prop)); | |
158 | |
159 if (!log_file_.value().empty()) | |
160 base::DeleteFile(log_file_, false); | |
161 | |
162 // We want our singleton torn down after each test. | |
163 TraceLog::DeleteForTesting(); | |
164 } | |
165 | |
166 void ExpectEvent(REFGUID guid, | |
167 EtwEventType type, | |
168 const char* name, | |
169 size_t name_len, | |
170 const void* id, | |
171 const char* extra, | |
172 size_t extra_len) { | |
173 // Build the trace event buffer we expect will result from this. | |
174 std::stringbuf str; | |
175 str.sputn(name, name_len + 1); | |
176 str.sputn(reinterpret_cast<const char*>(&id), sizeof(id)); | |
177 str.sputn(extra, extra_len + 1); | |
178 | |
179 // And set up the expectation for the event callback. | |
180 EXPECT_CALL(consumer_, Event(guid, | |
181 type, | |
182 testing::Ge(str.str().length()), | |
183 BufferStartsWith(str.str()))); | |
184 } | |
185 | |
186 void ExpectPlayLog() { | |
187 // Ignore EventTraceGuid events. | |
188 EXPECT_CALL(consumer_, Event(kEventTraceGuid, _, _, _)) | |
189 .Times(AnyNumber()); | |
190 } | |
191 | |
192 void PlayLog() { | |
193 EtwTraceProperties prop; | |
194 EXPECT_HRESULT_SUCCEEDED(controller_.Flush(&prop)); | |
195 EXPECT_HRESULT_SUCCEEDED(controller_.Stop(&prop)); | |
196 ASSERT_HRESULT_SUCCEEDED( | |
197 consumer_.OpenFileSession(log_file_.value().c_str())); | |
198 | |
199 ASSERT_HRESULT_SUCCEEDED(consumer_.Consume()); | |
200 } | |
201 | |
202 private: | |
203 // We want our singleton torn down after each test. | |
204 ShadowingAtExitManager at_exit_manager_; | |
205 EtwTraceController controller_; | |
206 FilePath log_file_; | |
207 TestEventConsumer consumer_; | |
208 }; | |
209 | |
210 } // namespace | |
211 | |
212 | |
213 TEST_F(TraceEventWinTest, TraceLog) { | |
214 ExpectPlayLog(); | |
215 | |
216 // The events should arrive in the same sequence as the expects. | |
217 InSequence in_sequence; | |
218 | |
219 // Full argument version, passing lengths explicitly. | |
220 TraceEventETWProvider::Trace(kName, | |
221 strlen(kName), | |
222 TRACE_EVENT_PHASE_BEGIN, | |
223 kId, | |
224 kExtra, | |
225 strlen(kExtra)); | |
226 | |
227 ExpectEvent(kTraceEventClass32, | |
228 kTraceEventTypeBegin, | |
229 kName, strlen(kName), | |
230 kId, | |
231 kExtra, strlen(kExtra)); | |
232 | |
233 // Const char* version. | |
234 TraceEventETWProvider::Trace(static_cast<const char*>(kName), | |
235 TRACE_EVENT_PHASE_END, | |
236 kId, | |
237 static_cast<const char*>(kExtra)); | |
238 | |
239 ExpectEvent(kTraceEventClass32, | |
240 kTraceEventTypeEnd, | |
241 kName, strlen(kName), | |
242 kId, | |
243 kExtra, strlen(kExtra)); | |
244 | |
245 // std::string extra version. | |
246 TraceEventETWProvider::Trace(static_cast<const char*>(kName), | |
247 TRACE_EVENT_PHASE_INSTANT, | |
248 kId, | |
249 std::string(kExtra)); | |
250 | |
251 ExpectEvent(kTraceEventClass32, | |
252 kTraceEventTypeInstant, | |
253 kName, strlen(kName), | |
254 kId, | |
255 kExtra, strlen(kExtra)); | |
256 | |
257 | |
258 // Test for sanity on NULL inputs. | |
259 TraceEventETWProvider::Trace(NULL, | |
260 0, | |
261 TRACE_EVENT_PHASE_BEGIN, | |
262 kId, | |
263 NULL, | |
264 0); | |
265 | |
266 ExpectEvent(kTraceEventClass32, | |
267 kTraceEventTypeBegin, | |
268 kEmpty, 0, | |
269 kId, | |
270 kEmpty, 0); | |
271 | |
272 TraceEventETWProvider::Trace(NULL, | |
273 TraceEventETWProvider::kUseStrlen, | |
274 TRACE_EVENT_PHASE_END, | |
275 kId, | |
276 NULL, | |
277 TraceEventETWProvider::kUseStrlen); | |
278 | |
279 ExpectEvent(kTraceEventClass32, | |
280 kTraceEventTypeEnd, | |
281 kEmpty, 0, | |
282 kId, | |
283 kEmpty, 0); | |
284 | |
285 PlayLog(); | |
286 } | |
287 | |
288 TEST_F(TraceEventWinTest, Macros) { | |
289 ExpectPlayLog(); | |
290 | |
291 // The events should arrive in the same sequence as the expects. | |
292 InSequence in_sequence; | |
293 | |
294 TRACE_EVENT_BEGIN_ETW(kName, kId, kExtra); | |
295 ExpectEvent(kTraceEventClass32, | |
296 kTraceEventTypeBegin, | |
297 kName, strlen(kName), | |
298 kId, | |
299 kExtra, strlen(kExtra)); | |
300 | |
301 TRACE_EVENT_END_ETW(kName, kId, kExtra); | |
302 ExpectEvent(kTraceEventClass32, | |
303 kTraceEventTypeEnd, | |
304 kName, strlen(kName), | |
305 kId, | |
306 kExtra, strlen(kExtra)); | |
307 | |
308 TRACE_EVENT_INSTANT_ETW(kName, kId, kExtra); | |
309 ExpectEvent(kTraceEventClass32, | |
310 kTraceEventTypeInstant, | |
311 kName, strlen(kName), | |
312 kId, | |
313 kExtra, strlen(kExtra)); | |
314 | |
315 PlayLog(); | |
316 } | |
317 | |
318 } // namespace debug | |
319 } // namespace base | |
OLD | NEW |