Перейти к основному содержимому
Перейти к основному содержимому

system.trace_log

Выполнение запросов в ClickHouse Cloud

Данные в этой системной таблице хранятся локально на каждом узле в ClickHouse Cloud. Поэтому для получения полного обзора всех данных требуется функция clusterAllReplicas. Подробности см. здесь.

Описание

Содержит трассировки стека, собираемые sampling query profiler.

ClickHouse создаёт эту таблицу, когда задана секция конфигурации сервера trace_log. См. также настройки: query_profiler_real_time_period_ns, query_profiler_cpu_time_period_ns, memory_profiler_step, memory_profiler_sample_probability, trace_profile_events.

Для анализа журналов используйте функции интроспекции addressToLine, addressToLineWithInlines, addressToSymbol и demangle.

Столбцы

  • hostname (LowCardinality(String)) — Имя хоста сервера, который выполняет запрос.
  • event_date (Date) — Дата момента отбора данных.
  • event_time (DateTime) — Таймстэмп момента, когда была выполнена выборка.
  • event_time_microseconds (DateTime64(6)) — таймстамп момента выборки с точностью до микросекунд.
  • timestamp_ns (UInt64) — Таймстамп времени выборки в наносекундах.
  • revision (UInt32) — ревизия сборки сервера ClickHouse. При подключении к серверу с помощью clickhouse-client вы увидите строку вида Connected to ClickHouse server version 19.18.1.. Это поле содержит значение revision, а не version сервера.
  • trace_type (Enum8('Real' = 0, 'CPU' = 1, 'Memory' = 2, 'MemorySample' = 3, 'MemoryPeak' = 4, 'ProfileEvent' = 5, 'JemallocSample' = 6, 'MemoryAllocatedWithoutCheck' = 7, 'Instrumentation' = 8)) — Тип трейса: Real означает сбор стек-трейсов по реальному времени. CPU означает сбор стек-трейсов по времени CPU. Memory означает сбор сведений о выделении и освобождении памяти, когда объём выделяемой памяти превышает заданный порог. MemorySample означает сбор случайных выделений и освобождений памяти. MemoryPeak означает сбор обновлений пикового потребления памяти. ProfileEvent означает сбор инкрементов profile events. JemallocSample означает сбор выборок jemalloc. MemoryAllocatedWithoutCheck означает сбор значительных выделений памяти (>16MiB), который выполняется без учёта каких-либо ограничений памяти (только для разработчиков ClickHouse).Instrumentation означает трейсы, собранные с помощью инструментирования через XRay.
  • cpu_id (UInt64) — идентификатор процессора.
  • thread_id (UInt64) — идентификатор потока.
  • thread_name (LowCardinality(String)) — Название потока.
  • query_id (String) — идентификатор запроса, который можно использовать для получения сведений о выполнявшемся запросе из системной таблицы query_log.
  • trace (Array(UInt64)) — Стек вызовов на момент семплирования. Каждый элемент — виртуальный адрес памяти в процессе сервера ClickHouse.
  • size (Int64) — для типов трейса Memory, MemorySample, MemoryAllocatedWithoutCheck или MemoryPeak это объём выделенной памяти, для остальных типов трейса — 0.
  • ptr (UInt64) — адрес выделенного фрагмента.
  • memory_context (Enum8('Unknown' = -1, 'Global' = 0, 'User' = 1, 'Process' = 2, 'Thread' = 3, 'Max' = 4)) — Контекст трекера памяти (только для Memory/MemoryPeak): контекст Unknown не определён для этого trace_type. Global обозначает глобальный контекст сервера. User обозначает контекст пользователя или слияния. Process обозначает контекст процесса (то есть запроса). Thread обозначает контекст потока (потока конкретного процесса). Max — это специальное значение, означающее, что трекер памяти не заблокирован (для столбца blocked_context).
  • memory_blocked_context (Enum8('Unknown' = -1, 'Global' = 0, 'User' = 1, 'Process' = 2, 'Thread' = 3, 'Max' = 4)) — Контекст, в котором заблокирован трекер памяти (только для разработчиков ClickHouse): контекст Unknown не определён для этого trace_type. Global обозначает контекст сервера. User обозначает контекст пользователя/слияния. Process обозначает контекст процесса (то есть запроса). Thread обозначает контекст потока (потока конкретного процесса). Max — это специальное значение, которое означает, что трекер памяти не заблокирован (для столбца blocked_context).
  • event (LowCardinality(String)) — Для типа трейса ProfileEvent это имя обновлённого события профиля, для других типов трейсов — пустая строка.
  • increment (Int64) — для трейса типа ProfileEvent это величина приращения события профиля, для остальных типов трейсов — 0.
  • symbols (Array(LowCardinality(String))) — Если символизация включена, содержит деманглированные имена символов, соответствующие трейсу. Символизацию можно включить или отключить с помощью настройки symbolize в разделе trace_log в файле конфигурации сервера.
  • lines (Array(LowCardinality(String))) — Если символизация включена, содержит строки с именами файлов и номерами строк, соответствующие трейсу.
  • function_id (Nullable(Int32)) — Для Instrumentation типа «трейс» — идентификатор, присвоенный функции в разделе xray_instr_map ELF-бинарного файла.
  • function_name (Nullable(String)) — Для типа трейса Instrumentation: имя функции, к которой применена инструментализация.
  • handler (Nullable(String)) — Для Instrumentation типа трейс — handler инструментируемой функции.
  • entry_type (Nullable(Enum8('Entry' = 0, 'Exit' = 1))) — Для трейса типа Instrumentation: тип входа/выхода инструментируемой функции.
  • duration_nanoseconds (Nullable(UInt64)) — Для типа Instrumentation в трейсе — длительность выполнения функции в наносекундах.

Псевдонимы:

  • build_id — псевдоним для 'E2EEB60ED9503BFFA825B628D480CCDC40B2D416'.

Символизацию можно включить или отключить в параметре symbolize в секции trace_log конфигурационного файла сервера.

Пример

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 с помощью следующего запроса. Сохраните запрос в файл 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, который затем можно импортировать либо в Perfetto, либо в speedscope.

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

Мы можем опустить часть со стеком, если хотим более компактную, но менее информативную трассировку.

См. также

  • SYSTEM INSTRUMENT — Добавить или удалить точки инструментирования.
  • system.instrumentation — Просматривать проинструментированные точки.
  • system.symbols — Просматривать символы для добавления точек инструментирования.