system.trace_log | ClickHouse Docs

Descrição

Contém stack traces coletados pelo profiler de consultas por amostragem.

O ClickHouse cria esta tabela quando a seção de configuração do servidor trace_log é definida. Veja também as configurações: query_profiler_real_time_period_ns, query_profiler_cpu_time_period_ns, memory_profiler_step, memory_profiler_sample_probability, trace_profile_events.

Quando a simbolização está habilitada (o padrão), os nomes de funções desmangleados e os locais do código-fonte já estão disponíveis nas colunas symbols e lines, portanto, você pode analisar os logs diretamente sem funções de introspecção. A configuração symbolize aplica-se aos tipos de trace coletados pelo profiler; as linhas com o tipo de trace Instrumentation são simbolizadas independentemente dessa configuração. A simbolização é compatível com plataformas ELF (como Linux) e macOS; no FreeBSD, as colunas symbols e lines estão sempre vazias. Os nomes das funções em symbols vêm da tabela de símbolos do binário e estão disponíveis por padrão, enquanto os locais do código-fonte em lines são fornecidos na medida do possível: eles exigem informações de depuração (um pacote .dSYM no macOS) e, em plataformas ELF, são resolvidos apenas para frames dentro do binário principal do ClickHouse; frames não resolvidos têm entradas lines vazias. 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), use as funções de introspecção addressToLine, addressToLineWithInlines, addressToSymbol e demangle. Essas funções estão disponíveis nas mesmas plataformas que oferecem suporte à 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.

Colunas

hostname (LowCardinality(String)) — Hostname do servidor que executa a consulta.
event_date (Date) — Data do momento em que a amostragem ocorreu.
event_time (DateTime) — Timestamp do momento da amostragem.
event_time_microseconds (DateTime64(6)) — Timestamp do momento da amostragem com precisão de microssegundos.
timestamp_ns (UInt64) — Timestamp do momento de amostragem em nanossegundos.
revision (UInt32) — revisão de compilação do servidor ClickHouse. Ao se conectar ao servidor com o clickhouse-client, você verá uma string semelhante a Connected to ClickHouse server version 19.18.1.. Este campo contém a revision, mas não a version de um servidor.
trace_type (Enum8('Real' = 0, 'CPU' = 1, 'Memory' = 2, 'MemorySample' = 3, 'MemoryPeak' = 4, 'ProfileEvent' = 5, 'JemallocSample' = 6, 'MemoryAllocatedWithoutCheck' = 7, 'Instrumentation' = 8)) — Tipo de trace: Real representa a coleta de stack traces por tempo de relógio. CPU representa a coleta de stack traces por tempo de CPU. Memory representa a coleta de alocações e desalocações quando a alocação de memória excede a watermark subsequente. MemorySample representa a coleta aleatória de alocações e desalocações. MemoryPeak representa a coleta de atualizações do pico de uso de memória. ProfileEvent representa a coleta de incrementos de eventos de profile. JemallocSample representa a coleta de amostras do jemalloc. MemoryAllocatedWithoutCheck representa a coleta de alocações significativas (>16MiB), feita sem considerar quaisquer limites de memória (apenas para desenvolvedores do ClickHouse).Instrumentation representa traces coletados pela instrumentação realizada por meio do XRay.
cpu_id (UInt64) — identificador da CPU.
thread_id (UInt64) — Identificador da thread.
thread_name (LowCardinality(String)) — Nome da thread.
query_id (String) — Identificador da consulta que pode ser usado para obter detalhes sobre uma consulta que estava em execução a partir da tabela de sistema query_log.
trace (Array(UInt64)) — Stack trace no momento da amostragem. Para tipos de trace coletados pelo profiler, em plataformas ELF, exceto FreeBSD, os endereços dentro do binário principal do ClickHouse são armazenados como offsets físicos de arquivo, e os demais endereços são endereços de memória virtual no processo do servidor ClickHouse. As linhas de trace de Instrumentation são uma exceção: elas armazenam endereços brutos de memória virtual.
size (Int64) — Para os tipos de trace Memory, MemorySample, MemoryAllocatedWithoutCheck ou MemoryPeak, é a quantidade de memória alocada; para os demais tipos de trace, é 0.
ptr (UInt64) — O endereço do fragmento alocado.
memory_context (Enum8('Unknown' = -1, 'Global' = 0, 'User' = 1, 'Process' = 2, 'Thread' = 3, 'Max' = 4)) — contexto do memory tracker (apenas para Memory/MemoryPeak): o contexto Unknown não está definido para este trace_type. Global representa o contexto do servidor. User representa o contexto do usuário/merge. Process representa o contexto do processo (ou seja, da consulta). Thread representa o contexto da thread (thread de um processo específico). Max é um valor especial que significa que o memory tracker não está bloqueado (para a coluna blocked_context).
memory_blocked_context (Enum8('Unknown' = -1, 'Global' = 0, 'User' = 1, 'Process' = 2, 'Thread' = 3, 'Max' = 4)) — Contexto no qual o memory tracker está bloqueado (somente para desenvolvedores do ClickHouse): o contexto Unknown não está definido para este trace_type. Global representa o contexto do servidor. User representa o contexto de usuário/merge. Process representa o contexto do processo (ou seja, da consulta). Thread representa o contexto da thread (thread de um processo específico). Max é um valor especial que significa que o memory tracker não está bloqueado (para a coluna blocked_context).
event (LowCardinality(String)) — Para o tipo de trace ProfileEvent, é o nome do evento de perfil atualizado; para os outros tipos de trace, é uma string vazia.
increment (Int64) — Para traces do tipo ProfileEvent, é o valor do incremento do evento de profile; para outros tipos de trace, é 0.
symbols (Array(LowCardinality(String))) — Se a simbolização estiver habilitada, contém nomes de símbolos desmanglados, correspondentes ao trace. A simbolização pode ser habilitada ou desabilitada pela configuração symbolize, em trace_log, no arquivo de configuração do servidor. A configuração se aplica aos tipos de trace coletados pelo profiler, enquanto as linhas com o tipo de trace Instrumentation são simbolizadas independentemente dela. A simbolização é compatível com plataformas ELF (como Linux) e macOS; no FreeBSD, esta coluna está sempre vazia.
lines (Array(LowCardinality(String))) — Se a simbolização estiver habilitada, contém strings com nomes de arquivos e números de linha correspondentes ao trace. A configuração symbolize se aplica aos tipos de trace coletados pelo profiler, enquanto as linhas com o tipo de trace Instrumentation são simbolizadas independentemente dela. A simbolização é compatível com plataformas ELF (como Linux) e macOS; no FreeBSD, esta coluna está sempre vazia. As localizações de origem são obtidas da melhor forma possível: 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; os frames não resolvidos têm entradas vazias.
function_id (Nullable(Int32)) — Para o trace do tipo Instrumentation, ID atribuído à função na seção xray_instr_map do binário ELF.
function_name (Nullable(String)) — Para o trace do tipo Instrumentation, nome da função instrumentada.
handler (Nullable(String)) — Para o trace do tipo Instrumentation, handler da função instrumentada.
entry_type (Nullable(Enum8('Entry' = 0, 'Exit' = 1))) — Para o tipo de trace Instrumentation, indica se é a entrada ou a saída da função instrumentada.
duration_nanoseconds (Nullable(UInt64)) — Para o tipo de trace Instrumentation, tempo de execução da função, em nanossegundos.

Aliases:

build_id — Alias do ID de compilação do binário em execução do servidor ClickHouse.

A simbolização pode ser ativada ou desativada pela configuração symbolize em trace_log, no arquivo de configuração do servidor. Ela é ativada por padrão. A configuração se aplica aos tipos de trace coletados pelo profiler; as linhas com o tipo de trace Instrumentation são simbolizadas independentemente dessa configuração.

Exemplo

SELECT * FROM system.trace_log LIMIT 1 \G

Row 1:
──────
hostname:                clickhouse.eu-central1.internal
event_date:              2025-11-11
event_time:              2025-11-11 11:53:59
event_time_microseconds: 2025-11-11 11:53:59.128333
timestamp_ns:            1762862039128333000
revision:                54504
trace_type:              Instrumentation
cpu_id:                  19
thread_id:               3166432 -- 3.17 million
query_id:                ef462508-e189-4ea2-b231-4489506728e8
trace:                   [350594916,447733712,447742095,447727324,447726659,221642873,450882315,451852359,451905441,451885554,512404306,512509092,612861767,612863269,612466367,612455825,137631896259267,137631896856768]
size:                    0
ptr:                     0
memory_context:          Unknown
memory_blocked_context:  Unknown
event:
increment:               0
symbols:                 ['StackTrace::StackTrace()','DB::InstrumentationManager::createTraceLogElement(DB::InstrumentationManager::InstrumentedPointInfo const&, XRayEntryType, std::__1::chrono::time_point<std::__1::chrono::system_clock, std::__1::chrono::duration<long long, std::__1::ratio<1l, 1000000l>>>) const','DB::InstrumentationManager::profile(XRayEntryType, DB::InstrumentationManager::InstrumentedPointInfo const&)','DB::InstrumentationManager::dispatchHandlerImpl(int, XRayEntryType)','DB::InstrumentationManager::dispatchHandler(int, XRayEntryType)','__xray_FunctionEntry','DB::QueryMetricLog::startQuery(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>> const&, std::__1::chrono::time_point<std::__1::chrono::system_clock, std::__1::chrono::duration<long long, std::__1::ratio<1l, 1000000l>>>, unsigned long)','DB::logQueryStart(std::__1::chrono::time_point<std::__1::chrono::system_clock, std::__1::chrono::duration<long long, std::__1::ratio<1l, 1000000l>>> const&, std::__1::shared_ptr<DB::Context> const&, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>> const&, unsigned long, std::__1::shared_ptr<DB::IAST> const&, DB::QueryPipeline const&, DB::IInterpreter const*, bool, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>> const&, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>> const&, bool)','DB::executeQueryImpl(char const*, char const*, std::__1::shared_ptr<DB::Context>, DB::QueryFlags, DB::QueryProcessingStage::Enum, std::__1::unique_ptr<DB::ReadBuffer, std::__1::default_delete<DB::ReadBuffer>>&, std::__1::shared_ptr<DB::IAST>&, std::__1::shared_ptr<DB::ImplicitTransactionControlExecutor>, std::__1::function<void ()>)','DB::executeQuery(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>> const&, std::__1::shared_ptr<DB::Context>, DB::QueryFlags, DB::QueryProcessingStage::Enum)','DB::TCPHandler::runImpl()','DB::TCPHandler::run()','Poco::Net::TCPServerConnection::start()','Poco::Net::TCPServerDispatcher::run()','Poco::PooledThread::run()','Poco::ThreadImpl::runnableEntry(void*)','start_thread','__clone3']
lines:                   ['./build/../src/Common/StackTrace.cpp:395','./src/Common/StackTrace.h:62','./contrib/llvm-project/libcxx/include/__memory/shared_ptr.h:738','./build/./src/Interpreters/InstrumentationManager.cpp:257','./build/./src/Interpreters/InstrumentationManager.cpp:225','','./build/./src/Interpreters/QueryMetricLog.cpp:0','./contrib/llvm-project/libcxx/include/__memory/shared_ptr.h:667','./build/./src/Interpreters/executeQuery.cpp:0','./build/./src/Interpreters/executeQuery.cpp:0','./contrib/llvm-project/libcxx/include/__memory/shared_ptr.h:744','./contrib/llvm-project/libcxx/include/__memory/shared_ptr.h:583','./build/../base/poco/Net/src/TCPServerConnection.cpp:54','../contrib/llvm-project/libcxx/include/__memory/unique_ptr.h:80','./build/../base/poco/Foundation/src/ThreadPool.cpp:219','../base/poco/Foundation/include/Poco/AutoPtr.h:77','','']
function_id:             231255
function_name:           DB::QueryMetricLog::startQuery(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>> const&, std::__1::chrono::time_point<std::__1::chrono::system_clock, std::__1::chrono::duration<long long, std::__1::ratio<1l, 1000000l>>>, unsigned long)
handler:                 profile
entry_type:              Exit
duration_nanoseconds:   58435

Convertendo para o Chrome Event Trace Format

Os dados de profiling podem ser convertidos para o Chrome Event Trace Format com a consulta a seguir. Salve a consulta em um arquivo chrome_trace.sql:

WITH traces AS (
    SELECT * FROM system.trace_log
    WHERE event_date >= today() AND trace_type = 'Instrumentation' AND handler = 'profile'
    ORDER BY event_time, entry_type
)
SELECT
    format(
        '{{"traceEvents": [{}\n]}}',
        arrayStringConcat(
            groupArray(
                format(
                    '\n{{"name": "{}", "cat": "clickhouse", "ph": "{}", "ts": {}, "pid": 1, "tid": {}, "args": {{"query_id": "{}", "cpu_id": {}, "stack": [{}]}}}},',
                    function_name,
                    if(entry_type = 0, 'B', 'E'),
                    timestamp_ns/1000,
                    toString(thread_id),
                    query_id,
                    cpu_id,
                    arrayStringConcat(arrayMap((x, y) -> concat('"', x, ': ', y, '", '), lines, symbols))
                )
            )
        )
    )
FROM traces;

E executá-lo com o ClickHouse Client para exportá-lo para um arquivo trace.json, que podemos importar no Perfetto ou no speedscope.

echo $(clickhouse client --query "$(cat chrome_trace.sql)") > trace.json

Podemos omitir a pilha de chamadas se quisermos um trace mais compacto, mas menos informativo.

Veja também

SYSTEM INSTRUMENT — Adicione ou remova pontos de instrumentação.
system.instrumentation — Inspecione os pontos instrumentados.
system.symbols — Inspecione os símbolos para adicionar pontos de instrumentação.