feat(infra): automated database query execution time logging for slow query detection (Closes #1365)

backend/src/dal/index.js

@@ -30,6 +30,10 @@ import { createSqliteCampaignRewardNotificationRepository } from './sqliteCampai
 import { runPgMigrations } from './pg/migrate.js';
 import { createPgCampaignRepository } from './pg/pgCampaignRepository.js';
 import { createPgAuditLogRepository } from './pg/pgAuditLogRepository.js';
+import {
+  wrapDatabaseWithQueryLogger,
+  wrapPoolWithQueryLogger,
+} from '../db/queryLogger.js';
 
 /**
  * Build the DAL.
@@ -55,17 +59,19 @@ export async function createDal({
   allowedCategories,
   allowlistRepository,
 } = {}) {
-  const db = new Database(dbPath);
-  await runMigrations(db);
+  const rawDb = new Database(dbPath);
+  await runMigrations(rawDb);
+  const db = wrapDatabaseWithQueryLogger(rawDb);
 
   const categories = allowedCategories ?? parseCategoriesConfig(process.env.TRIVELA_CATEGORIES);
 
   let pgPool;
   let pgCampaigns;
   let pgAuditLogs;
   if (isPostgresUrl(databaseUrl)) {
-    pgPool = createPool(databaseUrl);
-    await runPgMigrations(pgPool);
+    const rawPgPool = createPool(databaseUrl);
+    await runPgMigrations(rawPgPool);
+    pgPool = wrapPoolWithQueryLogger(rawPgPool);
     pgCampaigns = createPgCampaignRepository({
       pool: pgPool,
       seed: campaigns,

backend/src/db/migrations/046_session_tokens.js

@@ -1,25 +1,24 @@
-export const migration = {
-  name: '046_session_tokens',
-  description: 'Add session_tokens table for temporary session token storage and cleanup',
-  up: (db) => {
-    db.exec(`
-      CREATE TABLE IF NOT EXISTS session_tokens (
-        id TEXT PRIMARY KEY,
-        user_address TEXT NOT NULL,
-        token TEXT NOT NULL UNIQUE,
-        expires_at DATETIME NOT NULL,
-        created_at DATETIME DEFAULT CURRENT_TIMESTAMP,
-        updated_at DATETIME DEFAULT CURRENT_TIMESTAMP
-      );
+export const version = 46;
+export const description = 'Add session_tokens table for temporary session token storage and cleanup';
 
-      CREATE INDEX IF NOT EXISTS idx_session_tokens_user
-        ON session_tokens(user_address);
+export function up(db) {
+  db.exec(`
+    CREATE TABLE IF NOT EXISTS session_tokens (
+      id TEXT PRIMARY KEY,
+      user_address TEXT NOT NULL,
+      token TEXT NOT NULL UNIQUE,
+      expires_at DATETIME NOT NULL,
+      created_at DATETIME DEFAULT CURRENT_TIMESTAMP,
+      updated_at DATETIME DEFAULT CURRENT_TIMESTAMP
+    );
 
-      CREATE INDEX IF NOT EXISTS idx_session_tokens_expires
-        ON session_tokens(expires_at);
+    CREATE INDEX IF NOT EXISTS idx_session_tokens_user
+      ON session_tokens(user_address);
 
-      CREATE INDEX IF NOT EXISTS idx_session_tokens_token
-        ON session_tokens(token);
-    `);
-  },
-};
+    CREATE INDEX IF NOT EXISTS idx_session_tokens_expires
+      ON session_tokens(expires_at);
+
+    CREATE INDEX IF NOT EXISTS idx_session_tokens_token
+      ON session_tokens(token);
+  `);
+}

backend/src/db/migrations/047_campaign_tenant_isolation.js

@@ -1,15 +1,14 @@
-export const migration = {
-  name: '047_campaign_tenant_isolation',
-  description: 'Add tenant_id to campaigns for enterprise multi-tenant isolation',
-  up: (db) => {
-    db.exec(`
-      ALTER TABLE campaigns ADD COLUMN tenant_id TEXT;
+export const version = 47;
+export const description = 'Add tenant_id to campaigns for enterprise multi-tenant isolation';
 
-      CREATE INDEX IF NOT EXISTS idx_campaigns_tenant_id
-        ON campaigns(tenant_id);
+export function up(db) {
+  db.exec(`
+    ALTER TABLE campaigns ADD COLUMN tenant_id TEXT;
 
-      CREATE INDEX IF NOT EXISTS idx_campaigns_tenant_id_active
-        ON campaigns(tenant_id, active);
-    `);
-  },
-};
+    CREATE INDEX IF NOT EXISTS idx_campaigns_tenant_id
+      ON campaigns(tenant_id);
+
+    CREATE INDEX IF NOT EXISTS idx_campaigns_tenant_id_active
+      ON campaigns(tenant_id, active);
+  `);
+}

backend/src/db/migrations/048_campaign_reward_notifications.js

@@ -1,26 +1,25 @@
-export const migration = {
-  name: '048_campaign_reward_notifications',
-  description: 'Track campaign reward availability notifications to prevent duplicate sends',
-  up: (db) => {
-    db.exec(`
-      CREATE TABLE IF NOT EXISTS campaign_reward_notifications (
-        id TEXT PRIMARY KEY,
-        campaign_id TEXT NOT NULL,
-        user_address TEXT NOT NULL,
-        notification_type TEXT NOT NULL DEFAULT 'reward_available',
-        sent_at DATETIME DEFAULT CURRENT_TIMESTAMP,
-        created_at DATETIME DEFAULT CURRENT_TIMESTAMP,
-        UNIQUE(campaign_id, user_address, notification_type)
-      );
+export const version = 48;
+export const description = 'Track campaign reward availability notifications to prevent duplicate sends';
 
-      CREATE INDEX IF NOT EXISTS idx_reward_notif_campaign
-        ON campaign_reward_notifications(campaign_id);
+export function up(db) {
+  db.exec(`
+    CREATE TABLE IF NOT EXISTS campaign_reward_notifications (
+      id TEXT PRIMARY KEY,
+      campaign_id TEXT NOT NULL,
+      user_address TEXT NOT NULL,
+      notification_type TEXT NOT NULL DEFAULT 'reward_available',
+      sent_at DATETIME DEFAULT CURRENT_TIMESTAMP,
+      created_at DATETIME DEFAULT CURRENT_TIMESTAMP,
+      UNIQUE(campaign_id, user_address, notification_type)
+    );
 
-      CREATE INDEX IF NOT EXISTS idx_reward_notif_user
-        ON campaign_reward_notifications(user_address);
+    CREATE INDEX IF NOT EXISTS idx_reward_notif_campaign
+      ON campaign_reward_notifications(campaign_id);
 
-      CREATE INDEX IF NOT EXISTS idx_reward_notif_sent
-        ON campaign_reward_notifications(sent_at);
-    `);
-  },
-};
+    CREATE INDEX IF NOT EXISTS idx_reward_notif_user
+      ON campaign_reward_notifications(user_address);
+
+    CREATE INDEX IF NOT EXISTS idx_reward_notif_sent
+      ON campaign_reward_notifications(sent_at);
+  `);
+}

backend/src/db/queryLogger.js

@@ -0,0 +1,209 @@
+// @ts-check
+import { log as defaultLogger } from '../middleware/logger.js';
+import { captureMessage as defaultCaptureMessage } from '../services/sentryIntegration.js';
+
+export const DEFAULT_SLOW_QUERY_THRESHOLD_MS = 200;
+
+/**
+ * Get configured threshold in ms from environment or default (200ms).
+ * @returns {number}
+ */
+export function getSlowQueryThresholdMs() {
+  const envVal = process.env.SLOW_QUERY_THRESHOLD_MS;
+  if (envVal) {
+    const parsed = parseInt(envVal, 10);
+    if (!isNaN(parsed) && parsed > 0) return parsed;
+  }
+  return DEFAULT_SLOW_QUERY_THRESHOLD_MS;
+}
+
+/**
+ * Sanitize query parameters before logging to prevent sensitive data leakage.
+ * @param {unknown} params
+ * @returns {unknown}
+ */
+export function sanitizeQueryParams(params) {
+  if (params === null || params === undefined) return params;
+  if (typeof params !== 'object') return params;
+
+  if (Array.isArray(params)) {
+    return params.map((item) => sanitizeQueryParams(item));
+  }
+
+  const sanitized = {};
+  const sensitiveRegex = /password|secret|token|apikey|key|auth|credential/i;
+
+  for (const [key, value] of Object.entries(params)) {
+    if (sensitiveRegex.test(key)) {
+      sanitized[key] = '[REDACTED]';
+    } else if (typeof value === 'object' && value !== null) {
+      sanitized[key] = sanitizeQueryParams(value);
+    } else {
+      sanitized[key] = value;
+    }
+  }
+
+  return sanitized;
+}
+
+/**
+ * Record query execution time and alert if it exceeds threshold.
+ *
+ * @param {Object} options
+ * @param {string} options.query - SQL query string
+ * @param {number} options.durationMs - Execution duration in milliseconds
+ * @param {unknown} [options.params] - Bound parameters
+ * @param {number} [options.thresholdMs] - Threshold override
+ * @param {Object} [options.logger] - Logger instance
+ * @param {Function} [options.sentryCapture] - Sentry message capture function
+ * @returns {boolean} true if query was slow and logged
+ */
+export function recordQueryExecution({
+  query,
+  durationMs,
+  params = null,
+  thresholdMs = getSlowQueryThresholdMs(),
+  logger = defaultLogger,
+  sentryCapture = defaultCaptureMessage,
+}) {
+  if (durationMs < thresholdMs) {
+    return false;
+  }
+
+  const sanitizedParams = sanitizeQueryParams(params);
+  const logPayload = {
+    query: query?.trim(),
+    duration_ms: durationMs,
+    threshold_ms: thresholdMs,
+    params: sanitizedParams,
+  };
+
+  // Log to CloudWatch via structured JSON log
+  if (typeof logger?.warn === 'function') {
+    logger.warn(logPayload, 'Slow database query detected');
+  }
+
+  // Log to Sentry
+  if (typeof sentryCapture === 'function') {
+    const querySummary = (query || 'UNKNOWN').trim().replace(/\s+/g, ' ').slice(0, 120);
+    sentryCapture(
+      `Slow query detected: ${durationMs}ms - ${querySummary}`,
+      'warning',
+      { slow_query: logPayload },
+    );
+  }
+
+  return true;
+}
+
+/**
+ * Wraps a better-sqlite3 Database instance to intercept and measure query executions.
+ *
+ * @param {import('better-sqlite3').Database} db
+ * @param {Object} [options]
+ * @param {number} [options.thresholdMs]
+ * @param {Object} [options.logger]
+ * @param {Function} [options.sentryCapture]
+ * @returns {import('better-sqlite3').Database}
+ */
+export function wrapDatabaseWithQueryLogger(db, options = {}) {
+  if (!db || typeof db.prepare !== 'function') {
+    return db;
+  }
+
+  // Prevent double-wrapping
+  if (db.__queryLoggerWrapped) {
+    return db;
+  }
+
+  const originalPrepare = db.prepare.bind(db);
+  const originalExec = db.exec.bind(db);
+
+  db.prepare = function prepareWithTiming(sql) {
+    const stmt = originalPrepare(sql);
+
+    const wrapMethod = (methodName) => {
+      const originalMethod = stmt[methodName].bind(stmt);
+      stmt[methodName] = function timedStatementExecution(...args) {
+        const start = performance.now();
+        try {
+          return originalMethod(...args);
+        } finally {
+          const durationMs = Math.round(performance.now() - start);
+          recordQueryExecution({
+            query: sql,
+            durationMs,
+            params: args.length > 0 ? args : null,
+            ...options,
+          });
+        }
+      };
+    };
+
+    if (typeof stmt.run === 'function') wrapMethod('run');
+    if (typeof stmt.get === 'function') wrapMethod('get');
+    if (typeof stmt.all === 'function') wrapMethod('all');
+
+    return stmt;
+  };
+
+  db.exec = function execWithTiming(sql) {
+    const start = performance.now();
+    try {
+      return originalExec(sql);
+    } finally {
+      const durationMs = Math.round(performance.now() - start);
+      recordQueryExecution({
+        query: sql,
+        durationMs,
+        ...options,
+      });
+    }
+  };
+
+  db.__queryLoggerWrapped = true;
+  return db;
+}
+
+/**
+ * Wraps a pg.Pool or pg.Client instance to intercept and measure query executions.
+ *
+ * @param {Object} pool - node-postgres Pool or Client
+ * @param {Object} [options]
+ * @param {number} [options.thresholdMs]
+ * @param {Object} [options.logger]
+ * @param {Function} [options.sentryCapture]
+ * @returns {Object}
+ */
+export function wrapPoolWithQueryLogger(pool, options = {}) {
+  if (!pool || typeof pool.query !== 'function') {
+    return pool;
+  }
+
+  if (pool.__queryLoggerWrapped) {
+    return pool;
+  }
+
+  const originalQuery = pool.query.bind(pool);
+
+  pool.query = async function queryWithTiming(...args) {
+    const start = performance.now();
+    const query = typeof args[0] === 'string' ? args[0] : args[0]?.text;
+    const params = Array.isArray(args[1]) ? args[1] : args[0]?.values;
+
+    try {
+      return await originalQuery(...args);
+    } finally {
+      const durationMs = Math.round(performance.now() - start);
+      recordQueryExecution({
+        query: query || 'UNKNOWN',
+        durationMs,
+        params,
+        ...options,
+      });
+    }
+  };
+
+  pool.__queryLoggerWrapped = true;
+  return pool;
+}