feat(server): /metrics 可观测与日志上下文（F22）

- 新增 Prometheus 指标端点 /metrics（HTTP + DB + 作业统计）
- request.log 绑定 requestId/actorId，避免日志难追踪
- cron/pg-boss 作业增加 metrics 计数（runs/processed）
- 更新 env/runbook/README 与 v3 CSV 状态推进

server/src/app.js

@@ -30,6 +30,7 @@ const approvalRulesRoutes = require("./routes/approvalRules");
 const notificationsRoutes = require("./routes/notifications");
 const exportsRoutes = require("./routes/exports");
 const { startJobs } = require("./jobs/jobSystem");
+const { initMetrics } = require("./observability");
 const { AppError } = require("./utils/AppError");
 
 async function buildApp() {
@@ -112,6 +113,9 @@ async function buildApp() {
 
   app.addHook("onRequest", async (request, reply) => {
     reply.header("x-request-id", request.id);
+    if (request.log && typeof request.log.child === "function") {
+      request.log = request.log.child({ requestId: request.id });
+    }
   });
 
   app.setNotFoundHandler(async (request, reply) => {
@@ -189,6 +193,23 @@ async function buildApp() {
     }
   });
 
+  if (config.metricsEnabled) {
+    initMetrics(app);
+    app.get("/metrics", async (request, reply) => {
+      try {
+        await app.prisma.$queryRaw`SELECT 1`;
+        app.metrics.dbReady.set(1);
+      } catch {
+        app.metrics.dbReady.set(0);
+      }
+
+      const payload = await app.metrics.registry.metrics();
+      reply.header("content-type", app.metrics.registry.contentType);
+      return reply.send(payload);
+    });
+    app.log.info("Metrics endpoint enabled at /metrics");
+  }
+
   await app.register(authRoutes, { prefix: "/api/auth" });
   await app.register(meRoutes, { prefix: "/api" });
   await app.register(reimbursementRoutes, { prefix: "/api" });

server/src/config.js

@@ -22,6 +22,8 @@ function getConfig() {
     port: Number(process.env.PORT ?? 3000),
     host: process.env.HOST ?? "0.0.0.0",
 
+    metricsEnabled: process.env.METRICS_ENABLED !== "false",
+
     appOrigin: process.env.APP_ORIGIN ?? "",
     jwtSecret: requiredEnv("JWT_SECRET"),
 

server/src/jobs/delegationRevokeJob.js

@@ -92,9 +92,29 @@ function startDelegationRevokeJob(fastify) {
 
     running = true;
     try {
-      await revokeExpiredDelegations(fastify.prisma, fastify.log);
+      const revoked = await revokeExpiredDelegations(fastify.prisma, fastify.log);
+      fastify.metrics?.jobRunsTotal?.inc?.({
+        job: "delegation.revoke-expired",
+        driver: "cron",
+        outcome: "success",
+      });
+      if (revoked > 0) {
+        fastify.metrics?.jobProcessedTotal?.inc?.(
+          {
+            job: "delegation.revoke-expired",
+            driver: "cron",
+            kind: "revoked",
+          },
+          revoked,
+        );
+      }
     } catch (error) {
       fastify.log.error({ err: error }, "Delegation revoke job failed");
+      fastify.metrics?.jobRunsTotal?.inc?.({
+        job: "delegation.revoke-expired",
+        driver: "cron",
+        outcome: "failure",
+      });
     } finally {
       running = false;
     }

server/src/jobs/invoiceArchiveJob.js

@@ -76,12 +76,32 @@ function startInvoiceArchiveJob(fastify) {
 
     running = true;
     try {
-      await archiveUnusedInvoices(fastify.prisma, fastify.log, {
+      const archived = await archiveUnusedInvoices(fastify.prisma, fastify.log, {
         batchSize: fastify.config.invoiceArchiveBatchSize,
         unusedDays: fastify.config.invoiceArchiveUnusedDays,
       });
+      fastify.metrics?.jobRunsTotal?.inc?.({
+        job: "invoice.archive-unused",
+        driver: "cron",
+        outcome: "success",
+      });
+      if (archived > 0) {
+        fastify.metrics?.jobProcessedTotal?.inc?.(
+          {
+            job: "invoice.archive-unused",
+            driver: "cron",
+            kind: "archived",
+          },
+          archived,
+        );
+      }
     } catch (error) {
       fastify.log.error({ err: error }, "Invoice archive job failed");
+      fastify.metrics?.jobRunsTotal?.inc?.({
+        job: "invoice.archive-unused",
+        driver: "cron",
+        outcome: "failure",
+      });
     } finally {
       running = false;
     }
@@ -107,4 +127,3 @@ module.exports = {
   archiveUnusedInvoices,
   startInvoiceArchiveJob,
 };
-

server/src/jobs/ocrJob.js

@@ -301,6 +301,29 @@ function startOcrJob(fastify) {
     running = true;
     try {
       const result = await runOcrOnce(fastify.prisma, fastify.config, fastify.log, workerId);
+      fastify.metrics?.jobRunsTotal?.inc?.({
+        job: "ocr.tick",
+        driver: "cron",
+        outcome: "success",
+      });
+      if (result.available > 0) {
+        fastify.metrics?.jobProcessedTotal?.inc?.(
+          { job: "ocr.tick", driver: "cron", kind: "available" },
+          result.available,
+        );
+      }
+      if (result.duplicate > 0) {
+        fastify.metrics?.jobProcessedTotal?.inc?.(
+          { job: "ocr.tick", driver: "cron", kind: "duplicate" },
+          result.duplicate,
+        );
+      }
+      if (result.failed > 0) {
+        fastify.metrics?.jobProcessedTotal?.inc?.(
+          { job: "ocr.tick", driver: "cron", kind: "failed" },
+          result.failed,
+        );
+      }
       if (result.claimed > 0) {
         fastify.log.info(
           {
@@ -312,6 +335,11 @@ function startOcrJob(fastify) {
       }
     } catch (error) {
       fastify.log.error({ err: error }, "OCR job tick failed");
+      fastify.metrics?.jobRunsTotal?.inc?.({
+        job: "ocr.tick",
+        driver: "cron",
+        outcome: "failure",
+      });
     } finally {
       running = false;
     }

server/src/jobs/pgBossJobs.js

@@ -38,26 +38,64 @@ async function startPgBossJobs(fastify) {
 
   await boss.work(JOB_DELEGATION_REVOKE, { batchSize: 1 }, async (jobs) => {
     const job = jobs?.[0];
-    const revoked = await revokeExpiredDelegations(fastify.prisma, fastify.log);
-    if (revoked > 0) {
-      fastify.log.info(
-        { jobId: job?.id, revoked },
-        "pg-boss delegation revoke tick processed",
-      );
+    try {
+      const revoked = await revokeExpiredDelegations(fastify.prisma, fastify.log);
+      fastify.metrics?.jobRunsTotal?.inc?.({
+        job: JOB_DELEGATION_REVOKE,
+        driver: "pgboss",
+        outcome: "success",
+      });
+      if (revoked > 0) {
+        fastify.metrics?.jobProcessedTotal?.inc?.(
+          { job: JOB_DELEGATION_REVOKE, driver: "pgboss", kind: "revoked" },
+          revoked,
+        );
+        fastify.log.info(
+          { jobId: job?.id, revoked },
+          "pg-boss delegation revoke tick processed",
+        );
+      }
+    } catch (error) {
+      fastify.metrics?.jobRunsTotal?.inc?.({
+        job: JOB_DELEGATION_REVOKE,
+        driver: "pgboss",
+        outcome: "failure",
+      });
+      fastify.log.error({ err: error, jobId: job?.id }, "pg-boss delegation revoke tick failed");
+      throw error;
     }
   });
 
   await boss.work(JOB_INVOICE_ARCHIVE, { batchSize: 1 }, async (jobs) => {
     const job = jobs?.[0];
-    const archived = await archiveUnusedInvoices(fastify.prisma, fastify.log, {
-      batchSize: fastify.config.invoiceArchiveBatchSize,
-      unusedDays: fastify.config.invoiceArchiveUnusedDays,
-    });
-    if (archived > 0) {
-      fastify.log.info(
-        { jobId: job?.id, archived, unusedDays: fastify.config.invoiceArchiveUnusedDays },
-        "pg-boss invoice archive tick processed",
-      );
+    try {
+      const archived = await archiveUnusedInvoices(fastify.prisma, fastify.log, {
+        batchSize: fastify.config.invoiceArchiveBatchSize,
+        unusedDays: fastify.config.invoiceArchiveUnusedDays,
+      });
+      fastify.metrics?.jobRunsTotal?.inc?.({
+        job: JOB_INVOICE_ARCHIVE,
+        driver: "pgboss",
+        outcome: "success",
+      });
+      if (archived > 0) {
+        fastify.metrics?.jobProcessedTotal?.inc?.(
+          { job: JOB_INVOICE_ARCHIVE, driver: "pgboss", kind: "archived" },
+          archived,
+        );
+        fastify.log.info(
+          { jobId: job?.id, archived, unusedDays: fastify.config.invoiceArchiveUnusedDays },
+          "pg-boss invoice archive tick processed",
+        );
+      }
+    } catch (error) {
+      fastify.metrics?.jobRunsTotal?.inc?.({
+        job: JOB_INVOICE_ARCHIVE,
+        driver: "pgboss",
+        outcome: "failure",
+      });
+      fastify.log.error({ err: error, jobId: job?.id }, "pg-boss invoice archive tick failed");
+      throw error;
     }
   });
 
@@ -68,12 +106,46 @@ async function startPgBossJobs(fastify) {
 
     const job = jobs?.[0];
     const workerId = `pgboss:ocr:${process.pid}`;
-    const stats = await runOcrOnce(fastify.prisma, fastify.config, fastify.log, workerId);
-    if (stats.claimed > 0) {
-      fastify.log.info(
-        { jobId: job?.id, workerId, ...stats },
-        "pg-boss OCR tick processed",
-      );
+    try {
+      const stats = await runOcrOnce(fastify.prisma, fastify.config, fastify.log, workerId);
+      fastify.metrics?.jobRunsTotal?.inc?.({
+        job: JOB_OCR_TICK,
+        driver: "pgboss",
+        outcome: "success",
+      });
+      if (stats.available > 0) {
+        fastify.metrics?.jobProcessedTotal?.inc?.(
+          { job: JOB_OCR_TICK, driver: "pgboss", kind: "available" },
+          stats.available,
+        );
+      }
+      if (stats.duplicate > 0) {
+        fastify.metrics?.jobProcessedTotal?.inc?.(
+          { job: JOB_OCR_TICK, driver: "pgboss", kind: "duplicate" },
+          stats.duplicate,
+        );
+      }
+      if (stats.failed > 0) {
+        fastify.metrics?.jobProcessedTotal?.inc?.(
+          { job: JOB_OCR_TICK, driver: "pgboss", kind: "failed" },
+          stats.failed,
+        );
+      }
+
+      if (stats.claimed > 0) {
+        fastify.log.info(
+          { jobId: job?.id, workerId, ...stats },
+          "pg-boss OCR tick processed",
+        );
+      }
+    } catch (error) {
+      fastify.metrics?.jobRunsTotal?.inc?.({
+        job: JOB_OCR_TICK,
+        driver: "pgboss",
+        outcome: "failure",
+      });
+      fastify.log.error({ err: error, jobId: job?.id }, "pg-boss OCR tick failed");
+      throw error;
     }
   });
 

server/src/observability/index.js

@@ -0,0 +1,6 @@
+const { initMetrics } = require("./metrics");
+
+module.exports = {
+  initMetrics,
+};
+

server/src/observability/metrics.js

@@ -0,0 +1,105 @@
+const client = require("prom-client");
+
+function resolveRouteLabel(request) {
+  const url = request?.routeOptions?.url;
+  if (typeof url === "string" && url.trim()) {
+    return url;
+  }
+
+  const routerPath = request?.routerPath;
+  if (typeof routerPath === "string" && routerPath.trim()) {
+    return routerPath;
+  }
+
+  const rawUrl = request?.raw?.url;
+  if (typeof rawUrl === "string" && rawUrl.trim()) {
+    return rawUrl.split("?")[0];
+  }
+
+  return "unknown";
+}
+
+function initMetrics(app) {
+  const registry = new client.Registry();
+
+  client.collectDefaultMetrics({
+    register: registry,
+  });
+
+  const httpRequestsTotal = new client.Counter({
+    name: "hyb_http_requests_total",
+    help: "Total number of HTTP requests",
+    labelNames: ["method", "route", "status_code"],
+    registers: [registry],
+  });
+
+  const httpRequestDurationSeconds = new client.Histogram({
+    name: "hyb_http_request_duration_seconds",
+    help: "HTTP request duration in seconds",
+    labelNames: ["method", "route", "status_code"],
+    buckets: [0.005, 0.01, 0.025, 0.05, 0.1, 0.25, 0.5, 1, 2.5, 5, 10],
+    registers: [registry],
+  });
+
+  const jobRunsTotal = new client.Counter({
+    name: "hyb_job_runs_total",
+    help: "Total number of background job runs",
+    labelNames: ["job", "driver", "outcome"],
+    registers: [registry],
+  });
+
+  const jobProcessedTotal = new client.Counter({
+    name: "hyb_job_processed_total",
+    help: "Total number of processed items per job",
+    labelNames: ["job", "driver", "kind"],
+    registers: [registry],
+  });
+
+  const dbReady = new client.Gauge({
+    name: "hyb_db_ready",
+    help: "Database readiness probe result (1=ready, 0=not ready)",
+    registers: [registry],
+  });
+
+  app.decorate("metrics", {
+    registry,
+    httpRequestsTotal,
+    httpRequestDurationSeconds,
+    jobRunsTotal,
+    jobProcessedTotal,
+    dbReady,
+  });
+
+  app.decorateRequest("metricsStart", null);
+
+  app.addHook("onRequest", async (request) => {
+    request.metricsStart = process.hrtime.bigint();
+  });
+
+  app.addHook("onResponse", async (request, reply) => {
+    const start = request.metricsStart;
+    if (typeof start !== "bigint") {
+      return;
+    }
+
+    const end = process.hrtime.bigint();
+    const durationSeconds = Number(end - start) / 1e9;
+
+    const method = request.method;
+    const route = resolveRouteLabel(request);
+    const statusCode = String(reply.statusCode);
+
+    httpRequestsTotal.inc({ method, route, status_code: statusCode });
+    httpRequestDurationSeconds.observe(
+      { method, route, status_code: statusCode },
+      durationSeconds,
+    );
+  });
+
+  return app.metrics;
+}
+
+module.exports = {
+  initMetrics,
+};
+

server/src/plugins/auth.js

@@ -99,6 +99,10 @@ async function authPlugin(fastify) {
       roleCodes,
       permissionCodes,
     };
+
+    if (request.log && typeof request.log.child === "function") {
+      request.log = request.log.child({ actorId: employee.id });
+    }
   });
 }