Tracing pre-filtering

base/trace_event/trace_log.cc

 // Copyright 2015 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/trace_event/trace_log.h"
 
 #include <algorithm>
 #include <cmath>
 #include <memory>
 #include <utility>
 
 #include "base/base_switches.h"
 #include "base/bind.h"
 #include "base/command_line.h"
 #include "base/debug/leak_annotations.h"
 #include "base/lazy_instance.h"
 #include "base/location.h"
 #include "base/macros.h"
+#include "base/memory/ptr_util.h"
 #include "base/memory/ref_counted_memory.h"
 #include "base/memory/singleton.h"
 #include "base/process/process_metrics.h"
 #include "base/stl_util.h"
 #include "base/strings/string_split.h"
 #include "base/strings/string_tokenizer.h"
 #include "base/strings/stringprintf.h"
 #include "base/sys_info.h"
 #include "base/third_party/dynamic_annotations/dynamic_annotations.h"
 #include "base/thread_task_runner_handle.h"
@@ skipping 66 matching lines @@
 // convert internally to determine the category name from the char enabled
 // pointer.
 const char* g_category_groups[MAX_CATEGORY_GROUPS] = {
     "toplevel",
     "tracing already shutdown",
     "tracing categories exhausted; must increase MAX_CATEGORY_GROUPS",
     "__metadata"};
 
 // The enabled flag is char instead of bool so that the API can be used from C.
 unsigned char g_category_group_enabled[MAX_CATEGORY_GROUPS] = {0};
+
+class TraceEventFilter {
+ public:
+  TraceEventFilter() {}

[Primiano Tucci (use gerrit), 2016/05/11 16:11:57]

I think you need a virtual dtor here (and override in the EventNameFilter).
Otherwise I believe you might end up leaking the whitelist_ below when you
clear() the list.

[oystein (OOO til 10th of July), 2016/05/20 20:03:44]

Done.

+  virtual bool FilterTraceEvent(const TraceEvent& trace_event) const = 0;
+
+ private:
+  DISALLOW_COPY_AND_ASSIGN(TraceEventFilter);
+};
+
+class EventNameFilter : public TraceEventFilter {
+ public:
+  EventNameFilter(const base::DictionaryValue* filter_args) {
+    const base::ListValue* whitelist = nullptr;
+    if (filter_args->GetList("event_name_whitelist", &whitelist)) {
+      for (size_t i = 0; i < whitelist->GetSize(); ++i) {
+        std::string event_name;
+        if (!whitelist->GetString(i, &event_name))
+          continue;
+
+        whitelist_[event_name] = true;
+      }
+    }
+  }
+
+  bool FilterTraceEvent(const TraceEvent& trace_event) const override {
+    return (whitelist_.find(trace_event.name()) != whitelist_.end());

[Primiano Tucci (use gerrit), 2016/05/11 16:11:57]

either .count(...) != 0 or ContainsKey from base/std_util.h (which does exactly
this)

[oystein (OOO til 10th of July), 2016/05/20 20:03:44]

Done.

+  }
+
+ private:
+  std::unordered_map<std::string, bool> whitelist_;

[Primiano Tucci (use gerrit), 2016/05/11 16:11:57]

Not sure what the bool is for, you seem to always set to true? This smells like
an unordererd_set

[oystein (OOO til 10th of July), 2016/05/20 20:03:44]

Done.

+};
+
+base::LazyInstance<std::list<std::unique_ptr<TraceEventFilter>>>::Leaky
+    g_category_group_filter[MAX_CATEGORY_GROUPS] = {LAZY_INSTANCE_INITIALIZER};
+
 // Indexes here have to match the g_category_groups array indexes above.
 const int g_category_already_shutdown = 1;
 const int g_category_categories_exhausted = 2;
 const int g_category_metadata = 3;
 const int g_num_builtin_categories = 4;
 // Skip default categories.
 base::subtle::AtomicWord g_category_index = g_num_builtin_categories;
 
 // The name of the current thread. This is used to decide if the current
 // thread name has changed. We combine all the seen thread names into the
@@ skipping 312 matching lines @@
 const unsigned char* TraceLog::GetCategoryGroupEnabled(
     const char* category_group) {
   TraceLog* tracelog = GetInstance();
   if (!tracelog) {
     DCHECK(!g_category_group_enabled[g_category_already_shutdown]);
     return &g_category_group_enabled[g_category_already_shutdown];
   }
   return tracelog->GetCategoryGroupEnabledInternal(category_group);
 }
 
-const char* TraceLog::GetCategoryGroupName(
-    const unsigned char* category_group_enabled) {
+namespace {
+uintptr_t GetCategoryIndex(const unsigned char* category_group_enabled) {

[Primiano Tucci (use gerrit), 2016/05/11 16:11:57]

should this be moved to the anonymous namespace above, instead of having an
anonymous namespace in the middle (not strongly on this honestly, I just wonder
if there is precedence for having an anonymous namespace in the middle to
improve flow readability)

[oystein (OOO til 10th of July), 2016/05/20 20:03:44]

Ah, done; added it in the middle for expensive while poking at it, forgot to
move after :).

   // Calculate the index of the category group by finding
   // category_group_enabled in g_category_group_enabled array.
   uintptr_t category_begin =
       reinterpret_cast<uintptr_t>(g_category_group_enabled);
   uintptr_t category_ptr = reinterpret_cast<uintptr_t>(category_group_enabled);
   DCHECK(category_ptr >= category_begin &&
          category_ptr < reinterpret_cast<uintptr_t>(g_category_group_enabled +
                                                     MAX_CATEGORY_GROUPS))
       << "out of bounds category pointer";
   uintptr_t category_index =
       (category_ptr - category_begin) / sizeof(g_category_group_enabled[0]);
-  return g_category_groups[category_index];
+
+  return category_index;
+}
+}
+
+const char* TraceLog::GetCategoryGroupName(
+    const unsigned char* category_group_enabled) {
+  return g_category_groups[GetCategoryIndex(category_group_enabled)];
+}
+
+std::list<std::unique_ptr<TraceEventFilter>>* GetCategoryGroupFilter(
+    const unsigned char* category_group_enabled) {
+  return g_category_group_filter[GetCategoryIndex(category_group_enabled)]
+      .Pointer();
 }
 
 void TraceLog::UpdateCategoryGroupEnabledFlag(size_t category_index) {
   unsigned char enabled_flag = 0;
   const char* category_group = g_category_groups[category_index];
   if (mode_ == RECORDING_MODE &&
       trace_config_.IsCategoryGroupEnabled(category_group)) {
     enabled_flag |= ENABLED_FOR_RECORDING;
   }
 
   if (event_callback_ &&
       event_callback_trace_config_.IsCategoryGroupEnabled(category_group)) {
     enabled_flag |= ENABLED_FOR_EVENT_CALLBACK;
   }
 
 #if defined(OS_WIN)
   if (base::trace_event::TraceEventETWExport::IsCategoryGroupEnabled(
           category_group)) {
     enabled_flag |= ENABLED_FOR_ETW_EXPORT;
   }
 #endif
 
+  if (!(g_category_group_filter[category_index] == nullptr))

[Primiano Tucci (use gerrit), 2016/05/11 16:11:57]

Isn't a bit more readable if here you cache once the std::list<>*, i'.e.

auto& filters_list = g_category_group_filter[category_index].Get();
filters_list.clear();  // I assume it's a very quick noop if the list is empty.

for  .....

  filters_list.push_back

From a performance viewpoint, that will limit the acquire_load performed by
LazyInstance to one (as opposite to one per loop iteration, as th ecode here)

[oystein (OOO til 10th of July), 2016/05/20 20:03:44]

My idea was to avoid the Get() (and hence the LazyInstance initialization) in
the by-far most common case, i.e. no filter present. It should be rare that we
have multiple predicates handling a category, too. We can always revisit this if
usage changes.

+    g_category_group_filter[category_index].Get().clear();
+
+  for (const auto& category_event_filter :
+      trace_config_.category_event_filters()) {
+    if (category_event_filter.IsCategoryGroupEnabled(category_group)) {
+      std::unique_ptr<TraceEventFilter> new_filter;
+
+      if (category_event_filter.predicate_name() ==
+          "event_whitelist_predicate") {
+        new_filter =
+            WrapUnique(new EventNameFilter(category_event_filter.args()));
+      }
+
+      if (new_filter) {
+        g_category_group_filter[category_index].Get().push_back(
+            std::move(new_filter));
+        enabled_flag |= ENABLED_FOR_FILTERING;
+      }
+    }
+  }
+
   g_category_group_enabled[category_index] = enabled_flag;
 }
 
 void TraceLog::UpdateCategoryGroupEnabledFlags() {
   size_t category_index = base::subtle::NoBarrier_Load(&g_category_index);
   for (size_t i = 0; i < category_index; i++)
     UpdateCategoryGroupEnabledFlag(i);
 }
 
 void TraceLog::UpdateSyntheticDelaysFromTraceConfig() {
@@ skipping 757 matching lines @@
 #if defined(OS_WIN)
   // This is done sooner rather than later, to avoid creating the event and
   // acquiring the lock, which is not needed for ETW as it's already threadsafe.
   if (*category_group_enabled & ENABLED_FOR_ETW_EXPORT)
     TraceEventETWExport::AddEvent(phase, category_group_enabled, name, id,
                                   num_args, arg_names, arg_types, arg_values,
                                   convertable_values);
 #endif  // OS_WIN
 
   std::string console_message;
-  if (*category_group_enabled & ENABLED_FOR_RECORDING) {
+  if (*category_group_enabled & ENABLED_FOR_FILTERING) {
+    std::unique_ptr<TraceEvent> new_trace_event(new TraceEvent);

[oystein (OOO til 10th of July), 2016/05/04 23:20:44]

TODO: Figure out a way to keep this on the stack instead, combined with the
unique_ptr semantics that TraceEvent::MoveFrom uses.

+    new_trace_event->Initialize(thread_id, offset_event_timestamp, thread_now,
+                                phase, category_group_enabled, name, scope, id,
+                                bind_id, num_args, arg_names, arg_types,
+                                arg_values, convertable_values, flags);
+
+    std::list<std::unique_ptr<TraceEventFilter>>* filter_list =

[Primiano Tucci (use gerrit), 2016/05/11 16:11:58]

maybe that's a good case for auto? :)

[oystein (OOO til 10th of July), 2016/05/20 20:03:44]

Done.

+        GetCategoryGroupFilter(category_group_enabled);
+    DCHECK(filter_list);

[Primiano Tucci (use gerrit), 2016/05/11 16:11:57]

I think the policy in chrome is to not DCHECK for nullptr if you are going to
dereference the thing in the same scope. rationale: It will segfault anyways.
I'd keep only the 2nd dcheck

[oystein (OOO til 10th of July), 2016/05/20 20:03:44]

Done.

+    DCHECK(!filter_list->empty());
+
+    bool should_add_event = false;
+    for (const auto& trace_event_filter : *filter_list) {
+      DCHECK(trace_event_filter);

[Primiano Tucci (use gerrit), 2016/05/11 16:11:57]

ditto here, remove this dcheck

[oystein (OOO til 10th of July), 2016/05/20 20:03:44]

Done.

+      if (trace_event_filter.get()->FilterTraceEvent(*new_trace_event))
+        should_add_event = true;
+    }
+
+    if (should_add_event) {
+      OptionalAutoLock lock(&lock_);
+
+      TraceEvent* trace_event = NULL;
+      if (thread_local_event_buffer) {
+        trace_event = thread_local_event_buffer->AddTraceEvent(&handle);
+      } else {
+        lock.EnsureAcquired();

[Primiano Tucci (use gerrit), 2016/05/11 16:11:57]

Instead of copy-pasting this logic here, which is almost identical to the
ENABLED_FOR_RECORDING part below, can we instead here do the following?

std::unique_ptr<TraceEvent> filtered_trace_event;  //nullptr
if (ENABLED_FOR_FILTERING) {
  filtered_trace_event.reset(, thid, offset, bla bla)
  foreach ...
     FilterTraceEvent(filtered_trace_event)
}
if (ENABLED_FOR_RECORDING || filtered_trace_event) {
  if (thread_local)
    ...
  else
    ...
  if (filtered_trace_event)
    trace_event->MoveFrom(filtered_trace_event)
}

does it make sense?

[oystein (OOO til 10th of July), 2016/05/20 20:03:44]

Done; it's a little awkward to handle all the cases, but at least there's no
duplicated code now.

+        trace_event = AddEventToThreadSharedChunkWhileLocked(&handle, true);
+      }
+
+      trace_event->MoveFrom(std::move(new_trace_event));
+    }
+  } else if (*category_group_enabled & ENABLED_FOR_RECORDING) {
     OptionalAutoLock lock(&lock_);
 
     TraceEvent* trace_event = NULL;
     if (thread_local_event_buffer) {
       trace_event = thread_local_event_buffer->AddTraceEvent(&handle);
     } else {
       lock.EnsureAcquired();
       trace_event = AddEventToThreadSharedChunkWhileLocked(&handle, true);
     }
 
@@ skipping 481 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