diff --git a/src/services/webhook-dispatcher.ts b/src/services/webhook-dispatcher.ts index 6415e27..9b3cec3 100644 --- a/src/services/webhook-dispatcher.ts +++ b/src/services/webhook-dispatcher.ts @@ -104,7 +104,7 @@ async function sendWebhook( logger.error({ url, err }, "Webhook dispatch failed"); return { success: false, error: err.message }; } finally { - clearTimeout(timer); + clearTimeout(timeout); } } diff --git a/src/utils/logger.ts b/src/utils/logger.ts index 6c16b49..1f7af07 100644 --- a/src/utils/logger.ts +++ b/src/utils/logger.ts @@ -5,6 +5,8 @@ import { getRequestId } from "./request-context.js"; // that module imports this one (to log its own validation warnings/errors), // so importing config here would form a cycle — ESM leaves the not-yet- // initialized `config` export as undefined partway through that cycle, +// which crashed every request (and every test that imports anything +// touching this module) before config had finished evaluating. // which crashed every request (and every test, since buildApp() creates a // logger on every call) before config had finished evaluating. const nodeEnv = process.env.NODE_ENV ?? "development"; diff --git a/tests/unit/config/redis.test.ts b/tests/unit/config/redis.test.ts new file mode 100644 index 0000000..5b9bb09 --- /dev/null +++ b/tests/unit/config/redis.test.ts @@ -0,0 +1,132 @@ +import { describe, it, expect, vi, beforeEach, afterEach } from "vitest"; + +/** + * #607: config/redis.ts constructs a single ioredis client from + * config.REDIS_URL at import time (same memoize-on-import pattern as + * config/index.ts), so each case resets the module registry and re-imports + * with a fresh env/mock rather than relying on the already-imported client. + */ + +const mockRedisInstance = { + on: vi.fn(), + quit: vi.fn().mockResolvedValue("OK"), +}; + +const RedisConstructorMock = vi.fn(() => mockRedisInstance); + +vi.mock("ioredis", () => ({ + default: RedisConstructorMock, +})); + +vi.mock("../../../src/utils/logger.js", () => ({ + logger: { info: vi.fn(), error: vi.fn(), warn: vi.fn() }, +})); + +async function loadRedisConfig(env: Record = {}) { + vi.resetModules(); + RedisConstructorMock.mockClear(); + mockRedisInstance.on.mockClear(); + mockRedisInstance.quit.mockClear(); + + for (const [key, value] of Object.entries(env)) { + if (value === undefined) { + vi.stubEnv(key, ""); + delete process.env[key]; + } else { + vi.stubEnv(key, value); + } + } + + return import("../../../src/config/redis.js"); +} + +describe("config/redis.ts (#607)", () => { + beforeEach(() => { + vi.unstubAllEnvs(); + }); + + afterEach(() => { + vi.unstubAllEnvs(); + vi.resetModules(); + }); + + describe("client creation", () => { + it("constructs a single ioredis client from config.REDIS_URL", async () => { + await loadRedisConfig({ REDIS_URL: "redis://custom-host:6380" }); + + expect(RedisConstructorMock).toHaveBeenCalledOnce(); + expect(RedisConstructorMock).toHaveBeenCalledWith( + "redis://custom-host:6380", + expect.objectContaining({ maxRetriesPerRequest: 3 }) + ); + }); + + it("falls back to the default redis://localhost:6379 when REDIS_URL is unset", async () => { + await loadRedisConfig({ REDIS_URL: undefined }); + + expect(RedisConstructorMock).toHaveBeenCalledWith( + "redis://localhost:6379", + expect.anything() + ); + }); + + it("exports the constructed client as `redis`", async () => { + const { redis } = await loadRedisConfig(); + + expect(redis).toBe(mockRedisInstance); + }); + + it("registers error and connect event handlers on the client", async () => { + await loadRedisConfig(); + + const registeredEvents = mockRedisInstance.on.mock.calls.map((call) => call[0]); + expect(registeredEvents).toContain("error"); + expect(registeredEvents).toContain("connect"); + }); + }); + + describe("retryStrategy", () => { + it("backs off linearly, capped at 2000ms", async () => { + await loadRedisConfig(); + + const options = RedisConstructorMock.mock.calls[0]![1] as { + retryStrategy: (times: number) => number | null; + }; + + expect(options.retryStrategy(1)).toBe(200); + expect(options.retryStrategy(5)).toBe(1000); + // 8 * 200 = 1600 + expect(options.retryStrategy(8)).toBe(1600); + // 10 * 200 = 2000, exactly at the cap + expect(options.retryStrategy(10)).toBe(2000); + }); + + it("gives up (returns null) after more than 10 attempts", async () => { + await loadRedisConfig(); + + const options = RedisConstructorMock.mock.calls[0]![1] as { + retryStrategy: (times: number) => number | null; + }; + + expect(options.retryStrategy(10)).not.toBeNull(); + expect(options.retryStrategy(11)).toBeNull(); + }); + }); + + describe("closeRedis()", () => { + it("quits the underlying client", async () => { + const { closeRedis } = await loadRedisConfig(); + + await closeRedis(); + + expect(mockRedisInstance.quit).toHaveBeenCalledOnce(); + }); + + it("propagates an error from quit()", async () => { + const { closeRedis } = await loadRedisConfig(); + mockRedisInstance.quit.mockRejectedValueOnce(new Error("quit failed")); + + await expect(closeRedis()).rejects.toThrow("quit failed"); + }); + }); +}); diff --git a/tests/unit/jobs/cleanup-idempotency.test.ts b/tests/unit/jobs/cleanup-idempotency.test.ts new file mode 100644 index 0000000..92e81b1 --- /dev/null +++ b/tests/unit/jobs/cleanup-idempotency.test.ts @@ -0,0 +1,110 @@ +import { describe, it, expect, vi, beforeEach, afterEach } from "vitest"; + +/** + * #609: startIdempotencyCleanup/stopIdempotencyCleanup is a thin interval + * wrapper around middleware/idempotency.js's cleanupIdempotencyKeys(), which + * already has its own deletion-logic tests in + * tests/unit/services/idempotency.test.ts. This suite covers the job + * wrapper itself: that it schedules on an interval, can be stopped, and + * doesn't crash the process when the underlying cleanup rejects. + */ + +const mockCleanupIdempotencyKeys = vi.fn(); + +vi.mock("../../../src/middleware/idempotency.js", () => ({ + cleanupIdempotencyKeys: mockCleanupIdempotencyKeys, +})); + +vi.mock("../../../src/utils/logger.js", () => ({ + logger: { info: vi.fn(), error: vi.fn() }, +})); + +const { startIdempotencyCleanup, stopIdempotencyCleanup } = await import( + "../../../src/jobs/cleanup-idempotency.js" +); +const { logger } = await import("../../../src/utils/logger.js"); + +describe("cleanup-idempotency job (#609)", () => { + beforeEach(() => { + vi.useFakeTimers(); + vi.clearAllMocks(); + mockCleanupIdempotencyKeys.mockResolvedValue(0); + }); + + afterEach(() => { + stopIdempotencyCleanup(); + vi.useRealTimers(); + }); + + it("schedules cleanup on an hourly interval", async () => { + startIdempotencyCleanup(); + + expect(mockCleanupIdempotencyKeys).not.toHaveBeenCalled(); + + await vi.advanceTimersByTimeAsync(60 * 60 * 1000); + + expect(mockCleanupIdempotencyKeys).toHaveBeenCalledOnce(); + }); + + it("runs again on the next interval tick", async () => { + startIdempotencyCleanup(); + + await vi.advanceTimersByTimeAsync(60 * 60 * 1000); + await vi.advanceTimersByTimeAsync(60 * 60 * 1000); + + expect(mockCleanupIdempotencyKeys).toHaveBeenCalledTimes(2); + }); + + it("logs the deleted count when keys were actually deleted", async () => { + mockCleanupIdempotencyKeys.mockResolvedValue(5); + startIdempotencyCleanup(); + + await vi.advanceTimersByTimeAsync(60 * 60 * 1000); + + expect(logger.info).toHaveBeenCalledWith( + { deleted: 5 }, + "Cleaned up expired idempotency keys" + ); + }); + + it("does not log when nothing was deleted", async () => { + mockCleanupIdempotencyKeys.mockResolvedValue(0); + startIdempotencyCleanup(); + + await vi.advanceTimersByTimeAsync(60 * 60 * 1000); + + expect(logger.info).not.toHaveBeenCalled(); + }); + + it("logs and does not throw when cleanupIdempotencyKeys rejects", async () => { + mockCleanupIdempotencyKeys.mockRejectedValue(new Error("db unavailable")); + startIdempotencyCleanup(); + + await vi.advanceTimersByTimeAsync(60 * 60 * 1000); + + expect(logger.error).toHaveBeenCalledWith( + { err: expect.any(Error) }, + "Failed to clean up idempotency keys" + ); + }); + + it("stops scheduling further runs once stopped", async () => { + startIdempotencyCleanup(); + + await vi.advanceTimersByTimeAsync(60 * 60 * 1000); + expect(mockCleanupIdempotencyKeys).toHaveBeenCalledTimes(1); + + stopIdempotencyCleanup(); + + await vi.advanceTimersByTimeAsync(60 * 60 * 1000); + expect(mockCleanupIdempotencyKeys).toHaveBeenCalledTimes(1); + }); + + it("stopping before starting (or stopping twice) does not throw", () => { + expect(() => stopIdempotencyCleanup()).not.toThrow(); + + startIdempotencyCleanup(); + stopIdempotencyCleanup(); + expect(() => stopIdempotencyCleanup()).not.toThrow(); + }); +}); diff --git a/tests/unit/notifications/cleanup-notifications.test.ts b/tests/unit/jobs/cleanup-notifications.test.ts similarity index 85% rename from tests/unit/notifications/cleanup-notifications.test.ts rename to tests/unit/jobs/cleanup-notifications.test.ts index c87a98d..c7cc9c5 100644 --- a/tests/unit/notifications/cleanup-notifications.test.ts +++ b/tests/unit/jobs/cleanup-notifications.test.ts @@ -4,13 +4,14 @@ import { describe, it, expect, vi, beforeEach, afterEach } from "vitest"; const mockDeleteChain = { where: vi.fn(), + returning: vi.fn(), }; const mockDb = { delete: vi.fn(() => mockDeleteChain) }; vi.mock("../../../src/config/database.js", () => ({ db: mockDb })); vi.mock("../../../src/database/schema.js", () => ({ - notifications: { createdAt: "createdAt" }, + notifications: { createdAt: "createdAt", id: "id" }, })); vi.mock("../../../src/utils/logger.js", () => ({ logger: { info: vi.fn(), error: vi.fn() }, @@ -24,20 +25,22 @@ const { cleanupExpiredNotifications, startNotificationCleanup, stopNotificationC describe("cleanupExpiredNotifications()", () => { beforeEach(() => { vi.clearAllMocks(); + mockDeleteChain.where.mockReturnValue(mockDeleteChain); }); it("deletes notifications older than 30 days and returns the count", async () => { - mockDeleteChain.where.mockResolvedValue([{ id: "a" }, { id: "b" }]); + mockDeleteChain.returning.mockResolvedValue([{ id: "a" }, { id: "b" }]); const deleted = await cleanupExpiredNotifications(); expect(deleted).toBe(2); expect(mockDb.delete).toHaveBeenCalledOnce(); expect(mockDeleteChain.where).toHaveBeenCalledOnce(); + expect(mockDeleteChain.returning).toHaveBeenCalledOnce(); }); it("returns 0 when no notifications are older than 30 days", async () => { - mockDeleteChain.where.mockResolvedValue([]); + mockDeleteChain.returning.mockResolvedValue([]); const deleted = await cleanupExpiredNotifications(); @@ -45,7 +48,7 @@ describe("cleanupExpiredNotifications()", () => { }); it("passes a cutoff date that is approximately 30 days ago", async () => { - mockDeleteChain.where.mockResolvedValue([]); + mockDeleteChain.returning.mockResolvedValue([]); const before = Date.now(); await cleanupExpiredNotifications(); @@ -66,7 +69,7 @@ describe("cleanupExpiredNotifications()", () => { }); it("propagates database errors", async () => { - mockDeleteChain.where.mockRejectedValue(new Error("DB error")); + mockDeleteChain.returning.mockRejectedValue(new Error("DB error")); await expect(cleanupExpiredNotifications()).rejects.toThrow("DB error"); }); @@ -75,7 +78,8 @@ describe("cleanupExpiredNotifications()", () => { describe("startNotificationCleanup / stopNotificationCleanup", () => { beforeEach(() => { vi.useFakeTimers(); - mockDeleteChain.where.mockResolvedValue([]); + mockDeleteChain.where.mockReturnValue(mockDeleteChain); + mockDeleteChain.returning.mockResolvedValue([]); }); afterEach(() => { diff --git a/tests/unit/jobs/process-webhook-retries.test.ts b/tests/unit/jobs/process-webhook-retries.test.ts new file mode 100644 index 0000000..cfc6496 --- /dev/null +++ b/tests/unit/jobs/process-webhook-retries.test.ts @@ -0,0 +1,126 @@ +import { describe, it, expect, vi, beforeEach, afterEach } from "vitest"; + +/** + * #611: startWebhookRetryProcessor/stopWebhookRetryProcessor is a thin + * interval wrapper around webhook-dispatcher.js's processWebhookRetries(), + * which does the actual ready-for-retry query, dispatch, and + * success/failure bookkeeping against the database. This suite covers the + * job wrapper itself: that it schedules on an interval, can be stopped + * (including the "stop mid-flight, a tick already queued must not run" + * case via the generation counter), and doesn't crash the process when the + * underlying retry pass rejects. + */ + +const mockProcessWebhookRetries = vi.fn(); + +vi.mock("../../../src/services/webhook-dispatcher.js", () => ({ + processWebhookRetries: mockProcessWebhookRetries, +})); + +vi.mock("../../../src/utils/logger.js", () => ({ + logger: { info: vi.fn(), error: vi.fn(), warn: vi.fn() }, +})); + +const { startWebhookRetryProcessor, stopWebhookRetryProcessor } = await import( + "../../../src/jobs/process-webhook-retries.js" +); +const { logger } = await import("../../../src/utils/logger.js"); + +const POLL_INTERVAL_MS = 60_000; + +describe("process-webhook-retries job (#611)", () => { + beforeEach(() => { + vi.useFakeTimers(); + vi.clearAllMocks(); + mockProcessWebhookRetries.mockResolvedValue(undefined); + }); + + afterEach(() => { + stopWebhookRetryProcessor(); + vi.useRealTimers(); + }); + + it("runs an immediate pass on start, before the first interval tick", async () => { + await startWebhookRetryProcessor(); + + expect(mockProcessWebhookRetries).toHaveBeenCalledOnce(); + }); + + it("schedules the next pass on a 1 minute interval", async () => { + await startWebhookRetryProcessor(); + mockProcessWebhookRetries.mockClear(); + + await vi.advanceTimersByTimeAsync(POLL_INTERVAL_MS); + + expect(mockProcessWebhookRetries).toHaveBeenCalledOnce(); + }); + + it("is a no-op if already running", async () => { + await startWebhookRetryProcessor(); + mockProcessWebhookRetries.mockClear(); + + await startWebhookRetryProcessor(); + + expect(mockProcessWebhookRetries).not.toHaveBeenCalled(); + }); + + it("logs and does not throw when processWebhookRetries rejects", async () => { + mockProcessWebhookRetries.mockRejectedValueOnce(new Error("db unavailable")); + + await expect(startWebhookRetryProcessor()).resolves.not.toThrow(); + expect(logger.error).toHaveBeenCalledWith( + { err: expect.any(Error) }, + "Webhook retry processor tick failed" + ); + }); + + it("keeps polling on the interval even after a tick's pass rejected", async () => { + mockProcessWebhookRetries.mockRejectedValueOnce(new Error("transient")); + await startWebhookRetryProcessor(); + mockProcessWebhookRetries.mockClear(); + mockProcessWebhookRetries.mockResolvedValue(undefined); + + await vi.advanceTimersByTimeAsync(POLL_INTERVAL_MS); + + expect(mockProcessWebhookRetries).toHaveBeenCalledOnce(); + }); + + it("stops scheduling further passes once stopped", async () => { + await startWebhookRetryProcessor(); + mockProcessWebhookRetries.mockClear(); + + stopWebhookRetryProcessor(); + + await vi.advanceTimersByTimeAsync(POLL_INTERVAL_MS * 2); + + expect(mockProcessWebhookRetries).not.toHaveBeenCalled(); + }); + + it("allows starting again after being stopped", async () => { + await startWebhookRetryProcessor(); + stopWebhookRetryProcessor(); + mockProcessWebhookRetries.mockClear(); + + await startWebhookRetryProcessor(); + + expect(mockProcessWebhookRetries).toHaveBeenCalledOnce(); + }); + + it("a tick already scheduled before stop() does not run after stop()", async () => { + await startWebhookRetryProcessor(); + mockProcessWebhookRetries.mockClear(); + + // Advance partway into the interval so a timer is pending, then stop. + await vi.advanceTimersByTimeAsync(POLL_INTERVAL_MS - 1); + stopWebhookRetryProcessor(); + await vi.advanceTimersByTimeAsync(10_000); + + expect(mockProcessWebhookRetries).not.toHaveBeenCalled(); + }); + + it("stopping before starting (or stopping twice) does not throw", () => { + expect(() => stopWebhookRetryProcessor()).not.toThrow(); + stopWebhookRetryProcessor(); + expect(() => stopWebhookRetryProcessor()).not.toThrow(); + }); +});