processor: Import and export legacy flow event args for all TrackEvents
(Legacy) flow events can be attached to events of any phase, including
those that we import into native (non-raw events) tables in TP.
To preserve them for proto2json conversion, also import the flow-event
related args for slices into their args set and convert them back into
the legacy json event attributes during export_json().
Bug: 130786981, 130786269
Change-Id: I89d5b846009b5ecff350e6b26361576187eee1cd
diff --git a/src/trace_processor/export_json.cc b/src/trace_processor/export_json.cc
index 64f6644..e3c5950 100644
--- a/src/trace_processor/export_json.cc
+++ b/src/trace_processor/export_json.cc
@@ -38,6 +38,26 @@
using IndexMap = perfetto::trace_processor::TraceStorage::Stats::IndexMap;
+const char kLegacyEventArgsKey[] = "legacy_event";
+const char kLegacyEventCategoryKey[] = "category";
+const char kLegacyEventNameKey[] = "name";
+const char kLegacyEventPhaseKey[] = "phase";
+const char kLegacyEventDurationNsKey[] = "duration_ns";
+const char kLegacyEventThreadTimestampNsKey[] = "thread_timestamp_ns";
+const char kLegacyEventThreadDurationNsKey[] = "thread_duration_ns";
+const char kLegacyEventThreadInstructionCountKey[] = "thread_instruction_count";
+const char kLegacyEventThreadInstructionDeltaKey[] = "thread_instruction_delta";
+const char kLegacyEventUseAsyncTtsKey[] = "use_async_tts";
+const char kLegacyEventGlobalIdKey[] = "global_id";
+const char kLegacyEventLocalIdKey[] = "local_id";
+const char kLegacyEventIdScopeKey[] = "id_scope";
+const char kLegacyEventBindIdKey[] = "bind_id";
+const char kLegacyEventBindToEnclosingKey[] = "bind_to_enclosing";
+const char kLegacyEventFlowDirectionKey[] = "flow_direction";
+const char kFlowDirectionValueIn[] = "in";
+const char kFlowDirectionValueOut[] = "out";
+const char kFlowDirectionValueInout[] = "inout";
+
const char* GetNonNullString(const TraceStorage* storage, StringId id) {
return id == kNullStringId ? "" : storage->GetString(id).c_str();
}
@@ -267,6 +287,33 @@
std::vector<Json::Value> args_sets_;
};
+void ConvertLegacyFlowEventArgs(const Json::Value& legacy_args,
+ Json::Value* event) {
+ if (legacy_args.isMember(kLegacyEventIdScopeKey))
+ (*event)["scope"] = legacy_args[kLegacyEventIdScopeKey];
+
+ if (legacy_args.isMember(kLegacyEventBindIdKey)) {
+ (*event)["bind_id"] =
+ PrintUint64(legacy_args[kLegacyEventBindIdKey].asUInt64());
+ }
+
+ if (legacy_args.isMember(kLegacyEventBindToEnclosingKey))
+ (*event)["bp"] = "e";
+
+ if (legacy_args.isMember(kLegacyEventFlowDirectionKey)) {
+ const char* val = legacy_args[kLegacyEventFlowDirectionKey].asCString();
+ if (strcmp(val, kFlowDirectionValueIn) == 0) {
+ (*event)["flow_in"] = true;
+ } else if (strcmp(val, kFlowDirectionValueOut) == 0) {
+ (*event)["flow_out"] = true;
+ } else {
+ PERFETTO_DCHECK(strcmp(val, kFlowDirectionValueInout) == 0);
+ (*event)["flow_in"] = true;
+ (*event)["flow_out"] = true;
+ }
+ }
+}
+
ResultCode ExportThreadNames(const TraceStorage* storage,
TraceFormatWriter* writer) {
for (UniqueTid i = 1; i < storage->thread_count(); ++i) {
@@ -304,7 +351,14 @@
event["pid"] = 0;
const Json::Value& args = args_builder.GetArgs(slices.arg_set_ids()[i]);
if (!args.empty()) {
- event["args"] = args;
+ event["args"] = args; // Makes a copy of |args|.
+
+ if (event["args"].isMember(kLegacyEventArgsKey)) {
+ ConvertLegacyFlowEventArgs(event["args"][kLegacyEventArgsKey], &event);
+
+ if (event["args"].empty())
+ event.removeMember("args");
+ }
}
if (slices.types()[i] == RefType::kRefTrack) { // Async event.
@@ -460,28 +514,6 @@
Json::Value ConvertLegacyRawEventToJson(const TraceStorage* storage,
const ArgsBuilder& args_builder,
uint32_t index) {
- const char kLegacyEventArgsKey[] = "legacy_event";
- const char kLegacyEventCategoryKey[] = "category";
- const char kLegacyEventNameKey[] = "name";
- const char kLegacyEventPhaseKey[] = "phase";
- const char kLegacyEventDurationNsKey[] = "duration_ns";
- const char kLegacyEventThreadTimestampNsKey[] = "thread_timestamp_ns";
- const char kLegacyEventThreadDurationNsKey[] = "thread_duration_ns";
- const char kLegacyEventThreadInstructionCountKey[] =
- "thread_instruction_count";
- const char kLegacyEventThreadInstructionDeltaKey[] =
- "thread_instruction_delta";
- const char kLegacyEventUseAsyncTtsKey[] = "use_async_tts";
- const char kLegacyEventGlobalIdKey[] = "global_id";
- const char kLegacyEventLocalIdKey[] = "local_id";
- const char kLegacyEventIdScopeKey[] = "id_scope";
- const char kLegacyEventBindIdKey[] = "bind_id";
- const char kLegacyEventBindToEnclosingKey[] = "bind_to_enclosing";
- const char kLegacyEventFlowDirectionKey[] = "flow_direction";
- const char kFlowDirectionValueIn[] = "in";
- const char kFlowDirectionValueOut[] = "out";
- const char kFlowDirectionValueInout[] = "inout";
-
const auto& events = storage->raw_events();
Json::Value event;
@@ -495,10 +527,9 @@
}
// Raw legacy events store all other params in the arg set. Make a copy of
- // the converted args here and remove these params.
- Json::Value args = args_builder.GetArgs(events.arg_set_ids()[index]);
- Json::Value legacy_args = args[kLegacyEventArgsKey];
- args.removeMember(kLegacyEventArgsKey);
+ // the converted args here, parse, and then remove the legacy params.
+ event["args"] = args_builder.GetArgs(events.arg_set_ids()[index]);
+ const Json::Value& legacy_args = event["args"][kLegacyEventArgsKey];
PERFETTO_DCHECK(legacy_args.isMember(kLegacyEventCategoryKey));
event["cat"] = legacy_args[kLegacyEventCategoryKey];
@@ -509,9 +540,8 @@
PERFETTO_DCHECK(legacy_args.isMember(kLegacyEventPhaseKey));
event["ph"] = legacy_args[kLegacyEventPhaseKey];
- if (legacy_args.isMember(kLegacyEventDurationNsKey)) {
+ if (legacy_args.isMember(kLegacyEventDurationNsKey))
event["dur"] = legacy_args[kLegacyEventDurationNsKey].asInt64() / 1000;
- }
if (legacy_args.isMember(kLegacyEventThreadTimestampNsKey)) {
event["tts"] =
@@ -523,17 +553,14 @@
legacy_args[kLegacyEventThreadDurationNsKey].asInt64() / 1000;
}
- if (legacy_args.isMember(kLegacyEventThreadInstructionCountKey)) {
+ if (legacy_args.isMember(kLegacyEventThreadInstructionCountKey))
event["ticount"] = legacy_args[kLegacyEventThreadInstructionCountKey];
- }
- if (legacy_args.isMember(kLegacyEventThreadInstructionDeltaKey)) {
+ if (legacy_args.isMember(kLegacyEventThreadInstructionDeltaKey))
event["tidelta"] = legacy_args[kLegacyEventThreadInstructionDeltaKey];
- }
- if (legacy_args.isMember(kLegacyEventUseAsyncTtsKey)) {
+ if (legacy_args.isMember(kLegacyEventUseAsyncTtsKey))
event["use_async_tts"] = legacy_args[kLegacyEventUseAsyncTtsKey];
- }
if (legacy_args.isMember(kLegacyEventGlobalIdKey)) {
event["id2"]["global"] =
@@ -545,35 +572,11 @@
PrintUint64(legacy_args[kLegacyEventLocalIdKey].asUInt64());
}
- if (legacy_args.isMember(kLegacyEventIdScopeKey)) {
- event["scope"] = legacy_args[kLegacyEventIdScopeKey];
- }
+ ConvertLegacyFlowEventArgs(legacy_args, &event);
- if (legacy_args.isMember(kLegacyEventBindIdKey)) {
- event["bind_id"] =
- PrintUint64(legacy_args[kLegacyEventBindIdKey].asUInt64());
- }
-
- if (legacy_args.isMember(kLegacyEventBindToEnclosingKey)) {
- event["bp"] = "e";
- }
-
- if (legacy_args.isMember(kLegacyEventFlowDirectionKey)) {
- const char* val = legacy_args[kLegacyEventFlowDirectionKey].asCString();
- if (strcmp(val, kFlowDirectionValueIn) == 0) {
- event["flow_in"] = true;
- } else if (strcmp(val, kFlowDirectionValueOut) == 0) {
- event["flow_out"] = true;
- } else {
- PERFETTO_DCHECK(strcmp(val, kFlowDirectionValueInout) == 0);
- event["flow_in"] = true;
- event["flow_out"] = true;
- }
- }
-
- if (!args.empty()) {
- event["args"] = args;
- }
+ event["args"].removeMember(kLegacyEventArgsKey);
+ if (event["args"].empty())
+ event.removeMember("args");
return event;
}
diff --git a/src/trace_processor/export_json_unittest.cc b/src/trace_processor/export_json_unittest.cc
index 511f677..d57e856 100644
--- a/src/trace_processor/export_json_unittest.cc
+++ b/src/trace_processor/export_json_unittest.cc
@@ -104,6 +104,7 @@
EXPECT_EQ(event["name"].asString(), kName);
EXPECT_FALSE(event.isMember("args"));
}
+
TEST(ExportJsonTest, StorageWithOneUnfinishedSlice) {
const int64_t kTimestamp = 10000000;
const int64_t kDuration = -1;
@@ -381,6 +382,63 @@
EXPECT_EQ(event["args"]["src"].asString(), kSrc);
}
+TEST(ExportJsonTest, StorageWithSliceAndFlowEventArgs) {
+ const char* kCategory = "cat";
+ const char* kName = "name";
+ constexpr TrackId track = 22;
+ const uint64_t kBindId = 0xaa00aa00aa00aa00;
+ const char* kFlowDirection = "inout";
+ const char* kArgName = "arg_name";
+ const int kArgValue = 123;
+
+ TraceProcessorContext context;
+ context.storage.reset(new TraceStorage());
+ TraceStorage* storage = context.storage.get();
+
+ UniqueTid utid = storage->AddEmptyThread(0);
+ StringId cat_id = storage->InternString(base::StringView(kCategory));
+ StringId name_id = storage->InternString(base::StringView(kName));
+ RowId row_id = TraceStorage::CreateRowId(
+ kNestableSlices,
+ storage->mutable_nestable_slices()->AddSlice(
+ 0, 0, track, utid, RefType::kRefUtid, cat_id, name_id, 0, 0, 0));
+
+ ArgsTracker args(&context);
+ auto add_arg = [&](const char* key, Variadic value) {
+ StringId key_id = storage->InternString(key);
+ args.AddArg(row_id, key_id, key_id, value);
+ };
+
+ add_arg("legacy_event.bind_id", Variadic::UnsignedInteger(kBindId));
+ add_arg("legacy_event.bind_to_enclosing", Variadic::Boolean(true));
+ StringId flow_direction_id = storage->InternString(kFlowDirection);
+ add_arg("legacy_event.flow_direction", Variadic::String(flow_direction_id));
+
+ add_arg(kArgName, Variadic::Integer(kArgValue));
+
+ args.Flush();
+
+ 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(), 1u);
+
+ Json::Value event = result["traceEvents"][0];
+ EXPECT_EQ(event["cat"].asString(), kCategory);
+ EXPECT_EQ(event["name"].asString(), kName);
+ EXPECT_EQ(event["bind_id"].asString(), "0xaa00aa00aa00aa00");
+ EXPECT_EQ(event["bp"].asString(), "e");
+ EXPECT_EQ(event["flow_in"].asBool(), true);
+ EXPECT_EQ(event["flow_out"].asBool(), true);
+ EXPECT_EQ(event["args"][kArgName].asInt(), kArgValue);
+}
+
TEST(ExportJsonTest, StorageWithListArgs) {
const char* kCategory = "cat";
const char* kName = "name";
diff --git a/src/trace_processor/proto_trace_parser.cc b/src/trace_processor/proto_trace_parser.cc
index 3ce4ef1..423c798 100644
--- a/src/trace_processor/proto_trace_parser.cc
+++ b/src/trace_processor/proto_trace_parser.cc
@@ -1849,7 +1849,7 @@
}
}
- auto args_callback = [this, &event, &sequence_state,
+ auto args_callback = [this, &event, &legacy_event, &sequence_state,
sequence_state_generation, ts,
utid](ArgsTracker* args_tracker, RowId row_id) {
for (auto it = event.debug_annotations(); it; ++it) {
@@ -1867,6 +1867,42 @@
sequence_state_generation, ts, utid, args_tracker,
row_id);
}
+
+ // TODO(eseckler): Parse legacy flow events into flow events table once we
+ // have a design for it.
+ if (legacy_event.has_bind_id()) {
+ args_tracker->AddArg(row_id, legacy_event_bind_id_key_id_,
+ legacy_event_bind_id_key_id_,
+ Variadic::UnsignedInteger(legacy_event.bind_id()));
+ }
+
+ if (legacy_event.bind_to_enclosing()) {
+ args_tracker->AddArg(row_id, legacy_event_bind_to_enclosing_key_id_,
+ legacy_event_bind_to_enclosing_key_id_,
+ Variadic::Boolean(true));
+ }
+
+ if (legacy_event.flow_direction()) {
+ StringId value;
+ switch (legacy_event.flow_direction()) {
+ case protos::pbzero::TrackEvent::LegacyEvent::FLOW_IN:
+ value = flow_direction_value_in_id_;
+ break;
+ case protos::pbzero::TrackEvent::LegacyEvent::FLOW_OUT:
+ value = flow_direction_value_out_id_;
+ break;
+ case protos::pbzero::TrackEvent::LegacyEvent::FLOW_INOUT:
+ value = flow_direction_value_inout_id_;
+ break;
+ default:
+ PERFETTO_FATAL("Unknown flow direction: %d",
+ legacy_event.flow_direction());
+ break;
+ }
+ args_tracker->AddArg(row_id, legacy_event_flow_direction_key_id_,
+ legacy_event_flow_direction_key_id_,
+ Variadic::String(value));
+ }
};
switch (static_cast<char>(phase)) {
@@ -2088,8 +2124,6 @@
StringId name_id,
const protos::pbzero::TrackEvent::LegacyEvent::Decoder& legacy_event,
SliceTracker::SetArgsCallback args_callback) {
- using LegacyEvent = protos::pbzero::TrackEvent::LegacyEvent;
-
if (!utid) {
context_->storage->IncrementStats(stats::track_event_parser_errors);
PERFETTO_DLOG("raw legacy event without thread association");
@@ -2167,41 +2201,6 @@
context_->storage->InternString(legacy_event.id_scope())));
}
- // TODO(eseckler): Parse legacy flow events into flow events table once we
- // have a design for it.
- if (legacy_event.has_bind_id()) {
- args.AddArg(row_id, legacy_event_bind_id_key_id_,
- legacy_event_bind_id_key_id_,
- Variadic::UnsignedInteger(legacy_event.bind_id()));
- }
-
- if (legacy_event.bind_to_enclosing()) {
- args.AddArg(row_id, legacy_event_bind_to_enclosing_key_id_,
- legacy_event_bind_to_enclosing_key_id_,
- Variadic::Boolean(true));
- }
-
- if (legacy_event.flow_direction()) {
- StringId value;
- switch (legacy_event.flow_direction()) {
- case LegacyEvent::FLOW_IN:
- value = flow_direction_value_in_id_;
- break;
- case LegacyEvent::FLOW_OUT:
- value = flow_direction_value_out_id_;
- break;
- case LegacyEvent::FLOW_INOUT:
- value = flow_direction_value_inout_id_;
- break;
- default:
- PERFETTO_FATAL("Unknown flow direction: %d",
- legacy_event.flow_direction());
- break;
- }
- args.AddArg(row_id, legacy_event_flow_direction_key_id_,
- legacy_event_flow_direction_key_id_, Variadic::String(value));
- }
-
// No need to parse legacy_event.instant_event_scope() because we import
// instant events into the slice table.
diff --git a/src/trace_processor/proto_trace_parser_unittest.cc b/src/trace_processor/proto_trace_parser_unittest.cc
index f751b8d..9b6c7d5 100644
--- a/src/trace_processor/proto_trace_parser_unittest.cc
+++ b/src/trace_processor/proto_trace_parser_unittest.cc
@@ -950,6 +950,10 @@
legacy_event->set_duration_us(23); // absolute end: 1028.
legacy_event->set_thread_duration_us(12); // absolute end: 2015.
legacy_event->set_thread_instruction_delta(50); // absolute end: 3060.
+ legacy_event->set_bind_id(9999);
+ legacy_event->set_bind_to_enclosing(true);
+ legacy_event->set_flow_direction(
+ protos::pbzero::TrackEvent::LegacyEvent::FLOW_INOUT);
auto* interned_data = packet->set_interned_data();
auto cat2 = interned_data->add_event_categories();
@@ -991,12 +995,17 @@
InSequence in_sequence; // Below slices should be sorted by timestamp.
+ RowId first_slice_row_id =
+ TraceStorage::CreateRowId(TableId::kNestableSlices, 3u);
EXPECT_CALL(*slice_, Scoped(1005000, thread_1_track, 1, RefType::kRefUtid,
StringId(1), StringId(2), 23000, _))
- .WillOnce(DoAll(
- InvokeArgument<7>(
- &args, TraceStorage::CreateRowId(TableId::kNestableSlices, 0u)),
- Return(0u)));
+ .WillOnce(
+ DoAll(InvokeArgument<7>(&args, first_slice_row_id), Return(0u)));
+
+ EXPECT_CALL(
+ args, AddArg(first_slice_row_id, _, _, Variadic::UnsignedInteger(9999u)));
+ EXPECT_CALL(args, AddArg(first_slice_row_id, _, _, Variadic::Boolean(true)));
+ EXPECT_CALL(args, AddArg(first_slice_row_id, _, _, _));
EXPECT_CALL(*slice_, Begin(1010000, thread_1_track, 1, RefType::kRefUtid,
StringId(3), StringId(4), _))
