Files
ObsidianDragon/src/daemon/daemon_busy_detect.h
T
DanSandClaude Opus 4.8 2c9e99c022 perf(daemon): memoize the external debug.log miss
When following the debug.log of a node this session did not launch, every
poll re-read the last 2 MB of the file and re-scanned it for the process
banner. If that node logs to its console instead, the banner is never
there, so the full re-scan repeated on every poll for the life of the
process.

- A miss is now remembered by pid and file size: if nothing has changed
  since the last miss, or the file is growing but the backoff has not
  elapsed, the scan is skipped.
- The retry schedule re-scans quickly during a fresh-node grace window
  (the banner flushes a beat after the pid appears) and then backs off
  from 4 s, doubling to a 60 s cap. The memo is cleared on a successful
  tie and when the followed process goes away.

Tests: the retry delay is fast within the grace window and then steps
4, 8, 16 s up to the 60 s cap.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
2026-10-13 17:42:30 -05:00

208 lines
9.6 KiB
C++

#pragma once
// Is the node busy with something that stopping it would throw away? Tracks dragonxd's own log markers,
// in order, for two independent states:
// - rebuilding: a witness-cache rebuild (BuildWitnessCache). It holds cs_main for up to an hour on a
// big wallet, its second phase logs nothing and ignores shutdown, and a node killed mid-rebuild redoes
// it (after replaying everything since its last flush) on the next start;
// - replaying: the startup replay ("Activating best chain..."). Stopping there is safe — the daemon
// checks for shutdown between steps and flushes — it just takes a moment.
// A rebuild can start in the middle of a replay, so its end must not clear `replaying`, and the state is
// order-based: it never compares timestamps (POSIX nodes log to stdout without them). Pure and
// header-only, so the test target can feed it lines.
#include <cstdint>
#include <cstdio>
#include <string>
namespace dragonx {
namespace daemon {
/**
* "YYYY-MM-DD HH:MM:SS ..." (dragonxd's debug.log prefix, which is UTC) -> seconds since the epoch, or 0
* when the line has no such prefix. Days-from-civil arithmetic, not mktime(): mktime reads local time.
*/
inline std::int64_t parseDaemonLogUtc(const std::string& line)
{
int y = 0, mo = 0, d = 0, h = 0, mi = 0, s = 0;
if (line.size() < 19 || std::sscanf(line.c_str(), "%4d-%2d-%2d %2d:%2d:%2d", &y, &mo, &d, &h, &mi, &s) != 6)
return 0;
if (mo < 1 || mo > 12 || d < 1 || d > 31 || h > 23 || mi > 59 || s > 60) return 0;
// Howard Hinnant's days_from_civil.
const int yy = y - (mo <= 2 ? 1 : 0);
const int era = (yy >= 0 ? yy : yy - 399) / 400;
const unsigned yoe = static_cast<unsigned>(yy - era * 400);
const unsigned doy = (153u * static_cast<unsigned>(mo + (mo > 2 ? -3 : 9)) + 2u) / 5u + static_cast<unsigned>(d) - 1u;
const unsigned doe = yoe * 365u + yoe / 4u - yoe / 100u + doy;
const std::int64_t days = static_cast<std::int64_t>(era) * 146097 + static_cast<std::int64_t>(doe) - 719468;
return days * 86400 + h * 3600 + mi * 60 + s;
}
class DaemonBusyTracker {
public:
// Feed raw output: any chunking, a line split across two chunks is reassembled.
void feed(const std::string& chunk)
{
for (char c : chunk) {
if (c == '\n') {
feedLine(carry_);
carry_.clear();
} else if (c != '\r') {
carry_.push_back(c);
if (carry_.size() > 64 * 1024) carry_.clear(); // not a log line; don't grow without bound
}
}
}
void feedLine(const std::string& line)
{
// A new daemon process, or the end of the last one: forget everything.
if (contains(line, "DragonX version ") || contains(line, "Hush version ") || contains(line, "Shutdown: done")) {
reset();
return;
}
if (contains(line, "init message: Activating best chain")) {
replaying_ = true;
replayStartUtc_ = parseDaemonLogUtc(line);
lastMarker_ = line;
return;
}
if (contains(line, "init message: Full Node Done Loading") || contains(line, "init message: Done loading")) {
replaying_ = false;
lastMarker_ = line;
return;
}
const size_t read = line.find("Reading blocks for witness rebuild: ");
if (read != std::string::npos || contains(line, "Building Witnesses for block ")) {
if (!rebuilding_) rebuildStartUtc_ = parseDaemonLogUtc(line);
rebuilding_ = true;
if (read != std::string::npos) {
long done = 0, total = 0;
if (std::sscanf(line.c_str() + read, "Reading blocks for witness rebuild: %ld / %ld", &done, &total) == 2) {
readDone_ = done;
readTotal_ = total;
}
}
lastMarker_ = line;
return;
}
// The rebuild's end. UpdateTip is logged under cs_main, so one after a rebuild marker means the
// rebuild has released it (exceptions and non-bulk paths print no end line).
if (rebuilding_ && (contains(line, "note witness cache(s) to height") ||
contains(line, "aborting witness rebuild") ||
contains(line, "aborted during witness rebuild") ||
contains(line, "aborting building witnesses") ||
contains(line, "UpdateTip: "))) {
rebuilding_ = false;
readDone_ = readTotal_ = 0;
rebuildStartUtc_ = 0;
lastMarker_ = line;
}
}
void reset()
{
rebuilding_ = replaying_ = false;
readDone_ = readTotal_ = 0;
rebuildStartUtc_ = replayStartUtc_ = 0;
lastMarker_.clear();
}
bool rebuilding() const { return rebuilding_; }
bool replaying() const { return replaying_; }
bool busy() const { return rebuilding_ || replaying_; }
long readDone() const { return readDone_; } // the last Phase-1 "reading blocks" progress, 0 if none
long readTotal() const { return readTotal_; }
std::int64_t rebuildStartUtc() const { return rebuildStartUtc_; } // 0: unknown (no timestamps)
std::int64_t replayStartUtc() const { return replayStartUtc_; }
const std::string& lastMarker() const { return lastMarker_; }
private:
static bool contains(const std::string& s, const char* needle) { return s.find(needle) != std::string::npos; }
std::string carry_;
bool rebuilding_ = false;
bool replaying_ = false;
long readDone_ = 0;
long readTotal_ = 0;
std::int64_t rebuildStartUtc_ = 0;
std::int64_t replayStartUtc_ = 0;
std::string lastMarker_;
};
/**
* The "keep the node running?" guard on quit. Prompt only when this quit would stop the node and it is
* rebuilding witnesses, or has been alive but too busy to answer RPC for a while (a rebuild that logged
* no marker). A replay alone never prompts: stopping it is safe. No daemon version suppresses the prompt
* (v1.3.0 does not checkpoint a witness rebuild; nothing survives a kill).
*/
inline bool shouldConfirmStop(bool stopsDaemon, const DaemonBusyTracker& tracker, bool rpcBusyWhileAlive)
{
return stopsDaemon && (tracker.rebuilding() || rpcBusyWhileAlive);
}
// Retry schedule after failing to find a pid's banner in debug.log: re-scan fast during the fresh-node grace
// window, then back off 4 s doubling to a 60 s cap. `backoff` is the caller's running state (0 until grace ends).
inline double nextExternalLogRetryDelay(double ageSinceMiss, double& backoff,
double graceWindow = 15.0, double fast = 2.0,
double base = 4.0, double cap = 60.0)
{
if (ageSinceMiss < graceWindow) return fast;
backoff = (backoff < base) ? base : (backoff * 2.0 < cap ? backoff * 2.0 : cap);
return backoff;
}
/**
* Where to start feeding a DaemonBusyTracker from the last `window` of the debug.log of a node someone else
* started at `processStartUtc` (UTC seconds). Only lines that process wrote count: a node started with
* -printtoconsole leaves an old debug.log behind, whose last run may have died mid-rebuild. Returns the
* offset of that process's startup banner in the window; 0 when its banner is older than the window
* (`windowStartsMidFile`) and the window's first stamped line postdates the process start; npos when the
* log isn't that process's.
*/
inline size_t externalLogFeedOffset(const std::string& window, bool windowStartsMidFile, std::int64_t processStartUtc)
{
size_t lastBanner = std::string::npos;
std::int64_t lastBannerAt = 0, firstStamp = 0;
size_t pos = 0;
while (pos < window.size()) {
size_t end = window.find('\n', pos);
if (end == std::string::npos) end = window.size();
const std::string line = window.substr(pos, end - pos);
const std::int64_t at = parseDaemonLogUtc(line);
if (at > 0 && firstStamp == 0) firstStamp = at;
if (line.find("DragonX version ") != std::string::npos || line.find("Hush version ") != std::string::npos) {
lastBanner = pos;
lastBannerAt = at;
}
pos = end + 1;
}
if (processStartUtc <= 0) return std::string::npos;
const std::int64_t since = processStartUtc - 5; // the log's whole seconds vs the process's start time
if (lastBanner != std::string::npos) return (lastBannerAt > 0 && lastBannerAt >= since) ? lastBanner : std::string::npos;
if (windowStartsMidFile && firstStamp > 0 && firstStamp >= since) return 0;
return std::string::npos;
}
// What the "node is starting / not answering" overlay should say, most specific first.
enum class DaemonStatusKind {
Rebuilding, // its own log says it's rebuilding note witnesses
Replaying, // its own log says it's catching up on blocks it saved before (startup replay)
InitPhase, // a recognisable init phase line (loading the block index, verifying, ...)
Busy, // it answers the connection but not the request (reply timeout / queue full)
Launching, // nothing bound to the RPC port yet
};
inline DaemonStatusKind chooseDaemonStatus(bool hasInitPhaseLine, bool reachableButBusy,
const DaemonBusyTracker& tracker)
{
if (tracker.rebuilding()) return DaemonStatusKind::Rebuilding;
if (tracker.replaying()) return DaemonStatusKind::Replaying;
if (hasInitPhaseLine) return DaemonStatusKind::InitPhase;
if (reachableButBusy) return DaemonStatusKind::Busy;
return DaemonStatusKind::Launching;
}
} // namespace daemon
} // namespace dragonx