Логирование и трассировка pgx

Интерфейс из tracer.go выглядит так: TraceQueryStart(ctx context.Context, conn pgx.Conn, data pgx.TraceQueryStartData) context.Context и TraceQueryEnd(ctx context.Context, conn pgx.Conn, data pgx.TraceQueryEndData). В данных старта — SQL и слайс аргументов; в данных конца — CommandTag с числом затронутых строк и Err. Хук начала возвращает контекст, и именно он приезжает в хук конца: это единственный канал передачи данных между хуками, и через него несут, например, время старта. Дизайн важный: в TraceQueryEndData нет SQL — если хотите логировать запрос целиком в конце, положите его в контекст в начале. Один QueryTracer покрывает Exec, Query и QueryRow: драйвер не различает их, для него это один путь. Трейсер получает conn, и через conn.PgConn().PID() можно достать идентификатор серверного процесса — полезно, когда запрос висит в pg_stat_activity и его нужно срастить с логом.

Рабочий набор полей короткий: обрезанный SQL, длительность, число затронутых строк, ошибка и идентификатор процесса — PID, полученный через conn.PgConn().PID(), позволяет найти зависший запрос в pg_stat_activity по логу. Аргументы — самая спорная часть. С одной стороны, без args медленный INSERT не воспроизвести; с другой — в аргументах живут персональные данные, токены и пароли, и лог-система с удержанием на месяц превращает отладочное удобство в утечку. Компромисс стандартный: в разработке логируем всё, в проде — SQL без аргументов, либо обрезаем и маскируем значения. Готовые решения экономят: пакет tracelog перед печатью режет строки и байты длиннее шестидесяти четырёх символов с пометкой о размере — история не пухнет на блобах, хотя о чувствительности это не спасает. Вторая ось — объём: на тысяче запросов в секунду лог каждого запроса рождает гигабайты и душит сборщик логов, поэтому в проде пишут только ошибки и slow query log, а полный поток оставляют dev-окружению и временным включениям по флагу.

QueryTracer — не единственный интерфейс. В том же tracer.go живут PrepareTracer с методами TracePrepareStart и TracePrepareEnd (данные: имя стейтмента, SQL, флаг AlreadyPrepared), BatchTracer для SendBatch, CopyFromTracer для COPY и ConnectTracer для события установления соединения. Механика единая: драйвер проверяет ваш трейсер на соответствие каждому интерфейсу и зовёт те хуки, которые он реализует. Prepare-события приходят и при явном conn.Prepare, и при неявной подготовке в режимах с кэшем стейтментов: AlreadyPrepared равно true, когда стейтмент взят из кэша — по этим записям видно, как греется кэш. Чтобы повесить несколько трейсеров сразу, поле Tracer одно, но в свежих выпусках v5 есть пакет multitracer: multitracer.New(a, b) собирает из двух трейсеров один, раскладывая их по интерфейсам автоматически. Без него роль свёртки выполняет собственный враппер в десяток строк — писать его или тянуть multitracer, дело вкуса, но два хука slow-трейсера и полный tracelog совместимы без проблем.

Писать трейсер с нуля необязательно: в поставке pgx есть пакет github.com/jackc/pgx/v5/tracelog со структурой TraceLog — она реализует сразу QueryTracer, BatchTracer, CopyFromTracer, ConnectTracer и даже трейсеры Acquire и Release пула, так что одним значением закрывается весь цикл жизни соединения. Настройка — два поля: Logger и LogLevel. Уровни свои, от LogLevelTrace и LogLevelDebug через Info и Warn до LogLevelError и LogLevelNone. Успешный запрос логируется на Info с полями sql, args, time и commandTag, ошибка — на Error с полем err, Prepare — отдельным сообщением с alreadyPrepared, acquire и release пула — на Debug. Интерфейс Logger из tracelog описывает один метод Log(ctx, level, msg, data map[string]any), и адаптер на slog — это switch по уровню плюс разворачивание карты в пары ключ-значение. Уровень LogLevelInfo покажет каждый запрос; LogLevelError превратит tracelog в тихого сторожа только для сбоев.

Трейсинг не бесплатен, но дёшев: на каждый запрос — два вызова интерфейса и, если носите данные, один context.WithValue с аллокацией. На фоне сетевого рейса в Postgres это шум, однако на горячих путях с десятками тысяч мелких запросов в секунду даже такой overhead становится измеримым, а полный лог — заметной статьёй расходов на диск и сеть сборщика. Правило то же, что и с args: полный трафик — в разработке, в проде — ошибки и slow query log, полный режим включается флагом на время разбора инцидента. Когда SQL-лог указал на медленный запрос, следующий шаг — EXPLAIN из двадцать второго урока: трейсер даёт кандидата, план объясняет причину. Отдельная ветка — распределённая трассировка: для OpenTelemetry есть готовая обвязка otelpgx от exaring, которая реализует те же pgx-интерфейсы и создаёт спан на каждый запрос; её трейсер ставится в ConnConfig.Tracer так же, как ваш собственный, а при необходимости совмещается с лог-трейсером через multitracer. Логи отвечают на вопрос что тормозило, спаны — где в цепочке вызовов.