Подробное руководство по логгированию Zap в Go

Zap — это пакет для ведения структурированных журналов (логов), разработанный Uber для приложений Go. Согласно их документу GitHub README, он предлагает «молниеносную», структурированную, c поддержкой уровней регистрацию с минимальными кол-вом аллокаций. Это утверждение подтверждается их результатами бенчмаркинга , которые демонстрируют, что Zap превосходит почти все другие сопоставимые библиотеки структурированного ведения журналов для Go, кроме Zerolog.

В этом подробном руководстве мы углубимся в пакет Zap и обсудим многие из его наиболее полезных функций. Мы начнем с базовой настройки Zap в программе Go, а затем перейдем к подробным примерам, иллюстрирующим, как писать журналы различных уровней и форматов и управлять ими. Наконец, мы завершим статью, коснувшись более сложных тем, таких как пользовательские кодировщики, ведение журнала с несколькими выходами и использование Zap в качестве бэкэнда Slog.

Давайте начнем!

Предпосылки

Прежде чем приступить к выполнению этого руководства, мы рекомендуем установить на свой компьютер последнюю версию Go (v1.20 на момент написания). После того, как вы установили Go, создайте новый каталог проекта на своем компьютере, чтобы вы могли запускать приведенные в этой статье примеры:

mkdir zap-logging

cd zap-logging

go mod init github.com/<user>/zap-logging

Начало работы с Zap

Прежде чем вы сможете начать работать с Zap, вам необходимо установить его в свой проект с помощью следующей команды:

go get -u go.uber.org/zap

После того, как вы установили Zap, вы можете начать использовать его в своей программе следующим образом:

package main

import (
    "go.uber.org/zap"
)

func main() {
    logger := zap.Must(zap.NewProduction())

    defer logger.Sync()

    logger.Info("Hello from Zap logger!")
}

{"level":"info","ts":1684092708.7246346,"caller":"zap/main.go:12","msg":"Hello from Zap logger!"}

В отличие от большинства других пакетов ведения журналов для Go, Zap не предоставляет предварительно настроенный глобальный регистратор, готовый к использованию. Следовательно, вы должны создать экземпляр zap.Logger, прежде чем сможете начать запись журналов. МетодNewProduction()возвращает Loggerнастроенный для ведения журнала стандартной ошибки в формате JSON, а для его минимального уровня журнала задано значение INFO.

Полученный результат является относительно простым и не содержит сюрпризов, за исключением стандартного формата метки времени (ts), который представлен как количество наносекунд, прошедших с 1 января 1970 года по Гринвичу, а не в типичном формате ISO-8601.

Вы также можете использовать NewDevelopment()предустановку для создания Loggerболее оптимизированного для использования в средах разработки. Это означает ведение журнала на DEBUGуровне и использование более удобного для человека формата:

logger := zap.Must(zap.NewDevelopment())

Настройка глобального логгера

Если вы хотите писать журналы без Loggerпредварительного создания экземпляра, вы можете использовать ReplaceGlobals()метод, возможно, в init()функции:

package main

import (
    "go.uber.org/zap"
)

func init() {
    zap.ReplaceGlobals(zap.Must(zap.NewProduction()))
}

func main() {
    zap.L().Info("Hello from Zap!")
}

Этот метод заменяет глобальный регистратор, доступный через, zap.L()функциональным Loggerэкземпляром, чтобы вы могли использовать его напрямую, просто импортировав zapпакет в свой файл.

Изучение API ведения журналов Zap

Zap предоставляет два основных API для ведения журнала. Первый — это низкоуровневый Logger тип, обеспечивающий структурированный способ регистрации сообщений. Он предназначен для использования в контекстах, чувствительных к производительности, где важно каждое выделение, и поддерживает только строго типизированные контекстные поля:

func main() {
    logger := zap.Must(zap.NewProduction())

    defer logger.Sync()

    logger.Info("User logged in",
        zap.String("username", "johndoe"),
        zap.Int("userid", 123456),
        zap.String("provider", "google"),
    )
}

{"level":"info","ts":1684094903.7353888,"caller":"zap/main.go:17","msg":"User logged in","username":"johndoe","userid":123456,"provider":"google"}

Тип Loggerпредоставляет один метод для каждого из поддерживаемых уровней журнала ( Info(), Warn(), Error(), и т. д.), и каждый из них принимает сообщение и ноль или более полей , которые представляют собой строго типизированные пары ключ/значение, как показано в приведенном выше примере.

Второй высокоуровневый API SugaredLoggerпредставляет собой более непринужденный подход к ведению журнала. Он имеет менее подробный API, чем Loggerтип, но снижает производительность . За кулисами он полагается на Loggerтип для фактических операций ведения журнала:

func main() {
    logger := zap.Must(zap.NewProduction())

    defer logger.Sync()

    sugar := logger.Sugar()

    sugar.Info("Hello from Zap logger!")
    sugar.Infoln(
        "Hello from Zap logger!",
    )
    sugar.Infof(
        "Hello from Zap logger! The time is %s",
        time.Now().Format("03:04 AM"),
    )

    sugar.Infow("User logged in",
        "username", "johndoe",
        "userid", 123456,
        zap.String("provider", "google"),
    )
}

Выход

{"level":"info","ts":1684147807.960761,"caller":"zap/main.go:17","msg":"Hello from Zap logger!"}
{"level":"info","ts":1684147807.960845,"caller":"zap/main.go:18","msg":"Hello from Zap logger!"}
{"level":"info","ts":1684147807.960909,"caller":"zap/main.go:21","msg":"Hello from Zap logger! The time is 11:50 AM"}
{"level":"info","ts":1684148355.2692218,"caller":"zap/main.go:25","msg":"User logged in","username":"johndoe","userid":123456,"provider":"google"}

A Loggerможно преобразовать в SugaredLoggerтип, вызвав Sugar() для него метод. И наоборот, Desugar()метод преобразует a SugaredLoggerв a Logger, и вы можете выполнять эти преобразования так часто, как это необходимо, поскольку накладные расходы на производительность незначительны.

sugar := zap.Must(zap.NewProduction()).Sugar()

defer sugar.Sync()
sugar.Infow("Hello from SugaredLogger!")

logger := sugar.Desugar()

logger.Info("Hello from Logger!")

Эта функция означает, что вам не нужно внедрять тот или иной код в свою кодовую базу. Например, вы можете по умолчанию использовать тип SugaredLoggerв обычном случае для его гибкости, а затем преобразовать в Loggerтип на границах кода, чувствительного к производительности.

Тип SugaredLoggerпредоставляет четыре метода для каждого поддерживаемого уровня:

1. Первый ( Info(), Error(), и т. д.) идентичен по имени методу уровня на a Logger, но он принимает один или несколько аргументов типа any. Под капотом они используют fmt.Sprint()метод для объединения аргументов в msgсвойство на выходе.
2. Методы, оканчивающиеся на ln(например, Infoln()и , Errorln()такие же, как и первый, за исключением того, что fmt.Sprintln()вместо этого используются для создания и регистрации сообщения.
3. Методы, оканчивающиеся на , fиспользуют fmt.Sprintf()метод для создания и регистрации шаблонного сообщения.
4. Наконец, методы, оканчивающиеся на , wпозволяют добавлять к записям журнала смесь пар ключ/значение со строгой и свободной типизацией. Сообщение журнала является первым аргументом; ожидается, что последующие аргументы будут в парах ключ/значение, как показано в примере выше.

Следует отметить одну вещь, касающуюся использования пар ключ/значение со свободной типизацией, это то, что ключи всегда должны быть строками, а значение может быть любого типа. Если вы используете нестроковый ключ, ваша программа будет паниковать в разработке:

sugar.Infow("User logged in", 1234, "userID")

2023-05-15T12:06:12.996+0100    ERROR   zap@v1.24.0/sugar.go:210        Ignored key-value pairs with non-string keys.   {"invalid": [{"position": 0, "key": 1234, "value": "userID"}]}
go.uber.org/zap.(*SugaredLogger).Infow
        /home/ayo/go/pkg/mod/go.uber.org/zap@v1.24.0/sugar.go:210
main.main
        /home/ayo/dev/demo/zap/main.go:14
runtime.main
        /usr/local/go/src/runtime/proc.go:250
2023-05-15T12:06:12.996+0100    INFO    zap/main.go:14  User logged in

В продакшене регистрируется отдельная ошибка и пропускается пара ключ/значение:

{"level":"error","ts":1684148883.086758,"caller":"zap@v1.24.0/sugar.go:210","msg":"Ignored key-value pairs with non-string keys.","invalid":[{"position":0,"key":1234,"value":"userID"}],"stacktrace":"go.uber.org/zap.(*SugaredLogger).Infow\n\t/home/ayo/go/pkg/mod/go.uber.org/zap@v1.24.0/sugar.go:210\nmain.main\n\t/home/ayo/dev/demo/zap/main.go:14\nruntime.main\n\t/usr/local/go/src/runtime/proc.go:250"}
{"level":"info","ts":1684148883.0867138,"caller":"zap/main.go:14","msg":"User logged in"}

Передача потерянного ключа (без соответствующего значения) ведет себя аналогично: паника в разработке и ошибка в продакшене. Из-за всех этих предостережений в отношении нечетко типизированных пар ключ/значение мы рекомендуем всегда использовать строго типизированные контекстные поля, независимо от того, используете ли вы Loggerили SugaredLogger.

Уровни логов в Zap

Zap предоставляет уровни журнала ниже в порядке возрастания серьезности. Каждый из них связан с соответствующим целым числом:

• DEBUG(-1): для записи сообщений, полезных для отладки.
• INFO(0): для сообщений, описывающих обычные операции приложения.
• WARN(1): для записи сообщений о том, что произошло что-то необычное, что может потребовать внимания, прежде чем оно перерастет в более серьезную проблему.
• ERROR(2): для записи непредвиденных ошибок в программе.
• DPANIC(3): для регистрации серьезных ошибок в процессе разработки. Он ведет себя как PANICв разработке, так и ERRORв производстве.
• PANIC(4): вызывается panic()после регистрации состояния ошибки.
• FATAL(5): вызывается os.Exit(1)после регистрации состояния ошибки.

Эти уровни определены в пакете zapcore , который определяет и реализует низкоуровневые интерфейсы, на которых построен Zap.

Примечательно, что здесь нет ни TRACEуровня, ни возможности добавить пользовательские уровни в Logger , что для некоторых может стать препятствием. Как указывалось ранее, уровень журнала, установленный по умолчанию для производственного регистратора, равен INFO. Если вы хотите изменить этот параметр, вы должны создать собственный регистратор, который мы подробно рассмотрим в следующем разделе.

Создание пользовательского регистратора

До сих пор мы показывали, как использовать конфигурации по умолчанию, предоставляемые Zap через его предустановки для производства и разработки. Давайте теперь рассмотрим, как создать Loggerэкземпляр с настраиваемыми параметрами конфигурации.

Есть два основных способа создания кастома Loggerс помощью Zap. Первый включает использование его типа конфигурации для создания пользовательского регистратора, как показано ниже:

package main

import (
    "os"

    "go.uber.org/zap"
    "go.uber.org/zap/zapcore"
)

func createLogger() *zap.Logger {
    encoderCfg := zap.NewProductionEncoderConfig()
    encoderCfg.TimeKey = "timestamp"
    encoderCfg.EncodeTime = zapcore.ISO8601TimeEncoder

    config := zap.Config{
        Level:             zap.NewAtomicLevelAt(zap.InfoLevel),
        Development:       false,
        DisableCaller:     false,
        DisableStacktrace: false,
        Sampling:          nil,
        Encoding:          "json",
        EncoderConfig:     encoderCfg,
        OutputPaths: []string{
            "stderr",
        },
        ErrorOutputPaths: []string{
            "stderr",
        },
        InitialFields: map[string]interface{}{
            "pid": os.Getpid(),
        },
    }

    return zap.Must(config.Build())
}

func main() {
    logger := createLogger()

    defer logger.Sync()

    logger.Info("Hello from Zap!")
}

{"level":"info","timestamp":"2023-05-15T12:40:16.647+0100","caller":"zap/main.go:42","msg":"Hello from Zap!","pid":2329946}

Приведенная выше функция createLogger()возвращает новое значение zap.Logger, которое действует аналогично функции, NewProduction() Loggerно с некоторыми отличиями. Мы используем производственную конфигурацию Zap в качестве основы для нашего пользовательского регистратора, вызвав NewProductionEncoderConfig()и немного изменив его, изменив tsполе timestampи формат времени на ISO-8601. Пакет zapcore предоставляет интерфейсы, на которых построен Zap, чтобы вы могли настраивать и расширять его возможности.

Объект Configсодержит многие из наиболее распространенных параметров конфигурации, необходимых при создании нового файла Logger. Подробные описания того, что представляет каждое поле, есть в документации проекта , поэтому мы не будем повторять их все здесь, за исключением нескольких:

• OutputPathsуказывает одну или несколько целей для выходных данных журнала ( дополнительные сведения см. в разделе Открыть ).
• ErrorOutputPathsаналогичен, OutputPathsно используется только для внутренних ошибок Zap, а не для тех, которые генерируются или регистрируются вашим приложением (например, ошибка из-за несоответствия пар ключ/значение с нечетким типом).
• InitialFieldsопределяет глобальные контекстуальные поля, которые должны быть включены в каждую запись журнала, созданную каждым средством ведения журнала, созданным из объекта Config. Здесь мы указываем только идентификатор процесса программы, но вы можете добавить другие полезные глобальные метаданные, такие как версия Go, в которой запущена программа, хэш git commit или версия приложения, информация о среде или развертывании и многое другое.

После того, как вы настроили предпочтительные параметры конфигурации, вы должны вызвать метод Build()для создания файла Logger. Обязательно ознакомьтесь с документацией по Config и zapcore.EncoderConfig для всех доступных параметров.

Второй, более продвинутый способ создания пользовательского регистратора включает в себя использование zap.New()метода. Он принимает интерфейс zapcore.Core и ноль или более параметров для настройки файла Logger. Вот пример, который одновременно записывает раскрашенный вывод в консоль и формат JSON в файл:

func createLogger() *zap.Logger {
    stdout := zapcore.AddSync(os.Stdout)

    file := zapcore.AddSync(&lumberjack.Logger{
        Filename:   "logs/app.log",
        MaxSize:    10, // megabytes
        MaxBackups: 3,
        MaxAge:     7, // days
    })

    level := zap.NewAtomicLevelAt(zap.InfoLevel)

    productionCfg := zap.NewProductionEncoderConfig()
    productionCfg.TimeKey = "timestamp"
    productionCfg.EncodeTime = zapcore.ISO8601TimeEncoder

    developmentCfg := zap.NewDevelopmentEncoderConfig()
    developmentCfg.EncodeLevel = zapcore.CapitalColorLevelEncoder

    consoleEncoder := zapcore.NewConsoleEncoder(developmentCfg)
    fileEncoder := zapcore.NewJSONEncoder(productionCfg)

    core := zapcore.NewTee(
        zapcore.NewCore(consoleEncoder, stdout, level),
        zapcore.NewCore(fileEncoder, file, level),
    )

    return zap.New(core)
}

func main() {
    logger := createLogger()

    defer logger.Sync()

    logger.Info("Hello from Zap!")
}

2023-05-15T16:15:05.466+0100    INFO    Hello from Zap!

{"level":"info","timestamp":"2023-05-15T16:15:05.466+0100","msg":"Hello from Zap!"}

В этом примере используется пакет Lumberjack для автоматической ротации файлов журналов , чтобы они не становились слишком большими. Этот NewTee()метод дублирует записи журнала в два или более места назначения. В этом случае журналы отправляются на стандартный вывод с использованием раскрашенного формата открытого текста, а эквивалент JSON отправляется в файл logs/app.log.

Кстати, мы обычно рекомендуем использовать внешний инструмент, такой как Logrotate, для управления файлами журналов и их ротации, а не делать это в самом приложении.

Добавление контекста в ваши журналы

Как упоминалось ранее, контекстное ведение журнала с помощью Zap выполняется путем передачи строго типизированных пар ключ/значение после сообщения журнала, например:

logger.Warn("User account is nearing the storage limit",
    zap.String("username", "john.doe"),
    zap.Float64("storageUsed", 4.5),
    zap.Float64("storageLimit", 5.0),
)

{"level":"warn","ts":1684166023.952419,"caller":"zap/main.go:46","msg":"User account is nearing the storage limit","username":"john.doe","storageUsed":4.5,"storageLimit":5}

Используя дочерние регистраторы, вы также можете добавлять контекстные свойства ко всем журналам, созданным в определенной области. Это поможет вам избежать ненужного повторения в точке журнала. Дочерние регистраторы создаются с использованием With()метода на Logger:

func main() {
    logger := zap.Must(zap.NewProduction())

    defer logger.Sync()

    childLogger := logger.With(
        zap.String("service", "userService"),
        zap.String("requestID", "abc123"),
    )

    childLogger.Info("user registration successful",
        zap.String("username", "john.doe"),
        zap.String("email", "john@example.com"),
    )

    childLogger.Info("redirecting user to admin dashboard")
}

Обратите внимание, что serviceи requestIDприсутствуют в обоих журналах:

Выход

{"level":"info","ts":1684164941.7644951,"caller":"zap/main.go:52","msg":"user registration successful","service":"userService","requestID":"abc123","username":"john.doe","email":"john@example.com"}
{"level":"info","ts":1684164941.764551,"caller":"zap/main.go:57","msg":"redirecting user to admin dashboard","service":"userService","requestID":"abc123"}

Вы можете использовать тот же метод для добавления глобальных метаданных во все ваши журналы. Например, вы можете сделать что-то подобное, чтобы включить идентификатор процесса и версию Go, используемую для компиляции программы, во все ваши записи:

func createLogger() *zap.Logger {
    . . .

    buildInfo, _ := debug.ReadBuildInfo()

    return zap.New(samplingCore.With([]zapcore.Field{
        zap.String("go_version", buildInfo.GoVersion),
        zap.Int("pid", os.Getpid()),
    },
    ))
}

Регистрация ошибок с помощью Zap

Ошибки являются одной из наиболее важных целей ведения журналов, поэтому знание того, как фреймворк обрабатывает ошибки, имеет решающее значение перед его внедрением. В Zap вы можете регистрировать ошибки, используя Error()метод. A stacktraceвключается в вывод вместе со errorсвойством, если zap.Error()используется метод:

logger.Error("Failed to perform an operation",
    zap.String("operation", "someOperation"),
    zap.Error(errors.New("something happened")), // the key will be `error` here
    zap.Int("retryAttempts", 3),
    zap.String("user", "john.doe"),
)

Выход

{"level":"error","ts":1684164638.0570025,"caller":"zap/main.go:47","msg":"Failed to perform an operation","operation":"someOperation","error":"something happened","retryAttempts":3,"user":"john.doe","stacktrace":"main.main\n\t/home/ayo/dev/demo/zap/main.go:47\nruntime.main\n\t/usr/local/go/src/runtime/proc.go:250"}

Fatal()Этот метод доступен для более серьезных ошибок . Он вызывается os.Exit(1) после записи и очистки сообщения журнала:

logger.Fatal("Something went terribly wrong",
    zap.String("context", "main"),
    zap.Int("code", 500),
    zap.Error(errors.New("An error occurred")),
)

{"level":"fatal","ts":1684170760.2103574,"caller":"zap/main.go:47","msg":"Something went terribly wrong","context":"main","code":500,"error":"An error occurred","stacktrace":"main.main\n\t/home/ayo/dev/demo/zap/main.go:47\nruntime.main\n\t/usr/local/go/src/runtime/proc.go:250"}
exit status 1

Если ошибку можно исправить, вы можете использовать этот Panic()метод. Логируется на PANICуровне и вызывает panic()вместо os.Exit(1). Также есть DPanic()уровень, который паникует в разработке только после регистрации на DPANIC уровне. В продакшне он регистрируется на DPANICуровне без паники.

Если вы предпочитаете не использовать нестандартные уровни, такие как PANICи DPANIC, вы можете настроить оба метода для ведения журнала на ERRORуровне, используя следующий код:

func lowerCaseLevelEncoder(
    level zapcore.Level,
    enc zapcore.PrimitiveArrayEncoder,
) {
    if level == zap.PanicLevel || level == zap.DPanicLevel {
        enc.AppendString("error")
        return
    }

    zapcore.LowercaseLevelEncoder(level, enc)
}

func createLogger() *zap.Logger {
    stdout := zapcore.AddSync(os.Stdout)

    level := zap.NewAtomicLevelAt(zap.InfoLevel)

    productionCfg := zap.NewProductionEncoderConfig()
    productionCfg.TimeKey = "timestamp"
    productionCfg.EncodeTime = zapcore.ISO8601TimeEncoder
    productionCfg.EncodeLevel = lowerCaseLevelEncoder

    jsonEncoder := zapcore.NewJSONEncoder(productionCfg)

    core := zapcore.NewCore(jsonEncoder, stdout, level)

    return zap.New(core)
}

func main() {
    logger := createLogger()

    defer logger.Sync()

    logger.DPanic(
        "this was never supposed to happen",
    )
}

{"level":"error","timestamp":"2023-05-15T18:55:33.534+0100","msg":"this was never supposed to happen"}

Выборка журнала с помощью Zap

Выборка журнала — это метод, используемый для уменьшения объема журнала приложения путем выборочного захвата и записи только подмножества событий журнала. Его цель — найти баланс между необходимостью всесторонней регистрации и потенциальным влиянием на производительность регистрации слишком большого количества данных.

Вместо того, чтобы фиксировать каждое отдельное событие журнала, выборка журнала позволяет выбрать репрезентативное подмножество сообщений журнала на основе определенных критериев или правил. Таким образом, объем генерируемых данных журнала значительно уменьшается, что может быть особенно полезно в системах с высокой пропускной способностью.

В Zap выборку можно настроить с Loggerпомощью метода zapcore.NewSamplerWithOptions() , как показано ниже:

func createLogger() *zap.Logger {
    stdout := zapcore.AddSync(os.Stdout)

    level := zap.NewAtomicLevelAt(zap.InfoLevel)

    productionCfg := zap.NewProductionEncoderConfig()
    productionCfg.TimeKey = "timestamp"
    productionCfg.EncodeTime = zapcore.ISO8601TimeEncoder
    productionCfg.EncodeLevel = lowerCaseLevelEncoder
    productionCfg.StacktraceKey = "stack"

    jsonEncoder := zapcore.NewJSONEncoder(productionCfg)

    jsonOutCore := zapcore.NewCore(jsonEncoder, stdout, level)

    samplingCore := zapcore.NewSamplerWithOptions(
        jsonOutCore,
        time.Second, // interval
        3, // log first 3 entries
        0, // thereafter log zero entires within the interval
    )

    return zap.New(samplingCore)
}

Zap выборки путем регистрации первых N записей с заданным уровнем и сообщением в течение указанного интервала времени. В приведенном выше примере только первые 3 записи журнала с одинаковым уровнем и сообщением записываются с интервалом в одну секунду. Каждая другая запись журнала будет удалена в течение 0указанного здесь интервала.

Вы можете проверить это, войдя в forцикл:

func main() {
    logger := createLogger()

    defer logger.Sync()

    for i := 1; i <= 10; i++ {
        logger.Info("an info message")
        logger.Warn("a warning")
    }
}

Таким образом, вместо просмотра 20 записей журнала вы должны увидеть всего шесть:

{"level":"info","timestamp":"2023-05-17T16:00:17.611+0100","msg":"an info message"}
{"level":"warn","timestamp":"2023-05-17T16:00:17.611+0100","msg":"a warning"}
{"level":"info","timestamp":"2023-05-17T16:00:17.611+0100","msg":"an info message"}
{"level":"warn","timestamp":"2023-05-17T16:00:17.611+0100","msg":"a warning"}
{"level":"info","timestamp":"2023-05-17T16:00:17.611+0100","msg":"an info message"}
{"level":"warn","timestamp":"2023-05-17T16:00:17.611+0100","msg":"a warning"}

Здесь только первые три итерации цикла дали некоторый результат. Это связано с тем, что журналы, созданные в других семи итерациях, были отброшены из-за конфигурации выборки. Точно так же Zap будет удалять дубликаты, когда похожие записи регистрируются несколько раз в секунду из-за большой нагрузки или когда приложение испытывает серию ошибок.

Хотя выборка журнала может использоваться для уменьшения объема журнала и влияния ведения журнала на производительность, она также потенциально может привести к пропуску некоторых событий журнала, что может повлиять на усилия по устранению неполадок и отладке. Следовательно, выборку следует применять только после тщательного рассмотрения конкретных требований рассматриваемого приложения.

Скрытие конфиденциальных данных в ваших журналах

Еще в 2018 году Twitter пришлось призвать своих пользователей сменить свои пароли из-за того, что они случайно записали миллионы паролей в виде открытого текста во внутренний журнал. Хотя никаких доказательств неправильного использования обнаружено не было, этот инцидент служит горьким напоминанием о том, как журналы приложений, если не обращаться с должным вниманием, могут поставить под угрозу безопасность и конфиденциальность пользователей.

Одним из методов предотвращения непреднамеренной регистрации типа с конфиденциальными полями является редактирование или маскирование данных в точке журнала. В Zap это можно сделать, реализовав интерфейс Stringer , а затем определив точную строку, которая должна возвращаться при регистрации типа. Вот короткая демонстрация:

type User struct {
    ID    string `json:"id"`
    Name  string `json:"name"`
    Email string `json:"email"`
}

func main() {
    logger := createLogger()

    defer logger.Sync()

    user := User{
        ID:    "USR-12345",
        Name:  "John Doe",
        Email: "john.doe@example.com",
    }

    logger.Info("user login", zap.Any("user", user))
}

{"level":"info","timestamp":"2023-05-17T17:00:59.899+0100","msg":"user login","user":{"id":"USR-12345","name":"John Doe","email":"john.doe@example.com"}}

В этом примере все userрегистрируется, раскрывая адрес электронной почты пользователя без необходимости. Вы можете предотвратить это, реализовав Stringerинтерфейс следующим образом:

func (u User) String() string {
    return u.ID
}

Это заменяет весь Userтип только полем IDв журналах:

{"level":"info","timestamp":"2023-05-17T17:05:01.081+0100","msg":"user login","user":"USR-12345"}

Если вам нужно больше контроля, вы можете создать свой собственный zapcore.Encoder, который использует кодировщик JSON в качестве основы при фильтрации конфиденциальных полей:

type SensitiveFieldEncoder struct {
    zapcore.Encoder
    cfg zapcore.EncoderConfig
}

// EncodeEntry is called for every log line to be emitted so it needs to be
// as efficient as possible so that you don't negate the speed/memory advantages
// of Zap
func (e *SensitiveFieldEncoder) EncodeEntry(
    entry zapcore.Entry,
    fields []zapcore.Field,
) (*buffer.Buffer, error) {
    filtered := make([]zapcore.Field, 0, len(fields))

    for _, field := range fields {
        user, ok := field.Interface.(User)
        if ok {
            user.Email = "[REDACTED]"
            field.Interface = user
        }

        filtered = append(filtered, field)
    }

    return e.Encoder.EncodeEntry(entry, filtered)
}

func NewSensitiveFieldsEncoder(config zapcore.EncoderConfig) zapcore.Encoder {
    encoder := zapcore.NewJSONEncoder(config)
    return &SensitiveFieldEncoder{encoder, config}
}

func createLogger() *zap.Logger {
    . . .

    jsonEncoder := NewSensitiveFieldsEncoder(productionCfg)

    . . .

    return zap.New(samplingCore)
}

Этот приведенный выше фрагмент гарантирует, что emailсвойство будет отредактировано, а другие поля оставлены как есть:

{"level":"info","timestamp":"2023-05-17T17:38:11.749+0100","msg":"user login","user":{"id":"USR-12345","name":"John Doe","email":"[REDACTED]"}}

Конечно, это мало поможет, если Userтип зарегистрирован под другим ключом, например user_details. Вы можете удалить if field.Key == "user" условие, чтобы гарантировать, что редактирование выполняется независимо от предоставленного ключа.

Некоторые предостережения относительно пользовательских кодировщиков

При использовании пользовательской кодировки с Zap, как и в предыдущем разделе, вам также может потребоваться реализовать Clone()метод в zapcore.Encoderинтерфейсе, чтобы он также работал для дочерних регистраторов, созданных с помощью With()метода:

child := logger.With(zap.String("name", "main"))
child.Info("an info log", zap.Any("user", u))

Перед реализацией Clone()вы заметите, что пользовательская настройка EncodeEntry() не выполняется для дочернего регистратора, в результате чего поле электронной почты отображается неотредактированным:

{"level":"info","timestamp":"2023-05-20T09:14:46.043+0100","msg":"an info log","name":"main","user":{"id":"USR-12345","name":"John Doe","email":"john.doe@example.com"}}

Когда With()используется для создания дочернего регистратора, метод Clone()настроенного Encoderвыполняется для его копирования и обеспечения того, чтобы добавленные поля не влияли на оригинал. Без реализации этого метода для вашего пользовательского типа кодировщика вместо этого вызывается Clone()метод, объявленный во встроенном кодировщике (в данном случае JSON Encoder), и это означает, что дочерние регистраторы не будут использовать вашу пользовательскую кодировку.zapcore.Encoder

Вы можете исправить эту ситуацию, реализуя Clone()метод следующим образом:

func (e *SensitiveFieldEncoder) Clone() zapcore.Encoder {
    return &SensitiveFieldEncoder{
        Encoder: e.Encoder.Clone(),
    }
}

Теперь вы увидите правильный отредактированный вывод:

{"level":"info","timestamp":"2023-05-20T09:28:31.231+0100","msg":"an info log","name":"main","user":{"id":"USR-12345","name":"John Doe","email":"[REDACTED]"}}

Однако обратите внимание, что пользовательские кодировщики не влияют на поля, прикрепленные с помощью With()метода, поэтому, если вы сделаете что-то вроде этого:

child := logger.With(zap.String("name", "main"), zap.Any("user", u))
child.Info("an info log")

Вы получите предыдущий неотредактированный вывод независимо от того, реализовано это или нет, потому что в аргументе Clone()присутствуют только поля, добавленные в точку журнала :fields []zapcore.FieldEncodeEntry()

{"level":"info","timestamp":"2023-05-20T09:31:11.919+0100","msg":"an info log","name":"main","user":{"id":"USR-12345","name":"John Doe","email":"john.doe@example.com"}}

Регистрация с помощью Zap в приложении Go

Теперь, когда мы изучили API ведения журнала Zap и некоторые из его наиболее полезных функций, пришло время изучить практический пример, демонстрирующий, как вы можете использовать его для включения ведения журнала в веб-приложение Go. Конкретный пример этой реализации вы можете найти здесь .

Начните с клонирования демонстрационного проекта на свой компьютер с помощью следующей команды:

git clone https://github.com/betterstack-community/go-logging

cd go-logging

Затем переключитесь на zapветку следующим образом:

git checkout zap

Откройте logger/logger.goфайл в текстовом редакторе и проверьте его содержимое:

регистратор/logger.go

package logger

. . .

func Get() *zap.Logger {

    . . .

    return logger
}

func FromCtx(ctx context.Context) *zap.Logger {
    if l, ok := ctx.Value(ctxKey{}).(*zap.Logger); ok {
        return l
    } else if l := logger; l != nil {
        return l
    }

    return zap.NewNop()
}

func WithCtx(ctx context.Context, l *zap.Logger) context.Context {
    if lp, ok := ctx.Value(ctxKey{}).(*zap.Logger); ok {
        if lp == l {
            return ctx
        }
    }

    return context.WithValue(ctx, ctxKey{}, l)
}

Функция Get()используется для инициализации zap.Loggerэкземпляра, если он еще не был инициализирован, и возвращает тот же экземпляр для последующих вызовов. Регистратор настроен на logs/app.logодновременную запись в стандартный вывод и в файл:

func Get() *zap.Logger {
    once.Do(func() {
        . . .

        // log to multiple destinations (console and file)
        // extra fields are added to the JSON output alone
        core := zapcore.NewTee(
            zapcore.NewCore(consoleEncoder, stdout, logLevel),
            zapcore.NewCore(fileEncoder, file, logLevel).
                With(
                    []zapcore.Field{
                        zap.String("git_revision", gitRevision),
                        zap.String("go_version", buildInfo.GoVersion),
                    },
                ),
        )

        logger = zap.New(core)
    })

    return logger
}

Он используется в mainфункции следующим образом:

main.go

func main() {
    l := logger.Get()
    . . .
}

С другой стороны, WithCtx()метод связывает zap.Loggerэкземпляр с a context.Contextи возвращает его, а FromCtx()принимает a context.Contextи возвращает zap.Loggerсвязанное с ним (если есть). Это упрощает хранение и получение одного и того же Loggerэкземпляра в контексте HTTP-запроса.

Например, это requestLogger()функция промежуточного программного обеспечения, которая извлекает экземпляр регистратора и создает дочерний регистратор, используя идентификатор корреляции запроса. Затем он продолжает связывать дочерний регистратор с контекстом запроса, чтобы вы могли получить его в последующих обработчиках:

промежуточное ПО.go

func requestLogger(next http.Handler) http.Handler {
    return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
        // retrieve the standard logger instance
        l := logger.Get()

        // create a correlation ID for the request
        correlationID := xid.New().String()

        ctx := context.WithValue(
            r.Context(),
            correlationIDCtxKey,
            correlationID,
        )

        r = r.WithContext(ctx)

        // create a child logger containing the correlation ID
        // so that it appears in all subsequent logs
        l = l.With(zap.String(string(correlationIDCtxKey), correlationID))

        w.Header().Add("X-Correlation-ID", correlationID)

        lrw := newLoggingResponseWriter(w)

        // the logger is associated with the request context here
        // so that it may be retrieved in subsequent `http.Handlers`
        r = r.WithContext(logger.WithCtx(ctx, l))

        . . .

        next.ServeHTTP(lrw, r)
    })
}

Регистратор может быть впоследствии извлечен из контекста запроса следующим образом:

handlers.go

func searchHandler(w http.ResponseWriter, r *http.Request) error {
    ctx := r.Context()

    l := logger.FromCtx(ctx)

    l.Debug("entered searchHandler()")

     . . .
}

Обратите внимание на наличие correlation_idв выводе:

2023-05-20T15:32:50.821+0100    DEBUG   entered searchHandler() {"correlation_id": "chkdk4koo2ej1bpr4l90"}

Использование Zap в качестве бэкенда для Slog

После введения нового пакета структурированного ведения журналов для Go , известного как Slog , была проведена работа по реализации slog.Handlerинтерфейса в Zap, позволяющего использовать Slog API с серверной частью Zap. Эта интеграция обеспечивает согласованность API ведения журналов при различных зависимостях и облегчает плавную замену пакетов ведения журналов с минимальными изменениями в коде.

На данный момент Slog не был включен в официальный выпуск Go. Поэтому официальная интеграция Zap со Slog обеспечена в виде отдельного модуля , который можно установить с помощью следующей команды:

go get go.uber.org/zap/exp/zapslog

После этого вы можете использовать его в своей программе следующим образом:

func main() {
    logger := zap.Must(zap.NewProduction())

    defer logger.Sync()

    sl := slog.New(zapslog.NewHandler(logger.Core()))

    sl.Info(
        "incoming request",
        slog.String("method", "GET"),
        slog.String("path", "/api/user"),
        slog.Int("status", 200),
    )
}

{"level":"info","ts":1684613929.8395753,"msg":"incoming request","method":"GET","path":"/api/user","status":200}

Если вы когда-нибудь решите переключиться на другой бэкенд, единственное необходимое изменение — это аргумент метода slog.New(). Например, вы можете переключиться с Zap на серверную часть Slog JSONHandler , внеся следующее изменение:

func main() {
    sl := slog.New(slog.NewJSONHandler(os.Stdout, nil))

    sl.Info(
        "incoming request",
        slog.String("method", "GET"),
        slog.String("path", "/api/user"),
        slog.Int("status", 200),
    )
}

Все остальное должно продолжать работать, за исключением того, что вывод журнала может немного отличаться в зависимости от вашей конфигурации.

{"time":"2023-05-20T21:21:43.335894635+01:00","level":"INFO","msg":"incoming request","method":"GET","path":"/api/user","status":200}

Заключительные мысли

В этой статье представлен анализ пакета Zap, одного из самых популярных пакетов ведения журналов, используемых в программах Go. В нем освещаются многие ключевые функции пакета и объясняется, как его можно интегрировать в стандартную настройку веб-приложения. В статье также рассматриваются некоторые передовые методы ведения журналов и способы их интеграции с новой стандартной библиотекой пакета Slog. Чтобы углубиться в ведение журнала Zap, обязательно изучите его официальную документацию и часто задаваемые вопросы .

Спасибо за прочтение и удачной регистрации!