tracing: split trace event filter classes out of TraceLog

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>
@@ skipping 14 matching lines @@
 #include "base/strings/string_split.h"
 #include "base/strings/string_tokenizer.h"
 #include "base/strings/stringprintf.h"
 #include "base/sys_info.h"
 #include "base/threading/platform_thread.h"
 #include "base/threading/thread_id_name_manager.h"
 #include "base/threading/thread_task_runner_handle.h"
 #include "base/threading/worker_pool.h"
 #include "base/time/time.h"
 #include "base/trace_event/category_registry.h"
+#include "base/trace_event/event_name_filter.h"
 #include "base/trace_event/heap_profiler.h"
 #include "base/trace_event/heap_profiler_allocation_context_tracker.h"
+#include "base/trace_event/heap_profiler_event_filter.h"
 #include "base/trace_event/memory_dump_manager.h"
 #include "base/trace_event/memory_dump_provider.h"
 #include "base/trace_event/process_memory_dump.h"
 #include "base/trace_event/trace_buffer.h"
 #include "base/trace_event/trace_event.h"
 #include "base/trace_event/trace_event_synthetic_delay.h"
 #include "build/build_config.h"
 
 #if defined(OS_WIN)
 #include "base/trace_event/trace_event_etw_export_win.h"
@@ skipping 30 matching lines @@
     kTraceEventVectorBufferChunks <= TraceBufferChunk::kMaxChunkIndex,
     "Too many vector buffer chunks");
 const size_t kTraceEventRingBufferChunks = kTraceEventVectorBufferChunks / 4;
 
 // ECHO_TO_CONSOLE needs a small buffer to hold the unfinished COMPLETE events.
 const size_t kEchoToConsoleTraceEventBufferChunks = 256;
 
 const size_t kTraceEventBufferSizeInBytes = 100 * 1024;
 const int kThreadFlushTimeoutMs = 3000;
 
-const char kEventNameWhitelist[] = "event_name_whitelist";
-
 #define MAX_TRACE_EVENT_FILTERS 32
 
 // List of TraceEventFilter objects from the most recent tracing session.
-base::LazyInstance<std::vector<std::unique_ptr<TraceLog::TraceEventFilter>>>::
-    Leaky g_category_group_filters = LAZY_INSTANCE_INITIALIZER;
-
-class EventNameFilter : public TraceLog::TraceEventFilter {
- public:
-  EventNameFilter(const base::DictionaryValue* filter_args) {
-    const base::ListValue* whitelist = nullptr;
-    if (filter_args->GetList(kEventNameWhitelist, &whitelist)) {
-      for (size_t i = 0; i < whitelist->GetSize(); ++i) {
-        std::string event_name;
-        if (!whitelist->GetString(i, &event_name))
-          continue;
-
-        whitelist_.insert(event_name);
-      }
-    }
-  }
-
-  bool FilterTraceEvent(const TraceEvent& trace_event) const override {
-    return ContainsKey(whitelist_, trace_event.name());
-  }
-
- private:
-  std::unordered_set<std::string> whitelist_;
-};
-
-// This filter is used to record trace events as pseudo stack for the heap
-// profiler. It does not filter-out any events from the trace, ie. the behavior
-// of trace events being added to TraceLog remains same: the events are added
-// iff enabled for recording and not filtered-out by any other filter.
-class HeapProfilerFilter : public TraceLog::TraceEventFilter {
- public:
-  HeapProfilerFilter() {}
-
-  bool FilterTraceEvent(const TraceEvent& trace_event) const override {
-    if (AllocationContextTracker::capture_mode() !=
-        AllocationContextTracker::CaptureMode::PSEUDO_STACK) {
-      return true;
-    }
-
-    // TODO(primiano): Add support for events with copied name crbug.com/581079.
-    if (trace_event.flags() & TRACE_EVENT_FLAG_COPY)
-      return true;
-
-    const char* category_name =
-        TraceLog::GetCategoryGroupName(trace_event.category_group_enabled());
-    if (trace_event.phase() == TRACE_EVENT_PHASE_BEGIN ||
-        trace_event.phase() == TRACE_EVENT_PHASE_COMPLETE) {
-      AllocationContextTracker::GetInstanceForCurrentThread()
-          ->PushPseudoStackFrame({category_name, trace_event.name()});
-    } else if (trace_event.phase() == TRACE_EVENT_PHASE_END) {
-      // The pop for |TRACE_EVENT_PHASE_COMPLETE| events is in |EndEvent|.
-      AllocationContextTracker::GetInstanceForCurrentThread()
-          ->PopPseudoStackFrame({category_name, trace_event.name()});
-    }
-    // Do not filter-out any events and always return true. TraceLog adds the
-    // event only if it is enabled for recording.
-    return true;
-  }
-
-  void EndEvent(const char* name, const char* category_group) override {
-    if (AllocationContextTracker::capture_mode() ==
-        AllocationContextTracker::CaptureMode::PSEUDO_STACK) {
-      AllocationContextTracker::GetInstanceForCurrentThread()
-          ->PopPseudoStackFrame({category_group, name});
-    }
-  }
-};
-
-TraceLog::TraceEventFilterConstructorForTesting
-    g_trace_event_filter_constructor_for_testing = nullptr;
+base::LazyInstance<std::vector<std::unique_ptr<TraceEventFilter>>>::Leaky
+    g_category_group_filters = LAZY_INSTANCE_INITIALIZER;
 
 // 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
 // output name for the thread.
 LazyInstance<ThreadLocalPointer<const char>>::Leaky g_current_thread_name =
     LAZY_INSTANCE_INITIALIZER;
 
 ThreadTicks ThreadNow() {
   return ThreadTicks::IsSupported() ? ThreadTicks::Now() : ThreadTicks();
 }
@@ skipping 52 matching lines @@
   DCHECK(chunk_seq);
   DCHECK(chunk_index <= TraceBufferChunk::kMaxChunkIndex);
   DCHECK(event_index < TraceBufferChunk::kTraceBufferChunkSize);
   DCHECK(chunk_index <= std::numeric_limits<uint16_t>::max());
   handle->chunk_seq = chunk_seq;
   handle->chunk_index = static_cast<uint16_t>(chunk_index);
   handle->event_index = static_cast<uint16_t>(event_index);
 }
 
 template <typename Function>
-void ForEachCategoryGroupFilter(const unsigned char* category_group_enabled,
-                                Function filter_fn) {
-  const TraceCategory* category =
-      CategoryRegistry::GetCategoryByStatePtr(category_group_enabled);
-  uint32_t filter_bitmap = category->enabled_filters();
-  int index = 0;
-  while (filter_bitmap) {
+void ForEachCategoryFilter(const unsigned char* category_group_enabled,
+                           Function filter_fn) {
+  auto* cat = CategoryRegistry::GetCategoryByStatePtr(category_group_enabled);
+  uint32_t filter_bitmap = cat->enabled_filters();

[oystein (OOO til 10th of July), 2016/12/08 20:40:20]

nit: Not convinced auto and the abbreviation makes this any more readable than
the additional line in the previous version :).

[Primiano Tucci (use gerrit), 2016/12/09 11:50:09]

alright undid the auto+cat

+  for (int index = 0; filter_bitmap != 0; filter_bitmap >>= 1, index++) {
     if (filter_bitmap & 1 && g_category_group_filters.Get()[index])
       filter_fn(g_category_group_filters.Get()[index].get());
-    filter_bitmap = filter_bitmap >> 1;
-    index++;
   }
 }
 
 }  // namespace
 
 // A helper class that allows the lock to be acquired in the middle of the scope
 // and unlocks at the end of scope if locked.
 class TraceLog::OptionalAutoLock {
  public:
   explicit OptionalAutoLock(Lock* lock) : lock_(lock), locked_(false) {}
@@ skipping 166 matching lines @@
     : enabled_modes_(0),
       num_traces_recorded_(0),
       dispatching_to_observer_list_(false),
       process_sort_index_(0),
       process_id_hash_(0),
       process_id_(0),
       trace_options_(kInternalRecordUntilFull),
       trace_config_(TraceConfig()),
       thread_shared_chunk_index_(0),
       generation_(0),
-      use_worker_thread_(false) {
+      use_worker_thread_(false),
+      filter_factory_for_testing_(nullptr) {
   CategoryRegistry::Initialize();
 
 #if defined(OS_NACL)  // NaCl shouldn't expose the process id.
   SetProcessID(0);
 #else
   SetProcessID(static_cast<int>(GetCurrentProcId()));
 #endif
 
   logged_events_.reset(CreateTraceBuffer());
 
@@ skipping 66 matching lines @@
   return category->state_ptr();
 }
 
 const char* TraceLog::GetCategoryGroupName(
     const unsigned char* category_group_enabled) {
   return CategoryRegistry::GetCategoryByStatePtr(category_group_enabled)
       ->name();
 }
 
 void TraceLog::UpdateCategoryState(TraceCategory* category) {
+  lock_.AssertAcquired();
   DCHECK(category->is_valid());
   unsigned char state_flags = 0;
   if (enabled_modes_ & RECORDING_MODE &&
       trace_config_.IsCategoryGroupEnabled(category->name())) {
     state_flags |= TraceCategory::ENABLED_FOR_RECORDING;
   }
 
   // TODO(primiano): this is a temporary workaround for catapult:#2341,
   // to guarantee that metadata events are always added even if the category
   // filter is "-*". See crbug.com/618054 for more details and long-term fix.
@@ skipping 20 matching lines @@
     if (index++ >= MAX_TRACE_EVENT_FILTERS) {
       NOTREACHED();
       break;
     }
   }
   category->set_enabled_filters(enabled_filters_bitmap);
   category->set_state(state_flags);
 }
 
 void TraceLog::UpdateCategoryRegistry() {
+  lock_.AssertAcquired();
   CreateFiltersForTraceConfig();
   for (TraceCategory& category : CategoryRegistry::GetAllCategories()) {
     UpdateCategoryState(&category);
   }
 }
 
 void TraceLog::CreateFiltersForTraceConfig() {
   if (!(enabled_modes_ & FILTERING_MODE))
     return;
 
   // Filters were already added and tracing could be enabled. Filters list
   // cannot be changed when trace events are using them.
   if (g_category_group_filters.Get().size())
     return;
 
-  for (auto& event_filter : enabled_event_filters_) {
+  for (auto& filter_config : enabled_event_filters_) {
     if (g_category_group_filters.Get().size() >= MAX_TRACE_EVENT_FILTERS) {
       NOTREACHED()
           << "Too many trace event filters installed in the current session";
       break;
     }
 
     std::unique_ptr<TraceEventFilter> new_filter;
-    if (event_filter.predicate_name() ==
-        TraceEventFilter::kEventWhitelistPredicate) {
-      new_filter = MakeUnique<EventNameFilter>(event_filter.filter_args());
-    } else if (event_filter.predicate_name() ==
-               TraceEventFilter::kHeapProfilerPredicate) {
-      new_filter = MakeUnique<HeapProfilerFilter>();
-    } else if (event_filter.predicate_name() == "testing_predicate") {
-      CHECK(g_trace_event_filter_constructor_for_testing);
-      new_filter = g_trace_event_filter_constructor_for_testing();
+    const std::string predicate_name = filter_config.predicate_name();

[oystein (OOO til 10th of July), 2016/12/08 20:40:20]

reference

[Primiano Tucci (use gerrit), 2016/12/09 11:50:10]

Oops. well spotted, thanks.

+    if (predicate_name == EventNameFilter::kName) {
+      auto whitelist = MakeUnique<std::unordered_set<std::string>>();
+      const ListValue* list = nullptr;
+      if (filter_config.filter_args()->GetList("event_name_whitelist", &list)) {

[oystein (OOO til 10th of July), 2016/12/08 20:40:20]

Hrm. I get why you're doing this, but maybe it'd be slightly less smelly to move
this (the config parsing) to within TraceConfig instead? e.g.
TraceConfig::ConfigureFilter(EventNameFilter&) or something.

[Primiano Tucci (use gerrit), 2016/12/09 11:50:10]

I don't like too much coupling all that into TraceConfig. The main problem with
that is that we'd end up in a state where TraceLog knows about *most* of the
strings of the filter configs, but TraceConfig knows about
"event_name_whitelist", which would be inconsistent.
However I agree that all this code here hurts readability.

I added a more generic bool GetArgAsSet(const char* key,
std::unordered_set<std::string>*) method to TraceConfig::EventFilterConfig.
This still allows me to move all the code there as you proposed, but I can keep
the "event_name_whitelist" in the tracelog and still get rid of all this code
here.

+        for (size_t i = 0; i < list->GetSize(); ++i) {
+          std::string event_name;
+          if (list->GetString(i, &event_name))
+            whitelist->insert(event_name);
+        }
+      }
+      new_filter = MakeUnique<EventNameFilter>(std::move(whitelist));
+    } else if (predicate_name == HeapProfilerEventFilter::kName) {
+      new_filter = MakeUnique<HeapProfilerEventFilter>();
     } else {
-      NOTREACHED();
+      if (filter_factory_for_testing_)
+        new_filter = filter_factory_for_testing_(predicate_name);
+      CHECK(new_filter) << "Unknown trace filter " << predicate_name;
     }
     g_category_group_filters.Get().push_back(std::move(new_filter));
   }
 }
 
 void TraceLog::UpdateSyntheticDelaysFromTraceConfig() {
   ResetTraceEventSyntheticDelays();
   const TraceConfig::StringList& delays =
       trace_config_.GetSyntheticDelayValues();
   TraceConfig::StringList::const_iterator ci;
@@ skipping 181 matching lines @@
     return;
   }
 
   bool is_recording_mode_disabled =
       (enabled_modes_ & RECORDING_MODE) && (modes_to_disable & RECORDING_MODE);
   enabled_modes_ &= ~modes_to_disable;
 
   if (modes_to_disable & FILTERING_MODE)
     enabled_event_filters_.clear();
 
-  if (modes_to_disable & RECORDING_MODE) {
+  if (modes_to_disable & RECORDING_MODE)
     trace_config_.Clear();
-  }
 
   UpdateCategoryRegistry();
 
   // Add metadata events and notify observers only if recording mode was
   // disabled now.
   if (!is_recording_mode_disabled)
     return;
 
   AddMetadataEventsWhileLocked();
 
@@ skipping 524 matching lines @@
   std::unique_ptr<TraceEvent> filtered_trace_event;
   bool disabled_by_filters = false;
   if (*category_group_enabled & TraceCategory::ENABLED_FOR_FILTERING) {
     std::unique_ptr<TraceEvent> new_trace_event(new TraceEvent);
     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);
 
     disabled_by_filters = true;
-    ForEachCategoryGroupFilter(
+    ForEachCategoryFilter(
         category_group_enabled, [&new_trace_event, &disabled_by_filters](
                                     TraceEventFilter* trace_event_filter) {
           if (trace_event_filter->FilterTraceEvent(*new_trace_event))
             disabled_by_filters = false;
         });
     if (!disabled_by_filters)
       filtered_trace_event = std::move(new_trace_event);
   }
 
   // If enabled for recording, the event should be added only if one of the
@@ skipping 109 matching lines @@
   if (phase == TRACE_EVENT_PHASE_BEGIN)
     thread_event_start_times_[thread_id].push(timestamp);
 
   return log.str();
 }
 
 void TraceLog::EndFilteredEvent(const unsigned char* category_group_enabled,
                                 const char* name,
                                 TraceEventHandle handle) {
   const char* category_name = GetCategoryGroupName(category_group_enabled);
-  ForEachCategoryGroupFilter(
+  ForEachCategoryFilter(
       category_group_enabled,
       [name, category_name](TraceEventFilter* trace_event_filter) {
-        trace_event_filter->EndEvent(name, category_name);
+        trace_event_filter->EndEvent(category_name, name);
       });
 }
 
 void TraceLog::UpdateTraceEventDuration(
     const unsigned char* category_group_enabled,
     const char* name,
     TraceEventHandle handle) {
   char category_group_enabled_local = *category_group_enabled;
   if (!category_group_enabled_local)
     return;
@@ skipping 120 matching lines @@
                             "overflowed_at_ts",
                             buffer_limit_reached_timestamp_);
   }
 }
 
 void TraceLog::DeleteForTesting() {
   internal::DeleteTraceLogForTesting::Delete();
   CategoryRegistry::ResetForTesting();
 }
 
-void TraceLog::SetTraceEventFilterConstructorForTesting(
-    TraceEventFilterConstructorForTesting predicate) {
-  g_trace_event_filter_constructor_for_testing = predicate;
-}
-
 TraceEvent* TraceLog::GetEventByHandle(TraceEventHandle handle) {
   return GetEventByHandleInternal(handle, NULL);
 }
 
 TraceEvent* TraceLog::GetEventByHandleInternal(TraceEventHandle handle,
                                                OptionalAutoLock* lock) {
   if (!handle.chunk_seq)
     return NULL;
 
   DCHECK(handle.chunk_seq);
@@ skipping 167 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