Log errors for very slow queries

Author: matt-aitken

apps/webapp/app/db.server.ts

@@ -15,6 +15,7 @@ import { isValidDatabaseUrl } from "./utils/db";
 import { singleton } from "./utils/singleton";
 import { startActiveSpan } from "./v3/tracer.server";
 import { Span } from "@opentelemetry/api";
+import { queryPerformanceMonitor } from "./utils/queryPerformanceMonitor.server";
 
 export type {
   PrismaTransactionClient,
@@ -153,13 +154,19 @@ function getClient() {
             },
           ]
         : []) satisfies Prisma.LogDefinition[]),
-      // verbose
-      ...((process.env.VERBOSE_PRISMA_LOGS === "1"
+      // Query performance monitoring
+      ...((process.env.VERBOSE_PRISMA_LOGS === "1" ||
+      process.env.VERY_SLOW_QUERY_THRESHOLD_MS !== undefined
         ? [
             {
               emit: "event",
               level: "query",
             },
+          ]
+        : []) satisfies Prisma.LogDefinition[]),
+      // verbose
+      ...((process.env.VERBOSE_PRISMA_LOGS === "1"
+        ? [
             {
               emit: "stdout",
               level: "query",
@@ -206,6 +213,11 @@ function getClient() {
     });
   }
 
+  // Add query performance monitoring
+  client.$on("query", (log) => {
+    queryPerformanceMonitor.onQuery("writer", log);
+  });
+
   // connect eagerly
   client.$connect();
 
@@ -265,13 +277,19 @@ function getReplicaClient() {
             },
           ]
         : []) satisfies Prisma.LogDefinition[]),
-      // verbose
-      ...((process.env.VERBOSE_PRISMA_LOGS === "1"
+      // Query performance monitoring
+      ...((process.env.VERBOSE_PRISMA_LOGS === "1" ||
+      process.env.VERY_SLOW_QUERY_THRESHOLD_MS !== undefined
         ? [
             {
               emit: "event",
               level: "query",
             },
+          ]
+        : []) satisfies Prisma.LogDefinition[]),
+      // verbose
+      ...((process.env.VERBOSE_PRISMA_LOGS === "1"
+        ? [
             {
               emit: "stdout",
               level: "query",
@@ -317,6 +335,11 @@ function getReplicaClient() {
     });
   }
 
+  // Add query performance monitoring for replica client
+  replicaClient.$on("query", (log) => {
+    queryPerformanceMonitor.onQuery("replica", log);
+  });
+
   // connect eagerly
   replicaClient.$connect();
 

apps/webapp/app/env.server.ts

@@ -1080,6 +1080,8 @@ const EnvironmentSchema = z.object({
   AI_RUN_FILTER_MODEL: z.string().optional(),
 
   EVENT_LOOP_MONITOR_THRESHOLD_MS: z.coerce.number().int().default(100),
+
+  VERY_SLOW_QUERY_THRESHOLD_MS: z.coerce.number().int().optional(),
 });
 
 export type Environment = z.infer<typeof EnvironmentSchema>;

apps/webapp/app/utils/queryPerformanceMonitor.server.ts

@@ -0,0 +1,64 @@
+import { env } from "~/env.server";
+import { logger } from "~/services/logger.server";
+
+export interface QueryPerformanceConfig {
+  verySlowQueryThreshold?: number; // ms
+  maxQueryLogLength: number;
+}
+
+export class QueryPerformanceMonitor {
+  private config: QueryPerformanceConfig;
+
+  constructor(config: Partial<QueryPerformanceConfig> = {}) {
+    this.config = {
+      maxQueryLogLength: 1000,
+      ...config,
+    };
+  }
+
+  onQuery(
+    clientType: "writer" | "replica",
+    log: {
+      duration: number;
+      query: string;
+      params: string;
+      target: string;
+      timestamp: Date;
+    }
+  ) {
+    if (this.config.verySlowQueryThreshold === undefined) {
+      return;
+    }
+
+    const { duration, query, params, target, timestamp } = log;
+
+    // Only log very slow queries as errors
+    if (duration > this.config.verySlowQueryThreshold) {
+      // Truncate long queries for readability
+      const truncatedQuery =
+        query.length > this.config.maxQueryLogLength
+          ? query.substring(0, this.config.maxQueryLogLength) + "..."
+          : query;
+
+      logger.error("Prisma: very slow database query", {
+        clientType,
+        durationMs: duration,
+        query: truncatedQuery,
+        target,
+        timestamp,
+        paramCount: this.countParams(query),
+        hasParams: params !== "[]" && params !== "",
+      });
+    }
+  }
+
+  private countParams(query: string): number {
+    // Count the number of $1, $2, etc. parameters in the query
+    const paramMatches = query.match(/\$\d+/g);
+    return paramMatches ? paramMatches.length : 0;
+  }
+}
+
+export const queryPerformanceMonitor = new QueryPerformanceMonitor({
+  verySlowQueryThreshold: env.VERY_SLOW_QUERY_THRESHOLD_MS,
+});