Rebuild: hedged chunk fetches and connection max age (both off by default)
Test and deploy / test (push) Successful in 24s
Test and deploy / deploy (push) Skipped

A chunk not in after NNTP_HEDGE_AFTER_SECONDS (10) is asked again on one
of NNTP_HEDGE_CONNECTIONS spare connections; the first answer wins and
the other connection is closed (lib/nntp/hedge.ts, tested). Connections
can be retired after NNTP_CONNECTION_MAX_MINUTES (±25%). The prefetch
report counts hedges and slow first requests by connection age.

Homelab, 15 min each: hedging on (40 + 6) 280k articles/s, off 273k.
The second request won about half of its races, but ~25-35% of first
requests were slow (>10 s) at every connection age, so neither helps:
Eweka is slow under our load, not on particular connections. Both
off by default; the age statistics stay.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
Daan MeijerandClaude Opus 5.5 committed 2026-10-09 22:13:44 +02:00
1 parent fc8ec9ff48
commit 8475969145
7 files changed
+234 -11

No files matched your search

+81 -7
View File
@@ -3,6 +3,7 @@ import logger from '@adonisjs/core/services/logger'
import coordinatorConfig from '#config/coordinator'
import NntpPool from '#services/nntp_pool'
import Spool, { type ChunkSpan } from '#services/spool'
import { hedge, type Request, type XoverClient } from '#lib/nntp/index'
interface Target {
id: number
@@ -15,6 +16,9 @@ interface Target {
total: number
}
/** Connection ages the report counts slow first requests by, in minutes. */
const AGE_BUCKETS = [2, 10, Infinity]
/** How often the targets are read again from the database. */
const REFRESH_MS = 2000
/** How often the spool's size is measured (a stat per file). */
@@ -27,7 +31,8 @@ const SIZE_MS = 30_000
* order), then the next planned ranges, about SPOOL_AHEAD_PER_LEASE per
* active lease (at least SPOOL_MIN_AHEAD), within SPOOL_MAX_GB. One
* connection fills ~26 k overview lines/s, so a range on one connection
* kept its worker waiting (LOG.md 2026-10-09).
* kept its worker waiting (LOG.md 2026-10-09). A chunk that takes long is
* asked again on a spare connection (fetchHedged).
*/
export class Prefetcher {
/**
@@ -45,7 +50,25 @@ export class Prefetcher {
private spoolBytes = 0
private sizedAt = 0
/** Fetched since the last report: chunks, articles, ms spent fetching. */
private stats = { chunks: 0, articles: 0, fetchMs: 0, since: Date.now() }
private stats = this.freshStats()
private freshStats() {
return {
chunks: 0,
articles: 0,
fetchMs: 0,
hedged: 0,
hedgeWon: 0,
/** First requests per connection-age bucket, and how many of them were slow. */
byAge: AGE_BUCKETS.map(() => ({ requests: 0, slow: 0 })),
since: Date.now(),
}
}
/** The prefetcher's loops: the pool less the connections kept for hedging. */
private get loops() {
return Math.max(1, NntpPool.size - coordinatorConfig.nntpHedgeConnections)
}
/** One round: refreshes the targets now and then, and puts idle connections to work. */
async tick() {
@@ -54,7 +77,7 @@ export class Prefetcher {
this.targets = await this.readTargets()
}
this.report()
while (!this.stopped && this.running < NntpPool.size && this.peek()) {
while (!this.stopped && this.running < this.loops && this.peek()) {
this.running++
this.work()
.catch((error) => logger.warn(`Prefetching: ${error.message}`))
@@ -82,7 +105,7 @@ export class Prefetcher {
await client.group(target.group)
return client.xoverRaw(span.from, span.to)
}
const data = target.plain.has(span.from) ? await NntpPool.usePlain(fetch) : await NntpPool.use(fetch)
const data = target.plain.has(span.from) ? await NntpPool.usePlain(fetch) : await this.fetchHedged(target.group, span)
this.stats.chunks++
this.stats.articles += span.to - span.from + 1
this.stats.fetchMs += Date.now() - fetchedAt
@@ -101,18 +124,69 @@ export class Prefetcher {
}
}
/**
* A chunk over a pooled connection. Not in after nntpHedgeAfterMs, it's
* asked again on a free connection (if there is one): Eweka stalls single
* requests, and the same chunk on another connection mostly comes in
* seconds (LOG.md 2026-10-09 (15)). The first answer wins; the other
* request can't be cancelled, so its connection is closed (the pool opens
* a fresh one).
*/
private async fetchHedged(group: string, span: ChunkSpan): Promise<Buffer> {
let age: number | undefined
const request = (start: (work: (client: XoverClient) => Promise<Buffer>) => Promise<Buffer> | null, first: boolean): Request<Buffer> | null => {
let client: XoverClient | undefined
let cancelled = false
const done = start(async (c) => {
// Given up before it got a connection: the connection goes back unused.
if (cancelled) return Buffer.alloc(0)
client = c
if (first) age = NntpPool.ageOf(c)
await c.group(group)
return c.xoverRaw(span.from, span.to)
})
if (!done) return null
done.catch(() => {})
return {
done,
// The request can't be called off on the wire: its connection is closed, and the pool opens a fresh one.
cancel: () => {
cancelled = true
client?.close()
},
}
}
const result = await hedge(
() => request((work) => NntpPool.use(work), true)!,
() => request((work) => NntpPool.tryUse(work), false),
coordinatorConfig.nntpHedgeAfterMs
)
if (age !== undefined) {
const bucket = this.stats.byAge[AGE_BUCKETS.findIndex((minutes) => age! < minutes * 60_000)]
bucket.requests++
if (result.late) bucket.slow++
}
if (result.hedged) this.stats.hedged++
if (result.secondWon) this.stats.hedgeWon++
return result.value
}
/** A line a minute: what the connections fetched, and how long a chunk took. */
private report() {
const seconds = (Date.now() - this.stats.since) / 1000
if (seconds < 60) return
const { chunks, articles, fetchMs } = this.stats
const { chunks, articles, fetchMs, hedged, hedgeWon, byAge } = this.stats
if (chunks > 0) {
const ages = byAge
.map((b, i) => `${i === 0 ? '<' : `${AGE_BUCKETS[i - 1]}–`}${AGE_BUCKETS[i] === Infinity ? '' : AGE_BUCKETS[i]} min ${b.slow}/${b.requests}`.replace('– min', '+ min'))
.join(', ')
logger.info(
`Prefetched ${chunks} chunks in ${seconds.toFixed(0)} s: ${Math.round(articles / seconds).toLocaleString('en')} articles/s, ` +
`${(fetchMs / chunks / 1000).toFixed(1)} s a chunk, connections busy ${Math.round((fetchMs / (seconds * 1000 * NntpPool.size)) * 100)}%.`
`${(fetchMs / chunks / 1000).toFixed(1)} s a chunk, loops busy ${Math.round((fetchMs / (seconds * 1000 * this.loops)) * 100)}%; ` +
`hedged ${hedged} (second won ${hedgeWon}); slow by connection age: ${ages}.`
)
}
this.stats = { chunks: 0, articles: 0, fetchMs: 0, since: Date.now() }
this.stats = this.freshStats()
}
private peek(): boolean {