feat(cron): logger + per-step debug instrumentation

src/app/api/cron/tripwire-asn-update/route.ts

@@ -6,8 +6,10 @@
 // whatever ASN db is currently in blob.
 
 import { NextResponse, type NextRequest } from "next/server"
-import { syncGeoipToBlob } from "@/lib/tripwire/sync-geoip"
-import { checkCronAuth, makeCronLogger } from "@/lib/cron-helpers"
+import { revalidateTag } from "next/cache"
+import { syncGeoipToBlob, ASN_BLOB_TAG } from "@/lib/tripwire/sync-geoip"
+import { checkCronAuth } from "@/lib/cron-helpers"
+import { log } from "@/lib/log"
 
 export const runtime = "nodejs"
 export const dynamic = "force-dynamic"
@@ -18,11 +20,14 @@ export async function GET(req: NextRequest): Promise<NextResponse> {
   if (authError) return authError
 
   const startedAt = Date.now()
-  const log = makeCronLogger("cron.tripwire_asn_update", startedAt)
+  const cronLog = log.child({ event: "cron.tripwire_asn_update" })
 
-  log({ step: "start" })
+  cronLog.info({ step: "start" })
   const result = await syncGeoipToBlob()
-  log({ step: "done", ...result })
+  // Invalidate the build-stats fetch cache so the next build-stats run
+  // picks up the freshly-uploaded mmdb instead of serving the stale one.
+  revalidateTag(ASN_BLOB_TAG, "max")
+  cronLog.info({ step: "done", elapsed_ms: Date.now() - startedAt, ...result })
 
   return NextResponse.json({
     ok: true,

src/app/api/cron/tripwire-build-stats/route.ts

@@ -8,7 +8,9 @@
 import { NextResponse, type NextRequest } from "next/server"
 import { revalidateTag } from "next/cache"
 import { buildAggregates, publishAggregates } from "@/lib/tripwire/stats"
-import { checkCronAuth, makeCronLogger } from "@/lib/cron-helpers"
+import { STATS_BLOB_TAG } from "@/lib/tripwire/aggregate-shape"
+import { checkCronAuth } from "@/lib/cron-helpers"
+import { log } from "@/lib/log"
 
 export const runtime = "nodejs"
 export const dynamic = "force-dynamic"
@@ -19,21 +21,22 @@ export async function GET(req: NextRequest): Promise<NextResponse> {
   if (authError) return authError
 
   const startedAt = Date.now()
-  const log = makeCronLogger("cron.tripwire_build_stats", startedAt)
+  const cronLog = log.child({ event: "cron.tripwire_build_stats" })
 
-  log({ step: "build_start" })
+  cronLog.info({ step: "build_start" })
   const aggregates = await buildAggregates()
-  log({
+  cronLog.info({
     step: "build_done",
+    elapsed_ms: Date.now() - startedAt,
     total: aggregates.lifetime.totalEvents,
     ips: aggregates.lifetime.distinctIps,
     asns: aggregates.lifetime.distinctAsns,
   })
 
-  log({ step: "publish_start" })
+  cronLog.info({ step: "publish_start" })
   await publishAggregates(aggregates)
-  revalidateTag("tripwire-aggregates", "max")
-  log({ step: "publish_done" })
+  revalidateTag(STATS_BLOB_TAG, "max")
+  cronLog.info({ step: "publish_done", elapsed_ms: Date.now() - startedAt })
 
   return NextResponse.json({
     ok: true,

src/app/api/cron/tripwire-ingest/route.ts

@@ -7,7 +7,8 @@
 
 import { NextResponse, type NextRequest } from "next/server"
 import { ingestNewEvents } from "@/lib/tripwire/ingest"
-import { checkCronAuth, makeCronLogger } from "@/lib/cron-helpers"
+import { checkCronAuth } from "@/lib/cron-helpers"
+import { log } from "@/lib/log"
 
 export const runtime = "nodejs"
 export const dynamic = "force-dynamic"
@@ -20,14 +21,14 @@ export async function GET(req: NextRequest): Promise<NextResponse> {
   if (authError) return authError
 
   const startedAt = Date.now()
-  const log = makeCronLogger("cron.tripwire_ingest", startedAt)
+  const cronLog = log.child({ event: "cron.tripwire_ingest" })
 
-  log({ step: "start" })
+  cronLog.info({ step: "start" })
   const result = await ingestNewEvents({
-    onProgress: log,
+    onProgress: (e) => cronLog.info(e),
     deadlineMs: startedAt + INGEST_DEADLINE_MS,
   })
-  log({ step: "done", ...result })
+  cronLog.info({ step: "done", elapsed_ms: Date.now() - startedAt, ...result })
 
   return NextResponse.json({
     ok: true,

src/lib/cron-helpers.ts

@@ -1,32 +1,20 @@
 // src/lib/cron-helpers.ts
 //
 // Shared boilerplate for the tripwire cron route handlers. Each route
-// does ONE thing — this just removes the repeated auth check and the
-// structured-log scaffolding from those handlers.
+// does ONE thing — this just removes the repeated auth check. Logging
+// goes through the singleton in src/lib/log.ts.
 
 import { NextResponse, type NextRequest } from "next/server"
+import { log } from "@/lib/log"
 
 export function checkCronAuth(req: NextRequest): NextResponse | null {
   const secret = process.env.CRON_SECRET
   if (!secret) {
-    console.error("[cron] CRON_SECRET not configured")
+    log.error({ event: "cron.auth", reason: "no_secret" })
     return NextResponse.json({ ok: false, error: "not_configured" }, { status: 500 })
   }
   if (req.headers.get("authorization") !== `Bearer ${secret}`) {
     return NextResponse.json({ ok: false, error: "unauthorized" }, { status: 401 })
   }
   return null
 }
-
-export type CronLogger = (fields: Record<string, unknown>) => void
-
-export function makeCronLogger(eventName: string, startedAt: number): CronLogger {
-  return (fields) =>
-    console.log(
-      JSON.stringify({
-        event: eventName,
-        elapsed_ms: Date.now() - startedAt,
-        ...fields,
-      }),
-    )
-}

src/lib/log.test.ts

@@ -0,0 +1,102 @@
+// src/lib/log.test.ts
+import { describe, test, expect, mock } from "bun:test"
+import { consoleLogger } from "./log"
+
+function captureConsole(): { lines: unknown[][]; restore: () => void } {
+  const lines: unknown[][] = []
+  const original = console.log
+  const spy = mock((...args: unknown[]) => {
+    lines.push(args)
+  })
+  console.log = spy
+  return { lines, restore: () => { console.log = original } }
+}
+
+describe("consoleLogger", () => {
+  test("emits one JSON line per call with time + level + fields", () => {
+    const { lines, restore } = captureConsole()
+    try {
+      const log = consoleLogger({ level: "debug" })
+      log.info({ event: "boot", step: "ok" })
+      expect(lines).toHaveLength(1)
+      expect(lines[0]).toHaveLength(1)
+      const record = JSON.parse(lines[0][0] as string)
+      expect(record.level).toBe("info")
+      expect(record.event).toBe("boot")
+      expect(record.step).toBe("ok")
+      expect(typeof record.time).toBe("string")
+      expect(Number.isNaN(Date.parse(record.time))).toBe(false)
+    } finally {
+      restore()
+    }
+  })
+
+  test("filters records below the threshold", () => {
+    const { lines, restore } = captureConsole()
+    try {
+      const log = consoleLogger({ level: "warn" })
+      log.debug({ x: 1 })
+      log.info({ x: 2 })
+      log.warn({ x: 3 })
+      log.error({ x: 4 })
+      const levels = lines.map((l) => JSON.parse(l[0] as string).level)
+      expect(levels).toEqual(["warn", "error"])
+    } finally {
+      restore()
+    }
+  })
+
+  test("silent mutes everything", () => {
+    const { lines, restore } = captureConsole()
+    try {
+      const log = consoleLogger({ level: "silent" })
+      log.error({ x: 1 })
+      expect(lines).toHaveLength(0)
+    } finally {
+      restore()
+    }
+  })
+
+  test("child merges bindings; later bindings win on key collision", () => {
+    const { lines, restore } = captureConsole()
+    try {
+      const root = consoleLogger({ level: "debug", bindings: { service: "tripwire", env: "test" } })
+      const child = root.child({ event: "cron.ingest", env: "prod" })
+      child.info({ step: "start" })
+      const record = JSON.parse(lines[0][0] as string)
+      expect(record.service).toBe("tripwire")
+      expect(record.event).toBe("cron.ingest")
+      expect(record.env).toBe("prod")
+      expect(record.step).toBe("start")
+    } finally {
+      restore()
+    }
+  })
+
+  test("call-site fields override parent + child bindings", () => {
+    const { lines, restore } = captureConsole()
+    try {
+      const log = consoleLogger({ level: "debug", bindings: { event: "from-root" } }).child({
+        event: "from-child",
+      })
+      log.info({ event: "from-call" })
+      const record = JSON.parse(lines[0][0] as string)
+      expect(record.event).toBe("from-call")
+    } finally {
+      restore()
+    }
+  })
+
+  test("child inherits the parent level", () => {
+    const { lines, restore } = captureConsole()
+    try {
+      const log = consoleLogger({ level: "warn" }).child({ scope: "x" })
+      log.info({ skip: true })
+      log.warn({ keep: true })
+      expect(lines).toHaveLength(1)
+      expect(JSON.parse(lines[0][0] as string).keep).toBe(true)
+    } finally {
+      restore()
+    }
+  })
+})

src/lib/log.ts

@@ -0,0 +1,83 @@
+// src/lib/log.ts
+//
+// Tiny structured logger. One `Logger` interface, one provider that
+// writes JSON lines via console.log. Vercel auto-parses JSON in stdout
+// into searchable fields in runtime logs and forwards the same to log
+// drains, so this is the idiomatic shape for this platform.
+//
+// Why a wrapper at all instead of raw `console.log(JSON.stringify(...))`:
+// the interface gives us levels, bound context (`child`), and a single
+// place to swap implementations later (an HTTP drain, a no-op for tests,
+// a prefixed logger for CLI scripts) without touching call sites.
+//
+// What this is not: it has no transports, no formatters, no redaction,
+// no async I/O. If we ever need any of those, they're additive.
+
+export type Level = "debug" | "info" | "warn" | "error" | "silent"
+
+export interface Logger {
+  debug(fields: Record<string, unknown>): void
+  info(fields: Record<string, unknown>): void
+  warn(fields: Record<string, unknown>): void
+  error(fields: Record<string, unknown>): void
+  child(bindings: Record<string, unknown>): Logger
+}
+
+const RANK: Record<Exclude<Level, "silent">, number> = {
+  debug: 10,
+  info: 20,
+  warn: 30,
+  error: 40,
+}
+
+interface ConsoleLoggerOptions {
+  level?: Level
+  bindings?: Record<string, unknown>
+}
+
+export function consoleLogger(opts: ConsoleLoggerOptions = {}): Logger {
+  const level = opts.level ?? "info"
+  const bindings = opts.bindings ?? {}
+  const threshold = level === "silent" ? Number.POSITIVE_INFINITY : RANK[level]
+
+  function emit(name: Exclude<Level, "silent">, fields: Record<string, unknown>): void {
+    if (RANK[name] < threshold) return
+    console.log(
+      JSON.stringify({
+        time: new Date().toISOString(),
+        level: name,
+        ...bindings,
+        ...fields,
+      }),
+    )
+  }
+
+  return {
+    debug: (f) => emit("debug", f),
+    info: (f) => emit("info", f),
+    warn: (f) => emit("warn", f),
+    error: (f) => emit("error", f),
+    child: (b) => consoleLogger({ level, bindings: { ...bindings, ...b } }),
+  }
+}
+
+function readLevel(): Level {
+  // Default: quiet on production, debug everywhere else (preview, dev).
+  // Crons run identical code in every environment, so a preview deploy
+  // gets the per-step trace without needing a manual env var. LOG_LEVEL
+  // overrides if set explicitly.
+  const fallback = process.env.VERCEL_ENV === "production" ? "info" : "debug"
+  const raw = (process.env.LOG_LEVEL ?? fallback).toLowerCase()
+  if (
+    raw === "debug" ||
+    raw === "info" ||
+    raw === "warn" ||
+    raw === "error" ||
+    raw === "silent"
+  ) {
+    return raw
+  }
+  return "info"
+}
+
+export const log: Logger = consoleLogger({ level: readLevel() })

src/lib/tripwire/aggregate-shape.ts

@@ -8,6 +8,10 @@
 // before this split.
 
 export const STATS_BLOB_KEY = "stats/tripwire-aggregates.json"
+// Next.js fetch-cache tag. The page-side loader fetches with this tag;
+// the build-stats cron calls revalidateTag after a successful publish,
+// so warm pages flip to fresh aggregates without polling on a TTL.
+export const STATS_BLOB_TAG = "tripwire-aggregates"
 export const DEFAULT_TOP_PATHS = 100
 
 export interface Aggregates {