Skip to content

Carry the request id from the dispatching request into the worker - #283

Merged
haksungjang merged 2 commits into
mainfrom
feat/celery-request-id-propagation
Sep 2, 2026
Merged

Carry the request id from the dispatching request into the worker#283
haksungjang merged 2 commits into
mainfrom
feat/celery-request-id-propagation

Conversation

@haksungjang

Copy link
Copy Markdown
Contributor

First half of the observability groundwork (O1). The signal handlers this adds are also where O4 will write its task-run rows, which is why the two were sequenced together: this way the handlers get written once.

The gap

A scan starts as an HTTP request and finishes minutes later inside a worker. The middleware binds request_id for the request, but apply_async sends only the task arguments, so every line the worker logs belongs to no request at all. Tracing a scan back to the request that started it meant guessing from timestamps.

The fix

Three Celery signals, no call site touched:

Signal Process What it does
before_task_publish dispatcher copies request_id onto the message headers while the request context still exists
task_prerun worker reads it back and binds it with task_name and celery_task_id
task_postrun worker clears exactly those three

The clear matters as much as the bind. Worker slots are reused, so an id left behind attaches itself to the next task and misattributes its logs to an unrelated request, while looking perfectly valid. There is a test for precisely that.

Handling this at signal level rather than per task is what makes the coverage complete: 24 task modules bind context by hand today, each a different subset, and 10 bind nothing. Tasks that beat dispatches have no request behind them and get no request_id. That absence is meaningful, so it is not filled with a substitute.

What is deliberately not done

Task-owned context stays where it is. scan_id, dry_run and friends belong to the task, which binds and unbinds them itself; the handlers clear only their own keys. Removing the manual binds mechanically would drop scan_id from scan logs, which would make this change reduce correlation rather than add it.

The two duplicated keys (task_name, task_id) now have both paths writing them. bind_contextvars lets the later call win, so the task's value survives, and the values agree. Cleaning that duplication up is tidying, not correctness, and belongs in its own change.

Handlers never raise

Each one swallows its own errors and logs a warning. Losing a context field is a degradation; failing a scan because logging broke is an outage. Three tests drive that path directly.

Docs

The contributor guide claimed worker logs already carried request_id. That was not true until this change. The entry now says where the propagation happens, and that a beat task legitimately has none. EN and KO both.

Verification

15 new tests, full backend unit suite green (5798 passed; the 28 errors are the DB-backed tests, which need a local instance and are unaffected by this change), ruff check clean, mypy clean across 818 files.

Signals are connected with explicit connect() calls rather than the @signal.connect decorator: Celery ships no types for those decorators, so decorating erases the annotations and mypy stops checking the bodies.

A scan starts as an HTTP request and finishes minutes later inside a worker.
Those two halves could not be joined up in the logs: the middleware binds
request_id for the request, but apply_async sends only the task arguments, so
every line the worker emitted belonged to no request. Tracing a scan back to
the request that started it meant guessing from timestamps.

Three Celery signals close the gap without touching a call site.
before_task_publish copies request_id onto the message while the dispatching
context still exists; task_prerun reads it back in the worker and binds it
with the task name and the Celery task id; task_postrun clears exactly those
three. The clear matters as much as the bind: worker slots are reused, and an
id left behind would attach itself to the next task and misattribute its logs
to an unrelated request while looking perfectly valid.

Handling this at signal level rather than per task is what makes the coverage
complete. Twenty-four task modules bind context by hand today and each binds a
different subset; ten bind nothing at all. Tasks beat dispatches have no
request behind them and get no request_id, which is a meaningful absence
rather than a gap to fill with a substitute.

The handlers swallow their own errors. Losing a context field is a
degradation; failing a scan because logging broke is an outage.

Task-owned context (scan_id, dry_run) is untouched. Those belong to the task,
which binds and unbinds them itself, and the handlers clear only their own
keys so nothing is dropped mid-flight.

The contributor guide claimed worker logs already carried request_id. That
was not true until now; it is now, and the entry says where the propagation
happens and why a beat task has no id.
The handler wrote celery_task_id while twelve task modules bind task_id for
the same value. Both paths run on the same task, so every scan log line would
have carried the Celery task id twice under two names, and a reader would
have had to know which one to filter on.

Using the existing names means the handler writes the same field the task
does. Where both run the values agree and the task's later bind wins, so the
duplication disappears instead of being introduced. task_name was already
aligned; task_id is now too.

The doc entry gains the numbers behind the change: 22 modules bound task_name
and 12 bound task_id, which is why the ten that bound neither had no way to
say what had run.
@haksungjang
haksungjang merged commit 32537dc into main Sep 2, 2026
30 checks passed
@haksungjang
haksungjang deleted the feat/celery-request-id-propagation branch September 2, 2026 21:47
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant