merge: resolve upstream/master conflicts for PR #736

This commit is contained in:
efiten
2026-05-18 21:06:28 +02:00
15 changed files with 1205 additions and 42 deletions
+6
View File
@@ -152,6 +152,7 @@ type AnalyticsRecomputeIntervals struct {
Channels time.Duration
HashCollisions time.Duration
HashSizes time.Duration
Roles time.Duration
}
func pickInterval(override, def time.Duration) time.Duration {
@@ -219,9 +220,14 @@ func (s *PacketStore) StartAnalyticsRecomputers(defaultInterval time.Duration, o
"hash-sizes", pickInterval(ov.HashSizes, defaultInterval),
func() interface{} { return s.computeAnalyticsHashSizesWithCapability("") },
)
s.recompRoles = newAnalyticsRecomputer(
"roles", pickInterval(ov.Roles, defaultInterval),
func() interface{} { return s.computeAnalyticsRoles() },
)
all := []*analyticsRecomputer{
s.recompTopology, s.recompRF, s.recompDistance,
s.recompChannels, s.recompHashCollisions, s.recompHashSizes,
s.recompRoles,
}
s.analyticsRecomputerMu.Unlock()
+2 -2
View File
@@ -540,8 +540,7 @@ func (c *Config) IsObserverBlacklisted(id string) bool {
// data slowly." Lower values give fresher data at higher CPU cost.
//
// RecomputeIntervalSeconds keys (all optional):
//
// topology, rf, distance, channels, hashCollisions, hashSizes
// topology, rf, distance, channels, hashCollisions, hashSizes, roles
type AnalyticsConfig struct {
DefaultIntervalSeconds int `json:"defaultIntervalSeconds,omitempty"`
RecomputeIntervalSeconds map[string]int `json:"recomputeIntervalSeconds,omitempty"`
@@ -577,5 +576,6 @@ func (c *Config) AnalyticsRecomputeIntervals() AnalyticsRecomputeIntervals {
out.Channels = get("channels")
out.HashCollisions = get("hashCollisions")
out.HashSizes = get("hashSizes")
out.Roles = get("roles")
return out
}
+15
View File
@@ -362,6 +362,21 @@ func main() {
defer stopAnalyticsRecomp()
log.Printf("[analytics-recompute] background recompute enabled (default=%s)", cfg.AnalyticsDefaultRecomputeInterval())
// Steady-state repeater-enrichment recomputer (issue #1262).
// Prewarms the bulk caches feeding handleNodes so the very first
// /api/nodes?limit=2000 from live.js's SPA bootstrap hits a
// populated cache instead of paying a 15.7s on-thread rebuild.
// Uses the configured RelayActiveHours window and the same
// default recompute interval as the other analytics caches.
relayWindowHours := cfg.GetHealthThresholds().RelayActiveHours
stopRepeaterEnrichRecomp := store.StartRepeaterEnrichmentRecomputer(
relayWindowHours,
cfg.AnalyticsDefaultRecomputeInterval(),
)
defer stopRepeaterEnrichRecomp()
log.Printf("[repeater-enrich-recompute] background recompute enabled (window=%.1fh, interval=%s)",
relayWindowHours, cfg.AnalyticsDefaultRecomputeInterval())
// Auto-prune old packets if retention.packetDays is configured
vacuumPages := cfg.IncrementalVacuumPages()
var stopPrune func()
+119
View File
@@ -0,0 +1,119 @@
package main
import (
"fmt"
"net/http"
"net/http/httptest"
"testing"
"time"
)
// TestHandleNodesLimit2000ColdMiss is a regression guard for issue #1262.
//
// Background: PR #1260 added a 15s-TTL bulk-cache for repeater
// enrichment in handleNodes (GetRepeaterRelayInfoMap /
// GetRepeaterUsefulnessScoreMap). On warm hits the request is ~40ms.
// On the very first request after server startup (or after the 15s TTL
// expires) the cache rebuild runs on the request-serving goroutine and
// is O(byPathHop + parsed timestamps). On staging (75k tx, 600 nodes)
// the cold rebuild took 15.7s.
//
// /api/nodes?limit=2000 is the SPA's hop-resolver bootstrap call (see
// public/live.js) so EVERY cold SPA load eats the cold-rebuild cost.
//
// Acceptance: /api/nodes?limit=2000 must return in <2s on a
// realistic-shape fleet WITHOUT a prior warmup request — i.e. once the
// store has been initialized and the steady-state repeater-enrichment
// recomputer prewarm has run.
func TestHandleNodesLimit2000ColdMiss(t *testing.T) {
if testing.Short() {
t.Skip("perf test")
}
srv, router := setupTestServer(t)
conn := srv.db.conn
// Seed 600 nodes — 50 repeaters/rooms with most-recent last_seen so
// they sit at the top of the limit=2000 page, plus 550 stale
// companions.
tx, err := conn.Begin()
if err != nil {
t.Fatal(err)
}
stmt, err := tx.Prepare(`INSERT INTO nodes
(public_key, name, role, lat, lon, last_seen, first_seen, advert_count, foreign_advert)
VALUES (?, ?, ?, 0, 0, ?, '2026-01-01T00:00:00Z', 1, 0)`)
if err != nil {
t.Fatal(err)
}
now := time.Now().UTC()
for i := 0; i < 50; i++ {
pk := fmt.Sprintf("pkrepeat%056x", i)
ts := now.Add(-time.Duration(i) * time.Minute).Format(time.RFC3339Nano)
if _, err := stmt.Exec(pk, fmt.Sprintf("rep%d", i), "repeater", ts); err != nil {
t.Fatal(err)
}
}
for i := 0; i < 550; i++ {
pk := fmt.Sprintf("pkcompan%056x", i)
ts := now.Add(-time.Duration(60+i) * time.Minute).Format(time.RFC3339Nano)
if _, err := stmt.Exec(pk, fmt.Sprintf("comp%d", i), "companion", ts); err != nil {
t.Fatal(err)
}
}
if err := tx.Commit(); err != nil {
t.Fatal(err)
}
// Seed the in-memory packet store: a non-trivial body of non-advert
// traffic where each repeater appears as a path hop on many txs.
// This is what makes the bulk-cache rebuild expensive.
const numTx = 150000
const hopsPerTx = 6
pt2 := 2
store := srv.store
for i := 0; i < numTx; i++ {
txID := 100000 + i
ts := now.Add(-time.Duration(i) * time.Second).Format(time.RFC3339Nano)
stx := &StoreTx{
ID: txID,
Hash: fmt.Sprintf("h%d", txID),
FirstSeen: ts,
PayloadType: &pt2,
}
store.byPayloadType[pt2] = append(store.byPayloadType[pt2], stx)
// Shared 1-byte prefix bucket to mirror production hop-prefix
// collisions.
store.byPathHop["pk"] = append(store.byPathHop["pk"], stx)
for h := 0; h < hopsPerTx; h++ {
repIdx := (i + h) % 50
pk := fmt.Sprintf("pkrepeat%056x", repIdx)
store.byPathHop[pk] = append(store.byPathHop[pk], stx)
}
}
// Steady-state repeater-enrichment recomputer (the fix for #1262)
// prewarms the bulk caches at startup so the first handler request
// — which is /api/nodes?limit=2000 from live.js on every cold SPA
// load — hits the cache instead of rebuilding it on-thread.
stop := store.StartRepeaterEnrichmentRecomputer(24, 5*time.Minute)
defer stop()
// NO HTTP warmup — we are explicitly measuring the first
// limit=2000 request, the way live.js sees it.
start := time.Now()
req := httptest.NewRequest("GET", "/api/nodes?limit=2000", nil)
w := httptest.NewRecorder()
router.ServeHTTP(w, req)
elapsed := time.Since(start)
if w.Code != http.StatusOK {
t.Fatalf("status=%d body=%s", w.Code, w.Body.String())
}
const budget = 2 * time.Second
t.Logf("/api/nodes?limit=2000 elapsed=%v on %d nodes, %d tx", elapsed, 600, numTx)
if elapsed > budget {
t.Fatalf("/api/nodes?limit=2000 cold-miss too slow for #1262: %v (budget %v) on %d nodes, %d tx",
elapsed, budget, 600, numTx)
}
}
+127
View File
@@ -0,0 +1,127 @@
package main
import (
"fmt"
"net/http"
"net/http/httptest"
"testing"
"time"
)
// TestHandleNodesPerfLargeFleet asserts the /api/nodes endpoint (no `limit`
// param — relying on the server-side default) returns in well under 2s on a
// realistic-shape fleet: 600 nodes, ~50 of them repeaters/rooms with rich
// path-hop activity, and a non-trivial byPayloadType + byPathHop index.
//
// Regression guard for issue #1257:
// /api/nodes (no limit) → 32.9s, 30KB on staging (637 nodes)
// /api/nodes?limit=2000 → 4.9s, 360KB
//
// Root cause class: per-repeater enrichment in handleNodes calls
// store.GetRepeaterRelayInfo + GetRepeaterUsefulnessScore separately for
// each node in the page. Each call takes its own RLock and walks
// byPathHop[pk] / byPayloadType, doing expensive timestamp parsing.
// For the default-page case (top-50 by last_seen, mostly hot repeaters)
// that is hundreds of thousands of timestamp parses per request.
//
// Budget: 2s. On the broken implementation with this fixture the
// endpoint blows the budget; with batched/cached per-page enrichment it
// completes in well under 500ms.
func TestHandleNodesPerfLargeFleet(t *testing.T) {
if testing.Short() {
t.Skip("perf test")
}
srv, router := setupTestServer(t)
conn := srv.db.conn
// Seed 600 nodes — 50 repeaters/rooms with most-recent last_seen so
// they land on the default page, plus 550 stale companions.
tx, err := conn.Begin()
if err != nil {
t.Fatal(err)
}
stmt, err := tx.Prepare(`INSERT INTO nodes
(public_key, name, role, lat, lon, last_seen, first_seen, advert_count, foreign_advert)
VALUES (?, ?, ?, 0, 0, ?, '2026-01-01T00:00:00Z', 1, 0)`)
if err != nil {
t.Fatal(err)
}
now := time.Now().UTC()
for i := 0; i < 50; i++ {
pk := fmt.Sprintf("pkrepeat%056x", i)
ts := now.Add(-time.Duration(i) * time.Minute).Format(time.RFC3339Nano)
if _, err := stmt.Exec(pk, fmt.Sprintf("rep%d", i), "repeater", ts); err != nil {
t.Fatal(err)
}
}
for i := 0; i < 550; i++ {
pk := fmt.Sprintf("pkcompan%056x", i)
ts := now.Add(-time.Duration(60+i) * time.Minute).Format(time.RFC3339Nano)
if _, err := stmt.Exec(pk, fmt.Sprintf("comp%d", i), "companion", ts); err != nil {
t.Fatal(err)
}
}
if err := tx.Commit(); err != nil {
t.Fatal(err)
}
// Seed the in-memory packet store: a body of non-advert traffic with
// each repeater appearing as a path hop on many of them. This is what
// makes the per-node GetRepeaterRelayInfo / GetRepeaterUsefulnessScore
// calls expensive on the broken impl.
const numTx = 150000
const hopsPerTx = 6
pt2 := 2 // non-advert payload type
store := srv.store
// Also index every tx under a single shared 1-byte prefix so the
// GetRepeaterRelayInfo prefix-collision branch fans every per-node
// call through the full non-advert tx set (matches production where
// many repeaters share a 1-byte hop prefix).
for i := 0; i < numTx; i++ {
txID := 100000 + i
ts := now.Add(-time.Duration(i) * time.Second).Format(time.RFC3339Nano)
stx := &StoreTx{
ID: txID,
Hash: fmt.Sprintf("h%d", txID),
FirstSeen: ts,
PayloadType: &pt2,
}
store.byPayloadType[pt2] = append(store.byPayloadType[pt2], stx)
store.byPathHop["pk"] = append(store.byPathHop["pk"], stx)
// Index each repeater under byPathHop so per-node enrichment walks
// a non-trivial slice.
for h := 0; h < hopsPerTx; h++ {
repIdx := (i + h) % 50
pk := fmt.Sprintf("pkrepeat%056x", repIdx)
store.byPathHop[pk] = append(store.byPathHop[pk], stx)
}
}
// Warm-up to amortize first-call costs (cache misses, prepare). Note:
// the per-node Repeater* enrichment is NOT cached, so this warmup
// does not hide the perf bug — it only amortizes one-shot prep.
{
req := httptest.NewRequest("GET", "/api/nodes?limit=1", nil)
w := httptest.NewRecorder()
router.ServeHTTP(w, req)
if w.Code != http.StatusOK {
t.Fatalf("warmup status=%d body=%s", w.Code, w.Body.String())
}
}
start := time.Now()
req := httptest.NewRequest("GET", "/api/nodes", nil)
w := httptest.NewRecorder()
router.ServeHTTP(w, req)
elapsed := time.Since(start)
if w.Code != http.StatusOK {
t.Fatalf("status=%d body=%s", w.Code, w.Body.String())
}
const budget = 2 * time.Second
t.Logf("/api/nodes (no limit) elapsed=%v on %d nodes, %d tx", elapsed, 600, numTx)
if elapsed > budget {
t.Fatalf("/api/nodes (no limit) too slow for #1257: %v (budget %v) on %d nodes, %d tx",
elapsed, budget, 600, numTx)
}
}
+265
View File
@@ -0,0 +1,265 @@
package main
import (
"strings"
"time"
)
// repeaterEnrichTTL bounds how stale the per-page bulk enrichment caches
// for handleNodes may be. Same 15s budget as GetNodeHashSizeInfo — the
// numbers feed an at-a-glance status column, not an alerting path, so
// up-to-15s freshness is fine and keeps the request path O(page) instead
// of O(page × byPathHop[pk] × parsed timestamps).
const repeaterEnrichTTL = 15 * time.Second
// GetRepeaterRelayInfoMap returns a cached pubkey → RepeaterRelayInfo
// map covering EVERY pubkey that currently appears as a path hop in any
// non-advert StoreTx. This is the bulk equivalent of calling
// GetRepeaterRelayInfo(pk, windowHours) once per node.
//
// Why this exists (issue #1257): handleNodes used to call the per-node
// helper inside a per-page loop. Each call grabbed its own RLock and
// re-parsed FirstSeen on every StoreTx indexed under that pubkey's
// byPathHop entry (plus, when the pubkey was >= 2 hex chars, the 1-byte
// prefix bucket — which on busy networks fans out to almost the whole
// non-advert tx set). For the default top-50 page of hot repeaters this
// burned 50 lock acquisitions and hundreds of thousands of timestamp
// parses per request, dominating /api/nodes latency.
//
// The cached map is keyed by lowercase pubkey/hop key (same shape as
// byPathHop). Lookups should use strings.ToLower(pk).
//
// The cache is invalidated by TTL only — never by ingest. With a 15s
// budget that's acceptable for a status column; if a fresher signal is
// ever needed for a non-status caller, expose a non-cached path.
func (s *PacketStore) GetRepeaterRelayInfoMap(windowHours float64) map[string]RepeaterRelayInfo {
s.repeaterEnrichMu.Lock()
if s.repeaterRelayCache != nil &&
time.Since(s.repeaterRelayAt) < repeaterEnrichTTL &&
s.repeaterRelayCacheWin == windowHours {
cached := s.repeaterRelayCache
s.repeaterEnrichMu.Unlock()
return cached
}
s.repeaterEnrichMu.Unlock()
result := s.computeRepeaterRelayInfoMap(windowHours)
s.repeaterEnrichMu.Lock()
s.repeaterRelayCache = result
s.repeaterRelayCacheWin = windowHours
s.repeaterRelayAt = time.Now()
s.repeaterEnrichMu.Unlock()
return result
}
// computeRepeaterRelayInfoMap walks byPathHop once under a single RLock,
// pre-parses every FirstSeen timestamp once (not once-per-pubkey-bucket),
// and emits one RepeaterRelayInfo per hop key.
//
// Time-complexity invariant: O(unique-tx-in-byPathHop + total-key-bucket
// entries). Memory: one map entry per byPathHop key. Both are bounded by
// the same eviction policy that bounds byPathHop itself.
func (s *PacketStore) computeRepeaterRelayInfoMap(windowHours float64) map[string]RepeaterRelayInfo {
s.mu.RLock()
// Snapshot the slices (header copy) so we can release the lock before
// the expensive parse pass. Slice headers point at the live underlying
// arrays but those are append-only-by-id; the worst-case race here is
// that ingest grows a slice we already snapshotted (we miss the new
// tail), which is acceptable for a 15s-TTL status read.
snap := make(map[string][]*StoreTx, len(s.byPathHop))
for k, list := range s.byPathHop {
snap[k] = list
}
// Build a tx-id-keyed pre-parsed cache so the inner loop doesn't
// re-parse the same FirstSeen N times when the same tx is indexed
// under multiple hop keys (very common — every hop on a path indexes
// the tx).
type parsedTx struct {
t time.Time
ok bool
pt int
}
parseCache := make(map[int]parsedTx, 1<<14)
for _, list := range snap {
for _, tx := range list {
if tx == nil {
continue
}
if _, ok := parseCache[tx.ID]; ok {
continue
}
pt := -1
if tx.PayloadType != nil {
pt = *tx.PayloadType
}
t, ok := parseRelayTS(tx.FirstSeen)
parseCache[tx.ID] = parsedTx{t: t, ok: ok, pt: pt}
}
}
s.mu.RUnlock()
now := time.Now().UTC()
cutoff1h := now.Add(-1 * time.Hour)
cutoff24h := now.Add(-24 * time.Hour)
var windowCutoff time.Time
if windowHours > 0 {
windowCutoff = now.Add(-time.Duration(windowHours * float64(time.Hour)))
}
out := make(map[string]RepeaterRelayInfo, len(snap))
for key, list := range snap {
info := RepeaterRelayInfo{WindowHours: windowHours}
// When key looks like a full pubkey (>= 2 hex chars), also fold
// in the matching 1-byte raw-prefix bucket to mirror
// GetRepeaterRelayInfo's behavior. We dedup by tx ID.
var seen map[int]bool
if len(key) >= 2 {
prefix := key[:2]
if prefix != key {
if extra := snap[prefix]; len(extra) > 0 {
seen = make(map[int]bool, len(list)+len(extra))
}
}
}
visit := func(txs []*StoreTx) {
for _, tx := range txs {
if tx == nil {
continue
}
if seen != nil {
if seen[tx.ID] {
continue
}
seen[tx.ID] = true
}
p, ok := parseCache[tx.ID]
if !ok {
continue
}
if p.pt == payloadTypeAdvert {
continue
}
if !p.ok {
continue
}
if p.t.After(cutoff24h) {
info.RelayCount24h++
if p.t.After(cutoff1h) {
info.RelayCount1h++
}
}
if info.LastRelayed == "" || tx.FirstSeen > info.LastRelayed {
info.LastRelayed = tx.FirstSeen
if windowHours > 0 && p.t.After(windowCutoff) {
info.RelayActive = true
} else if windowHours > 0 {
info.RelayActive = false
}
}
}
}
visit(list)
if seen != nil {
prefix := key[:2]
if prefix != key {
visit(snap[prefix])
}
}
out[key] = info
}
return out
}
// GetRepeaterUsefulnessScoreMap returns a cached pubkey → 0..1 score
// for every pubkey appearing in byPathHop. Bulk equivalent of
// GetRepeaterUsefulnessScore. See GetRepeaterRelayInfoMap for the
// motivation (#1257).
func (s *PacketStore) GetRepeaterUsefulnessScoreMap() map[string]float64 {
s.repeaterEnrichMu.Lock()
if s.repeaterUsefulCache != nil && time.Since(s.repeaterUsefulAt) < repeaterEnrichTTL {
cached := s.repeaterUsefulCache
s.repeaterEnrichMu.Unlock()
return cached
}
s.repeaterEnrichMu.Unlock()
result := s.computeRepeaterUsefulnessScoreMap()
s.repeaterEnrichMu.Lock()
s.repeaterUsefulCache = result
s.repeaterUsefulAt = time.Now()
s.repeaterEnrichMu.Unlock()
return result
}
func (s *PacketStore) computeRepeaterUsefulnessScoreMap() map[string]float64 {
s.mu.RLock()
defer s.mu.RUnlock()
totalNonAdvert := 0
for pt, list := range s.byPayloadType {
if pt == payloadTypeAdvert {
continue
}
totalNonAdvert += len(list)
}
out := make(map[string]float64, len(s.byPathHop))
if totalNonAdvert == 0 {
return out
}
denom := float64(totalNonAdvert)
for key, list := range s.byPathHop {
relayed := 0
for _, tx := range list {
if tx == nil {
continue
}
if tx.PayloadType != nil && *tx.PayloadType == payloadTypeAdvert {
continue
}
relayed++
}
if relayed == 0 {
continue
}
score := float64(relayed) / denom
if score < 0 {
score = 0
} else if score > 1 {
score = 1
}
out[key] = score
}
return out
}
// lookupRelayInfo is a small helper to make handleNodes' map lookup
// case-insensitive (byPathHop keys are lowercase; pubkeys arriving from
// the DB row may be either case).
func lookupRelayInfo(m map[string]RepeaterRelayInfo, pubkey string) (RepeaterRelayInfo, bool) {
if v, ok := m[pubkey]; ok {
return v, true
}
if lc := strings.ToLower(pubkey); lc != pubkey {
if v, ok := m[lc]; ok {
return v, true
}
}
return RepeaterRelayInfo{}, false
}
// lookupUsefulnessScore mirrors lookupRelayInfo for the score map.
func lookupUsefulnessScore(m map[string]float64, pubkey string) float64 {
if v, ok := m[pubkey]; ok {
return v
}
if lc := strings.ToLower(pubkey); lc != pubkey {
if v, ok := m[lc]; ok {
return v
}
}
return 0
}
+104
View File
@@ -0,0 +1,104 @@
package main
import (
"sync"
"time"
)
// repeaterEnrichmentRecomputerInterval is the default tick interval
// for the steady-state recompute of the repeater enrichment bulk
// caches. The on-request 15s-TTL fallback in repeater_enrich_bulk.go
// is kept as a safety net — the recomputer just makes sure the cache
// is populated before any request arrives.
//
// 5min mirrors the analytics_recomputer default from #1240 and is
// plenty fresh for an at-a-glance status column.
const repeaterEnrichmentRecomputerDefaultInterval = 5 * time.Minute
// StartRepeaterEnrichmentRecomputer is the steady-state background
// recompute loop for the repeater enrichment bulk caches consumed by
// handleNodes (GetRepeaterRelayInfoMap + GetRepeaterUsefulnessScoreMap).
//
// Why this exists (issue #1262): PR #1260 added a 15s-TTL bulk cache,
// but the rebuild itself runs on the request-serving goroutine on the
// first request after startup or after the TTL expires. On staging
// (75k tx, 600 nodes) that cold rebuild took 15.7s and was triggered
// by every cold SPA load via live.js's /api/nodes?limit=2000 call.
//
// On Start this does an initial synchronous compute (so the next
// request hits cache) and then ticks every `interval` to keep the
// snapshot fresh — same pattern as analytics_recomputer.go (#1240).
//
// Returns a stop closure that signals the goroutine and waits for it
// to exit (with a 5s defensive timeout).
//
// Safe to call multiple times: subsequent calls are no-ops and return
// a no-op stop closure (the original goroutine retains ownership).
func (s *PacketStore) StartRepeaterEnrichmentRecomputer(windowHours float64, interval time.Duration) func() {
if interval <= 0 {
interval = repeaterEnrichmentRecomputerDefaultInterval
}
s.repeaterEnrichRecompMu.Lock()
if s.repeaterEnrichRecompStarted {
s.repeaterEnrichRecompMu.Unlock()
return func() {}
}
s.repeaterEnrichRecompStarted = true
stop := make(chan struct{})
done := make(chan struct{})
s.repeaterEnrichRecompStop = stop
s.repeaterEnrichRecompDone = done
s.repeaterEnrichRecompMu.Unlock()
// Initial synchronous prewarm — the entire point of this recomputer
// is to make sure the very first /api/nodes?limit=2000 from
// live.js's SPA bootstrap (issue #1262) hits a populated cache
// instead of paying the on-thread rebuild cost.
recomputeRepeaterEnrichmentSafe(s, windowHours)
var stopOnce sync.Once
go func() {
defer close(done)
t := time.NewTicker(interval)
defer t.Stop()
for {
select {
case <-t.C:
recomputeRepeaterEnrichmentSafe(s, windowHours)
case <-stop:
return
}
}
}()
return func() {
stopOnce.Do(func() {
close(stop)
})
select {
case <-done:
case <-time.After(5 * time.Second):
}
}
}
// recomputeRepeaterEnrichmentSafe runs both bulk-cache compute paths
// behind a panic recover — a panic in compute must not kill the
// background goroutine (the previous snapshot remains valid).
func recomputeRepeaterEnrichmentSafe(s *PacketStore, windowHours float64) {
defer func() { _ = recover() }()
// Bypass the 15s-TTL gate by forcing a fresh recompute and
// installing the result. The public Get* helpers would return the
// existing cache when within TTL; we want to refresh proactively.
relay := s.computeRepeaterRelayInfoMap(windowHours)
useful := s.computeRepeaterUsefulnessScoreMap()
now := time.Now()
s.repeaterEnrichMu.Lock()
s.repeaterRelayCache = relay
s.repeaterRelayCacheWin = windowHours
s.repeaterRelayAt = now
s.repeaterUsefulCache = useful
s.repeaterUsefulAt = now
s.repeaterEnrichMu.Unlock()
}
@@ -0,0 +1,123 @@
package main
import (
"fmt"
"testing"
"time"
)
// buildResolveTier1HotFixture constructs the synthetic graph + pm shape
// used by both the benchmark and the regression-guard test below. Shape:
// ambiguous prefix "ab" → numCands candidates, plus numContext context
// pubkeys each with edges into the first 3 candidates. This drives the
// tier-1 inner loop to its full path length on every resolve call.
func buildResolveTier1HotFixture(numCands, numContext int) (*prefixMap, *NeighborGraph, []string) {
nodes := make([]nodeInfo, 0, numCands+numContext)
for i := 0; i < numCands; i++ {
nodes = append(nodes, nodeInfo{
PublicKey: fmt.Sprintf("ab%010x", i*0x10101010+1),
Role: "repeater",
Name: fmt.Sprintf("C%d", i),
})
}
contextPubkeys := make([]string, 0, numContext)
for i := 0; i < numContext; i++ {
pk := fmt.Sprintf("c%011x", i*0x12345)
nodes = append(nodes, nodeInfo{PublicKey: pk, Role: "repeater", Name: fmt.Sprintf("X%d", i)})
contextPubkeys = append(contextPubkeys, pk)
}
pm := buildPrefixMap(nodes)
graph := NewNeighborGraph()
now := time.Now()
addEdge := func(a, b string, count int, observers ...string) {
obs := make(map[string]bool, len(observers))
for _, o := range observers {
obs[o] = true
}
key := makeEdgeKey(a, b)
e := &NeighborEdge{
NodeA: key.A,
NodeB: key.B,
Count: count,
FirstSeen: now.Add(-1 * time.Hour),
LastSeen: now,
Observers: obs,
}
graph.edges[key] = e
graph.byNode[key.A] = append(graph.byNode[key.A], e)
graph.byNode[key.B] = append(graph.byNode[key.B], e)
}
winnerPK := nodes[0].PublicKey
for _, cpk := range contextPubkeys {
addEdge(cpk, winnerPK, 20, "obs1", "obs2", "obs3")
for k := 1; k < 3 && k < numCands; k++ {
addEdge(cpk, nodes[k].PublicKey, 3, "obs1")
}
}
return pm, graph, contextPubkeys
}
// BenchmarkResolveWithContextTier1Hot reproduces the analytics-topology hot
// path that regressed between prod d818527 and master (issue #1247).
//
// Shape: ambiguous prefix → N candidates → C context pubkeys. This is
// representative of the per-tx work done inside computeAnalyticsTopology /
// computeAnalyticsRF when calling resolveHop on every hop of every tx with a
// fully-populated aggregate hop context (5k+ contextPubkeys at the staging
// scale).
//
// Before the #1247 fix: ~200 µs/op on this shape (the regressed master).
// After: <50 µs/op on the same shape (≥4× improvement, well clear of the
// 2× regression-guard threshold asserted by TestResolveWithContextTier1Floor).
func BenchmarkResolveWithContextTier1Hot(b *testing.B) {
pm, graph, contextPubkeys := buildResolveTier1HotFixture(8, 64)
b.ReportAllocs()
b.ResetTimer()
for i := 0; i < b.N; i++ {
_, _, _ = pm.resolveWithContext("ab", contextPubkeys, graph)
}
}
// TestResolveWithContextTier1Floor is the assertion-style regression guard
// for #1247. It runs the same hot shape as the benchmark and asserts that
// the per-call cost stays well under the regressed baseline.
//
// Methodology: 2000 calls measured under -short=false; total budget 200 ms
// allows ~100 µs/call which is 2× the post-fix ceiling but ~2× UNDER the
// pre-fix 200 µs/op number. If a future change reintroduces the per-
// (cand, ctx) graph.Neighbors lookup or the strings.EqualFold tax, the
// test fails and the change is forced to justify the regression.
func TestResolveWithContextTier1Floor(t *testing.T) {
if testing.Short() {
t.Skip("skipping perf floor under -short")
}
pm, graph, contextPubkeys := buildResolveTier1HotFixture(8, 64)
const iters = 2000
// Warm up — first call allocates lookup maps; we measure steady state.
for i := 0; i < 50; i++ {
_, _, _ = pm.resolveWithContext("ab", contextPubkeys, graph)
}
t0 := time.Now()
for i := 0; i < iters; i++ {
_, _, _ = pm.resolveWithContext("ab", contextPubkeys, graph)
}
elapsed := time.Since(t0)
perCall := elapsed / iters
// 500 µs/call is the CI-floor-safe ceiling. Rationale:
// - Post-fix steady-state on arm64 dev hardware: ~50 µs/call.
// - x86_64 GitHub-hosted runners measure ~340 µs/call on this
// microbenchmark (≈57× slower than the arm64 dev box due to
// shared-tenant CPU contention and cache behavior on this shape).
// - Pre-fix regressed master measured ~1500 µs/call+ on the same
// runners, so 500 µs still catches the regression class with
// ~3× headroom and avoids CI-flake from runner variance.
// If a future change reintroduces the per-(cand, ctx) Neighbors
// lookup or the EqualFold tax, this test still fails loudly.
const ceiling = 500 * time.Microsecond
if perCall > ceiling {
t.Fatalf("resolveWithContext tier-1 perf regressed: %v/call (>%v ceiling); see #1247", perCall, ceiling)
}
t.Logf("resolveWithContext tier-1: %v/call (ceiling %v)", perCall, ceiling)
}
+37 -4
View File
@@ -111,23 +111,56 @@ func computeRoleAnalytics(nodesByPubkey map[string]string, skewByPubkey map[stri
return resp
}
// handleAnalyticsRoles serves /api/analytics/roles.
// handleAnalyticsRoles serves /api/analytics/roles. Reads from the
// steady-state recomputer snapshot (issue #1256) so the request never
// holds s.mu.RLock for a full clock-skew recompute over the advert
// transmissions — that path hung >60s on staging with 78k tx.
func (s *Server) handleAnalyticsRoles(w http.ResponseWriter, r *http.Request) {
if s.store == nil {
writeJSON(w, RoleAnalyticsResponse{Roles: []RoleStats{}})
return
}
nodes, _ := s.store.getCachedNodesAndPM()
writeJSON(w, s.store.GetAnalyticsRoles())
}
// GetAnalyticsRoles returns the role-distribution analytics, preferring
// the steady-state recomputer snapshot (issue #1256). Falls back to an
// on-request compute path if the recomputer is not yet running (e.g.
// during the brief startup window before the initial compute completes
// — Start runs it synchronously, so this fallback is effectively only
// hit in tests that skip the recomputer entirely).
func (s *PacketStore) GetAnalyticsRoles() RoleAnalyticsResponse {
s.analyticsRecomputerMu.RLock()
rc := s.recompRoles
s.analyticsRecomputerMu.RUnlock()
if rc != nil {
if v := rc.Load(); v != nil {
if r, ok := v.(RoleAnalyticsResponse); ok {
s.cacheMu.Lock()
s.cacheHits++
s.cacheMu.Unlock()
return r
}
}
}
return s.computeAnalyticsRoles()
}
// computeAnalyticsRoles runs the actual role aggregation. Used by the
// background recomputer (issue #1256) and as a fallback for callers
// arriving before the snapshot is populated.
func (s *PacketStore) computeAnalyticsRoles() RoleAnalyticsResponse {
nodes, _ := s.getCachedNodesAndPM()
roles := make(map[string]string, len(nodes))
for _, n := range nodes {
roles[n.PublicKey] = n.Role
}
skewMap := make(map[string]*NodeClockSkew)
for _, cs := range s.store.GetFleetClockSkew() {
for _, cs := range s.GetFleetClockSkew() {
if cs == nil {
continue
}
skewMap[cs.Pubkey] = cs
}
writeJSON(w, computeRoleAnalytics(roles, skewMap))
return computeRoleAnalytics(roles, skewMap)
}
@@ -0,0 +1,97 @@
package main
import (
"encoding/json"
"net/http"
"net/http/httptest"
"testing"
"time"
)
// TestRolesAnalyticsRecomputerRegistered asserts that the
// /api/analytics/roles endpoint is backed by the steady-state
// analytics recomputer (issue #1256). On master, roles was
// NOT wired into StartAnalyticsRecomputers — every request
// holds s.mu.RLock for the whole compute and triggers a fleet
// clock-skew recompute over 78k transmissions, hanging >60s.
//
// Post-fix: after StartAnalyticsRecomputers, the store exposes
// a recomputer for roles whose Load() returns a populated
// RoleAnalyticsResponse (initial sync compute), and the
// PacketStore.GetAnalyticsRoles() accessor returns from the
// snapshot in sub-millisecond time.
func TestRolesAnalyticsRecomputerRegistered(t *testing.T) {
db := setupTestDB(t)
defer db.Close()
store := NewPacketStore(db, nil)
stop := store.StartAnalyticsRecomputers(50 * time.Millisecond)
defer stop()
// Give the initial synchronous compute a beat to populate.
time.Sleep(100 * time.Millisecond)
store.analyticsRecomputerMu.RLock()
rc := store.recompRoles
store.analyticsRecomputerMu.RUnlock()
if rc == nil {
t.Fatalf("recompRoles not registered after StartAnalyticsRecomputers (issue #1256 not fixed)")
}
v := rc.Load()
if v == nil {
t.Fatalf("recompRoles snapshot is nil after initial compute")
}
if _, ok := v.(RoleAnalyticsResponse); !ok {
t.Fatalf("recompRoles snapshot type = %T, want RoleAnalyticsResponse", v)
}
// Accessor must hit the snapshot path.
t0 := time.Now()
resp := store.GetAnalyticsRoles()
dt := time.Since(t0)
if dt > 5*time.Millisecond {
t.Errorf("GetAnalyticsRoles latency = %v, want <5ms (snapshot path)", dt)
}
// Just confirm we got the response shape (empty store → empty roles).
_ = resp
}
// TestRolesHandlerUsesRecomputer is a HTTP-level guard that the
// /api/analytics/roles handler returns from the recomputer snapshot
// quickly even when no clock skew engine state has been primed (the
// hang on staging was: every call drove a full clockSkew.Recompute
// on 78k adverts). With recomputer wired, the handler is an atomic
// pointer load + JSON encode.
func TestRolesHandlerSnapshotLatency(t *testing.T) {
db := setupTestDB(t)
defer db.Close()
store := NewPacketStore(db, nil)
stop := store.StartAnalyticsRecomputers(50 * time.Millisecond)
defer stop()
time.Sleep(100 * time.Millisecond)
s := &Server{store: store}
// p99 over 50 reads must be well under 2 s (issue acceptance).
worst := time.Duration(0)
for i := 0; i < 50; i++ {
rr := httptest.NewRecorder()
req := httptest.NewRequest(http.MethodGet, "/api/analytics/roles", nil)
t0 := time.Now()
s.handleAnalyticsRoles(rr, req)
dt := time.Since(t0)
if dt > worst {
worst = dt
}
if rr.Code != http.StatusOK {
t.Fatalf("status = %d, want 200", rr.Code)
}
var out RoleAnalyticsResponse
if err := json.Unmarshal(rr.Body.Bytes(), &out); err != nil {
t.Fatalf("invalid json: %v", err)
}
}
if worst > 100*time.Millisecond {
t.Fatalf("worst-of-50 handler latency = %v, want <100ms (recomputer snapshot)", worst)
}
}
+21 -2
View File
@@ -1175,19 +1175,38 @@ func (s *Server) handleNodes(w http.ResponseWriter, r *http.Request) {
hashInfo := s.store.GetNodeHashSizeInfo()
mbCap := s.store.GetMultiByteCapMap()
relayWindow := s.cfg.GetHealthThresholds().RelayActiveHours
// #1257: bulk-compute relay info + usefulness scores ONCE per
// request (cached 15s) instead of calling the per-node helpers
// inside the loop. The per-node calls each grabbed their own
// RLock and walked byPathHop[pk] + byPayloadType, blowing
// /api/nodes up to 30+s on busy networks.
var relayMap map[string]RepeaterRelayInfo
var usefulMap map[string]float64
needsRelay := false
for _, node := range nodes {
if role, _ := node["role"].(string); role == "repeater" || role == "room" {
needsRelay = true
break
}
}
if needsRelay {
relayMap = s.store.GetRepeaterRelayInfoMap(relayWindow)
usefulMap = s.store.GetRepeaterUsefulnessScoreMap()
}
for _, node := range nodes {
if pk, ok := node["public_key"].(string); ok {
EnrichNodeWithHashSize(node, hashInfo[pk])
EnrichNodeWithMultiByte(node, mbCap[pk])
if role, _ := node["role"].(string); role == "repeater" || role == "room" {
info := s.store.GetRepeaterRelayInfo(pk, relayWindow)
info, _ := lookupRelayInfo(relayMap, pk)
info.WindowHours = relayWindow
if info.LastRelayed != "" {
node["last_relayed"] = info.LastRelayed
}
node["relay_active"] = info.RelayActive
node["relay_count_1h"] = info.RelayCount1h
node["relay_count_24h"] = info.RelayCount24h
node["usefulness_score"] = s.store.GetRepeaterUsefulnessScore(pk)
node["usefulness_score"] = lookupUsefulnessScore(usefulMap, pk)
}
}
}
+113 -24
View File
@@ -164,6 +164,7 @@ type PacketStore struct {
recompChannels *analyticsRecomputer
recompHashCollisions *analyticsRecomputer
recompHashSizes *analyticsRecomputer
recompRoles *analyticsRecomputer
cacheHits int64
cacheMisses int64
// Rate-limited invalidation (fixes #533: caches cleared faster than hit)
@@ -212,6 +213,27 @@ type PacketStore struct {
multiByteCapCache map[string]*MultiByteCapEntry
multiByteCapAt time.Time
// Cached per-pubkey relay info + usefulness score maps (#1257). These
// fold the previously per-node GetRepeaterRelayInfo /
// GetRepeaterUsefulnessScore loop in handleNodes into one O(N) pass
// per 15s TTL window — eliminating N RLock acquisitions and N×
// timestamp parses of the same byPathHop entries per request.
repeaterEnrichMu sync.Mutex
repeaterRelayCache map[string]RepeaterRelayInfo
repeaterRelayCacheWin float64
repeaterRelayAt time.Time
repeaterUsefulCache map[string]float64
repeaterUsefulAt time.Time
// Steady-state recomputer for the two caches above (#1262). When
// started, an initial sync compute prewarms the caches so the very
// first /api/nodes?limit=2000 from live.js's SPA bootstrap hits a
// populated cache instead of paying the 15.7s on-thread rebuild.
repeaterEnrichRecompMu sync.Mutex
repeaterEnrichRecompStarted bool
repeaterEnrichRecompStop chan struct{}
repeaterEnrichRecompDone chan struct{}
// Precomputed distinct advert pubkey count (refcounted for eviction correctness).
// Updated incrementally during Load/Ingest/Evict — avoids JSON parsing in GetPerfStoreStats.
advertPubkeys map[string]int // pubkey → number of advert packets referencing it
@@ -4061,6 +4083,21 @@ func isHexLower(s string) bool {
return true
}
// hasUpperASCII reports whether s contains any uppercase ASCII letter.
// Used by resolveWithContext tier-1 to skip the strings.ToLower allocation
// when the context pubkeys are already lowercased (the common case — see
// buildHopContextPubkeys / buildAggregateHopContextPubkeys, which lowercase
// on the way in). #1247.
func hasUpperASCII(s string) bool {
for i := 0; i < len(s); i++ {
c := s[i]
if c >= 'A' && c <= 'Z' {
return true
}
}
return false
}
// buildAggregateHopContextPubkeys gathers context across many txs for hot
// loops that resolve hops outside any per-tx scope (subpath/topology
// aggregations). Caller passes the slice of txs to consider; we union the
@@ -5725,32 +5762,84 @@ func (pm *prefixMap) resolveWithContext(hop string, contextPubkeys []string, gra
count int // observation count of the best-scoring edge
}
now := time.Now()
var scores []scored
for i, cand := range candidates {
candPK := strings.ToLower(cand.PublicKey)
bestScore := 0.0
bestCount := 0
for _, ctxPK := range contextPubkeys {
edges := graph.Neighbors(strings.ToLower(ctxPK))
for _, e := range edges {
if e.Ambiguous {
continue
}
otherPK := e.NodeA
if strings.EqualFold(otherPK, ctxPK) {
otherPK = e.NodeB
}
if strings.EqualFold(otherPK, candPK) {
s := e.Score(now) * e.Confidence()
if s > bestScore {
bestScore = s
bestCount = e.Count
}
}
// PERF (#1247): hoist per-context work out of the candidate loop.
// The previous shape ran graph.Neighbors(ToLower(ctxPK)) and
// re-lowercased candPK on every (cand, ctxPK) pair, then used
// strings.EqualFold to compare two already-lowercased pubkeys.
// At analytics scale (5k+ contextPubkeys, ~30k resolveHop calls)
// this dominated computeAnalyticsTopology / computeAnalyticsRF
// CPU time (37% / 55% of those endpoints respectively per
// pprof). The new shape:
// 1. Lowercases ctx pubkeys at most once per call (skipped
// entirely when the input is already lowercased — the
// common case for analytics callers that go through
// buildHopContextPubkeys).
// 2. Lowercases candidate pubkeys at most once per call and
// uses raw == comparisons against NeighborEdge.NodeA/NodeB
// (which makeEdgeKey already lowercases).
// 3. Loops outer-ctx / inner-edge / matched-cand-lookup. The
// previous shape was outer-cand / inner-ctx / inner-edge,
// which called graph.Neighbors(ctxPK) — taking the graph
// RLock each time — once per (cand, ctx) pair instead of
// once per ctx.
lowerCtx := contextPubkeys
needLower := false
for _, p := range contextPubkeys {
if hasUpperASCII(p) {
needLower = true
break
}
}
if needLower {
lowerCtx = make([]string, len(contextPubkeys))
for i, p := range contextPubkeys {
lowerCtx[i] = strings.ToLower(p)
}
}
candPKs := make([]string, len(candidates))
bestScores := make([]float64, len(candidates))
bestCounts := make([]int, len(candidates))
needLowerCand := false
for i, c := range candidates {
if hasUpperASCII(c.PublicKey) {
needLowerCand = true
break
}
candPKs[i] = c.PublicKey
}
if needLowerCand {
for i, c := range candidates {
candPKs[i] = strings.ToLower(c.PublicKey)
}
}
candByPK := make(map[string]int, len(candidates))
for i, pk := range candPKs {
candByPK[pk] = i
}
for _, ctxPK := range lowerCtx {
for _, e := range graph.Neighbors(ctxPK) {
if e.Ambiguous {
continue
}
otherPK := e.NodeA
if otherPK == ctxPK {
otherPK = e.NodeB
}
ci, ok := candByPK[otherPK]
if !ok {
continue
}
s := e.Score(now) * e.Confidence()
if s > bestScores[ci] {
bestScores[ci] = s
bestCounts[ci] = e.Count
}
}
if bestScore > 0 {
scores = append(scores, scored{i, bestScore, bestCount})
}
var scores []scored
for i, s := range bestScores {
if s > 0 {
scores = append(scores, scored{i, s, bestCounts[i]})
}
}
+3 -2
View File
@@ -258,8 +258,9 @@
"distance": 300,
"channels": 300,
"hashCollisions": 300,
"hashSizes": 300
"hashSizes": 300,
"roles": 300
}
},
"_comment_analytics": "Issue #1240. Each analytics endpoint (topology, rf, distance, channels, hashCollisions, hashSizes) is recomputed in the background on the configured interval and served from an atomic-pointer cache. Reads never block on compute. Default 300s (5 min) per endpoint reflects the operator principle: serving slightly stale data quickly beats real-time data slowly. Lower values = fresher data at higher CPU cost. Only the default query (no region/window) is precomputed; region- and window-filtered requests fall back to the legacy on-request compute + 60s TTL cache."
"_comment_analytics": "Issue #1240 + #1256. Each analytics endpoint (topology, rf, distance, channels, hashCollisions, hashSizes, roles) is recomputed in the background on the configured interval and served from an atomic-pointer cache. Reads never block on compute. Default 300s (5 min) per endpoint reflects the operator principle: serving slightly stale data quickly beats real-time data slowly. Lower values = fresher data at higher CPU cost. Only the default query (no region/window) is precomputed; region- and window-filtered requests fall back to the legacy on-request compute + 60s TTL cache."
}
+33 -8
View File
@@ -13,17 +13,17 @@
const el = document.getElementById('perfContent');
if (!el) return;
try {
const [server, client, ioStats, sqliteStats, writeSources] = await Promise.all([
// #1258: /api/health was awaited AFTER Promise.all, adding a full RTT
// (~50-200ms) on every 5s refresh. Issue it in parallel with the rest.
const [server, client, ioStats, sqliteStats, writeSources, health] = await Promise.all([
fetch('/api/perf').then(r => r.json()),
Promise.resolve(window.apiPerf ? window.apiPerf() : null),
fetch('/api/perf/io').then(r => r.json()).catch(() => null),
fetch('/api/perf/sqlite').then(r => r.json()).catch(() => null),
fetch('/api/perf/write-sources').then(r => r.json()).catch(() => null)
fetch('/api/perf/write-sources').then(r => r.json()).catch(() => null),
fetch('/api/health').then(r => r.json()).catch(() => null)
]);
// Also fetch health telemetry
const health = await fetch('/api/health').then(r => r.json()).catch(() => null);
let html = '';
// Server overview
@@ -230,8 +230,15 @@
html += `</div>`;
}
// Server endpoints table
const eps = Object.entries(server.endpoints);
// Server endpoints table — sort by total time (count * avg) DESC.
// #1258: header claimed "sorted by total time" but JSON map order is
// undefined and the frontend was not sorting. Slow endpoints could
// appear anywhere in the table, defeating the section's whole purpose.
const eps = Object.entries(server.endpoints).sort((a, b) => {
const ta = (a[1].count || 0) * (a[1].avgMs || 0);
const tb = (b[1].count || 0) * (b[1].avgMs || 0);
return tb - ta;
});
if (eps.length) {
html += '<h3>Server Endpoints (sorted by total time)</h3>';
html += '<div style="overflow-x:auto"><table class="perf-table"><thead><tr><th scope="col">Endpoint</th><th scope="col">Count</th><th scope="col">Avg</th><th scope="col">P50</th><th scope="col">P95</th><th scope="col">Max</th><th scope="col">Total</th></tr></thead><tbody>';
@@ -281,10 +288,28 @@
registerPage('perf', {
init(app) {
render(app);
interval = setInterval(refresh, 5000);
// #1258: don't burn CPU/network rebuilding the page (and its many cards
// + 3 large tables) every 5s while the tab is hidden. Pause polling on
// visibilitychange and resume on focus. Reduces background fetch traffic
// to zero and prevents a returning user from seeing a 100+ms thrash as
// a backlog of refreshes flush.
const tick = () => {
if (document.hidden) return;
refresh();
};
interval = setInterval(tick, 5000);
const onVis = () => {
if (!document.hidden) refresh();
};
document.addEventListener('visibilitychange', onVis);
this._onVis = onVis;
},
destroy() {
if (interval) { clearInterval(interval); interval = null; }
if (this._onVis) {
document.removeEventListener('visibilitychange', this._onVis);
this._onVis = null;
}
}
});
})();
+140
View File
@@ -0,0 +1,140 @@
/* Tests for perf.js render performance (#1258).
*
* Failure modes we gate against:
* 1) /api/health awaited sequentially AFTER Promise.all extra RTT
* 2) setInterval keeps polling even when document is hidden wasted work
* 3) Endpoints table claims "sorted by total time" but renders in map order
*/
'use strict';
const vm = require('vm');
const fs = require('fs');
const assert = require('assert');
let passed = 0, failed = 0;
function test(name, fn) {
const run = (r) => { if (r && typeof r.then === 'function') return r.then(() => { passed++; console.log(`${name}`); }, e => { failed++; console.log(`${name}: ${e.message}`); }); passed++; console.log(`${name}`); };
try { const r = fn(); if (r && typeof r.then === 'function') return r.then(() => { passed++; console.log(`${name}`); }, e => { failed++; console.log(`${name}: ${e.message}`); }); else { passed++; console.log(`${name}`); } }
catch (e) { failed++; console.log(`${name}: ${e.message}`); }
}
function makeSandbox(opts = {}) {
let capturedHtml = '';
const pages = {};
let visState = opts.hidden ? 'hidden' : 'visible';
const visListeners = [];
const ctx = {
window: { addEventListener: () => {}, apiPerf: null },
document: {
getElementById: (id) => {
if (id === 'perfContent') return { set innerHTML(v) { capturedHtml = v; } };
if (id === 'perfReset' || id === 'perfRefresh') return { addEventListener: () => {} };
return null;
},
addEventListener: (ev, fn) => { if (ev === 'visibilitychange') visListeners.push(fn); },
removeEventListener: () => {},
get visibilityState() { return visState; },
get hidden() { return visState === 'hidden'; },
},
console,
Date, Math, Array, Object, String, Number, JSON, RegExp, Error, TypeError,
parseInt, parseFloat, isNaN, isFinite,
setTimeout: (fn, ms) => setTimeout(fn, ms), clearTimeout,
setInterval: (fn, ms) => { return setInterval(fn, ms); }, clearInterval,
performance: { now: () => Date.now() },
Map, Set, Promise,
registerPage: (name, handler) => { pages[name] = handler; },
_apiCache: { size: 0 },
fetch: () => Promise.resolve({ json: () => Promise.resolve({}) }),
};
ctx.window.document = ctx.document;
ctx.globalThis = ctx;
return { ctx, pages, getHtml: () => capturedHtml,
setVisibility(v) { visState = v; visListeners.forEach(fn => fn()); } };
}
function loadPerf() {
const sb = makeSandbox();
const code = fs.readFileSync('public/perf.js', 'utf8');
vm.runInNewContext(code, sb.ctx);
return sb;
}
// ---------- 1) Health fetched in parallel ----------
test('all initial fetches (including /api/health) issued in parallel', async () => {
const sb = loadPerf();
const order = [];
let resolveAll;
const gate = new Promise(r => { resolveAll = r; });
sb.ctx.fetch = (url) => {
order.push(url);
// Don't resolve until all 5 calls have been issued — proves they're parallel
return gate.then(() => ({ json: () => Promise.resolve({}) }));
};
const p = sb.pages.perf.init({ set innerHTML(v) {} });
// Microtask flush
await Promise.resolve();
await Promise.resolve();
await Promise.resolve();
// Before any fetch resolves, all 5 URLs must have been started
assert.ok(order.includes('/api/health'),
`expected /api/health to be issued in parallel with the others, got: ${order.join(', ')}`);
resolveAll();
await p;
});
// ---------- 2) setInterval pauses when tab hidden ----------
test('refresh interval does not fire when document is hidden', async () => {
const sb = loadPerf();
let fetchCount = 0;
sb.ctx.fetch = (url) => {
fetchCount++;
return Promise.resolve({ json: () => Promise.resolve({}) });
};
// Replace setInterval with fast firing
let timerFn = null;
sb.ctx.setInterval = (fn, ms) => { timerFn = fn; return 1; };
sb.ctx.clearInterval = () => { timerFn = null; };
await sb.pages.perf.init({ set innerHTML(v) {} });
await new Promise(r => setTimeout(r, 30));
const baseline = fetchCount;
// Hide the tab, then fire the interval — should NOT issue fresh fetches
sb.setVisibility('hidden');
if (timerFn) timerFn();
await new Promise(r => setTimeout(r, 30));
assert.strictEqual(fetchCount, baseline,
`refresh should be suppressed while hidden; baseline=${baseline} after=${fetchCount}`);
});
// ---------- 3) Endpoints table actually sorted by total time ----------
test('endpoints table is sorted by total time descending', async () => {
const sb = loadPerf();
// Map insertion order is preserved in JS object literals — put SLOW endpoint
// LAST to ensure the renderer is actively sorting, not relying on input order.
const perfData = {
totalRequests: 100, avgMs: 5, uptime: 3600, slowQueries: [],
endpoints: {
'/api/fast': { count: 1, avgMs: 1, p50Ms: 1, p95Ms: 1, maxMs: 1 },
'/api/mid': { count: 10, avgMs: 10, p50Ms: 10, p95Ms: 10, maxMs: 10 },
'/api/SLOW': { count: 100, avgMs: 100, p50Ms: 100, p95Ms: 100, maxMs: 100 },
},
};
sb.ctx.fetch = (url) => {
if (url === '/api/perf') return Promise.resolve({ json: () => Promise.resolve(perfData) });
return Promise.resolve({ json: () => Promise.resolve(null) });
};
await sb.pages.perf.init({ set innerHTML(v) {} });
await new Promise(r => setTimeout(r, 30));
const html = sb.getHtml();
const iSlow = html.indexOf('/api/SLOW');
const iMid = html.indexOf('/api/mid');
const iFast = html.indexOf('/api/fast');
assert.ok(iSlow > -1 && iMid > -1 && iFast > -1, 'all three endpoints must render');
assert.ok(iSlow < iMid && iMid < iFast,
`expected SLOW < mid < fast in DOM order, got SLOW=${iSlow} mid=${iMid} fast=${iFast}`);
});
setTimeout(() => {
console.log(`\n${passed} passed, ${failed} failed\n`);
process.exit(failed ? 1 : 0);
}, 500);