The 8-Second Query That Was Actually Five Doomed Retries

A dashboard panel caught my eye one day. The p95 response time for one endpoint was spiking to around 8 seconds, a few times a day. Everything else on that same endpoint was sitting comfortably under 100ms.

The strange part is that every one of these slow requests returned a normal HTTP 200. Nothing was actually failing. It was just slow, once in a while, and nobody could explain why.

This post is the story of chasing that 8 seconds all the way down to its root, and the surprisingly small fix at the end.

---

Clue #1: The spikes were suspiciously identical

The first thing I did was pull the raw durations of the slow requests, instead of trusting the aggregated p95. This is roughly what I saw:

8419ms
8299ms
8261ms
8260ms
8258ms
8249ms
8249ms
...

Look at how tightly these numbers are clustered. All of them are within around 200ms of 8.2 seconds.

That is a big hint. Real load is noisy. If the slowness was coming from a busy database, or a slow network hop, or CPU contention, you would see a spread like 2s, 5s, 11s, 800ms. When the latency clusters this tightly around a single constant, it is usually not load. It is a fixed delay sitting somewhere in the code path, like a timeout, a sleep, or a retry schedule.

So the question changed from “why is the database slow?” to “what in my code takes exactly 8.2 seconds?”

---

Clue #2: The time was not where I expected

I took one slow request and pulled every log line for it in order, with per statement timing. The actual job of the endpoint, its main query and the response, took only about 30 milliseconds. The rest of the 8.2 seconds was spent before that, inside what looked like a routine “find or create this record” step in an authentication middleware.

Here is the trace, cleaned up a bit:

12.839  START TRANSACTION
12.841  SELECT ... WHERE unique_col = X   -> no row found
12.855  INSERT ...                         (14ms)
14.044  INSERT ...                         (6ms)   <- ~1.19s later
15.545  INSERT ...                         (1ms)   <- ~1.50s later
17.797  INSERT ...                         (1ms)   <- ~2.25s later
21.175  INSERT ...                         (1ms)   <- ~3.38s later
21.177  SELECT ... WHERE unique_col = X   -> found it
21.178  COMMIT
21.215  Done — 8419ms

Two things jumped out at me:

1. There are five INSERT statements for what should have been a single insert.
2. Each INSERT itself finishes in 1 to 14ms. Nothing is blocked waiting on a lock. All the time is in the gaps between the inserts, and those gaps keep growing: around 1.2s, then 1.5s, then 2.25s, then 3.4s.

Growing gaps between the same operation is a classic sign of exponential backoff. Something was retrying that INSERT five times, sleeping a little longer each time, before finally giving up and reading the row instead.

---

The code: an innocent looking findOrCreate

The middleware creates a local record for a user the first time it sees them. In Sequelize (a popular Node.js ORM), that is a one liner:

const [user] = await User.findOrCreate({
  where: { external_id: id },
  defaults: { name, email, external_id: id },
});

findOrCreate does exactly what the name says. It runs a SELECT using the where clause, and if nothing is found, it does an INSERT with the defaults. Simple enough. So why five inserts?

---

The root cause: a race, and a retry policy that could not tell the difference

Here is what was actually happening.

When a brand new user arrives for the first time, the client fires several requests at once (a typical bootstrap, fetch status, fetch a token, fetch some config), and all of them carry the same new user id. Each of these requests independently reaches that findOrCreate.

And now the classic race plays out:

1. Two requests run the SELECT at almost the same time. Both of them see no row.
2. Both go ahead and INSERT.
3. One transaction commits first and wins, so the row now exists.
4. The other request’s INSERT violates the unique constraint on the column, and the database rejects it with a duplicate key error (ER_DUP_ENTRY in MySQL, which Sequelize surfaces as a UniqueConstraintError).

This race is completely normal and expected. It is why the unique constraint is there in the first place. And findOrCreate already handles it correctly. On a unique constraint error it catches the exception and does a second SELECT to return the row that the winner just created.

But there was a retry policy sitting underneath all of this. Sequelize lets you configure automatic query retries (through the retry option, powered by retry-as-promised), usually added to survive transient failures like deadlocks or dropped connections. Sequelize even ships a sensible, conservative default, retry on exactly one known transient error:

// Sequelize's built-in default
retry: { max: 5, match: ["SQLITE_BUSY: database is locked"] }

So how did a duplicate key error, which is not in that list, end up getting retried? This is the part that surprised me, and it comes down to two behaviours combining together.

First, the config had overridden retry to tune the backoff, but without specifying match:

// somewhere in the DB config
retry: {
  max: 5,
  backoffBase: 1000,
  backoffExponent: 1.5,
  // note: no `match` key
}

Sequelize merges these options with a shallow spread, so this custom block does not extend the default, it replaces it completely. The curated match: ["SQLITE_BUSY"] is silently gone. You can actually watch it happen:

new Sequelize(db, { dialect: "mysql" }).options.retry;
//=> { max: 5, match: ["SQLITE_BUSY: database is locked"] }

new Sequelize(db, { dialect: "mysql", retry: { max: 5, backoffBase: 1000 } }).options.retry;
//=> { max: 5, backoffBase: 1000 }   // <-- no `match` anymore

Second, and this is the real trap, an empty or missing match does not mean “retry nothing”. In retry-as-promised it means the exact opposite:

// retry-as-promised
shouldRetry = options.match.length === 0 || options.match.some(m => matches(m, err));

match.length === 0 short circuits to true. So no filter actually means retry on every error. Leaving match off is the most aggressive setting, not the safest one.

Put it all together. The backoff override wiped out the default allowlist, the now empty match meant “retry everything”, and so the losing INSERT’s duplicate key error was treated as retryable. The retry layer re-ran the identical INSERT, with backoff, five times, even though nobody ever listed that error as retryable.

And here is the thing that makes this a real bug and not just slowness. A duplicate key error is permanent. The winning row is already committed. Re-running the exact same INSERT will fail in exactly the same way, every single time, forever. There is no version of “try again” that can ever succeed. So the retry policy was spending 8 seconds sleeping between attempts that were guaranteed to fail, and only after exhausting all five did the error finally reach findOrCreate’s catch block, which then did the one thing that actually works, read the row.

The delays match the config almost exactly:

Retry	backoffBase * backoffExponent^(n-1)	Delay
1	1000 × 1.5⁰	1000ms
2	1000 × 1.5¹	1500ms
3	1000 × 1.5²	2250ms
4	1000 × 1.5³	3375ms
	total	~8.1s

And there is the 8.2 seconds.

---

An overlooked side effect: connection starvation

The latency was the visible symptom, but there is a nastier problem hiding underneath it.

That whole 8.2s happens inside an open transaction, which holds a connection checked out from the pool the entire time. Connection pools are small (5, 10, maybe 20 per instance). If a burst of new users arrives together, several connections can each get pinned for 8 seconds doing nothing except sleeping between doomed retries. Once the pool is exhausted, even unrelated requests start queuing for a connection. So one user’s harmless race can quietly degrade the latency for everyone on that instance.

Non-blocking I/O saves the event loop here (the backoff is a setTimeout, not a busy wait, so the CPU stays free), but the connection is still held the whole time. “It’s async so it’s fine” does not cover the resources you are holding across the await.

---

The fix

The correct recovery for a findOrCreate race is not “retry the insert”, it is “read the row that someone else just created”. That logic already exists in findOrCreate’s catch block. All I had to do was stop the retry layer from getting in its way:

const [user] = await User.findOrCreate({
  where: { external_id: id },
  defaults: { name, email, external_id: id },
  // A duplicate-key error here is the *expected* outcome of a race, not a
  // transient fault. Don't retry it — fall straight through to the built-in
  // findOne fallback instead of burning the backoff budget on a doomed INSERT.
  retry: { max: 0 },
});

I verified this with a tiny standalone script using the same libraries. I stubbed a create that always throws a UniqueConstraintError, and then timed it under the old policy versus the fix:

BEFORE (retry max:5)   attempts=5   elapsed=8130.6ms
AFTER  (retry max:0)   attempts=1   elapsed=0.1ms

So it went from around 8,130ms to around 0.1ms per losing request. Same outcome (the error still propagates to the read fallback), just without all the pointless sleeping.

Should you keep one retry?

Tempting, but no. A single retry (max: 1) still costs a full ~1s backoff sleep and still fails, because the duplicate is permanent. One retry of a non retryable error is pure waste. The real value of retries lives entirely with transient errors, which brings me to the deeper fix.

The deeper fix

Disabling retry at this one call site is the fast, local patch. The real root cause is broader. The retry policy had no match allowlist at all, so it was retrying every error. The proper fix is to give it an explicit match that lists only genuinely retryable failures, like deadlocks, lock wait timeouts and connection resets, and never deterministic ones like unique constraint violations. That fixes every findOrCreate and create in the codebase at once, not just the one I happened to be looking at. (I also reported the silent default wiping behaviour upstream, since “override the backoff, accidentally retry everything” is a sharp edge worth flagging.)

---

Some lessons worth keeping

1. Tightly clustered latency is a fixed delay, not load. If your slow requests all land within a few percent of the same number, stop staring at load graphs and start looking for a timeout, a sleep, or a retry schedule in the code.

2. Measure where the time goes before theorising about why. Per statement timing turned “the database is slow” into “we sleep for 8 seconds between five inserts” in about two minutes. Once you can say the second sentence, the fix is almost obvious.

3. Not every error is retryable, and check what “no filter” actually means. Retries are meant for transient failures. Retrying a deterministic error like a duplicate key, a validation failure or a 400 can never succeed, it just multiplies the cost of failing. And always know your retry library’s default. In more than one of them, an empty match list means “retry everything”, not “retry nothing”. The safe posture is an explicit allowlist of transient errors, deny by default.

4. A findOrCreate race is normal, handle it by reading, not by rewriting. The unique constraint is doing its job when it rejects the second insert. The right response is to go and fetch the row that the winner created, which most ORMs already do for you.

5. Watch what you hold across an await. The event loop being free does not mean nothing is blocked. A connection, a lock, or a transaction that is pinned for 8 seconds is a scalability bug even when your CPU usage looks perfectly fine.

The final diff was one line. Finding which line took a lot longer, and honestly that is almost always the shape of a good debugging story.