Profiling do ClickHouse com o XRay do LLVM

O LLVM já inclui uma ferramenta que instrumenta o código, permitindo fazer profiling por instrumentação. Ao contrário do profiling por amostragem ou estatístico, ele é muito preciso, sem perder nenhuma chamada, mas exige instrumentar o código e consome mais recursos.

Em poucas palavras, um profiler por instrumentação introduz novo código para rastrear as chamadas de todas as funções. Profilers estatísticos nos permitem executar o código sem exigir nenhuma alteração, tirando snapshots periodicamente para ver o estado da aplicação. Assim, apenas as funções em execução no momento em que o snapshot é tirado são consideradas. O perf é um profiler estatístico muito conhecido.

No ClickHouse 25.12, o XRay é integrado para adicionar novos pontos de instrumentação a funções de forma transparente. Assim, qualquer lançamento oficial já vem com esse recurso, que pode ser acionado sob demanda, sem afetar o desempenho geral quando não estiver habilitado. A ideia é habilitar a quantidade mínima de pontos de instrumentação para obter informações valiosas.

Podemos adicionar um novo ponto de instrumentação de profiling usando a instrução SYSTEM INSTRUMENT ADD PROFILE. As funções a serem instrumentadas podem ser obtidas na tabela de sistema system.symbols. Digamos que queiramos fazer o profiling da função sleepForNanoseconds, que é uma função prática para verificar quanto tempo ela leva para executar.

SYSTEM INSTRUMENT ADD 'sleepForNanoseconds' PROFILE

Em seguida, deixamos ele em execução pelo período que queremos perfilar e depois o interrompemos.

SYSTEM INSTRUMENT REMOVE ALL

Convertemos os dados coletados em system.trace_log para o formato Chrome para visualizá-los no Perfetto. Observe o query_id, o cpu_id e o stacktrace de cada registro.

A seção a seguir é mantida como referência para entender como o XRay funciona internamente e como pode ser usado imediatamente para fazer profiling de uma aplicação nativa.

Imagine o seguinte código-fonte:

#include <chrono>
#include <cstdio>
#include <thread>

void one()
{
    std::this_thread::sleep_for(std::chrono::milliseconds(10));
}

void two()
{
    std::this_thread::sleep_for(std::chrono::milliseconds(5));
}

int main()
{
    printf("Start\n");

    for (int i = 0; i < 10; ++i)
    {
        one();
        two();
    }

    printf("Finish\n");
}

Para instrumentar com o XRay, precisamos adicionar algumas flags assim:

clang++ -o test test.cpp -fxray-instrument -fxray-instruction-threshold=1

• -fxray-instrument é necessário para instrumentar o código.
• -fxray-instruction-threshold=1 é usado para instrumentar todas as funções, mesmo que sejam muito pequenas, como no nosso exemplo. Por padrão, ele instrumenta funções com pelo menos 200 instruções.

Podemos verificar se o código foi instrumentado corretamente conferindo se há uma nova seção no binário:

objdump -h -j xray_instr_map test

test:     file format elf64-x86-64

Sections:
Idx Name          Size      VMA               LMA               File off  Algn
 17 xray_instr_map 000005c0  000000000002f91c  000000000002f91c  0002f91c  2**0
                  CONTENTS, ALLOC, LOAD, READONLY, DATA

Por padrão, não há coleta do profiler, a menos que ela seja solicitada explicitamente. Em outras palavras, a menos que estejamos fazendo profiling, a sobrecarga é insignificante. Podemos definir valores diferentes para XRAY_OPTIONS para configurar quando o profiler começa a coletar e como isso é feito.

XRAY_OPTIONS="patch_premain=true xray_mode=xray-basic verbosity=1" ./test
==74394==XRay: Log file in 'xray-log.test.14imlN'
Start
Finish
==74394==Cleaned up log for TID: 74394

Os traces do XRay podem ser convertidos para vários formatos. O formato trace_event é muito útil porque é fácil de fazer o parse e já há várias ferramentas que o suportam, então usaremos esse:

llvm-xray convert --symbolize --instr_map=./test --output-format=trace_event xray-log.test.14imlN | gzip > test-trace.txt.gz

Podemos usar UIs baseadas na web, como speedscope.app ou Perfetto.

Embora o Perfetto facilite a visualização de várias threads e a consulta dos dados, o speedscope é melhor para gerar um flamegraph e uma visualização tipo sanduíche dos seus dados.

• SYSTEM INSTRUMENT — Adicione ou remova pontos de instrumentação.
• system.instrumentation — Inspecione os pontos instrumentados.
• system.symbols — Inspecione símbolos para adicionar pontos de instrumentação.
• system.trace_log — Inspecione os dados coletados usando pontos de instrumentação.
• XRay Instrumentation
• Documentação sobre Debugging with XRay para mais detalhes.