| OLD | NEW |
|---|
| (Empty) |
| 1 // Copyright 2010 Google Inc. | |
| 2 // | |
| 3 // Licensed under the Apache License, Version 2.0 (the "License"); | |
| 4 // you may not use this file except in compliance with the License. | |
| 5 // You may obtain a copy of the License at | |
| 6 // | |
| 7 // http://www.apache.org/licenses/LICENSE-2.0 | |
| 8 // | |
| 9 // Unless required by applicable law or agreed to in writing, software | |
| 10 // distributed under the License is distributed on an "AS IS" BASIS, | |
| 11 // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. | |
| 12 // See the License for the specific language governing permissions and | |
| 13 // limitations under the License. | |
| 14 // ======================================================================== | |
| 15 // | |
| 16 // ETW log writer unittests. | |
| 17 | |
| 18 #include <atlbase.h> | |
| 19 #include <atlstr.h> | |
| 20 #include <atlsync.h> | |
| 21 #include "omaha/base/app_util.h" | |
| 22 #include "omaha/base/etw_log_writer.h" | |
| 23 #include "omaha/base/event_trace_consumer.h" | |
| 24 #include "omaha/base/event_trace_controller.h" | |
| 25 #include "omaha/testing/unit_test.h" | |
| 26 | |
| 27 | |
| 28 namespace { | |
| 29 | |
| 30 using omaha::EtwEventType; | |
| 31 using omaha::EtwLogWriter; | |
| 32 using omaha::EtwTraceConsumerBase; | |
| 33 using testing::StrEq; | |
| 34 | |
| 35 class TestConsumer : public EtwTraceConsumerBase<TestConsumer> { | |
| 36 public: | |
| 37 TestConsumer() { | |
| 38 EXPECT_EQ(NULL, s_current_); | |
| 39 s_current_ = this; | |
| 40 } | |
| 41 | |
| 42 ~TestConsumer() { | |
| 43 EXPECT_TRUE(this == s_current_); | |
| 44 s_current_ = NULL; | |
| 45 } | |
| 46 | |
| 47 MOCK_METHOD1(OnLogMessage, void(const char* msg)); | |
| 48 | |
| 49 void ProcessLogEvent(EtwEventType type, const void* data, size_t data_len) { | |
| 50 data_len; // Unused | |
| 51 if (type == EtwLogWriter::kLogMessageType) { | |
| 52 OnLogMessage(reinterpret_cast<const char*>(data)); | |
| 53 } else if (type == EtwLogWriter::kLogMessageWithStackTraceType) { | |
| 54 const DWORD* depth = reinterpret_cast<const DWORD*>(data); | |
| 55 void* const* stack_trace = reinterpret_cast<void* const*>(depth + 1); | |
| 56 OnLogMessage(reinterpret_cast<const char*>(stack_trace + *depth)); | |
| 57 } else { | |
| 58 FAIL() << "Unexpected message type " << type; | |
| 59 } | |
| 60 } | |
| 61 | |
| 62 static void ProcessEvent(EVENT_TRACE* event) { | |
| 63 if (event->Header.Guid == EtwLogWriter::kLogEventId) { | |
| 64 s_current_->ProcessLogEvent(event->Header.Class.Type, | |
| 65 event->MofData, | |
| 66 event->MofLength); | |
| 67 } | |
| 68 } | |
| 69 | |
| 70 private: | |
| 71 static TestConsumer* s_current_; | |
| 72 }; | |
| 73 | |
| 74 TestConsumer* TestConsumer::s_current_ = NULL; | |
| 75 | |
| 76 const wchar_t kTestSessionName[] = L"EtwLogWriterTest Session"; | |
| 77 // {AD914B7A-0C5F-426e-895C-58B125408125} | |
| 78 const GUID kTestProviderGuid = { 0xad914b7a, 0xc5f, 0x426e, | |
| 79 { 0x89, 0x5c, 0x58, 0xb1, 0x25, 0x40, 0x81, 0x25 } }; | |
| 80 | |
| 81 // Subclass to allow using a distinct provider GUID and overriding | |
| 82 // event handlers. | |
| 83 class TestingLogWriter: public EtwLogWriter { | |
| 84 public: | |
| 85 TestingLogWriter() : EtwLogWriter(kTestProviderGuid) { | |
| 86 EXPECT_TRUE(events_enabled_.Create(NULL, TRUE, FALSE, NULL)); | |
| 87 EXPECT_TRUE(events_disabled_.Create(NULL, TRUE, FALSE, NULL)); | |
| 88 } | |
| 89 | |
| 90 void WaitUntilEnabled() { | |
| 91 // Wait for a the callback to hit, then reset the event. | |
| 92 EXPECT_EQ(WAIT_OBJECT_0, | |
| 93 ::WaitForSingleObject(events_enabled_, INFINITE)); | |
| 94 EXPECT_TRUE(::ResetEvent(events_enabled_)); | |
| 95 } | |
| 96 | |
| 97 void WaitUntilDisabled() { | |
| 98 // Wait for a the callback to hit, then reset the event. | |
| 99 EXPECT_EQ(WAIT_OBJECT_0, | |
| 100 ::WaitForSingleObject(events_disabled_, INFINITE)); | |
| 101 EXPECT_TRUE(::ResetEvent(events_disabled_)); | |
| 102 } | |
| 103 | |
| 104 ~TestingLogWriter() { | |
| 105 // We explicitly call Cleanup() here so that the ETW provider will | |
| 106 // be torn down before the CEvent destructors are called. We had | |
| 107 // issues with the test failing spuriously because the provider | |
| 108 // teardown is done on a separate thread, and would attempt to call | |
| 109 // OnEventsDisabled() after the event handles had been released. | |
| 110 // (http://b/2873205) | |
| 111 | |
| 112 Cleanup(); | |
| 113 } | |
| 114 | |
| 115 protected: | |
| 116 // Override from EtwTraceProvider. | |
| 117 virtual void OnEventsEnabled() { | |
| 118 EtwLogWriter::OnEventsEnabled(); | |
| 119 events_enabled_.Set(); | |
| 120 } | |
| 121 | |
| 122 virtual void OnEventsDisabled() { | |
| 123 EtwLogWriter::OnEventsDisabled(); | |
| 124 events_disabled_.Set(); | |
| 125 } | |
| 126 | |
| 127 CEvent events_enabled_; | |
| 128 CEvent events_disabled_; | |
| 129 }; | |
| 130 | |
| 131 } // namespace | |
| 132 | |
| 133 namespace omaha { | |
| 134 | |
| 135 class EtwLogWriterTest: public testing::Test { | |
| 136 public: | |
| 137 EtwLogWriterTest() : counter_(0) { | |
| 138 } | |
| 139 | |
| 140 virtual void SetUp() { | |
| 141 // Kill any dangling trace session. | |
| 142 EtwTraceProperties prop; | |
| 143 EtwTraceController::Stop(kTestSessionName, &prop); | |
| 144 | |
| 145 // And create a session on a new temp file. | |
| 146 EXPECT_TRUE(::GetTempFileName(app_util::GetTempDir(), _T("tmp"), 0, | |
| 147 CStrBuf(temp_file_, MAX_PATH))); | |
| 148 | |
| 149 EXPECT_HRESULT_SUCCEEDED( | |
| 150 controller_.StartFileSession(kTestSessionName, temp_file_, false)); | |
| 151 } | |
| 152 | |
| 153 virtual void TearDown() { | |
| 154 if (controller_.session() != NULL) { | |
| 155 EXPECT_HRESULT_SUCCEEDED(controller_.Stop(NULL)); | |
| 156 EXPECT_TRUE(::DeleteFile(temp_file_)); | |
| 157 } | |
| 158 } | |
| 159 | |
| 160 // Asserts that enabling ETW logging at trace_level causes | |
| 161 // logging at log_level to be enabled. | |
| 162 void ExpectLogLevelEnabled(EtwEventLevel trace_level, LogLevel log_level) { | |
| 163 TestingLogWriter writer; | |
| 164 EXPECT_HRESULT_SUCCEEDED( | |
| 165 controller_.EnableProvider(kTestProviderGuid, | |
| 166 trace_level, | |
| 167 0xFFFFFFFF)) << | |
| 168 _T("[trace level: ") << static_cast<uint16>(trace_level) << | |
| 169 _T("][log level: ") << log_level << _T("]"); | |
| 170 writer.WaitUntilEnabled(); | |
| 171 EXPECT_EQ(true, writer.IsCatLevelEnabled(LC_LOGGING, log_level)); | |
| 172 } | |
| 173 | |
| 174 // Asserts that enabling ETW logging at trace_level causes | |
| 175 // logging at log_level to be disabled. | |
| 176 void ExpectLogLevelDisabled(EtwEventLevel trace_level, LogLevel log_level) { | |
| 177 TestingLogWriter writer; | |
| 178 EXPECT_HRESULT_SUCCEEDED( | |
| 179 controller_.EnableProvider(kTestProviderGuid, | |
| 180 trace_level, | |
| 181 0xFFFFFFFF)) << | |
| 182 _T("[trace level: ") << static_cast<uint16>(trace_level) << | |
| 183 _T("][log level: ") << log_level << _T("]"); | |
| 184 writer.WaitUntilEnabled(); | |
| 185 EXPECT_EQ(false, writer.IsCatLevelEnabled(LC_LOGGING, log_level)); | |
| 186 } | |
| 187 | |
| 188 void ExpectLogMessage(EtwEventLevel trace_level, | |
| 189 EtwEventFlags enable_bits, | |
| 190 LogLevel log_level, | |
| 191 LogCategory log_cat, | |
| 192 bool should_log) { | |
| 193 TestingLogWriter writer; | |
| 194 EXPECT_HRESULT_SUCCEEDED( | |
| 195 controller_.EnableProvider(kTestProviderGuid, | |
| 196 trace_level, | |
| 197 enable_bits)) << | |
| 198 _T("[trace level: ") << static_cast<uint16>(trace_level) << | |
| 199 _T("][flags: 0x") << std::hex << enable_bits << std::dec << | |
| 200 _T("][log level: ") << log_level << | |
| 201 _T("][category: ") << log_cat << | |
| 202 _T("][should_log: ") << should_log << _T("]"); | |
| 203 writer.WaitUntilEnabled(); | |
| 204 | |
| 205 CString message; | |
| 206 message.Format(L"[%d][%d][0x%08X][%d][%d]", | |
| 207 ++counter_, // Make each expectation call unique. | |
| 208 trace_level, | |
| 209 enable_bits, | |
| 210 log_level, | |
| 211 log_cat); | |
| 212 OutputInfo info(log_cat, log_level, L"[Prefix]", message); | |
| 213 writer.OutputMessage(&info); | |
| 214 | |
| 215 CStringA expected_msg("[Prefix]"); | |
| 216 expected_msg += message; | |
| 217 // Set up an expectation for zero or one calls with this string, | |
| 218 // depending whether should_log or not. | |
| 219 EXPECT_CALL(consumer_, OnLogMessage(StrEq(expected_msg.GetString()))) | |
| 220 .Times(should_log ? 1 : 0); | |
| 221 } | |
| 222 | |
| 223 void ConsumeAndRestartLog() { | |
| 224 EXPECT_HRESULT_SUCCEEDED(controller_.Stop(NULL)); | |
| 225 | |
| 226 EXPECT_HRESULT_SUCCEEDED(consumer_.OpenFileSession(temp_file_)); | |
| 227 EXPECT_HRESULT_SUCCEEDED(consumer_.Consume()); | |
| 228 EXPECT_HRESULT_SUCCEEDED(consumer_.Close()); | |
| 229 | |
| 230 EXPECT_TRUE(::DeleteFile(temp_file_)); | |
| 231 | |
| 232 // Restart the log collection. | |
| 233 EXPECT_HRESULT_SUCCEEDED( | |
| 234 controller_.StartFileSession(kTestSessionName, temp_file_, false)); | |
| 235 } | |
| 236 | |
| 237 protected: | |
| 238 EtwTraceController controller_; | |
| 239 TestConsumer consumer_; | |
| 240 CString temp_file_; | |
| 241 int counter_; | |
| 242 }; | |
| 243 | |
| 244 TEST_F(EtwLogWriterTest, ProviderNotEnabled) { | |
| 245 // Verify that everything is turned off when the provider is not enabled. | |
| 246 TestingLogWriter writer; | |
| 247 | |
| 248 EXPECT_FALSE(writer.WantsToLogRegardless()); | |
| 249 for (int cat = LC_LOGGING; cat < LC_MAX_CAT; ++cat) { | |
| 250 for (int level = LEVEL_FATALERROR; level < LEVEL_ALL; ++level) { | |
| 251 EXPECT_EQ(false, writer.IsCatLevelEnabled(static_cast<LogCategory>(cat), | |
| 252 static_cast<LogLevel>(level))); | |
| 253 } | |
| 254 } | |
| 255 } | |
| 256 | |
| 257 TEST_F(EtwLogWriterTest, ProviderEnableFlags) { | |
| 258 // Test that various provider enable flags have the expected effect on | |
| 259 // IsCatLevelEnabled. | |
| 260 for (int cat = LC_LOGGING; cat < LC_MAX_CAT; ++cat) { | |
| 261 EtwEventFlags flags = 1 << (cat + 1); | |
| 262 | |
| 263 TestingLogWriter writer; | |
| 264 EXPECT_HRESULT_SUCCEEDED( | |
| 265 controller_.EnableProvider(kTestProviderGuid, | |
| 266 TRACE_LEVEL_INFORMATION, | |
| 267 flags)) << | |
| 268 _T("cat[") << cat << _T("]: 0x") << std::hex << flags; | |
| 269 writer.WaitUntilEnabled(); | |
| 270 | |
| 271 for (int probe = LC_LOGGING; probe < LC_MAX_CAT; ++probe) { | |
| 272 bool category_enabled = probe == cat; | |
| 273 EXPECT_EQ(category_enabled, | |
| 274 writer.IsCatLevelEnabled(static_cast<LogCategory>(probe), | |
| 275 LEVEL_ERROR)); | |
| 276 } | |
| 277 } | |
| 278 } | |
| 279 | |
| 280 // On Windows XP, it appears that 32 enable/disable trace level operations | |
| 281 // saturates some sort of a buffer, which causes the subsequent enable/disable | |
| 282 // operations to fail. To work around this, the following tests are chopped up | |
| 283 // into unnaturally small pieces. | |
| 284 TEST_F(EtwLogWriterTest, ProviderLevel) { | |
| 285 // Test that various trace levels have the expected effect on | |
| 286 // IsCatLevelEnabled. | |
| 287 | |
| 288 // TRACE_LEVEL_NONE | |
| 289 ExpectLogLevelDisabled(TRACE_LEVEL_NONE, LEVEL_FATALERROR); | |
| 290 ExpectLogLevelDisabled(TRACE_LEVEL_NONE, LEVEL_ERROR); | |
| 291 ExpectLogLevelDisabled(TRACE_LEVEL_NONE, LE); | |
| 292 ExpectLogLevelDisabled(TRACE_LEVEL_NONE, LEVEL_WARNING); | |
| 293 ExpectLogLevelDisabled(TRACE_LEVEL_NONE, LW); | |
| 294 ExpectLogLevelDisabled(TRACE_LEVEL_NONE, L1); | |
| 295 ExpectLogLevelDisabled(TRACE_LEVEL_NONE, L2); | |
| 296 ExpectLogLevelDisabled(TRACE_LEVEL_NONE, L3); | |
| 297 ExpectLogLevelDisabled(TRACE_LEVEL_NONE, L4); | |
| 298 ExpectLogLevelDisabled(TRACE_LEVEL_NONE, L5); | |
| 299 ExpectLogLevelDisabled(TRACE_LEVEL_NONE, L6); | |
| 300 ConsumeAndRestartLog(); | |
| 301 | |
| 302 if (!ShouldRunLargeTest()) { | |
| 303 // This test takes about 6 seconds, so only run part of it by default. | |
| 304 return; | |
| 305 } | |
| 306 | |
| 307 // TRACE_LEVEL_FATAL | |
| 308 ExpectLogLevelEnabled(TRACE_LEVEL_FATAL, LEVEL_FATALERROR); | |
| 309 ExpectLogLevelDisabled(TRACE_LEVEL_FATAL, LEVEL_ERROR); | |
| 310 ExpectLogLevelDisabled(TRACE_LEVEL_FATAL, LE); | |
| 311 ExpectLogLevelDisabled(TRACE_LEVEL_FATAL, LEVEL_WARNING); | |
| 312 ExpectLogLevelDisabled(TRACE_LEVEL_FATAL, LW); | |
| 313 ExpectLogLevelDisabled(TRACE_LEVEL_FATAL, L1); | |
| 314 ExpectLogLevelDisabled(TRACE_LEVEL_FATAL, L2); | |
| 315 ExpectLogLevelDisabled(TRACE_LEVEL_FATAL, L3); | |
| 316 ExpectLogLevelDisabled(TRACE_LEVEL_FATAL, L4); | |
| 317 ExpectLogLevelDisabled(TRACE_LEVEL_FATAL, L5); | |
| 318 ExpectLogLevelDisabled(TRACE_LEVEL_FATAL, L6); | |
| 319 ConsumeAndRestartLog(); | |
| 320 | |
| 321 // TRACE_LEVEL_ERROR | |
| 322 ExpectLogLevelEnabled(TRACE_LEVEL_ERROR, LEVEL_FATALERROR); | |
| 323 ExpectLogLevelEnabled(TRACE_LEVEL_ERROR, LEVEL_ERROR); | |
| 324 ExpectLogLevelEnabled(TRACE_LEVEL_ERROR, LE); | |
| 325 ExpectLogLevelDisabled(TRACE_LEVEL_ERROR, LEVEL_WARNING); | |
| 326 ExpectLogLevelDisabled(TRACE_LEVEL_ERROR, LW); | |
| 327 ExpectLogLevelDisabled(TRACE_LEVEL_ERROR, L1); | |
| 328 ExpectLogLevelDisabled(TRACE_LEVEL_ERROR, L2); | |
| 329 ExpectLogLevelDisabled(TRACE_LEVEL_ERROR, L3); | |
| 330 ExpectLogLevelDisabled(TRACE_LEVEL_ERROR, L4); | |
| 331 ExpectLogLevelDisabled(TRACE_LEVEL_ERROR, L5); | |
| 332 ExpectLogLevelDisabled(TRACE_LEVEL_ERROR, L6); | |
| 333 ConsumeAndRestartLog(); | |
| 334 | |
| 335 // TRACE_LEVEL_WARNING | |
| 336 ExpectLogLevelEnabled(TRACE_LEVEL_WARNING, LEVEL_FATALERROR); | |
| 337 ExpectLogLevelEnabled(TRACE_LEVEL_WARNING, LEVEL_ERROR); | |
| 338 ExpectLogLevelEnabled(TRACE_LEVEL_WARNING, LE); | |
| 339 ExpectLogLevelEnabled(TRACE_LEVEL_WARNING, LEVEL_WARNING); | |
| 340 ExpectLogLevelEnabled(TRACE_LEVEL_WARNING, LW); | |
| 341 ExpectLogLevelDisabled(TRACE_LEVEL_WARNING, L1); | |
| 342 ExpectLogLevelDisabled(TRACE_LEVEL_WARNING, L2); | |
| 343 ExpectLogLevelDisabled(TRACE_LEVEL_WARNING, L3); | |
| 344 ExpectLogLevelDisabled(TRACE_LEVEL_WARNING, L4); | |
| 345 ExpectLogLevelDisabled(TRACE_LEVEL_WARNING, L5); | |
| 346 ExpectLogLevelDisabled(TRACE_LEVEL_WARNING, L6); | |
| 347 ConsumeAndRestartLog(); | |
| 348 | |
| 349 // TRACE_LEVEL_INFORMATION | |
| 350 ExpectLogLevelEnabled(TRACE_LEVEL_INFORMATION, LEVEL_FATALERROR); | |
| 351 ExpectLogLevelEnabled(TRACE_LEVEL_INFORMATION, LEVEL_ERROR); | |
| 352 ExpectLogLevelEnabled(TRACE_LEVEL_INFORMATION, LE); | |
| 353 ExpectLogLevelEnabled(TRACE_LEVEL_INFORMATION, LEVEL_WARNING); | |
| 354 ExpectLogLevelEnabled(TRACE_LEVEL_INFORMATION, LW); | |
| 355 ExpectLogLevelEnabled(TRACE_LEVEL_INFORMATION, L1); | |
| 356 ExpectLogLevelEnabled(TRACE_LEVEL_INFORMATION, L2); | |
| 357 ExpectLogLevelDisabled(TRACE_LEVEL_INFORMATION, L3); | |
| 358 ExpectLogLevelDisabled(TRACE_LEVEL_INFORMATION, L4); | |
| 359 ExpectLogLevelDisabled(TRACE_LEVEL_INFORMATION, L5); | |
| 360 ExpectLogLevelDisabled(TRACE_LEVEL_INFORMATION, L6); | |
| 361 ConsumeAndRestartLog(); | |
| 362 | |
| 363 // TRACE_LEVEL_VERBOSE | |
| 364 ExpectLogLevelEnabled(TRACE_LEVEL_VERBOSE, LEVEL_FATALERROR); | |
| 365 ExpectLogLevelEnabled(TRACE_LEVEL_VERBOSE, LEVEL_ERROR); | |
| 366 ExpectLogLevelEnabled(TRACE_LEVEL_VERBOSE, LE); | |
| 367 ExpectLogLevelEnabled(TRACE_LEVEL_VERBOSE, LEVEL_WARNING); | |
| 368 ExpectLogLevelEnabled(TRACE_LEVEL_VERBOSE, LW); | |
| 369 ExpectLogLevelEnabled(TRACE_LEVEL_VERBOSE, L1); | |
| 370 ExpectLogLevelEnabled(TRACE_LEVEL_VERBOSE, L2); | |
| 371 ExpectLogLevelEnabled(TRACE_LEVEL_VERBOSE, L3); | |
| 372 ExpectLogLevelEnabled(TRACE_LEVEL_VERBOSE, L4); | |
| 373 ExpectLogLevelEnabled(TRACE_LEVEL_VERBOSE, L5); | |
| 374 ExpectLogLevelEnabled(TRACE_LEVEL_VERBOSE, L6); | |
| 375 } | |
| 376 | |
| 377 TEST_F(EtwLogWriterTest, UpdateProviderLevel) { | |
| 378 // Test that changing ETW trace levels and flags causes a pre-existing | |
| 379 // ETWLogProvider to update its log levels per IsCatLevelEnabled. | |
| 380 TestingLogWriter writer; | |
| 381 for (int cat = LC_LOGGING; cat < LC_MAX_CAT; ++cat) { | |
| 382 EXPECT_FALSE(writer.IsCatLevelEnabled(static_cast<LogCategory>(cat), | |
| 383 LEVEL_WARNING)); | |
| 384 } | |
| 385 | |
| 386 // Turn logging on. | |
| 387 EXPECT_HRESULT_SUCCEEDED( | |
| 388 controller_.EnableProvider(kTestProviderGuid, | |
| 389 TRACE_LEVEL_INFORMATION, | |
| 390 0xFFFFFFFF)); | |
| 391 | |
| 392 // Wait for the callback to hit, then assert that logging is now enabled. | |
| 393 writer.WaitUntilEnabled(); | |
| 394 for (int cat = LC_LOGGING; cat < LC_MAX_CAT; ++cat) { | |
| 395 EXPECT_TRUE(writer.IsCatLevelEnabled(static_cast<LogCategory>(cat), | |
| 396 LEVEL_WARNING)); | |
| 397 } | |
| 398 | |
| 399 // Turn down the enable mask, aka categories. | |
| 400 EXPECT_HRESULT_SUCCEEDED( | |
| 401 controller_.EnableProvider(kTestProviderGuid, | |
| 402 TRACE_LEVEL_INFORMATION, | |
| 403 0x0003)); // 3 is LC_LOGGING + stack traces. | |
| 404 | |
| 405 // Wait for the callback to hit, then assert that logging is still enabled | |
| 406 // but only for the LC_LOGGING category. | |
| 407 writer.WaitUntilEnabled(); | |
| 408 for (int cat = LC_LOGGING; cat < LC_MAX_CAT; ++cat) { | |
| 409 EXPECT_EQ(cat == LC_LOGGING, | |
| 410 writer.IsCatLevelEnabled(static_cast<LogCategory>(cat), | |
| 411 LEVEL_WARNING)); | |
| 412 } | |
| 413 | |
| 414 EXPECT_HRESULT_SUCCEEDED(controller_.DisableProvider(kTestProviderGuid)); | |
| 415 | |
| 416 // Wait for the callback to hit, then assert that logging is now disabled. | |
| 417 writer.WaitUntilDisabled(); | |
| 418 for (int cat = LC_LOGGING; cat < LC_MAX_CAT; ++cat) { | |
| 419 EXPECT_FALSE(writer.IsCatLevelEnabled(static_cast<LogCategory>(cat), | |
| 420 LEVEL_WARNING)); | |
| 421 } | |
| 422 } | |
| 423 | |
| 424 TEST_F(EtwLogWriterTest, OutputMessageIsRobust) { | |
| 425 // Test that OutputMessage doesn't fall over on unexpected inputs. | |
| 426 | |
| 427 // Turn logging on. | |
| 428 TestingLogWriter writer; | |
| 429 EXPECT_HRESULT_SUCCEEDED( | |
| 430 controller_.EnableProvider(kTestProviderGuid, | |
| 431 TRACE_LEVEL_INFORMATION, | |
| 432 0xFFFFFFFF)); | |
| 433 writer.WaitUntilEnabled(); | |
| 434 | |
| 435 OutputInfo msg(LC_LOGGING, LW, L"TEST", NULL); | |
| 436 writer.OutputMessage(&msg); | |
| 437 | |
| 438 msg.category = static_cast<LogCategory>(0xFF); | |
| 439 msg.level = static_cast<LogLevel>(0xFF); | |
| 440 msg.msg1 = NULL; | |
| 441 msg.msg2 = L"TEST"; | |
| 442 writer.OutputMessage(&msg); | |
| 443 } | |
| 444 | |
| 445 TEST_F(EtwLogWriterTest, OutputMessageOnlyLevelsEnabled) { | |
| 446 #define EXPECT_LOG(trace_level, enable_bits, log_level, log_cat) \ | |
| 447 ExpectLogMessage(trace_level, enable_bits, log_level, log_cat, true); | |
| 448 #define EXPECT_NO_LOG(trace_level, enable_bits, log_level, log_cat) \ | |
| 449 ExpectLogMessage(trace_level, enable_bits, log_level, log_cat, false); | |
| 450 | |
| 451 // Try different levels at LC_LOGGING category. | |
| 452 EXPECT_NO_LOG(TRACE_LEVEL_NONE, 0x3, LEVEL_FATALERROR, LC_LOGGING); | |
| 453 EXPECT_NO_LOG(TRACE_LEVEL_NONE, 0x3, LEVEL_ERROR, LC_LOGGING); | |
| 454 EXPECT_NO_LOG(TRACE_LEVEL_NONE, 0x3, LE, LC_LOGGING); | |
| 455 EXPECT_NO_LOG(TRACE_LEVEL_NONE, 0x3, LEVEL_WARNING, LC_LOGGING); | |
| 456 EXPECT_NO_LOG(TRACE_LEVEL_NONE, 0x3, LW, LC_LOGGING); | |
| 457 EXPECT_NO_LOG(TRACE_LEVEL_NONE, 0x3, L1, LC_LOGGING); | |
| 458 EXPECT_NO_LOG(TRACE_LEVEL_NONE, 0x3, L2, LC_LOGGING); | |
| 459 EXPECT_NO_LOG(TRACE_LEVEL_NONE, 0x3, L3, LC_LOGGING); | |
| 460 EXPECT_NO_LOG(TRACE_LEVEL_NONE, 0x3, L4, LC_LOGGING); | |
| 461 EXPECT_NO_LOG(TRACE_LEVEL_NONE, 0x3, L5, LC_LOGGING); | |
| 462 EXPECT_NO_LOG(TRACE_LEVEL_NONE, 0x3, L6, LC_LOGGING); | |
| 463 ConsumeAndRestartLog(); | |
| 464 | |
| 465 if (!ShouldRunLargeTest()) { | |
| 466 // This test takes about 7 seconds, so only run part of it by default. | |
| 467 return; | |
| 468 } | |
| 469 | |
| 470 EXPECT_LOG(TRACE_LEVEL_FATAL, 0x3, LEVEL_FATALERROR, LC_LOGGING); | |
| 471 EXPECT_NO_LOG(TRACE_LEVEL_FATAL, 0x3, LEVEL_ERROR, LC_LOGGING); | |
| 472 EXPECT_NO_LOG(TRACE_LEVEL_FATAL, 0x3, LE, LC_LOGGING); | |
| 473 EXPECT_NO_LOG(TRACE_LEVEL_FATAL, 0x3, LEVEL_WARNING, LC_LOGGING); | |
| 474 EXPECT_NO_LOG(TRACE_LEVEL_FATAL, 0x3, LW, LC_LOGGING); | |
| 475 EXPECT_NO_LOG(TRACE_LEVEL_FATAL, 0x3, L1, LC_LOGGING); | |
| 476 EXPECT_NO_LOG(TRACE_LEVEL_FATAL, 0x3, L2, LC_LOGGING); | |
| 477 EXPECT_NO_LOG(TRACE_LEVEL_FATAL, 0x3, L3, LC_LOGGING); | |
| 478 EXPECT_NO_LOG(TRACE_LEVEL_FATAL, 0x3, L4, LC_LOGGING); | |
| 479 EXPECT_NO_LOG(TRACE_LEVEL_FATAL, 0x3, L5, LC_LOGGING); | |
| 480 EXPECT_NO_LOG(TRACE_LEVEL_FATAL, 0x3, L6, LC_LOGGING); | |
| 481 ConsumeAndRestartLog(); | |
| 482 | |
| 483 EXPECT_LOG(TRACE_LEVEL_ERROR, 0x3, LEVEL_FATALERROR, LC_LOGGING); | |
| 484 EXPECT_LOG(TRACE_LEVEL_ERROR, 0x3, LEVEL_ERROR, LC_LOGGING); | |
| 485 EXPECT_LOG(TRACE_LEVEL_ERROR, 0x3, LE, LC_LOGGING); | |
| 486 EXPECT_NO_LOG(TRACE_LEVEL_ERROR, 0x3, LEVEL_WARNING, LC_LOGGING); | |
| 487 EXPECT_NO_LOG(TRACE_LEVEL_ERROR, 0x3, LW, LC_LOGGING); | |
| 488 EXPECT_NO_LOG(TRACE_LEVEL_ERROR, 0x3, L1, LC_LOGGING); | |
| 489 EXPECT_NO_LOG(TRACE_LEVEL_ERROR, 0x3, L2, LC_LOGGING); | |
| 490 EXPECT_NO_LOG(TRACE_LEVEL_ERROR, 0x3, L3, LC_LOGGING); | |
| 491 EXPECT_NO_LOG(TRACE_LEVEL_ERROR, 0x3, L4, LC_LOGGING); | |
| 492 EXPECT_NO_LOG(TRACE_LEVEL_ERROR, 0x3, L5, LC_LOGGING); | |
| 493 EXPECT_NO_LOG(TRACE_LEVEL_ERROR, 0x3, L6, LC_LOGGING); | |
| 494 ConsumeAndRestartLog(); | |
| 495 | |
| 496 EXPECT_LOG(TRACE_LEVEL_WARNING, 0x3, LEVEL_FATALERROR, LC_LOGGING); | |
| 497 EXPECT_LOG(TRACE_LEVEL_WARNING, 0x3, LEVEL_ERROR, LC_LOGGING); | |
| 498 EXPECT_LOG(TRACE_LEVEL_WARNING, 0x3, LE, LC_LOGGING); | |
| 499 EXPECT_LOG(TRACE_LEVEL_WARNING, 0x3, LEVEL_WARNING, LC_LOGGING); | |
| 500 EXPECT_LOG(TRACE_LEVEL_WARNING, 0x3, LW, LC_LOGGING); | |
| 501 EXPECT_NO_LOG(TRACE_LEVEL_WARNING, 0x3, L1, LC_LOGGING); | |
| 502 EXPECT_NO_LOG(TRACE_LEVEL_WARNING, 0x3, L2, LC_LOGGING); | |
| 503 EXPECT_NO_LOG(TRACE_LEVEL_WARNING, 0x3, L3, LC_LOGGING); | |
| 504 EXPECT_NO_LOG(TRACE_LEVEL_WARNING, 0x3, L4, LC_LOGGING); | |
| 505 EXPECT_NO_LOG(TRACE_LEVEL_WARNING, 0x3, L5, LC_LOGGING); | |
| 506 EXPECT_NO_LOG(TRACE_LEVEL_WARNING, 0x3, L6, LC_LOGGING); | |
| 507 ConsumeAndRestartLog(); | |
| 508 | |
| 509 EXPECT_LOG(TRACE_LEVEL_INFORMATION, 0x3, LEVEL_FATALERROR, LC_LOGGING); | |
| 510 EXPECT_LOG(TRACE_LEVEL_INFORMATION, 0x3, LEVEL_ERROR, LC_LOGGING); | |
| 511 EXPECT_LOG(TRACE_LEVEL_INFORMATION, 0x3, LE, LC_LOGGING); | |
| 512 EXPECT_LOG(TRACE_LEVEL_INFORMATION, 0x3, LEVEL_WARNING, LC_LOGGING); | |
| 513 EXPECT_LOG(TRACE_LEVEL_INFORMATION, 0x3, LW, LC_LOGGING); | |
| 514 EXPECT_LOG(TRACE_LEVEL_INFORMATION, 0x3, L1, LC_LOGGING); | |
| 515 EXPECT_LOG(TRACE_LEVEL_INFORMATION, 0x3, L2, LC_LOGGING); | |
| 516 EXPECT_NO_LOG(TRACE_LEVEL_INFORMATION, 0x3, L3, LC_LOGGING); | |
| 517 EXPECT_NO_LOG(TRACE_LEVEL_INFORMATION, 0x3, L4, LC_LOGGING); | |
| 518 EXPECT_NO_LOG(TRACE_LEVEL_INFORMATION, 0x3, L5, LC_LOGGING); | |
| 519 EXPECT_NO_LOG(TRACE_LEVEL_INFORMATION, 0x3, L6, LC_LOGGING); | |
| 520 ConsumeAndRestartLog(); | |
| 521 | |
| 522 EXPECT_LOG(TRACE_LEVEL_VERBOSE, 0x3, LEVEL_FATALERROR, LC_LOGGING); | |
| 523 EXPECT_LOG(TRACE_LEVEL_VERBOSE, 0x3, LEVEL_ERROR, LC_LOGGING); | |
| 524 EXPECT_LOG(TRACE_LEVEL_VERBOSE, 0x3, LE, LC_LOGGING); | |
| 525 EXPECT_LOG(TRACE_LEVEL_VERBOSE, 0x3, LEVEL_WARNING, LC_LOGGING); | |
| 526 EXPECT_LOG(TRACE_LEVEL_VERBOSE, 0x3, LW, LC_LOGGING); | |
| 527 EXPECT_LOG(TRACE_LEVEL_VERBOSE, 0x3, L1, LC_LOGGING); | |
| 528 EXPECT_LOG(TRACE_LEVEL_VERBOSE, 0x3, L2, LC_LOGGING); | |
| 529 EXPECT_LOG(TRACE_LEVEL_VERBOSE, 0x3, L3, LC_LOGGING); | |
| 530 EXPECT_LOG(TRACE_LEVEL_VERBOSE, 0x3, L4, LC_LOGGING); | |
| 531 EXPECT_LOG(TRACE_LEVEL_VERBOSE, 0x3, L5, LC_LOGGING); | |
| 532 EXPECT_LOG(TRACE_LEVEL_VERBOSE, 0x3, L6, LC_LOGGING); | |
| 533 ConsumeAndRestartLog(); | |
| 534 } | |
| 535 | |
| 536 TEST_F(EtwLogWriterTest, OutputMessageOnlyCategoriesEnabled) { | |
| 537 int max_cat = LC_MAX_CAT; | |
| 538 if (!ShouldRunLargeTest()) { | |
| 539 // This test takes about 12 seconds, so only run part of it by default. | |
| 540 max_cat = LC_LOGGING + 2; // Test combinations of the first two categories. | |
| 541 } | |
| 542 | |
| 543 // Loop through categories. | |
| 544 for (int log_cat = LC_LOGGING; log_cat < max_cat; ++log_cat) { | |
| 545 for (int enable_cat = LC_LOGGING; enable_cat < max_cat; ++enable_cat) { | |
| 546 EtwEventFlags enable_bits = | |
| 547 EtwLogWriter::CategoryToEnableFlag( | |
| 548 static_cast<LogCategory>(enable_cat)); | |
| 549 | |
| 550 ExpectLogMessage(TRACE_LEVEL_VERBOSE, | |
| 551 enable_bits, | |
| 552 LEVEL_WARNING, | |
| 553 static_cast<LogCategory>(log_cat), | |
| 554 log_cat == enable_cat); | |
| 555 } | |
| 556 | |
| 557 // Play the log for every log category, due to the ETW enable/disable | |
| 558 // restriction on Windows XP that's mentioned above. | |
| 559 ConsumeAndRestartLog(); | |
| 560 } | |
| 561 } | |
| 562 | |
| 563 } // namespace omaha | |
| OLD | NEW |
|---|
Chromium Code Reviews
Issue 624713003:
Keep only base/extractor.[cc|h]. (Closed)
Base URL: https://chromium.googlesource.com/external/omaha.git@master