trace_event: Add support for interned data in typed events

This patch adds support for interned data in typed trace points. This
helps to reduce trace size for frequently repeated data.

As an example, an interning index for base::Location could be defined as
follows:

struct InternedLocationIndex
    : public perfetto::TrackEventInternedDataIndex<
          InternedLocationIndex,
          perfetto::protos::pbzero::
              InternedData::kSourceLocationsFieldNumber,
          Location> {
  static void Add(perfetto::protos::pbzero::InternedData* interned_data,
                  size_t iid,
                  const Location& location) {
    auto* loc = interned_data->add_source_locations();
    loc->set_file_name(location.file_name());
    loc->set_function_name(location.function_name());
    loc->set_line_number(location.line_number());
  }
};

A corresponding typed trace point using the index could look like this:

  TRACE_EVENT("cat", "Name", [](perfetto::EventContext ctx) {
    auto* log = ctx.event()->set_log_message();
    size_t iid = InternedLocationIndex::Get(&ctx, FROM_HERE);
    log->set_body_iid(iid);
  }

Bug: b/156727531
Change-Id: I5a78784be688071f7373ac1655b1ce74428f7b0f
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2410117
Auto-Submit: Sami Kyöstilä <skyostil@chromium.org>
Commit-Queue: Wez <wez@chromium.org>
Reviewed-by: Wez <wez@chromium.org>
Reviewed-by: Stephen Nusko <nuskos@chromium.org>
Cr-Commit-Position: refs/heads/master@{#808484}

base/BUILD.gn

@@ -3377,6 +3377,12 @@ test("base_unittests") {
         "trace_event/trace_event_android_unittest.cc",
       ]
     }
+
+    deps += [
+      "//third_party/perfetto/protos/perfetto/trace:lite",
+      "//third_party/perfetto/protos/perfetto/trace/interned_data:lite",
+      "//third_party/perfetto/protos/perfetto/trace/track_event:lite",
+    ]
   }
 
   # TODO(jschuh): crbug.com/167187 fix size_t to int truncations.

base/trace_event/typed_macros_embedder_support.h

@@ -7,6 +7,7 @@
 
 #include "base/base_export.h"
 #include "base/trace_event/trace_event.h"
+#include "third_party/perfetto/include/perfetto/tracing/internal/track_event_internal.h"
 #include "third_party/perfetto/protos/perfetto/trace/track_event/track_event.pbzero.h"
 
 namespace base {
@@ -15,6 +16,7 @@ namespace trace_event {
 class BASE_EXPORT TrackEventHandle {
  public:
   using TrackEvent = perfetto::protos::pbzero::TrackEvent;
+  using IncrementalState = perfetto::internal::TrackEventIncrementalState;
 
   class BASE_EXPORT CompletionListener {
    public:
@@ -28,11 +30,15 @@ class BASE_EXPORT TrackEventHandle {
   // into the event. Note that |listener| must outlive the TRACE_EVENT call,
   // i.e. cannot be destroyed until OnTrackEventCompleted() is called. Ownership
   // of both TrackEvent and the listener remains with the caller.
-  TrackEventHandle(TrackEvent* event, CompletionListener* listener)
-      : event_(event), listener_(listener) {}
+  TrackEventHandle(TrackEvent* event,
+                   IncrementalState* incremental_state,
+                   CompletionListener* listener)
+      : event_(event),
+        incremental_state_(incremental_state),
+        listener_(listener) {}
 
   // Creates an invalid handle.
-  TrackEventHandle() : TrackEventHandle(nullptr, nullptr) {}
+  TrackEventHandle() : TrackEventHandle(nullptr, nullptr, nullptr) {}
 
   ~TrackEventHandle() {
     if (listener_)
@@ -44,8 +50,11 @@ class BASE_EXPORT TrackEventHandle {
   TrackEvent* operator->() const { return event_; }
   TrackEvent* get() const { return event_; }
 
+  IncrementalState* incremental_state() const { return incremental_state_; }
+
  private:
   TrackEvent* event_;
+  IncrementalState* incremental_state_;
   CompletionListener* listener_;
 };
 

base/trace_event/typed_macros_internal.h

@@ -113,7 +113,8 @@ static inline void AddTraceEvent(char phase,
   if (track)
     track_event->set_track_uuid(track.uuid);
 
-  argument_func(perfetto::EventContext(track_event.get()));
+  argument_func(perfetto::EventContext(track_event.get(),
+                                       track_event.incremental_state()));
 }
 
 template <

base/trace_event/typed_macros_unittest.cc

@@ -4,14 +4,19 @@
 
 #include "base/trace_event/typed_macros.h"
 
+#include "base/location.h"
 #include "base/synchronization/waitable_event.h"
 #include "base/trace_event/trace_log.h"
 #include "base/trace_event/typed_macros_embedder_support.h"
 #include "testing/gmock/include/gmock/gmock.h"
 #include "testing/gtest/include/gtest/gtest.h"
 #include "third_party/perfetto/include/perfetto/protozero/scattered_heap_buffer.h"
+#include "third_party/perfetto/include/perfetto/tracing/track_event_interned_data_index.h"
 
+#include "third_party/perfetto/protos/perfetto/trace/interned_data/interned_data.pb.h"
 #include "third_party/perfetto/protos/perfetto/trace/track_event/log_message.pbzero.h"
+#include "third_party/perfetto/protos/perfetto/trace/track_event/source_location.pb.h"
+#include "third_party/perfetto/protos/perfetto/trace/track_event/source_location.pbzero.h"
 
 namespace base {
 namespace trace_event {
@@ -56,6 +61,7 @@ struct TestTrackEvent : public TrackEventHandle::CompletionListener {
   }
 
   protozero::HeapBuffered<perfetto::protos::pbzero::TrackEvent> event;
+  perfetto::internal::TrackEventIncrementalState incremental_state;
   bool prepare_called = false;
   bool event_completed = false;
 };
@@ -63,7 +69,9 @@ struct TestTrackEvent : public TrackEventHandle::CompletionListener {
 TrackEventHandle PrepareTrackEvent(TraceEvent*) {
   CHECK_NE(g_test_track_event, nullptr) << "TestTrackEvent not set yet";
   g_test_track_event->prepare_called = true;
-  return TrackEventHandle(g_test_track_event->event.get(), g_test_track_event);
+  return TrackEventHandle(g_test_track_event->event.get(),
+                          &g_test_track_event->incremental_state,
+                          g_test_track_event);
 }
 
 class TypedTraceEventTest : public testing::Test {
@@ -107,5 +115,84 @@ TEST_F(TypedTraceEventTest, CallbackNotExecutedWhenTracingDisabled) {
   EXPECT_FALSE(event_.event_completed);
 }
 
+namespace {
+
+struct InternedLocationIndex
+    : public perfetto::TrackEventInternedDataIndex<
+          InternedLocationIndex,
+          perfetto::protos::pbzero::InternedData::kSourceLocationsFieldNumber,
+          Location> {
+  static void Add(perfetto::protos::pbzero::InternedData* interned_data,
+                  size_t iid,
+                  const Location& location) {
+    auto* loc = interned_data->add_source_locations();
+    loc->set_iid(iid);
+    loc->set_file_name(location.file_name());
+    loc->set_function_name(location.function_name());
+    loc->set_line_number(location.line_number());
+  }
+};
+
+}  // namespace
+
+TEST_F(TypedTraceEventTest, InternedData) {
+  TraceLog::GetInstance()->SetEnabled(TraceConfig(kRecordAllCategoryFilter, ""),
+                                      TraceLog::RECORDING_MODE);
+  const Location location("TestFunction", "test.cc", 123,
+                          reinterpret_cast<void*>(0xdada));
+  size_t iid = 0;
+
+  TRACE_EVENT("cat", "Name", [&location, &iid](perfetto::EventContext ctx) {
+    auto* log = ctx.event()->set_log_message();
+    iid = InternedLocationIndex::Get(&ctx, location);
+    EXPECT_NE(0u, iid);
+    log->set_body_iid(iid);
+
+    size_t iid2 = InternedLocationIndex::Get(&ctx, location);
+    EXPECT_EQ(iid, iid2);
+
+    Location location2("TestFunction2", "test.cc", 456,
+                       reinterpret_cast<void*>(0xf00d));
+    size_t iid3 = InternedLocationIndex::Get(&ctx, location2);
+    EXPECT_NE(0u, iid3);
+    EXPECT_NE(iid, iid3);
+  });
+
+  auto serialized_data =
+      event_.incremental_state.serialized_interned_data.SerializeAsArray();
+  perfetto::protos::InternedData interned_data;
+  EXPECT_TRUE(interned_data.ParseFromArray(serialized_data.data(),
+                                           serialized_data.size()));
+  EXPECT_EQ(2, interned_data.source_locations_size());
+  auto interned_loc = interned_data.source_locations()[0];
+  EXPECT_EQ(iid, interned_loc.iid());
+  EXPECT_EQ("TestFunction", interned_loc.function_name());
+  EXPECT_EQ("test.cc", interned_loc.file_name());
+  EXPECT_EQ(123u, interned_loc.line_number());
+  interned_loc = interned_data.source_locations()[1];
+  EXPECT_EQ("TestFunction2", interned_loc.function_name());
+  EXPECT_EQ("test.cc", interned_loc.file_name());
+  EXPECT_EQ(456u, interned_loc.line_number());
+
+  // Make sure the in-memory interning index persists between trace events by
+  // recording another event.
+  event_.incremental_state.serialized_interned_data.Reset();
+  event_.event_completed = false;
+
+  TRACE_EVENT("cat", "Name", [&location](perfetto::EventContext ctx) {
+    auto* log = ctx.event()->set_log_message();
+    size_t iid = InternedLocationIndex::Get(&ctx, location);
+    EXPECT_NE(0u, iid);
+    log->set_body_iid(iid);
+  });
+
+  // No new data should have been interned the second time around.
+  EXPECT_EQ(
+      "",
+      event_.incremental_state.serialized_interned_data.SerializeAsString());
+
+  CancelTrace();
+}
+
 }  // namespace trace_event
 }  // namespace base

services/tracing/public/cpp/perfetto/trace_event_data_source_unittest.cc

@@ -36,6 +36,7 @@
 #include "services/tracing/public/mojom/perfetto_service.mojom.h"
 #include "testing/gtest/include/gtest/gtest.h"
 #include "third_party/perfetto/include/perfetto/tracing/track.h"
+#include "third_party/perfetto/include/perfetto/tracing/track_event_interned_data_index.h"
 #include "third_party/perfetto/protos/perfetto/trace/clock_snapshot.pb.h"
 #include "third_party/perfetto/protos/perfetto/trace/trace_packet.pb.h"
 #include "third_party/perfetto/protos/perfetto/trace/trace_packet.pbzero.h"
@@ -1990,6 +1991,46 @@ TEST_F(TraceEventDataSourceTest, UserActionEvent) {
             base::HashMetricName("Test_Action"));
 }
 
+namespace {
+
+struct InternedLogMessageBody
+    : public perfetto::TrackEventInternedDataIndex<
+          InternedLogMessageBody,
+          perfetto::protos::pbzero::InternedData::kLogMessageBodyFieldNumber,
+          std::string> {
+  static void Add(perfetto::protos::pbzero::InternedData* interned_data,
+                  size_t iid,
+                  const std::string& body) {
+    auto* msg = interned_data->add_log_message_body();
+    msg->set_iid(iid);
+    msg->set_body(body);
+  }
+};
+
+}  // namespace
+
+TEST_F(TraceEventDataSourceTest, TypedEventInterning) {
+  CreateTraceEventDataSource();
+
+  {
+    TRACE_EVENT("browser", "bar", [&](perfetto::EventContext ctx) {
+      size_t iid = InternedLogMessageBody::Get(&ctx, "Hello interned world!");
+      ctx.event()->set_log_message()->set_body_iid(iid);
+    });
+  }
+  size_t packet_index = ExpectStandardPreamble();
+  auto* e_packet = producer_client()->GetFinalizedPacket(packet_index++);
+
+  ExpectEventCategories(e_packet, {{1u, "browser"}});
+  ExpectEventNames(e_packet, {{1u, "bar"}});
+  ASSERT_TRUE(e_packet->track_event().has_log_message());
+  ASSERT_TRUE(e_packet->has_interned_data());
+  EXPECT_EQ(e_packet->track_event().log_message().body_iid(),
+            e_packet->interned_data().log_message_body()[0].iid());
+  ASSERT_EQ("Hello interned world!",
+            e_packet->interned_data().log_message_body()[0].body());
+}
+
 // TODO(eseckler): Add startup tracing unittests.
 
 }  // namespace

services/tracing/public/cpp/perfetto/track_event_thread_local_event_sink.cc

@@ -271,15 +271,38 @@ TrackEventThreadLocalEventSink::AddTypedTraceEvent(
 
   // |pending_trace_packet_| will be finalized in OnTrackEventCompleted() after
   // the code in //base ran the typed trace point's argument function.
-  return base::trace_event::TrackEventHandle(track_event, this);
+  return base::trace_event::TrackEventHandle(track_event, &incremental_state_,
+                                             this);
 }
 
 void TrackEventThreadLocalEventSink::OnTrackEventCompleted() {
   DCHECK(pending_trace_packet_);
 
+  auto& serialized_interned_data = incremental_state_.serialized_interned_data;
   if (!pending_interning_updates_.empty()) {
+    // TODO(skyostil): Combine |pending_interning_updates_| and
+    // |serialized_interned_data| so we don't need to merge the two here.
+    if (!serialized_interned_data.empty()) {
+      EmitStoredInternedData(serialized_interned_data.get());
+    } else {
       EmitStoredInternedData(pending_trace_packet_->set_interned_data());
     }
+  }
+
+  // When the track event is finalized (i.e., the context is destroyed), we
+  // should flush any newly seen interned data to the trace. The data has
+  // earlier been written to a heap allocated protobuf message
+  // (|serialized_interned_data|). Here we just need to flush it to the main
+  // trace.
+  if (!serialized_interned_data.empty()) {
+    auto ranges = serialized_interned_data.GetRanges();
+    pending_trace_packet_->AppendScatteredBytes(
+        perfetto::protos::pbzero::TracePacket::kInternedDataFieldNumber,
+        &ranges[0], ranges.size());
+
+    // Reset the message but keep one buffer allocated for future use.
+    serialized_interned_data.Reset();
+  }
 
   pending_trace_packet_ = perfetto::TraceWriter::TracePacketHandle();
 
@@ -932,6 +955,8 @@ void TrackEventThreadLocalEventSink::DoResetIncrementalState(
   interned_source_locations_.ResetEmittedState();
   interned_log_message_bodies_.ResetEmittedState();
   extra_emitted_track_descriptor_uuids_.clear();
+  incremental_state_.interned_data_indices = {};
+  incremental_state_.seen_tracks.clear();
 
   // Reset the reference timestamp.
   base::TimeTicks timestamp;

services/tracing/public/cpp/perfetto/track_event_thread_local_event_sink.h

@@ -152,6 +152,10 @@ class COMPONENT_EXPORT(TRACING_CPP) TrackEventThreadLocalEventSink
       interned_log_message_bodies_;
   InternedIndexesUpdates pending_interning_updates_;
 
+  // Track event interning state.
+  // TODO(skyostil): Merge the above interning indices into this.
+  perfetto::internal::TrackEventIncrementalState incremental_state_;
+
   std::vector<uint64_t> extra_emitted_track_descriptor_uuids_;
 
   static std::atomic<uint32_t> incremental_state_reset_id_;