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.

Por padrão, o profiler simboliza os stack traces no momento da coleta e armazena os resultados nas colunas symbols e lines de system.trace_log, portanto, os exemplos abaixo leem essas colunas diretamente e não exigem funções de introspecção. A simbolização é controlada pela configuração symbolize na seção de configuração do servidor trace_log (habilitada por padrão) e é compatível com plataformas ELF (como Linux) e macOS; no FreeBSD, as colunas symbols e lines estão sempre vazias. Os nomes de funções em symbols vêm da tabela de símbolos do binário e estão disponíveis por padrão. As localizações no código-fonte em lines são obtidas da melhor forma possível: elas exigem informações de depuração (no macOS, um pacote .dSYM ao lado do binário) e, em plataformas ELF, apenas os frames dentro do binário principal do ClickHouse são resolvidos; portanto, as entradas de frames que não podem ser resolvidos (por exemplo, em bibliotecas compartilhadas) ficam vazias. Se a simbolização estiver desabilitada, use as funções de introspecção addressToSymbol, demangle e addressToLine para resolver os endereços brutos na coluna trace. Essas funções estão disponíveis nas mesmas plataformas que a simbolização (plataformas ELF, como Linux, e macOS); no FreeBSD, elas também não são compiladas, portanto, os endereços em trace precisam ser resolvidos fora do servidor.

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((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

Autogerenciado

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

​

Usando o profiler de consulta em implantações autogerenciadas

Em implantações autogerenciadas, para usar o profiler de consulta, 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:

   <!-- 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>
   

   Esta seção configura a tabela de sistema trace_log, que contém os resultados do funcionamento do profiler. A opção symbolize (habilitada por padrão) faz com que o ClickHouse resolva cada frame da pilha no momento da coleta e armazene os nomes de função desmangleados e as localizações no código-fonte nas colunas symbols e lines. Os nomes de função em symbols vêm da tabela de símbolos e estão disponíveis por padrão, enquanto as localizações no código-fonte em lines exigem informações de depuração (um pacote .dSYM no macOS) e, em plataformas ELF, são resolvidas apenas para frames dentro do binário principal do ClickHouse; frames não resolvidos têm entradas vazias em lines.

   Observe que os endereços brutos na coluna trace são menos estáveis entre reinicializações e upgrades do que as colunas pré-simbolizadas. Em plataformas ELF, exceto no FreeBSD, os frames no binário principal do ClickHouse são armazenados como offsets físicos no arquivo, portanto permanecem resolvíveis entre reinicializações, desde que o binário não seja alterado; no macOS e no FreeBSD, eles são armazenados como endereços virtuais de tempo de execução que podem se tornar inválidos após uma reinicialização. Frames fora do binário principal (por exemplo, em bibliotecas compartilhadas) são sempre armazenados como endereços virtuais de tempo de execução que podem se tornar inválidos após uma reinicialização, e qualquer endereço bruto deixa de ser resolvível após um upgrade do binário, pois o layout do código muda. O ClickHouse não limpa a tabela na reinicialização, portanto endereços brutos desatualizados podem permanecer. Por outro lado, as colunas pré-simbolizadas symbols e lines permanecem válidas entre reinicializações e upgrades; portanto, prefira-as ao analisar dados históricos.

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 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.

   Quando a simbolização está habilitada (o padrão), os nomes de funções desmangleados e as localizações no código-fonte já estão disponíveis nas colunas symbols e lines, portanto nenhuma configuração adicional é necessária. A simbolização não é compatível com FreeBSD, onde essas colunas estão sempre vazias. As entradas de lines podem estar vazias para frames que não têm informações de depuração ou que estão fora do binário principal do ClickHouse (consulte acima).

   Se a simbolização estiver desabilitada ou se você quiser resolver dinamicamente os endereços brutos na coluna trace (por exemplo, para expandir frames inline), 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. Assim como a simbolização, essas funções estão disponíveis em plataformas ELF (como Linux) e macOS, mas não no FreeBSD.

   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.
• Lê as colunas pré-simbolizadas symbols e lines 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.
• Agrega pelo stack trace bruto (a coluna trace), usando as colunas simbolizadas apenas para exibição, para que stack traces distintos nunca sejam agrupados pela simbolização aproximada.

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