processor: Export async event thread timestamps to JSON

Related importer patch: aosp/1085917

Bug: 130786269
Change-Id: I2e4258aaadc5dd523063604e2d4793d1153d4243

src/trace_processor/export_json.cc

diff --git a/src/trace_processor/export_json.cc b/src/trace_processor/export_json.cc
index 5a191a3..03d996f 100644
--- a/src/trace_processor/export_json.cc
+++ b/src/trace_processor/export_json.cc
@@ -269,6 +269,27 @@
       uint32_t track_id = static_cast<uint32_t>(slices.refs()[i]);
       VirtualTrackScope scope = storage->virtual_tracks().scopes()[track_id];
       UniquePid upid = storage->virtual_tracks().upids()[track_id];
+
+      const auto& virtual_track_slices = storage->virtual_track_slices();
+      int64_t thread_end_ts_us = 0;
+      base::Optional<uint32_t> vtrack_slice_row =
+          virtual_track_slices.FindRowForSliceId(i);
+      if (vtrack_slice_row) {
+        int64_t thread_ts_ns =
+            virtual_track_slices.thread_timestamp_ns()[*vtrack_slice_row];
+        if (thread_ts_ns > 0) {
+          int64_t thread_ts_us = thread_ts_ns / 1000;
+          event["use_async_tts"] = Json::Int(1);
+          event["tts"] = Json::Int64(thread_ts_us);
+          int64_t thread_duration_ns =
+              virtual_track_slices.thread_duration_ns()[*vtrack_slice_row];
+          // If the slice didn't finish, the duration may be negative. Don't
+          // write the thread timestamp for the end event in this case.
+          if (thread_duration_ns >= 0)
+            thread_end_ts_us = thread_ts_us + (thread_duration_ns / 1000);
+        }
+      }
+
       if (scope == VirtualTrackScope::kGlobal) {
         event["id2"]["global"] = PrintUint64(track_id);
       } else {
@@ -284,6 +305,12 @@
         event["ph"] = "e";
         event["ts"] =
             Json::Int64((slices.start_ns()[i] + slices.durations()[i]) / 1000);
+        if (thread_end_ts_us) {
+          event["tts"] = Json::Int64(thread_end_ts_us);
+        } else {
+          event.removeMember("tts");
+          event.removeMember("use_async_tts");
+        }
         event.removeMember("args");
         writer->WriteCommonEvent(event);
       }

src/trace_processor/export_json_unittest.cc

diff --git a/src/trace_processor/export_json_unittest.cc b/src/trace_processor/export_json_unittest.cc
index b511616..4884e9e 100644
--- a/src/trace_processor/export_json_unittest.cc
+++ b/src/trace_processor/export_json_unittest.cc
@@ -549,6 +549,8 @@
   EXPECT_EQ(begin_event["cat"].asString(), kCategory);
   EXPECT_EQ(begin_event["name"].asString(), kName);
   EXPECT_EQ(begin_event["args"][kArgName].asInt(), kArgValue);
+  EXPECT_FALSE(begin_event.isMember("tts"));
+  EXPECT_FALSE(begin_event.isMember("use_async_tts"));
 
   Json::Value end_event = result["traceEvents"][1];
   EXPECT_EQ(end_event["ph"].asString(), "e");
@@ -558,6 +560,62 @@
   EXPECT_EQ(end_event["cat"].asString(), kCategory);
   EXPECT_EQ(end_event["name"].asString(), kName);
   EXPECT_FALSE(end_event.isMember("args"));
+  EXPECT_FALSE(end_event.isMember("tts"));
+  EXPECT_FALSE(end_event.isMember("use_async_tts"));
+}
+
+TEST(ExportJsonTest, AsyncEventWithThreadTimestamp) {
+  const int64_t kTimestamp = 10000000;
+  const int64_t kDuration = 100000;
+  const int64_t kThreadTimestamp = 10000001;
+  const int64_t kThreadDuration = 99998;
+  const int64_t kProcessID = 100;
+  const char* kCategory = "cat";
+  const char* kName = "name";
+
+  TraceStorage storage;
+  UniquePid upid = storage.AddEmptyProcess(kProcessID);
+  StringId cat_id = storage.InternString(base::StringView(kCategory));
+  StringId name_id = storage.InternString(base::StringView(kName));
+  uint32_t track_id = storage.mutable_virtual_tracks()->AddVirtualTrack(
+      0, 0, VirtualTrackScope::kProcess, upid);
+  auto slice_id = storage.mutable_nestable_slices()->AddSlice(
+      kTimestamp, kDuration, track_id, RefType::kRefTrack, cat_id, name_id, 0,
+      0, 0);
+  storage.mutable_virtual_track_slices()->AddVirtualTrackSlice(
+      slice_id, kThreadTimestamp, kThreadDuration, 0, 0);
+
+  base::TempFile temp_file = base::TempFile::Create();
+  FILE* output = fopen(temp_file.path().c_str(), "w+");
+  int code = ExportJson(&storage, output);
+
+  EXPECT_EQ(code, kResultOk);
+
+  Json::Reader reader;
+  Json::Value result;
+  EXPECT_TRUE(reader.parse(ReadFile(output), result));
+  EXPECT_EQ(result["traceEvents"].size(), 2u);
+
+  Json::Value begin_event = result["traceEvents"][0];
+  EXPECT_EQ(begin_event["ph"].asString(), "b");
+  EXPECT_EQ(begin_event["ts"].asInt64(), kTimestamp / 1000);
+  EXPECT_EQ(begin_event["tts"].asInt64(), kThreadTimestamp / 1000);
+  EXPECT_EQ(begin_event["use_async_tts"].asInt(), 1);
+  EXPECT_EQ(begin_event["pid"].asInt64(), kProcessID);
+  EXPECT_EQ(begin_event["id2"]["local"].asString(), "0x0");
+  EXPECT_EQ(begin_event["cat"].asString(), kCategory);
+  EXPECT_EQ(begin_event["name"].asString(), kName);
+
+  Json::Value end_event = result["traceEvents"][1];
+  EXPECT_EQ(end_event["ph"].asString(), "e");
+  EXPECT_EQ(end_event["ts"].asInt64(), (kTimestamp + kDuration) / 1000);
+  EXPECT_EQ(end_event["tts"].asInt64(),
+            (kThreadTimestamp + kThreadDuration) / 1000);
+  EXPECT_EQ(end_event["use_async_tts"].asInt(), 1);
+  EXPECT_EQ(end_event["pid"].asInt64(), kProcessID);
+  EXPECT_EQ(end_event["id2"]["local"].asString(), "0x0");
+  EXPECT_EQ(end_event["cat"].asString(), kCategory);
+  EXPECT_EQ(end_event["name"].asString(), kName);
 }
 
 TEST(ExportJsonTest, AsyncInstantEvent) {