processor: Parse TrackEvent arguments
Parse TaskExecution source locations and debug annotations and emit
them into the slices table.
Also introduces new Variadic and ColumnType types for new types of
argument values. (We have to preserve pointer/json types in the storage
for the JSON export of those value types.)
Bug: 130786981
Change-Id: I88d710e8b79c8ca29f302317411be575ac45a974
diff --git a/include/perfetto/ext/base/string_writer.h b/include/perfetto/ext/base/string_writer.h
index 10e92a0..6bc7fad 100644
--- a/include/perfetto/ext/base/string_writer.h
+++ b/include/perfetto/ext/base/string_writer.h
@@ -68,34 +68,20 @@
// digits of the integer is less than |padding|.
template <char padchar, uint64_t padding>
void AppendPaddedInt(int64_t sign_value) {
- // Need to add 2 to the number of digits to account for minus sign and
- // rounding down of digits10.
- constexpr auto kMaxDigits = std::numeric_limits<uint64_t>::digits10 + 2;
- constexpr auto kSizeNeeded = kMaxDigits > padding ? kMaxDigits : padding;
- PERFETTO_DCHECK(pos_ + kSizeNeeded <= size_);
-
- char data[kSizeNeeded];
const bool negate = signbit(static_cast<double>(sign_value));
- uint64_t value = static_cast<uint64_t>(std::abs(sign_value));
+ uint64_t absolute_value = static_cast<uint64_t>(std::abs(sign_value));
+ AppendPaddedInt<padchar, padding>(absolute_value, negate);
+ }
- size_t idx;
- for (idx = kSizeNeeded - 1; value >= 10;) {
- char digit = value % 10;
- value /= 10;
- data[idx--] = digit + '0';
- }
- data[idx--] = static_cast<char>(value) + '0';
+ void AppendUnsignedInt(uint64_t value) {
+ AppendPaddedUnsignedInt<'0', 0>(value);
+ }
- if (padding > 0) {
- size_t num_digits = kSizeNeeded - 1 - idx;
- for (size_t i = num_digits; i < padding; i++) {
- data[idx--] = padchar;
- }
- }
-
- if (negate)
- buffer_[pos_++] = '-';
- AppendString(&data[idx + 1], kSizeNeeded - idx - 1);
+ // Appends an unsigned integer to the buffer, padding with |padchar| if the
+ // number of digits of the integer is less than |padding|.
+ template <char padchar, uint64_t padding>
+ void AppendPaddedUnsignedInt(uint64_t value) {
+ AppendPaddedInt<padchar, padding>(value, false);
}
// Appends a hex integer to the buffer.
@@ -118,6 +104,14 @@
pos_ += res;
}
+ void AppendBool(bool value) {
+ if (value) {
+ AppendLiteral("true");
+ return;
+ }
+ AppendLiteral("false");
+ }
+
StringView GetStringView() {
PERFETTO_DCHECK(pos_ <= size_);
return StringView(buffer_, pos_);
@@ -137,6 +131,36 @@
void reset() { pos_ = 0; }
private:
+ template <char padchar, uint64_t padding>
+ void AppendPaddedInt(uint64_t absolute_value, bool negate) {
+ // Need to add 2 to the number of digits to account for minus sign and
+ // rounding down of digits10.
+ constexpr auto kMaxDigits = std::numeric_limits<uint64_t>::digits10 + 2;
+ constexpr auto kSizeNeeded = kMaxDigits > padding ? kMaxDigits : padding;
+ PERFETTO_DCHECK(pos_ + kSizeNeeded <= size_);
+
+ char data[kSizeNeeded];
+
+ size_t idx;
+ for (idx = kSizeNeeded - 1; absolute_value >= 10;) {
+ char digit = absolute_value % 10;
+ absolute_value /= 10;
+ data[idx--] = digit + '0';
+ }
+ data[idx--] = static_cast<char>(absolute_value) + '0';
+
+ if (padding > 0) {
+ size_t num_digits = kSizeNeeded - 1 - idx;
+ for (size_t i = num_digits; i < padding; i++) {
+ data[idx--] = padchar;
+ }
+ }
+
+ if (negate)
+ buffer_[pos_++] = '-';
+ AppendString(&data[idx + 1], kSizeNeeded - idx - 1);
+ }
+
char* buffer_ = nullptr;
size_t size_ = 0;
size_t pos_ = 0;
diff --git a/src/base/string_writer_unittest.cc b/src/base/string_writer_unittest.cc
index 8d83dcc..12a7872 100644
--- a/src/base/string_writer_unittest.cc
+++ b/src/base/string_writer_unittest.cc
@@ -37,6 +37,11 @@
}
{
base::StringWriter writer(buffer, sizeof(buffer));
+ writer.AppendUnsignedInt(523);
+ ASSERT_EQ(writer.GetStringView().ToStdString(), "523");
+ }
+ {
+ base::StringWriter writer(buffer, sizeof(buffer));
writer.AppendPaddedInt<'0', 3>(0);
ASSERT_EQ(writer.GetStringView().ToStdString(), "000");
}
@@ -62,6 +67,11 @@
}
{
base::StringWriter writer(buffer, sizeof(buffer));
+ writer.AppendPaddedUnsignedInt<' ', 5>(123);
+ ASSERT_EQ(writer.GetStringView().ToStdString(), " 123");
+ }
+ {
+ base::StringWriter writer(buffer, sizeof(buffer));
writer.AppendDouble(123.25);
ASSERT_EQ(writer.GetStringView().ToStdString(), "123.250000");
}
@@ -75,6 +85,21 @@
writer.AppendInt(std::numeric_limits<int64_t>::max());
ASSERT_EQ(writer.GetStringView().ToStdString(), "9223372036854775807");
}
+ {
+ base::StringWriter writer(buffer, sizeof(buffer));
+ writer.AppendUnsignedInt(std::numeric_limits<uint64_t>::max());
+ ASSERT_EQ(writer.GetStringView().ToStdString(), "18446744073709551615");
+ }
+ {
+ base::StringWriter writer(buffer, sizeof(buffer));
+ writer.AppendBool(true);
+ ASSERT_EQ(writer.GetStringView().ToStdString(), "true");
+ }
+ {
+ base::StringWriter writer(buffer, sizeof(buffer));
+ writer.AppendBool(false);
+ ASSERT_EQ(writer.GetStringView().ToStdString(), "false");
+ }
constexpr char kTestStr[] = "test";
{
@@ -105,13 +130,16 @@
base::StringWriter writer(buffer, sizeof(buffer));
writer.AppendChar('0');
writer.AppendInt(132545);
+ writer.AppendUnsignedInt(523);
writer.AppendPaddedInt<'0', 0>(1);
writer.AppendPaddedInt<'0', 3>(0);
writer.AppendPaddedInt<'0', 1>(1);
writer.AppendPaddedInt<'0', 2>(1);
writer.AppendPaddedInt<'0', 3>(1);
writer.AppendPaddedInt<' ', 5>(123);
+ writer.AppendPaddedUnsignedInt<' ', 5>(456);
writer.AppendDouble(123.25);
+ writer.AppendBool(true);
constexpr char kTestStr[] = "test";
writer.AppendLiteral(kTestStr);
@@ -119,7 +147,7 @@
writer.AppendString(kTestStr);
ASSERT_EQ(writer.GetStringView().ToStdString(),
- "01325451000101001 123123.250000testtesttest");
+ "01325455231000101001 123 456123.250000truetesttesttest");
}
} // namespace
diff --git a/src/trace_processor/args_table.cc b/src/trace_processor/args_table.cc
index 8b781f2..bc89ef0 100644
--- a/src/trace_processor/args_table.cc
+++ b/src/trace_processor/args_table.cc
@@ -79,14 +79,30 @@
case Variadic::Type::kInt:
sqlite_utils::ReportSqliteResult(ctx, value.int_value);
break;
- case Variadic::Type::kReal:
- sqlite_utils::ReportSqliteResult(ctx, value.real_value);
+ case Variadic::Type::kUint:
+ // BEWARE: uint64 is handled as signed int64 for SQLite operations.
+ sqlite_utils::ReportSqliteResult(ctx,
+ static_cast<int64_t>(value.uint_value));
break;
case Variadic::Type::kString: {
const char* str = storage_->GetString(value.string_value).c_str();
sqlite3_result_text(ctx, str, -1, sqlite_utils::kSqliteStatic);
break;
}
+ case Variadic::Type::kReal:
+ sqlite_utils::ReportSqliteResult(ctx, value.real_value);
+ break;
+ case Variadic::Type::kPointer:
+ // BEWARE: pointers are handled as signed int64 for SQLite operations.
+ sqlite_utils::ReportSqliteResult(
+ ctx, static_cast<int64_t>(value.pointer_value));
+ break;
+ case Variadic::Type::kBool:
+ sqlite_utils::ReportSqliteResult(ctx, value.bool_value);
+ break;
+ case Variadic::Type::kJson:
+ sqlite_utils::ReportSqliteResult(ctx, value.json_value);
+ break;
}
}
@@ -110,13 +126,16 @@
});
break;
}
- case Variadic::Type::kReal: {
+ case Variadic::Type::kUint: {
bool op_is_null = sqlite_utils::IsOpIsNull(op);
- auto predicate = sqlite_utils::CreateNumericPredicate<double>(op, value);
+ // BEWARE: uint64 is handled as signed int64 for SQLite operations.
+ auto predicate = sqlite_utils::CreateNumericPredicate<int64_t>(op, value);
index->FilterRows(
[this, predicate, op_is_null](uint32_t row) PERFETTO_ALWAYS_INLINE {
const auto& arg = storage_->args().arg_values()[row];
- return arg.type == type_ ? predicate(arg.real_value) : op_is_null;
+ return arg.type == type_
+ ? predicate(static_cast<int64_t>(arg.uint_value))
+ : op_is_null;
});
break;
}
@@ -131,6 +150,50 @@
});
break;
}
+ case Variadic::Type::kReal: {
+ bool op_is_null = sqlite_utils::IsOpIsNull(op);
+ auto predicate = sqlite_utils::CreateNumericPredicate<double>(op, value);
+ index->FilterRows(
+ [this, predicate, op_is_null](uint32_t row) PERFETTO_ALWAYS_INLINE {
+ const auto& arg = storage_->args().arg_values()[row];
+ return arg.type == type_ ? predicate(arg.real_value) : op_is_null;
+ });
+ break;
+ }
+ case Variadic::Type::kPointer: {
+ bool op_is_null = sqlite_utils::IsOpIsNull(op);
+ // BEWARE: pointers are handled as signed int64 for SQLite operations.
+ auto predicate = sqlite_utils::CreateNumericPredicate<int64_t>(op, value);
+ index->FilterRows(
+ [this, predicate, op_is_null](uint32_t row) PERFETTO_ALWAYS_INLINE {
+ const auto& arg = storage_->args().arg_values()[row];
+ return arg.type == type_
+ ? predicate(static_cast<int64_t>(arg.pointer_value))
+ : op_is_null;
+ });
+ break;
+ }
+ case Variadic::Type::kBool: {
+ bool op_is_null = sqlite_utils::IsOpIsNull(op);
+ auto predicate = sqlite_utils::CreateNumericPredicate<bool>(op, value);
+ index->FilterRows(
+ [this, predicate, op_is_null](uint32_t row) PERFETTO_ALWAYS_INLINE {
+ const auto& arg = storage_->args().arg_values()[row];
+ return arg.type == type_ ? predicate(arg.bool_value) : op_is_null;
+ });
+ break;
+ }
+ case Variadic::Type::kJson: {
+ auto predicate = sqlite_utils::CreateStringPredicate(op, value);
+ index->FilterRows([this,
+ &predicate](uint32_t row) PERFETTO_ALWAYS_INLINE {
+ const auto& arg = storage_->args().arg_values()[row];
+ return arg.type == type_
+ ? predicate(storage_->GetString(arg.json_value).c_str())
+ : predicate(nullptr);
+ });
+ break;
+ }
}
}
@@ -150,14 +213,32 @@
switch (type_) {
case Variadic::Type::kInt:
return sqlite_utils::CompareValuesAsc(arg_f.int_value, arg_s.int_value);
- case Variadic::Type::kReal:
- return sqlite_utils::CompareValuesAsc(arg_f.real_value,
- arg_s.real_value);
+ case Variadic::Type::kUint:
+ // BEWARE: uint64 is handled as signed int64 for SQLite operations.
+ return sqlite_utils::CompareValuesAsc(
+ static_cast<int64_t>(arg_f.uint_value),
+ static_cast<int64_t>(arg_s.uint_value));
case Variadic::Type::kString: {
const auto& f_str = storage_->GetString(arg_f.string_value);
const auto& s_str = storage_->GetString(arg_s.string_value);
return sqlite_utils::CompareValuesAsc(f_str, s_str);
}
+ case Variadic::Type::kReal:
+ return sqlite_utils::CompareValuesAsc(arg_f.real_value,
+ arg_s.real_value);
+ case Variadic::Type::kPointer:
+ // BEWARE: pointers are handled as signed int64 for SQLite operations.
+ return sqlite_utils::CompareValuesAsc(
+ static_cast<int64_t>(arg_f.pointer_value),
+ static_cast<int64_t>(arg_s.pointer_value));
+ case Variadic::Type::kBool:
+ return sqlite_utils::CompareValuesAsc(arg_f.bool_value,
+ arg_s.bool_value);
+ case Variadic::Type::kJson: {
+ const auto& f_str = storage_->GetString(arg_f.json_value);
+ const auto& s_str = storage_->GetString(arg_s.json_value);
+ return sqlite_utils::CompareValuesAsc(f_str, s_str);
+ }
}
} else if (arg_s.type == type_) {
return -1;
diff --git a/src/trace_processor/args_table.h b/src/trace_processor/args_table.h
index 0d9fd4b..3327e57 100644
--- a/src/trace_processor/args_table.h
+++ b/src/trace_processor/args_table.h
@@ -56,9 +56,17 @@
switch (type_) {
case Variadic::Type::kInt:
return Table::ColumnType::kLong;
+ case Variadic::Type::kUint:
+ return Table::ColumnType::kLong;
+ case Variadic::Type::kString:
+ return Table::ColumnType::kString;
case Variadic::Type::kReal:
return Table::ColumnType::kDouble;
- case Variadic::Type::kString:
+ case Variadic::Type::kPointer:
+ return Table::ColumnType::kLong;
+ case Variadic::Type::kBool:
+ return Table::ColumnType::kBool;
+ case Variadic::Type::kJson:
return Table::ColumnType::kString;
}
PERFETTO_FATAL("Not reached"); // For gcc
diff --git a/src/trace_processor/args_tracker.h b/src/trace_processor/args_tracker.h
index b966dc9..7eb27d7 100644
--- a/src/trace_processor/args_tracker.h
+++ b/src/trace_processor/args_tracker.h
@@ -32,10 +32,12 @@
virtual ~ArgsTracker();
// Adds a arg for this row id with the given key and value.
- void AddArg(RowId row_id, StringId flat_key, StringId key, Variadic);
+ // Virtual for testing.
+ virtual void AddArg(RowId row_id, StringId flat_key, StringId key, Variadic);
// Commits the added args to storage.
- void Flush();
+ // Virtual for testing.
+ virtual void Flush();
private:
std::vector<TraceStorage::Args::Arg> args_;
diff --git a/src/trace_processor/proto_incremental_state.h b/src/trace_processor/proto_incremental_state.h
index 38f4abd..b2dc1de 100644
--- a/src/trace_processor/proto_incremental_state.h
+++ b/src/trace_processor/proto_incremental_state.h
@@ -77,7 +77,7 @@
struct InternedDataView {
InternedDataView(TraceBlobView msg) : message(std::move(msg)) {}
- typename MessageType::Decoder CreateDecoder() {
+ typename MessageType::Decoder CreateDecoder() const {
return typename MessageType::Decoder(message.data(), message.length());
}
diff --git a/src/trace_processor/proto_trace_parser.cc b/src/trace_processor/proto_trace_parser.cc
index ae94745..3355766 100644
--- a/src/trace_processor/proto_trace_parser.cc
+++ b/src/trace_processor/proto_trace_parser.cc
@@ -118,7 +118,11 @@
oom_score_adj_id_(context->storage->InternString("oom_score_adj")),
ion_total_unknown_id_(context->storage->InternString("mem.ion.unknown")),
ion_change_unknown_id_(
- context->storage->InternString("mem.ion_change.unknown")) {
+ context->storage->InternString("mem.ion_change.unknown")),
+ task_file_name_args_key_id_(
+ context->storage->InternString("task.posted_from.file_name")),
+ task_function_name_args_key_id_(
+ context->storage->InternString("task.posted_from.function_name")) {
for (const auto& name : BuildMeminfoCounterNames()) {
meminfo_strs_id_.emplace_back(context->storage->InternString(name));
}
@@ -1436,21 +1440,35 @@
// TODO(eseckler): Handle thread timestamp/duration, debug annotations, task
// souce locations, legacy event attributes, ...
+ auto args_callback = [this, &event, &sequence_state](
+ ArgsTracker* args_tracker, RowId row) {
+ for (auto it = event.debug_annotations(); it; ++it) {
+ ParseDebugAnnotationArgs(it->as_bytes(), sequence_state, args_tracker,
+ row);
+ }
+
+ if (event.has_task_execution()) {
+ ParseTaskExecutionArgs(event.task_execution(), sequence_state,
+ args_tracker, row);
+ }
+ };
+
int32_t phase = legacy_event.phase();
switch (static_cast<char>(phase)) {
case 'B': { // TRACE_EVENT_PHASE_BEGIN.
- slice_tracker->Begin(ts, utid, category_id, name_id);
+ slice_tracker->Begin(ts, utid, category_id, name_id, args_callback);
break;
}
case 'E': { // TRACE_EVENT_PHASE_END.
- slice_tracker->End(ts, utid, category_id, name_id);
+ slice_tracker->End(ts, utid, category_id, name_id, args_callback);
break;
}
case 'X': { // TRACE_EVENT_PHASE_COMPLETE.
auto duration_ns = legacy_event.duration_us() * 1000;
if (duration_ns < 0)
return;
- slice_tracker->Scoped(ts, utid, category_id, name_id, duration_ns);
+ slice_tracker->Scoped(ts, utid, category_id, name_id, duration_ns,
+ args_callback);
break;
}
case 'M': { // TRACE_EVENT_PHASE_METADATA (process and thread names).
@@ -1486,6 +1504,176 @@
}
}
+void ProtoTraceParser::ParseDebugAnnotationArgs(
+ ConstBytes debug_annotation,
+ ProtoIncrementalState::PacketSequenceState* sequence_state,
+ ArgsTracker* args_tracker,
+ RowId row) {
+ protos::pbzero::DebugAnnotation::Decoder annotation(debug_annotation.data,
+ debug_annotation.size);
+ uint32_t iid = annotation.name_iid();
+ if (!iid)
+ return;
+
+ auto* map =
+ sequence_state->GetInternedDataMap<protos::pbzero::DebugAnnotationName>();
+ auto name_view_it = map->find(iid);
+ if (name_view_it == map->end()) {
+ PERFETTO_ELOG(
+ "Could not find debug annotation name interning entry for ID %u", iid);
+ return;
+ }
+
+ TraceStorage* storage = context_->storage.get();
+
+ StringId name_id = 0;
+
+ // If the name is already in the pool, no need to decode it again.
+ if (name_view_it->second.storage_refs) {
+ name_id = name_view_it->second.storage_refs->name_id;
+ } else {
+ auto name = name_view_it->second.CreateDecoder();
+ std::string name_prefixed = "debug." + name.name().ToStdString();
+ name_id = storage->InternString(base::StringView(name_prefixed));
+ // Avoid having to decode & look up the name again in the future.
+ name_view_it->second.storage_refs =
+ ProtoIncrementalState::StorageReferences<
+ protos::pbzero::DebugAnnotationName>{name_id};
+ }
+
+ if (annotation.has_bool_value()) {
+ args_tracker->AddArg(row, name_id, name_id,
+ Variadic::Boolean(annotation.bool_value()));
+ } else if (annotation.has_uint_value()) {
+ args_tracker->AddArg(row, name_id, name_id,
+ Variadic::UnsignedInteger(annotation.uint_value()));
+ } else if (annotation.has_int_value()) {
+ args_tracker->AddArg(row, name_id, name_id,
+ Variadic::Integer(annotation.int_value()));
+ } else if (annotation.has_double_value()) {
+ args_tracker->AddArg(row, name_id, name_id,
+ Variadic::Real(annotation.double_value()));
+ } else if (annotation.has_string_value()) {
+ args_tracker->AddArg(
+ row, name_id, name_id,
+ Variadic::String(storage->InternString(annotation.string_value())));
+ } else if (annotation.has_pointer_value()) {
+ args_tracker->AddArg(row, name_id, name_id,
+ Variadic::Pointer(annotation.pointer_value()));
+ } else if (annotation.has_legacy_json_value()) {
+ args_tracker->AddArg(row, name_id, name_id,
+ Variadic::String(storage->InternString(
+ annotation.legacy_json_value())));
+ } else if (annotation.has_nested_value()) {
+ auto name = storage->GetString(name_id);
+ ParseNestedValueArgs(annotation.nested_value(), name, name, args_tracker,
+ row);
+ }
+}
+
+void ProtoTraceParser::ParseNestedValueArgs(ConstBytes nested_value,
+ base::StringView flat_key,
+ base::StringView key,
+ ArgsTracker* args_tracker,
+ RowId row) {
+ protos::pbzero::DebugAnnotation::NestedValue::Decoder value(
+ nested_value.data, nested_value.size);
+ switch (value.nested_type()) {
+ case protos::pbzero::DebugAnnotation::NestedValue::UNSPECIFIED: {
+ auto flat_key_id = context_->storage->InternString(flat_key);
+ auto key_id = context_->storage->InternString(key);
+ // Leaf value.
+ if (value.has_bool_value()) {
+ args_tracker->AddArg(row, flat_key_id, key_id,
+ Variadic::Boolean(value.bool_value()));
+ } else if (value.has_int_value()) {
+ args_tracker->AddArg(row, flat_key_id, key_id,
+ Variadic::Integer(value.int_value()));
+ } else if (value.has_double_value()) {
+ args_tracker->AddArg(row, flat_key_id, key_id,
+ Variadic::Real(value.double_value()));
+ } else if (value.has_string_value()) {
+ args_tracker->AddArg(row, flat_key_id, key_id,
+ Variadic::String(context_->storage->InternString(
+ value.string_value())));
+ }
+ break;
+ }
+ case protos::pbzero::DebugAnnotation::NestedValue::DICT: {
+ auto key_it = value.dict_keys();
+ auto value_it = value.dict_values();
+ for (; key_it && value_it; ++key_it, ++value_it) {
+ std::string child_name = key_it->as_std_string();
+ std::string child_flat_key = flat_key.ToStdString() + "." + child_name;
+ std::string child_key = key.ToStdString() + "." + child_name;
+ ParseNestedValueArgs(value_it->as_bytes(),
+ base::StringView(child_flat_key),
+ base::StringView(child_key), args_tracker, row);
+ }
+ break;
+ }
+ case protos::pbzero::DebugAnnotation::NestedValue::ARRAY: {
+ int child_index = 0;
+ std::string child_flat_key = flat_key.ToStdString();
+ for (auto value_it = value.array_values(); value_it;
+ ++value_it, ++child_index) {
+ std::string child_key =
+ key.ToStdString() + "[" + std::to_string(child_index) + "]";
+ ParseNestedValueArgs(value_it->as_bytes(),
+ base::StringView(child_flat_key),
+ base::StringView(child_key), args_tracker, row);
+ }
+ break;
+ }
+ }
+}
+
+void ProtoTraceParser::ParseTaskExecutionArgs(
+ ConstBytes task_execution,
+ ProtoIncrementalState::PacketSequenceState* sequence_state,
+ ArgsTracker* args_tracker,
+ RowId row) {
+ protos::pbzero::TaskExecution::Decoder task(task_execution.data,
+ task_execution.size);
+ uint32_t iid = task.posted_from_iid();
+ if (!iid)
+ return;
+
+ auto* map =
+ sequence_state->GetInternedDataMap<protos::pbzero::SourceLocation>();
+ auto location_view_it = map->find(iid);
+ if (location_view_it == map->end()) {
+ PERFETTO_ELOG("Could not find source location interning entry for ID %u",
+ iid);
+ return;
+ }
+
+ StringId file_name_id = 0;
+ StringId function_name_id = 0;
+
+ // If the names are already in the pool, no need to decode them again.
+ if (location_view_it->second.storage_refs) {
+ file_name_id = location_view_it->second.storage_refs->file_name_id;
+ function_name_id = location_view_it->second.storage_refs->function_name_id;
+ } else {
+ TraceStorage* storage = context_->storage.get();
+ auto location = location_view_it->second.CreateDecoder();
+ file_name_id = storage->InternString(location.file_name());
+ function_name_id = storage->InternString(location.function_name());
+ // Avoid having to decode & look up the names again in the future.
+ location_view_it->second.storage_refs =
+ ProtoIncrementalState::StorageReferences<
+ protos::pbzero::SourceLocation>{file_name_id, function_name_id};
+ }
+
+ args_tracker->AddArg(row, task_file_name_args_key_id_,
+ task_file_name_args_key_id_,
+ Variadic::String(file_name_id));
+ args_tracker->AddArg(row, task_function_name_args_key_id_,
+ task_function_name_args_key_id_,
+ Variadic::String(function_name_id));
+}
+
void ProtoTraceParser::ParseChromeBenchmarkMetadata(ConstBytes blob) {
TraceStorage* storage = context_->storage.get();
protos::pbzero::ChromeBenchmarkMetadata::Decoder packet(blob.data, blob.size);
diff --git a/src/trace_processor/proto_trace_parser.h b/src/trace_processor/proto_trace_parser.h
index a66573d..0fbe329 100644
--- a/src/trace_processor/proto_trace_parser.h
+++ b/src/trace_processor/proto_trace_parser.h
@@ -33,6 +33,7 @@
namespace perfetto {
namespace trace_processor {
+class ArgsTracker;
class TraceProcessorContext;
class ProtoTraceParser : public TraceParser {
@@ -92,6 +93,21 @@
int64_t tts,
ProtoIncrementalState::PacketSequenceState*,
ConstBytes);
+ void ParseDebugAnnotationArgs(
+ ConstBytes debug_annotation,
+ ProtoIncrementalState::PacketSequenceState* sequence_state,
+ ArgsTracker* args_tracker,
+ RowId row);
+ void ParseNestedValueArgs(ConstBytes nested_value,
+ base::StringView flat_key,
+ base::StringView key,
+ ArgsTracker* args_tracker,
+ RowId row);
+ void ParseTaskExecutionArgs(
+ ConstBytes task_execution,
+ ProtoIncrementalState::PacketSequenceState* sequence_state,
+ ArgsTracker* args_tracker,
+ RowId row);
void ParseChromeBenchmarkMetadata(ConstBytes);
private:
@@ -123,6 +139,8 @@
const StringId oom_score_adj_id_;
const StringId ion_total_unknown_id_;
const StringId ion_change_unknown_id_;
+ const StringId task_file_name_args_key_id_;
+ const StringId task_function_name_args_key_id_;
std::vector<StringId> meminfo_strs_id_;
std::vector<StringId> vmstat_strs_id_;
std::vector<StringId> rss_members_;
diff --git a/src/trace_processor/proto_trace_parser_unittest.cc b/src/trace_processor/proto_trace_parser_unittest.cc
index 6107f4f..a40868d 100644
--- a/src/trace_processor/proto_trace_parser_unittest.cc
+++ b/src/trace_processor/proto_trace_parser_unittest.cc
@@ -104,6 +104,7 @@
MockTraceStorage() : TraceStorage() {}
MOCK_METHOD1(InternString, StringId(base::StringView));
+ MOCK_CONST_METHOD1(GetString, NullTermStringView(StringId));
MOCK_METHOD2(SetMetadata, void(size_t, Variadic));
MOCK_METHOD2(AppendMetadata, void(size_t, Variadic));
};
@@ -147,8 +148,7 @@
ProtoTraceParserTest() {
nice_storage_ = new NiceMock<MockTraceStorage>();
context_.storage.reset(nice_storage_);
- args_ = new MockArgsTracker(&context_);
- context_.args_tracker.reset(args_);
+ context_.args_tracker.reset(new ArgsTracker(&context_));
event_ = new MockEventTracker(&context_);
context_.event_tracker.reset(event_);
process_ = new MockProcessTracker(&context_);
@@ -189,7 +189,6 @@
std::unique_ptr<protozero::ScatteredStreamWriter> stream_writer_;
protos::pbzero::Trace trace_;
TraceProcessorContext context_;
- MockArgsTracker* args_;
MockEventTracker* event_;
MockProcessTracker* process_;
MockSliceTracker* slice_;
@@ -976,6 +975,264 @@
context_.sorter->ExtractEventsForced();
}
+TEST_F(ProtoTraceParserTest, TrackEventWithDebugAnnotations) {
+ InitStorage();
+ context_.sorter.reset(new TraceSorter(
+ &context_, std::numeric_limits<int64_t>::max() /*window size*/));
+ MockArgsTracker args(&context_);
+
+ {
+ auto* packet = trace_.add_packet();
+ packet->set_trusted_packet_sequence_id(1);
+ packet->set_incremental_state_cleared(true);
+ auto* thread_desc = packet->set_thread_descriptor();
+ thread_desc->set_pid(15);
+ thread_desc->set_tid(16);
+ thread_desc->set_reference_timestamp_us(1000);
+ thread_desc->set_reference_thread_time_us(2000);
+ }
+ {
+ auto* packet = trace_.add_packet();
+ packet->set_trusted_packet_sequence_id(1);
+ auto* event = packet->set_track_event();
+ event->set_timestamp_delta_us(10); // absolute: 1010.
+ event->set_thread_time_delta_us(5); // absolute: 2005.
+ event->add_category_iids(1);
+ auto* annotation1 = event->add_debug_annotations();
+ annotation1->set_name_iid(1);
+ annotation1->set_uint_value(10u);
+ auto* annotation2 = event->add_debug_annotations();
+ annotation2->set_name_iid(2);
+ auto* nested = annotation2->set_nested_value();
+ nested->set_nested_type(protos::pbzero::DebugAnnotation::NestedValue::DICT);
+ nested->add_dict_keys("child1");
+ nested->add_dict_keys("child2");
+ auto* child1 = nested->add_dict_values();
+ child1->set_nested_type(
+ protos::pbzero::DebugAnnotation::NestedValue::UNSPECIFIED);
+ child1->set_bool_value(true);
+ auto* child2 = nested->add_dict_values();
+ child2->set_nested_type(
+ protos::pbzero::DebugAnnotation::NestedValue::ARRAY);
+ auto* child21 = child2->add_array_values();
+ child21->set_nested_type(
+ protos::pbzero::DebugAnnotation::NestedValue::UNSPECIFIED);
+ child21->set_string_value("child21");
+ auto* child22 = child2->add_array_values();
+ child22->set_nested_type(
+ protos::pbzero::DebugAnnotation::NestedValue::UNSPECIFIED);
+ child22->set_double_value(2.2);
+ auto* child23 = child2->add_array_values();
+ child23->set_nested_type(
+ protos::pbzero::DebugAnnotation::NestedValue::UNSPECIFIED);
+ child23->set_int_value(23);
+ auto* legacy_event = event->set_legacy_event();
+ legacy_event->set_name_iid(1);
+ legacy_event->set_phase('B');
+
+ auto* interned_data = packet->set_interned_data();
+ auto cat1 = interned_data->add_event_categories();
+ cat1->set_iid(1);
+ cat1->set_name("cat1");
+ auto ev1 = interned_data->add_legacy_event_names();
+ ev1->set_iid(1);
+ ev1->set_name("ev1");
+ auto an1 = interned_data->add_debug_annotation_names();
+ an1->set_iid(1);
+ an1->set_name("an1");
+ auto an2 = interned_data->add_debug_annotation_names();
+ an2->set_iid(2);
+ an2->set_name("an2");
+ }
+ {
+ auto* packet = trace_.add_packet();
+ packet->set_trusted_packet_sequence_id(1);
+ auto* event = packet->set_track_event();
+ event->set_timestamp_delta_us(10); // absolute: 1020.
+ event->set_thread_time_delta_us(5); // absolute: 2010.
+ event->add_category_iids(1);
+ auto* annotation3 = event->add_debug_annotations();
+ annotation3->set_name_iid(3);
+ annotation3->set_int_value(-3);
+ auto* annotation4 = event->add_debug_annotations();
+ annotation4->set_name_iid(4);
+ annotation4->set_bool_value(true);
+ auto* annotation5 = event->add_debug_annotations();
+ annotation5->set_name_iid(5);
+ annotation5->set_double_value(-5.5);
+ auto* annotation6 = event->add_debug_annotations();
+ annotation6->set_name_iid(6);
+ annotation6->set_pointer_value(20u);
+ auto* annotation7 = event->add_debug_annotations();
+ annotation7->set_name_iid(7);
+ annotation7->set_string_value("val7");
+ auto* annotation8 = event->add_debug_annotations();
+ annotation8->set_name_iid(8);
+ annotation8->set_legacy_json_value("val8");
+ auto* legacy_event = event->set_legacy_event();
+ legacy_event->set_name_iid(1);
+ legacy_event->set_phase('E');
+
+ auto* interned_data = packet->set_interned_data();
+ auto an3 = interned_data->add_debug_annotation_names();
+ an3->set_iid(3);
+ an3->set_name("an3");
+ auto an4 = interned_data->add_debug_annotation_names();
+ an4->set_iid(4);
+ an4->set_name("an4");
+ auto an5 = interned_data->add_debug_annotation_names();
+ an5->set_iid(5);
+ an5->set_name("an5");
+ auto an6 = interned_data->add_debug_annotation_names();
+ an6->set_iid(6);
+ an6->set_name("an6");
+ auto an7 = interned_data->add_debug_annotation_names();
+ an7->set_iid(7);
+ an7->set_name("an7");
+ auto an8 = interned_data->add_debug_annotation_names();
+ an8->set_iid(8);
+ an8->set_name("an8");
+ }
+
+ Tokenize();
+
+ EXPECT_CALL(*process_, UpdateThread(16, 15))
+ .Times(2)
+ .WillRepeatedly(Return(1));
+
+ InSequence in_sequence; // Below slices should be sorted by timestamp.
+
+ EXPECT_CALL(*storage_, InternString(base::StringView("cat1")))
+ .WillOnce(Return(1));
+ EXPECT_CALL(*storage_, InternString(base::StringView("ev1")))
+ .WillOnce(Return(2));
+ EXPECT_CALL(*slice_, Begin(1010000, 1, 1, 2, _))
+ .WillOnce(testing::InvokeArgument<4>(&args, 1u));
+ EXPECT_CALL(*storage_, InternString(base::StringView("debug.an1")))
+ .WillOnce(Return(3));
+ EXPECT_CALL(args, AddArg(1u, 3, 3, Variadic::UnsignedInteger(10u)));
+
+ EXPECT_CALL(*storage_, InternString(base::StringView("debug.an2")))
+ .WillOnce(Return(4));
+ EXPECT_CALL(*storage_, GetString(4)).WillOnce(Return("debug.an2"));
+ EXPECT_CALL(*storage_, InternString(base::StringView("debug.an2.child1")))
+ .Times(2)
+ .WillRepeatedly(Return(5));
+ EXPECT_CALL(args, AddArg(1u, 5, 5, Variadic::Boolean(true)));
+
+ EXPECT_CALL(*storage_, InternString(base::StringView("debug.an2.child2")))
+ .WillOnce(Return(6));
+ EXPECT_CALL(*storage_, InternString(base::StringView("debug.an2.child2[0]")))
+ .WillOnce(Return(7));
+ EXPECT_CALL(*storage_, InternString(base::StringView("child21")))
+ .WillOnce(Return(8));
+ EXPECT_CALL(args, AddArg(1u, 6, 7, Variadic::String(8)));
+
+ EXPECT_CALL(*storage_, InternString(base::StringView("debug.an2.child2")))
+ .WillOnce(Return(6));
+ EXPECT_CALL(*storage_, InternString(base::StringView("debug.an2.child2[1]")))
+ .WillOnce(Return(9));
+ EXPECT_CALL(args, AddArg(1u, 6, 9, Variadic::Real(2.2)));
+
+ EXPECT_CALL(*storage_, InternString(base::StringView("debug.an2.child2")))
+ .WillOnce(Return(6));
+ EXPECT_CALL(*storage_, InternString(base::StringView("debug.an2.child2[2]")))
+ .WillOnce(Return(10));
+ EXPECT_CALL(args, AddArg(1u, 6, 10, Variadic::Integer(23)));
+
+ EXPECT_CALL(*slice_, End(1020000, 1, 1, 2, _))
+ .WillOnce(testing::InvokeArgument<4>(&args, 1u));
+
+ EXPECT_CALL(*storage_, InternString(base::StringView("debug.an3")))
+ .WillOnce(Return(11));
+ EXPECT_CALL(args, AddArg(1u, 11, 11, Variadic::Integer(-3)));
+ EXPECT_CALL(*storage_, InternString(base::StringView("debug.an4")))
+ .WillOnce(Return(12));
+ EXPECT_CALL(args, AddArg(1u, 12, 12, Variadic::Boolean(true)));
+ EXPECT_CALL(*storage_, InternString(base::StringView("debug.an5")))
+ .WillOnce(Return(13));
+ EXPECT_CALL(args, AddArg(1u, 13, 13, Variadic::Real(-5.5)));
+ EXPECT_CALL(*storage_, InternString(base::StringView("debug.an6")))
+ .WillOnce(Return(14));
+ EXPECT_CALL(args, AddArg(1u, 14, 14, Variadic::Pointer(20u)));
+ EXPECT_CALL(*storage_, InternString(base::StringView("debug.an7")))
+ .WillOnce(Return(15));
+ EXPECT_CALL(*storage_, InternString(base::StringView("val7")))
+ .WillOnce(Return(16));
+ EXPECT_CALL(args, AddArg(1u, 15, 15, Variadic::String(16)));
+ EXPECT_CALL(*storage_, InternString(base::StringView("debug.an8")))
+ .WillOnce(Return(17));
+ EXPECT_CALL(*storage_, InternString(base::StringView("val8")))
+ .WillOnce(Return(18));
+ EXPECT_CALL(args, AddArg(1u, 17, 17, Variadic::String(18)));
+
+ context_.sorter->ExtractEventsForced();
+}
+
+TEST_F(ProtoTraceParserTest, TrackEventWithTaskExecution) {
+ InitStorage();
+ context_.sorter.reset(new TraceSorter(
+ &context_, std::numeric_limits<int64_t>::max() /*window size*/));
+ MockArgsTracker args(&context_);
+
+ {
+ auto* packet = trace_.add_packet();
+ packet->set_trusted_packet_sequence_id(1);
+ packet->set_incremental_state_cleared(true);
+ auto* thread_desc = packet->set_thread_descriptor();
+ thread_desc->set_pid(15);
+ thread_desc->set_tid(16);
+ thread_desc->set_reference_timestamp_us(1000);
+ thread_desc->set_reference_thread_time_us(2000);
+ }
+ {
+ auto* packet = trace_.add_packet();
+ packet->set_trusted_packet_sequence_id(1);
+ auto* event = packet->set_track_event();
+ event->set_timestamp_delta_us(10); // absolute: 1010.
+ event->set_thread_time_delta_us(5); // absolute: 2005.
+ event->add_category_iids(1);
+ auto* task_execution = event->set_task_execution();
+ task_execution->set_posted_from_iid(1);
+ auto* legacy_event = event->set_legacy_event();
+ legacy_event->set_name_iid(1);
+ legacy_event->set_phase('B');
+
+ auto* interned_data = packet->set_interned_data();
+ auto cat1 = interned_data->add_event_categories();
+ cat1->set_iid(1);
+ cat1->set_name("cat1");
+ auto ev1 = interned_data->add_legacy_event_names();
+ ev1->set_iid(1);
+ ev1->set_name("ev1");
+ auto loc1 = interned_data->add_source_locations();
+ loc1->set_iid(1);
+ loc1->set_file_name("file1");
+ loc1->set_function_name("func1");
+ }
+
+ Tokenize();
+
+ EXPECT_CALL(*process_, UpdateThread(16, 15)).WillOnce(Return(1));
+
+ InSequence in_sequence; // Below slices should be sorted by timestamp.
+
+ EXPECT_CALL(*storage_, InternString(base::StringView("cat1")))
+ .WillOnce(Return(1));
+ EXPECT_CALL(*storage_, InternString(base::StringView("ev1")))
+ .WillOnce(Return(2));
+ EXPECT_CALL(*slice_, Begin(1010000, 1, 1, 2, _))
+ .WillOnce(testing::InvokeArgument<4>(&args, 1u));
+ EXPECT_CALL(*storage_, InternString(base::StringView("file1")))
+ .WillOnce(Return(3));
+ EXPECT_CALL(*storage_, InternString(base::StringView("func1")))
+ .WillOnce(Return(4));
+ EXPECT_CALL(args, AddArg(1u, _, _, Variadic::String(3)));
+ EXPECT_CALL(args, AddArg(1u, _, _, Variadic::String(4)));
+
+ context_.sorter->ExtractEventsForced();
+}
+
TEST_F(ProtoTraceParserTest, LoadChromeBenchmarkMetadata) {
static const char kName[] = "name";
static const char kTag2[] = "tag1";
diff --git a/src/trace_processor/raw_table.cc b/src/trace_processor/raw_table.cc
index 1f9196e..d7dcffe 100644
--- a/src/trace_processor/raw_table.cc
+++ b/src/trace_processor/raw_table.cc
@@ -90,12 +90,27 @@
case Variadic::kInt:
writer->AppendInt(value.int_value);
break;
- case Variadic::kReal:
- writer->AppendDouble(value.real_value);
+ case Variadic::kUint:
+ writer->AppendUnsignedInt(value.uint_value);
break;
case Variadic::kString: {
const auto& str = storage_->GetString(value.string_value);
writer->AppendString(str.c_str(), str.size());
+ break;
+ }
+ case Variadic::kReal:
+ writer->AppendDouble(value.real_value);
+ break;
+ case Variadic::kPointer:
+ writer->AppendUnsignedInt(value.pointer_value);
+ break;
+ case Variadic::kBool:
+ writer->AppendBool(value.bool_value);
+ break;
+ case Variadic::kJson: {
+ const auto& str = storage_->GetString(value.json_value);
+ writer->AppendString(str.c_str(), str.size());
+ break;
}
}
};
diff --git a/src/trace_processor/sqlite_utils.h b/src/trace_processor/sqlite_utils.h
index 60d095f..64ad4fb 100644
--- a/src/trace_processor/sqlite_utils.h
+++ b/src/trace_processor/sqlite_utils.h
@@ -132,6 +132,13 @@
return sqlite3_value_double(value);
}
+template <>
+inline bool ExtractSqliteValue(sqlite3_value* value) {
+ auto type = sqlite3_value_type(value);
+ PERFETTO_DCHECK(type == SQLITE_INTEGER);
+ return static_cast<bool>(sqlite3_value_int(value));
+}
+
// Do not add a uint64_t version of ExtractSqliteValue. You should not be using
// uint64_t at all given that SQLite doesn't support it.
@@ -362,6 +369,11 @@
}
template <>
+inline void ReportSqliteResult(sqlite3_context* ctx, bool value) {
+ sqlite3_result_int(ctx, value);
+}
+
+template <>
inline void ReportSqliteResult(sqlite3_context* ctx, double value) {
sqlite3_result_double(ctx, value);
}
@@ -430,6 +442,8 @@
type = Table::ColumnType::kString;
} else if (strcmp(raw_type, "DOUBLE") == 0) {
type = Table::ColumnType::kDouble;
+ } else if (strcmp(raw_type, "BOOLEAN") == 0) {
+ type = Table::ColumnType::kBool;
} else if (!*raw_type) {
PERFETTO_DLOG("Unknown column type for %s %s", raw_table_name.c_str(),
name);
diff --git a/src/trace_processor/table.cc b/src/trace_processor/table.cc
index 1218b5a..1110d6f 100644
--- a/src/trace_processor/table.cc
+++ b/src/trace_processor/table.cc
@@ -39,6 +39,8 @@
return "INT";
case Table::ColumnType::kDouble:
return "DOUBLE";
+ case Table::ColumnType::kBool:
+ return "BOOLEAN";
case Table::ColumnType::kUnknown:
PERFETTO_FATAL("Cannot map unknown column type");
}
diff --git a/src/trace_processor/table.h b/src/trace_processor/table.h
index 0c8e638..c89f002 100644
--- a/src/trace_processor/table.h
+++ b/src/trace_processor/table.h
@@ -49,7 +49,8 @@
kLong = 3,
kInt = 4,
kDouble = 5,
- kUnknown = 6,
+ kBool = 6,
+ kUnknown = 7,
};
// Describes a column of this table.
diff --git a/src/trace_processor/trace_storage.h b/src/trace_processor/trace_storage.h
index 45ffed3..de4dfa5 100644
--- a/src/trace_processor/trace_storage.h
+++ b/src/trace_processor/trace_storage.h
@@ -131,12 +131,24 @@
case Variadic::Type::kInt:
hash.Update(arg.value.int_value);
break;
+ case Variadic::Type::kUint:
+ hash.Update(arg.value.uint_value);
+ break;
case Variadic::Type::kString:
hash.Update(arg.value.string_value);
break;
case Variadic::Type::kReal:
hash.Update(arg.value.real_value);
break;
+ case Variadic::Type::kPointer:
+ hash.Update(arg.value.pointer_value);
+ break;
+ case Variadic::Type::kBool:
+ hash.Update(arg.value.bool_value);
+ break;
+ case Variadic::Type::kJson:
+ hash.Update(arg.value.json_value);
+ break;
}
return hash.digest();
}
@@ -832,7 +844,8 @@
}
// Reading methods.
- NullTermStringView GetString(StringId id) const {
+ // Virtual for testing.
+ virtual NullTermStringView GetString(StringId id) const {
return string_pool_.Get(id);
}
diff --git a/src/trace_processor/variadic.h b/src/trace_processor/variadic.h
index 761aea3..6df011e 100644
--- a/src/trace_processor/variadic.h
+++ b/src/trace_processor/variadic.h
@@ -24,7 +24,7 @@
// Variadic type representing value of different possible types.
struct Variadic {
- enum Type { kInt, kString, kReal };
+ enum Type { kInt, kUint, kString, kReal, kPointer, kBool, kJson };
static Variadic Integer(int64_t int_value) {
Variadic variadic;
@@ -33,6 +33,17 @@
return variadic;
}
+ // BEWARE: Unsigned 64-bit integers will be handled as signed integers by
+ // SQLite for built-in SQL operators. This variadic type is used to
+ // distinguish between int64 and uint64 for correct JSON export of TrackEvent
+ // arguments.
+ static Variadic UnsignedInteger(uint64_t uint_value) {
+ Variadic variadic;
+ variadic.type = Type::kUint;
+ variadic.uint_value = uint_value;
+ return variadic;
+ }
+
static Variadic String(StringPool::Id string_id) {
Variadic variadic;
variadic.type = Type::kString;
@@ -47,16 +58,49 @@
return variadic;
}
+ // This variadic type is used to distinguish between integers and pointer
+ // values for correct JSON export of TrackEvent arguments.
+ static Variadic Pointer(uint64_t pointer_value) {
+ Variadic variadic;
+ variadic.type = Type::kPointer;
+ variadic.pointer_value = pointer_value;
+ return variadic;
+ }
+
+ static Variadic Boolean(bool bool_value) {
+ Variadic variadic;
+ variadic.type = Type::kBool;
+ variadic.bool_value = bool_value;
+ return variadic;
+ }
+
+ // This variadic type is used to distinguish between regular string and JSON
+ // string values for correct JSON export of TrackEvent arguments.
+ static Variadic Json(StringPool::Id json_value) {
+ Variadic variadic;
+ variadic.type = Type::kJson;
+ variadic.json_value = json_value;
+ return variadic;
+ }
+
// Used in tests.
bool operator==(const Variadic& other) const {
if (type == other.type) {
switch (type) {
case kInt:
return int_value == other.int_value;
+ case kUint:
+ return uint_value == other.uint_value;
case kString:
return string_value == other.string_value;
case kReal:
return std::equal_to<double>()(real_value, other.real_value);
+ case kPointer:
+ return pointer_value == other.pointer_value;
+ case kBool:
+ return bool_value == other.bool_value;
+ case kJson:
+ return json_value == other.json_value;
}
}
return false;
@@ -65,8 +109,12 @@
Type type;
union {
int64_t int_value;
+ uint64_t uint_value;
StringPool::Id string_value;
double real_value;
+ uint64_t pointer_value;
+ bool bool_value;
+ StringPool::Id json_value;
};
};
