WIP NOCOMMIT: New trace event macros proposal

base/trace_event/trace_event_unittest.cc

Index: base/trace_event/trace_event_unittest.cc
diff --git a/base/trace_event/trace_event_unittest.cc b/base/trace_event/trace_event_unittest.cc
index a588ce04b4f2245ca23a4c7b7f855e4d510fefe5..578eaea57fce9b59edf22df19d6869dcdb99fa42 100644
--- a/base/trace_event/trace_event_unittest.cc
+++ b/base/trace_event/trace_event_unittest.cc
@@ -182,6 +182,7 @@ void TraceEventTestFixture::OnTraceDataCollected(
     WaitableEvent* flush_complete_event,
     const scoped_refptr<base::RefCountedString>& events_str,
     bool has_more_events) {
+  // LOG(ERROR) << events_str->data();
   num_flush_callbacks_++;
   if (num_flush_callbacks_ > 1) {
     EXPECT_FALSE(events_str->data().empty());
@@ -399,8 +400,436 @@ std::vector<const DictionaryValue*> FindTraceEntries(
   return hits;
 }
 
+#define INTERNAL_NEW_TRACE_EVENT_ADD(phase, category_group, name, flags, ...)  \
+  do {                                                                         \
+    INTERNAL_TRACE_EVENT_GET_CATEGORY_INFO(category_group);                    \
+    if (INTERNAL_TRACE_EVENT_CATEGORY_GROUP_ENABLED_FOR_RECORDING_MODE()) {    \
+      NewAddTraceEvent(phase,                                                  \
+                       INTERNAL_TRACE_EVENT_UID(category_group_enabled), name, \
+                       flags, ##__VA_ARGS__);                                  \
+    }                                                                          \
+  } while (0)
+
+// Implementation detail: internal macro to create static category and add begin
+// event if the category is enabled. Also adds the end event when the scope
+// ends.
+#define INTERNAL_NEW_TRACE_EVENT_ADD_SCOPED(category_group, name, ...)      \
+  INTERNAL_TRACE_EVENT_GET_CATEGORY_INFO(category_group);                   \
+  trace_event_internal::ScopedTracer INTERNAL_TRACE_EVENT_UID(tracer);      \
+  if (INTERNAL_TRACE_EVENT_CATEGORY_GROUP_ENABLED_FOR_RECORDING_MODE()) {   \
+    base::trace_event::TraceEventHandle h =                                 \
+        NewAddTraceEvent(TRACE_EVENT_PHASE_COMPLETE,                        \
+                         INTERNAL_TRACE_EVENT_UID(category_group_enabled),  \
+                         name, TRACE_EVENT_FLAG_NONE, ##__VA_ARGS__);       \
+    INTERNAL_TRACE_EVENT_UID(tracer)                                        \
+        .Initialize(INTERNAL_TRACE_EVENT_UID(category_group_enabled), name, \
+                    h);                                                     \
+  }
+
+#define TRACE_EVENT(category_group, name, ...) \
+  INTERNAL_NEW_TRACE_EVENT_ADD_SCOPED(category_group, name, ##__VA_ARGS__)
+
+#define TRACE_EVENT_BEGIN(category_group, name, ...)                          \
+  INTERNAL_NEW_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_BEGIN, category_group, name, \
+                               TRACE_EVENT_FLAG_NONE, ##__VA_ARGS__)
+
+#define TRACE_EVENT_END(category_group, name, ...)                          \
+  INTERNAL_NEW_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_END, category_group, name, \
+                               TRACE_EVENT_FLAG_NONE, ##__VA_ARGS__)
+
+#define TRACE_EVENT_INSTANT(category_group, name, scope, ...)             \
+  INTERNAL_NEW_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_INSTANT, category_group, \
+                               name, TRACE_EVENT_FLAG_NONE | scope,       \
+                               ##__VA_ARGS__)
+
+#define TRACE_EVENT_ASYNC_BEGIN(category_group, name, id, ...)                \
+  INTERNAL_NEW_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_ASYNC_BEGIN, category_group, \
+                               name, TRACE_EVENT_FLAG_NONE, TraceEventID(id), \
+                               ##__VA_ARGS__)
+
+#define TRACE_EVENT_ASYNC_END(category_group, name, id, ...)                  \
+  INTERNAL_NEW_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_ASYNC_END, category_group,   \
+                               name, TRACE_EVENT_FLAG_NONE, TraceEventID(id), \
+                               ##__VA_ARGS__)
+
+#define TRACE_EVENT_ASYNC_STEP_INTO(category_group, name, id, step, ...)      \
+  INTERNAL_NEW_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_ASYNC_STEP_INTO,             \
+                               category_group, name, TRACE_EVENT_FLAG_NONE,   \
+                               TraceEventID(id), TraceEventArg("step", step), \
+                               ##__VA_ARGS__)
+
+#define TRACE_EVENT_FLOW_BEGIN(category_group, name, id, ...)                 \
+  INTERNAL_NEW_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_FLOW_BEGIN, category_group,  \
+                               name, TRACE_EVENT_FLAG_NONE, TraceEventID(id), \
+                               ##__VA_ARGS__)
+
+#define TRACE_EVENT_FLOW_STEP(category_group, name, id, step, ...)            \
+  INTERNAL_NEW_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_FLOW_STEP, category_group,   \
+                               name, TRACE_EVENT_FLAG_NONE, TraceEventID(id), \
+                               TraceEventArg("step", step), ##__VA_ARGS__)
+
+#define TRACE_EVENT_FLOW_END_BIND_TO_ENCLOSING(category_group, name, id, ...) \
+  INTERNAL_NEW_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_FLOW_END, category_group,    \
+                               name, TRACE_EVENT_FLAG_BIND_TO_ENCLOSING,      \
+                               TraceEventID(id), ##__VA_ARGS__)
+
+#define TRACE_COUNTER(category_group, name, ...)                          \
+  INTERNAL_NEW_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_COUNTER, category_group, \
+                               name, TRACE_EVENT_FLAG_NONE, ##__VA_ARGS__)
+
+#define TRACE_COUNTER_ID(category_group, name, id, ...)                       \
+  INTERNAL_NEW_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_COUNTER, category_group,     \
+                               name, TRACE_EVENT_FLAG_NONE, TraceEventID(id), \
+                               ##__VA_ARGS__)
+
+#define TRACE_EVENT_COPY_BEGIN(category_group, name, ...)                     \
+  INTERNAL_NEW_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_BEGIN, category_group, name, \
+                               TRACE_EVENT_FLAG_COPY, ##__VA_ARGS__)
+
+#define TRACE_EVENT_COPY_END(category_group, name, ...)                     \
+  INTERNAL_NEW_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_END, category_group, name, \
+                               TRACE_EVENT_FLAG_COPY, ##__VA_ARGS__)
+
+#define TRACE_EVENT_ASYNC_STEP_PAST(category_group, name, id, step, ...)      \
+  INTERNAL_NEW_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_ASYNC_STEP_PAST,             \
+                               category_group, name, TRACE_EVENT_FLAG_NONE,   \
+                               TraceEventID(id), TraceEventArg("step", step), \
+                               ##__VA_ARGS__)
+
+namespace {
+
+struct TraceParams {
+  TraceParams(unsigned int flags)
+      : id_(trace_event_internal::kNoId),
+        context_id_(trace_event_internal::kNoId),
+        bind_id_(trace_event_internal::kNoId),
+        thread_id_(static_cast<int>(base::PlatformThread::CurrentId())),
+        timestamp_(base::TimeTicks::Now()),
+        num_args_(0),
+        convertable_values_(NULL),
+        flags_(flags) {}
+
+  base::trace_event::TraceEventHandle Finalize(
+      char phase,
+      const unsigned char* category_group_enabled,
+      const char* name) {
+    return TRACE_EVENT_API_ADD_TRACE_EVENT_WITH_THREAD_ID_AND_TIMESTAMP(
+        phase, category_group_enabled, name, id_, context_id_, bind_id_,
+        thread_id_, timestamp_, num_args_, arg_names_, arg_types_, arg_values_,
+        &convertable_values_, flags_);
+  }
+
+  unsigned long long id_;
+  unsigned long long context_id_;
+  unsigned long long bind_id_;
+  int thread_id_;
+  TimeTicks timestamp_;
+  int num_args_;
+  const char* arg_names_[2];
+  unsigned char arg_types_[2];
+  unsigned long long arg_values_[2];
+  scoped_refptr<ConvertableToTraceFormat> convertable_values_;
+  unsigned int flags_;
+};
+
+base::trace_event::TraceEventHandle NewAddTraceEvent(
+    char phase,
+    const unsigned char* category_group_enabled,
+    const char* name,
+    unsigned int flags) {
+  TraceParams trace_params(flags);
+  return trace_params.Finalize(phase, category_group_enabled, name);
+}
+
+template <typename PARAM1_TYPE>
+base::trace_event::TraceEventHandle NewAddTraceEvent(
+    char phase,
+    const unsigned char* category_group_enabled,
+    const char* name,
+    unsigned int flags,
+    const PARAM1_TYPE& param1) {
+  TraceParams trace_params(flags);
+
+  param1.Fill(&trace_params);
+  return trace_params.Finalize(phase, category_group_enabled, name);
+}
+
+template <typename PARAM1_TYPE, typename PARAM2_TYPE>
+base::trace_event::TraceEventHandle NewAddTraceEvent(
+    char phase,
+    const unsigned char* category_group_enabled,
+    const char* name,
+    unsigned int flags,
+    const PARAM1_TYPE& param1,
+    const PARAM2_TYPE& param2) {
+  TraceParams trace_params(flags);
+
+  param1.Fill(&trace_params);
+  param2.Fill(&trace_params);
+  return trace_params.Finalize(phase, category_group_enabled, name);
+}
+
+template <typename PARAM1_TYPE, typename PARAM2_TYPE, typename PARAM3_TYPE>
+base::trace_event::TraceEventHandle NewAddTraceEvent(
+    char phase,
+    const unsigned char* category_group_enabled,
+    const char* name,
+    unsigned int flags,
+    const PARAM1_TYPE& param1,
+    const PARAM2_TYPE& param2,
+    const PARAM3_TYPE& param3) {
+  TraceParams trace_params(flags);
+
+  param1.Fill(&trace_params);
+  param2.Fill(&trace_params);
+  param3.Fill(&trace_params);
+  return trace_params.Finalize(phase, category_group_enabled, name);
+}
+
+template <typename PARAM1_TYPE,
+          typename PARAM2_TYPE,
+          typename PARAM3_TYPE,
+          typename PARAM4_TYPE>
+base::trace_event::TraceEventHandle NewAddTraceEvent(
+    char phase,
+    const unsigned char* category_group_enabled,
+    const char* name,
+    unsigned int flags,
+    const PARAM1_TYPE& param1,
+    const PARAM2_TYPE& param2,
+    const PARAM3_TYPE& param3,
+    const PARAM4_TYPE& param4) {
+  TraceParams trace_params(flags);
+
+  param1.Fill(&trace_params);
+  param2.Fill(&trace_params);
+  param3.Fill(&trace_params);
+  param4.Fill(&trace_params);
+  return trace_params.Finalize(phase, category_group_enabled, name);
+}
+
+struct TraceEventBindID {
+  TraceEventBindID(const unsigned long long& bind_id) : bind_id_(bind_id) {}
+
+  void Fill(TraceParams* trace_params) const {
+    trace_event_internal::TraceID trace_event_bind_id(bind_id_,
+                                                      &trace_params->flags_);
+    trace_params->bind_id_ = trace_event_bind_id.data();
+  }
+
+  const unsigned long long& bind_id_;
+};
+
+struct TraceEventID {
+  TraceEventID(const unsigned long long& id) : id_(id) {}
+
+  void Fill(TraceParams* trace_params) const {
+    trace_params->flags_ |= TRACE_EVENT_FLAG_HAS_ID;
+    trace_event_internal::TraceID trace_event_id(id_, &trace_params->flags_);
+    trace_params->id_ = trace_event_id.data();
+  }
+
+  const unsigned long long& id_;
+};
+
+struct TraceEventThreadID {
+  TraceEventThreadID(const unsigned long long& thread_id)
+      : thread_id_(thread_id) {}
+
+  void Fill(TraceParams* trace_params) const {
+    trace_params->thread_id_ = thread_id_;
+  }
+
+  const unsigned long long& thread_id_;
+};
+
+struct TraceEventTimestamp {
+  TraceEventTimestamp(const unsigned long long& timestamp)
+      : timestamp_(timestamp) {}
+
+  void Fill(TraceParams* trace_params) const {
+    trace_params->flags_ |= TRACE_EVENT_FLAG_EXPLICIT_TIMESTAMP;
+    trace_params->timestamp_ = base::TimeTicks::FromInternalValue(timestamp_);
+  }
+
+  const unsigned long long& timestamp_;
+};
+
+template <typename ARG_TYPE>
+struct TraceEventArgImpl {
+  TraceEventArgImpl(const char* arg_name, const ARG_TYPE& arg_value)
+      : arg_name_(arg_name), arg_value_(arg_value) {}
+
+  TraceEventArgImpl(const ARG_TYPE& arg_value)
+      : arg_name_("value"), arg_value_(arg_value) {}
+
+  void Fill(TraceParams* trace_params) const {
+    int current_arg_num = trace_params->num_args_;
+    DCHECK(current_arg_num < 2);
+    trace_params->arg_names_[current_arg_num] = arg_name_;
+
+    trace_event_internal::SetTraceValue(
+        arg_value_, &trace_params->arg_types_[current_arg_num],
+        &trace_params->arg_values_[current_arg_num]);
+    trace_params->num_args_++;
+  }
+
+  const char* arg_name_;
+  const ARG_TYPE& arg_value_;
+};
+
+// Wrapper construction functions to make template argument deduction possible.
+template <typename ARG_TYPE>
+TraceEventArgImpl<ARG_TYPE> TraceEventArg(const char* arg_name,
+                                          const ARG_TYPE& arg_value) {
+  return TraceEventArgImpl<ARG_TYPE>(arg_name, arg_value);
+}
+
+template <typename ARG_TYPE>
+TraceEventArgImpl<ARG_TYPE> TraceEventArg(const ARG_TYPE& arg_value) {
+  return TraceEventArgImpl<ARG_TYPE>(arg_value);
+}
+
+}  // namespace
+
+#define TRACE_EVENT_ARG(arg_name, arg_value) \
+  TraceEventArg(#arg_name, arg_value)
+
+TEST_F(TraceEventTestFixture, NewTraceMacros) {
+  BeginTrace();
+
+  TRACE_EVENT_BEGIN("category", "event name", TraceEventBindID(8080),
+                    TRACE_EVENT_ARG(arg1, 42), TRACE_EVENT_ARG(arg2, "foo"),
+                    TraceEventID(88));
+
+  EndTraceAndFlush();
+
+  const DictionaryValue* entry1 = FindTraceEntry(trace_parsed_, "event name");
+  ASSERT_TRUE(entry1);
+
+  int i;
+  EXPECT_TRUE(entry1->GetInteger("args.arg1", &i));
+  EXPECT_EQ(i, 42);
+
+  // std::string str;
+  // EXPECT_TRUE(entry1->GetString("id", &str));
+  // EXPECT_EQ(str, "myID");
+}
+
 const char kControlCharacters[] = "\001\002\003\n\r";
 
+void TraceWithAllNewMacroVariants(WaitableEvent* task_complete_event) {
+  {
+    TRACE_EVENT("all", "TRACE_EVENT0 call");
+    TRACE_EVENT("all", "TRACE_EVENT1 call", TraceEventArg("name1", "value1"));
+    TRACE_EVENT("all", "TRACE_EVENT2 call",
+                TraceEventArg("name1", "\"value1\""),
+                TraceEventArg("name2", "value\\2"));
+
+    TRACE_EVENT_INSTANT("all", "TRACE_EVENT_INSTANT0 call",
+                        TRACE_EVENT_SCOPE_GLOBAL);
+    TRACE_EVENT_INSTANT("all", "TRACE_EVENT_INSTANT1 call",
+                        TRACE_EVENT_SCOPE_PROCESS,
+                        TraceEventArg("name1", "value1"));
+    TRACE_EVENT_INSTANT(
+        "all", "TRACE_EVENT_INSTANT2 call", TRACE_EVENT_SCOPE_THREAD,
+        TraceEventArg("name1", "value1"), TraceEventArg("name2", "value2"));
+
+    TRACE_EVENT_BEGIN("all", "TRACE_EVENT_BEGIN0 call");
+    TRACE_EVENT_BEGIN("all", "TRACE_EVENT_BEGIN1 call",
+                      TraceEventArg("name1", "value1"));
+    TRACE_EVENT_BEGIN("all", "TRACE_EVENT_BEGIN2 call",
+                      TraceEventArg("name1", "value1"),
+                      TraceEventArg("name2", "value2"));
+
+    TRACE_EVENT_END("all", "TRACE_EVENT_END0 call");
+    TRACE_EVENT_END("all", "TRACE_EVENT_END1 call",
+                    TraceEventArg("name1", "value1"));
+    TRACE_EVENT_END("all", "TRACE_EVENT_END2 call",
+                    TraceEventArg("name1", "value1"),
+                    TraceEventArg("name2", "value2"));
+
+    TRACE_EVENT_ASYNC_BEGIN("all", "TRACE_EVENT_ASYNC_BEGIN0 call", kAsyncId);
+    TRACE_EVENT_ASYNC_BEGIN("all", "TRACE_EVENT_ASYNC_BEGIN1 call", kAsyncId,
+                            TraceEventArg("name1", "value1"));
+    TRACE_EVENT_ASYNC_BEGIN("all", "TRACE_EVENT_ASYNC_BEGIN2 call", kAsyncId,
+                            TraceEventArg("name1", "value1"),
+                            TraceEventArg("name2", "value2"));
+
+    TRACE_EVENT_ASYNC_STEP_INTO("all", "TRACE_EVENT_ASYNC_STEP_INTO0 call",
+                                kAsyncId, "step_begin1");
+    TRACE_EVENT_ASYNC_STEP_INTO("all", "TRACE_EVENT_ASYNC_STEP_INTO1 call",
+                                kAsyncId, "step_begin2",
+                                TraceEventArg("name1", "value1"));
+
+    TRACE_EVENT_ASYNC_END("all", "TRACE_EVENT_ASYNC_END0 call", kAsyncId);
+    TRACE_EVENT_ASYNC_END("all", "TRACE_EVENT_ASYNC_END1 call", kAsyncId,
+                          TraceEventArg("name1", "value1"));
+    TRACE_EVENT_ASYNC_END("all", "TRACE_EVENT_ASYNC_END2 call", kAsyncId,
+                          TraceEventArg("name1", "value1"),
+                          TraceEventArg("name2", "value2"));
+
+    TRACE_EVENT_FLOW_BEGIN("all", "TRACE_EVENT_FLOW_BEGIN0 call", kFlowId);
+    TRACE_EVENT_FLOW_STEP("all", "TRACE_EVENT_FLOW_STEP0 call", kFlowId,
+                          "step1");
+    TRACE_EVENT_FLOW_END_BIND_TO_ENCLOSING(
+        "all", "TRACE_EVENT_FLOW_END_BIND_TO_ENCLOSING0 call", kFlowId);
+
+    TRACE_COUNTER("all", "TRACE_COUNTER1 call", TraceEventArg(31415));
+    TRACE_COUNTER("all", "TRACE_COUNTER2 call", TraceEventArg("a", 30000),
+                  TraceEventArg("b", 1415));
+
+    TRACE_COUNTER("all", "TRACE_COUNTER_WITH_TIMESTAMP1 call",
+                  TraceEventTimestamp(42), TraceEventArg(31415));
+    TRACE_COUNTER("all", "TRACE_COUNTER_WITH_TIMESTAMP2 call",
+                  TraceEventTimestamp(42), TraceEventArg("a", 30000),
+                  TraceEventArg("b", 1415));
+
+    TRACE_COUNTER_ID("all", "TRACE_COUNTER_ID1 call", 0x319009,
+                     TraceEventArg(31415));
+    TRACE_COUNTER_ID("all", "TRACE_COUNTER_ID2 call", 0x319009,
+                     TraceEventArg("a", 30000), TraceEventArg("b", 1415));
+
+    TRACE_EVENT_COPY_BEGIN(
+        "all", "TRACE_EVENT_COPY_BEGIN_WITH_ID_TID_AND_TIMESTAMP0 call",
+        TraceEventID(kAsyncId), TraceEventThreadID(kThreadId),
+        TraceEventTimestamp(12345));
+    TRACE_EVENT_COPY_END("all",
+                         "TRACE_EVENT_COPY_END_WITH_ID_TID_AND_TIMESTAMP0 call",
+                         TraceEventID(kAsyncId), TraceEventThreadID(kThreadId),
+                         TraceEventTimestamp(23456));
+
+    TRACE_EVENT_BEGIN("all",
+                      "TRACE_EVENT_BEGIN_WITH_ID_TID_AND_TIMESTAMP0 call",
+                      TraceEventID(kAsyncId2), TraceEventThreadID(kThreadId),
+                      TraceEventTimestamp(34567));
+    TRACE_EVENT_ASYNC_STEP_PAST("all", "TRACE_EVENT_ASYNC_STEP_PAST0 call",
+                                kAsyncId2, "step_end1");
+    TRACE_EVENT_ASYNC_STEP_PAST("all", "TRACE_EVENT_ASYNC_STEP_PAST1 call",
+                                kAsyncId2, "step_end2",
+                                TraceEventArg("name1", "value1"));
+
+    TRACE_EVENT_END("all", "TRACE_EVENT_END_WITH_ID_TID_AND_TIMESTAMP0 call",
+                    TraceEventID(kAsyncId2), TraceEventThreadID(kThreadId),
+                    TraceEventTimestamp(45678));
+
+    TRACE_EVENT_OBJECT_CREATED_WITH_ID("all", "tracked object 1", 0x42);
+    TRACE_EVENT_OBJECT_SNAPSHOT_WITH_ID("all", "tracked object 1", 0x42,
+                                        "hello");
+    TRACE_EVENT_OBJECT_DELETED_WITH_ID("all", "tracked object 1", 0x42);
+
+    TraceScopedTrackableObject<int> trackable("all", "tracked object 2",
+                                              0x2128506);
+    trackable.snapshot("world");
+
+    TRACE_EVENT1(kControlCharacters, kControlCharacters, kControlCharacters,
+                 kControlCharacters);
+  }  // Scope close causes TRACE_EVENT0 etc to send their END events.
+
+  if (task_complete_event)
+    task_complete_event->Signal();
+}
+
 void TraceWithAllMacroVariants(WaitableEvent* task_complete_event) {
   {
     TRACE_EVENT0("all", "TRACE_EVENT0 call");
@@ -907,6 +1336,17 @@ TEST_F(TraceEventTestFixture, DataCaptured) {
   ValidateAllTraceMacrosCreatedData(trace_parsed_);
 }
 
+TEST_F(TraceEventTestFixture, DataCapturedFromNewMacros) {
+  TraceLog::GetInstance()->SetEnabled(TraceConfig(kRecordAllCategoryFilter, ""),
+                                      TraceLog::RECORDING_MODE);
+
+  TraceWithAllNewMacroVariants(NULL);
+
+  EndTraceAndFlush();
+
+  ValidateAllTraceMacrosCreatedData(trace_parsed_);
+}
+
 // Emit some events and validate that only empty strings are received
 // if we tell Flush() to discard events.
 TEST_F(TraceEventTestFixture, DataDiscarded) {