DEV Community

Elsie Rainee
Elsie Rainee

Posted on

How I Debugged a Ghost: A Production Mystery Story

Summer Bug Smash: Smash Stories 🐛🛹

This is a submission for DEV's Summer Bug Smash: Smash Stories powered by Sentry.

👻 The Ghost Appears

Act I — The Problem
It started with a Slack message at 11:43 PM on a Wednesday. Not an alert. Just a message from our most senior backend engineer, Priya, with no punctuation — which meant it was serious.

priya: hey. our /api/orders endpoint is slow. like, really slow. not always. but sometimes. been happening for weeks i think

That word at times refers to a problem which keeps engineers awake. For consistent bugs there is a solution. Consistent bugs have stack traces, patterns, and reproducible conditions. The phrase "at times" means that you're chasing a ghost.

The next morning I pulled the last 30 days of response time logs for GET /api/orders. The median response time was about 180ms, but the 95th percentile was at 4.2 seconds and the 99th was over 9 seconds.

Users weren't dropping off on every request. Just on some of them, unpredictably, and mostly during business hours. The ghost had a schedule.

🔍 The Investigation

Act II — Following the Trail

The first thing I thought of was the database since that's always the case. I used EXPLAIN ANALYZE on the query for orders and found that all the indexes were appropriate, with no sequential scans on the large tables. The query took less than 20ms to run when executed by itself.

First red herring: The database wasn't the bottleneck; by running a query in a test environment you eliminate all the real-world factors such as connection pool pressure and concurrent transactions together with lock contention.

I focussed on the Node.js application itself and found that the endpoint handler was no different from what might be expected; it retrieved a paginated list of orders for the authenticated user, joined a few related tables, formatted the result and then returned it. Approximately, it looked like this:

// routes/orders.js
router.get('/orders', authenticate, async (req, res) => {
  const { page = 1, limit = 20 } = req.query;
  const userId = req.user.id;

  const orders = await db.query(
    `SELECT o.*, u.name, u.email
     FROM orders o
     JOIN users u ON u.id = o.user_id
     WHERE o.user_id = $1
     ORDER BY o.created_at DESC
     LIMIT $2 OFFSET $3`,
    [userId, limit, (page - 1) * limit]
  );

  // Enrich each order with its line items
  const enriched = await Promise.all(
    orders.rows.map(async (order) => {
      const items = await db.query(
        `SELECT * FROM order_items WHERE order_id = $1`,
        [order.id]
      );
      return { ...order, items: items.rows };
    })
  );

  res.json({ orders: enriched, page, limit });
});
Enter fullscreen mode Exit fullscreen mode

I read it twice. Then a third time. Then I saw it.

On the surface, Promise.all() looks like it's doing the right thing — running requests in parallel, not sequentially. And technically, it is. All 20 queries for order items fire at once.

But here's what I hadn't accounted for: our PostgreSQL connection pool had a maximum of 10 connections.

The ghost, revealed: During low-traffic periods, the pool had spare connections and all 20 queries resolved fast. During busy periods, between business hours, the pool was already used up by other requests. Because Promise.all() triggered all 20 queries at the same time, they all had to wait in queue for the already exhausted connection pool, resulting in a thundering herd that caused the entire request to stall for seconds at a time.

This is the classic N+1 query problem disguised as a call to Promise.all(). We weren't carrying out the N+1 queries sequentially, since that would have been obvious and always slow. Instead, we carried them out in parallel, which completely concealed the problem under light load but made the situation catastrophic when under pressure.

⚒️ The Fix

Act III — Smashing the Ghost

The solution wasn't complicated once I understood the problem. Instead of making one database query per order, I needed to fetch all the order items for the entire page in a single query, then stitch the results together in JavaScript.

// routes/orders.js — after the fix
router.get('/orders', authenticate, async (req, res) => {
  const { page = 1, limit = 20 } = req.query;
  const userId = req.user.id;
  const offset = (page - 1) * limit;

  // Single query for orders
  const orders = await db.query(
    `SELECT o.*, u.name, u.email
     FROM orders o
     JOIN users u ON u.id = o.user_id
     WHERE o.user_id = $1
     ORDER BY o.created_at DESC
     LIMIT $2 OFFSET $3`,
    [userId, limit, offset]
  );

  if (orders.rows.length === 0) {
    return res.json({ orders: [], page, limit });
  }

  // Collect all order IDs from this page
  const orderIds = orders.rows.map((o) => o.id);

  // ONE query to get ALL line items for the entire page
  const itemsResult = await db.query(
    `SELECT * FROM order_items
     WHERE order_id = ANY($1::uuid[])`,
    [orderIds]
  );

  // Group items by order_id in memory — O(n) operation
  const itemsByOrderId = itemsResult.rows.reduce((acc, item) => {
    if (!acc[item.order_id]) acc[item.order_id] = [];
    acc[item.order_id].push(item);
    return acc;
  }, {});

  // Stitch together in JS — no extra DB round trips
  const enriched = orders.rows.map((order) => ({
    ...order,
    items: itemsByOrderId[order.id] || [],
  }));

  res.json({ orders: enriched, page, limit });
});
Enter fullscreen mode Exit fullscreen mode

The change reduced the number of database queries per request from 21 queries (1 for orders + 20 for items) down to 2 queries, flat, regardless of page size. The grouping step in JavaScript takes time that is proportional to the number of items and is therefore effectively free when compared to making a database round trip.

📊 Before vs. After

Before
4.2s
p95 response time

After
190ms
p95 response time

Before
21
DB queries per request

After
2
DB queries per request

Before
9.1s
p99 response time

After
310ms
p99 response time

The ghost was gone: Same endpoint, same data, same database server. Two queries instead of twenty-one. The p95 time fell from 4.2 seconds to 190 milliseconds, which is a 95% improvement and connection pool pressure during peak hours has completely disappeared.

🧠 What I Actually Learned

The technical fix is the easy part to write about. The harder lessons are the ones about how bugs like this survive in codebases for months:

  • Promise.all() can hide N+1 problems, not solve them: Running N queries in parallel still costs N database connections. Under light load it looks fast. Under pressure it becomes a connection pool bomb. Always count your queries, not just your awaits.
  • Median metrics lie: Our p50 response time was perfectly healthy. The ghost only showed up at p95 and above — which represents real users with real frustration. If you're not watching high percentiles, you're not watching what matters.
  • Load-dependent bugs are the hardest kind: If a bug only manifests under concurrent load, your local dev environment will never show it. A query that takes 20ms in isolation can take 4 seconds when 20 of its siblings are fighting for the same connection pool simultaneously.
  • The fix was in JavaScript, not SQL: Grouping records in memory with a reduce is something junior developers often treat as a code smell — "shouldn't the database handle this?" Sometimes yes. But two queries + one O(n) reduce is orders of magnitude faster than 21 queries under pool contention. Know when to move work to the application layer.
  • "It works on my machine" is a connection pool problem waiting to happen: Set your local dev pool size to match production. You'll catch these things in review instead of three months later in a Slack message with no punctuation.

✌️ Final Thoughts

The ghost wasn't supernatural. It was twenty queries fighting over ten connections, invisible at low traffic and catastrophic at high. It hid behind a Promise.all() that looked like good practice on the surface, in a codebase where nobody had checked the query count in a while.

Three months. A single database call and a JavaScript reduce. The p99 went from 9.1 seconds to 310ms overnight.

Priya messaged the next morning. This time with punctuation.

priya: okay yeah orders is fast now. what did you do?

Some victories are quiet. This was one of them.

Top comments (0)