Why Your App Fails in Ways You Never Anticipated
You've load-tested your application, deployed it carefully, and it performs well under normal conditions. Then a spike in traffic hits at 2 AM, a slow database query starts blocking connection pools, memory usage creeps up over 12 hours, and your app crashes. By the time you find out, thousands of users have already abandoned your service.
Observability — knowing what your application is doing at all times — prevents this. The three pillars of observability are metrics, logs, and traces. This guide shows you how to implement all three.
The Three Pillars of Observability
1. Metrics: What Is Happening (Now and Over Time)
Metrics are numeric measurements sampled over time: CPU usage, request rate, error rate, response time percentiles. They answer "is something wrong?"
Metric examples:
- http_requests_total{method="GET", status="200"} = 15203
- http_request_duration_seconds{p99} = 0.234
- nodejs_heap_used_bytes = 142606336
- database_connections_active = 12
2. Logs: What Happened (Events)
Logs are discrete events with context. They answer "what exactly happened, and why?"
{
"timestamp": "2026-05-28T14:23:11.234Z",
"level": "error",
"message": "Database connection timeout",
"requestId": "req_abc123",
"userId": "user_456",
"query": "SELECT * FROM orders WHERE user_id = ?",
"duration_ms": 30002,
"error": "connect ETIMEDOUT 10.0.0.5:5432"
}
3. Traces: How a Request Traveled (Causality)
Distributed traces show the path a request took through multiple services. They answer "why is this specific request slow?"
Request abc123 (total: 234ms)
├── API Gateway (2ms)
├── Auth Service (8ms)
├── User Service (12ms)
│ └── PostgreSQL query (10ms)
└── Orders Service (212ms) ← SLOW!
├── Redis cache miss (3ms)
└── PostgreSQL query (208ms) ← This is the bottleneck
Setting Up Prometheus + Grafana
Prometheus scrapes metrics from your app. Grafana visualizes them.
# docker-compose.yml
version: '3.8'
services:
app:
build: .
ports: ["3000:3000"]
prometheus:
image: prom/prometheus:latest
ports: ["9090:9090"]
volumes:
- ./prometheus.yml:/etc/prometheus/prometheus.yml
grafana:
image: grafana/grafana:latest
ports: ["3001:3000"]
environment:
- GF_SECURITY_ADMIN_PASSWORD=admin
volumes:
- grafana_data:/var/lib/grafana
volumes:
grafana_data:
# prometheus.yml
global:
scrape_interval: 15s
scrape_configs:
- job_name: 'nodejs-app'
static_configs:
- targets: ['app:3000']
metrics_path: '/metrics'
Exposing Metrics from Node.js
import express from 'express';
import { register, Counter, Histogram, Gauge } from 'prom-client';
import { collectDefaultMetrics } from 'prom-client';
const app = express();
// Collect default Node.js metrics (CPU, memory, event loop, GC)
collectDefaultMetrics({ prefix: 'nodejs_' });
// Custom metrics
const httpRequestsTotal = new Counter({
name: 'http_requests_total',
help: 'Total HTTP requests',
labelNames: ['method', 'route', 'status_code'],
});
const httpRequestDuration = new Histogram({
name: 'http_request_duration_seconds',
help: 'HTTP request duration in seconds',
labelNames: ['method', 'route'],
buckets: [0.001, 0.005, 0.01, 0.05, 0.1, 0.5, 1, 5],
});
const activeConnections = new Gauge({
name: 'http_active_connections',
help: 'Active HTTP connections',
});
// Middleware to track requests
app.use((req, res, next) => {
const end = httpRequestDuration.startTimer({
method: req.method,
route: req.path
});
activeConnections.inc();
res.on('finish', () => {
httpRequestsTotal.inc({
method: req.method,
route: req.route?.path ?? req.path,
status_code: res.statusCode,
});
end(); // Records duration
activeConnections.dec();
});
next();
});
// Expose metrics endpoint (Prometheus scrapes this)
app.get('/metrics', async (req, res) => {
res.set('Content-Type', register.contentType);
res.send(await register.metrics());
});
Useful Prometheus Queries (PromQL)
# Request rate (per second, 5-minute window)
rate(http_requests_total[5m])
# Error rate percentage
rate(http_requests_total{status_code=~"5.."}[5m])
/ rate(http_requests_total[5m]) * 100
# 99th percentile latency
histogram_quantile(0.99, rate(http_request_duration_seconds_bucket[5m]))
# Memory usage in MB
nodejs_heap_used_bytes / 1024 / 1024
# Event loop lag (p99) — indicates CPU pressure
histogram_quantile(0.99, rate(nodejs_eventloop_lag_seconds_bucket[5m]))
Structured Logging with Winston/Pino
// pino is faster, winston is more flexible
import pino from 'pino';
const logger = pino({
level: process.env.LOG_LEVEL ?? 'info',
// In production, output JSON for log aggregation
transport: process.env.NODE_ENV === 'development'
? { target: 'pino-pretty', options: { colorize: true } }
: undefined,
// Add base metadata to every log
base: {
service: 'api-service',
version: process.env.npm_package_version,
env: process.env.NODE_ENV,
},
// Redact sensitive fields
redact: ['req.headers.authorization', 'req.body.password'],
});
// Use child loggers to add context
app.use((req, res, next) => {
req.log = logger.child({
requestId: crypto.randomUUID(),
method: req.method,
url: req.url,
});
next();
});
// In route handlers
app.get('/users/:id', async (req, res) => {
req.log.info('Fetching user');
try {
const user = await db.users.findById(req.params.id);
req.log.info({ userId: user.id }, 'User found');
res.json(user);
} catch (error) {
req.log.error({ err: error }, 'Failed to fetch user');
res.status(500).json({ error: 'Internal server error' });
}
});
OpenTelemetry: Distributed Tracing
// Instrumentation setup (must run before other imports!)
// tracing.js
import { NodeSDK } from '@opentelemetry/sdk-node';
import { getNodeAutoInstrumentations } from '@opentelemetry/auto-instrumentations-node';
import { OTLPTraceExporter } from '@opentelemetry/exporter-trace-otlp-http';
import { Resource } from '@opentelemetry/resources';
import { ATTR_SERVICE_NAME } from '@opentelemetry/semantic-conventions';
const sdk = new NodeSDK({
resource: new Resource({
[ATTR_SERVICE_NAME]: 'my-api-service',
}),
traceExporter: new OTLPTraceExporter({
url: 'http://jaeger:4318/v1/traces', // or Tempo, Zipkin, etc.
}),
// Auto-instrument: http, express, pg, redis, etc.
instrumentations: [getNodeAutoInstrumentations()],
});
sdk.start();
// Graceful shutdown
process.on('SIGTERM', () => sdk.shutdown());
// Adding custom spans to traces
import { trace, context, SpanStatusCode } from '@opentelemetry/api';
const tracer = trace.getTracer('my-service');
async function processOrder(orderId) {
// Create a custom span
return tracer.startActiveSpan('processOrder', async (span) => {
span.setAttribute('order.id', orderId);
span.setAttribute('order.processor', 'v2');
try {
const order = await db.orders.findById(orderId);
span.setAttribute('order.amount', order.total);
// Nested spans are automatically linked
await chargePayment(order);
await updateInventory(order);
await sendConfirmationEmail(order);
span.setStatus({ code: SpanStatusCode.OK });
return order;
} catch (error) {
span.setStatus({
code: SpanStatusCode.ERROR,
message: error.message
});
span.recordException(error);
throw error;
} finally {
span.end(); // Always end spans!
}
});
}
Error Monitoring with Sentry
import * as Sentry from '@sentry/node';
Sentry.init({
dsn: process.env.SENTRY_DSN,
environment: process.env.NODE_ENV,
// Performance monitoring (captures traces)
tracesSampleRate: 0.1, // Sample 10% of transactions
// Breadcrumbs: automatic context before errors
integrations: [
Sentry.httpIntegration(),
Sentry.expressIntegration(),
Sentry.postgresIntegration(),
],
// Don't send certain errors
ignoreErrors: [
'ResizeObserver loop limit exceeded',
/^Network Error/,
],
beforeSend(event) {
// Scrub sensitive data
if (event.request?.data?.password) {
event.request.data.password = '[REDACTED]';
}
return event;
},
});
// Add user context to errors
app.use((req, res, next) => {
if (req.user) {
Sentry.setUser({ id: req.user.id, email: req.user.email });
}
next();
});
// Error handler must be after routes
app.use(Sentry.expressErrorHandler());
Key Metrics to Monitor
The Four Golden Signals (Google SRE)
1. Latency - How long requests take (p50, p95, p99)
2. Traffic - How many requests per second
3. Errors - What percentage fail
4. Saturation - How close to capacity (CPU, memory, queue depth)
Node.js-Specific Metrics
// Event loop lag — most important Node.js metric
// High lag = CPU-bound code blocking async operations
const Histogram = require('prom-client').Histogram;
const lag = new Histogram({ name: 'eventloop_lag', help: 'Event loop lag' });
let prev = Date.now();
setInterval(() => {
const now = Date.now();
lag.observe((now - prev - 1000) / 1000); // Expected 1000ms, measure drift
prev = now;
}, 1000);
// Heap usage
// Watch for continuous growth → memory leak
// GC pause duration → garbage collection pressure
// External memory → native addons, Buffers
Alerting Best Practices
# Prometheus alerting rules
groups:
- name: app-alerts
rules:
# High error rate
- alert: HighErrorRate
expr: |
rate(http_requests_total{status_code=~"5.."}[5m])
/ rate(http_requests_total[5m]) > 0.05
for: 2m
labels:
severity: critical
annotations:
summary: "Error rate above 5%"
# High latency
- alert: HighLatency
expr: |
histogram_quantile(0.99,
rate(http_request_duration_seconds_bucket[5m])
) > 1.0
for: 5m
labels:
severity: warning
annotations:
summary: "p99 latency above 1 second"
# Memory leak indicator
- alert: HighMemoryUsage
expr: nodejs_heap_used_bytes / nodejs_heap_size_total_bytes > 0.9
for: 10m
labels:
severity: critical
→ Use the Benchmark Builder to measure and compare performance of different code implementations.