|
| 1 | +import { describe, it, expect } from "vitest"; |
| 2 | +import { readFileSync } from "node:fs"; |
| 3 | +import { fileURLToPath } from "node:url"; |
| 4 | +import { trpcDuration } from "./metrics"; |
| 5 | +import { publicProcedure, protectedProcedure, uploadProcedure } from "../trpc"; |
| 6 | +import { appRouter } from "../root"; |
| 7 | + |
| 8 | +// p95 and p99 are read off a histogram, so they are only as good as its bucket |
| 9 | +// edges: a quantile is interpolated inside whichever bucket it lands in, and a |
| 10 | +// threshold with no edge near it is a straight line drawn across the range the |
| 11 | +// alert fires on. These tests hold the edges, the interpolation and the rules |
| 12 | +// that read them together. |
| 13 | + |
| 14 | +const rules = readFileSync( |
| 15 | + fileURLToPath( |
| 16 | + new URL("../../../../monitoring/rules/payments.yml", import.meta.url), |
| 17 | + ), |
| 18 | + "utf-8", |
| 19 | +); |
| 20 | + |
| 21 | +const buckets = (trpcDuration as unknown as { upperBounds: number[] }) |
| 22 | + .upperBounds; |
| 23 | + |
| 24 | +/** Prometheus `histogram_quantile`, over cumulative bucket counts. */ |
| 25 | +function histogramQuantile( |
| 26 | + q: number, |
| 27 | + counts: { le: number; count: number }[], |
| 28 | + total: number, |
| 29 | +) { |
| 30 | + const rank = q * total; |
| 31 | + for (let i = 0; i < counts.length; i += 1) { |
| 32 | + const bucket = counts[i]!; |
| 33 | + if (bucket.count < rank) continue; |
| 34 | + |
| 35 | + const lower = i === 0 ? 0 : counts[i - 1]!.le; |
| 36 | + const lowerCount = i === 0 ? 0 : counts[i - 1]!.count; |
| 37 | + if (!Number.isFinite(bucket.le)) return lower; |
| 38 | + |
| 39 | + const span = bucket.count - lowerCount; |
| 40 | + if (span === 0) return bucket.le; |
| 41 | + return lower + (bucket.le - lower) * ((rank - lowerCount) / span); |
| 42 | + } |
| 43 | + return counts[counts.length - 1]!.le; |
| 44 | +} |
| 45 | + |
| 46 | +/** Cumulative counts for a set of observed durations, in this metric's buckets. */ |
| 47 | +function observe(durations: number[]) { |
| 48 | + const edges = [...buckets, Number.POSITIVE_INFINITY]; |
| 49 | + return edges.map((le) => ({ |
| 50 | + le, |
| 51 | + count: durations.filter((d) => d <= le).length, |
| 52 | + })); |
| 53 | +} |
| 54 | + |
| 55 | +/** |
| 56 | + * Every `> N` threshold in seconds, from the alerts that read this histogram. |
| 57 | + * Split per alert so a counter alert next door cannot be mistaken for one. |
| 58 | + */ |
| 59 | +function latencyThresholds() { |
| 60 | + return ( |
| 61 | + rules |
| 62 | + .split(/^\s*- alert:/m) |
| 63 | + .slice(1) |
| 64 | + .filter((block) => /dsgt_trpc_duration_seconds/.test(block)) |
| 65 | + .flatMap((block) => [...block.matchAll(/>\s*([\d.]+)/g)]) |
| 66 | + .map((match) => Number(match[1])) |
| 67 | + // The error-rate alert compares a ratio, not seconds. |
| 68 | + .filter((threshold) => threshold >= 1) |
| 69 | + ); |
| 70 | +} |
| 71 | + |
| 72 | +describe("histogram buckets", () => { |
| 73 | + it("climb, and never repeat an edge", () => { |
| 74 | + expect(buckets.length).toBeGreaterThan(0); |
| 75 | + for (let i = 1; i < buckets.length; i += 1) { |
| 76 | + expect(buckets[i]!).toBeGreaterThan(buckets[i - 1]!); |
| 77 | + } |
| 78 | + }); |
| 79 | + |
| 80 | + it("puts an edge on every latency threshold that is alerted on", () => { |
| 81 | + const thresholds = latencyThresholds(); |
| 82 | + expect(thresholds.length).toBeGreaterThan(0); |
| 83 | + |
| 84 | + // Without an edge at the threshold, the alert fires on an interpolation |
| 85 | + // across the bucket the threshold sits inside. |
| 86 | + for (const threshold of thresholds) { |
| 87 | + expect(buckets).toContain(threshold); |
| 88 | + } |
| 89 | + }); |
| 90 | + |
| 91 | + it("does not more than double across the tail", () => { |
| 92 | + // Below 0.5 the resolution does not matter — nothing alerts there. |
| 93 | + const tail = buckets.filter((edge) => edge >= 0.5); |
| 94 | + for (let i = 1; i < tail.length; i += 1) { |
| 95 | + expect(tail[i]! / tail[i - 1]!).toBeLessThanOrEqual(2); |
| 96 | + } |
| 97 | + }); |
| 98 | +}); |
| 99 | + |
| 100 | +describe("p95 and p99 over these buckets", () => { |
| 101 | + it("keeps a healthy service well under both alert thresholds", () => { |
| 102 | + const counts = observe(Array.from({ length: 1000 }, () => 0.04)); |
| 103 | + |
| 104 | + expect(histogramQuantile(0.95, counts, 1000)).toBeLessThan(0.1); |
| 105 | + expect(histogramQuantile(0.99, counts, 1000)).toBeLessThan(0.1); |
| 106 | + }); |
| 107 | + |
| 108 | + it("puts p99 above p95, which is the reason both are recorded", () => { |
| 109 | + // 970 fast calls, 30 slow ones: the tail moves, the median does not. |
| 110 | + const counts = observe([ |
| 111 | + ...Array.from({ length: 970 }, () => 0.04), |
| 112 | + ...Array.from({ length: 30 }, () => 4), |
| 113 | + ]); |
| 114 | + |
| 115 | + const p95 = histogramQuantile(0.95, counts, 1000); |
| 116 | + const p99 = histogramQuantile(0.99, counts, 1000); |
| 117 | + |
| 118 | + expect(p95).toBeLessThan(p99); |
| 119 | + // The p95 alert stays quiet at 2s; the p99 alert is what catches this. |
| 120 | + expect(p95).toBeLessThan(2); |
| 121 | + expect(p99).toBeGreaterThan(2.5); |
| 122 | + }); |
| 123 | + |
| 124 | + it("catches a service that is slow for everybody", () => { |
| 125 | + const counts = observe(Array.from({ length: 1000 }, () => 6)); |
| 126 | + |
| 127 | + expect(histogramQuantile(0.95, counts, 1000)).toBeGreaterThan(2); |
| 128 | + expect(histogramQuantile(0.99, counts, 1000)).toBeGreaterThan(5); |
| 129 | + }); |
| 130 | + |
| 131 | + it("reports a quantile inside the bucket it lands in, never outside it", () => { |
| 132 | + for (const trueValue of [0.03, 0.3, 0.9, 1.7, 3, 7]) { |
| 133 | + const counts = observe(Array.from({ length: 100 }, () => trueValue)); |
| 134 | + const reported = histogramQuantile(0.99, counts, 100); |
| 135 | + |
| 136 | + const upper = buckets.find((edge) => edge >= trueValue); |
| 137 | + const lower = |
| 138 | + [...buckets].reverse().find((edge) => edge < trueValue) ?? 0; |
| 139 | + |
| 140 | + // Interpolation is allowed to be wrong, but only within one bucket. |
| 141 | + expect(reported).toBeGreaterThanOrEqual(lower); |
| 142 | + if (upper !== undefined) expect(reported).toBeLessThanOrEqual(upper); |
| 143 | + } |
| 144 | + }); |
| 145 | + |
| 146 | + it("cannot report above the last finite edge", () => { |
| 147 | + // Everything past 10s falls in +Inf, which has no upper bound to |
| 148 | + // interpolate towards, so 10 is the largest number this can ever say. |
| 149 | + const counts = observe(Array.from({ length: 100 }, () => 120)); |
| 150 | + |
| 151 | + expect(histogramQuantile(0.99, counts, 100)).toBe(10); |
| 152 | + }); |
| 153 | +}); |
| 154 | + |
| 155 | +describe("the rules that read them", () => { |
| 156 | + it("takes its quantiles from the bucket series, grouped by le", () => { |
| 157 | + const quantileExprs = rules |
| 158 | + .split("histogram_quantile(") |
| 159 | + .slice(1) |
| 160 | + .map((chunk) => chunk.slice(0, 200)); |
| 161 | + |
| 162 | + expect(quantileExprs.length).toBeGreaterThan(0); |
| 163 | + |
| 164 | + for (const expr of quantileExprs) { |
| 165 | + // histogram_quantile over anything but `_bucket` grouped by `le` returns |
| 166 | + // nothing at all — a silent no-data alert that never fires. |
| 167 | + expect(expr).toContain("_bucket"); |
| 168 | + expect(expr).toMatch(/sum by \(le[,)]/); |
| 169 | + } |
| 170 | + }); |
| 171 | + |
| 172 | + it("records p99 for the whole API and per procedure", () => { |
| 173 | + expect(rules).toContain("record: job:dsgt_trpc_duration_seconds:p99"); |
| 174 | + expect(rules).toContain("record: procedure:dsgt_trpc_duration_seconds:p99"); |
| 175 | + |
| 176 | + const perProcedure = rules.slice( |
| 177 | + rules.indexOf("record: procedure:dsgt_trpc_duration_seconds:p99"), |
| 178 | + ); |
| 179 | + expect(perProcedure).toMatch(/sum by \(le, procedure\)/); |
| 180 | + }); |
| 181 | + |
| 182 | + it("alerts only on recorded names that exist", () => { |
| 183 | + const recorded = [...rules.matchAll(/record:\s*(\S+)/g)].map((m) => m[1]!); |
| 184 | + const referenced = [ |
| 185 | + ...rules.matchAll(/expr:\s*(job|procedure):(\S+)/g), |
| 186 | + ].map((m) => `${m[1]}:${m[2]}`); |
| 187 | + |
| 188 | + for (const name of referenced) { |
| 189 | + expect(recorded).toContain(name); |
| 190 | + } |
| 191 | + }); |
| 192 | +}); |
| 193 | + |
| 194 | +describe("what gets measured", () => { |
| 195 | + // The timer is the first middleware on every base builder, so this is the |
| 196 | + // same function object each procedure should carry. |
| 197 | + const timer = ( |
| 198 | + publicProcedure as unknown as { _def: { middlewares: unknown[] } } |
| 199 | + )._def.middlewares[0]; |
| 200 | + |
| 201 | + const chainOf = (procedure: unknown) => |
| 202 | + (procedure as { _def: { middlewares: unknown[] } })._def.middlewares; |
| 203 | + |
| 204 | + it("times every base builder with the same middleware", () => { |
| 205 | + expect(timer).toBeTruthy(); |
| 206 | + expect(chainOf(protectedProcedure)).toContain(timer); |
| 207 | + expect(chainOf(uploadProcedure)).toContain(timer); |
| 208 | + }); |
| 209 | + |
| 210 | + it("times every procedure the router exposes", () => { |
| 211 | + const procedures = Object.entries( |
| 212 | + ( |
| 213 | + appRouter as unknown as { |
| 214 | + _def: { procedures: Record<string, unknown> }; |
| 215 | + } |
| 216 | + )._def.procedures, |
| 217 | + ); |
| 218 | + |
| 219 | + // A vacuous pass here would be worse than a failure. |
| 220 | + expect(procedures.length).toBeGreaterThan(100); |
| 221 | + |
| 222 | + // A procedure with no timer contributes to no percentile: it is invisible |
| 223 | + // in both p95 and p99 no matter how slow it is. |
| 224 | + const untimed = procedures |
| 225 | + .filter(([, procedure]) => !chainOf(procedure).includes(timer)) |
| 226 | + .map(([name]) => name); |
| 227 | + |
| 228 | + expect(untimed).toEqual([]); |
| 229 | + }); |
| 230 | + |
| 231 | + it("labels each observation with a path from that fixed set", () => { |
| 232 | + const names = Object.keys( |
| 233 | + ( |
| 234 | + appRouter as unknown as { |
| 235 | + _def: { procedures: Record<string, unknown> }; |
| 236 | + } |
| 237 | + )._def.procedures, |
| 238 | + ); |
| 239 | + |
| 240 | + // The label is bounded because the paths are; an unbounded label value is |
| 241 | + // what turns a histogram into a cardinality incident. |
| 242 | + for (const name of names) { |
| 243 | + expect(name).toMatch(/^[a-zA-Z0-9.]+$/); |
| 244 | + } |
| 245 | + }); |
| 246 | +}); |
0 commit comments