Skip to content

feat(hotblocks): count and log query tasks that hold a worker for long - #117

Merged
mo4islona merged 1 commit into
masterfrom
feat/slow-query-task-log
Oct 16, 2026
Merged

mo4islona merged 1 commit into
masterfrom
feat/slow-query-task-log

Conversation

@mo4islona

@mo4islona mo4islona commented Oct 15, 2026 •

Copy link
Copy Markdown
Contributor

The query task histograms show that tasks wait in the query pool's queue behind other tasks. They do not show which queries hold the workers. This PR answers that question.

What it adds

  • hotblocks_query_slow_tasks_total{dataset_name, client_id, step} counts each task that holds a query pool worker longer than the slow-task threshold.
  • A WARN line for a slow task carries:
    • the dataset, the client and the step;
    • the own time and the nested time of the task;
    • the chunks, blocks and buffered bytes the task read or produced;
    • the client's query, truncated to 16 KiB.
  • The worker reports the task after it ends and before it wakes the caller. So a task that fails and a task whose client disconnects are also reported.

Log volume

Log lines are rate-limited the same way as the shadow logs: at most one line per query shape (the query without its block range), up to --slow-task-log-limit lines per 5 minutes. The counter is not limited.

Nested time

A rayon worker that waits for its task's parallel work can take another queued task in the meantime (find_work also pops injected jobs). Without a correction, a light task could show the time of a heavy task that ran inside it. The executor now subtracts the time of tasks nested on the same worker, and the threshold applies to the remaining own time. Tasks nested on other workers are not seen.

Settings

Flag Default Runtime setting
--slow-task-threshold-ms 500 PATCH /settings {"slowTasks": {"thresholdMs": …}}
--slow-task-log-limit 20 PATCH /settings {"slowTasks": {"logLimit": …}}

A runtime change lasts until a restart, the same as the shadow settings. A log limit of 0 turns the log lines off.

Refactor

The shadow's log window, query fingerprint and query truncation moved to log_window.rs, so that both logs share them.

Tests

  • Unit tests: the log window limit, a fingerprint that ignores the block range, and nested time that does not make a task slow.
  • An integration test that runs from the flag, through PATCH /settings, to the counter.
  • A failed first task is counted, and a task is reported after its caller is dropped.

🤖 Generated with Claude Code

@mo4islona
mo4islona force-pushed the feat/slow-query-task-log branch from a721172 to 827107b Compare October 15, 2026 14:36
The queue histograms show that tasks wait behind other tasks, not which
queries they wait behind. A slow task is now counted by dataset, client and
step, and logged with its query at most once per query shape and up to a
limit per five minutes. A worker that waits for its task's parallel work can
run another queued task meanwhile, so that nested time is not held against
the outer task. The worker reports the task, not the caller, so a task that
fails or whose client disconnects is reported too.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
@mo4islona
mo4islona force-pushed the feat/slow-query-task-log branch from 827107b to 8658841 Compare October 15, 2026 14:38
@mo4islona
mo4islona merged commit 9e8395d into master Oct 16, 2026
3 checks passed
@mo4islona
mo4islona deleted the feat/slow-query-task-log branch October 16, 2026 00:49
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