Change mojo watcher event to typed trace events

New type of trace event macros use proto fields, for uploading
background traces

TBR=ssid@google.com

Change-Id: I91e4d211ec46bd68eee3c238d8efccbd0f342329
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2454976Reviewed-by: ssid <ssid@chromium.org>
Reviewed-by: Ken Rockot <rockot@google.com>
Commit-Queue: ssid <ssid@chromium.org>
Cr-Commit-Position: refs/heads/master@{#815802}

mojo/public/DEPS

@@ -9,4 +9,5 @@ include_rules = [
 
   # Temporary until mojom [Native] is gone.
   "+ipc/ipc_param_traits.h",
+  "+third_party/perfetto/protos/perfetto/trace/track_event",
 ]

mojo/public/cpp/bindings/connector.h

@@ -85,7 +85,7 @@ class COMPONENT_EXPORT(MOJO_CPP_BINDINGS) Connector : public MessageReceiver {
   Connector(ScopedMessagePipeHandle message_pipe,
             ConnectorConfig config,
             scoped_refptr<base::SequencedTaskRunner> runner,
-            const char* heap_profiler_tag = "unknown interface");
+            const char* interface_name = "unknown interface");
   ~Connector() override;
 
   // Sets outgoing serialization mode.
@@ -306,7 +306,7 @@ class COMPONENT_EXPORT(MOJO_CPP_BINDINGS) Connector : public MessageReceiver {
 
   // The tag used to track heap allocations that originated from a Watcher
   // notification.
-  const char* heap_profiler_tag_ = "unknown interface";
+  const char* interface_name_ = "unknown interface";
 
   // A cached pointer to the RunLoopNestingObserver for the thread on which this
   // Connector was created.

mojo/public/cpp/bindings/lib/connector.cc

@@ -21,6 +21,7 @@
 #include "base/task/current_thread.h"
 #include "base/threading/sequence_local_storage_slot.h"
 #include "base/trace_event/trace_event.h"
+#include "base/trace_event/typed_macros.h"
 #include "mojo/public/c/system/quota.h"
 #include "mojo/public/cpp/bindings/features.h"
 #include "mojo/public/cpp/bindings/lib/may_auto_lock.h"
@@ -29,6 +30,7 @@
 #include "mojo/public/cpp/bindings/mojo_buildflags.h"
 #include "mojo/public/cpp/bindings/sync_handle_watcher.h"
 #include "mojo/public/cpp/system/wait.h"
+#include "third_party/perfetto/protos/perfetto/trace/track_event/chrome_mojo_event_info.pbzero.h"
 
 #if defined(ENABLE_IPC_FUZZER)
 #include "mojo/public/cpp/bindings/message_dumper.h"
@@ -145,14 +147,14 @@ void Connector::ActiveDispatchTracker::NotifyBeginNesting() {
 Connector::Connector(ScopedMessagePipeHandle message_pipe,
                      ConnectorConfig config,
                      scoped_refptr<base::SequencedTaskRunner> runner,
-                     const char* heap_profiler_tag)
+                     const char* interface_name)
     : message_pipe_(std::move(message_pipe)),
       task_runner_(std::move(runner)),
       error_(false),
       force_immediate_dispatch_(!EnableTaskPerMessage()),
       outgoing_serialization_mode_(g_default_outgoing_serialization_mode),
       incoming_serialization_mode_(g_default_incoming_serialization_mode),
-      heap_profiler_tag_(heap_profiler_tag),
+      interface_name_(interface_name),
       nesting_observer_(RunLoopNestingObserver::GetForThread()) {
   if (config == MULTI_THREADED_SEND)
     lock_.emplace();
@@ -410,7 +412,7 @@ void Connector::WaitToReadMore() {
   DCHECK(task_runner_->RunsTasksInCurrentSequence());
   handle_watcher_ = std::make_unique<SimpleWatcher>(
       FROM_HERE, SimpleWatcher::ArmingPolicy::MANUAL, task_runner_,
-      heap_profiler_tag_);
+      interface_name_);
   MojoResult rv = handle_watcher_->Watch(
       message_pipe_.get(), MOJO_HANDLE_SIGNAL_READABLE,
       base::BindRepeating(&Connector::OnWatcherHandleReady,
@@ -459,11 +461,11 @@ MojoResult Connector::ReadMessage(Message* message) {
     // was a problem extracting handles from it. We treat this essentially as
     // a bad IPC because we don't really have a better option.
     //
-    // We include |heap_profiler_tag_| in the error message since it usually
+    // We include |interface_name_| in the error message since it usually
     // (via this Connector's owner) provides useful information about which
     // binding interface is using this Connector.
     NotifyBadMessage(handle.get(),
-                     std::string(heap_profiler_tag_) +
+                     std::string(interface_name_) +
                          "One or more handle attachments were invalid.");
     return MOJO_RESULT_ABORTED;
   }
@@ -494,7 +496,12 @@ bool Connector::DispatchMessage(Message message) {
                          TRACE_EVENT_FLAG_FLOW_IN);
 #if !BUILDFLAG(MOJO_TRACE_ENABLED)
   // This emits just full class name, and is inferior to mojo tracing.
-  TRACE_EVENT0("mojom", heap_profiler_tag_);
+  TRACE_EVENT("toplevel", "Connector::DispatchMessage",
+              [this](perfetto::EventContext ctx) {
+                ctx.event()
+                    ->set_chrome_mojo_event_info()
+                    ->set_watcher_notify_interface_tag(interface_name_);
+              });
 #endif
 
   if (connection_group_)

mojo/public/cpp/system/simple_watcher.cc

@@ -13,7 +13,9 @@
 #include "base/threading/thread_task_runner_handle.h"
 #include "base/trace_event/heap_profiler.h"
 #include "base/trace_event/trace_event.h"
+#include "base/trace_event/typed_macros.h"
 #include "mojo/public/c/system/trap.h"
+#include "third_party/perfetto/protos/perfetto/trace/track_event/chrome_mojo_event_info.pbzero.h"
 
 namespace mojo {
 
@@ -32,9 +34,9 @@ class SimpleWatcher::Context : public base::RefCountedThreadSafe<Context> {
       MojoTriggerCondition condition,
       int watch_id,
       MojoResult* result,
-      const char* heap_profiler_tag) {
+      const char* handler_tag) {
     scoped_refptr<Context> context =
-        new Context(watcher, task_runner, watch_id, heap_profiler_tag);
+        new Context(watcher, task_runner, watch_id, handler_tag);
 
     // If MojoAddTrigger succeeds, it effectively assumes ownership of a
     // reference to |context|. In that case, this reference is balanced in
@@ -70,11 +72,11 @@ class SimpleWatcher::Context : public base::RefCountedThreadSafe<Context> {
   Context(base::WeakPtr<SimpleWatcher> weak_watcher,
           scoped_refptr<base::SequencedTaskRunner> task_runner,
           int watch_id,
-          const char* heap_profiler_tag)
+          const char* handler_tag)
       : weak_watcher_(weak_watcher),
         task_runner_(task_runner),
         watch_id_(watch_id),
-        heap_profiler_tag_(heap_profiler_tag) {}
+        handler_tag_(handler_tag) {}
 
   ~Context() = default;
 
@@ -92,10 +94,8 @@ class SimpleWatcher::Context : public base::RefCountedThreadSafe<Context> {
       weak_watcher_->OnHandleReady(watch_id_, result, state);
     } else {
       {
-        // Annotate the posted task with |heap_profiler_tag_| as the IPC
-        // interface.
-        base::TaskAnnotator::ScopedSetIpcHash scoped_set_ipc_hash(
-            heap_profiler_tag_);
+        // Annotate the posted task with |handler_tag_| as the IPC interface.
+        base::TaskAnnotator::ScopedSetIpcHash scoped_set_ipc_hash(handler_tag_);
         task_runner_->PostTask(
             FROM_HERE, base::BindOnce(&SimpleWatcher::OnHandleReady,
                                       weak_watcher_, watch_id_, result, state));
@@ -106,7 +106,7 @@ class SimpleWatcher::Context : public base::RefCountedThreadSafe<Context> {
   const base::WeakPtr<SimpleWatcher> weak_watcher_;
   const scoped_refptr<base::SequencedTaskRunner> task_runner_;
   const int watch_id_;
-  const char* heap_profiler_tag_ = nullptr;
+  const char* handler_tag_ = nullptr;
 
   DISALLOW_COPY_AND_ASSIGN(Context);
 };
@@ -114,14 +114,13 @@ class SimpleWatcher::Context : public base::RefCountedThreadSafe<Context> {
 SimpleWatcher::SimpleWatcher(const base::Location& from_here,
                              ArmingPolicy arming_policy,
                              scoped_refptr<base::SequencedTaskRunner> runner,
-                             const char* heap_profiler_tag)
+                             const char* handler_tag)
     : arming_policy_(arming_policy),
       task_runner_(std::move(runner)),
       is_default_task_runner_(base::ThreadTaskRunnerHandle::IsSet() &&
                               task_runner_ ==
                                   base::ThreadTaskRunnerHandle::Get()),
-      heap_profiler_tag_(heap_profiler_tag ? heap_profiler_tag
-                                           : from_here.file_name()) {
+      handler_tag_(handler_tag ? handler_tag : from_here.file_name()) {
   MojoResult rv = CreateTrap(&Context::CallNotify, &trap_handle_);
   DCHECK_EQ(MOJO_RESULT_OK, rv);
   DCHECK(task_runner_->RunsTasksInCurrentSequence());
@@ -152,7 +151,7 @@ MojoResult SimpleWatcher::Watch(Handle handle,
   MojoResult result = MOJO_RESULT_UNKNOWN;
   context_ = Context::Create(weak_factory_.GetWeakPtr(), task_runner_,
                              trap_handle_.get(), handle_, signals, condition,
-                             watch_id_, &result, heap_profiler_tag_);
+                             watch_id_, &result, handler_tag_);
   if (!context_) {
     handle_.set_value(kInvalidHandleValue);
     callback_.Reset();
@@ -230,9 +229,8 @@ void SimpleWatcher::ArmOrNotify() {
 
   DCHECK_EQ(MOJO_RESULT_FAILED_PRECONDITION, rv);
   {
-    // Annotate the posted task with |heap_profiler_tag_| as the IPC interface.
-    base::TaskAnnotator::ScopedSetIpcHash scoped_set_ipc_hash(
-        heap_profiler_tag_);
+    // Annotate the posted task with |handler_tag_| as the IPC interface.
+    base::TaskAnnotator::ScopedSetIpcHash scoped_set_ipc_hash(handler_tag_);
     task_runner_->PostTask(FROM_HERE,
                            base::BindOnce(&SimpleWatcher::OnHandleReady,
                                           weak_factory_.GetWeakPtr(), watch_id_,
@@ -261,12 +259,16 @@ void SimpleWatcher::OnHandleReady(int watch_id,
 
   // NOTE: It's legal for |callback| to delete |this|.
   if (!callback.is_null()) {
-    TRACE_HEAP_PROFILER_API_SCOPED_TASK_EXECUTION event(heap_profiler_tag_);
+    TRACE_HEAP_PROFILER_API_SCOPED_TASK_EXECUTION event(handler_tag_);
     // Lot of janks caused are grouped to OnHandleReady tasks. This trace event
-    // helps identify the cause of janks. It is ok to pass |heap_profiler_tag_|
+    // helps identify the cause of janks. It is ok to pass |handler_tag_|
     // here since it is a string literal.
-    // TODO(927206): Consider renaming |heap_profiler_tag_|.
-    TRACE_EVENT0("toplevel", heap_profiler_tag_);
+    TRACE_EVENT("toplevel", "SimpleWatcher::OnHandleReady",
+                [this](perfetto::EventContext ctx) {
+                  ctx.event()
+                      ->set_chrome_mojo_event_info()
+                      ->set_watcher_notify_interface_tag(handler_tag_);
+                });
 
     base::WeakPtr<SimpleWatcher> weak_self = weak_factory_.GetWeakPtr();
     callback.Run(result, state);

mojo/public/cpp/system/simple_watcher.h

@@ -90,7 +90,7 @@ class MOJO_CPP_SYSTEM_EXPORT SimpleWatcher {
                 ArmingPolicy arming_policy,
                 scoped_refptr<base::SequencedTaskRunner> runner =
                     base::SequencedTaskRunnerHandle::Get(),
-                const char* heap_profiler_tag = nullptr);
+                const char* handler_tag = nullptr);
   ~SimpleWatcher();
 
   // Indicates if the SimpleWatcher is currently watching a handle.
@@ -226,7 +226,7 @@ class MOJO_CPP_SYSTEM_EXPORT SimpleWatcher {
 
   // Tag used to ID memory allocations that originated from notifications in
   // this watcher.
-  const char* heap_profiler_tag_ = nullptr;
+  const char* handler_tag_ = nullptr;
 
   base::WeakPtrFactory<SimpleWatcher> weak_factory_{this};
 

services/tracing/perfetto/privacy_filtered_fields-inl.h

@@ -170,10 +170,15 @@ constexpr MessageInfo kChromeFrameReporter = {kChromeFrameReporterIndices,
 constexpr int kChromeMessagePumpIndices[] = {1, -1};
 constexpr MessageInfo kChromeMessagePump = {kChromeMessagePumpIndices, nullptr};
 
+// Proto Message: ChromeMojoEventInfo
+constexpr int kChromeMojoEventInfoIndices[] = {1, -1};
+constexpr MessageInfo kChromeMojoEventInfo = {kChromeMojoEventInfoIndices,
+                                              nullptr};
+
 // Proto Message: TrackEvent
-constexpr int kTrackEventIndices[] = {1,  2,  3,  5,  6,  9,  10, 11,
-                                      12, 16, 17, 24, 25, 26, 27, 28,
-                                      29, 30, 31, 32, 33, 34, 35, -1};
+constexpr int kTrackEventIndices[] = {1,  2,  3,  5,  6,  9,  10, 11, 12,
+                                      16, 17, 24, 25, 26, 27, 28, 29, 30,
+                                      31, 32, 33, 34, 35, 38, -1};
 constexpr MessageInfo const* kTrackEventComplexMessages[] = {
     nullptr,
     nullptr,
@@ -197,7 +202,8 @@ constexpr MessageInfo const* kTrackEventComplexMessages[] = {
     &kChromeFrameReporter,
     &kSourceLocation,
     nullptr,
-    &kChromeMessagePump};
+    &kChromeMessagePump,
+    &kChromeMojoEventInfo};
 constexpr MessageInfo kTrackEvent = {kTrackEventIndices,
                                      kTrackEventComplexMessages};