From 83b3761c9ec3c359f98533dc55c069902d4f6af9 Mon Sep 17 00:00:00 2001 From: stgatilov Date: Sun, 13 Jun 2021 11:37:45 +0700 Subject: [PATCH 01/17] Added mercurial ignore filter. --- .hgignore | 6 ++++++ 1 file changed, 6 insertions(+) create mode 100644 .hgignore diff --git a/.hgignore b/.hgignore new file mode 100644 index 0000000..0f9be94 --- /dev/null +++ b/.hgignore @@ -0,0 +1,6 @@ +syntax: regexp +^out\/ +^packages\/ +\.vs\/ +Release\/ +Debug\/ \ No newline at end of file From 53e41a02ae31f1b2adeb8340707b60b092de415c Mon Sep 17 00:00:00 2001 From: stgatilov Date: Sun, 13 Jun 2021 17:59:46 +0700 Subject: [PATCH 02/17] Added TemplateStats analyzer. --- src/TemplateStats/TemplateStats.cpp | 80 +++++++++++++++++++++++++++++ src/TemplateStats/TemplateStats.h | 38 ++++++++++++++ vcperf.vcxproj | 2 + vcperf.vcxproj.filters | 9 ++++ 4 files changed, 129 insertions(+) create mode 100644 src/TemplateStats/TemplateStats.cpp create mode 100644 src/TemplateStats/TemplateStats.h diff --git a/src/TemplateStats/TemplateStats.cpp b/src/TemplateStats/TemplateStats.cpp new file mode 100644 index 0000000..8b5783c --- /dev/null +++ b/src/TemplateStats/TemplateStats.cpp @@ -0,0 +1,80 @@ +#include "TemplateStats.h" +#include +#include + +using namespace Microsoft::Cpp::BuildInsights; +using namespace vcperf; + + +TemplateStatsAnalyzer::TemplateStatsAnalyzer(const std::string& prefix) +{ + prefix_ = prefix; +} + +BI::AnalysisControl TemplateStatsAnalyzer::OnEndAnalysisPass() +{ + if (passNumber_ == 0) { + std::sort(filteredKeys_.begin(), filteredKeys_.end()); + } + else if (passNumber_ == 1) { + filteredKeys_.clear(); + + printf("Total time for template instantiations matching \"%s\":\n", prefix_.c_str()); + printf(" CPU Time: %10.6lf / %10.6lf\n", 1e-9 * exclusiveCpuTime_, 1e-9 * inclusiveCpuTime_); + printf(" Duration: %10.6lf / %10.6lf\n", 1e-9 * exclusiveDuration_, 1e-9 * inclusiveDuration_); + } + passNumber_++; + + return AnalysisControl::CONTINUE; +} + +AnalysisControl TemplateStatsAnalyzer::OnStopActivity(const EventStack& eventStack) +{ + if (passNumber_ == 1) { + MatchEventStackInMemberFunction(eventStack, this, &TemplateStatsAnalyzer::OnFinishTemplateInstantiation); + } + + return AnalysisControl::CONTINUE; +} + +AnalysisControl TemplateStatsAnalyzer::OnSimpleEvent(const EventStack& eventStack) +{ + if (passNumber_ == 0) { + MatchEventStackInMemberFunction(eventStack, this, &TemplateStatsAnalyzer::OnSymbolName); + } + + return AnalysisControl::CONTINUE; +} + +void TemplateStatsAnalyzer::OnSymbolName(const SE::SymbolName& symbolName) +{ + const char *name = symbolName.Name(); + size_t len = strlen(name); + if (len >= prefix_.length() && memcmp(name, prefix_.data(), prefix_.length()) == 0) { + filteredKeys_.push_back(symbolName.Key()); + } +} + +bool TemplateStatsAnalyzer::MatchesPrefix(uint64_t primaryKey) const +{ + size_t pos = std::lower_bound(filteredKeys_.begin(), filteredKeys_.end(), primaryKey) - filteredKeys_.begin(); + return (pos < filteredKeys_.size() && filteredKeys_[pos] == primaryKey); +} + +void TemplateStatsAnalyzer::OnFinishTemplateInstantiation(const A::Activity& parent, const A::TemplateInstantiationGroup& templateInstantiationGroup) +{ + bool matchLast = MatchesPrefix(templateInstantiationGroup.Back().PrimaryTemplateSymbolKey()); + bool matchAny = matchLast; + for (int i = templateInstantiationGroup.Size() - 2; i >= 0 && !matchAny; i--) + if (MatchesPrefix(templateInstantiationGroup[i].PrimaryTemplateSymbolKey())) + matchAny = true; + + if (matchLast) { + exclusiveCpuTime_ += templateInstantiationGroup.Back().ExclusiveCPUTime().count(); + exclusiveDuration_ += templateInstantiationGroup.Back().Duration().count(); + } + if (matchAny) { + inclusiveCpuTime_ += templateInstantiationGroup.Back().ExclusiveCPUTime().count(); + inclusiveDuration_ += templateInstantiationGroup.Back().Duration().count(); + } +} diff --git a/src/TemplateStats/TemplateStats.h b/src/TemplateStats/TemplateStats.h new file mode 100644 index 0000000..61cc938 --- /dev/null +++ b/src/TemplateStats/TemplateStats.h @@ -0,0 +1,38 @@ +#pragma once + +#include + +#include "VcperfBuildInsights.h" + + +namespace vcperf +{ + +class TemplateStatsAnalyzer : public BI::IAnalyzer { +public: + TemplateStatsAnalyzer(const std::string& prefix); + + BI::AnalysisControl OnEndAnalysisPass() override; + BI::AnalysisControl OnStopActivity(const BI::EventStack& eventStack) override; + BI::AnalysisControl OnSimpleEvent(const BI::EventStack& eventStack) override; + +private: + void OnFinishTemplateInstantiation(const A::Activity& parent, const A::TemplateInstantiationGroup& templateInstantiationGroup); + void OnSymbolName(const SE::SymbolName& symbolName); + + bool MatchesPrefix(uint64_t primaryKey) const; + + int passNumber_ = 0; + std::string prefix_; + + //pass 0: + std::vector filteredKeys_; + + //pass 1: + uint64_t exclusiveCpuTime_ = 0; + uint64_t exclusiveDuration_ = 0; + uint64_t inclusiveCpuTime_ = 0; + uint64_t inclusiveDuration_ = 0; +}; + +} diff --git a/vcperf.vcxproj b/vcperf.vcxproj index b97c256..e82f195 100644 --- a/vcperf.vcxproj +++ b/vcperf.vcxproj @@ -180,6 +180,7 @@ + @@ -194,6 +195,7 @@ + diff --git a/vcperf.vcxproj.filters b/vcperf.vcxproj.filters index 8c28a01..307152a 100644 --- a/vcperf.vcxproj.filters +++ b/vcperf.vcxproj.filters @@ -37,6 +37,9 @@ {f61a812e-1836-4138-94d5-51a333458674} + + {eda37a9b-4613-4d88-963d-17845f38d077} + @@ -75,6 +78,9 @@ Source Files\TimeTrace + + Source Files\TemplateStats + @@ -122,6 +128,9 @@ Header Files\TimeTrace + + Source Files\TemplateStats + From c41e5c996cc090729115e1b9921d9f428b2b721e Mon Sep 17 00:00:00 2001 From: stgatilov Date: Sun, 13 Jun 2021 18:00:00 +0700 Subject: [PATCH 03/17] Added /templateStats command. --- src/Commands.cpp | 18 ++++++++++++++++++ src/Commands.h | 1 + src/main.cpp | 15 +++++++++++++++ 3 files changed, 34 insertions(+) diff --git a/src/Commands.cpp b/src/Commands.cpp index 4d93c07..8c649a8 100644 --- a/src/Commands.cpp +++ b/src/Commands.cpp @@ -14,6 +14,7 @@ #include "WPA\Views\TemplateInstantiationsView.h" #include "TimeTrace\ExecutionHierarchy.h" #include "TimeTrace\TimeTraceGenerator.h" +#include "TemplateStats\TemplateStats.h" using namespace Microsoft::Cpp::BuildInsights; @@ -243,6 +244,23 @@ RESULT_CODE AnalyzeToTimeTrace(const std::filesystem::path& inputFile, const std return Analyze(inputFile.c_str(), analysisPassCount, analyzerGroup); } +std::string ws2s(const std::wstring& wstr) +{ + std::string res; + for (int i = 0; i < wstr.size(); i++) { + // I feel sorry =) + assert(wstr[i] >= 0 && wstr[i] < 128); + res += char(wstr[i]); + } + return res; +} +HRESULT DoTemplateStats(const std::filesystem::path& inputFile, const std::wstring& prefix) +{ + TemplateStatsAnalyzer analyzer{ ws2s(prefix) }; + auto analyzerGroup = MakeStaticAnalyzerGroup(&analyzer); + return Analyze(inputFile.c_str(), 2, analyzerGroup); +} + HRESULT DoStart(const std::wstring& sessionName, bool cpuSampling, VerbosityLevel verbosityLevel) { TRACING_SESSION_OPTIONS options{}; diff --git a/src/Commands.h b/src/Commands.h index 6dfd032..fd403ad 100644 --- a/src/Commands.h +++ b/src/Commands.h @@ -18,5 +18,6 @@ HRESULT DoStart(const std::wstring& sessionName, bool cpuSampling, VerbosityLeve HRESULT DoStop(const std::wstring& sessionName, const std::filesystem::path& outputFile, bool analyzeTemplates = false, bool generateTimeTrace = false); HRESULT DoStopNoAnalyze(const std::wstring& sessionName, const std::filesystem::path& outputFile); HRESULT DoAnalyze(const std::filesystem::path& inputFile, const std::filesystem::path& outputFile, bool analyzeTemplates = false, bool generateTimeTrace = false); +HRESULT DoTemplateStats(const std::filesystem::path& inputFile, const std::wstring& prefix); } // namespace vcperf \ No newline at end of file diff --git a/src/main.cpp b/src/main.cpp index 8b59636..bf658c9 100644 --- a/src/main.cpp +++ b/src/main.cpp @@ -169,6 +169,7 @@ int wmain(int argc, wchar_t* argv[]) std::wcout << L"vcperf.exe /stopnoanalyze sessionName outputRawFile.etl" << std::endl; std::wcout << L"vcperf.exe /analyze [/templates] inputRawFile.etl output.etl" << std::endl; std::wcout << L"vcperf.exe /analyze [/templates] inputRawFile.etl /timetrace output.json" << std::endl; + std::wcout << L"vcperf.exe /templateStats {prefix} inputRawFile.etl" << std::endl; std::wcout << std::endl; @@ -293,6 +294,20 @@ int wmain(int argc, wchar_t* argv[]) return DoAnalyze(inputFile, outputFile, analyzeTemplates, generateTimeTrace); } + else if (CheckCommand(argv[1], L"templateStats")) + { + if (argc < 4) { + return E_FAIL; + } + std::wstring prefix = argv[2]; + std::wstring inputFile = argv[3]; + + if (!ValidateFile(inputFile, true, L".etl")) { + return E_FAIL; + } + + return DoTemplateStats(inputFile, prefix); + } else { std::wcout << L"ERROR: Unknown command " << argv[1] << std::endl; From bb34b363edeb3aa74b2b0b54a531c4f75631018a Mon Sep 17 00:00:00 2001 From: stgatilov Date: Sun, 13 Jun 2021 18:39:41 +0700 Subject: [PATCH 04/17] Added simple Wildcard matcher. --- src/TemplateStats/Wildcard.h | 35 +++++++++++++++++++++++++++++++++++ vcperf.vcxproj | 1 + vcperf.vcxproj.filters | 3 +++ 3 files changed, 39 insertions(+) create mode 100644 src/TemplateStats/Wildcard.h diff --git a/src/TemplateStats/Wildcard.h b/src/TemplateStats/Wildcard.h new file mode 100644 index 0000000..6630d26 --- /dev/null +++ b/src/TemplateStats/Wildcard.h @@ -0,0 +1,35 @@ +#pragma once + +bool WildcardMatch(const char* pat, const char* str) { + int i, star; + +new_segment: + + star = 0; + if (*pat == '*') { + star = 1; + do { pat++; } while (*pat == '*'); /* enddo */ + } /* endif */ + +test_match: + + for (i = 0; pat[i] && (pat[i] != '*'); i++) { + if (str[i] != pat[i]) { + if (!str[i]) return 0; + if ((pat[i] == '?') && (str[i] != '.')) continue; + if (!star) return 0; + str++; + goto test_match; + } + } + if (pat[i] == '*') { + str += i; + pat += i; + goto new_segment; + } + if (!str[i]) return 1; + if (i && pat[i - 1] == '*') return 1; + if (!star) return 0; + str++; + goto test_match; +} diff --git a/vcperf.vcxproj b/vcperf.vcxproj index e82f195..ce94309 100644 --- a/vcperf.vcxproj +++ b/vcperf.vcxproj @@ -196,6 +196,7 @@ + diff --git a/vcperf.vcxproj.filters b/vcperf.vcxproj.filters index 307152a..886d7ec 100644 --- a/vcperf.vcxproj.filters +++ b/vcperf.vcxproj.filters @@ -131,6 +131,9 @@ Source Files\TemplateStats + + Source Files\TemplateStats + From 942f472174e2a1012eb65ee23a71c98ca56f9a5d Mon Sep 17 00:00:00 2001 From: stgatilov Date: Sun, 13 Jun 2021 18:40:16 +0700 Subject: [PATCH 05/17] Fixed TemplateStats to properly aggregate time, also use wildcard instead of prefix. --- src/TemplateStats/TemplateStats.cpp | 45 +++++++++++++++++++---------- src/TemplateStats/TemplateStats.h | 4 +-- 2 files changed, 32 insertions(+), 17 deletions(-) diff --git a/src/TemplateStats/TemplateStats.cpp b/src/TemplateStats/TemplateStats.cpp index 8b5783c..57de7f2 100644 --- a/src/TemplateStats/TemplateStats.cpp +++ b/src/TemplateStats/TemplateStats.cpp @@ -1,14 +1,15 @@ #include "TemplateStats.h" #include #include +#include "Wildcard.h" using namespace Microsoft::Cpp::BuildInsights; using namespace vcperf; -TemplateStatsAnalyzer::TemplateStatsAnalyzer(const std::string& prefix) +TemplateStatsAnalyzer::TemplateStatsAnalyzer(const std::string& wildcard) { - prefix_ = prefix; + wildcard_ = wildcard; } BI::AnalysisControl TemplateStatsAnalyzer::OnEndAnalysisPass() @@ -19,7 +20,7 @@ BI::AnalysisControl TemplateStatsAnalyzer::OnEndAnalysisPass() else if (passNumber_ == 1) { filteredKeys_.clear(); - printf("Total time for template instantiations matching \"%s\":\n", prefix_.c_str()); + printf("Total time for template instantiations matching \"%s\":\n", wildcard_.c_str()); printf(" CPU Time: %10.6lf / %10.6lf\n", 1e-9 * exclusiveCpuTime_, 1e-9 * inclusiveCpuTime_); printf(" Duration: %10.6lf / %10.6lf\n", 1e-9 * exclusiveDuration_, 1e-9 * inclusiveDuration_); } @@ -50,9 +51,12 @@ void TemplateStatsAnalyzer::OnSymbolName(const SE::SymbolName& symbolName) { const char *name = symbolName.Name(); size_t len = strlen(name); - if (len >= prefix_.length() && memcmp(name, prefix_.data(), prefix_.length()) == 0) { + if (WildcardMatch(wildcard_.c_str(), name)) { filteredKeys_.push_back(symbolName.Key()); } + /*if (len >= prefix_.length() && memcmp(name, prefix_.data(), prefix_.length()) == 0) { + filteredKeys_.push_back(symbolName.Key()); + }*/ } bool TemplateStatsAnalyzer::MatchesPrefix(uint64_t primaryKey) const @@ -63,18 +67,29 @@ bool TemplateStatsAnalyzer::MatchesPrefix(uint64_t primaryKey) const void TemplateStatsAnalyzer::OnFinishTemplateInstantiation(const A::Activity& parent, const A::TemplateInstantiationGroup& templateInstantiationGroup) { - bool matchLast = MatchesPrefix(templateInstantiationGroup.Back().PrimaryTemplateSymbolKey()); - bool matchAny = matchLast; - for (int i = templateInstantiationGroup.Size() - 2; i >= 0 && !matchAny; i--) - if (MatchesPrefix(templateInstantiationGroup[i].PrimaryTemplateSymbolKey())) - matchAny = true; + int n = (int)templateInstantiationGroup.Size(); + uint64_t inclCpuTime = templateInstantiationGroup.Back().CPUTime().count(); + uint64_t inclDuration = templateInstantiationGroup.Back().Duration().count(); - if (matchLast) { - exclusiveCpuTime_ += templateInstantiationGroup.Back().ExclusiveCPUTime().count(); - exclusiveDuration_ += templateInstantiationGroup.Back().Duration().count(); + if (n >= 1 && MatchesPrefix(templateInstantiationGroup[n-1].PrimaryTemplateSymbolKey())) { + bool hasMatchingAncestor = false; + for (int i = n-2; i >= 0; i--) + if (MatchesPrefix(templateInstantiationGroup[i].PrimaryTemplateSymbolKey())) { + hasMatchingAncestor = true; + break; + } + if (!hasMatchingAncestor) { + //instantiation stack looks like: no, no, no, ..., no, match + inclusiveCpuTime_ += inclCpuTime; + inclusiveDuration_ += inclDuration; + } + //instantiation stack looks like: any, any, any, ..., any, match + exclusiveCpuTime_ += inclCpuTime; + exclusiveDuration_ += inclDuration; } - if (matchAny) { - inclusiveCpuTime_ += templateInstantiationGroup.Back().ExclusiveCPUTime().count(); - inclusiveDuration_ += templateInstantiationGroup.Back().Duration().count(); + if (n >= 2 && MatchesPrefix(templateInstantiationGroup[n-2].PrimaryTemplateSymbolKey())) { + //instantiation stack looks like: any any ... any match any + exclusiveCpuTime_ -= inclCpuTime; + exclusiveDuration_ -= inclDuration; } } diff --git a/src/TemplateStats/TemplateStats.h b/src/TemplateStats/TemplateStats.h index 61cc938..4ccacc1 100644 --- a/src/TemplateStats/TemplateStats.h +++ b/src/TemplateStats/TemplateStats.h @@ -10,7 +10,7 @@ namespace vcperf class TemplateStatsAnalyzer : public BI::IAnalyzer { public: - TemplateStatsAnalyzer(const std::string& prefix); + TemplateStatsAnalyzer(const std::string& wildcard); BI::AnalysisControl OnEndAnalysisPass() override; BI::AnalysisControl OnStopActivity(const BI::EventStack& eventStack) override; @@ -23,7 +23,7 @@ class TemplateStatsAnalyzer : public BI::IAnalyzer { bool MatchesPrefix(uint64_t primaryKey) const; int passNumber_ = 0; - std::string prefix_; + std::string wildcard_; //pass 0: std::vector filteredKeys_; From 7014ee769961a9d05d4af6ec899cdb2a224d8ceb Mon Sep 17 00:00:00 2001 From: stgatilov Date: Sun, 13 Jun 2021 18:40:33 +0700 Subject: [PATCH 06/17] Rename prefix to wildcard everywhere. --- src/Commands.cpp | 4 ++-- src/Commands.h | 2 +- src/main.cpp | 6 +++--- 3 files changed, 6 insertions(+), 6 deletions(-) diff --git a/src/Commands.cpp b/src/Commands.cpp index 8c649a8..838b86e 100644 --- a/src/Commands.cpp +++ b/src/Commands.cpp @@ -254,9 +254,9 @@ std::string ws2s(const std::wstring& wstr) } return res; } -HRESULT DoTemplateStats(const std::filesystem::path& inputFile, const std::wstring& prefix) +HRESULT DoTemplateStats(const std::filesystem::path& inputFile, const std::wstring& wildcard) { - TemplateStatsAnalyzer analyzer{ ws2s(prefix) }; + TemplateStatsAnalyzer analyzer{ ws2s(wildcard) }; auto analyzerGroup = MakeStaticAnalyzerGroup(&analyzer); return Analyze(inputFile.c_str(), 2, analyzerGroup); } diff --git a/src/Commands.h b/src/Commands.h index fd403ad..fe74f30 100644 --- a/src/Commands.h +++ b/src/Commands.h @@ -18,6 +18,6 @@ HRESULT DoStart(const std::wstring& sessionName, bool cpuSampling, VerbosityLeve HRESULT DoStop(const std::wstring& sessionName, const std::filesystem::path& outputFile, bool analyzeTemplates = false, bool generateTimeTrace = false); HRESULT DoStopNoAnalyze(const std::wstring& sessionName, const std::filesystem::path& outputFile); HRESULT DoAnalyze(const std::filesystem::path& inputFile, const std::filesystem::path& outputFile, bool analyzeTemplates = false, bool generateTimeTrace = false); -HRESULT DoTemplateStats(const std::filesystem::path& inputFile, const std::wstring& prefix); +HRESULT DoTemplateStats(const std::filesystem::path& inputFile, const std::wstring& wildcard); } // namespace vcperf \ No newline at end of file diff --git a/src/main.cpp b/src/main.cpp index bf658c9..24e0762 100644 --- a/src/main.cpp +++ b/src/main.cpp @@ -169,7 +169,7 @@ int wmain(int argc, wchar_t* argv[]) std::wcout << L"vcperf.exe /stopnoanalyze sessionName outputRawFile.etl" << std::endl; std::wcout << L"vcperf.exe /analyze [/templates] inputRawFile.etl output.etl" << std::endl; std::wcout << L"vcperf.exe /analyze [/templates] inputRawFile.etl /timetrace output.json" << std::endl; - std::wcout << L"vcperf.exe /templateStats {prefix} inputRawFile.etl" << std::endl; + std::wcout << L"vcperf.exe /templateStats {wildcard} inputRawFile.etl" << std::endl; std::wcout << std::endl; @@ -299,14 +299,14 @@ int wmain(int argc, wchar_t* argv[]) if (argc < 4) { return E_FAIL; } - std::wstring prefix = argv[2]; + std::wstring wildcard = argv[2]; std::wstring inputFile = argv[3]; if (!ValidateFile(inputFile, true, L".etl")) { return E_FAIL; } - return DoTemplateStats(inputFile, prefix); + return DoTemplateStats(inputFile, wildcard); } else { From 1ba41b05f60f35d5c90182ceaaf253aefba0a5f5 Mon Sep 17 00:00:00 2001 From: stgatilov Date: Sun, 13 Jun 2021 23:29:08 +0700 Subject: [PATCH 07/17] Refactor TemplateStatsAnalyzer, handle parsing time too. --- src/TemplateStats/TemplateStats.cpp | 64 ++++++++++++++++++++--------- src/TemplateStats/TemplateStats.h | 23 ++++++++--- 2 files changed, 63 insertions(+), 24 deletions(-) diff --git a/src/TemplateStats/TemplateStats.cpp b/src/TemplateStats/TemplateStats.cpp index 57de7f2..8ce7c13 100644 --- a/src/TemplateStats/TemplateStats.cpp +++ b/src/TemplateStats/TemplateStats.cpp @@ -12,6 +12,12 @@ TemplateStatsAnalyzer::TemplateStatsAnalyzer(const std::string& wildcard) wildcard_ = wildcard; } +void TemplateStatsAnalyzer::WildcardTime::Print() const +{ + printf(" CPU Time: %10.6lf / %10.6lf / %10.6lf\n", 1e-9 * exclusiveCpuTime_, 1e-9 * subtractedCpuTime_, 1e-9 * inclusiveCpuTime_); + printf(" Duration: %10.6lf / %10.6lf / %10.6lf\n", 1e-9 * exclusiveDuration_, 1e-9 * subtractedDuration_, 1e-9 * inclusiveDuration_); +} + BI::AnalysisControl TemplateStatsAnalyzer::OnEndAnalysisPass() { if (passNumber_ == 0) { @@ -20,9 +26,10 @@ BI::AnalysisControl TemplateStatsAnalyzer::OnEndAnalysisPass() else if (passNumber_ == 1) { filteredKeys_.clear(); + printf("Total time for parsing files matching \"%s\":\n", wildcard_.c_str()); + _parsingTime.Print(); printf("Total time for template instantiations matching \"%s\":\n", wildcard_.c_str()); - printf(" CPU Time: %10.6lf / %10.6lf\n", 1e-9 * exclusiveCpuTime_, 1e-9 * inclusiveCpuTime_); - printf(" Duration: %10.6lf / %10.6lf\n", 1e-9 * exclusiveDuration_, 1e-9 * inclusiveDuration_); + _instantiationsTime.Print(); } passNumber_++; @@ -33,6 +40,7 @@ AnalysisControl TemplateStatsAnalyzer::OnStopActivity(const EventStack& eventSta { if (passNumber_ == 1) { MatchEventStackInMemberFunction(eventStack, this, &TemplateStatsAnalyzer::OnFinishTemplateInstantiation); + MatchEventStackInMemberFunction(eventStack, this, &TemplateStatsAnalyzer::OnFileParse); } return AnalysisControl::CONTINUE; @@ -54,42 +62,60 @@ void TemplateStatsAnalyzer::OnSymbolName(const SE::SymbolName& symbolName) if (WildcardMatch(wildcard_.c_str(), name)) { filteredKeys_.push_back(symbolName.Key()); } - /*if (len >= prefix_.length() && memcmp(name, prefix_.data(), prefix_.length()) == 0) { - filteredKeys_.push_back(symbolName.Key()); - }*/ } -bool TemplateStatsAnalyzer::MatchesPrefix(uint64_t primaryKey) const +bool TemplateStatsAnalyzer::InstantiationMatchesWildcard(const A::TemplateInstantiation& templateInstantiation) const { + uint64_t primaryKey = templateInstantiation.PrimaryTemplateSymbolKey(); size_t pos = std::lower_bound(filteredKeys_.begin(), filteredKeys_.end(), primaryKey) - filteredKeys_.begin(); return (pos < filteredKeys_.size() && filteredKeys_[pos] == primaryKey); } -void TemplateStatsAnalyzer::OnFinishTemplateInstantiation(const A::Activity& parent, const A::TemplateInstantiationGroup& templateInstantiationGroup) +bool TemplateStatsAnalyzer::FileParseMatchesWildcard(const A::FrontEndFile& file) const +{ + const char *path = file.Path(); + //bool isHeader = !(WildcardMatch("*.cpp", path) || WildcardMatch("*.cxx", path) || WildcardMatch("*.c", path)); + return WildcardMatch(wildcard_.c_str(), path); +} + +template void TemplateStatsAnalyzer::UpdateWildcardTime(const BI::EventGroup& activityGroup, bool (TemplateStatsAnalyzer::*matchFunc)(const Activity&) const, WildcardTime& totalTime) const { - int n = (int)templateInstantiationGroup.Size(); - uint64_t inclCpuTime = templateInstantiationGroup.Back().CPUTime().count(); - uint64_t inclDuration = templateInstantiationGroup.Back().Duration().count(); + int n = (int)activityGroup.Size(); + uint64_t inclCpuTime = activityGroup.Back().CPUTime().count(); + uint64_t inclDuration = activityGroup.Back().Duration().count(); + uint64_t exclCpuTime = activityGroup.Back().ExclusiveCPUTime().count(); + uint64_t exclDuration = activityGroup.Back().ExclusiveDuration().count(); - if (n >= 1 && MatchesPrefix(templateInstantiationGroup[n-1].PrimaryTemplateSymbolKey())) { + if (n >= 1 && (this->*matchFunc)(activityGroup[n-1])) { bool hasMatchingAncestor = false; for (int i = n-2; i >= 0; i--) - if (MatchesPrefix(templateInstantiationGroup[i].PrimaryTemplateSymbolKey())) { + if ((this->*matchFunc)(activityGroup[i])) { hasMatchingAncestor = true; break; } if (!hasMatchingAncestor) { //instantiation stack looks like: no, no, no, ..., no, match - inclusiveCpuTime_ += inclCpuTime; - inclusiveDuration_ += inclDuration; + totalTime.inclusiveCpuTime_ += inclCpuTime; + totalTime.inclusiveDuration_ += inclDuration; } //instantiation stack looks like: any, any, any, ..., any, match - exclusiveCpuTime_ += inclCpuTime; - exclusiveDuration_ += inclDuration; + totalTime.subtractedCpuTime_ += inclCpuTime; + totalTime.subtractedDuration_ += inclDuration; + totalTime.exclusiveCpuTime_ += exclCpuTime; + totalTime.exclusiveDuration_ += exclDuration; } - if (n >= 2 && MatchesPrefix(templateInstantiationGroup[n-2].PrimaryTemplateSymbolKey())) { + if (n >= 2 && (this->*matchFunc)(activityGroup[n-2])) { //instantiation stack looks like: any any ... any match any - exclusiveCpuTime_ -= inclCpuTime; - exclusiveDuration_ -= inclDuration; + totalTime.subtractedCpuTime_ -= inclCpuTime; + totalTime.subtractedDuration_ -= inclDuration; } } + +void TemplateStatsAnalyzer::OnFinishTemplateInstantiation(const A::Activity& parent, const A::TemplateInstantiationGroup& templateInstantiationGroup) +{ + UpdateWildcardTime(templateInstantiationGroup, &TemplateStatsAnalyzer::InstantiationMatchesWildcard, _instantiationsTime); +} + +void TemplateStatsAnalyzer::OnFileParse(const A::FrontEndFileGroup& files) { + UpdateWildcardTime(files, &TemplateStatsAnalyzer::FileParseMatchesWildcard, _parsingTime); +} diff --git a/src/TemplateStats/TemplateStats.h b/src/TemplateStats/TemplateStats.h index 4ccacc1..0169edb 100644 --- a/src/TemplateStats/TemplateStats.h +++ b/src/TemplateStats/TemplateStats.h @@ -19,9 +19,24 @@ class TemplateStatsAnalyzer : public BI::IAnalyzer { private: void OnFinishTemplateInstantiation(const A::Activity& parent, const A::TemplateInstantiationGroup& templateInstantiationGroup); void OnSymbolName(const SE::SymbolName& symbolName); + void OnFileParse(const A::FrontEndFileGroup& files); - bool MatchesPrefix(uint64_t primaryKey) const; + bool InstantiationMatchesWildcard(const A::TemplateInstantiation& templateInstantiation) const; + bool FileParseMatchesWildcard(const A::FrontEndFile& file) const; + struct WildcardTime { + uint64_t exclusiveCpuTime_ = 0; + uint64_t exclusiveDuration_ = 0; + uint64_t subtractedCpuTime_ = 0; + uint64_t subtractedDuration_ = 0; + uint64_t inclusiveCpuTime_ = 0; + uint64_t inclusiveDuration_ = 0; + + void Print() const; + }; + template void UpdateWildcardTime(const BI::EventGroup& activityGroup, bool (TemplateStatsAnalyzer::*matchFunc)(const Activity&) const, WildcardTime& totalTime) const; + + //global int passNumber_ = 0; std::string wildcard_; @@ -29,10 +44,8 @@ class TemplateStatsAnalyzer : public BI::IAnalyzer { std::vector filteredKeys_; //pass 1: - uint64_t exclusiveCpuTime_ = 0; - uint64_t exclusiveDuration_ = 0; - uint64_t inclusiveCpuTime_ = 0; - uint64_t inclusiveDuration_ = 0; + WildcardTime _instantiationsTime; + WildcardTime _parsingTime; }; } From bf226374146549905f0985b7657e5d639cae4bdf Mon Sep 17 00:00:00 2001 From: stgatilov Date: Sun, 13 Jun 2021 23:39:05 +0700 Subject: [PATCH 08/17] TemplateStats renamed to FilteredAggregator. --- .../FilteredAggregator.cpp} | 34 +++++++++---------- .../FilteredAggregator.h} | 6 ++-- .../Wildcard.h | 0 vcperf.vcxproj | 4 +-- vcperf.vcxproj.filters | 17 ++++++---- 5 files changed, 32 insertions(+), 29 deletions(-) rename src/{TemplateStats/TemplateStats.cpp => FilteredAggregator/FilteredAggregator.cpp} (65%) rename src/{TemplateStats/TemplateStats.h => FilteredAggregator/FilteredAggregator.h} (81%) rename src/{TemplateStats => FilteredAggregator}/Wildcard.h (100%) diff --git a/src/TemplateStats/TemplateStats.cpp b/src/FilteredAggregator/FilteredAggregator.cpp similarity index 65% rename from src/TemplateStats/TemplateStats.cpp rename to src/FilteredAggregator/FilteredAggregator.cpp index 8ce7c13..2e71261 100644 --- a/src/TemplateStats/TemplateStats.cpp +++ b/src/FilteredAggregator/FilteredAggregator.cpp @@ -1,4 +1,4 @@ -#include "TemplateStats.h" +#include "FilteredAggregator.h" #include #include #include "Wildcard.h" @@ -7,18 +7,18 @@ using namespace Microsoft::Cpp::BuildInsights; using namespace vcperf; -TemplateStatsAnalyzer::TemplateStatsAnalyzer(const std::string& wildcard) +FilteringAggregator::FilteringAggregator(const std::string& wildcard) { wildcard_ = wildcard; } -void TemplateStatsAnalyzer::WildcardTime::Print() const +void FilteringAggregator::WildcardTime::Print() const { printf(" CPU Time: %10.6lf / %10.6lf / %10.6lf\n", 1e-9 * exclusiveCpuTime_, 1e-9 * subtractedCpuTime_, 1e-9 * inclusiveCpuTime_); printf(" Duration: %10.6lf / %10.6lf / %10.6lf\n", 1e-9 * exclusiveDuration_, 1e-9 * subtractedDuration_, 1e-9 * inclusiveDuration_); } -BI::AnalysisControl TemplateStatsAnalyzer::OnEndAnalysisPass() +BI::AnalysisControl FilteringAggregator::OnEndAnalysisPass() { if (passNumber_ == 0) { std::sort(filteredKeys_.begin(), filteredKeys_.end()); @@ -36,26 +36,26 @@ BI::AnalysisControl TemplateStatsAnalyzer::OnEndAnalysisPass() return AnalysisControl::CONTINUE; } -AnalysisControl TemplateStatsAnalyzer::OnStopActivity(const EventStack& eventStack) +AnalysisControl FilteringAggregator::OnStopActivity(const EventStack& eventStack) { if (passNumber_ == 1) { - MatchEventStackInMemberFunction(eventStack, this, &TemplateStatsAnalyzer::OnFinishTemplateInstantiation); - MatchEventStackInMemberFunction(eventStack, this, &TemplateStatsAnalyzer::OnFileParse); + MatchEventStackInMemberFunction(eventStack, this, &FilteringAggregator::OnFinishTemplateInstantiation); + MatchEventStackInMemberFunction(eventStack, this, &FilteringAggregator::OnFileParse); } return AnalysisControl::CONTINUE; } -AnalysisControl TemplateStatsAnalyzer::OnSimpleEvent(const EventStack& eventStack) +AnalysisControl FilteringAggregator::OnSimpleEvent(const EventStack& eventStack) { if (passNumber_ == 0) { - MatchEventStackInMemberFunction(eventStack, this, &TemplateStatsAnalyzer::OnSymbolName); + MatchEventStackInMemberFunction(eventStack, this, &FilteringAggregator::OnSymbolName); } return AnalysisControl::CONTINUE; } -void TemplateStatsAnalyzer::OnSymbolName(const SE::SymbolName& symbolName) +void FilteringAggregator::OnSymbolName(const SE::SymbolName& symbolName) { const char *name = symbolName.Name(); size_t len = strlen(name); @@ -64,21 +64,21 @@ void TemplateStatsAnalyzer::OnSymbolName(const SE::SymbolName& symbolName) } } -bool TemplateStatsAnalyzer::InstantiationMatchesWildcard(const A::TemplateInstantiation& templateInstantiation) const +bool FilteringAggregator::InstantiationMatchesWildcard(const A::TemplateInstantiation& templateInstantiation) const { uint64_t primaryKey = templateInstantiation.PrimaryTemplateSymbolKey(); size_t pos = std::lower_bound(filteredKeys_.begin(), filteredKeys_.end(), primaryKey) - filteredKeys_.begin(); return (pos < filteredKeys_.size() && filteredKeys_[pos] == primaryKey); } -bool TemplateStatsAnalyzer::FileParseMatchesWildcard(const A::FrontEndFile& file) const +bool FilteringAggregator::FileParseMatchesWildcard(const A::FrontEndFile& file) const { const char *path = file.Path(); //bool isHeader = !(WildcardMatch("*.cpp", path) || WildcardMatch("*.cxx", path) || WildcardMatch("*.c", path)); return WildcardMatch(wildcard_.c_str(), path); } -template void TemplateStatsAnalyzer::UpdateWildcardTime(const BI::EventGroup& activityGroup, bool (TemplateStatsAnalyzer::*matchFunc)(const Activity&) const, WildcardTime& totalTime) const +template void FilteringAggregator::UpdateWildcardTime(const BI::EventGroup& activityGroup, bool (FilteringAggregator::*matchFunc)(const Activity&) const, WildcardTime& totalTime) const { int n = (int)activityGroup.Size(); uint64_t inclCpuTime = activityGroup.Back().CPUTime().count(); @@ -111,11 +111,11 @@ template void TemplateStatsAnalyzer::UpdateWildcardTime(const BI } } -void TemplateStatsAnalyzer::OnFinishTemplateInstantiation(const A::Activity& parent, const A::TemplateInstantiationGroup& templateInstantiationGroup) +void FilteringAggregator::OnFinishTemplateInstantiation(const A::Activity& parent, const A::TemplateInstantiationGroup& templateInstantiationGroup) { - UpdateWildcardTime(templateInstantiationGroup, &TemplateStatsAnalyzer::InstantiationMatchesWildcard, _instantiationsTime); + UpdateWildcardTime(templateInstantiationGroup, &FilteringAggregator::InstantiationMatchesWildcard, _instantiationsTime); } -void TemplateStatsAnalyzer::OnFileParse(const A::FrontEndFileGroup& files) { - UpdateWildcardTime(files, &TemplateStatsAnalyzer::FileParseMatchesWildcard, _parsingTime); +void FilteringAggregator::OnFileParse(const A::FrontEndFileGroup& files) { + UpdateWildcardTime(files, &FilteringAggregator::FileParseMatchesWildcard, _parsingTime); } diff --git a/src/TemplateStats/TemplateStats.h b/src/FilteredAggregator/FilteredAggregator.h similarity index 81% rename from src/TemplateStats/TemplateStats.h rename to src/FilteredAggregator/FilteredAggregator.h index 0169edb..1c8019b 100644 --- a/src/TemplateStats/TemplateStats.h +++ b/src/FilteredAggregator/FilteredAggregator.h @@ -8,9 +8,9 @@ namespace vcperf { -class TemplateStatsAnalyzer : public BI::IAnalyzer { +class FilteringAggregator : public BI::IAnalyzer { public: - TemplateStatsAnalyzer(const std::string& wildcard); + FilteringAggregator(const std::string& wildcard); BI::AnalysisControl OnEndAnalysisPass() override; BI::AnalysisControl OnStopActivity(const BI::EventStack& eventStack) override; @@ -34,7 +34,7 @@ class TemplateStatsAnalyzer : public BI::IAnalyzer { void Print() const; }; - template void UpdateWildcardTime(const BI::EventGroup& activityGroup, bool (TemplateStatsAnalyzer::*matchFunc)(const Activity&) const, WildcardTime& totalTime) const; + template void UpdateWildcardTime(const BI::EventGroup& activityGroup, bool (FilteringAggregator::*matchFunc)(const Activity&) const, WildcardTime& totalTime) const; //global int passNumber_ = 0; diff --git a/src/TemplateStats/Wildcard.h b/src/FilteredAggregator/Wildcard.h similarity index 100% rename from src/TemplateStats/Wildcard.h rename to src/FilteredAggregator/Wildcard.h diff --git a/vcperf.vcxproj b/vcperf.vcxproj index ce94309..9357bcd 100644 --- a/vcperf.vcxproj +++ b/vcperf.vcxproj @@ -180,7 +180,7 @@ - + @@ -195,7 +195,7 @@ - + diff --git a/vcperf.vcxproj.filters b/vcperf.vcxproj.filters index 886d7ec..dcf1281 100644 --- a/vcperf.vcxproj.filters +++ b/vcperf.vcxproj.filters @@ -37,9 +37,12 @@ {f61a812e-1836-4138-94d5-51a333458674} - + {eda37a9b-4613-4d88-963d-17845f38d077} + + {77b5c8c0-a632-4e3c-816f-5e9606de3010} + @@ -78,8 +81,8 @@ Source Files\TimeTrace - - Source Files\TemplateStats + + Source Files\FilteredAggregator @@ -128,11 +131,11 @@ Header Files\TimeTrace - - Source Files\TemplateStats - - Source Files\TemplateStats + Header Files\FilteredAggregator + + + Header Files\FilteredAggregator From 9528b6cf2494641e0452b57fe43712729c7f671f Mon Sep 17 00:00:00 2001 From: stgatilov Date: Sun, 13 Jun 2021 23:39:24 +0700 Subject: [PATCH 09/17] Fixed usage in main/commands: now it is called /sumof. --- src/Commands.cpp | 6 +++--- src/Commands.h | 2 +- src/main.cpp | 6 +++--- 3 files changed, 7 insertions(+), 7 deletions(-) diff --git a/src/Commands.cpp b/src/Commands.cpp index 838b86e..d239cce 100644 --- a/src/Commands.cpp +++ b/src/Commands.cpp @@ -14,7 +14,7 @@ #include "WPA\Views\TemplateInstantiationsView.h" #include "TimeTrace\ExecutionHierarchy.h" #include "TimeTrace\TimeTraceGenerator.h" -#include "TemplateStats\TemplateStats.h" +#include "FilteredAggregator\FilteredAggregator.h" using namespace Microsoft::Cpp::BuildInsights; @@ -254,9 +254,9 @@ std::string ws2s(const std::wstring& wstr) } return res; } -HRESULT DoTemplateStats(const std::filesystem::path& inputFile, const std::wstring& wildcard) +HRESULT DoFilteredAggregate(const std::filesystem::path& inputFile, const std::wstring& wildcard) { - TemplateStatsAnalyzer analyzer{ ws2s(wildcard) }; + FilteringAggregator analyzer{ ws2s(wildcard) }; auto analyzerGroup = MakeStaticAnalyzerGroup(&analyzer); return Analyze(inputFile.c_str(), 2, analyzerGroup); } diff --git a/src/Commands.h b/src/Commands.h index fe74f30..f06f9d5 100644 --- a/src/Commands.h +++ b/src/Commands.h @@ -18,6 +18,6 @@ HRESULT DoStart(const std::wstring& sessionName, bool cpuSampling, VerbosityLeve HRESULT DoStop(const std::wstring& sessionName, const std::filesystem::path& outputFile, bool analyzeTemplates = false, bool generateTimeTrace = false); HRESULT DoStopNoAnalyze(const std::wstring& sessionName, const std::filesystem::path& outputFile); HRESULT DoAnalyze(const std::filesystem::path& inputFile, const std::filesystem::path& outputFile, bool analyzeTemplates = false, bool generateTimeTrace = false); -HRESULT DoTemplateStats(const std::filesystem::path& inputFile, const std::wstring& wildcard); +HRESULT DoFilteredAggregate(const std::filesystem::path& inputFile, const std::wstring& wildcard); } // namespace vcperf \ No newline at end of file diff --git a/src/main.cpp b/src/main.cpp index 24e0762..350c6f6 100644 --- a/src/main.cpp +++ b/src/main.cpp @@ -169,7 +169,7 @@ int wmain(int argc, wchar_t* argv[]) std::wcout << L"vcperf.exe /stopnoanalyze sessionName outputRawFile.etl" << std::endl; std::wcout << L"vcperf.exe /analyze [/templates] inputRawFile.etl output.etl" << std::endl; std::wcout << L"vcperf.exe /analyze [/templates] inputRawFile.etl /timetrace output.json" << std::endl; - std::wcout << L"vcperf.exe /templateStats {wildcard} inputRawFile.etl" << std::endl; + std::wcout << L"vcperf.exe /sumof {wildcard} inputRawFile.etl" << std::endl; std::wcout << std::endl; @@ -294,7 +294,7 @@ int wmain(int argc, wchar_t* argv[]) return DoAnalyze(inputFile, outputFile, analyzeTemplates, generateTimeTrace); } - else if (CheckCommand(argv[1], L"templateStats")) + else if (CheckCommand(argv[1], L"sumof")) { if (argc < 4) { return E_FAIL; @@ -306,7 +306,7 @@ int wmain(int argc, wchar_t* argv[]) return E_FAIL; } - return DoTemplateStats(inputFile, wildcard); + return DoFilteredAggregate(inputFile, wildcard); } else { From abae8f58b56064bb4a6025f935eb2437a354e0ee Mon Sep 17 00:00:00 2001 From: stgatilov Date: Sun, 13 Jun 2021 23:59:22 +0700 Subject: [PATCH 10/17] Updated readme: added /sumof command explanation. --- README.md | 33 +++++++++++++++++++++++++++++++++ 1 file changed, 33 insertions(+) diff --git a/README.md b/README.md index 3ea9786..71f6ab2 100644 --- a/README.md +++ b/README.md @@ -1,3 +1,36 @@ +# Fork changes + +Added `/sumof` command, which computes total time for all stuff matching given wildcard. Given a raw trace, it can be used as follows: + + vcperf /sumof *Eigen* rawTrace.etl + +It prints results to stdout: +``` +Total time for parsing files matching "*Eigen*": + CPU Time: 79.565226 / 96.567721 / 110.676782 + Duration: 448.373768 / 1112.570639 / 1168.585713 +Total time for template instantiations matching "*Eigen*": + CPU Time: 169.516602 / 169.516602 / 170.677942 + Duration: 122.637069 / 188.706707 / 190.002096 +``` + +Ideally, this should show how much time is spent on Eigen template library. +Better use "CPU Time" instead of "Duration", unless you disable parallel builds. + +Note that every line reports three numbers, which are slightly different. +The first one is the sum of exclusive time (as reported by framework) over all matching activities. +The second one also the sum of exclusive time over all matches, but exclusive time is computed as inclusive time minus inclusive time of all children. +The last one is the sum of inclusive time over all topmost matches. + +For instance, if we consider parsing files in the sample above: + +* 110.676782 seconds is spent on Eigen headers and all headers included from them (regardless of whether they are from Eigen of not). +* 96.567721 or 79.565226 seconds is spent on Eigen headers only, and excludes time for non-Eigen headers included from them. No idea why these two numbers are different... + +*(Original vcperf readme follows)* + +--------------------- + # vcperf ## Overview From 0d41631c4b6412b20ca8b9028737f47bdcd34b99 Mon Sep 17 00:00:00 2001 From: stgatilov Date: Sat, 31 Jul 2021 02:35:50 +0700 Subject: [PATCH 11/17] Added a function to undecorate set of symbols. --- src/FilteredAggregator/Undecorate.cpp | 108 ++++++++++++++++++++++++++ src/FilteredAggregator/Undecorate.h | 6 ++ vcperf.vcxproj | 2 + vcperf.vcxproj.filters | 6 ++ 4 files changed, 122 insertions(+) create mode 100644 src/FilteredAggregator/Undecorate.cpp create mode 100644 src/FilteredAggregator/Undecorate.h diff --git a/src/FilteredAggregator/Undecorate.cpp b/src/FilteredAggregator/Undecorate.cpp new file mode 100644 index 0000000..243515d --- /dev/null +++ b/src/FilteredAggregator/Undecorate.cpp @@ -0,0 +1,108 @@ +#include "Undecorate.h" +#define WIN32_LEAN_AND_MEAN +#include +#include + +static bool UndecorateImpl(const std::vector& decoratedNames, std::vector& undecoratedNames) +{ + static const char* INPUT_FILENAME = "__temp_undname_input.txt"; + static const char* OUTPUT_FILENAME = "__temp_undname_output.txt"; + + FILE* f = nullptr; + if (fopen_s(&f, INPUT_FILENAME, "wb") || !f) { + printf("Failed to create temporary input file\n"); + return false; + } + for (const std::string& name : decoratedNames) { + fwrite(name.data(), 1, name.size(), f); + fputc('\n', f); + } + fclose(f); + f = nullptr; + + SECURITY_ATTRIBUTES securityAttributes = { 0 }; + securityAttributes.nLength = sizeof(SECURITY_ATTRIBUTES); + securityAttributes.bInheritHandle = TRUE; + securityAttributes.lpSecurityDescriptor = NULL; + HANDLE hFile = CreateFile( + OUTPUT_FILENAME, + GENERIC_READ | GENERIC_WRITE, + FILE_SHARE_WRITE | FILE_SHARE_READ, + &securityAttributes, + OPEN_ALWAYS, + FILE_ATTRIBUTE_NORMAL, + 0 + ); + if (hFile == INVALID_HANDLE_VALUE) { + printf("Failed to create temporary output file\n"); + return false; + } + + char cmd[256]; + sprintf_s(cmd, "undname.exe 0x%x %s", 0x29FFF, INPUT_FILENAME); + STARTUPINFO startInfo = { 0 }; + startInfo.cb = sizeof(STARTUPINFO); + startInfo.dwFlags |= STARTF_USESTDHANDLES; + startInfo.hStdInput = INVALID_HANDLE_VALUE; + startInfo.hStdError = INVALID_HANDLE_VALUE; + startInfo.hStdOutput = hFile; + PROCESS_INFORMATION processInfo = { 0 }; + BOOL ok = CreateProcess( + NULL, cmd, NULL, NULL, + TRUE, CREATE_NO_WINDOW, + NULL, NULL, + &startInfo, &processInfo + ); + if (!ok) { + printf("Failed to run undname.exe from Visual C++ environment\n"); + CloseHandle(hFile); + return false; + } + if (WaitForSingleObject(processInfo.hProcess, INFINITE) != WAIT_OBJECT_0) { + printf("Could not wait for process completion\n"); + CloseHandle(processInfo.hProcess); + CloseHandle(hFile); + return false; + } + + CloseHandle(processInfo.hProcess); + CloseHandle(hFile); + + if (fopen_s(&f, OUTPUT_FILENAME, "rb") || !f) { + printf("Failed to read temporary output file\n"); + return false; + } + for (int i = 0; i < decoratedNames.size(); i++) { + char buffer[1 << 16]; //undecorated names can be quite lengthy =( + buffer[0] = 0; + if (!fgets(buffer, sizeof(buffer), f)) + return false; + size_t len = strlen(buffer); + if (len + 1 >= sizeof(buffer)) { + printf("Undecorated name is too long\n"); + fclose(f); + return false; + } + while (len > 0 && isspace(buffer[len - 1])) + buffer[--len] = 0; + undecoratedNames.push_back(buffer); + } + fclose(f); + f = nullptr; + + return true; +} + +bool Undecorate(const std::vector& decoratedNames, std::vector& undecoratedNames) +{ + undecoratedNames.clear(); + + bool ok = UndecorateImpl(decoratedNames, undecoratedNames); + + if (undecoratedNames.size() != decoratedNames.size()) + ok = false; + if (!ok) + undecoratedNames.assign(decoratedNames.size(), ""); + + return ok; +} diff --git a/src/FilteredAggregator/Undecorate.h b/src/FilteredAggregator/Undecorate.h new file mode 100644 index 0000000..1b49e16 --- /dev/null +++ b/src/FilteredAggregator/Undecorate.h @@ -0,0 +1,6 @@ +#pragma once + +#include +#include + +bool Undecorate(const std::vector& decoratedNames, std::vector& undecoratedNames); diff --git a/vcperf.vcxproj b/vcperf.vcxproj index 9357bcd..6e74deb 100644 --- a/vcperf.vcxproj +++ b/vcperf.vcxproj @@ -181,6 +181,7 @@ + @@ -196,6 +197,7 @@ + diff --git a/vcperf.vcxproj.filters b/vcperf.vcxproj.filters index dcf1281..36b8e30 100644 --- a/vcperf.vcxproj.filters +++ b/vcperf.vcxproj.filters @@ -84,6 +84,9 @@ Source Files\FilteredAggregator + + Source Files\FilteredAggregator + @@ -137,6 +140,9 @@ Header Files\FilteredAggregator + + Header Files\FilteredAggregator + From 02dfdba0d66cf8e2845fe9ae9b3d0cdf7e089db7 Mon Sep 17 00:00:00 2001 From: stgatilov Date: Sat, 31 Jul 2021 02:36:44 +0700 Subject: [PATCH 12/17] Print filtered statistics for code generation of functions too. --- src/FilteredAggregator/FilteredAggregator.cpp | 51 ++++++++++++++++++- src/FilteredAggregator/FilteredAggregator.h | 7 +++ 2 files changed, 56 insertions(+), 2 deletions(-) diff --git a/src/FilteredAggregator/FilteredAggregator.cpp b/src/FilteredAggregator/FilteredAggregator.cpp index 2e71261..6b44ed5 100644 --- a/src/FilteredAggregator/FilteredAggregator.cpp +++ b/src/FilteredAggregator/FilteredAggregator.cpp @@ -2,6 +2,7 @@ #include #include #include "Wildcard.h" +#include "Undecorate.h" using namespace Microsoft::Cpp::BuildInsights; using namespace vcperf; @@ -22,6 +23,11 @@ BI::AnalysisControl FilteringAggregator::OnEndAnalysisPass() { if (passNumber_ == 0) { std::sort(filteredKeys_.begin(), filteredKeys_.end()); + filteredKeys_.resize(std::unique(filteredKeys_.begin(), filteredKeys_.end()) - filteredKeys_.begin()); + + std::sort(functionNamesDecorated_.begin(), functionNamesDecorated_.end()); + functionNamesDecorated_.resize(std::unique(functionNamesDecorated_.begin(), functionNamesDecorated_.end()) - functionNamesDecorated_.begin()); + Undecorate(functionNamesDecorated_, functionNamesUndecorated_); } else if (passNumber_ == 1) { filteredKeys_.clear(); @@ -30,6 +36,8 @@ BI::AnalysisControl FilteringAggregator::OnEndAnalysisPass() _parsingTime.Print(); printf("Total time for template instantiations matching \"%s\":\n", wildcard_.c_str()); _instantiationsTime.Print(); + printf("Total time for code generation matching \"%s\":\n", wildcard_.c_str()); + _generationTime.Print(); } passNumber_++; @@ -42,6 +50,7 @@ AnalysisControl FilteringAggregator::OnStopActivity(const EventStack& eventStack MatchEventStackInMemberFunction(eventStack, this, &FilteringAggregator::OnFinishTemplateInstantiation); MatchEventStackInMemberFunction(eventStack, this, &FilteringAggregator::OnFileParse); } + MatchEventStackInMemberFunction(eventStack, this, &FilteringAggregator::OnFunction); return AnalysisControl::CONTINUE; } @@ -78,10 +87,20 @@ bool FilteringAggregator::FileParseMatchesWildcard(const A::FrontEndFile& file) return WildcardMatch(wildcard_.c_str(), path); } +bool FilteringAggregator::FunctionMatchesWildcard(const A::Function& function) const +{ + std::string decName = function.Name(); + size_t pos = std::lower_bound(functionNamesDecorated_.begin(), functionNamesDecorated_.end(), decName) - functionNamesDecorated_.begin(); + if (pos == functionNamesDecorated_.size() || functionNamesDecorated_[pos] != decName) + return false; //not even registered + const std::string& undecName = functionNamesUndecorated_[pos]; + return WildcardMatch(wildcard_.c_str(), undecName.c_str()); +} + template void FilteringAggregator::UpdateWildcardTime(const BI::EventGroup& activityGroup, bool (FilteringAggregator::*matchFunc)(const Activity&) const, WildcardTime& totalTime) const { int n = (int)activityGroup.Size(); - uint64_t inclCpuTime = activityGroup.Back().CPUTime().count(); + uint64_t inclCpuTime = activityGroup.Back().CPUTime().count(); uint64_t inclDuration = activityGroup.Back().Duration().count(); uint64_t exclCpuTime = activityGroup.Back().ExclusiveCPUTime().count(); uint64_t exclDuration = activityGroup.Back().ExclusiveDuration().count(); @@ -111,11 +130,39 @@ template void FilteringAggregator::UpdateWildcardTime(const BI:: } } +template void FilteringAggregator::UpdateWildcardTime(const Activity& activity, bool (FilteringAggregator::* matchFunc)(const Activity&) const, WildcardTime& totalTime) const +{ + if (!(this->*matchFunc)(activity)) + return; + + uint64_t inclCpuTime = activity.CPUTime().count(); + uint64_t inclDuration = activity.Duration().count(); + uint64_t exclCpuTime = activity.ExclusiveCPUTime().count(); + uint64_t exclDuration = activity.ExclusiveDuration().count(); + totalTime.inclusiveCpuTime_ += inclCpuTime; + totalTime.inclusiveDuration_ += inclDuration; + totalTime.subtractedCpuTime_ += inclCpuTime; + totalTime.subtractedDuration_ += inclDuration; + totalTime.exclusiveCpuTime_ += exclCpuTime; + totalTime.exclusiveDuration_ += exclDuration; +} + void FilteringAggregator::OnFinishTemplateInstantiation(const A::Activity& parent, const A::TemplateInstantiationGroup& templateInstantiationGroup) { UpdateWildcardTime(templateInstantiationGroup, &FilteringAggregator::InstantiationMatchesWildcard, _instantiationsTime); } -void FilteringAggregator::OnFileParse(const A::FrontEndFileGroup& files) { +void FilteringAggregator::OnFileParse(const A::FrontEndFileGroup& files) +{ UpdateWildcardTime(files, &FilteringAggregator::FileParseMatchesWildcard, _parsingTime); } + +void FilteringAggregator::OnFunction(const A::Function& function) +{ + if (passNumber_ == 0) { + functionNamesDecorated_.push_back(function.Name()); + } + if (passNumber_ == 1) { + UpdateWildcardTime(function, &FilteringAggregator::FunctionMatchesWildcard, _generationTime); + } +} diff --git a/src/FilteredAggregator/FilteredAggregator.h b/src/FilteredAggregator/FilteredAggregator.h index 1c8019b..737b8f7 100644 --- a/src/FilteredAggregator/FilteredAggregator.h +++ b/src/FilteredAggregator/FilteredAggregator.h @@ -20,9 +20,12 @@ class FilteringAggregator : public BI::IAnalyzer { void OnFinishTemplateInstantiation(const A::Activity& parent, const A::TemplateInstantiationGroup& templateInstantiationGroup); void OnSymbolName(const SE::SymbolName& symbolName); void OnFileParse(const A::FrontEndFileGroup& files); + void OnFunction(const A::Function& function); bool InstantiationMatchesWildcard(const A::TemplateInstantiation& templateInstantiation) const; bool FileParseMatchesWildcard(const A::FrontEndFile& file) const; + bool FunctionMatchesWildcard(const A::Function& function) const; + struct WildcardTime { uint64_t exclusiveCpuTime_ = 0; @@ -35,6 +38,7 @@ class FilteringAggregator : public BI::IAnalyzer { void Print() const; }; template void UpdateWildcardTime(const BI::EventGroup& activityGroup, bool (FilteringAggregator::*matchFunc)(const Activity&) const, WildcardTime& totalTime) const; + template void UpdateWildcardTime(const Activity& activity, bool (FilteringAggregator::* matchFunc)(const Activity&) const, WildcardTime& totalTime) const; //global int passNumber_ = 0; @@ -42,10 +46,13 @@ class FilteringAggregator : public BI::IAnalyzer { //pass 0: std::vector filteredKeys_; + std::vector functionNamesDecorated_; + std::vector functionNamesUndecorated_; //pass 1: WildcardTime _instantiationsTime; WildcardTime _parsingTime; + WildcardTime _generationTime; }; } From e4e9368d764bd468f223f27c19851673c0c01026 Mon Sep 17 00:00:00 2001 From: stgatilov Date: Sat, 31 Jul 2021 02:57:31 +0700 Subject: [PATCH 13/17] Refactored template instantiations: don't filter prematurely. This will be useful in future to remove parameter and produce full hierarchy. --- src/FilteredAggregator/FilteredAggregator.cpp | 33 +++++++++---------- src/FilteredAggregator/FilteredAggregator.h | 8 ++--- 2 files changed, 20 insertions(+), 21 deletions(-) diff --git a/src/FilteredAggregator/FilteredAggregator.cpp b/src/FilteredAggregator/FilteredAggregator.cpp index 6b44ed5..b83e047 100644 --- a/src/FilteredAggregator/FilteredAggregator.cpp +++ b/src/FilteredAggregator/FilteredAggregator.cpp @@ -22,22 +22,19 @@ void FilteringAggregator::WildcardTime::Print() const BI::AnalysisControl FilteringAggregator::OnEndAnalysisPass() { if (passNumber_ == 0) { - std::sort(filteredKeys_.begin(), filteredKeys_.end()); - filteredKeys_.resize(std::unique(filteredKeys_.begin(), filteredKeys_.end()) - filteredKeys_.begin()); + std::sort(symbolNames_.begin(), symbolNames_.end()); std::sort(functionNamesDecorated_.begin(), functionNamesDecorated_.end()); functionNamesDecorated_.resize(std::unique(functionNamesDecorated_.begin(), functionNamesDecorated_.end()) - functionNamesDecorated_.begin()); Undecorate(functionNamesDecorated_, functionNamesUndecorated_); } else if (passNumber_ == 1) { - filteredKeys_.clear(); - printf("Total time for parsing files matching \"%s\":\n", wildcard_.c_str()); - _parsingTime.Print(); + parsingTime_.Print(); printf("Total time for template instantiations matching \"%s\":\n", wildcard_.c_str()); - _instantiationsTime.Print(); + instantiationsTime_.Print(); printf("Total time for code generation matching \"%s\":\n", wildcard_.c_str()); - _generationTime.Print(); + generationTime_.Print(); } passNumber_++; @@ -66,18 +63,19 @@ AnalysisControl FilteringAggregator::OnSimpleEvent(const EventStack& eventStack) void FilteringAggregator::OnSymbolName(const SE::SymbolName& symbolName) { - const char *name = symbolName.Name(); - size_t len = strlen(name); - if (WildcardMatch(wildcard_.c_str(), name)) { - filteredKeys_.push_back(symbolName.Key()); - } + symbolNames_.emplace_back(symbolName.Key(), symbolName.Name()); } bool FilteringAggregator::InstantiationMatchesWildcard(const A::TemplateInstantiation& templateInstantiation) const { uint64_t primaryKey = templateInstantiation.PrimaryTemplateSymbolKey(); - size_t pos = std::lower_bound(filteredKeys_.begin(), filteredKeys_.end(), primaryKey) - filteredKeys_.begin(); - return (pos < filteredKeys_.size() && filteredKeys_[pos] == primaryKey); + std::pair key(primaryKey, ""); + size_t pos = std::lower_bound(symbolNames_.begin(), symbolNames_.end(), key) - symbolNames_.begin(); + if (pos == symbolNames_.size() || symbolNames_[pos].first != primaryKey) + return false; //not even registered + + const std::string& fullName = symbolNames_[pos].second; + return WildcardMatch(wildcard_.c_str(), fullName.c_str()); } bool FilteringAggregator::FileParseMatchesWildcard(const A::FrontEndFile& file) const @@ -93,6 +91,7 @@ bool FilteringAggregator::FunctionMatchesWildcard(const A::Function& function) c size_t pos = std::lower_bound(functionNamesDecorated_.begin(), functionNamesDecorated_.end(), decName) - functionNamesDecorated_.begin(); if (pos == functionNamesDecorated_.size() || functionNamesDecorated_[pos] != decName) return false; //not even registered + const std::string& undecName = functionNamesUndecorated_[pos]; return WildcardMatch(wildcard_.c_str(), undecName.c_str()); } @@ -149,12 +148,12 @@ template void FilteringAggregator::UpdateWildcardTime(const Acti void FilteringAggregator::OnFinishTemplateInstantiation(const A::Activity& parent, const A::TemplateInstantiationGroup& templateInstantiationGroup) { - UpdateWildcardTime(templateInstantiationGroup, &FilteringAggregator::InstantiationMatchesWildcard, _instantiationsTime); + UpdateWildcardTime(templateInstantiationGroup, &FilteringAggregator::InstantiationMatchesWildcard, instantiationsTime_); } void FilteringAggregator::OnFileParse(const A::FrontEndFileGroup& files) { - UpdateWildcardTime(files, &FilteringAggregator::FileParseMatchesWildcard, _parsingTime); + UpdateWildcardTime(files, &FilteringAggregator::FileParseMatchesWildcard, parsingTime_); } void FilteringAggregator::OnFunction(const A::Function& function) @@ -163,6 +162,6 @@ void FilteringAggregator::OnFunction(const A::Function& function) functionNamesDecorated_.push_back(function.Name()); } if (passNumber_ == 1) { - UpdateWildcardTime(function, &FilteringAggregator::FunctionMatchesWildcard, _generationTime); + UpdateWildcardTime(function, &FilteringAggregator::FunctionMatchesWildcard, generationTime_); } } diff --git a/src/FilteredAggregator/FilteredAggregator.h b/src/FilteredAggregator/FilteredAggregator.h index 737b8f7..6904fbe 100644 --- a/src/FilteredAggregator/FilteredAggregator.h +++ b/src/FilteredAggregator/FilteredAggregator.h @@ -45,14 +45,14 @@ class FilteringAggregator : public BI::IAnalyzer { std::string wildcard_; //pass 0: - std::vector filteredKeys_; + std::vector> symbolNames_; std::vector functionNamesDecorated_; std::vector functionNamesUndecorated_; //pass 1: - WildcardTime _instantiationsTime; - WildcardTime _parsingTime; - WildcardTime _generationTime; + WildcardTime instantiationsTime_; + WildcardTime parsingTime_; + WildcardTime generationTime_; }; } From 5a4c941580a81977eae479410aea9f88c71221f5 Mon Sep 17 00:00:00 2001 From: stgatilov Date: Tue, 3 Aug 2021 12:46:01 +0700 Subject: [PATCH 14/17] Backed out previous changeset. --- src/FilteredAggregator/FilteredAggregator.cpp | 33 ++++++++++--------- src/FilteredAggregator/FilteredAggregator.h | 8 ++--- 2 files changed, 21 insertions(+), 20 deletions(-) diff --git a/src/FilteredAggregator/FilteredAggregator.cpp b/src/FilteredAggregator/FilteredAggregator.cpp index b83e047..6b44ed5 100644 --- a/src/FilteredAggregator/FilteredAggregator.cpp +++ b/src/FilteredAggregator/FilteredAggregator.cpp @@ -22,19 +22,22 @@ void FilteringAggregator::WildcardTime::Print() const BI::AnalysisControl FilteringAggregator::OnEndAnalysisPass() { if (passNumber_ == 0) { - std::sort(symbolNames_.begin(), symbolNames_.end()); + std::sort(filteredKeys_.begin(), filteredKeys_.end()); + filteredKeys_.resize(std::unique(filteredKeys_.begin(), filteredKeys_.end()) - filteredKeys_.begin()); std::sort(functionNamesDecorated_.begin(), functionNamesDecorated_.end()); functionNamesDecorated_.resize(std::unique(functionNamesDecorated_.begin(), functionNamesDecorated_.end()) - functionNamesDecorated_.begin()); Undecorate(functionNamesDecorated_, functionNamesUndecorated_); } else if (passNumber_ == 1) { + filteredKeys_.clear(); + printf("Total time for parsing files matching \"%s\":\n", wildcard_.c_str()); - parsingTime_.Print(); + _parsingTime.Print(); printf("Total time for template instantiations matching \"%s\":\n", wildcard_.c_str()); - instantiationsTime_.Print(); + _instantiationsTime.Print(); printf("Total time for code generation matching \"%s\":\n", wildcard_.c_str()); - generationTime_.Print(); + _generationTime.Print(); } passNumber_++; @@ -63,19 +66,18 @@ AnalysisControl FilteringAggregator::OnSimpleEvent(const EventStack& eventStack) void FilteringAggregator::OnSymbolName(const SE::SymbolName& symbolName) { - symbolNames_.emplace_back(symbolName.Key(), symbolName.Name()); + const char *name = symbolName.Name(); + size_t len = strlen(name); + if (WildcardMatch(wildcard_.c_str(), name)) { + filteredKeys_.push_back(symbolName.Key()); + } } bool FilteringAggregator::InstantiationMatchesWildcard(const A::TemplateInstantiation& templateInstantiation) const { uint64_t primaryKey = templateInstantiation.PrimaryTemplateSymbolKey(); - std::pair key(primaryKey, ""); - size_t pos = std::lower_bound(symbolNames_.begin(), symbolNames_.end(), key) - symbolNames_.begin(); - if (pos == symbolNames_.size() || symbolNames_[pos].first != primaryKey) - return false; //not even registered - - const std::string& fullName = symbolNames_[pos].second; - return WildcardMatch(wildcard_.c_str(), fullName.c_str()); + size_t pos = std::lower_bound(filteredKeys_.begin(), filteredKeys_.end(), primaryKey) - filteredKeys_.begin(); + return (pos < filteredKeys_.size() && filteredKeys_[pos] == primaryKey); } bool FilteringAggregator::FileParseMatchesWildcard(const A::FrontEndFile& file) const @@ -91,7 +93,6 @@ bool FilteringAggregator::FunctionMatchesWildcard(const A::Function& function) c size_t pos = std::lower_bound(functionNamesDecorated_.begin(), functionNamesDecorated_.end(), decName) - functionNamesDecorated_.begin(); if (pos == functionNamesDecorated_.size() || functionNamesDecorated_[pos] != decName) return false; //not even registered - const std::string& undecName = functionNamesUndecorated_[pos]; return WildcardMatch(wildcard_.c_str(), undecName.c_str()); } @@ -148,12 +149,12 @@ template void FilteringAggregator::UpdateWildcardTime(const Acti void FilteringAggregator::OnFinishTemplateInstantiation(const A::Activity& parent, const A::TemplateInstantiationGroup& templateInstantiationGroup) { - UpdateWildcardTime(templateInstantiationGroup, &FilteringAggregator::InstantiationMatchesWildcard, instantiationsTime_); + UpdateWildcardTime(templateInstantiationGroup, &FilteringAggregator::InstantiationMatchesWildcard, _instantiationsTime); } void FilteringAggregator::OnFileParse(const A::FrontEndFileGroup& files) { - UpdateWildcardTime(files, &FilteringAggregator::FileParseMatchesWildcard, parsingTime_); + UpdateWildcardTime(files, &FilteringAggregator::FileParseMatchesWildcard, _parsingTime); } void FilteringAggregator::OnFunction(const A::Function& function) @@ -162,6 +163,6 @@ void FilteringAggregator::OnFunction(const A::Function& function) functionNamesDecorated_.push_back(function.Name()); } if (passNumber_ == 1) { - UpdateWildcardTime(function, &FilteringAggregator::FunctionMatchesWildcard, generationTime_); + UpdateWildcardTime(function, &FilteringAggregator::FunctionMatchesWildcard, _generationTime); } } diff --git a/src/FilteredAggregator/FilteredAggregator.h b/src/FilteredAggregator/FilteredAggregator.h index 6904fbe..737b8f7 100644 --- a/src/FilteredAggregator/FilteredAggregator.h +++ b/src/FilteredAggregator/FilteredAggregator.h @@ -45,14 +45,14 @@ class FilteringAggregator : public BI::IAnalyzer { std::string wildcard_; //pass 0: - std::vector> symbolNames_; + std::vector filteredKeys_; std::vector functionNamesDecorated_; std::vector functionNamesUndecorated_; //pass 1: - WildcardTime instantiationsTime_; - WildcardTime parsingTime_; - WildcardTime generationTime_; + WildcardTime _instantiationsTime; + WildcardTime _parsingTime; + WildcardTime _generationTime; }; } From 08c958abdfbfdf6581b2f1a5adbbfcad25216f24 Mon Sep 17 00:00:00 2001 From: stgatilov Date: Tue, 3 Aug 2021 13:54:15 +0700 Subject: [PATCH 15/17] First version of /stats command. --- src/Commands.cpp | 7 + src/Commands.h | 1 + .../StatisticsCollector.cpp | 202 ++++++++++++++++++ src/FilteredAggregator/StatisticsCollector.h | 47 ++++ src/main.cpp | 14 ++ vcperf.vcxproj | 2 + vcperf.vcxproj.filters | 6 + 7 files changed, 279 insertions(+) create mode 100644 src/FilteredAggregator/StatisticsCollector.cpp create mode 100644 src/FilteredAggregator/StatisticsCollector.h diff --git a/src/Commands.cpp b/src/Commands.cpp index d239cce..4bc9116 100644 --- a/src/Commands.cpp +++ b/src/Commands.cpp @@ -15,6 +15,7 @@ #include "TimeTrace\ExecutionHierarchy.h" #include "TimeTrace\TimeTraceGenerator.h" #include "FilteredAggregator\FilteredAggregator.h" +#include "FilteredAggregator\StatisticsCollector.h" using namespace Microsoft::Cpp::BuildInsights; @@ -260,6 +261,12 @@ HRESULT DoFilteredAggregate(const std::filesystem::path& inputFile, const std::w auto analyzerGroup = MakeStaticAnalyzerGroup(&analyzer); return Analyze(inputFile.c_str(), 2, analyzerGroup); } +HRESULT DoCollectStatistics(const std::filesystem::path& inputFile) +{ + StatisticsCollector analyzer; + auto analyzerGroup = MakeStaticAnalyzerGroup(&analyzer); + return Analyze(inputFile.c_str(), 2, analyzerGroup); +} HRESULT DoStart(const std::wstring& sessionName, bool cpuSampling, VerbosityLevel verbosityLevel) { diff --git a/src/Commands.h b/src/Commands.h index f06f9d5..1925736 100644 --- a/src/Commands.h +++ b/src/Commands.h @@ -19,5 +19,6 @@ HRESULT DoStop(const std::wstring& sessionName, const std::filesystem::path& out HRESULT DoStopNoAnalyze(const std::wstring& sessionName, const std::filesystem::path& outputFile); HRESULT DoAnalyze(const std::filesystem::path& inputFile, const std::filesystem::path& outputFile, bool analyzeTemplates = false, bool generateTimeTrace = false); HRESULT DoFilteredAggregate(const std::filesystem::path& inputFile, const std::wstring& wildcard); +HRESULT DoCollectStatistics(const std::filesystem::path& inputFile); } // namespace vcperf \ No newline at end of file diff --git a/src/FilteredAggregator/StatisticsCollector.cpp b/src/FilteredAggregator/StatisticsCollector.cpp new file mode 100644 index 0000000..ff0515f --- /dev/null +++ b/src/FilteredAggregator/StatisticsCollector.cpp @@ -0,0 +1,202 @@ +#include "StatisticsCollector.h" +#include +#include +#include "Undecorate.h" + +using namespace Microsoft::Cpp::BuildInsights; +using namespace vcperf; + + +void StatisticsCollector::Result::operator+= (const Result& other) { + count_ += other.count_; + totalTime_ += other.totalTime_; +} + +StatisticsCollector::StatisticsCollector() +{ +} + +BI::AnalysisControl StatisticsCollector::OnEndAnalysisPass() +{ + if (passNumber_ == 0) { + std::sort(parsedFilePaths_.begin(), parsedFilePaths_.end()); + parsedFilePaths_.resize(std::unique(parsedFilePaths_.begin(), parsedFilePaths_.end()) - parsedFilePaths_.begin()); + + std::sort(symbolNames_.begin(), symbolNames_.end()); + + std::sort(functionNamesDecorated_.begin(), functionNamesDecorated_.end()); + functionNamesDecorated_.resize(std::unique(functionNamesDecorated_.begin(), functionNamesDecorated_.end()) - functionNamesDecorated_.begin()); + Undecorate(functionNamesDecorated_, functionNamesUndecorated_); + + parseTimes_.resize(parsedFilePaths_.size()); + instantiationTimes_.resize(symbolNames_.size()); + generationTimes_.resize(functionNamesUndecorated_.size()); + } + else if (passNumber_ == 1) { + + auto BuildTree = [](const std::vector& paths, const std::vector& times, std::string separator, std::map& tree) { + for (int i = 0; i < paths.size(); i++) { + const std::string& text = paths[i]; + + size_t pos = 0; + while (1) { + tree["#" + text.substr(0, pos)] += times[i]; + if (pos == text.size()) + break; + + pos = text.find(separator, pos+1); + if (pos == std::string::npos) + pos = text.size(); + } + } + }; + + auto PrintTree = [](const std::map& tree, uint64_t totalTime) { + double invTotal = 1.0 / totalTime; + + uint64_t totalTreeTime = tree.at("#").totalTime_; + printf(" Total: %10.3lf (%6.3lf%%)\n", totalTreeTime * 1e-9, totalTreeTime * invTotal * 100.0); + + struct PrintLine { + std::string path; + double totalTimeSec; + int count; + double totalTimePercent; + }; + + std::vector arr; + for (auto& kv : tree) { + PrintLine pl; + pl.path = kv.first; + pl.totalTimeSec = kv.second.totalTime_ * 1e-9; + pl.count = kv.second.count_; + pl.totalTimePercent = kv.second.totalTime_ * invTotal * 100.0; + if (pl.path.size() > 120) + pl.path = pl.path.substr(0, 117) + "..."; + arr.push_back(pl); + } + + static const double MIN_TIME_SEC = 1e-3; + static const double MIN_TIME_PERCENT = 1e-1; + + printf("\n sorted by total time:\n"); + std::sort(arr.begin(), arr.end(), [](const PrintLine& a, const PrintLine& b) { + return a.totalTimeSec > b.totalTimeSec; + }); + for (int i = 0; i < arr.size(); i++) { + if (arr[i].totalTimeSec < MIN_TIME_SEC || arr[i].totalTimePercent < MIN_TIME_PERCENT) + break; + printf(" %-120s : %10.3lf | %6d (%6.3lf%%)\n", arr[i].path.c_str(), arr[i].totalTimeSec, arr[i].count, arr[i].totalTimePercent); + } + + printf("\n sorted lexicographically:\n"); + std::sort(arr.begin(), arr.end(), [](const PrintLine& a, const PrintLine& b) { + return a.path < b.path; + }); + for (int i = 0; i < arr.size(); i++) { + if (arr[i].totalTimeSec < MIN_TIME_SEC || arr[i].totalTimePercent < MIN_TIME_PERCENT) + continue; + printf(" %-120s : %10.3lf | %6d (%6.3lf%%)\n", arr[i].path.c_str(), arr[i].totalTimeSec, arr[i].count, arr[i].totalTimePercent); + } + }; + + std::vector symbolStrNames(symbolNames_.size()); + for (int i = 0; i < symbolNames_.size(); i++) + symbolStrNames[i] = symbolNames_[i].second; + + std::map parseTree_; + std::map instantiationTree_; + std::map generationTree_; + BuildTree(parsedFilePaths_, parseTimes_, "\\", parseTree_); + BuildTree(symbolStrNames, instantiationTimes_, "::", instantiationTree_); + BuildTree(functionNamesUndecorated_, generationTimes_, "::", generationTree_); + + uint64_t totalTime = parseTree_.at("#").totalTime_ + instantiationTree_.at("#").totalTime_ + generationTree_.at("#").totalTime_; + printf("All reported values are exclusive CPU times.\n"); + + printf("\n\n\nFile parsing:\n"); + PrintTree(parseTree_, totalTime); + printf("\n\n\nTemplate instantiation:\n"); + PrintTree(instantiationTree_, totalTime); + printf("\n\n\nCode generation:\n"); + PrintTree(generationTree_, totalTime); + } + passNumber_++; + + return AnalysisControl::CONTINUE; +} + +AnalysisControl StatisticsCollector::OnStopActivity(const EventStack& eventStack) +{ + if (passNumber_ == 1) { + MatchEventStackInMemberFunction(eventStack, this, &StatisticsCollector::OnFinishTemplateInstantiation); + } + MatchEventStackInMemberFunction(eventStack, this, &StatisticsCollector::OnFileParse); + MatchEventStackInMemberFunction(eventStack, this, &StatisticsCollector::OnFunction); + + return AnalysisControl::CONTINUE; +} + +AnalysisControl StatisticsCollector::OnSimpleEvent(const EventStack& eventStack) +{ + if (passNumber_ == 0) { + MatchEventStackInMemberFunction(eventStack, this, &StatisticsCollector::OnSymbolName); + } + + return AnalysisControl::CONTINUE; +} + +void StatisticsCollector::OnSymbolName(const SE::SymbolName& symbolName) +{ + symbolNames_.emplace_back(symbolName.Key(), symbolName.Name()); +} + +void StatisticsCollector::OnFinishTemplateInstantiation(const A::Activity& parent, const A::TemplateInstantiationGroup& templateInstantiationGroup) +{ + uint64_t primaryKey = templateInstantiationGroup.Back().PrimaryTemplateSymbolKey(); + uint64_t spentTime = templateInstantiationGroup.Back().ExclusiveCPUTime().count(); + + std::pair key(primaryKey, ""); + size_t pos = std::lower_bound(symbolNames_.begin(), symbolNames_.end(), key) - symbolNames_.begin(); + if (pos == symbolNames_.size() || symbolNames_[pos].first != primaryKey) + return; //not even registered + + instantiationTimes_[pos].totalTime_ += spentTime; + instantiationTimes_[pos].count_++; +} + +void StatisticsCollector::OnFileParse(const A::FrontEndFileGroup& files) +{ + if (passNumber_ == 0) { + parsedFilePaths_.push_back(files.Back().Path()); + } + if (passNumber_ == 1) { + std::string path = files.Back().Path(); + uint64_t spentTime = files.Back().ExclusiveCPUTime().count(); + + size_t pos = std::lower_bound(parsedFilePaths_.begin(), parsedFilePaths_.end(), path) - parsedFilePaths_.begin(); + if (pos == parsedFilePaths_.size() || parsedFilePaths_[pos] != path) + return; //not even registered + + parseTimes_[pos].totalTime_ += spentTime; + parseTimes_[pos].count_++; + } +} + +void StatisticsCollector::OnFunction(const A::Function& function) +{ + if (passNumber_ == 0) { + functionNamesDecorated_.push_back(function.Name()); + } + if (passNumber_ == 1) { + std::string decoratedName = function.Name(); + uint64_t spentTime = function.ExclusiveCPUTime().count(); + + size_t pos = std::lower_bound(functionNamesDecorated_.begin(), functionNamesDecorated_.end(), decoratedName) - functionNamesDecorated_.begin(); + if (pos == functionNamesDecorated_.size() || functionNamesDecorated_[pos] != decoratedName) + return; //not even registered + + generationTimes_[pos].totalTime_ += spentTime; + generationTimes_[pos].count_++; + } +} diff --git a/src/FilteredAggregator/StatisticsCollector.h b/src/FilteredAggregator/StatisticsCollector.h new file mode 100644 index 0000000..494cfb8 --- /dev/null +++ b/src/FilteredAggregator/StatisticsCollector.h @@ -0,0 +1,47 @@ +#pragma once + +#include +#include + +#include "VcperfBuildInsights.h" + + +namespace vcperf +{ + +class StatisticsCollector : public BI::IAnalyzer { +public: + StatisticsCollector(); + + BI::AnalysisControl OnEndAnalysisPass() override; + BI::AnalysisControl OnStopActivity(const BI::EventStack& eventStack) override; + BI::AnalysisControl OnSimpleEvent(const BI::EventStack& eventStack) override; + +private: + void OnFinishTemplateInstantiation(const A::Activity& parent, const A::TemplateInstantiationGroup& templateInstantiationGroup); + void OnSymbolName(const SE::SymbolName& symbolName); + void OnFileParse(const A::FrontEndFileGroup& files); + void OnFunction(const A::Function& function); + + //global + int passNumber_ = 0; + + //pass 0: + std::vector> symbolNames_; + std::vector functionNamesDecorated_; + std::vector functionNamesUndecorated_; + std::vector parsedFilePaths_; + + struct Result { + int count_ = 0; + uint64_t totalTime_ = 0; //CPU time, exclusive + void operator+= (const Result& other); + }; + + //pass 1: + std::vector parseTimes_; + std::vector instantiationTimes_; + std::vector generationTimes_; +}; + +} diff --git a/src/main.cpp b/src/main.cpp index 350c6f6..f97e001 100644 --- a/src/main.cpp +++ b/src/main.cpp @@ -170,6 +170,7 @@ int wmain(int argc, wchar_t* argv[]) std::wcout << L"vcperf.exe /analyze [/templates] inputRawFile.etl output.etl" << std::endl; std::wcout << L"vcperf.exe /analyze [/templates] inputRawFile.etl /timetrace output.json" << std::endl; std::wcout << L"vcperf.exe /sumof {wildcard} inputRawFile.etl" << std::endl; + std::wcout << L"vcperf.exe /stats inputRawFile.etl" << std::endl; std::wcout << std::endl; @@ -308,6 +309,19 @@ int wmain(int argc, wchar_t* argv[]) return DoFilteredAggregate(inputFile, wildcard); } + else if (CheckCommand(argv[1], L"stats")) + { + if (argc < 3) { + return E_FAIL; + } + std::wstring inputFile = argv[2]; + + if (!ValidateFile(inputFile, true, L".etl")) { + return E_FAIL; + } + + return DoCollectStatistics(inputFile); + } else { std::wcout << L"ERROR: Unknown command " << argv[1] << std::endl; diff --git a/vcperf.vcxproj b/vcperf.vcxproj index 6e74deb..1ef7248 100644 --- a/vcperf.vcxproj +++ b/vcperf.vcxproj @@ -181,6 +181,7 @@ + @@ -197,6 +198,7 @@ + diff --git a/vcperf.vcxproj.filters b/vcperf.vcxproj.filters index 36b8e30..2e26284 100644 --- a/vcperf.vcxproj.filters +++ b/vcperf.vcxproj.filters @@ -87,6 +87,9 @@ Source Files\FilteredAggregator + + Source Files\FilteredAggregator + @@ -143,6 +146,9 @@ Header Files\FilteredAggregator + + Header Files\FilteredAggregator + From ffc53245198338267ac44d02d1323bc168655475 Mon Sep 17 00:00:00 2001 From: stgatilov Date: Tue, 3 Aug 2021 14:13:41 +0700 Subject: [PATCH 16/17] Trying to remove template arguments from names. --- .../StatisticsCollector.cpp | 40 ++++++++++++++++--- 1 file changed, 35 insertions(+), 5 deletions(-) diff --git a/src/FilteredAggregator/StatisticsCollector.cpp b/src/FilteredAggregator/StatisticsCollector.cpp index ff0515f..dcde5ce 100644 --- a/src/FilteredAggregator/StatisticsCollector.cpp +++ b/src/FilteredAggregator/StatisticsCollector.cpp @@ -2,6 +2,7 @@ #include #include #include "Undecorate.h" +#include using namespace Microsoft::Cpp::BuildInsights; using namespace vcperf; @@ -77,7 +78,7 @@ BI::AnalysisControl StatisticsCollector::OnEndAnalysisPass() } static const double MIN_TIME_SEC = 1e-3; - static const double MIN_TIME_PERCENT = 1e-1; + static const double MIN_TIME_PERCENT = 1e-2; printf("\n sorted by total time:\n"); std::sort(arr.begin(), arr.end(), [](const PrintLine& a, const PrintLine& b) { @@ -86,7 +87,7 @@ BI::AnalysisControl StatisticsCollector::OnEndAnalysisPass() for (int i = 0; i < arr.size(); i++) { if (arr[i].totalTimeSec < MIN_TIME_SEC || arr[i].totalTimePercent < MIN_TIME_PERCENT) break; - printf(" %-120s : %10.3lf | %6d (%6.3lf%%)\n", arr[i].path.c_str(), arr[i].totalTimeSec, arr[i].count, arr[i].totalTimePercent); + printf(" %10.3lf | %6d (%6.3lf%%) : %s\n", arr[i].totalTimeSec, arr[i].count, arr[i].totalTimePercent, arr[i].path.c_str()); } printf("\n sorted lexicographically:\n"); @@ -96,20 +97,49 @@ BI::AnalysisControl StatisticsCollector::OnEndAnalysisPass() for (int i = 0; i < arr.size(); i++) { if (arr[i].totalTimeSec < MIN_TIME_SEC || arr[i].totalTimePercent < MIN_TIME_PERCENT) continue; - printf(" %-120s : %10.3lf | %6d (%6.3lf%%)\n", arr[i].path.c_str(), arr[i].totalTimeSec, arr[i].count, arr[i].totalTimePercent); + printf(" %10.3lf | %6d (%6.3lf%%) : %s\n", arr[i].totalTimeSec, arr[i].count, arr[i].totalTimePercent, arr[i].path.c_str()); } }; + auto FilterTemplateArguments = [](std::string path) -> std::string { + int totalBalance = 0; + int lastBalanceZero = 0; + for (int i = 0; i < path.size(); i++) { + if (path[i] == '<') + totalBalance++; + if (path[i] == '>') + totalBalance--; + if (totalBalance == 0) + lastBalanceZero = i + 1; + } + + std::string res; + int runningBalance = 0; + for (int i = 0; i < path.size(); i++) { + if (path[i] == '<') + runningBalance++; + if (runningBalance == 0 || i >= lastBalanceZero) + res += path[i]; + if (path[i] == '>') + runningBalance--; + } + return res; + }; + + std::vector generationPaths; + for (int i = 0; i < functionNamesUndecorated_.size(); i++) + generationPaths.push_back(FilterTemplateArguments(functionNamesUndecorated_[i])); + std::vector symbolStrNames(symbolNames_.size()); for (int i = 0; i < symbolNames_.size(); i++) - symbolStrNames[i] = symbolNames_[i].second; + symbolStrNames[i] = FilterTemplateArguments(symbolNames_[i].second); std::map parseTree_; std::map instantiationTree_; std::map generationTree_; BuildTree(parsedFilePaths_, parseTimes_, "\\", parseTree_); BuildTree(symbolStrNames, instantiationTimes_, "::", instantiationTree_); - BuildTree(functionNamesUndecorated_, generationTimes_, "::", generationTree_); + BuildTree(generationPaths, generationTimes_, "::", generationTree_); uint64_t totalTime = parseTree_.at("#").totalTime_ + instantiationTree_.at("#").totalTime_ + generationTree_.at("#").totalTime_; printf("All reported values are exclusive CPU times.\n"); From f88bf1dbafb64d7a702d0b4b9c295702f578cc90 Mon Sep 17 00:00:00 2001 From: stgatilov Date: Thu, 5 Aug 2021 15:33:39 +0700 Subject: [PATCH 17/17] Fixed exception if some events are absent. --- src/FilteredAggregator/StatisticsCollector.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/FilteredAggregator/StatisticsCollector.cpp b/src/FilteredAggregator/StatisticsCollector.cpp index dcde5ce..4e5ed78 100644 --- a/src/FilteredAggregator/StatisticsCollector.cpp +++ b/src/FilteredAggregator/StatisticsCollector.cpp @@ -141,7 +141,7 @@ BI::AnalysisControl StatisticsCollector::OnEndAnalysisPass() BuildTree(symbolStrNames, instantiationTimes_, "::", instantiationTree_); BuildTree(generationPaths, generationTimes_, "::", generationTree_); - uint64_t totalTime = parseTree_.at("#").totalTime_ + instantiationTree_.at("#").totalTime_ + generationTree_.at("#").totalTime_; + uint64_t totalTime = parseTree_["#"].totalTime_ + instantiationTree_["#"].totalTime_ + generationTree_["#"].totalTime_; printf("All reported values are exclusive CPU times.\n"); printf("\n\n\nFile parsing:\n");