Author: Jacob Lalonde Date: 2024-09-10T09:58:43-07:00 New Revision: 22144e20cbd237a432fdc4106abe3960555aff42
URL: https://github.com/llvm/llvm-project/commit/22144e20cbd237a432fdc4106abe3960555aff42 DIFF: https://github.com/llvm/llvm-project/commit/22144e20cbd237a432fdc4106abe3960555aff42.diff LOG: [LLDB][Data Formatters] Calculate average and total time for summary providers within lldb (#102708) This PR adds a statistics provider cache, which allows an individual target to keep a rolling tally of it's total time and number of invocations for a given summary provider. This information is then available in statistics dump to help slow summary providers, and gleam more into insight into LLDB's time use. Added: lldb/test/API/commands/statistics/basic/BoxFormatter.py lldb/test/API/commands/statistics/basic/main.cpp lldb/unittests/Target/SummaryStatisticsTest.cpp Modified: lldb/include/lldb/DataFormatters/TypeSummary.h lldb/include/lldb/Target/Statistics.h lldb/include/lldb/Target/Target.h lldb/source/Core/ValueObject.cpp lldb/source/DataFormatters/TypeSummary.cpp lldb/source/Target/Statistics.cpp lldb/source/Target/Target.cpp lldb/test/API/commands/statistics/basic/Makefile lldb/test/API/commands/statistics/basic/TestStats.py lldb/unittests/Target/CMakeLists.txt Removed: lldb/test/API/commands/statistics/basic/main.c ################################################################################ diff --git a/lldb/include/lldb/DataFormatters/TypeSummary.h b/lldb/include/lldb/DataFormatters/TypeSummary.h index a82641021dad36..382824aa2813da 100644 --- a/lldb/include/lldb/DataFormatters/TypeSummary.h +++ b/lldb/include/lldb/DataFormatters/TypeSummary.h @@ -258,6 +258,14 @@ class TypeSummaryImpl { virtual std::string GetDescription() = 0; + /// Get the name of the Type Summary Provider, either a C++ class, a summary + /// string, or a script function name. + virtual std::string GetName() = 0; + + /// Get the name of the kind of Summary Provider, either c++, summary string, + /// script or python. + virtual std::string GetSummaryKindName(); + uint32_t &GetRevision() { return m_my_revision; } typedef std::shared_ptr<TypeSummaryImpl> SharedPointer; @@ -293,6 +301,8 @@ struct StringSummaryFormat : public TypeSummaryImpl { std::string GetDescription() override; + std::string GetName() override; + static bool classof(const TypeSummaryImpl *S) { return S->GetKind() == Kind::eSummaryString; } @@ -340,6 +350,8 @@ struct CXXFunctionSummaryFormat : public TypeSummaryImpl { return S->GetKind() == Kind::eCallback; } + std::string GetName() override; + typedef std::shared_ptr<CXXFunctionSummaryFormat> SharedPointer; private: @@ -352,6 +364,7 @@ struct CXXFunctionSummaryFormat : public TypeSummaryImpl { struct ScriptSummaryFormat : public TypeSummaryImpl { std::string m_function_name; std::string m_python_script; + std::string m_script_formatter_name; StructuredData::ObjectSP m_script_function_sp; ScriptSummaryFormat(const TypeSummaryImpl::Flags &flags, @@ -384,6 +397,8 @@ struct ScriptSummaryFormat : public TypeSummaryImpl { std::string GetDescription() override; + std::string GetName() override; + static bool classof(const TypeSummaryImpl *S) { return S->GetKind() == Kind::eScript; } diff --git a/lldb/include/lldb/Target/Statistics.h b/lldb/include/lldb/Target/Statistics.h index 5193d099a5494d..f3414ae314f339 100644 --- a/lldb/include/lldb/Target/Statistics.h +++ b/lldb/include/lldb/Target/Statistics.h @@ -9,6 +9,7 @@ #ifndef LLDB_TARGET_STATISTICS_H #define LLDB_TARGET_STATISTICS_H +#include "lldb/DataFormatters/TypeSummary.h" #include "lldb/Utility/ConstString.h" #include "lldb/Utility/RealpathPrefixes.h" #include "lldb/Utility/Stream.h" @@ -17,6 +18,7 @@ #include "llvm/Support/JSON.h" #include <atomic> #include <chrono> +#include <mutex> #include <optional> #include <ratio> #include <string> @@ -26,6 +28,9 @@ namespace lldb_private { using StatsClock = std::chrono::high_resolution_clock; using StatsTimepoint = std::chrono::time_point<StatsClock>; +class SummaryStatistics; +// Declaring here as there is no private forward +typedef std::shared_ptr<SummaryStatistics> SummaryStatisticsSP; class StatsDuration { public: @@ -175,6 +180,81 @@ struct StatisticsOptions { std::optional<bool> m_include_transcript; }; +/// A class that represents statistics about a TypeSummaryProviders invocations +/// \note All members of this class need to be accessed in a thread safe manner +class SummaryStatistics { +public: + explicit SummaryStatistics(std::string name, std::string impl_type) + : m_total_time(), m_impl_type(std::move(impl_type)), + m_name(std::move(name)), m_count(0) {} + + std::string GetName() const { return m_name; }; + double GetTotalTime() const { return m_total_time.get().count(); } + + uint64_t GetSummaryCount() const { + return m_count.load(std::memory_order_relaxed); + } + + StatsDuration &GetDurationReference() { return m_total_time; }; + + std::string GetSummaryKindName() const { return m_impl_type; } + + llvm::json::Value ToJSON() const; + + /// Basic RAII class to increment the summary count when the call is complete. + class SummaryInvocation { + public: + SummaryInvocation(SummaryStatisticsSP summary_stats) + : m_stats(summary_stats), + m_elapsed_time(summary_stats->GetDurationReference()) {} + ~SummaryInvocation() { m_stats->OnInvoked(); } + + /// Delete the copy constructor and assignment operator to prevent + /// accidental double counting. + /// @{ + SummaryInvocation(const SummaryInvocation &) = delete; + SummaryInvocation &operator=(const SummaryInvocation &) = delete; + /// @} + + private: + SummaryStatisticsSP m_stats; + ElapsedTime m_elapsed_time; + }; + +private: + void OnInvoked() noexcept { m_count.fetch_add(1, std::memory_order_relaxed); } + lldb_private::StatsDuration m_total_time; + const std::string m_impl_type; + const std::string m_name; + std::atomic<uint64_t> m_count; +}; + +/// A class that wraps a std::map of SummaryStatistics objects behind a mutex. +class SummaryStatisticsCache { +public: + /// Get the SummaryStatistics object for a given provider name, or insert + /// if statistics for that provider is not in the map. + SummaryStatisticsSP + GetSummaryStatisticsForProvider(lldb_private::TypeSummaryImpl &provider) { + std::lock_guard<std::mutex> guard(m_map_mutex); + if (auto iterator = m_summary_stats_map.find(provider.GetName()); + iterator != m_summary_stats_map.end()) + return iterator->second; + + auto it = m_summary_stats_map.try_emplace( + provider.GetName(), + std::make_shared<SummaryStatistics>(provider.GetName(), + provider.GetSummaryKindName())); + return it.first->second; + } + + llvm::json::Value ToJSON(); + +private: + llvm::StringMap<SummaryStatisticsSP> m_summary_stats_map; + std::mutex m_map_mutex; +}; + /// A class that represents statistics for a since lldb_private::Target. class TargetStats { public: diff --git a/lldb/include/lldb/Target/Target.h b/lldb/include/lldb/Target/Target.h index 7f4d607f5427df..50df01aac74004 100644 --- a/lldb/include/lldb/Target/Target.h +++ b/lldb/include/lldb/Target/Target.h @@ -1224,6 +1224,10 @@ class Target : public std::enable_shared_from_this<Target>, void ClearAllLoadedSections(); + lldb_private::SummaryStatisticsSP GetSummaryStatisticsSPForProviderName( + lldb_private::TypeSummaryImpl &summary_provider); + lldb_private::SummaryStatisticsCache &GetSummaryStatisticsCache(); + /// Set the \a Trace object containing processor trace information of this /// target. /// @@ -1557,6 +1561,7 @@ class Target : public std::enable_shared_from_this<Target>, std::string m_label; ModuleList m_images; ///< The list of images for this process (shared /// libraries and anything dynamically loaded). + SummaryStatisticsCache m_summary_statistics_cache; SectionLoadHistory m_section_load_history; BreakpointList m_breakpoint_list; BreakpointList m_internal_breakpoint_list; diff --git a/lldb/source/Core/ValueObject.cpp b/lldb/source/Core/ValueObject.cpp index 1bedd87e943dc3..5b1c171c01f2db 100644 --- a/lldb/source/Core/ValueObject.cpp +++ b/lldb/source/Core/ValueObject.cpp @@ -615,7 +615,17 @@ bool ValueObject::GetSummaryAsCString(TypeSummaryImpl *summary_ptr, m_synthetic_value->UpdateValueIfNeeded(); // the summary might depend on // the synthetic children being // up-to-date (e.g. ${svar%#}) - summary_ptr->FormatObject(this, destination, actual_options); + + if (TargetSP target_sp = GetExecutionContextRef().GetTargetSP()) { + SummaryStatisticsSP stats_sp = + target_sp->GetSummaryStatisticsCache() + .GetSummaryStatisticsForProvider(*summary_ptr); + + // Construct RAII types to time and collect data on summary creation. + SummaryStatistics::SummaryInvocation invocation(stats_sp); + summary_ptr->FormatObject(this, destination, actual_options); + } else + summary_ptr->FormatObject(this, destination, actual_options); } m_flags.m_is_getting_summary = false; return !destination.empty(); diff --git a/lldb/source/DataFormatters/TypeSummary.cpp b/lldb/source/DataFormatters/TypeSummary.cpp index 3707d2d879d33a..339068e8cc6aa6 100644 --- a/lldb/source/DataFormatters/TypeSummary.cpp +++ b/lldb/source/DataFormatters/TypeSummary.cpp @@ -48,6 +48,19 @@ TypeSummaryOptions::SetCapping(lldb::TypeSummaryCapping cap) { TypeSummaryImpl::TypeSummaryImpl(Kind kind, const TypeSummaryImpl::Flags &flags) : m_flags(flags), m_kind(kind) {} +std::string TypeSummaryImpl::GetSummaryKindName() { + switch (m_kind) { + case Kind::eSummaryString: + return "string"; + case Kind::eCallback: + return "callback"; + case Kind::eScript: + return "python"; + case Kind::eInternal: + return "c++"; + } +} + StringSummaryFormat::StringSummaryFormat(const TypeSummaryImpl::Flags &flags, const char *format_cstr) : TypeSummaryImpl(Kind::eSummaryString, flags), m_format_str() { @@ -116,6 +129,8 @@ std::string StringSummaryFormat::GetDescription() { return std::string(sstr.GetString()); } +std::string StringSummaryFormat::GetName() { return m_format_str; } + CXXFunctionSummaryFormat::CXXFunctionSummaryFormat( const TypeSummaryImpl::Flags &flags, Callback impl, const char *description) : TypeSummaryImpl(Kind::eCallback, flags), m_impl(impl), @@ -145,15 +160,27 @@ std::string CXXFunctionSummaryFormat::GetDescription() { return std::string(sstr.GetString()); } +std::string CXXFunctionSummaryFormat::GetName() { return m_description; } + ScriptSummaryFormat::ScriptSummaryFormat(const TypeSummaryImpl::Flags &flags, const char *function_name, const char *python_script) : TypeSummaryImpl(Kind::eScript, flags), m_function_name(), m_python_script(), m_script_function_sp() { - if (function_name) + // Take preference in the python script name over the function name. + if (function_name) { m_function_name.assign(function_name); - if (python_script) + m_script_formatter_name = function_name; + } + if (python_script) { m_python_script.assign(python_script); + m_script_formatter_name = python_script; + } + + // Python scripts include the tabbing of the function def so we remove the + // leading spaces. + m_script_formatter_name = m_script_formatter_name.erase( + 0, m_script_formatter_name.find_first_not_of(' ')); } bool ScriptSummaryFormat::FormatObject(ValueObject *valobj, std::string &retval, @@ -201,3 +228,5 @@ std::string ScriptSummaryFormat::GetDescription() { } return std::string(sstr.GetString()); } + +std::string ScriptSummaryFormat::GetName() { return m_script_formatter_name; } diff --git a/lldb/source/Target/Statistics.cpp b/lldb/source/Target/Statistics.cpp index 390e04cebf6be6..d619f92122cb9d 100644 --- a/lldb/source/Target/Statistics.cpp +++ b/lldb/source/Target/Statistics.cpp @@ -196,6 +196,8 @@ TargetStats::ToJSON(Target &target, m_source_realpath_attempt_count); target_metrics_json.try_emplace("sourceRealpathCompatibleCount", m_source_realpath_compatible_count); + target_metrics_json.try_emplace("summaryProviderStatistics", + target.GetSummaryStatisticsCache().ToJSON()); return target_metrics_json; } @@ -420,3 +422,21 @@ llvm::json::Value DebuggerStats::ReportStatistics( return std::move(global_stats); } + +llvm::json::Value SummaryStatistics::ToJSON() const { + return json::Object{{ + {"name", GetName()}, + {"type", GetSummaryKindName()}, + {"count", GetSummaryCount()}, + {"totalTime", GetTotalTime()}, + }}; +} + +json::Value SummaryStatisticsCache::ToJSON() { + std::lock_guard<std::mutex> guard(m_map_mutex); + json::Array json_summary_stats; + for (const auto &summary_stat : m_summary_stats_map) + json_summary_stats.emplace_back(summary_stat.second->ToJSON()); + + return json_summary_stats; +} diff --git a/lldb/source/Target/Target.cpp b/lldb/source/Target/Target.cpp index f1c378b968d2ba..3e7e7b7d784e90 100644 --- a/lldb/source/Target/Target.cpp +++ b/lldb/source/Target/Target.cpp @@ -3204,6 +3204,16 @@ bool Target::SetSectionUnloaded(const lldb::SectionSP §ion_sp, void Target::ClearAllLoadedSections() { m_section_load_history.Clear(); } +lldb_private::SummaryStatisticsSP Target::GetSummaryStatisticsSPForProviderName( + lldb_private::TypeSummaryImpl &summary_provider) { + return m_summary_statistics_cache.GetSummaryStatisticsForProvider( + summary_provider); +} + +SummaryStatisticsCache &Target::GetSummaryStatisticsCache() { + return m_summary_statistics_cache; +} + void Target::SaveScriptedLaunchInfo(lldb_private::ProcessInfo &process_info) { if (process_info.IsScriptedProcess()) { // Only copy scripted process launch options. diff --git a/lldb/test/API/commands/statistics/basic/BoxFormatter.py b/lldb/test/API/commands/statistics/basic/BoxFormatter.py new file mode 100644 index 00000000000000..07681b32dfd090 --- /dev/null +++ b/lldb/test/API/commands/statistics/basic/BoxFormatter.py @@ -0,0 +1,15 @@ +import lldb + + +def summary(valobj, dict): + return f"[{valobj.GetChildAtIndex(0).GetValue()}]" + + +def __lldb_init_module(debugger, dict): + typeName = "Box<.*$" + debugger.HandleCommand( + 'type summary add -x "' + + typeName + + '" --python-function ' + + f"{__name__}.summary" + ) diff --git a/lldb/test/API/commands/statistics/basic/Makefile b/lldb/test/API/commands/statistics/basic/Makefile index c9319d6e6888a4..3d0b98f13f3d7b 100644 --- a/lldb/test/API/commands/statistics/basic/Makefile +++ b/lldb/test/API/commands/statistics/basic/Makefile @@ -1,2 +1,2 @@ -C_SOURCES := main.c +CXX_SOURCES := main.cpp include Makefile.rules diff --git a/lldb/test/API/commands/statistics/basic/TestStats.py b/lldb/test/API/commands/statistics/basic/TestStats.py index a8ac60090a760d..03ec1693447051 100644 --- a/lldb/test/API/commands/statistics/basic/TestStats.py +++ b/lldb/test/API/commands/statistics/basic/TestStats.py @@ -81,7 +81,7 @@ def get_command_stats(self, debug_stats): def test_expressions_frame_var_counts(self): self.build() lldbutil.run_to_source_breakpoint( - self, "// break here", lldb.SBFileSpec("main.c") + self, "// break here", lldb.SBFileSpec("main.cpp") ) self.expect("expr patatino", substrs=["27"]) @@ -224,7 +224,7 @@ def test_default_with_run(self): self.build() target = self.createTestTarget() lldbutil.run_to_source_breakpoint( - self, "// break here", lldb.SBFileSpec("main.c") + self, "// break here", lldb.SBFileSpec("main.cpp") ) debug_stats = self.get_stats() debug_stat_keys = [ @@ -250,6 +250,7 @@ def test_default_with_run(self): "launchOrAttachTime", "moduleIdentifiers", "targetCreateTime", + "summaryProviderStatistics", ] self.verify_keys(stats, '"stats"', keys_exist, None) self.assertGreater(stats["firstStopTime"], 0.0) @@ -447,6 +448,7 @@ def test_breakpoints(self): "targetCreateTime", "moduleIdentifiers", "totalBreakpointResolveTime", + "summaryProviderStatistics", ] self.verify_keys(target_stats, '"stats"', keys_exist, None) self.assertGreater(target_stats["totalBreakpointResolveTime"], 0.0) @@ -918,3 +920,67 @@ def test_order_of_options_do_not_matter(self): debug_stats_1, f"The order of options '{options[0]}' and '{options[1]}' should not matter", ) + + def test_summary_statistics_providers(self): + """ + Test summary timing statistics is included in statistics dump when + a type with a summary provider exists, and is evaluated. + """ + + self.build() + target = self.createTestTarget() + lldbutil.run_to_source_breakpoint( + self, "// stop here", lldb.SBFileSpec("main.cpp") + ) + self.expect("frame var", substrs=["hello world"]) + stats = self.get_target_stats(self.get_stats()) + self.assertIn("summaryProviderStatistics", stats) + summary_providers = stats["summaryProviderStatistics"] + # We don't want to take a dependency on the type name, so we just look + # for string and that it was called once. + summary_provider_str = str(summary_providers) + self.assertIn("string", summary_provider_str) + self.assertIn("'count': 1", summary_provider_str) + self.assertIn("'totalTime':", summary_provider_str) + # We may hit the std::string C++ provider, or a summary provider string + self.assertIn("'type':", summary_provider_str) + self.assertTrue( + "c++" in summary_provider_str or "string" in summary_provider_str + ) + + self.runCmd("continue") + self.runCmd("command script import BoxFormatter.py") + self.expect("frame var", substrs=["box = [27]"]) + stats = self.get_target_stats(self.get_stats()) + self.assertIn("summaryProviderStatistics", stats) + summary_providers = stats["summaryProviderStatistics"] + summary_provider_str = str(summary_providers) + self.assertIn("BoxFormatter.summary", summary_provider_str) + self.assertIn("'count': 1", summary_provider_str) + self.assertIn("'totalTime':", summary_provider_str) + self.assertIn("'type': 'python'", summary_provider_str) + + def test_summary_statistics_providers_vec(self): + """ + Test summary timing statistics is included in statistics dump when + a type with a summary provider exists, and is evaluated. This variation + tests that vector recurses into it's child type. + """ + self.build() + target = self.createTestTarget() + lldbutil.run_to_source_breakpoint( + self, "// stop vector", lldb.SBFileSpec("main.cpp") + ) + self.expect( + "frame var", substrs=["int_vec", "double_vec", "[0] = 1", "[7] = 8"] + ) + stats = self.get_target_stats(self.get_stats()) + self.assertIn("summaryProviderStatistics", stats) + summary_providers = stats["summaryProviderStatistics"] + summary_provider_str = str(summary_providers) + self.assertIn("'count': 2", summary_provider_str) + self.assertIn("'totalTime':", summary_provider_str) + self.assertIn("'type':", summary_provider_str) + # We may hit the std::vector C++ provider, or a summary provider string + if "c++" in summary_provider_str: + self.assertIn("std::vector", summary_provider_str) diff --git a/lldb/test/API/commands/statistics/basic/main.c b/lldb/test/API/commands/statistics/basic/main.c deleted file mode 100644 index 2c5b4f5f098ee4..00000000000000 --- a/lldb/test/API/commands/statistics/basic/main.c +++ /dev/null @@ -1,7 +0,0 @@ -// Test that the lldb command `statistics` works. - -int main(void) { - int patatino = 27; - - return 0; // break here -} diff --git a/lldb/test/API/commands/statistics/basic/main.cpp b/lldb/test/API/commands/statistics/basic/main.cpp new file mode 100644 index 00000000000000..321d4b5034393e --- /dev/null +++ b/lldb/test/API/commands/statistics/basic/main.cpp @@ -0,0 +1,35 @@ +// Test that the lldb command `statistics` works. +#include <string> +#include <vector> + +template <typename T> class Box { + T m_value; + +public: + Box(T value) : m_value(value) {} +}; + +void foo() { + std::string str = "hello world"; + str += "\n"; // stop here +} + +void bar(int x) { + auto box = Box<int>(x); + // stop here +} + +void vec() { + std::vector<int> int_vec = {1, 2, 3, 4, 5, 6, 7, 8}; + std::vector<double> double_vec = {1.0, 2.0, 3.0, 4.0, 5.0, 6.0, 7.0, 8.0}; + // stop vector + int x = int_vec.size(); +} + +int main(void) { + int patatino = 27; + foo(); + bar(patatino); + vec(); + return 0; // break here +} diff --git a/lldb/unittests/Target/CMakeLists.txt b/lldb/unittests/Target/CMakeLists.txt index d10e93ca6336d6..a64876184de160 100644 --- a/lldb/unittests/Target/CMakeLists.txt +++ b/lldb/unittests/Target/CMakeLists.txt @@ -11,6 +11,7 @@ add_lldb_unittest(TargetTests RegisterFlagsTest.cpp RemoteAwarePlatformTest.cpp StackFrameRecognizerTest.cpp + SummaryStatisticsTest.cpp FindFileTest.cpp LINK_LIBS diff --git a/lldb/unittests/Target/SummaryStatisticsTest.cpp b/lldb/unittests/Target/SummaryStatisticsTest.cpp new file mode 100644 index 00000000000000..f4033752845408 --- /dev/null +++ b/lldb/unittests/Target/SummaryStatisticsTest.cpp @@ -0,0 +1,58 @@ +#include "lldb/DataFormatters/TypeSummary.h" +#include "lldb/Target/Statistics.h" +#include "lldb/Utility/Stream.h" +#include "lldb/lldb-forward.h" +#include "lldb/lldb-private-enumerations.h" +#include "lldb/lldb-private.h" +#include "llvm/Testing/Support/Error.h" +#include "gtest/gtest.h" +#include <thread> + +using namespace lldb_private; +using Duration = std::chrono::duration<double>; + +class DummySummaryImpl : public lldb_private::TypeSummaryImpl { +public: + DummySummaryImpl() + : TypeSummaryImpl(TypeSummaryImpl::Kind::eSummaryString, + TypeSummaryImpl::Flags()) {} + + std::string GetName() override { return "DummySummary"; } + + std::string GetSummaryKindName() override { return "dummy"; } + + std::string GetDescription() override { return ""; } + + bool FormatObject(ValueObject *valobj, std::string &dest, + const TypeSummaryOptions &options) override { + return false; + } +}; + +TEST(MultithreadFormatting, Multithread) { + SummaryStatisticsCache statistics_cache; + DummySummaryImpl summary; + std::vector<std::thread> threads; + for (int i = 0; i < 10; ++i) { + threads.emplace_back(std::thread([&statistics_cache, &summary]() { + auto sp = statistics_cache.GetSummaryStatisticsForProvider(summary); + { + SummaryStatistics::SummaryInvocation invocation(sp); + std::this_thread::sleep_for(Duration(1)); + } + })); + } + + for (auto &thread : threads) + thread.join(); + + auto sp = statistics_cache.GetSummaryStatisticsForProvider(summary); + ASSERT_TRUE(sp->GetDurationReference().get().count() > 10); + ASSERT_TRUE(sp->GetSummaryCount() == 10); + + std::string stats_as_json; + llvm::raw_string_ostream ss(stats_as_json); + ss << sp->ToJSON(); + ASSERT_THAT(stats_as_json, ::testing::HasSubstr("\"name\":\"DummySummary\"")); + ASSERT_THAT(stats_as_json, ::testing::HasSubstr("\"type\":\"dummy\"")); +} _______________________________________________ lldb-commits mailing list lldb-commits@lists.llvm.org https://lists.llvm.org/cgi-bin/mailman/listinfo/lldb-commits
