diff options
author | Yabin Cui <yabinc@google.com> | 2020-03-31 18:04:59 -0700 |
---|---|---|
committer | Yabin Cui <yabinc@google.com> | 2020-04-01 10:20:42 -0700 |
commit | c118258b5f24ae4ce3fbff947ef26b1c80d3a3df (patch) | |
tree | 52289547eaa00b333154f3cf7c73f2dff38e4b84 | |
parent | 9611c7902783d35f36f5c9214c7cfea4b0af7a49 (diff) | |
download | extras-c118258b5f24ae4ce3fbff947ef26b1c80d3a3df.tar.gz |
simpleperf: fix comment for per-thread and per-core report.
For task-clock, it uses software counter, so multiplexing will not
happen. And it isn't proper to scale comment value in per-core report.
For rate computation involving runtime, the current way to find runtime
is via FindRunningTimeForSummary() function. But that function doesn't
take care of thread and core match. And it seems more proper to use
the sum of runtime given by perf counters. So switch to it.
Also add some tests for comment string.
Also adjust comment title in report.
Bug: 152911261
Test: run simpleperf_unit_test.
Change-Id: I475fae32952ed2680888c6a76b43cfb10bc9b06e
(cherry picked from commit 6922c076ce73fd4bca357aeea0d20797e3321749)
-rw-r--r-- | simpleperf/cmd_stat.cpp | 53 | ||||
-rw-r--r-- | simpleperf/cmd_stat_impl.h | 8 | ||||
-rw-r--r-- | simpleperf/cmd_stat_test.cpp | 61 |
3 files changed, 86 insertions, 36 deletions
diff --git a/simpleperf/cmd_stat.cpp b/simpleperf/cmd_stat.cpp index 3bfc635f..1ee6ef81 100644 --- a/simpleperf/cmd_stat.cpp +++ b/simpleperf/cmd_stat.cpp @@ -109,7 +109,7 @@ void CounterSummaries::AutoGenerateSummaries() { if (other != nullptr && other->IsMonitoredAtTheSameTime(s)) { if (FindSummary(s.type_name, "", s.thread, s.cpu) == nullptr) { summaries_.emplace_back(s.type_name, "", s.group_id, s.thread, s.cpu, - s.count + other->count, s.scale, true, csv_); + s.count + other->count, s.runtime_in_ns, s.scale, true, csv_); } } } @@ -135,7 +135,7 @@ void CounterSummaries::ShowCSV(FILE* fp) { if (s.thread != nullptr) { fprintf(fp, "%s,%d,%d,", s.thread->name.c_str(), s.thread->pid, s.thread->tid); } - fprintf(fp, "%s,%s,%s,(%.0lf%%)%s\n", s.readable_count.c_str(), s.Name().c_str(), + fprintf(fp, "%s,%s,%s,(%.0f%%)%s\n", s.readable_count.c_str(), s.Name().c_str(), s.comment.c_str(), 1.0 / s.scale * 100, (s.auto_generated ? " (generated)," : ",")); } } @@ -153,7 +153,7 @@ void CounterSummaries::ShowText(FILE* fp) { } titles.emplace_back("count"); titles.emplace_back("event_name"); - titles.emplace_back(" # percentage = event_run_time / enabled_time"); + titles.emplace_back(" # count / runtime, runtime / enabled_time"); std::vector<size_t> width(titles.size(), 0); @@ -202,7 +202,7 @@ void CounterSummaries::ShowText(FILE* fp) { if (show_cpu) { fprintf(fp, " %-*d", static_cast<int>(width[i++]), s.cpu); } - fprintf(fp, " %*s %-*s # %-*s (%.0lf%%)%s\n", static_cast<int>(width[i]), + fprintf(fp, " %*s %-*s # %-*s (%.0f%%)%s\n", static_cast<int>(width[i]), s.readable_count.c_str(), static_cast<int>(width[i + 1]), s.Name().c_str(), static_cast<int>(width[i + 2]), s.comment.c_str(), 1.0 / s.scale * 100, (s.auto_generated ? " (generated)" : "")); @@ -219,46 +219,45 @@ std::string CounterSummaries::GetCommentForSummary(const CounterSummary& s, } if (s.type_name == "task-clock") { double run_sec = s.count / 1e9; - double used_cpus = run_sec / (duration_in_sec / s.scale); - return android::base::StringPrintf("%lf%ccpus used", used_cpus, sap_mid); + double used_cpus = run_sec / duration_in_sec; + return android::base::StringPrintf("%f%ccpus used", used_cpus, sap_mid); } if (s.type_name == "cpu-clock") { return ""; } if (s.type_name == "cpu-cycles") { - double running_time_in_sec; - if (!FindRunningTimeForSummary(s, &running_time_in_sec)) { + if (s.runtime_in_ns == 0) { return ""; } - double hz = s.count / (running_time_in_sec / s.scale); - return android::base::StringPrintf("%lf%cGHz", hz / 1e9, sap_mid); + double ghz = static_cast<double>(s.count) / s.runtime_in_ns; + return android::base::StringPrintf("%f%cGHz", ghz, sap_mid); } if (s.type_name == "instructions" && s.count != 0) { const CounterSummary* other = FindSummary("cpu-cycles", s.modifier, s.thread, s.cpu); if (other != nullptr && other->IsMonitoredAtTheSameTime(s)) { double cpi = static_cast<double>(other->count) / s.count; - return android::base::StringPrintf("%lf%ccycles per instruction", cpi, sap_mid); + return android::base::StringPrintf("%f%ccycles per instruction", cpi, sap_mid); } } std::string rate_comment = GetRateComment(s, sap_mid); if (!rate_comment.empty()) { return rate_comment; } - double running_time_in_sec; - if (!FindRunningTimeForSummary(s, &running_time_in_sec)) { + if (s.runtime_in_ns == 0) { return ""; } - double rate = s.count / (running_time_in_sec / s.scale); - if (rate > 1e9) { - return android::base::StringPrintf("%.3lf%cG/sec", rate / 1e9, sap_mid); + double runtime_in_sec = static_cast<double>(s.runtime_in_ns) / 1e9; + double rate = s.count / runtime_in_sec; + if (rate >= 1e9 - 1e5) { + return android::base::StringPrintf("%.3f%cG/sec", rate / 1e9, sap_mid); } - if (rate > 1e6) { - return android::base::StringPrintf("%.3lf%cM/sec", rate / 1e6, sap_mid); + if (rate >= 1e6 - 1e2) { + return android::base::StringPrintf("%.3f%cM/sec", rate / 1e6, sap_mid); } - if (rate > 1e3) { - return android::base::StringPrintf("%.3lf%cK/sec", rate / 1e3, sap_mid); + if (rate >= 1e3) { + return android::base::StringPrintf("%.3f%cK/sec", rate / 1e3, sap_mid); } - return android::base::StringPrintf("%.3lf%c/sec", rate, sap_mid); + return android::base::StringPrintf("%.3f%c/sec", rate, sap_mid); } std::string CounterSummaries::GetRateComment(const CounterSummary& s, char sep) { @@ -289,18 +288,6 @@ std::string CounterSummaries::GetRateComment(const CounterSummary& s, char sep) return ""; } -bool CounterSummaries::FindRunningTimeForSummary(const CounterSummary& summary, - double* running_time_in_sec) { - for (auto& s : summaries_) { - if ((s.type_name == "task-clock" || s.type_name == "cpu-clock") && - s.IsMonitoredAtTheSameTime(summary) && s.count != 0u) { - *running_time_in_sec = s.count / 1e9; - return true; - } - } - return false; -} - } // namespace simpleperf namespace { diff --git a/simpleperf/cmd_stat_impl.h b/simpleperf/cmd_stat_impl.h index f8a751fe..a7f60df7 100644 --- a/simpleperf/cmd_stat_impl.h +++ b/simpleperf/cmd_stat_impl.h @@ -77,20 +77,22 @@ struct CounterSummary { const ThreadInfo* thread; int cpu; // -1 represents all cpus uint64_t count; + uint64_t runtime_in_ns; double scale; std::string readable_count; std::string comment; bool auto_generated; CounterSummary(const std::string& type_name, const std::string& modifier, uint32_t group_id, - const ThreadInfo* thread, int cpu, uint64_t count, double scale, - bool auto_generated, bool csv) + const ThreadInfo* thread, int cpu, uint64_t count, uint64_t runtime_in_ns, + double scale, bool auto_generated, bool csv) : type_name(type_name), modifier(modifier), group_id(group_id), thread(thread), cpu(cpu), count(count), + runtime_in_ns(runtime_in_ns), scale(scale), auto_generated(auto_generated) { readable_count = ReadableCountValue(csv); @@ -207,7 +209,7 @@ class CounterSummaryBuilder { thread = &it->second; } summaries_.emplace_back(info.event_name, info.event_modifier, info.group_id, thread, cpu, - sum.value, scale, false, csv_); + sum.value, sum.time_running, scale, false, csv_); } void SortSummaries(std::vector<CounterSummary>::iterator begin, diff --git a/simpleperf/cmd_stat_test.cpp b/simpleperf/cmd_stat_test.cpp index 8bc4e4ff..6b6196a9 100644 --- a/simpleperf/cmd_stat_test.cpp +++ b/simpleperf/cmd_stat_test.cpp @@ -487,3 +487,64 @@ TEST_F(StatCmdSummaryBuilderTest, per_thread_core_aggregate) { ASSERT_EQ(summaries[3].count, 1); ASSERT_NEAR(summaries[3].scale, 1.0, 1e-5); } + +class StatCmdSummariesTest : public ::testing::Test { + protected: + void AddSummary(const std::string event_name, pid_t tid, int cpu, uint64_t count, + uint64_t runtime_in_ns) { + ThreadInfo* thread = nullptr; + if (tid != -1) { + thread = &thread_map_[tid]; + } + summary_v_.emplace_back(event_name, "", 0, thread, cpu, count, runtime_in_ns, 1.0, false, + false); + } + + const std::string* GetComment(size_t index) { + if (!summaries_) { + summaries_.reset(new CounterSummaries(std::move(summary_v_), false)); + summaries_->GenerateComments(1.0); + } + if (index < summaries_->Summaries().size()) { + return &(summaries_->Summaries()[index].comment); + } + return nullptr; + } + + std::unordered_map<pid_t, ThreadInfo> thread_map_; + std::vector<CounterSummary> summary_v_; + std::unique_ptr<CounterSummaries> summaries_; +}; + +TEST_F(StatCmdSummariesTest, task_clock_comment) { + AddSummary("task-clock", -1, -1, 1e9, 0); + AddSummary("task-clock", 0, -1, 2e9, 0); + AddSummary("task-clock", -1, 0, 0.5e9, 0); + AddSummary("task-clock", 1, 1, 3e9, 0); + ASSERT_EQ(*GetComment(0), "1.000000 cpus used"); + ASSERT_EQ(*GetComment(1), "2.000000 cpus used"); + ASSERT_EQ(*GetComment(2), "0.500000 cpus used"); + ASSERT_EQ(*GetComment(3), "3.000000 cpus used"); +} + +TEST_F(StatCmdSummariesTest, cpu_cycles_comment) { + AddSummary("cpu-cycles", -1, -1, 100, 100); + AddSummary("cpu-cycles", 0, -1, 200, 100); + AddSummary("cpu-cycles", -1, 0, 50, 100); + AddSummary("cpu-cycles", 1, 1, 300, 100); + ASSERT_EQ(*GetComment(0), "1.000000 GHz"); + ASSERT_EQ(*GetComment(1), "2.000000 GHz"); + ASSERT_EQ(*GetComment(2), "0.500000 GHz"); + ASSERT_EQ(*GetComment(3), "3.000000 GHz"); +} + +TEST_F(StatCmdSummariesTest, rate_comment) { + AddSummary("branch-misses", -1, -1, 1e9, 1e9); + AddSummary("branch-misses", 0, -1, 1e6, 1e9); + AddSummary("branch-misses", -1, 0, 1e3, 1e9); + AddSummary("branch-misses", 1, 1, 1, 1e9); + ASSERT_EQ(*GetComment(0), "1.000 G/sec"); + ASSERT_EQ(*GetComment(1), "1.000 M/sec"); + ASSERT_EQ(*GetComment(2), "1.000 K/sec"); + ASSERT_EQ(*GetComment(3), "1.000 /sec"); +}
\ No newline at end of file |