Skip to content
Source
Sign inSign up

serverLogger.test.ts

317 lines11.1 KB

1import * as NodePath from "@effect/platform-node/NodePath";
2import { assert, describe, it } from "@effect/vitest";
3import * as NodeOS from "node:os";
4import * as NodeUtil from "node:util";
5​
6import { ExternalLauncherBrowserSpawnError } from "@t3tools/contracts";
7import * as Cause from "effect/Cause";
8import * as Console from "effect/Console";
9import * as Effect from "effect/Effect";
10import * as Exit from "effect/Exit";
11import * as Layer from "effect/Layer";
12import * as Redactable from "effect/Redactable";
13import * as Path from "effect/Path";
14import * as Tracer from "effect/Tracer";
15import * as HttpClient from "effect/http/HttpClient";
16import * as HttpClientResponse from "effect/http/HttpClientResponse";
17import * as TestConsole from "effect/testing/TestConsole";
18​
19import { DEFAULT_SIGNAL_EXPORT } from "@t3tools/shared/observability";
20import * as OtelEnvironment from "@t3tools/shared/otelEnvironment";
21​
22import * as ServerConfig from "./config.ts";
23import * as ExternalLauncher from "./process/externalLauncher.ts";
24import * as ServerLogger from "./serverLogger.ts";
25import {
26 announceStartupPairingUrl,
27 logBrowserAutoOpenUnavailable,
28 maybeOpenBrowser,
29} from "./serverRuntimeStartup.ts";
30​
31interface ExportedRequest {
32 readonly url: string;
33 readonly headers: Readonly<Record<string, string>>;
34 readonly body: string;
36​
37const layerCollector = (requests: Array<ExportedRequest>) =>
38 Layer.succeed(
39 HttpClient.HttpClient,
40 HttpClient.make((request) =>
41 Effect.sync(() => {
42 requests.push({
43 url: request.url,
44 headers: request.headers,
45 body:
46 request.body._tag === "Uint8Array" ? new TextDecoder().decode(request.body.body) : "",
47 });
48 return HttpClientResponse.fromWeb(request, new Response(null, { status: 200 }));
49 }),
50 ),
51 );
52​
53const layerConfig = (overrides: Partial<ServerConfig.ServerConfig["Service"]>) =>
54 Layer.effect(
55 ServerConfig.ServerConfig,
56 Effect.gen(function* () {
57 const path = yield* Path.Path;
58 const baseDir = path.join(NodeOS.tmpdir(), "t3-server-logger-test");
59 const derivedPaths = yield* ServerConfig.deriveServerPaths(baseDir, undefined);
60 return ServerConfig.make({
61 logLevel: "Info",
62 traceMinLevel: "Info",
63 traceTimingEnabled: false,
64 traceBatchWindowMs: 200,
65 traceMaxBytes: 1024,
66 traceMaxFiles: 1,
67 otlpTracesUrl: undefined,
68 otlpMetricsUrl: undefined,
69 otlpLogsUrl: undefined,
70 otlpTracesExport: DEFAULT_SIGNAL_EXPORT,
71 otlpMetricsExport: DEFAULT_SIGNAL_EXPORT,
72 otlpLogsExport: DEFAULT_SIGNAL_EXPORT,
73 otelEnvironment: OtelEnvironment.none,
74 cwd: baseDir,
75 baseDir,
76 ...derivedPaths,
77 mode: "web",
78 autoBootstrapProjectFromCwd: false,
79 logWebSocketEvents: false,
80 tailscaleServeEnabled: false,
81 tailscaleServePort: 443,
82 port: 0,
83 host: undefined,
84 desktopBootstrapToken: undefined,
85 desktopTelemetryFd: undefined,
86 desktopTelemetryControlFd: undefined,
87 resourceMonitorPath: undefined,
88 staticDir: undefined,
89 devUrl: undefined,
90 devAllowedOrigins: [],
91 noBrowser: false,
92 startupPresentation: "browser",
93 ...overrides,
94 });
95 }),
96 ).pipe(Layer.provide(NodePath.layer));
97​
98/**
99 * Runs `program` (one log line by default) inside a span so the tracer logger
100 * has somewhere to attach an event, then reports both what the collector
101 * received and what landed on the span.
102 */
103const logInSpanThrough = (
104 overrides: Partial<ServerConfig.ServerConfig["Service"]>,
105 program: Effect.Effect<void> = Effect.log("server logger under test"),
106) =>
107 Effect.gen(function* () {
108 const requests: Array<ExportedRequest> = [];
109 const spans: Array<Tracer.NativeSpan> = [];
110 const layerTracer = Layer.succeed(
111 Tracer.Tracer,
112 Tracer.make({
113 span: (spanOptions) => {
114 const span = new Tracer.NativeSpan(spanOptions);
115 spans.push(span);
116 return span;
117 },
118 }),
119 );
120 yield* program.pipe(
121 Effect.withSpan("server-logger-test"),
122 Effect.provide(
123 Layer.mergeAll(
124 ServerLogger.layer.pipe(
125 Layer.provide(layerConfig(overrides)),
126 Layer.provide(layerCollector(requests)),
127 ),
128 layerTracer,
129 ),
130 ),
131 );
132 return { requests, spans };
133 });
134​
135const printThroughConsole = (fields: object) =>
136 Effect.gen(function* () {
137 const printed: Array<string> = [];
138 const testConsole = {
139 ...globalThis.console,
140 log: (...args: ReadonlyArray<unknown>) => {
141 printed.push(NodeUtil.format(...args));
142 },
143 } satisfies Console.Console;
144 yield* Effect.logWarning("pull request watch check failed", fields).pipe(
145 Effect.provide(
146 ServerLogger.layer.pipe(Layer.provide(layerConfig({})), Layer.provide(layerCollector([]))),
147 ),
148 Effect.provideService(Console.Console, testConsole),
149 );
150 return printed.join("\n");
151 });
152​
153describe("ServerLoggerLive", () => {
154 it.effect("exports the operator's service instance id instead of a generated one", () =>
155 Effect.gen(function* () {
156 const { requests } = yield* logInSpanThrough({
157 otlpLogsUrl: "https://collector.example.com/v1/logs",
158 otelEnvironment: {
159 ...OtelEnvironment.none,
160 resourceAttributes: { "service.instance.id": "pod-7" },
161 },
162 });
163​
164 const body = requests.map((request) => request.body).join("\n");
165 assert.include(body, '"key":"service.instance.id","value":{"stringValue":"pod-7"}');
166 }),
167 );
168​
169 it.effect("exports a resource that names whether the desktop app launched the server", () =>
170 Effect.gen(function* () {
171 const { requests } = yield* logInSpanThrough({
172 otlpLogsUrl: "https://collector.example.com/v1/logs",
173 mode: "desktop",
174 });
175​
176 const body = requests.map((request) => request.body).join("\n");
177 assert.include(body, '"key":"t3code.server.managed_by","value":{"stringValue":"desktop"}');
178 assert.notInclude(body, "service.mode");
179 }),
180 );
181​
182 it.effect("exports logged request failures without their connection tickets", () =>
183 Effect.gen(function* () {
184 const { requests } = yield* logInSpanThrough(
185 { otlpLogsUrl: "https://collector.example.com/v1/logs" },
186 Effect.logError(
187 Cause.die(
188 new Error("RequestParseError (GET /ws?wsTicket=ticket-secret&dpop=proof-secret)"),
189 ),
190 ),
191 );
192​
193 const body = requests.map((request) => request.body).join("\n");
194 assert.include(body, "wsTicket=<redacted>&dpop=<redacted>");
195 assert.notInclude(body, "ticket-secret");
196 assert.notInclude(body, "proof-secret");
197 }),
198 );
199​
200 it.effect("prints a cause passed as a log field instead of collapsing it", () =>
201 Effect.gen(function* () {
202 const output = yield* printThroughConsole({
203 threadId: "thread-1",
204 cause: Cause.fail(new Error("gh: HTTP 502 from api.github.com")),
205 });
206​
207 assert.include(output, "threadId: 'thread-1'");
208 assert.include(output, "gh: HTTP 502 from api.github.com");
209 assert.notInclude(output, "[Object]");
210 }),
211 );
212​
213 // regression: #16642 logs printed causes as [Object]
214 it.effect("leaves getters uncalled while printing a cause field", () =>
215 Effect.gen(function* () {
216 const output = yield* printThroughConsole({
217 cause: Cause.fail(new Error("upstream refused")),
218 get detail(): string {
219 throw new Error("getter must not run");
220 },
221 });
222​
223 assert.include(output, "upstream refused");
224 assert.notInclude(output, "getter must not run");
225 }),
226 );
227​
228 it.effect("leaves a message with its own redaction hook to that hook", () =>
229 Effect.gen(function* () {
230 const output = yield* printThroughConsole({
231 token: "secret-token-value",
232 cause: Cause.fail(new Error("upstream refused")),
233 [Redactable.symbolRedactable](this: { readonly cause: unknown }) {
234 return { token: "<redacted>", cause: Cause.isCause(this.cause) ? "cause" : "missing" };
235 },
236 });
237​
238 assert.include(output, "token: '<redacted>'");
239 assert.include(output, "cause: 'cause'");
240 assert.notInclude(output, "secret-token-value");
241 }),
242 );
243​
244 describe("startup pairing URL", () => {
245 const pairingToken = "PAIRTOKEN7Q4K9";
246 const pairingUrl = `http://localhost:3773/pair#token=${pairingToken}`;
247 const announce = announceStartupPairingUrl(pairingUrl).pipe(
248 Effect.andThen(logBrowserAutoOpenUnavailable),
249 );
250​
251 it.effect("prints the full URL but keeps its token out of exported log records", () =>
252 Effect.gen(function* () {
253 const { requests } = yield* logInSpanThrough(
254 { otlpLogsUrl: "https://collector.example.com/v1/logs" },
255 announce,
256 );
257​
258 const body = requests.map((request) => request.body).join("\n");
259 assert.include(body, "Authentication required");
260 assert.notInclude(body, pairingToken);
261 const printed = (yield* TestConsole.logLines).map((line) =>
262 Array.isArray(line) ? line.join(" ") : String(line),
263 );
264 assert.isTrue(printed.some((line) => line.includes(`pairingUrl: ${pairingUrl}`)));
265 }).pipe(Effect.provide(TestConsole.layer)),
266 );
267​
268 it.effect("keeps the token off the span events the trace file records", () =>
269 Effect.gen(function* () {
270 const { spans } = yield* logInSpanThrough({}, announce);
271​
272 const events = JSON.stringify(
273 spans.flatMap((span) => span.events.map(([name, , attributes]) => [name, attributes])),
274 );
275 assert.include(events, "Authentication required");
276 assert.notInclude(events, pairingToken);
277 }).pipe(Effect.provide(TestConsole.layer)),
278 );
279​
280 it.effect("keeps the token out of traces when the browser fails to open", () =>
281 Effect.gen(function* () {
282 const failingLaunch = maybeOpenBrowser(pairingUrl).pipe(
283 Effect.provide(
284 Layer.mergeAll(
285 layerConfig({ noBrowser: false }),
286 Layer.mock(ExternalLauncher.ExternalLauncher)({
287 launchBrowser: (target) =>
288 Effect.fail(
289 new ExternalLauncherBrowserSpawnError({
290 target,
291 command: "xdg-open",
292 args: [target],
293 cause: new Error("spawn xdg-open ENOENT"),
294 }),
295 ).pipe(Effect.withSpan("externalLauncher.launchBrowser")),
296 }),
297 ),
298 ),
299 );
300 const { spans } = yield* logInSpanThrough({}, failingLaunch);
301​
302 const recorded = JSON.stringify(
303 spans.map((span) => ({
304 name: span.name,
305 events: span.events.map(([name, , attributes]) => [name, attributes]),
306 exit:
307 span.status._tag === "Ended" && Exit.isFailure(span.status.exit)
308 ? Cause.pretty(span.status.exit.cause)
309 : null,
310 })),
311 );
312 assert.include(recorded, "browser auto-open unavailable");
313 assert.notInclude(recorded, pairingToken);
314 }),
315 );
316 });
317});