1import { PositiveInt } from "@t3tools/contracts";
2import * as Clock from "effect/Clock";
3import * as Config from "effect/Config";
4import * as Console from "effect/Console";
5import * as DateTime from "effect/DateTime";
6import * as Duration from "effect/Duration";
7import * as Effect from "effect/Effect";
8import * as FileSystem from "effect/FileSystem";
9import * as Option from "effect/Option";
10import * as Schema from "effect/Schema";
11import { Command, Flag } from "effect/cli";
12
13import * as ServerConfig from "../config.ts";
14import { streamTraceFileLines, toRotatedTracePaths } from "../diagnostics/TraceDiagnostics.ts";
15import { resolveBaseDir } from "../os-jank.ts";
16import { baseDirFlag, DurationFromString, traceFileConfig, traceMaxFilesConfig } from "./config.ts";
17
18const decodeTraceSpanLine = Schema.decodeUnknownOption(
19 Schema.fromJsonString(
20 Schema.Struct({
21 name: Schema.String,
22 durationMs: Schema.Finite,
23 endTimeUnixNano: Schema.FiniteFromString,
24 exit: Schema.optional(Schema.Struct({ _tag: Schema.String })),
25 // OTLP errors use code 2; interrupts carry effect.fiber.interrupted, or code 1 with Interrupted before Effect 4.0.2.
26 status: Schema.optional(
27 Schema.Struct({
28 code: Schema.optional(Schema.String),
29 message: Schema.optional(Schema.String),
30 }),
31 ),
32 attributes: Schema.optional(
33 Schema.Struct({ "effect.fiber.interrupted": Schema.optional(Schema.Unknown) }),
34 ),
35 }),
36 ),
37);
38
39export function makeTraceSpanSummary(sinceMs = -Infinity) {
40 const byName = new Map<string, { durations: number[]; interrupted: number; failures: number }>();
41 let spanCount = 0;
42 let skippedLineCount = 0;
43 let firstEndMs = Infinity;
44 let lastEndMs = -Infinity;
45
46 const addLine = (line: string) => {
47 if (line.trim().length === 0) return;
48 const span = Option.getOrUndefined(decodeTraceSpanLine(line));
49 if (span === undefined) {
50 skippedLineCount += 1;
51 return;
52 }
53 const endMs = span.endTimeUnixNano / 1_000_000;
54 // The report prints end times as dates, so skip ones outside the Date range.
55 if (Option.isNone(DateTime.make(endMs))) {
56 skippedLineCount += 1;
57 return;
58 }
59 if (endMs < sinceMs) return;
60
61 spanCount += 1;
62 firstEndMs = Math.min(firstEndMs, endMs);
63 lastEndMs = Math.max(lastEndMs, endMs);
64 const stats = byName.get(span.name) ?? { durations: [], interrupted: 0, failures: 0 };
65 stats.durations.push(span.durationMs);
66 if (
67 span.exit?._tag === "Interrupted" ||
68 span.attributes?.["effect.fiber.interrupted"] === true ||
69 span.status?.message === "Interrupted"
70 ) {
71 stats.interrupted += 1;
72 }
73 if (span.exit?._tag === "Failure" || span.status?.code === "2") stats.failures += 1;
74 byName.set(span.name, stats);
75 };
76
77 const finish = () => {
78 const minutes = (lastEndMs - firstEndMs) / 60_000;
79 const spans = [...byName]
80 .map(([name, { durations, interrupted, failures }]) => {
81 const sorted = durations.toSorted((left, right) => left - right);
82 const percentile = (p: number) => sorted[Math.ceil(p * sorted.length) - 1]!;
83 return {
84 name,
85 count: sorted.length,
86 perMinute: minutes > 0 ? sorted.length / minutes : undefined,
87 p50Ms: percentile(0.5),
88 p90Ms: percentile(0.9),
89 maxMs: sorted[sorted.length - 1]!,
90 interrupted,
91 failures,
92 };
93 })
94 .toSorted((left, right) => right.count - left.count || left.name.localeCompare(right.name));
95
96 return { spanCount, skippedLineCount, firstEndMs, lastEndMs, minutes, spans };
97 };
98
99 return { addLine, finish };
100}
101
102const formatMs = (ms: number) =>
103 Math.round(ms) < 1_000 ? `${Math.round(ms)}ms` : `${Math.round(ms / 100) / 10}s`;
104
105export function formatTraceSummary(
106 summary: ReturnType<ReturnType<typeof makeTraceSpanSummary>["finish"]>,
107 limit: number,
108) {
109 const header = ["span", "count", "/min", "p50", "p90", "max", "interrupted", "failed"];
110 const rows = summary.spans
111 .slice(0, limit)
112 .map((span) => [
113 span.name,
114 String(span.count),
115 span.perMinute === undefined
116 ? "-"
117 : span.perMinute < 0.1
118 ? "<0.1"
119 : span.perMinute.toFixed(1),
120 formatMs(span.p50Ms),
121 formatMs(span.p90Ms),
122 formatMs(span.maxMs),
123 String(span.interrupted),
124 String(span.failures),
125 ]);
126 const table = [header, ...rows];
127 const widths = header.map((_, column) => Math.max(...table.map((row) => row[column]!.length)));
128 const formatIso = (ms: number) => DateTime.formatIso(DateTime.makeUnsafe(ms));
129 return [
130 `${summary.spanCount} spans ended from ${formatIso(summary.firstEndMs)} to ${formatIso(summary.lastEndMs)} (${summary.minutes.toFixed(1).replace(/\.0+$/, "")} min).`,
131 ...(summary.skippedLineCount > 0
132 ? [`Skipped ${summary.skippedLineCount} lines that are not spans.`]
133 : []),
134 "",
135 ...table.map((row) =>
136 row
137 .map((cell, column) =>
138 column === 0 ? cell.padEnd(widths[column]!) : cell.padStart(widths[column]!),
139 )
140 .join(" "),
141 ),
142 ...(summary.spans.length > limit
143 ? ["", `${summary.spans.length - limit} more span names. Use --limit to show more.`]
144 : []),
145 ].join("\n");
146}
147
148const traceSummaryCommand = Command.make("summary", {
149 baseDir: baseDirFlag,
150 since: Flag.String("since").pipe(
151 Flag.withSchema(DurationFromString),
152 Flag.withDescription("Only count spans that ended in this window, for example 30m or 2h."),
153 Flag.optional,
154 ),
155 limit: Flag.Int("limit").pipe(
156 Flag.withSchema(PositiveInt),
157 Flag.withDescription("Number of span names to show, busiest first."),
158 Flag.withDefault(25),
159 ),
160}).pipe(
161 Command.withDescription("Summarize the local server trace file: counts, rates, and latency."),
162 Command.withHandler(
163 Effect.fn("cli.trace.summary")(function* (flags) {
164 const fs = yield* FileSystem.FileSystem;
165 const envHome = yield* Config.String("T3CODE_HOME").pipe(Config.option);
166 const baseDir = yield* resolveBaseDir(
167 Option.getOrUndefined(Option.orElse(flags.baseDir, () => envHome)),
168 );
169 const traceFilePath =
170 (yield* traceFileConfig) ??
171 (yield* ServerConfig.deriveServerPaths(baseDir, undefined)).serverTracePath;
172 const sinceMs = Option.isSome(flags.since)
173 ? (yield* Clock.currentTimeMillis) - Duration.toMillis(flags.since.value)
174 : undefined;
175 const summarizer = makeTraceSpanSummary(sinceMs);
176 yield* Effect.forEach(
177 toRotatedTracePaths(traceFilePath, yield* traceMaxFilesConfig),
178 (path) => streamTraceFileLines(fs, path, summarizer.addLine),
179 { discard: true },
180 );
181 const summary = summarizer.finish();
182
183 yield* Console.log(
184 summary.spanCount === 0
185 ? `No spans found in ${traceFilePath} or its rotated files${sinceMs === undefined ? "" : " in that window"}.${summary.skippedLineCount > 0 ? ` Skipped ${summary.skippedLineCount} lines that are not spans.` : ""}`
186 : formatTraceSummary(summary, flags.limit),
187 );
188 }),
189 ),
190);
191
192export const traceCommand = Command.make("trace").pipe(
193 Command.withDescription("Inspect the local server trace file."),
194 Command.withSubcommands([traceSummaryCommand]),
195);