https://github.com/oontvoo updated https://github.com/llvm/llvm-project/pull/87815
>From cdee622a6646ba5c16a3c8156a5a50a938a14b57 Mon Sep 17 00:00:00 2001 From: Vy Nguyen <v...@google.com> Date: Fri, 5 Apr 2024 14:14:30 -0400 Subject: [PATCH 1/3] [lldb]POC implementation for telemetry in LLDB --- lldb/include/lldb/API/SBDebugger.h | 4 + lldb/include/lldb/Core/Debugger.h | 10 + lldb/include/lldb/Core/Telemetry.h | 206 ++++++ lldb/include/lldb/Target/Process.h | 3 + lldb/source/API/SBDebugger.cpp | 9 + lldb/source/Core/CMakeLists.txt | 1 + lldb/source/Core/Debugger.cpp | 32 +- lldb/source/Core/Telemetry.cpp | 620 ++++++++++++++++++ .../source/Interpreter/CommandInterpreter.cpp | 44 +- lldb/source/Target/Process.cpp | 7 +- lldb/source/Target/Target.cpp | 17 +- lldb/tools/lldb-dap/DAP.cpp | 18 +- 12 files changed, 953 insertions(+), 18 deletions(-) create mode 100644 lldb/include/lldb/Core/Telemetry.h create mode 100644 lldb/source/Core/Telemetry.cpp diff --git a/lldb/include/lldb/API/SBDebugger.h b/lldb/include/lldb/API/SBDebugger.h index 62b2f91f5076d..c4b51fc925f09 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 418c2403d020f..a3ecb7e472437 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 0000000000000..1c7b030bb2a49 --- /dev/null +++ b/lldb/include/lldb/Core/Telemetry.h @@ -0,0 +1,206 @@ +#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; +}; + +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 2f3a3c22422ef..c9a7f3db2eb0b 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 fbcf30e67fc1c..6078ab59a20af 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 10525ac39e6ef..4ce9e5d81679f 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 ebd112110e5f2..929b22e1df311 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 0000000000000..2f8bca1da582b --- /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; +} + +static std::string StatusToString(CommandReturnObject *result) { + // TODO: surely there's a better way to translate status to text??? + std::string msg; + switch (result->GetStatus()) { + case lldb::eReturnStatusInvalid: + msg = "invalid"; + break; + case lldb::eReturnStatusSuccessFinishNoResult: + msg = "success_finish_no_result"; + break; + case lldb::eReturnStatusSuccessFinishResult: + msg = "success_finish_result"; + break; + case lldb::eReturnStatusSuccessContinuingNoResult: + msg = "success_continuing_no_result"; + break; + case lldb::eReturnStatusSuccessContinuingResult: + msg = "success_continuing_result"; + break; + case lldb::eReturnStatusStarted: + msg = "started"; + break; + case lldb::eReturnStatusFailed: + msg = "failed"; + break; + case lldb::eReturnStatusQuit: + msg = "quit"; + break; + } + if (llvm::StringRef error_data = result->GetErrorData(); + !error_data.empty()) { + msg += " Error msg: " + error_data.str(); + } + return msg; +} + +std::string CommandInfoEntry::ToString() const { + // Whether this entry was emitted at the start or at the end of the + // command-execution. + if (stats.m_end.has_value()) { + return BaseTelemetryEntry::ToString() + "\n" + + ("[CommandInfoEntry] - END\n") + + (" target_uuid: " + target_uuid + "\n") + + (" command_uuid: " + command_uuid + "\n") + + (" command_name: " + command_name + "\n") + + (" args: " + args + "\n") + + (" command_runtime: " + std::to_string(stats.Duration()->count()) + + "(nanosec)\n") + + (" exit_code: " + std::to_string(exit_description.exit_code) + + ", exit description: " + exit_description.description + "\n"); + } else { + // NOt going to have much info at the beginning. + return BaseTelemetryEntry::ToString() + "\n" + + ("[CommandInfoEntry] - START\n") + + (" target_uuid: " + target_uuid + "\n") + + (" command_uuid: " + command_uuid + "\n") + + (" original_command: " + original_command + "\n"); + } +} + +std::string MiscInfoEntry::ToString() const { + std::string ret = + BaseTelemetryEntry::ToString() + "\n" + ("[MiscInfoEntry]\n") + + (" target_uuid: " + target_uuid + "\n") + (" meta_data:\n"); + + for (const auto &kv : meta_data) { + ret += (" " + kv.first + ": " + kv.second + "\n"); + } + return ret; +} + +class StreamTelemetryDestination : public TelemetryDestination { +public: + StreamTelemetryDestination(std::ostream &os, std::string desc, + bool omit_sensitive_fields) + : os(os), desc(desc), omit_sensitive_fields(omit_sensitive_fields) {} + Status EmitEntry(const lldb_private::BaseTelemetryEntry *entry) override { + Status ret_status; + if (omit_sensitive_fields) { + // clean up the data before logging + // TODO: clean up the data before logging + os << entry->ToString() << "\n"; + } else { + os << entry->ToString() << "\n"; + } + os.flush(); + return ret_status; + } + + std::string name() const override { return desc; } + +private: + std::ostream &os; + const std::string desc; + const bool omit_sensitive_fields; +}; + +// No-op logger to use when users disable logging. +class NoOpTelemetryLogger : public TelemetryLogger { +public: + static std::shared_ptr<TelemetryLogger> CreateInstance(Debugger *debugger) { + static std::shared_ptr<TelemetryLogger> ins( + new NoOpTelemetryLogger(debugger)); + return ins; + } + + NoOpTelemetryLogger(Debugger *debugger) {} + void LogStartup(llvm::StringRef lldb_path, + TelemetryEventStats stats) override {} + void LogExit(llvm::StringRef lldb_path, TelemetryEventStats stats) override {} + void LogProcessExit(int status, llvm::StringRef exit_string, + TelemetryEventStats stats, Target *target_ptr) override {} + void LogMainExecutableLoadStart(lldb::ModuleSP exec_mod, + TelemetryEventStats stats) override {} + void LogMainExecutableLoadEnd(lldb::ModuleSP exec_mod, + TelemetryEventStats stats) override {} + + void LogCommandStart(llvm::StringRef uuid, llvm::StringRef original_command, + TelemetryEventStats stats, Target *target_ptr) override { + } + void LogCommandEnd(llvm::StringRef uuid, llvm::StringRef command_name, + llvm::StringRef command_args, TelemetryEventStats stats, + Target *target_ptr, CommandReturnObject *result) override { + } + + void + LogClientTelemetry(lldb_private::StructuredData::Object *entry) override {} + + void AddDestination(TelemetryDestination *destination) override {} + std::string GetNextUUID() override { return ""; } +}; + +class BasicTelemetryLogger : public TelemetryLogger { +public: + static std::shared_ptr<TelemetryLogger> CreateInstance(Debugger *); + + virtual ~BasicTelemetryLogger() = default; + + void LogStartup(llvm::StringRef lldb_path, + TelemetryEventStats stats) override; + void LogExit(llvm::StringRef lldb_path, TelemetryEventStats stats) override; + void LogProcessExit(int status, llvm::StringRef exit_string, + TelemetryEventStats stats, Target *target_ptr) override; + void LogMainExecutableLoadStart(lldb::ModuleSP exec_mod, + TelemetryEventStats stats) override; + void LogMainExecutableLoadEnd(lldb::ModuleSP exec_mod, + TelemetryEventStats stats) override; + + void LogCommandStart(llvm::StringRef uuid, llvm::StringRef original_command, + TelemetryEventStats stats, Target *target_ptr) override; + void LogCommandEnd(llvm::StringRef uuid, llvm::StringRef command_name, + llvm::StringRef command_args, TelemetryEventStats stats, + Target *target_ptr, CommandReturnObject *result) override; + + void LogClientTelemetry(lldb_private::StructuredData::Object *entry) override; + + void AddDestination(TelemetryDestination *destination) override { + m_destinations.push_back(destination); + } + + std::string GetNextUUID() override { + return std::to_string(uuid_seed.fetch_add(1)); + } + +protected: + BasicTelemetryLogger(Debugger *debugger); + + void CollectMiscBuildInfo(); + +private: + template <typename EntrySubType> EntrySubType MakeBaseEntry() { + EntrySubType entry; + entry.session_uuid = m_session_uuid; + entry.counter = counter.fetch_add(1); + return entry; + } + + void EmitToDestinations(const BaseTelemetryEntry *entry); + + Debugger *m_debugger; + const std::string m_session_uuid; + std::string startup_lldb_path; + + // counting number of entries. + std::atomic<size_t> counter = 0; + + std::vector<TelemetryDestination *> m_destinations; + + std::atomic<size_t> uuid_seed = 0; +}; + +static std::string MakeUUID(lldb_private::Debugger *debugger) { + std::string ret; + uint8_t random_bytes[16]; + if (auto ec = llvm::getRandomBytes(random_bytes, 16)) { + std::cerr << "entropy source failure: " + ec.message(); + // fallback to using timestamp + debugger ID. + ret = std::to_string( + std::chrono::steady_clock::now().time_since_epoch().count()) + + "_" + std::to_string(debugger->GetID()); + } else { + ret = lldb_private::UUID(random_bytes).GetAsString(); + } + + return ret; +} +BasicTelemetryLogger::BasicTelemetryLogger(lldb_private::Debugger *debugger) + : m_debugger(debugger), m_session_uuid(MakeUUID(debugger)) {} + +std::shared_ptr<TelemetryLogger> +BasicTelemetryLogger::CreateInstance(lldb_private::Debugger *debugger) { + auto *config = GetLoggerConfig(); + assert(config->enable_logging); + + BasicTelemetryLogger *ins = new BasicTelemetryLogger(debugger); + + // TODO: configure which destination(s) to use here. + for (const std ::string &dest : config->additional_destinations) { + if (dest == "stdout") { + ins->AddDestination( + new StreamTelemetryDestination(std::cout, "stdout", true)); + } else if (dest == "stderr") { + ins->AddDestination( + new StreamTelemetryDestination(std::cerr, "stderr", true)); + } else { + // TODO: handle file paths + } + } + + return std::shared_ptr<BasicTelemetryLogger>(ins); +} + +void BasicTelemetryLogger::EmitToDestinations( + const lldb_private::BaseTelemetryEntry *entry) { + // TODO: can do this in a separate thread (need to own the ptrs!). + for (auto destination : m_destinations) { + destination->EmitEntry(entry); + } +} + +void BasicTelemetryLogger::LogStartup(llvm::StringRef lldb_path, + TelemetryEventStats stats) { + std::cout << "debugger starting up\n"; + + startup_lldb_path = lldb_path.str(); + lldb_private::DebuggerInfoEntry startup_info = + MakeBaseEntry<lldb_private::DebuggerInfoEntry>(); + + auto &resolver = lldb_private::HostInfo::GetUserIDResolver(); + auto opt_username = resolver.GetUserName(lldb_private::HostInfo::GetUserID()); + if (opt_username) + startup_info.username = *opt_username; + + startup_info.lldb_git_sha = lldb_private::GetVersion(); // TODO: fix this + startup_info.lldb_path = startup_lldb_path; + startup_info.stats = stats; + + llvm::SmallString<64> cwd; + if (!llvm::sys::fs::current_path(cwd)) { + startup_info.cwd = cwd.c_str(); + } else { + MiscInfoEntry misc_info = MakeBaseEntry<MiscInfoEntry>(); + misc_info.meta_data["internal_errors"] = "Cannot determine CWD"; + EmitToDestinations(&misc_info); + } + + std::cout << "emitting startup info\n"; + EmitToDestinations(&startup_info); + + // OPtional part + CollectMiscBuildInfo(); +} + +void BasicTelemetryLogger::LogProcessExit(int status, + llvm::StringRef exit_string, + TelemetryEventStats stats, + Target *target_ptr) { + lldb_private::TargetInfoEntry exit_info = + MakeBaseEntry<lldb_private::TargetInfoEntry>(); + exit_info.stats = stats; + exit_info.target_uuid = + target_ptr && !target_ptr->IsDummyTarget() + ? target_ptr->GetExecutableModule()->GetUUID().GetAsString() + : ""; + exit_info.process_exit = {status, exit_string.str()}; + + std::cout << "emitting process exit ...\n"; + EmitToDestinations(&exit_info); +} + +void BasicTelemetryLogger::LogExit(llvm::StringRef lldb_path, + TelemetryEventStats stats) { + std::cout << "debugger exiting at " << lldb_path.str() << "\n"; + // we should be shutting down the same instance that we started?! + assert(startup_lldb_path == lldb_path.str()); + + lldb_private::DebuggerInfoEntry exit_info = + MakeBaseEntry<lldb_private::DebuggerInfoEntry>(); + exit_info.stats = stats; + exit_info.lldb_path = startup_lldb_path; + if (auto *selected_target = + m_debugger->GetSelectedExecutionContext().GetTargetPtr()) { + if (!selected_target->IsDummyTarget()) { + const lldb::ProcessSP proc = selected_target->GetProcessSP(); + if (proc == nullptr) { + // no process has been launched yet. + exit_info.lldb_exit = {-1, "no process launched."}; + } else { + exit_info.lldb_exit = {proc->GetExitStatus(), ""}; + if (const char *description = proc->GetExitDescription()) + exit_info.lldb_exit->description = std::string(description); + } + } + } + EmitToDestinations(&exit_info); +} + +void BasicTelemetryLogger::CollectMiscBuildInfo() { + // collecting use-case specific data +} + +void BasicTelemetryLogger::LogMainExecutableLoadStart( + lldb::ModuleSP exec_mod, TelemetryEventStats stats) { + TargetInfoEntry target_info = MakeBaseEntry<TargetInfoEntry>(); + target_info.stats = std::move(stats); + target_info.binary_path = + exec_mod->GetFileSpec().GetPathAsConstString().GetCString(); + target_info.file_format = exec_mod->GetArchitecture().GetArchitectureName(); + target_info.target_uuid = exec_mod->GetUUID().GetAsString(); + if (auto err = llvm::sys::fs::file_size(exec_mod->GetFileSpec().GetPath(), + target_info.binary_size)) { + // If there was error obtaining it, just reset the size to 0. + // Maybe log the error too? + target_info.binary_size = 0; + } + EmitToDestinations(&target_info); +} + +void BasicTelemetryLogger::LogMainExecutableLoadEnd(lldb::ModuleSP exec_mod, + TelemetryEventStats stats) { + TargetInfoEntry target_info = MakeBaseEntry<TargetInfoEntry>(); + target_info.stats = std::move(stats); + target_info.binary_path = + exec_mod->GetFileSpec().GetPathAsConstString().GetCString(); + target_info.file_format = exec_mod->GetArchitecture().GetArchitectureName(); + target_info.target_uuid = exec_mod->GetUUID().GetAsString(); + if (auto err = llvm::sys::fs::file_size(exec_mod->GetFileSpec().GetPath(), + target_info.binary_size)) { + // If there was error obtaining it, just reset the size to 0. + // Maybe log the error too? + target_info.binary_size = 0; + } + EmitToDestinations(&target_info); + + // Collect some more info, might be useful? + MiscInfoEntry misc_info = MakeBaseEntry<MiscInfoEntry>(); + misc_info.target_uuid = exec_mod->GetUUID().GetAsString(); + misc_info.meta_data["symtab_index_time"] = + std::to_string(exec_mod->GetSymtabIndexTime().get().count()); + misc_info.meta_data["symtab_parse_time"] = + std::to_string(exec_mod->GetSymtabParseTime().get().count()); + EmitToDestinations(&misc_info); +} + +void BasicTelemetryLogger::LogClientTelemetry( + lldb_private::StructuredData::Object *entry) { + ClientTelemetryEntry data_entry = MakeBaseEntry<ClientTelemetryEntry>(); + auto *dictionary = entry->GetAsDictionary(); + llvm::StringRef request_name; + if (!dictionary->GetValueForKeyAsString("request_name", request_name, "")) { + MiscInfoEntry misc_info = MakeBaseEntry<MiscInfoEntry>(); + // TODO: log the entry too? + misc_info.meta_data["internal_errors"] = + "Cannot determine request name from client entry"; + EmitToDestinations(&misc_info); + return; + } + data_entry.request_name = request_name.str(); + + size_t start_time; + size_t end_time; + if (!dictionary->GetValueForKeyAsInteger("start_time", start_time) || + !dictionary->GetValueForKeyAsInteger("end_time", end_time)) { + MiscInfoEntry misc_info = MakeBaseEntry<MiscInfoEntry>(); + misc_info.meta_data["internal_errors"] = + "Cannot determine start/end time from client entry"; + EmitToDestinations(&misc_info); + return; + } + + std::chrono::nanoseconds start_time_nanos = + std::chrono::nanoseconds(start_time); + std::chrono::nanoseconds end_time_nanos = std::chrono::nanoseconds(end_time); + data_entry.stats.m_start = SteadyTimePoint(start_time_nanos); + data_entry.stats.m_end = SteadyTimePoint(end_time_nanos); + + EmitToDestinations(&data_entry); +} +void BasicTelemetryLogger::LogCommandStart(llvm::StringRef uuid, + llvm::StringRef original_command, + TelemetryEventStats stats, + Target *target_ptr) { + + lldb_private::CommandInfoEntry command_info = + MakeBaseEntry<lldb_private::CommandInfoEntry>(); + + // If we have a target attached to this command, then get the UUID. + command_info.target_uuid = ""; + if (target_ptr && target_ptr->GetExecutableModule() != nullptr) { + command_info.target_uuid = + target_ptr->GetExecutableModule()->GetUUID().GetAsString(); + } + command_info.command_uuid = uuid.str(); + command_info.original_command = original_command.str(); + command_info.stats = std::move(stats); + + EmitToDestinations(&command_info); +} + +void BasicTelemetryLogger::LogCommandEnd(llvm::StringRef uuid, + llvm::StringRef command_name, + llvm::StringRef command_args, + TelemetryEventStats stats, + Target *target_ptr, + CommandReturnObject *result) { + + lldb_private::CommandInfoEntry command_info = + MakeBaseEntry<lldb_private::CommandInfoEntry>(); + + // If we have a target attached to this command, then get the UUID. + command_info.target_uuid = ""; + if (target_ptr && target_ptr->GetExecutableModule() != nullptr) { + command_info.target_uuid = + target_ptr->GetExecutableModule()->GetUUID().GetAsString(); + } + command_info.command_uuid = uuid.str(); + + command_info.stats = std::move(stats); + command_info.exit_description = {result->Succeeded() ? 0 : -1, + StatusToString(result)}; + EmitToDestinations(&command_info); +} + +llvm::StringRef parse_value(llvm::StringRef str, llvm::StringRef label) { + return str.substr(label.size()).trim(); +} + +bool parse_field(llvm::StringRef str, llvm::StringRef label) { + if (parse_value(str, label) == "true") + return true; + return false; +} + +LoggerConfig *GetLoggerConfig() { + static lldb_private::LoggerConfig *config = []() { + bool enable_logging = true; + std::vector<std::string> additional_destinations; + + // TODO parse the $HOME/.lldb_telemetry_config file to populate the struct + llvm::SmallString<64> init_file; + FileSystem::Instance().GetHomeDirectory(init_file); + llvm::sys::path::append(init_file, ".lldb_telemetry_config"); + FileSystem::Instance().Resolve(init_file); + if (llvm::sys::fs::exists(init_file)) { + auto contents = llvm::MemoryBuffer::getFile(init_file, /*IsText*/ true); + if (contents) { + llvm::line_iterator iter = + llvm::line_iterator(contents->get()->getMemBufferRef()); + for (; !iter.is_at_eof(); ++iter) { + + if (iter->starts_with("enable_logging:")) { + enable_logging = parse_field(*iter, "enable_logging:"); + } else if (iter->starts_with("destination:")) { + llvm::StringRef dest = parse_value(*iter, "destination:"); + if (dest == "stdout") { + additional_destinations.push_back("stdout"); + } else if (dest == "stderr") { + additional_destinations.push_back("stderr"); + } else { + additional_destinations.push_back(dest.str()); + } + } + } + } + // TODO: maybe log that there's an issue reading the init-file? + } + + if (additional_destinations.empty()) + additional_destinations.push_back("stdout"); + auto *ret = + new lldb_private::LoggerConfig{enable_logging, additional_destinations}; + return ret; + }(); + return config; +} + +std::shared_ptr<TelemetryLogger> +TelemetryLogger::CreateInstance(lldb_private::Debugger *debugger) { + auto *config = GetLoggerConfig(); + if (!config->enable_logging) { + return NoOpTelemetryLogger::CreateInstance(debugger); + } + return BasicTelemetryLogger::CreateInstance(debugger); +} + +} // namespace lldb_private \ No newline at end of file diff --git a/lldb/source/Interpreter/CommandInterpreter.cpp b/lldb/source/Interpreter/CommandInterpreter.cpp index 8c3972a2ba4ce..c88fc703e82c6 100644 --- a/lldb/source/Interpreter/CommandInterpreter.cpp +++ b/lldb/source/Interpreter/CommandInterpreter.cpp @@ -6,11 +6,14 @@ // //===----------------------------------------------------------------------===// +#include <chrono> #include <cstdlib> +#include <iostream> #include <limits> #include <memory> #include <optional> #include <string> +#include <typeinfo> #include <vector> #include "Commands/CommandObjectApropos.h" @@ -53,7 +56,10 @@ #include "lldb/Utility/Stream.h" #include "lldb/Utility/Timer.h" +#include "lldb/Core/Telemetry.h" #include "lldb/Host/Config.h" +#include "lldb/Interpreter/CommandObject.h" + #if LLDB_ENABLE_LIBEDIT #include "lldb/Host/Editline.h" #endif @@ -1868,8 +1874,28 @@ bool CommandInterpreter::HandleCommand(const char *command_line, LazyBool lazy_add_to_history, CommandReturnObject &result, bool force_repeat_command) { + std::cout << "HandleCommand: " << command_line << "\n"; + TelemetryEventStats command_stats(std::chrono::steady_clock::now()); + auto logger = GetDebugger().GetTelemetryLogger(); + // Generate a UUID for this command so the logger can match + // the start/end entries correctly. + const std::string command_uuid = logger->GetNextUUID(); + + logger->LogCommandStart(command_uuid, command_line, command_stats, + GetExecutionContext().GetTargetPtr()); + std::string command_string(command_line); std::string original_command_string(command_line); + std::string parsed_command_args; + CommandObject *cmd_obj = nullptr; + + auto log_on_exit = llvm::make_scope_exit([&]() { + command_stats.m_end = std::chrono::steady_clock::now(); + llvm::StringRef command_name = cmd_obj ? cmd_obj->GetCommandName() : ""; + logger->LogCommandEnd(command_uuid, command_name, parsed_command_args, + command_stats, GetExecutionContext().GetTargetPtr(), + &result); + }); Log *log = GetLog(LLDBLog::Commands); llvm::PrettyStackTraceFormat stack_trace("HandleCommand(command = \"%s\")", @@ -1893,11 +1919,10 @@ bool CommandInterpreter::HandleCommand(const char *command_line, bool empty_command = false; bool comment_command = false; - if (command_string.empty()) + if (command_string.empty()) { empty_command = true; - else { + } else { const char *k_space_characters = "\t\n\v\f\r "; - size_t non_space = command_string.find_first_not_of(k_space_characters); // Check for empty line or comment line (lines whose first non-space // character is the comment character for this interpreter) @@ -1960,7 +1985,7 @@ bool CommandInterpreter::HandleCommand(const char *command_line, // From 1 above, we can determine whether the Execute function wants raw // input or not. - CommandObject *cmd_obj = ResolveCommandImpl(command_string, result); + cmd_obj = ResolveCommandImpl(command_string, result); // We have to preprocess the whole command string for Raw commands, since we // don't know the structure of the command. For parsed commands, we only @@ -2021,21 +2046,20 @@ bool CommandInterpreter::HandleCommand(const char *command_line, if (add_to_history) m_command_history.AppendString(original_command_string); - std::string remainder; const std::size_t actual_cmd_name_len = cmd_obj->GetCommandName().size(); if (actual_cmd_name_len < command_string.length()) - remainder = command_string.substr(actual_cmd_name_len); + parsed_command_args = command_string.substr(actual_cmd_name_len); // Remove any initial spaces - size_t pos = remainder.find_first_not_of(k_white_space); + size_t pos = parsed_command_args.find_first_not_of(k_white_space); if (pos != 0 && pos != std::string::npos) - remainder.erase(0, pos); + parsed_command_args.erase(0, pos); LLDB_LOGF( log, "HandleCommand, command line after removing command name(s): '%s'", - remainder.c_str()); + parsed_command_args.c_str()); - cmd_obj->Execute(remainder.c_str(), result); + cmd_obj->Execute(parsed_command_args.c_str(), result); } LLDB_LOGF(log, "HandleCommand, command %s", diff --git a/lldb/source/Target/Process.cpp b/lldb/source/Target/Process.cpp index f02ec37cb0f08..c3035eb936204 100644 --- a/lldb/source/Target/Process.cpp +++ b/lldb/source/Target/Process.cpp @@ -7,6 +7,7 @@ //===----------------------------------------------------------------------===// #include <atomic> +#include <chrono> #include <memory> #include <mutex> #include <optional> @@ -450,7 +451,8 @@ Process::Process(lldb::TargetSP target_sp, ListenerSP listener_sp, m_clear_thread_plans_on_stop(false), m_force_next_event_delivery(false), m_last_broadcast_state(eStateInvalid), m_destroy_in_process(false), m_can_interpret_function_calls(false), m_run_thread_plan_lock(), - m_can_jit(eCanJITDontKnow) { + m_can_jit(eCanJITDontKnow), + m_event_stats(std::chrono::steady_clock::now()) { CheckInWithManager(); Log *log = GetLog(LLDBLog::Object); @@ -1058,6 +1060,7 @@ bool Process::SetExitStatus(int status, llvm::StringRef exit_string) { // Use a mutex to protect setting the exit status. std::lock_guard<std::mutex> guard(m_exit_status_mutex); + m_event_stats.m_end = std::chrono::steady_clock::now(); Log *log(GetLog(LLDBLog::State | LLDBLog::Process)); LLDB_LOG(log, "(plugin = {0} status = {1} ({1:x8}), description=\"{2}\")", GetPluginName(), status, exit_string); @@ -1071,6 +1074,8 @@ bool Process::SetExitStatus(int status, llvm::StringRef exit_string) { GetPluginName()); return false; } + GetTarget().GetDebugger().GetTelemetryLogger()->LogProcessExit( + status, exit_string, m_event_stats, &GetTarget()); m_exit_status = status; if (!exit_string.empty()) diff --git a/lldb/source/Target/Target.cpp b/lldb/source/Target/Target.cpp index 09b0ac42631d1..a07c7a85ac818 100644 --- a/lldb/source/Target/Target.cpp +++ b/lldb/source/Target/Target.cpp @@ -24,6 +24,7 @@ #include "lldb/Core/Section.h" #include "lldb/Core/SourceManager.h" #include "lldb/Core/StructuredDataImpl.h" +#include "lldb/Core/Telemetry.h" #include "lldb/Core/ValueObject.h" #include "lldb/Core/ValueObjectConstResult.h" #include "lldb/Expression/DiagnosticManager.h" @@ -67,6 +68,7 @@ #include "llvm/ADT/ScopeExit.h" #include "llvm/ADT/SetVector.h" +#include <chrono> #include <memory> #include <mutex> #include <optional> @@ -1470,11 +1472,22 @@ void Target::DidExec() { void Target::SetExecutableModule(ModuleSP &executable_sp, LoadDependentFiles load_dependent_files) { + Log *log = GetLog(LLDBLog::Target); ClearModules(false); - if (executable_sp) { + TelemetryEventStats load_executable_stats(std::chrono::steady_clock::now()); + m_debugger.GetTelemetryLogger()->LogMainExecutableLoadStart( + executable_sp, load_executable_stats); + + auto log_on_exit = llvm::make_scope_exit([&]() { + load_executable_stats.m_end = std::chrono::steady_clock::now(); + m_debugger.GetTelemetryLogger()->LogMainExecutableLoadEnd( + executable_sp, load_executable_stats); + }); + ElapsedTime elapsed(m_stats.GetCreateTime()); + LLDB_SCOPED_TIMERF("Target::SetExecutableModule (executable = '%s')", executable_sp->GetFileSpec().GetPath().c_str()); @@ -1486,6 +1499,8 @@ void Target::SetExecutableModule(ModuleSP &executable_sp, // what we found in the executable module. if (!m_arch.GetSpec().IsValid()) { m_arch = executable_sp->GetArchitecture(); + // executable_sp->GetArchitecture().GetSpec().GetArchitectureName(); + // m_arch. LLDB_LOG(log, "Target::SetExecutableModule setting architecture to {0} ({1}) " "based on executable file", diff --git a/lldb/tools/lldb-dap/DAP.cpp b/lldb/tools/lldb-dap/DAP.cpp index b254ddfef0d5f..da7f3bc7cb8ff 100644 --- a/lldb/tools/lldb-dap/DAP.cpp +++ b/lldb/tools/lldb-dap/DAP.cpp @@ -6,17 +6,17 @@ // //===----------------------------------------------------------------------===// +#include "DAP.h" +#include "LLDBUtils.h" +#include "lldb/API/SBStructuredData.h" +#include "llvm/ADT/StringExtras.h" +#include "llvm/Support/FormatVariadic.h" #include <chrono> #include <cstdarg> #include <fstream> #include <mutex> #include <sstream> -#include "DAP.h" -#include "LLDBUtils.h" -#include "llvm/ADT/StringExtras.h" -#include "llvm/Support/FormatVariadic.h" - #if defined(_WIN32) #define NOMINMAX #include <fcntl.h> @@ -570,17 +570,25 @@ PacketStatus DAP::GetNextObject(llvm::json::Object &object) { } bool DAP::HandleObject(const llvm::json::Object &object) { + // auto start_time = std::chrono::steady_clock::now(); const auto packet_type = GetString(object, "type"); if (packet_type == "request") { const auto command = GetString(object, "command"); auto handler_pos = request_handlers.find(std::string(command)); if (handler_pos != request_handlers.end()) { handler_pos->second(object); + // auto end_time = std::chrono::steady_clock::now(); + // TODO: fill in the SBStructuredData and send it. + // debugger.SendTelemetry(...); return true; // Success } else { + // auto end_time = std::chrono::steady_clock::now(); if (log) *log << "error: unhandled command \"" << command.data() << "\"" << std::endl; + // auto end_time = std::chrono::steady_clock::now(); + // TODO: fill in the SBStructuredData and send it. + // debugger.SendTelemetry(...); return false; // Fail } } >From 7321a9073f1ec326f53ada9f40e258c038037af2 Mon Sep 17 00:00:00 2001 From: Vy Nguyen <v...@google.com> Date: Fri, 5 Apr 2024 14:28:40 -0400 Subject: [PATCH 2/3] more docs on config --- lldb/include/lldb/Core/Telemetry.h | 31 ++++++++++++++++++++++++++++++ 1 file changed, 31 insertions(+) diff --git a/lldb/include/lldb/Core/Telemetry.h b/lldb/include/lldb/Core/Telemetry.h index 1c7b030bb2a49..f021437772aa0 100644 --- a/lldb/include/lldb/Core/Telemetry.h +++ b/lldb/include/lldb/Core/Telemetry.h @@ -200,6 +200,37 @@ class TelemetryLogger { 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 >From f2d5dfebd1be5a71b03514c5f362ace429dff892 Mon Sep 17 00:00:00 2001 From: Vy Nguyen <v...@google.com> Date: Tue, 14 May 2024 15:50:14 -0400 Subject: [PATCH 3/3] refactor some common API to llvm/lib/Telelemtry --- lldb/include/lldb/API/SBDebugger.h | 2 +- lldb/include/lldb/Core/Debugger.h | 6 +- lldb/include/lldb/Core/Telemetry.h | 120 +++------------- lldb/source/API/SBDebugger.cpp | 2 +- lldb/source/Core/Debugger.cpp | 22 ++- lldb/source/Core/Telemetry.cpp | 177 +++++++++++------------- lldb/source/Target/Target.cpp | 2 - llvm/include/llvm/CMakeLists.txt | 1 + llvm/include/llvm/Telemetry/Telemetry.h | 101 ++++++++++++++ llvm/lib/CMakeLists.txt | 1 + llvm/lib/Telemetry/CMakeLists.txt | 6 + llvm/lib/Telemetry/Telemetry.cpp | 32 +++++ 12 files changed, 259 insertions(+), 213 deletions(-) create mode 100644 llvm/include/llvm/Telemetry/Telemetry.h create mode 100644 llvm/lib/Telemetry/CMakeLists.txt create mode 100644 llvm/lib/Telemetry/Telemetry.cpp diff --git a/lldb/include/lldb/API/SBDebugger.h b/lldb/include/lldb/API/SBDebugger.h index c4b51fc925f09..90bfcb8096df4 100644 --- a/lldb/include/lldb/API/SBDebugger.h +++ b/lldb/include/lldb/API/SBDebugger.h @@ -14,7 +14,7 @@ #include "lldb/API/SBDefines.h" #include "lldb/API/SBPlatform.h" -#include "third_party/llvm/llvm-project/lldb/include/lldb/API/SBStructuredData.h" +#include "lldb/API/SBStructuredData.h" namespace lldb_private { class CommandPluginInterfaceImplementation; diff --git a/lldb/include/lldb/Core/Debugger.h b/lldb/include/lldb/Core/Debugger.h index a3ecb7e472437..479eba1457fec 100644 --- a/lldb/include/lldb/Core/Debugger.h +++ b/lldb/include/lldb/Core/Debugger.h @@ -32,6 +32,7 @@ #include "lldb/Utility/Diagnostics.h" #include "lldb/Utility/FileSpec.h" #include "lldb/Utility/Status.h" +#include "lldb/Utility/StructuredData.h" #include "lldb/Utility/UserID.h" #include "lldb/lldb-defines.h" #include "lldb/lldb-enumerations.h" @@ -39,7 +40,6 @@ #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" @@ -147,7 +147,7 @@ class Debugger : public std::enable_shared_from_this<Debugger>, lldb::StreamFileSP GetErrorStreamSP() { return m_error_stream_sp; } - std::shared_ptr<TelemetryLogger> GetTelemetryLogger() { + std::shared_ptr<LldbTelemetryLogger> GetTelemetryLogger() { return m_telemetry_logger; } @@ -745,7 +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; + std::shared_ptr<LldbTelemetryLogger> m_telemetry_logger; // Events for m_sync_broadcaster enum { eBroadcastBitEventThreadIsListening = (1 << 0), diff --git a/lldb/include/lldb/Core/Telemetry.h b/lldb/include/lldb/Core/Telemetry.h index f021437772aa0..293c9a6175bbf 100644 --- a/lldb/include/lldb/Core/Telemetry.h +++ b/lldb/include/lldb/Core/Telemetry.h @@ -6,87 +6,29 @@ #include <memory> #include <optional> #include <string> +#include <unordered_map> #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" +#include "llvm/Telemetry/Telemetry.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; +using namespace llvm::telemetry; - virtual ~BaseTelemetryEntry() = default; - virtual std::string ToString() const; -}; - -struct ExitDescription { - int exit_code; - std::string description; -}; +namespace lldb_private { -struct DebuggerInfoEntry : public BaseTelemetryEntry { +struct DebuggerInfoEntry : public ::llvm::telemetry::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 { +struct TargetInfoEntry : public ::llvm::telemetry::BaseTelemetryEntry { // All entries emitted for the same SBTarget will have the same // target_uuid. std::string target_uuid; @@ -95,21 +37,17 @@ struct TargetInfoEntry : public BaseTelemetryEntry { 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 { +struct ClientTelemetryEntry : public ::llvm::telemetry::BaseTelemetryEntry { std::string request_name; std::string error_msg; std::string ToString() const override; }; -struct CommandInfoEntry : public BaseTelemetryEntry { +struct CommandInfoEntry : public ::llvm::telemetry::BaseTelemetryEntry { // If the command is/can be associated with a target entry, // this field contains that target's UUID. // <EMPTY> otherwise. @@ -124,14 +62,12 @@ struct CommandInfoEntry : public BaseTelemetryEntry { 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 { +struct MiscInfoEntry : public ::llvm::telemetry::BaseTelemetryEntry { // If the event is/can be associated with a target entry, // this field contains that target's UUID. // <EMPTY> otherwise. @@ -143,28 +79,16 @@ struct MiscInfoEntry : public BaseTelemetryEntry { 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 { +class LldbTelemetryLogger : public llvm::telemetry::BaseTelemetryLogger { public: - static std::shared_ptr<TelemetryLogger> CreateInstance(Debugger *); - - virtual ~TelemetryLogger() = default; + static std::shared_ptr<LldbTelemetryLogger> CreateInstance(Debugger *); - // Invoked upon lldb startup - virtual void LogStartup(llvm::StringRef lldb_path, - TelemetryEventStats stats) = 0; + virtual ~LldbTelemetryLogger() = default; - // Invoked upon lldb exit. - virtual void LogExit(llvm::StringRef lldb_path, - TelemetryEventStats stats) = 0; + // void LogStartup(llvm::StringRef lldb_path, + // BaseTelemetryEntry *entry) override; + // void LogExit(llvm::StringRef lldb_path, BaseTelemetryEntry *entry) + // override; // Invoked upon process exit virtual void LogProcessExit(int status, llvm::StringRef exit_string, @@ -196,8 +120,6 @@ class TelemetryLogger { // For client (eg., SB API) to send telemetry entries. virtual void LogClientTelemetry(lldb_private::StructuredData::Object *entry) = 0; - - virtual void AddDestination(TelemetryDestination *destination) = 0; }; /* @@ -215,12 +137,12 @@ 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. + 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 + 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 diff --git a/lldb/source/API/SBDebugger.cpp b/lldb/source/API/SBDebugger.cpp index 6078ab59a20af..086880978712a 100644 --- a/lldb/source/API/SBDebugger.cpp +++ b/lldb/source/API/SBDebugger.cpp @@ -970,7 +970,7 @@ 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"; + std::cerr << " --- cannot send telemetry entry - debugger is null\n"; } } diff --git a/lldb/source/Core/Debugger.cpp b/lldb/source/Core/Debugger.cpp index 929b22e1df311..8117e4d188e55 100644 --- a/lldb/source/Core/Debugger.cpp +++ b/lldb/source/Core/Debugger.cpp @@ -54,6 +54,8 @@ #include "lldb/Utility/Stream.h" #include "lldb/Utility/StreamString.h" #include "lldb/lldb-enumerations.h" +#include "llvm/Telemetry/Telemetry.h" +#include <chrono> #if defined(_WIN32) #include "lldb/Host/windows/PosixApi.h" @@ -743,14 +745,11 @@ DebuggerSP Debugger::CreateInstance(lldb::LogOutputCallback log_callback, } 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. + llvm::telemetry::BaseTelemetryEntry entry; + entry.stats = {start_time, std::chrono::steady_clock::now()}; debugger_sp->m_telemetry_logger->LogStartup( HostInfo::GetProgramFileSpec().GetPathAsConstString().GetCString(), - std::move(init_stats)); + &entry); return debugger_sp; } @@ -859,8 +858,7 @@ 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_telemetry_logger(TelemetryLogger::CreateInstance(this)) { + m_forward_listener_sp(), m_clear_once() { // 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); @@ -957,12 +955,12 @@ void Debugger::Clear() { // (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()}; + llvm::telemetry::BaseTelemetryEntry entry; + entry.stats = {/*start_session*/ stats.m_start, + /*end_session*/ std::chrono::steady_clock::now()}; m_telemetry_logger->LogExit( HostInfo::GetProgramFileSpec().GetPathAsConstString().GetCString(), - session_stats); + &entry); ClearIOHandlers(); StopIOHandlerThread(); diff --git a/lldb/source/Core/Telemetry.cpp b/lldb/source/Core/Telemetry.cpp index 2f8bca1da582b..940839cb3eb9a 100644 --- a/lldb/source/Core/Telemetry.cpp +++ b/lldb/source/Core/Telemetry.cpp @@ -8,10 +8,11 @@ //===----------------------------------------------------------------------===// #include "lldb/Core/Telemetry.h" -#include <memory> #include <stdbool.h> #include <sys/auxv.h> +#include <memory> + #include <chrono> #include <cstdlib> #include <ctime> @@ -37,69 +38,59 @@ #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/STLExtras.h" #include "llvm/ADT/SmallString.h" +#include "llvm/ADT/StringRef.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" +#include "llvm/Telemetry/Telemetry.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)); +static std::string GetDuration(const TelemetryEventStats &stats) { + if (stats.m_end.has_value()) + return std::to_string((stats.m_end.value() - stats.m_start).count()) + + "(nanosec)"; + return "<NONE>"; } std::string DebuggerInfoEntry::ToString() const { - auto duration = stats.Duration(); + std::string duration_desc = + (exit_description.has_value() ? " lldb session duration: " + : " lldb startup duration: ") + + std::to_string((stats.m_end.value() - stats.m_start).count()) + + "(nanosec)\n"; + 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 ") - : ("")); + duration_desc + "\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") + + (" request_duration: " + GetDuration(stats) + "(nanosec)\n") + (" error_msg: " + error_msg + "\n"); } std::string TargetInfoEntry::ToString() const { std::string exit_or_load_desc; - if (process_exit.has_value()) { + if (exit_description.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"; + exit_or_load_desc = " process_duration: " + GetDuration(stats) + + " exit: " + exit_description->ToString() + "\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"; + exit_or_load_desc = + " startup_init_duration: " + GetDuration(stats) + "\n"; } else { exit_or_load_desc = " startup_init_start\n"; } @@ -158,12 +149,11 @@ std::string CommandInfoEntry::ToString() const { (" command_uuid: " + command_uuid + "\n") + (" command_name: " + command_name + "\n") + (" args: " + args + "\n") + - (" command_runtime: " + std::to_string(stats.Duration()->count()) + - "(nanosec)\n") + - (" exit_code: " + std::to_string(exit_description.exit_code) + - ", exit description: " + exit_description.description + "\n"); + (" command_runtime: " + GetDuration(stats) + "\n") + + (exit_description.has_value() ? exit_description->ToString() + : "no exit-description") + + "\n"; } else { - // NOt going to have much info at the beginning. return BaseTelemetryEntry::ToString() + "\n" + ("[CommandInfoEntry] - START\n") + (" target_uuid: " + target_uuid + "\n") + @@ -188,8 +178,8 @@ class StreamTelemetryDestination : public TelemetryDestination { StreamTelemetryDestination(std::ostream &os, std::string desc, bool omit_sensitive_fields) : os(os), desc(desc), omit_sensitive_fields(omit_sensitive_fields) {} - Status EmitEntry(const lldb_private::BaseTelemetryEntry *entry) override { - Status ret_status; + llvm::Error EmitEntry(const BaseTelemetryEntry *entry) override { + llvm::Error ret_status = llvm::Error::success(); if (omit_sensitive_fields) { // clean up the data before logging // TODO: clean up the data before logging @@ -210,18 +200,19 @@ class StreamTelemetryDestination : public TelemetryDestination { }; // No-op logger to use when users disable logging. -class NoOpTelemetryLogger : public TelemetryLogger { +class NoOpTelemetryLogger : public LldbTelemetryLogger { public: - static std::shared_ptr<TelemetryLogger> CreateInstance(Debugger *debugger) { - static std::shared_ptr<TelemetryLogger> ins( + static std::shared_ptr<LldbTelemetryLogger> + CreateInstance(Debugger *debugger) { + static std::shared_ptr<LldbTelemetryLogger> ins( new NoOpTelemetryLogger(debugger)); return ins; } NoOpTelemetryLogger(Debugger *debugger) {} - void LogStartup(llvm::StringRef lldb_path, - TelemetryEventStats stats) override {} - void LogExit(llvm::StringRef lldb_path, TelemetryEventStats stats) override {} + void LogStartup(llvm::StringRef tool_path, + BaseTelemetryEntry *entry) override {} + void LogExit(llvm::StringRef tool_path, BaseTelemetryEntry *entry) override {} void LogProcessExit(int status, llvm::StringRef exit_string, TelemetryEventStats stats, Target *target_ptr) override {} void LogMainExecutableLoadStart(lldb::ModuleSP exec_mod, @@ -244,15 +235,16 @@ class NoOpTelemetryLogger : public TelemetryLogger { std::string GetNextUUID() override { return ""; } }; -class BasicTelemetryLogger : public TelemetryLogger { +class BasicTelemetryLogger : public LldbTelemetryLogger { public: - static std::shared_ptr<TelemetryLogger> CreateInstance(Debugger *); + static std::shared_ptr<BasicTelemetryLogger> CreateInstance(Debugger *); virtual ~BasicTelemetryLogger() = default; void LogStartup(llvm::StringRef lldb_path, - TelemetryEventStats stats) override; - void LogExit(llvm::StringRef lldb_path, TelemetryEventStats stats) override; + BaseTelemetryEntry *entry) override; + void LogExit(llvm::StringRef lldb_path, BaseTelemetryEntry *entry) override; + void LogProcessExit(int status, llvm::StringRef exit_string, TelemetryEventStats stats, Target *target_ptr) override; void LogMainExecutableLoadStart(lldb::ModuleSP exec_mod, @@ -318,13 +310,14 @@ static std::string MakeUUID(lldb_private::Debugger *debugger) { return ret; } + BasicTelemetryLogger::BasicTelemetryLogger(lldb_private::Debugger *debugger) : m_debugger(debugger), m_session_uuid(MakeUUID(debugger)) {} -std::shared_ptr<TelemetryLogger> +std::shared_ptr<BasicTelemetryLogger> BasicTelemetryLogger::CreateInstance(lldb_private::Debugger *debugger) { auto *config = GetLoggerConfig(); - assert(config->enable_logging); + // llvm::Assert(config->enable_logging); BasicTelemetryLogger *ins = new BasicTelemetryLogger(debugger); @@ -344,16 +337,18 @@ BasicTelemetryLogger::CreateInstance(lldb_private::Debugger *debugger) { return std::shared_ptr<BasicTelemetryLogger>(ins); } -void BasicTelemetryLogger::EmitToDestinations( - const lldb_private::BaseTelemetryEntry *entry) { +void BasicTelemetryLogger::EmitToDestinations(const BaseTelemetryEntry *entry) { // TODO: can do this in a separate thread (need to own the ptrs!). for (auto destination : m_destinations) { - destination->EmitEntry(entry); + if (auto err = destination->EmitEntry(entry); !err.success()) { + std::cerr << "error emitting to destination: " << destination->name() + << "\n"; + } } } void BasicTelemetryLogger::LogStartup(llvm::StringRef lldb_path, - TelemetryEventStats stats) { + BaseTelemetryEntry *entry) { std::cout << "debugger starting up\n"; startup_lldb_path = lldb_path.str(); @@ -367,7 +362,7 @@ void BasicTelemetryLogger::LogStartup(llvm::StringRef lldb_path, startup_info.lldb_git_sha = lldb_private::GetVersion(); // TODO: fix this startup_info.lldb_path = startup_lldb_path; - startup_info.stats = stats; + startup_info.stats = entry->stats; llvm::SmallString<64> cwd; if (!llvm::sys::fs::current_path(cwd)) { @@ -381,36 +376,19 @@ void BasicTelemetryLogger::LogStartup(llvm::StringRef lldb_path, std::cout << "emitting startup info\n"; EmitToDestinations(&startup_info); - // OPtional part + // Optional part CollectMiscBuildInfo(); } -void BasicTelemetryLogger::LogProcessExit(int status, - llvm::StringRef exit_string, - TelemetryEventStats stats, - Target *target_ptr) { - lldb_private::TargetInfoEntry exit_info = - MakeBaseEntry<lldb_private::TargetInfoEntry>(); - exit_info.stats = stats; - exit_info.target_uuid = - target_ptr && !target_ptr->IsDummyTarget() - ? target_ptr->GetExecutableModule()->GetUUID().GetAsString() - : ""; - exit_info.process_exit = {status, exit_string.str()}; - - std::cout << "emitting process exit ...\n"; - EmitToDestinations(&exit_info); -} - void BasicTelemetryLogger::LogExit(llvm::StringRef lldb_path, - TelemetryEventStats stats) { + BaseTelemetryEntry *entry) { std::cout << "debugger exiting at " << lldb_path.str() << "\n"; // we should be shutting down the same instance that we started?! - assert(startup_lldb_path == lldb_path.str()); + // llvm::Assert(startup_lldb_path == lldb_path.str()); lldb_private::DebuggerInfoEntry exit_info = MakeBaseEntry<lldb_private::DebuggerInfoEntry>(); - exit_info.stats = stats; + exit_info.stats = entry->stats; exit_info.lldb_path = startup_lldb_path; if (auto *selected_target = m_debugger->GetSelectedExecutionContext().GetTargetPtr()) { @@ -418,17 +396,34 @@ void BasicTelemetryLogger::LogExit(llvm::StringRef lldb_path, const lldb::ProcessSP proc = selected_target->GetProcessSP(); if (proc == nullptr) { // no process has been launched yet. - exit_info.lldb_exit = {-1, "no process launched."}; + exit_info.exit_description = {-1, "no process launched."}; } else { - exit_info.lldb_exit = {proc->GetExitStatus(), ""}; + exit_info.exit_description = {proc->GetExitStatus(), ""}; if (const char *description = proc->GetExitDescription()) - exit_info.lldb_exit->description = std::string(description); + exit_info.exit_description->description = std::string(description); } } } EmitToDestinations(&exit_info); } +void BasicTelemetryLogger::LogProcessExit(int status, + llvm::StringRef exit_string, + TelemetryEventStats stats, + Target *target_ptr) { + lldb_private::TargetInfoEntry exit_info = + MakeBaseEntry<lldb_private::TargetInfoEntry>(); + exit_info.stats = stats; + exit_info.target_uuid = + target_ptr && !target_ptr->IsDummyTarget() + ? target_ptr->GetExecutableModule()->GetUUID().GetAsString() + : ""; + exit_info.exit_description = {status, exit_string.str()}; + + std::cout << "emitting process exit ...\n"; + EmitToDestinations(&exit_info); +} + void BasicTelemetryLogger::CollectMiscBuildInfo() { // collecting use-case specific data } @@ -501,15 +496,8 @@ void BasicTelemetryLogger::LogClientTelemetry( EmitToDestinations(&misc_info); return; } - - std::chrono::nanoseconds start_time_nanos = - std::chrono::nanoseconds(start_time); - std::chrono::nanoseconds end_time_nanos = std::chrono::nanoseconds(end_time); - data_entry.stats.m_start = SteadyTimePoint(start_time_nanos); - data_entry.stats.m_end = SteadyTimePoint(end_time_nanos); - - EmitToDestinations(&data_entry); } + void BasicTelemetryLogger::LogCommandStart(llvm::StringRef uuid, llvm::StringRef original_command, TelemetryEventStats stats, @@ -565,8 +553,8 @@ bool parse_field(llvm::StringRef str, llvm::StringRef label) { return false; } -LoggerConfig *GetLoggerConfig() { - static lldb_private::LoggerConfig *config = []() { +llvm::telemetry::LoggerConfig *GetLoggerConfig() { + static llvm::telemetry::LoggerConfig *config = []() { bool enable_logging = true; std::vector<std::string> additional_destinations; @@ -601,20 +589,19 @@ LoggerConfig *GetLoggerConfig() { if (additional_destinations.empty()) additional_destinations.push_back("stdout"); - auto *ret = - new lldb_private::LoggerConfig{enable_logging, additional_destinations}; + auto *ret = new llvm::telemetry::LoggerConfig{enable_logging, + additional_destinations}; return ret; }(); return config; } -std::shared_ptr<TelemetryLogger> -TelemetryLogger::CreateInstance(lldb_private::Debugger *debugger) { +std::shared_ptr<LldbTelemetryLogger> +LldbTelemetryLogger::CreateInstance(lldb_private::Debugger *debugger) { auto *config = GetLoggerConfig(); if (!config->enable_logging) { return NoOpTelemetryLogger::CreateInstance(debugger); } return BasicTelemetryLogger::CreateInstance(debugger); } - } // namespace lldb_private \ No newline at end of file diff --git a/lldb/source/Target/Target.cpp b/lldb/source/Target/Target.cpp index a07c7a85ac818..73eeb10464748 100644 --- a/lldb/source/Target/Target.cpp +++ b/lldb/source/Target/Target.cpp @@ -1499,8 +1499,6 @@ void Target::SetExecutableModule(ModuleSP &executable_sp, // what we found in the executable module. if (!m_arch.GetSpec().IsValid()) { m_arch = executable_sp->GetArchitecture(); - // executable_sp->GetArchitecture().GetSpec().GetArchitectureName(); - // m_arch. LLDB_LOG(log, "Target::SetExecutableModule setting architecture to {0} ({1}) " "based on executable file", diff --git a/llvm/include/llvm/CMakeLists.txt b/llvm/include/llvm/CMakeLists.txt index ac6b96a68ab92..5f96431bba8b4 100644 --- a/llvm/include/llvm/CMakeLists.txt +++ b/llvm/include/llvm/CMakeLists.txt @@ -7,3 +7,4 @@ add_subdirectory(IR) add_subdirectory(Support) add_subdirectory(Frontend) add_subdirectory(TargetParser) +add_subdirectory(Telemetry) diff --git a/llvm/include/llvm/Telemetry/Telemetry.h b/llvm/include/llvm/Telemetry/Telemetry.h new file mode 100644 index 0000000000000..7990821d57ae0 --- /dev/null +++ b/llvm/include/llvm/Telemetry/Telemetry.h @@ -0,0 +1,101 @@ +#ifndef LVM_TELEMETRY_TELEMETRY_H +#define LVM_TELEMETRY_TELEMETRY_H + +#include <chrono> +#include <ctime> +#include <memory> +#include <optional> +#include <string> + +#include "llvm/ADT/StringExtras.h" +#include "llvm/ADT/StringRef.h" +#include "llvm/Support/Error.h" +#include "llvm/Support/JSON.h" + +namespace llvm { +namespace telemetry { + +using SteadyTimePoint = std::chrono::time_point<std::chrono::steady_clock>; + +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; +}; + +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::string ToString() const; +}; + +struct ExitDescription { + int exit_code; + std::string description; + + std::string ToString() const; +}; + +// 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 the tool starts. + // All entries emitted for the same session will have + // the same session_uuid + std::string session_uuid; + + TelemetryEventStats stats; + + std::optional<ExitDescription> exit_description; + + // 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; + + BaseTelemetryEntry() = default; + virtual ~BaseTelemetryEntry() = default; + virtual std::string ToString() const; +}; + +// Where/how to send the logged entries. +class TelemetryDestination { +public: + virtual ~TelemetryDestination() = default; + virtual Error EmitEntry(const BaseTelemetryEntry *entry) = 0; + virtual std::string name() const = 0; +}; + +class BaseTelemetryLogger { +public: + virtual ~BaseTelemetryLogger() = default; + + // Invoked upon tool startup + virtual void LogStartup(llvm::StringRef tool_path, + BaseTelemetryEntry *entry) = 0; + + // Invoked upon tool exit. + virtual void LogExit(llvm::StringRef tool_path, + BaseTelemetryEntry *entry) = 0; + + virtual void AddDestination(TelemetryDestination *destination) = 0; +}; + +} // namespace telemetry +} // namespace llvm + +#endif // LVM_TELEMETRY_TELEMETRY_H diff --git a/llvm/lib/CMakeLists.txt b/llvm/lib/CMakeLists.txt index 74e2d03c07953..84acd8143604e 100644 --- a/llvm/lib/CMakeLists.txt +++ b/llvm/lib/CMakeLists.txt @@ -39,6 +39,7 @@ add_subdirectory(ProfileData) add_subdirectory(Passes) add_subdirectory(TargetParser) add_subdirectory(TextAPI) +add_subdirectory(Telemetry) add_subdirectory(ToolDrivers) add_subdirectory(XRay) if (LLVM_INCLUDE_TESTS) diff --git a/llvm/lib/Telemetry/CMakeLists.txt b/llvm/lib/Telemetry/CMakeLists.txt new file mode 100644 index 0000000000000..8208bdadb05e9 --- /dev/null +++ b/llvm/lib/Telemetry/CMakeLists.txt @@ -0,0 +1,6 @@ +add_llvm_component_library(LLVMTelemetry + Telemetry.cpp + + ADDITIONAL_HEADER_DIRS + "${LLVM_MAIN_INCLUDE_DIR}/llvm/Telemetry" +) diff --git a/llvm/lib/Telemetry/Telemetry.cpp b/llvm/lib/Telemetry/Telemetry.cpp new file mode 100644 index 0000000000000..1026838953ede --- /dev/null +++ b/llvm/lib/Telemetry/Telemetry.cpp @@ -0,0 +1,32 @@ +#include "llvm/Telemetry/Telemetry.h" + +namespace llvm { +namespace telemetry { + +std::string TelemetryEventStats::ToString() const { + std::string result; + llvm::raw_string_ostream os(result); + os << "start_timestamp: " << m_start.time_since_epoch().count() + << ", end_timestamp: " + << (m_end.has_value() ? std::to_string(m_end->time_since_epoch().count()) + : "<NONE>"); + return result; +} + +std::string ExitDescription::ToString() const { + return "exit_code: " + std::to_string(exit_code) + + ", description: " + description + "\n"; +} + +std::string BaseTelemetryEntry::ToString() const { + return "[BaseTelemetryEntry]\n" + (" session_uuid:" + session_uuid + "\n") + + (" stats: " + stats.ToString() + "\n") + + (" exit_description: " + + (exit_description.has_value() ? exit_description->ToString() + : "<NONE>") + + "\n") + + (" counter: " + std::to_string(counter) + "\n"); +} + +} // namespace telemetry +} // namespace llvm \ No newline at end of file _______________________________________________ lldb-commits mailing list lldb-commits@lists.llvm.org https://lists.llvm.org/cgi-bin/mailman/listinfo/lldb-commits