Debug Pipeline

Overview

The debug pipeline is a set of composable middleware wrappers — ExecutionTracer, PerformanceProfiler, and DebugLogger — that instrument any UDIOT MiddlewarePipeline without modifying the middleware themselves. The createDebugPipeline() factory attaches all three with a single call and is the recommended entry point. Source: src/middleware/debug.ts.

All instrumentation is additive: the original middleware is called unchanged, and results pass through. ExecutionTracer measures exclusive per-middleware time (subtracting time spent in downstream middleware), so latency is attributed to the middleware that actually caused it.

Key Concepts

ExecutionTracer wraps each middleware in the pipeline via tracer.trace(), which mutates the pipeline in place and starts recording ExecutionTrace objects on each pipeline run
Exclusive timing: the tracer subtracts the time spent inside next() from each entry's duration, so upstream middleware do not accumulate downstream latency
PerformanceProfiler wraps individual middleware objects via profiler.profile(middleware) and accumulates aggregate statistics across all pipeline executions
DebugLogger wraps individual middleware via logger.log(middleware) and writes entry/exit messages through UDIOT's logger
createDebugPipeline is a convenience factory that wires tracing, profiling, and logging based on the options you pass

API Reference

`TraceEntry`

interface TraceEntry {
  name: string;                        // Middleware name
  startTime: number;                   // performance.now() at entry
  endTime?: number;                    // performance.now() at exit
  duration?: number;                   // Exclusive time (endTime - startTime - innerTime)
  success: boolean;                    // false if the middleware threw
  error?: Error;                       // Populated on middleware-owned errors
  metadata?: Record<string, any>;      // Tenant or request-level context tags
}

`ExecutionTrace`

interface ExecutionTrace {
  traceId: string;                     // Unique ID (trace-<timestamp>-<random>)
  startTime: number;
  endTime?: number;
  duration?: number;                   // Total pipeline duration
  entries: TraceEntry[];               // One entry per middleware, in execution order
  success: boolean;
  contextType: string;                 // context.constructor.name or 'unknown'
  metadata?: Record<string, any>;
}

`PerformanceProfile`

interface PerformanceProfile {
  name: string;
  executionCount: number;
  averageTime: number;
  minTime: number;
  maxTime: number;
  totalTime: number;
  errorCount: number;
  successRate: number;                 // 0–100 (percentage)
}

`ExecutionTracer<TContext>`

class ExecutionTracer<TContext extends BaseContext> {
  // Pass the pipeline to instrument
  constructor(pipeline: MiddlewarePipeline<TContext>)

  // Mutates the pipeline: wraps every registered middleware with timing hooks.
  // Returns the same pipeline for chaining.
  trace(): MiddlewarePipeline<TContext>

  // Call after each pipeline.execute() to finalise the current trace.
  endTrace(success?: boolean): ExecutionTrace | null

  // All completed traces (newest last, capped at 1000)
  getTraces(): ExecutionTrace[]

  // The most recently completed trace
  getLastTrace(): ExecutionTrace | null

  // Clear all recorded traces
  clearTraces(): void

  // Per-middleware aggregate statistics derived from all traces
  getPerformanceProfile(): PerformanceProfile[]

  // ASCII timeline for a single ExecutionTrace
  generateTimeline(trace: ExecutionTrace): string

  // Tabular performance report across all recorded traces
  generatePerformanceReport(): string
}

`PerformanceProfiler<TContext>`

class PerformanceProfiler<TContext extends BaseContext> {
  // Wraps a single Middleware object in-place with timing hooks.
  // Returns the same middleware for chaining.
  profile(middleware: Middleware<TContext>): Middleware<TContext>

  // All accumulated profiles (one per unique middleware.name)
  getProfiles(): PerformanceProfile[]

  // Profile for one middleware by name
  getProfile(name: string): PerformanceProfile | undefined

  // N slowest middleware by averageTime (default: 5)
  getSlowest(count?: number): PerformanceProfile[]

  // N middleware with the most errors (default: 5)
  getMostErrors(count?: number): PerformanceProfile[]

  // Reset all accumulated stats
  reset(): void
}

`DebugLogger<TContext>`

class DebugLogger<TContext extends BaseContext> {
  constructor(prefix?: string)  // default prefix: '[Middleware]'

  // Wraps a Middleware object in-place with entry/exit logging.
  log(middleware: Middleware<TContext>): Middleware<TContext>

  // Enable or disable logging at runtime
  setEnabled(enabled: boolean): void

  // All log entries recorded since construction
  getLogs(): Array<{ timestamp: number; message: string; level: string }>

  // Clear log buffer
  clearLogs(): void
}

`createDebugPipeline()`

function createDebugPipeline<TContext extends BaseContext>(
  pipeline: MiddlewarePipeline<TContext>,
  options?: {
    trace?:   boolean;   // Attach ExecutionTracer (default: true)
    profile?: boolean;   // Attach PerformanceProfiler (default: false)
    log?:     boolean;   // Attach DebugLogger (default: false)
  }
): {
  pipeline: MiddlewarePipeline<TContext>;
  tracer?:  ExecutionTracer<TContext>;
  profiler?: PerformanceProfiler<TContext>;
  logger?:  DebugLogger<TContext>;
}

trace defaults to true — calling createDebugPipeline(pipeline) without options always attaches the tracer.

Basic Usage

Using the factory

import { MiddlewarePipeline } from '@tagna/udiot';
import { createDebugPipeline } from '@tagna/udiot';
import { devOnly } from '@tagna/udiot/dev';

const pipeline = new MiddlewarePipeline<MyContext>();
pipeline.use(authMiddleware).use(validationMiddleware).use(handlerMiddleware);

let activePipeline = pipeline;

devOnly(() => {
  const { pipeline: debugged, tracer, profiler } = createDebugPipeline(pipeline, {
    trace:   true,
    profile: true,
    log:     true,
  });
  activePipeline = debugged;

  // After each pipeline run you can inspect results:
  // tracer?.generateTimeline(tracer.getLastTrace()!)
  // profiler?.getSlowest(3)
});

export { activePipeline as pipeline };

Using `ExecutionTracer` directly

import { MiddlewarePipeline } from '@tagna/udiot';
import { ExecutionTracer } from '@tagna/udiot';

const pipeline = new MiddlewarePipeline<MyContext>();
pipeline.use(authMiddleware).use(handlerMiddleware);

const tracer = new ExecutionTracer(pipeline);
tracer.trace(); // wraps all middleware in the pipeline

await pipeline.execute(context);
const trace = tracer.endTrace(true);

if (trace) {
  console.log(tracer.generateTimeline(trace));
  /*
  Execution Timeline (trace-1711234567890-abc12)
  Total Duration: 14.20ms

  ✓ [OK]  authenticate              ████████████░░░░░░░░░░░░░░░░░░  12.10ms
  ✓ [OK]  handler                   ██░░░░░░░░░░░░░░░░░░░░░░░░░░░░   2.10ms
  */
}

Using `PerformanceProfiler` directly

import { MiddlewarePipeline } from '@tagna/udiot';
import { PerformanceProfiler } from '@tagna/udiot';

const pipeline = new MiddlewarePipeline<MyContext>();
const profiler = new PerformanceProfiler<MyContext>();

pipeline.use(profiler.profile(authMiddleware));
pipeline.use(profiler.profile(validationMiddleware));

// After many executions:
const slowest = profiler.getSlowest(3);
slowest.forEach(p => {
  console.log(`${p.name}: avg=${p.averageTime.toFixed(2)}ms errors=${p.errorCount}`);
});

Using `DebugLogger` directly

import { MiddlewarePipeline } from '@tagna/udiot';
import { DebugLogger } from '@tagna/udiot';

const pipeline = new MiddlewarePipeline<MyContext>();
const logger = new DebugLogger<MyContext>('[Auth]');

pipeline.use(logger.log(parseBodyMiddleware));
pipeline.use(logger.log(validateMiddleware));

// Disable in hot-path sections:
logger.setEnabled(false);

Common Patterns

Generating a performance report after a test suite

import { ExecutionTracer } from '@tagna/udiot';

const tracer = new ExecutionTracer(pipeline);
tracer.trace();

afterAll(() => {
  console.log(tracer.generatePerformanceReport());
  /*
  Performance Report
  Total Traces: 200

  Middleware Performance:
  ────────────────────────────────────────────────────────────────────────────────
  Name                          Calls     Avg         Min         Max         Errors
  ────────────────────────────────────────────────────────────────────────────────
  authenticate                  200       0.42ms      0.11ms      3.20ms      2
  authorize                     200       0.09ms      0.05ms      0.81ms      0
  */
});

Identifying error-prone middleware

const problematic = profiler.getMostErrors(5);
problematic.forEach(p => {
  const errorRate = (100 - p.successRate).toFixed(1);
  console.warn(`${p.name}: ${errorRate}% error rate over ${p.executionCount} calls`);
});

Selective profiling in development only

import { devOnly } from '@tagna/udiot/dev';
import { PerformanceProfiler } from '@tagna/udiot';

devOnly(() => {
  const profiler = new PerformanceProfiler<MyContext>();
  pipeline.use(profiler.profile(expensiveMiddleware));

  setInterval(() => {
    const report = profiler.getSlowest(3);
    console.table(report);
  }, 10_000);
});

Integration Notes

ExecutionTracer mutates the pipeline's middleware list by replacing each handler in place — call tracer.trace() once per pipeline, not once per request
Exclusive timing subtracts all time inside next() (including downstream middleware). Background async work that outlives await next() is not captured and will make the entry appear faster than reality
PerformanceProfiler and DebugLogger also mutate middleware handlers in place — only call profiler.profile(mw) or logger.log(mw) once per middleware object
Both ExecutionTracer and PerformanceProfiler use performance.now() which is available natively in Node.js 16+ and all modern browsers
DebugLogger routes through UDIOT's internal logger (getLogger()), not directly to console — configure UDIOT's log level to control output verbosity

Pitfalls

Calling tracer.trace() more than once on the same pipeline double-wraps every middleware and produces duplicate trace entries per execution
endTrace() must be called after each pipeline execution to finalise the current ExecutionTrace; if omitted, the trace is never stored and getLastTrace() returns null
createDebugPipeline enables trace by default (trace !== false); pass { trace: false } if you only want profiling or logging without tracing overhead
PerformanceProfiler accumulates data indefinitely; call profiler.reset() periodically in long-running servers to prevent unbounded growth
generateTimeline and generatePerformanceReport return plain text intended for console or log output — do not parse their output programmatically; use getTraces() and getPerformanceProfile() for structured data

From the canonical UDIOT public documentation.Try it in the playground ↗

Debug Pipeline

Overview

Key Concepts

API Reference

TraceEntry

ExecutionTrace

PerformanceProfile

ExecutionTracer<TContext>

PerformanceProfiler<TContext>

DebugLogger<TContext>

createDebugPipeline()