diff --git a/server/src/index.ts b/server/src/index.ts index 0d74d6831..7748bfdc6 100644 --- a/server/src/index.ts +++ b/server/src/index.ts @@ -18,11 +18,17 @@ import { flushLogFileSync, logError } from './nest/audit/audit-log.logger'; import type { DatabaseLifecycle } from './nest/database/database-lifecycle.service'; import { ReadinessService } from './nest/health/readiness.service'; import { createFatalHandler } from './shutdown'; +import { widenConnectAttemptTimeout } from './utils/connectAttempt'; import type { INestApplication } from '@nestjs/common'; import fs from 'node:fs'; import http from 'node:http'; +// Before any outbound request: Node's 250 ms per-address attempt is shorter +// than a round trip from Australia to Europe, which cut off every connection +// to the TREK services there on networks without IPv6. +widenConnectAttemptTimeout(); + // data/tmp is the driver-agnostic global scratch dir (restore-upload spool, // mirror stream staging) and stays boot-created here. Driver-owned roots — the // uploads/ category tree and data/backups — are ensured by LocalDriver.init on diff --git a/server/src/nest/service-identity/service-identity.helpers.ts b/server/src/nest/service-identity/service-identity.helpers.ts index dd47328d3..39ee2d8b5 100644 --- a/server/src/nest/service-identity/service-identity.helpers.ts +++ b/server/src/nest/service-identity/service-identity.helpers.ts @@ -72,3 +72,26 @@ export function serverDateMs(headers: Headers): number | null { export function keyFingerprint(token: string): string { return createHash('sha256').update(token).digest('hex').slice(0, 16); } + +/** + * A failure as one log line. undici only says "fetch failed" and keeps the + * reason in `cause`, an AggregateError when every address was tried, so each + * attempt's code and address are spelled out (ETIMEDOUT 203.0.113.7:443). + */ +export function describeFailure(err: unknown): string { + if (!(err instanceof Error)) return String(err); + const cause = (err as { cause?: unknown }).cause; + if (!(cause instanceof Error)) return err.message; + const attempts = cause instanceof AggregateError ? cause.errors : [cause]; + const reasons = attempts.map(describeAttempt).filter(Boolean); + return reasons.length > 0 ? `${err.message} (${reasons.join(', ')})` : err.message; +} + +function describeAttempt(attempt: unknown): string { + if (!(attempt instanceof Error)) return String(attempt); + const { code, address, port } = attempt as { code?: unknown; address?: unknown; port?: unknown }; + if (typeof code !== 'string') return attempt.message; + if (typeof address !== 'string') return code; + const host = address.includes(':') ? `[${address}]` : address; + return typeof port === 'number' ? `${code} ${host}:${port}` : `${code} ${host}`; +} diff --git a/server/src/nest/service-identity/service-key.service.ts b/server/src/nest/service-identity/service-key.service.ts index 6c3aa9a8a..9a6a3cd15 100644 --- a/server/src/nest/service-identity/service-key.service.ts +++ b/server/src/nest/service-identity/service-key.service.ts @@ -9,7 +9,7 @@ import { RefusalStreak } from './refusal-streak'; import type { RegistrationDialect } from './registration-dialect.types'; import { ServiceClock } from './service-clock'; import { REGISTRATION_DIALECT, SERVICE_ISSUER_ORIGIN } from './service-identity.constants'; -import { isAllowlisted, keyFingerprint, sameServiceUrl } from './service-identity.helpers'; +import { describeFailure, isAllowlisted, keyFingerprint, sameServiceUrl } from './service-identity.helpers'; import { parseServiceKey, type ServiceKey } from './service-key.format'; import { solvePow } from './service-key.pow'; import { EMPTY_KEY_STATE, ServiceKeyStore, type KeyState, type StoredIdentity } from './service-key.store'; @@ -235,7 +235,7 @@ export class ServiceKeyService { const previous = this.work ?? Promise.resolve(); const run = previous.then(() => withRequestContext(this.orm, task)); const next = run - .catch((err: unknown) => logWarn(`TREK services: ${err instanceof Error ? err.message : String(err)}`)) + .catch((err: unknown) => logWarn(`TREK services: ${describeFailure(err)}`)) .finally(() => { if (this.work === next) this.work = null; }); diff --git a/server/src/utils/connectAttempt.ts b/server/src/utils/connectAttempt.ts new file mode 100644 index 000000000..9d32c8817 --- /dev/null +++ b/server/src/utils/connectAttempt.ts @@ -0,0 +1,28 @@ +import net from 'node:net'; + +/** + * How long Node waits for one address of a dual-stack name before it gives up + * on that connection attempt and tries the next address. + * + * Node's default is 250 ms. That is shorter than a single round trip from + * Australia or New Zealand to a server in Europe, so on a network without IPv6 + * the IPv4 handshake is cut off before it can finish, the IPv6 attempt fails at + * once, and the request ends in ETIMEDOUT although the host was reachable all + * along. Two seconds lets a slow but working handshake through; a host that + * really does not answer on one family still moves on to the other. + */ +export const CONNECT_ATTEMPT_TIMEOUT_MS = 2_000; + +/** + * Raises Node's per-address connect attempt timeout for every outbound + * connection, global fetch and undici agents alike (undici leaves the attempt + * timeout to Node unless a caller sets autoSelectFamily itself). A larger value + * an operator already set, for example through + * NODE_OPTIONS=--network-family-autoselection-attempt-timeout, is kept. + */ +export function widenConnectAttemptTimeout(): number { + const current = net.getDefaultAutoSelectFamilyAttemptTimeout(); + if (current >= CONNECT_ATTEMPT_TIMEOUT_MS) return current; + net.setDefaultAutoSelectFamilyAttemptTimeout(CONNECT_ATTEMPT_TIMEOUT_MS); + return CONNECT_ATTEMPT_TIMEOUT_MS; +} diff --git a/server/tests/unit/nest/service-identity/service-identity.helpers.test.ts b/server/tests/unit/nest/service-identity/service-identity.helpers.test.ts index 245f70f6f..3a746098d 100644 --- a/server/tests/unit/nest/service-identity/service-identity.helpers.test.ts +++ b/server/tests/unit/nest/service-identity/service-identity.helpers.test.ts @@ -1,4 +1,5 @@ import { + describeFailure, isAllowlisted, keyFingerprint, readQuotaHeaders, @@ -103,3 +104,51 @@ describe('keyFingerprint', () => { expect(keyFingerprint(token)).not.toBe(keyFingerprint(`${token}x`)); }); }); + +describe('describeFailure', () => { + const attempt = (code: string, address: string, port = 443) => + Object.assign(new Error(`connect ${code} ${address}:${port}`), { code, address, port }); + + it('spells out every address undici tried behind "fetch failed"', () => { + const cause = new AggregateError( + [attempt('ETIMEDOUT', '185.255.115.203'), attempt('ENETUNREACH', '2a0d:5940:140:bf4::2')], + '', + ); + const err = new TypeError('fetch failed', { cause }); + + expect(describeFailure(err)).toBe( + 'fetch failed (ETIMEDOUT 185.255.115.203:443, ENETUNREACH [2a0d:5940:140:bf4::2]:443)', + ); + }); + + it('names a single cause by its code', () => { + const cause = Object.assign(new Error('getaddrinfo ENOTFOUND places.liketrek.com'), { code: 'ENOTFOUND' }); + + expect(describeFailure(new TypeError('fetch failed', { cause }))).toBe('fetch failed (ENOTFOUND)'); + }); + + it('falls back to the cause message without a code', () => { + const cause = new Error('unable to verify the first certificate'); + + expect(describeFailure(new TypeError('fetch failed', { cause }))).toBe( + 'fetch failed (unable to verify the first certificate)', + ); + }); + + it('handles a cause list without usable entries and an address without a port', () => { + const portless = Object.assign(new Error('connect ECONNREFUSED'), { code: 'ECONNREFUSED', address: '192.0.2.1' }); + + expect(describeFailure(new TypeError('fetch failed', { cause: new AggregateError([], '') }))).toBe('fetch failed'); + expect(describeFailure(new TypeError('fetch failed', { cause: new AggregateError(['odd'], '') }))).toBe( + 'fetch failed (odd)', + ); + expect(describeFailure(new TypeError('fetch failed', { cause: portless }))).toBe( + 'fetch failed (ECONNREFUSED 192.0.2.1)', + ); + }); + + it('keeps a plain error or value as it is', () => { + expect(describeFailure(new Error('the issuer answered 503'))).toBe('the issuer answered 503'); + expect(describeFailure('boom')).toBe('boom'); + }); +}); diff --git a/server/tests/unit/utils/connectAttempt.test.ts b/server/tests/unit/utils/connectAttempt.test.ts new file mode 100644 index 000000000..8029f43d1 --- /dev/null +++ b/server/tests/unit/utils/connectAttempt.test.ts @@ -0,0 +1,30 @@ +import { CONNECT_ATTEMPT_TIMEOUT_MS, widenConnectAttemptTimeout } from '../../../src/utils/connectAttempt'; + +import net from 'node:net'; +import { afterEach, beforeEach, describe, expect, it } from 'vitest'; + +describe('widenConnectAttemptTimeout', () => { + let original: number; + + beforeEach(() => { + original = net.getDefaultAutoSelectFamilyAttemptTimeout(); + }); + + afterEach(() => { + net.setDefaultAutoSelectFamilyAttemptTimeout(original); + }); + + it('raises Node’s 250 ms default so a slow but working handshake is not cut off', () => { + net.setDefaultAutoSelectFamilyAttemptTimeout(250); + + expect(widenConnectAttemptTimeout()).toBe(CONNECT_ATTEMPT_TIMEOUT_MS); + expect(net.getDefaultAutoSelectFamilyAttemptTimeout()).toBe(CONNECT_ATTEMPT_TIMEOUT_MS); + }); + + it('keeps a larger value an operator already set', () => { + net.setDefaultAutoSelectFamilyAttemptTimeout(5_000); + + expect(widenConnectAttemptTimeout()).toBe(5_000); + expect(net.getDefaultAutoSelectFamilyAttemptTimeout()).toBe(5_000); + }); +});