g1t/apps/web/app/lib/perf.server.ts

154 lines5,485 bytesCodeBlame
1import { AsyncLocalStorage } from "node:async_hooks";
2
3import type { ServiceBinding } from "@g1t/contracts";
4
5import {
6 type Bookmarks,
7 type ServiceTiming,
8 PRIMARY_WINDOW_SECONDS,
9 bookmarkCookie,
10 coveredMs,
11 mayWrite,
12 readBookmarks,
13 rpcMethodOf,
14 serverTiming,
15 serviceDuration,
16 databaseTime,
17 sessionFor,
18 SESSION_SERVICES,
19} from "./perf";
20
21/**
22 * What one request to the site did: when it started, each service call
23 * and how long it took, each loader, and the D1 bookmarks it read with and
24 * got back. Kept per request with AsyncLocalStorage, so the service
25 * clients, which are shared by every request in the isolate, can record
26 * into the right one.
27 */
28type RequestPerf = {
29 started: number;
30 /** Not GET or HEAD: an action, a form post. */
31 writing: boolean;
32 /** A service call that may have written (lib/perf.ts `mayWrite`). */
33 wrote: boolean;
34 bookmarks: Bookmarks;
35 returned: Record<string, string>;
36 intervals: [number, number][];
37 services: Record<string, ServiceTiming>;
38 loaders: { id: string; ms: number; kind: "loader" | "action" }[];
39 /** How each session-capable service was asked to read, for the header. */
40 sessions: Map<string, string>;
41};
42
43const scope = new AsyncLocalStorage<RequestPerf>();
44
45/** Runs `handle` with a fresh record for `request`. */
46export function withRequestPerf<T>(request: Request, handle: () => Promise<T>): Promise<T> {
47 const writing = request.method !== "GET" && request.method !== "HEAD";
48 return scope.run(
49 {
50 started: Date.now(),
51 writing,
52 wrote: false,
53 bookmarks: readBookmarks(request.headers.get("cookie")),
54 returned: {},
55 intervals: [],
56 services: {},
57 loaders: [],
58 sessions: new Map(),
59 },
60 handle,
61 );
62}
63
64/**
65 * `binding` with its calls timed, and, for a service that reads D1 with
66 * sessions, the `x-d1-bookmark` each call should carry (lib/perf.ts
67 * `sessionFor`). Only `fetch` is wrapped: the clients use nothing else.
68 */
69export function instrumented(name: string, binding: ServiceBinding): ServiceBinding {
70 return {
71 async fetch(input: string, init?: RequestInit) {
72 const perf = scope.getStore();
73 if (!perf) return binding.fetch(input, init);
74 const session = sessionFor(name, perf.bookmarks, perf.writing, Math.floor(Date.now() / 1000));
75 let sent = init;
76 if (session) {
77 const headers = new Headers(init?.headers);
78 headers.set("x-d1-bookmark", session);
79 sent = { ...init, headers };
80 perf.sessions.set(name, session.startsWith("first-") ? session.slice(6) : "bookmark");
81 }
82 if (SESSION_SERVICES.has(name) && mayWrite(rpcMethodOf(input))) perf.wrote = true;
83 const from = Date.now();
84 const response = await binding.fetch(input, sent);
85 const to = Date.now();
86 perf.intervals.push([from, to]);
87 const timing = (perf.services[name] ??= { calls: 0, wallMs: 0, serviceMs: 0 });
88 timing.calls += 1;
89 timing.wallMs += to - from;
90 const reported = response.headers.get("server-timing");
91 timing.serviceMs += serviceDuration(reported) ?? 0;
92 const database = databaseTime(reported);
93 if (database) {
94 timing.dbMs = (timing.dbMs ?? 0) + database.ms;
95 timing.dbTrips = (timing.dbTrips ?? 0) + database.trips;
96 }
97 const bookmark = response.headers.get("x-d1-bookmark");
98 if (bookmark && SESSION_SERVICES.has(name)) perf.returned[name] = bookmark;
99 return response;
100 },
101 };
102}
103
104/**
105 * Whether this request must read current data: it writes, or the person
106 * wrote moments ago (lib/perf.ts `PRIMARY_WINDOW_SECONDS`). Caches step
107 * aside then (lib/cache.server.ts).
108 */
109export function mustReadFresh(): boolean {
110 const perf = scope.getStore();
111 if (!perf) return true;
112 if (perf.writing) return true;
113 const at = perf.bookmarks.at;
114 return at != null && Math.floor(Date.now() / 1000) - at < PRIMARY_WINDOW_SECONDS;
115}
116
117/** Records a loader's or action's time, from the route instrumentation. */
118export function recordHandler(id: string, kind: "loader" | "action", ms: number) {
119 scope.getStore()?.loaders.push({ id, kind, ms });
120}
121
122/**
123 * `response` with the request's `Server-Timing`, and, after a request
124 * that may have written, the bookmarks its services returned, so the
125 * person's next pages read at least what they just did.
126 */
127export function finishResponse(request: Request, response: Response): Response {
128 const perf = scope.getStore();
129 if (!perf) return response;
130 // A redirect's headers cannot be changed; a copy's can.
131 const answered = new Response(response.body, response);
132 const sessions = [...perf.sessions].map(([service, how]) => `${service}=${how}`).join(" ");
133 answered.headers.append(
134 "server-timing",
135 serverTiming({
136 totalMs: Date.now() - perf.started,
137 loaders: perf.loaders,
138 rpcMs: coveredMs(perf.intervals),
139 services: perf.services,
140 sessions,
141 }),
142 );
143 // Signing in with GitHub writes on a GET; the session it starts says so.
144 const signedIn = answered.headers.getSetCookie().some((cookie) => cookie.startsWith("g1t_session="));
145 const wrote = perf.writing || perf.wrote || signedIn;
146 if (wrote) {
147 const next: Bookmarks = {
148 at: Math.floor(Date.now() / 1000),
149 services: { ...perf.bookmarks.services, ...perf.returned },
150 };
151 answered.headers.append("set-cookie", bookmarkCookie(next, new URL(request.url).protocol === "https:"));
152 }
153 return answered;
154}