Configure synthetic delays through TraceLog

base/debug/trace_event_impl.cc

 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "base/debug/trace_event_impl.h"
 
 #include <algorithm>
 
 #include "base/base_switches.h"
 #include "base/bind.h"
 #include "base/command_line.h"
 #include "base/debug/leak_annotations.h"
 #include "base/debug/trace_event.h"
+#include "base/debug/trace_event_synthetic_delay.h"
 #include "base/format_macros.h"
 #include "base/json/string_escape.h"
 #include "base/lazy_instance.h"
 #include "base/memory/singleton.h"
 #include "base/message_loop/message_loop.h"
 #include "base/process/process_metrics.h"
 #include "base/stl_util.h"
 #include "base/strings/string_number_conversions.h"
 #include "base/strings/string_split.h"
 #include "base/strings/string_tokenizer.h"
@@ skipping 41 matching lines @@
 // Can store results for 30 seconds with 1 ms sampling interval.
 const size_t kMonitorTraceEventBufferChunks = 30000 / kTraceBufferChunkSize;
 // ECHO_TO_CONSOLE needs a small buffer to hold the unfinished COMPLETE events.
 const size_t kEchoToConsoleTraceEventBufferChunks = 256;
 
 const int kThreadFlushTimeoutMs = 3000;
 
 // These categories will cause deadlock when ECHO_TO_CONSOLE. crbug.com/325575.
 const char kEchoToConsoleCategoryFilter[] = "-ipc,-task";
 
+const char kSyntheticDelayCategoryFilterPrefix[] = "DELAY(";
+
 #define MAX_CATEGORY_GROUPS 100
 
 // Parallel arrays g_category_groups and g_category_group_enabled are separate
 // so that a pointer to a member of g_category_group_enabled can be easily
 // converted to an index into g_category_groups. This allows macros to deal
 // only with char enabled pointers from g_category_group_enabled, and we can
 // convert internally to determine the category name from the char enabled
 // pointer.
 const char* g_category_groups[MAX_CATEGORY_GROUPS] = {
   "tracing already shutdown",
@@ skipping 1117 matching lines @@
       event_callback_category_filter_.IsCategoryGroupEnabled(category_group))
     enabled_flag |= ENABLED_FOR_EVENT_CALLBACK;
   g_category_group_enabled[category_index] = enabled_flag;
 }
 
 void TraceLog::UpdateCategoryGroupEnabledFlags() {
   for (int i = 0; i < g_category_index; i++)
     UpdateCategoryGroupEnabledFlag(i);
 }
 
+void TraceLog::UpdateSyntheticDelaysFromCategoryFilter() {
+  ResetTraceEventSyntheticDelays();
+  const CategoryFilter::DelayValueList& delays =
+      category_filter_.GetSyntheticDelayValues();
+  CategoryFilter::DelayValueList::const_iterator ci;
+  for (ci = delays.begin(); ci != delays.end(); ++ci) {
+    TraceEventSyntheticDelay* delay =
+        TraceEventSyntheticDelay::Lookup(ci->first);
+    StringTokenizer tokens(ci->second, ";");
+    while (tokens.GetNext()) {
+      double target_duration;
+      if (StringToDouble(tokens.token(), &target_duration)) {
+        delay->SetTargetDuration(
+            TimeDelta::FromMicroseconds(target_duration * 1e6));
+      } else if (tokens.token() == "static") {
+        delay->SetMode(TraceEventSyntheticDelay::STATIC);
+      } else if (tokens.token() == "oneshot") {
+        delay->SetMode(TraceEventSyntheticDelay::ONE_SHOT);
+      } else if (tokens.token() == "alternating") {
+        delay->SetMode(TraceEventSyntheticDelay::ALTERNATING);
+      }
+    }
+  }
+}
+
 const unsigned char* TraceLog::GetCategoryGroupEnabledInternal(
     const char* category_group) {
   DCHECK(!strchr(category_group, '"')) <<
       "Category groups may not contain double quote";
   AutoLock lock(lock_);
 
   unsigned char* category_group_enabled = NULL;
   // Search for pre-existing category group.
   for (int i = 0; i < g_category_index; i++) {
     if (strcmp(g_category_groups[i], category_group) == 0) {
@@ skipping 74 matching lines @@
 
     if (options != old_options) {
       subtle::NoBarrier_Store(&trace_options_, options);
       UseNextTraceBuffer();
     }
 
     num_traces_recorded_++;
 
     category_filter_ = CategoryFilter(category_filter);
     UpdateCategoryGroupEnabledFlags();
+    UpdateSyntheticDelaysFromCategoryFilter();
 
     if (options & ENABLE_SAMPLING) {
       sampling_thread_.reset(new TraceSamplingThread);
       sampling_thread_->RegisterSampleBucket(
           &g_trace_state[0],
           "bucket0",
           Bind(&TraceSamplingThread::DefaultSamplingCallback));
       sampling_thread_->RegisterSampleBucket(
           &g_trace_state[1],
           "bucket1",
@@ skipping 853 matching lines @@
 CategoryFilter::CategoryFilter(const std::string& filter_string) {
   if (!filter_string.empty())
     Initialize(filter_string);
   else
     Initialize(CategoryFilter::kDefaultCategoryFilterString);
 }
 
 CategoryFilter::CategoryFilter(const CategoryFilter& cf)
     : included_(cf.included_),
       disabled_(cf.disabled_),
-      excluded_(cf.excluded_) {
+      excluded_(cf.excluded_),
+      delays_(cf.delays_) {
 }
 
 CategoryFilter::~CategoryFilter() {
 }
 
 CategoryFilter& CategoryFilter::operator=(const CategoryFilter& rhs) {
   if (this == &rhs)
     return *this;
 
   included_ = rhs.included_;
   disabled_ = rhs.disabled_;
   excluded_ = rhs.excluded_;
+  delays_ = rhs.delays_;
   return *this;
 }
 
 void CategoryFilter::Initialize(const std::string& filter_string) {
   // Tokenize list of categories, delimited by ','.
   StringTokenizer tokens(filter_string, ",");
   // Add each token to the appropriate list (included_,excluded_).
   while (tokens.GetNext()) {
     std::string category = tokens.token();
     // Ignore empty categories.
     if (category.empty())
       continue;
-    // Excluded categories start with '-'.
-    if (category.at(0) == '-') {
+    // Synthetic delays are of the form 'DELAY(delay;option;option;...)'.
+    if (category.find(kSyntheticDelayCategoryFilterPrefix) == 0 &&
+        category.at(category.size() - 1) == ')') {
+      category = category.substr(
+          strlen(kSyntheticDelayCategoryFilterPrefix),
+          category.size() - strlen(kSyntheticDelayCategoryFilterPrefix) - 1);
+      size_t name_length = category.find(';');
+      if (name_length != std::string::npos && name_length > 0 &&
+          name_length != category.size() - 1) {
+        delays_.push_back(DelayValue(category.substr(0, name_length),
+                                     category.substr(name_length + 1)));
+      }
+    } else if (category.at(0) == '-') {
+      // Excluded categories start with '-'.
       // Remove '-' from category string.
       category = category.substr(1);
       excluded_.push_back(category);
     } else if (category.compare(0, strlen(TRACE_DISABLED_BY_DEFAULT("")),
                                 TRACE_DISABLED_BY_DEFAULT("")) == 0) {
       disabled_.push_back(category);
     } else {
       included_.push_back(category);
     }
   }
 }
 
 void CategoryFilter::WriteString(const StringList& values,
                                  std::string* out,
                                  bool included) const {
   bool prepend_comma = !out->empty();
   int token_cnt = 0;
   for (StringList::const_iterator ci = values.begin();
        ci != values.end(); ++ci) {
     if (token_cnt > 0 || prepend_comma)
       StringAppendF(out, ",");
     StringAppendF(out, "%s%s", (included ? "" : "-"), ci->c_str());
     ++token_cnt;
   }
 }
 
+void CategoryFilter::WriteString(const DelayValueList& delays,
+                                 std::string* out) const {
+  bool prepend_comma = !out->empty();
+  int token_cnt = 0;
+  for (DelayValueList::const_iterator ci = delays.begin();
+       ci != delays.end(); ++ci) {
+    if (token_cnt > 0 || prepend_comma)
+      StringAppendF(out, ",");
+    StringAppendF(out, "%s%s;%s)", kSyntheticDelayCategoryFilterPrefix,
+                  ci->first.c_str(), ci->second.c_str());
+    ++token_cnt;
+  }
+}
+
 std::string CategoryFilter::ToString() const {
   std::string filter_string;
   WriteString(included_, &filter_string, true);
   WriteString(disabled_, &filter_string, true);
   WriteString(excluded_, &filter_string, false);
+  WriteString(delays_, &filter_string);
   return filter_string;
 }
 
 bool CategoryFilter::IsCategoryGroupEnabled(
     const char* category_group_name) const {
   // TraceLog should call this method only as  part of enabling/disabling
   // categories.
   StringList::const_iterator ci;
 
   // Check the disabled- filters and the disabled-* wildcard first so that a
@@ skipping 35 matching lines @@
   } else {
     included_.clear();
   }
 
   disabled_.insert(disabled_.end(),
                    nested_filter.disabled_.begin(),
                    nested_filter.disabled_.end());
   excluded_.insert(excluded_.end(),
                    nested_filter.excluded_.begin(),
                    nested_filter.excluded_.end());
+  delays_.insert(delays_.end(),
+                 nested_filter.delays_.begin(),
+                 nested_filter.delays_.end());
 }
 
 void CategoryFilter::Clear() {
   included_.clear();
   disabled_.clear();
   excluded_.clear();
 }
 
+const CategoryFilter::DelayValueList&
+    CategoryFilter::GetSyntheticDelayValues() const {
+  return delays_;
+}
+
 }  // namespace debug
 }  // namespace base
 
 namespace trace_event_internal {
 
 ScopedTraceBinaryEfficient::ScopedTraceBinaryEfficient(
     const char* category_group, const char* name) {
   // The single atom works because for now the category_group can only be "gpu".
   DCHECK(strcmp(category_group, "gpu") == 0);
   static TRACE_EVENT_API_ATOMIC_WORD atomic = 0;
@@ skipping 12 matching lines @@
 }
 
 ScopedTraceBinaryEfficient::~ScopedTraceBinaryEfficient() {
   if (*category_group_enabled_) {
     TRACE_EVENT_API_UPDATE_TRACE_EVENT_DURATION(category_group_enabled_,
                                                 name_, event_handle_);
   }
 }
 
 }  // namespace trace_event_internal