DEV Community

Timevolt
Timevolt

Posted on

Monitoring and Logging: The Avengers Assemble

The Quest Begins (The "Why")

Honestly, I still remember the night I got paged at 2 a.m. because a handful of users were seeing “500 Internal Server Error” on our checkout page. I rolled out of bed, opened the logs, and found… nothing useful. Just a wall of console.log lines that said “Processing request” and “Done”. No context, no request ID, no clue which user’s cart had exploded. I felt like I was wandering through a maze blindfolded while the users were already shouting at the exit. That night I swore I’d never let a bug sneak past us again— I wanted to spot the problem before the user even noticed it.

The Revelation (The Insight)

The game‑changer was realizing that monitoring and logging aren’t just about dumping text to a file; they’re about correlating data so you can see the full story of a request as it travels through your system. Think of it like assembling the Avengers: each hero (logs, metrics, traces, alerts) brings a unique power, and together they can defeat any villain (bug) before it reaches the civilian (your user).

The insight was simple: give every request a unique identifier, attach that ID to every log line, capture structured key‑value pairs (so you can query them), and expose vital signs (latency, error rates, throughput) as metrics that your alerting system can watch. When something goes wrong, you can instantly filter logs by that ID, see the exact SQL query that failed, the external API call that timed out, and the user’s session data— all without guessing.

Wielding the Power (Code & Examples)

The Struggle: Naïve Logging

Here’s what our Express route looked like before we leveled up:

// server.js – before
const express = require('express');
const app = express();

app.get('/checkout', (req, res) => {
  console.log('Processing checkout request'); // <-- useless!
  try {
    const order = processOrder(req.body);
    res.json(order);
  } catch (err) {
    console.error('Something went wrong'); // <-- no stack, no context
    res.status(500).send('Internal Server Error');
  }
});

app.listen(3000);
Enter fullscreen mode Exit fullscreen mode

Problems?

  • No request‑specific ID → impossible to tie logs together.
  • Plain text → can’t query for “all errors for user 123”.
  • No metrics → we only knew something was broken after users complained.

The Victory: Structured Logging + Metrics

After we applied the Avengers‑style approach, the same route looks like this:

// server.js – after
const express = require('express');
const { createLogger, format, transports } = require('winston');
const client = require('prom-client');

// ---------- Logger ----------
const logger = createLogger({
  level: 'info',
  format: format.combine(
    format.timestamp(),
    format.errors({ stack: true }),   // capture stack traces
    format.splat(),
    format.json()                     // structured output
  ),
  transports: [new transports.Console()],
});

// ---------- Metrics ----------
const httpRequestDurationMicroseconds = new client.Histogram({
  name: 'http_request_duration_ms',
  help: 'Duration of HTTP requests in ms',
  labelNames: ['method', 'route', 'status_code'],
  buckets: [50, 100, 200, 400, 800, 1600, 3200, 6400, 12800, 25600],
});

const app = express();

// Middleware to assign a request ID and start a timer
app.use((req, res, next) => {
  req.id = require('crypto').randomBytes(8).toString('hex');
  const start = Date.now();
  res.on('finish', () => {
    const durationMs = Date.now() - start;
    logger.info('request completed', {
      requestId: req.id,
      method: req.method,
      url: req.originalUrl,
      status: res.statusCode,
      durationMs,
    });
    httpRequestDurationMicroseconds.observe(
      { method: req.method, route: req.path, status_code: res.statusCode },
      durationMs
    );
  });
  next();
});

// Instrumented route
app.get('/checkout', (req, res) => {
  logger.info('starting checkout', { requestId: req.id, payload: req.body });
  try {
    const order = processOrder(req.body);
    logger.info('checkout succeeded', { requestId: req.id, orderId: order.id });
    res.json(order);
  } catch (err) {
    logger.error('checkout failed', {
      requestId: req.id,
      error: err.message,
      stack: err.stack,
      userId: req.body.userId,
    });
    res.status(500).send('Internal Server Error');
  }
});

// Expose metrics for Prometheus
app.get('/metrics', async (req, res) => {
  res.set('Content-Type', client.register.contentType);
  res.end(await client.register.metrics());
});

app.listen(3000, () => logger.info('Server listening on :3000'));
Enter fullscreen mode Exit fullscreen mode

What changed?

  1. Request ID – every log line now carries requestId, letting us grep or query a single request’s whole lifecycle.
  2. Structured JSON logs – we can feed these straight into Elasticsearch, Loki, or any log‑aggregation tool and run queries like requestId:"a1b2c3d4" AND level:"error".
  3. Error context – we log the exact error message, stack trace, and relevant payload (user ID, order data). No more guessing what went wrong.
  4. Metrics – a Prometheus histogram tracks request latency per endpoint and status code. Alerts can fire when the 95th‑percentile latency spikes or error rate exceeds a threshold, before users start complaining.
  5. Health endpoint (not shown but easy to add) – /healthz returns 200 when the app and its dependencies are OK, giving your orchestration layer a quick sanity check.

Traps to Avoid (The Villains on the Path)

  • Logging everything at info level – you’ll drown in noise. Reserve debug for verbose dev details, info for flow, warn for unexpected but non‑fatal events, and error for genuine failures.
  • Forgetting to correlate logs – without a request ID, you’re back to staring at a wall of text.
  • Over‑instrumenting – adding timers to every tiny function can add overhead. Focus on boundaries: HTTP entry/exit, external calls, and database queries.
  • Ignoring log retention and rotation – huge log files crash your node. Use a proper log driver or sidecar (like Fluent Bit) to ship logs out.

Why This New Power Matters

Now, when a misbehaving third‑party payment gateway starts timing out, our metrics show a rise in latency for /checkout, the alert fires, and I can pull up the exact request IDs that failed. I see the user IDs, the exact payload sent, and the gateway’s error response— all before the user even notices a delay. It’s like having Spider‑Man’s spider‑sense: you feel the danger coming and can swing in to fix it.

Beyond firefighting, this setup unlocks proactive improvements. By querying latency trends, we spotted a slow database query that was only affecting 2 % of traffic but added 150 ms to every request. Fixing it cut our average response time by 80 ms—users got a snappier experience, and our conversion rate crept up. Monitoring and logging stopped being a chore and became a superpower we wield every day.

Your Turn: Start Your Own Quest

Grab your favorite language—whether it’s Python’s structlog, Go’s zap, or Java’s Logback—and give each request a unique ID. Push those logs into a system that lets you query by that ID, and sprinkle in a few key metrics (latency, error rate, throughput). Set up a simple alert (even just a Slack webhook) for when error rates creep above 1 %.

Try it out on a small service tonight, and tell me: what’s the first hidden bug you caught before your users even knew it existed? I can’t wait to hear your war stories! 🚀

Top comments (0)