base/debug/trace_event_unittest.cc

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