tracing: simplify lifetime of TraceEventFilter(s)

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_filter_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"
@@ skipping 34 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;
 
-#define MAX_TRACE_EVENT_FILTERS 32
-
-// List of TraceEventFilter objects from the most recent tracing session.
-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 57 matching lines @@
   handle->event_index = static_cast<uint16_t>(event_index);
 }
 
 template <typename Function>
 void ForEachCategoryFilter(const unsigned char* category_group_enabled,
                            Function filter_fn) {
   const TraceCategory* category =
       CategoryRegistry::GetCategoryByStatePtr(category_group_enabled);
   uint32_t filter_bitmap = category->enabled_filters();
   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());
+    if (filter_bitmap & 1)
+      filter_fn(EventFilterRegistry::Get(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 278 matching lines @@
   }
 
 #if defined(OS_WIN)
   if (base::trace_event::TraceEventETWExport::IsCategoryGroupEnabled(
           category->name())) {
     state_flags |= TraceCategory::ENABLED_FOR_ETW_EXPORT;
   }
 #endif
 
   uint32_t enabled_filters_bitmap = 0;
-  int index = 0;
-  for (const auto& event_filter : enabled_event_filters_) {
-    if (event_filter.IsCategoryGroupEnabled(category->name())) {
+  for (auto it = EventFilterRegistry::GetActiveFilters(); it.IsValid();
+       it.MoveNext()) {
+    if (it->IsEnabledForCategory(category->name())) {
       state_flags |= TraceCategory::ENABLED_FOR_FILTERING;
-      DCHECK(g_category_group_filters.Get()[index]);
-      enabled_filters_bitmap |= 1 << index;
-    }
-    if (index++ >= MAX_TRACE_EVENT_FILTERS) {
-      NOTREACHED();
-      break;
+      enabled_filters_bitmap |= 1ul << it.GetIndex();
     }
   }
   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;
+void TraceLog::CreateFiltersAndUpdateFilterRegistry() {
+  // At this point all existing filters should have been unregistered.
+  DCHECK(!EventFilterRegistry::GetActiveFilters().IsValid());
 
-  // 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& 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;
-    }
-
+  for (const auto& filter_config : trace_config_.event_filters()) {
+    // Create a copy of the filter config and pass it to the newly created
+    // filter instance. This allows to check whether a given category should
+    // be filtered without having to keep additional state here in the TraceLog.
+    std::unique_ptr<TraceEventFilter::Config> base_filter_config(
+        new TraceConfig::EventFilterConfig(filter_config));
     std::unique_ptr<TraceEventFilter> new_filter;
     const std::string& predicate_name = filter_config.predicate_name();
     if (predicate_name == EventNameFilter::kName) {
       auto whitelist = MakeUnique<std::unordered_set<std::string>>();
       CHECK(filter_config.GetArgAsSet("event_name_whitelist", &*whitelist));
-      new_filter = MakeUnique<EventNameFilter>(std::move(whitelist));
+      new_filter = MakeUnique<EventNameFilter>(std::move(base_filter_config),
+                                               std::move(whitelist));
     } else if (predicate_name == HeapProfilerEventFilter::kName) {
-      new_filter = MakeUnique<HeapProfilerEventFilter>();
-    } else {
-      if (filter_factory_for_testing_)
-        new_filter = filter_factory_for_testing_(predicate_name);
-      CHECK(new_filter) << "Unknown trace filter " << predicate_name;
+      new_filter =
+          MakeUnique<HeapProfilerEventFilter>(std::move(base_filter_config));
+    } else if (filter_factory_for_testing_) {
+      new_filter = filter_factory_for_testing_(predicate_name,
+                                               std::move(base_filter_config));
     }
-    g_category_group_filters.Get().push_back(std::move(new_filter));
+    CHECK(new_filter) << "Unknown trace filter " << predicate_name;
+    EventFilterRegistry::RegisterFilter(std::move(new_filter));
   }
 }
 
 void TraceLog::UpdateSyntheticDelaysFromTraceConfig() {
   ResetTraceEventSyntheticDelays();
   const TraceConfig::StringList& delays =
       trace_config_.GetSyntheticDelayValues();
   TraceConfig::StringList::const_iterator ci;
   for (ci = delays.begin(); ci != delays.end(); ++ci) {
     StringTokenizer tokens(*ci, ";");
@@ skipping 42 matching lines @@
 
     InternalTraceOptions old_options = trace_options();
 
     if (dispatching_to_observer_list_) {
       // TODO(ssid): Change to NOTREACHED after fixing crbug.com/625170.
       DLOG(ERROR)
           << "Cannot manipulate TraceLog::Enabled state from an observer.";
       return;
     }
 
-    // Clear all filters from previous tracing session. These filters are not
-    // cleared at the end of tracing because some threads which hit trace event
-    // when disabling, could try to use the filters.
-    if (!enabled_modes_)
-      g_category_group_filters.Get().clear();
+    // Update trace config for recording.
+    const bool already_recording = (enabled_modes_ & RECORDING_MODE) != 0;
+    if (modes_to_enable & RECORDING_MODE) {
+      // Save the current filter config (and restore below) in order to prevent
+      // clobbering the filter section of the TraceConfig when enabling only
+      // the recording mode. This is to ensure that GetCurrentTraceConfig()
+      // always returns a consistent snapshot of the current state.
+      std::unique_ptr<TraceConfig::EventFilters> saved_filters_config;

[ssid, 2016/12/12 04:50:18]

I do not think this is required anymore. The TraceConfig::Merge should take care
of this.
Previously this was added because there could be a case where someone passes a
trace config with filters and not enable FILTERING_MODE. Instead of failing
here, we just ignored the filters. Now there are CHECKs for both the cases where
filter configs are passed without enabling FILTERING_MODE and filter configs are
passed when filters are enabled already. There is no other way the filter config
here can be inconsistent with the active filters now.

But, if we decide to remove tone of the CHECK below, see comment, then this is
required.

+      if (!(modes_to_enable & FILTERING_MODE)) {
+        saved_filters_config.reset(
+            new TraceConfig::EventFilters(trace_config_.event_filters()));
+      }
 
-    // Update trace config for recording.
-    const bool already_recording = enabled_modes_ & RECORDING_MODE;
-    if (modes_to_enable & RECORDING_MODE) {
       if (already_recording) {
         // TODO(ssid): Stop suporting enabling of RECODING_MODE when already
         // enabled crbug.com/625170.
         DCHECK_EQ(new_options, old_options) << "Attempting to re-enable "
                                                "tracing with a different set "
                                                "of options.";
         trace_config_.Merge(trace_config);
       } else {
         trace_config_ = trace_config;
       }
+
+      if (saved_filters_config)
+        trace_config_.SetEventFilters(*saved_filters_config);
     }
 
     // Update event filters.
     if (modes_to_enable & FILTERING_MODE) {
-      DCHECK(!trace_config.event_filters().empty())
-          << "Attempting to enable filtering without any filters";
-      DCHECK(enabled_event_filters_.empty()) << "Attempting to re-enable "
-                                                "filtering when filters are "
-                                                "already enabled.";
-
-      // Use the given event filters only if filtering was not enabled.
-      if (enabled_event_filters_.empty())
-        enabled_event_filters_ = trace_config.event_filters();
+      const bool already_filtering = (enabled_modes_ & FILTERING_MODE) != 0;
+      CHECK(!already_filtering) << "Attempting to re-enable filtering";
+      CHECK(!trace_config.event_filters().empty())
+          << "Attempting to enable filtering with an empty filter set";
+      trace_config_.SetEventFilters(trace_config.event_filters());
+      CreateFiltersAndUpdateFilterRegistry();
+    } else {
+      CHECK(trace_config.event_filters().empty())

[ssid, 2016/12/12 04:50:18]

Crashes in case of --enable-heap-profiling:
TracingControllerImpl::AddTraceMessageFilter sends a "begin tracing" message to
a new process that has started after tracing starts. This uses the
GetCurrentTraceConfig() method.
Now the child process will crash because FILTERING_MODE will not be enabled by
ChildTraceMessageFilter::OnBeginTracing, but the trace config passed will have
filters.

The FILTERING_MODE in child process will be enabled by
MemoryDumpManager::Initialize much before the tracing is started, which is
better. Currently we just ignore the filters given by the config since filtering
is already enabled (by command line flag).

This CL first tries to fixes the issue of child process not passing the
FILTERING_MODE flag:
https://codereview.chromium.org/2466873002/
But, it is waiting on the discussion thread with you ("Filtering mode
discussion").

I cannot think of any better solution than to ignore new filters in case of heap
profiler filter being enabled by both MDM and trace message filter. Or we can
check for heap_profiler_filter as special case and ignore multiple
registrations.
We cannot avoid sending filter config along with begin tracing message since for
slow reports, only browser will set the event_name_filter and it has to be sent
through the ipc.

+          << "The trace config is specifying some filters but tracing is not "
+             "being enabled for FILTERING_MODE.";
     }
-    // Keep the |trace_config_| updated with only enabled filters in case anyone
-    // tries to read it using |GetCurrentTraceConfig| (even if filters are
-    // empty).
-    trace_config_.SetEventFilters(enabled_event_filters_);
 
     enabled_modes_ |= modes_to_enable;
     UpdateCategoryRegistry();
 
     // Do not notify observers or create trace buffer if only enabled for
     // filtering or if recording was already enabled.
     if (!(modes_to_enable & RECORDING_MODE) || already_recording)
       return;
 
     if (new_options != old_options) {
@@ skipping 78 matching lines @@
     DLOG(ERROR)
         << "Cannot manipulate TraceLog::Enabled state from an observer.";
     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();
+    EventFilterRegistry::UnregisterAllFilters();
 
   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;
@@ skipping 988 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