Что выбрать для логирования оператора?

Давайте поднимем нашу тему с журналом INFO оператора. В отличие от наиболее распространенного метода печати fmt.Printf, он печатает информацию о конкретном параметре не в сообщении, а в журнале отдельно, как строку JSON.

{"severity":"INFO","eventTime":"2022-07-09T09:04:55.260Z","logger":"controller.opresource","message":"Deleting OpResource, because it is no longer in scope!","reconciler group":"op.spotify.com","reconciler kind":"OpResource","name":"afs-proxy-0618bce","namespace":"","name":"afs-proxy"}

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

Войти оператор

controller-runtime alias.go предоставил объект Log по умолчанию, реализация которого выполняется go-logr по умолчанию.

// Log is the base logger used by controller-runtime.  It delegates
// to another logr.Logger.  You *must* call SetLogger to
// get any actual logging.
Log = log.Log

go-logr — это простая структура журнала, в которой нет самой функции вывода журнала, но есть дальнейшая оптимизация Go log классификации журнала, предложенная Дэйвом Чейни.

  • При нормальных обстоятельствах программе Go нужны только два уровня журналов: INFO и ERROR; Пока, тогда как другие уровни не важны.
  • Для отладки он обеспечивает вывод V-уровня, отказываясь от других уровней, таких как trace или debug.

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

В controller-runtime по умолчанию DelegatingLogSink реализовано как вывод журнала Logr по умолчанию, где logger использует простой NullLogSink. Этой реализации по умолчанию достаточно для большинства сценариев, и ее можно применять в сочетании с fmt.Sprintf.

log.V(10).Info(fmt.Sprintf("Create Resources for User:%s, Project:%s", user, project))

Однако у DelegatingLogSink есть очевидный недостаток: его неэффективность является узким местом в производительности, когда он развертывается в качестве контроллера на уровне кластера и управляет тысячами ресурсов. И следующие две являются основными причинами, приводящими к его неэффективности.

  • Он использует много блокировок. DelegatingLogSink использует блокировку мьютекса promisesLock, и оба метода WithName и WithValues loggerPromise требуют блокировки, и даже функции Enable, Info и Error полагаются на RLock, блокировку чтения. Несомненно, частые блокировки, даже с блокировками чтения, в выводе журнала с большим количеством операций записи приведут к низкой производительности.
func (l *DelegatingLogSink) Info(level int, msg string,keysAndValues ...interface{}) {
  l.lock.RLock()
  defer l.lock.RUnlock()
  l.logger.Info(level, msg, keysAndValues...)
}
  • В содержимом журнала используется fmt.Sprintf. Мы используем операции Strings.Join или Buffer для замены fmt.Sprintf и + для соединения строк для повышения эффективности многих строковых операций Go (прочитайте Объединить строки в golang: быстрый тест: + или fmt.Sprintf, чтобы узнать больше). Но при написании журналов мы надеемся получить это бесплатно из среды журналов, а не изобретать велосипеды, чего не могут предложить реализации logr и controller-runtime по умолчанию.

Другие варианты

Есть ли другие варианты, если мы откажемся от реализации по умолчанию? И как переключаться?

Сообщество Go предоставляет широкий спектр пакетов журналов, и даже собственный пакет может удовлетворить основные требования к выводу журнала.

В разделе A Sip of Go Log мы углубились в базовую логику журнала и сравнили некоторые популярные пакеты с открытым исходным кодом для журналов, среди которых zap от Uber привлек наше внимание своей производительностью. Давайте вспомним эти удивительные цифры и посмотрим, является ли zap лучшим вариантом.

В controller-runtime уже есть реализация zapr по умолчанию, которая использовалась во многих местах внутри компании. Но почему он не используется в качестве реализации по умолчанию?

Пользователи могут интегрировать zap, настроив Logger для реализации определенных дополнительных функций, таких как преобразование времени, вывод журналов во внешнее хранилище и т. д. controller-runtime инкапсулирует его как logr.Logger, в конечном счете, в zap реализации controller-runtime.

Выполните четыре шага для определения zap Logger.

zap.go реализует два энкодера console и json и предоставляет функции, требуемые стандартом zapr Logger, такие как WriteTo и Level.

По умолчанию zapr использует consoleEncoder и debugLevel/warnLevelв режиме разработки, а jsonEncoderи infoLevel/errorLevelв производстве.

А что касается замены дефолтного Logr в этом Операторе, то нам достаточно использовать Log: zap.New(), при инициализации Reconciler в основном методе, и тогда мы можем распечатать лог в контроллере по следующему шаблону.

Почему зап быстрый

5 шагов, которые выполняет zap, каждый из которых отражает оптимизацию, в основном используют две функции Go, которые определяют эффективность zap.

  • Используйте sync.Pool, чтобы избежать перегрузки памяти при выводе журналов.

log.Check — это первый шаг печати, и в методе Check сделаны две оптимизации производительности.

  1. Избегайте ненужных операций, таких как пропуск ненужных Log уровней и прямой возврат журналов, которые не нужно печатать. Например, он возвращается сразу, как только приходит журнал уровня Debug, если наш уровень журнала Info.
  2. Повторно используйте объект Entry. zap создает реальный печатный объект Entry, который будет проверен, чтобы повторно использовать его в объектах, сохраненных в sync.Pool, снижая частоту создания и устранения высокочастотных объектов журнала и, в конечном итоге, уменьшая GC.
func getCheckedEntry() *CheckedEntry {
  ce := _cePool.Get().(*CheckedEntry)
  ce.reset()
  return ce
}

Pool обновляется каждые Write.

func (ce *CheckedEntry) Write(fields ...Field) {
  //…
  putCheckedEntry(ce)
}

При выводе логов мы также используем sync.Pool для оптимизации памяти. И consoleEncoder, и jsonEncoder по умолчанию хранят напечатанную информацию в abuffer, который использует bufferPool, созданный sync.Pool, для получения объекта и получения окончательного выходного журнала путем последующего сплайсинга.

  • Избегайте разработки API с interface{} и оптимизации сериализации JSON. Обеспечьте сериализацию JSON с дизайном со строгой типизацией и нулевым объемом памяти.

В выводе журнала zap формат JSON является окончательным унифицированным форматом вывода, даже console_encoder вызывает json_encoder печатать поля в конце концов. Структура Fields значительно ускоряет печать журнала и используется для определения информации о типе каждого входного параметра для быстрого преобразования типа в строку. И все возможные преобразования между типом и строкой определены в методе AddTo поля, что позволяет избежать вывода или отражения типа с помощью zap и значительно повышает эффективность вывода.

Конечно, не забудьте выпустить объект, полученный в bufferPool!

Тест производительности

Пусть эталонный тест подтвердит отличную производительность zap.

Сравнивая производительность трех пакетов журналов как в сценариях без параметров, так и в сценариях с несколькими параметрами, я могу «с гордостью» заявить, что zap является лучшим: zap Logr примерно в 7 раз быстрее, чем logr по умолчанию. в controller-runtime.

Легко сделать вывод, что замена реализации журнала по умолчанию необходима, если мы хотим реализовать высокопроизводительный оператор. Но следует отметить, что вам может потребоваться обновить kubebuilder до последней версии v3, если вы все еще используете v1, что включает в себя миграцию с klog на logr, и см. Инструкции по миграции структурированного и контекстного ведения журналов для получения инструкций.

Спасибо за прочтение!