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