Twenty-five queues, one core

At 11:35 on a Thursday morning, a job in our pipeline logged this:

converting pages 41-45 of 234

Then it said nothing for seventy minutes.

Three seconds after that line, two other jobs went quiet. Then a fourth. CPU sat pinned at 100%, a backlog doubled, and the queue that turns company filings into something searchable stopped moving entirely. Nothing crashed. Nothing threw. No alert fired, because from the outside the service looked busy, and busy is what a healthy pipeline looks like.

The strangest part came later, when I read the job logs properly. One job had indexed its document successfully. Six hundred and one chunks, written, done. And it had been marked failed.

Three separate times.

This is the story of why, and of what we changed. It is mostly a story about one thread.

The shape of the thing

The service is a cron worker. It runs about twenty-five queues on BullMQ, backed by Redis, on a single container with four CPUs and 16 GB of memory. Some queues are chatty and small: send an email, track a click, fire a WhatsApp alert. Some are heavy: pull a 234-page annual report, rasterise every page, run it through a model, chunk the text, embed it, store the vectors.

All of them lived in one Node process.

That sentence is the whole bug, but it takes a minute to see why.

Node runs your JavaScript on a single thread. You probably know this. I knew this. But knowing it as a fact and seeing what it does to a queue system at 11:35 on a Thursday are different kinds of knowing.

Because here is the thing nobody tells you: the single thread is not just where your code runs. It is also where the queue library does its bookkeeping.

How a scheduled run actually works

Before the lock makes sense, it is worth being precise about what "a cron job" means here, because the phrase hides four hops.

There is no crontab. The schedule is a repeatable stored in Redis: a cron expression BullMQ persists and fires on its own, which means it survives a deploy and keeps running whether or not anyone remembers it exists.

When it fires, a small prep job wakes up. It does not do the work. It reads what is due, builds a flow — a parent job with children in a defined order — and adds the whole thing in one bulk write. The children land in a queue and wait.

Then a worker picks one up. Which worker depends on the role, and that is where the story goes next.

Two properties of this shape matter for what follows. The children are ordered but independent, so a failure part way through does not stop the rest. And nothing in the chain reports failure upward: a child that writes zero rows and a child that writes five thousand both finish, and the flow says it is done either way.

The lock, and the timer that renews it

When a BullMQ worker picks up a job, it takes a lock on it. The lock says: I have this one, nobody else touch it. The lock has an expiry, five minutes by default, because if a worker dies mid-job you need someone else to eventually pick the work back up.

So the lock has to be renewed while the job is still running. BullMQ does that with a timer, firing every thirty seconds or so, pushing the expiry back out.

A timer is a callback. A callback runs on the event loop. And the event loop is the thread your job is running on.

Read that twice, because it is genuinely strange. The mechanism that proves a job is healthy is the same mechanism the job can starve.

Now, most of the time this is completely fine. Look at what a normal job actually does:

const res = await fetch(url)       // yields
const rows = await prisma.find()   // yields
await redis.set(key, value)        // yields

Every await on real I/O hands the thread back. The renewal timer gets its turn. Lock stays fresh. Twenty-one of our twenty-five queues are like this, all network and database, yielding constantly. They never had a problem.

The PDF renderer is not like this.

The two lines that stopped everything

We rasterise PDF pages with mupdf. The build we use is compiled to WebAssembly, and WASM runs on the same thread as your JavaScript. Two calls, in a loop, once per page:

const pixmap = page.toPixmap(matrix, ColorSpace.DeviceRGB, false)
const png = pixmap.asPNG()

There is no await there, and that is not an oversight. There is nothing to await. It is pure computation: turn this page into pixels, encode those pixels. From the moment you enter toPixmap to the moment asPNG returns, the event loop is not running. No timers fire. No sockets are read. Nothing else gets a turn.

For one page, that is a blip. The loop iterates 234 pages back to back.

So the lock expires. And then BullMQ does exactly what it should do, given what it can see.

Killed for being alive

From the outside, an expired lock means one thing: the worker holding this job is gone. Crashed, killed, network-partitioned. The job is stalled. Recover it.

So BullMQ hands the job to another worker. Which is on the same blocked thread, in the same process, so now there are two copies of a heavy render fighting for a thread that already has none to give. That drives CPU higher, which makes the next lock expire faster, which stalls another job.

That is the feedback loop. It is why five jobs across three queues went silent inside three seconds and stayed silent for seventy minutes.

And it explains the log line that made no sense to me:

failedReason: Missing lock for job stock:920107F2... moveToFinished
progress: 100

progress: 100. The job finished. It embedded all 601 chunks. Then it went to write down that it was done, and the lock it needed was not there any more, because it had been declared dead while it was working. The work was real. The failure was bookkeeping.

It did that three times: 14:35, 14:52, 16:48. Same document, same 601 chunks, indexed correctly, marked failed, retried.

Fix one: stop sharing a core

The first change was the obvious one, and it is worth being clear that obvious is not the same as sufficient.

One process can only ever use one core. We had four. So we split the workers into four processes by role, each owning a slice of the queues:

This worked, and I want to give it its due. During the incident, average CPU was 2.69 of 4 cores: one process pegged, three healthy. Email went out. WhatsApp alerts went out. The nightly jobs ran. The dashboard stayed up, which mattered more than it sounds, because the previous time this happened the dashboard went down with everything else and we were debugging blind for six hours.

It also gave us a property I have come to value a lot: the failure got smaller. Not gone. Smaller, and contained somewhere I could see it.

But look at the diagram again. Eight queues in media, one event loop. Splitting processes isolates workloads from each other. It does nothing for one workload blocking itself. The PDF renderer could still freeze the seven queues sitting next to it, and on 31 August, it did.

Fix two: get the work off the loop entirely

The real fix is to stop doing CPU-heavy work on the thread that owns the lock renewal timer. BullMQ has a built-in answer called sandboxed processors: instead of giving the worker a function, you give it a path to a file. It forks a child process, runs the job there, and talks to it over IPC.

The parent keeps its loop free. It has almost nothing to do but renew locks and wait.

We moved four queues: the PDF renderer, the classifier that also rasterises, the embedder that tokenises 601 chunks synchronously, and the IPO extractor. The other four in media stayed inline, because they are pure network and never block anything.

We also raised the lock from 5 minutes to 30 on those queues. That is belt and braces, deliberately. The fork keeps the loop free; the longer lock absorbs whatever still slips through.

How you know it worked

I want to be specific here, because "it seems better" is not a result.

The signal is the lock's own TTL. Sample a running job every five seconds and watch the number:

healthy   1800s → 1795s → 1790s … jumps back to 1800s every minute
broken     300s →  295s →  290s … never resets, ends at -2

That is the entire bug in six numbers. A healthy job's lock resets, because the renewal timer is getting its turn. A blocked job's lock counts down to zero and past it, because the timer never fires, and then the job dies for a crime it did not commit.

The other measurement is cruder and just as useful. On a 4-CPU box, one core fully used is about 900 CPU-seconds per 15-minute bucket. Before the split we were flat at 833 seconds for six hours straight — a completely saturated single core, and three idle ones. Above 900 means more than one core is actually working.

What I actually took from this

The mechanism that proves health can be starved by the thing it is proving. This is the part I keep thinking about. Our health signal was not independent of the work. Once you see that pattern you start finding it elsewhere: the heartbeat that shares a thread with the request handler, the readiness probe answered by the process that is thrashing.

The scariest failures are the ones that look like success. A job blocking the loop looks identical to a job doing lots of work. There is no exception, no stack trace, no 500. We found this by reading raw job logs out of Redis, not from an alert, because we had not thought to alert on silence.

That lesson landed twice, actually. A separate investigation into the same service found four sub-jobs that had been writing zero rows on every run for at least three days — 5,500 companies, no data written — while logging completed successfully every time. The tally was computed, then the success line was printed unconditionally, and nothing checked whether the number was zero. Wrong numbers reached production and nobody knew, because the pipeline said it was fine.

Containment is worth shipping before the cure. The process split did not fix the block. It was still the right thing to deploy first: it turned a total outage into one degraded subsystem, and it made the remaining bug small enough to actually see.

Read the library's docs about your specific failure. BullMQ documents this exactly — CPU-heavy work keeps the loop busy, which prevents lock extension, which leads to stalled jobs. It was written down the whole time. I got there from logs and metrics first, which took days. The docs would have taken twenty minutes.

Below is the pipeline this all runs, drawn as it works when nothing is on fire: a filing arrives, gets read, gets chunked and embedded, and turns into an answer somebody can act on. All of the above is in service of that clip playing on time.