28.5. Динамическая трассировка

Postgres Pro позволяет выполнять динамическую трассировку сервера базы данных. Имеющиеся возможности позволяют вызывать внешнюю утилиту в определённых точках кода и таким образом отслеживать его выполнение.

Несколько подобных точек сбора метрик, или точек трассировки, уже встроено в исходный код. Предполагается, что эти точки будут использоваться разработчиками и администраторами базы данных. По умолчанию точки трассировки не входят в сборку Postgres Pro; пользователь должен явно указать конфигурационному скрипту необходимость включения этих макросов.

В настоящее время поддерживается только утилита DTrace, которая доступна для Solaris, OS X, FreeBSD, NetBSD и Oracle Linux. Проект SystemTap для Linux представляет собой эквивалент DTrace и также может быть использован. Теоретически возможна поддержка и других утилит динамической трассировки, для этого необходимо изменить определения для макроса в src/include/utils/probes.h.

28.5.1. Компиляция для включения динамической трассировки

По умолчанию точки трассировки недоступны, поэтому в конфигурационном скрипте Postgres Pro требуется явно указать необходимость их подключения. Для поддержки утилиты DTrace укажите --enable-dtrace при конфигурировании.

28.5.2. Встроенные точки трассировки

В исходный код входит несколько стандартных точек трассировки, которые представлены в Таблице 28.22; в Таблице 28.23 показаны типы данных, которые используются для этих точек. Конечно, для более детального отслеживания работы Postgres Pro можно добавлять и другие точки трассировки.

Таблица 28.22. Встроенные точки трассировки DTrace

ИмяПараметрыОписание
transaction-start(LocalTransactionId)Срабатывает в начале новой транзакции. arg0 задаёт идентификатор транзакции.
transaction-commit(LocalTransactionId)Срабатывает при успешном завершении транзакции. arg0 задаёт идентификатор транзакции.
transaction-abort(LocalTransactionId)Срабатывает, когда транзакция завершается с ошибкой. arg0 задаёт идентификатор транзакции.
query-start(const char *)Срабатывает, когда начинается обработка запроса. arg0 задаёт текст запроса.
query-done(const char *)Срабатывает по завершении обработки запроса. arg0 задаёт текст запроса.
query-parse-start(const char *)Срабатывает, когда начинается разбор запроса. arg0 задаёт текст запроса.
query-parse-done(const char *)Срабатывает по завершении разбора (parsing) запроса. arg0 задаёт текст запроса.
query-rewrite-start(const char *)Срабатывает, когда начинается модификация запроса. arg0 задаёт текст запроса.
query-rewrite-done(const char *)Срабатывает по завершении модификации запроса. arg0 задаёт текст запроса.
query-plan-start()Срабатывает, когда начинает работать планировщик выполнения запроса.
query-plan-done()Срабатывает по завершении работы планировщика запроса.
query-execute-start()Срабатывает, когда начинается выполнение запроса.
query-execute-done()Срабатывает по завершении выполнения запроса.
statement-status(const char *)Срабатывает каждый раз, когда серверный процесс обновляет свой статус в pg_stat_activity.status. arg0 задаёт новую строку состояния.
checkpoint-start(int)Срабатывает в начале контрольной точки. arg0 содержит битовые флаги, с помощью которых задаются разные типы контрольных точек, такие как shutdown, immediate или force.
checkpoint-done(int, int, int, int, int)Срабатывает по завершении контрольной точки. (Перечисленные далее точки трассировки срабатывают последовательно при обработке контрольной точки.) arg0 задаёт число записанных буферов. arg1 — общее число буферов. arg2, arg3 и arg4 задают число файлов WAL, которые были добавлены, удалены или переработаны, соответственно.
clog-checkpoint-start(bool)Срабатывает, когда начинается запись контрольной точки в CLOG. arg0 = true для обычных контрольных точек и false для контрольных точек типа shutdown.
clog-checkpoint-done(bool)Срабатывает по завершении записи контрольной точки в CLOG. Значение arg0 задаётся аналогично значению для clog-checkpoint-start.
subtrans-checkpoint-start(bool)Срабатывает, когда начинается запись контрольной точки в SUBTRANS. arg0 = true для обычных контрольных точек и false для контрольных точек типа shutdown.
subtrans-checkpoint-done(bool)Срабатывает по завершении записи контрольной точки в SUBTRANS. Значение arg0 задаётся аналогично значению для subtrans-checkpoint-start.
multixact-checkpoint-start(bool)Срабатывает, когда начинается запись контрольной точки в MultiXact. arg0 = true для обычных контрольных точек и false для контрольных точек типа shutdown.
multixact-checkpoint-done(bool)Срабатывает по завершении записи контрольной точки в MultiXact. Значение arg0 задаётся аналогично значению для multixact-checkpoint-start.
buffer-checkpoint-start(int)Срабатывает, когда начинается запись буферов контрольной точки. arg0 содержит битовые флаги, с помощью которых задаются разные типы контрольных точек, такие как shutdown, immediate или force.
buffer-sync-start(int, int)Срабатывает во время контрольной точки, когда начинается запись грязных буферов (после нахождения буферов, которые должны быть записаны). arg0 задаёт общее число буферов. arg1 задаёт число буферов, которые в настоящий момент являются грязными и должны быть записаны.
buffer-sync-written(int)Срабатывает после записи каждого буфера при выполнении контрольной точки. arg0 задаёт идентификатор буфера.
buffer-sync-done(int, int, int)Срабатывает после записи всех грязных буферов. arg0 задаёт общее число буферов. arg1 задаёт число буферов, которые фактически были записаны процессом выполнения контрольной точки. arg2 задаёт число буферов, которое должно было быть записано (arg1 из buffer-sync-start); разные значения говорят о том, что во время выполнения этой контрольной точки буферы сбрасывались другими процессами.
buffer-checkpoint-sync-start()Срабатывает после записи грязных буферов в ядро и до начала формирования запросов fsync.
buffer-checkpoint-done()Срабатывает по завершении синхронизации буферов с диском.
twophase-checkpoint-start()Срабатывает, когда начинается двухфазный этап выполнения контрольной точки.
twophase-checkpoint-done()Срабатывает по завершении двухфазного этапа выполнения контрольной точки.
buffer-read-start(ForkNumber, BlockNumber, Oid, Oid, Oid, int, bool)Срабатывает, когда начинается чтение из буфера. arg0 и arg1 содержат номер слоя и блока этой страницы (arg1 будет иметь значение -1, если выполняется запрос на расширение места для таблицы). arg2, arg3 и arg4 содержат OID-ы табличного пространства, базы данных и отношения, которые однозначно идентифицируют отношение. arg5 для локального буфера задаёт идентификатор серверного процесса, создавшего временное отношение, или InvalidBackendId (-1) — для разделяемого буфера. arg6 = true для запросов на расширение места для таблицы, false — в случае обычного чтения.
buffer-read-done(ForkNumber, BlockNumber, Oid, Oid, Oid, int, bool, bool)Срабатывает по завершении чтения буфера. arg0 и arg1 содержат номер слоя и номер блока этой страницы (arg1 будет содержать номер только что добавленного блока, если выполняется запрос на расширение места для таблицы). arg2, arg3 и arg4 содержат OID-ы табличного пространства, базы данных и отношения, которые однозначно идентифицируют отношение. arg5 для локального буфера задаёт идентификатор серверного процесса, создавшего временное отношение, или InvalidBackendId (-1) — для разделяемого буфера. arg6 = true для запросов на расширение места для таблицы, false — в случае обычного чтения. arg7 = true, если буфер был обнаружен в пуле, false — если нет.
buffer-flush-start(ForkNumber, BlockNumber, Oid, Oid, Oid)Срабатывает перед формированием любого запроса на запись в разделяемый буфер. arg0 и arg1 содержат номер слоя и номер блока этой страницы. arg2, arg3 и arg4 содержат OID-ы табличного пространства, базы данных и отношения, которые однозначно идентифицируют отношение.
buffer-flush-done(ForkNumber, BlockNumber, Oid, Oid, Oid)Срабатывает по завершении запроса на запись. (Учтите, что это отражает только момент передачи данных в ядро; обычно на диск они ещё не записаны.) Аргументы аналогичны buffer-flush-start.
buffer-write-dirty-start(ForkNumber, BlockNumber, Oid, Oid, Oid)Срабатывает, когда серверный процесс начинает запись грязного буфера. (Частое повторение такой пробы означает, что значение shared_buffers слишком мало или что необходимо откорректировать управляющие параметры процесса фоновой записи.) arg0 и arg1 содержат номер слоя и блока этой страницы. arg2, arg3 и arg4 содержат OID-ы табличного пространства, базы данных и отношения, которые однозначно идентифицируют отношение.
buffer-write-dirty-done(ForkNumber, BlockNumber, Oid, Oid, Oid)Срабатывает по завершении записи грязного буфера. Аргументы аналогичны buffer-write-dirty-start.
wal-buffer-write-dirty-start()Срабатывает, когда серверный процесс начинает запись грязного WAL буфера из-за того, что свободные WAL буферы закончились. (Частое повторение такой ситуации означает, что значение wal_buffers слишком мало.)
wal-buffer-write-dirty-done()Срабатывает по завершении записи грязного WAL буфера.
xlog-insert(unsigned char, unsigned char)Срабатывает при добавлении записи в WAL. arg0 задаёт идентификатор менеджера ресурсов (rmid) для этой записи. arg1 задаёт информационные флаги.
xlog-switch()Срабатывает при запросе на переключение сегмента WAL.
smgr-md-read-start(ForkNumber, BlockNumber, Oid, Oid, Oid, int)Срабатывает, когда начинается чтение блока из отношения. arg0 и arg1 содержат номер слоя и номер блока этой страницы. arg2, arg3 и arg4 содержат OID-ы табличного пространства, базы данных и отношения, которые однозначно идентифицируют отношение. arg5 для локального буфера задаёт идентификатор серверного процесса, создавшего временное отношение, или InvalidBackendId (-1) для разделяемого буфера.
smgr-md-read-done(ForkNumber, BlockNumber, Oid, Oid, Oid, int, int, int)Срабатывает по завершении чтения блока. arg0 и arg1 содержат номер слоя и номер блока страницы. arg2, arg3 и arg4 содержат OID-ы табличного пространства, базы данных и отношения, которые однозначно идентифицируют отношение. arg5 для локального буфера задаёт идентификатор серверного процесса, создавшего временное отношение, или InvalidBackendId (-1) — для разделяемого буфера. arg6 задаёт количество фактически прочитанных байтов, тогда как arg7 задаёт количество запрошенных байтов (различия говорят о наличии проблемы).
smgr-md-write-start(ForkNumber, BlockNumber, Oid, Oid, Oid, int)Срабатывает, когда начинается запись блока в отношение. arg0 и arg1 содержат номер слоя и номер блока этой страницы. arg2, arg3 и arg4 содержат OID-ы табличного пространства, базы данных и отношения, которые однозначно идентифицируют отношение. arg5 для локального буфера задаёт идентификатор серверного процесса, создавшего временное отношение, или InvalidBackendId (-1) — для разделяемого буфера.
smgr-md-write-done(ForkNumber, BlockNumber, Oid, Oid, Oid, int, int, int)Срабатывает по завершении записи блока. arg0 и arg1 содержат номер слоя и номер блока этой страницы. arg2, arg3 и arg4 содержат OID-ы табличного пространства, базы данных и отношения, которые однозначно идентифицируют отношение. arg5 для локального буфера задаёт идентификатор серверного процесса, создавшего временное отношение, или InvalidBackendId (-1) — для разделяемого буфера. arg6 задаёт количество фактически записанных байтов, тогда как arg7 задаёт количество запрошенных байтов (различия говорят о наличии проблемы).
sort-start(int, bool, int, int, bool)Срабатывает, когда начинается операция сортировки. arg0 задаёт сортировку таблицы, индекса или элемента данных. arg1 = true, если данные ожидаются уникальными. arg2 задаёт число ключевых столбцов. arg3 задаёт объём доступной рабочей памяти в килобайтах. arg4 = true, если требуется произвольный доступ к результату сортировки.
sort-done(bool, long)Срабатывает по завершении сортировки. arg0 = true для внешней сортировки, false — для внутренней сортировки. arg1 задаёт число дисковых блоков, использованных для внешней сортировки, или объём памяти, использованной для внутренней сортировки, в килобайтах.
lwlock-acquire(char *, int, LWLockMode)Срабатывает, когда накладывается блокировка LWLock. arg0 задаёт идентификатор блокировки. arg1 задаёт смещение LWLOCK в своей части. arg2 задаёт тип запрошенной блокировки: монопольная или разделяемая.
lwlock-release(char *, int)Срабатывает, когда блокировка LWLock была снята (однако учтите, что никакие ждущие процессы ещё не были активированы). arg0 задаёт идентификатор блокировки LWLock. arg1 задаёт смещение внутри идентификатора блокировки LWLock.
lwlock-wait-start(char *, int, LWLockMode)Срабатывает, когда оказывается, что наложить блокировку LWLock немедленно нельзя, и серверный процесс начинает ожидать освобождения блокировки. arg0 задаёт идентификатор блокировки LWLock. arg1 задаёт смещение внутри идентификатора блокировки LWLock. arg2 задаёт тип запрошенной блокировки, монопольная или разделяемая.
lwlock-wait-done(char *, int, LWLockMode)Срабатывает, когда серверный процесс прекращает ожидание блокировки LWLock (но саму блокировку он ещё не получил). arg0 задаёт идентификатор блокировки LWLock. arg1 задаёт смещение внутри идентификатора блокировки LWLock. arg2 задаёт тип запрошенной блокировки, монопольная или разделяемая.
lwlock-condacquire(char *, int, LWLockMode)Срабатывает, когда блокировка LWLock была успешно получена процессом, запросившим её в режиме без ожидания. arg0 задаёт идентификатор блокировки LWLock. arg1 задаёт смещение внутри идентификатора блокировки LWLock. arg2 задаёт тип запрошенной блокировки, монопольная или разделяемая.
lwlock-condacquire-fail(char *, int, LWLockMode)Срабатывает, когда процесс, запросивший блокировку LWLock в режиме без ожидания, не смог её получить. arg0 задаёт идентификатор блокировки LWLock. arg1 задаёт смещение внутри идентификатора блокировки LWLock. arg2 задаёт тип запрошенной блокировки, монопольная или разделяемая.
lock-wait-start(unsigned int, unsigned int, unsigned int, unsigned int, unsigned int, LOCKMODE)Срабатывает, когда запрос на тяжёлую блокировку (блокировку lmgr) переходит в состояние ожидания, поскольку блокировка недоступна. Аргументы с arg0 до arg3 задают атрибуты, идентифицирующие объект, на который накладывается блокировка. arg4 задаёт тип объекта, на который накладывается блокировка. arg5 задаёт тип запрошенной блокировки.
lock-wait-done(unsigned int, unsigned int, unsigned int, unsigned int, unsigned int, LOCKMODE)Срабатывает, когда запрос на тяжёлую блокировку (блокировку lmgr) выходит из состояния ожидания (т. е. получает блокировку). Аргументы аналогичны lock-wait-start.
deadlock-found()Срабатывает, когда детектор взаимных блокировок обнаруживает такую взаимную блокировку

Таблица 28.23. Предопределённые типы, используемые в параметрах точек трассировки

ТипОпределение
LocalTransactionIdunsigned int
LWLockModeint
LOCKMODEint
BlockNumberunsigned int
Oidunsigned int
ForkNumberint
boolchar

28.5.3. Использование точек трассировки

В приведённом ниже примере показан скрипт DTrace для анализа числа транзакций в системе, который можно использовать в качестве альтернативы созданию снимка данных pg_stat_database до и после выполнения теста производительности:

#!/usr/sbin/dtrace -qs

postgresql$1:::transaction-start
{
      @start["Start"] = count();
      self->ts  = timestamp;
}

postgresql$1:::transaction-abort
{
      @abort["Abort"] = count();
}

postgresql$1:::transaction-commit
/self->ts/
{
      @commit["Commit"] = count();
      @time["Total time (ns)"] = sum(timestamp - self->ts);
      self->ts=0;
}

При выполнении этот D-скрипт возвращает результат вида:

# ./txn_count.d `pgrep -n postgres` or ./txn_count.d <PID>
^C

Start                                          71
Commit                                         70
Total time (ns)                        2312105013

Примечание

SystemTap использует отличную от DTrace нотацию для скриптов трассировки, хотя лежащие в их основе точки трассировки совместимы. Стоит отметить, что на момент написания этой главы в скриптах SystemTap имена точек трассировки должны обрамляться двойными подчёркиваниями, а не дефисами. Ожидается, что эта проблема будет решена в следующих версиях SystemTap.

Необходимо помнить, что скрипты DTrace должны быть аккуратно написаны и отлажены, в противном случае собранная трассировочная информация может оказаться бессмысленной. В большинстве случаев причиной обнаруженных проблем является инструментарий, а не сама система. Отправляя на рассмотрение данные, полученные с использованием динамической трассировки, обязательно прилагайте скрипт, с помощью которого они были получены, для того чтобы его также проверить и обсудить.

28.5.4. Задание новых точек трассировки

Новые точки трассировки разработчик может определить в любом участке кода, однако это потребует перекомпиляции. Ниже приведены шаги, необходимые для добавления новых точек трассировки:

  1. Определить имена точек трассировки и данные, которые будут доступны в этих точках

  2. Добавить описание точек трассировки в src/backend/utils/probes.d

  3. Включить pg_trace.h, если его ещё не использовали в модуле (модулях), содержащих точки трассировки, и вставить TRACE_POSTGRESQL отладочные макросы в нужные места исходного кода

  4. Перекомпилировать и убедиться в доступности новых точек трассировки

Пример: Вот пример того, как можно добавить точку для трассировки всех новых транзакций по их идентификатору.

  1. Устанавливаем, что проба будет называться transaction-start и принимать параметр типа LocalTransactionId

  2. Добавляем определение пробы в src/backend/utils/probes.d:

    probe transaction__start(LocalTransactionId);

    Обратите внимание на использование двойного подчёркивания в имени пробы. В скрипте DTrace, использующем эту точку, двойное подчёркивание нужно будет заменить дефисом, поэтому в документации для пользователей имя этой пробы — transaction-start.

  3. Во время компиляции transaction__start преобразуется в макрос TRACE_POSTGRESQL_TRANSACTION_START (обратите внимание, что здесь используется одинарное подчёркивание), который доступен в результате включения pg_trace.h. Добавим вызов макроса в требуемую точку исходного кода. В данном случае это будет выглядеть приблизительно так:

    TRACE_POSTGRESQL_TRANSACTION_START(vxid.localTransactionId);
  4. После перекомпиляции и запуска нового бинарного файла используйте следующую команду DTrace, чтобы проверить доступность только что добавленной пробы. Должен получиться результат, подобный этому:

    # dtrace -ln transaction-start
       ID    PROVIDER          MODULE           FUNCTION NAME
    18705 postgresql49878     postgres     StartTransactionCommand transaction-start
    18755 postgresql49877     postgres     StartTransactionCommand transaction-start
    18805 postgresql49876     postgres     StartTransactionCommand transaction-start
    18855 postgresql49875     postgres     StartTransactionCommand transaction-start
    18986 postgresql49873     postgres     StartTransactionCommand transaction-start
    

При добавлении макросов трассировки в код, написанный на языке C, необходимо позаботиться о следующем:

  • Нужно убедиться, что типы данных, определённые в параметрах пробы, совпадают с типами данных переменных, которые используются в макросе. В противном случае компиляция завершится с ошибками.

  • В большинстве платформ в случае, если Postgres Pro собран с указанием --enable-dtrace, то аргументы макроса трассировки вычисляются каждый раз, когда макрос получает управление, даже если трассировка не выполняется. Об этом не стоит беспокоиться, если вы просто возвращаете значения небольшого числа локальных переменных. Однако избегайте использования ресурсоёмких вызовов функций в аргументах. Если это необходимо, то постарайтесь защитить макрос проверкой, которая будет определять, действительно ли включена трассировка:

    if (TRACE_POSTGRESQL_TRANSACTION_START_ENABLED())
        TRACE_POSTGRESQL_TRANSACTION_START(some_function(...));

    Каждый макрос трассировки имеет соответствующий макрос ENABLED.