feat: Phase 5 — pino structured logger, request logging, tRPC timing middleware

server/_core/trpc.ts

@@ -1,6 +1,9 @@
 import { initTRPC, TRPCError } from "@trpc/server";
 import type { TrpcContext } from "./context.js";
 import { isSubscriptionActive } from "../db.js";
+import { childLogger } from "./logger.js";
+
+const trpcLog = childLogger("trpc");
 
 const t = initTRPC.context<TrpcContext>().create({
   errorFormatter({ shape }) {
@@ -10,7 +13,31 @@ const t = initTRPC.context<TrpcContext>().create({
 
 export const router = t.router;
 export const middleware = t.middleware;
-export const publicProcedure = t.procedure;
+
+// Timing middleware: logs every procedure call with its duration. Errors are
+// re-thrown so the existing error handlers in the express adapter still fire.
+const timing = t.middleware(async ({ path, type, next, ctx }) => {
+  const start = Date.now();
+  try {
+    const result = await next();
+    const durationMs = Date.now() - start;
+    if (result.ok) {
+      trpcLog.debug({ path, type, durationMs, userId: ctx.user?.id ?? null }, "procedure ok");
+    } else {
+      trpcLog.warn(
+        { path, type, durationMs, userId: ctx.user?.id ?? null, code: result.error.code },
+        "procedure error"
+      );
+    }
+    return result;
+  } catch (err) {
+    const durationMs = Date.now() - start;
+    trpcLog.error({ err, path, type, durationMs, userId: ctx.user?.id ?? null }, "procedure threw");
+    throw err;
+  }
+});
+
+export const publicProcedure = t.procedure.use(timing);
 
 const isAuthed = t.middleware(({ ctx, next }) => {
   if (!ctx.user) {