Merge pull request #160 from Jayking40/Performance--hot-path-profiling-hooks-for-gateway-proxy

greatest0fallt1me · web-flow · commit c5199b1e2b7b · 2026-03-24T22:28:34.000+05:30
perf(gateway): add upstream latency metrics
diff --git a/src/__tests__/upstreamProfiling.test.ts b/src/__tests__/upstreamProfiling.test.ts
@@ -0,0 +1,239 @@
+import {
+  startUpstreamTimer,
+  isProfilingEnabled,
+  resetUpstreamMetrics,
+} from '../metrics.js';
+import client from 'prom-client';
+
+// ── Helpers ──────────────────────────────────────────────────────────────────
+
+/** A single value entry from prom-client (includes metricName at runtime). */
+interface MetricEntry {
+  value: number;
+  labels: Record<string, string>;
+  metricName?: string;
+}
+
+/** Retrieve a single metric's collected values from the default registry. */
+async function getMetricValues(name: string) {
+  const metrics = await client.register.getMetricsAsJSON();
+  const found = metrics.find((m) => m.name === name);
+  if (!found) return undefined;
+  return { ...found, values: found.values as MetricEntry[] };
+}
+
+// ── Setup / teardown ─────────────────────────────────────────────────────────
+
+const originalEnv = process.env.GATEWAY_PROFILING_ENABLED;
+
+afterEach(() => {
+  // Restore env var to its original value between tests
+  if (originalEnv === undefined) {
+    delete process.env.GATEWAY_PROFILING_ENABLED;
+  } else {
+    process.env.GATEWAY_PROFILING_ENABLED = originalEnv;
+  }
+  resetUpstreamMetrics();
+});
+
+// ── Tests ────────────────────────────────────────────────────────────────────
+
+describe('isProfilingEnabled', () => {
+  it('returns false when GATEWAY_PROFILING_ENABLED is unset', () => {
+    delete process.env.GATEWAY_PROFILING_ENABLED;
+    expect(isProfilingEnabled()).toBe(false);
+  });
+
+  it('returns false for arbitrary truthy strings', () => {
+    process.env.GATEWAY_PROFILING_ENABLED = 'yes';
+    expect(isProfilingEnabled()).toBe(false);
+  });
+
+  it('returns true only when set to "true"', () => {
+    process.env.GATEWAY_PROFILING_ENABLED = 'true';
+    expect(isProfilingEnabled()).toBe(true);
+  });
+});
+
+describe('startUpstreamTimer (profiling disabled)', () => {
+  beforeEach(() => {
+    delete process.env.GATEWAY_PROFILING_ENABLED;
+  });
+
+  it('returns a no-op timer that does not throw', () => {
+    const timer = startUpstreamTimer('api_1', 'GET');
+    expect(() => timer.stop(200, 'success')).not.toThrow();
+  });
+
+  it('does not record any histogram observations', async () => {
+    const timer = startUpstreamTimer('api_1', 'POST');
+    timer.stop(200, 'success');
+
+    const metric = await getMetricValues('gateway_upstream_duration_seconds');
+    // When profiling is off the metric exists but has no observed values
+    const values = metric?.values ?? [];
+    expect(values.filter((v) => v.labels.api_id === 'api_1')).toHaveLength(0);
+  });
+});
+
+describe('startUpstreamTimer (profiling enabled)', () => {
+  beforeEach(() => {
+    process.env.GATEWAY_PROFILING_ENABLED = 'true';
+    resetUpstreamMetrics();
+  });
+
+  it('records a histogram observation on success', async () => {
+    const timer = startUpstreamTimer('api_abc', 'GET');
+    // Simulate a short delay
+    await new Promise((r) => setTimeout(r, 15));
+    timer.stop(200, 'success');
+
+    const metric = await getMetricValues('gateway_upstream_duration_seconds');
+    expect(metric).toBeDefined();
+
+    const countEntry = (metric?.values ?? []).find(
+      (v) =>
+        v.metricName === 'gateway_upstream_duration_seconds_count' &&
+        v.labels.api_id === 'api_abc' &&
+        v.labels.method === 'GET' &&
+        v.labels.status_code === '200' &&
+        v.labels.outcome === 'success',
+    );
+    expect(countEntry).toBeDefined();
+    expect(countEntry!.value).toBe(1);
+  });
+
+  it('increments the upstream requests counter', async () => {
+    const timer = startUpstreamTimer('api_xyz', 'POST');
+    timer.stop(201, 'success');
+
+    const metric = await getMetricValues('gateway_upstream_requests_total');
+    expect(metric).toBeDefined();
+
+    const entry = (metric?.values ?? []).find(
+      (v) =>
+        v.labels.api_id === 'api_xyz' &&
+        v.labels.method === 'POST' &&
+        v.labels.status_code === '201' &&
+        v.labels.outcome === 'success',
+    );
+    expect(entry).toBeDefined();
+    expect(entry!.value).toBe(1);
+  });
+
+  it('records timeout outcome correctly', async () => {
+    const timer = startUpstreamTimer('api_slow', 'GET');
+    timer.stop(504, 'timeout');
+
+    const metric = await getMetricValues('gateway_upstream_requests_total');
+    const entry = (metric?.values ?? []).find(
+      (v) =>
+        v.labels.api_id === 'api_slow' &&
+        v.labels.outcome === 'timeout' &&
+        v.labels.status_code === '504',
+    );
+    expect(entry).toBeDefined();
+    expect(entry!.value).toBe(1);
+  });
+
+  it('records error outcome correctly', async () => {
+    const timer = startUpstreamTimer('api_down', 'POST');
+    timer.stop(502, 'error');
+
+    const metric = await getMetricValues('gateway_upstream_requests_total');
+    const entry = (metric?.values ?? []).find(
+      (v) =>
+        v.labels.api_id === 'api_down' &&
+        v.labels.outcome === 'error' &&
+        v.labels.status_code === '502',
+    );
+    expect(entry).toBeDefined();
+    expect(entry!.value).toBe(1);
+  });
+
+  it('normalises method to uppercase', async () => {
+    const timer = startUpstreamTimer('api_case', 'post');
+    timer.stop(200, 'success');
+
+    const metric = await getMetricValues('gateway_upstream_requests_total');
+    const entry = (metric?.values ?? []).find(
+      (v) => v.labels.api_id === 'api_case' && v.labels.method === 'POST',
+    );
+    expect(entry).toBeDefined();
+  });
+
+  it('accumulates multiple observations for the same label set', async () => {
+    for (let i = 0; i < 3; i++) {
+      const timer = startUpstreamTimer('api_multi', 'GET');
+      timer.stop(200, 'success');
+    }
+
+    const metric = await getMetricValues('gateway_upstream_requests_total');
+    const entry = (metric?.values ?? []).find(
+      (v) => v.labels.api_id === 'api_multi' && v.labels.outcome === 'success',
+    );
+    expect(entry).toBeDefined();
+    expect(entry!.value).toBe(3);
+  });
+
+  it('records a positive duration value', async () => {
+    const timer = startUpstreamTimer('api_dur', 'GET');
+    await new Promise((r) => setTimeout(r, 10));
+    timer.stop(200, 'success');
+
+    const metric = await getMetricValues('gateway_upstream_duration_seconds');
+    const sumEntry = (metric?.values ?? []).find(
+      (v) =>
+        v.metricName === 'gateway_upstream_duration_seconds_sum' &&
+        v.labels.api_id === 'api_dur',
+    );
+    expect(sumEntry).toBeDefined();
+    expect(sumEntry!.value).toBeGreaterThan(0);
+  });
+});
+
+describe('metric registration', () => {
+  it('gateway_upstream_duration_seconds is registered with correct buckets', async () => {
+    process.env.GATEWAY_PROFILING_ENABLED = 'true';
+    const timer = startUpstreamTimer('api_bucket', 'GET');
+    timer.stop(200, 'success');
+
+    const metric = await getMetricValues('gateway_upstream_duration_seconds');
+    expect(metric).toBeDefined();
+    expect(metric!.type).toBe('histogram');
+
+    // Verify bucket boundaries exist in the values
+    const bucketValues = (metric?.values ?? []).filter(
+      (v) => v.metricName === 'gateway_upstream_duration_seconds_bucket',
+    );
+    const bucketLe = bucketValues.map((v) => Number(v.labels.le)).filter((n) => isFinite(n));
+    expect(bucketLe).toEqual(expect.arrayContaining([0.01, 0.05, 0.1, 0.25, 0.5, 1, 2.5, 5, 10]));
+  });
+
+  it('gateway_upstream_requests_total is registered as a counter', async () => {
+    process.env.GATEWAY_PROFILING_ENABLED = 'true';
+    const timer = startUpstreamTimer('api_type', 'GET');
+    timer.stop(200, 'success');
+
+    const metric = await getMetricValues('gateway_upstream_requests_total');
+    expect(metric).toBeDefined();
+    expect(metric!.type).toBe('counter');
+  });
+});
+
+describe('resetUpstreamMetrics', () => {
+  it('clears previously recorded observations', async () => {
+    process.env.GATEWAY_PROFILING_ENABLED = 'true';
+
+    const timer = startUpstreamTimer('api_reset', 'GET');
+    timer.stop(200, 'success');
+
+    resetUpstreamMetrics();
+
+    const metric = await getMetricValues('gateway_upstream_requests_total');
+    const entry = (metric?.values ?? []).find(
+      (v) => v.labels.api_id === 'api_reset',
+    );
+    expect(entry).toBeUndefined();
+  });
+});
diff --git a/src/metrics.ts b/src/metrics.ts
@@ -1,5 +1,6 @@
 import { Request, Response, NextFunction } from 'express';
 import client from 'prom-client';
+import { performance } from 'node:perf_hooks';
 
 // Initialize the Prometheus Registry and collect default Node.js metrics (CPU, RAM, Event Loop)
 const register = new client.Registry();
@@ -23,6 +24,83 @@ const httpRequestsTotal = new client.Counter({
 register.registerMetric(httpRequestDuration);
 register.registerMetric(httpRequestsTotal);
 
+// ── Gateway upstream profiling ─────────────────────────────────────────────
+//
+// Metric: gateway_upstream_duration_seconds
+//   Type:    Histogram
+//   Labels:  api_id, method, status_code, outcome
+//   Buckets: tuned for typical upstream API latencies (10 ms → 10 s)
+//
+// Metric: gateway_upstream_requests_total
+//   Type:    Counter
+//   Labels:  api_id, method, status_code, outcome
+//
+// Both metrics are gated behind GATEWAY_PROFILING_ENABLED=true.
+// When disabled the timer helper is a cheap no-op.
+// ────────────────────────────────────────────────────────────────────────────
+
+const UPSTREAM_LABEL_NAMES = ['api_id', 'method', 'status_code', 'outcome'] as const;
+
+const gatewayUpstreamDuration = new client.Histogram({
+  name: 'gateway_upstream_duration_seconds',
+  help: 'Latency of proxied requests to upstream services in seconds',
+  labelNames: [...UPSTREAM_LABEL_NAMES],
+  buckets: [0.01, 0.05, 0.1, 0.25, 0.5, 1, 2.5, 5, 10],
+});
+
+const gatewayUpstreamRequestsTotal = new client.Counter({
+  name: 'gateway_upstream_requests_total',
+  help: 'Total proxied requests forwarded to upstream services',
+  labelNames: [...UPSTREAM_LABEL_NAMES],
+});
+
+register.registerMetric(gatewayUpstreamDuration);
+register.registerMetric(gatewayUpstreamRequestsTotal);
+
+/** Check whether gateway profiling hooks are active. */
+export function isProfilingEnabled(): boolean {
+  return process.env.GATEWAY_PROFILING_ENABLED === 'true';
+}
+
+export type UpstreamOutcome = 'success' | 'timeout' | 'error';
+
+interface UpstreamTimer {
+  /** Call once the upstream response (or error) has been received. */
+  stop(statusCode: number, outcome: UpstreamOutcome): void;
+}
+
+const NOOP_TIMER: UpstreamTimer = { stop() {} };
+
+/**
+ * Begin timing an upstream request.
+ *
+ * Returns a timer whose `stop()` method records the observed latency and
+ * increments the request counter.  When profiling is disabled the returned
+ * timer is a zero-cost no-op.
+ *
+ * Labels intentionally avoid PII — only the API identifier and HTTP method
+ * are captured, never user IDs, API keys, or request paths.
+ */
+export function startUpstreamTimer(apiId: string, method: string): UpstreamTimer {
+  if (!isProfilingEnabled()) return NOOP_TIMER;
+
+  const start = performance.now();
+
+  return {
+    stop(statusCode: number, outcome: UpstreamOutcome) {
+      const durationSec = (performance.now() - start) / 1000;
+      const labels = {
+        api_id: apiId,
+        method: method.toUpperCase(),
+        status_code: String(statusCode),
+        outcome,
+      };
+      gatewayUpstreamDuration.observe(labels, durationSec);
+      gatewayUpstreamRequestsTotal.inc(labels);
+    },
+  };
+}
+
 /**
  * Global middleware to record request metrics.
  * Safely extracts the parameterized route to prevent PII leakage and cardinality explosions.
@@ -60,6 +138,12 @@ export const metricsMiddleware = (req: Request, res: Response, next: NextFunctio
  * Controller to expose the /api/metrics endpoint.
  * Protected by a Bearer token in production environments.
  */
+/** Exposed for testing — reset upstream profiling metrics. */
+export function resetUpstreamMetrics(): void {
+  gatewayUpstreamDuration.reset();
+  gatewayUpstreamRequestsTotal.reset();
+}
+
 export const metricsEndpoint = async (req: Request, res: Response) => {
   const isProduction = process.env.NODE_ENV === 'production';
   const expectedKey = process.env.METRICS_API_KEY;
diff --git a/src/routes/gatewayRoutes.ts b/src/routes/gatewayRoutes.ts
@@ -1,6 +1,7 @@
 import { Router, Request, Response } from 'express';
 import { randomUUID } from 'node:crypto';
 import { GatewayDeps } from '../types/gateway.js';
+import { startUpstreamTimer } from '../metrics.js';
 
 const CREDIT_COST_PER_CALL = 1; // cost per proxied request
 
@@ -62,6 +63,7 @@ export function createGatewayRouter(deps: GatewayDeps): Router {
     // 4. Proxy to upstream
     let upstreamStatus = 502;
     let upstreamBody: string = '{"error":"Bad Gateway"}';
+    const timer = startUpstreamTimer(req.params.apiId, req.method);
 
     try {
       const upstreamRes = await fetch(`${upstreamUrl}${req.path}`, {
@@ -72,9 +74,11 @@ export function createGatewayRouter(deps: GatewayDeps): Router {
 
       upstreamStatus = upstreamRes.status;
       upstreamBody = await upstreamRes.text();
+      timer.stop(upstreamStatus, 'success');
     } catch {
       upstreamStatus = 502;
       upstreamBody = JSON.stringify({ error: 'Bad Gateway: upstream unreachable' });
+      timer.stop(upstreamStatus, 'error');
     }
 
     // 5. Record usage event
diff --git a/src/routes/proxyRoutes.ts b/src/routes/proxyRoutes.ts
