| 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 |