diff --git a/docker-compose.yaml b/docker-compose.yaml index a4ed1bd0..b871cccd 100644 --- a/docker-compose.yaml +++ b/docker-compose.yaml @@ -346,6 +346,8 @@ services: - GATEWAYS_GQL_CIRCUIT_BREAKER_ERROR_THRESHOLD_PERCENTAGE=${GATEWAYS_GQL_CIRCUIT_BREAKER_ERROR_THRESHOLD_PERCENTAGE:-} - GATEWAYS_GQL_CIRCUIT_BREAKER_ROLLING_COUNT_TIMEOUT_MS=${GATEWAYS_GQL_CIRCUIT_BREAKER_ROLLING_COUNT_TIMEOUT_MS:-} - GATEWAYS_GQL_CIRCUIT_BREAKER_RESET_TIMEOUT_MS=${GATEWAYS_GQL_CIRCUIT_BREAKER_RESET_TIMEOUT_MS:-} + - GATEWAYS_GQL_SOFT_DEADLINE_ENABLED=${GATEWAYS_GQL_SOFT_DEADLINE_ENABLED:-} + - GATEWAYS_GQL_SOFT_DEADLINE_MS=${GATEWAYS_GQL_SOFT_DEADLINE_MS:-} - HYPERBEAM_ENDPOINT=${HYPERBEAM_ENDPOINT:-} - HYPERBEAM_REQUEST_TIMEOUT_MS=${HYPERBEAM_REQUEST_TIMEOUT_MS:-} - HYPERBEAM_ROOT_TX_RATE_LIMIT_BURST_SIZE=${HYPERBEAM_ROOT_TX_RATE_LIMIT_BURST_SIZE:-} diff --git a/docs/envs.md b/docs/envs.md index a8fb951c..a2811cf1 100644 --- a/docs/envs.md +++ b/docs/envs.md @@ -491,6 +491,8 @@ When enabled, the `transaction(id)` GraphQL query can resolve unindexed data ite | GATEWAYS_GQL_CIRCUIT_BREAKER_ERROR_THRESHOLD_PERCENTAGE | Number | 80 | Error rate (0–100) within the rolling window that trips the breaker open | | GATEWAYS_GQL_CIRCUIT_BREAKER_ROLLING_COUNT_TIMEOUT_MS | Number | 60000 | Rolling window in milliseconds over which error rate is measured | | GATEWAYS_GQL_CIRCUIT_BREAKER_RESET_TIMEOUT_MS | Number | 30000 | How long an open breaker stays open before transitioning to half-open for a trial request | +| GATEWAYS_GQL_SOFT_DEADLINE_ENABLED | Boolean | false | When `true`, fan-out list queries (transactions/blocks) stop waiting for slow upstreams once at least one has answered and `GATEWAYS_GQL_SOFT_DEADLINE_MS` elapses, returning a partial merge with an `UPSTREAM_SOFT_DEADLINE` warning per unfinished source. Abandoned requests keep running so the circuit breaker still sees their true outcome. When `false` (default), the fan-out waits for every upstream (bounded by `GATEWAYS_GQL_REQUEST_TIMEOUT_MS`) | +| GATEWAYS_GQL_SOFT_DEADLINE_MS | Number | 2000 | Soft-deadline window in milliseconds, armed once the first upstream returns a usable result. Only used when `GATEWAYS_GQL_SOFT_DEADLINE_ENABLED` is `true` | ## HTTPSIG Response Signing diff --git a/src/config.ts b/src/config.ts index af71f8c1..4619f15d 100644 --- a/src/config.ts +++ b/src/config.ts @@ -421,6 +421,24 @@ export const GATEWAYS_GQL_CIRCUIT_BREAKER_RESET_TIMEOUT_MS = 30 * 1_000, ); +// Soft deadline for the GraphQL fan-out list queries (transactions/blocks). +// When enabled, once at least one upstream has returned a usable result the +// merge waits at most this long for the remaining upstreams, then returns a +// partial merge with an `UPSTREAM_SOFT_DEADLINE` warning for each source that +// had not yet responded. The abandoned requests keep running in the +// background so the per-upstream circuit breaker still observes their true +// outcome (a real success or timeout). The deadline is only armed after the +// first usable result, so an all-slow moment never turns a would-succeed +// query into a failure. When disabled (the default), the fan-out waits for +// every upstream to settle (bounded by GATEWAYS_GQL_REQUEST_TIMEOUT_MS), +// preserving the prior behavior. +export const GATEWAYS_GQL_SOFT_DEADLINE_ENABLED = + env.varOrDefault('GATEWAYS_GQL_SOFT_DEADLINE_ENABLED', 'false') === 'true'; +export const GATEWAYS_GQL_SOFT_DEADLINE_MS = env.positiveIntOrDefault( + 'GATEWAYS_GQL_SOFT_DEADLINE_MS', + 2_000, +); + // GraphQL root TX lookup rate limiting export const GRAPHQL_ROOT_TX_RATE_LIMIT_BURST_SIZE = +env.varOrDefault( 'GRAPHQL_ROOT_TX_RATE_LIMIT_BURST_SIZE', diff --git a/src/database/gateways-gql-queryable.test.ts b/src/database/gateways-gql-queryable.test.ts index 96143e1b..53d2caaf 100644 --- a/src/database/gateways-gql-queryable.test.ts +++ b/src/database/gateways-gql-queryable.test.ts @@ -920,3 +920,171 @@ describe('RemoteGqlQueryable circuit breaker', () => { ); }); }); + +describe('GatewaysGqlQueryable soft deadline', () => { + class DelayedTxQueryable extends FakeQueryable { + constructor( + data: { transactions?: GqlTransaction[]; throws?: Error }, + private readonly delayMs: number, + ) { + super(data); + } + async getGqlTransactions(args: { + pageSize: number; + cursor?: string; + sortOrder?: 'HEIGHT_DESC' | 'HEIGHT_ASC'; + }): Promise { + await new Promise((r) => setTimeout(r, this.delayMs)); + return super.getGqlTransactions(args); + } + } + + const fastSource = () => + new FakeQueryable({ transactions: [txAt({ id: 'fast', height: 100 })] }); + + it('returns the fast source without waiting for a laggard, with a warning', async () => { + const merger = GatewaysGqlQueryable.forTesting({ + log, + sources: [ + fastSource(), + new DelayedTxQueryable( + { transactions: [txAt({ id: 'slow', height: 99 })] }, + // Abandoned laggard: kept short (not multi-second) so its still-ref'd + // timer can't leave the process hanging at exit, but well above the + // 30ms deadline so the assertion proves we returned via the deadline. + 500, + ), + ], + labels: ['', 'http://slow.example'], + softDeadlineEnabled: true, + softDeadlineMs: 30, + }); + + const started = Date.now(); + const result = await merger.getGqlTransactions({ + pageSize: 10, + sortOrder: 'HEIGHT_DESC', + tags: [], + }); + const elapsed = Date.now() - started; + + assert.deepEqual( + result.edges.map((e) => e.node.id), + ['fast'], + ); + assert.ok( + elapsed < 300, + `expected to return via the 30ms soft deadline, not wait for the 500ms laggard, took ${elapsed}ms`, + ); + const warnings = result.warnings ?? []; + assert.equal(warnings.length, 1); + assert.equal(warnings[0].code, 'UPSTREAM_SOFT_DEADLINE'); + assert.equal(warnings[0].source, 'http://slow.example'); + }); + + it('waits for the laggard and omits the warning when disabled (default)', async () => { + const merger = GatewaysGqlQueryable.forTesting({ + log, + sources: [ + fastSource(), + new DelayedTxQueryable( + { transactions: [txAt({ id: 'slow', height: 99 })] }, + 40, + ), + ], + // softDeadlineEnabled defaults to false -> prior behavior + }); + const result = await merger.getGqlTransactions({ + pageSize: 10, + sortOrder: 'HEIGHT_DESC', + tags: [], + }); + assert.deepEqual( + result.edges.map((e) => e.node.id), + ['fast', 'slow'], + ); + assert.equal(result.warnings, undefined); + }); + + it('arms the deadline only after the first result, so an all-slow moment is not a failure', async () => { + // Both sources take ~200ms; the deadline is 100ms. Armed at call time the + // 100ms deadline would fire before either source (200ms) responds, cut + // both, and throw "all sources failed". Armed after the first fulfillment + // it fires at ~300ms, well after the second source (~200ms) settles, so + // both results are captured. The deadline must stay below the source delay + // — that gap is what distinguishes the two arming strategies — while the + // ~100ms slack between the second source and the timer keeps the test + // robust against CI scheduling jitter. + const merger = GatewaysGqlQueryable.forTesting({ + log, + sources: [ + new DelayedTxQueryable( + { transactions: [txAt({ id: 'a', height: 100 })] }, + 200, + ), + new DelayedTxQueryable( + { transactions: [txAt({ id: 'b', height: 99 })] }, + 200, + ), + ], + softDeadlineEnabled: true, + softDeadlineMs: 100, + }); + const result = await merger.getGqlTransactions({ + pageSize: 10, + sortOrder: 'HEIGHT_DESC', + tags: [], + }); + assert.deepEqual( + result.edges.map((e) => e.node.id), + ['a', 'b'], + ); + assert.equal(result.warnings, undefined); + }); + + it('applies the soft deadline to block queries too', async () => { + class DelayedBlockQueryable extends FakeQueryable { + constructor( + data: { blocks?: GqlBlock[] }, + private readonly delayMs: number, + ) { + super(data); + } + async getGqlBlocks(args: { + pageSize: number; + sortOrder?: 'HEIGHT_DESC' | 'HEIGHT_ASC'; + }): Promise { + await new Promise((r) => setTimeout(r, this.delayMs)); + return super.getGqlBlocks(args); + } + } + const merger = GatewaysGqlQueryable.forTesting({ + log, + sources: [ + new FakeQueryable({ + blocks: [{ id: 'b100', height: 100, timestamp: 0, previous: '' }], + }), + new DelayedBlockQueryable( + { blocks: [{ id: 'b99', height: 99, timestamp: 0, previous: '' }] }, + // Abandoned laggard kept short so its ref'd timer can't hang exit. + 500, + ), + ], + labels: ['', 'http://slow.example'], + softDeadlineEnabled: true, + softDeadlineMs: 30, + }); + const result = await merger.getGqlBlocks({ + pageSize: 10, + sortOrder: 'HEIGHT_DESC', + }); + assert.deepEqual( + result.edges.map((e) => e.node.id), + ['b100'], + ); + const warnings = result.warnings ?? []; + assert.equal(warnings.length, 1); + assert.equal(warnings[0].code, 'UPSTREAM_SOFT_DEADLINE'); + assert.equal(warnings[0].source, 'http://slow.example'); + }); +}); diff --git a/src/database/gateways-gql-queryable.ts b/src/database/gateways-gql-queryable.ts index a4a93333..5ee3781a 100644 --- a/src/database/gateways-gql-queryable.ts +++ b/src/database/gateways-gql-queryable.ts @@ -726,6 +726,22 @@ function compareTxRichness( return 0; } +/** + * Reason attached to a fan-out source that had not responded by the soft + * deadline (see GATEWAYS_GQL_SOFT_DEADLINE_ENABLED). Distinguished from a real + * upstream failure by its `code` so `handleSourceFailures` can surface it as a + * dedicated `UPSTREAM_SOFT_DEADLINE` warning and log it at debug rather than + * warn. The underlying request is not aborted — it keeps running so the + * per-upstream circuit breaker still records its true outcome. + */ +class SoftDeadlineExceededError extends Error { + readonly code = 'ESOFTDEADLINE'; + constructor(deadlineMs: number) { + super(`GraphQL fan-out soft deadline (${deadlineMs}ms) exceeded`); + this.name = 'SoftDeadlineExceededError'; + } +} + export class GatewaysGqlQueryable implements GqlQueryable, SelectionAwareGqlQueryable { @@ -733,6 +749,8 @@ export class GatewaysGqlQueryable private readonly log: winston.Logger; private readonly sources: GqlQueryable[]; private readonly sourceLabels: string[]; + private readonly softDeadlineEnabled: boolean; + private readonly softDeadlineMs: number; constructor({ log, @@ -747,6 +765,8 @@ export class GatewaysGqlQueryable config.GATEWAYS_GQL_CIRCUIT_BREAKER_ROLLING_COUNT_TIMEOUT_MS, resetTimeout: config.GATEWAYS_GQL_CIRCUIT_BREAKER_RESET_TIMEOUT_MS, }, + softDeadlineEnabled = config.GATEWAYS_GQL_SOFT_DEADLINE_ENABLED, + softDeadlineMs = config.GATEWAYS_GQL_SOFT_DEADLINE_MS, axiosInstance, }: { log: winston.Logger; @@ -754,9 +774,13 @@ export class GatewaysGqlQueryable localGqlQueryable?: GqlQueryable; requestTimeoutMs?: number; circuitBreakerOptions?: CircuitBreaker.Options; + softDeadlineEnabled?: boolean; + softDeadlineMs?: number; axiosInstance?: AxiosInstance; }) { this.log = log.child({ class: 'GatewaysGqlQueryable' }); + this.softDeadlineEnabled = softDeadlineEnabled; + this.softDeadlineMs = softDeadlineMs; if (urls.length === 0 && localGqlQueryable === undefined) { throw new Error( @@ -789,6 +813,8 @@ export class GatewaysGqlQueryable log: winston.Logger; sources: GqlQueryable[]; labels?: string[]; + softDeadlineEnabled?: boolean; + softDeadlineMs?: number; }): GatewaysGqlQueryable { if (params.sources.length === 0) { throw new Error('forTesting requires at least one source'); @@ -797,6 +823,8 @@ export class GatewaysGqlQueryable log: params.log, urls: [], localGqlQueryable: params.sources[0], + softDeadlineEnabled: params.softDeadlineEnabled, + softDeadlineMs: params.softDeadlineMs, }); (merger as any).sources = params.sources; @@ -880,7 +908,7 @@ export class GatewaysGqlQueryable args: TransactionQueryArgs, ): Promise { const sortOrder = args.sortOrder ?? 'HEIGHT_DESC'; - const results = await Promise.allSettled( + const results = await this.settleWithSoftDeadline( this.sources.map((source) => source.getGqlTransactions(args)), ); const failureWarnings = this.handleSourceFailures( @@ -922,7 +950,7 @@ export class GatewaysGqlQueryable async getGqlBlocks(args: BlockQueryArgs): Promise { const sortOrder = args.sortOrder ?? 'HEIGHT_DESC'; - const results = await Promise.allSettled( + const results = await this.settleWithSoftDeadline( this.sources.map((source) => source.getGqlBlocks(args)), ); const failureWarnings = this.handleSourceFailures( @@ -1119,6 +1147,78 @@ export class GatewaysGqlQueryable }); } + /** + * Settle every fan-out source, optionally bounded by the soft deadline. + * + * With the soft deadline disabled this is exactly `Promise.allSettled` — the + * merge waits for every source (each bounded by the per-upstream request + * timeout). With it enabled, the deadline timer is armed only after the + * first source *fulfills*; once it fires, any source that has not settled is + * reported as a `SoftDeadlineExceededError` rejection so the caller merges + * whatever arrived and surfaces the rest as warnings. Arming on the first + * fulfillment (rather than at call time) guarantees an all-slow moment never + * turns a would-succeed query into a failure. + * + * The source promises are never aborted here — they keep running so the + * per-upstream circuit breaker still observes their real success/timeout. + * Each carries a rejection handler, so a laggard that rejects after we have + * returned does not surface as an unhandled rejection. + */ + private settleWithSoftDeadline( + promises: Promise[], + ): Promise[]> { + if (!this.softDeadlineEnabled || promises.length === 0) { + return Promise.allSettled(promises); + } + + const reflected = promises.map((p) => + p.then( + (value): PromiseSettledResult => ({ status: 'fulfilled', value }), + (reason): PromiseSettledResult => ({ status: 'rejected', reason }), + ), + ); + + const settled: (PromiseSettledResult | undefined)[] = new Array( + reflected.length, + ).fill(undefined); + let pending = reflected.length; + + return new Promise((resolve) => { + let timer: NodeJS.Timeout | undefined; + let done = false; + const finish = () => { + if (done) return; + done = true; + if (timer !== undefined) clearTimeout(timer); + resolve(); + }; + + reflected.forEach((r, i) => { + void r.then((res) => { + if (settled[i] === undefined) { + settled[i] = res; + pending--; + } + if (pending === 0) { + finish(); + } else if (res.status === 'fulfilled' && timer === undefined) { + // Arm the deadline only once we hold a usable result. + timer = setTimeout(finish, this.softDeadlineMs); + if (typeof timer.unref === 'function') timer.unref(); + } + }); + }); + }).then(() => + settled.map( + (res) => + res ?? { + status: 'rejected' as const, + reason: new SoftDeadlineExceededError(this.softDeadlineMs), + }, + ), + ); + } + private handleSourceFailures( results: PromiseSettledResult[], method: string, @@ -1134,7 +1234,16 @@ export class GatewaysGqlQueryable if (failures.length === 0) return []; for (const f of failures) { - const level = f.r.reason?.code === 'EOPENBREAKER' ? 'debug' : 'warn'; + const code = f.r.reason?.code; + // Circuit-open and soft-deadline cuts are expected, low-signal + // degradations — log them at debug so they don't drown real upstream + // errors. Soft-deadline cuts also get their own counter so operators + // can see how often (and against which source) the deadline bites. + const level = + code === 'EOPENBREAKER' || code === 'ESOFTDEADLINE' ? 'debug' : 'warn'; + if (code === 'ESOFTDEADLINE') { + metrics.gatewaysGqlSoftDeadlineSourceCutTotal.inc({ source: f.label }); + } this.log[level]('Upstream source failed', { method, args, @@ -1153,16 +1262,32 @@ export class GatewaysGqlQueryable // the caller knows the merge is missing contributions, instead of // silently returning reduced results. return failures.map((f) => ({ - code: - f.r.reason?.code === 'EOPENBREAKER' - ? 'UPSTREAM_CIRCUIT_OPEN' - : 'UPSTREAM_UNAVAILABLE', + code: warningCodeForReason(f.r.reason), message: f.r.reason?.message ?? String(f.r.reason), source: f.label, })); } } +/** + * Map a settled-source rejection reason to the GraphQL warning code surfaced + * to callers: an open circuit breaker becomes `UPSTREAM_CIRCUIT_OPEN`, a soft + * deadline cut (`SoftDeadlineExceededError`) becomes `UPSTREAM_SOFT_DEADLINE`, + * and anything else (a real upstream error or request timeout) becomes + * `UPSTREAM_UNAVAILABLE`. + */ +function warningCodeForReason(reason: unknown): string { + const code = (reason as { code?: unknown } | null | undefined)?.code; + switch (code) { + case 'EOPENBREAKER': + return 'UPSTREAM_CIRCUIT_OPEN'; + case 'ESOFTDEADLINE': + return 'UPSTREAM_SOFT_DEADLINE'; + default: + return 'UPSTREAM_UNAVAILABLE'; + } +} + function createHttpClient(timeoutMs: number): AxiosInstance { return axios.create({ timeout: timeoutMs, diff --git a/src/metrics.ts b/src/metrics.ts index 28a275ca..ff3684de 100644 --- a/src/metrics.ts +++ b/src/metrics.ts @@ -136,6 +136,12 @@ export const graphqlRootTxBatchTokenWaitTimeoutTotal = new promClient.Counter({ labelNames: ['endpoint'], }); +export const gatewaysGqlSoftDeadlineSourceCutTotal = new promClient.Counter({ + name: 'gateways_gql_soft_deadline_source_cut_total', + help: 'Count of fan-out GraphQL upstreams dropped from a list-query merge because they had not responded by the soft deadline, by source', + labelNames: ['source'], +}); + // // Optimistic chunk ingest cache metrics //