Sampling query profiler

Documentação da ferramenta Sampling query profiler no ClickHouse

O ClickHouse executa um profiler por amostragem que permite analisar a execução de consultas. Usando o profiler, você pode encontrar as rotinas do código-fonte usadas com mais frequência durante a execução da consulta. Você pode rastrear o tempo de CPU e o tempo de relógio gasto, incluindo o tempo ocioso.

O profiler de consulta é habilitado automaticamente no ClickHouse Cloud. A consulta de exemplo a seguir encontra os stack traces mais frequentes de uma consulta analisada pelo profiler, com nomes de funções resolvidos e localizações no código-fonte:

Substitua o valor de query_id pelo ID da consulta que você quer analisar com o profiler.

ClickHouse Cloud

No ClickHouse Cloud, você pode obter o ID da consulta clicando em ”…” na extremidade direita da barra acima da tabela de resultados da consulta (ao lado do botão de alternância entre tabela/gráfico). Isso abre um menu de contexto no qual você pode clicar em “Copiar ID da consulta”.

Use clusterAllReplicas(default, system.trace_log) para selecionar dados de todos os nós do cluster:

SELECT
    count(),
    arrayStringConcat(arrayMap(x -> concat(demangle(addressToSymbol(x)), '\n    ', addressToLine(x)), trace), '\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
SETTINGS allow_introspection_functions = 1

Autogerenciado

SELECT
    count(),
    arrayStringConcat(arrayMap(x -> concat(demangle(addressToSymbol(x)), '\n    ', addressToLine(x)), trace), '\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
SETTINGS allow_introspection_functions = 1

​

Usando o profiler de consultas em implantações autogerenciadas

Em implantações autogerenciadas, para usar o profiler de consultas, siga as etapas abaixo:

1. ​

   Instale o ClickHouse com informações de depuração

   Instale o pacote clickhouse-common-static-dbg:

   1. Siga as instruções na etapa “Configurar o repositório Debian”
   2. Execute sudo apt-get install clickhouse-server clickhouse-client clickhouse-common-static-dbg para instalar os arquivos binários compilados do ClickHouse com informações de depuração
   3. Execute sudo service clickhouse-server start para iniciar o servidor
   4. Execute clickhouse-client. Os símbolos de depuração de clickhouse-common-static-dbg serão carregados automaticamente pelo servidor — você não precisa fazer nada de especial para habilitá-los
2. ​

   Verifique a configuração do servidor

   Certifique-se de que a seção trace_log do seu arquivo de configuração do servidor esteja configurada. Ela vem habilitada por padrão:

   <!-- Log de rastreamento. Armazena stack traces coletados pelos profilers de consultas.
        Consulte as configurações query_profiler_real_time_period_ns e query_profiler_cpu_time_period_ns. -->
   <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>
       <!-- Indica se os logs devem ser gravados em disco em caso de falha -->
       <flush_on_crash>false</flush_on_crash>
       <symbolize>true</symbolize>
   </trace_log>
   

   Esta seção configura a tabela de sistema trace_log, que contém os resultados do funcionamento do profiler. Lembre-se de que os dados nessa tabela são válidos apenas enquanto o servidor estiver em execução. Após a reinicialização do servidor, o ClickHouse não limpa a tabela, e todos os endereços de memória virtual armazenados podem se tornar inválidos.

3. ​

   Configure os temporizadores do profiler

   Configure as definições query_profiler_cpu_time_period_ns ou query_profiler_real_time_period_ns. Ambas as configurações podem ser usadas simultaneamente.

   Essas configurações permitem ajustar os temporizadores do profiler. Como são configurações de sessão, você pode usar frequências de amostragem diferentes para o servidor inteiro, usuários individuais ou perfis de usuário, para sua sessão interativa e para cada consulta individual.

   A frequência de amostragem padrão é de uma amostra por segundo, e tanto os temporizadores de CPU quanto os de tempo real ficam habilitados. Essa frequência permite coletar informações suficientes sobre seu cluster ClickHouse sem afetar o desempenho do servidor. Se você precisar perfilar cada consulta individualmente, use uma frequência de amostragem mais alta.

4. ​

   Analise a tabela de sistema trace_log

   Para analisar a tabela de sistema trace_log, habilite as funções de introspecção com a configuração allow_introspection_functions:

   SET allow_introspection_functions=1
   

   Por motivos de segurança, as funções de introspecção vêm desabilitadas por padrão

   Use as addressToLine, addressToLineWithInlines, addressToSymbol e demangle funções de introspecção para obter nomes de funções e suas posições no código do ClickHouse. Para obter um perfil de alguma consulta, você precisa agregar dados da tabela trace_log. Você pode agregar os dados por função individual ou pelos stack traces completos.

   Se você precisar visualizar informações de trace_log, experimente flamegraph e speedscope.

​

Criando flame graphs com a função flameGraph

O ClickHouse fornece a função de agregação flameGraph, que cria um flame graph diretamente a partir de stack traces armazenados em trace_log. A saída é um array de strings em formato compatível com flamegraph.pl.

Sintaxe:

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

Argumentos:

• traces — um stack trace. Array(UInt64).
• size — o tamanho de uma alocação para profiling de memória. Int64.
• ptr — um endereço de alocação. UInt64.

Quando ptr é diferente de zero, flameGraph associa alocações (size > 0) e desalocações (size < 0) com o mesmo tamanho e ponteiro. Somente as alocações que não foram liberadas são mostradas. Desalocações sem correspondência são ignoradas.

​

Flame graph da CPU

As consultas abaixo exigem que você tenha o flamegraph.pl instalado.

Para isso, execute:

git clone https://github.com/brendangregg/FlameGraph
# Em seguida, use-o assim:
# ~/FlameGraph/flamegraph.pl

Substitua flamegraph.pl nas consultas a seguir pelo caminho em que flamegraph.pl está localizado na sua máquina

SET query_profiler_cpu_time_period_ns = 10000000;

Execute sua consulta e, em seguida, gere o 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

​

Flame graph de memória — todas as alocações

SET memory_profiler_sample_probability = 1, max_untracked_memory = 1;

Execute a consulta e, em seguida, gere o 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

​

Flame graph de memória — alocações não liberadas

Esta variante cruza alocações com desalocações por ponteiro e mostra apenas a memória que não foi liberada durante a consulta.

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;

Execute a consulta a seguir para gerar o 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

​

Flame graph de memória — alocações ativas em um determinado momento

Essa abordagem permite identificar o uso máximo de memória e visualizar o que foi alocado naquele momento.

SET memory_profiler_sample_probability = 1, max_untracked_memory = 1;

​

Encontre o uso de memória ao longo do tempo

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;

​

Encontre o instante com o maior uso de memória

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'
);

​

Crie um flame graph das alocações ativas naquele momento

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

​

Crie um flame graph de desalocações após esse momento (para entender o que foi liberado posteriormente)

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

​

Exemplo

O trecho de código abaixo:

• Filtra os dados de trace_log por um identificador de consulta e pela data atual.
• Agrupa por stack trace.
• Usa funções de introspecção para gerar um relatório com:
  • Os nomes dos símbolos e as funções correspondentes no código-fonte.
  • As localizações dessas funções no código-fonte.

SELECT
    count(),
    arrayStringConcat(arrayMap(x -> concat(demangle(addressToSymbol(x)), '\n    ', addressToLine(x)), trace), '\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