diff --git a/tests/unit/metrics/metrics.test.ts b/tests/unit/metrics/metrics.test.ts index 050d70e..791d11d 100644 --- a/tests/unit/metrics/metrics.test.ts +++ b/tests/unit/metrics/metrics.test.ts @@ -1,15 +1,31 @@ -import { describe, it, expect, vi, beforeEach } from "vitest"; +import { describe, it, expect, vi, beforeEach, afterEach } from "vitest"; +import { EventEmitter } from "node:events"; vi.mock("../../../src/utils/logger.js", () => ({ logger: { info: vi.fn(), error: vi.fn(), warn: vi.fn(), debug: vi.fn() }, })); -import { registry, httpRequestsTotal, httpRequestDurationSeconds } from "../../../src/metrics/index.js"; +import { + registry, + httpRequestsTotal, + httpRequestDurationSeconds, + stellarTxDurationSeconds, + quizSubmissionsTotal, + rewardClaimsTotal, + credentialsMintedTotal, + dependencyHealthCheckSeconds, + setupInfraMetrics, +} from "../../../src/metrics/index.js"; // prom-client's `Counter`/`Histogram` typings omit the `name` field even though // the metric instances carry it at runtime, so read it through a widened type. const metricName = (metric: unknown): string => (metric as { name: string }).name; +async function metricJson(name: string) { + const metrics = await registry.getMetricsAsJSON(); + return metrics.find((m) => m.name === name); +} + describe("Metrics", () => { beforeEach(() => { vi.clearAllMocks(); @@ -42,4 +58,182 @@ describe("Metrics", () => { const metrics = registry.getSingleMetric("http_request_duration_seconds"); expect(metrics).toBeDefined(); }); + + describe("metric registration (#602)", () => { + it("registers every exported metric on the shared registry", () => { + const registeredNames = registry.getMetricsAsArray().map((m) => m.name); + expect(registeredNames).toEqual( + expect.arrayContaining([ + "http_requests_total", + "http_request_duration_seconds", + "stellar_tx_duration_seconds", + "quiz_submissions_total", + "reward_claims_total", + "credentials_minted_total", + "dependency_health_check_seconds", + ]), + ); + }); + + it("registers stellarTxDurationSeconds as a histogram with method and status labels", () => { + expect(metricName(stellarTxDurationSeconds)).toBe("stellar_tx_duration_seconds"); + stellarTxDurationSeconds.observe({ method: "invoke", status: "success" }, 1.2); + const json = (stellarTxDurationSeconds as unknown as { labelNames: string[] }).labelNames; + expect(json).toEqual(["method", "status"]); + }); + + it("registers quizSubmissionsTotal as a counter with a result label", () => { + expect(metricName(quizSubmissionsTotal)).toBe("quiz_submissions_total"); + quizSubmissionsTotal.inc({ result: "pass" }); + }); + + it("registers rewardClaimsTotal as a counter with a status label", () => { + expect(metricName(rewardClaimsTotal)).toBe("reward_claims_total"); + rewardClaimsTotal.inc({ status: "claimed" }); + }); + + it("registers credentialsMintedTotal as an unlabeled counter", () => { + expect(metricName(credentialsMintedTotal)).toBe("credentials_minted_total"); + credentialsMintedTotal.inc(); + }); + + it("registers dependencyHealthCheckSeconds as a histogram with service and status labels", () => { + expect(metricName(dependencyHealthCheckSeconds)).toBe("dependency_health_check_seconds"); + dependencyHealthCheckSeconds.observe({ service: "redis", status: "ok" }, 0.01); + }); + }); + + describe("metric collection and label handling (#602)", () => { + it("accumulates multiple increments for the same label combination", async () => { + httpRequestsTotal.inc({ method: "GET", route: "/courses", status_code: "200" }); + httpRequestsTotal.inc({ method: "GET", route: "/courses", status_code: "200" }); + httpRequestsTotal.inc({ method: "GET", route: "/courses", status_code: "200" }); + + const metric = await metricJson("http_requests_total"); + const entry = metric?.values.find( + (v) => + v.labels.method === "GET" && + v.labels.route === "/courses" && + v.labels.status_code === "200", + ); + expect(entry?.value).toBe(3); + }); + + it("tracks distinct label combinations as separate time series", async () => { + httpRequestsTotal.inc({ method: "GET", route: "/courses", status_code: "200" }); + httpRequestsTotal.inc({ method: "POST", route: "/courses", status_code: "201" }); + httpRequestsTotal.inc({ method: "GET", route: "/courses", status_code: "500" }); + + const metric = await metricJson("http_requests_total"); + expect(metric?.values).toHaveLength(3); + }); + + it("records histogram observations into the correct bucket", async () => { + httpRequestDurationSeconds.observe({ method: "GET", route: "/fast", status_code: "200" }, 0.003); + httpRequestDurationSeconds.observe({ method: "GET", route: "/slow", status_code: "200" }, 4.5); + + const metric = await metricJson("http_request_duration_seconds"); + const bucketValues = metric?.values.filter((v) => "le" in v.labels) ?? []; + // The 0.005s bucket should have counted the fast request but not the slow one. + const smallestBucket = bucketValues.find( + (v) => v.labels.le === 0.005 && v.labels.route === "/fast", + ); + const slowInSmallestBucket = bucketValues.find( + (v) => v.labels.le === 0.005 && v.labels.route === "/slow", + ); + expect(smallestBucket?.value).toBe(1); + expect(slowInSmallestBucket?.value).toBe(0); + }); + + it("exposes metrics in Prometheus exposition format via registry.metrics()", async () => { + httpRequestsTotal.inc({ method: "GET", route: "/health", status_code: "200" }); + const output = await registry.metrics(); + expect(output).toContain("http_requests_total"); + expect(output).toMatch(/http_requests_total\{[^}]*method="GET"[^}]*}\s+1/); + }); + + it("resetMetrics clears accumulated counter values", async () => { + httpRequestsTotal.inc({ method: "GET", route: "/x", status_code: "200" }); + registry.resetMetrics(); + const metric = await metricJson("http_requests_total"); + expect(metric?.values).toHaveLength(0); + }); + }); + + describe("setupInfraMetrics (#602)", () => { + function fakePool(totalCount: number, idleCount: number) { + return { totalCount, idleCount } as unknown as import("pg").Pool; + } + + function fakeRedis() { + return new EventEmitter() as unknown as import("ioredis").Redis; + } + + // setupInfraMetrics registers its Gauges on the shared registry on + // every call; registry.resetMetrics() clears VALUES but not + // registrations, so calling it twice without unregistering first + // throws "already been registered". Each test gets a clean slate. + afterEach(() => { + registry.removeSingleMetric("db_active_connections"); + registry.removeSingleMetric("redis_connected"); + }); + + it("registers db_active_connections as totalCount minus idleCount", async () => { + const pool = fakePool(10, 3); + setupInfraMetrics(pool, fakeRedis()); + + const metric = await metricJson("db_active_connections"); + expect(metric?.values[0]?.value).toBe(7); + }); + + it("registers redis_connected starting at 0 (disconnected)", async () => { + setupInfraMetrics(fakePool(1, 0), fakeRedis()); + const metric = await metricJson("redis_connected"); + expect(metric?.values[0]?.value).toBe(0); + }); + + it("sets redis_connected to 1 after a connect event", async () => { + const redis = fakeRedis(); + setupInfraMetrics(fakePool(1, 0), redis); + + redis.emit("connect"); + + const metric = await metricJson("redis_connected"); + expect(metric?.values[0]?.value).toBe(1); + }); + + it("sets redis_connected back to 0 after a close event", async () => { + const redis = fakeRedis(); + setupInfraMetrics(fakePool(1, 0), redis); + + redis.emit("connect"); + redis.emit("close"); + + const metric = await metricJson("redis_connected"); + expect(metric?.values[0]?.value).toBe(0); + }); + + it("sets redis_connected to 0 after an error event", async () => { + const redis = fakeRedis(); + setupInfraMetrics(fakePool(1, 0), redis); + + redis.emit("connect"); + redis.emit("error", new Error("connection lost")); + + const metric = await metricJson("redis_connected"); + expect(metric?.values[0]?.value).toBe(0); + }); + + it("re-derives db_active_connections on every collection, reflecting live pool state", async () => { + const pool = { totalCount: 5, idleCount: 5 } as unknown as import("pg").Pool; + setupInfraMetrics(pool, fakeRedis()); + + let metric = await metricJson("db_active_connections"); + expect(metric?.values[0]?.value).toBe(0); + + pool.idleCount = 2; + metric = await metricJson("db_active_connections"); + expect(metric?.values[0]?.value).toBe(3); + }); + }); }); diff --git a/tests/unit/users/recommendations.test.ts b/tests/unit/users/recommendations.test.ts index b94a8b3..445d45c 100644 --- a/tests/unit/users/recommendations.test.ts +++ b/tests/unit/users/recommendations.test.ts @@ -3,6 +3,7 @@ import { rankCourses, scoreCourse, targetLevel, + DIFFICULTY_ORDER, type CandidateCourse, type RecommendationProfile, } from "../../../src/modules/users/recommendations.js"; @@ -47,6 +48,17 @@ describe("targetLevel", () => { targetLevel({ ...baseProfile, pace: "fast", highestCompletedLevel: 0, averageScorePercent: 95 }), ).toBe(2); }); + + it("caps at the top difficulty level when the user has completed everything (#593)", () => { + const topLevel = DIFFICULTY_ORDER.length - 1; + expect( + targetLevel({ ...baseProfile, highestCompletedLevel: topLevel, averageScorePercent: 95, pace: "fast" }), + ).toBe(topLevel); + }); + + it("stays at beginner for a slow-paced new learner with no completion history", () => { + expect(targetLevel({ ...baseProfile, pace: "slow", highestCompletedLevel: -1 })).toBe(0); + }); }); describe("scoreCourse", () => { @@ -84,4 +96,40 @@ describe("rankCourses", () => { ); expect(ranked.map((r) => r.courseId)).toEqual(["high", "mid"]); }); + + it("returns an empty list for a candidate pool with no signal at all (#593)", () => { + const ranked = rankCourses(baseProfile, [ + course({ id: "a", difficulty: "advanced" }), + course({ id: "b", difficulty: "advanced" }), + ]); + expect(ranked).toEqual([]); + }); + + it("still ranks beginner-level courses for a brand-new learner with no history (#593)", () => { + const ranked = rankCourses(baseProfile, [ + course({ id: "beginner-course", difficulty: "beginner" }), + course({ id: "advanced-course", difficulty: "advanced" }), + ]); + expect(ranked.map((r) => r.courseId)).toEqual(["beginner-course"]); + }); + + it("recommends the top difficulty level for a learner who has completed everything (#593)", () => { + const topLevel = DIFFICULTY_ORDER.length - 1; + const profile = { ...baseProfile, highestCompletedLevel: topLevel, averageScorePercent: 90 }; + const ranked = rankCourses(profile, [ + course({ id: "advanced-course", difficulty: "advanced" }), + course({ id: "beginner-course", difficulty: "beginner" }), + ]); + expect(ranked[0]?.courseId).toBe("advanced-course"); + }); + + it("returns an empty list when given no candidates", () => { + expect(rankCourses(baseProfile, [])).toEqual([]); + }); + + it("respects a limit larger than the candidate pool without erroring", () => { + const profile = { ...baseProfile, interestTags: ["stellar"] }; + const ranked = rankCourses(profile, [course({ id: "only", tags: ["stellar"] })], 10); + expect(ranked).toHaveLength(1); + }); }); diff --git a/tests/unit/utils/cursor-pagination.test.ts b/tests/unit/utils/cursor-pagination.test.ts index 472ed92..f68c8e4 100644 --- a/tests/unit/utils/cursor-pagination.test.ts +++ b/tests/unit/utils/cursor-pagination.test.ts @@ -34,4 +34,62 @@ describe("cursor-pagination (#482)", () => { ).toString("base64url"); expect(decodeCursor(cursor)).toBeNull(); }); + + it("returns null when id is present but not a string (#594)", () => { + const cursor = Buffer.from( + JSON.stringify({ createdAt: new Date().toISOString(), id: 12345 }), + "utf8", + ).toString("base64url"); + expect(decodeCursor(cursor)).toBeNull(); + }); + + it("returns null when createdAt is present but not a string (#594)", () => { + const cursor = Buffer.from( + JSON.stringify({ createdAt: 1700000000000, id: "abc" }), + "utf8", + ).toString("base64url"); + expect(decodeCursor(cursor)).toBeNull(); + }); + + it("returns null for a JSON array instead of an object (#594)", () => { + const cursor = Buffer.from(JSON.stringify(["createdAt", "id"]), "utf8").toString("base64url"); + expect(decodeCursor(cursor)).toBeNull(); + }); + + it("returns null for a JSON primitive instead of an object (#594)", () => { + const cursor = Buffer.from(JSON.stringify("just a string"), "utf8").toString("base64url"); + expect(decodeCursor(cursor)).toBeNull(); + }); + + it("still decodes successfully when the payload has extra unexpected fields (#594)", () => { + const cursor = Buffer.from( + JSON.stringify({ createdAt: new Date("2026-01-15T10:30:00.000Z").toISOString(), id: "abc", extra: "ignored" }), + "utf8", + ).toString("base64url"); + const decoded = decodeCursor(cursor); + expect(decoded).not.toBeNull(); + expect(decoded!.id).toBe("abc"); + }); + + it("round-trips an id containing special characters (#594)", () => { + const row = { createdAt: new Date("2026-01-15T10:30:00.000Z"), id: "id/with+special=chars&more" }; + const decoded = decodeCursor(encodeCursor(row)); + expect(decoded!.id).toBe(row.id); + }); + + it("round-trips distinct cursors for two rows sharing the same createdAt, differing only by id (#594)", () => { + const createdAt = new Date("2026-01-15T10:30:00.000Z"); + const cursorA = encodeCursor({ createdAt, id: "a" }); + const cursorB = encodeCursor({ createdAt, id: "b" }); + + expect(cursorA).not.toBe(cursorB); + expect(decodeCursor(cursorA)!.id).toBe("a"); + expect(decodeCursor(cursorB)!.id).toBe("b"); + }); + + it("round-trips a cursor at the Unix epoch boundary (#594)", () => { + const row = { createdAt: new Date(0), id: "epoch" }; + const decoded = decodeCursor(encodeCursor(row)); + expect(decoded!.createdAt.toISOString()).toBe(row.createdAt.toISOString()); + }); }); diff --git a/tests/unit/utils/logger.test.ts b/tests/unit/utils/logger.test.ts new file mode 100644 index 0000000..6ff3e03 --- /dev/null +++ b/tests/unit/utils/logger.test.ts @@ -0,0 +1,122 @@ +import { describe, it, expect, afterEach, vi } from "vitest"; + +/** + * #601: logger.ts builds its pino instance once at import time from + * process.env.NODE_ENV, so each level/transport case resets the module + * registry and re-imports it with a fresh env, same pattern as + * tests/unit/config/cors-origins.test.ts. + * + * Also re-imports request-context.js in the SAME reset cycle: after + * vi.resetModules(), logger.js's own import of request-context.js resolves + * to a fresh module instance with its own AsyncLocalStorage. A + * runWithRequestContext imported once at this file's top (before any + * reset) would be bound to a DIFFERENT instance and never share state with + * the logger's mixin, so each test that needs request-context must get it + * from this same loadLogger() call. + */ +async function loadLogger(nodeEnv: string | undefined) { + vi.resetModules(); + if (nodeEnv === undefined) { + vi.stubEnv("NODE_ENV", ""); + delete process.env.NODE_ENV; + } else { + vi.stubEnv("NODE_ENV", nodeEnv); + } + const loggerModule = await import("../../../src/utils/logger.js"); + const { runWithRequestContext } = await import("../../../src/utils/request-context.js"); + return { ...loggerModule, runWithRequestContext }; +} + +/** + * pino stores its configured mixin/serializers under plain (non-registry) + * Symbol("pino.mixin")/Symbol("pino.serializers") instances, so + * Symbol.for("pino.mixin") — which looks up the GLOBAL symbol registry — + * does not match pino's own symbol even though both stringify the same. + * Reflection is the only way to reach the real one from outside the module. + */ +function getPinoInternal(instance: object, description: string): T { + const symbol = Object.getOwnPropertySymbols(instance).find( + (s) => s.toString() === `Symbol(${description})`, + ); + if (!symbol) throw new Error(`pino instance has no ${description} symbol`); + return (instance as Record)[symbol] as T; +} + +describe("logger configuration (#601)", () => { + afterEach(() => { + vi.unstubAllEnvs(); + vi.resetModules(); + }); + + it("uses level 'info' in production", async () => { + const { logger } = await loadLogger("production"); + expect(logger.level).toBe("info"); + }); + + it("uses level 'silent' in test", async () => { + const { logger } = await loadLogger("test"); + expect(logger.level).toBe("silent"); + }); + + it("uses level 'debug' in development", async () => { + const { logger } = await loadLogger("development"); + expect(logger.level).toBe("debug"); + }); + + it("defaults to 'debug' (development behavior) when NODE_ENV is unset", async () => { + const { logger } = await loadLogger(undefined); + expect(logger.level).toBe("debug"); + }); + + it("serializes a request to only method and url, dropping sensitive headers", async () => { + const { logger } = await loadLogger("test"); + const fakeRequest = { method: "GET", url: "/api/v1/courses", headers: { authorization: "Bearer secret" } }; + const serializers = getPinoInternal<{ req: (r: typeof fakeRequest) => unknown }>(logger, "pino.serializers"); + const serialized = serializers.req(fakeRequest); + expect(serialized).toEqual({ method: "GET", url: "/api/v1/courses" }); + expect(serialized).not.toHaveProperty("headers"); + }); + + it("serializes a reply to only statusCode", async () => { + const { logger } = await loadLogger("test"); + const fakeReply = { statusCode: 201, body: { secret: "data" } }; + const serializers = getPinoInternal<{ res: (r: typeof fakeReply) => unknown }>(logger, "pino.serializers"); + const serialized = serializers.res(fakeReply); + expect(serialized).toEqual({ statusCode: 201 }); + expect(serialized).not.toHaveProperty("body"); + }); + + it("injects the current request's requestId via mixin when a request context is active", async () => { + const { logger, runWithRequestContext } = await loadLogger("test"); + const mixin = getPinoInternal<() => Record>(logger, "pino.mixin"); + + let result: Record = {}; + runWithRequestContext("req-abc-123", () => { + result = mixin(); + }); + expect(result).toEqual({ requestId: "req-abc-123" }); + }); + + it("returns an empty mixin object when no request context is active", async () => { + const { logger } = await loadLogger("test"); + const mixin = getPinoInternal<() => Record>(logger, "pino.mixin"); + expect(mixin()).toEqual({}); + }); + + it("lets an explicit requestId in the log call's own fields win over the mixin (pino merges mixin first, call fields on top)", async () => { + const { logger, runWithRequestContext } = await loadLogger("test"); + const mixin = getPinoInternal<() => Record>(logger, "pino.mixin"); + const chunks: string[] = []; + const destination = { write: (chunk: string) => { chunks.push(chunk); return true; } }; + const pino = (await import("pino")).default; + const testLogger = pino({ level: "info", mixin }, destination); + + runWithRequestContext("from-context", () => { + testLogger.info({ requestId: "explicit-override" }, "overridden message"); + }); + + expect(chunks.length).toBeGreaterThan(0); + const parsed = JSON.parse(chunks[chunks.length - 1]!); + expect(parsed.requestId).toBe("explicit-override"); + }); +});