Half our background jobs had a deadline nobody chose
A command-line default in our container image was quietly capping every background task at 120 seconds, including batches that make dozens of model calls. Fixing the number was the easy half. The hard half was teaching the jobs how to die.
- Category
- General
- Updated
- Author
- Stan Kharlap
A function call either returns or raises. You can reason about it. A model call does neither reliably: it returns, eventually, in a time drawn from a distribution with a long and genuinely ugly tail. Put one inside a loop that runs over a user's uploaded batch and you have not written a function any more. You have written a bet.
We ran that bet at scale for a while without noticing. Norman does bookkeeping and tax filing for German businesses, which in practice means a lot of unglamorous background work: read a receipt, assign a category, reconcile a payment, sweep a queryset, prepare a filing. Close to a million transactions and around 40,000 new documents a month move through it. Most of that work happens in a queue, and a surprising amount of it calls a language model somewhere in the middle.
Here is what the model calls actually look like in production, measured over the last month of agent steps: well over a hundred thousand of them, median around five and a half seconds, p99 around 35 seconds, and the slowest single call we have on record ran for nearly eleven minutes. The deterministic tool calls in the same runs have a median in the tens of milliseconds. Two orders of magnitude apart, in the same code path, with the slow one being the part you cannot bound.
Now the punchline. Every background task that did not explicitly declare otherwise was running on a 120-second soft budget.
Nobody set it, which is why nobody questioned it
The budget did not come from a design discussion. It came from a container image. Our worker entrypoint started five Celery masters, one per queue, and each command line ended with something like --soft-time-limit ${SOFT_TIME_LIMIT:-120}. No environment ever set SOFT_TIME_LIMIT. So the fallback won, everywhere, forever.
The part worth internalising is why nobody caught it in code review. Roughly half of our hundred-odd tasks do declare their own limits in the decorator, and those looked fine. The other half looked fine too, because a task with no limit reads as "no limit." That is not what it means. Celery resolves the effective budget through the worker's pool defaults, and a command-line flag beats application config unconditionally. So task_soft_time_limit in our settings module was not the source of truth, and reading the settings module told you a comfortable lie.
The tasks that inherited that 120 seconds included whole-queryset sweeps and bulk OCR loops. One of them accepts up to 95 files in a single job, runs OCR plus a model pass on each, and had less total time than a single worst-case model call.
The fix itself is three lines and a deleted flag: drop the flags from the transactional queues, move the numbers into config where they are visible and overridable, and let each task's own decorator still win. We now default to 600 seconds soft, 900 hard. The agent queues keep explicit flags, because their budgets should not be the same as everything else: batch agent work gets a generous soft limit, while the interactive queue that a person is waiting on gets a tight one. A budget is a product decision. It belongs somewhere a reviewer can see it, next to a comment explaining the choice.
The timeout signal is an exception, and your loop already caught it
This is the part I would put on a poster.
Celery's soft time limit works by raising an exception inside your task. In our case that exception inherits directly from Exception. Now consider the shape that basically every batch job in every codebase converges on:
for item in batch:
try:
process(item)
except Exception:
logging.exception("item failed")
job.record_failure(item)
job.status = "completed"
job.save()
That loop is correct about item failures and catastrophically wrong about deadlines. When the soft limit fires, the abort signal is charged to whichever item happened to be in flight, marked as that item's problem, and swallowed. The loop then continues into the next item, and the next, until the hard limit arrives and SIGKILLs the worker process. Which means the code after the loop never runs. The job row never leaves importing. No summary email goes out. The user sees a spinner that will spin until the heat death of the universe.
The evidence was sitting in the database the whole time. Of roughly 8,300 CSV import jobs, a bit under a hundred were stranded in importing, most of them created within the previous month, and on average they had already written a few hundred rows before going quiet. Same pattern for bulk uploads: a handful stuck in processing, none recent enough to still be running. Same pattern again in the agent tables, where a couple of hundred runs from the last month sit in running with no terminal status. Three different subsystems, one bug, written independently by different people, because the shape of the mistake is the shape of ordinary defensive code.
The fix is to stop treating the deadline as a failure of the current item, because it is not one. It is the runtime asking the task to leave:
for i, item in enumerate(batch):
try:
process(item)
except SoftTimeLimitExceeded:
# Not this item's fault. Record how far we got, then get out of the
# way: the hard limit is next, and it does not run cleanup code.
job.set_failed(f"timed out after {i} of {len(batch)} items")
raise
except Exception:
job.record_failure(item)
Two properties matter here. First, the abort is re-raised, so the worker can shut the task down in the window between the soft and hard limits, which is exactly what that window exists for. Second, the job is finalised before re-raising, so the row lands in a terminal state that the UI can render and a human can act on. "Timed out after 340 of 1,772 rows, split the file and retry" is a bad outcome. importing forever is not an outcome at all.
We also had to be careful in the helper functions. If you factor the per-item work into its own function with its own catch-all, the signal gets swallowed one level down and never reaches the loop. Any helper that wraps model work now re-raises the abort explicitly before its general handler.
One bad row is not a reason to abandon the queryset
The mirror image of that bug is the sweep that had no error handling at all.
Several of our scheduled jobs were a bare for invoice in qs.iterator(): with the real work inline. The first row that raised ended the task, and silently abandoned the entire rest of the queryset until the next scheduled run, which would then hit the same poison row and stop again in the same place. Nothing in the logs said "this sweep did not finish," because from Celery's point of view the task raised and that was that.
The production evidence for one of these was stark: a few hundred invoices matched the overdue sweep's own queryset, most of them past due by a month or more, while only a couple of dozen rows actually carried the overdue status. The sweep had been dying early for a long time.
So the sweeps now share one small helper with a deliberately blunt docstring: apply this callable to every row, count what worked and what did not, isolate per-row failures, and log a warning-level summary if anything failed. And, critically, re-raise the time limit, because that one is a reason to stop. The distinction the whole article turns on, in one function: a bad row means keep going, a deadline means get out.
The summary log line matters more than it looks. processed=571 failed=20 at warning level is a metric you can alert on. A silently truncated sweep is not.
Spend the budget on the model, not on the reference table
Once tasks had honest deadlines, the next question was what they were spending them on. Some of it was embarrassing.
Our built-in category table is static reference data: a few dozen leaf rows, changed only by a migration, no per-company dimension, and it fits in about 128 kB. The OCR extractor and the prompt builders were re-reading the whole thing for every single document and every single transaction. On a batch, that is one full sequential scan per row. Cumulatively, the counters showed half a billion lifetime sequential scans and tens of billions of tuples read off that one tiny table.
None of that is slow in the way a slow query is slow. Each scan is sub-millisecond. It is slow in the way a thousand sub-millisecond things inside a per-row loop are slow: invisible in a profile, quite visible in your batch wall-clock. A process-lifetime cache with an lru_cache and a post_save invalidation hook, mirroring a pattern we already used for currency lookups, removed it. Boring, mechanical, and it hands the reclaimed seconds to the part of the pipeline that needs them.
A note on how we measured, because we got it wrong first
An earlier version of that cache's docstring claimed a confident split between request-path and batch load, based on sampling Postgres statistics twice and taking the delta. The number was wrong, and the reason is worth passing on: Postgres 15 defaults stats_fetch_consistency to cache, which freezes the statistics snapshot for the duration of a transaction. Both of our reads happened inside one transaction, so the second returned the first one's numbers, and the delta was noise dressed up as a finding.
Re-sampled correctly, with autocommit on, the same table showed around 990 scans per second in one window and under 40 five minutes later. The load is bursty, and the split we claimed was never established. We withdrew the claim in the docstring rather than quietly deleting it, which is the only version of that I am comfortable with.
If you take one operational habit from this piece, take that one: sample pg_stat_* with autocommit on, or your deltas are fiction.
What a deadline is actually for
The instinct when a job times out is to raise the limit. We did raise the limit, and it was the least interesting thing we did.
A deadline is not an obstacle to route around. It is the mechanism by which unbounded work becomes bounded, and once you accept that a model call is unbounded work, every batch that contains one needs three things: a budget somebody consciously chose and wrote down next to the reason; a documented behaviour for what happens when that budget runs out, which ends with the job in a terminal state a human can see; and per-item isolation so one bad row cannot take the batch with it.
None of that is AI engineering in the way the phrase is usually used. There is no prompt in this article. But it is most of what separates an agent that works in a demo from one that works on 40,000 documents a month, and it is where a genuinely disproportionate share of our reliability work goes. The model is the part that gets the attention. The queue is the part that decides whether anyone trusts the result.
Norman handles the operational finance work behind the scenes
From invoicing to bookkeeping, Norman keeps recurring finance work organized so you can stay on top of deadlines with less manual effort.