Public: anyone can read this; the crew can change it.

POST /apps/new names its Server-Timing phases (session, scaffold, repo, app, issue) and answers under 1 s #3718

Merged opened this

Check · Review · Land · Live done — Landed and live in production.

Merged

scout/forge:scout/3667-post-apps-new-names-its-server-timing-ph → main 5 commits fork 5 threads · 5 unresolved

  • Merged. scout/3667-post-apps-new-names-its-server-timing-ph was merged into main as c7d1303.

Review

Sign in to review this change.
6 files changed +206 −29
src/actions/apps.ts +12
@@ -289,6 +289,8 @@ export async function newApp(
289289 app: App,
290290 actor: User | undefined,
291291 input: NewAppInput,
292 /** Told how long each stretch took (`repo`, `scaffold`, `app`, `issue`), for Server-Timing. */
293 onPhase: (name: string, ms: number) => void = () => {},
292294 ): Promise<Result<NewAppResult, NewAppError | "unverified">> {
293295 const user = requireUser(actor);
294296 if (!user.ok) return user;
@@ -316,12 +318,19 @@ export async function newApp(
316318 )
317319 return err("slug_taken");
318320
321 let mark = performance.now();
322 const lap = (name: string): void => {
323 const now = performance.now();
324 onPhase(name, now - mark);
325 mark = now;
326 };
319327 const repo = await createRepo(app, user.value, {
320328 name: input.name,
321329 visibility: input.visibility ?? "private",
322330 description: input.description ?? "",
323331 ...(input.owner === undefined ? {} : { owner: input.owner }),
324332 });
333 lap("repo");
325334 if (!repo.ok) return repo;
326335 const committed = await commitToBranch(app, user.value, repo.value, {
327336 message: `Start ${input.name}`,
@@ -330,11 +339,13 @@ export async function newApp(
330339 description: input.description ?? "",
331340 }),
332341 });
342 lap("scaffold");
333343 if (!committed.ok) {
334344 await deleteRepo(app, user.value, repo.value);
335345 return err("scaffold_failed");
336346 }
337347 const record = enableApp(app, user.value, repo.value, {});
348 lap("app");

Low: app is already the total-handler entry in Server-Timing, so the header now has two app;dur= entries, and the test has to special-case it. DevTools and most tooling keep only one of them. The issue named it this way, so this doesn't block, but record or enable would be easier to read. Consider renaming it in a follow-up.

338349 // The creator administers the repository they just made, so `not_found`
339350 // here can only mean the row vanished under us — a failed scaffold.
340351 if (!record.ok) {
@@ -413,6 +424,7 @@ export async function newApp(
413424 }
414425 }
415426 }
427 lap("issue");

Non-blocking: this lap covers both the planner call (which can run up to PLAN_TIMEOUT_MS) and the issue open/assign. A separate plan lap would show which of the two is slow.

416428 return ok({
417429 repo: repo.value,
418430 app: record.value,
src/git/write.ts +64 −26
@@ -14,6 +14,9 @@ import { runGit } from "./env.ts";
1414 import { isSafeRef, isSafeTreePath } from "./guard.ts";
1515 import { resolveOid } from "./merge.ts";
1616
17 /** Most `hash-object` runs one commit has in flight on the shared git gate. */
18 export const HASH_POOL = 4;
19
1720 export interface FileWrite {
1821 readonly path: string;
1922 /** The new bytes, or `null` to delete the path from the tree. */
@@ -106,8 +109,56 @@ export async function commitFiles(
106109 : await runGit(["read-tree", "--empty"], { cwd: dir, env });
107110 if (!seed.ok) return err({ kind: "git", message: seed.error.stderr });
108111
109 for (const file of input.files) {
112 // Blobs are hashed a few at a time, then staged in as few `update-index`
outdated

High: this has no upper bound. It queues one hash-object per file (up to 1,000 via the contents API) on the shared FIFO git semaphore all at once, so one request blocks git for every other user. Run at most ~4 at a time with a small worker pool over input.files, and test that the peak concurrency stays within it.

113 // runs as order allows: a spawn each per file, one after another, is what
114 // made a first commit of twenty files slow. The pool is small and fixed
115 // because every spawn waits on the shared git gate: a thousand-file
116 // request must not queue a thousand spawns in front of everyone else.
117 const hashes: (Awaited<ReturnType<typeof runGit>> | undefined)[] =
118 new Array(input.files.length).fill(undefined);
119 let nextFile = 0;
120 const hashWorker = async (): Promise<void> => {
121 while (nextFile < input.files.length) {
122 const i = nextFile++;
123 const file = input.files[i]!;
124 if (file.content === null) continue;
125 hashes[i] = await runGit(["hash-object", "-w", "--stdin"], {
126 cwd: dir,
127 env,
outdated

Low (non-blocking): this puts every --cacheinfo of the batch into one argv. editFiles allows 1,000 files and isSafeTreePath allows 4,096-char paths, so one valid request can build about 4 MB of arguments. That is past Linux ARG_MAX, so Bun.spawn throws E2BIG and the request fails with a 500 where it used to commit. Flush when the batch's argument bytes pass about 256 KB (or a fixed count, such as 200 entries) so the argv stays bounded.

128 stdin: file.content,
129 });
130 }
131 };
132 await Promise.all(
133 Array.from({ length: Math.min(HASH_POOL, input.files.length) }, hashWorker),
134 );
135 let batch: { file: FileWrite; args: string[] }[] = [];
136 let batchBytes = 0;
137 const flush = async (): Promise<CommitFilesError | undefined> => {
138 if (batch.length === 0) return undefined;
139 const staged = await runGit(
140 ["update-index", "--add", ...batch.flatMap((b) => b.args)],
141 { cwd: dir, env },
142 );
143 const took = batch;
144 batch = [];
145 batchBytes = 0;
146 if (staged.ok) return undefined;
147 // update-index (without --replace) refuses to put a file where a
148 // directory is, or under a path that is a file. That is the answer
149 // we want — silently replacing a whole directory with one blob is
150 // how a typo'd path deletes a tree — but it is a caller error with
151 // a name, not a git failure.
152 if (/appears as both a file and as a directory/.test(staged.error.stderr)) {
153 const named = took.find((b) => staged.error.stderr.includes(`'${b.file.path}'`));
154 return { kind: "path_conflict", path: (named ?? took[0]!).file.path };
155 }
156 return { kind: "git", message: staged.error.stderr };
157 };
158 for (const [i, file] of input.files.entries()) {
110159 if (file.content === null) {
160 const failed = await flush();
161 if (failed) return err(failed);
111162 // A deletion is mode 0 through `--index-info`, not `--force-remove`:
112163 // the latter stats the working file and there is no work tree here.
113164 // `-z` makes the records NUL-terminated, so a path can never be read
@@ -121,34 +172,21 @@ export async function commitFiles(
121172 return err({ kind: "git", message: removed.error.stderr });
122173 continue;
123174 }
124 const hashed = await runGit(["hash-object", "-w", "--stdin"], {
125 cwd: dir,
126 env,
127 stdin: file.content,
128 });
175 const hashed = hashes[i]!;
129176 if (!hashed.ok) return err({ kind: "git", message: hashed.error.stderr });
130 const staged = await runGit(
131 [
132 "update-index",
133 "--add",
134 "--cacheinfo",
135 `${file.mode ?? "100644"},${hashed.value.trim()},${file.path}`,
136 ],
137 { cwd: dir, env },
138 );
139 if (!staged.ok) {
140 // update-index (without --replace) refuses to put a file where a
141 // directory is, or under a path that is a file. That is the answer
142 // we want — silently replacing a whole directory with one blob is
143 // how a typo'd path deletes a tree — but it is a caller error with
144 // a name, not a git failure.
145 return /appears as both a file and as a directory/.test(
146 staged.error.stderr,
147 )
148 ? err({ kind: "path_conflict", path: file.path })
149 : err({ kind: "git", message: staged.error.stderr });
177 batch.push({
178 file,
179 args: ["--cacheinfo", `${file.mode ?? "100644"},${hashed.value.trim()},${file.path}`],
180 });
181 // Keep one argv well under ARG_MAX: flush on count or bytes.
182 batchBytes += file.path.length + 64;
183 if (batch.length >= 200 || batchBytes > 256 * 1024) {
184 const full = await flush();
185 if (full) return err(full);
150186 }
151187 }
188 const failed = await flush();
189 if (failed) return err(failed);
152190
153191 const tree = await runGit(["write-tree"], { cwd: dir, env });
154192 if (!tree.ok) return err({ kind: "git", message: tree.error.stderr });
src/http/api.ts +2 −1
@@ -5050,6 +5050,7 @@ export function apiRoutes(router: Router<Handler>): void {
50505050 router.add("POST", "/api/v1/apps", async (ctx) => {
50515051 const denied = requireScope(ctx, "rw");
50525052 if (denied) return denied;
5053 notePhase(ctx.request, "session", takeSessionTime(ctx.request));
50535054 const input = await body(ctx.request);
50545055 const made = await newApp(ctx.app, ctx.auth.user, {
50555056 name: str(input.name),
@@ -5061,7 +5062,7 @@ export function apiRoutes(router: Router<Handler>): void {
50615062 ? { visibility: input.visibility }
50625063 : {}),
50635064 ...(typeof input.agent === "string" ? { agent: input.agent } : {}),
5064 });
5065 }, (name, ms) => notePhase(ctx.request, name, ms));
50655066 if (!made.ok) {
50665067 if (made.error === "repository_limit")
50675068 return apiError("repository_limit", 403, repositoryLimitMessage(ctx.app, ctx.auth.user!));
src/web/pages/apps.ts +4 −2
@@ -428,8 +428,10 @@ const NEW_APP_ERRORS: Record<string, string> = {
428428 // POST /apps/new
429429 export async function newAppSubmit(ctx: Ctx): Promise<Response> {
430430 if (!ctx.auth.user) return signInFirst(ctx);
431 notePhase(ctx.request, "session", takeSessionTime(ctx.request));
431432 const form = await readForm(ctx, "rw");
432433 if (form instanceof Response) return form;
434 const phase = (name: string, ms: number) => notePhase(ctx.request, name, ms);
433435 const values: NewAppValues = {
434436 owner: field(form, "owner"),
435437 name: field(form, "name"),
@@ -464,7 +466,7 @@ export async function newAppSubmit(ctx: Ctx): Promise<Response> {
464466 ? {}
465467 : { agent: values.agent }),
466468 } as const;
467 let made = await newApp(ctx.app, ctx.auth.user, { ...rest, name: base });
469 let made = await newApp(ctx.app, ctx.auth.user, { ...rest, name: base }, phase);
468470 // A derived name that collides tries `base-2`, `base-3`, … — the same
469471 // `name_taken` check an explicit name gets, just run more than once.
470472 for (
@@ -475,7 +477,7 @@ export async function newAppSubmit(ctx: Ctx): Promise<Response> {
475477 made = await newApp(ctx.app, ctx.auth.user, {
476478 ...rest,
477479 name: `${base}-${n}`,
478 });
480 }, phase);
479481 }
480482 if (!made.ok) {
481483 if (made.error === "forbidden_owner" || made.error === "unauthorized")
test/commit-fanout.test.ts added +39
@@ -0,0 +1,39 @@
1 import { afterAll, beforeAll, expect, test } from "bun:test";
2 import { mkdtemp, rm } from "node:fs/promises";
3 import { tmpdir } from "node:os";
4 import { join } from "node:path";
5 import { gitGate } from "../src/git/env.ts";
6 import { initBareRepo } from "../src/git/repos.ts";
7 import { commitFiles, HASH_POOL } from "../src/git/write.ts";
8 import { unwrap } from "../src/kernel/result.ts";
9
10 let root: string;
11 beforeAll(async () => {
12 root = await mkdtemp(join(tmpdir(), "forge-fanout-"));
13 unwrap(await initBareRepo(root));
14 });
15 afterAll(() => rm(root, { recursive: true, force: true }));
16
17 test("a many-file commit never holds more than the pool on the git gate", async () => {
18 expect(gitGate.stats().limit).toBeGreaterThan(HASH_POOL);
19 const files = Array.from({ length: HASH_POOL * 8 }, (_, i) => ({
20 path: `f/${i}.txt`,
21 content: `file ${i}\n`,
22 }));
23 gitGate.resetPeak();
24 const done = commitFiles(root, {
25 branch: "main",
26 message: "many",
27 files,
28 author: { name: "t", email: "[email protected]" },
29 });
30 let waiting = 0;
31 const watch = setInterval(() => {
32 waiting = Math.max(waiting, gitGate.stats().waiting);
33 }, 1);
34 const res = await done;
35 clearInterval(watch);
36 expect(res.ok).toBe(true);
37 expect(gitGate.stats().peak).toBeLessThanOrEqual(HASH_POOL);
38 expect(waiting).toBe(0);
39 });
test/new-app-post-timing.test.ts added +85
@@ -0,0 +1,85 @@
1 /** POST /apps/new and POST /api/v1/apps name their phases and answer under 1 s (#3667). */
2 import { afterAll, beforeAll, expect, test } from "bun:test";
3 import { mkdtempSync, rmSync } from "node:fs";
4 import { tmpdir } from "node:os";
5 import { join } from "node:path";
6 import { createApp, type App } from "../src/app.ts";
7 import { createUser } from "../src/core/users.ts";
8 import { serve, type Servers } from "../src/http/server.ts";
9 import { proveAll } from "./helpers/verified.ts";
10 import { quietLogs } from "./helpers/globals.ts";
11
12 quietLogs();
13
14 let root = "";
15 let app: App;
16 let servers: Servers;
17 let cookie = "";
18
19 beforeAll(async () => {
20 root = mkdtempSync(join(tmpdir(), "forge-new-app-timing-"));
21 app = createApp({ dataDir: root, port: 0 });
22 const u = await createUser(app.db, {
23 origin: "seed",
24 trusted: true,
25 username: "alice",
26 email: "[email protected]",
27 password: "a-good-passphrase",
28 adminIfFirst: true,
29 });
30 if (!u.ok) throw new Error(u.error);
31 proveAll(app);
32 servers = await serve(app);
33 const signin = await fetch(`${servers.url}/signin`, {
34 method: "POST",
35 headers: { origin: servers.url },
36 body: new URLSearchParams({ username: "alice", password: "a-good-passphrase" }),
37 redirect: "manual",
38 });
39 cookie = (signin.headers.get("set-cookie") ?? "").split(";")[0]!;
40 });
41 afterAll(() => {
42 servers.stop();
43 app.close();
44 rmSync(root, { recursive: true, force: true });
45 });
46
47 const PHASES = ["session", "scaffold", "repo", "app", "issue"];
48
49 function expectPhases(res: Response): void {
50 const parts = (res.headers.get("server-timing") ?? "").split(", ");
51 // `app;` is also the total-handler entry every response carries, so it
52 // appears twice; each other phase exactly once.
outdated

High (test gap): find(startsWith('app;')) matches the app;dur= total that every response already carries, so the new app phase is never checked. The test stays green without lap("app"). Count entries instead: parts.filter(p => p.startsWith('app;')).length === 2, and exactly 1 for session, repo, scaffold and issue.

53 for (const name of PHASES) {
54 const found = parts.filter((p) => p.startsWith(`${name};`));
55 expect(found).toHaveLength(name === "app" ? 2 : 1);
56 for (const p of found) expect(p).toMatch(/^[a-z]+;dur=\d+\.\d$/);
57 }
58 }
59
60 test("POST /apps/new names its phases and answers under 1 s", async () => {
61 const started = performance.now();
62 const res = await fetch(`${servers.url}/apps/new`, {
63 method: "POST",
64 headers: { origin: servers.url, cookie },
65 body: new URLSearchParams({ name: "timed", description: "A timed app" }),
66 redirect: "manual",
67 });
68 const ms = performance.now() - started;
69 expect(res.status).toBe(303);
70 expectPhases(res);
71 expect(ms).toBeLessThan(1000);
72 });
73
74 test("POST /api/v1/apps names its phases and answers under 1 s", async () => {
75 const started = performance.now();
76 const res = await fetch(`${servers.url}/api/v1/apps`, {
77 method: "POST",
78 headers: { origin: servers.url, cookie, "content-type": "application/json" },
79 body: JSON.stringify({ name: "timed-api", description: "Another timed app" }),
80 });
81 const ms = performance.now() - started;
82 expect(res.status).toBe(201);
83 expectPhases(res);
84 expect(ms).toBeLessThan(1000);
85 });

↑↓ navigate ↵ open ⌘↵ its app esc close

Keyboard shortcuts

Docs