llvmbot wrote:
<!--LLVM PR SUMMARY COMMENT--> @llvm/pr-subscribers-lldb Author: Vy Nguyen (oontvoo) <details> <summary>Changes</summary> Implement telemetry in LLDB. (See previous discussions at https://discourse.llvm.org/t/rfc-lldb-telemetry-metrics/64588) --- Patch is 48.73 KiB, truncated to 20.00 KiB below, full version: https://github.com/llvm/llvm-project/pull/87815.diff 12 Files Affected: - (modified) lldb/include/lldb/API/SBDebugger.h (+4) - (modified) lldb/include/lldb/Core/Debugger.h (+10) - (added) lldb/include/lldb/Core/Telemetry.h (+237) - (modified) lldb/include/lldb/Target/Process.h (+3) - (modified) lldb/source/API/SBDebugger.cpp (+9) - (modified) lldb/source/Core/CMakeLists.txt (+1) - (modified) lldb/source/Core/Debugger.cpp (+31-1) - (added) lldb/source/Core/Telemetry.cpp (+620) - (modified) lldb/source/Interpreter/CommandInterpreter.cpp (+34-10) - (modified) lldb/source/Target/Process.cpp (+6-1) - (modified) lldb/source/Target/Target.cpp (+16-1) - (modified) lldb/tools/lldb-dap/DAP.cpp (+13-5) ``````````diff diff --git a/lldb/include/lldb/API/SBDebugger.h b/lldb/include/lldb/API/SBDebugger.h index 62b2f91f5076d5..c4b51fc925f094 100644 --- a/lldb/include/lldb/API/SBDebugger.h +++ b/lldb/include/lldb/API/SBDebugger.h @@ -9,10 +9,12 @@ #ifndef LLDB_API_SBDEBUGGER_H #define LLDB_API_SBDEBUGGER_H +#include <chrono> #include <cstdio> #include "lldb/API/SBDefines.h" #include "lldb/API/SBPlatform.h" +#include "third_party/llvm/llvm-project/lldb/include/lldb/API/SBStructuredData.h" namespace lldb_private { class CommandPluginInterfaceImplementation; @@ -243,6 +245,8 @@ class LLDB_API SBDebugger { lldb::SBTarget GetDummyTarget(); + void SendTelemetry(SBStructuredData *entry); + // Return true if target is deleted from the target list of the debugger. bool DeleteTarget(lldb::SBTarget &target); diff --git a/lldb/include/lldb/Core/Debugger.h b/lldb/include/lldb/Core/Debugger.h index 418c2403d020f4..a3ecb7e4724374 100644 --- a/lldb/include/lldb/Core/Debugger.h +++ b/lldb/include/lldb/Core/Debugger.h @@ -19,6 +19,7 @@ #include "lldb/Core/FormatEntity.h" #include "lldb/Core/IOHandler.h" #include "lldb/Core/SourceManager.h" +#include "lldb/Core/Telemetry.h" #include "lldb/Core/UserSettingsController.h" #include "lldb/Host/HostThread.h" #include "lldb/Host/StreamFile.h" @@ -38,6 +39,7 @@ #include "lldb/lldb-private-enumerations.h" #include "lldb/lldb-private-types.h" #include "lldb/lldb-types.h" +#include "third_party/llvm/llvm-project/lldb/include/lldb/Utility/StructuredData.h" #include "llvm/ADT/ArrayRef.h" #include "llvm/ADT/StringMap.h" @@ -145,6 +147,12 @@ class Debugger : public std::enable_shared_from_this<Debugger>, lldb::StreamFileSP GetErrorStreamSP() { return m_error_stream_sp; } + std::shared_ptr<TelemetryLogger> GetTelemetryLogger() { + return m_telemetry_logger; + } + + void SendClientTelemetry(lldb_private::StructuredData::Object *entry); + File &GetInputFile() { return *m_input_file_sp; } File &GetOutputFile() { return m_output_stream_sp->GetFile(); } @@ -737,6 +745,7 @@ class Debugger : public std::enable_shared_from_this<Debugger>, uint32_t m_interrupt_requested = 0; ///< Tracks interrupt requests std::mutex m_interrupt_mutex; + std::shared_ptr<TelemetryLogger> m_telemetry_logger; // Events for m_sync_broadcaster enum { eBroadcastBitEventThreadIsListening = (1 << 0), @@ -749,6 +758,7 @@ class Debugger : public std::enable_shared_from_this<Debugger>, Debugger(const Debugger &) = delete; const Debugger &operator=(const Debugger &) = delete; + TelemetryEventStats stats; }; } // namespace lldb_private diff --git a/lldb/include/lldb/Core/Telemetry.h b/lldb/include/lldb/Core/Telemetry.h new file mode 100644 index 00000000000000..f021437772aa09 --- /dev/null +++ b/lldb/include/lldb/Core/Telemetry.h @@ -0,0 +1,237 @@ +#ifndef LLDB_CORE_TELEMETRY_H +#define LLDB_CORE_TELEMETRY_H + +#include <chrono> +#include <ctime> +#include <memory> +#include <optional> +#include <string> + +#include "lldb/Interpreter/CommandReturnObject.h" +#include "lldb/Utility/StructuredData.h" +#include "lldb/lldb-forward.h" +#include "llvm/ADT/StringExtras.h" +#include "llvm/ADT/StringRef.h" + +namespace lldb_private { + +using SteadyTimePoint = std::chrono::time_point<std::chrono::steady_clock>; + +struct TelemetryEventStats { + // REQUIRED: Start time of event + SteadyTimePoint m_start; + // OPTIONAL: End time of event - may be empty if not meaningful. + std::optional<SteadyTimePoint> m_end; + + // TBD: could add some memory stats here too? + + TelemetryEventStats() = default; + TelemetryEventStats(SteadyTimePoint start) : m_start(start) {} + TelemetryEventStats(SteadyTimePoint start, SteadyTimePoint end) + : m_start(start), m_end(end) {} + + std::optional<std::chrono::nanoseconds> Duration() const { + if (m_end.has_value()) + return *m_end - m_start; + else + return std::nullopt; + } +}; + +struct LoggerConfig { + // If true, loggings will be enabled. + bool enable_logging; + + // Additional destinations to send the logged entries. + // Could be stdout, stderr, or some local paths. + // Note: these are destinations are __in addition to__ whatever the default + // destination(s) are, as implemented by vendors. + std::vector<std::string> additional_destinations; +}; + +// The base class contains the basic set of data. +// Downstream implementations can add more fields as needed. +struct BaseTelemetryEntry { + // A "session" corresponds to every time lldb starts. + // All entries emitted for the same session will have + // the same session_uuid + std::string session_uuid; + + TelemetryEventStats stats; + + // Counting number of entries. + // (For each set of entries with the same session_uuid, this value should + // be unique for each entry) + size_t counter; + + virtual ~BaseTelemetryEntry() = default; + virtual std::string ToString() const; +}; + +struct ExitDescription { + int exit_code; + std::string description; +}; + +struct DebuggerInfoEntry : public BaseTelemetryEntry { + std::string username; + std::string lldb_git_sha; + std::string lldb_path; + std::string cwd; + + // The debugger exit info. Not populated if this entry was emitted for startup + // event. + std::optional<ExitDescription> lldb_exit; + + std::string ToString() const override; +}; + +struct TargetInfoEntry : public BaseTelemetryEntry { + // All entries emitted for the same SBTarget will have the same + // target_uuid. + std::string target_uuid; + std::string file_format; + + std::string binary_path; + size_t binary_size; + + // The process(target) exit info. Not populated of this entry was emitted for + // startup event. + std::optional<ExitDescription> process_exit; + + std::string ToString() const override; +}; + +// Entry from client (eg., SB-API) +struct ClientTelemetryEntry : public BaseTelemetryEntry { + std::string request_name; + std::string error_msg; + std::string ToString() const override; +}; + +struct CommandInfoEntry : public BaseTelemetryEntry { + // If the command is/can be associated with a target entry, + // this field contains that target's UUID. + // <EMPTY> otherwise. + std::string target_uuid; + std::string command_uuid; + + // Eg., "breakpoint set" + std::string command_name; + + // !!NOTE!!: The following fields may be omitted due to PII risk. + // (Configurable via the LoggerConfig struct) + std::string original_command; + std::string args; + + ExitDescription exit_description; + + std::string ToString() const override; +}; + +// The "catch-all" entry to store a set of custom/non-standard +// data. +struct MiscInfoEntry : public BaseTelemetryEntry { + // If the event is/can be associated with a target entry, + // this field contains that target's UUID. + // <EMPTY> otherwise. + std::string target_uuid; + + // Set of key-value pairs for any optional (or impl-specific) data + std::unordered_map<std::string, std::string> meta_data; + + std::string ToString() const override; +}; + +// Where/how to send the logged entries. +class TelemetryDestination { +public: + virtual ~TelemetryDestination() = default; + virtual Status EmitEntry(const BaseTelemetryEntry *entry) = 0; + virtual std::string name() const = 0; +}; + +// The logger itself! +class TelemetryLogger { +public: + static std::shared_ptr<TelemetryLogger> CreateInstance(Debugger *); + + virtual ~TelemetryLogger() = default; + + // Invoked upon lldb startup + virtual void LogStartup(llvm::StringRef lldb_path, + TelemetryEventStats stats) = 0; + + // Invoked upon lldb exit. + virtual void LogExit(llvm::StringRef lldb_path, + TelemetryEventStats stats) = 0; + + // Invoked upon process exit + virtual void LogProcessExit(int status, llvm::StringRef exit_string, + TelemetryEventStats stats, + Target *target_ptr) = 0; + + // Invoked upon loading the main executable module + // We log in a fire-n-forget fashion so that if the load + // crashes, we don't lose the entry. + virtual void LogMainExecutableLoadStart(lldb::ModuleSP exec_mod, + TelemetryEventStats stats) = 0; + virtual void LogMainExecutableLoadEnd(lldb::ModuleSP exec_mod, + TelemetryEventStats stats) = 0; + + // Invoked for each command + // We log in a fire-n-forget fashion so that if the command execution + // crashes, we don't lose the entry. + virtual void LogCommandStart(llvm::StringRef uuid, + llvm::StringRef original_command, + TelemetryEventStats stats, + Target *target_ptr) = 0; + virtual void LogCommandEnd(llvm::StringRef uuid, llvm::StringRef command_name, + llvm::StringRef command_args, + TelemetryEventStats stats, Target *target_ptr, + CommandReturnObject *result) = 0; + + virtual std::string GetNextUUID() = 0; + + // For client (eg., SB API) to send telemetry entries. + virtual void + LogClientTelemetry(lldb_private::StructuredData::Object *entry) = 0; + + virtual void AddDestination(TelemetryDestination *destination) = 0; +}; + +/* + +Logger configs: LLDB users can also supply their own configs via: +$XDG_CONFIG_HOME/.lldb_telemetry_config + + +We can propose simple syntax: <field_name><colon><value> +Eg., +enable_logging:true +destination:stdout +destination:stderr +destination:/path/to/some/file + +The allowed field_name values are: + * enable_logging + If the fields are specified more than once, the last line will take precedence + If enable_logging is set to false, no logging will occur. + * destination. + This is allowed to be specified multiple times - it will add to the default + (ie, specified by vendor) list of destinations. + The value can be either of + + one of the two magic values "stdout" or "stderr". + + a path to a local file + +!!NOTE!!: We decided to use a separate file instead of the existing settings + file because that file is parsed too late in the process and by the + there might have been lots of telemetry-entries that need to be + sent already. + This approach avoid losing log entries if LLDB crashes during init. + +*/ +LoggerConfig *GetLoggerConfig(); + +} // namespace lldb_private +#endif // LLDB_CORE_TELEMETRY_H diff --git a/lldb/include/lldb/Target/Process.h b/lldb/include/lldb/Target/Process.h index 2f3a3c22422efe..c9a7f3db2eb0bb 100644 --- a/lldb/include/lldb/Target/Process.h +++ b/lldb/include/lldb/Target/Process.h @@ -28,6 +28,7 @@ #include "lldb/Core/LoadedModuleInfoList.h" #include "lldb/Core/PluginInterface.h" #include "lldb/Core/SourceManager.h" +#include "lldb/Core/Telemetry.h" #include "lldb/Core/ThreadSafeValue.h" #include "lldb/Core/ThreadedCommunication.h" #include "lldb/Core/UserSettingsController.h" @@ -3249,6 +3250,8 @@ void PruneThreadPlans(); Process(const Process &) = delete; const Process &operator=(const Process &) = delete; + + TelemetryEventStats m_event_stats; }; /// RAII guard that should be acquired when an utility function is called within diff --git a/lldb/source/API/SBDebugger.cpp b/lldb/source/API/SBDebugger.cpp index fbcf30e67fc1cd..6078ab59a20afc 100644 --- a/lldb/source/API/SBDebugger.cpp +++ b/lldb/source/API/SBDebugger.cpp @@ -34,6 +34,7 @@ #include "lldb/API/SBTypeNameSpecifier.h" #include "lldb/API/SBTypeSummary.h" #include "lldb/API/SBTypeSynthetic.h" +#include <iostream> #include "lldb/Core/Debugger.h" #include "lldb/Core/DebuggerEvents.h" @@ -965,6 +966,14 @@ SBTarget SBDebugger::GetDummyTarget() { return sb_target; } +void SBDebugger::SendTelemetry(SBStructuredData *entry) { + if (lldb_private::Debugger *debugger = this->get()) { + debugger->SendClientTelemetry(entry->m_impl_up->GetObjectSP().get()); + } else { + std::cerr << " --- cannot log dap request - debugger is null\n"; + } +} + bool SBDebugger::DeleteTarget(lldb::SBTarget &target) { LLDB_INSTRUMENT_VA(this, target); diff --git a/lldb/source/Core/CMakeLists.txt b/lldb/source/Core/CMakeLists.txt index 10525ac39e6ef5..4ce9e5d81679f5 100644 --- a/lldb/source/Core/CMakeLists.txt +++ b/lldb/source/Core/CMakeLists.txt @@ -54,6 +54,7 @@ add_lldb_library(lldbCore SourceLocationSpec.cpp SourceManager.cpp StreamAsynchronousIO.cpp + Telemetry.cpp ThreadedCommunication.cpp UserSettingsController.cpp Value.cpp diff --git a/lldb/source/Core/Debugger.cpp b/lldb/source/Core/Debugger.cpp index ebd112110e5f2d..929b22e1df311d 100644 --- a/lldb/source/Core/Debugger.cpp +++ b/lldb/source/Core/Debugger.cpp @@ -17,6 +17,7 @@ #include "lldb/Core/PluginManager.h" #include "lldb/Core/Progress.h" #include "lldb/Core/StreamAsynchronousIO.h" +#include "lldb/Core/Telemetry.h" #include "lldb/DataFormatters/DataVisualization.h" #include "lldb/Expression/REPL.h" #include "lldb/Host/File.h" @@ -733,12 +734,23 @@ void Debugger::InstanceInitialize() { DebuggerSP Debugger::CreateInstance(lldb::LogOutputCallback log_callback, void *baton) { + SteadyTimePoint start_time = std::chrono::steady_clock::now(); DebuggerSP debugger_sp(new Debugger(log_callback, baton)); + debugger_sp->stats.m_start = start_time; if (g_debugger_list_ptr && g_debugger_list_mutex_ptr) { std::lock_guard<std::recursive_mutex> guard(*g_debugger_list_mutex_ptr); g_debugger_list_ptr->push_back(debugger_sp); } debugger_sp->InstanceInitialize(); + TelemetryEventStats init_stats(start_time, std::chrono::steady_clock::now()); + + // TODO: we could split up the logging: + // - LogStartup_start: called at the beginning + // - LogStartup_end: called at the end + // This way if the init crashes, we still have some logging. + debugger_sp->m_telemetry_logger->LogStartup( + HostInfo::GetProgramFileSpec().GetPathAsConstString().GetCString(), + std::move(init_stats)); return debugger_sp; } @@ -847,7 +859,8 @@ Debugger::Debugger(lldb::LogOutputCallback log_callback, void *baton) m_sync_broadcaster(nullptr, "lldb.debugger.sync"), m_broadcaster(m_broadcaster_manager_sp, GetStaticBroadcasterClass().AsCString()), - m_forward_listener_sp(), m_clear_once() { + m_forward_listener_sp(), m_clear_once(), + m_telemetry_logger(TelemetryLogger::CreateInstance(this)) { // Initialize the debugger properties as early as possible as other parts of // LLDB will start querying them during construction. m_collection_sp->Initialize(g_debugger_properties); @@ -939,6 +952,18 @@ void Debugger::Clear() { // static void Debugger::Destroy(lldb::DebuggerSP &debugger_sp); // static void Debugger::Terminate(); llvm::call_once(m_clear_once, [this]() { + // Log the "quit" event. + // Note: this session_stats include the time since LLDB starts till quit + // (now). + // TBD: we could also record stats for *just* the quit action, if needed? + // (ie., how long it takes to run all these cleanup functions?) + TelemetryEventStats session_stats{ + /*start_session*/ stats.m_start, + /*end_session*/ std::chrono::steady_clock::now()}; + m_telemetry_logger->LogExit( + HostInfo::GetProgramFileSpec().GetPathAsConstString().GetCString(), + session_stats); + ClearIOHandlers(); StopIOHandlerThread(); StopEventHandlerThread(); @@ -2198,6 +2223,11 @@ Status Debugger::RunREPL(LanguageType language, const char *repl_options) { return err; } +void Debugger::SendClientTelemetry( + lldb_private::StructuredData::Object *entry) { + m_telemetry_logger->LogClientTelemetry(entry); +} + llvm::ThreadPoolInterface &Debugger::GetThreadPool() { assert(g_thread_pool && "Debugger::GetThreadPool called before Debugger::Initialize"); diff --git a/lldb/source/Core/Telemetry.cpp b/lldb/source/Core/Telemetry.cpp new file mode 100644 index 00000000000000..2f8bca1da582b8 --- /dev/null +++ b/lldb/source/Core/Telemetry.cpp @@ -0,0 +1,620 @@ + +//===-- Telemetry.cpp -----------------------------------------------------===// +// +// Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions. +// See https://llvm.org/LICENSE.txt for license information. +// SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception +// +//===----------------------------------------------------------------------===// +#include "lldb/Core/Telemetry.h" + +#include <memory> +#include <stdbool.h> +#include <sys/auxv.h> + +#include <chrono> +#include <cstdlib> +#include <ctime> +#include <fstream> +#include <iostream> +#include <string> +#include <typeinfo> +#include <utility> +#include <vector> + +#include "lldb/API/SBDebugger.h" +#include "lldb/API/SBProcess.h" +#include "lldb/Core/Debugger.h" +#include "lldb/Core/Module.h" +#include "lldb/Host/FileSystem.h" +#include "lldb/Host/HostInfo.h" +#include "lldb/Interpreter/CommandInterpreter.h" +#include "lldb/Target/Process.h" +#include "lldb/Target/Statistics.h" +#include "lldb/Utility/ConstString.h" +#include "lldb/Utility/FileSpec.h" +#include "lldb/Utility/UUID.h" +#include "lldb/Version/Version.h" +#include "lldb/lldb-enumerations.h" +#include "lldb/lldb-forward.h" +#include "third_party/llvm/llvm-project/llvm/include/llvm/ADT/StringRef.h" +#include "llvm/ADT/SmallString.h" +#include "llvm/ADT/Twine.h" +#include "llvm/Support/Chrono.h" +#include "llvm/Support/FileSystem.h" +#include "llvm/Support/LineIterator.h" +#include "llvm/Support/MemoryBuffer.h" +#include "llvm/Support/Path.h" +#include "llvm/Support/RandomNumberGenerator.h" + +#include "clang/Basic/Version.h" + +namespace lldb_private { + +std::string BaseTelemetryEntry::ToString() const { + return "[BaseTelemetryEntry]\n" + (" session_uuid:" + session_uuid + "\n") + + (" start timestamp: " + + std::to_string(stats.m_start.time_since_epoch().count()) + "\n") + + (" counter: " + std::to_string(counter)); +} + +std::string DebuggerInfoEntry::ToString() const { + auto duration = stats.Duration(); + return BaseTelemetryEntry::ToString() + "\n" + ("[DebuggerInfoEntry]\n") + + (" username: " + username + "\n") + + (" lldb_git_sha: " + lldb_git_sha + "\n") + + (" lldb_path: " + lldb_path + "\n") + (" cwd: " + cwd + "\n") + + (" lldb startup/session duration: " + + (duration.has_value() ? std::to_string(duration->count()) + : "<empty>") + + "(nanosec)\n") + + (lldb_exit.has_value() + ? ("lldb_exit_code: " + std::to_string(lldb_exit->exit_code) + + ", lldb_exit_description: " + lldb_exit->description + "\n ") + : ("")); +} + +std::string ClientTelemetryEntry::ToString() const { + return BaseTelemetryEntry::ToString() + "\n" + ("[DapRequestInfoEntry]\n") + + (" request_name: " + request_name + "\n") + + (" request_duration: " + std::to_string(stats.Duration()->count()) + + "(nanosec)\n") + + (" error_msg: " + error_msg + "\n"); +} + +std::string TargetInfoEntry::ToString() const { + std::string exit_or_load_desc; + if (process_exit.has_value()) { + // If this entry was emitted for an exit + exit_or_load_desc = + " process_duration: " + std::to_string(stats.Duration()->count()) + + "(nanosec)" + + "\n" + " exit_code: " + + std::to_string(process_exit->exit_code) + + ", exit description: " + process_exit->description + "\n"; + } else { + // This was emitted for a load event. + // See if it was the start-load or end-load entry + if (stats.m_end.has_value()) { + exit_or_load_desc = " startup_init_duration: " + + std::to_string(stats.Duration()->count()) + + "(nanosec)" + "\n"; + } else { + exit_or_load_desc = " startup_init_start\n"; + } + } + return BaseTelemetryEntry::ToString() + "\n" + ("[TargetInfoEntry]\n") + + (" target_uuid: " + target_uuid + "\n") + + (" file_format: " + file_format + "\n") + + (" binary_path: " + binary_path + "\n") + + (" binary_size: " + std::to_string(binary_size) + "\n") + + exit_or_load_desc;... [truncated] `````````` </details> https://github.com/llvm/llvm-project/pull/87815 _______________________________________________ lldb-commits mailing list lldb-commits@lists.llvm.org https://lists.llvm.org/cgi-bin/mailman/listinfo/lldb-commits
