Логирование

Из всех сквозных функций логирование появилось в курсе первым не случайно: пока у сервиса нет метрик и трейсинга, лог — единственный свидетель о жизни. Но пакет kitlog решает более глубокую задачу, чем вывод строк: он делает событие структурой. Вызов logger.Log("method", "uppercase", "err", err) — это не строка, а набор пар ключ-значение, который форматтер рендерит на выходе как угодно: logfmt для консоли разработчика, JSON для сборщика логов платформы. Причина проста: в микросервисах логи читает не человек, а конвейер — grep по ключу, группировка, алерт; строка «failed to process» для него мусор, а пара "method", "uppercase" — индексируемое поле. Поэтому go kit логирование начинается с вопроса «какие ключи будут у события», а не «что напечатать». Ты уже видел kitlog в уроке 04: kitlog.NewJSONLogger(os.Stdout) и logger.Log("msg", "listening", "addr", ":8080") — сегодня разберём каждую букву этого заклинания и соберём из него настоящий наблюдательный слой.

Откроем исходники пакета github.com/go-kit/log — весь интерфейс умещается в одну сигнатуру: type Logger interface { Log(keyvals ...interface{}) error }. Это осознанный минимализм в духе endpoint: никаких уровней, имён полей, форматтеров в контракте — только пары. Три следствия, которые надо понять сразу. Первое: пары идут чётно — ключ, значение, ключ, значение; если передать нечётное количество, логгер не упадёт, а подставит в хвост значение ErrMissingValue — константу с текстом (MISSING), и в логе появится громкий маркер ошибки программиста. Второе: Log возвращает error, и по общему соглашению курса его игнорируют: в defer-обёртках пишут _ = logger.Log(...). Падать из-за невозможности записать лог — путь к каскадной аварии. Третье: реализация обязана быть безопасной для конкурентного доступа и не менять переданные keyvals — контракт записан в доке пакета, и на него опирается вся композиция. Один интерфейс, а в результате любой компонент — middleware, транспорт, клиент — принимает log.Logger и не знает, куда именно едет вывод: stdout, файл, syslog или сетевой коллектор.

Главный инструмент kitlog — функция log.With(logger, keyvals...), возвращающая новый Logger с добавленными парами. Слои складываются: базовый With в main задаёт ts и caller, middleware поверх добавляет request_id, и каждая строка лога собирает их все — без передачи логгера по аргументам через весь стек. Пара слов о направлении: With добавляет пары в конец (ближе к твоим данным), WithPrefix — в начало (ближе к ts), и именно WithPrefix используют хелперы пакета level. Значения в With могут быть не константами, а Valuer — функциями func() interface{}; они перевычисляются на каждый вызов Log. Из коробки есть log.Timestamp(t func() time.Time), готовые DefaultTimestamp и DefaultTimestampUTC (обе — RFC3339Nano, вторая в UTC) и DefaultCaller. Свой Valuer пишется за минуту — например, генератор request id, если тот не пришёл в заголовке. Важная граница: слой With — место для контекста вызова (какой сервис, какой компонент пишет), а не для данных конкретного запроса; тело запроса в слой With не кладут никогда, для него есть поля события.

Вопрос, который тебе зададут на ревью: почему не написать logger.Log прямо в методе сервиса? Ответ — тот же принцип, что и весь курс. Сервис из урока 03 не знает ни о транспорте, ни о форматтерах: суй ему logger — и появится зависимость от инфраструктуры в самом чистом слое, а тесты сервиса потащат моки логгера. Endpoint-middleware — слой между транспортом и endpoint'ом: он видит и request, и response, и err, но остаётся транспорт-агностичным. Повесь один и тот же loggingMiddleware на HTTP-endpoint сегодня и на gRPC-endpoint из урока 13 завтра — логи поедут в обоих случаях, сервис не узнает об этом. Сравни уровни, куда можно вставить лог: декодер/энкодер знают только транспорт, endpoint-middleware знает операцию целиком, service middleware из урока 15 — даже бизнес-контекст, но требует интерфейса сервиса. Правило выбора: лог операции с временем и err — endpoint-middleware; лог бизнес-события («заказ создан») — service middleware; лог транспортных деталей — ServerFinalizer, о котором ниже.

В уроке 04 мы обещали: идентификатор запроса появится в уроке про логи. Схема из двух частей. Часть первая — ServerBefore: RequestFunc читает заголовок X-Request-ID (или генерирует новый) и кладёт его в контекст с приватным ключом; теперь значение едет через endpoint в сервис и доступно любому слою. Часть вторая — ServerFinalizer: опция NewServer принимает ServerFinalizerFunc func(ctx context.Context, code int, r *http.Request) и вызывается после того, как ответ уже записан клиенту; это официальное место для лога запроса: method, uri, статус код, длительность, размер ответа. Именно поэтому finalizer'а есть доступ к response headers и размеру: когда опция установлена, Server оборачивает ResponseWriter в interceptingWriter и складывает их в контекст под ключами ContextKeyResponseHeaders и ContextKeyResponseSize. Корреляция собирается в цепочку: клиент шлёт X-Request-ID → ServerBefore кладёт в ctx → endpoint-middleware логирует операцию → finalizer логирует запрос; в платформе логов по одному request_id разворачивается весь путь вызова через все сервисы.

В интерфейсе Logger нет уровней — и это не упущение, а точка расширения. Уровень в go-kit логировании — просто ещё одна пара в событии, по умолчанию ключ level со значениями debug, info, warn, error. Пакет github.com/go-kit/log/level даёт удобные хелперы: level.Error(logger) возвращает логгер с префиксом level=error, и далее level.Info, level.Warn, level.Debug — все они построены на log.WithPrefix над твоим логгером. Зачем нужен ключ, если можно писать "level", "error" руками: чтобы работала вторая половина пакета — фильтр. level.NewFilter(logger, level.AllowInfo()) оборачивает базовый логгер и пропускает только события с уровнем info и выше: debug-записи пишутся в коде всегда, но молчат в проде, где фильтр AllowInfo, и шумят локально, где AllowDebug. Важные дефолты фильтра: без опций он давит ВСЕ leveled-события (собери фильтр с Allow... — иначе ничего не увидишь), а события без уровня проходят мимо фильтра, пока ты не включил опцию SquelchNoLevel. Уровень — не замена тексту, а измеримая размерность: алерт платформы смотрит на rate error-событий, а не парсит слова.

Логи — данные, которые ты отправляешь неизвестно куда на годы вперёд, поэтому гигиена важнее многословия. Пароли, токены, заголовок Authorization — никогда, ни в debug, ни при ошибке; запрос с JWT в логе — это слитый доступ. Персональные данные — с осторожностью: имя и почта в логе делают его субъектом GDPR и удорожают хранение; часто достаточно хешированного идентификатора. Тела запросов целиком — только в debug и только на низовых окружениях: строка с телом в error-логе на проде быстро превращается в хранилище личных переписок. Про объём тоже думай: лог на каждый запрос — норма, лог на каждый внутренний цикл — инцидент бюджета; при всплесках помогает семплирование. И последнее — длина ключей: короткие имена (ts, err, took) — конвенция kitlog, они экономят и место, и глаза; главное — договориться об одном словаре ключей на все сервисы платформы, иначе фильтры коллектора будут враждовать с твоими названиями.

Сервис обрёл голос: структура события вместо строк, слои With вместо передачи логгера по стеку, уровни через фильтр, request id через ServerBefore и финальный лог запроса через ServerFinalizer. Вернуть контекст обёрток можно в уроке 02-endpoint, к опциям транспорта — в уроке 04-http-transport, к кодеку ошибок — в уроке 05-codeki; полная программа — на странице курса. Логирование — первый наблюдательный слой; второй — урок 07-metriki: Counter, Gauge и Histogram пакета metrics, prometheus-реализации, латентность в гистограмме и instrumenting middleware рядом с тем loggingMiddleware, который ты только что написал. Третье измерение — трейсинг — ждёт в уроке 08: там запросы получат сквозные спаны, и request id из этого урока окажется их предком.