diff --git a/docs/api.md b/docs/api.md index f04548a..f1dca24 100644 --- a/docs/api.md +++ b/docs/api.md @@ -118,8 +118,8 @@ the whole answer to "what does the default verbosity show?". | group | types | |---|---| -| the run | `run:cancelled`, `grab:done` | -| a site | `site:started` (with `dayZone` for a site on [another calendar](./configuration.md#which-day-is-today), whose days `days` then counts), `site:done` (its counts plus what it cost: `requests`, `ms`, `requestMs`), `site:failed`, `site:note`, `site:warning` (the last two carrying whatever [fields the site attached](./site-config.md#saying-something)) | +| the run | `run:cancelled`, `grab:done` (with every request of the run, by label — which a request a parse did not wait for can take past what its sites' `site:done` add up to) | +| a site | `site:started` (with `dayZone` for a site on [another calendar](./configuration.md#which-day-is-today), whose days `days` then counts), `site:done` (its counts plus what it cost: `requests`, `ms`, `requestMs`, `requestsBy`), `site:failed`, `site:note`, `site:warning` (the last two carrying whatever [fields the site attached](./site-config.md#saying-something)) | | one channel-day | `entry:cached`, `entry:fetched`, `entry:appended`, `entry:unchanged`, `entry:failed` | | one request | `request:started`, `request:done` (with `ms`), `request:failed` | | a whole-document source | `stream:gaps`, `stream:ignored` | @@ -160,6 +160,75 @@ waiting on something of its own: its `rateLimit`, or the parsing and writing that follow each response, which share [`localConcurrency`](./configuration.md#how-caching-works) with every other site. That is the measurement to take before tuning either. +`requestsBy` says the same by what each request was for, with what failed them +— so "5291 requests" says that 3,242 of them were detail calls answered `404`: + +```json +"requestsBy": { + "request": { "requests": 49, "requestMs": 12034, "failed": {} }, + "detail": { "requests": 5242, "requestMs": 573118, "failed": { "404": 3242, "timeout": 3 } } +} +``` + +`requestMs` is the label's share of the site's `requestMs`, the time spent +waiting on the source — not of `ms`, which is the site's wall clock. + +A label is the site's to name: [`requestLabel`](./site-config.md#reference) +for its own requests — a request site's planned ones, or, since a stream has +none, the fetches of a pass that give no label — and +[`paced(task, { label })`](./site-config.md#a-parse-that-needs-another-request) +for the rest. A label is a word with a letter in it, in any script, or words +joined by `.`, `_`, `/` or `-` — `detail`, `v2/episodes` — so it reads as one +name on the text line, not as a status, and is never `channels`. A site with a +`requestLabel` that is not one is refused, and asks its source for nothing but +its channel list, where the run settles every list before it grabs: a `build`, +whose guide still writes what the site has cached, or a grab with a selection +or a `cover` to apply. A `paced` call with one throws where it is called, past any `.catch` +meant for the request, and is said once as a warning of the site's, past a +`try` around the `await` too. A label names a kind of request, not one request: +a site whose requests come under more than 64 labels is warned once, and every +one is still counted. + +Without one, a request site's planned requests are `request`, a parse's `paced` +calls are `paced`, and a stream's fetches are `stream`. A channel list that was +fetched is `channels`, the calls of Schedules Direct's lineup among it, and +Schedules Direct names the rest of its own: `md5`, `schedules` and `programs`. +They come in the order each was first sent. + +A request is counted as its turn comes, so one a cancel dropped before it is +not, and one already under way when the cancel came is. A failure is counted +where the request threw it, so a `404` the site goes on to catch is counted all +the same: by its status, `timeout`, `network` where nothing answered, or +`error` for anything else the request threw — a Schedules Direct refusal +answered at `200` among them. A request the cancel itself stopped is not +counted as failed — one that threw the cancel's reason, or an `AbortError`, +read down the error's `cause` chain — though what a source answered before or +as the cancel came still is; and a `304` that said a channel-day is unchanged +is an answer. A request a parse sent and did not wait for counts in its site's +`site:done` as far as it had got by then, and in `grab:done` as far as it has +by the end of the run. + +`grab:done` carries every request a site's queue sent, a list settled before +the grab included — save the list of a site whose settings no queue can be made +from, which is fetched without one, counted nowhere, and the site then refused. +A site in a thread counts its requests in memory its thread shares with the +run's, read once the run is done with every site, as a site on the run's own +thread is counted until then. One whose thread dies has lost none of what it +counted, and its `site:failed` comes with a `site:done` saying what it had +done — once, and only once everything the thread sent has been heard: a site +that had said it failed is told its thread went too as a warning, and one +that had said its `site:done` is said no more. Heard, that is, when its port +says it has closed, which it does at once however a thread goes; should one +never say so, the site is said five seconds after from what its memory holds, +less any label its thread had not named. + +The text reporter lists them on a site's line where it had more than one kind +— and, for a site of one kind, only what failed it: `10647 requests (12 × 503)`: + +``` +[skylink.sk] 144 fetched, 0 from cache, 0 failed — 5291 requests (request 49, detail 5242: 3242 × 404 and 3 × timeout) in 11m37s, 585s waiting +``` + `merge:summary` says what the sources made of each other, once the last programme is out: @@ -189,6 +258,27 @@ shows it decides how, and a single-site grabber leaves it out. is told everything, which is what makes one worth writing; the ones below take a `level` and drop what is under it. +**A reporter that throws fails the grab, once it is done.** What it threw does +not stop a site part way through saying what it did, nor the run: every site is +counted and said, `grab:done` or `run:cancelled` included, and then the grab — +and the `build` around it, before its merge — rejects with a `ReporterError`. +That is an `AggregateError` whose `errors` are what was thrown, each kind once +— a name and a message make a kind — and whose `thrown` says how often each +was, and at which events: a broken reporter throws at every event, and a run +says tens of thousands. Ten kinds are kept, and any past them counted in +`untracked`. A merge goes the same way — `runMerge`, or a `build` whose +reporter throws only at its merge, writes the whole guide, then rejects, and +`guideStream` hands over the whole of it, then throws — and a run that fails +on its own as well rejects with a `RunFailedError`, so neither is lost: an +`AggregateError` of both, with the run's own failure as its `error` and the +`ReporterError` as its `reporter`. A reporter written `async`, though a reporter is synchronous, has what it +rejects with kept as a throw is, while the run lasts: nothing waits on a +reporter, so one that rejects after the run has answered is let go of. Nothing is said once the run has +answered, though a request a parse did not wait for may still be going. +Reporters joined by `combineReporters` are each told every event, whatever +another throws. A sink that cannot keep up is a bug in the sink, and is said +rather than swallowed. + ### The ones this package ships Each is built by a function that takes options, so naming one and configuring it @@ -532,7 +622,7 @@ are not re-exported at all. |---|---| | Config | `defineConfig`, `resolveConfigSource` | | Answers | `createConfigContext`, `defaultsReader`, `envReader` | -| Errors | `GrabberError`, `errorMessage`, `errorChain` | +| Errors | `GrabberError`, `ReporterError`, `RunFailedError`, `errorMessage`, `errorChain` | | Events | `LEVELS`, `PHASES`, `EVENT_KINDS`, `atLevel`, `emitter` | | Reporters | `textReporter`, `jsonReporter`, `progressReporter`, `loggerReporter`, `emitterReporter`, `combineReporters`, `render`, `renderFailure`, `isFailure`, `reporterFor`, `REPORTER_NAMES`, `FAILURE_MODES`, `DEFAULT_FAILURE_CAP` | | Runners | `build`, `runGrab`, `runMerge`, `guideStream`, `createCacheStore` | @@ -986,8 +1076,9 @@ cannot tell which it is serving. `kyWith`, `sitePacing`, `retryAfterMs`, `channelElement`, `defaultChannelInfo`, `SiteStateHandle`, `StateKey`, `TrackedMap`, `channelsMaxAgeMs`, `DEFAULT_CHANNELS_MAX_AGE_DAYS`, `UnchangedError`, `isUnchanged`, -`fellShort`, `resolveAllowance`, and `ProgrammeBuilder` / `ChannelBuilder` / -`ProgrammeOptions` / `NumberedOptions` as types. +`ReporterError`, `RunFailedError`, `fellShort`, `resolveAllowance`, and +`ProgrammeBuilder` / `ChannelBuilder` / `ProgrammeOptions` / `NumberedOptions` +/ `ReporterThrow` as types. `*` this subpath only — not re-exported from the root. diff --git a/docs/site-config.md b/docs/site-config.md index 8ef5ffe..b00005d 100644 --- a/docs/site-config.md +++ b/docs/site-config.md @@ -41,6 +41,7 @@ it cannot leave a half-built site's output in the cache. | `cacheChannels` | `boolean \| { maxAgeDays? }` | off | Keep a **fetched** channel list in the cache, so the next command reads it instead of asking the source — see [keeping a fetched list](#keeping-a-fetched-list). `true` means a day. | | `conditionalGet` | `boolean` | off | Ask the source whether anything has changed, and keep what is cached when it says no — see [asking only when it is worth it](#asking-only-when-it-is-worth-it). No code changes in the site. | | `request` | `(ctx) => Promise` | **required**\* | Fetch one request's raw data. The context's shape comes from `batching`. | +| `requestLabel` | `string` | `'request'`, or `'stream'` | What the site's own requests are counted as in `site:done`'s [`requestsBy`](./api.md#what-a-run-cost-and-what-the-merge-made-of-it): `request`'s, beside what a parse's [`paced`](#a-parse-that-needs-another-request) calls are labelled — `'listings'` beside `'detail'` — or, for a [stream](#a-pass-paces-its-own-requests), which has no planned requests, its `paced` calls that give no label. | | `parseDay` | `(ctx) => ParsedProgramme[] \| Promise<…>` | **required**\* | Turn part of a response into one channel-day's programmes. Called once per channel-day. May return builders, plain objects, or a mix. | | `stream` | `(ctx) => AsyncIterable` | — | \*Instead of `request` and `parseDay`: answer the whole window in one pass, yielding each channel-day as it is complete — see [sites that answer in one pass](#sites-that-answer-in-one-pass). Such a site is written with `defineStreamSiteConfig` rather than `defineSiteConfig`. | | `channelInfo` | `(channel, element) => XmltvChannel \| ChannelBuilder` | `defaultChannelInfo` — id, display name and logo | Build the `` element for a channel. | @@ -526,6 +527,38 @@ ahead of work that has not started. A site fetching a detail per programme would otherwise fill every slot with parses waiting on its own pacing, and leave every other site's parses queued behind them. +Give it a label, and the run's summary counts it apart from the requests it +came out of: + +```ts +const detail = await paced( + ({ signal }) => http.get(`detail/${item.id}`, { signal }).json(), + { label: 'detail' }, +); +``` + +`site:done`'s [`requestsBy`](./api.md#what-a-run-cost-and-what-the-merge-made-of-it) +then says how many detail calls there were, how long they waited, and what +failed them — a `404` the parse goes on to catch included — and the text line +says it beside the rest: + +``` +5291 requests (request 49, detail 5242: 3242 × 404 and 3 × timeout) in 11m37s, 585s waiting +``` + +Without a label a parse's are `paced`; the planned requests are `request`, or +what the site's `requestLabel` calls them. A label is a word with a letter in +it, or words joined by `.`, `_`, `/` or `-`. One that is not throws where +`paced` is called, so a `.catch` meant for a missing detail does not swallow it +with every detail — and is said once as a warning of the site's, for a `try` +around the `await` that would. + +A label names a kind of request — `detail`, `episodes` — not one request: each +is a key of `requestsBy` and a name on the site's line, so a label made from a +url or an id makes one of each. A site whose requests come under more than 64 +labels is told so once, as a warning of its own, and every one is still +counted. + A request straight through `http` works too and still aborts with the run — it is simply not queued, so nothing paces it. Requests a `request` makes itself share the one slot it is already holding, which is the other reason a @@ -1530,7 +1563,12 @@ thread's own. Only the fetch belongs inside `paced`, not the work its answer feeds: a slot is one request to the source, and holding one for the length of a pass would be -holding it for the length of the run. +holding it for the length of the run. A pass's fetches are counted in +`site:done`'s `requestsBy` under the label each `paced` call gives — as a +parse's are — and the rest under the site's `requestLabel`, `stream` unless it +gives one. A stream has no planned requests, so its fetches are what that +names: `requestLabel: 'document'` on a [published guide](#a-published-guide-as-a-source) +names the one fetch of its document. Everything else about a site is the same: `channels`, `cacheChannels`, `concurrency`, `rateLimit`, `backoff`, `ky`, `connection`, `staleness`, diff --git a/src/build.ts b/src/build.ts index 26495a9..9e3f4a9 100644 --- a/src/build.ts +++ b/src/build.ts @@ -9,7 +9,7 @@ import type { CacheDriver, CacheManagerOptions, CacheStore } from './cache/main. import { resolveSessions } from './grabber/channels.js'; import { grabWith } from './grabber/grab.js'; import { covered, coverageOf } from './grabber/main.js'; -import { earliestDay } from './grabber/site.js'; +import { earliestDay, siteName } from './grabber/site.js'; import { openSession, type SiteSession } from './grabber/session.js'; import { threadCount } from './grabber/thread.js'; import type { AnySiteConfig, GrabberChannel, GrabSummary } from './grabber/types.js'; @@ -20,7 +20,7 @@ import { outputOptions } from './xmltv/serialize.js'; import { addDays, dayIn, localTimeZone, resolveTimeZone } from './core/days.js'; import { GrabberError } from './core/error.js'; import type { Emit, Reporter, Says } from './core/events.js'; -import { emitter, reportingTo } from './core/events.js'; +import { emitter, keepingThrows, reportingTo } from './core/events.js'; import { resolveConfigSource, type ConfigSource, @@ -269,13 +269,52 @@ async function settled( now: Date, emit: Emit, ): Promise { - const failures: Settled['failures'] = []; const sessions = new Map(); + + try { + return await settling(config, cache, options, now, emit, sessions); + } catch (error) { + // Handed to no grab, which is what lets go of them otherwise: a hold's + // timer is not unref'd, and each listens to the run's signal. + for (const session of sessions.values()) { + session.pacing.dispose(); + } + + throw error; + } +} + +/** {@link settled}, opening the sessions its lists are fetched through into `sessions`. */ +async function settling( + config: EpgConfig, + cache: CacheStore, + options: RunOptions, + now: Date, + emit: Emit, + sessions: Map, +): Promise { + const failures: Settled['failures'] = []; const timeZone = zoneOf(config, options); + // A site its config named nothing is refused for it here, before anything + // is asked of its source: what it fetched would be kept under no name, for + // no grab or merge to read. Said by the grab, as a site whose list failed. + const named = config.sites.filter((site) => { + try { + siteName(site); + + return true; + } catch (error) { + failures.push({ site: site.site, error }); + + return false; + } + }); // For a site whose list is fetched, and only those: the fetch goes through the - // queue its requests will, and the grab carries on with the same one. - for (const site of config.sites) { + // queue its requests will, and the grab carries on with the same one. A site + // the grab will refuse is settled too: the merge writes what it has cached, + // which takes its list. + for (const site of named) { if (typeof site.channels !== 'function') { continue; } @@ -292,7 +331,7 @@ async function settled( } const sites = await resolveSessions( - config.sites, + named, { ...(config.siteConcurrency !== undefined ? { concurrency: config.siteConcurrency } : {}), ...(options.signal ? { signal: options.signal } : {}), @@ -485,7 +524,10 @@ async function grabInto( /** Grab all sites into the cache (only stale/missing channel-days are fetched). */ export async function runGrab(source: ConfigSource, given: RunOptions = {}): Promise { const config = await resolveConfigSource(source); - const options = reportingTo(given, config.events); + // From the first thing said — the cache's own warnings included — what a + // reporter throws is kept, and thrown once the run is done: see `grab`. + const kept = keepingThrows(reportingTo(given, config.events)); + const options = kept.options; // Before a channel list is fetched: a run that cannot start its threads, or // was given a zone that is not one, says so first, rather than after every @@ -494,42 +536,49 @@ export async function runGrab(source: ConfigSource, given: RunOptions = {}): Pro zoneOf(config, options); const now = options.now ?? new Date(); - return withCache(config, options, async (cache) => { - // Settled here only when there is something to narrow — a selection, or a - // `cover` that takes channels away. Every site resolves its own list anyway, - // so this is the same work done early enough to act on, and a - // `cacheChannels` site answers from the cache both times. - if (config.channels === undefined && !narrowed(config)) { + return kept.settle( + withCache(config, options, async (cache) => { + // Settled here only when there is something to narrow — a selection, or + // a `cover` that takes channels away. Every site resolves its own list + // anyway, so this is the same work done early enough to act on, and a + // `cacheChannels` site answers from the cache both times. + if (config.channels === undefined && !narrowed(config)) { + return grabInto( + config, + { sites: config.sites, failures: [], sessions: new Map() }, + cache, + options, + now, + ); + } + return grabInto( config, - { sites: config.sites, failures: [], sessions: new Map() }, + await settled(config, cache, options, now, emitter(options)), cache, options, now, ); - } - - return grabInto( - config, - await settled(config, cache, options, now, emitter(options)), - cache, - options, - now, - ); - }); + }), + ); } /** Generate the merged XMLTV guide from the cache, without grabbing. */ export async function runMerge(source: ConfigSource, given: RunOptions = {}): Promise { const config = await resolveConfigSource(source); - const options = reportingTo(given, config.events); - - await withCache(config, options, async (cache) => - writeGuide({ - ...guideOptions(config, options, options.now ?? new Date(), cache), - output: config.output, - ...(config.compress !== undefined ? { compress: config.compress } : {}), - }), + // As `runGrab` keeps them: what a reporter throws at the merge is thrown once + // the guide is written, rather than leaving it half made. + const kept = keepingThrows(reportingTo(given, config.events)); + const options = kept.options; + + await kept.settle( + withCache(config, options, async (cache) => + writeGuide({ + ...guideOptions(config, options, options.now ?? new Date(), cache), + output: config.output, + ...(config.compress !== undefined ? { compress: config.compress } : {}), + }), + ), ); } @@ -542,16 +591,30 @@ export async function* guideStream( given: RunOptions = {}, ): AsyncGenerator { const config = await resolveConfigSource(source); - const options = reportingTo(given, config.events); + // As `runMerge` keeps them: what a reporter throws is thrown once the whole + // guide has been handed over. + const kept = keepingThrows(reportingTo(given, config.events)); + const options = kept.options; const { cache, release } = await cacheFor(config, options); + let failed: { error: unknown } | undefined; try { yield* generateGuide(guideOptions(config, options, options.now ?? new Date(), cache)); + } catch (error) { + failed = { error }; } finally { // Whether the caller read the guide to its end or walked away half way // through it: a generator's `finally` runs either way, and a driver holding - // a handle open is waiting for exactly this. - await release(); + // a handle open is waiting for exactly this — as is what a reporter threw, + // which is thrown to whoever stopped reading as well, whatever letting go + // of the cache came to. + try { + await release(); + } catch (error) { + failed ??= { error }; + } + + await kept.settle(failed === undefined ? Promise.resolve() : Promise.reject(failed.error)); } } @@ -567,7 +630,10 @@ export async function build(source: ConfigSource, given: RunOptions = {}): Promi // Resolved once and passed on: a factory may read the environment or fetch, // and the grab and the merge that follows it must agree on one answer. const config = await resolveConfigSource(source); - const options = reportingTo(given, config.events); + // As `runGrab` keeps them, for the merge as well: what a reporter throws at + // it is thrown once the guide is written. + const kept = keepingThrows(reportingTo(given, config.events)); + const options = kept.options; const now = options.now ?? new Date(); // As `runGrab` does, and for the same reason: before the lists below. @@ -581,25 +647,31 @@ export async function build(source: ConfigSource, given: RunOptions = {}): Promi // Opened before the channel lists are resolved, rather than after, because // that is where a site's cached list lives — a `cacheChannels` site then makes // no request for a list this cache already has. - return withCache(config, options, async (cache) => { - // Settled once for both halves, which have to agree about what exists. - const settling = await settled(config, cache, options, now, emitter(options)); - // Without the selection, which the lists already went through, and without - // `events`, which `options` already reports to: a half handed either would - // act on it a second time — the same warning about the same missing - // channels, every event twice. - const { channels: _applied, events: _reported, ...rest } = config; - const resolved: EpgConfig = { - ...rest, - ...(settling.derived ? { derived: settling.derived } : {}), - sites: settling.sites, - }; - const summary = await grabInto(resolved, settling, cache, options, now); - - if (options.signal?.aborted !== true) { - await runMerge(resolved, { ...options, now, cache }); - } + return kept.settle( + withCache(config, options, async (cache) => { + // Settled once for both halves, which have to agree about what exists. + const settling = await settled(config, cache, options, now, emitter(options)); + // Without the selection, which the lists already went through, and + // without `events`, which `options` already reports to: a half handed + // either would act on it a second time — the same warning about the same + // missing channels, every event twice. + const { channels: _applied, events: _reported, ...rest } = config; + const resolved: EpgConfig = { + ...rest, + ...(settling.derived ? { derived: settling.derived } : {}), + sites: settling.sites, + }; + const summary = await grabInto(resolved, settling, cache, options, now); + + // Before the merge, should a reporter have thrown at the grab: a guide + // is not written by a run that is going to reject. + kept.rethrow(); + + if (options.signal?.aborted !== true) { + await runMerge(resolved, { ...options, now, cache }); + } - return summary; - }); + return summary; + }), + ); } diff --git a/src/cli/run.ts b/src/cli/run.ts index 6abb160..32f4e3c 100644 --- a/src/cli/run.ts +++ b/src/cli/run.ts @@ -28,6 +28,8 @@ import { OptionError, parseOptions } from '../core/options.js'; import { dayIn, dayToDate, resolveTimeZone, toDayString } from '../core/days.js'; import { reportingTo, + ReporterError, + RunFailedError, silent, stamped, LEVELS, @@ -628,10 +630,25 @@ export async function runCli(argv: string[], options: CliOptions = {}): Promise< try { return await execute(argv, stdout, stderr, options); - } catch (error) { + } catch (thrown) { + // A run that failed, whose reporter threw as well: its own failure is what + // it exits on, and the reporter's is said before it — cancelled or not. + const [error, reporting] = + thrown instanceof RunFailedError ? [thrown.error, thrown.reporter] : [thrown, undefined]; + + if (reporting !== undefined) { + await writeLines(stderr, reporting.message); + } + // Whatever the interruption surfaced as — a merge's own abort, a request // dropped mid-flight — a cancelled run is not a failure to describe. if (options.signal?.aborted) { + // Though what a reporter threw at the run, before it was cancelled, is + // still said. + if (error instanceof ReporterError) { + await writeLines(stderr, error.message); + } + await writeLines(stderr, 'Cancelled.'); return EXIT_CANCELLED; } diff --git a/src/cli/try.ts b/src/cli/try.ts index 20d77f3..2339d50 100644 --- a/src/cli/try.ts +++ b/src/cli/try.ts @@ -35,10 +35,16 @@ import { writeFlushed } from '../core/streams.js'; import { kyWith, resolveChannels, siteHttp } from '../grabber/channels.js'; import { parseContext, requestContext, streamContext } from '../grabber/context.js'; import { planRequests } from '../grabber/planner.js'; -import { resolveSite } from '../grabber/site.js'; +import { LABELS } from '../grabber/labels.js'; +import { pacedLabels, resolveSite } from '../grabber/site.js'; import { Memory } from '../grabber/remember.js'; import { SiteStateHandle } from '../grabber/state.js'; -import type { AnySiteConfig, GrabberChannel, ParsedProgramme } from '../grabber/types.js'; +import type { + AnySiteConfig, + GrabberChannel, + PacedOptions, + ParsedProgramme, +} from '../grabber/types.js'; import { ProgrammeBuilder } from '../xmltv/builder.js'; import { serializeProgramme } from '../xmltv/serialize.js'; import type { XmltvProgramme } from '../xmltv/types.js'; @@ -396,15 +402,24 @@ export async function tryChannelDay( throw new GrabberError(`Nothing to ask for ${channel.xmltvId} on ${day}`); } + const pacedLabel = pacedLabels(site.site, says.warn); const deps = { http, state: await state.bag(), says, ...(options.signal ? { signal: options.signal } : {}), // A request a pass or a parse makes of its own simply runs: there is no - // queue to pace it against, since this is the only thing happening. - paced: (task: (o: { signal?: AbortSignal | undefined }) => Promise): Promise => - task({ ...(options.signal ? { signal: options.signal } : {}) }), + // queue to pace it against, since this is the only thing happening. Its + // label is checked as a run checks it, so what works here works there, + // though nothing here counts by it. + paced: ( + task: (slot: { signal?: AbortSignal | undefined }) => Promise, + labelled?: PacedOptions, + ): Promise => { + pacedLabel(labelled, LABELS.paced); + + return task({ ...(options.signal ? { signal: options.signal } : {}) }); + }, timeZone: config.timeZone, dayZone: resolved.dayZone, // Over a store that keeps nothing, as `state` is: remembered for as long diff --git a/src/core/error.ts b/src/core/error.ts index 6f4d053..cc72c5f 100644 --- a/src/core/error.ts +++ b/src/core/error.ts @@ -36,12 +36,44 @@ export class GrabberError extends Error { * place a stray `throw 'nope'` becomes a crash. */ export function errorMessage(error: unknown): string { - return error instanceof Error ? error.message : String(error); + try { + return error instanceof Error ? error.message : String(error); + } catch { + // Something that cannot even be read — a revoked proxy, an object whose + // `toString` throws — said as such, rather than thrown from where it was + // being said. + return '[something that cannot be read]'; + } } /** How deep a `cause` chain is followed before it is called a cycle. */ export const MAX_CAUSE_DEPTH = 8; +/** + * `error`, then what caused it, and what caused that — down `cause` wherever + * there is one, error or not, since a site may hand on anything, and no + * further than {@link MAX_CAUSE_DEPTH}, where a cycle would go for ever. + */ +export function* causes(error: unknown): Generator { + let current = error; + + for (let depth = 0; depth <= MAX_CAUSE_DEPTH && current !== undefined; depth++) { + yield current; + + if (typeof current !== 'object' || current === null) { + return; + } + + try { + current = (current as { cause?: unknown }).cause; + } catch { + // A `cause` that cannot be read — a revoked proxy, a getter that throws + // — is where the chain ends, rather than a throw from reading it. + return; + } + } +} + /** * Statuses that say "not now" rather than "no": asked too often or too early, * or a request that took too long. A 5xx says the same, and is read as such @@ -53,7 +85,6 @@ const NOT_NOW = new Set([408, 425, 429]); const NETWORK_CODES = new Set([ 'ECONNREFUSED', 'ECONNRESET', - 'ETIMEDOUT', 'ENOTFOUND', 'EAI_AGAIN', 'EHOSTUNREACH', @@ -62,21 +93,45 @@ const NETWORK_CODES = new Set([ ]); /** - * Whether an error means the source did not answer — the network failed, the - * request timed out, or the source said "not now" (408, 425, 429, a 5xx) — - * rather than that it answered and what it said was wrong. + * What a connection that took too long is called, by Node and by undici — + * whose `fetch` says `fetch failed` and leaves the timeout to its `cause`. + */ +const TIMEOUT_CODES = new Set([ + 'ETIMEDOUT', + 'UND_ERR_CONNECT_TIMEOUT', + 'UND_ERR_HEADERS_TIMEOUT', + 'UND_ERR_BODY_TIMEOUT', +]); + +/** + * What a failed request came to: the status the source answered with, + * `'timeout'` or `'network'` where it did not answer, and `'error'` for + * anything else — an answer `.json()` could not read, a site's own throw. What + * `requestsBy` counts a failure under, and what {@link unanswered} decides by. * * Read down the `cause` chain, so a site that wraps a failed request in an * error of its own is still read for what happened underneath. And by name and * shape rather than `instanceof`: a site may bring a ky of its own, whose error * classes are not the ones this package imports. */ -export function unanswered(error: unknown): boolean { - let current = error; +export function failureOf(error: unknown): `${number}` | 'timeout' | 'network' | 'error' { + try { + return readFailure(error); + } catch { + // Whatever was thrown cannot be read — a revoked proxy, a getter that + // throws — so all that is known is that something was. + return 'error'; + } +} - for (let depth = 0; depth <= MAX_CAUSE_DEPTH; depth++) { +/** {@link failureOf}, reading what may throw for being read. */ +function readFailure(error: unknown): `${number}` | 'timeout' | 'network' | 'error' { + /** Said where nothing answered, unless what is beneath says it timed out. */ + let unanswering: 'network' | undefined; + + for (const current of causes(error)) { if (typeof current !== 'object' || current === null) { - return false; + break; } const candidate = current as { @@ -84,30 +139,70 @@ export function unanswered(error: unknown): boolean { message?: unknown; code?: unknown; response?: { status?: unknown }; - cause?: unknown; + statusCode?: unknown; }; + // ky's, on the response it answered with — or undici's own, whose errors + // for a status carry it beside their code. One that is not a success, as + // ky throws for: a site's own error about a `200` it could not use is the + // site's. + const answered = + typeof candidate.response?.status === 'number' + ? candidate.response.status + : typeof candidate.statusCode === 'number' + ? candidate.statusCode + : undefined; + const status = answered !== undefined && answered >= 300 ? answered : undefined; + + if (candidate.name === 'TimeoutError') { + return 'timeout'; + } - if (candidate.name === 'NetworkError' || candidate.name === 'TimeoutError') { - return true; + // Nothing answered — and how, its cause may say: undici's timeouts arrive + // as a `fetch failed`, and ky wraps that in a `NetworkError`. Read before + // a status on the same error, as it is before one beneath it. + if ( + candidate.name === 'NetworkError' || + (candidate.name === 'TypeError' && candidate.message === 'fetch failed') + ) { + unanswering = 'network'; } - // An answer, whatever else is below it: its status says which kind. - if (typeof candidate.response?.status === 'number') { - return NOT_NOW.has(candidate.response.status) || candidate.response.status >= 500; + // An answer, whatever else is below it — unless what is above it, or the + // error itself, says nothing answered, which a status cannot undo. + if (unanswering === undefined && status !== undefined) { + return `${status}`; } - if ( - (candidate.name === 'TypeError' && candidate.message === 'fetch failed') || - (typeof candidate.code === 'string' && - (NETWORK_CODES.has(candidate.code) || candidate.code.startsWith('UND_ERR_'))) - ) { - return true; + if (typeof candidate.code === 'string') { + if (TIMEOUT_CODES.has(candidate.code)) { + return 'timeout'; + } + + if (NETWORK_CODES.has(candidate.code) || candidate.code.startsWith('UND_ERR_')) { + return 'network'; + } } + } - current = candidate.cause; + return unanswering ?? 'error'; +} + +/** + * Whether an error means the source did not answer — the network failed, the + * request timed out, or the source said "not now" (408, 425, 429, a 5xx) — + * rather than that it answered and what it said was wrong. Read as + * {@link failureOf} reads it. + */ +export function unanswered(error: unknown): boolean { + const failure = failureOf(error); + + if (failure === 'timeout' || failure === 'network') { + return true; } - return false; + const status = Number(failure); + + return NOT_NOW.has(status) || status >= 500; } /** @@ -120,11 +215,16 @@ export function unanswered(error: unknown): boolean { * none of the evidence. Kept out of the default line because a chain per * failure is noise until you are looking for one. */ -export function errorChain(error: unknown, depth = 0): string { - const message = errorMessage(error); - const cause = error instanceof Error ? error.cause : undefined; - - return cause === undefined || depth >= MAX_CAUSE_DEPTH - ? message - : `${message}: ${errorChain(cause, depth + 1)}`; +export function errorChain( + error: unknown, + /** How far down a chain `error` is already, of the {@link MAX_CAUSE_DEPTH} followed. */ + depth = 0, +): string { + // Something, however little: `undefined` thrown is said as itself. + return error === undefined + ? errorMessage(error) + : [...causes(error)] + .slice(0, Math.max(1, MAX_CAUSE_DEPTH - depth + 1)) + .map(errorMessage) + .join(': '); } diff --git a/src/core/events.ts b/src/core/events.ts index 56377d8..21a626e 100644 --- a/src/core/events.ts +++ b/src/core/events.ts @@ -24,6 +24,7 @@ */ import { monitorEventLoopDelay } from 'node:perf_hooks'; +import { errorMessage } from './error.js'; /** * How much a reporter is being told, in the order a threshold reads them. @@ -159,6 +160,53 @@ export interface GrabCounts { sitesFailed: number; } +/** Every count at nought — a site's, a run's or a reporter's, before any is counted. */ +export function noCounts(): GrabCounts { + return { fetched: 0, empty: 0, fromCache: 0, unchanged: 0, failed: 0, sitesFailed: 0 }; +} + +/** A label's requests at nought, before any is counted — see {@link RequestCounts}. */ +export function noRequests(): RequestCounts { + return { requests: 0, requestMs: 0, failed: {} }; +} + +/** + * What one kind of request cost — a site's, or the run's, under one label of + * `requestsBy`. + * + * A label is what the request was for: a site's `requestLabel` for its planned + * requests, `'request'` without one; what a `ctx.paced` call names — without a + * name, `'paced'` from a parse, and from a stream its site's `requestLabel`, or + * `'stream'` without one; and `'channels'` for the channel list. Named by the + * site rather than read off a URL, whose ids would make a label of every + * channel. + * + * `requestsBy` lists them in the order each was first sent: a label has a + * letter in it, so none is put first as a number would be. + */ +export interface RequestCounts { + /** + * How many were sent — counted as each one's turn came, so one a cancel + * dropped before it was not, and one under way when the cancel came was. + */ + requests: number; + /** + * How long they spent waiting on the source, pacing not included: the + * label's share of `site:done`'s `requestMs`, and nothing like its `ms`, + * which is the site's wall clock. + */ + requestMs: number; + /** + * The ones that failed, by what failed them: the status the source answered + * with (`'404'`), `'timeout'`, `'network'` where nothing answered, or + * `'error'` for anything else the request threw — read where it was thrown, + * so a `404` a site goes on to catch is counted all the same. A request the + * cancel itself stopped is not counted as failed — what failed before it + * still is — and a `304` that said a channel-day is unchanged is an answer. + */ + failed: Record; +} + /** * What an emitter says: the type, and the fields that type carries. * @@ -191,7 +239,12 @@ export type EpgEventInput = * chunks, and keeps this in the tens of milliseconds however busy it keeps * the thread. */ - | ({ type: 'grab:done'; loopMaxMs: number } & GrabCounts) + | ({ + type: 'grab:done'; + loopMaxMs: number; + /** Every request of the run, by {@link RequestCounts} label. */ + requestsBy: Record; + } & GrabCounts) /** * What this site is about to do, which the planner has just worked out. * @@ -229,6 +282,10 @@ export type EpgEventInput = * long by; and `requestMs` is how long those requests spent waiting on the * source, which is less than `ms` where a site waits on its own pacing, and * more than it where a site runs several at once. + * + * `requestsBy` is `requests` and `requestMs` again, by what each request was + * for, with what failed them — see {@link RequestCounts}. "5291 requests" + * does not say that 3,242 of them were detail calls answered `404`. */ | ({ type: 'site:done'; @@ -236,6 +293,7 @@ export type EpgEventInput = requests: number; ms: number; requestMs: number; + requestsBy: Record; } & GrabCounts) /** The site could not be read or run at all, so none of it was grabbed. */ | { type: 'site:failed'; site: string; error: unknown } @@ -575,6 +633,254 @@ export function emitter(options: ReportedOptions): Emit { return options.reporter === undefined ? silent : stamped(options.reporter); } +/** How many kinds of what a reporter threw are kept — see {@link keepingThrows}. */ +const KEPT_KINDS = 10; + +/** One kind of what a reporter threw — see {@link ReporterError}. */ +export interface ReporterThrow { + /** The first of its kind, as the reporter threw it. */ + error: unknown; + /** How many times it was thrown. */ + times: number; + /** At which events, and how many times at each. */ + at: Partial>; +} + +/** + * What a run rejects with when its reporter threw — once the run is done, and + * has said everything it did. + * + * `errors` is what was thrown, each kind once — a name and a message make a + * kind — and `thrown` how often each was, and at which events: a broken + * reporter throws at every event, and a run says tens of thousands. No more + * than ten kinds are kept, and what is past them is counted in `untracked`. + */ +export class ReporterError extends AggregateError { + override readonly name = 'ReporterError'; + /** Each kind thrown, in the order each was first. */ + readonly thrown: readonly ReporterThrow[]; + /** Throws of kinds past the ten kept, counted and no more. */ + readonly untracked: number; + + constructor(thrown: readonly ReporterThrow[], untracked = 0) { + const times = thrown.reduce((sum, kind) => sum + kind.times, untracked); + const kinds = thrown.map( + (kind) => + `${kindOf(kind.error)} (${Object.entries(kind.at) + .map(([type, n]) => `${n} × at ${type}`) + .join(', ')})`, + ); + + super( + thrown.map((kind) => kind.error), + `The reporter threw ${times} ${times === 1 ? 'time' : 'times'}: ${kinds.join('; ')}` + + (untracked > 0 ? `; and ${untracked} more of other kinds` : ''), + ); + this.thrown = thrown; + this.untracked = untracked; + } +} + +/** + * What a run rejects with when it failed of itself, and its reporter threw as + * well: both, so neither is lost. An `AggregateError` of the two, in that + * order — `error`, what the run would have rejected with had its reporter not + * thrown, and `reporter`, what the reporter threw beside it. + */ +export class RunFailedError extends AggregateError { + override readonly name = 'RunFailedError'; + /** The run's own failure. */ + readonly error: unknown; + /** What its reporter threw, beside it. */ + readonly reporter: ReporterError; + + constructor(error: unknown, reporter: ReporterError) { + super([error, reporter], `${errorMessage(error)} — and the reporter threw as well`); + this.error = error; + this.reporter = reporter; + } +} + +/** What makes two things a reporter threw one kind: a name, and a message. */ +function kindOf(error: unknown): string { + let name: string; + + try { + name = error instanceof Error ? error.name : typeof error; + } catch { + // Something that cannot even be asked what it is — a revoked proxy. + name = 'something unreadable'; + } + + return `${name}: ${errorMessage(error)}`; +} + +/** A reporter's throws, kept — see {@link keepingThrows}. */ +export interface KeptThrows { + /** The options, reporting through the reporter that keeps them. */ + options: T; + /** Throw what has been kept so far, as a {@link ReporterError} — if anything has. */ + rethrow(): void; + /** + * `running`, once settled — and with it, what was kept: alone where it + * resolved, and beside its own error where it rejected, so neither is lost. + * Nothing is said after: what reported through these is done, and an event + * from work it left behind is told to nobody. + */ + settle(running: Promise): Promise; +} + +/** + * `options` reporting through a reporter whose throws are kept rather than let + * loose, and thrown as a {@link ReporterError} once whatever reported through + * it is done. So a sink that cannot keep up neither ends what it is told about + * part way — a site half said, or the process, from a listener nothing + * catches — nor is swallowed. What a grab reports through, and a run around + * one. + */ +export function keepingThrows(options: T): KeptThrows { + const { reporter } = options; + + // Kept already, by a run around this one, which throws what it keeps once + // it is done itself: not kept twice. + if (reporter !== undefined && keeping.has(reporter)) { + return { options, rethrow() {}, settle: (running) => running }; + } + + const kinds = new Map(); + let untracked = 0; + let over = false; + /** What {@link rethrow} threw, last — see `settle`. */ + let thrown: ReporterError | undefined; + + /** What has been kept so far, as it stands now: what is counted after is not in it. */ + const kept = (): ReporterError => + new ReporterError( + [...kinds.values()].map((kind) => ({ ...kind, at: { ...kind.at } })), + untracked, + ); + const rethrow = (): void => { + if (kinds.size > 0) { + thrown = kept(); + throw thrown; + } + }; + /** Keep `error`, thrown — or rejected with — at `event`. */ + const keep = (error: unknown, event: EpgEvent): void => { + if (over) { + return; + } + + const kind = kindOf(error); + let known = kinds.get(kind); + + if (known === undefined) { + if (kinds.size === KEPT_KINDS) { + untracked++; + + return; + } + + known = { error, times: 0, at: {} }; + kinds.set(kind, known); + } + + known.times++; + known.at[event.type] = (known.at[event.type] ?? 0) + 1; + }; + + if (reporter === undefined) { + return { options, rethrow, settle: (running) => running }; + } + + const keepingReporter: Reporter = (event) => { + if (over) { + return; + } + + try { + const returned: unknown = reporter(event); + + // Synchronous, as a reporter is — but one written `async` is not + // refused by its type, and what it rejects with is kept as a throw is, + // rather than left to end the process. Kept while what reported through + // this is going: nothing waits on a reporter, so one that rejects after + // the run has answered is let go of. + if (isThenable(returned)) { + returned.then(undefined, (error: unknown) => { + keep(error, event); + }); + } + } catch (error) { + keep(error, event); + } + }; + + keeping.add(keepingReporter); + + return { + options: { ...options, reporter: keepingReporter }, + rethrow, + async settle(running) { + let done: Awaited; + + try { + done = await running; + } catch (error) { + over = true; + + if (kinds.size === 0) { + throw error; + } + + // Thrown already, on the way out — as it stands now, then, with + // what was kept since. + if (error === thrown) { + throw kept(); + } + + throw new RunFailedError(error, kept()); + } + + over = true; + rethrow(); + + return done; + }, + }; +} + +/** + * Throw what reporters joined together threw: one as it is, several together. + * What each threw, and nothing of the event: the same reporters failing the + * same way at every event are one failure, and failing another way another — + * which is how {@link keepingThrows} keeps them. + */ +function throwAll(threw: unknown[]): void { + if (threw.length === 1) { + throw threw[0]; + } + + if (threw.length > 1) { + throw new AggregateError( + threw, + `${threw.length} reporters threw: ${threw.map(kindOf).join('; ')}`, + ); + } +} + +/** Every reporter {@link keepingThrows} made: one handed it again is kept already. */ +const keeping = new WeakSet(); + +/** Whether `value` is a promise, or anything awaited as one. */ +function isThenable(value: unknown): value is PromiseLike { + return ( + (typeof value === 'object' || typeof value === 'function') && + value !== null && + typeof (value as { then?: unknown }).then === 'function' + ); +} + /** * The options a run reports through, with the config's own emitter added. * @@ -641,9 +947,12 @@ export function emitterReporter(events: EpgEventSink): Reporter { * reporter: combineReporters(options.reporter, loggerReporter({ logger })), * ``` * - * A reporter that throws is not caught here, as it is not caught anywhere - * else: a sink that cannot keep up with a run is a bug in the sink, and - * swallowing it would leave a run reporting into silence with nothing said. + * A reporter that throws is not swallowed here: a sink that cannot keep up with + * a run is a bug in the sink, and swallowing it would leave a run reporting + * into silence with nothing said. The others are told all the same — one + * sink's bug is not another's silence — and what was thrown is thrown once + * they have been: one as it is, several together. A grab keeps the first, says + * the rest of the run, and rejects with it once it is done. */ export function combineReporters(...reporters: (Reporter | undefined)[]): Reporter { const listening = reporters.filter((reporter) => reporter !== undefined); @@ -654,11 +963,46 @@ export function combineReporters(...reporters: (Reporter | undefined)[]): Report return listening[0]!; } - return (event) => { + const combined = (event: EpgEvent): Promise | undefined => { + let threw: unknown[] | undefined; + let pending: Array> | undefined; + for (const reporter of listening) { - reporter(event); + try { + const returned: unknown = reporter(event); + + if (isThenable(returned)) { + (pending ??= []).push(returned); + } + } catch (error) { + (threw ??= []).push(error); + } } + + // What was thrown, thrown now, as a reporter's throw is: never held back + // behind what one written `async` is still doing. What those reject with + // at this event is then let go of — the throw is what is said of it. + if (threw !== undefined) { + for (const one of pending ?? []) { + one.then(undefined, () => {}); + } + + throwAll(threw); + } + + // Otherwise handed on — one as it is, several waited for together — for + // whoever keeps what reporters throw to keep what they reject with, all of + // it. One, as most are: nothing made for it at every event. + if (pending === undefined || pending.length === 1) { + return pending?.[0] as Promise | undefined; + } + + return Promise.allSettled(pending).then((settled) => { + throwAll(settled.flatMap((one) => (one.status === 'rejected' ? [one.reason] : []))); + }); }; + + return combined; } /** diff --git a/src/core/reporters.ts b/src/core/reporters.ts index 3cafbc3..fa9961c 100644 --- a/src/core/reporters.ts +++ b/src/core/reporters.ts @@ -20,9 +20,11 @@ import type { Writable } from 'node:stream'; import { inspect } from 'node:util'; import { atLevel, + noCounts, type EpgEvent, type EventLevel, type GrabCounts, + type RequestCounts, type Reporter, } from './events.js'; import { errorChain, errorMessage, MAX_CAUSE_DEPTH } from './error.js'; @@ -80,11 +82,53 @@ function took(ms: number): string { } /** What a site cost the run, which is not what it fetched. */ -function cost(event: { requests: number; ms: number; requestMs: number }): string { +function cost(event: { + requests: number; + ms: number; + requestMs: number; + /** Not on a `site:done` an earlier version wrote, which a log may replay. */ + requestsBy?: Record; +}): string { // The two times are kept apart rather than averaged into one: a site waiting // on its own `rateLimit` and a site waiting on a slow source look identical // in a total, and are the opposite problems. - return `${count(event.requests, 'request')} in ${took(event.ms)}, ${took(event.requestMs)} waiting`; + return ( + `${count(event.requests, 'request')}${byLabel(event.requestsBy ?? {})} ` + + `in ${took(event.ms)}, ${took(event.requestMs)} waiting` + ); +} + +/** + * A site's requests by what each was for, and what failed them — + * ` (request 49, detail 5242: 3242 × 404)`. Of one kind, only what failed: + * ` (3000 × 404)`, since the total already says how many there were. + */ +function byLabel(requestsBy: Record): string { + const labels = Object.entries(requestsBy); + // " and " between failures, so the commas are left to separate labels. + // `failed` read as `requestsBy` was, where an event from elsewhere may lack it. + const failures = (failed: Record | undefined): string => + Object.entries(failed ?? {}) + .map(([failure, n]) => `${n} × ${failure}`) + .join(' and '); + + if (labels.length === 1) { + const failed = failures(labels[0]![1].failed); + + return failed === '' ? '' : ` (${failed})`; + } + + if (labels.length === 0) { + return ''; + } + + const each = labels.map(([label, { requests, failed }]) => { + const said = failures(failed); + + return `${label} ${requests}${said === '' ? '' : `: ${said}`}`; + }); + + return ` (${each.join(', ')})`; } /** What a run or a site came to, in the one form both say it. */ @@ -548,20 +592,27 @@ export function textReporter(options: TextReporterOptions): Reporter { /** An error as JSON keeps it, `cause` chain and all. */ function errorJson(error: unknown, depth = 0): unknown { - if (!(error instanceof Error)) { - // Including the odd `throw 'nope'`: a log should not be where that becomes - // a crash, and `String` is the only honest thing left. - return { message: String(error) }; - } + try { + if (!(error instanceof Error)) { + // Including the odd `throw 'nope'`: a log should not be where that becomes + // a crash, and `String` is the only honest thing left. + return { message: String(error) }; + } - return { - name: error.name, - message: error.message, - ...(error.stack === undefined ? {} : { stack: error.stack }), - ...(error.cause === undefined || depth >= MAX_CAUSE_DEPTH - ? {} - : { cause: errorJson(error.cause, depth + 1) }), - }; + return { + name: error.name, + message: error.message, + ...(error.stack === undefined ? {} : { stack: error.stack }), + ...(error.cause === undefined || depth >= MAX_CAUSE_DEPTH + ? {} + : { cause: errorJson(error.cause, depth + 1) }), + }; + } catch { + // A site's error that cannot be read — a revoked proxy, a getter that + // throws — said as such: a reporter that threw at it would fail the run + // over what the site did. + return { message: errorMessage(error) }; + } } export interface JsonReporterOptions { @@ -669,14 +720,7 @@ export function progressReporter(options: ProgressReporterOptions): Reporter { return lines; } - const counts: GrabCounts = { - fetched: 0, - empty: 0, - fromCache: 0, - unchanged: 0, - failed: 0, - sitesFailed: 0, - }; + const counts = noCounts(); const sites = new Set(); let finishedSites = 0; let planned = 0; @@ -747,6 +791,9 @@ export function progressReporter(options: ProgressReporterOptions): Reporter { planned += event.entries; break; case 'site:done': + // Added here as well: a site that could not be read is done without + // having started, and is one of the run's all the same. + sites.add(event.site); finishedSites++; break; case 'entry:fetched': diff --git a/src/grabber/channels.ts b/src/grabber/channels.ts index 54e64f6..0e2ecdf 100644 --- a/src/grabber/channels.ts +++ b/src/grabber/channels.ts @@ -10,6 +10,7 @@ import { localTimeZone } from '../core/days.js'; import { errorMessage, unanswered } from '../core/error.js'; import { unplain } from '../core/plain.js'; import type { Emit, Says } from '../core/events.js'; +import { LABELS } from './labels.js'; import type { SiteSession } from './session.js'; import type { AnyIterable, @@ -598,7 +599,10 @@ export async function resolveSessions( try { const channels = await resolveChannels(site, { ...(session - ? { http: session.pacing.http, paced: (fetch) => session.send(fetch) } + ? { + http: session.pacing.http, + paced: (fetch) => session.send(fetch, { label: LABELS.channels }), + } : {}), ...(options.signal ? { signal: options.signal } : {}), ...(state ? { state } : {}), diff --git a/src/grabber/grab.ts b/src/grabber/grab.ts index 6673918..08bdeae 100644 --- a/src/grabber/grab.ts +++ b/src/grabber/grab.ts @@ -9,10 +9,23 @@ import PQueue from 'p-queue'; import { dayIn, resolveTimeZone } from '../core/days.js'; -import { emitter, type GrabCounts, watchEventLoop } from '../core/events.js'; -import type { SiteSession } from './session.js'; +import { + emitter, + keepingThrows, + noCounts, + type RequestCounts, + watchEventLoop, +} from '../core/events.js'; +import { + addRequests, + requestsObject, + siteDone, + type RequestSink, + type SiteSession, +} from './session.js'; import { SiteRun, type Run } from './site-run.js'; -import { SiteThreads, threadCount } from './thread.js'; +import { siteName } from './site.js'; +import { SiteNotRunError, SiteThreads, threadCount } from './thread.js'; import type { AnySiteConfig, GrabOptions, GrabSummary } from './types.js'; /** @@ -30,13 +43,35 @@ export async function grab(configs: AnySiteConfig[], options: GrabOptions): Prom /** * {@link grab}, carrying on with the sessions a run opened while it settled the * sites' lists — so a list fetch and the requests after it share one queue, - * one hold on a `429` and one state. A site on this thread only: a session is a - * queue and a timer, and neither crosses to a worker. + * one hold on a `429` and one state. A site on this thread carries on with its + * session; one in a thread cannot, since a session is a queue and a timer and + * neither crosses to a worker, so it is handed the session for what its list + * cost, added to its `site:done` as that passes — see `hostSite`. */ export async function grabWith( configs: AnySiteConfig[], options: GrabOptions, sessions: ReadonlyMap, +): Promise { + /** + * What a reporter throws, kept rather than let loose. Loose, it would end a + * site part way through saying what it did — counted failed on this thread, + * and not on another's — or end the process, from a thread's listener where + * nothing can catch it. Kept, the run goes on saying everything, and rejects + * with it once it has: a reporter that throws is a bug in it, and is never + * swallowed — see `combineReporters`. And once the run is done it is said + * no more, though a request a parse did not wait for is still going. + */ + const kept = keepingThrows(options); + + return kept.settle(grabbing(configs, kept.options, sessions)); +} + +/** {@link grabWith}'s run, reporting through what keeps a reporter's throws. */ +async function grabbing( + configs: AnySiteConfig[], + options: GrabOptions, + sessions: ReadonlyMap, ): Promise { // Before anything starts, rather than once per site that then cannot — it // throws when there are threads to start and no module to start them on. @@ -44,21 +79,46 @@ export async function grabWith( const timeZone = resolveTimeZone(options.timeZone); const threads = threadsWanted === 0 ? undefined : SiteThreads.for(threadsWanted, options.configModule!); - /** Every site running in a thread, so a cancelled run can wait for them — see below. */ - const inThreads: Promise[] = []; + /** + * Every site running in a thread, so a cancelled run can wait for them — and + * what hangs up on each, which tells the run what it counted: see below. + */ + const inThreads: Array void>> = []; + /** Every site running on this thread, so a cancelled run waits for them too. */ + const onThisThread: Array> = []; + /** What threw out of a site's task that was not the cancel — see below. */ + const faults: unknown[] = []; const now = options.now ?? new Date(); const emit = emitter(options); - const { cache, signal } = options; - const tally: GrabCounts = { - fetched: 0, - empty: 0, - fromCache: 0, - unchanged: 0, - failed: 0, - sitesFailed: 0, + let nameless = 0; + /** + * What a site's events call it: its name — or, for a config that left it + * out, which is refused for it, words saying so, numbered so two are two + * sites. Never `undefined`, which no reporter is promised. + */ + const nameOf = (site: unknown): string => { + try { + return siteName({ site }); + } catch { + return `a site with no name (${++nameless})`; + } + }; + /** Every request of the run, label by label, for `grab:done` — told as each is done. */ + const requests = new Map(); + const requested: RequestSink = (label, done) => { + addRequests(requests, label, done); }; + // A list settled before the run was asked for, and is counted with it — as + // is whatever is asked through the same session after, and said as the run + // says it. + for (const session of sessions.values()) { + session.joinRun({ requested, emit }); + } + const { cache, signal } = options; + const tally = noCounts(); + /** * Everything that is not a request: the staleness sweep, and parsing a * channel-day out of a response and writing it. @@ -119,26 +179,37 @@ export async function grabWith( localWork, enqueue, tally, + requested, }; // Said first, and the way a site says it when its list fails in its own turn, // so a run whose caller settled the lists reads the same as one that did not. - for (const failed of options.failedSites ?? []) { + /** + * A site that never ran — its list failed as the run settled it, or it could + * not be read — said as a site that failed running says it: `site:failed`, + * then a `site:done` whose counts are nought, save what its list cost. + */ + const unrun = (site: string, error: unknown): void => { + const session = sessions.get(site); + const named = nameOf(site); + tally.sitesFailed++; - emit({ type: 'site:failed', site: failed.site, error: failed.error }); - emit({ - type: 'site:done', - site: failed.site, - requests: 0, - ms: 0, - requestMs: 0, - fetched: 0, - empty: 0, - fromCache: 0, - unchanged: 0, - failed: 0, - sitesFailed: 1, - }); + emit({ type: 'site:failed', site: named, error }); + emit( + siteDone( + named, + // Its list was all it did, so its wall clock is its list's — waiting + // on its pacing included, which its `requestMs` leaves out. + session?.spanMs ?? 0, + // What its list cost — the `404` it was answered with included. + session?.requestsBy ?? {}, + { ...noCounts(), sitesFailed: 1 }, + ), + ); + }; + + for (const failed of options.failedSites ?? []) { + unrun(failed.site, failed.error); } const sites = new PQueue({ concurrency: Math.max(1, options.siteConcurrency ?? configs.length) }); @@ -146,42 +217,77 @@ export async function grabWith( await Promise.all( configs.map((config) => enqueue(sites, async () => { + if (threads !== undefined) { + // With what its list was settled with here, which a thread's session + // of its own would not otherwise know. + const site = threads.run(config, run, sessions.get(config.site)); + + inThreads.push(site); + + // A site its thread never ran says so as a site whose list failed + // does — and its thread says one that went part way through itself. + await site.then( + () => {}, + (error: unknown) => { + unrun(config.site, error instanceof SiteNotRunError ? error.cause : error); + }, + ); + + return; + } + + let site: SiteRun; + + // A site that cannot be resolved throws here, before it has a queue or + // a client to let go of — so nothing of it ran, as a thread says of one + // it never began. try { - // A site that cannot be resolved throws in the constructor, before it - // has a queue or a client to let go of — and one in a thread rejects - // the same way, for that or for a config its thread could not read. - if (threads === undefined) { - await new SiteRun(config, run, sessions.get(config.site)).run(); - } else { - const site = threads.run(config, run); - - inThreads.push(site); - await site; - } + site = new SiteRun(config, run, sessions.get(config.site)); } catch (error) { - // Only what the constructor threw reaches here: a site that could not - // be *read* — a missing `site`, `channels`, `request` or `parseDay` — - // which happens before it has a queue or a client to let go of. A - // site that failed while running says so itself, where it can do it - // before its own cleanup awaits anything. - // - // Its own count, not one added to the channel-days: nothing of this - // site was reached, so there is no grid to attribute it across — - // and a threshold that let a dead site pass as one lost channel-day - // would be measuring the wrong thing. - tally.sitesFailed++; - emit({ type: 'site:failed', site: config.site, error }); + unrun(config.site, error); + + return; + } + + // Never rejected: what fails in a site's turn it says itself, and what a + // reporter throws is kept. Should it be, that is heard where the run + // waits for it — see below — cancelled or not. + const running = site.run(); + + onThisThread.push(running); + await running.catch(() => {}); + }).catch((error: unknown) => { + // A site the cancel let go of, which winds down as it was. Anything + // else is a fault in this package, which fails the grab rather than + // being said of the site as something it did — once the run is done, + // as a reporter's throw does: the other sites still finish, and + // nothing of theirs is left holding the cache or the run's signal. + if (signal?.aborted !== true || error !== signal.reason) { + faults.push(error); } - }).catch(() => {}), + }), ), ); - // A cancel lets go of every site at once, and a site in its own thread is - // still winding down over there — finishing the write it started, saving its - // state, counting what it did. Waited for, so all of that lands in this - // run's summary rather than after it; a site on this thread goes on the same - // way, but has counted as it went. - await Promise.allSettled(inThreads); + // A cancel lets go of every site at once, while each is still winding down — + // finishing the write it started, saving its state, counting and saying what + // it did, here or in its own thread. Waited for, so all of that lands in this + // run's summary rather than after it, and whatever a reporter throws at it + // is still the run's to reject with. + for (const turn of await Promise.allSettled(onThisThread)) { + if (turn.status === 'rejected') { + faults.push(turn.reason); + } + } + + // And each in a thread then told the run what it counted, which a site on + // this thread has as it went: here, so a request a parse did not wait for is + // counted as far as it has got by now on either. + for (const hosted of await Promise.allSettled(inThreads)) { + if (hosted.status === 'fulfilled') { + hosted.value(); + } + } // A cancelled run is not a finished one, and the difference matters to // whoever is listening: `grab:done` is what a reporter treats as "this is @@ -189,13 +295,22 @@ export async function grabWith( // failed was dropped by the cancel itself. const loopMaxMs = await loop.worst(); + loop.stop(); + + // A fault in this package is not a run that came to what it came to: said by + // the grab rejecting, and not by a `grab:done` telling every reporter the run + // went as it should. + if (faults.length > 0) { + throw faults.length === 1 + ? faults[0] + : new AggregateError(faults, `${faults.length} sites' turns threw`); + } + emit( signal?.aborted ? { type: 'run:cancelled', fetched: tally.fetched } - : { type: 'grab:done', loopMaxMs, ...tally }, + : { type: 'grab:done', loopMaxMs, requestsBy: requestsObject(requests), ...tally }, ); - loop.stop(); - return tally; } diff --git a/src/grabber/labels.ts b/src/grabber/labels.ts new file mode 100644 index 0000000..b10218d --- /dev/null +++ b/src/grabber/labels.ts @@ -0,0 +1,16 @@ +/** + * What a run counts a request under where the site names none — see + * `RequestCounts`. Here once, so a default and the check of a site's own + * label cannot disagree; and in a module of its own, importing nothing, since + * the site, its channel list and its run all read it. + */ +export const LABELS = { + /** A channel list fetched: the run's own, so no site may name a request so. */ + channels: 'channels', + /** A planned request, where the site gives no `requestLabel`. */ + request: 'request', + /** A parse's `ctx.paced` call, where it gives no label. */ + paced: 'paced', + /** A stream's `ctx.paced` call, where neither it nor the site's `requestLabel` names one. */ + stream: 'stream', +} as const; diff --git a/src/grabber/main.ts b/src/grabber/main.ts index 1dfc968..cb85429 100644 --- a/src/grabber/main.ts +++ b/src/grabber/main.ts @@ -1,4 +1,6 @@ export { grab } from './grab.js'; +export { ReporterError, RunFailedError } from '../core/events.js'; +export type { ReporterThrow } from '../core/events.js'; export { channelElement, channelsFromChannelsXml, diff --git a/src/grabber/pacing.ts b/src/grabber/pacing.ts index b6bbf32..21f1536 100644 --- a/src/grabber/pacing.ts +++ b/src/grabber/pacing.ts @@ -69,8 +69,10 @@ export interface SitePacing { /** Its HTTP client, which reports a slow-down to the queue. */ http: KyInstance; /** - * Drop a hold that is still pending. A run that has finished must not be kept - * alive by a timer counting down a minute for requests that will never come. + * Let go of the site: a hold still pending keeps the process alive no longer + * — a run that has finished must not be kept alive by a timer counting down + * a minute — though it still ends, and lets go of a request a parse did not + * wait for; and the run's signal is listened to no more. */ dispose(): void; } @@ -110,6 +112,8 @@ export function sitePacing( const ceiling = queue.concurrency; let timer: NodeJS.Timeout | undefined; + /** Whether the site is done with this — see `dispose`. */ + let disposed = false; let holdingUntil = 0; let clean = 0; @@ -141,8 +145,15 @@ export function sitePacing( queue.pause(); emit({ type: 'pacing:held', site: config.site, status, ms: Math.round(ms) }); // Deliberately not unref'd: a run in the middle of a hold has to stay - // alive, or the process would exit with the guide half grabbed. + // alive, or the process would exit with the guide half grabbed. Save once + // the site is let go of: a hold then is a request its parse did not wait + // for, which nothing waits on either — and which a cancel, no longer + // listened for, would not end. timer = setTimeout(release, ms); + + if (disposed) { + timer.unref(); + } }; const client = siteHttp(config, options.signal); @@ -227,19 +238,27 @@ export function sitePacing( // hand out tasks that are about to be removed. The hold is dropped and the // queue left paused; each task takes itself out of it, and an emptied queue // reaches idle whether it is paused or not. - options.signal?.addEventListener( - 'abort', - () => { - clearTimeout(timer); - timer = undefined; - holdingUntil = 0; - }, - { once: true }, - ); + const cancelled = (): void => { + clearTimeout(timer); + timer = undefined; + holdingUntil = 0; + }; + + options.signal?.addEventListener('abort', cancelled, { once: true }); return { queue, http, - dispose: () => clearTimeout(timer), + // And let go of the run's signal, which may outlive the site by a while: + // what listens to it keeps all of this — the site's config, its channels + // among it — for as long as it does. + dispose: () => { + disposed = true; + // A hold under way still ends, and lets go of what it holds back — a + // request a parse did not wait for, which would otherwise wait for ever — + // but keeps nothing alive for it. + timer?.unref(); + options.signal?.removeEventListener('abort', cancelled); + }, }; } diff --git a/src/grabber/schedules-direct/client.ts b/src/grabber/schedules-direct/client.ts index 0424512..62c4e28 100644 --- a/src/grabber/schedules-direct/client.ts +++ b/src/grabber/schedules-direct/client.ts @@ -443,50 +443,71 @@ export function createSchedulesDirectClient( }, }); - /** One call: a path, a body if it takes one, and an answer of the shape asked for. */ - const request = (path: string, body?: unknown): Promise => - paced(({ signal }) => - clientWithAuth(path, { - method: body === undefined ? 'get' : 'post', - ...(body === undefined ? {} : { json: body }), - ...(signal ? { signal } : {}), - }).json(), - ); + /** + * A path, a body if it takes one, and an answer of the shape asked for — in + * whatever turn of the queue it was given. A `get`, or a `post` with a body, + * unless the call says which it is. + */ + const call = ( + path: string, + signal: AbortSignal | undefined, + sent: { body?: unknown; method?: 'put' | 'delete' } = {}, + ): Promise => + clientWithAuth(path, { + method: sent.method ?? (sent.body === undefined ? 'get' : 'post'), + ...(sent.body === undefined ? {} : { json: sent.body }), + ...(signal ? { signal } : {}), + }).json(); - /** A call that changes something, which is neither a `get` nor a `post`. */ - const change = (path: string, method: 'put' | 'delete'): Promise => - paced(({ signal }) => - clientWithAuth(path, { method, ...(signal ? { signal } : {}) }).json(), - ); + /** + * One call, in a turn of the queue of its own — a `put` or a `delete` where + * it says so, for one that changes something. + * + * `label` is what `requestsBy` counts it as — the kind of call, not its + * path, which carries a lineup's id. + */ + const request = ( + label: string, + path: string, + sent: { body?: unknown; method?: 'put' | 'delete' } = {}, + ): Promise => paced(({ signal }) => call(path, signal, sent), { label }); /** * A call whose answer is a list. * * The service answers a whole-request failure with an *object* even where * success is an array — at HTTP 200, so nothing threw and nothing but the - * shape says anything is wrong. + * shape says anything is wrong. Said inside the call's own turn, so the + * queue counts it as the failure it is. */ - const requestList = async (path: string, body: unknown): Promise => { - const answer = await request>(path, body); - - if (Array.isArray(answer)) { - return answer; - } - - throw new GrabberError(`${site}: Schedules Direct refused ${path} — ${wireMessage(answer)}`); - }; + const requestList = (label: string, path: string, body: unknown): Promise => + paced( + async ({ signal }) => { + const answer = await call>(path, signal, { body }); + + if (Array.isArray(answer)) { + return answer; + } + + throw new GrabberError( + `${site}: Schedules Direct refused ${path} — ${wireMessage(answer)}`, + ); + }, + { label }, + ); return { - status: () => request('status'), + status: () => request('status', 'status'), headends: (where) => // Its own spelling: the service takes `postalcode`, all lower case. requestList( + 'headends', `headends?${new URLSearchParams({ country: where.country, postalcode: where.postalCode }).toString()}`, undefined, ), lineups: async () => { try { - return await request('lineups'); + return await request('lineups', 'lineups'); } catch (error) { // An account with no lineups is not a failed request — the service's // own client does the same, and everything above here is already @@ -494,16 +515,21 @@ export function createSchedulesDirectClient( return refusalCode(error) === SD_NO_LINEUPS ? {} : Promise.reject(error); } }, - lineup: (id) => request(`lineups/${encodeURIComponent(id)}`), - addLineup: (id) => change(`lineups/${encodeURIComponent(id)}`, 'put'), - removeLineup: (id) => change(`lineups/${encodeURIComponent(id)}`, 'delete'), - schedulesMd5: (stations) => request('schedules/md5', stations), - schedules: (stations) => requestList('schedules', stations), - programs: (ids) => requestList('programs', ids), + lineup: (id) => request('lineups', `lineups/${encodeURIComponent(id)}`), + addLineup: (id) => + request('lineups', `lineups/${encodeURIComponent(id)}`, { method: 'put' }), + removeLineup: (id) => + request('lineups', `lineups/${encodeURIComponent(id)}`, { + method: 'delete', + }), + schedulesMd5: (stations) => + request('md5', 'schedules/md5', { body: stations }), + schedules: (stations) => requestList('schedules', 'schedules', stations), + programs: (ids) => requestList('programs', 'programs', ids), // The trailing slash is not decoration. Without it the service answers // `1008 INCORRECT_REQUEST` to every body — its own documented example // included, and with or without a token — and with it the same body is // accepted. Verified against the live service on 2026-09-17. - artwork: (ids) => requestList('metadata/programs/', ids), + artwork: (ids) => requestList('metadata', 'metadata/programs/', ids), }; } diff --git a/src/grabber/schedules-direct/main.ts b/src/grabber/schedules-direct/main.ts index 71876b6..27ce062 100644 --- a/src/grabber/schedules-direct/main.ts +++ b/src/grabber/schedules-direct/main.ts @@ -77,11 +77,16 @@ import type { WireAccountLineup, WireLineupChange } from './wire.js'; */ const MAPPING_VERSION = 1; +/** + * A site of Schedules Direct's — without `requestLabel`, since every call it + * makes names itself (`md5`, `schedules`, `programs`), and so a label for + * those that do not would name none. + */ export interface SchedulesDirectSiteOptions extends Omit< StreamSiteConfig, - 'stream' | 'channels' | 'conditionalGet' | 'dayZone' + 'stream' | 'channels' | 'conditionalGet' | 'dayZone' | 'requestLabel' >, SchedulesDirectMapOptions { username: string; diff --git a/src/grabber/session.ts b/src/grabber/session.ts index acd6c21..eb07931 100644 --- a/src/grabber/session.ts +++ b/src/grabber/session.ts @@ -14,70 +14,290 @@ */ import type { CacheStore } from '../cache/types.js'; -import type { Emit } from '../core/events.js'; +import { causes, failureOf } from '../core/error.js'; +import { + noRequests, + type Emit, + type EpgEventInput, + type GrabCounts, + type RequestCounts, +} from '../core/events.js'; import { sitePacing, type SitePacing } from './pacing.js'; +import { isUnchanged } from './revalidate.js'; import { SiteStateHandle } from './state.js'; import type { AnySiteConfig } from './types.js'; +/** Told of each request as it is done: what it was for, and what it came to. */ +export type RequestSink = (label: string, done: RequestCounts) => void; + +/** + * How many labels a site's requests may come under without a word. One more, + * and it is told a label names a kind of request, not one — each is a key of + * `requestsBy` and a name on its line, and a site naming its requests by url + * would make thousands. Told once, and every one still counted. + */ +export const MANY_LABELS = 64; + export interface SiteSession { /** The site's request queue, and the client that holds it on a `429`. */ readonly pacing: SitePacing; /** What the site remembers, read once and saved by whoever is done with it. */ readonly state: SiteStateHandle; - /** Requests sent through {@link send}, the list fetch included. */ - readonly sent: number; - /** How long they spent waiting on the source, pacing not included. */ - readonly spent: number; /** - * One request through the queue, counted and timed — handed the queue's own - * signal, which is the run's. + * Requests sent through {@link send}, the list fetch included, and how long + * they spent waiting on the source, pacing not included — by `label`, with + * what failed them: a copy, for `site:done`. {@link totalOf} adds them up. + */ + readonly requestsBy: Record; + /** + * From its first request asked for to its last answered, waiting on its + * pacing included — the wall clock of what it sent, which is a site's own + * where its requests were all it did, as a list settled before the grab's. + */ + readonly spanMs: number; + /** + * One request through the queue, counted and timed under `label` — handed + * the queue's own signal, which is the run's. * * Timed from inside the task rather than from the call, as `request:done` is: * what a site waited for a slot is pacing, not the source, and adding it in * would make a site paced to one request a second look like a site answering - * in a second. + * in a second. Counted as its turn comes, so one a cancel dropped before it + * is not, and one under way when the cancel came is; its time and how it + * failed once it is done. A failure is read where the task throws it, so a + * `404` the site goes on to catch is counted all the same. */ send( task: (slot: { signal?: AbortSignal | undefined }) => Promise, - options?: { priority?: number }, + options: { label: string; priority?: number }, ): Promise; + /** + * Be part of `run` from here: its `requested` told what has been counted so + * far, and of every request after, and its `emit` what the session says — for + * a session opened before the run it reports to, as one settling a channel + * list is. + */ + joinRun(run: { requested: RequestSink; emit: Emit }): void; +} + +/** + * Add `done` to what `into` holds under `label`. A `Map`, so a label that + * happens to be `constructor` is a name like any other, not something every + * object already has. + */ +export function addRequests( + into: Map, + label: string, + done: RequestCounts, +): void { + let total = into.get(label); + + if (total === undefined) { + total = noRequests(); + into.set(label, total); + } + + total.requests += done.requests; + total.requestMs += done.requestMs; + + for (const [failure, n] of Object.entries(done.failed)) { + total.failed[failure] = (total.failed[failure] ?? 0) + n; + } +} + +/** + * Tell `sink` of every label, in order. What it is told it does not keep — + * see {@link addRequests} — so it is handed the counts as they are. + */ +export function tellAll(sink: RequestSink, counted: Iterable<[string, RequestCounts]>): void { + for (const [label, counts] of counted) { + sink(label, counts); + } +} + +/** What requests came to, every label together. */ +export function totalOf(counted: Iterable): { requests: number; requestMs: number } { + let requests = 0; + let requestMs = 0; + + for (const counts of counted) { + requests += counts.requests; + requestMs += counts.requestMs; + } + + return { requests, requestMs }; +} + +/** A site's `site:done`: its requests added up from `requestsBy`, beside its channel-days. */ +export function siteDone( + site: string, + ms: number, + requestsBy: Record, + counts: GrabCounts, +): Extract { + const { requests, requestMs } = totalOf(Object.values(requestsBy)); + // The counts and nothing else, whatever else `counts` holds — an event. + const { fetched, empty, fromCache, unchanged, failed, sitesFailed } = counts; + + return { + type: 'site:done', + site, + requests, + ms, + requestMs, + requestsBy, + fetched, + empty, + fromCache, + unchanged, + failed, + sitesFailed, + }; +} + +/** Several `requestsBy` as one, label by label — each label where it first came. */ +export function mergedRequests( + ...from: Array> +): Record { + const by = new Map(); + + for (const requestsBy of from) { + for (const [label, counts] of Object.entries(requestsBy)) { + addRequests(by, label, counts); + } + } + + return requestsObject(by); +} + +/** What `by` holds, as an event carries it: copies, which go on saying what they said. */ +export function requestsObject(by: Map): Record { + return Object.fromEntries( + [...by].map(([label, { requests, requestMs, failed }]) => [ + label, + { requests, requestMs, failed: { ...failed } }, + ]), + ); +} + +/** + * Whether `error` is the run's cancel, as a request it interrupted throws it: + * the cancel's reason, or an `AbortError` — itself, or beneath what a site + * wrapped it in. Not what a source answered as the cancel came, which is a + * failure like any other. + */ +function cancelledBy(signal: AbortSignal | undefined, error: unknown): boolean { + if (signal?.aborted !== true) { + return false; + } + + for (const link of causes(error)) { + if (link === signal.reason || (link as { name?: unknown } | null)?.name === 'AbortError') { + return true; + } + } + + return false; +} + +/** + * What a request's failure is counted as — nothing, for one that is not the + * source's: the run's cancel, or a `304` saying what is cached still stands. + * + * Read off whatever the site threw, which may be anything — a getter that + * throws, a revoked proxy — so a value it cannot read is `error`, and what the + * site sees is always what it threw, never what counting it threw. + */ +function failureFor(error: unknown, signal: AbortSignal | undefined): string | undefined { + try { + return cancelledBy(signal, error) || isUnchanged(error) ? undefined : failureOf(error); + } catch { + return 'error'; + } } /** A session for one site — see {@link SiteSession}. */ export function openSession( config: AnySiteConfig, cache: CacheStore, - options: { signal?: AbortSignal | undefined; emit?: Emit } = {}, + options: { + signal?: AbortSignal | undefined; + emit?: Emit; + /** The run's, told of each request as it is done — see {@link SiteSession.joinRun}. */ + counted?: RequestSink; + } = {}, ): SiteSession { + /** Whoever is told what the session says: the run's, once it has joined one. */ + let say = options.emit; const pacing = sitePacing(config, { ...(options.signal ? { signal: options.signal } : {}), - ...(options.emit ? { emit: options.emit } : {}), + emit: (event) => say?.(event), }); - let sent = 0; - let spent = 0; + /** By label, in the order each was first sent — which is the order they are reported in. */ + const by = new Map(); + let sink = options.counted; + /** When the first request was asked for, and when the last was answered — see `spanMs`. */ + let asked: number | undefined; + let answered: number | undefined; + + /** Count what a request under `label` came to, here and for whoever is told. */ + const count = (label: string, done: RequestCounts): void => { + // The first label over, about to be counted. + if (by.size === MANY_LABELS && !by.has(label)) { + say?.({ + type: 'site:warning', + site: config.site, + message: + `its requests have come under more than ${MANY_LABELS} labels — a label names a ` + + `kind of request, such as detail, not one request: each is counted apart, in ` + + `site:done and on its line`, + }); + } + + addRequests(by, label, done); + sink?.(label, done); + }; return { pacing, state: SiteStateHandle.open(cache, config.site), - get sent() { - return sent; + get requestsBy() { + return requestsObject(by); }, - get spent() { - return spent; + get spanMs() { + return asked === undefined || answered === undefined ? 0 : answered - asked; }, - send: (task, sending = {}) => { - sent += 1; + joinRun(run) { + tellAll(run.requested, by); + sink = run.requested; + say = run.emit; + }, + send: (task, { label, ...sending }) => { + asked ??= Date.now(); // The run's signal on every task, as the run's own queues have it: a // waiting request is dropped on a cancel rather than started. return pacing.queue.add( async (slot) => { + // Sent now — and so listed in the order each label was first sent. + count(label, { requests: 1, requestMs: 0, failed: {} }); + const began = Date.now(); + let failure: string | undefined; try { return await task(slot); + } catch (error) { + failure = failureFor(error, options.signal); + + throw error; } finally { - spent += Date.now() - began; + answered = Date.now(); + count(label, { + requests: 0, + requestMs: answered - began, + failed: failure === undefined ? {} : { [failure]: 1 }, + }); } }, { ...sending, ...(options.signal ? { signal: options.signal } : {}) }, diff --git a/src/grabber/shared-counts.ts b/src/grabber/shared-counts.ts new file mode 100644 index 0000000..e4bbdf0 --- /dev/null +++ b/src/grabber/shared-counts.ts @@ -0,0 +1,230 @@ +/** + * A threaded site's counts, in memory its thread and the run's both see — so a + * thread that dies has lost none of what it counted, and nothing of the + * counting crosses as a message but each request count's name, once. + * + * When its thread began on it takes the first slot, and its channel-day counts + * — `GrabCounts` — the ones after: always the same slots, which need no name, + * and which the run's thread sees as soon as they are written — so a thread + * that dies leaves no doubt whether the site had begun, or had counted itself + * failed. After them, a label is given two slots + * side by side when it is first counted, for the + * two counts every label has — its `requests`, then its `requestMs` — and a + * kind of failure one of its own when it first fails that way: those are the + * names said. The site's thread alone adds to them, and the run's reads them + * when the site is done, or its thread gone. Counts it has no slot left for — + * a site of more labels and failures than {@link SLOTS} holds — are handed + * back for the thread to say another way. + */ + +import { noRequests, type GrabCounts, type RequestCounts } from '../core/events.js'; +import { addRequests } from './session.js'; + +/** How many counts a site's memory holds: far more than any site names. */ +export const SLOTS = 1024; + +/** Where in a site's memory each thing is that is always there, before any label's slots. */ +const Slot = { + /** When the site's thread began on it — nought, until it has. */ + BEGAN: 0, + /** Where the channel-day counts start, in the order of {@link TALLIED}. */ + TALLY: 1, +} as const; + +/** + * The channel-day counts, in the order of their slots from {@link Slot.TALLY}: + * every one of `GrabCounts`, which `count` and `tally` do not compile without. + */ +const TALLIED = [ + 'fetched', + 'empty', + 'fromCache', + 'unchanged', + 'failed', + 'sitesFailed', +] as const satisfies ReadonlyArray; + +/** + * What a slot counts: a label — its `requests` there, and its `requestMs` in + * the slot after — or, with `failure`, how many of its requests failed so. + */ +export interface SlotName { + label: string; + /** Which failure — see `RequestCounts.failed`. */ + failure?: string; +} + +/** Memory for one site's counts, to hand its thread and keep a {@link CountReader} on. */ +export function sharedCounts(): SharedArrayBuffer { + return new SharedArrayBuffer(SLOTS * BigInt64Array.BYTES_PER_ELEMENT); +} + +/** The site's thread's side: each count added in place, each new slot named once. */ +export class CountWriter { + readonly #view: BigInt64Array; + readonly #name: (index: number, slot: SlotName) => void; + /** + * Where each label's two counts are — nowhere, once there was no room — and + * each of its kinds of failure: looked up by the label's own string, so a + * slot already named costs a request nothing to find. + */ + readonly #slots = new Map< + string, + { at: number | undefined; failed: Map } + >(); + /** The first slot nothing counts in yet: when it began, and the channel-day counts, have theirs. */ + #free = Slot.TALLY + TALLIED.length; + + constructor(buffer: SharedArrayBuffer, name: (index: number, slot: SlotName) => void) { + this.#view = new BigInt64Array(buffer); + this.#name = name; + } + + /** Say the site begun on, and when: from here, a thread that dies may have run some of it. */ + begin(at = Date.now()): void { + Atomics.store(this.#view, Slot.BEGAN, BigInt(at)); + } + + /** Add `delta` to a channel-day count — less, as an empty day that then is not. */ + count(field: keyof GrabCounts, delta: number): void { + const at = TALLIED.indexOf(field); + + // Said, rather than added to the slot before the first: when it began. + if (at === -1) { + throw new TypeError(`No channel-day count is called ${String(field)}`); + } + + Atomics.add(this.#view, Slot.TALLY + at, BigInt(delta)); + } + + /** + * Add what `done` says of `label` — and answer what there was no slot for, + * where anything, for the caller to say another way. + */ + add(label: string, done: RequestCounts): RequestCounts | undefined { + let left: RequestCounts | undefined; + /** Slots this call took, named once what it adds is in them — see {@link #take}. */ + let taken: Array<[number, SlotName]> | undefined; + let slots = this.#slots.get(label); + + if (slots === undefined) { + slots = { at: this.#take(2), failed: new Map() }; + this.#slots.set(label, slots); + + if (slots.at !== undefined) { + (taken ??= []).push([slots.at, { label }]); + } + } + + if (slots.at === undefined) { + left = { requests: done.requests, requestMs: done.requestMs, failed: {} }; + } else { + Atomics.add(this.#view, slots.at, BigInt(done.requests)); + Atomics.add(this.#view, slots.at + 1, BigInt(done.requestMs)); + } + + for (const failure in done.failed) { + // Its own, and not what anything put on every object. + if (!Object.hasOwn(done.failed, failure)) { + continue; + } + + const n = done.failed[failure]!; + let index = slots.failed.get(failure); + + if (index === undefined && !slots.failed.has(failure)) { + index = this.#take(1); + slots.failed.set(failure, index); + + if (index !== undefined) { + (taken ??= []).push([index, { label, failure }]); + } + } + + if (index === undefined) { + left ??= noRequests(); + left.failed[failure] = (left.failed[failure] ?? 0) + n; + } else { + Atomics.add(this.#view, index, BigInt(n)); + } + } + + for (const [index, slot] of taken ?? []) { + this.#name(index, slot); + } + + return left; + } + + /** + * `size` slots, or none, where there is no room left — named by the caller, + * and only once what it adds is in them: the run's thread may read a slot + * the moment it hears its name, and for the last time, as the run hangs up. + */ + #take(size: number): number | undefined { + if (this.#free + size > SLOTS) { + return undefined; + } + + const index = this.#free; + + this.#free += size; + + return index; + } +} + +/** The run's thread's side: what each slot counts, as it is told, and what they hold. */ +export class CountReader { + /** The memory, to hand the site's thread. */ + readonly buffer: SharedArrayBuffer; + readonly #view: BigInt64Array; + readonly #names: SlotName[] = []; + + constructor(buffer = sharedCounts()) { + this.buffer = buffer; + this.#view = new BigInt64Array(buffer); + } + + /** When the site's thread began on it, if it has. */ + began(): number | undefined { + const at = Number(Atomics.load(this.#view, Slot.BEGAN)); + + return at === 0 ? undefined : at; + } + + /** What the slot at `index` counts, as the site's thread said when it began counting there. */ + named(index: number, slot: SlotName): void { + this.#names[index] = slot; + } + + /** The channel-day counts, as they stand. */ + tally(): GrabCounts { + return Object.fromEntries( + TALLIED.map((field, at) => [field, Number(Atomics.load(this.#view, Slot.TALLY + at))]), + ) as Record<(typeof TALLIED)[number], number>; + } + + /** + * What the site counted, by label, in the order each was first counted. A + * slot whose name has not been heard is not read: there is no saying what + * it counts. + */ + read(): Map { + const by = new Map(); + const at = (index: number): number => Number(Atomics.load(this.#view, index)); + + // Each slot read once, so adding what it holds is setting it. + this.#names.forEach((slot, index) => { + addRequests( + by, + slot.label, + slot.failure === undefined + ? { requests: at(index), requestMs: at(index + 1), failed: {} } + : { requests: 0, requestMs: 0, failed: { [slot.failure]: at(index) } }, + ); + }); + + return by; + } +} diff --git a/src/grabber/site-run.ts b/src/grabber/site-run.ts index f27be4a..57d057d 100644 --- a/src/grabber/site-run.ts +++ b/src/grabber/site-run.ts @@ -23,7 +23,8 @@ import PQueue from 'p-queue'; import { isStale } from '../cache/main.js'; import type { CacheStore } from '../cache/types.js'; import { count } from '../core/count.js'; -import type { Emit, GrabCounts } from '../core/events.js'; +import { errorMessage } from '../core/error.js'; +import { noCounts, type Emit, type GrabCounts } from '../core/events.js'; import { ProgrammeBuilder } from '../xmltv/builder.js'; import type { XmltvProgramme } from '../xmltv/types.js'; import { resolveChannels } from './channels.js'; @@ -39,8 +40,9 @@ import { type Revalidation, type Validator, } from './revalidate.js'; -import { openSession, type SiteSession } from './session.js'; -import { resolveSite, type ResolvedSite } from './site.js'; +import { LABELS } from './labels.js'; +import { openSession, siteDone, type RequestSink, type SiteSession } from './session.js'; +import { pacedLabels, resolveSite, type ResolvedSite } from './site.js'; import { StateKey, TrackedMap, type SiteStateHandle } from './state.js'; import type { AnySiteConfig, @@ -85,8 +87,17 @@ export interface Run { /** The run-wide queue for work that never leaves the machine. */ localWork: PQueue; enqueue: Enqueue; - /** What the run has counted so far — a site adds to it as it goes. */ + /** + * What the run has counted so far — a site adds to it as it goes, and one in + * a thread of its own as its turn ends, from the memory it counted in. + */ tally: GrabCounts; + /** + * Told of each request as it is done, for `grab:done`'s `requestsBy` — as + * {@link tally} is told of each count, so a site that never says `site:done` + * has still said what it asked. + */ + requested: RequestSink; } /** A parse may hand back either form; the cache only knows the object. */ @@ -119,6 +130,8 @@ export class SiteRun { * fortnight was building fourteen thousand of these to hand out. */ readonly #says: Pick; + /** What each `paced` call is counted as — see {@link pacedLabels}. */ + readonly #pacedLabel: ReturnType; /** * The site's queue, client and state for this run — handed over by a run that @@ -176,15 +189,13 @@ export class SiteRun { */ /** When this site's turn began, for the wall clock the session's two are not. */ #began = 0; + /** + * How long its list took to settle, where a session the run settled it + * through was handed on: its turn too, though before this one began. + */ + readonly #settledMs: number; - readonly #counts: GrabCounts = { - fetched: 0, - empty: 0, - fromCache: 0, - unchanged: 0, - failed: 0, - sitesFailed: 0, - }; + readonly #counts = noCounts(); /** Filled in by {@link run}, since each of them has to be waited for. */ #siteState: SiteState = new Map(); @@ -209,6 +220,7 @@ export class SiteRun { warn: (message, data) => run.emit({ type: 'site:warning', site: resolved.site, message, ...(data ? { data } : {}) }), }; + this.#pacedLabel = pacedLabels(this.#site, this.#says.warn); // The queue and the client together: the signal rides on the instance, so // every call a site makes through it is abortable without the site having to @@ -218,11 +230,13 @@ export class SiteRun { // the work its response is for. That is what its `concurrency`, `rateLimit` // and backoff are about, and keeping it to that is what lets a `parseDay` ask // for a request of its own. + this.#settledMs = session?.spanMs ?? 0; this.#session = session ?? openSession(config, run.cache, { ...(run.signal ? { signal: run.signal } : {}), emit: run.emit, + counted: run.requested, }); this.#http = this.#session.pacing.http; this.#state = this.#session.state; @@ -267,7 +281,7 @@ export class SiteRun { */ #sending( task: (options: { signal?: AbortSignal | undefined }) => Promise, - options?: { priority?: number }, + options: { label: string; priority?: number }, ): Promise { return this.#session.send(task, options); } @@ -290,41 +304,62 @@ export class SiteRun { */ async run(): Promise { this.#began = Date.now(); + let failed = false; try { await this.#work(); } catch (error) { - // Counted and said here rather than left to the run, and that ordering is - // load-bearing: p-queue rejects a cancelled task's promise while the task - // itself carries on, so the summary can be read the moment the cancel - // lands. Anything recorded after the awaits below would be recorded into a - // total nobody is going to read. + // Counted and said here, the moment it fails, rather than left to the + // run: what the site says of itself is the one account of it, and the + // run waits for every site's turn — cancelled or not — before it adds + // them up. // The site's own count, not one of its channel-days: what failed here is // the site — its channel list, or its whole turn — and none of the grid // it would have covered was ever asked for. + failed = true; this.#count('sitesFailed'); this.#run.emit({ type: 'site:failed', site: this.#site, error }); } finally { this.#session.pacing.dispose(); + // Beside `dispose`, and for the same reason: a site that threw, or was // cancelled part way, has as much to hand back as one that finished — the // channel list it fetched, and whatever its own code remembered. Only the // groups that changed are written. What the site remembered is pruned // first, so a site that no longer asks stops keeping what it kept. - await this.#memory.prune(); - await this.#state.save(); - // For a failed site too, where every count is nought — which is the truth, - // and reads correctly beside the `site:failed` that says why. - this.#run.emit({ - type: 'site:done', - site: this.#site, - requests: this.#session.sent, - // Wall clock, which is the one a nightly run is long by — and nothing - // like the sum below once a site runs several requests at once. - ms: Date.now() - this.#began, - requestMs: this.#session.spent, - ...this.#counts, - }); + // + // Said here rather than thrown, should it fail: the run then counts the + // site once, and hears its `site:done` either way. A site that had not + // failed has now; one that had is told so beside why. + try { + await this.#memory.prune(); + await this.#state.save(); + } catch (error) { + if (failed) { + this.#run.emit({ + type: 'site:warning', + site: this.#site, + message: `what it remembered could not be saved either: ${errorMessage(error)}`, + }); + } else { + this.#count('sitesFailed'); + this.#run.emit({ type: 'site:failed', site: this.#site, error }); + } + } + + // For a failed site too, with what it did count — nought, where it + // failed before it began — and beside the `site:failed` that says why. + this.#run.emit( + siteDone( + this.#site, + // Wall clock, which is the one a nightly run is long by — and + // nothing like its `requestMs` once a site runs several requests at + // once. + Date.now() - this.#began + this.#settledMs, + this.#session.requestsBy, + this.#counts, + ), + ); } } @@ -360,7 +395,7 @@ export class SiteRun { refresh: this.#resolved.staleness.refetchAll, now: this.#run.now, timeZone: this.#run.timeZone, - paced: (fetch) => this.#sending(fetch), + paced: (fetch) => this.#sending(fetch, { label: LABELS.channels }), }); const stale = await this.#collectStale(); @@ -403,6 +438,9 @@ export class SiteRun { // Everything this site does happens inside one of those pipelines — the // fetch, the parse, the write, and any request a parse made of its own — // and none of them is ever abandoned, so this is the site being done. + // A request a parse asked for and did not wait on is not waited on here + // either: one that never settles would hold the run for ever. It is counted + // when it is done — after this site's `site:done`, if it is still going. await this.#pipelines.onIdle(); } @@ -670,7 +708,12 @@ export class SiteRun { // A request of the parse's own goes through the site's queue, like // the request being parsed did — ahead of the planned ones, so a // channel-day in hand is finished rather than joined by another. - paced: (task) => slot.away(() => this.#sending(task, { priority: 1 })), + paced: (task, options) => { + // Asked before the slot is, so a label that is none throws here. + const label = this.#pacedLabel(options, LABELS.paced); + + return slot.away(() => this.#sending(task, { priority: 1, label })); + }, away: (wait) => slot.away(wait), }), ); @@ -815,31 +858,36 @@ export class SiteRun { // work for the first request of a site and silently for none of the rest. // Around the site's call and nothing else, which is also what keeps a // request made later from inside `parseDay` out of it. - payload = await this.#sending(({ signal: taskSignal }) => { - // Timed from inside the task, so what is reported is the request rather - // than the wait for a slot — a site paced to one request a second would - // otherwise report every request as having taken a second. - this.#run.emit({ type: 'request:started', site: this.#site, ...span }); - - const began = Date.now(); - - // No ambient store for a site that never asks: the hooks are not even - // installed, and an `AsyncLocalStorage` context per request is a real - // cost for a `none`-batched site with one request per channel-day. - const fetch = (): Promise => - config.request(requestContext(request, this.#resolved.batching, this.#deps(taskSignal))); - - return (this.#revalidates ? revalidation.run(asking, fetch) : fetch()).then((raw) => { - this.#run.emit({ - type: 'request:done', - site: this.#site, - ...span, - ms: Date.now() - began, + payload = await this.#sending( + ({ signal: taskSignal }) => { + // Timed from inside the task, so what is reported is the request rather + // than the wait for a slot — a site paced to one request a second would + // otherwise report every request as having taken a second. + this.#run.emit({ type: 'request:started', site: this.#site, ...span }); + + const began = Date.now(); + + // No ambient store for a site that never asks: the hooks are not even + // installed, and an `AsyncLocalStorage` context per request is a real + // cost for a `none`-batched site with one request per channel-day. + const fetch = (): Promise => + config.request( + requestContext(request, this.#resolved.batching, this.#deps(taskSignal)), + ); + + return (this.#revalidates ? revalidation.run(asking, fetch) : fetch()).then((raw) => { + this.#run.emit({ + type: 'request:done', + site: this.#site, + ...span, + ms: Date.now() - began, + }); + + return raw; }); - - return raw; - }); - }); + }, + { label: this.#resolved.requestLabel }, + ); // The run's own, and a different question: was this cancelled while it was // in flight? p-queue's task signal governs the slot, not the work in it, so // stopping is ours to do — and what it stops here is a response already paid @@ -932,7 +980,11 @@ export class SiteRun { ...this.#deps(signal), // As a parse's is, and ahead of the planned ones for the same // reason: a pass already under way is finished rather than joined. - paced: (task) => this.#sending(task, { priority: 1 }), + paced: (task, options) => + this.#sending(task, { + priority: 1, + label: this.#pacedLabel(options, this.#resolved.requestLabel), + }), // A pass holds no slot while it runs, so it waits as it is. away: (wait) => wait(), }), diff --git a/src/grabber/site.ts b/src/grabber/site.ts index 4c2e36e..880bfc4 100644 --- a/src/grabber/site.ts +++ b/src/grabber/site.ts @@ -11,11 +11,14 @@ import { DEFAULT_STALENESS } from '../cache/main.js'; import type { StalenessPolicy } from '../cache/types.js'; import { sameClock } from '../xmltv/zone.js'; import { dayIn, dayRange, daysCovering, resolveTimeZone } from '../core/days.js'; +import { errorMessage } from '../core/error.js'; import { resolveBatching, type ResolvedBatching } from './planner.js'; +import { LABELS } from './labels.js'; import type { AnySiteConfig, BatchingOption, GrabOptions, + PacedOptions, SiteConfig, StreamSiteConfig, } from './types.js'; @@ -54,6 +57,11 @@ interface ResolvedSiteBase { batching: ResolvedBatching; /** When a cached day counts as stale: run policy under site override. */ staleness: StalenessPolicy; + /** + * What its own requests are counted as: its `requestLabel`, or `request` — + * `stream`, for a stream's `paced` calls that give no label. + */ + requestLabel: string; } /** A site that fetches a request at a time and parses each channel-day out of it. */ @@ -87,6 +95,11 @@ function received(value: unknown): string { return 'null'; } + // The one string a check for a non-empty one refuses, said as itself. + if (value === '') { + return 'an empty string'; + } + if (Array.isArray(value)) { return 'an array'; } @@ -96,6 +109,168 @@ function received(value: unknown): string { return kind === 'undefined' ? 'undefined' : `${kind === 'object' ? 'an' : 'a'} ${kind}`; } +/** + * What reads as one name on the text line — `(request 49, detail 5242: 3242 + * × 404)` — and so what a label may be: a word, or words joined by `.`, `_`, + * `/` or `-`, in any script — a letter's combining marks with it, as a vowel + * sign or a decomposed accent is. A space, a comma or a colon would read as the + * line's own. + */ +const LABEL = /^[\p{L}\p{N}][\p{L}\p{M}\p{N}]*(?:[._/-][\p{L}\p{N}][\p{L}\p{M}\p{N}]*)*$/u; + +/** + * A letter, which a label must have one of: `404` beside a status would read + * as one, and a key of digits alone is put first in any object, whatever + * order it was sent in. + */ +const LETTER = /\p{L}/u; + +/** + * A label a site gave its requests, where it is one — `what` says where it was + * given. A name on the text line and a key in `requestsBy`: an empty one would + * read as a gap there, a number would be one key here and another there and + * read as a status, and `channels` would count the site's requests as the + * run's list fetch. + * + * Answered composed (NFC): a word written with an accent of its own and one + * written with a combining mark print alike, and are one label. + */ +export function labelOf(site: string, label: unknown, what: string): string { + if (typeof label !== 'string' || !LABEL.test(label) || !LETTER.test(label)) { + throw new RefusedLabel( + `Site "${site}": ${what} names what requests are for, as a word — letters and digits, ` + + `a letter among them, joined by . _ / or - (got ${ + typeof label === 'string' && label !== '' ? JSON.stringify(label) : received(label) + })`, + typeof label === 'string' ? 'a string that is no word' : received(label), + ); + } + + const composed = label.normalize('NFC'); + + if (composed === LABELS.channels) { + throw new RefusedLabel( + `Site "${site}": ${what} cannot be "${LABELS.channels}", which is what a run counts a ` + + `fetched channel list as`, + `"${LABELS.channels}"`, + ); + } + + return composed; +} + +/** + * A label {@link labelOf} refused, and which mistake it was — not which value: + * a site making its labels from what each request is for makes the same + * mistake with a new one every time, and is told of it once. + */ +class RefusedLabel extends TypeError { + readonly mistake: string; + + constructor(message: string, mistake: string) { + super(message); + this.mistake = mistake; + } +} + +/** How many labels a site's `paced` calls are checked once each, rather than at every call. */ +const CHECKED_LABELS = 256; + +/** + * What a `ctx.paced` call is counted as: the label its options give, checked, + * or `fallback` where they give none. One for the site, so a label is checked + * once for the whole of its run, and every context's `paced` asks it — a + * closure of the context's own, and nothing more, per channel-day. + * + * A label that is no label is a mistake in the site's code rather than a + * request that failed, so `paced` is to ask before it returns: it throws where + * `paced` is called — not as the call's rejection, which a `.catch` meant for + * a `404` would swallow — and is said once, through `warn`, beside: a `try` + * around the `await` catches what is thrown, and with it every request the + * site meant to send. + */ +export function pacedLabels( + site: string, + warn: (message: string) => void, +): (options: PacedOptions | undefined, fallback: string) => string { + // A site sends thousands under a handful of labels: each is checked once, + // and kept as it is counted. + const checked = new Map(); + const said = new Set(); + + /** + * Throw `error`, said once for the `kind` of mistake it is — not for each + * value: a label made from what each request is for, a url or an object + * built for the call, is a new one every time, and would be said for every + * request the site meant to send. + */ + function refuse(kind: string, error: unknown): never { + if (!said.has(kind)) { + said.add(kind); + warn(`${errorMessage(error)} — no request is sent with it`); + } + + throw error; + } + + return (options, fallback) => { + // A label handed as it is, where its options go — `paced(task, 'detail')` + // — would otherwise be no label at all, and counted as the fallback. + if ( + options !== undefined && + (typeof options !== 'object' || options === null || Array.isArray(options)) + ) { + refuse( + `options that are ${received(options)}`, + new TypeError( + `Site "${site}": a paced request's options are an object, such as ` + + `{ label: 'detail' } (got ${received(options)})`, + ), + ); + } + + const label = options?.label; + + if (label === undefined) { + return fallback; + } + + let counted = checked.get(label); + + if (counted === undefined) { + try { + counted = labelOf(site, label, "a paced request's label"); + } catch (error) { + refuse(`a label that is ${(error as RefusedLabel).mistake}`, error); + } + + // Kept for the next time, while there are few: a site naming its + // requests one by one would otherwise keep every name it made. + if (checked.size < CHECKED_LABELS) { + checked.set(label, counted); + } + } + + return counted; + }; +} + +/** + * A site's name — its cache namespace, and what every event says it as — or a + * throw saying it has none: a site refused for it, as one that cannot be told + * from another. + */ +export function siteName(config: { site?: unknown }): string { + if (typeof config.site !== 'string' || config.site === '') { + throw new TypeError( + `A site must define site: a non-empty string, unique to it, naming its cache namespace ` + + `(got ${received(config.site)})`, + ); + } + + return config.site; +} + /** * Resolve one site against the run: check what it must bring, then settle every * default in one pass. @@ -125,12 +300,7 @@ export function resolveSite( /** The run's "now", which decides a leading day the site is not asked for — see {@link siteWindow}. */ now?: Date, ): ResolvedSite { - if (typeof config.site !== 'string' || config.site === '') { - throw new TypeError( - `A site must define site: a non-empty string, unique to it, naming its cache namespace ` + - `(got ${received(config.site)})`, - ); - } + siteName(config); if (typeof config.channels !== 'function' && !Array.isArray(config.channels)) { throw new TypeError( @@ -151,6 +321,11 @@ export function resolveSite( resolveTimeZone(config.dayZone, `Site "${config.site}" dayZone`); } + const requestLabel = + config.requestLabel === undefined + ? undefined + : labelOf(config.site, config.requestLabel, 'requestLabel'); + const common = { site: config.site, window: siteWindow( @@ -190,6 +365,7 @@ export function resolveSite( // channel-day. So the planner needs no idea that this site is different. batching: resolveBatching({ mode: 'both' }), isStreaming: true, + requestLabel: requestLabel ?? LABELS.stream, config, }; } @@ -215,6 +391,7 @@ export function resolveSite( ...common, batching: resolveBatching(config.batching), isStreaming: false, + requestLabel: requestLabel ?? LABELS.request, config, }; } diff --git a/src/grabber/thread.ts b/src/grabber/thread.ts index bb2d2e6..d7c8416 100644 --- a/src/grabber/thread.ts +++ b/src/grabber/thread.ts @@ -30,8 +30,10 @@ * plain on the way, since copying one keeps neither its name nor anything a * library hung on it. * - **cancelling**, as a message the worker turns back into an abort. - * - **the counts**, as they are counted, so a site that never finishes has - * still said what it did. + * - **the counts**, in memory both threads see rather than as messages: a + * site that never finishes has still counted what it did, and a thread + * that dies cannot take any of it with it — nor leave the run unsure whether + * it had begun, or had counted itself failed. * * What a worker runs is `thread-worker.ts`, a file of its own and an entry of * the build of its own: started by its URL, so it runs that and nothing a @@ -40,16 +42,32 @@ import { availableParallelism } from 'node:os'; import { pathToFileURL } from 'node:url'; +import { inspect } from 'node:util'; import { MessageChannel, Worker } from 'node:worker_threads'; import PQueue from 'p-queue'; import { CacheManager } from '../cache/manager.js'; import { CODECS, fromLine, toLine, type CodecName } from '../cache/codec.js'; import type { CacheStore, ChannelDayKey } from '../cache/types.js'; import { resolveConfigSource, type ConfigSource, type EpgConfig } from '../config.js'; -import { MAX_CAUSE_DEPTH } from '../core/error.js'; -import type { EpgEventInput, GrabCounts } from '../core/events.js'; +import { errorMessage, MAX_CAUSE_DEPTH } from '../core/error.js'; +import { + noCounts, + noRequests, + type EpgEventInput, + type GrabCounts, + type RequestCounts, +} from '../core/events.js'; import type { XmltvProgramme } from '../xmltv/types.js'; import { assertPlainData } from './channels.js'; +import { + addRequests, + mergedRequests, + requestsObject, + siteDone, + tellAll, + type SiteSession, +} from './session.js'; +import { CountReader, CountWriter, type SlotName } from './shared-counts.js'; import { SiteRun, type Enqueue, type Run } from './site-run.js'; import type { AnySiteConfig, GrabberChannel } from './types.js'; @@ -73,6 +91,8 @@ export interface SiteThreadData { localConcurrency: number; /** The codec the run's store keeps its entries with, when a thread has it — see `CacheManager.codecName`. */ codec?: CodecName; + /** The memory its request counts go in, which the run's thread reads — see `shared-counts.ts`. */ + counts: SharedArrayBuffer; } /** Either end of the conversation: a worker, its `parentPort`, or a channel's port. */ @@ -80,7 +100,29 @@ export interface SitePort { /** With what it hands over rather than copies — none, as often as not. */ postMessage(value: unknown, transfer: ArrayBuffer[]): void; on(event: 'message', listener: (value: any) => void): unknown; + /** + * Its other end gone — after every message it sent, which a port hands over + * before it says so: measured for a thread that threw, exited, was stopped + * or ran out of memory. + */ + on(event: 'close', listener: () => void): unknown; off(event: 'message', listener: (value: any) => void): unknown; + off(event: 'close', listener: () => void): unknown; +} + +/** + * A site a thread never ran — refused before it began: a config its thread + * could not read, a site that could not be resolved, a list no thread can be + * handed — and why, as its `cause`. So the run can say of it what it says of + * such a site on its own thread, which a thread that dies part way through a + * site cannot be taken for. + */ +export class SiteNotRunError extends Error { + override readonly name = 'SiteNotRunError'; + + constructor(cause: unknown) { + super(errorMessage(cause), { cause }); + } } /** The cache's methods, which is all the worker's store asks the main thread. */ @@ -89,8 +131,12 @@ type CacheOp = Exclude | 'writeEncoded'; type ToHost = | { kind: 'event'; event: EpgEventInput } | { kind: 'cache'; id: number; op: CacheOp; args: unknown[] } - | { kind: 'count'; field: keyof GrabCounts; delta: number } + /** What a slot of the site's shared counts counts, said once — see `shared-counts.ts`. */ + | { kind: 'slot'; index: number; slot: SlotName } + /** Counts there was no slot left for, said instead. */ + | { kind: 'requested'; label: string; done: RequestCounts } | { kind: 'done' } + /** Whether any of it ran first is in its shared counts — see `CountWriter.begin`. */ | { kind: 'failed'; error: unknown }; type ToWorker = @@ -113,25 +159,36 @@ interface PlainError { * A copy of an `Error` keeps its message, its stack and its cause, but its name * only when it is one of the language's own — so ky's `HTTPError` would arrive * as `Error` — and nothing else a library put on it. Anything that is not an - * error crosses as it is. + * error crosses as it is — or, where no thread can be handed it, as + * {@link send} makes it. */ function plain(error: unknown, depth = 0): unknown { - if (!(error instanceof Error)) { - return error; - } - - const { code } = error as { code?: unknown }; + try { + if (!(error instanceof Error)) { + return error; + } - return { - kind: 'error', - name: error.name, - message: error.message, - ...(error.stack === undefined ? {} : { stack: error.stack }), - ...(typeof code === 'string' || typeof code === 'number' ? { code } : {}), - ...(error.cause === undefined || depth >= MAX_CAUSE_DEPTH - ? {} - : { cause: plain(error.cause, depth + 1) }), - } satisfies PlainError; + const { code } = error as { code?: unknown }; + + return { + kind: 'error', + name: error.name, + message: error.message, + ...(error.stack === undefined ? {} : { stack: error.stack }), + ...(typeof code === 'string' || typeof code === 'number' ? { code } : {}), + ...(error.cause === undefined || depth >= MAX_CAUSE_DEPTH + ? {} + : { cause: plain(error.cause, depth + 1) }), + } satisfies PlainError; + } catch { + // An error that cannot be read — a revoked proxy, a getter that throws — + // crosses as what can be said of it, rather than failing what says it. + return { + kind: 'error', + name: 'Error', + message: errorMessage(error), + } satisfies PlainError; + } } /** The error a {@link plain} one stands for, on this side. */ @@ -165,28 +222,90 @@ function plainEvent(event: EpgEventInput): EpgEventInput { * Send something to the other side, whatever a site put in it. * * A site's `log` and `warn` take fields of its own, which may hold something no - * thread can be handed — a function, a socket. As the JSON reporter does with - * them: what survives JSON goes as JSON, and what does not is named in place of - * its value (see `SaidFields`) — never a throw into the site's own code, where - * a log line would fail the channel-day it was about. + * thread can be handed — a function, a socket — and what it throws, or what a + * run is cancelled with, may hold one too, as itself or as an error's `cause`. + * As the JSON reporter does with them: what survives JSON goes as JSON, and + * what does not is named in place of its value (see `SaidFields`) — never a + * throw into the site's own code, where a log line would fail the channel-day + * it was about, nor into a listener, where it would end the process. Made so + * only once the message has been refused, so what crosses as it is is copied + * once. */ function send(port: SitePort, message: ToHost | ToWorker, transfer: ArrayBuffer[] = []): void { try { port.postMessage(message, transfer); } catch (error) { - if (message.kind !== 'event' || !('data' in message.event)) { + const handable = handableOf(message); + + if (handable === undefined) { throw error; } - let data: unknown; + port.postMessage(handable, []); + } +} - try { - data = JSON.parse(JSON.stringify(message.event.data)) as unknown; - } catch { - data = '[unserializable]'; +/** + * `message` with what of a site's — or a caller's — no thread can be handed + * made into what one can, as {@link send} says; nothing, for one that carries + * nothing of theirs. + */ +function handableOf(message: ToHost | ToWorker): ToHost | ToWorker | undefined { + switch (message.kind) { + case 'event': { + const event = message.event as EpgEventInput & { data?: unknown; error?: unknown }; + + return { + ...message, + event: { + ...event, + ...('data' in event ? { data: asJson(event.data) } : {}), + ...('error' in event ? { error: handableError(event.error) } : {}), + } as EpgEventInput, + }; } + case 'failed': + return { ...message, error: handableError(message.error) }; + case 'answer': + // An answer the store gave that no thread can be handed — something of + // a store of the config's own — is the call failing, said as such, + // rather than a call never answered. + return message.error === undefined + ? { + kind: 'answer', + id: message.id, + error: plain( + new TypeError("The run's cache answered with what no thread can be handed"), + ), + } + : { ...message, error: handableError(message.error) }; + case 'abort': + return { ...message, reason: handableError(message.reason) }; + default: + return undefined; + } +} - port.postMessage({ ...message, event: { ...message.event, data } }, []); +/** + * A {@link plain} error with what of it is no error — a `cause` holding a + * function, a thrown object holding a socket — as JSON keeps it. + */ +function handableError(error: unknown): unknown { + if (typeof error === 'object' && error !== null && (error as PlainError).kind === 'error') { + const { cause } = error as PlainError; + + return cause === undefined ? error : { ...(error as PlainError), cause: handableError(cause) }; + } + + return asJson(error); +} + +/** `value` as JSON keeps it, or named where JSON cannot have it. */ +function asJson(value: unknown): unknown { + try { + return JSON.parse(JSON.stringify(value)) as unknown; + } catch { + return '[unserializable]'; } } @@ -241,10 +360,14 @@ interface PooledWorker { worker: Worker; sites: number; /** - * Rejects when the thread dies — out of memory, or an error nothing caught — - * which fails every site it was running: the conversation would simply stop. + * Who is told when the thread dies — out of memory, or an error nothing + * caught — which fails every site it was running: the conversation would + * simply stop. A site's host is in it while its site runs, and no longer: the + * thread outlives the run, and a listener left would keep the run with it. */ - lost: Promise; + losing: Set<(error: unknown) => void>; + /** Why it died, once it has — so its `exit` after its `error` is not said again. */ + lostWith?: Error; } /** @@ -294,19 +417,31 @@ export class SiteThreads { /** * Run one site on a worker, and answer for it on this side. * - * Resolves when the site is done, as `new SiteRun(config, run).run()` would; - * rejects when it never got going — its config could not be imported, did - * not have it, or did not resolve, or it has a channel list no thread can be - * handed as it is — which the run reports as a site that failed. + * Resolves when the site is done, as `new SiteRun(config, run).run()` would, + * with what hangs up on it, which the run calls once it is done with every + * site — see {@link hostSite}. Rejects with a + * {@link SiteNotRunError} when it never got going — no thread to start, a config + * its thread could not import, did not have it, or did not resolve, or a + * channel list no thread can be handed as it is. */ - async run(config: AnySiteConfig, run: Run): Promise { + async run( + config: AnySiteConfig, + run: Run, + /** The session its list was settled through on this thread — see {@link hostSite}. */ + settled?: SiteSession, + ): Promise<() => void> { // Before a worker is asked for, so a site that cannot go starts nothing: a // copy would hand the thread something else without saying so, and a // function could not be copied at all. if (Array.isArray(config.channels)) { - assertPlainData(config.site, config.channels); + try { + assertPlainData(config.site, config.channels); + } catch (error) { + throw new SiteNotRunError(error); + } } + const reader = new CountReader(); const data: SiteThreadData = { module: this.#module, site: config.site, @@ -322,26 +457,52 @@ export class SiteThreads { ...(run.cache instanceof CacheManager && run.cache.codecName !== undefined ? { codec: run.cache.codecName } : {}), + counts: reader.buffer, }; const { port1, port2 } = new MessageChannel(); - const pooled = this.#pick(); + let pooled: PooledWorker; try { + pooled = this.#pick(); pooled.worker.postMessage({ data, port: port2 }, [port2]); } catch (error) { port1.close(); port2.close(); - throw error; + // Never handed over, so never run. + throw new SiteNotRunError(error); } pooled.sites++; try { - await Promise.race([hostSite(port1, run), pooled.lost]); + const hangUp = await hostSite(port1, run, { + site: config.site, + counts: reader, + ...(settled === undefined ? {} : { settled }), + // A worker picked is one still in the pool, and nothing between the + // pick and this can hear it go: it is listened to from here. + whenLost: (lose) => { + pooled.losing.add(lose); + + return () => pooled.losing.delete(lose); + }, + }); + + // Open until the run hangs up, to hear what a request the site did not + // wait for still counts — without holding the process open for it. + port1.unref(); + + return () => { + hangUp(); + port1.close(); + }; + } catch (error) { + port1.close(); + + throw error; } finally { pooled.sites--; - port1.close(); } } @@ -357,14 +518,7 @@ export class SiteThreads { } const worker = new Worker(WORKER); - let stopped: (error: unknown) => void = () => {}; - const pooled: PooledWorker = { - worker, - sites: 0, - lost: new Promise((_resolve, reject) => { - stopped = reject; - }), - }; + const pooled: PooledWorker = { worker, sites: 0, losing: new Set() }; /** * Fail what it was running, and leave the pool — at the first sign, since @@ -372,18 +526,38 @@ export class SiteThreads { * not be handed a thread that is going: a dead one runs nothing, and would * be the idlest of them for ever. */ - const gone = (error: unknown): void => { - stopped(error); + const gone = (thrown: unknown): void => { + if (pooled.lostWith !== undefined) { + return; + } + // An error whatever was thrown — a site's code may throw anything, even + // `undefined`, which would read here as a thread that never died — and + // what it was with it, an object's fields and all. + const error = + thrown instanceof Error + ? thrown + : new Error( + `A site's thread threw ${inspect(thrown, { depth: 2, breakLength: Infinity })}`, + ); + + pooled.lostWith = error; + + // Out of the pool before anyone is told: a site started by what they + // say must not be handed a thread that is going. const at = this.#workers.indexOf(pooled); if (at !== -1) { this.#workers.splice(at, 1); } + + for (const tell of pooled.losing) { + tell(error); + } + + pooled.losing.clear(); }; - // Heard by the sites racing it, if there are any when it happens. - pooled.lost.catch(() => {}); worker.once('error', gone); worker.once('exit', (code) => { gone(new Error(`A site's thread stopped (exit code ${code})`)); @@ -409,6 +583,37 @@ function moduleUrl(configModule: string | URL): string { : pathToFileURL(configModule).href; } +/** + * How long a site whose thread is gone waits for its port to say it closed — + * after everything the thread sent, which is how the run knows it has heard + * it all — before it is decided without, on what its memory holds. Measured, a + * port closes at once, for a thread that threw, exited, was stopped or ran out + * of memory — save one handed to a thread already gone, which never does; this + * is for that, and for one that goes some way that was not measured, which + * must not hold the run for ever. + */ +const LOST_PORT_GRACE_MS = 5_000; + +/** What a site's host is told beside its port and the run — see {@link hostSite}. */ +export interface Hosting { + /** The site's name, for what is said of it should its thread go. */ + site: string; + /** + * The session its list was settled through on this thread before it was + * handed over, which its `site:done` from over there could not know of: what + * it asked, and how long that took, are added as the event passes. The run + * was told of them when they were asked. + */ + settled?: SiteSession; + /** + * Listen for the thread going, for as long as the site runs — handed what to + * call, and answering what stops it. + */ + whenLost?: (lose: (error: unknown) => void) => () => void; + /** What the site's thread counts in — over the {@link SiteThreadData}'s memory. */ + counts: CountReader; +} + /** * This side of the conversation: answer the worker's cache, say what it says, * count what it counted, and tell it when the run is cancelled. @@ -421,15 +626,193 @@ function moduleUrl(configModule: string | URL): string { * would be. A site cancelled part way still finishes the write it started and * saves its state, and a site's state is read and saved straight through, as * it is in-process. + * + * Resolves when the site is done, with what hangs up on it — which tells the + * run what the site counted, from its shared memory. Not before the run is done + * with every site, as a site on the run's own thread is counted until then: a + * request a parse sent and did not wait for can be answered after its site's + * `site:done`, and is counted, cancelled with the run and said as it would be + * there. + * + * A site that throws out of its turn, which a site that finishes it does not, + * or whose thread goes part way through it, is said here as a site that fails + * says itself: `site:failed`, then `site:done` with what it did, from what it + * counted — once, should it have counted itself failed already. A thread that + * went is said of once its port has closed, which is after everything it sent: + * so whether the site had said its own `site:done` is known, not guessed. One + * the thread never began on rejects with a {@link SiteNotRunError}, for the run to + * say as a site that never ran. */ -export function hostSite(port: SitePort, run: Run): Promise { - const { cache, emit, localWork, signal, tally } = run; +export function hostSite(port: SitePort, run: Run, hosting: Hosting): Promise<() => void> { + const { cache, emit, localWork, signal, tally, requested } = run; + const { site, settled, whenLost, counts: reader } = hosting; + + return new Promise<() => void>((resolve, reject) => { + /** How far the site's turn has got, each of them once. */ + const turn = { + /** + * Its `site:done` heard — which is whether it was said, by the time + * anything after it is: a port hands over what it was sent in order, + * and says it closed after all of it. + */ + said: false, + /** Over — see {@link ended}: only the first of a done, a failure and a lost thread. */ + ended: false, + /** Hung up on — see {@link hangUp}. */ + hungUp: false, + }; + /** + * Its thread going, as it is heard of — see {@link lost}: why, once it + * has; whether its port has said it closed, which it does after all the + * thread sent; and what gives up waiting for that. + */ + const going: { + why?: { error: unknown }; + closed: boolean; + givingUp?: ReturnType; + } = { closed: false }; + /** What there was no slot for, said as it went — and told the run as it was. */ + const unslotted = new Map(); + // Before anything can be heard: a port may hand over what it holds as soon + // as it is listened to. + let stopListening: (() => void) | undefined; - return new Promise((resolve, reject) => { const abort = (): void => { send(port, { kind: 'abort', reason: plain(signal?.reason) }); }; + /** Stop listening, and tell the run what the site's slots hold — once. */ + const hangUp = (): void => { + if (turn.hungUp) { + return; + } + + turn.hungUp = true; + port.off('message', listen); + port.off('close', close); + signal?.removeEventListener('abort', abort); + tellAll(requested, reader.read()); + }; + + /** + * The site's turn over — done, thrown out of, or lost with its thread — or + * never begun. Settled before anything is said of it. + */ + const ended = (end?: { error: unknown; how: 'threw' | 'went' }): void => { + if (turn.ended) { + return; + } + + turn.ended = true; + stopListening?.(); + clearTimeout(going.givingUp); + + // A thread that went sends nothing more, and what it sent is heard — + // or given up on: nothing heard from here could be the site's own. + if (end?.how === 'went') { + port.off('message', listen); + } + + const began = reader.began(); + const counted = reader.tally(); + + // Its channel-days into the run's as its turn ends, as a site on the + // run's thread has added them by then: none comes after. + for (const [field, n] of Object.entries(counted) as Array<[keyof GrabCounts, number]>) { + tally[field] += n; + } + + if (end !== undefined && began === undefined) { + hangUp(); + reject(new SiteNotRunError(end.error)); + + return; + } + + resolve(hangUp); + + if (end === undefined) { + return; + } + + const went = end.how === 'went' ? 'its thread went' : 'it threw'; + + // All of it said, and nothing left but what was thrown after — or the + // thread's going, which is nothing of this site's. + if (turn.said) { + if (end.how === 'threw') { + emit({ + type: 'site:warning', + site, + message: `it threw after it was done: ${errorMessage(end.error)}`, + }); + } + + return; + } + + const by = reader.read(); + + for (const [label, done] of unslotted) { + addRequests(by, label, done); + } + + const done = siteDone(site, Date.now() - began!, requestsObject(by), { + ...counted, + sitesFailed: 1, + }); + + // Once: a site that failed has counted it, and said why. + if (counted.sitesFailed === 0) { + tally.sitesFailed++; + emit({ type: 'site:failed', site, error: end.error }); + } else { + emit({ + type: 'site:warning', + site, + message: `${went} before it was done: ${errorMessage(end.error)}`, + }); + } + + emit(settled === undefined ? done : withSettled(done, settled)); + }; + + /** + * Its thread gone, and everything it sent heard — see {@link SitePort}: + * for a site it never began on too, which may have said why it never + * could just before its thread went for another site's sake. + */ + const lost = (): void => { + if (going.why !== undefined && going.closed) { + ended({ error: going.why.error, how: 'went' }); + } + }; + + /** + * Half of its thread going heard — word that it went, or its port closing + * — and the other waited for a while, then taken as heard: see + * {@link LOST_PORT_GRACE_MS}. A port closed with no word of its thread is + * a host with no thread to hear from, or a thread gone some way that says + * nothing. + */ + const giveUpLater = (): void => { + if (turn.ended || going.givingUp !== undefined) { + return; + } + + going.givingUp = setTimeout(() => { + going.closed = true; + going.why ??= { error: new Error("The site's thread hung up without a word") }; + lost(); + }, LOST_PORT_GRACE_MS); + }; + + const close = (): void => { + going.closed = true; + lost(); + giveUpLater(); + }; + const listen = (message: ToHost): void => { switch (message.kind) { case 'event': { @@ -439,11 +822,26 @@ export function hostSite(port: SitePort, run: Run): Promise { (event as { error: unknown }).error = revived(event.error); } - emit(event); + turn.said ||= event.type === 'site:done'; + emit( + event.type === 'site:done' && settled !== undefined + ? withSettled(event, settled) + : event, + ); break; } - case 'count': - tally[message.field] += message.delta; + case 'slot': + reader.named(message.index, message.slot); + + // Its place among the run's labels taken now, when it was first + // sent, rather than when the run hangs up. + if (message.slot.failure === undefined) { + requested(message.slot.label, noRequests()); + } + break; + case 'requested': + requested(message.label, message.done); + addRequests(unslotted, message.label, message.done); break; case 'cache': { const { id, op, args } = message; @@ -451,7 +849,9 @@ export function hostSite(port: SitePort, run: Run): Promise { op === 'getState' || op === 'setState' ? answer(cache, op, args) : localWork.add(() => answer(cache, op, args), { - priority: op === 'write' || op === 'read' ? 1 : 0, + // A channel-day written — encoded already, for a store with + // a codec — or read to be added to, ahead of a sweep. + priority: op === 'write' || op === 'writeEncoded' || op === 'read' ? 1 : 0, }); void answering.then( @@ -465,28 +865,30 @@ export function hostSite(port: SitePort, run: Run): Promise { break; } case 'done': - finish(); - resolve(); + ended(); break; case 'failed': - finish(); - reject(revived(message.error)); + ended({ error: revived(message.error), how: 'threw' }); break; } }; - const finish = (): void => { - port.off('message', listen); - signal?.removeEventListener('abort', abort); - }; - port.on('message', listen); + port.on('close', close); if (signal?.aborted) { abort(); } else { signal?.addEventListener('abort', abort, { once: true }); } + + // Last, since a thread already gone ends the site here and now — and + // hanging up lets go of everything listened to before. + stopListening = whenLost?.((error) => { + going.why = { error }; + lost(); + giveUpLater(); + }); }); } @@ -528,8 +930,11 @@ async function answer(cache: CacheStore, op: CacheOp, args: unknown[]): Promise< // ── the worker's half ─────────────────────────────────────────────────────── -/** The run's cache, as the main thread answers it. */ -class RemoteCache implements CacheStore { +/** + * The run's cache, as the main thread answers it. Exported to be tried without + * a site to run. + */ +export class RemoteCache implements CacheStore { readonly #port: SitePort; /** The codec the run's store keeps its entries with, run here when there is one. */ readonly #codec: CodecName | undefined; @@ -537,35 +942,84 @@ class RemoteCache implements CacheStore { number, { resolve(value: unknown): void; reject(error: unknown): void } >(); + /** What {@link close} is waiting on, told once no call is left waiting — a turn later. */ + #drained: (() => void) | undefined; + /** Whether {@link close} is done, after which nothing is answered. */ + #closed = false; #next = 0; constructor(port: SitePort, codec: CodecName | undefined) { this.#port = port; this.#codec = codec; - port.on('message', (message: ToWorker) => { - if (message.kind !== 'answer') { - return; - } + port.on('message', this.#answered); + port.on('close', this.#hungUp); + } - const waiting = this.#waiting.get(message.id); + /** + * The run hung up, or the thread is going: nothing waiting will be answered, + * so each is told so — and whatever waits on it lets go — rather than left + * waiting for ever. Listened for until {@link close}. + */ + readonly #hungUp = (): void => { + // Nothing asked from here is answered either: refused, rather than sent. + this.#closed = true; - this.#waiting.delete(message.id); + for (const { reject } of this.#waiting.values()) { + reject(new Error('The run stopped answering its cache before this call was answered')); + } - if (message.error === undefined) { - waiting?.resolve(message.value); - } else { - waiting?.reject(revived(message.error)); - } - }); + this.#waiting.clear(); + this.#drained?.(); + }; + + /** What the main thread answered, to the call that asked it — listened for until {@link close}. */ + readonly #answered = (message: ToWorker): void => { + if (message.kind !== 'answer') { + return; + } + + const waiting = this.#waiting.get(message.id); + + // Its caller told first, so one asking again as it goes on is still waited + // for by a close that is waiting. + if (message.error === undefined) { + waiting?.resolve(message.value); + } else { + waiting?.reject(revived(message.error)); + } + + this.#forget(message.id); + }; + + /** Let go of call `id`, and tell {@link close} once no call is left waiting. */ + #forget(id: number): void { + this.#waiting.delete(id); + + if (this.#waiting.size === 0) { + this.#drained?.(); + } } /** One cache call, answered by the main thread — and the buffers it hands over rather than copies. */ #ask(op: CacheOp, args: unknown[], transfer: ArrayBuffer[] = []): Promise { + // Refused rather than sent: nothing is listening for its answer. + if (this.#closed) { + return Promise.reject(new Error('The run’s cache was asked after the site was done with it')); + } + const id = this.#next++; return new Promise((resolve, reject) => { this.#waiting.set(id, { resolve, reject }); - send(this.#port, { kind: 'cache', id, op, args }, transfer); + + try { + send(this.#port, { kind: 'cache', id, op, args }, transfer); + } catch (error) { + // Never sent — what no thread can be handed, as what a site keeps may + // hold — so never to be answered. + this.#forget(id); + throw error; + } }); } @@ -615,8 +1069,34 @@ class RemoteCache implements CacheStore { return this.#ask('setState', args); } - /** The main thread's store, which is the main thread's to close. */ - async close(): Promise {} + /** + * The main thread's store, which is the main thread's to close: this lets go + * of the port it was asked through, which outlives it. + * + * Once what is still asked is answered: a call a cancel let go of, or one + * beside a read that failed, is still the main thread's to answer, and what + * waits on it holds a slot of the thread's `localWork` — which every site the + * thread runs shares, in this run and the next — until it is. + */ + async close(): Promise { + // Until none is left, and none asked by what the last answer let go on — + // a read, then the write it was for: that goes on in the turn it was + // answered in, and a turn waited for comes after all of it. + do { + await new Promise((resolve) => { + this.#drained = () => setImmediate(resolve); + + if (this.#waiting.size === 0) { + this.#drained(); + } + }); + } while (this.#waiting.size > 0); + + this.#drained = undefined; + this.#closed = true; + this.#port.off('message', this.#answered); + this.#port.off('close', this.#hungUp); + } } /** @@ -635,35 +1115,74 @@ export async function workSite( localWork = new PQueue({ concurrency: data.localConcurrency }), ): Promise { const stop = new AbortController(); + /** + * Where the site's request counts go: memory the run's thread reads, so none + * is held here for a thread that dies to lose, and none crosses as a message + * but a count's name, once. Measured for 10,050 requests a millisecond each, + * one at a time: four messages and 74ms of the main thread, against 20,100 + * messages and 958ms said each time, and 10,100 and 857ms gathered a turn at + * a time — which also lost what a thread that died was holding. + */ + const writer = new CountWriter(data.counts, (index, slot) => { + send(port, { kind: 'slot', index, slot }); + }); + /** The run's store, asked through the port — closed once the site's turn is over. */ + const cache = new RemoteCache(port, data.codec); - port.on('message', (message: ToWorker) => { + /** + * The run cancelled — listened for until it hangs up, so a request the site + * did not wait for is cancelled with it — and let go of then. + */ + const cancelled = (message: ToWorker): void => { if (message.kind === 'abort') { stop.abort(revived(message.reason)); } - }); + }; + const hungUp = (): void => { + port.off('message', cancelled); + port.off('close', hungUp); + }; + + port.on('message', cancelled); + port.on('close', hungUp); try { // Once per worker however many of its sites are in it: a config function // then runs once a thread, not once a site. - let reading = configs.get(data.module); + // Read out of `data` rather than through it in what follows: a closure + // that names it keeps all of it — the site's channels among it — for as + // long as this conversation's listeners, which is the rest of the run. + const { module, site: name } = data; + let reading = configs.get(module); if (reading === undefined) { - reading = import(data.module).then((imported: { default?: ConfigSource }) => { + reading = import(module).then((imported: { default?: ConfigSource }) => { if (imported.default === undefined) { - throw new TypeError(`${data.module} has no default export, so there is no config to run`); + throw new TypeError(`${module} has no default export, so there is no config to run`); } return resolveConfigSource(imported.default); }); - configs.set(data.module, reading); + configs.set(module, reading); + + // Not kept, should it fail: a config that fetches, or reads what it is + // run with, may answer the next site it is asked for — in this run or a + // later one — where a failure kept would fail every one for good. + const failing = reading; + + failing.catch(() => { + if (configs.get(module) === failing) { + configs.delete(module); + } + }); } const config = await reading; - const found = config.sites.find((site) => site.site === data.site); + const found = config.sites.find((site) => site.site === name); if (found === undefined) { throw new TypeError( - `The config at ${data.module} has no site "${data.site}" when a thread imports it — ` + + `The config at ${module} has no site "${name}" when a thread imports it — ` + `every site has to be there each time the module is read for threads to find it`, ); } @@ -674,7 +1193,7 @@ export async function workSite( const run: Run = { defaults: data.defaults, - cache: new RemoteCache(port, data.codec), + cache, now: new Date(data.now), grabbedAt: data.grabbedAt, startDay: data.startDay, @@ -685,32 +1204,68 @@ export async function workSite( signal: stop.signal, localWork, enqueue, - // Each count sent as it is counted, as `SiteRun` counts into the run's - // tally in-process: a site whose thread dies, or that is cancelled - // before it can say `site:done`, has still said what it did. - tally: new Proxy( - { fetched: 0, empty: 0, fromCache: 0, unchanged: 0, failed: 0, sitesFailed: 0 }, - { - set(counts, field: keyof GrabCounts, value: number) { - send(port, { kind: 'count', field, delta: value - counts[field] }); - counts[field] = value; - - return true; - }, + // Each count into the memory both threads see, as `SiteRun` counts into + // the run's tally in-process — see `writer`: a site whose thread dies, + // or that is cancelled before it can say `site:done`, has still counted + // what it did. + tally: new Proxy(noCounts(), { + set(counts, field: keyof GrabCounts, value: number) { + writer.count(field, value - counts[field]); + counts[field] = value; + + return true; }, - ), + }), + // Into the memory both threads see — see `writer` — and what there is + // no room for, said instead. + requested: (label, done) => { + const left = writer.add(label, done); + + if (left !== undefined) { + send(port, { kind: 'requested', label, done: left }); + } + }, }; - await new SiteRun( + const site = new SiteRun( data.channels === undefined ? found : { ...found, channels: data.channels }, run, - ).run(); + ); + + // Into memory rather than said, so the run's thread knows it the moment it + // is so: a thread that dies a moment later may have run some of the site, + // and a message saying so may not arrive before word that it died. + writer.begin(); + await site.run(); send(port, { kind: 'done' }); } catch (error) { send(port, { kind: 'failed', error: plain(error) }); + } finally { + await cache.close(); } } /** Each config module this thread has read, resolved — see {@link workSite}. */ const configs = new Map>(); + +/** + * A thread's `site:done`, with what its list was settled with on this thread + * added in — first, since it was asked first — and the time that took. + */ +function withSettled( + event: Extract, + settled: SiteSession, +): EpgEventInput { + // Everything it said kept — what is added to here is what is changed. + return { + ...event, + ...siteDone( + event.site, + // The site's list was its turn too, though another thread's. + event.ms + settled.spanMs, + mergedRequests(settled.requestsBy, event.requestsBy), + event, + ), + }; +} diff --git a/src/grabber/types.ts b/src/grabber/types.ts index 40a1a9e..808c519 100644 --- a/src/grabber/types.ts +++ b/src/grabber/types.ts @@ -514,8 +514,24 @@ export interface SiteBackoff { */ export type PacedRequest = ( task: (options: { signal?: AbortSignal | undefined }) => Promise, + options?: PacedOptions, ) => Promise; +/** What a {@link PacedRequest} is told about the request beside it. */ +export interface PacedOptions { + /** + * What the request is for, as `site:done`'s `requestsBy` counts it — + * `'detail'`, `'episodes'`. When not given, `'paced'` from a parse, and + * from a stream its site's `requestLabel` — `'stream'` without one. A name + * of the site's, not a URL's: one label per kind of request, not per + * channel — a word with a letter in it, or words joined by `.`, `_`, `/` or + * `-`, and never `channels`. One that is not throws where `paced` is + * called, rather than rejecting the request: a mistake in the site's code + * is not a `404` to be caught. + */ + label?: string; +} + /** * What a parse is handed. `log` and `warn` come from {@link Says}, and a * parse is where a site most often has something to say — a field the source @@ -623,8 +639,10 @@ export interface ParseContext extends Says, SiteZones { * ```ts * async parseDay({ payload, programme, http, paced }) { * return Promise.all(payload.items.map(async (item) => { - * const detail = await paced(({ signal }) => - * http.get(`detail/${item.id}`, { signal }).json()); + * const detail = await paced( + * ({ signal }) => http.get(`detail/${item.id}`, { signal }).json(), + * { label: 'detail' }, + * ); * * return programme(new Date(item.start), item.title).desc(detail.synopsis); * })); @@ -674,6 +692,22 @@ export type ChannelElement = (displayName?: string) => ChannelBuilder; export interface BaseSiteConfig { /** Unique site identifier, e.g. `webtv.sk`. Used as cache namespace. */ site: string; + /** + * What the site's own requests are counted as in `site:done`'s + * `requestsBy`: a `request`'s, `'request'` unless given — and a stream's, + * which has no planned requests and asks through `paced`, those `paced` + * calls that give no label of their own, `'stream'` unless given. + * + * A site that makes requests of more than one kind names each, so its + * summary says which kind cost what: `requestLabel: 'listings'` beside a + * parse's `paced(task, { label: 'detail' })`. A word with a letter in it, + * or words joined by `.`, `_`, `/` or `-`, and never `channels`: a site + * with one that is not is refused, and fetches nothing but its channel + * list, where the run settles every list first — a `build`, whose guide + * still writes what the site has cached, or a grab with a selection or a + * `cover` to apply. + */ + requestLabel?: string; /** * The channels to grab. A function is called with the site's HTTP client, so * a list that has to be fetched costs no extra setup — and it is called only diff --git a/src/main.ts b/src/main.ts index fcc3f6f..2662a8a 100644 --- a/src/main.ts +++ b/src/main.ts @@ -11,7 +11,15 @@ export type { export { createConfigContext, defaultsReader, envReader } from './core/answers.js'; export type { ConfigContext, ConfigReader, StageDefaults } from './core/answers.js'; export { errorChain, errorMessage, GrabberError } from './core/error.js'; -export { atLevel, emitter, EVENT_KINDS, LEVELS, PHASES } from './core/events.js'; +export { + atLevel, + emitter, + EVENT_KINDS, + LEVELS, + PHASES, + ReporterError, + RunFailedError, +} from './core/events.js'; export type { Emit, EpgEvent, @@ -22,7 +30,9 @@ export type { EventLevel, GrabCounts, ReportedOptions, + RequestCounts, Reporter, + ReporterThrow, RunPhase, SaidFields, Says, diff --git a/test/build.test.ts b/test/build.test.ts index ea3fa35..dcafd58 100644 --- a/test/build.test.ts +++ b/test/build.test.ts @@ -1,4 +1,4 @@ -import { EventEmitter } from 'node:events'; +import { EventEmitter, getEventListeners } from 'node:events'; import { existsSync } from 'node:fs'; import { mkdtemp, readFile, readdir, stat, writeFile } from 'node:fs/promises'; import { tmpdir } from 'node:os'; @@ -9,7 +9,12 @@ import { describe, expect, it, vi } from 'vitest'; import { build, createCacheStore, guideStream, runGrab, runMerge } from '../src/build.js'; import { planRun } from '../src/cli/plan.js'; import { CacheManager, FsNdjsonCacheDriver, NoCacheDriver } from '../src/cache/main.js'; -import type { EpgEventMap } from '../src/core/events.js'; +import { + ReporterError, + RunFailedError, + type EpgEvent, + type EpgEventMap, +} from '../src/core/events.js'; import type { ChannelDayKey, StoredEntryMeta } from '../src/cache/main.js'; import { defineConfig, type EpgConfig } from '../src/config.js'; import { parseXmltvString } from '../src/xmltv/main.js'; @@ -82,6 +87,105 @@ describe('a channel list fetched before the grab', () => { // A build settles every list before any site is asked for a day, and the // fetch is still the first request of the site's turn: one queue, one state. + it('keeps what a reporter throws while the lists are settled, and rejects once the grab is', async () => { + const dir = await tempDir(); + const fellOver = new Error('the reporter fell over'); + const events: EpgEvent[] = []; + const listing: SiteConfig = { + ...site([]), + channels: async ({ log }) => { + // Said as the list is settled, before the grab begins. + log('listing'); + + return [{ xmltvId: 'one.example', siteId: '1', name: 'One' }]; + }, + }; + + const rejected = await build(config(dir, { sites: [listing] }), { + now: NOW, + reporter: (event) => { + events.push(event); + + if (event.type === 'site:note') { + throw fellOver; + } + }, + }).then( + () => undefined, + (error: unknown) => error, + ); + + expect(rejected).toBeInstanceOf(ReporterError); + expect((rejected as ReporterError).thrown).toEqual([ + { error: fellOver, times: 1, at: { 'site:note': 1 } }, + ]); + // Not taken for the site's list failing: the grab went on with it. + expect(events.filter((event) => event.type === 'site:failed')).toEqual([]); + expect(events.find((event) => event.type === 'grab:done')).toMatchObject({ fetched: 1 }); + // And no guide written by a run that is rejecting. + expect(existsSync(join(dir, 'guide.xml'))).toBe(false); + }); + + it('counts no nameless site’s list as another’s', async () => { + const dir = await tempDir(); + const report: EpgEvent[] = []; + let asked = 0; + const nameless = (siteId: string, name: unknown): SiteConfig => ({ + ...site([]), + site: name as never, + channels: async () => { + asked++; + + return [{ xmltvId: `${siteId}.example`, siteId, name: siteId }]; + }, + }); + + // No name, and an empty one, which is refused as none. + await build( + config(dir, { + sites: [nameless('one', undefined), nameless('two', ''), nameless('three', '')], + }), + { + now: NOW, + reporter: (event) => report.push(event), + }, + ).catch(() => undefined); + + // Each refused, and each said apart: no list of one counted as the other's. + const done = report.filter((event) => event.type === 'site:done'); + + // Nor any of their sources asked for a list kept under no name. + expect(asked).toBe(0); + expect(done).toHaveLength(3); + expect(done.map((event) => (event as { requestsBy: object }).requestsBy)).toEqual([{}, {}, {}]); + }); + + it('lets go of the sessions its lists were fetched through, should settling them fail', async () => { + const dir = await tempDir(); + const run = new AbortController(); + const listed: SiteConfig = { + ...site([]), + channels: async () => [{ xmltvId: 'one.example', siteId: '1', name: 'One' }], + }; + + await expect( + build( + config(dir, { + sites: [listed], + // Asked about the lists once they are settled — and failing. + derived: () => { + throw new Error('the derived channels could not be worked out'); + }, + }), + { now: NOW, signal: run.signal }, + ), + ).rejects.toThrow('the derived channels could not be worked out'); + + // Nothing of the session left listening to the run, with the site's + // config in hand. + expect(getEventListeners(run.signal, 'abort')).toHaveLength(0); + }); + it('is paced with the requests after it', async () => { const dir = await tempDir(); const at: number[] = []; @@ -253,6 +357,127 @@ describe('a site whose channel list fails', () => { expect(guide.programmes).toHaveLength(1); }); + it('says what the list it failed on cost, though it was asked before the grab', async () => { + const dir = await tempDir(); + const events: EpgEvent[] = []; + const refused: SiteConfig = { + ...site([]), + site: 'broken.example', + channels: async () => { + throw Object.assign(new Error('Not Found'), { + name: 'HTTPError', + response: { status: 404 }, + }); + }, + }; + + await build(config(dir, { sites: [site([]), refused] }), { + now: NOW, + reporter: (event) => events.push(event), + }); + + const done = events.find( + (event) => event.type === 'site:done' && event.site === 'broken.example', + ) as Extract; + const counted = { + channels: { requests: 1, requestMs: expect.any(Number), failed: { 404: 1 } }, + }; + + expect(done.requests).toBe(1); + // Its list was all it did: its time is the list's, pacing and all. + expect(done.ms).toBeGreaterThanOrEqual(done.requestMs); + expect(done.requestsBy).toEqual(counted); + expect( + ( + events.find((event) => event.type === 'grab:done') as Extract< + EpgEvent, + { type: 'grab:done' } + > + ).requestsBy, + ).toMatchObject(counted); + }); + + it("counts a settled list's time in its site's, as its requests are", async () => { + const dir = await tempDir(); + const events: EpgEvent[] = []; + const slow: SiteConfig = { + ...site([]), + site: 'slow.example', + channels: async () => { + await new Promise((resolve) => setTimeout(resolve, 60)); + + return [{ xmltvId: 'slow.one', siteId: '1' }]; + }, + }; + + await build(config(dir, { sites: [slow] }), { + now: NOW, + reporter: (event) => events.push(event), + }); + + const done = events.find( + (event) => event.type === 'site:done' && event.site === 'slow.example', + ) as Extract; + + // Settled before the grab began, and the site's time all the same. + expect(done.requestsBy.channels!.requestMs).toBeGreaterThanOrEqual(50); + expect(done.ms).toBeGreaterThanOrEqual(done.requestMs); + }); + + it('writes what a site it could not run has cached, and says what its list cost', async () => { + const dir = await tempDir(); + let asked = 0; + const unread = (requestLabel?: string): SiteConfig => ({ + ...site([]), + site: 'unread.example', + ...(requestLabel === undefined ? {} : { requestLabel }), + channels: async () => { + asked++; + + return [{ xmltvId: 'unread.one', siteId: '1' }]; + }, + parseDay: ({ day }) => [ + { + channel: 'unread.one', + start: new Date(`${day}T06:00:00.000Z`), + title: [{ value: 'Kept' }], + }, + ], + }); + + // A run that grabs it, and one after a mistake in its config. + await build(config(dir, { sites: [unread()] }), { now: NOW }); + + const events: EpgEvent[] = []; + const summary = await build(config(dir, { sites: [unread('detail calls')] }), { + now: NOW, + reporter: (event) => events.push(event), + }); + + expect(summary.sitesFailed).toBe(1); + // Its list asked for again — for the merge, which writes what it has + // cached rather than dropping the site from the guide. + expect(asked).toBe(2); + + const guide = parseXmltvString(await readFile(join(dir, 'guide.xml'), 'utf8')); + + expect(guide.programmes.map((programme) => programme.title[0]!.value)).toEqual(['Kept']); + + const ofSite = events.filter( + (event) => + (event.type === 'site:failed' || event.type === 'site:done') && + event.site === 'unread.example', + ); + + // And what that list cost, in the site's own line. + expect(ofSite.map((event) => event.type)).toEqual(['site:failed', 'site:done']); + expect(ofSite[1]).toMatchObject({ + requests: 1, + sitesFailed: 1, + requestsBy: { channels: { requests: 1, failed: {} } }, + }); + }); + it('costs a grab that resolves the lists early for `cover` only that site', async () => { const dir = await tempDir(); const asked: string[] = []; @@ -1801,6 +2026,125 @@ describe('a cache that cannot be read or made', () => { expect(existsSync(file)).toBe(false); }); + it('writes a merge’s guide though its reporter throws, and rejects once it is written', async () => { + const dir = await tempDir(); + const fellOver = new Error('the reporter fell over'); + + await runGrab(config(dir), { now: NOW }); + + const rejected = await runMerge(config(dir), { + now: NOW, + reporter: (event) => { + if (event.type === 'merge:channel') { + throw fellOver; + } + }, + }).then( + () => undefined, + (error: unknown) => error, + ); + + expect((rejected as ReporterError).thrown).toEqual([ + { error: fellOver, times: 1, at: { 'merge:channel': 1 } }, + ]); + // All of it, rather than what there was before the first throw. + expect(await readFile(join(dir, 'guide.xml'), 'utf8')).toContain(''); + }); + + it('throws what a reporter threw at a guide stream, though letting go of the cache failed', async () => { + const dir = await tempDir(); + const fellOver = new Error('the reporter fell over'); + + await runGrab(config(dir), { now: NOW }); + + class Closing extends FsNdjsonCacheDriver { + async close(): Promise { + throw new Error('the store would not close'); + } + } + + const reading = async (): Promise => { + for await (const _chunk of guideStream( + config(dir, { cache: { driver: () => new Closing({ dir: join(dir, 'cache') }) } }), + { + now: NOW, + reporter: (event) => { + if (event.type === 'merge:channel') { + throw fellOver; + } + }, + }, + )) { + // Read to the end. + } + }; + + // Both, rather than the second failure in place of the first. + const thrown = await reading().catch((error: unknown) => error); + + expect(thrown).toBeInstanceOf(RunFailedError); + expect(thrown).toMatchObject({ + error: { message: 'the store would not close' }, + reporter: { thrown: [{ error: fellOver }] }, + }); + }); + + it('throws what a reporter threw at a guide stream, to a reader that stopped early too', async () => { + const dir = await tempDir(); + const fellOver = new Error('the reporter fell over'); + + await runGrab(config(dir), { now: NOW }); + + const reading = async (): Promise => { + for await (const _chunk of guideStream(config(dir), { + now: NOW, + reporter: (event) => { + if (event.type === 'merge:channel') { + throw fellOver; + } + }, + })) { + // Walked away from after a chunk, as a client that hung up. + break; + } + }; + + await expect(reading()).rejects.toBeInstanceOf(ReporterError); + }); + + it('keeps what a reporter throws at what the cache says, and rejects once the guide is written', async () => { + const dir = await tempDir(); + const fellOver = new Error('the reporter fell over'); + + await runGrab(config(dir, { days: 2 }), { now: NOW }); + + // Tomorrow's, which is still fresh — today's is asked for again anyway. + const file = join(dir, 'cache', 'example.com', 'one.example', `${TOMORROW}.ndjson`); + const lines = (await readFile(file, 'utf8')).trimEnd().split('\n'); + + await writeFile(file, `${lines[0]}\n${lines[1]!.slice(0, 10)}\n`); + + // Not grabbed again, and said of by the cache as the merge reads it, where + // a throw would have broken the read. + const rejected = await build(config(dir, { days: 2 }), { + now: NOW, + reporter: (event) => { + if (event.type === 'site:warning') { + throw fellOver; + } + }, + }).then( + () => undefined, + (error: unknown) => error, + ); + + expect(rejected).toBeInstanceOf(ReporterError); + expect((rejected as ReporterError).thrown).toEqual([ + { error: fellOver, times: 1, at: { 'site:warning': 1 } }, + ]); + expect(existsSync(join(dir, 'guide.xml'))).toBe(true); + }); + it("says a sqlite cache's place is wrong as a place, not as a runtime", async () => { const dir = await tempDir(); const notADirectory = join(dir, 'notes.txt'); diff --git a/test/cli.test.ts b/test/cli.test.ts index 12bf683..580ac81 100644 --- a/test/cli.test.ts +++ b/test/cli.test.ts @@ -2213,6 +2213,52 @@ describe('flushing', () => { }); }); +describe('a reporter that throws', () => { + it('says what the run failed of, and what its reporter threw beside it', async () => { + const dir = await tempDir(); + const config = await configFile( + dir, + `export default { + // What the program asked to be told, through a listener that throws. + events: { + emit(type) { + if (type === 'site:note') { + throw new Error('the listener fell over'); + } + + return true; + }, + }, + sites: [{ + ...${siteSource()}, + channels: async ({ log }) => { + log('listing'); + + return [{ xmltvId: 'one.example.tv', siteId: '1', name: 'One' }]; + }, + }], + // And the run failing of itself, after. + derived: () => { + throw new Error('the derived channels could not be worked out'); + }, + days: 1, + output: ${JSON.stringify(join(dir, 'guide.xml'))}, + cache: { dir: ${JSON.stringify(join(dir, 'cache'))} }, + };`, + ); + + const { code, stderr } = await run(['build', '--config', config]); + + expect(code).toBe(1); + // Each said as itself: the reporter's, then the run's own. + expect(stderr).toContain( + 'The reporter threw 1 time: Error: the listener fell over (1 × at site:note)', + ); + expect(stderr).toContain('the derived channels could not be worked out\n'); + expect(stderr).not.toContain('and the reporter threw as well'); + }); +}); + describe('epg cache', () => { /** A site that remembers something, so there is state to look at too. */ async function rememberingConfig(dir: string): Promise { diff --git a/test/error.test.ts b/test/error.test.ts new file mode 100644 index 0000000..2b8bd71 --- /dev/null +++ b/test/error.test.ts @@ -0,0 +1,224 @@ +import { HTTPError, NetworkError, TimeoutError } from 'ky'; +import { describe, expect, it } from 'vitest'; +import { + causes, + errorChain, + errorMessage, + failureOf, + MAX_CAUSE_DEPTH, + unanswered, +} from '../src/core/error.js'; + +/** A request as ky made it, and the response it got. */ +function answered(status: number): HTTPError { + const request = new Request('https://example.tv/detail/1'); + + return new HTTPError(new Response(null, { status }), request, {} as never); +} + +describe('errorMessage', () => { + it('says what went wrong, whatever was thrown — even what cannot be read', () => { + const { proxy, revoke } = Proxy.revocable({}, {}); + + revoke(); + + expect(errorMessage(new Error('boom'))).toBe('boom'); + expect(errorMessage('nope')).toBe('nope'); + expect(errorMessage(proxy)).toBe('[something that cannot be read]'); + expect( + errorMessage({ + toString() { + throw new Error('no'); + }, + }), + ).toBe('[something that cannot be read]'); + }); +}); + +describe('errorChain', () => { + it('says what went wrong, and what caused it, down to where nothing did', () => { + const error = new Error('the lineup could not be read', { + cause: new TypeError('fetch failed', { cause: 'ECONNRESET' }), + }); + + expect(errorChain(error)).toBe('the lineup could not be read: fetch failed: ECONNRESET'); + expect(errorChain(undefined)).toBe('undefined'); + expect(errorChain('nope')).toBe('nope'); + }); + + it('stops at a depth, where a cycle would go for ever — sooner, for one already down a chain', () => { + const looped = new Error('again'); + + (looped as { cause?: unknown }).cause = looped; + + expect(errorChain(looped).split(': ')).toHaveLength(MAX_CAUSE_DEPTH + 1); + expect(errorChain(looped, 3).split(': ')).toHaveLength(MAX_CAUSE_DEPTH - 2); + expect(errorChain(looped, MAX_CAUSE_DEPTH + 5)).toBe('again'); + }); + + it('says what it can of a chain it cannot read to its end', () => { + const { proxy, revoke } = Proxy.revocable({}, {}); + + revoke(); + + const unreadable = Object.defineProperty(new Error('outer'), 'cause', { + get() { + throw new Error('no reading this'); + }, + }); + + expect(errorChain(new Error('outer', { cause: proxy }))).toBe( + 'outer: [something that cannot be read]', + ); + expect(errorChain(unreadable)).toBe('outer'); + expect(failureOf(proxy)).toBe('error'); + expect(failureOf(unreadable)).toBe('error'); + }); +}); + +describe('causes', () => { + it('walks down `cause`, error or not, and stops where there is none', () => { + const deepest = { reason: 'busy', cause: 'nope' }; + const inner = new Error('inner', { cause: deepest }); + const error = new Error('outer', { cause: inner }); + + expect([...causes(error)]).toEqual([error, inner, deepest, 'nope']); + expect([...causes(undefined)]).toEqual([]); + expect([...causes('thrown')]).toEqual(['thrown']); + }); + + it('stops at a depth, where a cycle would go for ever', () => { + const looped = new Error('again'); + + (looped as { cause?: unknown }).cause = looped; + + expect([...causes(looped)]).toHaveLength(MAX_CAUSE_DEPTH + 1); + }); +}); + +describe('failureOf', () => { + it('names a failure by the status the source answered with', () => { + expect(failureOf(answered(404))).toBe('404'); + expect(failureOf(answered(503))).toBe('503'); + }); + + it('names one nothing answered: a timeout, or the network', () => { + const request = new Request('https://example.tv/'); + + expect(failureOf(new TimeoutError(request))).toBe('timeout'); + expect(failureOf(new NetworkError(request, {} as never))).toBe('network'); + // Node's own, and the signal's. + expect(failureOf(new TypeError('fetch failed'))).toBe('network'); + expect(failureOf(Object.assign(new Error('refused'), { code: 'ECONNREFUSED' }))).toBe( + 'network', + ); + expect(failureOf(new DOMException('took too long', 'TimeoutError'))).toBe('timeout'); + }); + + it('reads a timeout beneath a fetch that failed, as undici and ky leave it', () => { + const request = new Request('https://example.tv/'); + + for (const code of [ + 'UND_ERR_HEADERS_TIMEOUT', + 'UND_ERR_CONNECT_TIMEOUT', + 'UND_ERR_BODY_TIMEOUT', + ]) { + const failed = new TypeError('fetch failed', { + cause: Object.assign(new Error('timed out'), { code }), + }); + + expect(failureOf(failed)).toBe('timeout'); + expect(failureOf(new NetworkError(request, { cause: failed } as never))).toBe('timeout'); + } + + expect(failureOf(Object.assign(new Error('timed out'), { code: 'ETIMEDOUT' }))).toBe('timeout'); + // Refused beneath it is the network, as is a fetch that says no more. + expect( + failureOf( + new TypeError('fetch failed', { + cause: Object.assign(new Error('refused'), { code: 'ECONNREFUSED' }), + }), + ), + ).toBe('network'); + }); + + it('reads no answer beneath a fetch that says nothing answered', () => { + const wrapped = new TypeError('fetch failed', { + cause: Object.assign(new Error('Not Found'), { response: { status: 404 } }), + }); + + expect(failureOf(wrapped)).toBe('network'); + expect(unanswered(wrapped)).toBe(true); + + // Nor on the error that says so, whatever status it carries too. + const named = Object.assign(new Error('the network failed'), { + name: 'NetworkError', + response: { status: 404 }, + }); + + expect(failureOf(named)).toBe('network'); + expect(unanswered(named)).toBe(true); + }); + + it('reads the status undici answered with, beside its code', () => { + // As undici's `request` throws for one, and its retry gives up with. + const refused = Object.assign(new Error('Response status code 404: Not Found'), { + name: 'ResponseStatusCodeError', + code: 'UND_ERR_RESPONSE_STATUS_CODE', + statusCode: 404, + }); + const retried = Object.assign(new Error('Request failed'), { + code: 'UND_ERR_REQ_RETRY', + statusCode: 503, + }); + + expect(failureOf(refused)).toBe('404'); + expect(unanswered(refused)).toBe(false); + expect(failureOf(retried)).toBe('503'); + expect(unanswered(retried)).toBe(true); + // And one of its own that nothing answered, still the network. + expect( + failureOf(Object.assign(new Error('other side closed'), { code: 'UND_ERR_SOCKET' })), + ).toBe('network'); + }); + + it('reads what a site wrapped, and what a ky of its own threw, for what is underneath', () => { + expect(failureOf(new Error('no detail for 1', { cause: answered(404) }))).toBe('404'); + // Another copy of ky: a name and a shape, not this package's class. + expect(failureOf(Object.assign(new Error('Not Found'), { response: { status: 410 } }))).toBe( + '410', + ); + }); + + it('names anything else an error — a site’s own about an answer it could not use among it', () => { + expect( + failureOf(Object.assign(new Error('an empty body'), { response: { status: 200 } })), + ).toBe('error'); + // Though a status that is no success is the source's, a `304` among them. + expect(failureOf(Object.assign(new Error('moved'), { statusCode: 302 }))).toBe('302'); + expect(failureOf(answered(304))).toBe('304'); + expect(failureOf(new SyntaxError('Unexpected token < in JSON'))).toBe('error'); + expect(failureOf('nope')).toBe('error'); + expect(failureOf(undefined)).toBe('error'); + }); +}); + +describe('unanswered', () => { + it('is a source that did not answer, or said not now', () => { + for (const error of [ + answered(429), + answered(503), + answered(408), + new TypeError('fetch failed'), + new TimeoutError(new Request('https://example.tv/')), + ]) { + expect(unanswered(error)).toBe(true); + } + }); + + it('is not a source that answered no, nor anything else', () => { + for (const error of [answered(404), answered(400), new SyntaxError('bad JSON'), 'nope']) { + expect(unanswered(error)).toBe(false); + } + }); +}); diff --git a/test/fixtures/thread-flaky.config.ts b/test/fixtures/thread-flaky.config.ts new file mode 100644 index 0000000..04548fb --- /dev/null +++ b/test/fixtures/thread-flaky.config.ts @@ -0,0 +1,27 @@ +// A config whose factory fails the first time it is asked — a fetch that did +// not answer — and answers after. +import { defineConfig } from '../../src/config.js'; + +let asked = 0; + +export default defineConfig(() => { + asked++; + + if (asked === 1) { + throw new Error('the token service did not answer'); + } + + return { + output: 'guide.xml', + sites: [ + { + site: 'flaky.example', + channels: [{ xmltvId: 'one', siteId: '1' }], + async request() { + return {}; + }, + parseDay: () => [], + }, + ], + }; +}); diff --git a/test/fixtures/thread-unreadable.config.ts b/test/fixtures/thread-unreadable.config.ts new file mode 100644 index 0000000..a25395e --- /dev/null +++ b/test/fixtures/thread-unreadable.config.ts @@ -0,0 +1,5 @@ +// A config module that cannot be read, and says why with what no thread can +// be handed: a function in its error's cause. +throw new Error('the config could not be read', { cause: { why: 'busy', retry() {} } }); + +export {}; diff --git a/test/fixtures/thread.config.ts b/test/fixtures/thread.config.ts index 9d9b9b7..8f915b7 100644 --- a/test/fixtures/thread.config.ts +++ b/test/fixtures/thread.config.ts @@ -80,6 +80,54 @@ const sites: SiteConfig[] = [ }, parseDay: () => [], }, + { + // The same, with nothing to say why: what it throws is no error at all. + site: 'crashing-quietly.example', + channels: one, + request: () => { + setTimeout(() => { + throw undefined; + }, 0); + + return new Promise(() => {}); + }, + parseDay: () => [], + }, + { + // A list that fails with what cannot be read: a cause whose getter throws. + site: 'unreadable.example', + channels: () => { + throw Object.defineProperty(new Error('no lineup'), 'cause', { + get() { + throw new Error('no reading this'); + }, + }); + }, + request: async () => ({}), + parseDay: () => [], + }, + { + // A failure whose cause no thread can be handed: a function in it. + site: 'odd-cause.example', + channels: one, + async request() { + throw new Error('the source said no', { cause: { status: 'busy', retry() {} } }); + }, + parseDay: () => [], + }, + { + // The same with an object of its own, which says why only in its fields. + site: 'crashing-plainly.example', + channels: one, + request: () => { + setTimeout(() => { + throw { reason: 'out of cheese' }; + }, 0); + + return new Promise(() => {}); + }, + parseDay: () => [], + }, { // A note whose fields no thread can be handed, nor JSON written: a cycle, // and a function inside it. diff --git a/test/grabber.test.ts b/test/grabber.test.ts index ec506c3..c1d0ca4 100644 --- a/test/grabber.test.ts +++ b/test/grabber.test.ts @@ -1,6 +1,7 @@ import { createServer } from 'node:http'; import type { IncomingMessage, ServerResponse } from 'node:http'; import type { AddressInfo } from 'node:net'; +import { Writable } from 'node:stream'; import { HTTPError, NetworkError } from 'ky'; import { describe, expect, expectTypeOf, it, vi } from 'vitest'; import type { @@ -15,14 +16,19 @@ import type { XmltvProgramme } from '../src/xmltv/types.js'; import { fellShort, grab, + ReporterError, resolveAllowance, resolveChannels, resolveSites, SiteStateHandle, + StateKey, UnchangedError, } from '../src/grabber/main.js'; import { errorMessage } from '../src/core/error.js'; import type { EpgEvent } from '../src/core/events.js'; +import { MANY_LABELS, openSession } from '../src/grabber/session.js'; +import { SiteRun } from '../src/grabber/site-run.js'; +import { combineReporters, jsonReporter } from '../src/core/reporters.js'; import { collect } from './reporting.js'; import type { ChannelsBatching, @@ -4328,10 +4334,9 @@ describe('what a run reports', () => { // // A hold is identified by its duration, which is the one thing no other // timer here shares: `ky`'s own default timeout is ten seconds, this is - // thirty. So: was one set, and was it cleared. + // thirty. So: was one set, and does it hold the process. const HOLD_MS = 30_000; const set = vi.spyOn(globalThis, 'setTimeout'); - const cleared = vi.spyOn(globalThis, 'clearTimeout'); try { const report = collect(); @@ -4362,9 +4367,10 @@ describe('what a run reports', () => { .filter((call) => call.ms === HOLD_MS); // One was set — without this the test would pass by holding nothing — - // and it was cleared rather than left counting down. + // and it holds the process no longer: still counting down, so it lets go + // of whatever waits behind it, but kept alive by nothing. expect(holds).toHaveLength(1); - expect(cleared.mock.calls.map(([handle]) => handle)).toContain(holds[0]!.handle); + expect((holds[0]!.handle as NodeJS.Timeout).hasRef()).toBe(false); expect(summary).toMatchObject({ failed: 0, sitesFailed: 1 }); expect(report.of('site:failed')).toHaveLength(1); expect(report.of('site:done')).toEqual([ @@ -4372,7 +4378,6 @@ describe('what a run reports', () => { ]); } finally { set.mockRestore(); - cleared.mockRestore(); server.close(); } }); @@ -4433,6 +4438,1091 @@ describe('what a run reports', () => { }); }); +describe('what a run says its requests were for', () => { + /** An error as ky throws one for a status, shaped rather than made. */ + const status = (code: number): Error => + Object.assign(new Error(`Request failed with status code ${code}`), { + name: 'HTTPError', + response: { status: code }, + }); + + const doneOf = (events: EpgEvent[]) => + events.find((event) => event.type === 'site:done') as Extract; + + it('counts each kind of request apart, with what failed them', async () => { + const report = collect(); + const config = makeConfig({ + requestLabel: 'listings', + async parseDay({ day, paced }) { + // Three details, one the source has none of — which the parse goes on + // to catch, and is counted all the same. + await Promise.all( + ['a', 'b', 'gone'].map((id) => + paced( + async () => { + if (id === 'gone') { + throw status(404); + } + + return id; + }, + { label: 'detail' }, + ).catch(() => undefined), + ), + ); + await paced( + async () => { + throw Object.assign(new Error('took too long'), { name: 'TimeoutError' }); + }, + { label: 'detail' }, + ).catch(() => undefined); + await paced(async () => 'unnamed'); + + return [programme(`${day}T06:00:00.000Z`)]; + }, + }); + + await grab([config], { cache: new MemoryCache(), now: NOW, reporter: report.reporter }); + + const done = doneOf(report.events); + + expect(done.requests).toBe(6); + expect(done.requestsBy).toEqual({ + listings: { requests: 1, requestMs: expect.any(Number), failed: {} }, + detail: { requests: 4, requestMs: expect.any(Number), failed: { 404: 1, timeout: 1 } }, + paced: { requests: 1, requestMs: expect.any(Number), failed: {} }, + }); + // In the order each was first asked for. + expect(Object.keys(done.requestsBy)).toEqual(['listings', 'detail', 'paced']); + expect(Object.values(done.requestsBy).every(({ requestMs }) => requestMs >= 0)).toBe(true); + expect( + Object.values(done.requestsBy).reduce((total, { requestMs }) => total + requestMs, 0), + ).toBe(done.requestMs); + }); + + it('names a fetched channel list, planned requests and a stream by default', async () => { + const report = collect(); + const listed = makeConfig({ + site: 'listed.example', + channels: async () => [channel('one.example')], + }); + const streamed: StreamSiteConfig = { + site: 'stream.example', + channels: [channel('a')], + days: 1, + async *stream({ channels, days, paced }) { + await paced(async () => 'page'); + yield { channel: channels[0]!, day: days[0]!, programmes: [] }; + }, + }; + + await grab([listed, streamed], { + cache: new MemoryCache(), + now: NOW, + reporter: report.reporter, + }); + + const by = (site: string) => + ( + report.events.find((event) => event.type === 'site:done' && event.site === site) as Extract< + EpgEvent, + { type: 'site:done' } + > + ).requestsBy; + + expect(Object.keys(by('listed.example'))).toEqual(['channels', 'request']); + expect(by('stream.example')).toEqual({ + stream: { requests: 1, requestMs: expect.any(Number), failed: {} }, + }); + }); + + it('does not wait on a request a parse let go of, which may never settle', async () => { + const report = collect(); + const config = makeConfig({ + parseDay({ day, paced }) { + // Asked for, not waited on — and never answered. + void paced(() => new Promise(() => {}), { label: 'prefetch' }); + + return [programme(`${day}T06:00:00.000Z`)]; + }, + }); + + // Done, rather than held by it for ever. + const summary = await grab([config], { + cache: new MemoryCache(), + now: NOW, + reporter: report.reporter, + }); + + expect(summary.fetched).toBe(1); + expect(report.events.filter((event) => event.type === 'site:done')).toHaveLength(1); + }); + + it('says a site failed whose state could not be saved, with what it did', async () => { + const report = collect(); + const cache = new MemoryCache(); + + cache.setState = async () => { + throw new Error('the disk is full'); + }; + + const config = makeConfig({ + parseDay({ day, state }) { + state.set('cursor', day); + + return [programme(`${day}T06:00:00.000Z`)]; + }, + }); + + const summary = await grab([config], { cache, now: NOW, reporter: report.reporter }); + + // Failed once, and said so — and done, with what it fetched and asked. + expect(summary).toMatchObject({ fetched: 1, sitesFailed: 1 }); + expect(report.events.filter((event) => event.type === 'site:failed')).toEqual([ + expect.objectContaining({ error: expect.objectContaining({ message: 'the disk is full' }) }), + ]); + expect(report.events.filter((event) => event.type === 'site:done')).toEqual([ + expect.objectContaining({ fetched: 1, sitesFailed: 1, requests: 1 }), + ]); + }); + + it('counts a site that failed, and could not save its state either, once', async () => { + const report = collect(); + const cache = new MemoryCache(); + + cache.setState = async () => { + throw new Error('the disk is full'); + }; + + const config = makeConfig({ + // Its list fetched, remembered — and then refused. + channels: async ({ state }) => { + state.set('token', 'abc'); + + throw new Error('the list is gone'); + }, + }); + + const summary = await grab([config], { cache, now: NOW, reporter: report.reporter }); + + expect(summary.sitesFailed).toBe(1); + expect(report.events.filter((event) => event.type === 'site:failed')).toEqual([ + expect.objectContaining({ error: expect.objectContaining({ message: 'the list is gone' }) }), + ]); + expect(report.events).toContainEqual( + expect.objectContaining({ + type: 'site:warning', + message: 'what it remembered could not be saved either: the disk is full', + }), + ); + expect(report.events.filter((event) => event.type === 'site:done')).toHaveLength(1); + }); + + it("names a stream's fetches after its requestLabel, where a fetch names none", async () => { + const report = collect(); + const streamed: StreamSiteConfig = { + site: 'stream.example', + channels: [channel('a')], + days: 1, + requestLabel: 'pages', + async *stream({ channels, days, paced }) { + await paced(async () => 'page 1'); + await paced(async () => 'page 2'); + await paced(async () => 'an episode', { label: 'episodes' }); + yield { channel: channels[0]!, day: days[0]!, programmes: [] }; + }, + }; + + await grab([streamed], { cache: new MemoryCache(), now: NOW, reporter: report.reporter }); + + expect(doneOf(report.events).requestsBy).toEqual({ + pages: { requests: 2, requestMs: expect.any(Number), failed: {} }, + episodes: { requests: 1, requestMs: expect.any(Number), failed: {} }, + }); + }); + + it("sums every site's for the run", async () => { + const report = collect(); + const sites = ['a.example', 'b.example', 'c.example'].map((site) => + makeConfig({ + site, + async request() { + if (site !== 'a.example') { + throw status(503); + } + + return {}; + }, + }), + ); + + await grab(sites, { cache: new MemoryCache(), now: NOW, reporter: report.reporter }); + + expect(report.events.at(-1)).toMatchObject({ type: 'grab:done' }); + expect((report.events.at(-1) as Extract).requestsBy).toEqual({ + request: { requests: 3, requestMs: expect.any(Number), failed: { 503: 2 } }, + }); + }); + + it('fails the grab, rather than saying it of the site, should a site’s turn throw', async () => { + const report = collect(); + const fault = new Error('a fault in the package'); + const run = SiteRun.prototype.run; + const slow = makeConfig({ + site: 'slow.example', + async request() { + await new Promise((resolve) => setTimeout(resolve, 30)); + + return {}; + }, + }); + // The first site's turn throws; the other is still going. + const running = vi.spyOn(SiteRun.prototype, 'run').mockImplementation(function (this: SiteRun) { + return running.mock.calls.length === 1 ? Promise.reject(fault) : run.call(this); + }); + + try { + await expect( + grab([makeConfig(), slow], { + cache: new MemoryCache(), + now: NOW, + reporter: report.reporter, + }), + ).rejects.toBe(fault); + // Nothing made up for the site: what it did is not knowable. And the run + // went on to its end, the other site with it. + expect(report.events.filter((event) => event.type === 'site:failed')).toEqual([]); + expect(report.events.filter((event) => event.type === 'site:done')).toEqual([ + expect.objectContaining({ site: 'slow.example', fetched: 1 }), + ]); + // Nor said to have finished as it should: it rejects instead. + expect(report.events.filter((event) => event.type === 'grab:done')).toEqual([]); + } finally { + running.mockRestore(); + } + }); + + it('fails the grab with a fault in a site’s turn, though the run was cancelled', async () => { + const stop = new AbortController(); + const fault = new Error('a fault in the package'); + const running = vi.spyOn(SiteRun.prototype, 'run').mockImplementation(async () => { + stop.abort(new Error('run cancelled')); + + throw fault; + }); + + try { + await expect( + grab([makeConfig()], { cache: new MemoryCache(), now: NOW, signal: stop.signal }), + ).rejects.toBe(fault); + } finally { + running.mockRestore(); + } + }); + + it('lets a cancelled site on this thread wind down before the run answers', async () => { + const stop = new AbortController(); + const report = collect(); + const slow = new MemoryCache(); + const save = slow.setState.bind(slow); + + // A save that takes a while, as a store across a network does. + slow.setState = async (...args) => { + await new Promise((resolve) => setTimeout(resolve, 50)); + + return save(...args); + }; + + await grab( + [ + makeConfig({ + parseDay({ day, state }) { + state.set('last', day); + stop.abort(new Error('run cancelled')); + + return [programme(`${day}T06:00:00.000Z`)]; + }, + }), + ], + { cache: slow, now: NOW, signal: stop.signal, reporter: report.reporter }, + ); + + // Its turn said to the end, and what it remembered saved, before the run + // said it was cancelled. + expect( + report.events + .filter((event) => event.type === 'site:done' || event.type === 'run:cancelled') + .map((event) => event.type), + ).toEqual(['site:done', 'run:cancelled']); + expect(await slow.getState('example.com', StateKey.SITE)).toBeDefined(); + }); + + it('counts no request a cancel dropped before its turn', async () => { + const stop = new AbortController(); + const report = collect(); + const config = makeConfig({ + async parseDay({ day, paced }) { + // Three at once, at a concurrency of one: the first cancels the run, + // and the other two never get their turn. + await Promise.allSettled( + [1, 2, 3].map((n) => + paced( + async () => { + if (n === 1) { + stop.abort(new Error('run cancelled')); + } + + return n; + }, + { label: 'detail' }, + ), + ), + ); + + return [programme(`${day}T06:00:00.000Z`)]; + }, + }); + + await grab([config], { + cache: new MemoryCache(), + now: NOW, + signal: stop.signal, + reporter: report.reporter, + }); + + expect(doneOf(report.events).requestsBy.detail).toEqual({ + requests: 1, + requestMs: expect.any(Number), + failed: {}, + }); + }); + + it('counts a request under way when the cancel came, though it ends after the site does', async () => { + const stop = new AbortController(); + const report = collect(); + const config = makeConfig({ + // Sent, and still going when the run is cancelled — and when the site + // says it is done. + async request() { + stop.abort(new Error('run cancelled')); + await new Promise((resolve) => setTimeout(resolve, 30)); + + return {}; + }, + }); + + await grab([config], { + cache: new MemoryCache(), + now: NOW, + signal: stop.signal, + reporter: report.reporter, + }); + + expect(doneOf(report.events)).toMatchObject({ + requests: 1, + requestsBy: { request: { requests: 1 } }, + }); + }); + + it('lists the labels in the order each was first sent, whichever answered first', async () => { + const report = collect(); + const config = makeConfig({ + concurrency: 2, + async parseDay({ day, paced }) { + await Promise.all([ + paced(() => new Promise((resolve) => setTimeout(resolve, 30)), { label: 'md5' }), + paced(async () => 'at once', { label: 'programs' }), + ]); + + return [programme(`${day}T06:00:00.000Z`)]; + }, + }); + + await grab([config], { cache: new MemoryCache(), now: NOW, reporter: report.reporter }); + + expect(Object.keys(doneOf(report.events).requestsBy)).toEqual(['request', 'md5', 'programs']); + expect( + Object.keys((report.events.at(-1) as Extract).requestsBy), + ).toEqual(['request', 'md5', 'programs']); + }); + + it('refuses a label that is no name', async () => { + const report = collect(); + const unnamed = makeConfig({ site: 'unnamed.example', requestLabel: '' }); + const numbered = makeConfig({ + site: 'numbered.example', + async parseDay({ day, paced }) { + await paced(async () => 'detail', { label: 7 as never }); + + return [programme(`${day}T06:00:00.000Z`)]; + }, + }); + + const summary = await grab([unnamed, numbered], { + cache: new MemoryCache(), + now: NOW, + reporter: report.reporter, + }); + + // The site's setting fails the site, as any of its settings would; a call's + // fails what it was called for. + expect(report.events).toContainEqual( + expect.objectContaining({ + type: 'site:failed', + site: 'unnamed.example', + error: expect.objectContaining({ + message: + 'Site "unnamed.example": requestLabel names what requests are for, as a word — ' + + 'letters and digits, a letter among them, joined by . _ / or - (got an empty string)', + }), + }), + ); + // As a site that never ran: its `site:done` too, with nothing done. + expect(report.events).toContainEqual({ + type: 'site:done', + level: 'info', + phase: 'grab', + site: 'unnamed.example', + requests: 0, + ms: 0, + requestMs: 0, + requestsBy: {}, + fetched: 0, + empty: 0, + fromCache: 0, + unchanged: 0, + failed: 0, + sitesFailed: 1, + }); + expect(report.events).toContainEqual( + expect.objectContaining({ + type: 'entry:failed', + site: 'numbered.example', + error: expect.objectContaining({ + message: expect.stringMatching(/a paced request's label names .*\(got a number\)$/), + }), + }), + ); + expect(summary).toMatchObject({ sitesFailed: 1, failed: 1 }); + }); + + it('says the whole run though a reporter throws, and rejects with what it threw once done', async () => { + const fellOver = new Error('the reporter fell over'); + /** A run whose reporter throws at every event of `type`, after keeping it. */ + const throwingAt = async ( + type: EpgEvent['type'], + config: SiteConfig, + cache: CacheStore = new MemoryCache(), + ) => { + const events: EpgEvent[] = []; + const rejected = await grab([config], { + cache, + now: NOW, + reporter: (event) => { + events.push(event); + + if (event.type === type) { + throw fellOver; + } + }, + }).then( + () => undefined, + (error: unknown) => error, + ); + const done = events.at(-1) as Extract; + + return { + rejected, + done, + said: events + .filter((event) => event.type === 'site:failed' || event.type === 'site:done') + .map((event) => event.type), + }; + }; + + // At the failure it said: counted, and said, once — its `site:done` after. + const failing = await throwingAt( + 'site:failed', + makeConfig({ + channels: () => { + throw new Error('no lineup'); + }, + }), + ); + + // What it threw, once, with how often and at what. + expect(failing.rejected).toBeInstanceOf(ReporterError); + expect((failing.rejected as ReporterError).errors).toEqual([fellOver]); + expect((failing.rejected as ReporterError).thrown).toEqual([ + { error: fellOver, times: 1, at: { 'site:failed': 1 } }, + ]); + expect(failing.said).toEqual(['site:failed', 'site:done']); + expect(failing.done).toMatchObject({ type: 'grab:done', sitesFailed: 1 }); + + // At every `site:done`, of a site that did not fail: not made one. + const finished = await throwingAt('site:done', makeConfig()); + + expect((finished.rejected as ReporterError).thrown).toEqual([ + { error: fellOver, times: 1, at: { 'site:done': 1 } }, + ]); + expect(finished.said).toEqual(['site:done']); + expect(finished.done).toMatchObject({ type: 'grab:done', fetched: 1, sitesFailed: 0 }); + + // At a failure said as it let go — what it remembered could not be saved — + // which still has its `site:done` said after it. + const unsaving = new MemoryCache(); + + unsaving.setState = async () => { + throw new Error('the disk is full'); + }; + + const unsaved = await throwingAt( + 'site:failed', + makeConfig({ + parseDay({ day, state }) { + state.set('last', day); + + return [programme(`${day}T06:00:00.000Z`)]; + }, + }), + unsaving, + ); + + expect((unsaved.rejected as ReporterError).errors).toEqual([fellOver]); + expect(unsaved.said).toEqual(['site:failed', 'site:done']); + expect(unsaved.done).toMatchObject({ fetched: 1, sitesFailed: 1 }); + + // At a warning said inside a request's turn: the request sent, and counted. + const warned = await throwingAt( + 'site:warning', + makeConfig({ + async parseDay({ day, paced }) { + for (let id = 0; id <= MANY_LABELS; id++) { + await paced(async () => id, { label: `item-${id}` }); + } + + return [programme(`${day}T06:00:00.000Z`)]; + }, + }), + ); + + expect((warned.rejected as ReporterError).thrown).toEqual([ + { error: fellOver, times: 1, at: { 'site:warning': 1 } }, + ]); + expect(warned.done).toMatchObject({ fetched: 1, failed: 0 }); + expect(Object.keys(warned.done.requestsBy)).toHaveLength(MANY_LABELS + 2); + }); + + it('rejects with what a reporter threw at grab:done, though one joined to it is async', async () => { + const sinkBroke = new Error('sink broke'); + + await expect( + grab([makeConfig()], { + cache: new MemoryCache(), + now: NOW, + reporter: combineReporters( + async () => {}, + (event) => { + if (event.type === 'grab:done') { + throw sinkBroke; + } + }, + ), + }), + ).rejects.toMatchObject({ thrown: [{ error: sinkBroke, at: { 'grab:done': 1 } }] }); + }); + + it('says a site whose error cannot be read, rather than failing the run for it', async () => { + const { proxy, revoke } = Proxy.revocable(new Error('gone'), {}); + + revoke(); + + const lines: string[] = []; + // The JSON reporter, which reads an error's fields. + const summary = await grab( + [ + makeConfig({ + channels: () => { + throw proxy; + }, + }), + ], + { + cache: new MemoryCache(), + now: NOW, + reporter: jsonReporter({ + stream: new Writable({ + write(chunk, _encoding, done) { + lines.push(String(chunk)); + done(); + }, + }), + }), + }, + ); + + expect(summary.sitesFailed).toBe(1); + expect(lines.join('')).toContain('[something that cannot be read]'); + }); + + it('names each site its config named nothing, so no reporter is handed none — and two, two', async () => { + const report = collect(); + const nameless = (): SiteConfig => ({ ...makeConfig(), site: undefined as never }); + + // An empty name is none either, as it is refused as none. + const summary = await grab([nameless(), { ...makeConfig(), site: '' }], { + cache: new MemoryCache(), + now: NOW, + reporter: report.reporter, + }); + + expect( + report.events + .filter((event) => event.type === 'site:failed' || event.type === 'site:done') + .map((event) => `${event.type} ${(event as { site: string }).site}`), + ).toEqual([ + 'site:failed a site with no name (1)', + 'site:done a site with no name (1)', + 'site:failed a site with no name (2)', + 'site:done a site with no name (2)', + ]); + expect(summary.sitesFailed).toBe(2); + }); + + it('refuses a list handed where its options go, as it does a label', async () => { + const report = collect(); + const config = makeConfig({ + async parseDay({ day, paced }) { + await paced(async () => 'detail', ['detail'] as never); + + return [programme(`${day}T06:00:00.000Z`)]; + }, + }); + + await grab([config], { cache: new MemoryCache(), now: NOW, reporter: report.reporter }); + + expect(report.events).toContainEqual( + expect.objectContaining({ + type: 'site:warning', + message: expect.stringContaining( + "options are an object, such as { label: 'detail' } (got an array)", + ), + }), + ); + expect(doneOf(report.events).requestsBy.paced).toBeUndefined(); + }); + + it('refuses a label handed where its options go, rather than counting it as none', async () => { + const report = collect(); + const config = makeConfig({ + channels: [channel('one.example'), channel('two.example')], + async parseDay({ channel: { siteId }, day, paced }) { + // A different one each time, as a label made from the request would be. + await paced(async () => 'detail', `detail-${siteId}` as never); + + return [programme(`${day}T06:00:00.000Z`)]; + }, + }); + + const summary = await grab([config], { + cache: new MemoryCache(), + now: NOW, + reporter: report.reporter, + }); + const message = + 'Site "example.com": a paced request\'s options are an object, such as ' + + "{ label: 'detail' } (got a string)"; + + expect(report.events).toContainEqual( + expect.objectContaining({ + type: 'entry:failed', + error: expect.objectContaining({ message }), + }), + ); + // Said once for the site, though each was another string. + expect(report.events.filter((event) => event.type === 'site:warning')).toEqual([ + expect.objectContaining({ message: `${message} — no request is sent with it` }), + ]); + expect(summary.failed).toBe(2); + }); + + it('names a label after what is on every object, and counts it as any other', async () => { + const report = collect(); + const config = makeConfig({ + requestLabel: 'constructor', + async parseDay({ day, paced }) { + await paced( + async () => { + throw status(404); + }, + { label: 'toString' }, + ).catch(() => undefined); + + return [programme(`${day}T06:00:00.000Z`)]; + }, + }); + + await grab([config], { cache: new MemoryCache(), now: NOW, reporter: report.reporter }); + + expect(doneOf(report.events).requestsBy).toEqual({ + constructor: { requests: 1, requestMs: expect.any(Number), failed: {} }, + toString: { requests: 1, requestMs: expect.any(Number), failed: { 404: 1 } }, + }); + expect((report.events.at(-1) as Extract).requestsBy).toEqual( + doneOf(report.events).requestsBy, + ); + // Nothing every object has was written to. + expect(({} as { requests?: unknown }).requests).toBeUndefined(); + }); + + it('counts a word written composed and with a combining mark as one label', async () => { + const report = collect(); + const config = makeConfig({ + requestLabel: 'rela\u0301cie', + async parseDay({ day, paced }) { + await paced(async () => 'detail', { label: 'relácie' }); + await paced(async () => 'detail', { label: 'rela\u0301cie' }); + + return [programme(`${day}T06:00:00.000Z`)]; + }, + }); + + await grab([config], { cache: new MemoryCache(), now: NOW, reporter: report.reporter }); + + expect(doneOf(report.events).requestsBy).toEqual({ + relácie: { requests: 3, requestMs: expect.any(Number), failed: {} }, + }); + }); + + it('refuses a label that would not read as one name, or would be the list fetch', async () => { + for (const [label, said] of [ + [' ', '(got " ")'], + ['detail: 404', '(got "detail: 404")'], + ['detail calls', '(got "detail calls")'], + ['channels', 'cannot be "channels"'], + // Read as a status beside the ones it is printed with, and put first. + ['404', '(got "404")'], + ['2024', '(got "2024")'], + ] as const) { + const report = collect(); + + await grab([makeConfig({ requestLabel: label })], { + cache: new MemoryCache(), + now: NOW, + reporter: report.reporter, + }); + + expect(report.events).toContainEqual( + expect.objectContaining({ + type: 'site:failed', + error: expect.objectContaining({ message: expect.stringContaining(said) }), + }), + ); + } + + // What one name may be: words joined, in any script — a letter's marks + // with it, as a vowel sign or a decomposed accent is. + for (const label of [ + 'detail', + 'detail-page', + 'v2/episodes', + 'podrobnosti_relácie', + 'podrobnosti_rela\u0301cie', + 'विवरण', + 'รายละเอียด', + 'api.1', + ]) { + const report = collect(); + + await grab([makeConfig({ requestLabel: label })], { + cache: new MemoryCache(), + now: NOW, + reporter: report.reporter, + }); + + // Counted composed, however it was written. + expect(Object.keys(doneOf(report.events).requestsBy)).toEqual([label.normalize('NFC')]); + } + }); + + it('throws a paced label that is no name where it is called, past a catch meant for a 404', async () => { + const report = collect(); + const config = makeConfig({ + async parseDay({ day, paced }) { + // As a parse does for details: a missing one is no reason to fail. + await paced(async () => 'detail', { label: '' }).catch(() => undefined); + + return [programme(`${day}T06:00:00.000Z`)]; + }, + }); + + const summary = await grab([config], { + cache: new MemoryCache(), + now: NOW, + reporter: report.reporter, + }); + + // Said, rather than every detail quietly missing. + expect(summary.failed).toBe(1); + expect(report.events).toContainEqual( + expect.objectContaining({ + type: 'entry:failed', + error: expect.objectContaining({ + message: expect.stringContaining("a paced request's label names what requests are for"), + }), + }), + ); + }); + + it('says a paced label that is no name once for the site, past a try around the await', async () => { + const report = collect(); + const config = makeConfig({ + channels: [channel('one.example'), channel('two.example')], + async parseDay({ day, paced }) { + let detail: string | undefined; + + // As a parse may write it — which catches what is thrown as well. + try { + detail = await paced(async () => 'detail', { label: 'detail calls' }); + } catch { + detail = undefined; + } + + return [ + { ...programme(`${day}T06:00:00.000Z`), title: [{ value: detail ?? 'no detail' }] }, + ]; + }, + }); + + await grab([config], { cache: new MemoryCache(), now: NOW, reporter: report.reporter }); + + // Two channel-days that swallowed it, and one warning of the site's. + expect( + report.events.filter( + (event) => event.type === 'site:warning' && event.message.includes('detail calls'), + ), + ).toEqual([ + expect.objectContaining({ + site: 'example.com', + message: expect.stringContaining('— no request is sent with it'), + }), + ]); + }); + + it('says a label that is no name once for each kind of mistake, not for each value', async () => { + const report = collect(); + let calls = 0; + const config = makeConfig({ + channels: [channel('one.example'), channel('two.example')], + async parseDay({ day, paced }) { + calls++; + // Built afresh for each channel-day, as a parse building its label from + // what each request is for would: an object, and a url. + try { + await paced(async () => 'detail', { label: ['detail'] as never }); + } catch { + // Thrown where it is called, as a label that is none is. + } + + await paced(async () => 'detail', { label: `https://example.tv/detail/${calls}` }); + + return [programme(`${day}T06:00:00.000Z`)]; + }, + }); + + await grab([config], { cache: new MemoryCache(), now: NOW, reporter: report.reporter }); + + // Two channel-days that failed for it, and one warning for each kind. + expect(report.events.filter((event) => event.type === 'entry:failed')).toHaveLength(2); + expect( + report.events + .filter((event) => event.type === 'site:warning') + .map((event) => (event as { message: string }).message.match(/\(got (.*)\)/)?.[1]), + ).toEqual(['an array', '"https://example.tv/detail/1"']); + }); + + it('counts what a site threw that cannot be read as an error, and hands it back as it was', async () => { + const report = collect(); + // What a site may throw: a value whose every property throws. + const hostile = new Proxy( + {}, + { + get() { + throw new Error('no reading this'); + }, + }, + ); + let caught: unknown; + const config = makeConfig({ + async parseDay({ day, paced }) { + try { + await paced( + async () => { + throw hostile; + }, + { label: 'detail' }, + ); + } catch (error) { + caught = error; + } + + return [programme(`${day}T06:00:00.000Z`)]; + }, + }); + + await grab([config], { cache: new MemoryCache(), now: NOW, reporter: report.reporter }); + + expect(caught).toBe(hostile); + expect(doneOf(report.events).requestsBy.detail).toEqual({ + requests: 1, + requestMs: expect.any(Number), + failed: { error: 1 }, + }); + }); + + it('says what a session settled before the run says as the run it joins says it', async () => { + const before: EpgEvent['type'][] = []; + const after: EpgEvent['type'][] = []; + // Paced, so its queue says when it is held as well. + const session = openSession( + makeConfig({ rateLimit: { requests: MANY_LABELS, perMs: 20 } }), + new MemoryCache(), + { emit: (event) => before.push(event.type) }, + ); + + try { + session.joinRun({ requested: () => {}, emit: (event) => after.push(event.type) }); + + for (let id = 0; id <= MANY_LABELS; id++) { + await session.send(async () => id, { label: `item-${id}` }); + } + } finally { + session.pacing.dispose(); + } + + expect(before).toEqual([]); + expect(after).toContain('site:warning'); + expect(after).toContain('pacing:rateLimit'); + }); + + it('counts no failure for a cancelled run, nor for a source saying nothing changed', async () => { + const stop = new AbortController(); + const cancelled = collect(); + const waiting = makeConfig({ + request: ({ signal }) => + new Promise((_resolve, reject) => { + signal?.addEventListener('abort', () => reject(signal.reason), { once: true }); + stop.abort(new Error('run cancelled')); + }), + }); + + await grab([waiting], { + cache: new MemoryCache(), + now: NOW, + signal: stop.signal, + reporter: cancelled.reporter, + }); + + expect(doneOf(cancelled.events).requestsBy).toEqual({ + request: { requests: 1, requestMs: expect.any(Number), failed: {} }, + }); + + const unchanged = collect(); + + await grab( + [ + makeConfig({ + async request() { + throw new UnchangedError('https://example.com/epg'); + }, + }), + ], + { cache: new MemoryCache(), now: NOW, reporter: unchanged.reporter }, + ); + + expect(doneOf(unchanged.events).requestsBy).toEqual({ + request: { requests: 1, requestMs: expect.any(Number), failed: {} }, + }); + }); + + it('warns a site once whose requests come under many labels, and counts every one', async () => { + /** A run whose parse sends `n` detail calls, each labelled as one request rather than a kind. */ + const labelled = async (n: number) => { + const report = collect(); + + await grab( + [ + makeConfig({ + async parseDay({ day, paced }) { + for (let id = 0; id < n; id++) { + await paced(async () => id, { label: `item-${id}` }); + } + + return [programme(`${day}T06:00:00.000Z`)]; + }, + }), + ], + { cache: new MemoryCache(), now: NOW, reporter: report.reporter }, + ); + + return { + warned: report.events.filter((event) => event.type === 'site:warning'), + labels: Object.keys(doneOf(report.events).requestsBy), + }; + }; + + // With the planned request's own: as many as a site may have, then one over. + expect((await labelled(MANY_LABELS - 1)).warned).toEqual([]); + expect((await labelled(MANY_LABELS)).warned).toEqual([ + expect.objectContaining({ + site: 'example.com', + message: + 'its requests have come under more than 64 labels — a label names a kind of request, ' + + 'such as detail, not one request: each is counted apart, in site:done and on its line', + }), + ]); + + // Once, however many more — and none of them left out. + const many = await labelled(MANY_LABELS + 20); + + expect(many.warned).toHaveLength(1); + expect(many.labels).toHaveLength(MANY_LABELS + 21); + }); + + it('counts what a source answered as the cancel came, and not the cancel however it is wrapped', async () => { + /** What one request failed with, thrown once the run is cancelled. */ + const failedWith = async ( + thrown: (reason: unknown) => unknown, + ): Promise | undefined> => { + const stop = new AbortController(); + const report = collect(); + + await grab( + [ + makeConfig({ + async request() { + stop.abort(new Error('run cancelled')); + + throw thrown(stop.signal.reason); + }, + }), + ], + { cache: new MemoryCache(), now: NOW, signal: stop.signal, reporter: report.reporter }, + ); + + return doneOf(report.events).requestsBy.request?.failed; + }; + const aborted = Object.assign(new Error('This operation was aborted'), { name: 'AbortError' }); + + // The source's answer, which the cancel happened to come with. + expect(await failedWith(() => status(503))).toEqual({ 503: 1 }); + // The cancel, as it is — and beneath what a site made of it. + expect(await failedWith((reason) => reason)).toEqual({}); + expect(await failedWith((reason) => new Error('gave up', { cause: reason }))).toEqual({}); + expect(await failedWith(() => new Error('gave up', { cause: aborted }))).toEqual({}); + }); +}); + describe('what a site can say, and from where', () => { it('lets a fetched channel list speak, which it had no way to before', async () => { // `request` and `parseDay` always had `log`/`warn`; `channels` was handed diff --git a/test/pacing.test.ts b/test/pacing.test.ts index e841948..2ba3182 100644 --- a/test/pacing.test.ts +++ b/test/pacing.test.ts @@ -1,7 +1,8 @@ +import { getEventListeners } from 'node:events'; import { createServer, type Server } from 'node:http'; import type { AddressInfo } from 'node:net'; import type { KyInstance } from 'ky'; -import { describe, expect, it } from 'vitest'; +import { describe, expect, it, vi } from 'vitest'; import { retryAfterMs, sitePacing } from '../src/grabber/pacing.js'; import type { AnySiteConfig } from '../src/grabber/types.js'; import { emitter } from '../src/core/events.js'; @@ -70,6 +71,77 @@ async function hit(http: KyInstance, url: string): Promise { return response; } +describe('sitePacing, let go of', () => { + it('stops listening to the run’s signal, which may outlive the site', () => { + const run = new AbortController(); + const pacing = sitePacing( + { site: 'a.tv', channels: [], request: async () => ({}), parseDay: () => [] } as never, + { signal: run.signal }, + ); + + expect(getEventListeners(run.signal, 'abort')).toHaveLength(1); + + pacing.dispose(); + + // What listened kept the site's config with it, its channels among it. + expect(getEventListeners(run.signal, 'abort')).toHaveLength(0); + }); + + it('still ends a hold under way, for what waits behind it, holding the process for it no longer', async () => { + const server = await scripted([{ status: 429 }]); + + try { + const { http, queue, dispose } = sitePacing(site({ backoff: { fallbackMs: 40, maxMs: 40 } })); + + await hit(http, server.url); + expect(queue.isPaused).toBe(true); + + // Let go of mid-hold, with a request a parse did not wait for behind it. + dispose(); + + const behind = queue.add(async () => 'answered'); + + await expect(behind).resolves.toBe('answered'); + expect(queue.isPaused).toBe(false); + } finally { + server.close(); + } + }); + + it('holds the process for nothing a request after it asks to wait for', async () => { + const server = await scripted([{ status: 429, headers: { 'retry-after': '600' } }]); + // The hold's own timer, known by its length: process-wide counts of timers + // take in whatever else is about. + const HOLD_MS = 60_000; + const set = vi.spyOn(globalThis, 'setTimeout'); + + try { + const { http, queue, dispose } = sitePacing( + site({ backoff: { fallbackMs: HOLD_MS, maxMs: HOLD_MS } }), + ); + + dispose(); + + // A request its parse did not wait for, answered after the site was + // done: held, but on a timer that keeps nobody waiting. + await hit(http, server.url); + + const holds = set.mock.calls + .map((call, index) => ({ ms: call[1], handle: set.mock.results[index]?.value })) + .filter((call) => call.ms === HOLD_MS); + + expect(queue.isPaused).toBe(true); + expect(holds).toHaveLength(1); + expect((holds[0]!.handle as NodeJS.Timeout).hasRef()).toBe(false); + clearTimeout(holds[0]!.handle as NodeJS.Timeout); + queue.clear(); + } finally { + set.mockRestore(); + server.close(); + } + }); +}); + describe('retryAfterMs', () => { it('reads delta-seconds', () => { expect(retryAfterMs('30')).toBe(30_000); diff --git a/test/readme-examples.ts b/test/readme-examples.ts index 4e40a16..df6ea27 100644 --- a/test/readme-examples.ts +++ b/test/readme-examples.ts @@ -570,6 +570,30 @@ export const askedOnce = defineSiteConfig<{ }, }); +// --- docs/site-config.md: A parse that needs another request ---------------- +export const labelled = defineSiteConfig<{ items: { id: string; start: string; title: string }[] }>( + { + site: 'example.tv', + channels: [], + requestLabel: 'listings', + async request({ channel, day, http }) { + return http.get(`epg/${channel.siteId}/${day}`).json(); + }, + async parseDay({ payload, http, paced, programme }) { + return Promise.all( + payload.items.map(async (item) => { + const detail = await paced( + ({ signal }) => http.get(`detail/${item.id}`, { signal }).json(), + { label: 'detail' }, + ); + + return programme(new Date(item.start), item.title).desc(detail.description); + }), + ); + }, + }, +); + // The mode decides which caps are accepted, and the shape of the context. export const wrongCap = defineSiteConfig({ site: 'example.tv', diff --git a/test/reporters.test.ts b/test/reporters.test.ts index 114976d..6a6fcf4 100644 --- a/test/reporters.test.ts +++ b/test/reporters.test.ts @@ -25,7 +25,14 @@ import type { Reporter, } from '../src/main.js'; import { silent, stamped, PHASES } from '../src/core/events.js'; -import { emitter } from '../src/core/events.js'; +import { + emitter, + keepingThrows, + ReporterError, + RunFailedError, + type ReportedOptions, +} from '../src/core/events.js'; +import { errorMessage } from '../src/core/error.js'; /** Collects lines, so what a reporter wrote can be read back. */ class Sink extends Writable { @@ -202,6 +209,7 @@ describe('render', () => { requests: 96, ms: 42_000, requestMs: 28_500, + requestsBy: {}, fetched: 412, empty: 0, fromCache: 8, @@ -211,6 +219,85 @@ describe('render', () => { }, '[a.tv] 412 fetched, 8 from cache, 0 failed — 96 requests in 42s, 29s waiting', ], + [ + { + type: 'site:done', + site: 'sky.sk', + requests: 5291, + ms: 697_000, + requestMs: 585_000, + requestsBy: { + request: { requests: 49, requestMs: 12_000, failed: {} }, + detail: { requests: 5242, requestMs: 573_000, failed: { 404: 3242, timeout: 3 } }, + }, + fetched: 144, + empty: 0, + fromCache: 0, + unchanged: 0, + failed: 0, + sitesFailed: 0, + }, + // By kind where there was more than one, and what failed them — " and " + // between failures, so the commas stay between kinds. + '[sky.sk] 144 fetched, 0 from cache, 0 failed — 5291 requests ' + + '(request 49, detail 5242: 3242 × 404 and 3 × timeout) in 11m37s, 585s waiting', + ], + [ + { + type: 'site:done', + site: 'one.tv', + requests: 3, + ms: 3000, + requestMs: 2000, + requestsBy: { listings: { requests: 3, requestMs: 2000, failed: { 500: 1 } } }, + fetched: 2, + empty: 0, + fromCache: 0, + unchanged: 0, + failed: 1, + sitesFailed: 0, + }, + // Of one kind, what failed and nothing more: the total says how many. + '[one.tv] 2 fetched, 0 from cache, 1 failed — 3 requests (1 × 500) in 3000ms, 2000ms waiting', + ], + [ + // An entry from elsewhere that says nothing failed by leaving it out. + { + type: 'site:done', + site: 'other.tv', + requests: 3, + ms: 3000, + requestMs: 2000, + requestsBy: { + request: { requests: 1, requestMs: 500 }, + detail: { requests: 2, requestMs: 1500 }, + }, + fetched: 1, + empty: 0, + fromCache: 0, + unchanged: 0, + failed: 0, + sitesFailed: 0, + } as unknown as EpgEventInput, + '[other.tv] 1 fetched, 0 from cache, 0 failed — 3 requests (request 1, detail 2) in 3000ms, 2000ms waiting', + ], + [ + // As an earlier version wrote one, which a log may replay. + { + type: 'site:done', + site: 'old.tv', + requests: 3, + ms: 3000, + requestMs: 2000, + fetched: 3, + empty: 0, + fromCache: 0, + unchanged: 0, + failed: 0, + sitesFailed: 0, + } as unknown as EpgEventInput, + '[old.tv] 3 fetched, 0 from cache, 0 failed — 3 requests in 3000ms, 2000ms waiting', + ], [ { type: 'site:done', @@ -218,6 +305,7 @@ describe('render', () => { requests: 1, ms: 2543, requestMs: 2100, + requestsBy: {}, fetched: 0, empty: 0, fromCache: 0, @@ -257,6 +345,7 @@ describe('render', () => { { type: 'grab:done', loopMaxMs: 0, + requestsBy: {}, fetched: 1, empty: 0, fromCache: 0, @@ -270,6 +359,7 @@ describe('render', () => { { type: 'grab:done', loopMaxMs: 0, + requestsBy: {}, fetched: 1, empty: 1, fromCache: 0, @@ -421,6 +511,7 @@ describe('textReporter', () => { { type: 'grab:done', loopMaxMs: 0, + requestsBy: {}, fetched: 0, empty: 0, fromCache: 0, @@ -444,6 +535,7 @@ describe('textReporter', () => { { type: 'grab:done', loopMaxMs: 0, + requestsBy: {}, fetched: 0, empty: 0, fromCache: 0, @@ -487,6 +579,7 @@ describe('textReporter', () => { { type: 'grab:done', loopMaxMs: 0, + requestsBy: {}, fetched: 0, empty: 0, fromCache: 0, @@ -511,6 +604,7 @@ describe('textReporter', () => { { type: 'grab:done', loopMaxMs: 0, + requestsBy: {}, fetched: 0, empty: 0, fromCache: 0, @@ -606,6 +700,7 @@ describe('progressReporter', () => { { type: 'grab:done', loopMaxMs: 0, + requestsBy: {}, fetched: 6, empty: 0, fromCache: 0, @@ -619,6 +714,32 @@ describe('progressReporter', () => { expect(out.raw.endsWith('Grab done: 6 fetched, 0 from cache, 0 failed\n')).toBe(true); }); + it('counts a site that could not be read among the sites, though it never started', () => { + const out = new Tty(); + const done = { + requests: 0, + ms: 0, + requestMs: 0, + requestsBy: {}, + fetched: 0, + empty: 0, + fromCache: 0, + unchanged: 0, + failed: 0, + }; + + run(progressReporter({ stream: out }), [ + // As a run says a site it could not read: failed, and done. + { type: 'site:failed', site: 'unread.tv', error: new Error('no request') }, + { type: 'site:done', site: 'unread.tv', ...done, sitesFailed: 1 }, + { type: 'site:started', site: 'a.tv', channels: 1, days: 1, entries: 1, requests: 1 }, + { type: 'site:started', site: 'b.tv', channels: 1, days: 1, entries: 1, requests: 1 }, + ]); + + // One of three done — not one of the two that started. + expect(out.raw.endsWith('1/3 sites · 0/2 channel-days · 1 site answered nothing')).toBe(true); + }); + it('writes nothing when the line would say what it already says', () => { const out = new Tty(); @@ -640,6 +761,7 @@ describe('progressReporter', () => { { type: 'grab:done', loopMaxMs: 0, + requestsBy: {}, fetched: 6, empty: 0, fromCache: 0, @@ -824,6 +946,440 @@ describe('emitterReporter and combineReporters', () => { // Nothing to call, and nothing that throws for being called. expect(() => combineReporters()(event({ type: 'serve:reloaded' }))).not.toThrow(); }); + + it('tells every reporter though one throws, and throws what was thrown once all are told', () => { + const told: string[] = []; + const first = new Error('the first fell over'); + const second = new Error('the second did too'); + const throwing = + (name: string, error?: Error): Reporter => + () => { + told.push(name); + + if (error !== undefined) { + throw error; + } + }; + + // One, as it is. + expect(() => + combineReporters(throwing('a', first), throwing('b'))(event({ type: 'serve:reloaded' })), + ).toThrow(first); + expect(told).toEqual(['a', 'b']); + + // Several, together. + let thrown: unknown; + + try { + combineReporters( + throwing('c', first), + throwing('d', second), + )(event({ type: 'serve:reloaded' })); + } catch (error) { + thrown = error; + } + + expect(thrown).toBeInstanceOf(AggregateError); + expect((thrown as AggregateError).errors).toEqual([first, second]); + expect(told).toEqual(['a', 'b', 'c', 'd']); + }); +}); + +describe('keepingThrows and ReporterError', () => { + const at = (type: 'site:done' | 'site:failed' | 'serve:reloaded') => + event( + type === 'serve:reloaded' + ? { type } + : type === 'site:failed' + ? { type, site: 'a.tv', error: new Error('no lineup') } + : { + type, + site: 'a.tv', + requests: 0, + ms: 0, + requestMs: 0, + requestsBy: {}, + fetched: 0, + empty: 0, + fromCache: 0, + unchanged: 0, + failed: 0, + sitesFailed: 0, + }, + ); + + it('keeps what a reporter throws, and throws it once done, with how often and at what', () => { + const broken = new TypeError('cannot read properties of undefined'); + const kept = keepingThrows({ + reporter: () => { + throw broken; + }, + }); + + // Told everything, throwing nothing yet. + expect(() => { + kept.options.reporter!(at('site:done')); + kept.options.reporter!(at('site:done')); + kept.options.reporter!(at('site:failed')); + }).not.toThrow(); + + let thrown: unknown; + + try { + kept.rethrow(); + } catch (error) { + thrown = error; + } + + expect(thrown).toBeInstanceOf(ReporterError); + expect(thrown).toBeInstanceOf(AggregateError); + expect(thrown).toMatchObject({ + name: 'ReporterError', + // The same one at every event, kept once. + errors: [broken], + thrown: [{ error: broken, times: 3, at: { 'site:done': 2, 'site:failed': 1 } }], + untracked: 0, + message: + 'The reporter threw 3 times: TypeError: cannot read properties of undefined ' + + '(2 × at site:done, 1 × at site:failed)', + }); + }); + + it('keeps each kind once, ten at most, and counts the rest', () => { + let n = 0; + const kept = keepingThrows({ + reporter: () => { + // A different message every time: a reporter that puts what it was + // told into what it throws. + throw new Error(`no room for event ${n++}`); + }, + }); + + for (let i = 0; i < 25; i++) { + kept.options.reporter!(at('serve:reloaded')); + } + + let thrown: ReporterError | undefined; + + try { + kept.rethrow(); + } catch (error) { + thrown = error as ReporterError; + } + + expect(thrown?.errors).toHaveLength(10); + expect(thrown?.thrown.map((kind) => kind.times)).toEqual(Array(10).fill(1)); + expect(thrown?.untracked).toBe(15); + expect(thrown?.message).toMatch(/^The reporter threw 25 times: /); + expect(thrown?.message).toMatch(/; and 15 more of other kinds$/); + }); + + it('throws nothing for a reporter that threw nothing, nor for no reporter', () => { + const kept = keepingThrows({ reporter: () => {} }); + + kept.options.reporter!(at('serve:reloaded')); + + expect(() => kept.rethrow()).not.toThrow(); + expect(() => keepingThrows({}).rethrow()).not.toThrow(); + expect(keepingThrows({}).options.reporter).toBeUndefined(); + }); + + it('throws what it kept once what reported through it is settled, and says nothing after', async () => { + const broken = new Error('the reporter fell over'); + const told: string[] = []; + const failing = keepingThrows({ + reporter: (given) => { + told.push(given.type); + + throw broken; + }, + }); + + failing.options.reporter!(at('site:done')); + + // Resolved: what was kept, alone. + await expect(failing.settle(Promise.resolve('done'))).rejects.toBeInstanceOf(ReporterError); + + // And nothing told after: the run is done. + failing.options.reporter!(at('site:failed')); + expect(told).toEqual(['site:done']); + + // Rejected, with something kept: both, neither lost. + const both = keepingThrows({ + reporter: () => { + throw broken; + }, + }); + const ownError = new Error('the store fell over'); + + both.options.reporter!(at('site:done')); + + const thrown = await both.settle(Promise.reject(ownError)).catch((error: unknown) => error); + + expect(thrown).toBeInstanceOf(RunFailedError); + expect(thrown).toBeInstanceOf(AggregateError); + expect(thrown).toMatchObject({ + name: 'RunFailedError', + message: 'the store fell over — and the reporter threw as well', + error: ownError, + reporter: expect.any(ReporterError), + errors: [ownError, expect.any(ReporterError)], + }); + + // Rejected, with nothing kept — or with what was kept, thrown already: as it is. + const quiet = keepingThrows({ reporter: () => {} }); + + await expect(quiet.settle(Promise.reject(ownError))).rejects.toBe(ownError); + await expect(quiet.settle(Promise.resolve(7))).resolves.toBe(7); + }); + + it('throws what was kept as it stood then, though more is counted after', () => { + const kept = keepingThrows({ + reporter: () => { + throw new Error('the reporter fell over'); + }, + }); + + kept.options.reporter!(at('site:done')); + + let thrown: ReporterError | undefined; + + try { + kept.rethrow(); + } catch (error) { + thrown = error as ReporterError; + } + + kept.options.reporter!(at('site:done')); + kept.options.reporter!(at('site:failed')); + + // As its message says. + expect(thrown?.thrown).toEqual([ + { error: expect.any(Error), times: 1, at: { 'site:done': 1 } }, + ]); + expect(thrown?.message).toMatch(/^The reporter threw 1 time:/); + }); + + it('keeps what a reporter written async rejects with, as a throw', async () => { + const rejected = new Error('the sink fell over'); + const kept = keepingThrows({ + // What a reporter is not, though its type lets it be written so. + reporter: async () => { + throw rejected; + }, + }); + + kept.options.reporter!(at('site:done')); + await new Promise((resolve) => setImmediate(resolve)); + + const thrown = await kept.settle(Promise.resolve()).catch((error: unknown) => error); + + expect((thrown as ReporterError).thrown).toEqual([ + { error: rejected, times: 1, at: { 'site:done': 1 } }, + ]); + }); + + it('keeps what reporters joined together reject with, as one of theirs', async () => { + const rejected = new Error('the sink fell over'); + const kept = keepingThrows({ + reporter: combineReporters( + () => {}, + async () => { + throw rejected; + }, + ), + }); + + kept.options.reporter!(at('site:failed')); + await new Promise((resolve) => setImmediate(resolve)); + + await expect(kept.settle(Promise.resolve())).rejects.toMatchObject({ + thrown: [{ error: rejected, times: 1, at: { 'site:failed': 1 } }], + }); + }); + + it('throws what a joined reporter threw at once, though another is written async', async () => { + const unhandled: unknown[] = []; + const listen = (reason: unknown): void => { + unhandled.push(reason); + }; + + process.on('unhandledRejection', listen); + + try { + const report = combineReporters( + async () => { + throw new Error('db down'); + }, + () => { + throw new Error('bad line'); + }, + async () => {}, + ); + + // Thrown now, as a reporter's throw is — not held back behind the + // others, past where anything is still listening for it. + expect(() => report(at('site:done'))).toThrow('bad line'); + await new Promise((resolve) => setImmediate(resolve)); + + // And what the one written async rejected with, let go of: handled. + expect(unhandled).toEqual([]); + } finally { + process.off('unhandledRejection', listen); + } + }); + + it('hands back the promise of the one reporter written async as it is', async () => { + const promised = Promise.resolve(); + const report = combineReporters( + () => promised as never, + () => {}, + ); + + expect((report as (event: unknown) => unknown)(at('site:done'))).toBe(promised); + }); + + it('hands back what reporters written async reject with, all of it, where none threw', async () => { + const report = combineReporters( + async () => { + throw new Error('db down'); + }, + async () => { + throw new Error('queue full'); + }, + () => {}, + ); + + const returned = (report as (event: unknown) => unknown)(at('site:done')) as Promise; + const thrown = await returned.catch((error: unknown) => error); + + expect((thrown as AggregateError).errors.map(errorMessage)).toEqual(['db down', 'queue full']); + }); + + it('keeps a reporter kept already as it is, for what kept it to throw', () => { + const outer = keepingThrows({ + reporter: () => { + throw new Error('the reporter fell over'); + }, + }); + const inner = keepingThrows(outer.options); + + expect(inner.options).toBe(outer.options); + + inner.options.reporter!(at('site:done')); + + // Nothing to throw for the inner; the outer kept it, once. + expect(() => inner.rethrow()).not.toThrow(); + expect(() => outer.rethrow()).toThrow(ReporterError); + }); + + it('throws, as it settles, what was kept since it was thrown on the way out', async () => { + const kept = keepingThrows({ + reporter: () => { + throw new Error('the reporter fell over'); + }, + }); + + kept.options.reporter!(at('site:done')); + + let early: unknown; + + try { + kept.rethrow(); + } catch (error) { + early = error; + } + + // Said, and thrown at, after — before what it was thrown out of let go. + kept.options.reporter!(at('site:failed')); + + const thrown = await kept.settle(Promise.reject(early)).catch((error: unknown) => error); + + expect((thrown as ReporterError).thrown).toEqual([ + { error: expect.any(Error), times: 2, at: { 'site:done': 1, 'site:failed': 1 } }, + ]); + }); + + it('keeps reporters joined together, failing at every event, as one kind', () => { + const kept = keepingThrows({ + reporter: combineReporters( + () => { + throw new Error('one fell over'); + }, + () => { + throw new Error('two fell over'); + }, + ), + }); + + kept.options.reporter!(at('site:done')); + kept.options.reporter!(at('site:failed')); + kept.options.reporter!(at('serve:reloaded')); + + let thrown: ReporterError | undefined; + + try { + kept.rethrow(); + } catch (error) { + thrown = error as ReporterError; + } + + expect(thrown?.thrown).toEqual([ + { + error: expect.any(AggregateError), + times: 3, + at: { 'site:done': 1, 'site:failed': 1, 'serve:reloaded': 1 }, + }, + ]); + }); + + it('keeps reporters joined together failing another way as another kind', () => { + let message = 'disk full'; + const kept = keepingThrows({ + reporter: combineReporters( + () => { + throw new Error(message); + }, + () => { + throw new Error('socket closed'); + }, + ), + }); + + kept.options.reporter!(at('site:done')); + kept.options.reporter!(at('site:done')); + message = 'quota exceeded'; + kept.options.reporter!(at('site:failed')); + + let thrown: ReporterError | undefined; + + try { + kept.rethrow(); + } catch (error) { + thrown = error as ReporterError; + } + + expect(thrown?.thrown.map((kind) => [(kind.error as Error).message, kind.times])).toEqual([ + ['2 reporters threw: Error: disk full; Error: socket closed', 2], + ['2 reporters threw: Error: quota exceeded; Error: socket closed', 1], + ]); + }); + + it('keeps what cannot even be read, as a kind of its own', () => { + const { proxy, revoke } = Proxy.revocable({}, {}); + + revoke(); + + const kept = keepingThrows({ + reporter: () => { + throw proxy; + }, + }); + + kept.options.reporter!(at('serve:reloaded')); + + expect(() => kept.rethrow()).toThrow(ReporterError); + }); }); describe('jsonReporter', () => { diff --git a/test/schedules-direct/client.test.ts b/test/schedules-direct/client.test.ts index e3828ae..3da48d1 100644 --- a/test/schedules-direct/client.test.ts +++ b/test/schedules-direct/client.test.ts @@ -312,6 +312,36 @@ describe('the Schedules Direct client', () => { expect(source.countOf('token')).toBe(1); }); + it('names each call by what it is for, not by its path', async () => { + const source = await sdServer({ status: { account: { messages: [] }, lineups: [] } }); + const named: Array = []; + const sd = client(source, { + paced: async (task, options) => { + named.push(options?.label); + + return task({}); + }, + }); + const calls: Array<[string, () => Promise]> = [ + ['status', () => sd.status()], + ['headends', () => sd.headends({ country: 'GBR', postalCode: 'SW1A' })], + ['lineups', () => sd.lineups()], + ['lineups', () => sd.lineup('GBR-1000014-DEFAULT')], + ['lineups', () => sd.addLineup('GBR-1000014-DEFAULT')], + ['lineups', () => sd.removeLineup('GBR-1000014-DEFAULT')], + ['md5', () => sd.schedulesMd5([{ stationID: '101' }])], + ['schedules', () => sd.schedules([{ stationID: '101', date: ['2026-09-12'] }])], + ['programs', () => sd.programs(['EP0001'])], + ['metadata', () => sd.artwork(['EP0001'])], + ]; + + for (const [, call] of calls) { + await call().catch(() => undefined); + } + + expect(named).toEqual(calls.map(([label]) => label)); + }); + it('says what the service refused a whole request with, where success is a list', async () => { const source = await sdServer(); @@ -319,8 +349,18 @@ describe('the Schedules Direct client', () => { // whose success is an array — at HTTP 200, so only the shape says so. source.answer({ schedules: { code: 7020, message: 'no such station' } as never }); - await expect(client(source).schedules([{ stationID: 'nope' }])).rejects.toThrow( - /no such station/, - ); + // Thrown inside the call's own turn, where the queue counts it as failed. + const failedInTurn: unknown[] = []; + const sd = client(source, { + paced: (task) => + task({}).catch((error: unknown) => { + failedInTurn.push(error); + + throw error; + }), + }); + + await expect(sd.schedules([{ stationID: 'nope' }])).rejects.toThrow(/no such station/); + expect(failedInTurn).toHaveLength(1); }); }); diff --git a/test/schedules-direct/site.test.ts b/test/schedules-direct/site.test.ts index cf69e2e..3d343b3 100644 --- a/test/schedules-direct/site.test.ts +++ b/test/schedules-direct/site.test.ts @@ -127,6 +127,41 @@ describe('defineSchedulesDirectSite', () => { expect(xml).toContain('Drama'); }); + it('says what each of its calls was for', async () => { + const source = await service(); + const report = collect(); + + await grab([site(source)], { cache: store(), now: NOW, reporter: report.reporter }); + + const done = report.events.find((event) => event.type === 'site:done') as Extract< + (typeof report.events)[number], + { type: 'site:done' } + >; + + // The kind of call, not its path. The token is earned inside another + // call's turn, and is no request of the queue's; the lineup's calls are + // made inside the channel list's, as one request of the run's. + const { requestsBy } = done; + + expect(Object.keys(requestsBy)).toEqual(['channels', 'md5', 'schedules', 'programs']); + expect(requestsBy.channels).toEqual({ requests: 1, requestMs: expect.any(Number), failed: {} }); + + for (const [label, path] of [ + ['md5', 'schedules/md5'], + ['schedules', 'schedules'], + ['programs', 'programs'], + ] as const) { + expect(requestsBy[label]).toEqual({ + requests: source.countOf(path), + requestMs: expect.any(Number), + failed: {}, + }); + } + expect(Object.values(requestsBy).reduce((total, { requests }) => total + requests, 0)).toBe( + done.requests, + ); + }); + it('asks for md5s once for the whole site, then only for what moved', async () => { const source = await service(); const cache = store(); diff --git a/test/shared-counts.test.ts b/test/shared-counts.test.ts new file mode 100644 index 0000000..27f8409 --- /dev/null +++ b/test/shared-counts.test.ts @@ -0,0 +1,196 @@ +import { describe, expect, it } from 'vitest'; +import { + CountReader, + CountWriter, + sharedCounts, + SLOTS, + type SlotName, +} from '../src/grabber/shared-counts.js'; + +/** A writer and a reader over one site's memory, the names said as a thread would say them. */ +function shared(): { writer: CountWriter; reader: CountReader; named: SlotName[] } { + const counts = sharedCounts(); + const reader = new CountReader(counts); + const named: SlotName[] = []; + const writer = new CountWriter(counts, (index, slot) => { + named.push(slot); + reader.named(index, slot); + }); + + return { writer, reader, named }; +} + +describe('shared counts', () => { + it('reads back what was added, by label, in the order each was first counted', () => { + const { writer, reader } = shared(); + + writer.add('listings', { requests: 1, requestMs: 0, failed: {} }); + writer.add('detail', { requests: 1, requestMs: 0, failed: {} }); + writer.add('listings', { requests: 0, requestMs: 120, failed: {} }); + writer.add('detail', { requests: 0, requestMs: 30, failed: { 404: 1 } }); + writer.add('detail', { requests: 1, requestMs: 25, failed: { 404: 1, timeout: 1 } }); + + expect([...reader.read()]).toEqual([ + ['listings', { requests: 1, requestMs: 120, failed: {} }], + ['detail', { requests: 2, requestMs: 55, failed: { 404: 2, timeout: 1 } }], + ]); + }); + + it('names each count once, however often it is added to', () => { + const { writer, reader, named } = shared(); + + for (let i = 0; i < 10_000; i++) { + writer.add('detail', { requests: 1, requestMs: 2, failed: i % 2 === 0 ? { 404: 1 } : {} }); + } + + // The label, with its two counts — and its one kind of failure. + expect(named).toEqual([{ label: 'detail' }, { label: 'detail', failure: '404' }]); + expect(reader.read().get('detail')).toEqual({ + requests: 10_000, + requestMs: 20_000, + failed: { 404: 5_000 }, + }); + }); + + it('names a label once for both its counts, before it has taken any time', () => { + const { writer, reader, named } = shared(); + + writer.add('detail', { requests: 1, requestMs: 0, failed: {} }); + writer.add('detail', { requests: 0, requestMs: 9, failed: {} }); + + expect(named).toEqual([{ label: 'detail' }]); + expect(reader.read().get('detail')).toEqual({ requests: 1, requestMs: 9, failed: {} }); + }); + + it('hands back what it has no slot left for, and keeps counting what it has', () => { + const { writer, reader } = shared(); + + // Every slot taken, two to a label after the seven always there — when it + // began, and the six of the channel-days — and the odd one by a failure. + const labels = Math.floor((SLOTS - 7) / 2); + + for (let i = 0; i < labels; i++) { + expect(writer.add(`label${i}`, { requests: 1, requestMs: 0, failed: {} })).toBeUndefined(); + } + + expect(writer.add('label1', { requests: 0, requestMs: 0, failed: { 500: 1 } })).toBeUndefined(); + + // A label already slotted still counts; a failure it has no slot for, and + // a label of none, are handed back. + expect(writer.add('label0', { requests: 1, requestMs: 7, failed: { 503: 1 } })).toEqual({ + requests: 0, + requestMs: 0, + failed: { 503: 1 }, + }); + expect(writer.add('more', { requests: 1, requestMs: 3, failed: {} })).toEqual({ + requests: 1, + requestMs: 3, + failed: {}, + }); + expect(reader.read().get('label0')).toEqual({ requests: 2, requestMs: 7, failed: {} }); + expect(reader.read().size).toBe(labels); + }); + + it('counts channel-days in slots of their own, which need no name', () => { + const { writer, reader, named } = shared(); + + writer.count('fetched', 1); + writer.count('empty', 1); + writer.count('fetched', 1); + // A day that came back empty and then did not. + writer.count('empty', -1); + writer.add('request', { requests: 1, requestMs: 0, failed: {} }); + + expect(reader.tally()).toEqual({ + fetched: 2, + empty: 0, + fromCache: 0, + unchanged: 0, + failed: 0, + sitesFailed: 0, + }); + // And none of a label's slots taken by them. + expect(named).toEqual([{ label: 'request' }]); + expect(reader.read().get('request')).toEqual({ requests: 1, requestMs: 0, failed: {} }); + }); + + it('says when the site began, in a slot of its own', () => { + const { writer, reader, named } = shared(); + + expect(reader.began()).toBeUndefined(); + + writer.begin(1_700_000_000_000); + + expect(reader.began()).toBe(1_700_000_000_000); + // Taking nothing of the counts' slots. + expect(reader.tally()).toEqual({ + fetched: 0, + empty: 0, + fromCache: 0, + unchanged: 0, + failed: 0, + sitesFailed: 0, + }); + expect(named).toEqual([]); + }); + + it('refuses a channel-day count it does not know, rather than counting it into another', () => { + const { writer, reader } = shared(); + + writer.begin(1_700_000_000_000); + + expect(() => writer.count('hours' as never, 1)).toThrow('No channel-day count is called hours'); + // When it began, untouched. + expect(reader.began()).toBe(1_700_000_000_000); + }); + + it('names a slot only once what was added is in it', () => { + const counts = sharedCounts(); + const reader = new CountReader(counts); + const seen: unknown[] = []; + // Read the moment each name is heard, as the run's thread may — for the + // last time, as it hangs up. + const writer = new CountWriter(counts, (index, slot) => { + reader.named(index, slot); + seen.push(reader.read().get('detail')); + }); + + writer.add('detail', { requests: 1, requestMs: 7, failed: { 404: 1 } }); + + expect(seen).toEqual([ + { requests: 1, requestMs: 7, failed: {} }, + { requests: 1, requestMs: 7, failed: { 404: 1 } }, + ]); + }); + + it('counts only the failures a request has, not what anything put on every object', () => { + const { writer, reader } = shared(); + + Object.defineProperty(Object.prototype, 'polluted', { + value: 'not a count', + enumerable: true, + configurable: true, + }); + + try { + writer.add('detail', { requests: 1, requestMs: 2, failed: { 404: 1 } }); + } finally { + delete (Object.prototype as { polluted?: unknown }).polluted; + } + + expect(reader.read().get('detail')).toEqual({ + requests: 1, + requestMs: 2, + failed: { 404: 1 }, + }); + }); + + it('reads nothing of a slot whose name it has not heard', () => { + const counts = sharedCounts(); + const writer = new CountWriter(counts, () => {}); + + writer.add('detail', { requests: 1, requestMs: 5, failed: {} }); + + expect(new CountReader(counts).read().size).toBe(0); + }); +}); diff --git a/test/thread.test.ts b/test/thread.test.ts index 3b7a0c3..8dbccac 100644 --- a/test/thread.test.ts +++ b/test/thread.test.ts @@ -1,20 +1,25 @@ +import { getEventListeners } from 'node:events'; import { availableParallelism } from 'node:os'; import { MessageChannel } from 'node:worker_threads'; import PQueue from 'p-queue'; -import { describe, expect, it } from 'vitest'; +import { describe, expect, it, vi } from 'vitest'; import { CacheManager, MemoryCacheDriver } from '../src/cache/main.js'; import type { CacheStore } from '../src/cache/types.js'; -import type { EpgEventInput } from '../src/core/events.js'; +import type { EpgEventInput, RequestCounts } from '../src/core/events.js'; import { build } from '../src/build.js'; import { grab, StateKey } from '../src/grabber/main.js'; import type { Run } from '../src/grabber/site-run.js'; import { hostSite, + RemoteCache, + SiteNotRunError, SiteThreads, threadCount, workSite, type SiteThreadData, } from '../src/grabber/thread.js'; +import { addRequests, openSession, requestsObject } from '../src/grabber/session.js'; +import { CountReader, CountWriter, sharedCounts } from '../src/grabber/shared-counts.js'; import { getXmltvOffset } from '../src/xmltv/main.js'; // Both halves of a site in a thread, talking over a `MessageChannel` in this @@ -27,8 +32,12 @@ const DAY = '2026-07-17'; const CONFIG = new URL('./fixtures/thread.config.ts', import.meta.url).href; /** The run's side: a real store, and every event it is told. */ -function hosting(cache: CacheStore, signal?: AbortSignal): { run: Run; events: EpgEventInput[] } { +function hosting( + cache: CacheStore, + signal?: AbortSignal, +): { run: Run; events: EpgEventInput[]; requested: Array<[string, RequestCounts]> } { const events: EpgEventInput[] = []; + const requested: Array<[string, RequestCounts]> = []; const run: Run = { defaults: { days: 1 }, cache, @@ -44,9 +53,12 @@ function hosting(cache: CacheStore, signal?: AbortSignal): { run: Run; events: E enqueue: (queue, task, options = {}) => queue.add(task, { ...options, ...(signal ? { signal } : {}) }), tally: { fetched: 0, empty: 0, fromCache: 0, unchanged: 0, failed: 0, sitesFailed: 0 }, + requested: (label, done) => { + requested.push([label, done]); + }, }; - return { run, events }; + return { run, events, requested }; } function started(site: string, extra: Partial = {}): SiteThreadData { @@ -59,22 +71,120 @@ function started(site: string, extra: Partial = {}): SiteThreadD timeZone: 'UTC', defaults: { days: 1 }, localConcurrency: 4, + counts: sharedCounts(), ...extra, }; } -/** Hold the conversation to its end, and let go of the channel either way. */ -async function converse(run: Run, data: SiteThreadData): Promise { +/** + * Hold the conversation to its end, hang up as the run would once every site + * is done, and let go of the channel either way — handing `heard` every + * message the thread sends the run. + */ +async function converse( + run: Run, + data: SiteThreadData, + heard?: (message: { kind: string }) => void, +): Promise { const { port1, port2 } = new MessageChannel(); + if (heard !== undefined) { + port1.on('message', heard); + } + try { - await Promise.all([hostSite(port1, run), workSite(port2, data)]); + const [hangUp] = await Promise.all([ + hostSite(port1, run, { site: data.site, counts: new CountReader(data.counts) }), + workSite(port2, data), + ]); + + hangUp(); } finally { port1.close(); port2.close(); } } +/** The run's end of a conversation the test holds the thread's end of. */ +function hostOnly( + run: Run, + options: { whenLost?: (lose: (error: unknown) => void) => () => void } = {}, +): { + hosted: Promise<() => void>; + reader: CountReader; + writer: CountWriter; + /** The thread's end, and the run's. */ + port: MessagePort; + host: MessagePort; + close: () => void; +} { + const { port1, port2 } = new MessageChannel(); + const reader = new CountReader(); + const hosted = hostSite(port1, run, { site: 'lost.example', counts: reader, ...options }); + // As the thread would name each slot. + const writer = new CountWriter(reader.buffer, (index, slot) => { + port2.postMessage({ kind: 'slot', index, slot }); + }); + + return { + hosted, + reader, + writer, + port: port2, + host: port1, + close: () => { + port1.close(); + port2.close(); + }, + }; +} + +/** What the run was told, label by label, in the order each was first told. */ +function toldOf(requested: Array<[string, RequestCounts]>): Record { + const told = new Map(); + + for (const [label, done] of requested) { + addRequests(told, label, done); + } + + return requestsObject(told); +} + +/** A `site:done` as a thread sends it, saying `fetched` channel-days. */ +function siteDoneOf(fetched: number): EpgEventInput { + return { + type: 'site:done', + site: 'lost.example', + requests: 0, + ms: 5, + requestMs: 0, + requestsBy: {}, + fetched, + empty: 0, + fromCache: 0, + unchanged: 0, + failed: 0, + sitesFailed: 0, + }; +} + +/** Listen for the thread going, handing the test what says it went. */ +function losing(): { + whenLost: (lose: (error: unknown) => void) => () => void; + lose: (error: unknown) => void; +} { + let told: (error: unknown) => void = () => {}; + + return { + whenLost: (lose) => { + told = lose; + + return () => {}; + }, + lose: (error) => told(error), + }; +} + describe('a site in a thread', () => { it('runs the site its module has, into the run’s cache, offsets and all', async () => { const cache = new CacheManager({ driver: new MemoryCacheDriver() }); @@ -248,23 +358,945 @@ describe('a site in a thread', () => { }); }); - it('counts as it goes, so a site that never says it is done has still counted', async () => { + it('counts in memory the run reads, rather than in a message a count', async () => { const cache = new CacheManager({ driver: new MemoryCacheDriver() }); - const { run, events } = hosting(cache); - const counted: number[] = []; + const { run } = hosting(cache); + const kinds: string[] = []; + const data = started('offset.example'); - run.emit = (event) => { - events.push(event); + await converse(run, data, (message) => kinds.push(message.kind)); + + // In the run's tally once the run hung up — and no count crossed. + expect(run.tally).toMatchObject({ fetched: 1, failed: 0 }); + expect(kinds).not.toContain('count'); + // Nor that it began: that is in memory too. + expect(new CountReader(data.counts).began()).toBeGreaterThan(0); + }); + + it('lets go of the port its cache was asked through once the site is done', async () => { + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const { run } = hosting(cache); + const { port1, port2 } = new MessageChannel(); + const data = started('offset.example'); + + try { + const [hangUp] = await Promise.all([ + hostSite(port1, run, { site: data.site, counts: new CountReader(data.counts) }), + workSite(port2, data), + ]); + + // The cache's listeners gone with it, and only the one for a cancel left, + // for a request the site did not wait for — until the run hangs up. + expect(port2.listenerCount('message')).toBe(1); + expect(port2.listenerCount('close')).toBe(1); + hangUp(); + + const closing = new Promise((resolve) => port2.once('close', resolve)); - if (event.type === 'entry:fetched') { - counted.push(run.tally.fetched); + port1.close(); + await closing; + + // And that one let go of too, once it has. + expect(port2.listenerCount('message')).toBe(0); + expect(port2.listenerCount('close')).toBe(0); + } finally { + port1.close(); + port2.close(); + } + }); + + it('lets what its site left asking finish, so the thread’s parsing is not short a slot', async () => { + for (const end of ['answered', 'hung up'] as const) { + const { port1, port2 } = new MessageChannel(); + const localWork = new PQueue({ concurrency: 4 }); + const held: number[] = []; + let metas = 0; + let said: string | undefined; + + // The run's side, by hand: the first channel's read fails, and the + // other's is held — so the site fails with a call still out. + port1.on('message', (message: { kind: string; id?: number; op?: string }) => { + if (message.kind === 'done' || message.kind === 'failed') { + said = message.kind; + } + + if (message.kind !== 'cache') { + return; + } + + if (message.op === 'getMetas' && metas++ === 0) { + port1.postMessage({ + kind: 'answer', + id: message.id, + error: { kind: 'error', name: 'Error', message: 'the store fell over' }, + }); + } else if (message.op === 'getMetas') { + held.push(message.id!); + } else { + port1.postMessage({ kind: 'answer', id: message.id, value: undefined }); + } + }); + + let finished = false; + const working = workSite( + port2, + started('offset.example', { + channels: [ + { xmltvId: 'one', siteId: '1' }, + { xmltvId: 'two', siteId: '2' }, + ], + }), + localWork, + ).then(() => { + finished = true; + }); + + try { + await vi.waitFor(() => expect(said).toBe('done')); + await new Promise((resolve) => setImmediate(resolve)); + + // Done, and still waiting on what it asked. + expect(held.length).toBeGreaterThan(0); + expect(finished).toBe(false); + + if (end === 'answered') { + for (const id of held) { + port1.postMessage({ kind: 'answer', id, value: [] }); + } + } else { + port1.close(); + } + + await working; + + // Every slot of the thread's parsing let go, for the sites after — + // once what held them has finished, which is a few turns on. + await vi.waitFor(() => expect(localWork.pending).toBe(0)); + expect(localWork.size).toBe(0); + } finally { + port1.close(); + port2.close(); } - }; + } + }); - await converse(run, started('offset.example')); + it('answers what is asked of the cache until it is closed, and refuses what is asked after', async () => { + const { port1, port2 } = new MessageChannel(); + const asked: number[] = []; + + port1.on('message', (message: { kind: string; id: number }) => { + if (message.kind === 'cache') { + asked.push(message.id); + } + }); + + const cache = new RemoteCache(port2, undefined); + + try { + const first = cache.getState('a.tv', 'one'); + + await vi.waitFor(() => expect(asked).toHaveLength(1)); + + let closed = false; + const closing = cache.close().then(() => { + closed = true; + }); + // Asked while it closes, as what waits on the first may as it finishes. + const second = cache.getState('a.tv', 'two'); + + port1.postMessage({ kind: 'answer', id: asked[0], value: 'one' }); + await expect(first).resolves.toBe('one'); + await vi.waitFor(() => expect(asked).toHaveLength(2)); + expect(closed).toBe(false); + + port1.postMessage({ kind: 'answer', id: asked[1], value: 'two' }); + await expect(second).resolves.toBe('two'); + await closing; + + // After: refused at once, rather than sent and never answered. + await expect(cache.getState('a.tv', 'three')).rejects.toThrow( + 'asked after the site was done with it', + ); + expect(asked).toHaveLength(2); + expect(port2.listenerCount('message')).toBe(0); + expect(port2.listenerCount('close')).toBe(0); + } finally { + port1.close(); + port2.close(); + } + }); + + it('lets go of a call no thread could be handed, as of one answered', async () => { + const { port1, port2 } = new MessageChannel(); + const cache = new RemoteCache(port2, undefined); + + try { + // What a site keeps, holding what no thread can be handed. + await expect( + cache.setState('a.tv', 'state', { data: [['retry', () => {}]] } as never), + ).rejects.toThrow(); + // Nothing left asking, so closing is done at once. + await cache.close(); + } finally { + port1.close(); + port2.close(); + } + }); + + it('waits, as it closes, for what an answer lets its caller go on to ask', async () => { + const { port1, port2 } = new MessageChannel(); + + // The run's side, answering at once. + port1.on('message', (message: { kind: string; id: number; op: string }) => { + if (message.kind === 'cache') { + port1.postMessage({ + kind: 'answer', + id: message.id, + value: message.op === 'read' ? [] : undefined, + }); + } + }); + + const cache = new RemoteCache(port2, undefined); + const key = { site: 'a.tv', channelId: 'one', day: DAY }; + + try { + // As a channel-day is added to: read, then the write it was for. + const appending = (async () => { + await cache.read(key); + await cache.write(key, [], {}); + + return 'written'; + })(); + + await new Promise((resolve) => setImmediate(resolve)); + + const closing = cache.close(); + + await expect(appending).resolves.toBe('written'); + await closing; + } finally { + port1.close(); + port2.close(); + } + }); + + it('refuses what is asked of the cache once the run has hung up', async () => { + const { port1, port2 } = new MessageChannel(); + const cache = new RemoteCache(port2, undefined); + const closing = new Promise((resolve) => port2.once('close', resolve)); + + port1.close(); + await closing; + + // Sent to nobody, it would wait for ever — and so would closing the cache. + await expect(cache.getState('a.tv', 'one')).rejects.toThrow( + 'asked after the site was done with it', + ); + await cache.close(); + }); + + it('tells the run what the site asked, from the memory its thread counted it in', async () => { + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const { run, requested } = hosting(cache); + const kinds: string[] = []; + + // Every message the thread sends the run, by kind. + await converse(run, started('offset.example'), (message) => kinds.push(message.kind)); + + expect(toldOf(requested)).toEqual({ + request: { requests: 1, requestMs: expect.any(Number), failed: {} }, + }); + // One name, for the label's two counts — and no message for the request + // itself. + expect(kinds.filter((kind) => kind === 'slot')).toHaveLength(1); + expect(kinds).not.toContain('requested'); + }); + + it('says an error whose cause no thread can be handed, rather than failing the site', async () => { + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const { run, events } = hosting(cache); + + await converse(run, started('odd-cause.example')); + + // As JSON keeps it, and the site's turn said to its end. + expect(events.find((event) => event.type === 'request:failed')).toMatchObject({ + error: { message: 'the source said no', cause: { status: 'busy' } }, + }); + expect(events.at(-1)).toMatchObject({ type: 'site:done', failed: 1, sitesFailed: 0 }); + }); + + it('says a site failed for what cannot be read, as what can be said of it', async () => { + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const { run, events } = hosting(cache); + + await converse(run, started('unreadable.example')); + + // Said as a site whose list failed — not as one that threw after it was done. + expect(events.filter((event) => event.type === 'site:warning')).toEqual([]); + expect(events.find((event) => event.type === 'site:failed')).toMatchObject({ + error: { message: 'no lineup' }, + }); + expect(events.at(-1)).toMatchObject({ type: 'site:done', sitesFailed: 1 }); + }); + + it('tells the run what a request that failed cost, though the site wrote nothing', async () => { + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const { run, requested } = hosting(cache); + + // One request, which fails — the error made plain to cross, its cause + // with it — and leaves nothing to write. + await converse(run, started('failing.example')); + + expect(toldOf(requested)).toEqual({ + request: { requests: 1, requestMs: expect.any(Number), failed: { network: 1 } }, + }); + }); + + it('says a site it never began on never ran', async () => { + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const { run } = hosting(cache); + + // Not in the module its thread reads: refused before anything of it ran. + const refused = await converse(run, started('nowhere.example')).catch( + (error: unknown) => error, + ); + + expect(refused).toBeInstanceOf(SiteNotRunError); + expect((refused as SiteNotRunError).cause).toMatchObject({ + message: expect.stringContaining('has no site "nowhere.example"'), + }); + }); + + it('says a site that threw out of its turn failed, once it had begun', async () => { + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const { run, events } = hosting(cache); + const { hosted, writer, port, close } = hostOnly(run); + + try { + writer.begin(); + writer.count('fetched', 1); + port.postMessage({ + kind: 'failed', + error: { kind: 'error', name: 'Error', message: 'boom' }, + }); + + // Said here rather than rejected, for the run to say again. + (await hosted)(); + + expect(events.map((event) => event.type)).toEqual(['site:failed', 'site:done']); + expect(events[0]).toMatchObject({ error: { message: 'boom' } }); + expect(events[1]).toMatchObject({ fetched: 1, sitesFailed: 1 }); + expect(run.tally).toMatchObject({ fetched: 1, sitesFailed: 1 }); + } finally { + close(); + } + }); + + it('says what a site threw, once, before or after it was done — not that its thread went', async () => { + const boom = { kind: 'failed', error: { kind: 'error', name: 'Error', message: 'boom' } }; + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const before = hosting(cache); + const after = hosting(cache); + const failing = hostOnly(before.run); + const finished = hostOnly(after.run); + + try { + // Counted itself failed, then threw before its `site:done`. + failing.writer.begin(); + failing.writer.count('sitesFailed', 1); + failing.port.postMessage(boom); + (await failing.hosted)(); + + expect(before.events.map((event) => event.type)).toEqual(['site:warning', 'site:done']); + expect(before.events[0]).toMatchObject({ message: 'it threw before it was done: boom' }); + expect(before.run.tally.sitesFailed).toBe(1); + + // All of it said, then threw. + finished.writer.begin(); + finished.port.postMessage({ kind: 'event', event: siteDoneOf(1) }); + finished.port.postMessage(boom); + (await finished.hosted)(); + + expect(after.events.map((event) => event.type)).toEqual(['site:done', 'site:warning']); + expect(after.events[1]).toMatchObject({ message: 'it threw after it was done: boom' }); + expect(after.run.tally.sitesFailed).toBe(0); + } finally { + failing.close(); + finished.close(); + } + }); + + it('says a site never ran whose thread was lost before it began on it', async () => { + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const { run, events } = hosting(cache); + const { whenLost, lose } = losing(); + const { hosted, port, close } = hostOnly(run, { whenLost }); + + try { + const failed = hosted.catch((error: unknown) => error); + + lose(new Error('the thread exited')); + port.close(); + + expect(await failed).toBeInstanceOf(SiteNotRunError); + expect(await failed).toMatchObject({ cause: { message: 'the thread exited' } }); + // Left to the run, which says it as a site that never ran. + expect(events).toEqual([]); + } finally { + close(); + } + }); + + it('says why a site never ran, though its thread went for another site straight after', async () => { + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const { run, events } = hosting(cache); + const { whenLost, lose } = losing(); + const { hosted, port, close } = hostOnly(run, { whenLost }); + + try { + const failed = hosted.catch((error: unknown) => error); + + // Said by the thread, and then the thread gone — word of which may be + // heard first. + port.postMessage({ + kind: 'event', + event: { type: 'site:warning', site: 'lost.example', message: 'first' }, + }); + port.postMessage({ + kind: 'failed', + error: { kind: 'error', name: 'TypeError', message: 'no request for it' }, + }); + lose(new Error('another site crashed the thread')); + port.close(); + + // Its own reason, and what it said before it. + expect(await failed).toMatchObject({ cause: { message: 'no request for it' } }); + expect(events).toEqual([expect.objectContaining({ type: 'site:warning', message: 'first' })]); + } finally { + close(); + } + }); + + it('says a site its thread lost part way failed, with all it had counted', async () => { + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const { run, events, requested } = hosting(cache); + const { whenLost, lose } = losing(); + const { hosted, writer, port, close } = hostOnly(run, { whenLost }); + + try { + // As the thread would: begun, a channel-day counted, two requests in + // memory — the last of them counted just before the thread went. + writer.begin(Date.now() - 50); + writer.count('fetched', 1); + writer.add('request', { requests: 1, requestMs: 30, failed: {} }); + writer.add('request', { requests: 1, requestMs: 10, failed: { 404: 1 } }); + lose(new Error('the thread exited')); + port.close(); + + // Said here, as the site would have said it. + const hangUp = await hosted; + + expect(events.map((event) => event.type)).toEqual(['site:failed', 'site:done']); + expect(events[0]).toMatchObject({ error: { message: 'the thread exited' } }); + expect(events[1]).toMatchObject({ + site: 'lost.example', + fetched: 1, + sitesFailed: 1, + requests: 2, + requestMs: 40, + requestsBy: { request: { requests: 2, requestMs: 40, failed: { 404: 1 } } }, + }); + // From when it began. + expect((events[1] as { ms: number }).ms).toBeGreaterThanOrEqual(50); + // Its channel-days at once, as its turn ended, and its label's place — + // what it asked once the run hangs up. + expect(run.tally).toMatchObject({ fetched: 1, sitesFailed: 1 }); + expect(toldOf(requested)).toEqual({ request: { requests: 0, requestMs: 0, failed: {} } }); - // Already counted when the entry was said, rather than on `site:done`. - expect(counted).toEqual([1]); + hangUp(); + + expect(toldOf(requested)).toEqual({ + request: { requests: 2, requestMs: 40, failed: { 404: 1 } }, + }); + expect(run.tally).toMatchObject({ fetched: 1, sitesFailed: 1 }); + } finally { + close(); + } + }); + + it('decides a site whose thread went, should its port never say it closed, a while after', async () => { + vi.useFakeTimers({ toFake: ['setTimeout', 'clearTimeout'] }); + + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const { run, events } = hosting(cache); + const { whenLost, lose } = losing(); + const { hosted, writer, port, close } = hostOnly(run, { whenLost }); + + try { + writer.begin(); + writer.count('fetched', 1); + lose(new Error('the thread exited')); + + // Waiting on its port, which here never closes. + await vi.advanceTimersByTimeAsync(4_000); + expect(events).toEqual([]); + + await vi.advanceTimersByTimeAsync(1_000); + + const hangUp = await hosted; + + expect(events.map((event) => event.type)).toEqual(['site:failed', 'site:done']); + + // Its own `site:done`, should it arrive after all — before the run hangs + // up — is not said twice. + port.postMessage({ kind: 'event', event: siteDoneOf(1) }); + await new Promise((resolve) => setImmediate(resolve)); + expect(events.map((event) => event.type)).toEqual(['site:failed', 'site:done']); + hangUp(); + } finally { + vi.useRealTimers(); + close(); + } + }); + + it('tells the run what its site counted once, however often it is hung up on', async () => { + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const { run, requested } = hosting(cache); + const { hosted, writer, port, close } = hostOnly(run); + + try { + writer.begin(); + writer.add('request', { requests: 1, requestMs: 5, failed: {} }); + port.postMessage({ kind: 'done' }); + + const hangUp = await hosted; + + hangUp(); + hangUp(); + + expect(toldOf(requested)).toEqual({ request: { requests: 1, requestMs: 5, failed: {} } }); + } finally { + close(); + } + }); + + it('decides a site whose port closed with no word of its thread, a while after', async () => { + vi.useFakeTimers({ toFake: ['setTimeout', 'clearTimeout'] }); + + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const { run, events } = hosting(cache); + // Nothing to say its thread went: a host with no thread, here. + const { hosted, writer, port, host, close } = hostOnly(run); + + try { + writer.begin(); + + const closing = new Promise((resolve) => host.once('close', resolve)); + + port.close(); + await closing; + await vi.advanceTimersByTimeAsync(5_000); + (await hosted)(); + + expect(events.map((event) => event.type)).toEqual(['site:failed', 'site:done']); + expect(events[0]).toMatchObject({ + error: { message: "The site's thread hung up without a word" }, + }); + } finally { + vi.useRealTimers(); + close(); + } + }); + + it('asks a config that failed to be read again, for the next site', async () => { + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const { run } = hosting(cache); + const module = new URL('./fixtures/thread-flaky.config.ts', import.meta.url).href; + + const first = await converse(run, started('flaky.example', { module })).catch( + (error: unknown) => error, + ); + + expect(first).toMatchObject({ cause: { message: 'the token service did not answer' } }); + + // Answered this time, rather than the failure kept for good. + await expect(converse(run, started('flaky.example', { module }))).resolves.toBeUndefined(); + }); + + it('says once that a site failed, should its thread go after it said so itself', async () => { + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const { run, events } = hosting(cache); + const { whenLost, lose } = losing(); + const { hosted, writer, port, close } = hostOnly(run, { whenLost }); + + try { + // Its list failed, which it counted and said — and its thread went as it + // saved what it remembered, before its `site:done`. + writer.begin(); + writer.count('sitesFailed', 1); + lose(new Error('the thread exited')); + port.close(); + (await hosted)(); + + expect(events.map((event) => event.type)).toEqual(['site:warning', 'site:done']); + expect(events[0]).toMatchObject({ + message: 'its thread went before it was done: the thread exited', + }); + expect(events[1]).toMatchObject({ sitesFailed: 1 }); + expect(run.tally.sitesFailed).toBe(1); + } finally { + close(); + } + }); + + it('hears all a thread sent before it went, and makes up no `site:done` it sent', async () => { + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const { run, events } = hosting(cache); + const { whenLost, lose } = losing(); + const { hosted, writer, port, close } = hostOnly(run, { whenLost }); + let settled = false; + + void hosted.then(() => { + settled = true; + }); + + try { + // Its `site:done` sent as it went — in no order Node promises against + // word that it went. + writer.begin(); + writer.count('fetched', 1); + lose(new Error('the thread exited')); + port.postMessage({ kind: 'event', event: siteDoneOf(1) }); + await new Promise((resolve) => setImmediate(resolve)); + + // Not decided while its port is open: what it sent may be on its way. + expect(settled).toBe(false); + + port.close(); + (await hosted)(); + + expect(events.map((event) => event.type)).toEqual(['site:done']); + expect(run.tally).toMatchObject({ fetched: 1, sitesFailed: 0 }); + } finally { + close(); + } + }); + + it('tells the run what a thread had no slot for, said instead', async () => { + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const { run, requested } = hosting(cache); + const { hosted, port, close } = hostOnly(run); + + try { + port.postMessage({ + kind: 'requested', + label: 'more', + done: { requests: 1, requestMs: 4, failed: {} }, + }); + port.postMessage({ kind: 'done' }); + + const hangUp = await hosted; + + // As it was said, not once the run hangs up — and once. + expect(requested).toEqual([['more', { requests: 1, requestMs: 4, failed: {} }]]); + hangUp(); + expect(toldOf(requested)).toEqual({ more: { requests: 1, requestMs: 4, failed: {} } }); + } finally { + close(); + } + }); + + it('counts what its site asked after it was done, until the run hangs up', async () => { + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const { run, requested } = hosting(cache); + const { hosted, writer, port, close } = hostOnly(run); + + try { + writer.begin(); + writer.add('request', { requests: 1, requestMs: 5, failed: {} }); + port.postMessage({ kind: 'done' }); + + const hangUp = await hosted; + + // A request a parse did not wait for, answered after its site was done — + // and under a label, and a failure, first named then. + writer.add('detail', { requests: 1, requestMs: 0, failed: {} }); + writer.add('detail', { requests: 0, requestMs: 7, failed: { 503: 1 } }); + await new Promise((resolve) => setImmediate(resolve)); + + // Each label in its place among the run's as it was first sent. + expect(Object.keys(toldOf(requested))).toEqual(['request', 'detail']); + + hangUp(); + + expect(toldOf(requested)).toEqual({ + request: { requests: 1, requestMs: 5, failed: {} }, + detail: { requests: 1, requestMs: 7, failed: { 503: 1 } }, + }); + } finally { + close(); + } + }); + + it('leaves nothing listening to the run for a site its thread was gone before it began', async () => { + vi.useFakeTimers({ toFake: ['setTimeout', 'clearTimeout'] }); + + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const controller = new AbortController(); + const { run } = hosting(cache, controller.signal); + // Gone already when the site is handed it — whose port, handed to a + // thread already gone, never says it closed. + const { hosted, close } = hostOnly(run, { + whenLost: (lose) => { + lose(new Error('the thread exited')); + + return () => {}; + }, + }); + + try { + const failed = hosted.catch((error: unknown) => error); + + await vi.advanceTimersByTimeAsync(5_000); + + expect(await failed).toBeInstanceOf(SiteNotRunError); + expect(getEventListeners(controller.signal, 'abort')).toHaveLength(0); + } finally { + vi.useRealTimers(); + close(); + } + }); + + it('answers a call with an error, where what the store answered no thread can be handed', async () => { + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const { run } = hosting(cache); + + run.cache = { ...cache, getMeta: async () => ({ grabbedAt: NOW, retry() {} }) } as never; + + const { hosted, port, close } = hostOnly(run); + + try { + const answered = new Promise((resolve) => { + port.on('message', (message: { kind: string }) => { + if (message.kind === 'answer') { + resolve(message); + } + }); + }); + + port.postMessage({ kind: 'cache', id: 1, op: 'getMeta', args: [{}] }); + + // Rather than an answer never sent, and a rejection nobody handles. + expect(await answered).toMatchObject({ + id: 1, + error: { message: "The run's cache answered with what no thread can be handed" }, + }); + + port.postMessage({ kind: 'done' }); + (await hosted)(); + } finally { + close(); + } + }); + + it('answers a channel-day written ahead of a sweep, encoded or not', async () => { + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const { run } = hosting(cache); + + // One slot, taken, so what is asked waits for it in turn. + run.localWork = new PQueue({ concurrency: 1 }); + + let unblock = (): void => {}; + + void run.localWork.add(() => new Promise((resolve) => (unblock = resolve))); + + const { hosted, port, close } = hostOnly(run); + const key = { site: 'lost.example', channelId: 'one', day: DAY }; + + try { + const answered: number[] = []; + const both = new Promise((resolve) => { + port.on('message', (message: { kind: string; id: number }) => { + if (message.kind === 'answer' && answered.push(message.id) === 2) { + resolve(); + } + }); + }); + + port.postMessage({ kind: 'cache', id: 1, op: 'getMetas', args: [[key]] }); + port.postMessage({ + kind: 'cache', + id: 2, + op: 'writeEncoded', + args: [key, new TextEncoder().encode('[]'), 0, {}], + }); + // Both waiting for the slot, before it is let go of. + await vi.waitFor(() => expect(run.localWork.size).toBe(2)); + unblock(); + await both; + + // The write first, though asked for second. + expect(answered).toEqual([2, 1]); + + port.postMessage({ kind: 'done' }); + (await hosted)(); + } finally { + close(); + } + }); + + it('answers with an error whose cause no thread can be handed', async () => { + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const { run } = hosting(cache); + + run.cache = { + ...cache, + getMeta: () => Promise.reject(new Error('the store fell over', { cause: { retry() {} } })), + } as never; + + const { hosted, port, close } = hostOnly(run); + + try { + const answered = new Promise((resolve) => { + port.on('message', (message: { kind: string }) => { + if (message.kind === 'answer') { + resolve(message); + } + }); + }); + + port.postMessage({ kind: 'cache', id: 1, op: 'getMeta', args: [{}] }); + + // As JSON keeps its cause, rather than a throw on this side. + expect(await answered).toMatchObject({ + id: 1, + error: { kind: 'error', message: 'the store fell over', cause: {} }, + }); + + port.postMessage({ kind: 'done' }); + (await hosted)(); + } finally { + close(); + } + }); + + it('says why a config could not be read, with what no thread can be handed', async () => { + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const { run } = hosting(cache); + const module = new URL('./fixtures/thread-unreadable.config.ts', import.meta.url).href; + + const refused = await converse(run, started('any.example', { module })).catch( + (error: unknown) => error, + ); + + // As JSON keeps its cause, rather than a thread that went for it. + expect(refused).toBeInstanceOf(SiteNotRunError); + expect((refused as SiteNotRunError).cause).toMatchObject({ + message: 'the config could not be read', + cause: { why: 'busy' }, + }); + }); + + it('tells a thread the run was cancelled, with what no thread can be handed', async () => { + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const controller = new AbortController(); + const { run } = hosting(cache, controller.signal); + const { hosted, port, close } = hostOnly(run); + + try { + const told = new Promise((resolve) => { + port.on('message', (message: { kind: string }) => { + if (message.kind === 'abort') { + resolve(message); + } + }); + }); + + controller.abort({ why: 'shutting down', retry() {} }); + + expect(await told).toEqual({ kind: 'abort', reason: { why: 'shutting down' } }); + + port.postMessage({ kind: 'done' }); + (await hosted)(); + } finally { + close(); + } + }); + + it('adds what its list cost on this thread to its `site:done`, keeping all else it said', async () => { + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const { run, events } = hosting(cache); + const settled = openSession({ site: 'lost.example' } as never, cache); + + await settled.send(async () => [], { label: 'channels' }); + + const { port1, port2 } = new MessageChannel(); + const hosted = hostSite(port1, run, { + site: 'lost.example', + counts: new CountReader(), + settled, + }); + + try { + // With a field `site:done` does not have today, as a later one might. + port2.postMessage({ kind: 'event', event: { ...siteDoneOf(1), later: 'kept' } }); + port2.postMessage({ kind: 'done' }); + (await hosted)(); + + expect(events).toEqual([ + expect.objectContaining({ + type: 'site:done', + later: 'kept', + fetched: 1, + requests: 1, + requestsBy: { channels: expect.objectContaining({ requests: 1 }) }, + }), + ]); + } finally { + settled.pacing.dispose(); + port1.close(); + port2.close(); + } + }); + + it('listens for its thread going only while its site runs', async () => { + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const { run } = hosting(cache); + const listening = new Set<(error: unknown) => void>(); + const { hosted, port, close } = hostOnly(run, { + whenLost: (lose) => { + listening.add(lose); + + return () => listening.delete(lose); + }, + }); + + try { + expect(listening.size).toBe(1); + port.postMessage({ kind: 'done' }); + await hosted; + + // A thread outlives the run: nothing of this site is left listening. + expect(listening.size).toBe(0); + } finally { + close(); + } + }); + + it('says a site it could not hand a thread never ran', async () => { + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const { run } = hosting(cache); + const pool = SiteThreads.for(1, CONFIG); + // A run default no thread can be handed. + const unsendable = { ...run, defaults: { staleness: { refetchAll: () => true } as never } }; + + await expect( + pool.run( + { site: 'offset.example', channels: [], request: async () => ({}), parseDay: () => [] }, + unsendable, + ), + ).rejects.toBeInstanceOf(SiteNotRunError); }); it('refuses a channel list a thread would be handed as something else', async () => { @@ -286,6 +1318,8 @@ describe('a site in a thread', () => { // Before a thread is asked for: in one, the zone would arrive as `{}` and // every parse calling `offset()` would fail without saying why. + // As a site that never ran, since it never did. await expect(pool.run(site, run)).rejects.toThrow('an instance of Zone'); + await expect(pool.run(site, run)).rejects.toBeInstanceOf(SiteNotRunError); }); }); diff --git a/test/threads.test.ts b/test/threads.test.ts index e7585ad..5a1de45 100644 --- a/test/threads.test.ts +++ b/test/threads.test.ts @@ -2,7 +2,9 @@ import { describe, expect, it } from 'vitest'; import { CacheManager, MemoryCacheDriver } from '../src/cache/main.js'; import type { CacheStore } from '../src/cache/types.js'; import type { EpgEventInput } from '../src/core/events.js'; -import { grab, StateKey, type AnySiteConfig } from '../src/grabber/main.js'; +import { grab, ReporterError, StateKey, type AnySiteConfig } from '../src/grabber/main.js'; +import { grabWith } from '../src/grabber/grab.js'; +import { openSession } from '../src/grabber/session.js'; import { getXmltvOffset } from '../src/xmltv/main.js'; import config from './fixtures/thread.config.js'; @@ -82,6 +84,131 @@ describe('sites in worker threads', () => { expect(getXmltvOffset(programme!.start)).toBe(120); }); + it("counts each site's requests by kind over there, and sums them here", async () => { + const { events } = await grabbed(['offset.example', 'failing.example']); + + const failing = events.find( + (event) => event.type === 'site:done' && event.site === 'failing.example', + ) as Extract; + + expect(failing.requestsBy).toEqual({ + request: { requests: 1, requestMs: expect.any(Number), failed: { network: 1 } }, + }); + // Read from what a thread said as each site finished. + expect(events.at(-1)).toMatchObject({ type: 'grab:done' }); + expect((events.at(-1) as Extract).requestsBy).toEqual({ + request: { requests: 2, requestMs: expect.any(Number), failed: { network: 1 } }, + }); + }); + + it('says what a list settled on this thread cost, beside what the thread asked', async () => { + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + const [found] = sites('channels.example'); + // As `build` leaves a site it settled: the list fetched through a session + // of this thread, and the site handed on with the list it came to. + const session = openSession(found!, cache); + + await session.send( + async () => { + await new Promise((resolve) => setTimeout(resolve, 60)); + + return [{ xmltvId: 'own', siteId: 'own' }]; + }, + { label: 'channels' }, + ); + + const events: EpgEventInput[] = []; + + try { + await grabWith( + [{ ...found!, channels: [{ xmltvId: 'own', siteId: 'own' }] } as AnySiteConfig], + { + cache, + now: NOW, + startDay: DAY, + days: 1, + threads: 1, + configModule: CONFIG, + reporter: (event) => events.push(event), + }, + new Map([['channels.example', session]]), + ); + } finally { + session.pacing.dispose(); + } + + const counted = { + channels: { requests: 1, requestMs: expect.any(Number), failed: {} }, + request: { requests: 1, requestMs: expect.any(Number), failed: {} }, + }; + const done = events.find((event) => event.type === 'site:done') as Extract< + EpgEventInput, + { type: 'site:done' } + >; + + expect(done).toMatchObject({ requests: 2 }); + // Its list's time its own too, as in a run on one thread. + expect(done.ms).toBeGreaterThanOrEqual(50); + expect(done.ms).toBeGreaterThanOrEqual(done.requestMs - 5); + expect(done.requestsBy).toEqual(counted); + expect(Object.keys(done.requestsBy)).toEqual(['channels', 'request']); + expect((events.at(-1) as Extract).requestsBy).toEqual( + counted, + ); + }); + + it('says what a site its thread never ran cost, as a site on this thread would', async () => { + class Zone {} + + const cache = new CacheManager({ driver: new MemoryCacheDriver() }); + // A list settled here, holding what no thread can be handed. + const refused = { + ...sites('offset.example')[0]!, + channels: [{ xmltvId: 'one', siteId: '1', data: { zone: new Zone() } }], + } as AnySiteConfig; + const session = openSession(refused, cache); + + await session.send(async () => [], { label: 'channels' }); + + const events: EpgEventInput[] = []; + + try { + await grabWith( + [refused], + { + cache, + now: NOW, + startDay: DAY, + days: 1, + threads: 1, + configModule: CONFIG, + reporter: (event) => events.push(event), + }, + new Map([['offset.example', session]]), + ); + } finally { + session.pacing.dispose(); + } + + const ofSite = events.filter( + (event) => event.type === 'site:failed' || event.type === 'site:done', + ); + + expect(ofSite.map((event) => event.type)).toEqual(['site:failed', 'site:done']); + // What refused it, as it is — as a site on this thread says it, unwrapped. + expect(ofSite[0]).toMatchObject({ + error: expect.objectContaining({ + name: 'TypeError', + message: expect.stringContaining('an instance of Zone'), + }), + }); + expect(ofSite[1]).toMatchObject({ + sitesFailed: 1, + requests: 1, + requestsBy: { channels: { requests: 1, failed: {} } }, + }); + }); + it('lets a cancelled site wind down before the run answers', async () => { // Cancelled once the quick site has written its day and the slow one is // waiting on a request. The slow one then saves its state on the way out, @@ -133,6 +260,72 @@ describe('sites in worker threads', () => { }); }); + it('says a lost thread’s site, and rejects, though the reporter throws at it', async () => { + const fellOver = new Error('the reporter fell over'); + const events: EpgEventInput[] = []; + + // Said from the thread's listener as it goes, where a throw that got out + // would end the process rather than the run. + const rejected = await grab(sites('crashing.example', 'offset.example'), { + cache: new CacheManager({ driver: new MemoryCacheDriver() }), + now: NOW, + startDay: DAY, + days: 1, + threads: 2, + configModule: CONFIG, + reporter: (event) => { + events.push(event); + + if (event.type === 'site:failed') { + throw fellOver; + } + }, + }).then( + () => undefined, + (error: unknown) => error, + ); + + expect(rejected).toBeInstanceOf(ReporterError); + expect((rejected as ReporterError).thrown).toEqual([ + { error: fellOver, times: 1, at: { 'site:failed': 1 } }, + ]); + expect( + events + .filter((event) => event.type === 'site:failed' || event.type === 'site:done') + .map((event) => `${event.type} ${(event as { site: string }).site}`) + .sort(), + ).toEqual([ + 'site:done crashing.example', + 'site:done offset.example', + 'site:failed crashing.example', + ]); + expect(events.at(-1)).toMatchObject({ type: 'grab:done', fetched: 1, sitesFailed: 1 }); + }); + + it('fails a site whose thread threw what is no error, with an error', async () => { + const { events, summary } = await grabbed(['crashing-quietly.example', 'offset.example'], { + threads: 3, + siteConcurrency: 1, + }); + + // Its thread counted as gone, though nothing said why: the next site is + // run elsewhere, and this one fails with an error that says so. + expect(summary).toMatchObject({ fetched: 1, sitesFailed: 1 }); + expect(events.find((event) => event.type === 'site:failed')).toMatchObject({ + site: 'crashing-quietly.example', + error: { message: expect.stringContaining('threw undefined') }, + }); + }); + + it('says what a thread threw that is no error, an object’s fields and all', async () => { + const { events } = await grabbed(['crashing-plainly.example'], { threads: 1 }); + + expect(events.find((event) => event.type === 'site:failed')).toMatchObject({ + site: 'crashing-plainly.example', + error: { message: "A site's thread threw { reason: 'out of cheese' }" }, + }); + }); + it('runs more sites than threads, sharing them', async () => { const { summary } = await grabbed(['offset.example', 'circular.example', 'channels.example'], { threads: 1, diff --git a/test/try.test.ts b/test/try.test.ts index 4d8f6ad..aa11b81 100644 --- a/test/try.test.ts +++ b/test/try.test.ts @@ -344,6 +344,26 @@ describe('epg try', () => { expect(out).toContain('a stream site'); }); + it('refuses a paced label a run would refuse, rather than working only here', async () => { + const config = configWith( + defineSiteConfig({ + site: 'example.tv', + channels: [{ xmltvId: 'one', siteId: '1' }], + request: async () => ({}), + parseDay: async ({ paced }) => { + await paced(async () => 'detail', { label: '' }); + + return []; + }, + }), + ); + + await expect(run(config, 'example.tv', 'one')).rejects.toThrow( + "a paced request's label names what requests are for, as a word — letters and digits, " + + 'a letter among them, joined by . _ / or - (got an empty string)', + ); + }); + it('refuses a site a run would refuse, in the same words', async () => { const config = configWith({ site: 'example.tv', diff --git a/test/xmltv-source.test.ts b/test/xmltv-source.test.ts index 72e31bb..f9e5042 100644 --- a/test/xmltv-source.test.ts +++ b/test/xmltv-source.test.ts @@ -163,6 +163,27 @@ describe('defineXmltvSite', () => { expect(await entries(cache, 'b', TOMORROW)).toHaveLength(1); }); + it('counts its document fetch under the requestLabel it is given', async () => { + const source = await serveGzip(); + const report = collect(); + + await grab( + [defineXmltvSite({ site: 'published.example', url: source.url, requestLabel: 'document' })], + { cache: store(), now: NOW, days: 2, reporter: report.reporter }, + ); + + const done = report.events.find((event) => event.type === 'site:done') as { + requestsBy: Record; + }; + + // The channel list out of the head of the document, then the document. + expect(done.requestsBy).toMatchObject({ + channels: { requests: 1 }, + document: { requests: 1 }, + }); + expect(Object.keys(done.requestsBy)).toEqual(['channels', 'document']); + }); + // A pass takes no queue slot of its own, so its fetch has to ask for one — or // the site's `rateLimit` would apply to the channel list and to nothing else. it('sends its document fetch through the site`s queue', async () => {