Author: Vy Nguyen Date: 2025-03-07T05:59:05-05:00 New Revision: de9cee1c97882dc69a20ac688d20a84f831b62c6
URL: https://github.com/llvm/llvm-project/commit/de9cee1c97882dc69a20ac688d20a84f831b62c6 DIFF: https://github.com/llvm/llvm-project/commit/de9cee1c97882dc69a20ac688d20a84f831b62c6.diff LOG: [LLDB][Telemetry]Define telemetry::CommandInfo (#129354) and collect telemetry about a command's execution. *NOTE: Please consider this PR a DRAFT ( Waiting on PR/127696 to be submitted. ) --------- Co-authored-by: Jonas Devlieghere <jo...@devlieghere.com> Added: Modified: lldb/include/lldb/Core/Telemetry.h lldb/source/Core/Telemetry.cpp lldb/source/Interpreter/CommandInterpreter.cpp lldb/unittests/Core/TelemetryTest.cpp Removed: ################################################################################ diff --git a/lldb/include/lldb/Core/Telemetry.h b/lldb/include/lldb/Core/Telemetry.h index 7d8716f1659b5..56259e4a673bf 100644 --- a/lldb/include/lldb/Core/Telemetry.h +++ b/lldb/include/lldb/Core/Telemetry.h @@ -13,12 +13,14 @@ #include "lldb/Interpreter/CommandReturnObject.h" #include "lldb/Utility/LLDBLog.h" #include "lldb/Utility/StructuredData.h" +#include "lldb/Utility/UUID.h" #include "lldb/lldb-forward.h" #include "llvm/ADT/FunctionExtras.h" #include "llvm/ADT/StringExtras.h" #include "llvm/ADT/StringRef.h" #include "llvm/Support/JSON.h" #include "llvm/Telemetry/Telemetry.h" +#include <atomic> #include <chrono> #include <ctime> #include <memory> @@ -28,6 +30,17 @@ namespace lldb_private { namespace telemetry { +struct LLDBConfig : public ::llvm::telemetry::Config { + // If true, we will collect full details about a debug command (eg., args and + // original command). Note: This may contain PII, hence can only be enabled by + // the vendor while creating the Manager. + const bool detailed_command_telemetry; + + explicit LLDBConfig(bool enable_telemetry, bool detailed_command_telemetry) + : ::llvm::telemetry::Config(enable_telemetry), + detailed_command_telemetry(detailed_command_telemetry) {} +}; + // We expect each (direct) subclass of LLDBTelemetryInfo to // have an LLDBEntryKind in the form 0b11xxxxxxxx // Specifically: @@ -37,6 +50,7 @@ namespace telemetry { // must have their LLDBEntryKind in the similar form (ie., share common prefix) struct LLDBEntryKind : public ::llvm::telemetry::EntryKind { static const llvm::telemetry::KindType BaseInfo = 0b11000000; + static const llvm::telemetry::KindType CommandInfo = 0b11010000; static const llvm::telemetry::KindType DebuggerInfo = 0b11000100; }; @@ -66,6 +80,52 @@ struct LLDBBaseTelemetryInfo : public llvm::telemetry::TelemetryInfo { void serialize(llvm::telemetry::Serializer &serializer) const override; }; +struct CommandInfo : public LLDBBaseTelemetryInfo { + /// If the command is/can be associated with a target entry this field + /// contains that target's UUID. <EMPTY> otherwise. + UUID target_uuid; + /// A unique ID for a command so the manager can match the start entry with + /// its end entry. These values only need to be unique within the same + /// session. Necessary because we'd send off an entry right before a command's + /// execution and another right after. This is to avoid losing telemetry if + /// the command does not execute successfully. + uint64_t command_id; + /// The command name(eg., "breakpoint set") + std::string command_name; + /// These two fields are not collected by default due to PII risks. + /// Vendor may allow them by setting the + /// LLDBConfig::detailed_command_telemetry. + /// @{ + std::optional<std::string> original_command; + std::optional<std::string> args; + /// @} + /// Return status of a command and any error description in case of error. + std::optional<lldb::ReturnStatus> ret_status; + std::optional<std::string> error_data; + + CommandInfo() = default; + + llvm::telemetry::KindType getKind() const override { + return LLDBEntryKind::CommandInfo; + } + + static bool classof(const llvm::telemetry::TelemetryInfo *T) { + return (T->getKind() & LLDBEntryKind::CommandInfo) == + LLDBEntryKind::CommandInfo; + } + + void serialize(llvm::telemetry::Serializer &serializer) const override; + + static uint64_t GetNextId(); + +private: + // We assign each command (in the same session) a unique id so that their + // "start" and "end" entries can be matched up. + // These values don't need to be unique across runs (because they are + // secondary-key), hence a simple counter is sufficent. + static std::atomic<uint64_t> g_command_id_seed; +}; + struct DebuggerInfo : public LLDBBaseTelemetryInfo { std::string lldb_version; @@ -93,24 +153,21 @@ class TelemetryManager : public llvm::telemetry::Manager { public: llvm::Error preDispatch(llvm::telemetry::TelemetryInfo *entry) override; - const llvm::telemetry::Config *GetConfig(); + const LLDBConfig *GetConfig() { return m_config.get(); } virtual llvm::StringRef GetInstanceName() const = 0; static TelemetryManager *GetInstance(); - static TelemetryManager *GetInstanceIfEnabled(); - protected: - TelemetryManager(std::unique_ptr<llvm::telemetry::Config> config); + TelemetryManager(std::unique_ptr<LLDBConfig> config); static void SetInstance(std::unique_ptr<TelemetryManager> manger); private: - std::unique_ptr<llvm::telemetry::Config> m_config; + std::unique_ptr<LLDBConfig> m_config; // Each instance of a TelemetryManager is assigned a unique ID. const std::string m_id; - static std::unique_ptr<TelemetryManager> g_instance; }; @@ -118,39 +175,54 @@ class TelemetryManager : public llvm::telemetry::Manager { template <typename Info> struct ScopedDispatcher { // The debugger pointer is optional because we may not have a debugger yet. // In that case, caller must set the debugger later. - ScopedDispatcher(llvm::unique_function<void(Info *info)> callback, + ScopedDispatcher(Debugger *debugger = nullptr) { + // Start the timer. + m_start_time = std::chrono::steady_clock::now(); + this->debugger = debugger; + } + ScopedDispatcher(llvm::unique_function<void(Info *info)> final_callback, Debugger *debugger = nullptr) - : m_callback(std::move(callback)) { + : m_final_callback(std::move(final_callback)) { // Start the timer. m_start_time = std::chrono::steady_clock::now(); - m_info.debugger = debugger; + this->debugger = debugger; } - void SetDebugger(Debugger *debugger) { m_info.debugger = debugger; } + void SetDebugger(Debugger *debugger) { this->debugger = debugger; } - ~ScopedDispatcher() { - // If Telemetry is disabled (either at buildtime or runtime), - // then don't do anything. - TelemetryManager *manager = TelemetryManager::GetInstanceIfEnabled(); - if (!manager) - return; + void DispatchOnExit(llvm::unique_function<void(Info *info)> final_callback) { + // We probably should not be overriding previously set cb. + assert(!m_final_callback); + m_final_callback = std::move(final_callback); + } - m_info.start_time = m_start_time; - // Populate common fields that we can only set now. - m_info.end_time = std::chrono::steady_clock::now(); - // The callback will set the remaining fields. - m_callback(&m_info); + void DispatchNow(llvm::unique_function<void(Info *info)> populate_fields_cb) { + TelemetryManager *manager = TelemetryManager::GetInstance(); + if (!manager->GetConfig()->EnableTelemetry) + return; + Info info; + // Populate the common fields we know about. + info.start_time = m_start_time; + info.end_time = std::chrono::steady_clock::now(); + info.debugger = debugger; + // The callback will set the rest. + populate_fields_cb(&info); // And then we dispatch. - if (llvm::Error er = manager->dispatch(&m_info)) { + if (llvm::Error er = manager->dispatch(&info)) { LLDB_LOG_ERROR(GetLog(LLDBLog::Object), std::move(er), - "Failed to dispatch entry of type: {0}", m_info.getKind()); + "Failed to dispatch entry of type: {0}", info.getKind()); } } + ~ScopedDispatcher() { + if (m_final_callback) + DispatchNow(std::move(m_final_callback)); + } + private: SteadyTimePoint m_start_time; - llvm::unique_function<void(Info *info)> m_callback; - Info m_info; + llvm::unique_function<void(Info *info)> m_final_callback; + Debugger *debugger; }; } // namespace telemetry diff --git a/lldb/source/Core/Telemetry.cpp b/lldb/source/Core/Telemetry.cpp index 367e94d6566de..be929a644706e 100644 --- a/lldb/source/Core/Telemetry.cpp +++ b/lldb/source/Core/Telemetry.cpp @@ -60,6 +60,22 @@ void LLDBBaseTelemetryInfo::serialize(Serializer &serializer) const { serializer.write("end_time", ToNanosec(end_time.value())); } +void CommandInfo::serialize(Serializer &serializer) const { + LLDBBaseTelemetryInfo::serialize(serializer); + + serializer.write("target_uuid", target_uuid.GetAsString()); + serializer.write("command_id", command_id); + serializer.write("command_name", command_name); + if (original_command.has_value()) + serializer.write("original_command", original_command.value()); + if (args.has_value()) + serializer.write("args", args.value()); + if (ret_status.has_value()) + serializer.write("ret_status", ret_status.value()); + if (error_data.has_value()) + serializer.write("error_data", error_data.value()); +} + void DebuggerInfo::serialize(Serializer &serializer) const { LLDBBaseTelemetryInfo::serialize(serializer); @@ -67,7 +83,10 @@ void DebuggerInfo::serialize(Serializer &serializer) const { serializer.write("is_exit_entry", is_exit_entry); } -TelemetryManager::TelemetryManager(std::unique_ptr<Config> config) +std::atomic<uint64_t> CommandInfo::g_command_id_seed = 0; +uint64_t CommandInfo::GetNextId() { return g_command_id_seed.fetch_add(1); } + +TelemetryManager::TelemetryManager(std::unique_ptr<LLDBConfig> config) : m_config(std::move(config)), m_id(MakeUUID()) {} llvm::Error TelemetryManager::preDispatch(TelemetryInfo *entry) { @@ -79,23 +98,41 @@ llvm::Error TelemetryManager::preDispatch(TelemetryInfo *entry) { return llvm::Error::success(); } -const Config *TelemetryManager::GetConfig() { return m_config.get(); } +class NoOpTelemetryManager : public TelemetryManager { +public: + llvm::Error preDispatch(llvm::telemetry::TelemetryInfo *entry) override { + // Does nothing. + return llvm::Error::success(); + } -std::unique_ptr<TelemetryManager> TelemetryManager::g_instance = nullptr; -TelemetryManager *TelemetryManager::GetInstance() { - if (!Config::BuildTimeEnableTelemetry) - return nullptr; - return g_instance.get(); -} + explicit NoOpTelemetryManager() + : TelemetryManager(std::make_unique<LLDBConfig>( + /*EnableTelemetry*/ false, /*DetailedCommand*/ false)) {} + + virtual llvm::StringRef GetInstanceName() const override { + return "NoOpTelemetryManager"; + } + + llvm::Error dispatch(llvm::telemetry::TelemetryInfo *entry) override { + // Does nothing. + return llvm::Error::success(); + } -TelemetryManager *TelemetryManager::GetInstanceIfEnabled() { - // Telemetry may be enabled at build time but disabled at runtime. - if (TelemetryManager *ins = TelemetryManager::GetInstance()) { - if (ins->GetConfig()->EnableTelemetry) - return ins; + static NoOpTelemetryManager *GetInstance() { + static std::unique_ptr<NoOpTelemetryManager> g_ins = + std::make_unique<NoOpTelemetryManager>(); + return g_ins.get(); } +}; - return nullptr; +std::unique_ptr<TelemetryManager> TelemetryManager::g_instance = nullptr; +TelemetryManager *TelemetryManager::GetInstance() { + // If Telemetry is disabled or if there is no default instance, then use the + // NoOp manager. We use a dummy instance to avoid having to do nullchecks in + // various places. + if (!Config::BuildTimeEnableTelemetry || !g_instance) + return NoOpTelemetryManager::GetInstance(); + return g_instance.get(); } void TelemetryManager::SetInstance(std::unique_ptr<TelemetryManager> manager) { diff --git a/lldb/source/Interpreter/CommandInterpreter.cpp b/lldb/source/Interpreter/CommandInterpreter.cpp index c363f20081f9e..24cf755d1f740 100644 --- a/lldb/source/Interpreter/CommandInterpreter.cpp +++ b/lldb/source/Interpreter/CommandInterpreter.cpp @@ -46,7 +46,9 @@ #include "Commands/CommandObjectWatchpoint.h" #include "lldb/Core/Debugger.h" +#include "lldb/Core/Module.h" #include "lldb/Core/PluginManager.h" +#include "lldb/Core/Telemetry.h" #include "lldb/Host/StreamFile.h" #include "lldb/Utility/ErrorMessages.h" #include "lldb/Utility/LLDBLog.h" @@ -88,6 +90,7 @@ #include "llvm/Support/Path.h" #include "llvm/Support/PrettyStackTrace.h" #include "llvm/Support/ScopedPrinter.h" +#include "llvm/Telemetry/Telemetry.h" #if defined(__APPLE__) #include <TargetConditionals.h> @@ -1883,9 +1886,48 @@ bool CommandInterpreter::HandleCommand(const char *command_line, LazyBool lazy_add_to_history, CommandReturnObject &result, bool force_repeat_command) { + telemetry::ScopedDispatcher<telemetry::CommandInfo> helper(&m_debugger); + const bool detailed_command_telemetry = + telemetry::TelemetryManager::GetInstance() + ->GetConfig() + ->detailed_command_telemetry; + const int command_id = telemetry::CommandInfo::GetNextId(); + std::string command_string(command_line); std::string original_command_string(command_string); std::string real_original_command_string(command_string); + std::string parsed_command_args; + CommandObject *cmd_obj = nullptr; + + helper.DispatchNow([&](lldb_private::telemetry::CommandInfo *info) { + info->command_id = command_id; + if (Target *target = GetExecutionContext().GetTargetPtr()) { + // If we have a target attached to this command, then get the UUID. + info->target_uuid = target->GetExecutableModule() != nullptr + ? target->GetExecutableModule()->GetUUID() + : UUID(); + } + if (detailed_command_telemetry) + info->original_command = original_command_string; + // The rest (eg., command_name, args, etc) hasn't been parsed yet; + // Those will be collected by the on-exit-callback. + }); + + helper.DispatchOnExit([&](lldb_private::telemetry::CommandInfo *info) { + // TODO: this is logging the time the command-handler finishes. + // But we may want a finer-grain durations too? + // (ie., the execute_time recorded below?) + info->command_id = command_id; + llvm::StringRef command_name = + cmd_obj ? cmd_obj->GetCommandName() : "<not found>"; + info->command_name = command_name.str(); + info->ret_status = result.GetStatus(); + if (std::string error_str = result.GetErrorString(); !error_str.empty()) + info->error_data = std::move(error_str); + + if (detailed_command_telemetry) + info->args = parsed_command_args; + }); Log *log = GetLog(LLDBLog::Commands); LLDB_LOGF(log, "Processing command: %s", command_line); @@ -1991,7 +2033,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 @@ -2053,37 +2095,36 @@ 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()); // To test whether or not transcript should be saved, `transcript_item` is // used instead of `GetSaveTranscript()`. This is because the latter will // fail when the command is "settings set interpreter.save-transcript true". if (transcript_item) { transcript_item->AddStringItem("commandName", cmd_obj->GetCommandName()); - transcript_item->AddStringItem("commandArguments", remainder); + transcript_item->AddStringItem("commandArguments", parsed_command_args); } ElapsedTime elapsed(execute_time); cmd_obj->SetOriginalCommandString(real_original_command_string); // Set the indent to the position of the command in the command line. - pos = real_original_command_string.rfind(remainder); + pos = real_original_command_string.rfind(parsed_command_args); std::optional<uint16_t> indent; if (pos != std::string::npos) indent = pos; result.SetDiagnosticIndent(indent); - 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/unittests/Core/TelemetryTest.cpp b/lldb/unittests/Core/TelemetryTest.cpp index 7fc2b3d0264e3..72db8c17f09ea 100644 --- a/lldb/unittests/Core/TelemetryTest.cpp +++ b/lldb/unittests/Core/TelemetryTest.cpp @@ -52,8 +52,8 @@ class TestDestination : public llvm::telemetry::Destination { class FakePlugin : public telemetry::TelemetryManager { public: FakePlugin() - : telemetry::TelemetryManager( - std::make_unique<llvm::telemetry::Config>(true)) {} + : telemetry::TelemetryManager(std::make_unique<telemetry::LLDBConfig>( + /*enable_telemetry=*/true, /*detailed_command_telemetry=*/true)) {} // TelemetryManager interface llvm::Error preDispatch(llvm::telemetry::TelemetryInfo *entry) override { _______________________________________________ lldb-commits mailing list lldb-commits@lists.llvm.org https://lists.llvm.org/cgi-bin/mailman/listinfo/lldb-commits
