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