跳到主要内容
跳到主要内容

system.trace_log

在 ClickHouse Cloud 中进行查询

该系统表中的数据保存在 ClickHouse Cloud 中每个节点的本地。因此,如需获得所有数据的完整视图,需要使用 clusterAllReplicas 函数。更多详情请参阅此处

包含由 sampling query profiler 收集的堆栈跟踪信息。

在配置了 trace_log 服务器配置部分后,ClickHouse 会创建此表。另请参阅以下设置:query_profiler_real_time_period_nsquery_profiler_cpu_time_period_nsmemory_profiler_stepmemory_profiler_sample_probabilitytrace_profile_events

要分析日志,请使用 addressToLineaddressToLineWithInlinesaddressToSymboldemangle 内省函数。

列:

  • hostname (LowCardinality(String)) — 执行查询的服务器主机名。

  • event_date (Date) — 采样时刻的日期。

  • event_time (DateTime) — 采样时刻的时间戳。

  • event_time_microseconds (DateTime64) — 具有微秒精度的采样时刻时间戳。

  • timestamp_ns (UInt64) — 以纳秒为单位的采样时刻时间戳。

  • revision (UInt32) — ClickHouse 服务器构建修订版本号。

    通过 clickhouse-client 连接到服务器时,你会看到类似 Connected to ClickHouse server version 19.18.1. 的字符串。该字段包含的是服务器的 revision,而不是 version

  • trace_type (Enum8) — 跟踪类型:

    • Real 表示按墙钟时间收集栈跟踪。
    • CPU 表示按 CPU 时间收集栈跟踪。
    • Memory 表示在内存分配超过后续水位线阈值时收集分配和释放。
    • MemorySample 表示随机收集分配和释放。
    • MemoryPeak 表示收集内存峰值使用的更新。
    • ProfileEvent 表示收集 profile 事件的增量。
    • JemallocSample 表示收集 jemalloc 样本。
    • MemoryAllocatedWithoutCheck 表示在忽略任何内存限制的情况下收集大额分配(>16MiB)(仅供 ClickHouse 开发者使用)。
    • Instrumentation 表示通过 XRay 进行 instrumentation 所收集的跟踪。
  • cpu_id (UInt64) — CPU 标识符。

  • thread_id (UInt64) — 线程标识符。

  • query_id (String) — 查询标识符,可用于从 query_log 系统表中获取曾经运行的查询的详细信息。

  • trace (Array(UInt64)) — 采样时刻的栈跟踪。每个元素是 ClickHouse 服务器进程内的虚拟内存地址。

  • size (Int64) - 对于 MemoryMemorySampleMemoryPeak 跟踪类型,是已分配内存的大小;对于其他跟踪类型为 0。

  • event (LowCardinality(String)) - 对于 ProfileEvent 跟踪类型,是更新后的 profile 事件名称;对于其他跟踪类型是空字符串。

  • increment (UInt64) - 对于 ProfileEvent 跟踪类型,是 profile 事件的增量值;对于其他跟踪类型为 0。

  • symbols, (Array(LowCardinality(String))), 如果启用了符号化,包含与 trace 对应的已还原符号名称。

  • lines, (Array(LowCardinality(String))), 如果启用了符号化,包含与 trace 对应的、带有行号的文件名字符串。

  • function_id (Nullable(Int32)), 对于 Instrumentation 跟踪类型,是在 elf-binary 的 xray_instr_map 段中分配给该函数的 ID。

  • function_name (Nullable(String)), 对于 Instrumentation 跟踪类型,是被插桩(instrumented)的函数名称。

  • handler (Nullable(String)), 对于 Instrumentation 跟踪类型,是被插桩函数的处理程序。

  • entry_type (Nullable(Enum('Entry' = 0, 'Exit' = 1))), 对于 Instrumentation 跟踪类型,是该跟踪的入口类型。

  • duration_nanoseconds (Nullable(UInt64)), 对于 Instrumentation 跟踪类型,是函数的运行时间(纳秒)。

可以在服务器配置文件的 trace_log 部分,通过 symbolize 启用或禁用符号化。

示例

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','/home/ubuntu/ClickHouse/ClickHouse/build/programs/clickhouse','./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','/home/ubuntu/ClickHouse/ClickHouse/build/programs/clickhouse','/home/ubuntu/ClickHouse/ClickHouse/build/programs/clickhouse']
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

转换为 Chrome 事件跟踪格式

可以使用以下查询将性能分析数据转换为 Chrome 的事件跟踪格式(Event Trace Format)。将该查询保存为名为 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;

并使用 ClickHouse Client 执行它,将结果导出为 trace.json 文件,以便我们在 Perfettospeedscope 中导入。

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

如果我们希望获得更紧凑但信息更少的 trace,可以省略 stack 部分。

另请参阅