feat: Redis opportunity cache, CW API retry/logging, adaptive TTLs

- Add Redis-backed opportunity cache with background refresh (30s interval) - Fix concurrency bug: use lazy thunks instead of eager promises for batching - Add withCwRetry utility with exponential backoff for transient CW errors - Add adaptive TTL algorithms (primary, sub-resource, products) based on opportunity activity - Add include query param on GET /sales/opportunities/:id (notes,contacts,products) - Add opt-in CW API logger (LOG_CW_API env var) with timestamped files in cw-api-logs/ - Add debug-scripts/analyze-cw-calls.py for API call analysis - Add computeSubResourceCacheTTL and computeProductsCacheTTL algorithms with tests - Increase CW API timeout from 15s to 30s - Unblock cache refresh from startup chain (remove await) - Prioritize recently updated opportunities in refresh cycle - Add CACHING.md documentation - Update API_ROUTES.md with caching details and include param - Update copilot instructions to require CACHING.md sync - Add dev:log script for CW API call logging during development
2026-03-02 23:23:24 -06:00
parent fe71248e88
commit 6d935e7180
33 changed files with 2634 additions and 176 deletions
@@ -0,0 +1,142 @@
+/**
+ * @module cwApiLogger
+ *
+ * Axios interceptor-based logger that records every ConnectWise API
+ * request to a JSONL (newline-delimited JSON) file for post-hoc analysis.
+ *
+ * Each line in the log file is a self-contained JSON object with:
+ *   - timestamp (ISO-8601)
+ *   - method, url, baseURL
+ *   - status (HTTP status or null on network error)
+ *   - durationMs (wall-clock time from request start → response/error)
+ *   - error (error code / message, if any)
+ *   - timeout (configured timeout in ms)
+ *
+ * Logging is **opt-in** — set the `LOG_CW_API` environment variable to
+ * any truthy value to enable it. When enabled, each process start creates
+ * a new timestamped file inside the `cw-api-logs/` directory:
+ *
+ *   LOG_CW_API=1 bun run dev          # uses cw-api-logs/<timestamp>.jsonl
+ *   bun run dev:log                    # shorthand (sets LOG_CW_API=1)
+ *
+ * Appends are non-blocking (fire-and-forget) to avoid slowing down
+ * the actual API flow.
+ *
+ * Usage:
+ *   import { attachCwApiLogger } from "./modules/cw-utils/cwApiLogger";
+ *   attachCwApiLogger(connectWiseApi);
+ */
+
+import { appendFile, mkdir } from "fs/promises";
+import path from "path";
+import type { AxiosInstance, InternalAxiosRequestConfig } from "axios";
+
+const LOG_DIR = path.resolve(process.cwd(), "cw-api-logs");
+
+/** Build a timestamped filename like `2026-03-02T14-30-05.123Z.jsonl` */
+function buildLogPath(): string {
+  const ts = new Date().toISOString().replace(/:/g, "-");
+  return path.join(LOG_DIR, `${ts}.jsonl`);
+}
+
+let LOG_PATH: string | null = null;
+
+// Symbol used to stash the start time on the request config
+const START_TIME = Symbol("cwLogStartTime");
+
+interface TimedConfig extends InternalAxiosRequestConfig {
+  [START_TIME]?: number;
+}
+
+export interface CwApiLogEntry {
+  timestamp: string;
+  method: string;
+  url: string;
+  baseURL: string;
+  status: number | null;
+  durationMs: number;
+  error: string | null;
+  timeout: number | undefined;
+}
+
+/** Write a single log entry (fire-and-forget). */
+function writeEntry(entry: CwApiLogEntry): void {
+  if (!LOG_PATH) return;
+  appendFile(LOG_PATH, JSON.stringify(entry) + "\n").catch((err) => {
+    // Swallow write errors — logging should never crash the app
+    console.error("[cw-logger] failed to write log entry:", err.message);
+  });
+}
+
+/**
+ * Attach request/response interceptors to an Axios instance to log
+ * every CW API call with timing information.
+ */
+export function attachCwApiLogger(api: AxiosInstance): void {
+  if (!process.env.LOG_CW_API) {
+    return;
+  }
+
+  // Create the log directory and build a unique file path for this run
+  LOG_PATH = buildLogPath();
+  mkdir(LOG_DIR, { recursive: true }).catch((err) => {
+    console.error("[cw-logger] failed to create log directory:", err.message);
+  });
+
+  // ---- Request interceptor: record start time --------------------------
+  api.interceptors.request.use((config: TimedConfig) => {
+    config[START_TIME] = performance.now();
+    return config;
+  });
+
+  // ---- Response interceptor: log successful calls ----------------------
+  api.interceptors.response.use(
+    (response) => {
+      const config = response.config as TimedConfig;
+      const start = config[START_TIME] ?? performance.now();
+      const durationMs = Math.round(performance.now() - start);
+
+      writeEntry({
+        timestamp: new Date().toISOString(),
+        method: (config.method ?? "GET").toUpperCase(),
+        url: config.url ?? "",
+        baseURL: config.baseURL ?? "",
+        status: response.status,
+        durationMs,
+        error: null,
+        timeout: config.timeout,
+      });
+
+      return response;
+    },
+
+    // ---- Error interceptor: log failed calls -----------------------------
+    (err) => {
+      const config = (err.config ?? {}) as TimedConfig;
+      const start = config[START_TIME] ?? performance.now();
+      const durationMs = Math.round(performance.now() - start);
+
+      writeEntry({
+        timestamp: new Date().toISOString(),
+        method: (config.method ?? "GET").toUpperCase(),
+        url: config.url ?? "",
+        baseURL: config.baseURL ?? "",
+        status: err.response?.status ?? null,
+        durationMs,
+        error: err.code
+          ? `${err.code}: ${err.message}`
+          : (err.message ?? "unknown"),
+        timeout: config.timeout,
+      });
+
+      return Promise.reject(err);
+    },
+  );
+
+  console.log(`[cw-logger] logging CW API calls to ${LOG_PATH}`);
+}
+
+/** Returns the current log file path (or null if logging is disabled). */
+export function getCwLogPath(): string | null {
+  return LOG_PATH;
+}