Sampling query profiler

ClickHouse runs a sampling profiler that allows analyzing query execution. Using the profiler, you can find the source code routines that are used the most frequently during query execution. You can trace CPU time and wall-clock time spent including idle time. The query profiler is automatically enabled in ClickHouse Cloud. The following example query finds the most frequent stack traces for a profiled query, with resolved function names and source locations. By default, the profiler symbolizes stack traces at collection time and stores the results in the symbols and lines columns of system.trace_log, so the examples below read those columns directly and do not require introspection functions. Symbolization is controlled by the symbolize setting in the trace_log server configuration section (enabled by default) and is supported on ELF platforms (such as Linux) and macOS; on FreeBSD the symbols and lines columns are always empty. Function names in symbols come from the binary’s symbol table and are available by default. Source locations in lines are best-effort: they require debug info (on macOS, a .dSYM bundle next to the binary), and on ELF platforms only frames inside the main ClickHouse binary are resolved, so entries for frames that cannot be resolved (for example, in shared libraries) are left empty. If symbolization is disabled, use the addressToSymbol, demangle and addressToLine introspection functions to resolve the raw addresses in the trace column instead. These functions are available on the same platforms as symbolization (ELF platforms such as Linux, and macOS); on FreeBSD they are not compiled in either, so the addresses in trace have to be resolved outside the server.

Replace the query_id value with the ID of the query you want to profile.

ClickHouse Cloud
Self-managed

In ClickHouse Cloud, you can obtain the query ID by clicking ”…” on the far right of the bar above the query result table (next to the table/chart toggle). This opens a context menu where you can click “Copy query ID”.Use clusterAllReplicas(default, system.trace_log) to select from all nodes of the cluster:

SELECT
    count(),
    arrayStringConcat(arrayMap((symbol, line) -> concat(symbol, '\n    ', line), any(symbols), any(lines)), '\n') AS sym
FROM clusterAllReplicas(default, system.trace_log)
WHERE query_id = '<query_id>' AND trace_type = 'CPU' AND event_date = today()
GROUP BY trace
ORDER BY count() DESC
LIMIT 10

SELECT
    count(),
    arrayStringConcat(arrayMap((symbol, line) -> concat(symbol, '\n    ', line), any(symbols), any(lines)), '\n') AS sym
FROM system.trace_log
WHERE query_id = '<query_id>' AND trace_type = 'CPU' AND event_date = today()
GROUP BY trace
ORDER BY count() DESC
LIMIT 10

Using the query profiler in self-managed deployments

In self-managed deployments, to use the query profiler follow the steps below:

Install ClickHouse with debug info

Install the clickhouse-common-static-dbg package:

Follow the instructions in step “Set up the Debian repository”
Run sudo apt-get install clickhouse-server clickhouse-client clickhouse-common-static-dbg to install ClickHouse compiled binary files with debug info
Run sudo service clickhouse-server start to start the server
Run clickhouse-client. The debug symbols from clickhouse-common-static-dbg will automatically be picked up by the server - you don’t need to do anything special to enable them

Check server config

Ensure that the trace_log section of your server configuration file is set up. It is enabled by default:

<!-- Trace log. Stores stack traces collected by query profilers.
     See query_profiler_real_time_period_ns and query_profiler_cpu_time_period_ns settings. -->
<trace_log>
    <database>system</database>
    <table>trace_log</table>

    <partition_by>toYYYYMM(event_date)</partition_by>
    <flush_interval_milliseconds>7500</flush_interval_milliseconds>
    <max_size_rows>1048576</max_size_rows>
    <reserved_size_rows>8192</reserved_size_rows>
    <buffer_size_rows_flush_threshold>524288</buffer_size_rows_flush_threshold>
    <!-- Indication whether logs should be dumped to the disk in case of a crash -->
    <flush_on_crash>false</flush_on_crash>
    <symbolize>true</symbolize>
</trace_log>

This section configures the trace_log system table containing the results of the profiler functioning. The symbolize option (enabled by default) makes ClickHouse resolve each stack frame at collection time and store the demangled function names and source locations in the symbols and lines columns. Function names in symbols come from the symbol table and are available by default, while source locations in lines require debug info (a .dSYM bundle on macOS) and, on ELF platforms, are resolved only for frames inside the main ClickHouse binary; unresolved frames have empty lines entries.Note that the raw addresses in the trace column are less stable across restarts and upgrades than the pre-symbolized columns. On ELF platforms except FreeBSD, frames in the main ClickHouse binary are stored as physical file offsets, so they stay resolvable across restarts as long as the binary is unchanged; on macOS and FreeBSD they are stored as runtime virtual addresses that may become invalid after a restart. Frames outside the main binary (for example, in shared libraries) are always stored as runtime virtual addresses that may become invalid after a restart, and any raw address becomes unresolvable after a binary upgrade because the code layout changes. ClickHouse does not clean up the table on restart, so stale raw addresses can remain. The pre-symbolized symbols and lines columns, on the other hand, remain valid across restarts and upgrades, so prefer them when analyzing historical data.

Configure profile timers

Set up the query_profiler_cpu_time_period_ns or query_profiler_real_time_period_ns settings. Both settings can be used simultaneously.These settings allow you to configure profiler timers. As these are the session settings, you can get different sampling frequency for the whole server, individual users or user profiles, for your interactive session, and for each individual query.The default sampling frequency is one sample per second, and both CPU and real timers are enabled. This frequency allows you to collect sufficient information about your ClickHouse cluster whilst not affecting your server’s performance. If you need to profile each individual query, use a higher sampling frequency.

Analyze the trace_log system table

To get a profile for some query, you need to aggregate data from the trace_log table. You can aggregate data by individual functions or by the whole stack traces.When symbolization is enabled (the default), the demangled function names and source locations are already available in the symbols and lines columns, so no additional setup is required. Symbolization is not supported on FreeBSD, where these columns are always empty. lines entries may be empty for frames that lack debug info or fall outside the main ClickHouse binary (see above).If symbolization is disabled, or you want to resolve the raw addresses in the trace column on the fly (for example, to expand inline frames), allow introspection functions with the allow_introspection_functions setting:

SET allow_introspection_functions=1

For security reasons, introspection functions are disabled by default

Use the addressToLine, addressToLineWithInlines, addressToSymbol and demangle introspection functions to get function names and their positions in ClickHouse code. Like symbolization, these functions are available on ELF platforms (such as Linux) and macOS, but not on FreeBSD.

If you need to visualize trace_log info, try flamegraph and speedscope.

Building flame graphs with the `flameGraph` function

ClickHouse provides the flameGraph aggregate function which builds a flame graph directly from stack traces stored in trace_log. The output is an array of strings in a format compatible with flamegraph.pl. Syntax:

flameGraph(traces, [size = 1], [ptr = 0])

Arguments:

traces — a stacktrace. Array(UInt64).
size — an allocation size for memory profiling. Int64.
ptr — an allocation address. UInt64.

When ptr is non-zero, flameGraph maps allocations (size > 0) and deallocations (size < 0) with the same size and pointer. Only allocations that were not freed are shown. Unmatched deallocations are ignored.

CPU flame graph

The queries below require you to have flamegraph.pl installed.You can do so by running:

git clone https://github.com/brendangregg/FlameGraph
# Then use it as:
# ~/FlameGraph/flamegraph.pl

Replace flamegraph.pl in the following queries with the path where flamegraph.pl is located on your machine

SET query_profiler_cpu_time_period_ns = 10000000;

Run your query, then build the flame graph:

clickhouse client --allow_introspection_functions=1 \
    -q "SELECT arrayJoin(flameGraph(arrayReverse(trace)))
        FROM system.trace_log
        WHERE trace_type = 'CPU' AND query_id = '<query_id>'" \
    | flamegraph.pl > flame_cpu.svg

Memory flame graph — all allocations

SET memory_profiler_sample_probability = 1, max_untracked_memory = 1;

Run your query, then build the flame graph:

clickhouse client --allow_introspection_functions=1 \
    -q "SELECT arrayJoin(flameGraph(trace, size))
        FROM system.trace_log
        WHERE trace_type = 'MemorySample' AND query_id = '<query_id>'" \
    | flamegraph.pl --countname=bytes --color=mem > flame_mem.svg

Memory flame graph — unfreed allocations

This variant matches allocations against deallocations by pointer and shows only memory that was not freed during the query.

SET memory_profiler_sample_probability = 1, max_untracked_memory = 1,
    use_uncompressed_cache = 1,
    merge_tree_max_rows_to_use_cache = 100000000000,
    merge_tree_max_bytes_to_use_cache = 1000000000000;

Run the following query to build the flame graph:

clickhouse client --allow_introspection_functions=1 \
    -q "SELECT arrayJoin(flameGraph(trace, size, ptr))
        FROM system.trace_log
        WHERE trace_type = 'MemorySample' AND query_id = '<query_id>'" \
    | flamegraph.pl --countname=bytes --color=mem > flame_mem_unfreed.svg

Memory flame graph — active allocations at a point in time

This approach lets you find peak memory usage and visualize what was allocated at that moment.

SET memory_profiler_sample_probability = 1, max_untracked_memory = 1;

Find memory usage over time

SELECT
    event_time,
    formatReadableSize(max(s)) AS m
FROM (
    SELECT
        event_time,
        sum(size) OVER (ORDER BY event_time) AS s
    FROM system.trace_log
    WHERE query_id = '<query_id>' AND trace_type = 'MemorySample'
)
GROUP BY event_time
ORDER BY event_time;

Find the time point with maximum memory usage

SELECT
    argMax(event_time, s),
    max(s)
FROM (
    SELECT
        event_time,
        sum(size) OVER (ORDER BY event_time) AS s
    FROM system.trace_log
    WHERE query_id = '<query_id>' AND trace_type = 'MemorySample'
);

Build a flame graph of active allocations at that time point

clickhouse client --allow_introspection_functions=1 \
    -q "SELECT arrayJoin(flameGraph(trace, size, ptr))
        FROM (
            SELECT * FROM system.trace_log
            WHERE trace_type = 'MemorySample'
              AND query_id = '<query_id>'
              AND event_time <= '<time_point>'
            ORDER BY event_time
        )" \
    | flamegraph.pl --countname=bytes --color=mem > flame_mem_time_point_pos.svg

Build a flame graph of deallocations after that time point (to understand what was freed later)

clickhouse client --allow_introspection_functions=1 \
    -q "SELECT arrayJoin(flameGraph(trace, -size, ptr))
        FROM (
            SELECT * FROM system.trace_log
            WHERE trace_type = 'MemorySample'
              AND query_id = '<query_id>'
              AND event_time > '<time_point>'
            ORDER BY event_time DESC
        )" \
    | flamegraph.pl --countname=bytes --color=mem > flame_mem_time_point_neg.svg

Example

The code snippet below:

Filters trace_log data by a query identifier and the current date.
Reads the pre-symbolized symbols and lines columns to build a report of:
- The names of symbols and corresponding source code functions.
- The source code locations of these functions.
Aggregates by the raw stack trace (the trace column), using the symbolized columns only for display, so that distinct stack traces are never collapsed by best-effort symbolization.

SELECT
    count(),
    arrayStringConcat(arrayMap((symbol, line) -> concat(symbol, '\n    ', line), any(symbols), any(lines)), '\n') AS sym
FROM system.trace_log
WHERE (query_id = '<query_id>') AND (event_date = today())
GROUP BY trace
ORDER BY count() DESC
LIMIT 10

Fundamentals

ClickHouse concepts

Best practices

Using the query profiler in self-managed deployments

Building flame graphs with the `flameGraph` function

CPU flame graph

Memory flame graph — all allocations

Memory flame graph — unfreed allocations

Memory flame graph — active allocations at a point in time

Find memory usage over time

Find the time point with maximum memory usage

Build a flame graph of active allocations at that time point

Build a flame graph of deallocations after that time point (to understand what was freed later)

Example

​Using the query profiler in self-managed deployments

​Building flame graphs with the flameGraph function

​CPU flame graph

​Memory flame graph — all allocations

​Memory flame graph — unfreed allocations

​Memory flame graph — active allocations at a point in time

​Find memory usage over time

​Find the time point with maximum memory usage

​Build a flame graph of active allocations at that time point

​Build a flame graph of deallocations after that time point (to understand what was freed later)

​Example

Using the query profiler in self-managed deployments

Building flame graphs with the `flameGraph` function

CPU flame graph

Memory flame graph — all allocations

Memory flame graph — unfreed allocations

Memory flame graph — active allocations at a point in time

Find memory usage over time

Find the time point with maximum memory usage

Build a flame graph of active allocations at that time point

Build a flame graph of deallocations after that time point (to understand what was freed later)

Example