In ClickHouse, where do you look up how long a finished query ran and how much it read?
answer
- the server already logged that query
- a system table, one row per query event
- rows are buffered before they become visible
- you want the finish row, not the start row
- read_rows and query_duration_ms live there
basics
~20 sThe system.query_log table holds one row per query event, with query_duration_ms, read_rows, read_bytes and memory_usage. Filter on type = 'QueryFinish', and run SYSTEM FLUSH LOGS first because entries are buffered for a few seconds before they appear.
solid answer
~40 sClickHouse records every query in `system.query_log`, normally two rows per query: a `QueryStart` row and a terminal row that is `QueryFinish` on success or `ExceptionWhileProcessing` on failure. The terminal row carries the numbers you want — `query_duration_ms`, `read_rows` and `read_bytes` (what the storage layer actually delivered after pruning), `result_rows`, `memory_usage`, the `query` text and the `ProfileEvents` map of low-level counters. Because log rows sit in an in-memory buffer that flushes on a timer, a query you ran a second ago may not be there yet; `SYSTEM FLUSH LOGS` forces it out. For queries running *right now* you look at `system.processes` instead, which is also where you get the `query_id` to pass to `KILL QUERY`.
go deeper
Know the table name and the two or three columns: system.query_log, query_duration_ms, read_rows. Be ready to write the top-10-slowest query and to remember SYSTEM FLUSH LOGS.
Explain the row-per-event model — QueryStart plus QueryFinish or an exception row — and why read_rows differs from result_rows. Know that ProfileEvents is a map you index by counter name.
Use the log as a diagnosis tool: sort by read_bytes to find the expensive workloads, check the Settings map to see what the query actually ran with, and separate initial queries from shard sub-queries before quoting numbers.
Treat query_log as the workload telemetry the platform is built on — set retention and TTL deliberately, decide whether per-thread logging is worth its overhead, and drive capacity and cost conversations from aggregated log data rather than anecdotes.
## What system.query_log is ClickHouse writes a row into `system.query_log` for every query the server runs, as long as the `log_queries` setting is enabled — it is by default. Each query normally produces **two** rows: one when execution starts (`type = 'QueryStart'`) and one when it ends. The terminal row is `'QueryFinish'` if the query succeeded and `'ExceptionWhileProcessing'` if it failed partway through. A query rejected before it ever ran — a parse error, an unknown table, a limit tripped during analysis — produces a single `'ExceptionBeforeStart'` row and no start row. The log is itself an ordinary MergeTree table in the `system` database, so you query it with normal SQL. It is usually configured with a TTL, which is why last quarter's queries are no longer there. ## The columns that matter - `event_time`, `event_date` — when the row was written; `event_date` is the partition key, so always filter on it. - `query`, `query_id` — the text and the server-assigned identifier. - `query_duration_ms` — wall-clock duration of the query on this server. - `read_rows`, `read_bytes` — how much the storage layer actually handed to the query **after** parts and granules were skipped. This is the single most diagnostic pair: a query that reads four billion rows to return ten is a data-skipping problem, not a CPU problem. - `result_rows`, `result_bytes` — what was sent back to the client. The gap between `read_rows` and `result_rows` is the work the engine did on your behalf. - `memory_usage` — peak memory the query held on this server. - `ProfileEvents` — a `Map(String, UInt64)` of internal counters, read with `ProfileEvents['SelectedMarks']` and friends: `SelectedParts`, `SelectedRanges`, `SelectedMarks` tell you how much of the table survived pruning; the time counters tell you where the wall clock went. - `Settings` — a map of the settings that were in effect for that query, which is how you prove that someone ran it with a different `max_threads` than you did. - `exception`, `exception_code` — populated on the failure rows. - `user`, `is_initial_query`, `initial_query_id` — identity and cluster lineage. ## Flushing: why your query is not there yet Log rows are buffered in memory and written out on a timer (a few seconds by default) or when the buffer fills. So immediately after running something, `system.query_log` may legitimately return nothing for it. `SYSTEM FLUSH LOGS` pushes the buffers to disk synchronously. Concluding "query logging must be disabled" without flushing first is the classic beginner mistake. ## Finding the slow ones A top-N by duration for today, restricted to finished queries, is the standard opening move: ```sql SELECT query_duration_ms, read_rows, formatReadableSize(read_bytes) AS read, result_rows, memory_usage, query FROM system.query_log WHERE event_date = today() AND type = 'QueryFinish' ORDER BY query_duration_ms DESC LIMIT 10; ``` Sorting by `read_bytes` instead often finds the more interesting problem: queries that are not the slowest but are burning the most I/O, which on a shared cluster is what actually hurts everyone else. ## Running queries are somewhere else `system.query_log` only knows about queries that have started or ended. For what is executing at this instant — elapsed time so far, memory currently held, progress — you read `system.processes`, and you use the `query_id` from it to cancel with `KILL QUERY WHERE query_id = '...'`. ## The cluster caveat On a sharded cluster a single user query produces log rows on several servers: one on the node that received it, plus one per shard for the sub-query it forwarded. The row for the query the user actually submitted has `is_initial_query = 1`; the shard rows share its `initial_query_id`. Counting every row as a distinct user query inflates your traffic numbers by the shard count. ## Related logs There are sibling tables for finer detail: `system.query_thread_log` (per-thread, off by default), `system.trace_log` (sampling profiler stacks), `system.part_log` (merges and part lifecycle) and `system.text_log` (server log lines). Start at `query_log`; descend only when it does not answer the question.
- On a sharded cluster, how do you tell the user's query apart from the shard sub-queries it spawned?The row on the node that received the query has `is_initial_query = 1`. Every shard sub-query it forwarded writes its own row on its own server, sharing the same `initial_query_id` but with `is_initial_query = 0`. Filter on `is_initial_query = 1` when you are counting user traffic, and join on `initial_query_id` when you want to see what each shard actually did.
- Where do you look for a query that is still running, and how do you stop it?`system.processes` lists in-flight queries with elapsed time, current memory usage and read progress. Take the `query_id` from there and run `KILL QUERY WHERE query_id = '...'`. Note that killing is cooperative — the query stops at the next cancellation check, so a query stuck in a single long operation may take a moment to disappear.
- Which columns tell you whether a slow query is slow because of pruning rather than computation?Compare `read_rows` against `result_rows`, and look at `ProfileEvents['SelectedParts']` and `ProfileEvents['SelectedMarks']`. If the query read most of the table's marks to return a handful of rows, the primary key or partition key did not eliminate anything, and no amount of extra CPU will fix it.
saying these in an interview costs you the question
- Says you must re-run the query with a stopwatch to time it
- Thinks system.processes retains finished queries
- Concludes logging is off without running SYSTEM FLUSH LOGS
- Reads read_rows as the number of rows returned to the client
- Counts each shard's log row as a separate user query