Skip to content

Commit 0dbdc23

Browse files
authored
[lldb] Add ability to rate-limit progress reports (llvm#119377)
For high-frequency multithreaded progress reports, the contention of taking the progress mutex and the overhead of generating event can significantly slow down the operation whose progress we are reporting. This patch adds an (optional) capability to rate-limit them. It's optional because this approach has one drawback: if the progress reporting has a pattern where it generates a burst of activity and then blocks (without reporting anything) for a large amount of time, it can appear as if less progress was made that it actually was (because we only reported the first event from the burst and dropped the other ones). I've also made a small refactor of the Progress class to better distinguish between const (don't need protection), atomic (are used on the hot path) and other (need mutex protection) members.
1 parent e31c70d commit 0dbdc23

File tree

4 files changed

+185
-44
lines changed

4 files changed

+185
-44
lines changed

lldb/include/lldb/Core/Progress.h

Lines changed: 26 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,7 @@
1010
#define LLDB_CORE_PROGRESS_H
1111

1212
#include "lldb/Host/Alarm.h"
13+
#include "lldb/Utility/Timeout.h"
1314
#include "lldb/lldb-forward.h"
1415
#include "lldb/lldb-types.h"
1516
#include "llvm/ADT/StringMap.h"
@@ -81,7 +82,8 @@ class Progress {
8182
/// progress is to be reported only to specific debuggers.
8283
Progress(std::string title, std::string details = {},
8384
std::optional<uint64_t> total = std::nullopt,
84-
lldb_private::Debugger *debugger = nullptr);
85+
lldb_private::Debugger *debugger = nullptr,
86+
Timeout<std::nano> minimum_report_time = std::nullopt);
8587

8688
/// Destroy the progress object.
8789
///
@@ -121,21 +123,32 @@ class Progress {
121123
private:
122124
void ReportProgress();
123125
static std::atomic<uint64_t> g_id;
124-
/// More specific information about the current file being displayed in the
125-
/// report.
126-
std::string m_details;
127-
/// How much work ([0...m_total]) that has been completed.
128-
uint64_t m_completed;
126+
129127
/// Total amount of work, use a std::nullopt in the constructor for non
130128
/// deterministic progress.
131-
uint64_t m_total;
132-
std::mutex m_mutex;
133-
/// Set to true when progress has been reported where m_completed == m_total
134-
/// to ensure that we don't send progress updates after progress has
135-
/// completed.
136-
bool m_complete = false;
129+
const uint64_t m_total;
130+
131+
// Minimum amount of time between two progress reports.
132+
const Timeout<std::nano> m_minimum_report_time;
133+
137134
/// Data needed by the debugger to broadcast a progress event.
138-
ProgressData m_progress_data;
135+
const ProgressData m_progress_data;
136+
137+
/// How much work ([0...m_total]) that has been completed.
138+
std::atomic<uint64_t> m_completed = 0;
139+
140+
/// Time (in nanoseconds since epoch) of the last progress report.
141+
std::atomic<uint64_t> m_last_report_time_ns;
142+
143+
/// Guards non-const non-atomic members of the class.
144+
std::mutex m_mutex;
145+
146+
/// More specific information about the current file being displayed in the
147+
/// report.
148+
std::string m_details;
149+
150+
/// The "completed" value of the last reported event.
151+
std::optional<uint64_t> m_prev_completed;
139152
};
140153

141154
/// A class used to group progress reports by category. This is done by using a

lldb/source/Core/Progress.cpp

Lines changed: 52 additions & 30 deletions
Original file line numberDiff line numberDiff line change
@@ -11,7 +11,8 @@
1111
#include "lldb/Core/Debugger.h"
1212
#include "lldb/Utility/StreamString.h"
1313
#include "llvm/Support/Signposts.h"
14-
14+
#include <atomic>
15+
#include <chrono>
1516
#include <cstdint>
1617
#include <mutex>
1718
#include <optional>
@@ -26,17 +27,18 @@ static llvm::ManagedStatic<llvm::SignpostEmitter> g_progress_signposts;
2627

2728
Progress::Progress(std::string title, std::string details,
2829
std::optional<uint64_t> total,
29-
lldb_private::Debugger *debugger)
30-
: m_details(details), m_completed(0),
31-
m_total(Progress::kNonDeterministicTotal),
30+
lldb_private::Debugger *debugger,
31+
Timeout<std::nano> minimum_report_time)
32+
: m_total(total.value_or(Progress::kNonDeterministicTotal)),
33+
m_minimum_report_time(minimum_report_time),
3234
m_progress_data{title, ++g_id,
33-
/*m_progress_data.debugger_id=*/std::nullopt} {
34-
if (total)
35-
m_total = *total;
36-
37-
if (debugger)
38-
m_progress_data.debugger_id = debugger->GetID();
39-
35+
debugger ? std::optional<user_id_t>(debugger->GetID())
36+
: std::nullopt},
37+
m_last_report_time_ns(
38+
std::chrono::nanoseconds(
39+
std::chrono::steady_clock::now().time_since_epoch())
40+
.count()),
41+
m_details(std::move(details)) {
4042
std::lock_guard<std::mutex> guard(m_mutex);
4143
ReportProgress();
4244

@@ -65,29 +67,49 @@ Progress::~Progress() {
6567

6668
void Progress::Increment(uint64_t amount,
6769
std::optional<std::string> updated_detail) {
68-
if (amount > 0) {
69-
std::lock_guard<std::mutex> guard(m_mutex);
70-
if (updated_detail)
71-
m_details = std::move(updated_detail.value());
72-
// Watch out for unsigned overflow and make sure we don't increment too
73-
// much and exceed the total.
74-
if (m_total && (amount > (m_total - m_completed)))
75-
m_completed = m_total;
76-
else
77-
m_completed += amount;
78-
ReportProgress();
70+
if (amount == 0)
71+
return;
72+
73+
m_completed.fetch_add(amount, std::memory_order_relaxed);
74+
75+
if (m_minimum_report_time) {
76+
using namespace std::chrono;
77+
78+
nanoseconds now;
79+
uint64_t last_report_time_ns =
80+
m_last_report_time_ns.load(std::memory_order_relaxed);
81+
82+
do {
83+
now = steady_clock::now().time_since_epoch();
84+
if (now < nanoseconds(last_report_time_ns) + *m_minimum_report_time)
85+
return; // Too little time has passed since the last report.
86+
87+
} while (!m_last_report_time_ns.compare_exchange_weak(
88+
last_report_time_ns, now.count(), std::memory_order_relaxed,
89+
std::memory_order_relaxed));
7990
}
91+
92+
std::lock_guard<std::mutex> guard(m_mutex);
93+
if (updated_detail)
94+
m_details = std::move(updated_detail.value());
95+
ReportProgress();
8096
}
8197

8298
void Progress::ReportProgress() {
83-
if (!m_complete) {
84-
// Make sure we only send one notification that indicates the progress is
85-
// complete
86-
m_complete = m_completed == m_total;
87-
Debugger::ReportProgress(m_progress_data.progress_id, m_progress_data.title,
88-
m_details, m_completed, m_total,
89-
m_progress_data.debugger_id);
90-
}
99+
// NB: Comparisons with optional<T> rely on the fact that std::nullopt is
100+
// "smaller" than zero.
101+
if (m_prev_completed >= m_total)
102+
return; // We've reported completion already.
103+
104+
uint64_t completed =
105+
std::min(m_completed.load(std::memory_order_relaxed), m_total);
106+
if (completed < m_prev_completed)
107+
return; // An overflow in the m_completed counter. Just ignore these events.
108+
109+
Debugger::ReportProgress(m_progress_data.progress_id, m_progress_data.title,
110+
m_details, completed, m_total,
111+
m_progress_data.debugger_id);
112+
m_prev_completed = completed;
91113
}
92114

93115
ProgressManager::ProgressManager()

lldb/source/Plugins/SymbolFile/DWARF/ManualDWARFIndex.cpp

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -80,7 +80,8 @@ void ManualDWARFIndex::Index() {
8080
// indexing the unit, and then 8 extra entries for finalizing each index set.
8181
const uint64_t total_progress = units_to_index.size() * 2 + 8;
8282
Progress progress("Manually indexing DWARF", module_desc.GetData(),
83-
total_progress);
83+
total_progress, /*debugger=*/nullptr,
84+
/*minimum_report_time=*/std::chrono::milliseconds(20));
8485

8586
// Share one thread pool across operations to avoid the overhead of
8687
// recreating the threads.

lldb/unittests/Core/ProgressReportTest.cpp

Lines changed: 105 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,7 @@
1818
#include "gtest/gtest.h"
1919
#include <memory>
2020
#include <mutex>
21+
#include <thread>
2122

2223
using namespace lldb;
2324
using namespace lldb_private;
@@ -208,6 +209,110 @@ TEST_F(ProgressReportTest, TestReportDestructionWithPartialProgress) {
208209
EXPECT_EQ(data->GetMessage(), "Infinite progress: Report 2");
209210
}
210211

212+
TEST_F(ProgressReportTest, TestFiniteOverflow) {
213+
ListenerSP listener_sp = CreateListenerFor(lldb::eBroadcastBitProgress);
214+
EventSP event_sp;
215+
const ProgressEventData *data;
216+
217+
// Increment the report beyond its limit and make sure we only get one
218+
// completed event.
219+
{
220+
Progress progress("Finite progress", "Report 1", 10);
221+
progress.Increment(11);
222+
progress.Increment(47);
223+
}
224+
225+
ASSERT_TRUE(listener_sp->GetEvent(event_sp, TIMEOUT));
226+
data = ProgressEventData::GetEventDataFromEvent(event_sp.get());
227+
EXPECT_TRUE(data->IsFinite());
228+
EXPECT_EQ(data->GetCompleted(), 0);
229+
EXPECT_EQ(data->GetTotal(), 10);
230+
231+
ASSERT_TRUE(listener_sp->GetEvent(event_sp, TIMEOUT));
232+
data = ProgressEventData::GetEventDataFromEvent(event_sp.get());
233+
EXPECT_TRUE(data->IsFinite());
234+
EXPECT_EQ(data->GetCompleted(), 10);
235+
EXPECT_EQ(data->GetTotal(), 10);
236+
237+
ASSERT_FALSE(listener_sp->GetEvent(event_sp, TIMEOUT));
238+
}
239+
240+
TEST_F(ProgressReportTest, TestNonDeterministicOverflow) {
241+
ListenerSP listener_sp = CreateListenerFor(lldb::eBroadcastBitProgress);
242+
EventSP event_sp;
243+
const ProgressEventData *data;
244+
constexpr uint64_t max_minus_1 = std::numeric_limits<uint64_t>::max() - 1;
245+
246+
// Increment the report beyond its limit and make sure we only get one
247+
// completed event. The event which overflows the counter should be ignored.
248+
{
249+
Progress progress("Non deterministic progress", "Report 1");
250+
progress.Increment(max_minus_1);
251+
progress.Increment(max_minus_1);
252+
}
253+
254+
ASSERT_TRUE(listener_sp->GetEvent(event_sp, TIMEOUT));
255+
data = ProgressEventData::GetEventDataFromEvent(event_sp.get());
256+
EXPECT_FALSE(data->IsFinite());
257+
EXPECT_EQ(data->GetCompleted(), 0);
258+
EXPECT_EQ(data->GetTotal(), Progress::kNonDeterministicTotal);
259+
260+
ASSERT_TRUE(listener_sp->GetEvent(event_sp, TIMEOUT));
261+
data = ProgressEventData::GetEventDataFromEvent(event_sp.get());
262+
EXPECT_FALSE(data->IsFinite());
263+
EXPECT_EQ(data->GetCompleted(), max_minus_1);
264+
EXPECT_EQ(data->GetTotal(), Progress::kNonDeterministicTotal);
265+
266+
ASSERT_TRUE(listener_sp->GetEvent(event_sp, TIMEOUT));
267+
data = ProgressEventData::GetEventDataFromEvent(event_sp.get());
268+
EXPECT_FALSE(data->IsFinite());
269+
EXPECT_EQ(data->GetCompleted(), Progress::kNonDeterministicTotal);
270+
EXPECT_EQ(data->GetTotal(), Progress::kNonDeterministicTotal);
271+
272+
ASSERT_FALSE(listener_sp->GetEvent(event_sp, TIMEOUT));
273+
}
274+
275+
TEST_F(ProgressReportTest, TestMinimumReportTime) {
276+
ListenerSP listener_sp = CreateListenerFor(lldb::eBroadcastBitProgress);
277+
EventSP event_sp;
278+
const ProgressEventData *data;
279+
280+
{
281+
Progress progress("Finite progress", "Report 1", /*total=*/20,
282+
m_debugger_sp.get(),
283+
/*minimum_report_time=*/std::chrono::seconds(1));
284+
// Send 10 events in quick succession. These should not generate any events.
285+
for (int i = 0; i < 10; ++i)
286+
progress.Increment();
287+
288+
// Sleep, then send 10 more. This should generate one event for the first
289+
// increment, and then another for completion.
290+
std::this_thread::sleep_for(std::chrono::seconds(1));
291+
for (int i = 0; i < 10; ++i)
292+
progress.Increment();
293+
}
294+
295+
ASSERT_TRUE(listener_sp->GetEvent(event_sp, TIMEOUT));
296+
data = ProgressEventData::GetEventDataFromEvent(event_sp.get());
297+
EXPECT_TRUE(data->IsFinite());
298+
EXPECT_EQ(data->GetCompleted(), 0);
299+
EXPECT_EQ(data->GetTotal(), 20);
300+
301+
ASSERT_TRUE(listener_sp->GetEvent(event_sp, TIMEOUT));
302+
data = ProgressEventData::GetEventDataFromEvent(event_sp.get());
303+
EXPECT_TRUE(data->IsFinite());
304+
EXPECT_EQ(data->GetCompleted(), 11);
305+
EXPECT_EQ(data->GetTotal(), 20);
306+
307+
ASSERT_TRUE(listener_sp->GetEvent(event_sp, TIMEOUT));
308+
data = ProgressEventData::GetEventDataFromEvent(event_sp.get());
309+
EXPECT_TRUE(data->IsFinite());
310+
EXPECT_EQ(data->GetCompleted(), 20);
311+
EXPECT_EQ(data->GetTotal(), 20);
312+
313+
ASSERT_FALSE(listener_sp->GetEvent(event_sp, TIMEOUT));
314+
}
315+
211316
TEST_F(ProgressReportTest, TestProgressManager) {
212317
ListenerSP listener_sp =
213318
CreateListenerFor(lldb::eBroadcastBitProgressCategory);

0 commit comments

Comments
 (0)