Тестирование логов: capture и утверждения

Логи редко попадают в тесты — и напрасно: для дежурного в инциденте лог — такой же контракт, как ответ API. Если поле request_id пропало из записей, поиск по запросу сломается без единой ошибки в коде; если маска секретов перестала срабатывать, токены поедут в хранилище молча. Механика slog делает логи удобными для тестов: обработчик принимает любой io.Writer, поэтому тест подставляет буфер или собственный Handler в память и проверяет записи обычными утверждениями. В этом уроке соберём оба приёма, разберём, что именно проверять, а что — лишняя хрупкость, и добавим золотые строки для формата вывода, когда он становится контрактом конвейера сбора.

Тестирование логов go: захват вывода в буфер#

Приём-минимум: в тесте создаётся bytes.Buffer, логгер поверх него — и вызовы функции под тестом пишут в буфер, а не в stdout. Дальше буфер разбирается: json.Unmarshal превращает запись в map[string]any, и поля проверяются обычными сравнениями. Это честный тест конца в конце: он проходит через Handler, форматирование и сериализацию, то есть проверяет то же, что увидит конвейер сбора. Для тестов без зависимостей от JSON подойдёт свой Handler в памяти — он собирает slog.Record напрямую, и проверка идёт по уровню и атрибутам без парсинга. Оба приёма живут рядом: буферный тест проверяет формат и поля вывода, Handler-тест — поведение кода: сколько записей, какие уровни, какие атрибуты. Важная оговорка про контекст: вызовы через slog.Debug на отключённом уровне не вызывают сборку атрибутов — тест может проверить и это: буфер пуст, значит дорогой атрибут не собирался, что перекликается с механикой Enabled из четырнадцатого урока.

Захват в буфер и разбор записи

func TestCheckoutLogs(t *testing.T) {
        var buf bytes.Buffer
        logger := slog.New(slog.NewJSONHandler(&buf, nil))

        processCheckout(logger, "a-42")

        var rec map[string]any
        if err := json.Unmarshal(buf.Bytes(), &rec); err != nil {
                t.Fatalf("запись не разобралась: %v", err)
        }
        if rec["msg"] != "заказ оплачен" {
                t.Errorf("msg = %v, хочу заказ оплачен", rec["msg"])
        }
        if rec["order"] != "a-42" {
                t.Errorf("order = %v, хочу a-42", rec["order"])
        }
}

Буфер подставлен как io.Writer — Handler не знает, что пишет в тест. json.Unmarshal отдаёт поля для проверок: msg и атрибуты сравниваются напрямую. Честная деталь: числа после Unmarshal приходят как float64, поэтому числовое поле сравнивают с float64(2), а не с int — иначе тест падает на типе, а не на значении.

Проверка полей: уровень, msg и атрибуты#

Проверять всё — путь к хрупким тестам, которые ломаются на каждом переименовании. Проверяют поля-контракты: уровень, по которому фильтрует дежурный; поля, по которым ищут в хранилище — request_id, order, user_id; поле err, которое встроенные обработчики сериализуют строкой Error(). Текст msg проверяют реже: сообщение — для человека, и его правки не должны ронять сборку, если это не сообщение-сигнал вроде кода ошибки. Несколько записей разбирают json.Decoder в цикле — буфер содержит поток записей по одной на строку, и декодер возвращает их по порядку: тест проверяет и состав, и последовательность, например, что перед Error был Warn с тем же request_id. Проверка отсутствия записи — тоже утверждение: после успешного выполнения в буфере не должно быть записей уровня Error, и это ловит регресс, при котором ошибки начинают логироваться там, где всё отработало.

Handler в память: свой тестовый обработчик#

Свой Handler снимает зависимость от формата: тест проверяет записи, а не строки. Реализация компактна: структура со слайсом записей и предзаданными атрибутами, Enabled возвращает true, Handle добавляет рекорд в слайс, WithAttrs подмешивает поля, WithGroup в упрощённой версии игнорируется — для полного контракта обработчик сначала прогоняют через log/slogtest. Ключевая деталь в Handle — r.Clone(): рекорд переиспользуется после возврата Handle, и без копии сохранённые записи могут показать чужие атрибуты. Проверка идёт по slog.Record: r.Level сравнивается с slog.LevelError, r.Message — с сообщением, атрибуты — циклом по Attr. Такой тест не привязан к JSON, кавычкам и порядку полей, и его уместно держать рядом с тестами маскирования: Handler в память покажет, что до вывода дошло значение или маска.

TestHandler со слайсом записей

type testHandler struct {
        records *[]slog.Record
        attrs   []slog.Attr
}

func (h *testHandler) Enabled(_ context.Context, _ slog.Level) bool { return true }

func (h *testHandler) Handle(_ context.Context, r slog.Record) error {
        r.AddAttrs(h.attrs...)
        *h.records = append(*h.records, r.Clone())
        return nil
}

func (h *testHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
        merged := append(slog.Attr{}, h.attrs...)
        return &testHandler{records: h.records, attrs: append(merged, attrs...)}
}

func (h *testHandler) WithGroup(string) slog.Handler { return h }

Handle сохраняет копию рекорда в общий слайс — указатель на слайс разделяется между потомками через WithAttrs и WithGroup, поэтому тест видит весь поток записей. r.Clone() обязателен: рекорд переиспользуется, и без копии атрибуты последующих записей затирают сохранённые. WithGroup возвращает приёмника без префиксов — упрощение для тестов, полный контракт проверяет log/slogtest.

Общий буфер и t.Parallel: гонка

Кейс: пакетные тесты логировали в один общий logger с общим буфером на уровне пакета. После добавления t.Parallel в два теста CI начал падать редкими битыми записями — половина JSON на середине строки. Причина — гонка: два теста пишут в один буфер, append межуется, разбор видит смесь. go test -race ловит это сразу, но флаг часто включают уже после первого красного прогона. Фикс: конструктор newTestLogger(t), который создаёт свой буфер и свой логгер на каждый тест, — общий остаётся только Helper с кодом разбора. Правило: writer логгера живёт в пределах одного теста; если нужен общий список записей — наружу отдаётся копия, а не ссылка.

Золотые строки вывода: сравнение целиком#

Когда формат вывода становится контрактом — для парсера конвейера, для внешнего мониторинга, — записи сравнивают целиком: ожидаемая строка хранится в файле или в коде, и тест сравнивает буфер с ней посимвольно. Это самый строгий тест: любое изменение формата, порядок полей, экранирование — всё ловится сразу. И самый хрупкий: поле time меняется каждую секунду, поэтому в золотом сравнении время фиксируют — ReplaceAttr подменяет time на константу в тестовом HandlerOptions, — а иначе сравнение сравнивает часы. Второй подводный камень — порядок атрибутов: Handler печатает их в порядке передачи, и тест фиксирует этот порядок как часть контракта; для JSON его стоит зафиксировать осознанно, раз конвейер зависит от полей, а не от порядка. Золотые строки уместны на границе сервиса — там, где формат читает чужая система; внутри тесты полей дают больше пользы на меньше хрупкости.

Спорное: тестировать ли каждый лог#

Мнение, которое стоит оспорить на ретро: каждый вызов логирования заслуживает теста — иначе логи расползаются. Против: лог — побочный эффект, и тесты на каждое сообщение превращают любое улучшение формулировки в правку тестов; пользы в проверке текста msg почти нет, а хрупкость реальна. За: часть логов — инструмент инцидента, и его контракты стоят тестов: поля, по которым ищут, уровень, по которому фильтруют алерты, маскирование секретов. Компромисс, который прижился: тесты на поля-контракты и на отсутствие ошибочных записей в штатных сценариях, тест на маскирование — обязательный; тексты сообщений живут без тестов. Граница по потребителю: если запись читает конвейер или внешний монитор — тест есть; если запись подсобная отладочная — без теста, и это осознанное решение. Тот же принцип, что и у любых тестов: проверяются обещания, а не слова.

Что проверяем и чем#

Что проверяем	Механика	Когда уместно
Поля-контракты	json.Unmarshal в map, сравнение значений	request_id, order, err — поля поиска
Уровень записи	rec["level"] или r.Level в своём Handler	алерты и фильтры дежурных
Маскирование	фикстура с секретом, проверка маски	обязательный тест каждого сервиса
Несколько записей	json.Decoder в цикле по буферу	порядок и состав потока записей
Формат вывода	золотая строка с фиксированным time	формат читает чужая система
Свой Handler	log/slogtest плюс тесты формата	обработчик из двенадцатого урока

log/slogtest: контракт своего Handler

Для собственных Handler с Go 1.22 есть пакет log/slogtest: функция slogtest.Run прогоняет обработчик через сценарии — обычные записи, группы, WithAttrs, WithGroup — и проверяет, что вывод согласован между собой. Свой обработчик из двенадцатого урока стоит сначала прогнать через slogtest, а уже потом покрывать тестами формата: контракт с группами легко сломать, не заметив. Тестовый Handler в память из этого урока — упрощение, и log/slogtest честно укажет, что WithGroup без префиксов нарушает контракт.

Чек-лист тестов логов#

Логгер в тесте получает свой io.Writer: буфер для строк, слайс для записей.
Поля-контракты проверяются после json.Unmarshal: level, request_id, err.
Числа из JSON приходят float64: сравнивайте с float64(2), а не с int.
Свой testHandler копит slog.Record с r.Clone() в Handle.
Writer живёт в пределах теста: общий буфер и t.Parallel дают гонку, -race подтверждает.
Золотые строки — только с фиксированным time через ReplaceAttr.

Песочница: записи и сравнение на strings.Builder

Пакетов testing и log/slog в песочнице нет — там работают fmt, strings, strconv, math, sort, errors и time. Механику захвата она разминает честно: соберите функцию, которая пишет записи в strings.Builder через fmt.Fprintf, и сравнения-утверждения поверх неё — strings.Contains для поля, strings.Count для числа записей, обнуление буфера через builder.Reset(). Превращение числа в строку записи и обратно разминается на strconv.ParseFloat и strconv.Itoa — это модель float64 после json.Unmarshal. Полные тесты с testing и slogtest запускаются локально через go test.

Проверка: Clone в Handle

Зачем в Handle своего тестового Handler вызывать r.Clone() перед сохранением записи в слайс?

Проверка: число из JSON

В тесте после json.Unmarshal буфера сравнение rec["count"] с 2 даёт false, хотя в записи написано "count":2. Почему?

Что напечатает счётчик записей?

Прочитайте код и выберите, что он выведет:

var buf bytes.Buffer
logger := slog.New(slog.NewJSONHandler(&buf, &slog.HandlerOptions{
        Level: slog.LevelWarn,
}))

logger.Info("первая", "n", 1)
logger.Warn("вторая", "n", 2)

fmt.Println(strings.Count(buf.String(), "\n"))

Соберите захват в буфер

Допишите: создание буфера, JSON-обработчик и тип для разбора записи.

var buf bytes. logger := slog.New(slog.NewHandler(&buf, nil)) logger.Info("заказ оплачен", "order", "a-42") var rec map[string] if err := json.Unmarshal(buf.Bytes(), &rec); err != nil { t.Fatalf("запись не разобралась: %v", err) }

Тест записи по строкам

Расставьте по порядку: буфер, логгер, запись под тестом, разбор, утверждение по полю.

Строки

Ваша программа

Нажимайте на строки слева, чтобы собрать программу

Карточки: тестирование логов

Термин

capture в буфер

нажмите, чтобы перевернуть

Определение

Handler пишет в bytes.Buffer: тест разбирает записи json.Unmarshal и проверяет поля обычными сравнениями.

1 / 6

Логи стали контрактом: захват в буфер проверяет поля вывода, Handler в память — поток записей, золотые строки — формат на границе, тест маскирования — секреты. Дальше по курсу: двенадцатый урок про свой Handler даёт материал для slogtest, тринадцатый — конкурентные сценарии под -race, пятый — форматы, девятнадцатый — обязательный тест на маску, двадцать пятый — итоговый проект с тестами логов. Приёмы тестирования целиком — в уроке про тестирование курса по продвинутому Go и в курсе по testify. Карта курса — на странице курса.

Песочница урока

Редактируйте код и запускайте его прямо здесь — интерпретатор работает в браузере, ничего устанавливать не нужно. За каждый запуск — +2 XP.

Вывод

Запустите код, чтобы увидеть вывод.

Коротко: что запомнить

Захват в буфер: bytes.Buffer как io.Writer, json.Unmarshal в map, сравнения по полям.
Проверяют поля-контракты — уровень, поля поиска, err; тексты msg живут без тестов.
Свой testHandler копит slog.Record: r.Clone() в Handle обязателен, рекорд переиспользуется.
Числа после json.Unmarshal приходят float64: сравнение с int ложно даже при равных значениях.
Общий буфер и t.Parallel дают гонку: writer живёт в пределах одного теста, -race подтверждает.
log/slogtest с Go 1.22 проверяет контракт своего Handler: группы, WithAttrs, WithGroup.

Домашнее задание

Возьмите функцию из своего проекта или из урока и покройте тремя тестами: захват в буфер с проверкой полей и уровня, свой testHandler с подсчётом записей и тест на отсутствие записей уровня Error в штатном сценарии. Затем запустите go test -race и добавьте t.Parallel в два теста с общим буфером — посмотрите на гонку и почините её конструктором newTestLogger с личным буфером на тест.

Вопросы и ответы по уроку

Что лучше в тестах: буфер с JSON или свой Handler в память?

Оба приёма работают вместе: буферный тест проверяет то, что увидит конвейер — формат, экранирование, поля; Handler в память проверяет поведение кода без привязки к формату — число записей, уровни, атрибуты. Для формата вывода уместен первый, для бизнес-логики логирования — второй.

Как тестировать записи с полем time?

В буферном тесте поле просто игнорируется — сравниваются только контракты. В золотых строках время фиксируют ReplaceAttr в тестовых HandlerOptions: на выход идёт константа, и сравнение становится посимвольным. Проверять, что время стоит и выглядит RFC3339, лучше отдельным утверждением по формату, а не золотой строкой.

Нужно ли тестировать формат текста сообщений?

Обычно нет: msg пишут для человека, и его правки не должны ломать сборку. Исключение — сообщения-сигналы, по которым строят алерты или поиск в хранилище: если дежурный ищет по подстроке, сообщение становится контрактом и получает тест, как любое поле.

Термины урока

Ключевые понятия из этого урока — короткие определения в глоссарии. Наведите на термин, чтобы вспомнить, откройте карточку для подробностей и ссылки на практику.