--- title: "Тестирование логов: zaptest и observer" description: "zaptest и zaptest/observer: тестирование логов go — записи с полями в тестах, FilterField, zaptest.Logger для библиотек, детерминизм времени. Примеры тестов." course: "Zap: структурное логирование на Go" url: "https://golangmaster.ru/courses/zap/lessons/20-testirovanie-logov/" published: "2026-09-19" updated: "2026-09-21" minutes: 16 --- # Тестирование логов: zaptest и observer *Курс «Zap: структурное логирование на Go», урок 20 из 25. ~16 минут. Обновлено 21.09.2026. Источник: https://golangmaster.ru/courses/zap/lessons/20-testirovanie-logov/* zaptest — это два инструмента из экосистемы zap для тестирования логов: пакет zaptest/observer превращает записи в проверяемый список с уровнями, сообщениями и полями, а zaptest.Logger пишет лог прямо в вывод теста. Ниже — как проверить, что код логирует Warn при недоступности шлюза, и не догадываться об этом по прод-дашбордам. Заодно — горутины кода под тестом, табличные проверки уровней и правило, почему сэмплер из боевого конфига в тестовый логгер не ставят. «При недоступности шлюза мы логируем Warn» — говорят на планёрке, а в коде это Info, и никто не заметил. Логи — часть контракта: дашборды, алерты и рантбуки завязаны на уровни, сообщения и поля, и молча испорченная запись ломает разбор инцидентов не хуже бага в бизнес-коде. Тестирование логов go-приложения закрывает это без моков и парсинга текста: observer даёт записи как объекты, zaptest — логгер для библиотек, который пишет в вывод go test. Оба инструмента идут в комплекте zap, ничего придумывать не нужно. ### zaptest/observer: логи как записи в тесте Пакет go.uber.org/zap/zaptest/observer даёт пару: observer.New(zapcore.InfoLevel) возвращает ядро и накопитель ObservedLogs. Ядро подставляется в zap.New как обычный Core — код под тест не знает, что пишет в наблюдателя, и гоняет боевой zap.Logger, а не заглушку. Каждая запись попадает в накопитель как LoggedEntry: уровень, сообщение, время и слайс полей Context. Уровень enabler работает как в проде: записи ниже порога не сохраняются, и поведение логгера в тесте совпадает с боевым, включая With и Named. Это главное отличие от подхода «перехватим stdout и распарсим JSON»: формат вывода не тестируется вовсе, а проверяется то, что реально попадёт в систему сбора. ### Полный тест на Warn-запись ```go func TestSlowSQLWarns(t *testing.T) { core, logs := observer.New(zapcore.InfoLevel) logger := zap.New(core) reportSlowSQL(logger, "orders", 350*time.Millisecond) entries := logs.All() if len(entries) != 1 { t.Fatalf("want 1 entry, got %d", len(entries)) } if entries[0].Level != zapcore.WarnLevel { t.Errorf("level = %v, want warn", entries[0].Level) } if entries[0].Message != "slow sql" { t.Errorf("message = %q, want slow sql", entries[0].Message) } if ms := entries[0].ContextMap()["ms"]; ms != int64(350) { t.Errorf("ms = %v, want 350", ms) } } ``` Порядок: собрать пару ядро-накопитель, передать логгер в код, вызвать, проверить. All возвращает снимок записей, Level и Message сравниваются напрямую, ContextMap достаёт поле по имени. zap.Int64 в коде совпадает с int64 в карте — типы полей сверяются буквально, и ошибка в типе поля ловится тестом раньше системы сбора. Первый ассерт — длина: при лишних записях ошибка говорит о шуме, а не о пропавшем поле, и виновника видно по соседним записям снимка. Формулировки t.Fatalf с фактическим значением экономят минуту на каждый прогон после правки. ### API ObservedLogs: фильтры и Len ObservedLogs покрывает типовые проверки без ручных циклов. Len считает записи, All возвращает всё, TakeAll вынимает записи и очищает накопитель — удобно для сценария «первый вызов дал одну запись, второй не дал ничего». Фильтры FilterMessage, FilterMessageSnippet и FilterField возвращают укороченный ObservedLogs, и проверки читаются как предложения: логи, где сообщение про slow, где поле table равно orders. AllUntimed возвращает записи с обнулённым временем — для сравнения списков без меток. Уровень enabler — граница: всё, что ниже Info, копиться не будет. Если код под тест пишет Debug, ставьте DebugLevel в observer.New, иначе тест увидит пустоту и соврёт вам о поведении кода. Ещё один фильтр — FilterFieldSnippet(key, подстрока): записи, у которых строковое значение поля с данным ключом содержит фрагмент, — удобно для частичных совпадений без привязки к точной формулировке. > **Типичная ошибка: observer под сэмплером.** Если тестовый логгер собирается как боевой — с NewSamplerWithOptions поверх ядра, — observer получает прореженный поток: первые сто записей за тик, дальше по одной. Тест, рассчитанный на три записи, ловит одну и флакает от скорости машины: тик успел смениться или нет. В тестах сэмплер не ставят: observer должен видеть всё, что решил написать код, — прореживание это отдельное решение прод-конфигурации, а не поведение кода под тестом. ### Проверка: порог enabler **Вопрос:** observer.New(zapcore.InfoLevel). Код под тест вызывает logger.Debug("tick"). Сколько записей вернёт logs.All()? - Одну: Debug записывается всегда - ✅ Ноль: Debug ниже порога enabler - Панику: уровень не зарегистрирован - Зависит от zap.New(core) Enabler работает как боевое ядро: Debug ниже Info — Check вернёт nil, записи нет. Тест, который ждёт Debug-запись, должен создать observer.New(zapcore.DebugLevel). ### Проверка полей, уровня и сообщения Проверяйте контракт, а не вывод: уровень — на него первым смотрит алерт, сообщение — его ищут в рантбуке, поля — на них построены дашборды. Сообщение проверяйте целиком или через FilterMessageSnippet: точная строка ломается от правки формулировки, но и сниппет держите осмысленным — slow sql, payment declined. Поля сравнивайте по типам: zap.Int64 в коде и int64 в ContextMap — совпадение буквальное. Чего проверять не стоит: формат JSON, порядок полей, метку времени. Это решения энкодера, а не вашего кода, и завязывать тест на них — ломать сборку из-за смены конфигурации вывода. Хорошая проверка логов хрупче боевого кода не становится. ### Фильтры вместо циклов ```go if logs.FilterMessageSnippet("slow").Len() == 0 { t.Fatal("expected a slow sql warning") } orders := logs.FilterField(zap.String("table", "orders")) if orders.Len() != 1 { t.Fatalf("want 1 entry with table=orders, got %d", orders.Len()) } ``` FilterField принимает zapcore.Field — тот же конструктор, что в записи: совпадают ключ, тип и значение. Фильтры возвращают ObservedLogs, поэтому фильтры компонуются: сначала по сообщению, потом по полю. Len после фильтра — это и есть ассерт количества. Такой стиль читается в ревью без разбора циклов, и упавший тест говорит, какой именно контракт нарушен. ### Табличные тесты: контракт уровней Контракт «статус шлюза — уровень записи» — идеальный материал для табличного теста: список сценариев, один цикл, одна проверка. Сценарий — вход кода под тестом и ожидаемая запись: сообщение, уровень, ключевое поле. Перед каждой итерацией TakeAll очищает накопитель, и цикл смотрит только свои записи — ровно тот сценарий, ради которого TakeAll и придуман. Такой тест живёт рядом с политикой уровней из HTTP-урока и ловит то, о чём говорят на планёрках: кто-то поменял Warn на Info в одной ветке switch — табличный тест краснеет с названием сценария в сообщении. Пишется он один раз, при внедрении логирования, и правится вместе с политикой: цена строки в таблице несопоставима с ценой незаметно испорченного уровня в проде. ### zaptest.Logger: логгер для библиотек Библиотечный код не навязывает конфигурацию логов: он принимает *zap.Logger и пишет в него. В тестах этой библиотеки логгер даёт пакет zaptest: zaptest.NewLogger(t) строит логгер, который пишет каждую запись через t.Log, и запускается обычным go test на локальном Go без всякой обвязки. Две приятности бесплатно: записи привязаны к тесту, а go test показывает их только для упавших тестов или с флагом -v — успешный прогон не утопает в логах. Опции есть: zaptest.Level поднимает порог, zaptest.WrapCore подменяет ядро — так observer встраивается внутрь zaptest-логгера, когда хочется одновременно вывод в тест и проверки полей. Для простой библиотеки хватает NewLogger без опций. ### Проверка: порог zaptest.NewLogger **Вопрос:** zaptest.NewLogger(t) вызван без опций. Записи какого уровня дойдут до вывода теста? - Info и выше: пресет как в проде - ✅ Debug и выше: без опций порог — DebugLevel - Только Error: вывод теста экономят - Ни один: нужен явный zaptest.Level По умолчанию zaptest.NewLogger строит логгер на DebugLevel: библиотека под тестом пишет всё, а порог поднимают опцией zaptest.Level осознанно — когда болтовня мешает читать вывод упавшего теста. ### Библиотека под zaptest ```go func TestClientSilentOnSuccess(t *testing.T) { logger := zaptest.NewLogger(t) c := NewClient(logger) if err := c.Ping(context.Background()); err != nil { t.Fatalf("ping: %v", err) } // Записи уйдут в t.Log и появятся только при падении теста. } ``` Клиент получает *zap.Logger как в проде — зависимость без особых интерфейсов. При падении теста вывод t.Log покажет записи с уровнями и полями, и причину видно по логам, а не по догадкам. Флаг -v покажет те же записи и для успешного прогона, если нужно посмотреть глазами. > **Не оборачивайте логгер в свой интерфейс.** Ради тестируемости часто заводят интерфейс-обёртку над zap.Logger. With и Named в такой интерфейс не ложатся, поля теряются, а тесты мокают то, что в бою никогда не выполнится. Observer уже делает логи проверяемыми без обёрток: принимайте *zap.Logger и тестируйте реальный логгер. ### Детерминизм времени Каждая запись несёт время из реальных часов, и тест, сравнивающий Time с time.Now(), флакает: часы идут, планировщик дёргает, времена не равны. Практика, которая работает: время в тестах логов не сравнивать вообще. AllUntimed возвращает записи с обнулённым Time — сравниваются уровень, сообщение и поля, и тест перестаёт зависеть от скорости машины. Если логика завязана на длительность, проверяйте поле Duration, которое код посчитал сам, а не метку записи. Для кода, где время — часть контракта, например дедлайн в ошибке, значение прокидывайте отдельным полем из тестового таймера. Обёртка observer при этом синхронная: к моменту проверки записи уже лежат в накопителе, и никаких ожиданий в тест не нужно. У zaptest есть и управляемые часы — опция Clock: время в записях движется по шагу, а не по реальным ожиданиям; для ассертов это всё равно не аргумент — метки не сравниваются ни с реальными, ни с управляемыми часами. ### Код под тест пишет из горутин Накопитель ObservedLogs защищён мьютексом: записи из горутин кода под тест не рвут данные, гонок внутри observer нет. Проблема в другом: тест проверяет накопитель раньше, чем фоновая горутина успела записать, — и All() честно возвращает меньше записей, чем есть на самом деле. Observer синхронен внутри вызова Write, но ждать ваши горутины он не обязан. Синхронизация — обычные приёмы: WaitGroup с сигналом о завершении записи, канал как точка встречи или проверка с коротким экспоненциальным ожиданием для интеграционных сценариев. Жёсткое правило: если запись делает горутина, тест не смотрит в накопитель без синхронизации — иначе сборка флакает на загруженном CI раз в неделю, и охота за «случайным» падением стоит дороже самого теста. ### Гигиена тестов логов - Порог observer равен боевому: тест с заниженным порогом пропустит исчезновение Info-записей. - Один сценарий на тест; сценариев больше — TakeAll между фазами. - Время, формат JSON и порядок полей не проверяются: это решения энкодера, а не кода. - Поля сравниваются с типами: zap.Int64 против int64 в ContextMap, а не против float64 на глаз. - Сэмплер в тестовый логгер не включается: observer обязан видеть всё. - Флакующий тест чинят синхронизацией, а не sleep подлиннее. ### Проверка: AllUntimed **Вопрос:** Чем удобен AllUntimed() в тестах? - Возвращает записи быстрее по времени - ✅ Обнуляет Time: сравнение списков без меток - Фильтрует записи по времени - Возвращает только ошибки Метка времени в записях — реальное время, и сравнивать списки по ней нельзя. AllUntimed убирает метку, оставляя уровень, сообщение и поля. ### Сколько вернёт Len после TakeAll? ```go core, logs := observer.New(zapcore.InfoLevel) logger := zap.New(core) logger.Info("one") fmt.Println(len(logs.TakeAll())) fmt.Println(logs.Len()) ``` **Что выведет программа?** - ✅ 1 и 0 - 1 и 1 - 0 и 0 - Паника: TakeAll нельзя вызывать после All TakeAll возвращает накопленное и очищает накопитель: первая печать — 1, Len после очистки — 0. Это удобно для проверки последовательности: каждая фаза теста смотрит свои записи. ### Соберите тест наблюдателя Восстановите каркас теста: порог, ядро, снимок записей. ```go func TestPaymentWarns(t *testing.T) { core, logs := observer.New(zapcore.___Level) logger := zap.New(___) entries := logs.___() if entries[0].Level != zapcore.WarnLevel { t.Fatal("want warn") } } ``` Подсказка: Порог Info, в zap.New идёт ядро из observer, снимок записей — All. Правильные ответы в пропусках: `Info`, `core`, `All` ### Соберите проверку записи Расставьте строки теста по порядку. Правильный порядок строк: 1. `core, logs := observer.New(zapcore.InfoLevel)` 2. `logger := zap.New(core)` 3. `logger.Warn("slow sql", zap.Int64("ms", 350))` 4. `entries := logs.All()` 5. `if len(entries) != 1 {` 6. `t.Fatal("want exactly one entry")` ### Карточки: zaptest и observer - **observer.New** — Возвращает пару (zapcore.Core, *ObservedLogs): ядро уходит в zap.New, накопитель — в проверки теста. - **LoggedEntry** — Запись наблюдателя: Entry с уровнем, сообщением и временем плюс Context — слайс полей. - **TakeAll** — Вынимает записи и очищает накопитель: сценарий «каждая фаза теста смотрит свои записи». - **FilterField** — Отбирает записи с заданным полем: конструктором zap.String или zap.Int64, совпадают ключ, тип и значение. - **zaptest.Logger** — Логгер, пишущий в t.Log: вывод виден у упавших тестов и с флагом -v, успешный прогон чистый. - **AllUntimed** — Записи с обнулённым временем: сравнение списков без меток — тест не флакает. ### Что дальше по курсу Логгер, который тесты не трогают, часто берут глобальным: когда это уместно и чем опасно, разбирает [урок про ReplaceGlobals](/courses/zap/lessons/21-globalnyj-logger/); уровни для тестов и прода настраиваются в [уроке про конфиг zap](/courses/zap/lessons/07-zap-config/). Тесты gRPC-сервисов, где логам перехватчиков тоже нужна проверка, — в [уроке про тестирование gRPC](/courses/grpc-go/lessons/21-testirovanie/); карта курса — на [странице курса zap](/courses/zap/). ## Коротко: что запомнить - Логи — часть контракта: дашборды и алерты завязаны на уровни, сообщения и поля. - observer.New возвращает ядро и накопитель: код под тест пишет в боевой zap.Logger. - Проверяйте уровень, сообщение и поля; формат вывода и метки времени не тестируются. - Фильтры ObservedLogs читаются как предложения: FilterMessageSnippet, FilterField, Len. - zaptest.NewLogger пишет в t.Log: вывод виден у упавших тестов и с флагом -v. - Time в записях не сравнивают: AllUntimed обнуляет метки. - Enabler работает как в проде: Debug ниже порога Info не записывается. ## Домашнее задание Напишите тест на middleware или перехватчик из прошлых уроков: observer.New(zapcore.DebugLevel), логгер уходит в код, проверяются уровень и поля latency, code, request_id. Добавьте второй тест на отсутствие записей в штатном сценарии — Len должен остаться нулём. Запустите оба обычным go test на локальном Go и убедитесь, что вывод логгера не мусорит успешный прогон. Затем соберите боевой логгер с сэмплированием 100/100 и повторите тест на три одинаковые записи подряд: зафиксируйте, сколько записей увидел observer, и выпишите вывод — почему в тестах сэмплер не ставят. ## Вопросы и ответы по уроку ### Чем observer лучше захвата stdout логгера? Захват вывода заставит парсить JSON обратно в структуру и привяжет тест к формату. Observer держит записи как объекты: уровень, сообщение и поля в типах. Формат вывода меняется — тесты этого не замечают. ### Можно ли одновременно писать в тест и в observer? Да: zapcore.NewTee поверх двух ядер или zaptest.WrapCore с обёрткой. Вывод в t.Log идёт для человека, накопитель — для ассертов, и оба видят одни и те же записи. ### Тестирует ли observer формат итогового JSON? Нет, и это плюс: формат — ответственность энкодера из урока про JSON и console. Тестируйте содержимое записей; для формата есть отдельные тесты на конфигурацию логгера.