Node.js Performance Hooks Guide

The perf_hooks module provides APIs for performance measurement and timing. Here's how to use it.

Basic Performance Measurement#

const { performance, PerformanceObserver } = require('perf_hooks');

// Measure time
const start = performance.now();

// Do some work
for (let i = 0; i < 1000000; i++) {
  Math.sqrt(i);
}

const end = performance.now();
console.log(`Execution time: ${end - start} ms`);

// Using performance.mark and measure
performance.mark('start');

// Do work
await someAsyncOperation();

performance.mark('end');
performance.measure('My Operation', 'start', 'end');

// Get measurements
const measures = performance.getEntriesByType('measure');
console.log(measures[0].duration); // Duration in ms

Performance Observer#

const { performance, PerformanceObserver } = require('perf_hooks');

// Create observer
const obs = new PerformanceObserver((list) => {
  const entries = list.getEntries();
  entries.forEach((entry) => {
    console.log(`${entry.name}: ${entry.duration.toFixed(2)} ms`);
  });
});

// Observe specific entry types
obs.observe({ entryTypes: ['measure', 'function'] });

// Measure operations
performance.mark('fetch-start');
await fetch('https://api.example.com/data');
performance.mark('fetch-end');
performance.measure('API Fetch', 'fetch-start', 'fetch-end');

// Disconnect when done
obs.disconnect();

// Observe with buffered entries
obs.observe({ entryTypes: ['measure'], buffered: true });

Function Timing#

const { performance, PerformanceObserver } = require('perf_hooks');

// Wrap function for timing
const timedFunction = performance.timerify(originalFunction);

// Observer for function entries
const obs = new PerformanceObserver((list) => {
  list.getEntries().forEach((entry) => {
    console.log(`${entry.name} took ${entry.duration} ms`);
  });
});

obs.observe({ entryTypes: ['function'] });

// Call timed function
timedFunction(args);

// Wrap async function
async function fetchData(url) {
  const response = await fetch(url);
  return response.json();
}

const timedFetch = performance.timerify(fetchData);

// Time class methods
class DataService {
  constructor() {
    this.getData = performance.timerify(this.getData.bind(this));
  }

  async getData(id) {
    // ... fetch data
  }
}

Custom Metrics#

const { performance } = require('perf_hooks');

// Mark with details
performance.mark('request-start', {
  detail: {
    url: '/api/users',
    method: 'GET',
  },
});

// Access mark details
const marks = performance.getEntriesByName('request-start');
console.log(marks[0].detail); // { url: '/api/users', method: 'GET' }

// Clear marks
performance.clearMarks('request-start');
performance.clearMarks(); // Clear all

// Clear measures
performance.clearMeasures('My Operation');
performance.clearMeasures(); // Clear all

// Resource timing (if available)
const resources = performance.getEntriesByType('resource');
resources.forEach((resource) => {
  console.log(`${resource.name}: ${resource.duration} ms`);
});

HTTP Server Timing#

const http = require('http');
const { performance, PerformanceObserver } = require('perf_hooks');

// Middleware for request timing
function timingMiddleware(handler) {
  return async (req, res) => {
    const requestId = `${req.method}-${req.url}-${Date.now()}`;

    performance.mark(`${requestId}-start`);

    // Track response
    const originalEnd = res.end;
    res.end = function (...args) {
      performance.mark(`${requestId}-end`);
      performance.measure(requestId, `${requestId}-start`, `${requestId}-end`);

      const measure = performance.getEntriesByName(requestId)[0];
      console.log(`${req.method} ${req.url}: ${measure.duration.toFixed(2)} ms`);

      // Cleanup
      performance.clearMarks(`${requestId}-start`);
      performance.clearMarks(`${requestId}-end`);
      performance.clearMeasures(requestId);

      return originalEnd.apply(this, args);
    };

    await handler(req, res);
  };
}

// Usage
const server = http.createServer(
  timingMiddleware(async (req, res) => {
    // Handle request
    res.end('Hello World');
  })
);

Database Query Timing#

const { performance } = require('perf_hooks');

class QueryTimer {
  constructor() {
    this.queries = [];
  }

  async time(name, queryFn) {
    const start = performance.now();

    try {
      const result = await queryFn();
      const duration = performance.now() - start;

      this.queries.push({
        name,
        duration,
        timestamp: new Date(),
        success: true,
      });

      return result;
    } catch (error) {
      const duration = performance.now() - start;

      this.queries.push({
        name,
        duration,
        timestamp: new Date(),
        success: false,
        error: error.message,
      });

      throw error;
    }
  }

  getStats() {
    const durations = this.queries.map((q) => q.duration);
    return {
      count: this.queries.length,
      total: durations.reduce((a, b) => a + b, 0),
      average: durations.reduce((a, b) => a + b, 0) / durations.length,
      min: Math.min(...durations),
      max: Math.max(...durations),
    };
  }

  clear() {
    this.queries = [];
  }
}

// Usage
const timer = new QueryTimer();

const users = await timer.time('getUsers', () =>
  db.query('SELECT * FROM users')
);

const posts = await timer.time('getPosts', () =>
  db.query('SELECT * FROM posts WHERE user_id = ?', [userId])
);

console.log(timer.getStats());

Histogram#

const { createHistogram, performance } = require('perf_hooks');

// Create histogram for timing distribution
const histogram = createHistogram();

// Record values
for (let i = 0; i < 1000; i++) {
  const start = performance.now();
  // Do work
  someOperation();
  const duration = performance.now() - start;
  histogram.record(Math.floor(duration * 1e6)); // Convert to nanoseconds
}

// Get statistics
console.log('Min:', histogram.min);
console.log('Max:', histogram.max);
console.log('Mean:', histogram.mean);
console.log('Stddev:', histogram.stddev);
console.log('Percentiles:');
console.log('  50th:', histogram.percentile(50));
console.log('  90th:', histogram.percentile(90));
console.log('  99th:', histogram.percentile(99));

// Reset histogram
histogram.reset();

// Record with timestamps
const recordableHistogram = createHistogram({ lowest: 1, highest: 1e9 });

Event Loop Monitoring#

const { monitorEventLoopDelay } = require('perf_hooks');

// Create monitor
const h = monitorEventLoopDelay({ resolution: 20 });

// Start monitoring
h.enable();

// After some time, check results
setTimeout(() => {
  console.log('Event loop delay:');
  console.log('  Min:', h.min / 1e6, 'ms');
  console.log('  Max:', h.max / 1e6, 'ms');
  console.log('  Mean:', h.mean / 1e6, 'ms');
  console.log('  Stddev:', h.stddev / 1e6, 'ms');
  console.log('  P50:', h.percentile(50) / 1e6, 'ms');
  console.log('  P99:', h.percentile(99) / 1e6, 'ms');

  h.disable();
  h.reset();
}, 10000);

// Detect event loop blocking
setInterval(() => {
  const p99 = h.percentile(99) / 1e6;
  if (p99 > 100) {
    console.warn(`Event loop delay P99: ${p99.toFixed(2)} ms`);
  }
}, 5000);

Resource Usage Tracking#

const { performance } = require('perf_hooks');

// Track memory usage
function getMemoryMetrics() {
  const usage = process.memoryUsage();
  return {
    heapUsed: usage.heapUsed / 1024 / 1024,
    heapTotal: usage.heapTotal / 1024 / 1024,
    external: usage.external / 1024 / 1024,
    rss: usage.rss / 1024 / 1024,
  };
}

// Combined metrics collector
class MetricsCollector {
  constructor() {
    this.metrics = [];
    this.observer = new PerformanceObserver((list) => {
      list.getEntries().forEach((entry) => {
        this.metrics.push({
          name: entry.name,
          duration: entry.duration,
          timestamp: Date.now(),
          memory: getMemoryMetrics(),
        });
      });
    });
  }

  start() {
    this.observer.observe({ entryTypes: ['measure'] });
  }

  stop() {
    this.observer.disconnect();
  }

  getReport() {
    return {
      metrics: this.metrics,
      summary: {
        totalOperations: this.metrics.length,
        averageDuration:
          this.metrics.reduce((sum, m) => sum + m.duration, 0) /
          this.metrics.length,
        peakMemory: Math.max(...this.metrics.map((m) => m.memory.heapUsed)),
      },
    };
  }
}

Express Middleware#

const { performance } = require('perf_hooks');

function performanceMiddleware(options = {}) {
  const { logSlowRequests = 1000, onMetric } = options;

  return (req, res, next) => {
    const start = performance.now();
    const startMemory = process.memoryUsage().heapUsed;

    res.on('finish', () => {
      const duration = performance.now() - start;
      const memoryDelta = process.memoryUsage().heapUsed - startMemory;

      const metric = {
        method: req.method,
        path: req.path,
        statusCode: res.statusCode,
        duration,
        memoryDelta,
        timestamp: new Date().toISOString(),
      };

      if (duration > logSlowRequests) {
        console.warn('Slow request:', metric);
      }

      if (onMetric) {
        onMetric(metric);
      }
    });

    next();
  };
}

// Usage
app.use(performanceMiddleware({
  logSlowRequests: 500,
  onMetric: (metric) => metricsService.record(metric),
}));

Best Practices#

Measurement:
✓ Use marks and measures
✓ Clean up entries after use
✓ Use observers for async
✓ Include context in marks

Monitoring:
✓ Track event loop delay
✓ Monitor memory alongside timing
✓ Set up alerting thresholds
✓ Log slow operations

Performance:
✓ Minimize observer overhead
✓ Sample in production
✓ Aggregate metrics
✓ Use histograms for distribution

Avoid:
✗ Too many marks without cleanup
✗ Synchronous getEntries in hot paths
✗ Ignoring memory leaks
✗ Excessive logging overhead

The perf_hooks module provides powerful APIs for performance measurement in Node.js. Use marks and measures for timing, observers for async operations, and histograms for distribution analysis. Monitor event loop delay to detect blocking operations and combine with memory metrics for comprehensive profiling.