--- title: "gRPC: перехватчики для логов" description: "grpc interceptor logging на zap: Unary и Stream перехватчики, latency, коды статуса gRPC, Warn против Error и request id из metadata. Примеры кода." course: "Zap: структурное логирование на Go" url: "https://golangmaster.ru/courses/zap/lessons/17-grpc-zap/" published: "2026-09-19" updated: "2026-09-21" minutes: 18 --- # gRPC: перехватчики для логов *Курс «Zap: структурное логирование на Go», урок 17 из 25. ~18 минут. Обновлено 21.09.2026. Источник: https://golangmaster.ru/courses/zap/lessons/17-grpc-zap/* grpc interceptor logging в Go-сервисе строится на перехватчике: обёртке вокруг каждого RPC, которая пишет в zap метод, код статуса, адрес клиента и длительность вызова — одно место, которое видит весь трафик сервиса. Напишем Unary и Stream варианты, научимся превращать codes.Code в уровень Warn или Error и вытащим request id из metadata, чтобы gRPC-записи склеивались с остальным конвейером логов. gRPC-сервис без access-лога — чёрный ящик: трафик идёт, ошибки иногда приходят на клиент, а что происходило внутри, не знает никто. Разбрасывать zap.Error по каждому методу — путь к сотне разных форматов записей, из которых дашборд не соберёшь. У gRPC есть своё место для сквозной логики: перехватчики, аналог HTTP-middleware. Одна функция на весь сервер пишет единый лог вызовов: метод, код статуса, адрес клиента, длительность. Дальше — только политика: какой код каким уровнем логировать и как прокинуть request id внутрь. ### grpc interceptor logging: контракт UnaryServerInterceptor Связку zap и grpc для unary-вызовов описывает тип grpc.UnaryServerInterceptor: grpc interceptor logging — это функция, принимающая контекст, запрос, info с описанием вызова и handler — сам вызов обработчика. Между «до» и «после» handler у перехватчика полная свобода: засечь время, достать metadata, построить дочерний логгер. info.FullMethod даёт стабильное имя вида /user.UserService/GetUser — оно же ключ для дашбордов и алертов, в отличие от путей HTTP-роутера, меняющихся от версии API. Возвращённые ответ и ошибка проходят наружу как есть: перехватчик — наблюдатель, а не фильтр. Регистрация — через grpc.NewServer(grpc.ChainUnaryInterceptor(...)): цепочка выполняется по порядку, и логирующий перехватчик обычно ставят первым, чтобы он видел полное время остальных — recovery, валидацию, аутентификацию. ### Логирующий unary-перехватчик ```go func UnaryLogging(base *zap.Logger) grpc.UnaryServerInterceptor { return func(ctx context.Context, req any, info *grpc.UnaryServerInfo, handler grpc.UnaryHandler, ) (any, error) { start := time.Now() resp, err := handler(ctx, req) fields := []zap.Field{ zap.String("method", info.FullMethod), zap.String("code", status.Code(err).String()), zap.Duration("latency", time.Since(start)), zap.Error(err), } if p, ok := peer.FromContext(ctx); ok { fields = append(fields, zap.String("peer", p.Addr.String())) } base.Log(levelByCode(status.Code(err)), "grpc request", fields...) return resp, err } } ``` Логгер приходит снаружи — уже собранный через With и Named, с request_id из HTTP-конвейера или metadata, что разобраны в соседних уроках. Метод base.Log — редкий зверь в zap: пишет на произвольном zapcore.Level, который вернула функция levelByCode по коду ошибки. status.Code(nil) возвращает codes.OK, поэтому успешные вызовы получают поле code со значением OK — отдельная ветка для успеха не нужна. Peer добавляется в запись, только когда он есть в контексте: сервер кладёт его туда сам. status.Code(err) вызывается дважды — в слайсе полей и в base.Log; на горячих путях код вычисляют один раз в переменную, здесь имена нагляднее. zap.Error с nil-ошибкой поля не создаст: успешные вызовы не получат пустого error в записи. ### Разбор полей записи Каждое поле отвечает на конкретный вопрос. method с FullMethod — какие вызовы приходят и куда смотреть в коде; для access-аналитики этого мало, но для поиска по логам его хватает. code — строка из codes.Code через String(): в JSON уходит DEADLINE_EXCEEDED, а не магическое число 4 — грепается и строится в дашборды. latency считается вокруг handler: вместе с перехватчиками выше по цепочке цифра вырастет, поэтому меряющий перехватчик ставят первым — иначе в латентность затесаются чужие задержки. peer — адрес клиента: для расследований «кто долбит сервис» это первое поле, куда смотрят. А вот сам req в лог перехватчик не пишет: там почты, суммы и идентификаторы, и сериализация тела запроса — отдельное осознанное решение с маскированием, как с SQL в уроке про GORM. ### Код статуса: codes.Code Ошибки в gRPC — не произвольные объекты: их конструируют через status.Error(codes.NotFound, "user not found"), и код путешествует по сети внутри status. На сервере err из handler — это *status.Status, спрятанная за интерфейсом error, и status.Code(err) достаёт код обратно. Два граничных случая стоит запомнить. err == nil даёт codes.OK. А ошибка, созданная без status — errors.New, fmt.Errorf — даёт codes.Unknown: gRPC честно не знает, что с ней делать. Unknown — самый дорогой код в логах: за ним прячется всё, что вы забыли обернуть в статус, и именно его стоит сначала перевести в осмысленные коды, а потом уже настраивать уровни логирования. Иначе Error-лог покажет «что-то упало», но не скажет, что именно. ### Проверка: чужая ошибка **Вопрос:** Обработчик вернул ошибку, созданную через errors.New("boom"), без status. Что вернёт status.Code(err)? - codes.OK: ошибки нет - ✅ codes.Unknown: status распознать не удалось - codes.Internal: любая чужая ошибка — внутренняя - Панику: err не является *status.Status status.Code распаковывает status из ошибки; если её там нет — возвращает codes.Unknown. codes.OK выдаётся только для nil. Никакой паники нет: функция спроектирована для произвольных error. ### Ошибки по коду: Warn или Error Код статуса — машинное поле, уровень — ваше решение, и сводить их в правило «все ошибки — Error» значит утопить алерты. Моя рабочая политика простая. Internal, DataLoss и Unknown — Error: за ними баг в коде или потеря данных. DeadlineExceeded, Unavailable и ResourceExhausted — Warn: таймауты и недоступность живут в ретраях, и алерт на каждого клиента с плохой сетью отключают через неделю. Спорное место — codes.Canceled: я пишу его на Info и не согласен с командами, поднимающими его в Warn. Клиент сам закрыл соединение — аварии нет, а Warning на каждый закрытый контекст создаёт шум, маскирующий настоящие проблемы. Если ваша система реагирует на canceled иначе — политика у вас своя, но она должна быть записана кодом, а не в голове дежурного. ### Политика уровней: levelByCode ```go func levelByCode(code codes.Code) zapcore.Level { switch code { case codes.Internal, codes.DataLoss, codes.Unknown: return zapcore.ErrorLevel case codes.DeadlineExceeded, codes.Unavailable, codes.ResourceExhausted: return zapcore.WarnLevel default: return zapcore.InfoLevel } } ``` Политика уровней — обычная Go-функция: её видно в ревью, её покрывает табличный тест, её правят одной строкой. Дефолтная ветка отдаёт Info: NotFound, InvalidArgument и Canceled проходят как обычный access-лог. Проверка не требует сервера: таблица кодов и ожидаемых уровней запускается обычным go test на локальном Go. Это редкий случай, когда логику логирования проверяют так же строго, как бизнес-код. ### Коды и уровни: шпаргалка | Код | Уровень | Почему | | --- | --- | --- | | Internal | Error | баг сервера: паника, инвариант, деление на ноль | | DataLoss | Error | потеря данных — сигнализировать всегда | | Unknown | Error | необработанная ошибка: сначала обернуть в статус | | DeadlineExceeded | Warn | таймаут; ретрай — штатная реакция клиента | | Unavailable | Warn | сервис временно недоступен; клиент повторит | | ResourceExhausted | Warn | квота или rate limit: счётчик, а не алерт | | NotFound, InvalidArgument | Info | ожидаемый поток приложения | ### Что будет, если обработчик паникует grpc-go не ставит recover вокруг вызовов обработчиков: паника внутри handler раскручивает стек через все перехватчики и убивает процесс — пост-код логирующего перехватчика не выполнится, записи не будет, клиент увидит обрыв соединения вместо кода. Лечение — перехватчик recovery: defer с recover переводит панику в status.Error(codes.Internal), пишет zap.Error со стеком debug.Stack() и возвращает клиенту честную ошибку. Порядок в ChainUnaryInterceptor зеркальный Gin: логирующий первым, recovery вторым — паника гасится глубже, и логирующий после возврата handler видит обычную ошибку Internal с латентностью и пишет access-запись. Recovery последним в цепочке панику тоже поймает, но записи лога она не оставит — тот же симптом, что и в уроке про HTTP-посредников. > **Типичная ошибка: лог в середине цепочки.** ChainUnaryInterceptor выполняет перехватчики по порядку списка: первый — внешний слой. Если логирующий стоит после аутентификации, отказ в доступе происходит до входа в лог — вызовы идут, записей нет, и дашборд молчит, пока клиент стучится. Логирующий перехватчик — первым в списке: только он видит весь трафик, включая отбракованный. ### Request id из metadata HTTP-конвейер из урока про request id живёт в заголовках, gRPC — в metadata: та же идея, другой транспорт. На сервере metadata.FromIncomingContext(ctx) достаёт map из входящего контекста, и ключи в нём всегда в нижнем регистре: X-Request-Id с клиента превратится в x-request-id. Достали значение — собрали дочерний логгер base.With(zap.String("request_id", id)), и весь лог перехватчика, и всё, что обработчик нафлогирует через переданный дальше логгер, окажется с одним идентификатором. Две оговорки. Клиент может прислать какой угодно request_id: длину и алфавит стоит ограничить, иначе поле станет вектором для раздувания записей. И md.Get возвращает слайс: повторяющийся ключ легален в metadata, берите первый элемент, остальные игнорируйте. ### Дочерний логгер на вызов ```go func loggerFromContext(ctx context.Context, base *zap.Logger) *zap.Logger { md, ok := metadata.FromIncomingContext(ctx) if !ok { return base } ids := md.Get("x-request-id") if len(ids) == 0 || len(ids[0]) > 64 { return base } return base.With(zap.String("request_id", ids[0])) } ``` Дочерний логгер строится один раз на вызов и прокидывается дальше — цена With после урока про контекст логгера копеечная. metadata.FromIncomingContext возвращает false для контекста без входящих метаданных: в unit-тесте, где контекст построен руками, перехватчик просто работает с базовым логгером. md.Get возвращает слайс строк: повторяющийся ключ в metadata легален, берём первый. Проверка длины — минимальная гигиена: значение пришло по сети, и доверять ему на слово не стоит. ### Проверка: регистр ключа **Вопрос:** Клиент отправил metadata-ключ X-Request-Id. По какому ключу значение вернёт md.Get(...)? - X-Request-Id — как прислал клиент - ✅ x-request-id: ключи metadata нормализуются в нижний регистр - x_request_id - Ключ доступен только в headers HTTP/1.1 grpc-go приводит ключи metadata к нижнему регистру при приёме. Искать надо по x-request-id: оригинальный регистр не сохраняется. Это ловит каждого, кто первый раз работает с metadata. ### StreamServerInterceptor: чем отличается Стримы ломают картину «один запрос — один ответ». Перехватчик типа grpc.StreamServerInterceptor получает не запрос, а grpc.ServerStream — канал, через который сообщения бегут в обе стороны, и handler возвращает одну ошибку на весь стрим. Асимметрия важная: сообщений много, записей лога лучше одна, иначе десятистрочный чат заспамит access-лог. А вот ошибок в стриме несколько: SendMsg и RecvMsg возвращают их по ходу, и финальная ошибка handler — агрегат. Особый случай — io.EOF из RecvMsg: это штатный сигнал «клиент перестал слать», а не авария; без фильтра он превратит каждый обычный стрим в Error-запись. StreamServerInfo дополнительно к FullMethod даёт IsClientStream и IsServerStream — по ним различают виды стримов в логе, если трафик смешанный. ### Логирующий stream-перехватчик ```go func StreamLogging(base *zap.Logger) grpc.StreamServerInterceptor { return func(srv any, ss grpc.ServerStream, info *grpc.StreamServerInfo, handler grpc.StreamHandler, ) error { start := time.Now() err := handler(srv, ss) if errors.Is(err, io.EOF) { return err } base.Log(levelByCode(status.Code(err)), "grpc stream", zap.String("method", info.FullMethod), zap.Duration("latency", time.Since(start)), zap.Error(err), ) return err } } ``` Скелет тот же, что у unary: засечь время, отдать handler, разложить ошибку по коду. Разница — фильтр io.EOF: штатное завершение чтения уходит наружу без записи, а errors.Is распознаёт и обёрнутые варианты. Если сервис в основном стримовый, здесь же логируют счётчики сообщений: обёртка над ServerStream инкрементирует recv и send, цифры попадают в финальную запись. Для начала хватит и этой версии. > **EOF-шторм.** Первая версия stream-перехватчика обычно логирует zap.Error(err) на всё — и получает Error-запись на каждый нормально завершённый клиентом стрим: io.EOF вернулся, логгер честно его зафиксировал, алерт-движок посчитал аварии. Фильтр EOF ставьте до levelByCode, а не после: статус для io.EOF — Unknown, и без фильтра уровень будет Error. ### Что запишет перехватчик? ```go // UnaryLogging установлен на сервере. // handler возвращает: return nil, status.Error(codes.DeadlineExceeded, "handler took too long") ``` **Что выведет программа?** - ✅ Warn «grpc request» с code: DEADLINE_EXCEEDED и latency - Error: DeadlineExceeded — это ошибка - Info: до Error дело не дошло - Ничего: перехватчик не логирует ошибки статуса levelByCode относит DeadlineExceeded к Warn: таймаут — работа ретрая, а не авария. zap.Error запишет сообщение handler took too long в поле error, method и latency будут рядом. ### Соберите политику уровней Восстановите levelByCode: три уровня по трём группам кодов. ```go func levelByCode(code codes.Code) zapcore.Level { switch code { case codes.Internal: return zapcore.___Level case codes.DeadlineExceeded: return zapcore.___Level default: return zapcore.___Level } } ``` Подсказка: Внутренние ошибки — Error, таймауты — Warn, ожидаемый поток — Info. Правильные ответы в пропусках: `Error`, `Warn`, `Info` ### Соберите unary-перехватчик Расставьте строки от замера времени до возврата результата. Правильный порядок строк: 1. `start := time.Now()` 2. `resp, err := handler(ctx, req)` 3. `code := status.Code(err)` 4. `fields := append(baseFields, zap.String("code", code.String()))` 5. `base.Log(levelByCode(code), "grpc request", fields...)` 6. `return resp, err` ### Карточки: gRPC и zap - **UnaryServerInterceptor** — Функция (ctx, req, info, handler) → (any, error): доступ до и после обработчика; ставится через grpc.ChainUnaryInterceptor. - **info.FullMethod** — Путь вида /pkg.Service/Method: стабильный ключ в логах и дашбордах, не зависит от формата путей клиента. - **status.Code(err)** — Достаёт codes.Code из ошибки: nil даёт OK, ошибка без status — Unknown. - **peer.FromContext** — Адрес клиента: сервер кладёт Peer.Addr в контекст вызова — первое поле при расследовании «кто долбит сервис». - **metadata.FromIncomingContext** — Входящая metadata: ключи в нижнем регистре, Get возвращает слайс строк. - **StreamServerInterceptor** — (srv, ss, info, handler) error: одна запись на стрим; io.EOF из RecvMsg — норма, фильтруйте до levelByCode. ### Что дальше по курсу Перехватчики устроены так же, как middleware Gin: идея обёртки одна, тип другой. Без логирования их разбирает [урок про перехватчики](/courses/grpc-go/lessons/11-interceptors/) курса gRPC, семантику кодов статусов — [урок про статусы](/courses/grpc-go/lessons/13-statusy/). Request id из HTTP-конвейера — в [уроке про request id](/courses/zap/lessons/14-request-id/); связь логов с метриками и трейсами — в материале про [наблюдаемость](/courses/zap/lessons/23-observability/). Связка zap grpc собирается в один файл: перехватчик, политика уровней, извлечение request id. ## Коротко: что запомнить - Перехватчик — одно место для access-лога: метод, код, peer, latency, request id. - status.Code(nil) — это OK, а чужая ошибка без status — Unknown. - Политику уровней пишите функцией: Internal — Error, таймауты — Warn, canceled — Info. - Stream-перехватчик пишет одну запись на стрим; io.EOF фильтруется до levelByCode. - Request id лежит в metadata с ключом в нижнем регистре. - ChainUnaryInterceptor выполняется по порядку: логирующий — первым, чтобы видеть чужие задержки. - Тело запроса в лог не пишем без маскирования: там персональные данные. ## Домашнее задание Реализуйте UnaryLogging и levelByCode, подключите их через grpc.ChainUnaryInterceptor и запустите сервер с парой методов на локальном Go: один возвращает OK, второй — DeadlineExceeded. Проверьте по JSON-выводу, что поля method, code и latency на месте, а уровни различаются. Затем добавьте клиент, отправляющий metadata x-request-id, и найдите идентификатор в поле request_id. Затем добавьте обработчик, паникующий на одном методе, recovery-перехватчик в цепочку и проверьте: процесс жив, запись со статусом Internal родилась. ## Вопросы и ответы по уроку ### Почему не логировать req через zap.Any? В req — персональные данные: почты, суммы, идентификаторы. zap.Any уйдёт в рефлексию и вывалит всё содержимое в JSON. Если тело нужно для отладки, маскируйте поля и логируйте на Debug по флагу, а не на постоянной основе. ### Отличается ли клиентский перехватчик? Сигнатуры зеркальные: UnaryClientInterceptor и StreamClientInterceptor. Меняется контекст: peer — адрес сервера, metadata отправляется через outgoing-контекст, и request id туда ставит клиент перед вызовом. ### Что раньше — логирующий перехватчик или recovery? Оба, через ChainUnaryInterceptor: логирующий первым, recovery вторым. Панику, пойманную recovery, логирующий как ошибку не увидит — он уже отработал до handler. Запись о панике пишет сам recovery своим уровнем.