From 30d63769adcb4e9b10ce2bd8afa5c616b1a34bcd Mon Sep 17 00:00:00 2001 From: "SYM.BOT" Date: Wed, 14 Oct 2026 19:29:58 +0100 Subject: [PATCH 1/7] Flow control: past its record budget a receiver queues, refuses only past the queue and says so; a sender paces to the budget A receiver bounds what one session's records cost it (8 a second after 32; 128 KiB/s after 1.5 MiB; 32/s and 1 MiB/s before verification). A record past either lane was dropped, unevaluated, while its sender reported it dispatched: 49 directed messages in a burst arrived as 32-38, 12 x 200 KB as 7, 120 held records re-offered after a relay drop as 38. Receiver (lib/flow-control.js RecordAdmission, frame-handler): every record of a session is admitted only when both lanes hold it and nothing of the session waits ahead of it, else it waits in the session's queue, in order (64 s of the budget: 512 records, 8 Mi characters; 4096 and 32 Mi in all). Past the queue it is refused and the sender told in a sealed `cmb-refused` (assertionIds, retryAfterMs), at most once a second per peer. A peer that, told, keeps sending past its own queue before it drains is closed and not admitted for 60 s. A stopping node refuses and notifies what waits. Each admitted session is sent `cmb-budget` (rate, burst, chars rate, chars burst, queue bound). Sender (node.js): every record to a peer goes through its held list and is written only within the budget the peer advertised (0.14.2 peers: 6/s after 24, a margin under their 8/32, no size budget). Dispatched means written; delivery.queued counts what is held. A refused record goes back in its place and waits for the retry-after on any session; after 8 refusals or 23 h it is given up (cmb-undelivered, the 'undelivered' event, undelivered()). The held list refuses past its bound instead of pushing out what it holds. --- lib/flow-control.js | 520 ++++++++++++++++++++++++++++++++++++++++ lib/frame-handler.js | 178 +++++++++----- lib/node.js | 554 ++++++++++++++++++++++++++++++++++--------- 3 files changed, 1078 insertions(+), 174 deletions(-) create mode 100644 lib/flow-control.js diff --git a/lib/flow-control.js b/lib/flow-control.js new file mode 100644 index 00000000..2e19f334 --- /dev/null +++ b/lib/flow-control.js @@ -0,0 +1,520 @@ +'use strict'; + +/** + * @module @sym-bot/sym/flow-control + * @description Flow control for directed and room records (sym 0.14.3). + * + * A receiver bounds what one session's records cost it: a record budget per session, by count (8 a + * second after a burst of 32, security review D) and by size (128 KiB of record text a second after + * 1.5 MiB, R2-3), before SVAF evaluates anything. Until 0.14.3 a record past the budget was DROPPED + * unevaluated while its sender reported it dispatched, and nothing offered it again: 49 directed + * messages sent in a burst reached the receiver as 38, 12 records of 200 KB as 7, and 120 records + * held across a relay drop as 37. The budget is there to bound CPU and memory; it must not lose + * honest traffic. So: + * + * RECEIVER. A record past the budget is QUEUED, per session, in arrival order, and admitted + * (verified, evaluated, surfaced) as the budget refills: it is delayed, never dropped. The queue is + * bounded per session (QUEUE_SECONDS of the budget: 512 records, 8 Mi characters) and in all + * (QUEUE_TOTAL_*). Only past a bound is a record refused, and then the receiver tells the sender in + * a sealed control frame, `cmb-refused`, naming the refused assertionIds and a retry-after. A peer + * that keeps sending past the bound after it was told is cut (closed, and not admitted again for a + * minute): an honest sender never is, it paces. + * + * ADVERTISEMENT. Once a session is admitted, each side tells the other its budget in a sealed + * control frame, `cmb-budget` (the rate and burst by count and by size, and the queue bound). + * + * SENDER. Records to a peer — directed or room, fresh or held — are written to its session within + * the budget that peer advertised (one that advertises nothing, 0.14.2 and older, is paced to the + * 0.14.2 budget, with a margin: it drops past it). What does not fit waits in the peer's held list + * and is written as the budget refills. A record counts as dispatched only once it is written + * within the budget; a refused one goes back to the held list and is retried after the retry-after, + * and after HELD_REFUSALS_MAX refusals or HELD_MAX_AGE_MS it is reported undelivered. + * + * Nothing here changes what a record costs once it is admitted: the budget, and what it bounds, are + * exactly as before. Only what happens past it changes. + * + * @copyright 2026 SYM.BOT. Apache 2.0 License. + */ + +// ── The receiver's record budget, per session ────────────────────────────────────────────────── + +/** Records one session has evaluated, at most: a burst, then a rate a second (security review D). */ +const RECORDS_PER_SECOND = 8; +const RECORDS_BURST = 32; +/** The record lane by size (R2-3): characters of record text a second, after a burst. */ +const RECORD_CHARS_PER_SECOND = 128 * 1024; +const RECORD_CHARS_BURST = 1536 * 1024; + +/** + * The queue in front of the budget holds at most QUEUE_SECONDS of it per session, by count and by + * size, so a record that is queued waits at most about that long; and at most QUEUE_TOTAL_* in all, + * whatever the number of sessions. (Characters, as the size budget counts them.) + */ +const QUEUE_SECONDS = 64; +const QUEUE_RECORDS = RECORDS_PER_SECOND * QUEUE_SECONDS; +const QUEUE_CHARS = RECORD_CHARS_PER_SECOND * QUEUE_SECONDS; +const QUEUE_TOTAL_RECORDS = 4096; +const QUEUE_TOTAL_CHARS = 32 * 1024 * 1024; + +/** + * A refusal notice (`cmb-refused`) goes to a peer at most once every REFUSAL_NOTICE_MS, naming at most + * REFUSAL_IDS_MAX assertionIds; at most REFUSAL_PENDING_MAX wait for the next one (past it a refusal + * is counted, not listed: only a sender past every bound gets there). Notices for a peer with no open + * session wait at most REFUSAL_PENDING_MS for its next one. + */ +const REFUSAL_NOTICE_MS = 1000; +const REFUSAL_IDS_MAX = 256; +const REFUSAL_PENDING_MAX = 4 * REFUSAL_IDS_MAX; +const REFUSAL_PENDING_MS = 60_000; +const REFUSAL_PEERS_MAX = 1024; +/** The retry-after a refusal carries: the time the session's queue needs to drain, within these. */ +const RETRY_AFTER_MIN_MS = 1000; +const RETRY_AFTER_MAX_MS = QUEUE_SECONDS * 1000; +/** + * A peer told, and still sending past the bound by more than this many records before its queue has + * drained, is cut (closed, and not admitted again for FLOOD_PENALTY_MS). An honest sender stops within + * the records it had in flight when the notice reached it, far fewer. + */ +const REFUSALS_BEFORE_CUT = QUEUE_RECORDS; +const FLOOD_PENALTY_MS = 60_000; + +/** The sealed control frames (lib/core/sealed-control.js carries them; a 0.14.2 node ignores both, §7.3). */ +const BUDGET_FRAME = 'cmb-budget'; +const REFUSED_FRAME = 'cmb-refused'; +const BUDGET_MEMBERS = Object.freeze(['type', 'recordsPerSecond', 'recordsBurst', 'charsPerSecond', 'charsBurst', 'queueRecords', 'queueChars']); +const REFUSED_MEMBERS = Object.freeze(['type', 'assertionIds', 'retryAfterMs']); +const ASSERTION_ID = /^asrt-[0-9a-f]{64}$/; + +// ── The sender ───────────────────────────────────────────────────────────────────────────────── + +/** + * What a sender paces a peer to before, or without, its advertisement: the 0.14.2 record budget (8 a + * second, burst 32; 0.14.2 had no size budget) with a quarter of it kept as a margin. A 0.14.2 + * receiver DROPS past its budget, and a sender pacing exactly to it loses a record whenever two arrive + * closer together than they were written (a relay's pacer, the network): the margin absorbs that. An + * advertising receiver queues, so it is paced exactly to what it says. + */ +const LEGACY_BUDGET = Object.freeze({ recordsPerSecond: 6, recordsBurst: 24, charsPerSecond: Infinity, charsBurst: Infinity, queueRecords: 0, queueChars: 0 }); +/** A refused record is retried at most this many times; a held one is given up at this age (signed). */ +const HELD_REFUSALS_MAX = 8; +/** Below the receiver's 24 h window for a directed record's signed age (frame-handler DIRECTED_WINDOW_MS). */ +const HELD_MAX_AGE_MS = 23 * 60 * 60 * 1000; +/** + * A record written to a peer is remembered this long (and at most SENT_WINDOW_MAX of them in all), so + * a refusal naming it can put it back on the held list. Refusals are sent within REFUSAL_NOTICE_MS of + * the record's arrival; a minute covers a slow relay several times over. + */ +const SENT_WINDOW_MS = 60_000; +const SENT_WINDOW_MAX = 20_000; +/** The most undelivered records `undelivered()` lists (the newest kept). */ +const UNDELIVERED_LOG_MAX = 256; + +/** What a record weighs for the size budgets: its texts and application data, in characters. */ +function recordChars(cmb) { + let n = 512; + const cats = cmb && typeof cmb === 'object' ? cmb.categories : null; + if (cats && typeof cats === 'object') { + for (const v of Object.values(cats)) { + if (typeof v === 'string') n += v.length; + else if (v && typeof v === 'object' && typeof v.text === 'string') n += v.text.length; + } + } + const md = cmb && typeof cmb === 'object' ? cmb.metadata : null; + if (md && typeof md === 'object') { + if (md.application && typeof md.application === 'object' && typeof md.application.data === 'string') n += md.application.data.length; + if (typeof md.createdBy === 'string') n += md.createdBy.length; + } + return n; +} + +/** Refill a bucket {tokens, at} to `now` at `rate` a second up to `burst`. A clock stepped back refills nothing and takes nothing. */ +function refillBucket(b, rate, burst, now) { + const elapsed = now - b.at; + if (elapsed > 0) b.tokens = Math.min(burst, b.tokens + (elapsed * rate) / 1000); + b.at = Math.max(b.at, now); + return b; +} + +/** Milliseconds until bucket `b` holds `need` (at most its burst), refilled to `now`; 0 when it does. */ +function bucketWait(b, rate, burst, need, now) { + refillBucket(b, rate, burst, now); + const n = Math.min(need, burst); + if (b.tokens >= n) return 0; + return Math.max(1, Math.ceil(((n - b.tokens) * 1000) / rate)); +} + +/** The advertisement this node sends: its record budget and its queue bound per session. */ +function budgetFrame({ recordsPerSecond = RECORDS_PER_SECOND, recordsBurst = RECORDS_BURST, charsPerSecond = RECORD_CHARS_PER_SECOND, charsBurst = RECORD_CHARS_BURST, queueRecords = QUEUE_RECORDS, queueChars = QUEUE_CHARS } = {}) { + return { type: BUDGET_FRAME, recordsPerSecond, recordsBurst, charsPerSecond, charsBurst, queueRecords, queueChars }; +} + +const finiteIn = (v, lo, hi) => typeof v === 'number' && Number.isFinite(v) && v >= lo && v <= hi; +/** + * A peer's `cmb-budget`, checked: the frame's members exactly, each a finite number in range. A rate + * below one record a minute is taken as one a minute (a receiver that advertises less only slows what + * it is sent; the held list's age bound still gives the records up). @returns {object|null} + */ +function parseBudgetFrame(f) { + if (!f || typeof f !== 'object' || Array.isArray(f)) return null; + // No member outside the schema; each member is checked below (a missing one is not a finite number). + if (!Object.keys(f).every((k) => BUDGET_MEMBERS.includes(k))) return null; + if (!finiteIn(f.recordsPerSecond, 0, 1e6) || !finiteIn(f.recordsBurst, 1, 1e7)) return null; + if (!finiteIn(f.charsPerSecond, 0, 1e12) || !finiteIn(f.charsBurst, 1, 1e12)) return null; + if (!finiteIn(f.queueRecords, 0, 1e7) || !finiteIn(f.queueChars, 0, 1e12)) return null; + return Object.freeze({ + recordsPerSecond: Math.max(f.recordsPerSecond, 1 / 60), + recordsBurst: f.recordsBurst, + charsPerSecond: Math.max(f.charsPerSecond, 1), + charsBurst: f.charsBurst, + queueRecords: f.queueRecords, + queueChars: f.queueChars, + }); +} + +/** A peer's `cmb-refused`, checked: the frame's members exactly. @returns {{ ids: string[], retryAfterMs: number }|null} */ +function parseRefusedFrame(f) { + if (!f || typeof f !== 'object' || Array.isArray(f)) return null; + if (!Object.keys(f).every((k) => REFUSED_MEMBERS.includes(k))) return null; + const ids = f.assertionIds; + if (!Array.isArray(ids) || ids.length < 1 || ids.length > REFUSAL_IDS_MAX || !ids.every((id) => typeof id === 'string' && ASSERTION_ID.test(id))) return null; + if (!Number.isInteger(f.retryAfterMs) || f.retryAfterMs < 0 || f.retryAfterMs > 3_600_000) return null; + return { ids: [...new Set(ids)], retryAfterMs: Math.min(Math.max(f.retryAfterMs, RETRY_AFTER_MIN_MS), RETRY_AFTER_MAX_MS) }; +} + +/** + * One session's outbound record budget, as its receiver sees it: two buckets (count and size), the + * peer's advertised budget once it has said it (LEGACY_BUDGET until then), and a back-off a refusal + * set. Both ends start a session with full buckets, so a sender that spends here never exceeds what + * the receiver holds for it. + */ +class OutboundBudget { + constructor(now = Date.now()) { + this.budget = LEGACY_BUDGET; + this.advertised = false; + this.count = { tokens: LEGACY_BUDGET.recordsBurst, at: now }; + this.chars = { tokens: LEGACY_BUDGET.charsBurst, at: now }; + this.spent = { records: 0, chars: 0 }; + this.backoffUntil = 0; + } + + /** + * The peer said its budget. The first time, the buckets start from what the receiver can at least + * hold now: its burst less everything sent on this session so far (it may hold more, never less). + * A later one changes the rates and keeps what the buckets hold, within the new bursts. + */ + apply(b, now = Date.now()) { + if (!this.advertised) { + this.count = { tokens: Math.max(0, b.recordsBurst - this.spent.records), at: now }; + this.chars = { tokens: Math.max(0, b.charsBurst - this.spent.chars), at: now }; + } else { + this.count = { tokens: Math.min(refillBucket(this.count, this.budget.recordsPerSecond, this.budget.recordsBurst, now).tokens, b.recordsBurst), at: now }; + this.chars = { tokens: Math.min(refillBucket(this.chars, this.budget.charsPerSecond, this.budget.charsBurst, now).tokens, b.charsBurst), at: now }; + } + this.budget = b; + this.advertised = true; + } + + /** Milliseconds until a record of `chars` may be written: 0 now. */ + wait(chars, now = Date.now()) { + const b = this.budget; + return Math.max( + this.backoffUntil > now ? this.backoffUntil - now : 0, + bucketWait(this.count, b.recordsPerSecond, b.recordsBurst, 1, now), + Number.isFinite(b.charsBurst) ? bucketWait(this.chars, b.charsPerSecond, b.charsBurst, chars, now) : 0, + ); + } + + /** Spend a record of `chars` (written). A record past what the buckets hold (an anchor) still spends. */ + take(chars, now = Date.now()) { + const b = this.budget; + refillBucket(this.count, b.recordsPerSecond, b.recordsBurst, now); + this.count.tokens -= 1; + if (Number.isFinite(b.charsBurst)) { + refillBucket(this.chars, b.charsPerSecond, b.charsBurst, now); + this.chars.tokens -= Math.min(chars, b.charsBurst); + } + this.spent.records += 1; + this.spent.chars += chars; + } + + /** The receiver refused records: nothing more is written to this session for `ms`. */ + backOff(ms, now = Date.now()) { + this.backoffUntil = Math.max(this.backoffUntil, now + ms); + } +} + +// ── The receiver's admission queue ───────────────────────────────────────────────────────────── + +/** + * Records past a session's budget, waiting for it to refill (one FIFO per session), and the refusal + * notices owed to peers. The owner (the frame handler) supplies the budget and the work: + * + * wait(session, chars, now) ms until the session's budget holds a record of `chars` (0: now) + * run(entry) admit one record now (spends the budget and processes it) + * admitted(entry) whether its peer is still admitted (the door, a penalty): or dropped + * sessionFor(peerId) the peer's open session for a notice, or null + * cut(session) the penalty for a session that keeps sending past the bound + * fail(entry, err) a record that threw while it was admitted from the queue + * metric(m), say(key, line) + */ +class RecordAdmission { + constructor(o) { + this._o = o; + this.limits = { queueRecords: QUEUE_RECORDS, queueChars: QUEUE_CHARS, totalRecords: QUEUE_TOTAL_RECORDS, totalChars: QUEUE_TOTAL_CHARS, refusalsBeforeCut: REFUSALS_BEFORE_CUT }; + this._sessions = new Set(); + this._notices = new Map(); + this.total = { records: 0, chars: 0 }; + this.stats = { queued: 0, admittedLate: 0, refused: 0, dropped: 0, notices: 0, noticedIds: 0, unlisted: 0, unsent: 0, cut: 0, peakRecords: 0, peakChars: 0 }; + } + + _queueOf(session) { + return session._admitQueue || (session._admitQueue = { items: [], head: 0, chars: 0, timer: null }); + } + + /** + * A record arrived on `session`. Admitted now when nothing of the session's waits and its budget + * holds it (what run returns is returned); otherwise queued behind what waits, or, past a bound, + * refused and the sender told. @returns {*} run's result, or undefined + */ + offer(session, peerId, peerName, msg, chars, now = Date.now()) { + const q = this._queueOf(session); + const waiting = q.items.length - q.head; + const entry = { session, peerId, peerName, msg, chars }; + if (waiting === 0 && this._o.wait(session, chars, now) === 0) return this._o.run(entry); + const L = this.limits; + if (waiting >= L.queueRecords || q.chars + chars > L.queueChars) return this._refuse(entry, 'session-queue-full', now); + if (this.total.records >= L.totalRecords || this.total.chars + chars > L.totalChars) return this._refuse(entry, 'queue-full', now); + q.items.push(entry); + q.chars += chars; + this.total.records++; + this.total.chars += chars; + this.stats.queued++; + if (this.total.records > this.stats.peakRecords) this.stats.peakRecords = this.total.records; + if (this.total.chars > this.stats.peakChars) this.stats.peakChars = this.total.chars; + this._sessions.add(session); + this._o.metric({ type: 'cmb-queued', from: peerName, peer: peerId, key: keyOf(msg), waiting: waiting + 1 }); + if (!q.timer) this._arm(session, q, this._o.wait(session, q.items[q.head].chars, now)); + return undefined; + } + + _arm(session, q, ms) { + q.timer = setTimeout(() => { q.timer = null; this._drain(session); }, Math.max(ms, 1)); + if (q.timer.unref) q.timer.unref(); + } + + _shift(session, q) { + const e = q.items[q.head]; + q.items[q.head] = undefined; + q.head++; + if (q.head > 64 && q.head * 2 > q.items.length) { q.items = q.items.slice(q.head); q.head = 0; } + q.chars -= e.chars; + this.total.records--; + this.total.chars -= e.chars; + return e; + } + + /** Admit what the budget now holds, in order; re-arm for the next. */ + _drain(session) { + const q = session._admitQueue; + if (!q) return; + while (q.items.length - q.head > 0) { + const head = q.items[q.head]; + if (!this._o.admitted(head)) { + this._shift(session, q); + this.stats.dropped++; + this._o.metric({ type: 'cmb-queue-dropped', from: head.peerName, peer: head.peerId, key: keyOf(head.msg), reason: 'not-admitted' }); + continue; + } + const now = Date.now(); + const w = this._o.wait(session, head.chars, now); + if (w > 0) { this._arm(session, q, w); return; } + const e = this._shift(session, q); + this.stats.admittedLate++; + try { this._o.run(e); } catch (err) { this._o.fail(e, err); } + } + q.items = []; + q.head = 0; + this._sessions.delete(session); + // The session's queue drained: a peer told and back within its budget starts over. + const n = this._notices.get(session.nodeId); + if (n) { n.refusedSinceTold = 0; n.toldAt = 0; n.episode = false; } + } + + _refuse(entry, reason, now) { + const { session, peerId, peerName, msg } = entry; + this.stats.refused++; + this._o.metric({ type: 'cmb-queue-refused', from: peerName, peer: peerId, key: keyOf(msg), reason }); + this._o.say(`${peerId}|queue-refused`, `CMBs from ${peerName} refused: past ${reason === 'queue-full' ? 'this node\'s queue for all sessions' : 'its session\'s queue'} (${this.limits.queueRecords} records or ${this.limits.queueChars} characters a session, ${this.limits.totalRecords} in all); the sender is told to retry`); + const n = this._noticeOf(peerId, now); + const id = msg && msg.cmb && msg.cmb.metadata ? msg.cmb.metadata.assertionId : null; + if (typeof id === 'string' && ASSERTION_ID.test(id)) { + if (n.ids.length < REFUSAL_PENDING_MAX) n.ids.push(id); + else this.stats.unlisted++; + } else { + this.stats.unlisted++; + } + // Only a peer past ITS OWN queue can be cut: it sent more than QUEUE_SECONDS of its budget ahead + // of it. A paced sender never does; one refused because every session's queue together is full + // (others filled it) is not at fault, and is only told when to retry. An EPISODE is the time a + // peer's own queue is full: it starts with such a refusal and ends when the queue drains. Told + // means a notice went out during the episode (one for its tail, sent after the queue drained, + // tells nothing about the next), and what it sends past the bound after that counts. + if (reason === 'queue-full') n.othersFull = true; + if (reason === 'session-queue-full') n.episode = true; + if (n.toldAt) { + n.refusedSinceTold++; + if (n.refusedSinceTold > this.limits.refusalsBeforeCut) { + n.refusedSinceTold = 0; + this.stats.cut++; + this._o.cut(session); + } + } + this._scheduleNotice(peerId, n, now); + return undefined; + } + + _noticeOf(peerId, now) { + let n = this._notices.get(peerId); + if (!n) { + if (this._notices.size >= REFUSAL_PEERS_MAX) { + const [oldId, old] = this._notices.entries().next().value; + this._dropNotice(oldId, old, 'too-many-peers'); + } + n = { ids: [], lastAt: 0, toldAt: 0, refusedSinceTold: 0, episode: false, othersFull: false, timer: null, since: now }; + this._notices.set(peerId, n); + } + return n; + } + + _dropNotice(peerId, n, why) { + if (n.timer) clearTimeout(n.timer); + if (n.ids.length) { + this.stats.unsent += n.ids.length; + this._o.metric({ type: 'cmb-refusal-unsent', peer: peerId, count: n.ids.length, reason: why }); + } + this._notices.delete(peerId); + } + + _scheduleNotice(peerId, n, now) { + if (n.timer || !n.ids.length) return; + const due = Math.max(0, n.lastAt + REFUSAL_NOTICE_MS - now); + n.timer = setTimeout(() => { n.timer = null; this.flush(peerId); }, due); + if (n.timer.unref) n.timer.unref(); + } + + /** + * The retry-after a notice carries: the time the session's own queue needs to drain at its budget, + * or, when a record was refused because every session's queue together was full, the time the + * longest one needs; within RETRY_AFTER_MIN_MS and RETRY_AFTER_MAX_MS. + */ + _retryAfter(session, othersFull) { + const drain = (q) => (q ? Math.max(((q.items.length - q.head) * 1000) / RECORDS_PER_SECOND, (q.chars * 1000) / RECORD_CHARS_PER_SECOND) : 0); + let ms = drain(session && session._admitQueue); + if (othersFull) for (const s of this._sessions) ms = Math.max(ms, drain(s._admitQueue)); + return Math.round(Math.min(Math.max(ms, RETRY_AFTER_MIN_MS), RETRY_AFTER_MAX_MS)); + } + + /** + * Send `peerId` what it is owed: one `cmb-refused` frame naming up to REFUSAL_IDS_MAX refused + * assertionIds, at most once every REFUSAL_NOTICE_MS (`force`: now, in as many frames as it takes). + * With no open session for the peer the notice waits for its next one, at most REFUSAL_PENDING_MS. + */ + flush(peerId, { force = false } = {}) { + const n = this._notices.get(peerId); + if (!n || !n.ids.length) return; + const now = Date.now(); + if (!force && n.lastAt && now - n.lastAt < REFUSAL_NOTICE_MS) { this._scheduleNotice(peerId, n, now); return; } + const session = this._o.sessionFor(peerId); + if (!session) { + if (now - n.since > REFUSAL_PENDING_MS) this._dropNotice(peerId, n, 'no-session'); + return; + } + do { + const ids = n.ids.splice(0, REFUSAL_IDS_MAX); + const retryAfterMs = this._retryAfter(session, n.othersFull); + let sent = false; + try { sent = session.trySend({ type: REFUSED_FRAME, assertionIds: ids, retryAfterMs }).ok === true; } catch { sent = false; } + if (!sent) { + this.stats.unsent += ids.length; + this._o.metric({ type: 'cmb-refusal-unsent', peer: peerId, count: ids.length, reason: 'send-failed' }); + break; + } + this.stats.notices++; + this.stats.noticedIds += ids.length; + n.lastAt = now; + n.since = now; + n.othersFull = false; + if (n.episode && !n.toldAt) n.toldAt = now; + this._o.metric({ type: 'cmb-refusal-sent', peer: peerId, count: ids.length, retryAfterMs }); + } while (force && n.ids.length); + if (n.ids.length) this._scheduleNotice(peerId, n, now); + } + + /** Whatever waits for the peer goes on its new session (called when one is admitted). */ + flushFor(peerId) { + const n = this._notices.get(peerId); + if (n && n.ids.length && !n.timer) this.flush(peerId); + } + + /** + * The node stops: every queued record is refused — its sender told, where a session is still open, + * so it offers the record again to this node's next session — and every timer cleared. + * @returns {number} the records refused + */ + stop() { + let n = 0; + for (const session of [...this._sessions]) { + const q = session._admitQueue; + if (!q) continue; + if (q.timer) { clearTimeout(q.timer); q.timer = null; } + while (q.items.length - q.head > 0) { + const e = this._shift(session, q); + n++; + const notice = this._noticeOf(e.peerId, Date.now()); + const id = e.msg && e.msg.cmb && e.msg.cmb.metadata ? e.msg.cmb.metadata.assertionId : null; + if (typeof id === 'string' && ASSERTION_ID.test(id)) notice.ids.push(id); + this.stats.refused++; + this._o.metric({ type: 'cmb-queue-refused', from: e.peerName, peer: e.peerId, key: keyOf(e.msg), reason: 'node-stopping' }); + } + q.items = []; + q.head = 0; + } + this._sessions.clear(); + for (const peerId of [...this._notices.keys()]) { + const notice = this._notices.get(peerId); + if (notice.timer) { clearTimeout(notice.timer); notice.timer = null; } + this.flush(peerId, { force: true }); + const left = this._notices.get(peerId); + if (left) this._dropNotice(peerId, left, 'node-stopped'); + } + this._notices.clear(); + this.total = { records: 0, chars: 0 }; + return n; + } + + /** What status() reports. */ + status() { + return { + queuedRecords: this.total.records, + queuedChars: this.total.chars, + queuedSessions: this._sessions.size, + ...this.stats, + limits: { ...this.limits }, + }; + } +} + +function keyOf(msg) { + const md = msg && msg.cmb && msg.cmb.metadata; + return md && typeof md.key === 'string' ? md.key : null; +} + +module.exports = { + RECORDS_PER_SECOND, RECORDS_BURST, RECORD_CHARS_PER_SECOND, RECORD_CHARS_BURST, + QUEUE_SECONDS, QUEUE_RECORDS, QUEUE_CHARS, QUEUE_TOTAL_RECORDS, QUEUE_TOTAL_CHARS, + REFUSAL_NOTICE_MS, REFUSAL_IDS_MAX, REFUSAL_PENDING_MAX, RETRY_AFTER_MIN_MS, RETRY_AFTER_MAX_MS, + REFUSALS_BEFORE_CUT, FLOOD_PENALTY_MS, + BUDGET_FRAME, REFUSED_FRAME, LEGACY_BUDGET, HELD_REFUSALS_MAX, HELD_MAX_AGE_MS, SENT_WINDOW_MS, SENT_WINDOW_MAX, UNDELIVERED_LOG_MAX, + recordChars, refillBucket, bucketWait, budgetFrame, parseBudgetFrame, parseRefusedFrame, + OutboundBudget, RecordAdmission, +}; diff --git a/lib/frame-handler.js b/lib/frame-handler.js index 3fee8140..d353d0c5 100644 --- a/lib/frame-handler.js +++ b/lib/frame-handler.js @@ -7,6 +7,10 @@ const { wireNodeId, wireName } = require('./wire-identity'); const { canonicalRecordV2_0 } = require('./core/record-canonical'); const { moodFrameReason } = require('./core/mood-frame'); const { ATTEST_FRAME, fromWireAttestation, fromWireCheckpoint, fromWireWitness, fromWireNodeStats } = require('./core/attestation'); +const { + RECORDS_PER_SECOND, RECORDS_BURST, RECORD_CHARS_PER_SECOND, RECORD_CHARS_BURST, + BUDGET_FRAME, REFUSED_FRAME, recordChars, refillBucket, bucketWait, budgetFrame, RecordAdmission, +} = require('./flow-control'); /** * @module @sym-bot/sym/frame-handler @@ -94,23 +98,25 @@ const DIRECTED_MARK = /#(asrt-|sd:|sig:)/; const { PEER_INFO_MAX } = require('./core/wake'); /** A record refused for its audience is said at most once per this many ms per peer and reason. */ -/** Refill a session's token bucket `slot` (a burst, then a rate a second) and return it. */ +/** + * A session's token bucket `slot` (a burst, then a rate a second), refilled to `now`. A clock stepped + * back refills nothing and takes nothing (lib/flow-control.js refillBucket). + */ function refill(session, slot, perSecond, burst, now) { const b = session[slot] || (session[slot] = { tokens: burst, at: now }); - b.tokens = Math.min(burst, b.tokens + ((now - b.at) * perSecond) / 1000); - b.at = now; - return b; + return refillBucket(b, perSecond, burst, now); } -/** Take one record from a count bucket and `chars` from a size bucket, both or neither. */ -function takeBoth(session, countSlot, countRate, countBurst, sizeSlot, sizeRate, sizeBurst, chars) { - const now = Date.now(); - const c = refill(session, countSlot, countRate, countBurst, now); - const s = refill(session, sizeSlot, sizeRate, sizeBurst, now); - const need = Math.max(0, Math.min(Number(chars) || 0, sizeBurst)); - if (c.tokens < 1 || s.tokens < need) return false; - c.tokens -= 1; - s.tokens -= need; - return true; +/** Milliseconds until a session's count lane holds one record and its size lane `chars` (0: now). */ +function laneWait(session, countSlot, countRate, countBurst, sizeSlot, sizeRate, sizeBurst, chars, now) { + return Math.max( + bucketWait(refill(session, countSlot, countRate, countBurst, now), countRate, countBurst, 1, now), + bucketWait(refill(session, sizeSlot, sizeRate, sizeBurst, now), sizeRate, sizeBurst, Math.max(0, Number(chars) || 0), now), + ); +} +/** Spend one record and `chars` (at most the size burst) of a session's two lanes. */ +function laneSpend(session, countSlot, countRate, countBurst, sizeSlot, sizeRate, sizeBurst, chars, now) { + refill(session, countSlot, countRate, countBurst, now).tokens -= 1; + refill(session, sizeSlot, sizeRate, sizeBurst, now).tokens -= Math.min(Math.max(0, Number(chars) || 0), sizeBurst); } /** Freeze an object graph (plain data: a structured clone of a record). */ @@ -124,16 +130,14 @@ function deepFreeze(o) { /** A directed record older than this by its signed timestamp is refused as a replay (finding G). */ /** - * New records one session has evaluated, at most: a burst, then a rate a second (security review D). - * A busy room's peer sends a few a second; one record costs the SVAF encoder tens of milliseconds. - */ -const RECORDS_PER_SECOND = 8; -const RECORDS_BURST = 32; -/** + * New records one session has evaluated, at most: a burst, then a rate a second (security review D; + * RECORDS_PER_SECOND and RECORDS_BURST, lib/flow-control.js). A busy room's peer sends a few a second; + * one record costs the SVAF encoder tens of milliseconds. + * * Records one session may have checked at all, before any work on them (final re-review, Finding 3): * the lane spent ahead of the schema check, key recomputation and signature verification, as the - * gossip lane is ahead of a statement's. Past it a record is dropped unchecked and unmarked. The burst - * covers a fetch answer (at most 64 records) and the anchor replay. + * gossip lane is ahead of a statement's. The burst covers a fetch answer (at most 64 records) and the + * anchor replay. */ const VERIFY_PER_SECOND = 32; const VERIFY_BURST = 128; @@ -142,30 +146,19 @@ const VERIFY_BURST = 128; * the SVAF encoder in proportion to its text, and a record may carry 720 KiB, so counting records let * one peer send 32 of the largest a second and buy CPU, memory and disk without bound. A record spends * its size in characters (category texts and application data; recordChars) from a second bucket on - * each lane, and passes only if both buckets hold enough. Each burst holds at least two records of the - * largest size, so any one record can pass. The usual peer sends records of a few KiB: far inside both. + * each lane (RECORD_CHARS_PER_SECOND and RECORD_CHARS_BURST for the record lane). Each burst holds at + * least two records of the largest size, so any one record can pass. The usual peer sends records of + * a few KiB: far inside both. + * + * PAST THE BUDGET A RECORD WAITS, IT IS NOT DROPPED (flow control, 0.14.3; lib/flow-control.js). Every + * record a session brings is admitted only when both lanes hold it and nothing of that session waits + * ahead of it; otherwise it is queued, in order, and admitted as the lanes refill, so the budget bounds + * the work exactly as before and loses nothing. Only past the queue's bound is a record refused, and its + * sender is told (`cmb-refused`) when to try again. Until 0.14.3 a record past either lane was dropped + * unchecked or unevaluated while its sender reported it dispatched. */ const VERIFY_CHARS_PER_SECOND = 1024 * 1024; const VERIFY_CHARS_BURST = 4 * 1024 * 1024; -const RECORD_CHARS_PER_SECOND = 128 * 1024; -const RECORD_CHARS_BURST = 1536 * 1024; -/** What a record weighs for the size budgets: its texts and application data, in characters. */ -function recordChars(cmb) { - let n = 512; - const cats = cmb && typeof cmb === 'object' ? cmb.categories : null; - if (cats && typeof cats === 'object') { - for (const v of Object.values(cats)) { - if (typeof v === 'string') n += v.length; - else if (v && typeof v === 'object' && typeof v.text === 'string') n += v.text.length; - } - } - const md = cmb && typeof cmb === 'object' ? cmb.metadata : null; - if (md && typeof md === 'object') { - if (md.application && typeof md.application === 'object' && typeof md.application.data === 'string') n += md.application.data.length; - if (typeof md.createdBy === 'string') n += md.createdBy.length; - } - return n; -} /** cmb-fetch serving bounds per session (security review D, fetch-amp). */ const FETCH_SERVE_PER_SECOND = 2; const FETCH_SERVE_BURST = 8; @@ -283,6 +276,8 @@ class FrameHandler { this._ledgerLines = 0; // lines the file holds this._ledgerEvicted = 0; this._loadLedger(); + // FLOW CONTROL (0.14.3): records past a session's budget wait here, in order, for it to refill. + this._admission = this._makeAdmission(); } /** @private Read the delivery ledger (`mark\texpiresAt` per line; a 0.14.2 line is a bare mark). */ @@ -450,16 +445,60 @@ class FrameHandler { * @private */ /** - * @private Take one of `session`'s pre-verification tokens and `chars` of its pre-verification size - * budget (R2-3), or neither. @returns {boolean} + * @private Milliseconds until both of `session`'s lanes hold a record of `chars` (0: now): the + * pre-verification lane and the record lane, each by count and by size (R2-3). A record is admitted + * only when this is 0 (see _handleMemoryShare), so neither lane is ever overdrawn. */ - _verifyBudget(session, chars = 0) { - return takeBoth(session, '_verifyBucket', VERIFY_PER_SECOND, VERIFY_BURST, '_verifyCharsBucket', VERIFY_CHARS_PER_SECOND, VERIFY_CHARS_BURST, chars); + _admitWait(session, chars = 0, now = Date.now()) { + return Math.max( + laneWait(session, '_verifyBucket', VERIFY_PER_SECOND, VERIFY_BURST, '_verifyCharsBucket', VERIFY_CHARS_PER_SECOND, VERIFY_CHARS_BURST, chars, now), + laneWait(session, '_recordBucket', RECORDS_PER_SECOND, RECORDS_BURST, '_recordCharsBucket', RECORD_CHARS_PER_SECOND, RECORD_CHARS_BURST, chars, now), + ); + } + + /** @private Spend `session`'s pre-verification lane for a record of `chars`: before any work on it. */ + _spendVerify(session, chars = 0, now = Date.now()) { + laneSpend(session, '_verifyBucket', VERIFY_PER_SECOND, VERIFY_BURST, '_verifyCharsBucket', VERIFY_CHARS_PER_SECOND, VERIFY_CHARS_BURST, chars, now); + } + + /** @private Spend `session`'s record lane for a new record of `chars`: before SVAF encodes anything. */ + _spendRecord(session, chars = 0, now = Date.now()) { + laneSpend(session, '_recordBucket', RECORDS_PER_SECOND, RECORDS_BURST, '_recordCharsBucket', RECORD_CHARS_PER_SECOND, RECORD_CHARS_BURST, chars, now); + } + + /** The record budget this node advertises to each admitted session (`cmb-budget`). */ + flowBudget() { + const L = this._admission.limits; + return budgetFrame({ recordsPerSecond: RECORDS_PER_SECOND, recordsBurst: RECORDS_BURST, charsPerSecond: RECORD_CHARS_PER_SECOND, charsBurst: RECORD_CHARS_BURST, queueRecords: L.queueRecords, queueChars: L.queueChars }); } - /** @private Take one of `session`'s record tokens and `chars` of its record size budget (R2-3), or neither. @returns {boolean} */ - _recordBudget(session, chars = 0) { - return takeBoth(session, '_recordBucket', RECORDS_PER_SECOND, RECORDS_BURST, '_recordCharsBucket', RECORD_CHARS_PER_SECOND, RECORD_CHARS_BURST, chars); + /** @private The admission queue in front of the record budget (lib/flow-control.js). */ + _makeAdmission() { + const node = this._node; + return new RecordAdmission({ + wait: (session, chars, now) => this._admitWait(session, chars, now), + run: (e) => { + this._spendVerify(e.session, e.chars); + return this._processRecord(e.peerId, e.peerName, e.msg, e.session); + }, + // The door, consulted per frame (MMP §5.8.1), and again for a record that waited: a peer no + // longer admitted (evicted, penalised) has what it queued dropped, counted. + admitted: (e) => { + if (typeof node._penalised === 'function' && node._penalised(e.peerId)) return false; + if (typeof node._floodPenalised === 'function' && node._floodPenalised(e.peerId)) return false; + return typeof node._roomDoor !== 'function' || node._roomDoor(e.peerId).pass === true; + }, + sessionFor: (peerId) => { + const s = node._peers && node._peers.get(peerId) && node._peers.get(peerId).transport; + return s && s.confirmed && !s.closed && !s.legacy && typeof s.trySend === 'function' ? s : null; + }, + cut: (session) => { if (typeof node._penaliseFlood === 'function') node._penaliseFlood(session); }, + fail: (e, err) => { + if (typeof node._refuseFrame === 'function') node._refuseFrame(e.peerId, e.peerName, e.msg, e.session && e.session.kind === 'relay' ? 'relay' : 'lan', err); + }, + metric: (m) => { try { node.emit('metric', m); } catch { /* a sink's failure is not the queue's */ } }, + say: (key, line) => this._sayOnceAMinute(this._audienceSaid, key, (more) => `${line}${more}`), + }); } _markCmbSurfaced(key, msg) { @@ -621,6 +660,15 @@ class FrameHandler { if (typeof this._node._noteSessionRefusal === 'function') this._node._noteSessionRefusal(session, msg.type, 'legacy-attest-frame'); return undefined; + // Flow control (0.14.3, lib/flow-control.js): the peer's record budget, and the records of this + // node's it refused past its queue. A 0.14.2 node ignores both (§7.3, below). + case BUDGET_FRAME: + if (typeof this._node._onPeerBudget === 'function') this._node._onPeerBudget(session, msg); + return undefined; + case REFUSED_FRAME: + if (typeof this._node._onPeerRefused === 'function') this._node._onPeerRefused(session, msg); + return undefined; + case 'cmb-fetch': return this._handleCmbFetch(peerId, peerName, msg, session); @@ -861,15 +909,10 @@ class FrameHandler { if (!md.sig) return refuse('unsigned'); if (typeof md.createdByNodeId !== 'string' || !md.createdByNodeId) return refuse('no-author-node-id'); // The work a record costs is charged before any of it is done (final re-review, Finding 3): the - // session's verification lane, then the (relayer, author) failure window. Dropped unchecked and - // unmarked either way, so a genuine copy from elsewhere is still taken. + // session's verification lane was spent when the record was admitted (_handleMemoryShare), then + // the (relayer, author) failure window, dropped unchecked and unmarked, so a genuine copy from + // elsewhere is still taken. const session = this._sessionOf.get(msg); - if (session && !this._verifyBudget(session, recordChars(cmb))) { - msg._cmbVerified = false; - this._node.emit('metric', { type: 'cmb-over-verify-budget', from: peerName, key: k }); - this._sayOnceAMinute(this._audienceSaid, `${peerId}|verify-budget`, (more) => `CMBs from ${peerName} over its verification budget (${VERIFY_PER_SECOND}/s) — dropped unchecked${more}`); - return true; - } if (typeof this._node._relayMuted === 'function' && this._node._relayMuted(peerId, md.createdByNodeId)) { msg._cmbVerified = false; this._node.emit('metric', { type: 'relayed-signer-muted', kind: 'record', peer: peerId, author: md.createdByNodeId.slice(0, 128) }); @@ -1209,6 +1252,15 @@ class FrameHandler { // own node authored is marked one. if (msg.cmb && msg.cmb.metadata && msg.cmb.metadata.createdByNodeId === session.nodeId) msg._anchor = true; } + // FLOW CONTROL (0.14.3): a session's records are admitted in order, each once both of its lanes + // hold it; one that arrives past the budget, or behind one that waits, is queued until they do, + // and only past the queue's bound refused, its sender told (lib/flow-control.js). + if (session) return this._admission.offer(session, peerId, peerName, msg, recordChars(msg && msg.cmb)); + return this._processRecord(peerId, peerName, msg, session); + } + + /** @private One record, admitted: verified, evaluated and surfaced (or refused on its merits). */ + _processRecord(peerId, peerName, msg, session) { // The session rides beside the frame, never on it: entries are built from the frame and kept. if (session) this._sessionOf.set(msg, session); let pending; @@ -1442,13 +1494,9 @@ class FrameHandler { // A session's new records are evaluated at most RECORDS_PER_SECOND (burst RECORDS_BURST): charged // here, after the signature and the de-duplication and before SVAF encodes anything, which is - // most of what a record costs (security review D, record-flood). Past it the record is dropped - // unmarked, so a later copy is taken. - if (session && !this._recordBudget(session, recordChars(msg.cmb))) { - this._node.emit('metric', { type: 'cmb-over-budget', from: peerName, key: cognitionKey }); - this._sayOnceAMinute(this._audienceSaid, `${peerId}|record-budget`, (more) => `CMBs from ${peerName} over its budget (${RECORDS_PER_SECOND}/s) — dropped unevaluated${more}`); - return; - } + // most of what a record costs (security review D, record-flood). The record was admitted only once + // the lane held it (_handleMemoryShare), and nothing since spent it, so this never overdraws. + if (session) this._spendRecord(session, recordChars(msg.cmb)); // A record signed to this node by its author, verified, fresh, new and within the session's // budget, is accepted for delivery from here on whatever SVAF decides about memory (it surfaces, diff --git a/lib/node.js b/lib/node.js index 67d0e6d0..f28d6d6f 100644 --- a/lib/node.js +++ b/lib/node.js @@ -211,15 +211,20 @@ function inboxChars(m) { /** inbox file -> the SymNode in this process that owns it (see the constructor). */ const INBOX_OWNERS = new Map(); /** - * Records held for a peer's next session after a relay close (R3-4), at most: per peer by count and - * bytes (the pacer's own per-destination bound), and in all (the pacer's queue bound). And the bytes of - * re-offered records waiting in one relay session's pacer queue at once. + * Records held for a peer (R3-4; flow control, 0.14.3: waiting for its record budget, refused and + * waiting for its retry-after, or left by a closed session), at most: per peer by count and size (the + * pacer's own per-destination bounds; characters, as the record budget counts them), and in all (the + * pacer's queue bound). And the bytes and the records waiting in one relay session's pacer queue at once. */ const REDELIVER_PER_PEER = 2048; -const REDELIVER_PER_PEER_BYTES = 8 * 1024 * 1024; +const REDELIVER_PER_PEER_CHARS = 8 * 1024 * 1024; const REDELIVER_MAX = 10_000; const REOFFER_WINDOW_BYTES = 4 * 1024 * 1024; const REOFFER_WINDOW_COUNT = 512; +const { + BUDGET_FRAME, REFUSED_FRAME, HELD_REFUSALS_MAX, HELD_MAX_AGE_MS, SENT_WINDOW_MS, SENT_WINDOW_MAX, UNDELIVERED_LOG_MAX, FLOOD_PENALTY_MS, + recordChars, parseBudgetFrame, parseRefusedFrame, OutboundBudget, +} = require('./flow-control'); /** What start() returns on a running node with nothing queued (the same promise each time). */ const RUNNING = Promise.resolve(); /** A peer that delivered a forged signature is not admitted again for this long (security review D). */ @@ -235,7 +240,7 @@ const KNOWN_FRAME_TYPES = new Set(['cmb', 'cmb-encrypted', 'control-encrypted', 'ping', 'pong', 'error', 'cmb-anchors', 'mood', 'wake-channel', 'peer-info', 'sym-attest-attestation', 'sym-attest-checkpoint', 'sym-attest-witness', 'sym-attest-node-stats', 'attestation', 'checkpoint', 'witness', 'node-stats', 'cmb-fetch', 'cmb-fetch-result', 'role-grant', 'role-revoke', 'role-chain-fetch', 'role-chain', 'role-digest', 'authority-statement', 'authority-digest', - 'authority-fetch', 'authority-set', 'xmesh-insight', 'room-join', 'handshake', + 'authority-fetch', 'authority-set', 'xmesh-insight', 'room-join', 'handshake', 'cmb-budget', 'cmb-refused', 'state-sync', 'message', 'session-confirmed', 'relay-auth', 'relay-peers', 'relay-peer-joined', 'relay-peer-left', 'relay-ping', 'relay-pong', 'relay-reauth', 'relay-error']); /** 1011 replies to relay froms this node holds no session with: a token bucket over all of them. */ @@ -302,6 +307,7 @@ const NOT_SENT = Object.freeze({ SEND_FAILED: 'send-failed', // a transport that says only whether, not why UNSEALABLE: 'unsealable', // not a signed v2.0 record: nothing else travels in Core Secure QUEUE_FULL: 'queue-full', // the relay pacer's queue is full + HELD_FULL: 'held-full', // the records held for that peer are at their bound (flow control) }); /** How each reason reads in the log. */ @@ -312,6 +318,7 @@ const NOT_SENT_SAID = Object.freeze({ [NOT_SENT.SEND_FAILED]: 'send failed', [NOT_SENT.UNSEALABLE]: 'not a signed v2.0 record (only those travel in Core Secure)', [NOT_SENT.QUEUE_FULL]: 'the relay send queue is full', + [NOT_SENT.HELD_FULL]: 'the records held for that peer are at their bound (2048 or 8 Mi characters a peer, 10,000 in all)', }); /** @@ -2338,8 +2345,9 @@ class SymNode extends EventEmitter { for (const [peerId, peer] of this._peers) { // Only a frame a transport took counts: this counted every peer, so a block no peer could take // (too large, a closed socket) was logged as shared with all of them. - const sent = trySend(peer.transport, { type: 'cmb', timestamp: ts, cmb }); - if (sent.ok) shared++; + // Held for the peer's record budget counts as shared: it is written as the budget refills. + const sent = this._sendRecord(peerId, { type: 'cmb', timestamp: ts, cmb }, peer.transport); + if (sent.written || sent.queued) shared++; else this._log(`Not shared with ${peer.name || peerId.slice(0, 8)}: ${NOT_SENT_SAID[sent.reason] || sent.reason}${sent.bytes ? ` (${sent.bytes} bytes)` : ''}`); } @@ -2646,6 +2654,9 @@ class SymNode extends EventEmitter { this._legacy.stop(); if (this._interior) this._interior.close(); + // Records queued past a peer's budget are refused, the peer told while its session is still open, + // so it offers them again to this node's next session (flow control). + try { this._frameHandler._admission.stop(); } catch (err) { this._log(`Stopping the record queue failed: ${err && err.message}`); } // Every session, confirmed or not, ends with the node; a relay session tells its peer. for (const session of [...this._sessions]) { try { session.close('node-stopped'); } catch { /* shutting down */ } @@ -3197,7 +3208,7 @@ class SymNode extends EventEmitter { // Encrypt categories per-peer if shared secret is available (E2E encryption) const baseCmb = entry.cmb || null; - const { dispatched: shared, reason: notSent } = this._dispatchCmb(baseCmb, entry.storedAt, opts.to); + const { dispatched: shared, queued, reason: notSent } = this._dispatchCmb(baseCmb, entry.storedAt, opts.to); // Feed signal to the Layer-6 insight engine, when one is injected if (this._xmesh) this._xmesh.ingestSignal({ @@ -3210,8 +3221,8 @@ class SymNode extends EventEmitter { }); const fanoutDesc = opts.to - ? `target=${opts.to.slice(0, 8)} (${shared ? 'sent' : NOT_SENT_SAID[notSent] || notSent})` - : `${shared}/${this._peers.size} peers`; + ? `target=${opts.to.slice(0, 8)} (${shared ? 'sent' : queued ? 'held for its record budget' : NOT_SENT_SAID[notSent] || notSent})` + : `${shared}/${this._peers.size} peers${queued ? `, ${queued} held for their record budget` : ''}`; this._log(`Remembered: "${content.slice(0, 50)}${content.length > 50 ? '...' : ''}" → ${fanoutDesc}`); // MMP §4.4.4 — the addressed send is the one promise this layer makes, so it is @@ -3242,16 +3253,22 @@ class SymNode extends EventEmitter { // `undelivered` is still sound as written, and is the load-bearing category: // never-dispatched does entail never-delivered, even though the converse // does not hold. + // + // `queued` (flow control, 0.14.3) counts copies held for a peer's record budget: not dispatched + // yet, written as the budget refills, listed in pendingDeliveries() until they are, and said + // undelivered (the 'undelivered' event) if they are given up. A directed send held is not + // undelivered. Object.defineProperty(entry, 'delivery', { value: Object.freeze({ directed: !!opts.to, to: opts.to || null, targets: opts.to ? (this._peers.has(opts.to) ? 1 : 0) : this._peers.size, dispatched: shared, - undelivered: !!opts.to && shared === 0, + queued, + undelivered: !!opts.to && shared === 0 && queued === 0, // Why a directed send was not dispatched (NOT_SENT_SAID's keys): not connected is one // reason of several, and the one this used to report for all of them. - ...(opts.to && shared === 0 ? { reason: notSent } : {}), + ...(opts.to && shared === 0 && queued === 0 ? { reason: notSent } : {}), }), enumerable: false, configurable: true, @@ -3690,7 +3707,9 @@ class SymNode extends EventEmitter { try { cmb = this._mintMessage(content, to); } catch (err) { this._log(`Message to ${String(to).slice(0, 8)} not sent: ${err.message}`); continue; } const peer = this._peers.get(to); if (!peer) continue; - if (trySend(peer.transport, { type: 'cmb', timestamp: Date.now(), cmb }).ok) delivered++; + // Through the peer's held list (flow control): written within its record budget, or held. + const r = this._sendRecord(to, { type: 'cmb', timestamp: Date.now(), cmb }, peer.transport); + if (r.written || r.queued) delivered++; } // A sleeping peer is woken, and the message waits for it as a record signed to it (the retired // `message` frame is never queued). @@ -3885,8 +3904,11 @@ class SymNode extends EventEmitter { // WHY the relay is not connected, and the one-line description that says the fix. relayState: this._relay.state(), relayStatus: this._relay.describe(), - // Records a relay close left unsent, held for their peers' next sessions (pendingDeliveries()). + // Records taken to send and not yet dispatched: held for a peer's record budget or retry-after, + // or left by a closed session (pendingDeliveries()); flowControl says what was queued, refused + // and given up, as a receiver and as a sender (undelivered() lists the last given up). pendingDeliveries: this._redeliverCount || 0, + flowControl: this.flowStatus(), peers: this.peers(), peerCount: this._peers.size, memoryCount: this.memories(), @@ -4217,6 +4239,7 @@ class SymNode extends EventEmitter { _admitSession(session) { const nodeId = session.nodeId; if (this._penalised(nodeId)) { this._refuseAdmission(session, 'delivered a forged signature; not admitted again yet'); return; } + if (this._floodPenalised(nodeId)) { this._refuseAdmission(session, 'kept sending records past this node\'s queue after it was told; not admitted again yet'); return; } // EVERY CONFIRMED SESSION RUNS WITH A BINDING (security review D, binding-squat): its proven key is // held for nodeId while the session lives (the session-scoped table, bounded by the session caps), // and a second key for that nodeId is a conflict. The durable registry takes only EARNED @@ -4331,6 +4354,9 @@ class SymNode extends EventEmitter { * @private */ _greetSession(peer, session, isNew) { + // Flow control (0.14.3): this node's record budget for the session, first, so the peer paces what + // it sends to it (a 0.14.2 peer ignores the frame, §7.3). + if (this._flowSession(session)) session.send(this._frameHandler.flowBudget()); if (!this._lastAnchorSent) this._lastAnchorSent = new Map(); const lastSent = this._lastAnchorSent.get(peer.peerId) || 0; const now = Date.now(); @@ -4354,7 +4380,9 @@ class SymNode extends EventEmitter { announced = true; session.send({ type: 'cmb-anchors', keys: anchors.map((a) => a.cmb.metadata.key) }); let sent = 0; - for (const a of anchors) if (session.send({ type: 'cmb', cmb: a.cmb })) sent++; + // Anchors spend the session's record budget as any record does (at most five: within the burst). + const flow = this._flowSession(session) ? this._outFlow(session) : null; + for (const a of anchors) if (session.send({ type: 'cmb', cmb: a.cmb })) { sent++; if (flow) flow.take(recordChars(a.cmb)); } this._log(`Sent ${sent} anchor CMB(s) to ${peer.name}`); } } else if (isNew) { @@ -4377,13 +4405,19 @@ class SymNode extends EventEmitter { let sent = 0; for (const e of pending) { if (!e || !e.frame || e.key !== session.identityKey || !this._sessionTakes(session, e.frame.type)) continue; - if (session.send(e.frame)) sent++; + // A queued record (a message to a sleeping peer) goes through the peer's held list, paced. + if (e.frame.type === 'cmb' && this._flowSession(session)) { + const r = this._sendRecord(peer.peerId, e.frame, session); + if (r.written || r.queued) sent++; + } else if (session.send(e.frame)) sent++; } this._log(`Delivered ${sent} of ${pending.length} pending frame(s) to ${peer.name}`); this._pendingFrames.delete(peer.peerId); } // Records a relay close left unsent (R3-4), to a session proving the key they were sealed to. this._reofferHeld(peer.peerId, session); + // Refusals of this peer's records owed since its last session closed (flow control). + this._frameHandler._admission.flushFor(peer.peerId); } /** @private A frame from a session: the door first (design D6), then the one guarded dispatch. */ @@ -5037,10 +5071,13 @@ class SymNode extends EventEmitter { } /** - * Fan a CMB out to every peer, or to one peer when `to` is set (MMP §4.4.4). - * @returns {{ dispatched: number, reason: string|null }} `dispatched` counts frames a transport - * accepted (not frames a peer received); `reason` is why the last peer that did not get one did - * not (NOT_SENT_SAID's keys), or null when every target got one. + * Fan a CMB out to every peer, or to one peer when `to` is set (MMP §4.4.4). Each peer's copy goes + * through that peer's held list (_sendRecord): written now when its session's budget holds it, else + * held and written as the budget refills. + * @returns {{ dispatched: number, queued: number, reason: string|null }} `dispatched` counts frames a + * session took within its peer's budget (not frames a peer received); `queued`, copies held for the + * budget (listed in pendingDeliveries() until written); `reason` is why the last peer that got + * neither did not (NOT_SENT_SAID's keys), or null when every target got one or the other. * @private */ _dispatchCmb(baseCmb, timestamp, to) { @@ -5062,22 +5099,17 @@ class SymNode extends EventEmitter { } let shared = 0; + let queued = 0; for (const [peerId, peer] of targets) { // One sealed frame per peer session (design D4): each session has its own keys. The record's // binding — directed or room-bound — is its signed, AAD-bound `metadata.to` (§8.8.4), never a // frame flag; the session refuses a record that is not a signed v2.0 record. - const frame = { type: 'cmb', timestamp, cmb: baseCmb }; - const t = peer.transport; - // On a relay session the frame waits in the pacer; a `meta` rides with it, so a record the pacer - // never wrote before the connection closed is held for the peer's next session (R3-4). - const meta = t && t.kind === 'relay' && typeof t.identityKey === 'string' - ? { redeliver: true, to: peerId, key: t.identityKey, sessionId: t.sessionId, frame, recordKey: recordKey(baseCmb), since: Date.now(), attempts: 1, held: false, offered: false, bytes: 0 } - : null; - const sent = meta ? t.trySend(frame, meta) : trySend(t, frame); + const sent = this._sendRecord(peerId, { type: 'cmb', timestamp, cmb: baseCmb }, peer.transport); // A transport refuses a frame when the socket is closed, the relay is not open, the write // failed or the frame is over MAX_FRAME_SIZE. Counting those as dispatched made a stale peer // read as reached, and reporting them all as "not connected" hid a frame no peer could take. - if (sent.ok) { shared++; continue; } + if (sent.written) { shared++; continue; } + if (sent.queued) { queued++; continue; } reason = sent.reason; if (sent.reason === SEND_FAILURE.TOO_LARGE) { this._log(`CMB ${String(recordKey(baseCmb) || '').slice(0, 16)} not sent to ${peer.name || peerId.slice(0, 8)}: its frame is ${sent.bytes} bytes, over the ${MAX_FRAME_SIZE}-byte bound`); @@ -5085,26 +5117,97 @@ class SymNode extends EventEmitter { } } - return { dispatched: shared, reason }; + return { dispatched: shared, queued, reason }; } - // ── Records the relay pacer never wrote (R3-4) ───────────── + // ── Records to each peer: paced, held and offered again (R3-4; flow control, 0.14.3) ────────── + // + // EVERY RECORD TO A PEER GOES THROUGH THAT PEER'S HELD LIST, oldest first. It is written to the + // peer's session only within the record budget that peer advertised for it (`cmb-budget`; a peer + // that advertises nothing — 0.14.2 and older — gets the 0.14.2 budget with a margin, LEGACY_BUDGET) + // and, on a relay session, while the pacer has room. What fits is written at once; the rest waits + // and is written as the budget refills. A record counts as dispatched only when it is written. // - // `dispatched` counts records a session took. On a relay session a record then waits in the pacer - // (20 frames a second), and the pacer was simply emptied when the connection closed: 260 directed - // records reported dispatched, 227 lost after one drop. Now what the pacer still holds when the - // connection closes comes back here, is HELD for that peer — for the identity key it was sealed - // to — and is offered again, sealed afresh, to the next session that proves that key (over the - // relay or the LAN). It is reported as not delivered until it is written to a socket: - // pendingDeliveries() lists it, status().pendingDeliveries counts it, and metrics say each step - // ('cmb-requeued', 'cmb-redelivered', and 'cmb-undelivered' when it is dropped: the bound below, or - // the node stopping). A receiver surfaces a record once for the life of its store (the delivery - // ledger), so one offered twice is not delivered twice. + // Until 0.14.3 a record was written at once whatever the receiver could take, and the receiver + // dropped what was past its budget, unevaluated, while this node reported it dispatched: 49 directed + // messages in a burst arrived as 38; 12 of 200 KB as 7; 120 records re-offered after a relay drop + // as 37 (this node said 115 redelivered). The receiver now queues what is past its budget and + // refuses only past its queue, naming the records (`cmb-refused`): those come back here, are held + // again in their place, and are offered again after the retry-after it gave; after + // HELD_REFUSALS_MAX refusals, or once a record is HELD_MAX_AGE_MS old by its signed timestamp (past + // that a receiver refuses a directed record as a replay), it is given up and said undelivered. // - // THE RESIDUAL: a frame written to the socket and lost after that (in the kernel, in the relay, - // on the relay's way to the peer) is still lost and still reads as dispatched. Only an end-to-end - // receipt would close that, and that is protocol work. The held list is process memory: a node - // that stops or crashes drops it (the record stays in its store). + // On a relay session a record written waits in the pacer (20 frames a second), and is written to + // the socket later: it stays on the list (`offered`) until the socket's write callback says so, and + // what the pacer still holds when the connection or the session closes comes back here, held for + // that peer — for the identity key it was sealed to — and offered again, sealed afresh, to the next + // session that proves that key (over the relay or the LAN). It is reported as not delivered until + // then: pendingDeliveries() lists it, status().pendingDeliveries counts it, and metrics say each + // step ('cmb-requeued' with why, 'cmb-redelivered' when a held record is written, 'cmb-undelivered' + // and the 'undelivered' event when one is given up; undelivered() lists the last of those). A + // receiver surfaces a record once for the life of its store (the delivery ledger), so one offered + // twice is not delivered twice. + // + // THE RESIDUAL: a frame written to a socket and lost after that (in the kernel, in the relay, on the + // relay's way to the peer, or in a LAN socket's buffer when it closes) is still lost and still reads + // as dispatched. Only an end-to-end receipt would close that, and that is protocol work. The held + // list is process memory: a node that stops or crashes drops it (the record stays in its store). + + /** @private Whether records to `s` are flow-controlled: a Core Secure session that proved a key. */ + _flowSession(s) { + return !!s && typeof s.trySend === 'function' && typeof s.identityKey === 'string' && !!s.identityKey && !s.legacy; + } + + /** @private `session`'s outbound record budget, as its receiver keeps it (lib/flow-control.js). */ + _outFlow(session) { + return session._outFlow || (session._outFlow = new OutboundBudget(Date.now())); + } + + /** @private The flow-control counters status() reports. */ + _flowCounters() { + return this._flowStats || (this._flowStats = { written: 0, paced: 0, refusedByPeers: 0, refusedUnmatched: 0, undelivered: 0, budgetsHeard: 0, cut: 0 }); + } + + /** + * @private Send one record frame to one peer through its held list: written now when nothing of the + * peer's waits ahead of it and its session's budget (and a relay pacer's room) holds it; otherwise + * held, and written as the budget refills. A record the session refused outright (too large, not + * addressed to it, the transport down) is not held: it is reported as before. + * @returns {{ written?: true, queued?: true, reason?: string, bytes?: number }} + */ + _sendRecord(peerId, frame, session) { + const s = session || (this._peers.get(peerId) || {}).transport; + if (!s) return { reason: SEND_FAILURE.NOT_CONNECTED }; + if (!this._flowSession(s) || !this._running) { + // A transport no handshake proved a key for (an embedder's, a test's), or a node not running + // (nothing would write a held record later): written at once, as before. + const sent = trySend(s, frame); + return sent.ok ? { written: true } : { reason: sent.reason, bytes: sent.bytes }; + } + if (!s.confirmed || s.closed) return { reason: SEND_FAILURE.NOT_CONNECTED }; + const cmb = frame && frame.cmb; + const md = cmb && cmb.metadata; + const now = Date.now(); + const m = { + redeliver: true, to: peerId, key: s.identityKey, frame, recordKey: recordKey(cmb), + assertionId: md && typeof md.assertionId === 'string' ? md.assertionId : null, + chars: recordChars(cmb), bytes: 0, since: now, + signedAt: md && Number.isFinite(md.createdTimestamp) ? md.createdTimestamp : now, + attempts: 0, refusals: 0, notBefore: 0, held: false, offered: false, reported: false, written: false, sessionId: null, + }; + if (!this._holdRecord(m)) return { reason: NOT_SENT.HELD_FULL }; + this._reofferHeld(peerId, s); + if (m.written) return { written: true }; + if (!m.held || m.attempts > 0) { + // The session refused it (as before this was a send it did not take): not held, said by the caller. + this._unhold(m); + return { reason: m.failed || NOT_SENT.SEND_FAILED, ...(m.failedBytes ? { bytes: m.failedBytes } : {}) }; + } + m.reported = true; + this._flowCounters().paced++; + this._metricSafe({ type: 'cmb-requeued', to: peerId, key: m.recordKey, reason: 'paced' }); + return { queued: true }; + } /** @private Records the pacer handed back on a close: held for each peer's next session. */ _holdUnflushed(items) { @@ -5115,7 +5218,7 @@ class SymNode extends EventEmitter { const m = it && it.meta; if (!m || !m.redeliver) continue; if (m.held) this._releaseHeld(m, 'node-stopped'); - else this._metricSafe({ type: 'cmb-undelivered', to: m.to, key: m.recordKey, reason: 'node-stopped' }); + else this._reportUndelivered(m, 'node-stopped'); } return; } @@ -5125,8 +5228,11 @@ class SymNode extends EventEmitter { const m = it && it.meta; if (!m || !m.redeliver) continue; m.offered = false; + m.refusedEarly = false; // held again either way; its retry-after (notBefore) stands if (Number.isFinite(it.bytes)) m.bytes = it.bytes; - if (!m.held && !this._holdRecord(m)) continue; + if (!m.held && !this._holdRecord(m)) { this._reportUndelivered(m, 'held-full'); continue; } + m.reported = true; + this._metricSafe({ type: 'cmb-requeued', to: m.to, key: m.recordKey, reason: 'unflushed' }); held++; peers.add(m.to); } @@ -5141,152 +5247,379 @@ class SymNode extends EventEmitter { try { this.emit('metric', m); } catch { /* a bad sink never stops the bookkeeping */ } } - /** @private Hold one record for its peer, within the bounds. @returns {boolean} held */ + /** + * @private Hold one record for its peer, in the order records were first sent, within the bounds: per + * peer by count and size, and in all. A record that does not fit is not held — a new one is refused + * (its send says so), one coming back is said undelivered — and nothing held is pushed out for it. + * @returns {boolean} held + */ _holdRecord(m) { + if (!Number.isFinite(m.chars)) m.chars = recordChars(m.frame && m.frame.cmb); + if (!Number.isFinite(m.signedAt)) { + const ts = m.frame && m.frame.cmb && m.frame.cmb.metadata ? m.frame.cmb.metadata.createdTimestamp : undefined; + m.signedAt = Number.isFinite(ts) ? ts : Date.now(); + } + if (!Number.isFinite(m.refusals)) m.refusals = 0; + if (!Number.isFinite(m.notBefore)) m.notBefore = 0; if (!this._redeliver) this._redeliver = new Map(); let list = this._redeliver.get(m.to); - if (!list) { list = []; this._redeliver.set(m.to, list); } + const count = list ? list.items.length : 0; + if (count >= REDELIVER_PER_PEER || (count > 0 && list.chars + m.chars > REDELIVER_PER_PEER_CHARS) || (this._redeliverCount || 0) >= REDELIVER_MAX) { + try { this._sayOncePerMinute('redeliver-full', `UNDELIVERED: the records held for a peer are at the bound (${REDELIVER_PER_PEER} or ${REDELIVER_PER_PEER_CHARS} characters a peer, ${REDELIVER_MAX} in all): a record past it is not sent`); } catch { /* said or not, refused */ } + return false; + } + if (!list) { list = { items: [], chars: 0 }; this._redeliver.set(m.to, list); } m.held = true; - list.push(m); - // Oldest first: a record dispatched earlier can come back later (its session ended later). - if (list.length > 1 && list[list.length - 2].since > m.since) list.sort((x, y) => x.since - y.since); + // Oldest first: a record sent earlier can come back later (refused, or its session ended later). + let i = list.items.length; + while (i > 0 && list.items[i - 1].since > m.since) i--; + list.items.splice(i, 0, m); + list.chars += m.chars; this._redeliverCount = (this._redeliverCount || 0) + 1; - this._metricSafe({ type: 'cmb-requeued', to: m.to, key: m.recordKey }); - // The bounds: per peer by count and bytes, and in all; the oldest held record goes first. - const bytes = () => list.reduce((n, x) => n + (x.bytes || 0), 0); - while (list.length > REDELIVER_PER_PEER || (list.length > 1 && bytes() > REDELIVER_PER_PEER_BYTES)) this._releaseHeld(list[0], 'redelivery-overflow'); - while (this._redeliverCount > REDELIVER_MAX) { - const oldest = [...this._redeliver.values()].filter((l) => l.length).sort((x, y) => x[0].since - y[0].since)[0]; - if (!oldest) break; - this._releaseHeld(oldest[0], 'redelivery-overflow'); - } - return m.held; + return true; } - /** - * @private A held record leaves the list: written to a socket ('redelivered'), or dropped (any other - * reason: said as not delivered). - */ - _releaseHeld(m, outcome) { - if (!m || !m.held) return; + /** @private Take a record off its peer's held list, saying nothing. @returns {boolean} it was held */ + _unhold(m) { + if (!m || !m.held) return false; m.held = false; m.offered = false; const list = this._redeliver && this._redeliver.get(m.to); if (list) { - const i = list.indexOf(m); - if (i !== -1) { list.splice(i, 1); this._redeliverCount--; } - if (!list.length) this._redeliver.delete(m.to); + const i = list.items.indexOf(m); + if (i !== -1) { list.items.splice(i, 1); list.chars -= m.chars; this._redeliverCount--; } + if (!list.items.length) this._redeliver.delete(m.to); } + return true; + } + + /** + * @private A held record leaves the list: written ('sent' in its first pass, said nothing more; + * 'redelivered' once it had been held), or given up (any other outcome: said undelivered). + */ + _releaseHeld(m, outcome) { + if (!this._unhold(m)) return; + if (outcome === 'sent') return; if (outcome === 'redelivered') { this._metricSafe({ type: 'cmb-redelivered', to: m.to, key: m.recordKey, attempts: m.attempts }); return; } - if (outcome === 'redelivery-overflow') { - try { this._sayOncePerMinute('redeliver-overflow', `UNDELIVERED: held records over the bound (${REDELIVER_PER_PEER} or ${REDELIVER_PER_PEER_BYTES} bytes a peer, ${REDELIVER_MAX} in all): the oldest are dropped, not sent`); } catch { /* said or not, dropped */ } + this._reportUndelivered(m, outcome); + } + + /** @private A record this node will not send again: counted, listed (undelivered()), said, and raised. */ + _reportUndelivered(m, reason) { + this._flowCounters().undelivered++; + const item = Object.freeze({ to: m.to, key: m.recordKey || null, assertionId: m.assertionId || null, reason, attempts: m.attempts || 0, refusals: m.refusals || 0, since: m.since || null, at: Date.now() }); + if (!this._undeliveredLog) this._undeliveredLog = []; + this._undeliveredLog.push(item); + if (this._undeliveredLog.length > UNDELIVERED_LOG_MAX) this._undeliveredLog.shift(); + this._metricSafe({ type: 'cmb-undelivered', to: m.to, key: m.recordKey, reason }); + try { this._sayOncePerMinute(`undelivered|${reason}`, `UNDELIVERED: record ${String(m.recordKey || m.assertionId || '').slice(0, 16)} to ${String(m.to).slice(0, 8)} given up (${reason}); it stays in this node's store (undelivered())`); } catch { /* said or not, counted */ } + // The event a host shows: a send this node had taken and now will not make. + try { this.emit('undelivered', item); } catch (err) { try { this._log(`An 'undelivered' listener threw: ${err && err.message}`); } catch { /* */ } } + } + + /** + * @private A record was written to its session within its peer's budget (a LAN session), or the relay + * socket wrote it: dispatched. It is remembered SENT_WINDOW_MS, so a refusal naming it brings it back. + */ + _recordWritten(m) { + this._releaseHeld(m, m.reported ? 'redelivered' : 'sent'); + this._flowCounters().written++; + if (!m.assertionId) return; + if (!this._sentWindow) this._sentWindow = new Map(); + const k = `${m.to}|${m.assertionId}`; + m.sentAt = Date.now(); + this._sentWindow.delete(k); + this._sentWindow.set(k, m); + this._pruneSentWindow(m.sentAt); + } + + /** @private The records written that a refusal may still name: the last SENT_WINDOW_MS, at most SENT_WINDOW_MAX. */ + _pruneSentWindow(now = Date.now()) { + const w = this._sentWindow; + if (!w) return; + for (const [k, m] of w) { + if (w.size <= SENT_WINDOW_MAX && now - m.sentAt < SENT_WINDOW_MS) break; + w.delete(k); } - this._metricSafe({ type: 'cmb-undelivered', to: m.to, key: m.recordKey, reason: outcome }); } - /** @private The pacer wrote a frame sent with a meta: a held record is delivered as far as this node can tell. */ + /** @private The pacer wrote a frame sent with a meta: the record is dispatched as far as this node can tell. */ _redeliveryFlushed(m) { - if (!m || !m.held) return; + if (!m || !m.held || !m.offered) return; const to = m.to; - this._releaseHeld(m, 'redelivered'); + if (m.refusedEarly) { + // The peer refused it before this node heard the socket had written it: held again, as a refusal is. + m.offered = false; + m.refusedEarly = false; + this._metricSafe({ type: 'cmb-requeued', to, key: m.recordKey, reason: 'refused' }); + this._scheduleReoffer(to, Math.max(0, m.notBefore - Date.now())); + return; + } + this._recordWritten(m); // The next held records for that peer go once there is room in the pacer. if (this._redeliver && this._redeliver.has(to)) this._scheduleReoffer(to); } /** - * @private Re-offer `nodeId`'s held records soon: next turn, or after `delayMs` (a pass that found no - * room in the pacer and has nothing of its own waiting there to re-arm it). One pending per peer. + * @private Offer `nodeId`'s held records soon: next turn, or after `delayMs` (the budget refilling, a + * retry-after, a pass that found no room in the pacer). One pending per peer, the earliest kept. */ _scheduleReoffer(nodeId, delayMs = 0) { if (!this._running) return; if (!this._reofferSoon) this._reofferSoon = new Map(); - if (this._reofferSoon.has(nodeId)) return; + const at = Date.now() + Math.max(0, delayMs); + const pending = this._reofferSoon.get(nodeId); + if (pending) { + if (pending.at <= at) return; + clearTimeout(pending.t); clearImmediate(pending.t); + } const run = () => { this._reofferSoon.delete(nodeId); try { this._reofferHeld(nodeId); } catch (err) { this._log(`Re-offering held records failed: ${err && err.message}`); } }; + let t; if (delayMs > 0) { - const t = setTimeout(run, delayMs); + t = setTimeout(run, delayMs); if (t.unref) t.unref(); - this._reofferSoon.set(nodeId, t); } else { - this._reofferSoon.set(nodeId, setImmediate(run)); + t = setImmediate(run); } + this._reofferSoon.set(nodeId, { t, at }); } /** - * @private Offer `nodeId`'s held records to `session` (or the peer's current transport): only to a - * confirmed session proving the key each was sealed to, sealed afresh, oldest first. On a relay - * session a record stays held until the pacer writes it, and at most REOFFER_WINDOW_BYTES of them - * wait in the pacer at once (the pacer refuses past its own bound, and a refused sealed frame ends - * the session); on a LAN session it is written at once. + * @private Write `nodeId`'s held records to `session` (or the peer's current transport), oldest first: + * only to a confirmed session proving the key each was sealed to, sealed afresh, each once its + * session's budget holds it (and a refused one once its retry-after has passed). On a relay session + * a record stays held until the pacer writes it, and at most REOFFER_WINDOW_BYTES or + * REOFFER_WINDOW_COUNT of them wait in the pacer at once (the pacer refuses past its own bound, and a + * refused sealed frame ends the session); on a LAN session it is dispatched once written. The pass + * stops at the first record that has to wait, and comes back when it may go. */ _reofferHeld(nodeId, session) { if (!this._running) return; const list = this._redeliver && this._redeliver.get(nodeId); - if (!list || !list.length) return; + if (!list || !list.items.length) return; const s = session || (this._peers.get(nodeId) || {}).transport; - if (!s || s.closed || !s.confirmed || typeof s.trySend !== 'function') return; + if (!this._flowSession(s) || s.closed || !s.confirmed) return; // A relay client session the server has not yet shown it took (it waits to supersede the old one) // is not offered them: if its finish was lost, what it carried is lost with it. It is offered them // once it supersedes (_completeSupersede), and the old one meanwhile is the peer's. if (s._supersedes) return; const relay = s.kind === 'relay'; const room = (bytes) => !relay || !s.transport || typeof s.transport.hasRoom !== 'function' || s.transport.hasRoom(bytes); + const flow = this._outFlow(s); + const now = Date.now(); + let again = 0; let offered = 0; - let waiting = list.filter((m) => m.offered).length; + let waiting = 0; + if (relay) for (const m of list.items) if (m.offered) waiting++; let stalled = false; - for (const m of [...list]) { + for (const m of [...list.items]) { if (!m.held || m.offered || m.key !== s.identityKey) continue; - if (relay && (waiting >= REOFFER_WINDOW_COUNT || (s.pendingBytes() + (m.bytes || 0) > REOFFER_WINDOW_BYTES && s.pendingBytes() > 0) || !room(m.bytes || 0))) { stalled = true; break; } + if (now - m.signedAt > HELD_MAX_AGE_MS) { this._releaseHeld(m, 'expired'); continue; } + if (m.notBefore > now) { again = m.notBefore - now; break; } + const wait = flow.wait(m.chars, now); + if (wait > 0) { again = wait; break; } + // What the sealed frame will weigh in the pacer, until the pacer has said (a record's text, its + // JSON and the AEAD's base64url). + const bytes = m.bytes || Math.ceil(m.chars * 1.4) + 1024; + if (relay && (waiting >= REOFFER_WINDOW_COUNT || (s.pendingBytes() + bytes > REOFFER_WINDOW_BYTES && s.pendingBytes() > 0) || !room(bytes))) { stalled = true; break; } m.attempts++; if (relay) m.sessionId = s.sessionId; const r = relay ? s.trySend(m.frame, m) : s.trySend(m.frame); if (!r || !r.ok) { - const reason = r && r.reason; + const reason = (r && r.reason) || NOT_SENT.SEND_FAILED; + m.failed = reason; + m.failedBytes = r && r.bytes; // A record this session can never take (its audience, too large) is dropped; any other // refusal leaves it held for the next session. - if (reason === 'not-addressed' || reason === 'unsealable' || reason === SEND_FAILURE.TOO_LARGE) this._releaseHeld(m, `redelivery-${reason}`); + if (reason === 'not-addressed' || reason === 'unsealable' || reason === SEND_FAILURE.TOO_LARGE) { + if (m.reported) this._releaseHeld(m, `redelivery-${reason}`); else this._unhold(m); + } if (s.closed) break; continue; } - offered++; - if (relay) { m.offered = true; waiting++; } else this._releaseHeld(m, 'redelivered'); + flow.take(m.chars, now); + m.written = true; + if (m.reported) offered++; + if (relay) { m.offered = true; waiting++; } else this._recordWritten(m); } - if (offered) this._log(`Re-offered ${offered} held record(s) to ${s.name || nodeId.slice(0, 8)} on a new ${s.kind} session`); + if (offered) this._log(`Wrote ${offered} held record(s) to ${s.name || nodeId.slice(0, 8)} (${s.kind} session, within its record budget)`); + if (again > 0) this._scheduleReoffer(nodeId, again); // A pass the pacer's room stopped, with none of these records waiting in it (whose flush would // re-arm the next pass), tries again shortly: the pacer drains at its own rate. - if (stalled && waiting === 0) this._scheduleReoffer(nodeId, 250); + else if (stalled && waiting === 0) this._scheduleReoffer(nodeId, 250); + } + + /** @private Held records past HELD_MAX_AGE_MS are given up, and the sent window pruned (the heartbeat). */ + _sweepHeld(now = Date.now()) { + if (this._redeliver) { + for (const list of [...this._redeliver.values()]) { + for (const m of [...list.items]) if (!m.offered && now - m.signedAt > HELD_MAX_AGE_MS) this._releaseHeld(m, 'expired'); + } + } + this._pruneSentWindow(now); + } + + /** + * @private A peer told this node the record budget it keeps for this session (`cmb-budget`): records + * to it on this session are paced to it from now on. + */ + _onPeerBudget(session, frame) { + const b = parseBudgetFrame(frame); + if (!b) { this._noteSessionRefusal(session, BUDGET_FRAME, 'malformed'); return; } + const flow = this._outFlow(session); + if (!flow.advertised) this._flowCounters().budgetsHeard++; + flow.apply(b, Date.now()); + this._metricSafe({ type: 'peer-budget', peer: session.nodeId, ...b }); + if (this._redeliver && this._redeliver.has(session.nodeId)) this._scheduleReoffer(session.nodeId); + } + + /** + * @private A peer refused records of this node's past its queue (`cmb-refused`): nothing more goes on + * that session until the retry-after, and each record it names that this node wrote in the last + * SENT_WINDOW_MS goes back on the held list, in its place, to be offered after it — to that peer + * only (a room record other peers took is not sent to them again). A record refused more than + * HELD_REFUSALS_MAX times is given up and said undelivered. + */ + _onPeerRefused(session, frame) { + const r = parseRefusedFrame(frame); + if (!r) { this._noteSessionRefusal(session, REFUSED_FRAME, 'malformed'); return; } + const now = Date.now(); + const peerId = session.nodeId; + // The session the notice came on, and the one this node now writes that peer's records on. + this._outFlow(session).backOff(r.retryAfterMs, now); + const current = (this._peers.get(peerId) || {}).transport; + if (current && current !== session && this._flowSession(current)) this._outFlow(current).backOff(r.retryAfterMs, now); + const counters = this._flowCounters(); + let matched = 0; + // A record still marked as waiting in the relay pacer (its write callback not yet seen) may be + // refused already: it is held again when the callback comes (_redeliveryFlushed). + const inPacer = new Map(); + const list = this._redeliver && this._redeliver.get(peerId); + if (list) for (const m of list.items) if (m.offered && m.assertionId) inPacer.set(m.assertionId, m); + for (const id of r.ids) { + const k = `${peerId}|${id}`; + const early = inPacer.get(id); + if (early && !early.refusedEarly) { + matched++; + early.refusals++; + if (early.refusals > HELD_REFUSALS_MAX) { this._releaseHeld(early, 'refused'); continue; } + early.refusedEarly = true; + early.reported = true; + early.notBefore = now + r.retryAfterMs; + continue; + } + const m = this._sentWindow && this._sentWindow.get(k); + if (!m) continue; + this._sentWindow.delete(k); + matched++; + m.refusals++; + if (m.refusals > HELD_REFUSALS_MAX) { this._reportUndelivered(m, 'refused'); continue; } + m.notBefore = now + r.retryAfterMs; + m.offered = false; + m.written = false; + m.reported = true; + if (!this._holdRecord(m)) { this._reportUndelivered(m, 'held-full'); continue; } + this._metricSafe({ type: 'cmb-requeued', to: peerId, key: m.recordKey, reason: 'refused' }); + } + counters.refusedByPeers += matched; + this._metricSafe({ type: 'cmb-refused-by-peer', peer: peerId, count: r.ids.length, matched, retryAfterMs: r.retryAfterMs }); + if (matched < r.ids.length) { + // Not one this node wrote to that peer in the last minute (older, or never this node's): it may + // not have arrived, and nothing here can send it again. Counted and said, nothing more. + counters.refusedUnmatched += r.ids.length - matched; + this._metricSafe({ type: 'cmb-refused-unmatched', peer: peerId, count: r.ids.length - matched }); + } + this._sayOncePerMinute(`refused-by|${peerId}`, `${session.name || peerId.slice(0, 8)} refused ${r.ids.length} record(s) past its queue (${matched} held again here): offered again in ${Math.round(r.retryAfterMs / 1000)} s`); + this._scheduleReoffer(peerId, r.retryAfterMs); + } + + /** + * @private A session that kept sending records past this node's queue after it was told to retry + * (lib/flow-control.js): closed, and its peer not admitted again for FLOOD_PENALTY_MS, as a forgery + * is (an honest sender paces to the budget it was told and never gets here). + */ + _penaliseFlood(session) { + if (!session || session.closed || typeof session.close !== 'function') return false; + const nodeId = session.nodeId; + if (!this._floodPenalty) this._floodPenalty = new Map(); + this._floodPenalty.delete(nodeId); + if (this._floodPenalty.size >= GOSSIP_MAX_PEERS) this._floodPenalty.delete(this._floodPenalty.keys().next().value); + this._floodPenalty.set(nodeId, Date.now() + FLOOD_PENALTY_MS); + this._flowCounters().cut++; + this._metricSafe({ type: 'record-flood-cut', peer: nodeId }); + this._sayOncePerMinute(`flood|${nodeId}`, `[sym-security] ${session.name || String(nodeId).slice(0, 8)} kept sending records past this node's queue after it was told to retry later: session closed, not admitted again for ${FLOOD_PENALTY_MS / 1000} s`); + session.close('record-flood'); + return true; + } + + /** @private Whether `nodeId` is inside a record-flood penalty (and drop it when it has run out). */ + _floodPenalised(nodeId) { + const until = this._floodPenalty && this._floodPenalty.get(nodeId); + if (!until) return false; + if (Date.now() < until) return true; + this._floodPenalty.delete(nodeId); + return false; } /** @private Every held record is dropped (the node stopping): said, and counted as not delivered. */ _dropRedelivery(reason) { if (this._reofferSoon) { - for (const t of this._reofferSoon.values()) { try { clearTimeout(t); clearImmediate(t); } catch { /* */ } } + for (const p of this._reofferSoon.values()) { try { clearTimeout(p.t); clearImmediate(p.t); } catch { /* */ } } this._reofferSoon.clear(); } + if (this._sentWindow) this._sentWindow.clear(); if (!this._redeliver || !this._redeliver.size) return; let n = 0; - for (const list of [...this._redeliver.values()]) for (const m of [...list]) { this._releaseHeld(m, reason); n++; } + for (const list of [...this._redeliver.values()]) for (const m of [...list.items]) { this._releaseHeld(m, reason); n++; } this._redeliver.clear(); this._redeliverCount = 0; if (n) this._log(`UNDELIVERED: ${n} held record(s) dropped (${reason}); they stay in this node's store`); } /** - * Records this node dispatched over a relay session that closed before its pacer sent them, held - * for each peer's next session: NOT delivered until written to one (see above). Oldest first. - * @returns {Array<{ to: string, key: string, since: number, attempts: number, offered: boolean }>} + * Records this node has taken to send and not yet dispatched, held for each peer: waiting for the + * peer's record budget (`waiting`), refused by the peer and waiting for its retry-after + * (`refused`), written to a relay pacer and not yet to the socket (`written`), or left by a session + * that closed. NOT delivered until written (see above). Oldest first. + * @returns {Array<{ to: string, key: string, since: number, attempts: number, offered: boolean, state: string, refusals: number }>} */ pendingDeliveries() { const out = []; - if (this._redeliver) for (const list of this._redeliver.values()) for (const m of list) out.push({ to: m.to, key: m.recordKey, since: m.since, attempts: m.attempts, offered: !!m.offered }); + const now = Date.now(); + if (this._redeliver) { + for (const list of this._redeliver.values()) { + for (const m of list.items) { + out.push({ to: m.to, key: m.recordKey, since: m.since, attempts: m.attempts, offered: !!m.offered, state: m.offered ? 'written' : (m.notBefore > now ? 'refused' : 'waiting'), refusals: m.refusals || 0 }); + } + } + } return out.sort((a, b) => a.since - b.since); } + /** + * The last records (at most 256) this node had taken to send and gave up: refused by the peer more + * than HELD_REFUSALS_MAX times, held past HELD_MAX_AGE_MS, past the held list's bound, or dropped + * when the node stopped. Each is also raised as the 'undelivered' event. + * @returns {Array<{ to: string, key: string|null, assertionId: string|null, reason: string, attempts: number, refusals: number, since: number|null, at: number }>} + */ + undelivered() { + return [...(this._undeliveredLog || [])]; + } + + /** Flow control, as status() reports it: what this node queued and refused as a receiver, and what it holds and gave up as a sender. */ + flowStatus() { + return { + receiver: this._frameHandler && this._frameHandler._admission ? this._frameHandler._admission.status() : null, + sender: { held: this._redeliverCount || 0, sentWindow: this._sentWindow ? this._sentWindow.size : 0, ...this._flowCounters() }, + }; + } + /** * Deliver the record of a send that minted nothing (collapsed onto HEAD, or already stored) to * its one addressed peer, and attach the same `delivery` result a fresh send carries, so the @@ -5296,13 +5629,14 @@ class SymNode extends EventEmitter { */ _dispatchExisting(result, key, to) { const cmb = result.cmb || null; - const { dispatched: shared, reason } = cmb ? this._dispatchCmb(cmb, Date.now(), to) : { dispatched: 0, reason: NOT_SENT.SEND_FAILED }; + const { dispatched: shared, queued = 0, reason } = cmb ? this._dispatchCmb(cmb, Date.now(), to) : { dispatched: 0, reason: NOT_SENT.SEND_FAILED }; + const undelivered = shared === 0 && queued === 0; Object.defineProperty(result, 'delivery', { - value: Object.freeze({ directed: true, to, targets: this._peers.has(to) ? 1 : 0, dispatched: shared, undelivered: shared === 0, ...(shared === 0 ? { reason } : {}) }), + value: Object.freeze({ directed: true, to, targets: this._peers.has(to) ? 1 : 0, dispatched: shared, queued, undelivered, ...(undelivered ? { reason } : {}) }), enumerable: false, configurable: true, }); - if (shared === 0) { + if (undelivered) { this._log(`UNDELIVERED (directed): ${to.slice(0, 8)} ${NOT_SENT_SAID[reason] || reason} — record ${String(key).slice(0, 16)} NOT sent`); this.emit('metric', { type: 'cmb-undelivered', to, key, reason }); } @@ -5314,7 +5648,7 @@ class SymNode extends EventEmitter { */ _markUndelivered(result, key, to, reason) { Object.defineProperty(result, 'delivery', { - value: Object.freeze({ directed: true, to, targets: this._peers.has(to) ? 1 : 0, dispatched: 0, undelivered: true, reason }), + value: Object.freeze({ directed: true, to, targets: this._peers.has(to) ? 1 : 0, dispatched: 0, queued: 0, undelivered: true, reason }), enumerable: false, configurable: true, }); @@ -5349,6 +5683,8 @@ class SymNode extends EventEmitter { _checkHeartbeats() { const now = Date.now(); + // Held records past their age are given up; the sent window is pruned (flow control). + try { this._sweepHeld(now); } catch (err) { this._log(`Sweeping held records failed: ${err && err.message}`); } // Per session (§5.4): every live path is checked, so a degraded secondary is found and closed. for (const session of [...this._sessions]) { if (!session.confirmed) continue; From 4308f4aac965f485a424b7d0c6bc5625dda12773 Mon Sep 17 00:00:00 2001 From: "SYM.BOT" Date: Wed, 14 Oct 2026 19:29:58 +0100 Subject: [PATCH 2/7] Tests: flow control end to end (bursts, relay and LAN drops, both old-peer directions) and every new guard tests/flow-control.test.js: 49 messages, 12 x 200 KB and 40 x 50 KB over the LAN, 49 messages over a relay, 120 records across a relay drop and across a LAN drop, new sender to a 0.14.2-like receiver and a 0.14.2-like sender to a new receiver: all delivered once, the sender's counts true. tests/flow-control-bounds.test.js: the queue's bounds (per session and in all, by count and size), the door and penalties for what waits, arrival order, the cut and its episodes, the pre-verification lane for copies, the notice rate, a stopping receiver, the advertisement and malformed frames, legacy pacing, a late advertisement, anchors, refusals (in place, back-off, any session, given up, room records to one peer only, an unmatched or late refusal, one refused in the relay pacer), the age bound, the held list's bounds, the buckets' clock. The R2-3 and record-flood tests and the held-list bound test now pin waiting, not dropping. --- tests/core-secure-review.test.js | 6 +- tests/flow-control-bounds.test.js | 711 ++++++++++++++++++++++++++++++ tests/flow-control.test.js | 304 +++++++++++++ tests/relay-redelivery.test.js | 11 +- tests/security-0.14.3.test.js | 27 +- 5 files changed, 1043 insertions(+), 16 deletions(-) create mode 100644 tests/flow-control-bounds.test.js create mode 100644 tests/flow-control.test.js diff --git a/tests/core-secure-review.test.js b/tests/core-secure-review.test.js index 3cc06031..6c354b8c 100644 --- a/tests/core-secure-review.test.js +++ b/tests/core-secure-review.test.js @@ -235,7 +235,7 @@ describe('D. no shared budget before verification; bounds (cs-review-B, cs-revie assert.ok(resMs < 500, `resolved in ${resMs.toFixed(0)} ms`); }); - it('record-flood: one peer\'s distinct records are evaluated at most at the session budget', async () => { + it('record-flood: one peer\'s distinct records are evaluated at most at the session budget; the rest waits', async () => { const N = mk('rf-n', { room: 'g' }); const E = mk('rf-e', { room: 'g' }); try { await N.start(); await E.start(); @@ -245,11 +245,11 @@ describe('D. no shared budget before verification; bounds (cs-review-B, cs-revie const author = { nodeId: E.nodeId, name: E.name, publicKey: E._identity.publicKey, privateKey: E._identity.privateKey }; const s = E._peers.get(N.nodeId).transport; const metrics = []; - N.on('metric', (m) => { if (m.type === 'cmb-over-budget') metrics.push(m); }); + N.on('metric', (m) => { if (m.type === 'cmb-queued') metrics.push(m); }); for (let i = 0; i < 120; i++) s.send({ type: 'cmb', cmb: signedRecord(author, { room: 'g', categories: { focus: `distinct record ${i}` } }) }); await until(() => metrics.length + evaluated >= 120, 4000); assert.ok(evaluated <= 32 + 8 * 4, `evaluated ${evaluated}: the burst (32) and 8 a second`); - assert.ok(metrics.length >= 50, 'the rest dropped unevaluated, and counted'); + assert.ok(metrics.length >= 50, 'the rest waits in the session\'s queue (flow control, 0.14.3: it was dropped unevaluated), counted'); } finally { await stopAll(N, E); } }); diff --git a/tests/flow-control-bounds.test.js b/tests/flow-control-bounds.test.js new file mode 100644 index 00000000..e3526d0f --- /dev/null +++ b/tests/flow-control-bounds.test.js @@ -0,0 +1,711 @@ +'use strict'; + +require('./_isolate-home'); // redirect $HOME before lib/config loads +process.env.SYM_SEMANTIC_ENCODER = process.env.SYM_SEMANTIC_ENCODER || 'off'; // what is measured here is not SVAF + +/** + * Flow control (0.14.3): the receiver's bounds, the two control frames, and what a sender does when + * it is told. See tests/flow-control.test.js for delivery end to end and lib/flow-control.js for the + * design. Every test here fails on 9f6847c (most because what it checks is new: the queue, the + * frames, the held list's new states) and passes now; each guard the design adds is pinned by one. + */ + +const { describe, it } = require('node:test'); +const assert = require('node:assert'); +const fs = require('fs'); +const { SymNode } = require('../lib/node'); +const { NullDiscovery, BonjourDiscovery } = require('../lib/discovery'); +const { nodeDirById } = require('../lib/config'); +const { connectNodes, until, signedRecord } = require('./_core-secure'); + +const uniq = (b) => `${b}-${Date.now()}-${Math.random().toString(36).slice(2, 6)}`; +const sleep = (ms) => new Promise((r) => setTimeout(r, ms)); +const CATS = (focus) => ({ focus, issue: 'flow control', intent: 'deliver', motivation: 'm', commitment: 'c', perspective: 'p', mood: { text: 'calm', valence: 0, arousal: 0 } }); +const big = (n, seed) => { let t = ''; let j = 0; while (t.length < n) t += `queue bound ${seed} line ${j++} `; return t.slice(0, n); }; +function mk(base, extra = {}) { return new SymNode({ name: uniq(base), silent: true, discovery: new NullDiscovery(), room: extra.room || 'flow', ...extra }); } +async function stopAll(...nodes) { + for (const n of nodes) { try { await n.stop(); } catch { /* */ } } + for (const n of nodes) { try { fs.rmSync(nodeDirById(n.nodeId), { recursive: true, force: true }); } catch { /* */ } } +} +function metrics(node) { + const by = {}; + node.on('metric', (m) => { (by[m.type] || (by[m.type] = [])).push(m); }); + by.count = (t) => (by[t] || []).length; + return by; +} +/** A node's identity as the test helpers take it (to sign records in its name). */ +const authorOf = (n) => ({ nodeId: n.nodeId, name: n.name, publicKey: n._identity.publicKey, privateKey: n._identity.privateKey }); +/** Make `node` send as 0.14.2 does: every record written at once, whatever the receiver says. */ +const asLegacySender = (node) => { if (typeof node._flowSession === 'function') node._flowSession = () => false; }; +/** The refusal frames a node receives, as they arrive (frame-handler dispatch). */ +function refusalsAt(node) { + const got = []; + const orig = node._frameHandler._dispatch.bind(node._frameHandler); + node._frameHandler._dispatch = (session, peerId, peerName, msg) => { + if (msg && msg.type === 'cmb-refused') got.push({ at: Date.now(), frame: JSON.parse(JSON.stringify(msg)) }); + return orig(session, peerId, peerName, msg); + }; + return got; +} +const flowOf = (n) => (n.status().flowControl || {}).receiver || {}; +/** Count record frames on a pipe, by direction, with when each went. */ +function pipeTap() { + const frames = []; + return { frames, tap: (f, dir) => { if (f && f.type === 'cmb-encrypted') frames.push({ dir, at: Date.now() }); } }; +} + +describe('flow control, the receiver: past its budget a record waits; past its queue it is refused and its sender told', () => { + it('a flood from a peer that ignores everything: the work stays within the budget, the queue within its bound, every refusal is reported, and the peer is cut', async () => { + const N = mk('fb-n'); const E = mk('fb-e'); + asLegacySender(E); + const nm = metrics(N); + try { + await N.start(); await E.start(); + await connectNodes(E, N); + const refused = refusalsAt(E); + // The work: records that passed every check and are evaluated (the host hook fires for each). + const spent = []; + N.on('verified-record', () => spent.push(Date.now())); + const s = E._peers.get(N.nodeId).transport; + const author = authorOf(E); + const sent = new Set(); + const wave = (from, n) => { + for (let i = from; i < from + n; i++) { + const cmb = signedRecord(author, { room: 'flow', to: N.nodeId, categories: { focus: `flood ${i}` } }); + sent.add(cmb.metadata.assertionId); + if (!s.send({ type: 'cmb', cmb })) break; + } + }; + const t0 = Date.now(); + wave(0, 1700); + assert.ok(await until(() => refused.length > 0, 5000), 'told'); + assert.strictEqual(flowOf(N).cut, 0, 'refusals before the peer was told never count toward the cut'); + wave(1700, 600); // and it keeps on, told + assert.ok(await until(() => s.closed || nm.count('record-flood-cut') > 0, 15000), 'the peer that kept on past its queue after it was told was cut'); + const elapsed = (Date.now() - t0) / 1000; + const f = flowOf(N); + assert.ok(spent.length <= 32 + 8 * elapsed + 2, `the work stayed within the budget (${spent.length} evaluated in ${elapsed.toFixed(1)} s)`); + assert.ok(f.peakRecords <= 512, `the queue held at most 512 of the session's records (${f.peakRecords})`); + assert.ok(f.refused > 1000, `past it, records were refused (${f.refused})`); + assert.ok(f.notices >= 1 && f.notices <= Math.ceil(elapsed) + 2, `the sender was told, at most once a second (${f.notices} notices in ${elapsed.toFixed(1)} s)`); + assert.ok(f.unlisted > 0, 'refusals past what a notice can carry were counted, not listed'); + assert.ok(refused.length >= 1, 'the refusal reached the sender'); + for (const r of refused) { + assert.ok(r.frame.assertionIds.length >= 1 && r.frame.assertionIds.length <= 256, 'a notice names at most 256 records'); + assert.ok(r.frame.assertionIds.every((id) => sent.has(id)), 'and only records this peer sent'); + assert.ok(Number.isInteger(r.frame.retryAfterMs) && r.frame.retryAfterMs >= 1000 && r.frame.retryAfterMs <= 64000, `with a retry-after within its bounds (${r.frame.retryAfterMs})`); + } + assert.ok(refused[0].frame.retryAfterMs >= 30000, `the retry-after is the time the full queue needs to drain (${refused[0].frame.retryAfterMs} ms for ~512 records at 8/s)`); + assert.ok(N._floodPenalised(E.nodeId), 'and its peer is not admitted again for a while'); + assert.ok(await until(() => flowOf(N).queuedRecords === 0, 3000), `what it had queued is dropped, not evaluated (${flowOf(N).queuedRecords} left)`); + assert.ok(nm.count('cmb-queue-dropped') > 100); + assert.ok(nm.count('cmb-queue-refused') === f.refused && nm.count('cmb-queued') === f.queued, 'every refusal and every queued record is a metric'); + } finally { await stopAll(N, E); } + }); + + it('large records: the queue is bounded by size as well (8 Mi characters a session)', async () => { + const N = mk('fs-n'); const E = mk('fs-e'); + asLegacySender(E); + try { + await N.start(); await E.start(); + await connectNodes(E, N); + const s = E._peers.get(N.nodeId).transport; + const author = authorOf(E); + for (let i = 0; i < 40; i++) s.send({ type: 'cmb', cmb: signedRecord(author, { room: 'flow', to: N.nodeId, categories: { focus: big(200000, `f${i}`), issue: big(200000, `i${i}`) } }) }); + assert.ok(await until(() => flowOf(N).refused > 0, 10000), 'past 8 Mi characters, records are refused'); + const f = flowOf(N); + assert.ok(f.peakChars <= 8 * 1024 * 1024, `the queue held at most 8 Mi characters (${f.peakChars})`); + assert.ok(f.peakRecords >= 15, `which is ~20 records of 400 K (${f.peakRecords})`); + } finally { await stopAll(N, E); } + }); + + it('the queue in all is bounded by count: a record past it is refused for whichever session brings it, its sender told when to retry, never cut', async () => { + const N = mk('ft-n'); const E1 = mk('ft-e1'); const E2 = mk('ft-e2'); + asLegacySender(E1); asLegacySender(E2); + const nm = metrics(N); + try { + await N.start(); await E1.start(); await E2.start(); + N._frameHandler._admission.limits.totalRecords = 40; + N._frameHandler._admission.limits.refusalsBeforeCut = 5; + await connectNodes(E1, N); await connectNodes(E2, N); + const told2 = refusalsAt(E2); + for (const [E, tag] of [[E1, 'a'], [E2, 'b']]) { + const s = E._peers.get(N.nodeId).transport; + const author = authorOf(E); + for (let i = 0; i < 100; i++) s.send({ type: 'cmb', cmb: signedRecord(author, { room: 'flow', to: N.nodeId, categories: { focus: `total ${tag} ${i}` } }) }); + // E1's queue holds the queue in all for the rest of the test: its session's lane, spent far ahead. + if (E === E1) { + assert.ok(await until(() => flowOf(N).queuedRecords === 40, 3000)); + N._peers.get(E1.nodeId).transport._recordBucket = { tokens: -1e6, at: Date.now() }; + } + await sleep(200); + } + assert.ok(await until(() => told2.length > 0, 5000), 'the second sender was told'); + // Told, it sends on while the queue in all is still full (others' records): refused, never cut. + const s2 = E2._peers.get(N.nodeId).transport; + for (let i = 100; i < 120; i++) s2.send({ type: 'cmb', cmb: signedRecord(authorOf(E2), { room: 'flow', to: N.nodeId, categories: { focus: `total b ${i}` } }) }); + await sleep(300); + const f = flowOf(N); + assert.ok(f.peakRecords <= 40, `at most the total bound waited (${f.peakRecords})`); + assert.ok(f.refused >= 90, `the rest was refused (${f.refused})`); + assert.ok((nm['cmb-queue-refused'] || []).every((m) => m.reason === 'queue-full'), 'for the queue in all'); + assert.ok(told2[0].frame.retryAfterMs >= 3000, `told to retry once the longest queue has drained (${told2[0].frame.retryAfterMs} ms; ~40 records at 8/s)`); + assert.ok(f.refused >= 108, `E2's records sent after it was told were refused too (${f.refused})`); + assert.strictEqual(f.cut, 0, 'a sender refused for others\' records is never cut'); + assert.ok(!E1._peers.get(N.nodeId).transport.closed && !E2._peers.get(N.nodeId).transport.closed); + } finally { await stopAll(N, E1, E2); } + }); + + it('the queue in all is bounded by size too', async () => { + const N = mk('fc-n'); const E = mk('fc-e'); + asLegacySender(E); + try { + await N.start(); await E.start(); + N._frameHandler._admission.limits.totalChars = 300 * 1024; + await connectNodes(E, N); + const s = E._peers.get(N.nodeId).transport; + const author = authorOf(E); + // 100 records of 60 K: the first ~25 within the 1.5 Mi burst, then the queue, at most 300 K of it. + for (let i = 0; i < 100; i++) s.send({ type: 'cmb', cmb: signedRecord(author, { room: 'flow', to: N.nodeId, categories: { focus: big(60000, `c${i}`) } }) }); + assert.ok(await until(() => flowOf(N).refused > 0, 10000)); + const f = flowOf(N); + assert.ok(f.peakChars <= 300 * 1024, `the queue in all held at most its size bound (${f.peakChars})`); + assert.ok(f.peakRecords <= 5, `about 5 records of 60 K (${f.peakRecords})`); + } finally { await stopAll(N, E); } + }); + + it('a peer no longer admitted while its records wait: what it queued is dropped, counted, never evaluated', async () => { + const N = mk('fd-n'); const E = mk('fd-e'); + asLegacySender(E); + const nm = metrics(N); + const seen = []; + N.on('cmb-accepted', (e) => seen.push(e.cmb.categories.focus.text || e.cmb.categories.focus)); + try { + await N.start(); await E.start(); + await connectNodes(E, N); + const s = E._peers.get(N.nodeId).transport; + const author = authorOf(E); + for (let i = 0; i < 60; i++) s.send({ type: 'cmb', cmb: signedRecord(author, { room: 'flow', to: N.nodeId, categories: { focus: `door ${i}` } }) }); + assert.ok(await until(() => nm.count('cmb-queued') >= 20, 5000), 'records past the budget wait'); + // The door now refuses that peer (evicted from the room, say): what waits for it is not admitted. + const door = N._roomDoor.bind(N); + N._roomDoor = (peerId) => (peerId === E.nodeId ? { pass: false, reason: 'evicted' } : door(peerId)); + assert.ok(await until(() => nm.count('cmb-queue-dropped') > 0 && flowOf(N).queuedRecords === 0, 8000), 'what waited was dropped'); + await sleep(300); + const after = seen.length; + assert.ok(after <= 33, `nothing that waited was evaluated (${after} surfaced: the burst only)`); + assert.ok(nm['cmb-queue-dropped'].every((m) => m.reason === 'not-admitted')); + } finally { await stopAll(N, E); } + }); + + it('a peer penalised for a forgery while its records wait: what it queued is dropped', async () => { + const N = mk('fpn-n'); const E = mk('fpn-e'); + asLegacySender(E); + const nm = metrics(N); + try { + await N.start(); await E.start(); + await connectNodes(E, N); + const s = E._peers.get(N.nodeId).transport; + const author = authorOf(E); + for (let i = 0; i < 60; i++) s.send({ type: 'cmb', cmb: signedRecord(author, { room: 'flow', to: N.nodeId, categories: { focus: `penalty ${i}` } }) }); + assert.ok(await until(() => nm.count('cmb-queued') >= 20, 5000)); + if (!N._forgeryPenalty) N._forgeryPenalty = new Map(); + N._forgeryPenalty.set(E.nodeId, Date.now() + 60_000); + assert.ok(await until(() => flowOf(N).queuedRecords === 0, 3000), 'dropped at once'); + assert.ok(nm.count('cmb-queue-dropped') >= 20); + } finally { await stopAll(N, E); } + }); + + it('a session\'s records are admitted in arrival order: a small one never overtakes a large one waiting for the size budget', async () => { + const N = mk('fo-n'); const E = mk('fo-e'); + asLegacySender(E); + const seen = []; + N.on('cmb-accepted', (e) => { const t = e.cmb.categories.focus.text || e.cmb.categories.focus; if (/^order /.test(t)) seen.push(t.slice(0, 12)); }); + N.on('message', (_f, t) => { if (/^order /.test(t)) seen.push(t); }); + try { + await N.start(); await E.start(); + await connectNodes(E, N); + const s = E._peers.get(N.nodeId).transport; + const author = authorOf(E); + for (let i = 0; i < 12; i++) s.send({ type: 'cmb', cmb: signedRecord(author, { room: 'flow', to: N.nodeId, categories: { focus: `order big ${String(i).padStart(2, '0')} ${big(200000, `o${i}`)}` } }) }); + await sleep(100); + for (let i = 0; i < 3; i++) E.send(`order small ${i}`, { to: N.nodeId }); + assert.ok(await until(() => seen.length === 15, 30000), `all surfaced (${seen.length})`); + assert.deepStrictEqual(seen.slice(12), ['order small 0', 'order small 1', 'order small 2'], 'the small ones after every large one before them'); + } finally { await stopAll(N, E); } + }); + + it('a notice goes at most once a second, whatever asks for it (a new session of the peer included), and what waits is sent a second later', async () => { + const { RecordAdmission } = require('../lib/flow-control'); + const sent = []; + const session = { nodeId: 'p', confirmed: true, closed: false, trySend: (f) => { sent.push({ f, at: Date.now() }); return { ok: true }; } }; + const adm = new RecordAdmission({ wait: () => 1000, run: () => {}, admitted: () => true, sessionFor: () => session, cut: () => {}, fail: () => {}, metric: () => {}, say: () => {} }); + adm.limits.queueRecords = 0; + const msg = (i) => ({ cmb: { metadata: { assertionId: `asrt-${i.toString(16).padStart(64, '0')}` } } }); + let flushes = 0; + const flush = adm.flush.bind(adm); + adm.flush = (...a) => { flushes++; return flush(...a); }; + adm.offer(session, 'p', 'p', msg(1), 100); + adm.flush('p'); + assert.strictEqual(sent.length, 1, 'the first notice goes at once'); + adm.offer(session, 'p', 'p', msg(2), 100); + adm.flushFor('p'); + adm.flush('p'); + assert.strictEqual(sent.length, 1, 'a second within the second waits'); + flushes = 0; + await until(() => sent.length === 2, 2000); + assert.strictEqual(sent.length, 2, 'and goes a second after the first'); + assert.ok(sent[1].at - sent[0].at >= 990, `${sent[1].at - sent[0].at} ms apart`); + assert.ok(flushes <= 3, `one timer waited the second out, nothing spun (${flushes} flushes)`); + adm.stop(); + }); + + it('only a peer that keeps on past ITS OWN queue in one episode is cut: refusals start over once its queue has drained', async () => { + const N = mk('fe-n'); const E = mk('fe-e'); + asLegacySender(E); + try { + await N.start(); await E.start(); + N._frameHandler._admission.limits.queueRecords = 8; + N._frameHandler._admission.limits.refusalsBeforeCut = 20; + await connectNodes(E, N); + const s = E._peers.get(N.nodeId).transport; + const author = authorOf(E); + const told = refusalsAt(E); + const send = (tag, from, n) => { for (let i = from; i < from + n; i++) s.send({ type: 'cmb', cmb: signedRecord(author, { room: 'flow', to: N.nodeId, categories: { focus: `episode ${tag} ${i}` } }) }); }; + // An episode: a burst past the queue (32 now, 8 queued, the rest refused before the peer is + // told), then, told, `after` more while its queue is still full. + const episode = async (tag, after) => { + const n = told.length; + send(tag, 0, 60); + assert.ok(await until(() => told.length > n, 5000), `told in episode ${tag}`); + send(tag, 60, after); + await until(() => flowOf(N).queuedRecords === 0, 15000); + await sleep(1100); + }; + await episode('a', 15); + await episode('b', 15); + assert.strictEqual(flowOf(N).cut, 0, 'two episodes under the bound (15 refused after being told, of 20) do not add up to a cut'); + assert.ok(!s.closed); + await episode('c', 40); + assert.ok(await until(() => flowOf(N).cut === 1, 8000), 'one episode past the bound is a cut'); + } finally { await stopAll(N, E); } + }); + + it('copies of a record already delivered spend the pre-verification lane: at most its burst and 32 a second are checked', async () => { + const N = mk('fv-n'); const E = mk('fv-e'); + asLegacySender(E); + const nm = metrics(N); + try { + await N.start(); await E.start(); + await connectNodes(E, N); + const s = E._peers.get(N.nodeId).transport; + const rec = signedRecord(authorOf(E), { room: 'flow', to: N.nodeId, categories: { focus: 'once only' } }); + s.send({ type: 'cmb', cmb: rec }); + assert.ok(await until(() => N._frameHandler._ledger.size > 0, 5000), 'the record surfaced'); + await sleep(4500); // the lanes refill + const t0 = Date.now(); + for (let i = 0; i < 400; i++) s.send({ type: 'cmb', cmb: JSON.parse(JSON.stringify(rec)) }); + await sleep(1000); + const t = (Date.now() - t0) / 1000; + const checked = nm.count('cmb-already-delivered'); + assert.ok(checked >= 100, `the burst was checked (${checked})`); + assert.ok(checked <= 128 + 32 * t + 4, `and no more than the lane holds (${checked} in ${t.toFixed(1)} s)`); + assert.ok(await until(() => nm.count('cmb-already-delivered') === 400, 15000), `every copy was checked in the end, none dropped unchecked (${nm.count('cmb-already-delivered')} of 400)`); + } finally { await stopAll(N, E); } + }); + + it('the node stopping refuses what waits and tells the sender, which offers it again to the next session: every record surfaces once', async () => { + const room = uniq('flow-stop'); + const s = new SymNode({ name: uniq('fz-s'), room, silent: true, discovery: new BonjourDiscovery({ mdns: false, room }) }); + const r = new SymNode({ name: uniq('fz-r'), room, silent: true, discovery: new BonjourDiscovery({ mdns: false, room }) }); + const seen = []; + r.on('cmb-accepted', (e) => { const t = e.cmb.categories.focus.text || e.cmb.categories.focus; if (/^stop /.test(t)) seen.push(t); }); + const sm = metrics(s); + try { + // r advertises far more than it keeps, so s writes the whole burst at once and r queues most of it. + const fb = r._frameHandler.flowBudget.bind(r._frameHandler); + r._frameHandler.flowBudget = () => ({ ...fb(), recordsPerSecond: 1000, recordsBurst: 1000, charsPerSecond: 1e9, charsBurst: 1e9 }); + await s.start(); await r.start(); + assert.ok(await until(() => s._peers.has(r.nodeId) && r._peers.has(s.nodeId), 20000)); + assert.ok(await until(() => s._peers.get(r.nodeId).transport._outFlow && s._peers.get(r.nodeId).transport._outFlow.advertised, 5000)); + for (let i = 0; i < 100; i++) s.remember(CATS(`stop ${i}`), { to: r.nodeId }); + assert.ok(await until(() => flowOf(r).queuedRecords > 20, 5000), `r has records waiting (${flowOf(r).queuedRecords})`); + await r.stop(); + assert.ok(await until(() => sm.count('cmb-refused-by-peer') > 0, 5000), 'the stopping receiver told the sender what it had not taken'); + assert.ok(s.pendingDeliveries().some((p) => p.state === 'refused'), 'held again, waiting for the retry-after'); + await r.start(); + setTimeout(() => { try { s._discovery._scanLoopback(); r._discovery._scanLoopback(); } catch { /* */ } }, 300); + assert.ok(await until(() => new Set(seen).size === 100 && s.pendingDeliveries().length === 0, 40000), `every record surfaced (${new Set(seen).size} of 100; pending ${s.pendingDeliveries().length})`); + assert.strictEqual(seen.length, 100, 'each once'); + assert.strictEqual(sm.count('cmb-undelivered'), 0); + } finally { await stopAll(s, r); } + }); +}); + +describe('flow control, the advertisement (`cmb-budget`)', () => { + it('once a session is admitted each side advertises its record budget and queue bound, and the other paces to it', async () => { + const a = mk('fa-a'); const b = mk('fa-b'); + const am = metrics(a); + try { + await a.start(); await b.start(); + await connectNodes(a, b); + assert.ok(await until(() => am.count('peer-budget') > 0, 3000), 'a heard b\'s budget'); + const flow = a._peers.get(b.nodeId).transport._outFlow; + assert.ok(flow && flow.advertised); + assert.deepStrictEqual({ ...flow.budget }, { recordsPerSecond: 8, recordsBurst: 32, charsPerSecond: 131072, charsBurst: 1572864, queueRecords: 512, queueChars: 8388608 }); + const back = b._peers.get(a.nodeId).transport._outFlow; + assert.ok(back && back.advertised, 'and b heard a\'s'); + } finally { await stopAll(a, b); } + }); + + it('a malformed advertisement or refusal notice is refused, counted, and changes nothing', async () => { + const a = mk('fm-a'); const b = mk('fm-b'); + try { + await a.start(); await b.start(); + await connectNodes(a, b); + await until(() => a._peers.get(b.nodeId).transport._outFlow && a._peers.get(b.nodeId).transport._outFlow.advertised, 3000); + const s = b._peers.get(a.nodeId).transport; + const good = { type: 'cmb-budget', recordsPerSecond: 8, recordsBurst: 32, charsPerSecond: 131072, charsBurst: 1572864, queueRecords: 512, queueChars: 8388608 }; + const id = `asrt-${'a'.repeat(64)}`; + const bad = [ + { ...good, extra: 1 }, + { ...good, recordsPerSecond: -1 }, + { ...good, recordsBurst: 0 }, + { ...good, charsPerSecond: 'fast' }, + { ...good, charsBurst: Infinity }, + { ...good, queueRecords: -5 }, + (() => { const g = { ...good }; delete g.queueChars; return g; })(), + { type: 'cmb-refused', assertionIds: [id], retryAfterMs: 1000, extra: true }, + { type: 'cmb-refused', assertionIds: [], retryAfterMs: 1000 }, + { type: 'cmb-refused', assertionIds: ['asrt-zz'], retryAfterMs: 1000 }, + { type: 'cmb-refused', assertionIds: Array.from({ length: 257 }, (_, i) => `asrt-${i.toString(16).padStart(64, '0')}`), retryAfterMs: 1000 }, + { type: 'cmb-refused', assertionIds: [id], retryAfterMs: 1.5 }, + { type: 'cmb-refused', assertionIds: [id], retryAfterMs: -1 }, + { type: 'cmb-refused', assertionIds: [id] }, + ]; + const before = a._sessionStats.refusedByReason.malformed || 0; + for (const f of bad) s.send(f); + await until(() => (a._sessionStats.refusedByReason.malformed || 0) - before === bad.length, 3000); + assert.strictEqual((a._sessionStats.refusedByReason.malformed || 0) - before, bad.length, 'each malformed frame was refused and counted'); + const flow = a._peers.get(b.nodeId).transport._outFlow; + assert.strictEqual(flow.budget.recordsPerSecond, 8, 'the budget is unchanged'); + assert.strictEqual(flow.backoffUntil, 0, 'and nothing was backed off'); + } finally { await stopAll(a, b); } + }); + + it('before, or without, an advertisement a peer is paced to 0.14.2\'s budget with a margin: 24 at once, then 6 a second', async () => { + const s = mk('fl-s'); const r = mk('fl-r'); + // r advertises nothing (as 0.14.2). + r._frameHandler.flowBudget = () => ({ type: 'x-not-a-budget' }); + const { frames, tap } = pipeTap(); + try { + await s.start(); await r.start(); + await connectNodes(s, r, { tap }); + await sleep(300); + const t0 = Date.now(); + for (let i = 0; i < 60; i++) s.send(`legacy pace ${i}`, { to: r.nodeId }); + await sleep(1000); + const toR = () => frames.filter((f) => f.dir === 'a→b' && f.at >= t0); + const inFirst = toR().filter((f) => f.at - t0 < 100).length; + assert.ok(inFirst <= 24, `at most 24 at once (${inFirst})`); + assert.ok(inFirst >= 20, `and the burst went at once (${inFirst})`); + const inSecond = toR().length; + assert.ok(inSecond <= 24 + 7, `then about 6 a second (${inSecond} in the first second)`); + } finally { await stopAll(s, r); } + }); + + it('anchors spend the session\'s budget: the burst after them is what the receiver still holds', async () => { + const s = mk('fan-s'); const r = mk('fan-r'); + try { + await s.start(); await r.start(); + for (let i = 0; i < 5; i++) s.remember(CATS(`anchor ${i}`)); + await connectNodes(s, r); + assert.ok(await until(() => s._peers.get(r.nodeId).transport._outFlow && s._peers.get(r.nodeId).transport._outFlow.advertised, 3000)); + await sleep(50); + for (let i = 0; i < 40; i++) s.send(`after anchors ${i}`, { to: r.nodeId }); + await sleep(1500); + const f = flowOf(r); + assert.ok(f.peakRecords <= 2, `the receiver never had more than jitter waiting (${f.peakRecords})`); + } finally { await stopAll(s, r); } + }); + + it('an advertisement that arrives after records were sent starts from what the receiver can still hold (its burst less what was sent)', async () => { + const s = mk('fla-s'); const r = mk('fla-r'); + const fb = r._frameHandler.flowBudget.bind(r._frameHandler); + // r advertises nothing at first, then (400 ms later) its real budget. + r._frameHandler.flowBudget = () => ({ type: 'x-not-yet' }); + const greet = r._greetSession.bind(r); + r._greetSession = (peer, session, isNew) => { greet(peer, session, isNew); setTimeout(() => { if (!session.closed) session.send(fb()); }, 400); }; + try { + await s.start(); await r.start(); + await connectNodes(s, r); + const t0 = Date.now(); + for (let i = 0; i < 60; i++) s.send(`late budget ${i}`, { to: r.nodeId }); + assert.ok(await until(() => s._peers.get(r.nodeId).transport._outFlow.advertised, 3000)); + await until(() => Date.now() - t0 > 2500, 3000); + const f = flowOf(r); + assert.ok(f.peakRecords <= 4, `the receiver never had more than jitter waiting (${f.peakRecords})`); + assert.strictEqual(f.refused, 0); + } finally { await stopAll(s, r); } + }); +}); + +describe('flow control, the sender told a record was refused (`cmb-refused`)', () => { + it('refused records are held again in their place and offered first after the retry-after, nothing goes to that session meanwhile, and every record surfaces once', async () => { + const s = mk('fr-s'); const r = mk('fr-r'); + const fb = r._frameHandler.flowBudget.bind(r._frameHandler); + // r advertises more than it keeps: 60 at once and 20 a second (it keeps 32 and 8, and queues 16). + r._frameHandler.flowBudget = () => ({ ...fb(), recordsPerSecond: 20, recordsBurst: 60, charsPerSecond: 1e9, charsBurst: 1e9 }); + const seen = []; + r.on('message', (_f, t) => seen.push(t)); + const sm = metrics(s); + const { frames, tap } = pipeTap(); + try { + await s.start(); await r.start(); + r._frameHandler._admission.limits.queueRecords = 16; + await connectNodes(s, r, { tap }); + const told = refusalsAt(s); + assert.ok(await until(() => s._peers.get(r.nodeId).transport._outFlow.advertised, 3000)); + // 60 written at once, 40 held for the (advertised) budget; past r's queue some of the 60 are refused. + for (let i = 0; i < 100; i++) s.send(`refused ${i}`, { to: r.nodeId }); + assert.ok(await until(() => told.length > 0, 5000), 'the sender was told'); + const first = told[0]; + // Sent while the session is backed off: they wait for the retry-after too. + for (let i = 100; i < 105; i++) s.send(`refused ${i}`, { to: r.nodeId }); + assert.ok(await until(() => new Set(seen).size === 105 && s.pendingDeliveries().length === 0, 40000), `every record surfaced (${new Set(seen).size} of 105)`); + assert.strictEqual(seen.length, 105, 'each once'); + // 32 now and 16 queued, in order; after the retry-after the first refused record goes first, + // ahead of the 40 held behind it. (Later, a record written before the next notice reaches the + // sender can be taken ahead of one refused: order across a refusal is not kept, see CHANGELOG.) + assert.deepStrictEqual(seen.slice(0, 49), Array.from({ length: 49 }, (_, i) => `refused ${i}`), 'a refused record went back in its place, ahead of those held behind it'); + const quiet = frames.filter((f) => f.dir === 'a→b' && f.at > first.at + 50 && f.at < first.at + first.frame.retryAfterMs - 50); + assert.deepStrictEqual(quiet, [], `nothing was written to that session during the ${first.frame.retryAfterMs} ms retry-after`); + assert.ok((sm['cmb-requeued'] || []).some((m) => m.reason === 'refused'), 'refused records were requeued'); + assert.ok(sm.count('cmb-refused-by-peer') >= 1); + assert.strictEqual(sm.count('cmb-undelivered'), 0); + assert.strictEqual(flowOf(r).cut, 0, 'an honest sender is never cut'); + assert.ok(s.status().flowControl.sender.refusedByPeers > 0, 'counted in status'); + } finally { await stopAll(s, r); } + }); + + it('a refused record waits for its retry-after on any session, a new one included', async () => { + const s = mk('fn-s'); const r = mk('fn-r'); + const got = []; + r.on('message', (_f, t) => got.push({ t, at: Date.now() })); + try { + await s.start(); await r.start(); + // r refuses the first record it is brought (its queue in all full of others'), then takes them. + const adm = r._frameHandler._admission; + const offer = adm.offer.bind(adm); + let once = false; + adm.offer = (session, peerId, peerName, msg, chars) => { + if (!once) { once = true; return adm._refuse({ session, peerId, peerName, msg, chars }, 'queue-full', Date.now()); } + return offer(session, peerId, peerName, msg, chars); + }; + await connectNodes(s, r); + const told = refusalsAt(s); + await sleep(200); + s.send('wait for it', { to: r.nodeId }); + assert.ok(await until(() => told.length > 0, 3000), 'refused, and told'); + const retryAt = told[0].at + told[0].frame.retryAfterMs; + // A new session supersedes the old one at once: it has no back-off of its own. + await connectNodes(s, r); + assert.ok(await until(() => got.length === 1, 5000), 'delivered on the new session'); + assert.ok(got[0].at >= retryAt - 50, `not before the retry-after (${got[0].at - retryAt} ms after it)`); + } finally { await stopAll(s, r); } + }); + + it('a record refused more than 8 times is given up: said undelivered, listed, raised as an event, and no longer pending', async () => { + const s = mk('fg-s'); const r = mk('fg-r'); + const events = []; + s.on('undelivered', (u) => events.push(u)); + try { + await s.start(); await r.start(); + // r refuses every record (its queue in all is full of others'). + const adm = r._frameHandler._admission; + adm.offer = (session, peerId, peerName, msg, chars) => adm._refuse({ session, peerId, peerName, msg, chars }, 'queue-full', Date.now()); + await connectNodes(s, r); + const told = refusalsAt(s); + await sleep(200); + const e = s.remember(CATS('never taken'), { to: r.nodeId }); + assert.ok(e.delivery.dispatched === 1, 'written within the budget'); + assert.ok(await until(() => events.length > 0, 30000), 'given up'); + assert.strictEqual(events[0].reason, 'refused'); + assert.strictEqual(events[0].refusals, 9, 'after the 8th retry was refused'); + assert.strictEqual(events[0].key, e.key); + assert.deepStrictEqual(s.undelivered().map((u) => [u.key, u.reason]), [[e.key, 'refused']]); + assert.strictEqual(s.pendingDeliveries().length, 0); + assert.strictEqual(s.status().flowControl.sender.undelivered, 1); + assert.strictEqual(flowOf(r).cut, 0); + assert.ok(told.length >= 9 && told.every((t) => t.frame.retryAfterMs >= 1000), 'every notice carried at least the one-second retry-after, even with nothing queued'); + } finally { await stopAll(s, r); } + }); + + it('a room record refused by one peer is retried to that peer only', async () => { + const a = mk('fp-a'); const b = mk('fp-b'); const c = mk('fp-c'); const d = mk('fp-d'); + const at = { b: [], c: [], d: [] }; + b.on('verified-record', (e) => at.b.push(e.record.metadata.key)); + c.on('verified-record', (e) => at.c.push(e.record.metadata.key)); + d.on('verified-record', (e) => at.d.push(e.record.metadata.key)); + const taps = { b: pipeTap(), c: pipeTap(), d: pipeTap() }; + try { + await a.start(); await b.start(); await c.start(); await d.start(); + // c, the second of three peers a broadcasts to, refuses the first record it is brought. + const adm = c._frameHandler._admission; + const offer = adm.offer.bind(adm); + let once = false; + adm.offer = (session, peerId, peerName, msg, chars) => { + if (!once && msg && msg.cmb && msg.cmb.metadata && msg.cmb.metadata.assertionId) { once = true; return adm._refuse({ session, peerId, peerName, msg, chars }, 'queue-full', Date.now()); } + return offer(session, peerId, peerName, msg, chars); + }; + await connectNodes(a, b, { tap: taps.b.tap }); + await connectNodes(a, c, { tap: taps.c.tap }); + await connectNodes(a, d, { tap: taps.d.tap }); + await sleep(300); + const t0 = Date.now(); + const e = a.remember(CATS('to the room')); + assert.ok(await until(() => at.c.includes(e.key), 10000), 'c took it on the retry'); + await sleep(300); + for (const p of ['b', 'c', 'd']) assert.strictEqual(at[p].filter((k) => k === e.key).length, 1, `${p} took it once`); + const frames = (p) => taps[p].frames.filter((f) => f.dir === 'a→b' && f.at >= t0).length; + assert.deepStrictEqual({ b: frames('b'), c: frames('c'), d: frames('d') }, { b: 1, c: 2, d: 1 }, 'only c was sent it again'); + } finally { await stopAll(a, b, c, d); } + }); + + it('a refusal naming a record written over a minute ago (or never) changes nothing, and is counted', async () => { + const s = mk('fw-s'); const r = mk('fw-r'); + const sm = metrics(s); + try { + await s.start(); await r.start(); + await connectNodes(s, r); + await sleep(200); + const e = s.remember(CATS('long gone'), { to: r.nodeId }); + const k = `${r.nodeId}|${e.cmb.metadata.assertionId}`; + assert.ok(s._sentWindow && s._sentWindow.has(k), 'remembered while it may still be refused'); + s._sentWindow.get(k).sentAt -= 61_000; + s._pruneSentWindow(); + r._peers.get(s.nodeId).transport.send({ type: 'cmb-refused', assertionIds: [e.cmb.metadata.assertionId], retryAfterMs: 1000 }); + assert.ok(await until(() => sm.count('cmb-refused-unmatched') > 0, 3000), 'counted as a refusal of nothing held'); + assert.strictEqual(s.pendingDeliveries().length, 0, 'nothing was held again'); + // The peer's queue is full all the same: nothing more goes to it until the retry-after. + const t0 = Date.now(); + const got = []; + r.on('message', (_f, t) => got.push(Date.now())); + assert.ok(s.send('after the refusal', { to: r.nodeId }) === 1, 'taken'); + assert.strictEqual(s.pendingDeliveries().length, 1, 'held for the retry-after'); + assert.ok(await until(() => got.length === 1, 4000)); + assert.ok(got[0] - t0 >= 800, `written once the retry-after had passed (${got[0] - t0} ms)`); + } finally { await stopAll(s, r); } + }); + + it('a record refused while it still waits in the relay pacer (its write not yet seen) is held again when the write is seen, not counted delivered', async () => { + const n = mk('fq-n'); + const to = '01900000-0000-7000-8000-0000000000bb'; + try { + await n.start(); + const metas = []; + const fake = { closed: false, confirmed: true, kind: 'relay', identityKey: 'k', sessionId: 's1', nodeId: to, name: 'fake', pendingBytes: () => 0, + transport: { hasRoom: () => true }, trySend: (frame, meta) => { metas.push(meta); return { ok: true }; }, send: () => true }; + n._peers.set(to, { peerId: to, name: 'fake', transport: fake, transports: new Map([['relay', fake]]) }); + const rec = signedRecord(authorOf(n), { room: 'flow', to, categories: { focus: 'in the pacer' } }); + assert.strictEqual(n._dispatchCmb(rec, Date.now(), to).dispatched, 1, 'written to the session (into the pacer)'); + n._onPeerRefused(fake, { type: 'cmb-refused', assertionIds: [rec.metadata.assertionId], retryAfterMs: 1000 }); + n._redeliveryFlushed(metas[0]); + const p = n.pendingDeliveries(); + assert.strictEqual(p.length, 1, 'still pending'); + assert.strictEqual(p[0].state, 'refused', 'waiting for its retry-after'); + assert.strictEqual(p[0].refusals, 1); + } finally { n._peers.clear(); await stopAll(n); } + }); + + it('a held record older than 23 h by its signed timestamp is given up (a receiver would refuse it as a replay)', async () => { + const s = mk('fx-s'); + const events = []; + s.on('undelivered', (u) => events.push(u)); + try { + await s.start(); + const to = '01900000-0000-7000-8000-0000000000aa'; + const old = signedRecord(authorOf(s), { room: 'flow', to, categories: { focus: 'old' } }); + old.metadata.createdTimestamp = Date.now() - 24 * 3600 * 1000; + s._holdUnflushed([{ to, bytes: 100, meta: { redeliver: true, to, key: 'k', frame: { type: 'cmb', cmb: old }, recordKey: 'cmb-old', since: Date.now(), attempts: 1, held: false, offered: false, bytes: 0 } }]); + assert.strictEqual(s.pendingDeliveries().length, 1, 'held'); + s._sweepHeld(); + assert.strictEqual(s.pendingDeliveries().length, 0, 'and given up'); + assert.deepStrictEqual(events.map((u) => [u.key, u.reason]), [['cmb-old', 'expired']]); + // And a pass that would write one gives it up instead. + const to2 = '01900000-0000-7000-8000-0000000000ab'; + const written = []; + const fake = { closed: false, confirmed: true, kind: 'bonjour', identityKey: 'k2', sessionId: 's9', nodeId: to2, name: 'fake', pendingBytes: () => 0, trySend: (f) => { written.push(f); return { ok: true }; } }; + const old2 = signedRecord(authorOf(s), { room: 'flow', to: to2, categories: { focus: 'old too' } }); + old2.metadata.createdTimestamp = Date.now() - 24 * 3600 * 1000; + s._holdUnflushed([{ to: to2, bytes: 100, meta: { redeliver: true, to: to2, key: 'k2', frame: { type: 'cmb', cmb: old2 }, recordKey: 'cmb-old2', since: Date.now(), attempts: 1, held: false, offered: false, bytes: 0 } }]); + s._reofferHeld(to2, fake); + assert.deepStrictEqual(written, [], 'not written'); + assert.deepStrictEqual(events.map((u) => u.key), ['cmb-old', 'cmb-old2']); + } finally { await stopAll(s); } + }); + + it('a record the session refuses outright on its first write is not held: the send says why, as before', async () => { + const s = mk('fy-s'); + try { + await s.start(); + const { admitAs, identity } = require('./_core-secure'); + const peer = identity('fy-peer'); + const sess = admitAs(s, peer); + sess.trySend = () => ({ ok: false, reason: 'write-failed' }); + const e = s.remember(CATS('the socket failed'), { to: peer.nodeId }); + assert.strictEqual(e.delivery.undelivered, true); + assert.strictEqual(e.delivery.reason, 'write-failed'); + assert.strictEqual(s.pendingDeliveries().length, 0, 'not held'); + } finally { s._peers.clear(); await stopAll(s); } + }); + + it('the held list is bounded by size too: past 8 Mi characters for a peer a new record is not held', async () => { + const s = mk('fk-s'); const r = mk('fk-r'); + try { + await s.start(); await r.start(); + await connectNodes(s, r); + await until(() => s._peers.get(r.nodeId).transport._outFlow && s._peers.get(r.nodeId).transport._outFlow.advertised, 3000); + const body = big(200 * 1024, 'held'); + let taken = 0; + for (let i = 0; i < 60; i++) taken += s.send(`${i} ${body}`, { to: r.nodeId }); + assert.ok(taken >= 25 && taken <= 50, `the held list took what 8 Mi characters hold, past the 1.5 Mi written at once (${taken} of 60)`); + } finally { await stopAll(s, r); } + }); + + it('past the held list\'s bound a new record is not held: a directed send says so (held-full)', async () => { + const s = mk('fh-s'); const r = mk('fh-r'); + try { + await s.start(); await r.start(); + await connectNodes(s, r); + await until(() => s._peers.get(r.nodeId).transport._outFlow && s._peers.get(r.nodeId).transport._outFlow.advertised, 3000); + let taken = 0; + for (let i = 0; i < 2100; i++) taken += s.send(`bound ${i}`, { to: r.nodeId }); + assert.ok(taken < 2100 && taken >= 2048, `the held list took up to its bound (${taken})`); + const e = s.remember(CATS('one too many'), { to: r.nodeId }); + assert.strictEqual(e.delivery.undelivered, true); + assert.strictEqual(e.delivery.reason, 'held-full'); + assert.ok(s.pendingDeliveries().length <= 2048); + } finally { await stopAll(s, r); } + }); +}); + +describe('flow control, the buckets', () => { + it('a clock stepped back refills nothing and takes nothing; a back-off holds a session\'s records until it ends', () => { + const { refillBucket, bucketWait, OutboundBudget } = require('../lib/flow-control'); + const b = { tokens: 5, at: 10_000 }; + refillBucket(b, 8, 32, 9_000); + assert.strictEqual(b.tokens, 5, 'nothing taken by a clock stepped back'); + assert.strictEqual(b.at, 10_000, 'and the bucket keeps its time'); + refillBucket(b, 8, 32, 10_500); + assert.strictEqual(b.tokens, 9); + assert.strictEqual(bucketWait({ tokens: 0, at: 0 }, 8, 32, 1, 0), 125, 'one record at 8 a second waits 125 ms'); + assert.strictEqual(bucketWait({ tokens: 0, at: 0 }, 10, 100, 1000, 0), 10_000, 'a need past the burst waits for the burst'); + const o = new OutboundBudget(0); + assert.strictEqual(o.budget.recordsBurst, 24); + assert.strictEqual(o.wait(100, 0), 0); + o.backOff(2000, 0); + assert.strictEqual(o.wait(100, 1000), 1000, 'a back-off holds what the buckets would allow'); + assert.strictEqual(o.wait(100, 2000), 0); + }); +}); diff --git a/tests/flow-control.test.js b/tests/flow-control.test.js new file mode 100644 index 00000000..49498439 --- /dev/null +++ b/tests/flow-control.test.js @@ -0,0 +1,304 @@ +'use strict'; + +require('./_isolate-home'); // redirect $HOME before lib/config loads +process.env.SYM_SEMANTIC_ENCODER = process.env.SYM_SEMANTIC_ENCODER || 'off'; // what is measured here is not SVAF + +/** + * Flow control for directed and room records (0.14.3): delivery end to end, with real nodes. + * + * A receiver applies a record budget per session (8 a second after a burst of 32; 128 KiB of record + * text a second after 1.5 MiB). Until 0.14.3 a record past it was DROPPED unevaluated while its + * sender reported it dispatched, and nothing offered it again. Measured on 9f6847c (and 0.14.2): + * 49 directed messages in a burst arrived as 38 over a relay (32 over the LAN); 12 records of + * 200 KB as 7; 40 of 50 KB as 30; 120 records held across a relay drop and re-offered as 37, the + * sender saying 115 redelivered. Now the receiver queues what is past its budget (delay, never a + * silent drop), advertises its budget, and the sender paces every record to it. + * + * Every test here fails on 9f6847c (a `git archive` of it) and passes now. The mixed-version tests + * stand a 0.14.3 node in for 0.14.2 the way 0.14.2 behaves (it drops past a count-only budget and + * knows no flow-control frame; it writes everything at once): on 9f6847c the stock node already + * behaves so. The same runs against a real 0.14.2 tree are in the CHANGELOG. + */ + +const { describe, it } = require('node:test'); +const assert = require('node:assert'); +const fs = require('fs'); +const { SymNode } = require('../lib/node'); +const { NullDiscovery, BonjourDiscovery } = require('../lib/discovery'); +const { nodeDirById } = require('../lib/config'); +const { fakeRelay } = require('./_fake-relay'); +const { until } = require('./_core-secure'); + +const TOKEN = 'f'.repeat(40); +const uniq = (b) => `${b}-${Date.now()}-${Math.random().toString(36).slice(2, 6)}`; +const sleep = (ms) => new Promise((r) => setTimeout(r, ms)); +const CATS = (focus, issue = 'flow control') => ({ focus, issue, intent: 'deliver', motivation: 'm', commitment: 'c', perspective: 'p', mood: { text: 'calm', valence: 0, arousal: 0 } }); +const text = (kb, seed) => { let t = ''; let j = 0; while (t.length < kb * 1024) t += `report ${seed} line ${j++} lorem ipsum dolor sit amet `; return t.slice(0, kb * 1024); }; + +/** Two nodes in one room over the LAN (TCP on the loopback, found through the loopback registry). */ +function lanPair(extraR = {}) { + const room = uniq('flow-lan'); + const mk = (n, extra = {}) => new SymNode({ name: uniq(n), room, silent: true, discovery: new BonjourDiscovery({ mdns: false, room }), ...extra }); + return { s: mk('fl-s'), r: mk('fl-r', extraR) }; +} +/** Two nodes in one room over a relay. */ +function relayPair(relay, { sRate } = {}) { + const room = uniq('flow-relay'); + const mk = (n, extra = {}) => new SymNode({ name: uniq(n), room, silent: true, relayOnly: true, relay: relay.url, relayToken: TOKEN, discovery: new NullDiscovery(), ...extra }); + return { s: mk('fr-s', sRate ? { relayRate: sRate } : {}), r: mk('fr-r') }; +} +const paired = (s, r) => () => s._peers.has(r.nodeId) && r._peers.has(s.nodeId); +async function stopAll(...nodes) { + for (const n of nodes) { try { await n.stop(); } catch { /* */ } } + for (const n of nodes) { try { fs.rmSync(nodeDirById(n.nodeId), { recursive: true, force: true }); } catch { /* */ } } +} + +/** What a node surfaced, in order: the focus of each record ('cmb-accepted'), or a message's text. */ +function surfaced(node) { + const seen = []; + node.on('cmb-accepted', (e) => { const f = e && e.cmb && e.cmb.categories && e.cmb.categories.focus; const t = f && (f.text || f); if (typeof t === 'string') seen.push(t); }); + node.on('message', (_from, t) => seen.push(t)); + return seen; +} +/** Every metric a node emits, by type. */ +function metrics(node) { + const by = {}; + node.on('metric', (m) => { (by[m.type] || (by[m.type] = [])).push(m); }); + by.count = (t) => (by[t] || []).length; + return by; +} +const distinct = (seen, re) => new Set(seen.filter((t) => re.test(t))); +const dups = (seen) => seen.length - new Set(seen).size; +const pending = (n) => (typeof n.pendingDeliveries === 'function' ? n.pendingDeliveries().length : 0); + +/** + * The sender's counts are true: everything it took is accounted for — written at once, or held and + * written later — nothing left pending, nothing given up, and every record it held it later wrote. + */ +function assertSenderTrue(s, m, total, { dispatched, queued }) { + assert.strictEqual(dispatched + queued, total, `the sender took every record (${dispatched} written at once, ${queued} held for the budget)`); + assert.strictEqual(pending(s), 0, 'nothing is left pending'); + assert.strictEqual(m.count('cmb-undelivered'), 0, 'nothing was given up'); + const held = new Set((m['cmb-requeued'] || []).map((x) => x.key)); + const written = new Set((m['cmb-redelivered'] || []).map((x) => x.key)); + assert.deepStrictEqual([...written].sort(), [...held].sort(), 'every record it held, it then wrote'); + assert.strictEqual(typeof s.undelivered, 'function', 'the sender lists what it gives up (undelivered())'); + assert.deepStrictEqual(s.undelivered(), []); +} + +/** Send `n` directed records (remember) of `kb` KiB each; count what the sender said of each. */ +function burst(s, to, n, kb, label = 'rec') { + let dispatched = 0; + let queued = 0; + for (let i = 0; i < n; i++) { + const e = s.remember(CATS(`${label} ${i}`, kb ? text(kb, `${label}${i}`) : 'flow control'), { to }); + if (e.delivery.dispatched) dispatched++; + else if (e.delivery.queued) queued++; + } + return { dispatched, queued }; +} + +// ── 0.14.2 as the other end ─────────────────────────────────────────────────────────────────── +/** + * Make `node` receive as 0.14.2 does: a record past its count budget (8 a second, burst 32; 0.14.2 + * had no size budget) is dropped unevaluated, and no flow-control frame is sent or understood. On + * 9f6847c the stock node drops past its budget already (with the size budget too), so nothing is done. + */ +function asLegacyReceiver(node) { + const fh = node._frameHandler; + if (!fh._admission) return; + fh.flowBudget = () => ({ type: 'x-not-a-budget' }); // advertises nothing (a frame a receiver ignores, §7.3) + // 0.14.2's lanes by count only: 32 a second (burst 128) before verification, 8 (burst 32) before SVAF. + const holds = (session, slot, rate, burst) => { + const b = session[slot]; + return !b || Math.min(burst, b.tokens + ((Date.now() - b.at) * rate) / 1000) >= 1; + }; + fh._admission.offer = (session, peerId, peerName, msg, chars) => { + if (!holds(session, '_verifyBucket', 32, 128) || !holds(session, '_recordBucket', 8, 32)) { node.emit('metric', { type: 'cmb-over-budget', from: peerName }); return undefined; } + return fh._admission._o.run({ session, peerId, peerName, msg, chars }); + }; +} +/** Make `node` send as 0.14.2 does: every record written at once, whatever the receiver says. */ +function asLegacySender(node) { + if (typeof node._flowSession === 'function') node._flowSession = () => false; +} + +describe('flow control: honest bursts are delivered, not dropped', () => { + it('49 directed messages sent in one burst over the LAN: all 49 surface, once each and in order, and the sender\'s counts are true', async () => { + const { s, r } = lanPair(); + const seen = surfaced(r); + const m = metrics(s); + const rm = metrics(r); + try { + await s.start(); await r.start(); + assert.ok(await until(paired(s, r), 20000), 'paired over the LAN'); + await sleep(300); + let taken = 0; + for (let i = 0; i < 49; i++) taken += s.send(`message number ${i}`, { to: r.nodeId }); + assert.strictEqual(taken, 49, 'the sender took all 49'); + assert.ok(await until(() => distinct(seen, /^message number/).size === 49 && pending(s) === 0, 20000), `all 49 surfaced (${distinct(seen, /^message number/).size})`); + await sleep(300); + assert.strictEqual(dups(seen), 0, 'each once'); + assert.deepStrictEqual(seen.filter((t) => /^message number/.test(t)), Array.from({ length: 49 }, (_, i) => `message number ${i}`), 'in the order sent'); + assert.strictEqual(rm.count('cmb-over-budget') + rm.count('cmb-queue-refused'), 0, 'the receiver dropped and refused nothing'); + assert.strictEqual(pending(s), 0); + assert.strictEqual(m.count('cmb-undelivered'), 0); + } finally { await stopAll(s, r); } + }); + + it('12 directed records of 200 KB over the LAN: all 12 surface once, and the sender says how many it held for the size budget', async () => { + const { s, r } = lanPair(); + const seen = surfaced(r); + const m = metrics(s); + try { + await s.start(); await r.start(); + assert.ok(await until(paired(s, r), 20000)); + await sleep(300); + const counts = burst(s, r.nodeId, 12, 200, 'big'); + assert.ok(counts.queued > 0, `past the 1.5 MiB burst the sender held records for the budget (${counts.queued})`); + assert.ok(await until(() => distinct(seen, /^big /).size === 12 && pending(s) === 0, 40000), `all 12 surfaced (${distinct(seen, /^big /).size})`); + await sleep(300); + assert.strictEqual(dups(seen), 0); + assertSenderTrue(s, m, 12, counts); + } finally { await stopAll(s, r); } + }); + + it('40 directed records of 50 KB over the LAN: all 40 surface once', async () => { + const { s, r } = lanPair(); + const seen = surfaced(r); + const m = metrics(s); + try { + await s.start(); await r.start(); + assert.ok(await until(paired(s, r), 20000)); + await sleep(300); + const counts = burst(s, r.nodeId, 40, 50, 'mid'); + assert.ok(await until(() => distinct(seen, /^mid /).size === 40 && pending(s) === 0, 40000), `all 40 surfaced (${distinct(seen, /^mid /).size})`); + await sleep(300); + assert.strictEqual(dups(seen), 0); + assertSenderTrue(s, m, 40, counts); + } finally { await stopAll(s, r); } + }); + + it('49 directed messages 15 ms apart over a relay (the review\'s r-msgloss): all 49 surface once, in order', async () => { + const relay = fakeRelay(); + const { s, r } = relayPair(relay); + const seen = surfaced(r); + const m = metrics(s); + try { + await s.start(); await r.start(); + assert.ok(await until(paired(s, r), 20000), 'paired over the relay'); + await sleep(400); + for (let i = 0; i < 49; i++) { s.send(`message number ${i}`, { to: r.nodeId }); await sleep(15); } + assert.ok(await until(() => distinct(seen, /^message number/).size === 49 && pending(s) === 0, 20000), `all 49 surfaced (${distinct(seen, /^message number/).size})`); + await sleep(300); + assert.strictEqual(dups(seen), 0); + assert.deepStrictEqual(seen.filter((t) => /^message number/.test(t)), Array.from({ length: 49 }, (_, i) => `message number ${i}`), 'in the order sent'); + assert.strictEqual(m.count('cmb-undelivered'), 0); + } finally { await stopAll(s, r); await relay.close(); } + }); +}); + +describe('flow control: records held across a drop are re-offered within the receiver\'s budget', () => { + it('120 directed records across a relay drop (both links cut, the pacer back to 20/s burst 200): all 120 surface once; the sender\'s counts are true', async () => { + let relay = null; + let cut = false; + let rRef = null; + // Both links are cut from inside the receiver's own delivery of the 5th record: nothing of the + // sender's is then in flight in the relay (its pacer writes one frame every 250 ms), so what this + // test measures is the held list and the budget, not the residual. + relay = fakeRelay(); + const { s, r } = relayPair(relay, { sRate: { perSecond: 4, burst: 1 } }); + rRef = r; + const seen = surfaced(r); + r.on('cmb-accepted', () => { + if (!cut && distinct(seen, /^held /).size >= 5) { cut = true; relay.kick(s.nodeId); relay.kick(rRef.nodeId); } + }); + const m = metrics(s); + const rm = metrics(r); + try { + await s.start(); await r.start(); + assert.ok(await until(paired(s, r), 20000)); + await sleep(400); + const counts = burst(s, r.nodeId, 120, 0, 'held'); + assert.ok(await until(() => cut, 15000), 'the links were cut mid-stream'); + // The review's FASTPACER: the re-offer goes out of a pacer that would write 200 frames at once. + s._relay._rate = 20; s._relay._burst = 200; s._relay._bucket = { tokens: 200, at: Date.now() }; + assert.ok(await until(() => distinct(seen, /^held /).size === 120 && pending(s) === 0, 60000), `all 120 surfaced (${distinct(seen, /^held /).size}; pending ${pending(s)})`); + await sleep(500); + assert.strictEqual(dups(seen), 0, 'each once'); + assert.strictEqual(rm.count('cmb-over-budget') + rm.count('cmb-queue-refused'), 0, 'the receiver dropped and refused nothing'); + assertSenderTrue(s, m, 120, counts); + } finally { await stopAll(s, r); await relay.close(); } + }); + + it('120 directed records across a LAN drop: the records not yet written wait, and all 120 surface once on the next session', async () => { + const { s, r } = lanPair(); + const seen = surfaced(r); + let cut = false; + r.on('cmb-accepted', () => { + if (cut || distinct(seen, /^lan /).size < 60) return; + cut = true; + // The receiver's socket closes under the sender, between two of its paced writes. + const sess = r._peers.get(s.nodeId) && r._peers.get(s.nodeId).transports.get('bonjour'); + if (sess && sess.transport) sess.transport.close(); + setTimeout(() => { try { s._discovery._scanLoopback(); r._discovery._scanLoopback(); } catch { /* */ } }, 300); + }); + const m = metrics(s); + try { + await s.start(); await r.start(); + assert.ok(await until(paired(s, r), 20000)); + await sleep(300); + const counts = burst(s, r.nodeId, 120, 0, 'lan'); + assert.ok(await until(() => cut, 20000), 'the LAN connection was cut mid-stream'); + assert.ok(await until(() => distinct(seen, /^lan /).size === 120 && pending(s) === 0, 60000), `all 120 surfaced (${distinct(seen, /^lan /).size}; pending ${pending(s)})`); + await sleep(300); + assert.strictEqual(dups(seen), 0, 'each once'); + assertSenderTrue(s, m, 120, counts); + } finally { await stopAll(s, r); } + }); +}); + +describe('flow control with a 0.14.2 node at the other end', () => { + it('new sender → 0.14.2 receiver (drops past 8/s burst 32, advertises nothing): 49 messages and 12 × 200 KB all surface, none dropped', async () => { + const { s, r } = lanPair(); + asLegacyReceiver(r); + const seen = surfaced(r); + const rm = metrics(r); + const m = metrics(s); + try { + await s.start(); await r.start(); + assert.ok(await until(paired(s, r), 20000)); + await sleep(300); + for (let i = 0; i < 49; i++) s.send(`message number ${i}`, { to: r.nodeId }); + const counts = burst(s, r.nodeId, 12, 200, 'old-big'); + assert.ok(await until(() => distinct(seen, /^message number/).size === 49 && distinct(seen, /^old-big /).size === 12 && pending(s) === 0, 40000), + `all delivered (${distinct(seen, /^message number/).size} of 49 messages, ${distinct(seen, /^old-big /).size} of 12 records)`); + await sleep(300); + assert.strictEqual(rm.count('cmb-over-budget'), 0, 'the old receiver dropped nothing: the sender kept to its budget, with a margin'); + assert.strictEqual(dups(seen), 0); + assert.strictEqual(m.count('cmb-undelivered'), 0); + assert.strictEqual(counts.dispatched + counts.queued, 12); + } finally { await stopAll(s, r); } + }); + + it('0.14.2 sender (writes everything at once, hears nothing) → new receiver: 49 messages and 12 × 200 KB all surface, queued and not dropped', async () => { + const { s, r } = lanPair(); + asLegacySender(s); + const seen = surfaced(r); + const rm = metrics(r); + try { + await s.start(); await r.start(); + assert.ok(await until(paired(s, r), 20000)); + await sleep(300); + for (let i = 0; i < 49; i++) s.send(`message number ${i}`, { to: r.nodeId }); + burst(s, r.nodeId, 12, 200, 'from-old'); + assert.ok(await until(() => distinct(seen, /^message number/).size === 49 && distinct(seen, /^from-old /).size === 12, 40000), + `all delivered (${distinct(seen, /^message number/).size} of 49 messages, ${distinct(seen, /^from-old /).size} of 12 records)`); + await sleep(300); + assert.strictEqual(dups(seen), 0); + assert.ok(rm.count('cmb-queued') > 0, 'what was past the budget waited in the queue'); + assert.strictEqual(rm.count('cmb-queue-refused'), 0, 'and nothing was refused'); + assert.deepStrictEqual(seen.filter((t) => /^message number/.test(t)), Array.from({ length: 49 }, (_, i) => `message number ${i}`), 'in the order sent'); + } finally { await stopAll(s, r); } + }); +}); diff --git a/tests/relay-redelivery.test.js b/tests/relay-redelivery.test.js index b9135539..d6648b57 100644 --- a/tests/relay-redelivery.test.js +++ b/tests/relay-redelivery.test.js @@ -12,8 +12,8 @@ require('./_isolate-home'); // redirect $HOME before lib/config loads * connection stays up — is held for that peer's key and offered again, sealed afresh, to the next * session proving that key; until a socket has written it, it is listed in pendingDeliveries(). * - * These tests stay under the receiver's own record budget (8 a second, burst 32): past it the - * receiver drops records unevaluated, which is a separate loss (reported, not changed here). + * These tests stay under the receiver's own record budget (8 a second, burst 32). Past it the + * receiver queues records and the sender paces to it (flow control, 0.14.3): tests/flow-control.test.js. */ const { describe, it } = require('node:test'); @@ -176,7 +176,7 @@ describe('records the relay pacer never wrote are held and offered again (R3-4)' } finally { n._running = false; n._dropRedelivery('test'); await n.stop(); fs.rmSync(nodeDirById(n.nodeId), { recursive: true, force: true }); } }); - it('the held list is bounded: past the bound the oldest is dropped and said undelivered', () => { + it('the held list is bounded: past the bound a record is not held and is said undelivered; nothing held is pushed out', () => { const n = new SymNode({ name: uniq('rd-bound'), silent: true, discovery: new NullDiscovery() }); const said = []; n.on('metric', (m) => { if (m.type === 'cmb-undelivered') said.push(m); }); @@ -189,8 +189,9 @@ describe('records the relay pacer never wrote are held and offered again (R3-4)' n._running = false; const held = n.pendingDeliveries(); assert.strictEqual(held.length, 2048, 'at most 2048 a peer'); - assert.strictEqual(held[0].key, 'cmb-2', 'the oldest went first'); - assert.deepStrictEqual(said.map((m) => [m.key, m.reason]), [['cmb-0', 'redelivery-overflow'], ['cmb-1', 'redelivery-overflow']]); + assert.strictEqual(held[0].key, 'cmb-0', 'what was held stays held (flow control, 0.14.3: a held record is never pushed out)'); + assert.deepStrictEqual(said.map((m) => [m.key, m.reason]), [['cmb-2048', 'held-full'], ['cmb-2049', 'held-full']]); + assert.deepStrictEqual(n.undelivered().map((u) => u.key), ['cmb-2048', 'cmb-2049'], 'and listed as undelivered'); } finally { n.stop(); fs.rmSync(nodeDirById(n.nodeId), { recursive: true, force: true }); } }); }); diff --git a/tests/security-0.14.3.test.js b/tests/security-0.14.3.test.js index b002015a..2cbff37b 100644 --- a/tests/security-0.14.3.test.js +++ b/tests/security-0.14.3.test.js @@ -187,25 +187,36 @@ describe('R2-3: one admitted peer cannot buy CPU, memory or disk without bound', it('R2-3: the record and verification budgets are charged by size: two of the largest records pass, a third waits', () => { const fh = new FrameHandler({ _log: () => {} }, {}); + const now = Date.now(); + // A record is admitted only when both lanes hold it (flow control, 0.14.3: otherwise it waits). + const admit = (session, chars) => { + if (fh._admitWait(session, chars, now) > 0) return false; + fh._spendVerify(session, chars, now); + fh._spendRecord(session, chars, now); + return true; + }; const session = {}; const largest = 720 * 1024; - const r = [0, 1, 2].map(() => fh._recordBudget(session, largest)); + const r = [0, 1, 2].map(() => admit(session, largest)); assert.deepStrictEqual(r, [true, true, false], 'the record lane spends the size'); const small = {}; - for (let i = 0; i < 32; i++) assert.strictEqual(fh._recordBudget(small, 2048), true, 'small records are counted by number as before'); + for (let i = 0; i < 32; i++) assert.strictEqual(admit(small, 2048), true, 'small records are counted by number as before'); + assert.strictEqual(admit(small, 2048), false, 'and the 33rd waits'); + // The verification lane (4 MiB burst) spends the size too, whatever the record lane holds. const v = {}; - let passed = 0; - for (let i = 0; i < 12; i++) if (fh._verifyBudget(v, 400 * 1024)) passed++; - assert.ok(passed >= 8 && passed <= 11, `the verification lane spends the size too (${passed} of 12 passed)`); + for (let i = 0; i < 9; i++) fh._spendVerify(v, 400 * 1024, now); + assert.strictEqual(fh._admitWait(v, 1024, now), 0, '3.6 MiB checked: the lane still holds a small record'); + for (let i = 0; i < 2; i++) fh._spendVerify(v, 400 * 1024, now); + assert.ok(fh._admitWait(v, 1024, now) > 0, '4.4 MiB checked: past the burst, even a small record waits for the lane to refill'); }); - it('R2-3: a burst of large records from one peer: only what its size budget holds reaches SVAF', async () => { + it('R2-3: a burst of large records from one peer: only what its size budget holds reaches SVAF; the rest waits', async () => { try { const node = mk('r23-flood'); if (typeof node._store.load === 'function') await node._store.load(); const mallory = identity('mallory'); const s = admitAs(node, mallory); - const over = []; node.on('metric', (m) => { if (m.type === 'cmb-over-budget' || m.type === 'cmb-over-verify-budget') over.push(m.type); }); + const over = []; node.on('metric', (m) => { if (m.type === 'cmb-queued') over.push(m.type); }); let evaluated = 0; const admit = node._frameHandler._admit; node._frameHandler._admit = (...a) => { evaluated++; return admit(...a); }; @@ -215,7 +226,7 @@ describe('R2-3: one admitted peer cannot buy CPU, memory or disk without bound', } await settle(300); assert.ok(evaluated <= 4, `at most what 1.5 MiB holds was evaluated (${evaluated})`); - assert.ok(over.length >= 8, 'the rest was dropped and counted'); + assert.ok(over.length >= 8, 'the rest waits in the session\'s queue (flow control, 0.14.3: it was dropped), counted'); } finally { await stopAll(); } }); From 3259a4414e92f33dc147c346adee720043e364d8 Mon Sep 17 00:00:00 2001 From: "SYM.BOT" Date: Wed, 14 Oct 2026 19:35:03 +0100 Subject: [PATCH 3/7] CHANGELOG and SECURITY: flow control (the queue, the two frames, pacing, the cut, old peers), and the budget no longer drops The 0.14.3 header no longer says the wire is unchanged: two sealed control frames, which 0.14.2 ignores. "Known, not fixed here" loses the dropping receiver and gains what flow control does not keep (order across a refusal). The R3-4 held list refuses past its bound instead of pushing out the oldest. SECURITY.md's record bounds name the queue, the refusal notice and the cut. --- CHANGELOG.md | 125 +++++++++++++++++++++++++++++++++++++++++++++++---- SECURITY.md | 8 +++- 2 files changed, 124 insertions(+), 9 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 68c5b475..cfcd85e9 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,8 +5,10 @@ **An agent no longer loses its key to the 0.13 → by-id upgrade.** An XMesh review of `lib/config.js` 0.14.2 returned "do not ship" with 13 findings. Each was checked by running it in a sandbox state dir; 0.14.3 fixes the ones that lose or expose a key and the small ones beside them, by reading the state of an identity only from records committed in one -atomic step (see "Identity and on-disk state"). The wire is unchanged; the public surface gains `relocation.abortExport` -and `IdentityExportPendingError`. +atomic step (see "Identity and on-disk state"). The wire gains two sealed control frames for flow control, `cmb-budget` +and `cmb-refused`, which a 0.14.2 node ignores (see "Transport and node lifecycle", Flow control); the public surface +gains `relocation.abortExport`, `IdentityExportPendingError`, `node.undelivered()`, `node.flowStatus()`, the +`undelivered` event and `delivery.queued`. ### What was wrong @@ -176,7 +178,9 @@ An independent security review (R2) of the 0.14 core reproduced each finding bel (2,048 entries, 32 M characters); the inbox holds at most 32 M characters (read items make room, oldest first; an unread one never goes, and a delivery that does not fit is refused and counted, `inbox-full-refused`). The review's 24 records of 2 × 200 KB: 15 s CPU before, 0.4 s now. The store itself is still unbounded on disk by default - (retention is unlimited unless configured); the size budget bounds how fast one session can grow it. + (retention is unlimited unless configured); the size budget bounds how fast one session can grow it. Past either + budget a record now waits in the session's queue instead of being dropped (Flow control, under "Transport and node + lifecycle"). - Gossip signature checks are bounded whatever the number of sessions: every new attestation, checkpoint, witness or authority statement takes one global token before verification, through the sending peer's fair share. The ceiling after verification is gone (R2-4). @@ -331,7 +335,8 @@ is unchanged except where a line says so. delivered: `node.pendingDeliveries()` lists it, `status().pendingDeliveries` counts it, and metrics say each step (`cmb-requeued`, `cmb-redelivered`, and `cmb-undelivered` with reason `redelivery-overflow` or `node-stopped` when it is dropped). The list is bounded: 2048 records or - 8 MiB a peer, 10,000 in all, the oldest dropped first. A receiver surfaces a record once for the life + 8 Mi characters a peer, 10,000 in all; a record past it is not held (said undelivered, `held-full`) and nothing held + is pushed out for it (Flow control, below). A receiver surfaces a record once for the life of its store (the delivery ledger), so a record offered twice is not delivered twice. **The residual:** a frame a socket has written and the network, the relay or the relay's way to the peer then loses is still lost and still reads as dispatched; only an end-to-end receipt closes that, which is @@ -375,6 +380,80 @@ is unchanged except where a line says so. - `discovery.stop()` closes the connections it accepted and has not handed on, and its bounded wait no longer holds the process open. +#### Flow control (directed and room records) + +**What was wrong.** A receiver bounds what one session's records cost it: a record budget per session by +count (8 a second after a burst of 32, security review D) and, new in this release, by size (128 KiB of +record text a second after 1.5 MiB, R2-3), behind a pre-verification lane (32 a second, burst 128; 1 MiB/s, +burst 4 MiB). A record past either was DROPPED, unchecked or unevaluated, while its sender reported it +dispatched, and nothing offered it again. Measured on the first 0.14.3 candidate (9f6847c), real nodes on one +host: 49 directed messages sent in a burst, 32 delivered over the LAN and 38 over a relay (15 ms apart, the +review's r-msgloss; 0.14.2 the same); 12 records of 200 KB, 7 (0.14.2 delivered 12: it had no size budget); +40 of 50 KB, 30; 120 records held across a relay drop and re-offered by the new held-record path (the pacer +back at 20/s burst 200; over the LAN every held record was written at once), 38, the sender reporting 115 +redelivered and nothing pending. + +**The design.** The budget exists to bound CPU and memory; it must not lose honest traffic (`lib/flow-control.js`). + +- **The receiver queues, it does not drop.** Every record a session brings is admitted (verified, + evaluated, surfaced) only once both lanes hold it and nothing of that session waits ahead of it; + otherwise it waits in the session's queue, in order, and is admitted as the lanes refill. What the + budget bounds is exactly as before. The queue holds at most 64 s of the budget per session (512 + records, 8 Mi characters) and 4,096 records or 32 Mi characters in all. A record that arrived on a + session that has since closed is still admitted; one whose peer is no longer admitted (the door, a + penalty) is dropped and counted (`cmb-queue-dropped`). Counted: `cmb-queued`, and + `status().flowControl.receiver` (queued now, peaks, admitted late, refused, notices, cut). +- **Past the queue a record is refused and its sender told.** A sealed control frame + `{ type: 'cmb-refused', assertionIds: [≤ 256], retryAfterMs }` names the refused records (by the + assertionId the record carries) and when to try again: the time the session's queue needs to drain + at its budget, or, when every session's queue together was full, the longest one's; 1 s to 64 s. At + most one notice a second per peer; refusals past what four notices carry are counted, not listed; a + notice owed to a peer with no open session waits a minute for its next one. Counted: + `cmb-queue-refused`, `cmb-refusal-sent`, `cmb-refusal-unsent`. A node stopping refuses what waits + in its queue and tells each sender, so the records are offered again to its next session. +- **A peer that keeps on is cut.** One that, told, sends more than 512 records past its OWN queue + before that queue has drained (it sent more than 64 s of its budget ahead of it, and kept on) is + closed and not admitted again for 60 s, as a forgery is (`record-flood-cut`). A sender refused + because every session's queue together was full is not at fault and never counts toward it, and a + peer whose queue drains starts over. A paced sender never fills its own queue. +- **The receiver advertises its budget.** Once a session is admitted each side sends + `{ type: 'cmb-budget', recordsPerSecond, recordsBurst, charsPerSecond, charsBurst, queueRecords, + queueChars }` (8, 32, 131072, 1572864, 512, 8388608), sealed, first in the greeting. A frame with a + member outside these, or a value that is not a finite number in range, is refused and counted + (`malformed`), as a malformed `cmb-refused` is. +- **The sender paces every record to it.** Directed and room records, messages, a sleeping peer's + queued records, and the held records re-offered after a relay or LAN drop all go through the peer's + held list, oldest first, and are written to its session only within the budget that peer advertised + for it (each end starts a session with full buckets; anchors spend it too; an advertisement that + arrives late starts from the burst less what was already sent). A peer that advertises nothing + (0.14.2 and older) is paced to the 0.14.2 budget with a quarter kept as margin, 6 a second after 24, + and no size budget: 0.14.2 drops past 8/32, and a sender pacing exactly to it loses a record whenever + two arrive closer together than they were written. A record counts as dispatched only when it is + written: `delivery.dispatched` counts those, `delivery.queued` the copies held for the budget (a + directed send held is not undelivered), `pendingDeliveries()` lists every held record with its state + (`waiting`, `refused`, `written` to a relay pacer). A refused record goes back on the held list in + its place, nothing more goes to that session until the retry-after, and it is offered again (to that + peer only: a room record other peers took is not sent to them again); after 8 retries refused, or + once it is 23 h old by its signed timestamp (a receiver refuses a directed record older than 24 h), + it is given up: `cmb-undelivered`, the `undelivered` event, and `node.undelivered()` (the last 256). + A record past the held list's bound is refused at once (its send says `held-full`). +- **Old peers both ways.** A 0.14.2 node ignores both frames (§7.3: an unknown type is ignored); run + against a `git archive` of 0.14.2 (fe285a3) it logs and counts nothing for them. A 0.14.3 sender to a + 0.14.2 receiver: 49 messages, 12 × 200 KB, 40 × 50 KB and 120 records across a relay drop all + delivered, the receiver dropping none. A 0.14.2 sender (it paces nothing and hears nothing) to a + 0.14.3 receiver: 49 messages, 12 × 200 KB and 40 × 50 KB all delivered from the queue; past the queue + its records are refused (it never offers them again) and past the cut it is closed, so a new receiver + still bounds an old sender. + +**Measured now** (the same runs, 0.14.3): 49 messages over the LAN and over the relay, 49; 12 × 200 KB, +12; 40 × 50 KB, 40; 120 across a relay drop (the reviewer's script against sym-relay `origin/main` on +127.0.0.1, the relay process killed and restarted), 120, the sender's counts true (nothing pending, +nothing undelivered, every record it held then written), the receiver queueing at most one record at a +time (timer jitter, admitted within milliseconds); 120 across a LAN drop, 120. Each exactly once. A flood +of 2,300 records from a peer that ignores everything: at most 32 + 8/s evaluated, at most 512 waiting, +the rest refused and the peer told (each notice ≤ 256 ids, retry-after 64 s), then cut. 40 records of +400 K: at most 8 Mi characters waiting. + #### Known, not fixed here - **R3-8, one identity in several rooms in one process** (what XMesh's observer does): the inbox is @@ -382,10 +461,14 @@ is unchanged except where a line says so. design call; unchanged. Related: in a hot-swap the first node's stop() releases the identity lock file the second still relies on (an in-process re-acquisition gets a release that does nothing). - **End-to-end delivery receipts** (protocol work), and so the residual above. -- **A receiver drops records past its own record budget** (8 a second, burst 32, per session: security - review D) unevaluated while the sender reports them dispatched. Of R3's 260 directed records sent at - once, 55 were accepted in one run with no relay drop at all; R3's "227 lost after a drop" counts - these too. The tests here stay under the budget. +- (Was listed here in the first 0.14.3 candidate: a receiver dropped records past its own record budget, + unevaluated, while the sender reported them dispatched. Fixed, see Flow control above.) +- **Order across a refusal is not kept.** A receiver refuses a record only past its queue; a record the + sender wrote before the refusal notice reached it can be taken once the queue frees a slot, ahead of + the refused one, which the sender offers again later in its place. Within the budget (what a paced + sender never leaves) a session's records are admitted in the order they arrived. MMP promises no + application-level order; keeping it across refusals would mean refusing records inside the bound, + which costs a 0.14.2 sender (it never offers a refused record again) records it would otherwise keep. - **mesh-channel exits on `identity-collision`** (server.js), so one spoofed 4004 still stops a channel host until it exits on `info.pingPong` only. - A token holder that keeps claiming a nodeId keeps that member off the relay most of the time; only a @@ -403,6 +486,32 @@ is unchanged except where a line says so. and padded-roster attacks no longer close the victim's connection on 0.5.2 (the current relay already bounds both), and a member evicted by a spoofed 4004 is back on either relay after its retry. - `tests/relay-state.test.js`: the 4004 and 4006 cases now pin the long-backoff retry. +- **Flow control:** `tests/flow-control.test.js` (8, real nodes: the LAN over TCP on the loopback, the relay over a + WebSocket relay): the bursts, both drops and both old-peer directions above, each delivered exactly once with the + sender's counts true; all 8 fail on 9f6847c (a `git archive` of it): 32 of 49 messages over the LAN, 31 of 40 × + 50 KB, 38 of 49 over the relay, 38 of 120 across the relay drop, 32 of 120 across the LAN drop, and with the old + peer at either end 32 of 49 messages and at most 1 of 12 × 200 KB. + `tests/flow-control-bounds.test.js` (27): the queue's bounds per session and in all, by count and by size; the door + and the penalties for what waits; arrival order; the cut and its episodes; the pre-verification lane for copies of + a delivered record; the notice's rate; a stopping receiver; the advertisement and malformed frames; the legacy + pacing and its margin; a late advertisement; anchors; refusals (held again in place, the back-off, on a new + session, given up after 8, a room record retried to one peer only, a refusal of nothing held, one refused while in + the relay pacer); the age bound; the held list's bounds; the buckets' clock. 26 of the 27 fail on 9f6847c (most + because what they check is new); the one that passes pins what must not change, a write the session refuses + outright reported at once as before. The R2-3 and record-flood + tests (`security-0.14.3`, `core-secure-review`) and the held-list bound (`relay-redelivery`) now pin waiting, and a + held record never pushed out, instead of dropping. **Mutation check:** 52 mutants of `lib/flow-control.js`, + `lib/frame-handler.js` and `lib/node.js`, one per guard the design adds (the queue's FIFO and budget gate, its four + bounds, the door and the two penalties at the drain, the drain's wait, the cut's threshold, episode, reset and + told-in-episode, the notice's schedule, rate, id cap and pending cap, the retry-after's clamp and others-full, the + stop notice, the clock, the legacy margin, the advertisement's lower bound, the back-off and size pacing, six frame + checks, the two lane spends and the gate, advertising and applying the budget, pacing, not-before, the refusal + limit, both age checks, the held list's two bounds, the sent window's age and per-peer key, placement in order, the + refused-in-pacer case, the back-off call, a fresh write failure, the anchor spend): every one is caught. Five + survived a first run: four were caught once the tests measured the right thing (the drain's wait and the record + lane's spend, which the flood's cut had masked; the notice timer's spin; the sent window's per-peer key, which only + shows when the refusing peer is not the last one written); the fifth was a guard no input could reach (an own-queue + reason beside the episode, which already implies it) and was removed, its mutant replaced by one on the episode. ## 0.14.2 — 2026-10-14 diff --git a/SECURITY.md b/SECURITY.md index c7e716bf..d22eb0c0 100644 --- a/SECURITY.md +++ b/SECURITY.md @@ -240,7 +240,13 @@ Every store a peer can feed has a fixed bound. Reaching one never stops the node one sealed frame. This node mints nothing larger, and refuses a received record over any limit before anything validates, verifies or encodes it; a sealed frame longer than a 720 KiB record can produce (983,062 base64url characters) is refused before it is opened. At most 8 new records a - second per session are evaluated (burst 32). + second per session are evaluated (burst 32; and 128 KiB of record text a second, burst 1.5 MiB), + and at most 32 a second checked before verification (burst 128; 1 MiB/s, burst 4 MiB). Past either + a record waits in the session's queue, in order (0.14.3): at most 512 records or 8 Mi characters a + session, 4,096 records or 32 Mi characters in all. Past the queue it is refused unchecked and its + sender told (`cmb-refused`, at most one notice a second per peer, at most 256 records named in one); + a peer that, told, keeps sending more than 512 records past its own queue before that queue drains + is closed and not admitted again for 60 s. - **Wake channels**: at most 1,024, learned only from a confirmed session's own nodeId (a peer's word about another node is never stored), dropped after 30 days unseen; when the table is full a new first-hand channel displaces the least recently seen one of the weakest source, so many From 0b8991738dcd36d2ea49bd087ad11a5af2e15508 Mon Sep 17 00:00:00 2001 From: "SYM.BOT" Date: Wed, 14 Oct 2026 19:41:41 +0100 Subject: [PATCH 4/7] Tests: Finding 3's lane tests pin waiting (or refusal) before any work; the stop test waits until the receiver holds every record CI (Linux) caught both. The two final-review tests counted cmb-over-verify-budget, which flow control retires: past the pre-verification lane a record now waits in the session's queue (or, past it, is refused unchecked), and 3b also pins that only the lane's burst is checked at once. On a slower host part of the stop test's burst was still unread in the receiver's socket when it stopped: that is the transport residual (CHANGELOG now names it), not the queue, so the test now stops the receiver once every record has reached it. --- CHANGELOG.md | 3 ++- tests/core-secure-final-review.test.js | 13 +++++++++---- tests/flow-control-bounds.test.js | 5 ++++- 3 files changed, 15 insertions(+), 6 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index cfcd85e9..6b1c48ff 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -339,7 +339,8 @@ is unchanged except where a line says so. is pushed out for it (Flow control, below). A receiver surfaces a record once for the life of its store (the delivery ledger), so a record offered twice is not delivered twice. **The residual:** a frame a socket has written and the network, the relay or the relay's way to the peer then loses - is still lost and still reads as dispatched; only an end-to-end receipt closes that, which is + (or that is still unread in the receiver's socket when the receiver closes it) is still lost and + still reads as dispatched; only an end-to-end receipt closes that, which is protocol work. The held list is process memory: a stop drops it (said as undelivered); the record stays in the sender's store. - **The relay connection's ceiling is 8 MiB; the frame bound is per message (R3-1, R3-2).** A message diff --git a/tests/core-secure-final-review.test.js b/tests/core-secure-final-review.test.js index a75f2eb9..2cc68b3a 100644 --- a/tests/core-secure-final-review.test.js +++ b/tests/core-secure-final-review.test.js @@ -108,7 +108,7 @@ describe('C: the interior read side is scoped to the mind\'s mission (Finding 6) }); describe('3: relayed forgeries cost bounded work, and nobody is blamed (Finding 3)', () => { - it('Q1: 400 forged 200 KiB records relayed in another\'s name are mostly dropped before any work, with bounded logs and decisions', async () => { + it('Q1: 400 forged 200 KiB records relayed in another\'s name: most wait or are refused before any work, with bounded logs and decisions', async () => { const b = mk('q1', {}); try { await b.start(); @@ -126,7 +126,9 @@ describe('3: relayed forgeries cost bounded work, and nobody is blamed (Finding } assert.strictEqual(sM.closed, false, 'the relayer is not blamed'); assert.ok((metrics['relayed-signature-unverified'] || 0) <= 8, `verified and failed at most 8: ${metrics['relayed-signature-unverified']}`); - assert.ok((metrics['relayed-signer-muted'] || 0) + (metrics['cmb-over-verify-budget'] || 0) >= 380, 'the rest dropped before any work'); + // Past the pre-verification lane a record waits in the session's queue (flow control, 0.14.3: it + // was dropped), and past the queue it is refused unchecked: either way no work is done on it now. + assert.ok((metrics['relayed-signer-muted'] || 0) + (metrics['cmb-queued'] || 0) + (metrics['cmb-queue-refused'] || 0) >= 380, 'the rest waits or is refused before any work'); assert.ok(logs.length <= 10, `log lines: ${logs.length}`); assert.ok(b._decisionLog.count() - before <= 2, 'decision-log entries bounded'); } finally { await stopAll(b); } @@ -134,7 +136,7 @@ describe('3: relayed forgeries cost bounded work, and nobody is blamed (Finding }); describe('3b: the verification lane bounds work on records naming many signers', () => { - it('400 records naming 400 unknown authors: most are dropped before any schema, hash or signature work', async () => { + it('400 records naming 400 unknown authors: most wait (or are refused) before any schema, hash or signature work', async () => { const b = mk('lane', {}); try { await b.start(); @@ -148,7 +150,10 @@ describe('3b: the verification lane bounds work on records naming many signers', rec.metadata.createdByNodeId = crypto.randomUUID(); deliver(b, sM, { type: 'cmb', cmb: rec }); } - assert.ok((metrics['cmb-over-verify-budget'] || 0) >= 200, `dropped before any work: ${metrics['cmb-over-verify-budget']}`); + // They wait in the session's queue and are checked at the lane's rate (flow control, 0.14.3: they were dropped). + const waiting = (metrics['cmb-queued'] || 0) + (metrics['cmb-queue-refused'] || 0); + assert.ok(waiting >= 200, `waiting or refused before any work: ${waiting}`); + assert.ok((metrics['cmb-author-unresolvable'] || 0) <= 128 + 8, `and only the lane's burst was checked now (${metrics['cmb-author-unresolvable']})`); } finally { await stopAll(b); } }); }); diff --git a/tests/flow-control-bounds.test.js b/tests/flow-control-bounds.test.js index e3526d0f..227e51dd 100644 --- a/tests/flow-control-bounds.test.js +++ b/tests/flow-control-bounds.test.js @@ -329,7 +329,10 @@ describe('flow control, the receiver: past its budget a record waits; past its q assert.ok(await until(() => s._peers.has(r.nodeId) && r._peers.has(s.nodeId), 20000)); assert.ok(await until(() => s._peers.get(r.nodeId).transport._outFlow && s._peers.get(r.nodeId).transport._outFlow.advertised, 5000)); for (let i = 0; i < 100; i++) s.remember(CATS(`stop ${i}`), { to: r.nodeId }); - assert.ok(await until(() => flowOf(r).queuedRecords > 20, 5000), `r has records waiting (${flowOf(r).queuedRecords})`); + // Every record has reached r (surfaced or waiting): what is still unread in a socket when it closes + // is the residual (lost with the socket, said nowhere), not what this test is about. + assert.ok(await until(() => seen.length + flowOf(r).queuedRecords === 100, 10000), `r holds all 100 (${seen.length} surfaced, ${flowOf(r).queuedRecords} waiting)`); + assert.ok(flowOf(r).queuedRecords > 20, `r has records waiting (${flowOf(r).queuedRecords})`); await r.stop(); assert.ok(await until(() => sm.count('cmb-refused-by-peer') > 0, 5000), 'the stopping receiver told the sender what it had not taken'); assert.ok(s.pendingDeliveries().some((p) => p.state === 'refused'), 'held again, waiting for the retry-after'); From 49dfbad8b5fb17f4996f24bc330743ca89a03bf7 Mon Sep 17 00:00:00 2001 From: "SYM.BOT" Date: Wed, 14 Oct 2026 19:46:18 +0100 Subject: [PATCH 5/7] Tests: the door test counts records admitted after the door refused (none), not a surfaced total a slower host drains past; two timing windows widened --- tests/flow-control-bounds.test.js | 18 +++++++++++------- 1 file changed, 11 insertions(+), 7 deletions(-) diff --git a/tests/flow-control-bounds.test.js b/tests/flow-control-bounds.test.js index 227e51dd..b70785aa 100644 --- a/tests/flow-control-bounds.test.js +++ b/tests/flow-control-bounds.test.js @@ -178,8 +178,10 @@ describe('flow control, the receiver: past its budget a record waits; past its q const N = mk('fd-n'); const E = mk('fd-e'); asLegacySender(E); const nm = metrics(N); - const seen = []; - N.on('cmb-accepted', (e) => seen.push(e.cmb.categories.focus.text || e.cmb.categories.focus)); + let patched = false; + let after = 0; + // Raised synchronously when a record is admitted, before anything is evaluated. + N.on('verified-record', () => { if (patched) after++; }); try { await N.start(); await E.start(); await connectNodes(E, N); @@ -190,10 +192,10 @@ describe('flow control, the receiver: past its budget a record waits; past its q // The door now refuses that peer (evicted from the room, say): what waits for it is not admitted. const door = N._roomDoor.bind(N); N._roomDoor = (peerId) => (peerId === E.nodeId ? { pass: false, reason: 'evicted' } : door(peerId)); + patched = true; assert.ok(await until(() => nm.count('cmb-queue-dropped') > 0 && flowOf(N).queuedRecords === 0, 8000), 'what waited was dropped'); await sleep(300); - const after = seen.length; - assert.ok(after <= 33, `nothing that waited was evaluated (${after} surfaced: the burst only)`); + assert.strictEqual(after, 0, 'nothing that waited was admitted once the door refused its peer'); assert.ok(nm['cmb-queue-dropped'].every((m) => m.reason === 'not-admitted')); } finally { await stopAll(N, E); } }); @@ -409,8 +411,10 @@ describe('flow control, the advertisement (`cmb-budget`)', () => { for (let i = 0; i < 60; i++) s.send(`legacy pace ${i}`, { to: r.nodeId }); await sleep(1000); const toR = () => frames.filter((f) => f.dir === 'a→b' && f.at >= t0); - const inFirst = toR().filter((f) => f.at - t0 < 100).length; - assert.ok(inFirst <= 24, `at most 24 at once (${inFirst})`); + // Within 300 ms of the first: the burst of 24, and at 6 a second at most one or two more. + const first = toR()[0].at; + const inFirst = toR().filter((f) => f.at - first < 300).length; + assert.ok(inFirst <= 26, `at most 24 at once (${inFirst} in the first 300 ms)`); assert.ok(inFirst >= 20, `and the burst went at once (${inFirst})`); const inSecond = toR().length; assert.ok(inSecond <= 24 + 7, `then about 6 a second (${inSecond} in the first second)`); @@ -428,7 +432,7 @@ describe('flow control, the advertisement (`cmb-budget`)', () => { for (let i = 0; i < 40; i++) s.send(`after anchors ${i}`, { to: r.nodeId }); await sleep(1500); const f = flowOf(r); - assert.ok(f.peakRecords <= 2, `the receiver never had more than jitter waiting (${f.peakRecords})`); + assert.ok(f.peakRecords <= 3, `the receiver never had more than jitter waiting (${f.peakRecords})`); } finally { await stopAll(s, r); } }); From 8e9daf73b91608eee36874d53860502ea5491536 Mon Sep 17 00:00:00 2001 From: "SYM.BOT" Date: Wed, 14 Oct 2026 19:51:02 +0100 Subject: [PATCH 6/7] Tests: arrival order is read at admission (verified-record), not from surface events, which a large record's asynchronous evaluation reorders --- tests/flow-control-bounds.test.js | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/tests/flow-control-bounds.test.js b/tests/flow-control-bounds.test.js index b70785aa..f8ef3424 100644 --- a/tests/flow-control-bounds.test.js +++ b/tests/flow-control-bounds.test.js @@ -221,9 +221,10 @@ describe('flow control, the receiver: past its budget a record waits; past its q it('a session\'s records are admitted in arrival order: a small one never overtakes a large one waiting for the size budget', async () => { const N = mk('fo-n'); const E = mk('fo-e'); asLegacySender(E); + // The order records are ADMITTED in: the hook is raised synchronously at admission, for a record and a + // message alike (a large record's cmb-accepted comes after its evaluation, which is asynchronous). const seen = []; - N.on('cmb-accepted', (e) => { const t = e.cmb.categories.focus.text || e.cmb.categories.focus; if (/^order /.test(t)) seen.push(t.slice(0, 12)); }); - N.on('message', (_f, t) => { if (/^order /.test(t)) seen.push(t); }); + N.on('verified-record', (e) => { const f = e.record.categories.focus; const t = (f && f.text) || f; if (/^order /.test(t)) seen.push(/^order big/.test(t) ? t.slice(0, 12) : t); }); try { await N.start(); await E.start(); await connectNodes(E, N); From 7decf29c325c89ac78e39ddd3f5c24bc3b4cf8df Mon Sep 17 00:00:00 2001 From: "SYM.BOT" Date: Wed, 14 Oct 2026 20:58:36 +0100 Subject: [PATCH 7/7] CHANGELOG 0.14.3 flow control: the suite, integration, gate, audit, Linux and CI runs --- CHANGELOG.md | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index 6b1c48ff..cc2cf3ed 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -513,6 +513,12 @@ the rest refused and the peer told (each notice ≤ 256 ids, retry-after 64 s), lane's spend, which the flood's cut had masked; the notice timer's spin; the sent window's per-peer key, which only shows when the refusing peer is not the last one written); the fifth was a guard no input could reach (an own-queue reason beside the episode, which already implies it) and was removed, its mutant replaced by one on the episode. + **Runs:** full suite on macOS (Node 22, `--test-concurrency=2`): 1686 tests, 1682 pass, 0 fail, 4 skipped; + integration 6 of 6; `node scripts/gate-two-stock-nodes.mjs` passed; `npm audit` 0 vulnerabilities; the two + flow-control files with the four changed ones (95 tests) pass in `node:22-slim` (22.23.3) and `node:20-slim` + (20.20.2); CI (Linux, Node 20 and 22): 1686 tests, 1683 pass, 0 fail, 3 skipped. The bursts and drops above were + also run as scripts against a `git archive` of 0.14.2 (fe285a3) and of 9f6847c, both directions, over the LAN and + over sym-relay `origin/main` (2b23444) on 127.0.0.1. ## 0.14.2 — 2026-10-14