Revert "[lldb-vscode] attempt to fix flakiness"

Revert "[lldb-vscode] only report long running progress events"

This reverts commit f2c009dbcf.
This reverts commit aa4685c0fb.
This commit is contained in:
Walter Erquinigo 2021-06-21 10:53:31 -07:00
parent c197cddb16
commit 28d9fd00d4
5 changed files with 66 additions and 300 deletions

View File

@ -13,88 +13,43 @@
using namespace lldb_vscode;
using namespace llvm;
// The minimum duration of an event for it to be reported
const std::chrono::duration<double> kStartProgressEventReportDelay =
std::chrono::seconds(1);
// The minimum time interval between update events for reporting. If multiple
// updates fall within the same time interval, only the latest is reported.
const std::chrono::duration<double> kUpdateProgressEventReportDelay =
std::chrono::milliseconds(250);
ProgressEvent::ProgressEvent(uint64_t progress_id, Optional<StringRef> message,
uint64_t completed, uint64_t total,
const ProgressEvent *prev_event)
: m_progress_id(progress_id) {
if (message)
m_message = message->str();
const bool calculate_percentage = total != UINT64_MAX;
if (completed == 0) {
// Start event
m_event_type = progressStart;
// Wait a bit before reporting the start event in case in completes really
// quickly.
m_minimum_allowed_report_time =
m_creation_time + kStartProgressEventReportDelay;
if (calculate_percentage)
m_percentage = 0;
} else if (completed == total) {
// End event
ProgressEvent::ProgressEvent(uint64_t progress_id, const char *message,
uint64_t completed, uint64_t total)
: m_progress_id(progress_id), m_message(message) {
if (completed == total)
m_event_type = progressEnd;
// We should report the end event right away.
m_minimum_allowed_report_time = std::chrono::seconds::zero();
if (calculate_percentage)
m_percentage = 100;
} else {
// Update event
assert(prev_event);
m_percentage = std::min(
(uint32_t)((double)completed / (double)total * 100.0), (uint32_t)99);
if (prev_event->Reported()) {
// Add a small delay between reports
m_minimum_allowed_report_time =
prev_event->m_minimum_allowed_report_time +
kUpdateProgressEventReportDelay;
} else {
// We should use the previous timestamp, as it's still pending
m_minimum_allowed_report_time = prev_event->m_minimum_allowed_report_time;
}
}
else if (completed == 0)
m_event_type = progressStart;
else if (completed < total)
m_event_type = progressUpdate;
else
m_event_type = progressInvalid;
if (0 < total && total < UINT64_MAX)
m_percentage = (uint32_t)(((float)completed / (float)total) * 100.0);
}
Optional<ProgressEvent> ProgressEvent::Create(uint64_t progress_id,
Optional<StringRef> message,
uint64_t completed,
uint64_t total,
const ProgressEvent *prev_event) {
ProgressEvent event(progress_id, message, completed, total, prev_event);
// We shouldn't show unnamed start events in the IDE
if (event.GetEventType() == progressStart && event.GetEventName().empty())
return None;
if (prev_event && prev_event->EqualsForIDE(event))
return None;
return event;
}
bool ProgressEvent::EqualsForIDE(const ProgressEvent &other) const {
bool ProgressEvent::operator==(const ProgressEvent &other) const {
return m_progress_id == other.m_progress_id &&
m_event_type == other.m_event_type &&
m_percentage == other.m_percentage;
}
ProgressEventType ProgressEvent::GetEventType() const { return m_event_type; }
StringRef ProgressEvent::GetEventName() const {
const char *ProgressEvent::GetEventName() const {
if (m_event_type == progressStart)
return "progressStart";
else if (m_event_type == progressEnd)
return "progressEnd";
else
else if (m_event_type == progressUpdate)
return "progressUpdate";
else
return "progressInvalid";
}
bool ProgressEvent::IsValid() const { return m_event_type != progressInvalid; }
uint64_t ProgressEvent::GetID() const { return m_progress_id; }
json::Value ProgressEvent::ToJSON() const {
llvm::json::Object event(CreateEventObject(GetEventName()));
llvm::json::Object body;
@ -110,7 +65,9 @@ json::Value ProgressEvent::ToJSON() const {
body.try_emplace("cancellable", false);
}
std::string timestamp(llvm::formatv("{0:f9}", m_creation_time.count()));
auto now = std::chrono::duration<double>(
std::chrono::system_clock::now().time_since_epoch());
std::string timestamp(llvm::formatv("{0:f9}", now.count()));
EmplaceSafeString(body, "timestamp", timestamp);
if (m_percentage)
@ -120,108 +77,17 @@ json::Value ProgressEvent::ToJSON() const {
return json::Value(std::move(event));
}
bool ProgressEvent::Report(ProgressEventReportCallback callback) {
if (Reported())
return true;
if (std::chrono::system_clock::now().time_since_epoch() <
m_minimum_allowed_report_time)
return false;
ProgressEventFilterQueue::ProgressEventFilterQueue(
std::function<void(ProgressEvent)> callback)
: m_callback(callback) {}
m_reported = true;
callback(*this);
return true;
}
void ProgressEventFilterQueue::Push(const ProgressEvent &event) {
if (!event.IsValid())
return;
bool ProgressEvent::Reported() const { return m_reported; }
ProgressEventManager::ProgressEventManager(
const ProgressEvent &start_event,
ProgressEventReportCallback report_callback)
: m_start_event(start_event), m_finished(false),
m_report_callback(report_callback) {}
bool ProgressEventManager::ReportIfNeeded() {
// The event finished before we were able to report it.
if (!m_start_event.Reported() && Finished())
return true;
if (!m_start_event.Report(m_report_callback))
return false;
if (m_last_update_event)
m_last_update_event->Report(m_report_callback);
return true;
}
const ProgressEvent &ProgressEventManager::GetMostRecentEvent() const {
return m_last_update_event ? *m_last_update_event : m_start_event;
}
void ProgressEventManager::Update(uint64_t progress_id, uint64_t completed,
uint64_t total) {
if (Optional<ProgressEvent> event = ProgressEvent::Create(
progress_id, None, completed, total, &GetMostRecentEvent())) {
if (event->GetEventType() == progressEnd)
m_finished = true;
m_last_update_event = *event;
ReportIfNeeded();
}
}
bool ProgressEventManager::Finished() const { return m_finished; }
ProgressEventReporter::ProgressEventReporter(
ProgressEventReportCallback report_callback)
: m_report_callback(report_callback) {
m_thread_should_exit = false;
m_thread = std::thread([&] {
while (!m_thread_should_exit) {
std::this_thread::sleep_for(kUpdateProgressEventReportDelay);
ReportStartEvents();
}
});
}
ProgressEventReporter::~ProgressEventReporter() {
m_thread_should_exit = true;
m_thread.join();
}
void ProgressEventReporter::ReportStartEvents() {
std::lock_guard<std::mutex> locker(m_mutex);
while (!m_unreported_start_events.empty()) {
ProgressEventManagerSP event_manager = m_unreported_start_events.front();
if (event_manager->Finished())
m_unreported_start_events.pop();
else if (event_manager->ReportIfNeeded())
m_unreported_start_events
.pop(); // we remove it from the queue as it started reporting
// already, the Push method will be able to continue its
// reports.
else
break; // If we couldn't report it, then the next event in the queue won't
// be able as well, as it came later.
}
}
void ProgressEventReporter::Push(uint64_t progress_id, const char *message,
uint64_t completed, uint64_t total) {
std::lock_guard<std::mutex> locker(m_mutex);
auto it = m_event_managers.find(progress_id);
if (it == m_event_managers.end()) {
if (Optional<ProgressEvent> event =
ProgressEvent::Create(progress_id, StringRef(message), completed, total)) {
ProgressEventManagerSP event_manager =
std::make_shared<ProgressEventManager>(*event, m_report_callback);
m_event_managers.insert({progress_id, event_manager});
m_unreported_start_events.push(event_manager);
}
} else {
it->second->Update(progress_id, completed, total);
if (it->second->Finished())
m_event_managers.erase(it);
auto it = m_last_events.find(event.GetID());
if (it == m_last_events.end() || !(it->second == event)) {
m_last_events[event.GetID()] = event;
m_callback(event);
}
}

View File

@ -6,10 +6,6 @@
//
//===----------------------------------------------------------------------===//
#include <mutex>
#include <queue>
#include <thread>
#include "VSCodeForward.h"
#include "llvm/Support/JSON.h"
@ -17,142 +13,50 @@
namespace lldb_vscode {
enum ProgressEventType {
progressInvalid,
progressStart,
progressUpdate,
progressEnd
};
class ProgressEvent;
using ProgressEventReportCallback = std::function<void(ProgressEvent &)>;
class ProgressEvent {
public:
/// Actual constructor to use that returns an optional, as the event might be
/// not apt for the IDE, e.g. an unnamed start event, or a redundant one.
///
/// \param[in] progress_id
/// ID for this event.
///
/// \param[in] message
/// Message to display in the UI. Required for start events.
///
/// \param[in] completed
/// Number of jobs completed.
///
/// \param[in] total
/// Total number of jobs, or \b UINT64_MAX if not determined.
///
/// \param[in] prev_event
/// Previous event if this one is an update. If \b nullptr, then a start
/// event will be created.
static llvm::Optional<ProgressEvent>
Create(uint64_t progress_id, llvm::Optional<llvm::StringRef> message,
uint64_t completed, uint64_t total,
const ProgressEvent *prev_event = nullptr);
ProgressEvent() {}
ProgressEvent(uint64_t progress_id, const char *message, uint64_t completed,
uint64_t total);
llvm::json::Value ToJSON() const;
/// \return
/// \b true if two event messages would result in the same event for the
/// IDE, e.g. same rounded percentage.
bool EqualsForIDE(const ProgressEvent &other) const;
/// This operator returns \b true if two event messages
/// would result in the same event for the IDE, e.g.
/// same rounded percentage.
bool operator==(const ProgressEvent &other) const;
llvm::StringRef GetEventName() const;
const char *GetEventName() const;
ProgressEventType GetEventType() const;
bool IsValid() const;
/// Report this progress event to the provided callback only if enough time
/// has passed since the creation of the event and since the previous reported
/// update.
bool Report(ProgressEventReportCallback callback);
bool Reported() const;
uint64_t GetID() const;
private:
ProgressEvent(uint64_t progress_id, llvm::Optional<llvm::StringRef> message,
uint64_t completed, uint64_t total,
const ProgressEvent *prev_event);
uint64_t m_progress_id;
std::string m_message;
const char *m_message;
ProgressEventType m_event_type;
llvm::Optional<uint32_t> m_percentage;
std::chrono::duration<double> m_creation_time =
std::chrono::system_clock::now().time_since_epoch();
std::chrono::duration<double> m_minimum_allowed_report_time;
bool m_reported = false;
};
/// Class that keeps the start event and its most recent update.
/// It controls when the event should start being reported to the IDE.
class ProgressEventManager {
public:
ProgressEventManager(const ProgressEvent &start_event,
ProgressEventReportCallback report_callback);
/// Report the start event and the most recent update if the event has lasted
/// for long enough.
///
/// \return
/// \b false if the event hasn't finished and hasn't reported anything
/// yet.
bool ReportIfNeeded();
/// Receive a new progress event for the start event and try to report it if
/// appropriate.
void Update(uint64_t progress_id, uint64_t completed, uint64_t total);
/// \return
/// \b true if a \a progressEnd event has been notified. There's no
/// need to try to report manually an event that has finished.
bool Finished() const;
const ProgressEvent &GetMostRecentEvent() const;
private:
ProgressEvent m_start_event;
llvm::Optional<ProgressEvent> m_last_update_event;
bool m_finished;
ProgressEventReportCallback m_report_callback;
};
using ProgressEventManagerSP = std::shared_ptr<ProgressEventManager>;
/// Class that filters out progress event messages that shouldn't be reported
/// to the IDE, because they are invalid, they carry no new information, or they
/// don't last long enough.
///
/// We need to limit the amount of events that are sent to the IDE, as they slow
/// the render thread of the UI user, and they end up spamming the DAP
/// connection, which also takes some processing time out of the IDE.
class ProgressEventReporter {
/// to the IDE, either because they are invalid or because they are too chatty.
class ProgressEventFilterQueue {
public:
/// \param[in] report_callback
/// Function to invoke to report the event to the IDE.
ProgressEventReporter(ProgressEventReportCallback report_callback);
ProgressEventFilterQueue(std::function<void(ProgressEvent)> callback);
~ProgressEventReporter();
/// Add a new event to the internal queue and report the event if
/// appropriate.
void Push(uint64_t progress_id, const char *message, uint64_t completed,
uint64_t total);
void Push(const ProgressEvent &event);
private:
/// Report to the IDE events that haven't been reported to the IDE and have
/// lasted long enough.
void ReportStartEvents();
ProgressEventReportCallback m_report_callback;
std::map<uint64_t, ProgressEventManagerSP> m_event_managers;
/// Queue of start events in chronological order
std::queue<ProgressEventManagerSP> m_unreported_start_events;
/// Thread used to invoke \a ReportStartEvents periodically.
std::thread m_thread;
bool m_thread_should_exit;
/// Mutex that prevents running \a Push and \a ReportStartEvents
/// simultaneously, as both read and modify the same underlying objects.
std::mutex m_mutex;
std::function<void(ProgressEvent)> m_callback;
std::map<uint64_t, ProgressEvent> m_last_events;
};
} // namespace lldb_vscode

View File

@ -42,7 +42,7 @@ VSCode::VSCode()
focus_tid(LLDB_INVALID_THREAD_ID), sent_terminated_event(false),
stop_at_entry(false), is_attach(false), reverse_request_seq(0),
waiting_for_run_in_terminal(false),
progress_event_reporter(
progress_event_queue(
[&](const ProgressEvent &event) { SendJSON(event.ToJSON()); }) {
const char *log_file_path = getenv("LLDBVSCODE_LOG");
#if defined(_WIN32)
@ -322,9 +322,8 @@ void VSCode::SendOutput(OutputType o, const llvm::StringRef output) {
// };
// }
void VSCode::SendProgressEvent(uint64_t progress_id, const char *message,
uint64_t completed, uint64_t total) {
progress_event_reporter.Push(progress_id, message, completed, total);
void VSCode::SendProgressEvent(const ProgressEvent &event) {
progress_event_queue.Push(event);
}
void __attribute__((format(printf, 3, 4)))

View File

@ -114,7 +114,7 @@ struct VSCode {
uint32_t reverse_request_seq;
std::map<std::string, RequestCallback> request_handlers;
bool waiting_for_run_in_terminal;
ProgressEventReporter progress_event_reporter;
ProgressEventFilterQueue progress_event_queue;
// Keep track of the last stop thread index IDs as threads won't go away
// unless we send a "thread" event to indicate the thread exited.
llvm::DenseSet<lldb::tid_t> thread_ids;
@ -125,6 +125,10 @@ struct VSCode {
int64_t GetLineForPC(int64_t sourceReference, lldb::addr_t pc) const;
ExceptionBreakpoint *GetExceptionBreakpoint(const std::string &filter);
ExceptionBreakpoint *GetExceptionBreakpoint(const lldb::break_id_t bp_id);
// Send the JSON in "json_str" to the "out" stream. Correctly send the
// "Content-Length:" field followed by the length, followed by the raw
// JSON bytes.
void SendJSON(const std::string &json_str);
// Serialize the JSON value into a string and send the JSON packet to
// the "out" stream.
@ -134,8 +138,7 @@ struct VSCode {
void SendOutput(OutputType o, const llvm::StringRef output);
void SendProgressEvent(uint64_t progress_id, const char *message,
uint64_t completed, uint64_t total);
void SendProgressEvent(const ProgressEvent &event);
void __attribute__((format(printf, 3, 4)))
SendFormattedOutput(OutputType o, const char *format, ...);
@ -205,12 +208,6 @@ struct VSCode {
/// The callback to execute when the given request is triggered by the
/// IDE.
void RegisterRequestCallback(std::string request, RequestCallback callback);
private:
// Send the JSON in "json_str" to the "out" stream. Correctly send the
// "Content-Length:" field followed by the length, followed by the raw
// JSON bytes.
void SendJSON(const std::string &json_str);
};
extern VSCode g_vsc;

View File

@ -389,7 +389,8 @@ void ProgressEventThreadFunction() {
const char *message = lldb::SBDebugger::GetProgressFromEvent(
event, progress_id, completed, total, is_debugger_specific);
if (message)
g_vsc.SendProgressEvent(progress_id, message, completed, total);
g_vsc.SendProgressEvent(
ProgressEvent(progress_id, message, completed, total));
}
}
}
@ -1411,8 +1412,7 @@ void request_modules(const llvm::json::Object &request) {
// }
void request_initialize(const llvm::json::Object &request) {
g_vsc.debugger = lldb::SBDebugger::Create(true /*source_init_files*/);
// TODO: reenable once confirmed that this doesn't make the buildbots flaky
// g_vsc.progress_event_thread = std::thread(ProgressEventThreadFunction);
g_vsc.progress_event_thread = std::thread(ProgressEventThreadFunction);
// Create an empty target right away since we might get breakpoint requests
// before we are given an executable to launch in a "launch" request, or a