wallet/rpc: monotonic timers and a quieter default slow-walk line

Review follow-ups to the GetFilteredNotes / RPC timing logs:

- Time with std::chrono::steady_clock instead of GetTimeMicros(), which
  is the system clock. A wall-clock step otherwise writes false
  ">= 500ms" lines unconditionally; on a WSL2 host the clock was seen
  stepping +3.6s every ~32s.
- A long-poll getblocktemplate deliberately blocks (with cs_main
  released) until a new block arrives, so it is logged only under
  -debug=bench.
- Log the method as "RPC method=<name> took <n>ms". A bare " rescan "
  token followed by "<n>ms" matches ObsidianDragon's rescan-finished
  log heuristic.
- The always-on slow-walk line keeps just the filters and the walk
  time; the wallet-size counts (txs, notes, spent, entries) are logged
  only with -debug=bench, so a shared debug.log doesn't carry them.
- The -txindex=0 startup line names the version.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
2026-10-17 08:16:09 -05:00
co-authored by Claude Opus 5.5
parent 34b94e761a
commit 21586b353a
3 changed files with 26 additions and 13 deletions
+9 -4
View File
@@ -45,6 +45,7 @@
#include <limits>
#include <system_error>
#include <thread>
#include <chrono>
#include <atomic>
#include <mutex>
#include "zcash/zip32.h"
@@ -5762,7 +5763,7 @@ void CWallet::GetFilteredNotes(
// Every caller already holds LOCK2, so the lock above never waits and this times the walk alone.
// Time spent waiting for the locks shows up in the RPC's own "took" line (rpc/server.cpp).
const int64_t nTimeStart = GetTimeMicros();
const std::chrono::steady_clock::time_point walkStart = std::chrono::steady_clock::now();
const size_t nEntriesBefore = saplingEntries.size();
unsigned int nTxs = 0, nNotes = 0, nSpent = 0;
@@ -5850,12 +5851,16 @@ void CWallet::GetFilteredNotes(
}
// A slow walk holds cs_main long enough to stall block connection, so it is always logged; a
// fast one only with -debug=bench (the balance RPCs run it on every GUI poll).
const int64_t nWalkMs = (GetTimeMicros() - nTimeStart) / 1000;
if (nWalkMs >= 500 || LogAcceptCategory("bench")) {
// fast one only with -debug=bench (the balance RPCs run it on every GUI poll). The wallet-size
// counts go to the default log only with -debug=bench too.
const int64_t nWalkMs = std::chrono::duration_cast<std::chrono::milliseconds>(std::chrono::steady_clock::now() - walkStart).count();
if (LogAcceptCategory("bench")) {
LogPrintf("%s: minDepth=%d ignoreSpent=%d requireSpendingKey=%d ignoreLocked=%d txs=%u/%u notes=%u spent=%u entries=%u walk=%dms\n",
__func__, minDepth, ignoreSpent, requireSpendingKey, ignoreLocked, nTxs, (unsigned int)mapWallet.size(),
nNotes, nSpent, (unsigned int)(saplingEntries.size() - nEntriesBefore), nWalkMs);
} else if (nWalkMs >= 500) {
LogPrintf("%s: minDepth=%d ignoreSpent=%d requireSpendingKey=%d ignoreLocked=%d walk=%dms\n",
__func__, minDepth, ignoreSpent, requireSpendingKey, ignoreLocked, nWalkMs);
}
}