[Lldb-commits] [lldb] Add settings and code that limits the number of progress events. (PR #75769)
via lldb-commits
lldb-commits at lists.llvm.org
Sun Dec 17 23:07:21 PST 2023
llvmbot wrote:
<!--LLVM PR SUMMARY COMMENT-->
@llvm/pr-subscribers-lldb
Author: Greg Clayton (clayborg)
<details>
<summary>Changes</summary>
Currently in LLDB if clients listen for Debugger::eBroadcastBitProgress events, this can cause too many progress events to get sent to clients which makes the feature a bit less useful that originally planned.
This patch fixes this by adding two new settings in LLDB:
```
(lldb) apropos progress
The following settings variables may relate to 'progress':
progress-minimum-duration -- The minimum time in milliseconds required for a
progress to get reported. If a progress starts
and completes and the elapsed time is under this
threshold, then no progress will get reported.
progress-update-frequency -- The minimum time in milliseconds between
progress updates for progress notifications that
have a valid count.
```
This patch also adds code that spawns a progress thread in each debugger that manages all of the incoming events and only sends out progress events if they meet the setting requirements. The default settings are:
```
(lldb) settings show progress-minimum-duration progress-update-frequency
progress-minimum-duration (unsigned) = 500
progress-update-frequency (unsigned) = 1000
```
The `progress-minimum-duration` setting is the number of milliseconds that we wait before broadcasting any events for a progress. If the progress start and end events happen quicker than this number, no progress events get broadcast. This keeps the progress events from becoming too cumbersome on clients and makes sure that if we have thousands of very quick internal progress reports, we don't have to show any of them. The default of 500ms value is open to suggestions, maybe 250ms would be better?
The `progress-update-frequency` setting is for progress dialogs with finite amounts of work. When we index DWARF, we create progress dialogs with thousands and thousands of compile units and each time we manually index a compile unit, previously we would send thousands and thousands of progress updates for each compile unit no matter how quickly we would index them. With this new setting, will first wait `progress-minimum-duration` milliseconds before broadcasting any progress events, and then after that we will broadcast update progress events only every 1000 ms, or 1 second. This really keeps the number of progress notifications down to a minimum.
Posting this as a solution to the RFC:
https://discourse.llvm.org/t/rfc-improve-lldb-progress-reporting/75717
---
Patch is 20.53 KiB, truncated to 20.00 KiB below, full version: https://github.com/llvm/llvm-project/pull/75769.diff
6 Files Affected:
- (modified) lldb/include/lldb/Core/Debugger.h (+38)
- (modified) lldb/include/lldb/Core/DebuggerEvents.h (+1)
- (modified) lldb/include/lldb/Utility/LLDBLog.h (+2-1)
- (modified) lldb/source/Core/CoreProperties.td (+8)
- (modified) lldb/source/Core/Debugger.cpp (+294-4)
- (modified) lldb/source/Utility/LLDBLog.cpp (+1)
``````````diff
diff --git a/lldb/include/lldb/Core/Debugger.h b/lldb/include/lldb/Core/Debugger.h
index c6d603ca5dcde0..5ee2ef93fe496a 100644
--- a/lldb/include/lldb/Core/Debugger.h
+++ b/lldb/include/lldb/Core/Debugger.h
@@ -11,6 +11,7 @@
#include <cstdint>
+#include <condition_variable>
#include <memory>
#include <optional>
#include <vector>
@@ -365,6 +366,10 @@ class Debugger : public std::enable_shared_from_this<Debugger>,
lldb::DWIMPrintVerbosity GetDWIMPrintVerbosity() const;
+ uint64_t GetProgressUpdateFrequency() const;
+
+ uint64_t GetProgressMinDuration() const;
+
bool GetEscapeNonPrintables() const;
bool GetNotifyVoid() const;
@@ -588,6 +593,9 @@ class Debugger : public std::enable_shared_from_this<Debugger>,
return m_source_file_cache;
}
+ /// Notify the progress thread that there is new progress data.
+ void NotifyProgress(std::unique_ptr<ProgressEventData> &data_up);
+
protected:
friend class CommandInterpreter;
friend class REPL;
@@ -659,6 +667,12 @@ class Debugger : public std::enable_shared_from_this<Debugger>,
lldb::thread_result_t DefaultEventHandler();
+ bool StartProgressThread();
+
+ void StopProgressThread();
+
+ lldb::thread_result_t ProgressThread();
+
void HandleBreakpointEvent(const lldb::EventSP &event_sp);
void HandleProcessEvent(const lldb::EventSP &event_sp);
@@ -721,6 +735,30 @@ class Debugger : public std::enable_shared_from_this<Debugger>,
LoadedPluginsList m_loaded_plugins;
HostThread m_event_handler_thread;
HostThread m_io_handler_thread;
+ HostThread m_progress_thread;
+ std::mutex m_progress_mutex;
+ std::condition_variable m_progress_condition;
+ bool m_progress_thread_running = false;
+ using ProgressClock = std::chrono::system_clock;
+ using ProgressTimePoint = std::chrono::time_point<ProgressClock>;
+ using ProgressDuration = ProgressTimePoint::duration;
+ struct ProgressInfo {
+ ProgressInfo(ProgressEventData *data_ptr, uint64_t min_duration_ms) :
+ data_up(data_ptr), start(ProgressClock::now()) {
+ next_event_time = start + std::chrono::milliseconds(min_duration_ms);
+ }
+
+ std::unique_ptr<ProgressEventData> data_up;
+ /// The time the first progress was reported.
+ ProgressTimePoint start;
+ /// Only broadcast an event if the current time is >= this time.
+ ProgressTimePoint next_event_time;
+ /// If valid, the last time a notification was sent out for this progress.
+ std::optional<ProgressTimePoint> last_notification_time;
+ };
+ std::map<uint64_t, ProgressInfo> m_progress_map;
+ ///< Each time m_progress_map is updated, this gets incremented.
+ uint64_t m_progress_update_id = 0;
Broadcaster m_sync_broadcaster; ///< Private debugger synchronization.
Broadcaster m_broadcaster; ///< Public Debugger event broadcaster.
lldb::ListenerSP m_forward_listener_sp;
diff --git a/lldb/include/lldb/Core/DebuggerEvents.h b/lldb/include/lldb/Core/DebuggerEvents.h
index 982b22229701f8..8e93144d0b2f6f 100644
--- a/lldb/include/lldb/Core/DebuggerEvents.h
+++ b/lldb/include/lldb/Core/DebuggerEvents.h
@@ -41,6 +41,7 @@ class ProgressEventData : public EventData {
bool IsFinite() const { return m_total != UINT64_MAX; }
uint64_t GetCompleted() const { return m_completed; }
uint64_t GetTotal() const { return m_total; }
+ bool IsDone() const { return m_completed == m_total; }
std::string GetMessage() const {
std::string message = m_title;
if (!m_details.empty()) {
diff --git a/lldb/include/lldb/Utility/LLDBLog.h b/lldb/include/lldb/Utility/LLDBLog.h
index c7de41e74e85bd..475bc5f812387e 100644
--- a/lldb/include/lldb/Utility/LLDBLog.h
+++ b/lldb/include/lldb/Utility/LLDBLog.h
@@ -49,7 +49,8 @@ enum class LLDBLog : Log::MaskType {
Watchpoints = Log::ChannelFlag<30>,
OnDemand = Log::ChannelFlag<31>,
Source = Log::ChannelFlag<32>,
- LLVM_MARK_AS_BITMASK_ENUM(OnDemand),
+ Progress = Log::ChannelFlag<33>,
+ LLVM_MARK_AS_BITMASK_ENUM(Progress),
};
LLVM_ENABLE_BITMASK_ENUMS_IN_NAMESPACE();
diff --git a/lldb/source/Core/CoreProperties.td b/lldb/source/Core/CoreProperties.td
index 8d81967bdb50a4..357739c4be0ecd 100644
--- a/lldb/source/Core/CoreProperties.td
+++ b/lldb/source/Core/CoreProperties.td
@@ -220,4 +220,12 @@ let Definition = "debugger" in {
DefaultEnumValue<"eDWIMPrintVerbosityNone">,
EnumValues<"OptionEnumValues(g_dwim_print_verbosities)">,
Desc<"The verbosity level used by dwim-print.">;
+ def ProgressUpdateFrequency: Property<"progress-update-frequency", "UInt64">,
+ Global,
+ DefaultUnsignedValue<1000>,
+ Desc<"The minimum time in milliseconds between progress updates for progress notifications that have a valid count.">;
+ def ProgressMinDuration: Property<"progress-minimum-duration", "UInt64">,
+ Global,
+ DefaultUnsignedValue<500>,
+ Desc<"The minimum time in milliseconds required for a progress to get reported. If a progress starts and completes and the elapsed time is under this threshold, then no progress will get reported.">;
}
diff --git a/lldb/source/Core/Debugger.cpp b/lldb/source/Core/Debugger.cpp
index 97311b4716ac2f..b8c8b5bf8262a8 100644
--- a/lldb/source/Core/Debugger.cpp
+++ b/lldb/source/Core/Debugger.cpp
@@ -594,6 +594,20 @@ lldb::DWIMPrintVerbosity Debugger::GetDWIMPrintVerbosity() const {
g_debugger_properties[idx].default_uint_value));
}
+uint64_t Debugger::GetProgressUpdateFrequency() const {
+ const uint32_t idx = ePropertyProgressUpdateFrequency;
+ return GetPropertyAtIndexAs<uint64_t>(
+ idx, g_debugger_properties[idx].default_uint_value);
+}
+
+uint64_t Debugger::GetProgressMinDuration() const {
+ const uint32_t idx = ePropertyProgressMinDuration;
+ return GetPropertyAtIndexAs<uint64_t>(
+ idx, g_debugger_properties[idx].default_uint_value);
+}
+
+
+
#pragma mark Debugger
// const DebuggerPropertiesSP &
@@ -938,6 +952,7 @@ void Debugger::Clear() {
ClearIOHandlers();
StopIOHandlerThread();
StopEventHandlerThread();
+ StopProgressThread();
m_listener_sp->Clear();
for (TargetSP target_sp : m_target_list.Targets()) {
if (target_sp) {
@@ -1430,6 +1445,279 @@ void Debugger::SetDestroyCallback(
m_destroy_callback_baton = baton;
}
+
+ /// Notify the progress thread that there is new progress data.
+void Debugger::NotifyProgress(std::unique_ptr<ProgressEventData> &data_up) {
+ // Start the progress thread if it isn't already running.
+ if (!m_progress_thread.IsJoinable())
+ StartProgressThread();
+ // Scope to let the lock unlock before calling notify_one() to avoid
+ // the thread waking up an extra time.
+ {
+ std::unique_lock lock(m_progress_mutex);
+ Log *log = GetLog(LLDBLog::Progress);
+ if (log) {
+ if (data_up->GetCompleted() == 0)
+ LLDB_LOG(log, "NotifyProgress id = {1}, title = \"{2}\", type = start",
+ data_up.get(), data_up->GetID(), data_up->GetTitle(),
+ data_up->GetDetails());
+ else if (data_up->IsDone())
+ LLDB_LOG(log, "NotifyProgress id = {1}, title = \"{2}\", type = end",
+ data_up.get(), data_up->GetID(), data_up->GetTitle(),
+ data_up->GetDetails());
+ else if (data_up->GetDetails().empty())
+ LLDB_LOG(log, "NotifyProgress id = {1}, title = \"{2}\" {3}/{4}",
+ data_up.get(), data_up->GetID(), data_up->GetTitle(),
+ data_up->GetCompleted(), data_up->GetTotal());
+ else
+ LLDB_LOG(log, "NotifyProgress id = {1}, title = \"{2}\", "
+ "detail = \"{3}\" {4}/{5}", data_up.get(), data_up->GetID(),
+ data_up->GetTitle(), data_up->GetDetails(),
+ data_up->GetCompleted(), data_up->GetTotal());
+ }
+
+ const uint64_t progress_id = data_up->GetID();
+ auto pos = m_progress_map.find(progress_id);
+ if (pos != m_progress_map.end()) {
+ // We have a progress info tracking this progress already. If we haven't
+ // sent any events yet, then keep the initial progress data as it
+ // signifies the start progress notification which we might send if the
+ // progress doesn't finish too quickly.
+ ProgressInfo &info = pos->second;
+ bool replace_data = false;
+ if (info.last_notification_time) {
+ LLDB_LOG(log, "NotifyProgress id = {0} replace_data = 1 (event sent "
+ "already)", progress_id);
+ // We have sent an event for this already, always replace the progress
+ // data as this means we already sent a progress start event so we
+ // always want to send the most up to date information.
+ replace_data = true;
+ } else {
+ LLDB_LOG(log, "NotifyProgress id = {0} no event sent yet",
+ progress_id);
+ // We haven't sent any notifications yet for this progress.
+ if (info.data_up) {
+ // If we are done already, then set the data so we don't send any
+ // events for this progress. But if we aren't done, we need to leave
+ // the original start progress notification in the progress info in
+ // case we send it.
+ replace_data = data_up->IsDone();
+ LLDB_LOG(log, "NotifyProgress id = {0} replace_data = {1} (only "
+ "true if done)", progress_id, replace_data);
+ } else {
+ // There is no data in the ProgressInfo as it was sent in an event
+ // and the unique pointer was reset, so set the data.
+ LLDB_LOG(log, "NotifyProgress id = {0} replace_data = 1 ("
+ "ProgressEventData is NULL)", progress_id, replace_data);
+ replace_data = true;
+ }
+ }
+ // Replace the data
+ if (replace_data)
+ pos->second.data_up.reset(data_up.release());
+ } else {
+ m_progress_map.emplace(
+ progress_id,
+ ProgressInfo(data_up.release(), GetProgressMinDuration()));
+ }
+ // Bump the progress update ID so the progress thread can wake up.
+ ++m_progress_update_id;
+ }
+ // After the scoped locker has unlocked the progress mutex, notify the
+ // progress condition variable. This avoids the progress thread from waking up
+ // multuple times.
+ m_progress_condition.notify_one();
+}
+
+lldb::thread_result_t Debugger::ProgressThread() {
+
+ Log *log = GetLog(LLDBLog::Progress);
+ LLDB_LOG(log, "ProgressThread thread started");
+
+ std::unique_lock lock(m_progress_mutex);
+ // We use this variable along with the mutex + condition to exit this thread.
+ m_progress_thread_running = true;
+
+ uint64_t update_id = 0;
+ // The predicate which will get us out of our waiting
+ // std::condition_variable::wait or std::condition_variable::wait_for calls
+ // below. Exit the std::condition_variable wait(...) or wait_for(...) calls if
+ // we haven't seen this update ID or if we want the thread to exit.
+ auto predicate = [this, &update_id]{
+ return update_id != m_progress_update_id || !m_progress_thread_running;
+ };
+ const uint32_t event_type = Debugger::eBroadcastBitProgress;
+ const ProgressDuration min_duration =
+ std::chrono::milliseconds(GetProgressMinDuration());
+ const ProgressDuration update_frequency =
+ std::chrono::milliseconds(GetProgressUpdateFrequency());
+
+ LLDB_LOG(log, "ProgressThread update_frequency = {0}", update_frequency);
+ LLDB_LOG(log, "ProgressThread min_duration = {0}", min_duration);
+
+ std::optional<ProgressDuration> opt_wait_duration;
+ while (m_progress_thread_running) {
+ if (opt_wait_duration.has_value()) {
+ LLDB_LOG(log, "ProgressThread wait_for(timeout = {0})", *opt_wait_duration);
+ m_progress_condition.wait_for(lock, *opt_wait_duration, predicate);
+ } else {
+ // We have no progress events or updates pending wait for a notification.
+ LLDB_LOG(log, "ProgressThread no active progresses, wait()");
+ m_progress_condition.wait(lock, predicate);
+ }
+ // Update our update_id so we only exit the wait or wait_for calls when it
+ // gets updated.
+ update_id = m_progress_update_id;
+
+ // We will sent our wait duration as needed. If it doesn't get set, then
+ // we will call wait() (no timeout) and if it does get set, it will be set
+ // to the minimum value needed to wait for the next ProcessEventData for a
+ // progress.
+ opt_wait_duration = std::nullopt;
+
+ LLDB_LOG(log, "ProgressThread wait returned (keep running thread = {0})",
+ m_progress_thread_running);
+ // Our m_progress_mutex is now locked and we can iterate over all progress
+ // events and see if we need to notify any or remove any if the progress is
+ // completed.
+ std::set<uint64_t> done_ids;
+ const auto now = ProgressClock::now();
+ for (auto &pair: m_progress_map) {
+ // If we send a notification and use a ProgressEventData, we will set the
+ // ProgressEventData unique pointer to NULL, so if we don't have current
+ // ProgressEventData, then skip to the next progress info as we are
+ // waiting for new progress updates or progress end notifications.
+ ProgressInfo &info = pair.second;
+ LLDB_LOG(log, "ProgressThread id = {0}", pair.first);
+ if (info.data_up) {
+ bool send_event = false;
+ bool is_done_event = info.data_up->IsDone();
+ if (is_done_event)
+ done_ids.insert(pair.first);
+
+ if (info.last_notification_time) {
+ // We have sent out a notification for this progress already, we need
+ // to check if we need to send out any update.
+ LLDB_LOG(log, "ProgressThread id = {0} already sent event",
+ pair.first);
+ if (is_done_event) {
+ // Progress is done and can be removed and we need to send an event
+ // to signal we are done.
+ LLDB_LOG(log, "ProgressThread id = {0} send_event = 1 (done), "
+ "elapsed_time = {1}", pair.first, now - info.start);
+ send_event = true;
+ } else {
+ // If we aren't done, check if we need to send updates for this. For
+ // finite progress dialogs, we update the "info.next_event_time"
+ // when we broadcast the first event using the update frequency
+ // setting. This keeps us from spamming too many events.
+ if (info.data_up->IsFinite()) {
+ send_event = now >= info.next_event_time;
+ if (!send_event) {
+ // We are not ready to send an event yet. Calculate how long
+ // we need to wait. If it is shorter than the current wait
+ // duration, or "opt_wait_duration" doesn't have a value, then
+ // set "opt_wait_duration".
+ ProgressDuration wait_duration = info.next_event_time - now;
+ if (!opt_wait_duration || *opt_wait_duration > wait_duration)
+ opt_wait_duration = wait_duration;
+ }
+ LLDB_LOG(log, "ProgressThread id = {0} send_event = {1}} "
+ "(update check)", pair.first, send_event);
+ }
+ }
+
+ } else {
+ // We haven't sent any progress notifications for this yet. We might
+ // need to send one if enough time has passed, or if the progress is
+ // finite (it has a valid total number of work items that we want to
+ // update) and our update frequency has been met.
+ LLDB_LOG(log, "ProgressThread id = {0} no events sent yet",
+ pair.first);
+ if (is_done_event) {
+ // We are already done before we sent a start progress event, so
+ // nothing to do as the progress was too short be be displayed.
+ LLDB_LOG(log, "ProgressThread id = {0} send_event = 0, elapsed_time"
+ " = {1} (less than minimum duration {2})", pair.first,
+ now - info.start, min_duration);
+ } else {
+ // We will send our progress start event only if we exceed the
+ // minimum progress duration will cause us to enter this loop.
+ // Before the first event is broadcast, "info.next_event_time" is
+ // initialized to the progress start time + the minimum progress
+ // duration setting.
+ send_event = (now >= info.next_event_time);
+ if (!send_event) {
+ // Not enough time has elapsed to send a start event yet.
+ // Calculate how long we need to wait. If it is shorter than
+ // the current wait duration, or "opt_wait_duration" doesn't have
+ // a value, then set "opt_wait_duration".
+ ProgressDuration wait_duration = info.next_event_time - now;
+ if (!opt_wait_duration || *opt_wait_duration > wait_duration)
+ opt_wait_duration = wait_duration;
+ }
+ LLDB_LOG(log, "ProgressThread id = {0} send_event = {1} (min "
+ "notify time check)", pair.first, send_event);
+ }
+ }
+
+ if (send_event) {
+ // We need to send a progress event, send the ProgressEventData that
+ // we have in our unique pointer and release the progress event data.
+ // Any subsequent updates to the progress will update the
+ // ProgressEventData unique pointer with the right info.
+ LLDB_LOG(log, "ProgressThread id = {0} broadcasting event",
+ pair.first);
+ info.last_notification_time = now;
+ // If we are not done and have a finite progress, set the next event
+ // time so we know when to send an update for the progress.
+ if (!is_done_event && info.data_up->IsFinite())
+ info.next_event_time = now + update_frequency;
+ EventSP event_sp(new Event(event_type, info.data_up.release()));
+ GetBroadcaster().BroadcastEvent(event_sp);
+ }
+ } else {
+ LLDB_LOG(log, "ProgressThread id = {0} (waiting for updates)",
+ pair.first);
+ }
+ }
+
+ // Remove any progress infos that are done.
+ for (uint64_t progress_id: done_ids)
+ m_progress_map.erase(progress_id);
+ }
+ LLDB_LOG(log, "ProgressThread thread exited");
+ return {};
+}
+
+bool Debugger::StartProgressThread() {
+ if (!m_progress_thread.IsJoinable()) {
+ llvm::Expected<HostThread> expected_thread = ThreadLauncher::LaunchThread(
+ "lldb.debugger.progress", [this] { return ProgressThread(); },
+ 8 * 1024 * 1024); // Use 8MB stack for this thread
+ if (expected_thread) {
+ m_progress_thread = *expected_thread;
+ } else {
+ LLDB_LOG_ERROR(GetLog(LLDBLog::Host), expected_thread.takeError(),
+ "failed to launch progress thread: {0}");
+ }
+ }
+ return m_progress_thread.IsJoinable();
+}
+
+void Debugger::StopProgressThread() {
+ if (m_progress_thread.IsJoinable()) {
+ {
+ std::unique_lock lock(m_progress_mutex);
+ // Change the variable that allows the thread to loop to false and signal
+ // the progress thread so it exits.
+ m_progress_thread_running = false;
+ }
+ m_progress_condition.notify_one();
+ m_progress_thread.Join(nullptr);
+ }
+}
+
static void PrivateReportProgress(Debugger &debugger, uint64_t progress_id,
std::string title, std::string details,
uint64_t completed, uint64_t total,
@@ -1438,11 +1726,13 @@ static void PrivateReportProgress(Debugger &debugger, uint64_t progress_id,
const uint32_t event_type = Debugger::eBroadcastBitProgress;
if (!debugger.GetBroadcaster().EventTypeHasListeners(event_type))
return;
- EventSP event_sp(new Event(
- event_type,
+
+ // Make a ProgressEventData and send it to the debugger. It will manage how
+ // and when to actually send progress update events to any listeners.
+ std::unique_ptr<ProgressEventData> data_up(
new ProgressEventData(progress_id, std::move(title), std::move(details),
- completed, total, is_debugger_specific)));
- debugger.GetBroadcaster().BroadcastEvent(event_sp);
+ completed, total, is_debugger_specific));
+ debugger.NotifyProgress(data_up);
}
void Debugger::ReportProgress(uint64_t progress_id, std::string title,...
[truncated]
``````````
</details>
https://github.com/llvm/llvm-project/pull/75769
More information about the lldb-commits
mailing list