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 #include "base/debug/trace_event_unittest.h" 6 7 #include <cstdlib> 8 9 #include "base/bind.h" 10 #include "base/command_line.h" 11 #include "base/debug/trace_event.h" 12 #include "base/json/json_reader.h" 13 #include "base/json/json_writer.h" 14 #include "base/memory/ref_counted_memory.h" 15 #include "base/memory/scoped_ptr.h" 16 #include "base/memory/singleton.h" 17 #include "base/process/process_handle.h" 18 #include "base/strings/stringprintf.h" 19 #include "base/synchronization/waitable_event.h" 20 #include "base/threading/platform_thread.h" 21 #include "base/threading/thread.h" 22 #include "base/values.h" 23 #include "testing/gmock/include/gmock/gmock.h" 24 #include "testing/gtest/include/gtest/gtest.h" 25 26 using base::debug::HighResSleepForTraceTest; 27 28 namespace base { 29 namespace debug { 30 31 namespace { 32 33 enum CompareOp { 34 IS_EQUAL, 35 IS_NOT_EQUAL, 36 }; 37 38 struct JsonKeyValue { 39 const char* key; 40 const char* value; 41 CompareOp op; 42 }; 43 44 const int kThreadId = 42; 45 const int kAsyncId = 5; 46 const char kAsyncIdStr[] = "0x5"; 47 const int kAsyncId2 = 6; 48 const char kAsyncId2Str[] = "0x6"; 49 50 class TraceEventTestFixture : public testing::Test { 51 public: 52 void OnTraceDataCollected( 53 const scoped_refptr<base::RefCountedString>& events_str); 54 void OnTraceNotification(int notification) { 55 if (notification & TraceLog::EVENT_WATCH_NOTIFICATION) 56 ++event_watch_notification_; 57 notifications_received_ |= notification; 58 } 59 DictionaryValue* FindMatchingTraceEntry(const JsonKeyValue* key_values); 60 DictionaryValue* FindNamePhase(const char* name, const char* phase); 61 DictionaryValue* FindNamePhaseKeyValue(const char* name, 62 const char* phase, 63 const char* key, 64 const char* value); 65 bool FindMatchingValue(const char* key, 66 const char* value); 67 bool FindNonMatchingValue(const char* key, 68 const char* value); 69 void Clear() { 70 trace_parsed_.Clear(); 71 json_output_.json_output.clear(); 72 } 73 74 void BeginTrace() { 75 BeginSpecificTrace("*"); 76 } 77 78 void BeginSpecificTrace(const std::string& filter) { 79 event_watch_notification_ = 0; 80 notifications_received_ = 0; 81 TraceLog::GetInstance()->SetEnabled(CategoryFilter(filter), 82 TraceLog::RECORD_UNTIL_FULL); 83 } 84 85 void EndTraceAndFlush() { 86 while (TraceLog::GetInstance()->IsEnabled()) 87 TraceLog::GetInstance()->SetDisabled(); 88 TraceLog::GetInstance()->Flush( 89 base::Bind(&TraceEventTestFixture::OnTraceDataCollected, 90 base::Unretained(this))); 91 } 92 93 virtual void SetUp() OVERRIDE { 94 const char* name = PlatformThread::GetName(); 95 old_thread_name_ = name ? strdup(name) : NULL; 96 notifications_received_ = 0; 97 98 TraceLog::DeleteForTesting(); 99 TraceLog* tracelog = TraceLog::GetInstance(); 100 ASSERT_TRUE(tracelog); 101 ASSERT_FALSE(tracelog->IsEnabled()); 102 tracelog->SetNotificationCallback( 103 base::Bind(&TraceEventTestFixture::OnTraceNotification, 104 base::Unretained(this))); 105 trace_buffer_.SetOutputCallback(json_output_.GetCallback()); 106 } 107 virtual void TearDown() OVERRIDE { 108 if (TraceLog::GetInstance()) 109 EXPECT_FALSE(TraceLog::GetInstance()->IsEnabled()); 110 PlatformThread::SetName(old_thread_name_ ? old_thread_name_ : ""); 111 free(old_thread_name_); 112 old_thread_name_ = NULL; 113 // We want our singleton torn down after each test. 114 TraceLog::DeleteForTesting(); 115 } 116 117 char* old_thread_name_; 118 ListValue trace_parsed_; 119 base::debug::TraceResultBuffer trace_buffer_; 120 base::debug::TraceResultBuffer::SimpleOutput json_output_; 121 int event_watch_notification_; 122 int notifications_received_; 123 124 private: 125 // We want our singleton torn down after each test. 126 ShadowingAtExitManager at_exit_manager_; 127 Lock lock_; 128 }; 129 130 void TraceEventTestFixture::OnTraceDataCollected( 131 const scoped_refptr<base::RefCountedString>& events_str) { 132 AutoLock lock(lock_); 133 json_output_.json_output.clear(); 134 trace_buffer_.Start(); 135 trace_buffer_.AddFragment(events_str->data()); 136 trace_buffer_.Finish(); 137 138 scoped_ptr<Value> root; 139 root.reset(base::JSONReader::Read(json_output_.json_output, 140 JSON_PARSE_RFC | JSON_DETACHABLE_CHILDREN)); 141 142 if (!root.get()) { 143 LOG(ERROR) << json_output_.json_output; 144 } 145 146 ListValue* root_list = NULL; 147 ASSERT_TRUE(root.get()); 148 ASSERT_TRUE(root->GetAsList(&root_list)); 149 150 // Move items into our aggregate collection 151 while (root_list->GetSize()) { 152 scoped_ptr<Value> item; 153 root_list->Remove(0, &item); 154 trace_parsed_.Append(item.release()); 155 } 156 } 157 158 static bool CompareJsonValues(const std::string& lhs, 159 const std::string& rhs, 160 CompareOp op) { 161 switch (op) { 162 case IS_EQUAL: 163 return lhs == rhs; 164 case IS_NOT_EQUAL: 165 return lhs != rhs; 166 default: 167 CHECK(0); 168 } 169 return false; 170 } 171 172 static bool IsKeyValueInDict(const JsonKeyValue* key_value, 173 DictionaryValue* dict) { 174 Value* value = NULL; 175 std::string value_str; 176 if (dict->Get(key_value->key, &value) && 177 value->GetAsString(&value_str) && 178 CompareJsonValues(value_str, key_value->value, key_value->op)) 179 return true; 180 181 // Recurse to test arguments 182 DictionaryValue* args_dict = NULL; 183 dict->GetDictionary("args", &args_dict); 184 if (args_dict) 185 return IsKeyValueInDict(key_value, args_dict); 186 187 return false; 188 } 189 190 static bool IsAllKeyValueInDict(const JsonKeyValue* key_values, 191 DictionaryValue* dict) { 192 // Scan all key_values, they must all be present and equal. 193 while (key_values && key_values->key) { 194 if (!IsKeyValueInDict(key_values, dict)) 195 return false; 196 ++key_values; 197 } 198 return true; 199 } 200 201 DictionaryValue* TraceEventTestFixture::FindMatchingTraceEntry( 202 const JsonKeyValue* key_values) { 203 // Scan all items 204 size_t trace_parsed_count = trace_parsed_.GetSize(); 205 for (size_t i = 0; i < trace_parsed_count; i++) { 206 Value* value = NULL; 207 trace_parsed_.Get(i, &value); 208 if (!value || value->GetType() != Value::TYPE_DICTIONARY) 209 continue; 210 DictionaryValue* dict = static_cast<DictionaryValue*>(value); 211 212 if (IsAllKeyValueInDict(key_values, dict)) 213 return dict; 214 } 215 return NULL; 216 } 217 218 DictionaryValue* TraceEventTestFixture::FindNamePhase(const char* name, 219 const char* phase) { 220 JsonKeyValue key_values[] = { 221 {"name", name, IS_EQUAL}, 222 {"ph", phase, IS_EQUAL}, 223 {0, 0, IS_EQUAL} 224 }; 225 return FindMatchingTraceEntry(key_values); 226 } 227 228 DictionaryValue* TraceEventTestFixture::FindNamePhaseKeyValue( 229 const char* name, 230 const char* phase, 231 const char* key, 232 const char* value) { 233 JsonKeyValue key_values[] = { 234 {"name", name, IS_EQUAL}, 235 {"ph", phase, IS_EQUAL}, 236 {key, value, IS_EQUAL}, 237 {0, 0, IS_EQUAL} 238 }; 239 return FindMatchingTraceEntry(key_values); 240 } 241 242 bool TraceEventTestFixture::FindMatchingValue(const char* key, 243 const char* value) { 244 JsonKeyValue key_values[] = { 245 {key, value, IS_EQUAL}, 246 {0, 0, IS_EQUAL} 247 }; 248 return FindMatchingTraceEntry(key_values); 249 } 250 251 bool TraceEventTestFixture::FindNonMatchingValue(const char* key, 252 const char* value) { 253 JsonKeyValue key_values[] = { 254 {key, value, IS_NOT_EQUAL}, 255 {0, 0, IS_EQUAL} 256 }; 257 return FindMatchingTraceEntry(key_values); 258 } 259 260 bool IsStringInDict(const char* string_to_match, const DictionaryValue* dict) { 261 for (DictionaryValue::Iterator it(*dict); !it.IsAtEnd(); it.Advance()) { 262 if (it.key().find(string_to_match) != std::string::npos) 263 return true; 264 265 std::string value_str; 266 it.value().GetAsString(&value_str); 267 if (value_str.find(string_to_match) != std::string::npos) 268 return true; 269 } 270 271 // Recurse to test arguments 272 const DictionaryValue* args_dict = NULL; 273 dict->GetDictionary("args", &args_dict); 274 if (args_dict) 275 return IsStringInDict(string_to_match, args_dict); 276 277 return false; 278 } 279 280 const DictionaryValue* FindTraceEntry( 281 const ListValue& trace_parsed, 282 const char* string_to_match, 283 const DictionaryValue* match_after_this_item = NULL) { 284 // Scan all items 285 size_t trace_parsed_count = trace_parsed.GetSize(); 286 for (size_t i = 0; i < trace_parsed_count; i++) { 287 const Value* value = NULL; 288 trace_parsed.Get(i, &value); 289 if (match_after_this_item) { 290 if (value == match_after_this_item) 291 match_after_this_item = NULL; 292 continue; 293 } 294 if (!value || value->GetType() != Value::TYPE_DICTIONARY) 295 continue; 296 const DictionaryValue* dict = static_cast<const DictionaryValue*>(value); 297 298 if (IsStringInDict(string_to_match, dict)) 299 return dict; 300 } 301 return NULL; 302 } 303 304 std::vector<const DictionaryValue*> FindTraceEntries( 305 const ListValue& trace_parsed, 306 const char* string_to_match) { 307 std::vector<const DictionaryValue*> hits; 308 size_t trace_parsed_count = trace_parsed.GetSize(); 309 for (size_t i = 0; i < trace_parsed_count; i++) { 310 const Value* value = NULL; 311 trace_parsed.Get(i, &value); 312 if (!value || value->GetType() != Value::TYPE_DICTIONARY) 313 continue; 314 const DictionaryValue* dict = static_cast<const DictionaryValue*>(value); 315 316 if (IsStringInDict(string_to_match, dict)) 317 hits.push_back(dict); 318 } 319 return hits; 320 } 321 322 void TraceWithAllMacroVariants(WaitableEvent* task_complete_event) { 323 { 324 TRACE_EVENT_BEGIN_ETW("TRACE_EVENT_BEGIN_ETW call", 0x1122, "extrastring1"); 325 TRACE_EVENT_END_ETW("TRACE_EVENT_END_ETW call", 0x3344, "extrastring2"); 326 TRACE_EVENT_INSTANT_ETW("TRACE_EVENT_INSTANT_ETW call", 327 0x5566, "extrastring3"); 328 329 TRACE_EVENT0("all", "TRACE_EVENT0 call"); 330 TRACE_EVENT1("all", "TRACE_EVENT1 call", "name1", "value1"); 331 TRACE_EVENT2("all", "TRACE_EVENT2 call", 332 "name1", "\"value1\"", 333 "name2", "value\\2"); 334 335 TRACE_EVENT_INSTANT0("all", "TRACE_EVENT_INSTANT0 call", 336 TRACE_EVENT_SCOPE_GLOBAL); 337 TRACE_EVENT_INSTANT1("all", "TRACE_EVENT_INSTANT1 call", 338 TRACE_EVENT_SCOPE_PROCESS, "name1", "value1"); 339 TRACE_EVENT_INSTANT2("all", "TRACE_EVENT_INSTANT2 call", 340 TRACE_EVENT_SCOPE_THREAD, 341 "name1", "value1", 342 "name2", "value2"); 343 344 TRACE_EVENT_BEGIN0("all", "TRACE_EVENT_BEGIN0 call"); 345 TRACE_EVENT_BEGIN1("all", "TRACE_EVENT_BEGIN1 call", "name1", "value1"); 346 TRACE_EVENT_BEGIN2("all", "TRACE_EVENT_BEGIN2 call", 347 "name1", "value1", 348 "name2", "value2"); 349 350 TRACE_EVENT_END0("all", "TRACE_EVENT_END0 call"); 351 TRACE_EVENT_END1("all", "TRACE_EVENT_END1 call", "name1", "value1"); 352 TRACE_EVENT_END2("all", "TRACE_EVENT_END2 call", 353 "name1", "value1", 354 "name2", "value2"); 355 356 TRACE_EVENT_ASYNC_BEGIN0("all", "TRACE_EVENT_ASYNC_BEGIN0 call", kAsyncId); 357 TRACE_EVENT_ASYNC_BEGIN1("all", "TRACE_EVENT_ASYNC_BEGIN1 call", kAsyncId, 358 "name1", "value1"); 359 TRACE_EVENT_ASYNC_BEGIN2("all", "TRACE_EVENT_ASYNC_BEGIN2 call", kAsyncId, 360 "name1", "value1", 361 "name2", "value2"); 362 363 TRACE_EVENT_ASYNC_STEP0("all", "TRACE_EVENT_ASYNC_STEP0 call", 364 5, "step1"); 365 TRACE_EVENT_ASYNC_STEP1("all", "TRACE_EVENT_ASYNC_STEP1 call", 366 5, "step2", "name1", "value1"); 367 368 TRACE_EVENT_ASYNC_END0("all", "TRACE_EVENT_ASYNC_END0 call", kAsyncId); 369 TRACE_EVENT_ASYNC_END1("all", "TRACE_EVENT_ASYNC_END1 call", kAsyncId, 370 "name1", "value1"); 371 TRACE_EVENT_ASYNC_END2("all", "TRACE_EVENT_ASYNC_END2 call", kAsyncId, 372 "name1", "value1", 373 "name2", "value2"); 374 375 TRACE_EVENT_BEGIN_ETW("TRACE_EVENT_BEGIN_ETW0 call", kAsyncId, NULL); 376 TRACE_EVENT_BEGIN_ETW("TRACE_EVENT_BEGIN_ETW1 call", kAsyncId, "value"); 377 TRACE_EVENT_END_ETW("TRACE_EVENT_END_ETW0 call", kAsyncId, NULL); 378 TRACE_EVENT_END_ETW("TRACE_EVENT_END_ETW1 call", kAsyncId, "value"); 379 TRACE_EVENT_INSTANT_ETW("TRACE_EVENT_INSTANT_ETW0 call", kAsyncId, NULL); 380 TRACE_EVENT_INSTANT_ETW("TRACE_EVENT_INSTANT_ETW1 call", kAsyncId, "value"); 381 382 TRACE_COUNTER1("all", "TRACE_COUNTER1 call", 31415); 383 TRACE_COUNTER2("all", "TRACE_COUNTER2 call", 384 "a", 30000, 385 "b", 1415); 386 387 TRACE_COUNTER_ID1("all", "TRACE_COUNTER_ID1 call", 0x319009, 31415); 388 TRACE_COUNTER_ID2("all", "TRACE_COUNTER_ID2 call", 0x319009, 389 "a", 30000, "b", 1415); 390 391 TRACE_EVENT_COPY_BEGIN_WITH_ID_TID_AND_TIMESTAMP0("all", 392 "TRACE_EVENT_COPY_BEGIN_WITH_ID_TID_AND_TIMESTAMP0 call", 393 kAsyncId, kThreadId, 12345); 394 TRACE_EVENT_COPY_END_WITH_ID_TID_AND_TIMESTAMP0("all", 395 "TRACE_EVENT_COPY_END_WITH_ID_TID_AND_TIMESTAMP0 call", 396 kAsyncId, kThreadId, 23456); 397 398 TRACE_EVENT_BEGIN_WITH_ID_TID_AND_TIMESTAMP0("all", 399 "TRACE_EVENT_BEGIN_WITH_ID_TID_AND_TIMESTAMP0 call", 400 kAsyncId2, kThreadId, 34567); 401 TRACE_EVENT_END_WITH_ID_TID_AND_TIMESTAMP0("all", 402 "TRACE_EVENT_END_WITH_ID_TID_AND_TIMESTAMP0 call", 403 kAsyncId2, kThreadId, 45678); 404 405 TRACE_EVENT_OBJECT_CREATED_WITH_ID("all", "tracked object 1", 0x42); 406 TRACE_EVENT_OBJECT_SNAPSHOT_WITH_ID( 407 "all", "tracked object 1", 0x42, "hello"); 408 TRACE_EVENT_OBJECT_DELETED_WITH_ID("all", "tracked object 1", 0x42); 409 410 TraceScopedTrackableObject<int> trackable("all", "tracked object 2", 411 0x2128506); 412 trackable.snapshot("world"); 413 } // Scope close causes TRACE_EVENT0 etc to send their END events. 414 415 if (task_complete_event) 416 task_complete_event->Signal(); 417 } 418 419 void ValidateAllTraceMacrosCreatedData(const ListValue& trace_parsed) { 420 const DictionaryValue* item = NULL; 421 422 #define EXPECT_FIND_(string) \ 423 EXPECT_TRUE((item = FindTraceEntry(trace_parsed, string))); 424 #define EXPECT_NOT_FIND_(string) \ 425 EXPECT_FALSE((item = FindTraceEntry(trace_parsed, string))); 426 #define EXPECT_SUB_FIND_(string) \ 427 if (item) EXPECT_TRUE((IsStringInDict(string, item))); 428 429 EXPECT_FIND_("ETW Trace Event"); 430 EXPECT_FIND_("all"); 431 EXPECT_FIND_("TRACE_EVENT_BEGIN_ETW call"); 432 { 433 std::string str_val; 434 EXPECT_TRUE(item && item->GetString("args.id", &str_val)); 435 EXPECT_STREQ("0x1122", str_val.c_str()); 436 } 437 EXPECT_SUB_FIND_("extrastring1"); 438 EXPECT_FIND_("TRACE_EVENT_END_ETW call"); 439 EXPECT_FIND_("TRACE_EVENT_INSTANT_ETW call"); 440 EXPECT_FIND_("TRACE_EVENT0 call"); 441 { 442 std::string ph_begin; 443 std::string ph_end; 444 EXPECT_TRUE((item = FindTraceEntry(trace_parsed, "TRACE_EVENT0 call"))); 445 EXPECT_TRUE((item && item->GetString("ph", &ph_begin))); 446 EXPECT_TRUE((item = FindTraceEntry(trace_parsed, "TRACE_EVENT0 call", 447 item))); 448 EXPECT_TRUE((item && item->GetString("ph", &ph_end))); 449 EXPECT_EQ("B", ph_begin); 450 EXPECT_EQ("E", ph_end); 451 } 452 EXPECT_FIND_("TRACE_EVENT1 call"); 453 EXPECT_SUB_FIND_("name1"); 454 EXPECT_SUB_FIND_("value1"); 455 EXPECT_FIND_("TRACE_EVENT2 call"); 456 EXPECT_SUB_FIND_("name1"); 457 EXPECT_SUB_FIND_("\"value1\""); 458 EXPECT_SUB_FIND_("name2"); 459 EXPECT_SUB_FIND_("value\\2"); 460 461 EXPECT_FIND_("TRACE_EVENT_INSTANT0 call"); 462 { 463 std::string scope; 464 EXPECT_TRUE((item && item->GetString("s", &scope))); 465 EXPECT_EQ("g", scope); 466 } 467 EXPECT_FIND_("TRACE_EVENT_INSTANT1 call"); 468 { 469 std::string scope; 470 EXPECT_TRUE((item && item->GetString("s", &scope))); 471 EXPECT_EQ("p", scope); 472 } 473 EXPECT_SUB_FIND_("name1"); 474 EXPECT_SUB_FIND_("value1"); 475 EXPECT_FIND_("TRACE_EVENT_INSTANT2 call"); 476 { 477 std::string scope; 478 EXPECT_TRUE((item && item->GetString("s", &scope))); 479 EXPECT_EQ("t", scope); 480 } 481 EXPECT_SUB_FIND_("name1"); 482 EXPECT_SUB_FIND_("value1"); 483 EXPECT_SUB_FIND_("name2"); 484 EXPECT_SUB_FIND_("value2"); 485 486 EXPECT_FIND_("TRACE_EVENT_BEGIN0 call"); 487 EXPECT_FIND_("TRACE_EVENT_BEGIN1 call"); 488 EXPECT_SUB_FIND_("name1"); 489 EXPECT_SUB_FIND_("value1"); 490 EXPECT_FIND_("TRACE_EVENT_BEGIN2 call"); 491 EXPECT_SUB_FIND_("name1"); 492 EXPECT_SUB_FIND_("value1"); 493 EXPECT_SUB_FIND_("name2"); 494 EXPECT_SUB_FIND_("value2"); 495 496 EXPECT_FIND_("TRACE_EVENT_END0 call"); 497 EXPECT_FIND_("TRACE_EVENT_END1 call"); 498 EXPECT_SUB_FIND_("name1"); 499 EXPECT_SUB_FIND_("value1"); 500 EXPECT_FIND_("TRACE_EVENT_END2 call"); 501 EXPECT_SUB_FIND_("name1"); 502 EXPECT_SUB_FIND_("value1"); 503 EXPECT_SUB_FIND_("name2"); 504 EXPECT_SUB_FIND_("value2"); 505 506 EXPECT_FIND_("TRACE_EVENT_ASYNC_BEGIN0 call"); 507 EXPECT_SUB_FIND_("id"); 508 EXPECT_SUB_FIND_(kAsyncIdStr); 509 EXPECT_FIND_("TRACE_EVENT_ASYNC_BEGIN1 call"); 510 EXPECT_SUB_FIND_("id"); 511 EXPECT_SUB_FIND_(kAsyncIdStr); 512 EXPECT_SUB_FIND_("name1"); 513 EXPECT_SUB_FIND_("value1"); 514 EXPECT_FIND_("TRACE_EVENT_ASYNC_BEGIN2 call"); 515 EXPECT_SUB_FIND_("id"); 516 EXPECT_SUB_FIND_(kAsyncIdStr); 517 EXPECT_SUB_FIND_("name1"); 518 EXPECT_SUB_FIND_("value1"); 519 EXPECT_SUB_FIND_("name2"); 520 EXPECT_SUB_FIND_("value2"); 521 522 EXPECT_FIND_("TRACE_EVENT_ASYNC_STEP0 call"); 523 EXPECT_SUB_FIND_("id"); 524 EXPECT_SUB_FIND_(kAsyncIdStr); 525 EXPECT_SUB_FIND_("step1"); 526 EXPECT_FIND_("TRACE_EVENT_ASYNC_STEP1 call"); 527 EXPECT_SUB_FIND_("id"); 528 EXPECT_SUB_FIND_(kAsyncIdStr); 529 EXPECT_SUB_FIND_("step2"); 530 EXPECT_SUB_FIND_("name1"); 531 EXPECT_SUB_FIND_("value1"); 532 533 EXPECT_FIND_("TRACE_EVENT_ASYNC_END0 call"); 534 EXPECT_SUB_FIND_("id"); 535 EXPECT_SUB_FIND_(kAsyncIdStr); 536 EXPECT_FIND_("TRACE_EVENT_ASYNC_END1 call"); 537 EXPECT_SUB_FIND_("id"); 538 EXPECT_SUB_FIND_(kAsyncIdStr); 539 EXPECT_SUB_FIND_("name1"); 540 EXPECT_SUB_FIND_("value1"); 541 EXPECT_FIND_("TRACE_EVENT_ASYNC_END2 call"); 542 EXPECT_SUB_FIND_("id"); 543 EXPECT_SUB_FIND_(kAsyncIdStr); 544 EXPECT_SUB_FIND_("name1"); 545 EXPECT_SUB_FIND_("value1"); 546 EXPECT_SUB_FIND_("name2"); 547 EXPECT_SUB_FIND_("value2"); 548 549 EXPECT_FIND_("TRACE_EVENT_BEGIN_ETW0 call"); 550 EXPECT_SUB_FIND_("id"); 551 EXPECT_SUB_FIND_(kAsyncIdStr); 552 EXPECT_SUB_FIND_("extra"); 553 EXPECT_SUB_FIND_("NULL"); 554 EXPECT_FIND_("TRACE_EVENT_BEGIN_ETW1 call"); 555 EXPECT_SUB_FIND_("id"); 556 EXPECT_SUB_FIND_(kAsyncIdStr); 557 EXPECT_SUB_FIND_("extra"); 558 EXPECT_SUB_FIND_("value"); 559 EXPECT_FIND_("TRACE_EVENT_END_ETW0 call"); 560 EXPECT_SUB_FIND_("id"); 561 EXPECT_SUB_FIND_(kAsyncIdStr); 562 EXPECT_SUB_FIND_("extra"); 563 EXPECT_SUB_FIND_("NULL"); 564 EXPECT_FIND_("TRACE_EVENT_END_ETW1 call"); 565 EXPECT_SUB_FIND_("id"); 566 EXPECT_SUB_FIND_(kAsyncIdStr); 567 EXPECT_SUB_FIND_("extra"); 568 EXPECT_SUB_FIND_("value"); 569 EXPECT_FIND_("TRACE_EVENT_INSTANT_ETW0 call"); 570 EXPECT_SUB_FIND_("id"); 571 EXPECT_SUB_FIND_(kAsyncIdStr); 572 EXPECT_SUB_FIND_("extra"); 573 EXPECT_SUB_FIND_("NULL"); 574 EXPECT_FIND_("TRACE_EVENT_INSTANT_ETW1 call"); 575 EXPECT_SUB_FIND_("id"); 576 EXPECT_SUB_FIND_(kAsyncIdStr); 577 EXPECT_SUB_FIND_("extra"); 578 EXPECT_SUB_FIND_("value"); 579 580 EXPECT_FIND_("TRACE_COUNTER1 call"); 581 { 582 std::string ph; 583 EXPECT_TRUE((item && item->GetString("ph", &ph))); 584 EXPECT_EQ("C", ph); 585 586 int value; 587 EXPECT_TRUE((item && item->GetInteger("args.value", &value))); 588 EXPECT_EQ(31415, value); 589 } 590 591 EXPECT_FIND_("TRACE_COUNTER2 call"); 592 { 593 std::string ph; 594 EXPECT_TRUE((item && item->GetString("ph", &ph))); 595 EXPECT_EQ("C", ph); 596 597 int value; 598 EXPECT_TRUE((item && item->GetInteger("args.a", &value))); 599 EXPECT_EQ(30000, value); 600 601 EXPECT_TRUE((item && item->GetInteger("args.b", &value))); 602 EXPECT_EQ(1415, value); 603 } 604 605 EXPECT_FIND_("TRACE_COUNTER_ID1 call"); 606 { 607 std::string id; 608 EXPECT_TRUE((item && item->GetString("id", &id))); 609 EXPECT_EQ("0x319009", id); 610 611 std::string ph; 612 EXPECT_TRUE((item && item->GetString("ph", &ph))); 613 EXPECT_EQ("C", ph); 614 615 int value; 616 EXPECT_TRUE((item && item->GetInteger("args.value", &value))); 617 EXPECT_EQ(31415, value); 618 } 619 620 EXPECT_FIND_("TRACE_COUNTER_ID2 call"); 621 { 622 std::string id; 623 EXPECT_TRUE((item && item->GetString("id", &id))); 624 EXPECT_EQ("0x319009", id); 625 626 std::string ph; 627 EXPECT_TRUE((item && item->GetString("ph", &ph))); 628 EXPECT_EQ("C", ph); 629 630 int value; 631 EXPECT_TRUE((item && item->GetInteger("args.a", &value))); 632 EXPECT_EQ(30000, value); 633 634 EXPECT_TRUE((item && item->GetInteger("args.b", &value))); 635 EXPECT_EQ(1415, value); 636 } 637 638 EXPECT_FIND_("TRACE_EVENT_COPY_BEGIN_WITH_ID_TID_AND_TIMESTAMP0 call"); 639 { 640 int val; 641 EXPECT_TRUE((item && item->GetInteger("ts", &val))); 642 EXPECT_EQ(12345, val); 643 EXPECT_TRUE((item && item->GetInteger("tid", &val))); 644 EXPECT_EQ(kThreadId, val); 645 std::string id; 646 EXPECT_TRUE((item && item->GetString("id", &id))); 647 EXPECT_EQ(kAsyncIdStr, id); 648 } 649 650 EXPECT_FIND_("TRACE_EVENT_COPY_END_WITH_ID_TID_AND_TIMESTAMP0 call"); 651 { 652 int val; 653 EXPECT_TRUE((item && item->GetInteger("ts", &val))); 654 EXPECT_EQ(23456, val); 655 EXPECT_TRUE((item && item->GetInteger("tid", &val))); 656 EXPECT_EQ(kThreadId, val); 657 std::string id; 658 EXPECT_TRUE((item && item->GetString("id", &id))); 659 EXPECT_EQ(kAsyncIdStr, id); 660 } 661 662 EXPECT_FIND_("TRACE_EVENT_BEGIN_WITH_ID_TID_AND_TIMESTAMP0 call"); 663 { 664 int val; 665 EXPECT_TRUE((item && item->GetInteger("ts", &val))); 666 EXPECT_EQ(34567, val); 667 EXPECT_TRUE((item && item->GetInteger("tid", &val))); 668 EXPECT_EQ(kThreadId, val); 669 std::string id; 670 EXPECT_TRUE((item && item->GetString("id", &id))); 671 EXPECT_EQ(kAsyncId2Str, id); 672 } 673 674 EXPECT_FIND_("TRACE_EVENT_END_WITH_ID_TID_AND_TIMESTAMP0 call"); 675 { 676 int val; 677 EXPECT_TRUE((item && item->GetInteger("ts", &val))); 678 EXPECT_EQ(45678, val); 679 EXPECT_TRUE((item && item->GetInteger("tid", &val))); 680 EXPECT_EQ(kThreadId, val); 681 std::string id; 682 EXPECT_TRUE((item && item->GetString("id", &id))); 683 EXPECT_EQ(kAsyncId2Str, id); 684 } 685 686 EXPECT_FIND_("tracked object 1"); 687 { 688 std::string phase; 689 std::string id; 690 std::string snapshot; 691 692 EXPECT_TRUE((item && item->GetString("ph", &phase))); 693 EXPECT_EQ("N", phase); 694 EXPECT_TRUE((item && item->GetString("id", &id))); 695 EXPECT_EQ("0x42", id); 696 697 item = FindTraceEntry(trace_parsed, "tracked object 1", item); 698 EXPECT_TRUE(item); 699 EXPECT_TRUE(item && item->GetString("ph", &phase)); 700 EXPECT_EQ("O", phase); 701 EXPECT_TRUE(item && item->GetString("id", &id)); 702 EXPECT_EQ("0x42", id); 703 EXPECT_TRUE(item && item->GetString("args.snapshot", &snapshot)); 704 EXPECT_EQ("hello", snapshot); 705 706 item = FindTraceEntry(trace_parsed, "tracked object 1", item); 707 EXPECT_TRUE(item); 708 EXPECT_TRUE(item && item->GetString("ph", &phase)); 709 EXPECT_EQ("D", phase); 710 EXPECT_TRUE(item && item->GetString("id", &id)); 711 EXPECT_EQ("0x42", id); 712 } 713 714 EXPECT_FIND_("tracked object 2"); 715 { 716 std::string phase; 717 std::string id; 718 std::string snapshot; 719 720 EXPECT_TRUE(item && item->GetString("ph", &phase)); 721 EXPECT_EQ("N", phase); 722 EXPECT_TRUE(item && item->GetString("id", &id)); 723 EXPECT_EQ("0x2128506", id); 724 725 item = FindTraceEntry(trace_parsed, "tracked object 2", item); 726 EXPECT_TRUE(item); 727 EXPECT_TRUE(item && item->GetString("ph", &phase)); 728 EXPECT_EQ("O", phase); 729 EXPECT_TRUE(item && item->GetString("id", &id)); 730 EXPECT_EQ("0x2128506", id); 731 EXPECT_TRUE(item && item->GetString("args.snapshot", &snapshot)); 732 EXPECT_EQ("world", snapshot); 733 734 item = FindTraceEntry(trace_parsed, "tracked object 2", item); 735 EXPECT_TRUE(item); 736 EXPECT_TRUE(item && item->GetString("ph", &phase)); 737 EXPECT_EQ("D", phase); 738 EXPECT_TRUE(item && item->GetString("id", &id)); 739 EXPECT_EQ("0x2128506", id); 740 } 741 } 742 743 void TraceManyInstantEvents(int thread_id, int num_events, 744 WaitableEvent* task_complete_event) { 745 for (int i = 0; i < num_events; i++) { 746 TRACE_EVENT_INSTANT2("all", "multi thread event", 747 TRACE_EVENT_SCOPE_THREAD, 748 "thread", thread_id, 749 "event", i); 750 } 751 752 if (task_complete_event) 753 task_complete_event->Signal(); 754 } 755 756 void ValidateInstantEventPresentOnEveryThread(const ListValue& trace_parsed, 757 int num_threads, 758 int num_events) { 759 std::map<int, std::map<int, bool> > results; 760 761 size_t trace_parsed_count = trace_parsed.GetSize(); 762 for (size_t i = 0; i < trace_parsed_count; i++) { 763 const Value* value = NULL; 764 trace_parsed.Get(i, &value); 765 if (!value || value->GetType() != Value::TYPE_DICTIONARY) 766 continue; 767 const DictionaryValue* dict = static_cast<const DictionaryValue*>(value); 768 std::string name; 769 dict->GetString("name", &name); 770 if (name != "multi thread event") 771 continue; 772 773 int thread = 0; 774 int event = 0; 775 EXPECT_TRUE(dict->GetInteger("args.thread", &thread)); 776 EXPECT_TRUE(dict->GetInteger("args.event", &event)); 777 results[thread][event] = true; 778 } 779 780 EXPECT_FALSE(results[-1][-1]); 781 for (int thread = 0; thread < num_threads; thread++) { 782 for (int event = 0; event < num_events; event++) { 783 EXPECT_TRUE(results[thread][event]); 784 } 785 } 786 } 787 788 void TraceCallsWithCachedCategoryPointersPointers(const char* name_str) { 789 TRACE_EVENT0("category name1", name_str); 790 TRACE_EVENT_INSTANT0("category name2", name_str, TRACE_EVENT_SCOPE_THREAD); 791 TRACE_EVENT_BEGIN0("category name3", name_str); 792 TRACE_EVENT_END0("category name4", name_str); 793 } 794 795 } // namespace 796 797 void HighResSleepForTraceTest(base::TimeDelta elapsed) { 798 base::TimeTicks end_time = base::TimeTicks::HighResNow() + elapsed; 799 do { 800 base::PlatformThread::Sleep(base::TimeDelta::FromMilliseconds(1)); 801 } while (base::TimeTicks::HighResNow() < end_time); 802 } 803 804 // Simple Test for emitting data and validating it was received. 805 TEST_F(TraceEventTestFixture, DataCaptured) { 806 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"), 807 TraceLog::RECORD_UNTIL_FULL); 808 809 TraceWithAllMacroVariants(NULL); 810 811 EndTraceAndFlush(); 812 813 ValidateAllTraceMacrosCreatedData(trace_parsed_); 814 } 815 816 class MockEnabledStateChangedObserver : 817 public base::debug::TraceLog::EnabledStateObserver { 818 public: 819 MOCK_METHOD0(OnTraceLogEnabled, void()); 820 MOCK_METHOD0(OnTraceLogDisabled, void()); 821 }; 822 823 TEST_F(TraceEventTestFixture, EnabledObserverFiresOnEnable) { 824 MockEnabledStateChangedObserver observer; 825 TraceLog::GetInstance()->AddEnabledStateObserver(&observer); 826 827 EXPECT_CALL(observer, OnTraceLogEnabled()) 828 .Times(1); 829 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"), 830 TraceLog::RECORD_UNTIL_FULL); 831 testing::Mock::VerifyAndClear(&observer); 832 EXPECT_TRUE(TraceLog::GetInstance()->IsEnabled()); 833 834 // Cleanup. 835 TraceLog::GetInstance()->RemoveEnabledStateObserver(&observer); 836 TraceLog::GetInstance()->SetDisabled(); 837 } 838 839 TEST_F(TraceEventTestFixture, EnabledObserverDoesntFireOnSecondEnable) { 840 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"), 841 TraceLog::RECORD_UNTIL_FULL); 842 843 testing::StrictMock<MockEnabledStateChangedObserver> observer; 844 TraceLog::GetInstance()->AddEnabledStateObserver(&observer); 845 846 EXPECT_CALL(observer, OnTraceLogEnabled()) 847 .Times(0); 848 EXPECT_CALL(observer, OnTraceLogDisabled()) 849 .Times(0); 850 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"), 851 TraceLog::RECORD_UNTIL_FULL); 852 testing::Mock::VerifyAndClear(&observer); 853 EXPECT_TRUE(TraceLog::GetInstance()->IsEnabled()); 854 855 // Cleanup. 856 TraceLog::GetInstance()->RemoveEnabledStateObserver(&observer); 857 TraceLog::GetInstance()->SetDisabled(); 858 TraceLog::GetInstance()->SetDisabled(); 859 } 860 861 TEST_F(TraceEventTestFixture, EnabledObserverDoesntFireOnNestedDisable) { 862 CategoryFilter cf_inc_all("*"); 863 TraceLog::GetInstance()->SetEnabled(cf_inc_all, TraceLog::RECORD_UNTIL_FULL); 864 TraceLog::GetInstance()->SetEnabled(cf_inc_all, TraceLog::RECORD_UNTIL_FULL); 865 866 testing::StrictMock<MockEnabledStateChangedObserver> observer; 867 TraceLog::GetInstance()->AddEnabledStateObserver(&observer); 868 869 EXPECT_CALL(observer, OnTraceLogEnabled()) 870 .Times(0); 871 EXPECT_CALL(observer, OnTraceLogDisabled()) 872 .Times(0); 873 TraceLog::GetInstance()->SetDisabled(); 874 testing::Mock::VerifyAndClear(&observer); 875 876 // Cleanup. 877 TraceLog::GetInstance()->RemoveEnabledStateObserver(&observer); 878 TraceLog::GetInstance()->SetDisabled(); 879 } 880 881 TEST_F(TraceEventTestFixture, EnabledObserverFiresOnDisable) { 882 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"), 883 TraceLog::RECORD_UNTIL_FULL); 884 885 MockEnabledStateChangedObserver observer; 886 TraceLog::GetInstance()->AddEnabledStateObserver(&observer); 887 888 EXPECT_CALL(observer, OnTraceLogDisabled()) 889 .Times(1); 890 TraceLog::GetInstance()->SetDisabled(); 891 testing::Mock::VerifyAndClear(&observer); 892 893 // Cleanup. 894 TraceLog::GetInstance()->RemoveEnabledStateObserver(&observer); 895 } 896 897 // Tests the IsEnabled() state of TraceLog changes before callbacks. 898 class AfterStateChangeEnabledStateObserver 899 : public base::debug::TraceLog::EnabledStateObserver { 900 public: 901 AfterStateChangeEnabledStateObserver() {} 902 virtual ~AfterStateChangeEnabledStateObserver() {} 903 904 // base::debug::TraceLog::EnabledStateObserver overrides: 905 virtual void OnTraceLogEnabled() OVERRIDE { 906 EXPECT_TRUE(TraceLog::GetInstance()->IsEnabled()); 907 } 908 909 virtual void OnTraceLogDisabled() OVERRIDE { 910 EXPECT_FALSE(TraceLog::GetInstance()->IsEnabled()); 911 } 912 }; 913 914 TEST_F(TraceEventTestFixture, ObserversFireAfterStateChange) { 915 AfterStateChangeEnabledStateObserver observer; 916 TraceLog::GetInstance()->AddEnabledStateObserver(&observer); 917 918 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"), 919 TraceLog::RECORD_UNTIL_FULL); 920 EXPECT_TRUE(TraceLog::GetInstance()->IsEnabled()); 921 922 TraceLog::GetInstance()->SetDisabled(); 923 EXPECT_FALSE(TraceLog::GetInstance()->IsEnabled()); 924 925 TraceLog::GetInstance()->RemoveEnabledStateObserver(&observer); 926 } 927 928 // Tests that a state observer can remove itself during a callback. 929 class SelfRemovingEnabledStateObserver 930 : public base::debug::TraceLog::EnabledStateObserver { 931 public: 932 SelfRemovingEnabledStateObserver() {} 933 virtual ~SelfRemovingEnabledStateObserver() {} 934 935 // base::debug::TraceLog::EnabledStateObserver overrides: 936 virtual void OnTraceLogEnabled() OVERRIDE {} 937 938 virtual void OnTraceLogDisabled() OVERRIDE { 939 TraceLog::GetInstance()->RemoveEnabledStateObserver(this); 940 } 941 }; 942 943 TEST_F(TraceEventTestFixture, SelfRemovingObserver) { 944 ASSERT_EQ(0u, TraceLog::GetInstance()->GetObserverCountForTest()); 945 946 SelfRemovingEnabledStateObserver observer; 947 TraceLog::GetInstance()->AddEnabledStateObserver(&observer); 948 EXPECT_EQ(1u, TraceLog::GetInstance()->GetObserverCountForTest()); 949 950 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"), 951 TraceLog::RECORD_UNTIL_FULL); 952 TraceLog::GetInstance()->SetDisabled(); 953 // The observer removed itself on disable. 954 EXPECT_EQ(0u, TraceLog::GetInstance()->GetObserverCountForTest()); 955 } 956 957 bool IsNewTrace() { 958 bool is_new_trace; 959 TRACE_EVENT_IS_NEW_TRACE(&is_new_trace); 960 return is_new_trace; 961 } 962 963 TEST_F(TraceEventTestFixture, NewTraceRecording) { 964 ASSERT_FALSE(IsNewTrace()); 965 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"), 966 TraceLog::RECORD_UNTIL_FULL); 967 // First call to IsNewTrace() should succeed. But, the second shouldn't. 968 ASSERT_TRUE(IsNewTrace()); 969 ASSERT_FALSE(IsNewTrace()); 970 EndTraceAndFlush(); 971 972 // IsNewTrace() should definitely be false now. 973 ASSERT_FALSE(IsNewTrace()); 974 975 // Start another trace. IsNewTrace() should become true again, briefly, as 976 // before. 977 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"), 978 TraceLog::RECORD_UNTIL_FULL); 979 ASSERT_TRUE(IsNewTrace()); 980 ASSERT_FALSE(IsNewTrace()); 981 982 // Cleanup. 983 EndTraceAndFlush(); 984 } 985 986 987 // Test that categories work. 988 TEST_F(TraceEventTestFixture, Categories) { 989 // Test that categories that are used can be retrieved whether trace was 990 // enabled or disabled when the trace event was encountered. 991 TRACE_EVENT_INSTANT0("c1", "name", TRACE_EVENT_SCOPE_THREAD); 992 TRACE_EVENT_INSTANT0("c2", "name", TRACE_EVENT_SCOPE_THREAD); 993 BeginTrace(); 994 TRACE_EVENT_INSTANT0("c3", "name", TRACE_EVENT_SCOPE_THREAD); 995 TRACE_EVENT_INSTANT0("c4", "name", TRACE_EVENT_SCOPE_THREAD); 996 // Category groups containing more than one category. 997 TRACE_EVENT_INSTANT0("c5,c6", "name", TRACE_EVENT_SCOPE_THREAD); 998 TRACE_EVENT_INSTANT0("c7,c8", "name", TRACE_EVENT_SCOPE_THREAD); 999 TRACE_EVENT_INSTANT0(TRACE_DISABLED_BY_DEFAULT("c9"), "name", 1000 TRACE_EVENT_SCOPE_THREAD); 1001 1002 EndTraceAndFlush(); 1003 std::vector<std::string> cat_groups; 1004 TraceLog::GetInstance()->GetKnownCategoryGroups(&cat_groups); 1005 EXPECT_TRUE(std::find(cat_groups.begin(), 1006 cat_groups.end(), "c1") != cat_groups.end()); 1007 EXPECT_TRUE(std::find(cat_groups.begin(), 1008 cat_groups.end(), "c2") != cat_groups.end()); 1009 EXPECT_TRUE(std::find(cat_groups.begin(), 1010 cat_groups.end(), "c3") != cat_groups.end()); 1011 EXPECT_TRUE(std::find(cat_groups.begin(), 1012 cat_groups.end(), "c4") != cat_groups.end()); 1013 EXPECT_TRUE(std::find(cat_groups.begin(), 1014 cat_groups.end(), "c5,c6") != cat_groups.end()); 1015 EXPECT_TRUE(std::find(cat_groups.begin(), 1016 cat_groups.end(), "c7,c8") != cat_groups.end()); 1017 EXPECT_TRUE(std::find(cat_groups.begin(), 1018 cat_groups.end(), 1019 "disabled-by-default-c9") != cat_groups.end()); 1020 // Make sure metadata isn't returned. 1021 EXPECT_TRUE(std::find(cat_groups.begin(), 1022 cat_groups.end(), "__metadata") == cat_groups.end()); 1023 1024 const std::vector<std::string> empty_categories; 1025 std::vector<std::string> included_categories; 1026 std::vector<std::string> excluded_categories; 1027 1028 // Test that category filtering works. 1029 1030 // Include nonexistent category -> no events 1031 Clear(); 1032 included_categories.clear(); 1033 TraceLog::GetInstance()->SetEnabled(CategoryFilter("not_found823564786"), 1034 TraceLog::RECORD_UNTIL_FULL); 1035 TRACE_EVENT_INSTANT0("cat1", "name", TRACE_EVENT_SCOPE_THREAD); 1036 TRACE_EVENT_INSTANT0("cat2", "name", TRACE_EVENT_SCOPE_THREAD); 1037 EndTraceAndFlush(); 1038 EXPECT_TRUE(trace_parsed_.empty()); 1039 1040 // Include existent category -> only events of that category 1041 Clear(); 1042 included_categories.clear(); 1043 TraceLog::GetInstance()->SetEnabled(CategoryFilter("inc"), 1044 TraceLog::RECORD_UNTIL_FULL); 1045 TRACE_EVENT_INSTANT0("inc", "name", TRACE_EVENT_SCOPE_THREAD); 1046 TRACE_EVENT_INSTANT0("inc2", "name", TRACE_EVENT_SCOPE_THREAD); 1047 EndTraceAndFlush(); 1048 EXPECT_TRUE(FindMatchingValue("cat", "inc")); 1049 EXPECT_FALSE(FindNonMatchingValue("cat", "inc")); 1050 1051 // Include existent wildcard -> all categories matching wildcard 1052 Clear(); 1053 included_categories.clear(); 1054 TraceLog::GetInstance()->SetEnabled( 1055 CategoryFilter("inc_wildcard_*,inc_wildchar_?_end"), 1056 TraceLog::RECORD_UNTIL_FULL); 1057 TRACE_EVENT_INSTANT0("inc_wildcard_abc", "included", 1058 TRACE_EVENT_SCOPE_THREAD); 1059 TRACE_EVENT_INSTANT0("inc_wildcard_", "included", TRACE_EVENT_SCOPE_THREAD); 1060 TRACE_EVENT_INSTANT0("inc_wildchar_x_end", "included", 1061 TRACE_EVENT_SCOPE_THREAD); 1062 TRACE_EVENT_INSTANT0("inc_wildchar_bla_end", "not_inc", 1063 TRACE_EVENT_SCOPE_THREAD); 1064 TRACE_EVENT_INSTANT0("cat1", "not_inc", TRACE_EVENT_SCOPE_THREAD); 1065 TRACE_EVENT_INSTANT0("cat2", "not_inc", TRACE_EVENT_SCOPE_THREAD); 1066 TRACE_EVENT_INSTANT0("inc_wildcard_category,other_category", "included", 1067 TRACE_EVENT_SCOPE_THREAD); 1068 TRACE_EVENT_INSTANT0( 1069 "non_included_category,inc_wildcard_category", "included", 1070 TRACE_EVENT_SCOPE_THREAD); 1071 EndTraceAndFlush(); 1072 EXPECT_TRUE(FindMatchingValue("cat", "inc_wildcard_abc")); 1073 EXPECT_TRUE(FindMatchingValue("cat", "inc_wildcard_")); 1074 EXPECT_TRUE(FindMatchingValue("cat", "inc_wildchar_x_end")); 1075 EXPECT_FALSE(FindMatchingValue("name", "not_inc")); 1076 EXPECT_TRUE(FindMatchingValue("cat", "inc_wildcard_category,other_category")); 1077 EXPECT_TRUE(FindMatchingValue("cat", 1078 "non_included_category,inc_wildcard_category")); 1079 1080 included_categories.clear(); 1081 1082 // Exclude nonexistent category -> all events 1083 Clear(); 1084 TraceLog::GetInstance()->SetEnabled(CategoryFilter("-not_found823564786"), 1085 TraceLog::RECORD_UNTIL_FULL); 1086 TRACE_EVENT_INSTANT0("cat1", "name", TRACE_EVENT_SCOPE_THREAD); 1087 TRACE_EVENT_INSTANT0("cat2", "name", TRACE_EVENT_SCOPE_THREAD); 1088 TRACE_EVENT_INSTANT0("category1,category2", "name", TRACE_EVENT_SCOPE_THREAD); 1089 EndTraceAndFlush(); 1090 EXPECT_TRUE(FindMatchingValue("cat", "cat1")); 1091 EXPECT_TRUE(FindMatchingValue("cat", "cat2")); 1092 EXPECT_TRUE(FindMatchingValue("cat", "category1,category2")); 1093 1094 // Exclude existent category -> only events of other categories 1095 Clear(); 1096 TraceLog::GetInstance()->SetEnabled(CategoryFilter("-inc"), 1097 TraceLog::RECORD_UNTIL_FULL); 1098 TRACE_EVENT_INSTANT0("inc", "name", TRACE_EVENT_SCOPE_THREAD); 1099 TRACE_EVENT_INSTANT0("inc2", "name", TRACE_EVENT_SCOPE_THREAD); 1100 TRACE_EVENT_INSTANT0("inc2,inc", "name", TRACE_EVENT_SCOPE_THREAD); 1101 TRACE_EVENT_INSTANT0("inc,inc2", "name", TRACE_EVENT_SCOPE_THREAD); 1102 EndTraceAndFlush(); 1103 EXPECT_TRUE(FindMatchingValue("cat", "inc2")); 1104 EXPECT_FALSE(FindMatchingValue("cat", "inc")); 1105 EXPECT_FALSE(FindMatchingValue("cat", "inc2,inc")); 1106 EXPECT_FALSE(FindMatchingValue("cat", "inc,inc2")); 1107 1108 // Exclude existent wildcard -> all categories not matching wildcard 1109 Clear(); 1110 TraceLog::GetInstance()->SetEnabled( 1111 CategoryFilter("-inc_wildcard_*,-inc_wildchar_?_end"), 1112 TraceLog::RECORD_UNTIL_FULL); 1113 TRACE_EVENT_INSTANT0("inc_wildcard_abc", "not_inc", 1114 TRACE_EVENT_SCOPE_THREAD); 1115 TRACE_EVENT_INSTANT0("inc_wildcard_", "not_inc", 1116 TRACE_EVENT_SCOPE_THREAD); 1117 TRACE_EVENT_INSTANT0("inc_wildchar_x_end", "not_inc", 1118 TRACE_EVENT_SCOPE_THREAD); 1119 TRACE_EVENT_INSTANT0("inc_wildchar_bla_end", "included", 1120 TRACE_EVENT_SCOPE_THREAD); 1121 TRACE_EVENT_INSTANT0("cat1", "included", TRACE_EVENT_SCOPE_THREAD); 1122 TRACE_EVENT_INSTANT0("cat2", "included", TRACE_EVENT_SCOPE_THREAD); 1123 EndTraceAndFlush(); 1124 EXPECT_TRUE(FindMatchingValue("cat", "inc_wildchar_bla_end")); 1125 EXPECT_TRUE(FindMatchingValue("cat", "cat1")); 1126 EXPECT_TRUE(FindMatchingValue("cat", "cat2")); 1127 EXPECT_FALSE(FindMatchingValue("name", "not_inc")); 1128 } 1129 1130 1131 // Test EVENT_WATCH_NOTIFICATION 1132 TEST_F(TraceEventTestFixture, EventWatchNotification) { 1133 // Basic one occurrence. 1134 BeginTrace(); 1135 TraceLog::GetInstance()->SetWatchEvent("cat", "event"); 1136 TRACE_EVENT_INSTANT0("cat", "event", TRACE_EVENT_SCOPE_THREAD); 1137 EndTraceAndFlush(); 1138 EXPECT_EQ(event_watch_notification_, 1); 1139 1140 // Basic one occurrence before Set. 1141 BeginTrace(); 1142 TRACE_EVENT_INSTANT0("cat", "event", TRACE_EVENT_SCOPE_THREAD); 1143 TraceLog::GetInstance()->SetWatchEvent("cat", "event"); 1144 EndTraceAndFlush(); 1145 EXPECT_EQ(event_watch_notification_, 1); 1146 1147 // Auto-reset after end trace. 1148 BeginTrace(); 1149 TraceLog::GetInstance()->SetWatchEvent("cat", "event"); 1150 EndTraceAndFlush(); 1151 BeginTrace(); 1152 TRACE_EVENT_INSTANT0("cat", "event", TRACE_EVENT_SCOPE_THREAD); 1153 EndTraceAndFlush(); 1154 EXPECT_EQ(event_watch_notification_, 0); 1155 1156 // Multiple occurrence. 1157 BeginTrace(); 1158 int num_occurrences = 5; 1159 TraceLog::GetInstance()->SetWatchEvent("cat", "event"); 1160 for (int i = 0; i < num_occurrences; ++i) 1161 TRACE_EVENT_INSTANT0("cat", "event", TRACE_EVENT_SCOPE_THREAD); 1162 EndTraceAndFlush(); 1163 EXPECT_EQ(event_watch_notification_, num_occurrences); 1164 1165 // Wrong category. 1166 BeginTrace(); 1167 TraceLog::GetInstance()->SetWatchEvent("cat", "event"); 1168 TRACE_EVENT_INSTANT0("wrong_cat", "event", TRACE_EVENT_SCOPE_THREAD); 1169 EndTraceAndFlush(); 1170 EXPECT_EQ(event_watch_notification_, 0); 1171 1172 // Wrong name. 1173 BeginTrace(); 1174 TraceLog::GetInstance()->SetWatchEvent("cat", "event"); 1175 TRACE_EVENT_INSTANT0("cat", "wrong_event", TRACE_EVENT_SCOPE_THREAD); 1176 EndTraceAndFlush(); 1177 EXPECT_EQ(event_watch_notification_, 0); 1178 1179 // Canceled. 1180 BeginTrace(); 1181 TraceLog::GetInstance()->SetWatchEvent("cat", "event"); 1182 TraceLog::GetInstance()->CancelWatchEvent(); 1183 TRACE_EVENT_INSTANT0("cat", "event", TRACE_EVENT_SCOPE_THREAD); 1184 EndTraceAndFlush(); 1185 EXPECT_EQ(event_watch_notification_, 0); 1186 } 1187 1188 // Test ASYNC_BEGIN/END events 1189 TEST_F(TraceEventTestFixture, AsyncBeginEndEvents) { 1190 BeginTrace(); 1191 1192 unsigned long long id = 0xfeedbeeffeedbeefull; 1193 TRACE_EVENT_ASYNC_BEGIN0( "cat", "name1", id); 1194 TRACE_EVENT_ASYNC_STEP0( "cat", "name1", id, "step1"); 1195 TRACE_EVENT_ASYNC_END0("cat", "name1", id); 1196 TRACE_EVENT_BEGIN0( "cat", "name2"); 1197 TRACE_EVENT_ASYNC_BEGIN0( "cat", "name3", 0); 1198 1199 EndTraceAndFlush(); 1200 1201 EXPECT_TRUE(FindNamePhase("name1", "S")); 1202 EXPECT_TRUE(FindNamePhase("name1", "T")); 1203 EXPECT_TRUE(FindNamePhase("name1", "F")); 1204 1205 std::string id_str; 1206 StringAppendF(&id_str, "0x%llx", id); 1207 1208 EXPECT_TRUE(FindNamePhaseKeyValue("name1", "S", "id", id_str.c_str())); 1209 EXPECT_TRUE(FindNamePhaseKeyValue("name1", "T", "id", id_str.c_str())); 1210 EXPECT_TRUE(FindNamePhaseKeyValue("name1", "F", "id", id_str.c_str())); 1211 EXPECT_TRUE(FindNamePhaseKeyValue("name3", "S", "id", "0x0")); 1212 1213 // BEGIN events should not have id 1214 EXPECT_FALSE(FindNamePhaseKeyValue("name2", "B", "id", "0")); 1215 } 1216 1217 // Test ASYNC_BEGIN/END events 1218 TEST_F(TraceEventTestFixture, AsyncBeginEndPointerMangling) { 1219 void* ptr = this; 1220 1221 TraceLog::GetInstance()->SetProcessID(100); 1222 BeginTrace(); 1223 TRACE_EVENT_ASYNC_BEGIN0( "cat", "name1", ptr); 1224 TRACE_EVENT_ASYNC_BEGIN0( "cat", "name2", ptr); 1225 EndTraceAndFlush(); 1226 1227 TraceLog::GetInstance()->SetProcessID(200); 1228 BeginTrace(); 1229 TRACE_EVENT_ASYNC_END0( "cat", "name1", ptr); 1230 EndTraceAndFlush(); 1231 1232 DictionaryValue* async_begin = FindNamePhase("name1", "S"); 1233 DictionaryValue* async_begin2 = FindNamePhase("name2", "S"); 1234 DictionaryValue* async_end = FindNamePhase("name1", "F"); 1235 EXPECT_TRUE(async_begin); 1236 EXPECT_TRUE(async_begin2); 1237 EXPECT_TRUE(async_end); 1238 1239 Value* value = NULL; 1240 std::string async_begin_id_str; 1241 std::string async_begin2_id_str; 1242 std::string async_end_id_str; 1243 ASSERT_TRUE(async_begin->Get("id", &value)); 1244 ASSERT_TRUE(value->GetAsString(&async_begin_id_str)); 1245 ASSERT_TRUE(async_begin2->Get("id", &value)); 1246 ASSERT_TRUE(value->GetAsString(&async_begin2_id_str)); 1247 ASSERT_TRUE(async_end->Get("id", &value)); 1248 ASSERT_TRUE(value->GetAsString(&async_end_id_str)); 1249 1250 EXPECT_STREQ(async_begin_id_str.c_str(), async_begin2_id_str.c_str()); 1251 EXPECT_STRNE(async_begin_id_str.c_str(), async_end_id_str.c_str()); 1252 } 1253 1254 // Test that static strings are not copied. 1255 TEST_F(TraceEventTestFixture, StaticStringVsString) { 1256 TraceLog* tracer = TraceLog::GetInstance(); 1257 // Make sure old events are flushed: 1258 EndTraceAndFlush(); 1259 EXPECT_EQ(0u, tracer->GetEventsSize()); 1260 1261 { 1262 BeginTrace(); 1263 // Test that string arguments are copied. 1264 TRACE_EVENT2("cat", "name1", 1265 "arg1", std::string("argval"), "arg2", std::string("argval")); 1266 // Test that static TRACE_STR_COPY string arguments are copied. 1267 TRACE_EVENT2("cat", "name2", 1268 "arg1", TRACE_STR_COPY("argval"), 1269 "arg2", TRACE_STR_COPY("argval")); 1270 size_t num_events = tracer->GetEventsSize(); 1271 EXPECT_GT(num_events, 1u); 1272 const TraceEvent& event1 = tracer->GetEventAt(num_events - 2); 1273 const TraceEvent& event2 = tracer->GetEventAt(num_events - 1); 1274 EXPECT_STREQ("name1", event1.name()); 1275 EXPECT_STREQ("name2", event2.name()); 1276 EXPECT_TRUE(event1.parameter_copy_storage() != NULL); 1277 EXPECT_TRUE(event2.parameter_copy_storage() != NULL); 1278 EXPECT_GT(event1.parameter_copy_storage()->size(), 0u); 1279 EXPECT_GT(event2.parameter_copy_storage()->size(), 0u); 1280 EndTraceAndFlush(); 1281 } 1282 1283 { 1284 BeginTrace(); 1285 // Test that static literal string arguments are not copied. 1286 TRACE_EVENT2("cat", "name1", 1287 "arg1", "argval", "arg2", "argval"); 1288 // Test that static TRACE_STR_COPY NULL string arguments are not copied. 1289 const char* str1 = NULL; 1290 const char* str2 = NULL; 1291 TRACE_EVENT2("cat", "name2", 1292 "arg1", TRACE_STR_COPY(str1), 1293 "arg2", TRACE_STR_COPY(str2)); 1294 size_t num_events = tracer->GetEventsSize(); 1295 EXPECT_GT(num_events, 1u); 1296 const TraceEvent& event1 = tracer->GetEventAt(num_events - 2); 1297 const TraceEvent& event2 = tracer->GetEventAt(num_events - 1); 1298 EXPECT_STREQ("name1", event1.name()); 1299 EXPECT_STREQ("name2", event2.name()); 1300 EXPECT_TRUE(event1.parameter_copy_storage() == NULL); 1301 EXPECT_TRUE(event2.parameter_copy_storage() == NULL); 1302 EndTraceAndFlush(); 1303 } 1304 } 1305 1306 // Test that data sent from other threads is gathered 1307 TEST_F(TraceEventTestFixture, DataCapturedOnThread) { 1308 BeginTrace(); 1309 1310 Thread thread("1"); 1311 WaitableEvent task_complete_event(false, false); 1312 thread.Start(); 1313 1314 thread.message_loop()->PostTask( 1315 FROM_HERE, base::Bind(&TraceWithAllMacroVariants, &task_complete_event)); 1316 task_complete_event.Wait(); 1317 thread.Stop(); 1318 1319 EndTraceAndFlush(); 1320 ValidateAllTraceMacrosCreatedData(trace_parsed_); 1321 } 1322 1323 // Test that data sent from multiple threads is gathered 1324 TEST_F(TraceEventTestFixture, DataCapturedManyThreads) { 1325 BeginTrace(); 1326 1327 const int num_threads = 4; 1328 const int num_events = 4000; 1329 Thread* threads[num_threads]; 1330 WaitableEvent* task_complete_events[num_threads]; 1331 for (int i = 0; i < num_threads; i++) { 1332 threads[i] = new Thread(StringPrintf("Thread %d", i).c_str()); 1333 task_complete_events[i] = new WaitableEvent(false, false); 1334 threads[i]->Start(); 1335 threads[i]->message_loop()->PostTask( 1336 FROM_HERE, base::Bind(&TraceManyInstantEvents, 1337 i, num_events, task_complete_events[i])); 1338 } 1339 1340 for (int i = 0; i < num_threads; i++) { 1341 task_complete_events[i]->Wait(); 1342 } 1343 1344 for (int i = 0; i < num_threads; i++) { 1345 threads[i]->Stop(); 1346 delete threads[i]; 1347 delete task_complete_events[i]; 1348 } 1349 1350 EndTraceAndFlush(); 1351 1352 ValidateInstantEventPresentOnEveryThread(trace_parsed_, 1353 num_threads, num_events); 1354 } 1355 1356 // Test that thread and process names show up in the trace 1357 TEST_F(TraceEventTestFixture, ThreadNames) { 1358 // Create threads before we enable tracing to make sure 1359 // that tracelog still captures them. 1360 const int num_threads = 4; 1361 const int num_events = 10; 1362 Thread* threads[num_threads]; 1363 PlatformThreadId thread_ids[num_threads]; 1364 for (int i = 0; i < num_threads; i++) 1365 threads[i] = new Thread(StringPrintf("Thread %d", i).c_str()); 1366 1367 // Enable tracing. 1368 BeginTrace(); 1369 1370 // Now run some trace code on these threads. 1371 WaitableEvent* task_complete_events[num_threads]; 1372 for (int i = 0; i < num_threads; i++) { 1373 task_complete_events[i] = new WaitableEvent(false, false); 1374 threads[i]->Start(); 1375 thread_ids[i] = threads[i]->thread_id(); 1376 threads[i]->message_loop()->PostTask( 1377 FROM_HERE, base::Bind(&TraceManyInstantEvents, 1378 i, num_events, task_complete_events[i])); 1379 } 1380 for (int i = 0; i < num_threads; i++) { 1381 task_complete_events[i]->Wait(); 1382 } 1383 1384 // Shut things down. 1385 for (int i = 0; i < num_threads; i++) { 1386 threads[i]->Stop(); 1387 delete threads[i]; 1388 delete task_complete_events[i]; 1389 } 1390 1391 EndTraceAndFlush(); 1392 1393 std::string tmp; 1394 int tmp_int; 1395 const DictionaryValue* item; 1396 1397 // Make sure we get thread name metadata. 1398 // Note, the test suite may have created a ton of threads. 1399 // So, we'll have thread names for threads we didn't create. 1400 std::vector<const DictionaryValue*> items = 1401 FindTraceEntries(trace_parsed_, "thread_name"); 1402 for (int i = 0; i < static_cast<int>(items.size()); i++) { 1403 item = items[i]; 1404 ASSERT_TRUE(item); 1405 EXPECT_TRUE(item->GetInteger("tid", &tmp_int)); 1406 1407 // See if this thread name is one of the threads we just created 1408 for (int j = 0; j < num_threads; j++) { 1409 if(static_cast<int>(thread_ids[j]) != tmp_int) 1410 continue; 1411 1412 std::string expected_name = StringPrintf("Thread %d", j); 1413 EXPECT_TRUE(item->GetString("ph", &tmp) && tmp == "M"); 1414 EXPECT_TRUE(item->GetInteger("pid", &tmp_int) && 1415 tmp_int == static_cast<int>(base::GetCurrentProcId())); 1416 // If the thread name changes or the tid gets reused, the name will be 1417 // a comma-separated list of thread names, so look for a substring. 1418 EXPECT_TRUE(item->GetString("args.name", &tmp) && 1419 tmp.find(expected_name) != std::string::npos); 1420 } 1421 } 1422 } 1423 1424 TEST_F(TraceEventTestFixture, ThreadNameChanges) { 1425 BeginTrace(); 1426 1427 PlatformThread::SetName(""); 1428 TRACE_EVENT_INSTANT0("drink", "water", TRACE_EVENT_SCOPE_THREAD); 1429 1430 PlatformThread::SetName("cafe"); 1431 TRACE_EVENT_INSTANT0("drink", "coffee", TRACE_EVENT_SCOPE_THREAD); 1432 1433 PlatformThread::SetName("shop"); 1434 // No event here, so won't appear in combined name. 1435 1436 PlatformThread::SetName("pub"); 1437 TRACE_EVENT_INSTANT0("drink", "beer", TRACE_EVENT_SCOPE_THREAD); 1438 TRACE_EVENT_INSTANT0("drink", "wine", TRACE_EVENT_SCOPE_THREAD); 1439 1440 PlatformThread::SetName(" bar"); 1441 TRACE_EVENT_INSTANT0("drink", "whisky", TRACE_EVENT_SCOPE_THREAD); 1442 1443 EndTraceAndFlush(); 1444 1445 std::vector<const DictionaryValue*> items = 1446 FindTraceEntries(trace_parsed_, "thread_name"); 1447 EXPECT_EQ(1u, items.size()); 1448 ASSERT_GT(items.size(), 0u); 1449 const DictionaryValue* item = items[0]; 1450 ASSERT_TRUE(item); 1451 int tid; 1452 EXPECT_TRUE(item->GetInteger("tid", &tid)); 1453 EXPECT_EQ(PlatformThread::CurrentId(), static_cast<PlatformThreadId>(tid)); 1454 1455 std::string expected_name = "cafe,pub, bar"; 1456 std::string tmp; 1457 EXPECT_TRUE(item->GetString("args.name", &tmp)); 1458 EXPECT_EQ(expected_name, tmp); 1459 } 1460 1461 // Test that the disabled trace categories are included/excluded from the 1462 // trace output correctly. 1463 TEST_F(TraceEventTestFixture, DisabledCategories) { 1464 BeginTrace(); 1465 TRACE_EVENT_INSTANT0(TRACE_DISABLED_BY_DEFAULT("cc"), "first", 1466 TRACE_EVENT_SCOPE_THREAD); 1467 TRACE_EVENT_INSTANT0("included", "first", TRACE_EVENT_SCOPE_THREAD); 1468 EndTraceAndFlush(); 1469 { 1470 const DictionaryValue* item = NULL; 1471 ListValue& trace_parsed = trace_parsed_; 1472 EXPECT_NOT_FIND_("disabled-by-default-cc"); 1473 EXPECT_FIND_("included"); 1474 } 1475 Clear(); 1476 1477 BeginSpecificTrace("disabled-by-default-cc"); 1478 TRACE_EVENT_INSTANT0(TRACE_DISABLED_BY_DEFAULT("cc"), "second", 1479 TRACE_EVENT_SCOPE_THREAD); 1480 TRACE_EVENT_INSTANT0("other_included", "second", TRACE_EVENT_SCOPE_THREAD); 1481 EndTraceAndFlush(); 1482 1483 { 1484 const DictionaryValue* item = NULL; 1485 ListValue& trace_parsed = trace_parsed_; 1486 EXPECT_FIND_("disabled-by-default-cc"); 1487 EXPECT_FIND_("other_included"); 1488 } 1489 } 1490 1491 TEST_F(TraceEventTestFixture, NormallyNoDeepCopy) { 1492 // Test that the TRACE_EVENT macros do not deep-copy their string. If they 1493 // do so it may indicate a performance regression, but more-over it would 1494 // make the DEEP_COPY overloads redundant. 1495 std::string name_string("event name"); 1496 1497 BeginTrace(); 1498 TRACE_EVENT_INSTANT0("category", name_string.c_str(), 1499 TRACE_EVENT_SCOPE_THREAD); 1500 1501 // Modify the string in place (a wholesale reassignment may leave the old 1502 // string intact on the heap). 1503 name_string[0] = '@'; 1504 1505 EndTraceAndFlush(); 1506 1507 EXPECT_FALSE(FindTraceEntry(trace_parsed_, "event name")); 1508 EXPECT_TRUE(FindTraceEntry(trace_parsed_, name_string.c_str())); 1509 } 1510 1511 TEST_F(TraceEventTestFixture, DeepCopy) { 1512 static const char kOriginalName1[] = "name1"; 1513 static const char kOriginalName2[] = "name2"; 1514 static const char kOriginalName3[] = "name3"; 1515 std::string name1(kOriginalName1); 1516 std::string name2(kOriginalName2); 1517 std::string name3(kOriginalName3); 1518 std::string arg1("arg1"); 1519 std::string arg2("arg2"); 1520 std::string val1("val1"); 1521 std::string val2("val2"); 1522 1523 BeginTrace(); 1524 TRACE_EVENT_COPY_INSTANT0("category", name1.c_str(), 1525 TRACE_EVENT_SCOPE_THREAD); 1526 TRACE_EVENT_COPY_BEGIN1("category", name2.c_str(), 1527 arg1.c_str(), 5); 1528 TRACE_EVENT_COPY_END2("category", name3.c_str(), 1529 arg1.c_str(), val1, 1530 arg2.c_str(), val2); 1531 1532 // As per NormallyNoDeepCopy, modify the strings in place. 1533 name1[0] = name2[0] = name3[0] = arg1[0] = arg2[0] = val1[0] = val2[0] = '@'; 1534 1535 EndTraceAndFlush(); 1536 1537 EXPECT_FALSE(FindTraceEntry(trace_parsed_, name1.c_str())); 1538 EXPECT_FALSE(FindTraceEntry(trace_parsed_, name2.c_str())); 1539 EXPECT_FALSE(FindTraceEntry(trace_parsed_, name3.c_str())); 1540 1541 const DictionaryValue* entry1 = FindTraceEntry(trace_parsed_, kOriginalName1); 1542 const DictionaryValue* entry2 = FindTraceEntry(trace_parsed_, kOriginalName2); 1543 const DictionaryValue* entry3 = FindTraceEntry(trace_parsed_, kOriginalName3); 1544 ASSERT_TRUE(entry1); 1545 ASSERT_TRUE(entry2); 1546 ASSERT_TRUE(entry3); 1547 1548 int i; 1549 EXPECT_FALSE(entry2->GetInteger("args.@rg1", &i)); 1550 EXPECT_TRUE(entry2->GetInteger("args.arg1", &i)); 1551 EXPECT_EQ(5, i); 1552 1553 std::string s; 1554 EXPECT_TRUE(entry3->GetString("args.arg1", &s)); 1555 EXPECT_EQ("val1", s); 1556 EXPECT_TRUE(entry3->GetString("args.arg2", &s)); 1557 EXPECT_EQ("val2", s); 1558 } 1559 1560 // Test that TraceResultBuffer outputs the correct result whether it is added 1561 // in chunks or added all at once. 1562 TEST_F(TraceEventTestFixture, TraceResultBuffer) { 1563 Clear(); 1564 1565 trace_buffer_.Start(); 1566 trace_buffer_.AddFragment("bla1"); 1567 trace_buffer_.AddFragment("bla2"); 1568 trace_buffer_.AddFragment("bla3,bla4"); 1569 trace_buffer_.Finish(); 1570 EXPECT_STREQ(json_output_.json_output.c_str(), "[bla1,bla2,bla3,bla4]"); 1571 1572 Clear(); 1573 1574 trace_buffer_.Start(); 1575 trace_buffer_.AddFragment("bla1,bla2,bla3,bla4"); 1576 trace_buffer_.Finish(); 1577 EXPECT_STREQ(json_output_.json_output.c_str(), "[bla1,bla2,bla3,bla4]"); 1578 } 1579 1580 // Test that trace_event parameters are not evaluated if the tracing 1581 // system is disabled. 1582 TEST_F(TraceEventTestFixture, TracingIsLazy) { 1583 BeginTrace(); 1584 1585 int a = 0; 1586 TRACE_EVENT_INSTANT1("category", "test", TRACE_EVENT_SCOPE_THREAD, "a", a++); 1587 EXPECT_EQ(1, a); 1588 1589 TraceLog::GetInstance()->SetDisabled(); 1590 1591 TRACE_EVENT_INSTANT1("category", "test", TRACE_EVENT_SCOPE_THREAD, "a", a++); 1592 EXPECT_EQ(1, a); 1593 1594 EndTraceAndFlush(); 1595 } 1596 1597 TEST_F(TraceEventTestFixture, TraceEnableDisable) { 1598 TraceLog* trace_log = TraceLog::GetInstance(); 1599 CategoryFilter cf_inc_all("*"); 1600 trace_log->SetEnabled(cf_inc_all, TraceLog::RECORD_UNTIL_FULL); 1601 EXPECT_TRUE(trace_log->IsEnabled()); 1602 trace_log->SetDisabled(); 1603 EXPECT_FALSE(trace_log->IsEnabled()); 1604 1605 trace_log->SetEnabled(cf_inc_all, TraceLog::RECORD_UNTIL_FULL); 1606 EXPECT_TRUE(trace_log->IsEnabled()); 1607 const std::vector<std::string> empty; 1608 trace_log->SetEnabled(CategoryFilter(""), TraceLog::RECORD_UNTIL_FULL); 1609 EXPECT_TRUE(trace_log->IsEnabled()); 1610 trace_log->SetDisabled(); 1611 EXPECT_TRUE(trace_log->IsEnabled()); 1612 trace_log->SetDisabled(); 1613 EXPECT_FALSE(trace_log->IsEnabled()); 1614 } 1615 1616 TEST_F(TraceEventTestFixture, TraceCategoriesAfterNestedEnable) { 1617 TraceLog* trace_log = TraceLog::GetInstance(); 1618 trace_log->SetEnabled(CategoryFilter("foo,bar"), TraceLog::RECORD_UNTIL_FULL); 1619 EXPECT_TRUE(*trace_log->GetCategoryGroupEnabled("foo")); 1620 EXPECT_TRUE(*trace_log->GetCategoryGroupEnabled("bar")); 1621 EXPECT_FALSE(*trace_log->GetCategoryGroupEnabled("baz")); 1622 trace_log->SetEnabled(CategoryFilter("foo2"), TraceLog::RECORD_UNTIL_FULL); 1623 EXPECT_TRUE(*trace_log->GetCategoryGroupEnabled("foo2")); 1624 EXPECT_FALSE(*trace_log->GetCategoryGroupEnabled("baz")); 1625 // The "" becomes the default catergory set when applied. 1626 trace_log->SetEnabled(CategoryFilter(""), TraceLog::RECORD_UNTIL_FULL); 1627 EXPECT_TRUE(*trace_log->GetCategoryGroupEnabled("foo")); 1628 EXPECT_TRUE(*trace_log->GetCategoryGroupEnabled("baz")); 1629 EXPECT_STREQ("-*Debug,-*Test", 1630 trace_log->GetCurrentCategoryFilter().ToString().c_str()); 1631 trace_log->SetDisabled(); 1632 trace_log->SetDisabled(); 1633 trace_log->SetDisabled(); 1634 EXPECT_FALSE(*trace_log->GetCategoryGroupEnabled("foo")); 1635 EXPECT_FALSE(*trace_log->GetCategoryGroupEnabled("baz")); 1636 1637 trace_log->SetEnabled(CategoryFilter("-foo,-bar"), 1638 TraceLog::RECORD_UNTIL_FULL); 1639 EXPECT_FALSE(*trace_log->GetCategoryGroupEnabled("foo")); 1640 EXPECT_TRUE(*trace_log->GetCategoryGroupEnabled("baz")); 1641 trace_log->SetEnabled(CategoryFilter("moo"), TraceLog::RECORD_UNTIL_FULL); 1642 EXPECT_TRUE(*trace_log->GetCategoryGroupEnabled("baz")); 1643 EXPECT_TRUE(*trace_log->GetCategoryGroupEnabled("moo")); 1644 EXPECT_FALSE(*trace_log->GetCategoryGroupEnabled("foo")); 1645 EXPECT_STREQ("-foo,-bar", 1646 trace_log->GetCurrentCategoryFilter().ToString().c_str()); 1647 trace_log->SetDisabled(); 1648 trace_log->SetDisabled(); 1649 1650 // Make sure disabled categories aren't cleared if we set in the second. 1651 trace_log->SetEnabled(CategoryFilter("disabled-by-default-cc,foo"), 1652 TraceLog::RECORD_UNTIL_FULL); 1653 EXPECT_FALSE(*trace_log->GetCategoryGroupEnabled("bar")); 1654 trace_log->SetEnabled(CategoryFilter("disabled-by-default-gpu"), 1655 TraceLog::RECORD_UNTIL_FULL); 1656 EXPECT_TRUE(*trace_log->GetCategoryGroupEnabled("disabled-by-default-cc")); 1657 EXPECT_TRUE(*trace_log->GetCategoryGroupEnabled("disabled-by-default-gpu")); 1658 EXPECT_TRUE(*trace_log->GetCategoryGroupEnabled("bar")); 1659 EXPECT_STREQ("disabled-by-default-cc,disabled-by-default-gpu", 1660 trace_log->GetCurrentCategoryFilter().ToString().c_str()); 1661 trace_log->SetDisabled(); 1662 trace_log->SetDisabled(); 1663 } 1664 1665 TEST_F(TraceEventTestFixture, TraceOptionsParsing) { 1666 EXPECT_EQ(TraceLog::RECORD_UNTIL_FULL, 1667 TraceLog::TraceOptionsFromString(std::string())); 1668 1669 EXPECT_EQ(TraceLog::RECORD_UNTIL_FULL, 1670 TraceLog::TraceOptionsFromString("record-until-full")); 1671 EXPECT_EQ(TraceLog::RECORD_CONTINUOUSLY, 1672 TraceLog::TraceOptionsFromString("record-continuously")); 1673 EXPECT_EQ(TraceLog::RECORD_UNTIL_FULL | TraceLog::ENABLE_SAMPLING, 1674 TraceLog::TraceOptionsFromString("enable-sampling")); 1675 EXPECT_EQ(TraceLog::RECORD_CONTINUOUSLY | TraceLog::ENABLE_SAMPLING, 1676 TraceLog::TraceOptionsFromString( 1677 "record-continuously,enable-sampling")); 1678 } 1679 1680 TEST_F(TraceEventTestFixture, TraceSampling) { 1681 event_watch_notification_ = 0; 1682 TraceLog::GetInstance()->SetEnabled( 1683 CategoryFilter("*"), 1684 TraceLog::Options(TraceLog::RECORD_UNTIL_FULL | 1685 TraceLog::ENABLE_SAMPLING)); 1686 1687 WaitableEvent* sampled = new WaitableEvent(false, false); 1688 TraceLog::GetInstance()->InstallWaitableEventForSamplingTesting(sampled); 1689 1690 TRACE_EVENT_SET_SAMPLING_STATE_FOR_BUCKET(1, "cc", "Stuff"); 1691 sampled->Wait(); 1692 TRACE_EVENT_SET_SAMPLING_STATE_FOR_BUCKET(1, "cc", "Things"); 1693 sampled->Wait(); 1694 1695 EndTraceAndFlush(); 1696 1697 // Make sure we hit at least once. 1698 EXPECT_TRUE(FindNamePhase("Stuff", "P")); 1699 EXPECT_TRUE(FindNamePhase("Things", "P")); 1700 } 1701 1702 TEST_F(TraceEventTestFixture, TraceSamplingScope) { 1703 event_watch_notification_ = 0; 1704 TraceLog::GetInstance()->SetEnabled( 1705 CategoryFilter("*"), 1706 TraceLog::Options(TraceLog::RECORD_UNTIL_FULL | 1707 TraceLog::ENABLE_SAMPLING)); 1708 1709 WaitableEvent* sampled = new WaitableEvent(false, false); 1710 TraceLog::GetInstance()->InstallWaitableEventForSamplingTesting(sampled); 1711 1712 TRACE_EVENT_SCOPED_SAMPLING_STATE("AAA", "name"); 1713 sampled->Wait(); 1714 { 1715 EXPECT_STREQ(TRACE_EVENT_GET_SAMPLING_STATE(), "AAA"); 1716 TRACE_EVENT_SCOPED_SAMPLING_STATE("BBB", "name"); 1717 sampled->Wait(); 1718 EXPECT_STREQ(TRACE_EVENT_GET_SAMPLING_STATE(), "BBB"); 1719 } 1720 sampled->Wait(); 1721 { 1722 EXPECT_STREQ(TRACE_EVENT_GET_SAMPLING_STATE(), "AAA"); 1723 TRACE_EVENT_SCOPED_SAMPLING_STATE("CCC", "name"); 1724 sampled->Wait(); 1725 EXPECT_STREQ(TRACE_EVENT_GET_SAMPLING_STATE(), "CCC"); 1726 } 1727 sampled->Wait(); 1728 { 1729 EXPECT_STREQ(TRACE_EVENT_GET_SAMPLING_STATE(), "AAA"); 1730 TRACE_EVENT_SET_SAMPLING_STATE("DDD", "name"); 1731 sampled->Wait(); 1732 EXPECT_STREQ(TRACE_EVENT_GET_SAMPLING_STATE(), "DDD"); 1733 } 1734 sampled->Wait(); 1735 EXPECT_STREQ(TRACE_EVENT_GET_SAMPLING_STATE(), "DDD"); 1736 1737 EndTraceAndFlush(); 1738 } 1739 1740 class MyData : public base::debug::ConvertableToTraceFormat { 1741 public: 1742 MyData() {} 1743 virtual ~MyData() {} 1744 1745 virtual void AppendAsTraceFormat(std::string* out) const OVERRIDE { 1746 out->append("{\"foo\":1}"); 1747 } 1748 1749 private: 1750 DISALLOW_COPY_AND_ASSIGN(MyData); 1751 }; 1752 1753 TEST_F(TraceEventTestFixture, ConvertableTypes) { 1754 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"), 1755 TraceLog::RECORD_UNTIL_FULL); 1756 1757 scoped_ptr<MyData> data(new MyData()); 1758 scoped_ptr<MyData> data1(new MyData()); 1759 scoped_ptr<MyData> data2(new MyData()); 1760 TRACE_EVENT1("foo", "bar", "data", 1761 data.PassAs<base::debug::ConvertableToTraceFormat>()); 1762 TRACE_EVENT2("foo", "baz", 1763 "data1", data1.PassAs<base::debug::ConvertableToTraceFormat>(), 1764 "data2", data2.PassAs<base::debug::ConvertableToTraceFormat>()); 1765 1766 1767 scoped_ptr<MyData> convertData1(new MyData()); 1768 scoped_ptr<MyData> convertData2(new MyData()); 1769 TRACE_EVENT2( 1770 "foo", 1771 "string_first", 1772 "str", 1773 "string value 1", 1774 "convert", 1775 convertData1.PassAs<base::debug::ConvertableToTraceFormat>()); 1776 TRACE_EVENT2( 1777 "foo", 1778 "string_second", 1779 "convert", 1780 convertData2.PassAs<base::debug::ConvertableToTraceFormat>(), 1781 "str", 1782 "string value 2"); 1783 EndTraceAndFlush(); 1784 1785 // One arg version. 1786 DictionaryValue* dict = FindNamePhase("bar", "B"); 1787 ASSERT_TRUE(dict); 1788 1789 const DictionaryValue* args_dict = NULL; 1790 dict->GetDictionary("args", &args_dict); 1791 ASSERT_TRUE(args_dict); 1792 1793 const Value* value = NULL; 1794 const DictionaryValue* convertable_dict = NULL; 1795 EXPECT_TRUE(args_dict->Get("data", &value)); 1796 ASSERT_TRUE(value->GetAsDictionary(&convertable_dict)); 1797 1798 int foo_val; 1799 EXPECT_TRUE(convertable_dict->GetInteger("foo", &foo_val)); 1800 EXPECT_EQ(1, foo_val); 1801 1802 // Two arg version. 1803 dict = FindNamePhase("baz", "B"); 1804 ASSERT_TRUE(dict); 1805 1806 args_dict = NULL; 1807 dict->GetDictionary("args", &args_dict); 1808 ASSERT_TRUE(args_dict); 1809 1810 value = NULL; 1811 convertable_dict = NULL; 1812 EXPECT_TRUE(args_dict->Get("data1", &value)); 1813 ASSERT_TRUE(value->GetAsDictionary(&convertable_dict)); 1814 1815 value = NULL; 1816 convertable_dict = NULL; 1817 EXPECT_TRUE(args_dict->Get("data2", &value)); 1818 ASSERT_TRUE(value->GetAsDictionary(&convertable_dict)); 1819 1820 // Convertable with other types. 1821 dict = FindNamePhase("string_first", "B"); 1822 ASSERT_TRUE(dict); 1823 1824 args_dict = NULL; 1825 dict->GetDictionary("args", &args_dict); 1826 ASSERT_TRUE(args_dict); 1827 1828 std::string str_value; 1829 EXPECT_TRUE(args_dict->GetString("str", &str_value)); 1830 EXPECT_STREQ("string value 1", str_value.c_str()); 1831 1832 value = NULL; 1833 convertable_dict = NULL; 1834 foo_val = 0; 1835 EXPECT_TRUE(args_dict->Get("convert", &value)); 1836 ASSERT_TRUE(value->GetAsDictionary(&convertable_dict)); 1837 EXPECT_TRUE(convertable_dict->GetInteger("foo", &foo_val)); 1838 EXPECT_EQ(1, foo_val); 1839 1840 dict = FindNamePhase("string_second", "B"); 1841 ASSERT_TRUE(dict); 1842 1843 args_dict = NULL; 1844 dict->GetDictionary("args", &args_dict); 1845 ASSERT_TRUE(args_dict); 1846 1847 EXPECT_TRUE(args_dict->GetString("str", &str_value)); 1848 EXPECT_STREQ("string value 2", str_value.c_str()); 1849 1850 value = NULL; 1851 convertable_dict = NULL; 1852 foo_val = 0; 1853 EXPECT_TRUE(args_dict->Get("convert", &value)); 1854 ASSERT_TRUE(value->GetAsDictionary(&convertable_dict)); 1855 EXPECT_TRUE(convertable_dict->GetInteger("foo", &foo_val)); 1856 EXPECT_EQ(1, foo_val); 1857 } 1858 1859 class TraceEventCallbackTest : public TraceEventTestFixture { 1860 public: 1861 virtual void SetUp() OVERRIDE { 1862 TraceEventTestFixture::SetUp(); 1863 ASSERT_EQ(NULL, s_instance); 1864 s_instance = this; 1865 } 1866 virtual void TearDown() OVERRIDE { 1867 while (TraceLog::GetInstance()->IsEnabled()) 1868 TraceLog::GetInstance()->SetDisabled(); 1869 ASSERT_TRUE(!!s_instance); 1870 s_instance = NULL; 1871 TraceEventTestFixture::TearDown(); 1872 } 1873 1874 protected: 1875 std::vector<std::string> collected_events_; 1876 1877 static TraceEventCallbackTest* s_instance; 1878 static void Callback(char phase, 1879 const unsigned char* category_enabled, 1880 const char* name, 1881 unsigned long long id, 1882 int num_args, 1883 const char* const arg_names[], 1884 const unsigned char arg_types[], 1885 const unsigned long long arg_values[], 1886 unsigned char flags) { 1887 s_instance->collected_events_.push_back(name); 1888 } 1889 }; 1890 1891 TraceEventCallbackTest* TraceEventCallbackTest::s_instance; 1892 1893 TEST_F(TraceEventCallbackTest, TraceEventCallback) { 1894 TRACE_EVENT_INSTANT0("all", "before enable", TRACE_EVENT_SCOPE_THREAD); 1895 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"), 1896 TraceLog::RECORD_UNTIL_FULL); 1897 TRACE_EVENT_INSTANT0("all", "before callback set", TRACE_EVENT_SCOPE_THREAD); 1898 TraceLog::GetInstance()->SetEventCallback(Callback); 1899 TRACE_EVENT_INSTANT0("all", "event1", TRACE_EVENT_SCOPE_GLOBAL); 1900 TRACE_EVENT_INSTANT0("all", "event2", TRACE_EVENT_SCOPE_GLOBAL); 1901 TraceLog::GetInstance()->SetEventCallback(NULL); 1902 TRACE_EVENT_INSTANT0("all", "after callback removed", 1903 TRACE_EVENT_SCOPE_GLOBAL); 1904 ASSERT_EQ(2u, collected_events_.size()); 1905 EXPECT_EQ("event1", collected_events_[0]); 1906 EXPECT_EQ("event2", collected_events_[1]); 1907 } 1908 1909 TEST_F(TraceEventCallbackTest, TraceEventCallbackWhileFull) { 1910 TraceLog::GetInstance()->SetEnabled(CategoryFilter("*"), 1911 TraceLog::RECORD_UNTIL_FULL); 1912 do { 1913 TRACE_EVENT_INSTANT0("all", "badger badger", TRACE_EVENT_SCOPE_GLOBAL); 1914 } while ((notifications_received_ & TraceLog::TRACE_BUFFER_FULL) == 0); 1915 TraceLog::GetInstance()->SetEventCallback(Callback); 1916 TRACE_EVENT_INSTANT0("all", "a snake", TRACE_EVENT_SCOPE_GLOBAL); 1917 TraceLog::GetInstance()->SetEventCallback(NULL); 1918 ASSERT_EQ(1u, collected_events_.size()); 1919 EXPECT_EQ("a snake", collected_events_[0]); 1920 } 1921 1922 // TODO(dsinclair): Continuous Tracing unit test. 1923 1924 // Test the category filter. 1925 TEST_F(TraceEventTestFixture, CategoryFilter) { 1926 // Using the default filter. 1927 CategoryFilter default_cf = CategoryFilter( 1928 CategoryFilter::kDefaultCategoryFilterString); 1929 std::string category_filter_str = default_cf.ToString(); 1930 EXPECT_STREQ("-*Debug,-*Test", category_filter_str.c_str()); 1931 EXPECT_TRUE(default_cf.IsCategoryGroupEnabled("not-excluded-category")); 1932 EXPECT_FALSE( 1933 default_cf.IsCategoryGroupEnabled("disabled-by-default-category")); 1934 EXPECT_FALSE(default_cf.IsCategoryGroupEnabled("Category1,CategoryDebug")); 1935 EXPECT_FALSE(default_cf.IsCategoryGroupEnabled("CategoryDebug,Category1")); 1936 EXPECT_FALSE(default_cf.IsCategoryGroupEnabled("CategoryTest,Category2")); 1937 1938 // Make sure that upon an empty string, we fall back to the default filter. 1939 default_cf = CategoryFilter(""); 1940 category_filter_str = default_cf.ToString(); 1941 EXPECT_STREQ("-*Debug,-*Test", category_filter_str.c_str()); 1942 EXPECT_TRUE(default_cf.IsCategoryGroupEnabled("not-excluded-category")); 1943 EXPECT_FALSE(default_cf.IsCategoryGroupEnabled("Category1,CategoryDebug")); 1944 EXPECT_FALSE(default_cf.IsCategoryGroupEnabled("CategoryDebug,Category1")); 1945 EXPECT_FALSE(default_cf.IsCategoryGroupEnabled("CategoryTest,Category2")); 1946 1947 // Using an arbitrary non-empty filter. 1948 CategoryFilter cf("included,-excluded,inc_pattern*,-exc_pattern*"); 1949 category_filter_str = cf.ToString(); 1950 EXPECT_STREQ("included,inc_pattern*,-excluded,-exc_pattern*", 1951 category_filter_str.c_str()); 1952 EXPECT_TRUE(cf.IsCategoryGroupEnabled("included")); 1953 EXPECT_TRUE(cf.IsCategoryGroupEnabled("inc_pattern_category")); 1954 EXPECT_FALSE(cf.IsCategoryGroupEnabled("exc_pattern_category")); 1955 EXPECT_FALSE(cf.IsCategoryGroupEnabled("excluded")); 1956 EXPECT_FALSE(cf.IsCategoryGroupEnabled("not-excluded-nor-included")); 1957 EXPECT_FALSE(cf.IsCategoryGroupEnabled("Category1,CategoryDebug")); 1958 EXPECT_FALSE(cf.IsCategoryGroupEnabled("CategoryDebug,Category1")); 1959 EXPECT_FALSE(cf.IsCategoryGroupEnabled("CategoryTest,Category2")); 1960 1961 cf.Merge(default_cf); 1962 category_filter_str = cf.ToString(); 1963 EXPECT_STREQ("-excluded,-exc_pattern*,-*Debug,-*Test", 1964 category_filter_str.c_str()); 1965 cf.Clear(); 1966 1967 CategoryFilter reconstructed_cf(category_filter_str); 1968 category_filter_str = reconstructed_cf.ToString(); 1969 EXPECT_STREQ("-excluded,-exc_pattern*,-*Debug,-*Test", 1970 category_filter_str.c_str()); 1971 1972 // One included category. 1973 CategoryFilter one_inc_cf("only_inc_cat"); 1974 category_filter_str = one_inc_cf.ToString(); 1975 EXPECT_STREQ("only_inc_cat", category_filter_str.c_str()); 1976 1977 // One excluded category. 1978 CategoryFilter one_exc_cf("-only_exc_cat"); 1979 category_filter_str = one_exc_cf.ToString(); 1980 EXPECT_STREQ("-only_exc_cat", category_filter_str.c_str()); 1981 1982 // Enabling a disabled- category does not require all categories to be traced 1983 // to be included. 1984 CategoryFilter disabled_cat("disabled-by-default-cc,-excluded"); 1985 EXPECT_STREQ("disabled-by-default-cc,-excluded", 1986 disabled_cat.ToString().c_str()); 1987 EXPECT_TRUE(disabled_cat.IsCategoryGroupEnabled("disabled-by-default-cc")); 1988 EXPECT_TRUE(disabled_cat.IsCategoryGroupEnabled("some_other_group")); 1989 EXPECT_FALSE(disabled_cat.IsCategoryGroupEnabled("excluded")); 1990 1991 // Enabled a disabled- category and also including makes all categories to 1992 // be traced require including. 1993 CategoryFilter disabled_inc_cat("disabled-by-default-cc,included"); 1994 EXPECT_STREQ("included,disabled-by-default-cc", 1995 disabled_inc_cat.ToString().c_str()); 1996 EXPECT_TRUE( 1997 disabled_inc_cat.IsCategoryGroupEnabled("disabled-by-default-cc")); 1998 EXPECT_TRUE(disabled_inc_cat.IsCategoryGroupEnabled("included")); 1999 EXPECT_FALSE(disabled_inc_cat.IsCategoryGroupEnabled("other_included")); 2000 2001 // Test that IsEmptyOrContainsLeadingOrTrailingWhitespace actually catches 2002 // categories that are explicitly forbiden. 2003 // This method is called in a DCHECK to assert that we don't have these types 2004 // of strings as categories. 2005 EXPECT_TRUE(CategoryFilter::IsEmptyOrContainsLeadingOrTrailingWhitespace( 2006 " bad_category ")); 2007 EXPECT_TRUE(CategoryFilter::IsEmptyOrContainsLeadingOrTrailingWhitespace( 2008 " bad_category")); 2009 EXPECT_TRUE(CategoryFilter::IsEmptyOrContainsLeadingOrTrailingWhitespace( 2010 "bad_category ")); 2011 EXPECT_TRUE(CategoryFilter::IsEmptyOrContainsLeadingOrTrailingWhitespace( 2012 " bad_category")); 2013 EXPECT_TRUE(CategoryFilter::IsEmptyOrContainsLeadingOrTrailingWhitespace( 2014 "bad_category ")); 2015 EXPECT_TRUE(CategoryFilter::IsEmptyOrContainsLeadingOrTrailingWhitespace( 2016 " bad_category ")); 2017 EXPECT_TRUE(CategoryFilter::IsEmptyOrContainsLeadingOrTrailingWhitespace( 2018 "")); 2019 EXPECT_FALSE(CategoryFilter::IsEmptyOrContainsLeadingOrTrailingWhitespace( 2020 "good_category")); 2021 } 2022 2023 } // namespace debug 2024 } // namespace base 2025