tracing: fix races in CategoryRegistry

base/trace_event/trace_log.cc

Index: base/trace_event/trace_log.cc
diff --git a/base/trace_event/trace_log.cc b/base/trace_event/trace_log.cc
index f76393cf230a3e97772d3cee734ffac79b0ba5fc..4b21437c66114667b725e3dcfb1b70d7ea18f84b 100644
--- a/base/trace_event/trace_log.cc
+++ b/base/trace_event/trace_log.cc
@@ -493,11 +493,18 @@ const unsigned char* TraceLog::GetCategoryGroupEnabled(
     DCHECK(!CategoryRegistry::kCategoryAlreadyShutdown->is_enabled());
     return CategoryRegistry::kCategoryAlreadyShutdown->state_ptr();
   }
-  TraceCategory* category = nullptr;
-  bool is_new_category =
-      CategoryRegistry::GetOrCreateCategoryByName(category_group, &category);

[Primiano Tucci (use gerrit), 2016/11/16 16:46:54]

Essentially this was the core of the problem.
The original code, before my previous CL, was quite similar to the latest
patchset.
Then, in my previous CL, I modified as follows:

if (category_NOT_seen_before) {
1.   Lock
2.   Create Category
3.   Unlock
4.   Update category flags looking  at trace config
}

This opened a race window such that if two threads hit this code at the same
time:
- They will only create one category entry, as the creation is locked (good)
- The second thread might use the category before the first thread as hit 4
(bad)

So, in practice, what can happen is that:
two threads hit TRACE_EVENT0("something-enabled-by-default").

1. Thread 1: adds "something-enabled-by-default" to the registry
2. Thread 2: sees that "something-enabled-by-default" is already in the registry
and uses that. However since T1 didn't initialize the flags yet, T2 will assume
that the category is not enabled and skip and not add its event to the log.
3. T1: does the initialization: queries TraceConfig, figures out that
"something-enabled-by-default" is enabled, and updates the flag of the category.

Now, this is not really a drama. It means that if two thread hit a new
TRACE_EVENT with the same category at the same time, one of the two might be not
recorded.

However, there are unitttests that depend on this behavior. Also this behavior
was guaranteed by the previous design, before my previous CL, so it's seems
reasonable to re-establish.

As an unrelated note, this is yet another reason to kill the concept of
"dynamic" categories in the future and only have statically defined categories. 

-  if (is_new_category)
-    tracelog->UpdateCategoryState(category);
+  TraceCategory* category = CategoryRegistry::GetCategoryByName(category_group);
+  if (!category) {
+    // Slow path: in the case of a new category we have to repeat the check
+    // holding the lock, as multiple threads might have reached this point
+    // at the same time.
+    auto category_initializer = [](TraceCategory* category) {
+      TraceLog::GetInstance()->UpdateCategoryState(category);
+    };
+    AutoLock lock(tracelog->lock_);
+    CategoryRegistry::GetOrCreateCategoryLocked(
+        category_group, category_initializer, &category);
+  }
   DCHECK(category->state_ptr());
   return category->state_ptr();
 }