Merge "trace_processor: Parse SysStats trace events and add to counters table"
diff --git a/include/perfetto/traced/sys_stats_counters.h b/include/perfetto/traced/sys_stats_counters.h
index 5bb0974..98d25af 100644
--- a/include/perfetto/traced/sys_stats_counters.h
+++ b/include/perfetto/traced/sys_stats_counters.h
@@ -30,6 +30,7 @@
};
constexpr KeyAndId kMeminfoKeys[] = {
+ {"MemUnspecified", protos::pbzero::MeminfoCounters::MEMINFO_UNSPECIFIED},
{"MemTotal", protos::pbzero::MeminfoCounters::MEMINFO_MEM_TOTAL},
{"MemFree", protos::pbzero::MeminfoCounters::MEMINFO_MEM_FREE},
{"MemAvailable", protos::pbzero::MeminfoCounters::MEMINFO_MEM_AVAILABLE},
@@ -66,6 +67,7 @@
};
const KeyAndId kVmstatKeys[] = {
+ {"VmstatUnspecified", protos::pbzero::VmstatCounters::VMSTAT_UNSPECIFIED},
{"nr_free_pages", protos::pbzero::VmstatCounters::VMSTAT_NR_FREE_PAGES},
{"nr_alloc_batch", protos::pbzero::VmstatCounters::VMSTAT_NR_ALLOC_BATCH},
{"nr_inactive_anon",
diff --git a/src/trace_processor/BUILD.gn b/src/trace_processor/BUILD.gn
index 978f128..a3da82c 100644
--- a/src/trace_processor/BUILD.gn
+++ b/src/trace_processor/BUILD.gn
@@ -90,6 +90,7 @@
deps = [
"../../buildtools:sqlite",
"../../gn:default_deps",
+ "../../include/perfetto/traced:sys_stats_counters",
"../../protos/perfetto/trace:lite",
"../../protos/perfetto/trace_processor:lite",
"../base",
diff --git a/src/trace_processor/counters_table.cc b/src/trace_processor/counters_table.cc
index cd14cc4..b01400f 100644
--- a/src/trace_processor/counters_table.cc
+++ b/src/trace_processor/counters_table.cc
@@ -102,6 +102,18 @@
sqlite3_result_text(context, "utid", -1, nullptr);
break;
}
+ case RefType::kNoRef: {
+ sqlite3_result_null(context);
+ break;
+ }
+ case RefType::kIrq: {
+ sqlite3_result_text(context, "irq", -1, nullptr);
+ break;
+ }
+ case RefType::kSoftIrq: {
+ sqlite3_result_text(context, "softirq", -1, nullptr);
+ break;
+ }
}
break;
}
diff --git a/src/trace_processor/proto_trace_parser.cc b/src/trace_processor/proto_trace_parser.cc
index ac1b65c..c82982a 100644
--- a/src/trace_processor/proto_trace_parser.cc
+++ b/src/trace_processor/proto_trace_parser.cc
@@ -24,6 +24,7 @@
#include "perfetto/base/string_view.h"
#include "perfetto/base/utils.h"
#include "perfetto/protozero/proto_decoder.h"
+#include "perfetto/traced/sys_stats_counters.h"
#include "src/trace_processor/process_tracker.h"
#include "src/trace_processor/sched_tracker.h"
#include "src/trace_processor/slice_tracker.h"
@@ -102,11 +103,37 @@
ProtoTraceParser::ProtoTraceParser(TraceProcessorContext* context)
: context_(context),
- cpu_freq_name_id_(context->storage->InternString("cpufreq")) {}
+ cpu_freq_name_id_(context->storage->InternString("cpufreq")),
+ num_forks_name_id_(context->storage->InternString("num_forks")),
+ num_irq_total_name_id_(context->storage->InternString("num_irq_total")),
+ num_softirq_total_name_id_(
+ context->storage->InternString("num_softirq_total")),
+ num_irq_name_id_(context->storage->InternString("num_irq")),
+ num_softirq_name_id_(context->storage->InternString("num_softirq")),
+ cpu_times_user_ns_id_(
+ context->storage->InternString("cpu.times.user_ns")),
+ cpu_times_user_ice_ns_id_(
+ context->storage->InternString("cpu.times.user_ice_ns")),
+ cpu_times_system_mode_ns_id_(
+ context->storage->InternString("cpu.times.system_mode_ns")),
+ cpu_times_idle_ns_id_(
+ context->storage->InternString("cpu.times.idle_ns")),
+ cpu_times_io_wait_ns_id_(
+ context->storage->InternString("cpu.times.io_wait_ns")),
+ cpu_times_irq_ns_id_(context->storage->InternString("cpu.times.irq_ns")),
+ cpu_times_softirq_ns_id_(
+ context->storage->InternString("cpu.times.softirq_ns")) {
+ for (const auto& name : BuildMeminfoCounterNames()) {
+ meminfo_strs_id_.emplace_back(context->storage->InternString(name));
+ }
+ for (const auto& name : BuildVmstatCounterNames()) {
+ vmstat_strs_id_.emplace_back(context->storage->InternString(name));
+ }
+}
ProtoTraceParser::~ProtoTraceParser() = default;
-void ProtoTraceParser::ParseTracePacket(TraceBlobView packet) {
+void ProtoTraceParser::ParseTracePacket(uint64_t ts, TraceBlobView packet) {
ProtoDecoder decoder(packet.data(), packet.length());
for (auto fld = decoder.ReadField(); fld.id != 0; fld = decoder.ReadField()) {
@@ -116,6 +143,11 @@
ParseProcessTree(packet.slice(fld_off, fld.size()));
break;
}
+ case protos::TracePacket::kSysStatsFieldNumber: {
+ const size_t fld_off = packet.offset_of(fld.data());
+ ParseSysStats(ts, packet.slice(fld_off, fld.size()));
+ break;
+ }
default:
break;
}
@@ -123,6 +155,192 @@
PERFETTO_DCHECK(decoder.IsEndOfBuffer());
}
+void ProtoTraceParser::ParseSysStats(uint64_t ts, TraceBlobView stats) {
+ ProtoDecoder decoder(stats.data(), stats.length());
+ for (auto fld = decoder.ReadField(); fld.id != 0; fld = decoder.ReadField()) {
+ switch (fld.id) {
+ case protos::SysStats::kMeminfoFieldNumber: {
+ const size_t fld_off = stats.offset_of(fld.data());
+ ParseMemInfo(ts, stats.slice(fld_off, fld.size()));
+ break;
+ }
+ case protos::SysStats::kVmstatFieldNumber: {
+ const size_t fld_off = stats.offset_of(fld.data());
+ ParseVmStat(ts, stats.slice(fld_off, fld.size()));
+ break;
+ }
+ case protos::SysStats::kCpuStatFieldNumber: {
+ const size_t fld_off = stats.offset_of(fld.data());
+ ParseCpuTimes(ts, stats.slice(fld_off, fld.size()));
+ break;
+ }
+ case protos::SysStats::kNumIrqFieldNumber: {
+ const size_t fld_off = stats.offset_of(fld.data());
+ ParseIrqCount(ts, stats.slice(fld_off, fld.size()),
+ /*is_softirq=*/false);
+ break;
+ }
+ case protos::SysStats::kNumSoftirqFieldNumber: {
+ const size_t fld_off = stats.offset_of(fld.data());
+ ParseIrqCount(ts, stats.slice(fld_off, fld.size()),
+ /*is_softirq=*/true);
+ break;
+ }
+ case protos::SysStats::kNumForksFieldNumber: {
+ context_->sched_tracker->PushCounter(
+ ts, fld.as_uint32(), num_forks_name_id_, 0, RefType::kNoRef);
+ break;
+ }
+ case protos::SysStats::kNumIrqTotalFieldNumber: {
+ context_->sched_tracker->PushCounter(
+ ts, fld.as_uint32(), num_irq_total_name_id_, 0, RefType::kNoRef);
+ break;
+ }
+ case protos::SysStats::kNumSoftirqTotalFieldNumber: {
+ context_->sched_tracker->PushCounter(ts, fld.as_uint32(),
+ num_softirq_total_name_id_, 0,
+ RefType::kNoRef);
+ break;
+ }
+ default:
+ break;
+ }
+ }
+}
+void ProtoTraceParser::ParseIrqCount(uint64_t ts,
+ TraceBlobView irq,
+ bool is_soft) {
+ ProtoDecoder decoder(irq.data(), irq.length());
+ uint32_t key = 0;
+ uint32_t value = 0;
+ for (auto fld = decoder.ReadField(); fld.id != 0; fld = decoder.ReadField()) {
+ switch (fld.id) {
+ case protos::SysStats::InterruptCount::kIrqFieldNumber:
+ key = fld.as_uint32();
+ break;
+ case protos::SysStats::InterruptCount::kCountFieldNumber:
+ value = fld.as_uint32();
+ break;
+ }
+ }
+ RefType ref_type = is_soft ? RefType::kIrq : RefType::kSoftIrq;
+ StringId name_id = is_soft ? num_irq_name_id_ : num_softirq_name_id_;
+ context_->sched_tracker->PushCounter(ts, value, name_id, key, ref_type);
+}
+
+void ProtoTraceParser::ParseMemInfo(uint64_t ts, TraceBlobView mem) {
+ ProtoDecoder decoder(mem.data(), mem.length());
+ uint32_t key = 0;
+ uint32_t value = 0;
+ for (auto fld = decoder.ReadField(); fld.id != 0; fld = decoder.ReadField()) {
+ switch (fld.id) {
+ case protos::SysStats::MeminfoValue::kKeyFieldNumber:
+ key = fld.as_uint32();
+ break;
+ case protos::SysStats::MeminfoValue::kValueFieldNumber:
+ value = fld.as_uint32();
+ break;
+ }
+ }
+ if (PERFETTO_UNLIKELY(key >= meminfo_strs_id_.size())) {
+ PERFETTO_ELOG("MemInfo key %d is not recognized.", key);
+ return;
+ }
+ context_->sched_tracker->PushCounter(ts, value, meminfo_strs_id_[key], 0,
+ RefType::kNoRef);
+}
+
+void ProtoTraceParser::ParseVmStat(uint64_t ts, TraceBlobView stat) {
+ ProtoDecoder decoder(stat.data(), stat.length());
+ uint32_t key = 0;
+ uint32_t value = 0;
+ for (auto fld = decoder.ReadField(); fld.id != 0; fld = decoder.ReadField()) {
+ switch (fld.id) {
+ case protos::SysStats::VmstatValue::kKeyFieldNumber:
+ key = fld.as_uint32();
+ break;
+ case protos::SysStats::VmstatValue::kValueFieldNumber:
+ value = fld.as_uint32();
+ break;
+ }
+ }
+ if (PERFETTO_UNLIKELY(key >= vmstat_strs_id_.size())) {
+ PERFETTO_ELOG("VmStat key %d is not recognized.", key);
+ return;
+ }
+ context_->sched_tracker->PushCounter(ts, value, vmstat_strs_id_[key], 0,
+ RefType::kNoRef);
+}
+
+void ProtoTraceParser::ParseCpuTimes(uint64_t ts, TraceBlobView cpu_times) {
+ ProtoDecoder decoder(cpu_times.data(), cpu_times.length());
+ uint64_t cpu = 0;
+ uint32_t value = 0;
+ // Speculate on CPU being first.
+ constexpr auto kCpuFieldTag = protozero::proto_utils::MakeTagVarInt(
+ protos::SysStats::CpuTimes::kCpuIdFieldNumber);
+ if (cpu_times.length() > 2 && cpu_times.data()[0] == kCpuFieldTag &&
+ cpu_times.data()[1] < 0x80) {
+ cpu = cpu_times.data()[1];
+ } else {
+ if (!PERFETTO_LIKELY((
+ decoder.FindIntField<protos::SysStats::CpuTimes::kCpuIdFieldNumber>(
+ &cpu)))) {
+ PERFETTO_ELOG("CPU field not found in CpuTimes");
+ return;
+ }
+ }
+
+ for (auto fld = decoder.ReadField(); fld.id != 0; fld = decoder.ReadField()) {
+ switch (fld.id) {
+ case protos::SysStats::CpuTimes::kUserNsFieldNumber: {
+ value = fld.as_uint32();
+ context_->sched_tracker->PushCounter(ts, value, cpu_times_user_ns_id_,
+ cpu, RefType::kCPU_ID);
+ break;
+ }
+ case protos::SysStats::CpuTimes::kUserIceNsFieldNumber: {
+ value = fld.as_uint32();
+ context_->sched_tracker->PushCounter(
+ ts, value, cpu_times_user_ice_ns_id_, cpu, RefType::kCPU_ID);
+ break;
+ }
+ case protos::SysStats::CpuTimes::kSystemModeNsFieldNumber: {
+ value = fld.as_uint32();
+ context_->sched_tracker->PushCounter(
+ ts, value, cpu_times_system_mode_ns_id_, cpu, RefType::kCPU_ID);
+ break;
+ }
+ case protos::SysStats::CpuTimes::kIdleNsFieldNumber: {
+ value = fld.as_uint32();
+ context_->sched_tracker->PushCounter(ts, value, cpu_times_idle_ns_id_,
+ cpu, RefType::kCPU_ID);
+ break;
+ }
+ case protos::SysStats::CpuTimes::kIoWaitNsFieldNumber: {
+ value = fld.as_uint32();
+ context_->sched_tracker->PushCounter(
+ ts, value, cpu_times_io_wait_ns_id_, cpu, RefType::kCPU_ID);
+ break;
+ }
+ case protos::SysStats::CpuTimes::kIrqNsFieldNumber: {
+ value = fld.as_uint32();
+ context_->sched_tracker->PushCounter(ts, value, cpu_times_irq_ns_id_,
+ cpu, RefType::kCPU_ID);
+ break;
+ }
+ case protos::SysStats::CpuTimes::kSoftirqNsFieldNumber: {
+ value = fld.as_uint32();
+ context_->sched_tracker->PushCounter(
+ ts, value, cpu_times_softirq_ns_id_, cpu, RefType::kCPU_ID);
+ break;
+ }
+ default:
+ break;
+ }
+ }
+}
+
void ProtoTraceParser::ParseProcessTree(TraceBlobView pstree) {
ProtoDecoder decoder(pstree.data(), pstree.length());
diff --git a/src/trace_processor/proto_trace_parser.h b/src/trace_processor/proto_trace_parser.h
index 9da91e4..73b3682 100644
--- a/src/trace_processor/proto_trace_parser.h
+++ b/src/trace_processor/proto_trace_parser.h
@@ -54,7 +54,7 @@
virtual ~ProtoTraceParser();
// virtual for testing.
- virtual void ParseTracePacket(TraceBlobView);
+ virtual void ParseTracePacket(uint64_t timestamp, TraceBlobView);
virtual void ParseFtracePacket(uint32_t cpu,
uint64_t timestamp,
TraceBlobView);
@@ -64,10 +64,29 @@
void ParsePrint(uint32_t cpu, uint64_t timestamp, TraceBlobView);
void ParseThread(TraceBlobView);
void ParseProcess(TraceBlobView);
+ void ParseSysStats(uint64_t ts, TraceBlobView);
+ void ParseMemInfo(uint64_t ts, TraceBlobView);
+ void ParseVmStat(uint64_t ts, TraceBlobView);
+ void ParseCpuTimes(uint64_t ts, TraceBlobView);
+ void ParseIrqCount(uint64_t ts, TraceBlobView, bool is_soft);
private:
TraceProcessorContext* context_;
const StringId cpu_freq_name_id_;
+ const StringId num_forks_name_id_;
+ const StringId num_irq_total_name_id_;
+ const StringId num_softirq_total_name_id_;
+ const StringId num_irq_name_id_;
+ const StringId num_softirq_name_id_;
+ const StringId cpu_times_user_ns_id_;
+ const StringId cpu_times_user_ice_ns_id_;
+ const StringId cpu_times_system_mode_ns_id_;
+ const StringId cpu_times_idle_ns_id_;
+ const StringId cpu_times_io_wait_ns_id_;
+ const StringId cpu_times_irq_ns_id_;
+ const StringId cpu_times_softirq_ns_id_;
+ std::vector<StringId> meminfo_strs_id_;
+ std::vector<StringId> vmstat_strs_id_;
};
} // namespace trace_processor
diff --git a/src/trace_processor/proto_trace_parser_unittest.cc b/src/trace_processor/proto_trace_parser_unittest.cc
index c0881c8..e502da5 100644
--- a/src/trace_processor/proto_trace_parser_unittest.cc
+++ b/src/trace_processor/proto_trace_parser_unittest.cc
@@ -36,6 +36,7 @@
using ::testing::ElementsAreArray;
using ::testing::Eq;
using ::testing::Pointwise;
+using ::testing::NiceMock;
class MockSchedTracker : public SchedTracker {
public:
@@ -79,7 +80,7 @@
class ProtoTraceParserTest : public ::testing::Test {
public:
ProtoTraceParserTest() {
- storage_ = new MockTraceStorage();
+ storage_ = new NiceMock<MockTraceStorage>();
context_.storage.reset(storage_);
sched_ = new MockSchedTracker(&context_);
context_.sched_tracker.reset(sched_);
@@ -102,7 +103,7 @@
TraceProcessorContext context_;
MockSchedTracker* sched_;
MockProcessTracker* process_;
- MockTraceStorage* storage_;
+ NiceMock<MockTraceStorage>* storage_;
};
TEST_F(ProtoTraceParserTest, LoadSingleEvent) {
@@ -232,6 +233,36 @@
Tokenize(trace_2);
}
+TEST_F(ProtoTraceParserTest, LoadMemInfo) {
+ protos::Trace trace_1;
+ auto* packet = trace_1.add_packet();
+ uint64_t ts = 1000;
+ packet->set_timestamp(ts);
+ auto* bundle = packet->mutable_sys_stats();
+ auto* meminfo = bundle->add_meminfo();
+ meminfo->set_key(perfetto::protos::MEMINFO_MEM_TOTAL);
+ uint32_t value = 10;
+ meminfo->set_value(value);
+
+ EXPECT_CALL(*sched_, PushCounter(ts, value, 0, 0, RefType::kNoRef));
+ Tokenize(trace_1);
+}
+
+TEST_F(ProtoTraceParserTest, LoadVmStats) {
+ protos::Trace trace_1;
+ auto* packet = trace_1.add_packet();
+ uint64_t ts = 1000;
+ packet->set_timestamp(ts);
+ auto* bundle = packet->mutable_sys_stats();
+ auto* meminfo = bundle->add_vmstat();
+ meminfo->set_key(perfetto::protos::VMSTAT_COMPACT_SUCCESS);
+ uint32_t value = 10;
+ meminfo->set_value(value);
+
+ EXPECT_CALL(*sched_, PushCounter(ts, value, 0, 0, RefType::kNoRef));
+ Tokenize(trace_1);
+}
+
TEST_F(ProtoTraceParserTest, LoadCpuFreq) {
protos::Trace trace_1;
auto* bundle = trace_1.add_packet()->mutable_ftrace_events();
diff --git a/src/trace_processor/proto_trace_tokenizer.cc b/src/trace_processor/proto_trace_tokenizer.cc
index 730f9d4..f3284c9 100644
--- a/src/trace_processor/proto_trace_tokenizer.cc
+++ b/src/trace_processor/proto_trace_tokenizer.cc
@@ -133,9 +133,28 @@
}
void ProtoTraceTokenizer::ParsePacket(TraceBlobView packet) {
+ constexpr auto kTimestampFieldNumber =
+ protos::TracePacket::kTimestampFieldNumber;
ProtoDecoder decoder(packet.data(), packet.length());
+ uint64_t timestamp = 0;
+ bool timestamp_found = false;
- // TODO(taylori): Add a timestamp to TracePacket and read it here.
+ // Speculate on the fact that the timestamp is often the 1st field of the
+ // packet.
+ constexpr auto timestampFieldTag = MakeTagVarInt(kTimestampFieldNumber);
+ if (PERFETTO_LIKELY(packet.length() > 10 &&
+ packet.data()[0] == timestampFieldTag)) {
+ // Fastpath.
+ const uint8_t* next =
+ ParseVarInt(packet.data() + 1, packet.data() + 11, ×tamp);
+ timestamp_found = next != packet.data() + 1;
+ decoder.Reset(next);
+ } else {
+ // Slowpath.
+ timestamp_found = decoder.FindIntField<kTimestampFieldNumber>(×tamp);
+ }
+ if (timestamp_found)
+ last_timestamp_ = timestamp;
// TODO(primiano): this can be optimized for the ftrace case.
for (auto fld = decoder.ReadField(); fld.id != 0; fld = decoder.ReadField()) {
diff --git a/src/trace_processor/trace_sorter.cc b/src/trace_processor/trace_sorter.cc
index ea5c927..1158734 100644
--- a/src/trace_processor/trace_sorter.cc
+++ b/src/trace_processor/trace_sorter.cc
@@ -70,7 +70,7 @@
next_stage->ParseFtracePacket(it->cpu, it->timestamp,
std::move(it->blob_view));
} else {
- next_stage->ParseTracePacket(std::move(it->blob_view));
+ next_stage->ParseTracePacket(it->timestamp, std::move(it->blob_view));
}
}
diff --git a/src/trace_processor/trace_sorter_unittest.cc b/src/trace_processor/trace_sorter_unittest.cc
index 8716fbb..49fc021 100644
--- a/src/trace_processor/trace_sorter_unittest.cc
+++ b/src/trace_processor/trace_sorter_unittest.cc
@@ -28,6 +28,7 @@
using ::testing::_;
using ::testing::InSequence;
+using ::testing::NiceMock;
class MockTraceParser : public ProtoTraceParser {
public:
@@ -45,10 +46,11 @@
MOCK_ParseFtracePacket(cpu, timestamp, tbv.data(), tbv.length());
}
- MOCK_METHOD2(MOCK_ParseTracePacket, void(const uint8_t* data, size_t length));
+ MOCK_METHOD3(MOCK_ParseTracePacket,
+ void(uint64_t ts, const uint8_t* data, size_t length));
- void ParseTracePacket(TraceBlobView tbv) override {
- MOCK_ParseTracePacket(tbv.data(), tbv.length());
+ void ParseTracePacket(uint64_t ts, TraceBlobView tbv) override {
+ MOCK_ParseTracePacket(ts, tbv.data(), tbv.length());
}
};
@@ -63,7 +65,7 @@
public:
TraceSorterTest()
: test_buffer_(std::unique_ptr<uint8_t[]>(new uint8_t[8]), 0, 8) {
- storage_ = new MockTraceStorage();
+ storage_ = new NiceMock<MockTraceStorage>();
context_.storage.reset(storage_);
context_.sorter.reset(
new TraceSorter(&context_, GetParam(), 0 /*window_size*/));
@@ -74,7 +76,7 @@
protected:
TraceProcessorContext context_;
MockTraceParser* parser_;
- MockTraceStorage* storage_;
+ NiceMock<MockTraceStorage>* storage_;
TraceBlobView test_buffer_;
};
@@ -93,7 +95,7 @@
TEST_P(TraceSorterTest, TestTracePacket) {
TraceBlobView view = test_buffer_.slice(0, 1);
- EXPECT_CALL(*parser_, MOCK_ParseTracePacket(view.data(), 1));
+ EXPECT_CALL(*parser_, MOCK_ParseTracePacket(1000, view.data(), 1));
context_.sorter->PushTracePacket(1000, std::move(view));
context_.sorter->FlushEventsForced();
}
@@ -107,8 +109,8 @@
InSequence s;
EXPECT_CALL(*parser_, MOCK_ParseFtracePacket(0, 1000, view_1.data(), 1));
- EXPECT_CALL(*parser_, MOCK_ParseTracePacket(view_2.data(), 2));
- EXPECT_CALL(*parser_, MOCK_ParseTracePacket(view_3.data(), 3));
+ EXPECT_CALL(*parser_, MOCK_ParseTracePacket(1001, view_2.data(), 2));
+ EXPECT_CALL(*parser_, MOCK_ParseTracePacket(1100, view_3.data(), 3));
EXPECT_CALL(*parser_, MOCK_ParseFtracePacket(2, 1200, view_4.data(), 4));
context_.sorter->set_window_ns_for_testing(200);
diff --git a/src/trace_processor/trace_storage.h b/src/trace_processor/trace_storage.h
index fb4e92c..9a86cf4 100644
--- a/src/trace_processor/trace_storage.h
+++ b/src/trace_processor/trace_storage.h
@@ -43,7 +43,7 @@
// StringId is an offset into |string_pool_|.
using StringId = size_t;
-enum RefType { kUTID = 0, kCPU_ID = 1 };
+enum RefType { kNoRef = 0, kUTID = 1, kCPU_ID = 2, kIrq = 3, kSoftIrq = 4 };
// Stores a data inside a trace file in a columnar form. This makes it efficient
// to read or search across a single field of the trace (e.g. all the thread