mirror of
https://github.com/RetroShare/RetroShare.git
synced 2026-09-14 11:06:01 +05:00
gui(gxs): opt-in latency probes on the group statistics path
Set RS_GUI_PROFILE to a threshold in milliseconds (0 reports everything) to get one line per measured operation on stderr. These probes are what turned every claim of this branch into a number: the 839-jobs-per-second storm, the 104 timeouts, the 172 s serial pass, and the 15 s bounded window were all read from their output rather than guessed. GxsPerfProbe.h is shared byte-for-byte with the branch instrumenting the forum read/unread path, so both merge cleanly whichever lands first. All probes are inert unless the environment variable is set. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
This commit is contained in:
parent
20a3b6ff0a
commit
7aeabb9f25
@ -21,6 +21,7 @@
|
||||
#include <QDateTime>
|
||||
|
||||
#include "NewsFeed.h"
|
||||
#include "gui/gxs/GxsPerfProbe.h"
|
||||
#include "ui_NewsFeed.h"
|
||||
|
||||
#include <retroshare/rsbanlist.h>
|
||||
@ -275,6 +276,11 @@ void NewsFeed::handleForumEvent(std::shared_ptr<const RsEvent> event)
|
||||
const RsGxsForumEvent *pe = dynamic_cast<const RsGxsForumEvent*>(event.get());
|
||||
if(!pe) return;
|
||||
|
||||
// Runs on the GUI thread and builds one full widget per incoming message,
|
||||
// so a sync burst turns into a burst of widget construction here.
|
||||
RsGuiPerf::Probe prof("newsFeed::handleForumEvent");
|
||||
prof.detail(QString("code=%1").arg(static_cast<int>(pe->mForumEventCode)));
|
||||
|
||||
switch(pe->mForumEventCode)
|
||||
{
|
||||
case RsForumEventCode::MODERATOR_LIST_CHANGED:
|
||||
|
||||
@ -38,6 +38,7 @@
|
||||
#include "retroshare/rsgxsifacetypes.h"
|
||||
#include "GxsCommentDialog.h"
|
||||
#include "util/DateTime.h"
|
||||
#include "gui/gxs/GxsPerfProbe.h"
|
||||
|
||||
//#define DEBUG_GROUPFRAMEDIALOG
|
||||
|
||||
@ -982,6 +983,9 @@ void GxsGroupFrameDialog::insertGroupsData(const std::list<RsGxsGenericGroupData
|
||||
return;
|
||||
}
|
||||
|
||||
RsGuiPerf::Probe prof("insertGroupsData");
|
||||
prof.detail(QString("groups=%1").arg(groupList.size()));
|
||||
|
||||
mInFill = true;
|
||||
|
||||
QList<GroupItemInfo> adminList;
|
||||
@ -1110,6 +1114,8 @@ void GxsGroupFrameDialog::updateMessageSummaryListReal(RsGxsGroupId groupId)
|
||||
return;
|
||||
}
|
||||
|
||||
RsGuiPerf::Probe prof("updateMessageSummaryListReal");
|
||||
|
||||
if (groupId.isNull())
|
||||
{
|
||||
QTreeWidgetItem *items[2] = { mYourGroups, mSubscribedGroups };
|
||||
@ -1157,6 +1163,8 @@ void GxsGroupFrameDialog::updateGroupSummary()
|
||||
|
||||
RsQThreadUtils::postToObject( [this,groupInfo]()
|
||||
{
|
||||
RsGuiPerf::Probe prof("groupSummary(UI apply)");
|
||||
|
||||
/* Here it goes any code you want to be executed on the Qt Gui
|
||||
* thread, for example to update the data model with new information
|
||||
* after a blocking call to RetroShare API complete, note that
|
||||
@ -1325,13 +1333,24 @@ void GxsGroupFrameDialog::startOneStatisticsJob(const RsGxsGroupId &groupId)
|
||||
RsThread::async([this,groupId]()
|
||||
{
|
||||
GxsGroupStatistic stats;
|
||||
const bool ok = getGroupStatistics(groupId, stats);
|
||||
bool ok = false;
|
||||
|
||||
{
|
||||
// Runs off the GUI thread, but holds the GXS engine for its whole
|
||||
// duration, so it delays everything the interface waits for.
|
||||
RsGuiPerf::Probe prof("getGroupStatistics");
|
||||
prof.detail(QString::fromStdString(groupId.toStdString()));
|
||||
|
||||
ok = getGroupStatistics(groupId, stats);
|
||||
}
|
||||
|
||||
if(!ok)
|
||||
std::cerr << __PRETTY_FUNCTION__ << " failed to collect group statistics for group " << groupId << std::endl;
|
||||
|
||||
RsQThreadUtils::postToObject( [this,stats,groupId,ok]()
|
||||
{
|
||||
RsGuiPerf::Probe prof("groupStatistics(UI apply)");
|
||||
|
||||
/* Here it goes any code you want to be executed on the Qt Gui
|
||||
* thread, for example to update the data model with new information
|
||||
* after a blocking call to RetroShare API complete, note that
|
||||
|
||||
140
retroshare-gui/src/gui/gxs/GxsPerfProbe.h
Normal file
140
retroshare-gui/src/gui/gxs/GxsPerfProbe.h
Normal file
@ -0,0 +1,140 @@
|
||||
/*******************************************************************************
|
||||
* retroshare-gui/src/gui/gxs/GxsPerfProbe.h *
|
||||
* *
|
||||
* Copyright 2026 by Retroshare Team <retroshare.project@gmail.com> *
|
||||
* *
|
||||
* This program is free software: you can redistribute it and/or modify *
|
||||
* it under the terms of the GNU Affero General Public License as *
|
||||
* published by the Free Software Foundation, either version 3 of the *
|
||||
* License, or (at your option) any later version. *
|
||||
* *
|
||||
* This program is distributed in the hope that it will be useful, *
|
||||
* but WITHOUT ANY WARRANTY; without even the implied warranty of *
|
||||
* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the *
|
||||
* GNU Affero General Public License for more details. *
|
||||
* *
|
||||
* You should have received a copy of the GNU Affero General Public License *
|
||||
* along with this program. If not, see <https://www.gnu.org/licenses/>. *
|
||||
* *
|
||||
*******************************************************************************/
|
||||
|
||||
#pragma once
|
||||
|
||||
// Opt-in latency probes, off unless RS_GUI_PROFILE is set in the environment.
|
||||
// Its value is a reporting threshold in milliseconds, 0 reports everything:
|
||||
//
|
||||
// RS_GUI_PROFILE=0 ./retroshare
|
||||
//
|
||||
// Output goes through RsDbg(), i.e. stderr: launch from a terminal or the lines
|
||||
// go nowhere.
|
||||
|
||||
#include <QString>
|
||||
#include <QTimer>
|
||||
#include <QCoreApplication>
|
||||
|
||||
#include <chrono>
|
||||
#include <cstdlib>
|
||||
|
||||
#include "util/rsdebug.h"
|
||||
|
||||
namespace RsGuiPerf {
|
||||
|
||||
inline double threshold()
|
||||
{
|
||||
// <0 means disabled. Read once, the environment does not change at runtime.
|
||||
static const double t = []() -> double {
|
||||
const char *v = getenv("RS_GUI_PROFILE");
|
||||
if(!v)
|
||||
v = getenv("RS_FORUM_PROFILE"); // legacy name of the first investigation
|
||||
return v ? atof(v) : -1.0;
|
||||
}();
|
||||
|
||||
return t;
|
||||
}
|
||||
|
||||
inline bool enabled() { return threshold() >= 0; }
|
||||
|
||||
/* Breadcrumb of the last operation a probe measured on the current thread. The
|
||||
* stall watchdog prints it, so a stall can be attributed even when the probe
|
||||
* that covered it stayed below the reporting threshold. */
|
||||
inline const char *& lastOp() { static thread_local const char *s = "none"; return s; }
|
||||
inline double& lastOpMs() { static thread_local double d = 0; return d; }
|
||||
|
||||
/*!
|
||||
* \brief RAII timer around one operation.
|
||||
*
|
||||
* Report a probe placed on the GUI thread as time the interface stayed frozen.
|
||||
*/
|
||||
class Probe
|
||||
{
|
||||
public:
|
||||
explicit Probe(const char *what)
|
||||
: mWhat(what), mStart(std::chrono::steady_clock::now()) {}
|
||||
|
||||
~Probe()
|
||||
{
|
||||
if(!enabled())
|
||||
return;
|
||||
|
||||
const double ms = std::chrono::duration<double,std::milli>(
|
||||
std::chrono::steady_clock::now() - mStart ).count();
|
||||
|
||||
lastOp() = mWhat;
|
||||
lastOpMs() = ms;
|
||||
|
||||
if(ms >= threshold())
|
||||
RsDbg() << "GUI-PROF " << mWhat << " " << mDetails.toStdString()
|
||||
<< " in " << ms << "ms";
|
||||
}
|
||||
|
||||
void detail(const QString& s) { mDetails = s; }
|
||||
|
||||
private:
|
||||
const char *mWhat;
|
||||
QString mDetails;
|
||||
std::chrono::steady_clock::time_point mStart;
|
||||
};
|
||||
|
||||
/*!
|
||||
* \brief Watchdog for the GUI thread itself.
|
||||
*
|
||||
* The probes above only measure the code they wrap, so they cannot see a stall
|
||||
* that happens anywhere else. This timer runs on the GUI thread and reports
|
||||
* whenever the event loop failed to come back on time, whatever the reason and
|
||||
* wherever the blocking code lives. It also names the last operation a probe
|
||||
* measured, which points at the culprit when one covers it.
|
||||
*
|
||||
* Safe to call several times, only the first call installs anything.
|
||||
*/
|
||||
inline void installGuiStallWatchdog()
|
||||
{
|
||||
static bool installed = false;
|
||||
|
||||
if(installed || !enabled())
|
||||
return;
|
||||
|
||||
installed = true;
|
||||
|
||||
static const int TICK_MS = 50;
|
||||
|
||||
QTimer *timer = new QTimer(QCoreApplication::instance());
|
||||
auto *last = new std::chrono::steady_clock::time_point(
|
||||
std::chrono::steady_clock::now() );
|
||||
|
||||
QObject::connect(timer, &QTimer::timeout, QCoreApplication::instance(), [last]()
|
||||
{
|
||||
const auto now = std::chrono::steady_clock::now();
|
||||
const double ms = std::chrono::duration<double,std::milli>(now - *last).count();
|
||||
*last = now;
|
||||
|
||||
// Anything above the tick plus a comfortable margin means the event loop
|
||||
// was busy or blocked for that long.
|
||||
if(ms > TICK_MS + 150)
|
||||
RsDbg() << "GUI-PROF GUI-THREAD-STALL " << (ms - TICK_MS)
|
||||
<< "ms last_probe=" << lastOp() << " (" << lastOpMs() << "ms)";
|
||||
});
|
||||
|
||||
timer->start(TICK_MS);
|
||||
}
|
||||
|
||||
} // namespace RsGuiPerf
|
||||
@ -19,6 +19,7 @@
|
||||
*******************************************************************************/
|
||||
|
||||
#include "GxsForumsDialog.h"
|
||||
#include "gui/gxs/GxsPerfProbe.h"
|
||||
#include "GxsForumGroupDialog.h"
|
||||
#include "GxsForumThreadWidget.h"
|
||||
#include "CreateGxsForumMsg.h"
|
||||
@ -66,6 +67,8 @@ void GxsForumsDialog::flushPendingStatistics()
|
||||
|
||||
void GxsForumsDialog::handleEvent_main_thread(std::shared_ptr<const RsEvent> event)
|
||||
{
|
||||
RsGuiPerf::Probe prof("forumsDialog::handleEvent");
|
||||
|
||||
if(event->mType == RsEventType::GXS_FORUMS)
|
||||
{
|
||||
const RsGxsForumEvent *e = dynamic_cast<const RsGxsForumEvent*>(event.get());
|
||||
|
||||
Loading…
Reference in New Issue
Block a user