From e02f454e272c57bcf819584e6524cf6d6c5eb744 Mon Sep 17 00:00:00 2001 From: Harlan Wilton Date: Wed, 7 Oct 2026 03:19:39 +1100 Subject: [PATCH 1/2] perf(artifact-delivery): build a Resolution in its own request The queue delivered a build 1.2 s after the request at the median and 3.4 s at worst. Its consumer ran in US colos, 158 to 244 ms from the D1 primary in Sydney per call, and placement cannot move a queue consumer. The POST now runs the build after its response, in waitUntil, where the request reached Cloudflare. A delayed queue message goes out first, so the queue resumes a build the runtime stops. A build that throws goes to the queue at once, and one that follows an earlier build goes back after its wait, as in the consumer. --- .../server/api/v1/resolutions/index.post.ts | 17 ++- .../server/utils/request-resolution.ts | 64 +++++++--- test/unit/artifact-resolution-latency.test.ts | 109 +++++++++++++++--- 3 files changed, 153 insertions(+), 37 deletions(-) diff --git a/layers/artifact-delivery/server/api/v1/resolutions/index.post.ts b/layers/artifact-delivery/server/api/v1/resolutions/index.post.ts index 186f89ce..043f2cd1 100644 --- a/layers/artifact-delivery/server/api/v1/resolutions/index.post.ts +++ b/layers/artifact-delivery/server/api/v1/resolutions/index.post.ts @@ -7,11 +7,11 @@ import { problemCodeSchema, } from '../../../schemas/contracts' import { withArtifactProblems } from '../../../utils/artifact-problem' -import { failResolution } from '../../../utils/build' +import { failResolution, processArtifactBuild } from '../../../utils/build' import { findPrivateRepositoryAccess } from '../../../utils/private-access' import { privateArtifactAccessEnabled } from '../../../utils/private-feature' -import { enqueueArtifactBuild } from '../../../utils/queue' -import { enqueueAfterResponse, fetchAdmittedSkillIdentity, requestResolution } from '../../../utils/request-resolution' +import { createArtifactBuildDependencies, enqueueArtifactBuild } from '../../../utils/queue' +import { buildAfterResponse, fetchAdmittedSkillIdentity, requestResolution } from '../../../utils/request-resolution' import { setSkillPageUrlHeader } from '../../../utils/skill-page' import { getResolution } from '../../../utils/state' @@ -38,9 +38,16 @@ export default withArtifactProblems(defineApiHandler({ const result = await requestResolution({ db: platform.db, lookupAdmitted: fetchAdmittedSkillIdentity(event.context), - enqueue: enqueueAfterResponse({ + enqueue: buildAfterResponse({ schedule: work => event.waitUntil(work), - enqueue: resolutionId => enqueueArtifactBuild(platform.env, resolutionId), + build: resolutionId => processArtifactBuild(createArtifactBuildDependencies(platform.env), resolutionId), + enqueue: (resolutionId, delaySeconds) => enqueueArtifactBuild(platform.env, resolutionId, delaySeconds), + reportBuildError: (resolutionId, error) => console.error(JSON.stringify({ + operation: 'artifact-build', + outcome: 'failed-in-request', + resolutionId, + error: error instanceof Error ? error.message : String(error), + })), failUnqueued: async (resolutionId, error) => { console.error(JSON.stringify({ operation: 'artifact-build', diff --git a/layers/artifact-delivery/server/utils/request-resolution.ts b/layers/artifact-delivery/server/utils/request-resolution.ts index 83fdaa93..fc76b2a1 100644 --- a/layers/artifact-delivery/server/utils/request-resolution.ts +++ b/layers/artifact-delivery/server/utils/request-resolution.ts @@ -1,6 +1,7 @@ import type { H3EventContext } from 'h3' import type { SourceRequest } from '../schemas/contracts' import type { FetchAdmittedSkillIdentity } from './admitted-identity' +import type { ArtifactBuildOutcome } from './build' import type { CreateResolutionResult } from './state' import { admittedSourceRequest } from './admitted-identity' import { createResolution, resolutionRequestIdentity } from './state' @@ -61,30 +62,63 @@ export async function requestResolution( return result } -export interface AfterResponseEnqueueDependencies { +/** + * When the queue takes over a build that ran in its request. A Worker keeps a + * request alive 30 s after its response, so a build the runtime stopped + * resumes on the queue a few seconds later. + */ +export const IN_REQUEST_BUILD_FALLBACK_SECONDS = 35 + +export interface AfterResponseBuildDependencies { /** Keep work alive after the response, such as the Worker's `waitUntil`. */ schedule: (work: Promise) => void - enqueue: (resolutionId: string) => Promise - /** Settle a Resolution whose build never reached the queue. */ + /** Run the build here, as the queue consumer would. */ + build: (resolutionId: string) => Promise + enqueue: (resolutionId: string, delaySeconds?: number) => Promise + /** Settle a Resolution that neither this request nor the queue can build. */ failUnqueued: (resolutionId: string, error: unknown) => Promise + reportBuildError: (resolutionId: string, error: unknown) => void } /** - * An `enqueue` that sends the build message after the response. + * An `enqueue` that builds the Resolution in its own request, after the + * response, with the queue as the fallback. * - * The queue send took 446 to 500 ms of a 590 to 650 ms request in three - * production traces from Sydney and Bangkok on 2026-10-07. The CLI polls - * for the result anyway, so the send need not hold the first answer. A send - * that fails settles the Resolution as a retryable failure, so the polling - * CLI requests a new Resolution instead of waiting out its deadline. + * The queue delivered a build 1.2 s after the request at the median and 3.4 s + * at worst, in 20 production runs on 2026-10-07. Its consumer ran in US + * colos, where each D1 call to the Sydney primary took 158 to 244 ms. A + * request runs where the client reached Cloudflare, and from Sydney the same + * calls took 8 to 21 ms. Queue placement cannot move a consumer. + * + * A delayed message goes out first, so a build the runtime stops resumes on + * the queue. A build that throws goes to the queue at once, for its retry + * ladder. A build that follows an earlier build of the same Skill goes back + * on the queue after the wait it names, as the consumer does. */ -export function enqueueAfterResponse( - dependencies: AfterResponseEnqueueDependencies, +export function buildAfterResponse( + dependencies: AfterResponseBuildDependencies, ): (resolutionId: string) => Promise { return async (resolutionId) => { - dependencies.schedule( - dependencies.enqueue(resolutionId) - .catch(error => dependencies.failUnqueued(resolutionId, error)), - ) + dependencies.schedule(buildHere(dependencies, resolutionId)) } } + +async function buildHere(dependencies: AfterResponseBuildDependencies, resolutionId: string): Promise { + const fallback = dependencies.enqueue(resolutionId, IN_REQUEST_BUILD_FALLBACK_SECONDS) + .then(() => ({ _tag: 'queued' as const }), (error: unknown) => ({ _tag: 'unqueued' as const, error })) + const outcome = await dependencies.build(resolutionId) + .then(value => ({ _tag: 'built' as const, value }), (error: unknown) => ({ _tag: 'threw' as const, error })) + const queued = await fallback + if (outcome._tag === 'built' && outcome.value._tag !== 'deferred') + return + if (outcome._tag === 'threw') + dependencies.reportBuildError(resolutionId, outcome.error) + const delaySeconds = outcome._tag === 'built' && outcome.value._tag === 'deferred' + ? outcome.value.delaySeconds + : undefined + const sent = await dependencies.enqueue(resolutionId, delaySeconds) + .then(() => null, (error: unknown) => error) + // With the delayed message queued, the consumer still takes the build over. + if (sent !== null && queued._tag === 'unqueued') + await dependencies.failUnqueued(resolutionId, sent) +} diff --git a/test/unit/artifact-resolution-latency.test.ts b/test/unit/artifact-resolution-latency.test.ts index 9e300cae..47f785e8 100644 --- a/test/unit/artifact-resolution-latency.test.ts +++ b/test/unit/artifact-resolution-latency.test.ts @@ -1,8 +1,9 @@ import type { SourceRequest } from '../../layers/artifact-delivery/server/schemas/contracts' +import type { ArtifactBuildOutcome } from '../../layers/artifact-delivery/server/utils/build' import type { ResolutionRow } from '../../layers/artifact-delivery/server/utils/state' -import { describe, expect, it } from 'vitest' +import { describe, expect, it, vi } from 'vitest' import { failResolution } from '../../layers/artifact-delivery/server/utils/build' -import { enqueueAfterResponse } from '../../layers/artifact-delivery/server/utils/request-resolution' +import { buildAfterResponse, IN_REQUEST_BUILD_FALLBACK_SECONDS } from '../../layers/artifact-delivery/server/utils/request-resolution' import { RESOLUTION_CHECK_MS, RESOLUTION_WAIT_MS, @@ -111,35 +112,89 @@ describe('waiting for a Resolution to move', () => { }) }) -describe('queueing a build after the response', () => { - it('answers before the queue send finishes', async () => { +describe('building in the request after the response', () => { + const ID = '6d3c8f1e-8d5f-4a43-9f0e-2a5e1d4b7c11' + + function harness(options: { + build?: (resolutionId: string) => Promise + enqueue?: (resolutionId: string, delaySeconds?: number) => Promise + } = {}) { const scheduled: Array> = [] + const enqueue = vi.fn(options.enqueue ?? (async () => {})) + const failUnqueued = vi.fn(async () => {}) + const reportBuildError = vi.fn() + const start = buildAfterResponse({ + schedule: work => scheduled.push(work), + build: options.build ?? (async resolutionId => ({ _tag: 'ready', resolutionId })), + enqueue, + failUnqueued, + reportBuildError, + }) + return { start, enqueue, failUnqueued, reportBuildError, settle: () => Promise.all(scheduled), scheduled } + } + + it('answers before the build runs', async () => { let release = () => {} - const sent = new Promise((resolve) => { + const built = new Promise((resolve) => { release = resolve }) - const enqueue = enqueueAfterResponse({ - schedule: work => scheduled.push(work), - enqueue: async () => await sent, - failUnqueued: async () => expect.fail('the send did not fail'), - }) + const run = harness({ build: async (resolutionId) => { + await built + return { _tag: 'ready', resolutionId } + } }) - await enqueue('6d3c8f1e-8d5f-4a43-9f0e-2a5e1d4b7c11') + await run.start(ID) - expect(scheduled).toHaveLength(1) + expect(run.scheduled).toHaveLength(1) release() - await Promise.all(scheduled) + await run.settle() }) - it('fails the Resolution as retryable when the send fails', async () => { + it('builds in the request and leaves only the delayed fallback on the queue', async () => { + const build = vi.fn(async (resolutionId: string) => ({ _tag: 'ready' as const, resolutionId })) + const run = harness({ build }) + + await run.start(ID) + await run.settle() + + expect(build).toHaveBeenCalledWith(ID) + expect(run.enqueue.mock.calls).toEqual([[ID, IN_REQUEST_BUILD_FALLBACK_SECONDS]]) + }) + + it('sends a build that throws to the queue at once', async () => { + const run = harness({ build: async () => { + throw new Error('GitHub read failed at tree: The operation was aborted due to timeout') + } }) + + await run.start(ID) + await run.settle() + + expect(run.enqueue.mock.calls).toEqual([[ID, IN_REQUEST_BUILD_FALLBACK_SECONDS], [ID, undefined]]) + expect(run.reportBuildError).toHaveBeenCalledOnce() + expect(run.failUnqueued).not.toHaveBeenCalled() + }) + + it('puts a build that follows an earlier one back on the queue after the wait it names', async () => { + const run = harness({ build: async resolutionId => ({ _tag: 'deferred', resolutionId, delaySeconds: 2 }) }) + + await run.start(ID) + await run.settle() + + expect(run.enqueue.mock.calls).toEqual([[ID, IN_REQUEST_BUILD_FALLBACK_SECONDS], [ID, 2]]) + }) + + it('fails the Resolution as retryable when neither the request nor the queue can build it', async () => { const sqlite = createSqliteD1(MIGRATIONS) - const identity = await resolutionRequestIdentity(request, 'resolution-enqueue-test-key') + const identity = await resolutionRequestIdentity(request, 'resolution-build-test-key') const created = await createResolution(sqlite.db, request, identity, NOW) if (created._tag === 'idempotency-conflict') throw new Error('Test Resolution conflicted') const scheduled: Array> = [] - const enqueue = enqueueAfterResponse({ + const start = buildAfterResponse({ schedule: work => scheduled.push(work), + build: async () => { + throw new Error('D1_ERROR: Network connection lost.') + }, enqueue: async () => { throw new Error('Queue send failed: 503') }, @@ -148,9 +203,10 @@ describe('queueing a build after the response', () => { if (row) await failResolution({ db: sqlite.db, now: () => NOW }, row, 'SERVICE_UNAVAILABLE', true) }, + reportBuildError: () => {}, }) - await enqueue(created.row.id) + await start(created.row.id) await Promise.all(scheduled) const settled = await getResolution(sqlite.db, created.row.id) @@ -161,4 +217,23 @@ describe('queueing a build after the response', () => { }) sqlite.close() }) + + it('keeps a build that threw on the delayed fallback when the second send fails', async () => { + let sends = 0 + const run = harness({ + build: async () => { + throw new Error('The operation was aborted due to timeout') + }, + enqueue: async () => { + sends += 1 + if (sends > 1) + throw new Error('Queue send failed: 503') + }, + }) + + await run.start(ID) + await run.settle() + + expect(run.failUnqueued).not.toHaveBeenCalled() + }) }) From ee8d72b0a33b144ec635040bbdd7e74d6b29bbf4 Mon Sep 17 00:00:00 2001 From: Harlan Wilton Date: Wed, 7 Oct 2026 03:22:23 +1100 Subject: [PATCH 2/2] docs(artifact-delivery): state the measured Sydney D1 range --- layers/artifact-delivery/server/utils/request-resolution.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/layers/artifact-delivery/server/utils/request-resolution.ts b/layers/artifact-delivery/server/utils/request-resolution.ts index fc76b2a1..0aa9a731 100644 --- a/layers/artifact-delivery/server/utils/request-resolution.ts +++ b/layers/artifact-delivery/server/utils/request-resolution.ts @@ -88,7 +88,7 @@ export interface AfterResponseBuildDependencies { * at worst, in 20 production runs on 2026-10-07. Its consumer ran in US * colos, where each D1 call to the Sydney primary took 158 to 244 ms. A * request runs where the client reached Cloudflare, and from Sydney the same - * calls took 8 to 21 ms. Queue placement cannot move a consumer. + * calls took 8 to 36 ms. Queue placement cannot move a consumer. * * A delayed message goes out first, so a build the runtime stops resumes on * the queue. A build that throws goes to the queue at once, for its retry