processor: Export instant events on global/process tracks correctly We need to distinguish between instant events on global/process/ thread-associated async tracks and on non-async tracks (global or process associated), so that we can export the latter as non-async process- or global-scoped instant events to JSON. Bug: 130786269, chromium:1046381 Change-Id: Ibdc997c150faa31e5374d853831c9e567aa6feea
diff --git a/src/trace_processor/export_json.cc b/src/trace_processor/export_json.cc index 220debb..42370f7 100644 --- a/src/trace_processor/export_json.cc +++ b/src/trace_processor/export_json.cc
@@ -766,9 +766,11 @@ auto track_args_id = track_table.source_arg_set_id()[track_row]; const Json::Value* track_args = nullptr; bool legacy_chrome_track = false; + bool is_child_track = false; if (track_args_id) { track_args = &args_builder_.GetArgs(*track_args_id); legacy_chrome_track = (*track_args)["source"].asString() == "chrome"; + is_child_track = track_args->isMember("parent_track_id"); } const auto& thread_track = storage_->thread_track_table(); @@ -811,7 +813,7 @@ auto opt_thread_track_row = thread_track.id().IndexOf(TrackId{track_id}); - if (opt_thread_track_row) { + if (opt_thread_track_row && !is_child_track) { // Synchronous (thread) slice or instant event. UniqueTid utid = thread_track.utid()[*opt_thread_track_row]; auto pid_and_tid = UtidToPidAndTid(utid); @@ -852,7 +854,7 @@ } } writer_.WriteCommonEvent(event); - } else if (!legacy_chrome_track || + } else if (is_child_track || (legacy_chrome_track && track_args->isMember("source_id"))) { // Async event slice. auto opt_process_row = process_track.id().IndexOf(TrackId{track_id}); @@ -889,14 +891,20 @@ event["id"] = PrintUint64(source_id); } } else { - if (opt_process_row) { - uint32_t upid = process_track.upid()[*opt_process_row]; + if (opt_thread_track_row) { + UniqueTid utid = thread_track.utid()[*opt_thread_track_row]; + auto pid_and_tid = UtidToPidAndTid(utid); + event["pid"] = Json::Int(pid_and_tid.first); + event["tid"] = Json::Int(pid_and_tid.second); event["id2"]["local"] = PrintUint64(track_id); + } else if (opt_process_row) { + uint32_t upid = process_track.upid()[*opt_process_row]; uint32_t exported_pid = UpidToPid(upid); event["pid"] = Json::Int(exported_pid); event["tid"] = Json::Int(legacy_utid ? UtidToPidAndTid(*legacy_utid).second : exported_pid); + event["id2"]["local"] = PrintUint64(track_id); } else { // Some legacy importers don't understand "id2" fields, so we use // the "usually" global "id" field instead. This works as long as @@ -940,24 +948,31 @@ } } else { // Global or process-scoped instant event. - PERFETTO_DCHECK(legacy_chrome_track); - PERFETTO_DCHECK(duration_ns == 0); - // Use "I" instead of "i" phase for backwards-compat with old consumers. - event["ph"] = "I"; - - auto opt_process_row = process_track.id().IndexOf(TrackId{track_id}); - if (opt_process_row.has_value()) { - uint32_t upid = process_track.upid()[*opt_process_row]; - uint32_t exported_pid = UpidToPid(upid); - event["pid"] = Json::Int(exported_pid); - event["tid"] = - Json::Int(legacy_utid ? UtidToPidAndTid(*legacy_utid).second - : exported_pid); - event["s"] = "p"; + PERFETTO_DCHECK(legacy_chrome_track || !is_child_track); + if (duration_ns != 0) { + // We don't support exporting slices on the default global or process + // track to JSON (JSON only supports instant events on these tracks). + PERFETTO_DLOG( + "skipping non-instant slice on global or process track"); } else { - event["s"] = "g"; + // Use "I" instead of "i" phase for backwards-compat with old + // consumers. + event["ph"] = "I"; + + auto opt_process_row = process_track.id().IndexOf(TrackId{track_id}); + if (opt_process_row.has_value()) { + uint32_t upid = process_track.upid()[*opt_process_row]; + uint32_t exported_pid = UpidToPid(upid); + event["pid"] = Json::Int(exported_pid); + event["tid"] = + Json::Int(legacy_utid ? UtidToPidAndTid(*legacy_utid).second + : exported_pid); + event["s"] = "p"; + } else { + event["s"] = "g"; + } + writer_.WriteCommonEvent(event); } - writer_.WriteCommonEvent(event); } } return util::OkStatus();
diff --git a/src/trace_processor/export_json_unittest.cc b/src/trace_processor/export_json_unittest.cc index 6d149e6..14ca221 100644 --- a/src/trace_processor/export_json_unittest.cc +++ b/src/trace_processor/export_json_unittest.cc
@@ -716,9 +716,12 @@ TEST_F(ExportJsonTest, InstantEvent) { const int64_t kTimestamp = 10000000; + const int64_t kTimestamp2 = 10001000; + const int64_t kTimestamp3 = 10002000; const char* kCategory = "cat"; const char* kName = "name"; + // Global legacy track. TrackId track = context_.track_tracker->GetOrCreateLegacyChromeGlobalInstantTrack(); context_.args_tracker->Flush(); // Flush track args. @@ -727,6 +730,19 @@ context_.storage->mutable_slice_table()->Insert( {kTimestamp, 0, track.value, cat_id, name_id, 0, 0, 0}); + // Global track. + TrackId track2 = context_.track_tracker->GetOrCreateDefaultDescriptorTrack(); + context_.args_tracker->Flush(); // Flush track args. + context_.storage->mutable_slice_table()->Insert( + {kTimestamp2, 0, track2.value, cat_id, name_id, 0, 0, 0}); + + // Async event track. + context_.track_tracker->ReserveDescriptorChildTrack(1234, 0); + TrackId track3 = *context_.track_tracker->GetDescriptorTrack(1234); + context_.args_tracker->Flush(); // Flush track args. + context_.storage->mutable_slice_table()->Insert( + {kTimestamp3, 0, track3.value, cat_id, name_id, 0, 0, 0}); + base::TempFile temp_file = base::TempFile::Create(); FILE* output = fopen(temp_file.path().c_str(), "w+"); util::Status status = ExportJson(context_.storage.get(), output); @@ -734,7 +750,7 @@ EXPECT_TRUE(status.ok()); Json::Value result = ToJsonValue(ReadFile(output)); - EXPECT_EQ(result["traceEvents"].size(), 1u); + EXPECT_EQ(result["traceEvents"].size(), 3u); Json::Value event = result["traceEvents"][0]; EXPECT_EQ(event["ph"].asString(), "I"); @@ -742,6 +758,20 @@ EXPECT_EQ(event["s"].asString(), "g"); EXPECT_EQ(event["cat"].asString(), kCategory); EXPECT_EQ(event["name"].asString(), kName); + + Json::Value event2 = result["traceEvents"][1]; + EXPECT_EQ(event2["ph"].asString(), "I"); + EXPECT_EQ(event2["ts"].asInt64(), kTimestamp2 / 1000); + EXPECT_EQ(event2["s"].asString(), "g"); + EXPECT_EQ(event2["cat"].asString(), kCategory); + EXPECT_EQ(event2["name"].asString(), kName); + + Json::Value event3 = result["traceEvents"][2]; + EXPECT_EQ(event3["ph"].asString(), "n"); + EXPECT_EQ(event3["ts"].asInt64(), kTimestamp3 / 1000); + EXPECT_EQ(event3["id"].asString(), "0x2"); + EXPECT_EQ(event3["cat"].asString(), kCategory); + EXPECT_EQ(event3["name"].asString(), kName); } TEST_F(ExportJsonTest, InstantEventOnThread) {
diff --git a/src/trace_processor/importers/proto/proto_trace_parser_unittest.cc b/src/trace_processor/importers/proto/proto_trace_parser_unittest.cc index 5fd1d74..d490f9a 100644 --- a/src/trace_processor/importers/proto/proto_trace_parser_unittest.cc +++ b/src/trace_processor/importers/proto/proto_trace_parser_unittest.cc
@@ -1328,7 +1328,7 @@ EXPECT_CALL(*slice_, Scoped(1015000, TrackId{0}, cat_2, ev_2, 0, _)) .WillOnce(Return(1u)); - EXPECT_CALL(*slice_, Scoped(1016000, TrackId{2}, cat_3, ev_3, 0, _)) + EXPECT_CALL(*slice_, Scoped(1016000, TrackId{3}, cat_3, ev_3, 0, _)) .WillOnce(Return(2u)); EXPECT_CALL(*slice_, @@ -1337,12 +1337,13 @@ context_.sorter->ExtractEventsForced(); - // First track is "Thread track 1"; second is "Async track 1", third is - // "Thread track 2". - EXPECT_EQ(storage_->track_table().row_count(), 3u); + // First track is "Thread track 1"; second is "Async track 1", third is global + // default track (parent of async track), fourth is "Thread track 2". + EXPECT_EQ(storage_->track_table().row_count(), 4u); EXPECT_EQ(storage_->track_table().name().GetString(0), "Thread track 1"); EXPECT_EQ(storage_->track_table().name().GetString(1), "Async track 1"); - EXPECT_EQ(storage_->track_table().name().GetString(2), "Thread track 2"); + EXPECT_EQ(storage_->track_table().name().GetString(2), "Default Track"); + EXPECT_EQ(storage_->track_table().name().GetString(3), "Thread track 2"); EXPECT_EQ(storage_->thread_track_table().row_count(), 2u); EXPECT_EQ(storage_->thread_track_table().utid()[0], 1u); EXPECT_EQ(storage_->thread_track_table().utid()[1], 2u);
diff --git a/src/trace_processor/track_tracker.cc b/src/trace_processor/track_tracker.cc index 94661b8..0ff0bd3 100644 --- a/src/trace_processor/track_tracker.cc +++ b/src/trace_processor/track_tracker.cc
@@ -31,6 +31,7 @@ source_id_is_process_scoped_key_( context->storage->InternString("source_id_is_process_scoped")), source_scope_key_(context->storage->InternString("source_scope")), + parent_track_id_key_(context->storage->InternString("parent_track_id")), fuchsia_source_(context->storage->InternString("fuchsia")), chrome_source_(context->storage->InternString("chrome")), android_source_(context->storage->InternString("android")), @@ -364,11 +365,20 @@ if (!track_id) { tables::TrackTable::Row track; track_id = context_->storage->mutable_track_table()->Insert(track); + // The global track with no uuid is the default global track (e.g. for + // global instant events). Any other global tracks are considered children + // of the default track. + if (!parent_track_id && uuid) + parent_track_id = GetOrCreateDefaultDescriptorTrack(); } - context_->args_tracker->AddArgsTo(*track_id) - .AddArg(source_key_, Variadic::String(descriptor_source_)) + auto args = context_->args_tracker->AddArgsTo(*track_id); + args.AddArg(source_key_, Variadic::String(descriptor_source_)) .AddArg(source_id_key_, Variadic::Integer(static_cast<int64_t>(uuid))); + if (parent_track_id) { + args.AddArg(parent_track_id_key_, + Variadic::Integer(parent_track_id->value)); + } return *track_id; }
diff --git a/src/trace_processor/track_tracker.h b/src/trace_processor/track_tracker.h index de6233a..ddd6f11 100644 --- a/src/trace_processor/track_tracker.h +++ b/src/trace_processor/track_tracker.h
@@ -216,6 +216,7 @@ const StringId source_id_key_ = kNullStringId; const StringId source_id_is_process_scoped_key_ = kNullStringId; const StringId source_scope_key_ = kNullStringId; + const StringId parent_track_id_key_ = kNullStringId; const StringId fuchsia_source_ = kNullStringId; const StringId chrome_source_ = kNullStringId;