DEV Community

jidonglab
jidonglab

Posted on

Celery visibility_timeout Ran My Claude Jobs 3.3x: 1,800 Became 5,913

My Postgres table said 1,800. My Claude usage graph said I had paid for something closer to 6,000.

Both numbers were correct, and the database was the one hiding the problem. Every night I summarize 1,800 support tickets with Claude through a Celery queue on Redis. The summaries were fine, there was exactly one row per ticket, and nothing errored. But the Celery visibility_timeout on my Redis broker was quietly re-running most of those tasks, some of them six times, and my upsert erased the evidence every time.

This is the autopsy.

TL;DR

  • On Redis (and SQS), Celery redelivers any message that isn't acknowledged within visibility_timeout, which defaults to 1 hour.
  • Tasks scheduled with countdown or eta sit in a worker's memory unacknowledged until they run. If the wait is longer than an hour, the message goes back on the queue and another worker grabs a second copy. Then a third. It repeats every hour.
  • I spread 1,800 tasks over 6 hours with countdown=i * 12. Result: 5,913 Claude calls, 3.3x what I needed, and 1,500 of 1,800 task IDs ran more than once.
  • Fix: stop using multi-hour countdowns for rate limiting, feed the queue just-in-time instead, and add an idempotency key, because Celery on Redis is at-least-once no matter what you configure.
  • After the fix: 1,800 tickets, 1,803 calls. The 3 extras were real retries.

The setup that looked responsible

I didn't want to hammer the API with 1,800 requests at midnight, so I did what felt like the polite thing. Spread them out:

for i, ticket_id in enumerate(ticket_ids):
    summarize_ticket.apply_async((ticket_id,), countdown=i * 12)
Enter fullscreen mode Exit fullscreen mode

One task every 12 seconds. 1,800 tasks times 12 seconds is 21,600 seconds, so the last task was scheduled 6 hours out. Four workers, default settings.

The task itself was boring:

@app.task(bind=True, max_retries=5)
def summarize_ticket(self, ticket_id):
    ticket = load_ticket(ticket_id)
    msg = client.messages.create(
        model=MODEL,
        max_tokens=600,
        messages=[{"role": "user", "content": build_prompt(ticket)}],
    )
    upsert_summary(ticket_id, msg.content[0].text)
Enter fullscreen mode Exit fullscreen mode

Note the upsert. That word cost me weeks of not noticing.

Why does Celery run the same task twice on Redis?

Celery runs a task twice on Redis when the message stays unacknowledged longer than visibility_timeout. Redis has no native "this message is checked out" concept, so kombu (Celery's transport layer) fakes one: when a worker reserves a message, it's copied into an unacked set with a timestamp. Any client that later checks that set and finds an entry older than visibility_timeout pushes it back onto the queue.

That's a reasonable design for crash recovery. If a worker dies mid-task, someone else picks the job up an hour later.

The trap is what "unacknowledged" means. With default early acks, Celery acknowledges a task when it starts executing. A task with countdown=18000 gets reserved immediately and then sits in the worker's memory for five hours, unacknowledged the whole time. To the broker, it looks exactly like a crashed worker.

So after one hour the message is restored. Another worker reserves it, also holds it until the ETA, and that copy also times out after an hour. The original worker never lets go of its copy either. Each hour of waiting adds one more copy. When the ETA finally arrives, every copy fires at roughly the same moment.

The Celery docs do warn about this for ETA, countdown and retry tasks. I had read those docs. I had not connected "retry tasks" to "my rate-limiting loop".

How I found the duplicates

The bill was the only symptom, so I added one log line at the top of the task:

log.info("run task_id=%s ticket=%s host=%s",
         self.request.id, ticket_id, self.request.hostname)
Enter fullscreen mode Exit fullscreen mode

Redelivered copies keep the same task ID, which makes this easy to count:

grep 'run task_id=' worker-*.log \
  | sed -E 's/.*task_id=([^ ]+).*/\1/' \
  | sort | uniq -c | awk '{print $1}' | sort -n | uniq -c
Enter fullscreen mode Exit fullscreen mode

One night's output, grouped by how many times each task ran:

Countdown window Tasks Predicted runs each Measured avg runs
0 to 1 h 300 1 1.00
1 to 2 h 300 2 1.98
2 to 3 h 300 3 2.91
3 to 4 h 300 4 3.80
4 to 5 h 300 5 4.66
5 to 6 h 300 6 5.36
Total 1,800 6,300 5,913

The first 300 tasks were clean. Every task scheduled past the one-hour mark was duplicated, and the duplication scaled almost perfectly with how long it waited.

Honest caveat: measured runs come in under the prediction, and the gap grows with the wait. My best explanation is that the restore check runs on a polling interval rather than the exact second a message crosses the hour, so long-waiting tasks lose a few loop iterations to timing. I didn't dig into kombu deeply enough to prove that.

Why didn't anything break?

Nothing broke because the task was accidentally idempotent at the database layer, and expensive everywhere else. Six copies of the same ticket each called Claude, each got a slightly different summary, and each upserted over the previous one. Last writer wins. One row. Green dashboard.

There was one more clue I'd been ignoring. Duplicates all fire at the same ETA, on different workers, so my nice smooth 12-second spacing turned into bursts of up to six simultaneous requests. Rate-limit errors went from about 4 a night to 212. Those retries used countdown too, which meant some of them were also eligible for the redelivery loop. I had built a small machine for generating API calls.

How do you fix the Celery visibility_timeout problem?

The fix is three changes, and only the last one is mandatory.

1. Raise visibility_timeout above your longest ETA (the quick patch).

app.conf.broker_transport_options = {"visibility_timeout": 8 * 3600}
Enter fullscreen mode Exit fullscreen mode

This works, but the cost is real: if a worker actually crashes, its tasks now wait 8 hours before anyone retries them. Set it on every worker and on the producer too, since the restore check runs with whatever value the checking client has. One stale config and you're back to an hour.

2. Stop using long countdowns as a rate limiter (the real design fix).

Instead of scheduling 1,800 tasks six hours ahead, I now enqueue work just before it's needed. A beat task runs every minute and pushes the next five tickets:

@app.task
def feed_queue():
    for ticket_id in claim_next_batch(limit=5):  # SELECT ... FOR UPDATE SKIP LOCKED
        summarize_ticket.delay(ticket_id)

app.conf.beat_schedule = {
    "feed-summaries": {"task": "tasks.feed_queue", "schedule": 60.0},
}
Enter fullscreen mode Exit fullscreen mode

Five per minute over 1,800 tickets is still 6 hours, same pacing as before. But no message waits longer than a minute, so nothing gets near the timeout.

3. Make the expensive call idempotent (the fix you need anyway).

Celery on Redis is at-least-once delivery. Even with perfect config, a worker restart or network blip can hand you a duplicate. So the Claude call is now guarded:

@app.task(bind=True, max_retries=5)
def summarize_ticket(self, ticket_id):
    key = f"summarized:{ticket_id}:{run_date()}"
    if not r.set(key, self.request.id, nx=True, ex=86400):
        log.info("skip duplicate ticket=%s", ticket_id)
        return
    try:
        ticket = load_ticket(ticket_id)
        msg = client.messages.create(...)
        upsert_summary(ticket_id, msg.content[0].text)
    except Exception as exc:
        r.delete(key)  # let the real retry through
        raise self.retry(exc=exc, countdown=30)
Enter fullscreen mode Exit fullscreen mode

The r.delete on failure matters. Without it, a task that fails once would block its own retry and you'd silently drop tickets instead of duplicating them. Trading one silent bug for another is not a fix.

What happened after the fix?

The first night after deploying all three changes: 1,800 tickets, 1,803 Claude calls. The 3 extras were genuine retries after overloaded responses. The skip log fired 0 times, which tells me the feeder pattern removed the cause and the idempotency key is now just insurance. Rate-limit errors dropped back to single digits.

Rough math on what I'd been paying for: 4,113 wasted calls a night, at about 2,000 input tokens per ticket. That's around 8 million tokens a night spent producing summaries that were immediately overwritten.

Does this happen with RabbitMQ too?

Not in the same form. RabbitMQ tracks acknowledgements natively, so there's no visibility timeout loop. It has its own trap instead: a consumer acknowledgement timeout that closes the channel if a delivery stays unacked too long, which long ETA tasks can also hit. Different symptom, same root cause. Long-held unacked messages are a bad idea on every broker.

The lessons I'm keeping

  • countdown is for "retry in 30 seconds", not "run in 5 hours".
  • An upsert hides duplicates. Log the task ID at the top of every task that costs money.
  • Your bill is a monitoring system. Mine was the only one that noticed.
  • At-least-once means at-least-once. Put the idempotency check right next to the expensive call, not in the database at the end.

So why did Celery run my Claude jobs 3.3x?

Because Celery's Redis transport redelivers any message that stays unacknowledged longer than visibility_timeout (1 hour by default), and countdown/eta tasks stay unacknowledged until they start running. My 1,800 tasks were scheduled up to 6 hours out, so each one picked up roughly one extra copy per hour of waiting, producing 5,913 Claude calls. Raising visibility_timeout patches it, feeding the queue just-in-time removes the cause, and an idempotency key around the API call protects you from the duplicates that at-least-once delivery will always produce.


Written by the developer behind Preterview, an interview prep platform.

Top comments (0)