diff options
author | Yabin Cui <yabinc@google.com> | 2018-02-06 02:54:18 +0000 |
---|---|---|
committer | Gerrit Code Review <noreply-gerritcodereview@google.com> | 2018-02-06 02:54:18 +0000 |
commit | 329daa8b39041fb2041a52aa35dd945b39e870f2 (patch) | |
tree | 29c18a6c1cf5e761a0ec45616e0204a2f2ffa3d6 | |
parent | b58c9fa94cd59bf492e0bfd364e3f1dafc134b2f (diff) | |
parent | c3bf9d08671e8d41d24eeb5978a01b2dd40d0bc4 (diff) | |
download | extras-329daa8b39041fb2041a52aa35dd945b39e870f2.tar.gz |
Merge "simpleperf: add debug-unwind cmd."
-rw-r--r-- | simpleperf/Android.mk | 2 | ||||
-rw-r--r-- | simpleperf/cmd_debug_unwind.cpp | 397 | ||||
-rw-r--r-- | simpleperf/cmd_debug_unwind_test.cpp | 95 | ||||
-rw-r--r-- | simpleperf/cmd_record.cpp | 25 | ||||
-rw-r--r-- | simpleperf/command.cpp | 2 | ||||
-rw-r--r-- | simpleperf/get_test_data.h | 3 | ||||
-rw-r--r-- | simpleperf/record_file.h | 2 | ||||
-rw-r--r-- | simpleperf/record_file_writer.cpp | 48 | ||||
-rw-r--r-- | simpleperf/scripts/unwinding_result_reporter.py | 97 | ||||
-rw-r--r-- | simpleperf/testdata/perf_no_unwind.data | bin | 0 -> 550711 bytes |
10 files changed, 615 insertions, 56 deletions
diff --git a/simpleperf/Android.mk b/simpleperf/Android.mk index 69b4f10b..01263516 100644 --- a/simpleperf/Android.mk +++ b/simpleperf/Android.mk @@ -107,6 +107,7 @@ libsimpleperf_src_files := \ libsimpleperf_src_files_linux := \ CallChainJoiner.cpp \ + cmd_debug_unwind.cpp \ cmd_list.cpp \ cmd_record.cpp \ cmd_stat.cpp \ @@ -361,6 +362,7 @@ simpleperf_unit_test_src_files := \ simpleperf_unit_test_src_files_linux := \ CallChainJoiner_test.cpp \ + cmd_debug_unwind_test.cpp \ cmd_dumprecord_test.cpp \ cmd_list_test.cpp \ cmd_record_test.cpp \ diff --git a/simpleperf/cmd_debug_unwind.cpp b/simpleperf/cmd_debug_unwind.cpp new file mode 100644 index 00000000..d356355c --- /dev/null +++ b/simpleperf/cmd_debug_unwind.cpp @@ -0,0 +1,397 @@ +/* + * Copyright (C) 2018 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#include <algorithm> +#include <memory> +#include <string> +#include <unordered_map> +#include <vector> + +#include <android-base/file.h> +#include <android-base/logging.h> +#include <android-base/parseint.h> +#include <android-base/stringprintf.h> +#include <android-base/strings.h> + +#include "CallChainJoiner.h" +#include "command.h" +#include "environment.h" +#include "OfflineUnwinder.h" +#include "perf_regs.h" +#include "record_file.h" +#include "thread_tree.h" +#include "utils.h" +#include "workload.h" + +using namespace simpleperf; + +// Cache size used by CallChainJoiner to cache call chains in memory. +constexpr size_t DEFAULT_CALL_CHAIN_JOINER_CACHE_SIZE = 8 * 1024 * 1024; + +struct MemStat { + std::string vm_peak; + std::string vm_size; + std::string vm_hwm; + std::string vm_rss; + + std::string ToString() const { + return android::base::StringPrintf("VmPeak:%s;VmSize:%s;VmHWM:%s;VmRSS:%s", vm_peak.c_str(), + vm_size.c_str(), vm_hwm.c_str(), vm_rss.c_str()); + } +}; + +static bool GetMemStat(MemStat* stat) { + std::string s; + if (!android::base::ReadFileToString(android::base::StringPrintf("/proc/%d/status", getpid()), + &s)) { + PLOG(ERROR) << "Failed to read process status"; + return false; + } + std::vector<std::string> lines = android::base::Split(s, "\n"); + for (auto& line : lines) { + if (android::base::StartsWith(line, "VmPeak:")) { + stat->vm_peak = android::base::Trim(line.substr(strlen("VmPeak:"))); + } else if (android::base::StartsWith(line, "VmSize:")) { + stat->vm_size = android::base::Trim(line.substr(strlen("VmSize:"))); + } else if (android::base::StartsWith(line, "VmHWM:")) { + stat->vm_hwm = android::base::Trim(line.substr(strlen("VmHWM:"))); + } else if (android::base::StartsWith(line, "VmRSS:")) { + stat->vm_rss = android::base::Trim(line.substr(strlen("VmRSS:"))); + } + } + return true; +} + +class DebugUnwindCommand : public Command { + public: + DebugUnwindCommand() + : Command("debug-unwind", "Debug/test offline unwinding.", + // clang-format off +"Usage: simpleperf debug-unwind [options]\n" +" Given a perf.data generated with \"-g --no-unwind\", it converts\n" +" regs/stack data of samples into callchains, and write result into\n" +" a new perf.data. The new perf.data can be passed to\n" +" unwind_result_reporter.py to generate a text report.\n" +"-i <file> The path of record file generated with \"-g --no-unwind\".\n" +" Default is perf.data.\n" +"-o <file> The path ot write new perf.data. Default is perf.data.debug.\n" +"--time time Only unwind samples recorded at selected time.\n" + // clang-format on + ), + input_filename_("perf.data"), + output_filename_("perf.data.debug"), + offline_unwinder_(false, true), + callchain_joiner_(DEFAULT_CALL_CHAIN_JOINER_CACHE_SIZE, 1, true), + selected_time_(0) { + } + + bool Run(const std::vector<std::string>& args); + + private: + bool ParseOptions(const std::vector<std::string>& args); + bool UnwindRecordFile(); + bool ProcessRecord(Record* record); + void CollectHitFileInfo(const SampleRecord& r, const std::vector<uint64_t>& ips); + bool JoinCallChains(); + bool WriteFeatureSections(); + void PrintStat(); + + struct Stat { + // For testing unwinding performance. + uint64_t unwinding_sample_count = 0u; + uint64_t total_unwinding_time_in_ns = 0u; + uint64_t max_unwinding_time_in_ns = 0u; + + // For memory consumption. + MemStat mem_before_unwinding; + MemStat mem_after_unwinding; + }; + + std::string input_filename_; + std::string output_filename_; + std::unique_ptr<RecordFileReader> reader_; + std::unique_ptr<RecordFileWriter> writer_; + ThreadTree thread_tree_; + OfflineUnwinder offline_unwinder_; + CallChainJoiner callchain_joiner_; + Stat stat_; + uint64_t selected_time_; +}; + +bool DebugUnwindCommand::Run(const std::vector<std::string>& args) { + // 1. Parse options. + if (!ParseOptions(args)) { + return false; + } + + // 2. Read input perf.data, and generate new perf.data. + if (!UnwindRecordFile()) { + return false; + } + + // 3. Show stat of unwinding. + PrintStat(); + return true; +} + +bool DebugUnwindCommand::ParseOptions(const std::vector<std::string>& args) { + for (size_t i = 0; i < args.size(); ++i) { + if (args[i] == "-i") { + if (!NextArgumentOrError(args, &i)) { + return false; + } + input_filename_ = args[i]; + } else if (args[i] == "-o") { + if (!NextArgumentOrError(args, &i)) { + return false; + } + output_filename_ = args[i]; + } else if (args[i] == "--time") { + if (!NextArgumentOrError(args, &i)) { + return false; + } + if (!android::base::ParseUint(args[i].c_str(), &selected_time_)) { + LOG(ERROR) << "Invalid option for " << args[i-1] << ": " << args[i]; + return false; + } + } else { + ReportUnknownOption(args, i); + return false; + } + } + SetTempDirectoryUsedInRecording(android::base::Dirname(output_filename_)); + return true; +} + +bool DebugUnwindCommand::UnwindRecordFile() { + // 1. Check input file. + reader_ = RecordFileReader::CreateInstance(input_filename_); + if (!reader_) { + return false; + } + std::string record_cmd = android::base::Join(reader_->ReadCmdlineFeature(), " "); + if (record_cmd.find("--no-unwind") == std::string::npos || + (record_cmd.find("-g") == std::string::npos && + record_cmd.find("--call-graph dwarf") == std::string::npos)) { + LOG(ERROR) << input_filename_ << " isn't recorded with \"-g --no-unwind\""; + return false; + } + ScopedCurrentArch scoped_arch(GetArchType(reader_->ReadFeatureString(PerfFileFormat::FEAT_ARCH))); + + // 2. Copy attr section. + writer_ = RecordFileWriter::CreateInstance(output_filename_); + if (!writer_ || !writer_->WriteAttrSection(reader_->AttrSection())) { + return false; + } + + // 3. Process records in data section. + if (!GetMemStat(&stat_.mem_before_unwinding)) { + return false; + } + auto callback = [this](std::unique_ptr<Record> record) { + return ProcessRecord(record.get()); + }; + if (!reader_->ReadDataSection(callback)) { + return false; + } + if (!JoinCallChains()) { + return false; + } + if (!GetMemStat(&stat_.mem_after_unwinding)) { + return false; + } + + // 4. Write feature sections. + return WriteFeatureSections(); +} + +bool DebugUnwindCommand::ProcessRecord(Record* record) { + if (record->type() == PERF_RECORD_SAMPLE) { + auto& r = *static_cast<SampleRecord*>(record); + if (selected_time_ != 0u && r.Timestamp() != selected_time_) { + return true; + } + r.AdjustCallChainGeneratedByKernel(); + r.RemoveInvalidStackData(); + uint64_t need_type = PERF_SAMPLE_CALLCHAIN | PERF_SAMPLE_REGS_USER | PERF_SAMPLE_STACK_USER; + if ((r.sample_type & need_type) == need_type && r.regs_user_data.reg_mask != 0 && + r.GetValidStackSize() > 0) { + ThreadEntry* thread = thread_tree_.FindThreadOrNew(r.tid_data.pid, r.tid_data.tid); + RegSet regs = CreateRegSet(r.regs_user_data.abi, r.regs_user_data.reg_mask, + r.regs_user_data.regs); + std::vector<uint64_t> ips; + std::vector<uint64_t> sps; + if (!offline_unwinder_.UnwindCallChain(r.regs_user_data.abi, *thread, regs, + r.stack_user_data.data, r.GetValidStackSize(), + &ips, &sps)) { + return false; + } + + const UnwindingResult& unwinding_result = offline_unwinder_.GetUnwindingResult(); + stat_.unwinding_sample_count++; + stat_.total_unwinding_time_in_ns += unwinding_result.used_time; + stat_.max_unwinding_time_in_ns = std::max(stat_.max_unwinding_time_in_ns, + unwinding_result.used_time); + if (!writer_->WriteRecord(UnwindingResultRecord(r.time_data.time, unwinding_result))) { + return false; + } + // We want to keep both reg/stack data and callchain of a sample. However, storing both + // can exceed the size limit of a SampleRecord. So instead we store one sample with reg/stack + // data and one sample with callchain. + if (!writer_->WriteRecord(r)) { + return false; + } + r.ReplaceRegAndStackWithCallChain(ips); + if (!callchain_joiner_.AddCallChain(r.tid_data.pid, r.tid_data.tid, + CallChainJoiner::ORIGINAL_OFFLINE, ips, sps)) { + return false; + } + CollectHitFileInfo(r, ips); + } + } else { + thread_tree_.Update(*record); + } + return writer_->WriteRecord(*record); +} + +void DebugUnwindCommand::CollectHitFileInfo(const SampleRecord& r, + const std::vector<uint64_t>& ips) { + const ThreadEntry* thread = thread_tree_.FindThreadOrNew(r.tid_data.pid, r.tid_data.tid); + for (auto ip : ips) { + const MapEntry* map = thread_tree_.FindMap(thread, ip, false); + Dso* dso = map->dso; + if (!dso->HasDumpId()) { + dso->CreateDumpId(); + } + const Symbol* symbol = thread_tree_.FindSymbol(map, ip, nullptr, &dso); + if (!symbol->HasDumpId()) { + dso->CreateSymbolDumpId(symbol); + } + } +} + +bool DebugUnwindCommand::JoinCallChains() { + // 1. Prepare joined callchains. + if (!callchain_joiner_.JoinCallChains()) { + return false; + } + // 2. Move records from record_filename_ to a temporary file. + if (!writer_->Close()) { + return false; + } + writer_.reset(); + std::unique_ptr<TemporaryFile> tmpfile = CreateTempFileUsedInRecording(); + if (!Workload::RunCmd({"mv", output_filename_, tmpfile->path})) { + return false; + } + + // 3. Read records from the temporary file, and write records with joined call chains back + // to record_filename_. + std::unique_ptr<RecordFileReader> reader = RecordFileReader::CreateInstance(tmpfile->path); + if (!reader) { + return false; + } + writer_ = RecordFileWriter::CreateInstance(output_filename_); + if (!writer_ || !writer_->WriteAttrSection(reader->AttrSection())) { + return false; + } + + auto record_callback = [&](std::unique_ptr<Record> r) { + if (r->type() != PERF_RECORD_SAMPLE) { + return writer_->WriteRecord(*r); + } + SampleRecord& sr = *static_cast<SampleRecord*>(r.get()); + if (!sr.HasUserCallChain()) { + return writer_->WriteRecord(sr); + } + pid_t pid; + pid_t tid; + CallChainJoiner::ChainType type; + std::vector<uint64_t> ips; + std::vector<uint64_t> sps; + do { + if (!callchain_joiner_.GetNextCallChain(pid, tid, type, ips, sps)) { + return false; + } + if (!writer_->WriteRecord(CallChainRecord(pid, tid, type, sr.Timestamp(), ips, sps))) { + return false; + } + } while (type != CallChainJoiner::JOINED_OFFLINE); + CHECK_EQ(pid, static_cast<pid_t>(sr.tid_data.pid)); + CHECK_EQ(tid, static_cast<pid_t>(sr.tid_data.tid)); + sr.UpdateUserCallChain(ips); + return writer_->WriteRecord(sr); + }; + return reader->ReadDataSection(record_callback, false); +} + +bool DebugUnwindCommand::WriteFeatureSections() { + const std::map<int, PerfFileFormat::SectionDesc>& features = reader_->FeatureSectionDescriptors(); + if (!writer_->BeginWriteFeatures(features.size())) { + return false; + } + for (auto& pair : features) { + int feature = pair.first; + if (feature == PerfFileFormat::FEAT_META_INFO) { + std::unordered_map<std::string, std::string> info_map; + if (!reader_->ReadMetaInfoFeature(&info_map)) { + return false; + } + info_map["debug_unwind"] = "true"; + info_map["debug_unwind_mem_before"] = stat_.mem_before_unwinding.ToString(); + info_map["debug_unwind_mem_after"] = stat_.mem_after_unwinding.ToString(); + if (!writer_->WriteMetaInfoFeature(info_map)) { + return false; + } + } else if (feature == PerfFileFormat::FEAT_FILE) { + if (!writer_->WriteFileFeatures(thread_tree_.GetAllDsos())) { + return false; + } + } else { + std::vector<char> data; + if (!reader_->ReadFeatureSection(feature, &data) || !writer_->WriteFeature(feature, data)) { + return false; + } + } + } + return writer_->EndWriteFeatures() && writer_->Close(); +} + +void DebugUnwindCommand::PrintStat() { + printf("Unwinding sample count: %" PRIu64 "\n", stat_.unwinding_sample_count); + if (stat_.unwinding_sample_count > 0u) { + printf("Average unwinding time: %f us\n", static_cast<double>(stat_.total_unwinding_time_in_ns) + / 1000 / stat_.unwinding_sample_count); + printf("Max unwinding time: %f us\n", static_cast<double>(stat_.max_unwinding_time_in_ns) + / 1000); + } + printf("Memory change:\n"); + PrintIndented(1, "VmPeak: %s -> %s\n", stat_.mem_before_unwinding.vm_peak.c_str(), + stat_.mem_after_unwinding.vm_peak.c_str()); + PrintIndented(1, "VmSize: %s -> %s\n", stat_.mem_before_unwinding.vm_size.c_str(), + stat_.mem_after_unwinding.vm_size.c_str()); + PrintIndented(1, "VmHWM: %s -> %s\n", stat_.mem_before_unwinding.vm_hwm.c_str(), + stat_.mem_after_unwinding.vm_hwm.c_str()); + PrintIndented(1, "VmRSS: %s -> %s\n", stat_.mem_before_unwinding.vm_rss.c_str(), + stat_.mem_after_unwinding.vm_rss.c_str()); + callchain_joiner_.DumpStat(); + printf("Please use unwinding_result_reporter.py to get a report in details.\n"); +} + +void RegisterDebugUnwindCommand() { + RegisterCommand("debug-unwind", + []{ return std::unique_ptr<Command>(new DebugUnwindCommand()); }); +} diff --git a/simpleperf/cmd_debug_unwind_test.cpp b/simpleperf/cmd_debug_unwind_test.cpp new file mode 100644 index 00000000..bae45f6b --- /dev/null +++ b/simpleperf/cmd_debug_unwind_test.cpp @@ -0,0 +1,95 @@ +/* + * Copyright (C) 2018 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#include <gtest/gtest.h> + +#include <unistd.h> + +#include <memory> +#include <string> +#include <vector> + +#include <android-base/file.h> +#include <android-base/test_utils.h> + +#include "command.h" +#include "get_test_data.h" +#include "test_util.h" + +#if defined(__aarch64__) +static std::unique_ptr<Command> DebugUnwindCmd() { + return CreateCommandInstance("debug-unwind"); +} + +class CaptureStdout { + public: + CaptureStdout() : started_(false) {} + + ~CaptureStdout() { + if (started_) { + Finish(); + } + } + + bool Start() { + old_stdout_ = dup(STDOUT_FILENO); + if (old_stdout_ == -1) { + return false; + } + started_ = true; + tmpfile_.reset(new TemporaryFile); + if (dup2(tmpfile_->fd, STDOUT_FILENO) == -1) { + return false; + } + return true; + } + + std::string Finish() { + started_ = false; + dup2(old_stdout_, STDOUT_FILENO); + close(old_stdout_); + std::string s; + if (!android::base::ReadFileToString(tmpfile_->path, &s)) { + return ""; + } + return s; + } + + private: + bool started_; + int old_stdout_; + std::unique_ptr<TemporaryFile> tmpfile_; +}; +#endif // defined(__aarch64__) + +TEST(cmd_debug_unwind, smoke) { + // TODO: Remove the arch limitation once using cross-platform unwinding in the new unwinder. +#if defined(__aarch64__) + std::string input_data = GetTestData(PERF_DATA_NO_UNWIND); + CaptureStdout capture; + TemporaryFile tmp_file; + ASSERT_TRUE(capture.Start()); + ASSERT_TRUE(DebugUnwindCmd()->Run({"-i", input_data, "-o", tmp_file.path})); + ASSERT_NE(capture.Finish().find("Unwinding sample count: 8"), std::string::npos); + + ASSERT_TRUE(capture.Start()); + ASSERT_TRUE(DebugUnwindCmd()->Run({"-i", input_data, "-o", tmp_file.path, "--time", + "1516379654300997"})); + ASSERT_NE(capture.Finish().find("Unwinding sample count: 1"), std::string::npos); +#else + GTEST_LOG_(INFO) << "This test does nothing on non-ARM64 devices."; +#endif +} diff --git a/simpleperf/cmd_record.cpp b/simpleperf/cmd_record.cpp index 2a6bf334..4056474b 100644 --- a/simpleperf/cmd_record.cpp +++ b/simpleperf/cmd_record.cpp @@ -1342,30 +1342,7 @@ bool RecordCommand::DumpBuildIdFeature() { bool RecordCommand::DumpFileFeature() { std::vector<Dso*> dso_v = thread_tree_.GetAllDsos(); - for (Dso* dso : dso_v) { - if (!dso->HasDumpId()) { - continue; - } - uint32_t dso_type = dso->type(); - uint64_t min_vaddr = dso->MinVirtualAddress(); - - // Dumping all symbols in hit files takes too much space, so only dump - // needed symbols. - const std::vector<Symbol>& symbols = dso->GetSymbols(); - std::vector<const Symbol*> dump_symbols; - for (const auto& sym : symbols) { - if (sym.HasDumpId()) { - dump_symbols.push_back(&sym); - } - } - std::sort(dump_symbols.begin(), dump_symbols.end(), Symbol::CompareByAddr); - - if (!record_file_writer_->WriteFileFeature(dso->Path(), dso_type, min_vaddr, - dump_symbols)) { - return false; - } - } - return true; + return record_file_writer_->WriteFileFeatures(thread_tree_.GetAllDsos()); } bool RecordCommand::DumpMetaInfoFeature() { diff --git a/simpleperf/command.cpp b/simpleperf/command.cpp index 0d071ab4..3d6c2d2c 100644 --- a/simpleperf/command.cpp +++ b/simpleperf/command.cpp @@ -79,6 +79,7 @@ extern void RegisterRecordCommand(); extern void RegisterReportCommand(); extern void RegisterReportSampleCommand(); extern void RegisterStatCommand(); +extern void RegisterDebugUnwindCommand(); class CommandRegister { public: @@ -92,6 +93,7 @@ class CommandRegister { RegisterListCommand(); RegisterRecordCommand(); RegisterStatCommand(); + RegisterDebugUnwindCommand(); #endif } }; diff --git a/simpleperf/get_test_data.h b/simpleperf/get_test_data.h index 44dcd2c9..05b724ee 100644 --- a/simpleperf/get_test_data.h +++ b/simpleperf/get_test_data.h @@ -114,4 +114,7 @@ static const std::string PERF_DATA_WITH_TRACE_OFFCPU = "perf_with_trace_offcpu.d // generated by `simpleperf record -g --log debug sleep 1`. static const std::string PERF_DATA_WITH_CALLCHAIN_RECORD = "perf_with_callchain_record.data"; +// generated by `simpleperf record -g --no-unwind`. +static const std::string PERF_DATA_NO_UNWIND = "perf_no_unwind.data"; + #endif // SIMPLE_PERF_GET_TEST_DATA_H_ diff --git a/simpleperf/record_file.h b/simpleperf/record_file.h index 4e09d48e..00b8a344 100644 --- a/simpleperf/record_file.h +++ b/simpleperf/record_file.h @@ -54,11 +54,13 @@ class RecordFileWriter { bool WriteFeatureString(int feature, const std::string& s); bool WriteCmdlineFeature(const std::vector<std::string>& cmdline); bool WriteBranchStackFeature(); + bool WriteFileFeatures(const std::vector<Dso*>& files); bool WriteFileFeature(const std::string& file_path, uint32_t file_type, uint64_t min_vaddr, const std::vector<const Symbol*>& symbols); bool WriteMetaInfoFeature(const std::unordered_map<std::string, std::string>& info_map); + bool WriteFeature(int feature, const std::vector<char>& data); bool EndWriteFeatures(); bool Close(); diff --git a/simpleperf/record_file_writer.cpp b/simpleperf/record_file_writer.cpp index 6d0fdd9f..fd738d10 100644 --- a/simpleperf/record_file_writer.cpp +++ b/simpleperf/record_file_writer.cpp @@ -20,6 +20,7 @@ #include <string.h> #include <sys/mman.h> #include <unistd.h> +#include <algorithm> #include <set> #include <string> #include <unordered_map> @@ -28,6 +29,7 @@ #include <android-base/file.h> #include <android-base/logging.h> +#include "dso.h" #include "event_attr.h" #include "perf_event.h" #include "record.h" @@ -295,6 +297,32 @@ bool RecordFileWriter::WriteBranchStackFeature() { return WriteFeatureEnd(FEAT_BRANCH_STACK); } +bool RecordFileWriter::WriteFileFeatures(const std::vector<Dso*>& files) { + for (Dso* dso : files) { + if (!dso->HasDumpId()) { + continue; + } + uint32_t dso_type = dso->type(); + uint64_t min_vaddr = dso->MinVirtualAddress(); + + // Dumping all symbols in hit files takes too much space, so only dump + // needed symbols. + const std::vector<Symbol>& symbols = dso->GetSymbols(); + std::vector<const Symbol*> dump_symbols; + for (const auto& sym : symbols) { + if (sym.HasDumpId()) { + dump_symbols.push_back(&sym); + } + } + std::sort(dump_symbols.begin(), dump_symbols.end(), Symbol::CompareByAddr); + + if (!WriteFileFeature(dso->Path(), dso_type, min_vaddr, dump_symbols)) { + return false; + } + } + return true; +} + bool RecordFileWriter::WriteFileFeature(const std::string& file_path, uint32_t file_type, uint64_t min_vaddr, @@ -320,13 +348,7 @@ bool RecordFileWriter::WriteFileFeature(const std::string& file_path, } CHECK_EQ(buf.size(), static_cast<size_t>(p - buf.data())); - if (!WriteFeatureBegin(FEAT_FILE)) { - return false; - } - if (!Write(buf.data(), buf.size())) { - return false; - } - return WriteFeatureEnd(FEAT_FILE); + return WriteFeature(FEAT_FILE, buf); } bool RecordFileWriter::WriteMetaInfoFeature( @@ -342,13 +364,11 @@ bool RecordFileWriter::WriteMetaInfoFeature( MoveToBinaryFormat(pair.first.c_str(), pair.first.size() + 1, p); MoveToBinaryFormat(pair.second.c_str(), pair.second.size() + 1, p); } - if (!WriteFeatureBegin(FEAT_META_INFO)) { - return false; - } - if (!Write(buf.data(), buf.size())) { - return false; - } - return WriteFeatureEnd(FEAT_META_INFO); + return WriteFeature(FEAT_META_INFO, buf); +} + +bool RecordFileWriter::WriteFeature(int feature, const std::vector<char>& data) { + return WriteFeatureBegin(feature) && Write(data.data(), data.size()) && WriteFeatureEnd(feature); } bool RecordFileWriter::WriteFeatureBegin(int feature) { diff --git a/simpleperf/scripts/unwinding_result_reporter.py b/simpleperf/scripts/unwinding_result_reporter.py index 4c1663b1..3eee00a6 100644 --- a/simpleperf/scripts/unwinding_result_reporter.py +++ b/simpleperf/scripts/unwinding_result_reporter.py @@ -15,11 +15,25 @@ # limitations under the License. # -"""unwinding_result_reporter.py: report dwarf unwinding results. - It can be used on perf.data generated with the '-g --log debug' option. - It is used to help findinig problems of unwinding different libraries - using libBacktraceOffline. - +"""unwinding_result_reporter.py: report dwarf unwinding results generated by debug-unwind cmd. + Below is an example using unwinding_result_reporter.py: + 1. Record with "-g --no-unwind" option on device. + simpleperf record -g --no-unwind --app com.google.sample.tunnel --duration 10 + 2. Use debug-unwind cmd to unwind samples in perf.data on device. + simpleperf debug-unwind + 3. Pull perf.data.debug on host, and report it with this script. + python unwinding_result_reporter.py + + It reports below items: + 1. time used for offline dwarf unwinding for each sample. + 2. mem consumption before and after unwinding samples. + 3. For samples that don't have complete callchains, report their regs, stack data, + unwinding failure info, callchains. Samples having the same failure reason + in the same function are only reported once. + + It can be used to: + 1. show unwinding failures. + 2. show performance and memory consumption change caused by simpleperf/unwinder changes. """ from __future__ import print_function @@ -106,6 +120,13 @@ class UnwindingTimes(object): self.max_time = max(self.max_time, used_time) +class UnwindingMemConsumption(object): + + def __init___(self): + self.before_unwinding = None + self.after_unwinding = None + + class CallChainNode(object): """ Representing a node in a call chain.""" @@ -125,11 +146,12 @@ class SampleResult(object): """ Unwinding result per sample. """ - def __init__(self, pid, tid, unwinding_result, callchain): + def __init__(self, pid, tid, unwinding_result, callchain, sample_record): self.pid = pid self.tid = tid self.unwinding_result = unwinding_result self.callchain = callchain + self.sample_record = sample_record def show(self): print(' pid: %d' % self.pid) @@ -140,6 +162,10 @@ class SampleResult(object): print(' node %d: ip 0x%x, sp 0x%x, %s (%s[+%x]), map [%x-%x]' % ( i, node.ip, node.sp, node.function_name, node.filename, node.vaddr_in_file, node.map_start_addr, node.map_end_addr)) + if self.sample_record: + print(' original sample record:') + for line in self.sample_record: + print(' %s' % line) class FunctionResult(object): @@ -199,6 +225,7 @@ class UnwindingResultErrorReport(object): self.omit_callchains_fixed_by_joiner = omit_callchains_fixed_by_joiner self.process_maps = ProcessMaps() self.unwinding_times = UnwindingTimes() + self.mem_stat = UnwindingMemConsumption() self.file_results = {} # map from filename to FileResult. def add_sample_result(self, sample_result, joined_record): @@ -211,6 +238,17 @@ class UnwindingResultErrorReport(object): file_result = self.file_results[filename] = FileResult() file_result.add_sample_result(sample_result) + def add_mem_stat(self, name, mem_str): + # mem_str is like VmPeak:202464 kB;VmSize:183456 kB;VmHWM:98256 kB;VmRSS:33680 kB. + items = [] + for p in mem_str.split(';'): + key, value = p.split(':') + items.append((key, value)) + if name == 'debug_unwind_mem_before': + self.mem_stat.before_unwinding = items + else: + self.mem_stat.after_unwinding = items + def should_omit(self, sample_result, joined_record): # 1. Can't unwind code generated in memory. for name in ['/dev/ashmem/dalvik-jit-code-cache', '//anon']: @@ -239,6 +277,10 @@ class UnwindingResultErrorReport(object): print(' average time: %f us' % ( self.unwinding_times.total_time / 1e3 / self.unwinding_times.count)) print(' max time: %f us' % (self.unwinding_times.max_time / 1e3)) + print('Unwinding mem info:') + for items in zip(self.mem_stat.before_unwinding, self.mem_stat.after_unwinding): + assert items[0][0] == items[1][0] + print(' %s: %s -> %s' % (items[0][0], items[0][1], items[1][1])) print('Process maps:') self.process_maps.show() for filename in sorted(self.file_results): @@ -255,6 +297,15 @@ class CallChainRecord(object): self.tid = None self.callchain = [] +def parse_sample_record(lines, i): + """ Read the lines belong to a SampleRecord.""" + if i == len(lines) or not lines[i].startswith('record sample:'): + log_fatal('unexpected dump output near line %d' % i) + start_line = i + i += 1 + while i < len(lines) and (not lines[i] or lines[i].startswith(' ')): + i += 1 + return i, lines[start_line:i] def parse_callchain_record(lines, i, chain_type, process_maps): if i == len(lines) or not lines[i].startswith('record callchain:'): @@ -323,15 +374,15 @@ def parse_callchain_record(lines, i, chain_type, process_maps): return i, record -def build_unwinding_result_report(record_file, omit_callchains_fixed_by_joiner): +def build_unwinding_result_report(args): simpleperf_path = get_host_binary_path('simpleperf') - args = [simpleperf_path, 'dump', record_file] - proc = subprocess.Popen(args, stdout=subprocess.PIPE) + proc = subprocess.Popen([simpleperf_path, 'dump', args.record_file[0]], + stdout=subprocess.PIPE) (stdoutdata, _) = proc.communicate() - if 'record callchain' not in stdoutdata or 'record unwinding_result' not in stdoutdata: - log_exit("Can't parse unwinding result. Because %s is not recorded using '--log debug'." + if 'debug_unwind = true' not in stdoutdata: + log_exit("Can't parse unwinding result. Because %s is not generated by debug-unwind cmd." % record_file) - unwinding_report = UnwindingResultErrorReport(omit_callchains_fixed_by_joiner) + unwinding_report = UnwindingResultErrorReport(args.omit_callchains_fixed_by_joiner) process_maps = unwinding_report.process_maps lines = stdoutdata.split('\n') i = 0 @@ -368,10 +419,14 @@ def build_unwinding_result_report(record_file, omit_callchains_fixed_by_joiner): if key not in unwinding_result: log_fatal('unexpected dump output near line %d' % i) + i, sample_record = parse_sample_record(lines, i) i, original_record = parse_callchain_record(lines, i, 'ORIGINAL_OFFLINE', process_maps) i, joined_record = parse_callchain_record(lines, i, 'JOINED_OFFLINE', process_maps) + if args.omit_sample: + sample_record = [] sample_result = SampleResult(original_record.pid, original_record.tid, - unwinding_result, original_record.callchain) + unwinding_result, original_record.callchain, + sample_record) unwinding_report.add_sample_result(sample_result, joined_record) elif lines[i].startswith('record fork:'): i += 1 @@ -387,6 +442,11 @@ def build_unwinding_result_report(record_file, omit_callchains_fixed_by_joiner): if None in [pid, ppid]: log_fatal('unexpected dump output near line %d' % i) process_maps.fork_pid(pid, ppid) + elif lines[i].startswith(' debug_unwind_mem'): + items = lines[i].strip().split(' = ') + if len(items) == 2: + unwinding_report.add_mem_stat(items[0], items[1]) + i += 1 else: i += 1 return unwinding_report @@ -394,14 +454,15 @@ def build_unwinding_result_report(record_file, omit_callchains_fixed_by_joiner): def main(): parser = argparse.ArgumentParser( - description='report unwinding result in profiling data') - parser.add_argument('-i', '--record_file', nargs=1, default=['perf.data'], help=""" - Set profiling data to report. Default is perf.data.""") + description='report dwarf unwinding results generated by debug-unwind cmd') + parser.add_argument('-i', '--record_file', nargs=1, default=['perf.data.debug'], help=""" + Set profiling data to report. Default is perf.data.debug.""") parser.add_argument('--omit-callchains-fixed-by-joiner', action='store_true', help=""" Don't show incomplete callchains fixed by callchain joiner.""") + parser.add_argument('--omit-sample', action='store_true', help="""Don't show original sample + records.""") args = parser.parse_args() - report = build_unwinding_result_report(args.record_file[0], - args.omit_callchains_fixed_by_joiner) + report = build_unwinding_result_report(args) report.show() if __name__ == '__main__': diff --git a/simpleperf/testdata/perf_no_unwind.data b/simpleperf/testdata/perf_no_unwind.data Binary files differnew file mode 100644 index 00000000..473f7f2c --- /dev/null +++ b/simpleperf/testdata/perf_no_unwind.data |