Golang логирование ошибок

Этот пост вдохновлен темой в форуме Go Forum, начатой Nate Finch. Этот пост сконцентрирован на языке Go, но если пройти мимо этого, я думаю, идеи представленные тут широко применимы.

Почему нет любви?

Пакет log в Go не имеет уровней для логов, вы можете сами вручную добавить приставки DEBUG, INFO, WARN, и ERROR. Также logger тип в Go не имеет возможности включить или выключить эти уровни отдельно для выбранных пакетов. Для сравнения давайте глянем на несколько его замен от сторонних разработчиков.

glog от Google имеет уровни:

• Info
• Warning
• Error
• Fatal (завершает программу)

Посмотрим на другую библиотеку, loggo, разработанную для Juju, в ней доступны уровни:

• Trace
• Debug
• Info
• Warning
• Error
• Critical

Loggo также имеет возможность задать уровень детализации лога для нужных пакетов по отдельности.

Перед вами два примера, явно созданных под влиянием других библиотек для логирования на других языках.

Фактически их происхождение можно проследить до syslog(3), возможно, даже раньше. И я думаю, что они не правы.

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

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

Давайте поговорим о предупреждениях (WARNING)

Давайте начнем с самого простого. Никому не нужен уровень журнала WARNING (предупреждение).

Никто не читает предупреждения, потому что по определению ничего плохого не произошло. Возможно, что-то может пойти не так в будущем, но это звучит как чья-то, a не моя проблема.

Кроме того, если вы используете какое-то многоуровневое логирование, зачем вам устанавливать уровень WARNING? Вы установили бы уровень INFO или ERROR. Установка уровня WARNING означает, что вы, вероятно, регистрируете ошибки на уровне WARNING.

Исключите уровень warning — это или информационное сообщение, или ошибка.

Давайте поговорим об уровне невосстановимой ошибки (fatal)

Уровень FATAL фактически заносит сообщение в лог, а затем вызывает os.Exit(1). В принципе это означает:

• отложенные выражения в других подпрограммах(горутинах) не выполняются;
• буферы не очищаются;
• временные файлы и каталоги не удаляются.

По сути, log.Fatal менее многословен, но семантически эквивалентен панике.

Общепринято, что библиотеки не должны использовать panic1, но если вызов log.Fatal2 имеет тот же эффект, он также должен быть запрещен.

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

Не записывайте сообщения с уровнем FATAL, предпочтите вместо этого вернуть ошибку вызывающей стороне. Если ошибка доходит до main.main, то это правильное место для выполнения любых действий по очистке перед завершением программы.

Давайте поговорим об ошибке (уровень ERROR)

Обработка ошибок и ведение журнала (лога) тесно связаны, поэтому, на первый взгляд, регистрация на уровне ошибок (ERROR) должна быть легко оправданной. Я не согласен.

В Go, если вызов функции или метода возвращает значение ошибки, то реально у вас есть два варианта:

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

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

Позвольте мне убедить вас с помощью этого фрагмента кода:

err := somethingHard()
if err != nil {
        log.Error("oops, something was too hard", err)
        return err // what is this, Java ?
}

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

Нужно четко понимать, я не говорю, что вы не должны записывать в лог, что произошла смена состояния:

if err := planA(); err != nil {
        log.Infof("could't open the foo file, continuing with plan b: %v", err)
        planB()
}

Но в действительности log.Info и log.Error имеют одну и ту же цель.

Я не говорю «не регистрируйте ошибки»! Вместо этого я ставлю вопрос, что является наименьшим возможным API для ведения журнала (логирования)? И когда дело доходит до ошибок, я считаю, что подавляющая часть вещей, записанных на уровне ERROR, просто делается так, потому что они связаны с ошибкой. На самом деле они просто информационные, поэтому мы можем удалить логирование на уровне ошибок (ERROR) из нашего API.

Что осталось?

Мы исключили предупреждения (WARNING), аргументировали, что ничего не должно регистрироваться на уровне ошибок (ERROR), и показали, что только верхний уровень приложения должен иметь своего рода log.Fatal поведение. Что осталось?

Я считаю, что есть только две вещи, которые вы должны заносить в лог:

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

Очевидно, это уровни отладка (DEBUG) и информационный (INFO) соответственно.

log.Info должен просто записать эту строку в вывод журнала. Не должно быть возможности отключить его, так как пользователю следует рассказывать только то, что ему полезно. Если возникает ошибка, которая не может быть обработана, она должна появиться в main.main там, где программа завершается. Незначительные неудобства, связанные с необходимостью вставки префикса FATAL перед окончательным сообщением журнала или записи непосредственно в os.Stderr с помощью fmt.Fprintf, не является достаточным основанием для расширения пакета матодом log.Fatal.

log.Debug, это совсем другое дело. Он нужен разработчику или инженера поддержки для контроля работы программы. Во время разработки выражения отладки (debug) должны быть многочисленными, не прибегая к уровню трассировки (trace) или debug2 (ты знаешь кто ты). Пакет ведения логов должен поддерживать детализированное управление для включения или отключения выражений отладки, для нужных пакетов пакете или, возможно, даже в более узкой области видимости.

Заключение

Если бы это был опрос в Твиттере, я бы попросил вас выбрать между

• ведение логов — это важно
• ведение логов — это трудно

Но дело в том, что ведение лога является и тем и другим. Решение этой проблемы ДОЛЖНО состоять в том, чтобы разрушать и беспощадно сокращать ненужные отвлечения.

Как вы думаете? Это достаточно сумасбродно, чтобы работать, или просто сумасбродно?

Примечания

Некоторые библиотеки могут использовать panic/recover в качестве механизма внутреннего потока управления, но основная мантра заключается в том, что они не должны допускать утечки этих операций потока управления за границу пакета.

По иронии судьбы, хотя в нем отсутствует уровень вывода DEBUG, стандартный пакет логирования Go имеет функции Fatal и Panic. В этом пакете количество функций, которые приводят к внезапному завершению работы программы, превышает число тех, которые этого не делают.

Об авторе

Автор данной статьи, Дейв Чини, является автором многих популярных пакетов для Go, например github.com/pkg/errors и github.com/davecheney/httpstat. Авторитет и опыт автора вы можете оценить самостоятельно.

От переводчика

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

Плюс презентация размышление Нужен ли нам новый логер и каким он должен быть? от Chris Hines.

Есть несколько реализаций идей Дейва go-log и немного отходящий в вопросе уровня ERROR и более тщательно продуманный пакет logr.

Содержание статьи

• Разделение логирования для разных задач
• Логирование ошибок от HTTP-сервера
• Дополнительные методы логирования
• Конкурентное логирование в Golang
• Логирование сообщений в файл

Логгирование можно поделить на два различных типа, или уровня. К первому типу относятся информационные сообщения (вроде «Запуск сервера на :4000«), а ко второму типу относятся сообщения об ошибках.

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

• Информационным сообщениям добавим префикс "INFO". Такое сообщение будет выводиться в стандартный поток вывода (stdout);
• Сообщениям об ошибках добавим префикс "ERROR". Такие сообщения будут выводиться в стандартный поток ошибок (stderr) вместе с соответствующим названием файла и номером строки, которая вызвала логгер для записи (это поможет в отладке на будущее).

Есть несколько способов использования разных логгеров, но самый простой и понятный подход заключается в использовании функции log.New() для создания двух новых настраиваемых логгеров.

Откройте файл main.go и обновите его код следующим образом:

Отлично… проверим эти изменения в действии!

Попробуйте запустить приложение, затем откройте другое окно терминала и попробуйте запустить его во второй раз. В результате должна появится сообщение об ошибке, потому что сетевой адрес, который наш сервер хочет прослушать (":4000"), уже используется другим процессом.

Логи во втором терминале должны выглядеть следующим образом:

Обратите внимание, что у этих двух сообщений разные префиксы — чтобы их можно было легко различить в терминале — и наше сообщение об ошибке также включает в себя название файла и номер строки (main.go:37), которая вызывает логгер для записи возникнувшей ошибки.

На заметку: Если вы хотите включить весь путь файла в лог  вместо просто названия файла, при создании логгера можно использовать флаг log.Llongfile вместо log.Lshortfile. Вы также можете заставить свой логгер  использовать UTC дату (вместо локальной), добавив флаг log.LUTC.

Разделение логирования для разных задач

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

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

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

Например, можно перенаправить потоки из stdout и stderr в файлы на диске при запуске приложения из терминала следующим образом:

Логирование ошибок от HTTP-сервера

Нам нужно внести еще одно изменение в коде нашего веб-приложения. По умолчанию, если HTTP-сервер обнаруживает ошибку, он логирует её с помощью стандартного логгера. Но, лучше использовать наш новый логгер errorLog.

Нам требуется инициализировать новую структуру http.Server, содержащую параметры конфигурации для сервера, вместо использования http.ListenAndServe().

Проще всего будет показать это на примере:

Дополнительные методы логирования

До сих пор мы использовали методы Println(), Printf() и Fatal() для записи логов. Однако Go предоставляет ряд других методов, с которыми стоит ознакомиться.

Как правило, лучше избегать использования методов Panic() и Fatal() за пределами функции main(). Вместо этого рекомендуется возвращать возникшие ошибки, а паниковать или принудительно завершать приложение непосредственно из самого main().

Конкурентное логирование в Golang

Новые логгеры, созданные с помощью log.New(), конкурентно-безопасны. Вы можете делиться одним логгером и использовать его в нескольких горутинах, не беспокоясь об возможных конфликтах между ними из за записи сообщений в одном и том же логгере.

Если у вас есть несколько логгеров, использующих для записи одно и то же место назначения, вам требуется убедиться, что базовый метод  Write() также безопасен для конкурентного использования.

Логирование сообщений в файл

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

Скачать исходный код сайта

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

Скачать: snippetbox-11.zip

Logging is helpful for more than just tracking error conditions in your
application. It’s also a great way to record any notable events that occur
during the lifetime of a program so that you can have a good idea of what is
going on and what needs to be changed, dropped, or optimized further. Adopting
good logging practices provides valuable insights into the flow of your program,
and what parameters are responsible for various events, which is immensely
valuable when trying to reproduce problems in your application.

In this tutorial, we will discuss the basics of logging in Go starting with the
built-in log package, and then proceed to discuss third-party logging
frameworks and how they go far beyond what the default log package has to
offer. By following through with this article, you’ll learn the following Go
logging concepts:

Prerequisites

Before proceeding with this article, ensure that you have a recent version of Go
installed on your computer so that you can run the snippets and experiment with
some of the concepts that will be introduced in the following sections.

When to log

Logs need to communicate the various happenings in your application effectively
so they must be descriptive and provide enough context for you to understand
what happened, and what (if anything) needs to be done next. Logs are also
reactive because they can only tell you about something that has already
happened in your application.

You can read the log and take some action afterward to prevent that event from
happening again, but if you don’t have the log in the first place, you will be
at a disadvantage when trying to find the cause of a problem or gain insight
into some notable events.

Therefore, logging should start as early as possible during the development
process and it should be kept in place when the program is deployed to
production. Here are some general recommendations for where to log in your
application:

• At the beginning of an operation (e.g at the start of a scheduled job or when
  handing incoming HTTP requests).
• When a significant event occurs while the operation is in progress, especially
  if the flow of the code changes entirely due to such an event.
• When an operation is terminated regardless of whether it succeeds or fails.

What should you log

You should log all notable events in your program, and add sufficient context to
help you understand what triggered the event. For example, if a server error
occurs, the reason for the error and a stack trace should be included in the
corresponding log entry. If a failed login attempt is detected, you can log the
IP address of the client, user agent, username or id, and the reason for failure
(password incorrect, username invalid, etc.).

A high number of failed logins attempts for non-existent users or quickly
reaching the login attempts limits for many accounts may be an indicator of a
coordinated attack on your service, and you can set up alerts to draw your
attention to such issues when they arise if you’re processing your logs through
a log management service (see example from
Logtail below.

Let’s look at a practical example of what to include in a log entry for each
incoming HTTP request to your server. You should log at least the following:

• the route and query parameters (if any),
• request method (GET, POST, etc),
• response code,
• user agent, and
• time taken to complete the request.

Armed with this data, you can figure out your busiest routes, average response
times, if your service is experiencing some degradation in performance (due to
increased server errors or response times), and much more. You can also use the
captured data to build graphs and other visualizations, which could come in
handy when discussing trends and opportunities for future investment with the
management at your organization.

In the case of unexpected server errors (5xx), it may also be necessary to log
the request headers and body so that you can reproduce the request and track
down the issue, but ensure that you are careful not to leak sensitive details
when doing so as the headers and bodies of certain requests can contain
sensitive info like passwords, API keys, or credit card information. If you do
decide to log such data, ensure to write specific rules to sanitize it and
redact all the sensitive fields from the log entry.

What to avoid when logging

Generally, you should include as many details as possible in your log entries,
but you must also be careful not to add details that will make your logs
unnecessarily verbose as this will impact storage requirements and potentially
increase the cost of managing your logs.

As alluded to in the previous section, you should also avoid logging sensitive
information or Personally Identifiable Information (PII) such as phone numbers,
home addresses, and similar details, so you don’t fall afoul of regulations like
GDPR, CCPA, and other data compliance laws.

The Go standard library log package

Now that we’ve discussed a general strategy to help you get started quickly with
logging, let’s discuss the how of logging in Go applications. In this section,
We’ll explore the built-in log package in the standard library designed to
handle simple logging concerns. While this package does not meet our criteria
for a good logging framework due to some
missing features, it’s still necessary to be
familiar with how it works as many in the Go community rely on it.

Here’s the most basic way to write a log message in Go:

package main

import "log"

func main() {
    log.Println("Hello from Go application!")
}

2022/08/10 11:19:52 Hello from Go application!

The output contains the log message and a timestamp in the local time zone that
indicates when the entry was generated. Println() is one of methods accessible
on the preconfigured logger prints its output to the standard error. The
following other methods are available:

log.Print()
log.Printf()
log.Fatal()
log.Fatalf()
log.Fatalln()
log.Panic()
log.Panicf()
log.Panicln()

The difference between the Fatal and Panic methods above is that the former
calls os.Exit(1) after logging a message, while the latter calls panic().

log.Fatalln("cannot connect to the database")

2022/08/10 14:32:51 cannot connect to database
exit status 1

log.Panicln("cannot connect to the database")

2022/08/10 14:34:07 cannot connect to database
panic: cannot connect to database

goroutine 1 [running]:
log.Panicln({0xc00006cf60?, 0x0?, 0x0?})
        /usr/local/go/src/log/log.go:402 +0x65
main.main()
        /home/ayo/dev/demo/random/main.go:6 +0x45
exit status 2

If you want to customize the default logger, you can call log.Default() to
access it and then call the appropriate methods on the returned Logger object.
For example, you can change the output of the logger to stdout as shown below:

package main

import (
    "log"
    "os"
)

func main() {
    defaultLogger := log.Default()
    defaultLogger.SetOutput(os.Stdout)
    log.Println("Hello from Go application!")
}

You can also create a completely custom logger through the log.New() method
which has the following signature:

func New(out io.Writer, prefix string, flag int) *Logger

The first argument is the destination of the log messages produced by the
Logger, which can be anything that implements the io.Writer interface. The
second is a prefix that is prepended to each log message, while the third
specifies a set of constants that is
used to add details to each log message.

package main

import (
    "log"
    "os"
)

func main() {
    logger := log.New(os.Stderr, "", log.Ldate|log.Ltime)
    logger.Println("Hello from Go application!")
}

The above logger is configured to output to the standard error, and it uses the
initial values for the standard logger, which means the output from the logger
is the same as before:

2022/08/10 11:19:52 Hello from Go application!

We can customize it further by adding the application name, file name, and line
number to the log entry. We’ll also add microseconds to the timestamp and cause
it to be presented in UTC instead of the local time zone:

logger := log.New(
  os.Stderr,
  "MyApplication: ",
  log.Ldate|log.Ltime|log.Lmicroseconds|log.LUTC|log.Lshortfile,
)
logger.Println("Hello from Go application!")

The output becomes:

MyApplication: 2022/08/10 13:55:48.380189 main.go:14: Hello from Go application!

The MyApplication: prefix appears at the beginning of each log entry and the
timestamp (now UTC instead of the local time) now includes microseconds. The
point of log generation also included in the output to help you locate the
source of each entry in the codebase.

Logging to a file in Go

So far, we’ve seen several examples that log to the standard output or standard
error. Let’s now address the common need to transport logs into a file and also
how to rotate such log
files to prevent them
from growing too large which can make them cumbersome to work with.

Using shell redirection

The easiest way to output logs into a file is to keep logging to the console and
then use shell redirection to append each entry to a file:

go run main.go 2>> myapp.log

The above command redirects the standard error stream to a myapp.log file in
the current directory.

MyApplication: 2022/08/29 10:05:25.477612 main.go:14: Hello from Go application!

If you’re logging to the standard output, you can use 1>> or >> instead:

go run main.go >> myapp.log

To redirect both the standard output and standard error streams to a single
file, you can use &>>.

go run main.go &>> myapp.log

You can also redirect each output stream to separate files as shown below:

go run main.go 2>> stderr.log >> stdout.log

Finally, you can use the tee command to retain the console output while
redirecting one or both streams to a file:

go run main.go 2> >(tee -a stderr.log >&2)

go run main.go > >(tee -a stdout.log)

go run main.go > >(tee -a stdout.log) 2> >(tee -a stderr.log >&2)

Writing log messages directly to a file

A second way to log into files in Go is to open the desired file in the program
and write to it directly. When using this approach, you need to ensure that the
file is created or opened with the right permissions to ensure that the program
can write to it.

package main

import (
    "log"
    "os"
)

func main() {
    // create the file if it does not exist, otherwise append to it
    file, err := os.OpenFile(
        "myapp.log",
        os.O_APPEND|os.O_CREATE|os.O_WRONLY,
        0664,
    )
    if err != nil {
        panic(err)
    }
    defer file.Close()

    logger := log.New(
        file,
        "MyApplication: ",
        log.Ldate|log.Ltime|log.Lmicroseconds|log.LUTC|log.Lshortfile,
    )
    logger.Println("Hello from Go application!")
}

Since the os.File type implements a Write() method that satisfies the
io.Writer interface, we can open any file and use it as the output for our
logger as shown above. If you execute the code, you’ll notice that the log
message is placed in a myapp.log file in the current directory:

. . .
MyApplication: 2022/08/10 14:12:24.638976 main.go:26: Hello from Go application!

You can also use the io.MultiWriter() method to log to multiple writers at
once such as multiple files or a file and the standard error (or output) at
once:

. . .
logger := log.New(
  io.MultiWriter(file, os.Stderr), // log to both a file and the standard error
  "MyApplication: ",
  log.Ldate|log.Ltime|log.Lmicroseconds|log.LUTC|log.Lshortfile,
)
. . .

When you run the program again, you’ll notice that the log entry is recorded to
the console and the myapp.log file simultaneously.

Rotating log files

When logging to files, you should take the time to setup a log rotation
policy so that the file
sizes are kept manageable, and older logs get deleted automatically to save
storage space.

While you can rotate the files yourself by appending a timestamp to the log
filename coupled with some checks to delete older files, we generally recommend
using an external program like
logrotate, a standard utility on Linux
, or a well tested third-party Go package for this purpose.

We prefer the former approach since it’s the standard way to solve this problem
on Linux, and it is more flexible than other solutions. It can also copy and
truncate a file so that file deletion doesn’t occur in the middle of writing a
log entry which can be disruptive to the application. If you want to learn more
about rotating log files using
logrotate, please see
the linked tutorial on the subject.

You can also utilize Lumberjack a
rolling file logger package for Go applications as shown below:

package main

import (
    "log"

    "gopkg.in/natefinch/lumberjack.v2"
)

func main() {
    fileLogger := &lumberjack.Logger{
        Filename:   "myapp.log",
        MaxSize:    10, // megabytes
        MaxBackups: 10, // files
        MaxAge:     14,   // days
        Compress:   true, // disabled by default
    }

    logger := log.New(
        fileLogger,
        "MyApplication: ",
        log.Ldate|log.Ltime|log.Lmicroseconds|log.LUTC|log.Lshortfile,
    )
    logger.Println("Hello from Go application!")
}

With the above configuration in place, the myapp.log file will continue to be
populated until it reaches 10 megabytes. Afterward, it will be renamed to
myapp-<timestamp>.log (such as myapp-2022-08-10T18-30-00.000.log) and a new
file with the original name (myapp.log) is created. The backup files are also
gzip compressed so that they take up less space on the server, but you can
disable this feature if you want. When the number of backup files exceeds 10,
the older ones will be deleted automatically. The same thing happens if the file
exceeds the number of days configured in MaxAge regardless of the number of
files present.

Limitations of the log package

While the log package is a handy way to get started with logging in Go, it
does have several limitations that make it less than ideal for production
applications whose logs are meant to be processed by machines for monitoring and
further analysis.

Lack of log levels

Levelled logging are one of the most sought-after features in a
logging package, but they are strangely missing from the log package in Go.
You can fix this omission by create a custom log package that builds on the
standard log as demonstrated in
this GitHub gist.
It provides the ability to use leveled methods (Debug(), Error(), etc), and
turn off certain logs based on their level.

You can utilize the custom log package in your application as follows:

package main

import (
    "log"
    "os"

    "github.com/username/project/internal/logger"
)

func main() {
    l := log.New(
        os.Stderr,
        "MyApplication: ",
        log.Ldate|log.Ltime|log.Lmicroseconds|log.LUTC,
    )

    logger.SetLevel(2) // default to the info level
    logger.SetLogger(l) // Override the default logger

    logger.Trace("trace message")
    logger.Debug("debug message")
    logger.Info("info message")
    logger.Warn("warning message")
    logger.Error("error message")
    logger.Fatal("fatal message")
}

Notice that the Trace and Debug() methods do not produce any output proving
that the call to logger.SetLevel() had the desired effect:

MyApplication: 2022/08/10 16:22:45.146744 [INFO] info message
MyApplication: 2022/08/10 16:22:45.146775 [WARN] warning message
MyApplication: 2022/08/10 16:22:45.146789 [ERR] error message
MyApplication: 2022/08/10 16:22:45.146800 [FATAL] fatal message

2. Lack of support for structured logging

The use of basic or unstructured logs is being gradually phased out in the tech
industry as more organizations adopt the use of a structured format (usually
JSON) which enables each log entry to be treated as data that can be
automatically parsed by machines for monitoring, alerting, and other forms of
analysis.

Due to this trend, many logging frameworks have added structured logging APIs to
their public interface, and some support structured logging only. However, the
log package in Go is not of them as it only supports the basic string
formatted logs through its printf-style methods. If you desire to output your Go
logs in a structured format, you have no choice but to use a third-party logging
framework. In the next section, we will consider a few packages that make
structured logging in Go a breeze.

Third-party logging libraries to consider

Due to the above limitations, the standard library log package in Go should
generally be used in logging contexts where humans are the primary audience of
the logs. For everyone else, it’s necessary to adopt one of the Go logging
packages discussed below:

1. Zerolog

Zerolog is a structured logging package for Go that boasts of a great
development experience and
impressive performance when compared to
alternative libraries. It offers a chaining API that allows you to specify the
type of each field added to a
log entry which helps with avoiding unnecessary allocations and reflection.
Zerolog only supports JSON or the lesser-known
Concise Binary Object Representation (CBOR) format, but it
also provides a way to prettify its output in development environments.

package main

import (
    "github.com/rs/zerolog/log"
)

func main() {
    log.Info().
        Str("name", "John").
        Int("age", 9).
        Msg("hello from zerolog")
}

{"level":"info","name":"John","age":9,"time":"2022-08-11T21:28:12+01:00","message":"hello from zerolog"}

You can import a pre-configured global logger (as shown above) or use
zerolog.New() to create a customizable logger instance. You can also create
child loggers with additional context which can come in handy for logging in
various packages or components in an application. Zerolog also helps you
adequately log errors by providing the ability to include a formatted stacktrace
through its integration with the popular errors
package. It also provides a set of
helper functions for
better integration with HTTP handlers.

2. Zap

Uber’s Zap library pioneered the
reflection-free, zero-allocation logging approach adopted by Zerolog. Still, it
also supports a more loosely typed API that can be used when ergonomics and
flexibility are the overriding concern when logging. This less verbose API
(zap.SugaredLogger) supports both structured and formatted string logs, while
the base zap.Logger type supports only structured logs in JSON format by
default. The good news is that you don’t have to pick one or the other
throughout your codebase. You can use both and convert between the two freely at
any time.

package main

import (
    "fmt"
    "time"

    "go.uber.org/zap"
)

func main() {
    // returns zap.Logger, a strongly typed logging API
    logger, _ := zap.NewProduction()

    start := time.Now()

    logger.Info("Hello from zap Logger",
        zap.String("name", "John"),
        zap.Int("age", 9),
        zap.String("email", "[email protected]"),
    )

    // convert zap.Logger to zap.SugaredLogger for a more flexible and loose API
    // that's still faster than most other structured logging implementations
    sugar := logger.Sugar()
    sugar.Warnf("something bad is about to happen")
    sugar.Errorw("something bad happened",
        "error", fmt.Errorf("oh no!"),
        "answer", 42,
    )

    // you can freely convert back to the base `zap.Logger` type at the boundaries
    // of performance-sensitive operations.
    logger = sugar.Desugar()
    logger.Warn("the operation took longer than expected",
        zap.Int64("time_taken_ms", time.Since(start).Milliseconds()),
    )
}

{"level":"info","ts":1660252436.0265622,"caller":"random/main.go:16","msg":"Hello from zap Logger","name":"John","age":9,"email":"[email protected]"}
{"level":"warn","ts":1660252436.0271666,"caller":"random/main.go:24","msg":"something bad is about to happen"}
{"level":"error","ts":1660252436.0275867,"caller":"random/main.go:25","msg":"something bad happened","error":"oh no!","answer":42,"stacktrace":"main.mainnt/home/ayo/dev/demo/random/main.go:25nruntime.mainnt/usr/local/go/src/runtime/proc.go:250"}
{"level":"warn","ts":1660252436.0280342,"caller":"random/main.go:33","msg":"the operation took longer than expected","time_taken_ms":1}

Unlike Zerolog, Zap does not provide a functioning global logger by default but
you can configure one yourself through its
ReplaceGlobals()
function. Another difference between the two is that Zap
does not support the TRACE log level
at the time of writing, which may be a deal-breaker for some. In Zap’s favor,
you can greatly customize its behavior by implementing the interfaces in the
Zapcore package. For example, you
can output your logs in a custom format (like
lgofmt), or transport them directly
to a log aggregation and monitoring service like
Logtail.

Honourable mentions

Logrus was the default structured logging
framework for Go for a long time until it was surpassed by the aforementioned
Zap and Zerolog. Its major advantage was that it was API compatible with the
standard library log package while providing structured, leveled logging in
JSON or other formats. It is
currently in maintenance mode so no new features will be added, but it will
continue to be maintained for security, bug fixes, and performance improvements
where possible.

Log15’s primary goal is to provide a
structured logging API that outputs logs in a human and machine readable format.
It uses the Logfmt format by default to aid this goal although this can easily
be changed to JSON. It also provides built-in support for logging to files,
Syslog, and the network, and it
is also quite extensible through its
Handler interface.

Apex/log is a structured logging framework
inspired by Logrus, but with a simplified API along with several
built-in handlers that help to facilitate log
centralization. At the time of writing, it has not been updated in two years so
we’re not sure if it’s still being maintained.

Logr is not a logging framework, but an
interface that aims to decouple the practice of structured logging in a Go
application from a particular implementation. This means you get to write all
your logging calls in terms of the APIs provided on the logr.Logger interface,
while the actual logging implementation (Zap, Zerolog, or something else) is
managed in one place to ease future migrations.

Final thoughts

The log package in the Go standard library provides a simple way to get
started with logging, but you will likely find that you need to reach out for a
third-party framework to solve many common logging concerns. Once you’ve settled
on a solution that works for your use case, you should consider supercharging
your logs by sending them to a
log management platform, where they can be
monitored and analyzed in-depth.

Thanks for reading, and happy logging!

Next article

→

Логирование программ Golang

Журнал пакетов стандартной библиотеки предоставляет базовую инфраструктуру для управления логами на языке GO. Основная цель ведения логов — отследить, что происходит в программе, где это происходит и когда это происходит. Логи могут обеспечивать отслеживание кода, профилирование и аналитику. Ведение журнала логирования( глаза и уши программиста) — это способ найти эти ошибки и узнать больше о том, как работает программа.

Для работы с журналом логов мы должны импортировать модуль Log:

import (
	"log"
)

В самом простом случае модуль Log формирует сообщения и отправляет их на стандартную проверку ошибок, как показано в следующем примере:

// Program in GO language to demonstrates how to use base log package.
package main
import (
	"log"		
)
func init(){
	log.SetPrefix("LOG: ")
	log.SetFlags(log.Ldate | log.Lmicroseconds | log.Llongfile)
	log.Println("init started")
}
func main() {
// Println writes to the standard logger.
	log.Println("main started")

// Fatalln is Println() followed by a call to os.Exit(1)
	log.Fatalln("fatal message")

// Panicln is Println() followed by a call to panic()
	log.Panicln("panic message")
}

После выполнения этого кода вывод будет выглядеть так:

LOG: 2017/06/25 14:49:41.989813 C:/golang/example38.go:11: init started
LOG: 2017/06/25 14:49:41.990813 C:/golang/example38.go:15: main started
LOG: 2017/06/25 14:49:41.990813 C:/golang/example38.go:18: fatal message
exit status 1

Стандартная запись логов содержит следующую информцию:
- префикс (log.SetPrefix("LOG: "))
- отметка даты и времени (log.Ldate)
- полный путь к файлу исходного кода записи в лог (log.Llongfile)
- строка кода

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

Println — это стандартный способ записи сообщений журнала.
Fatalln - библиотека выводит сообщение об ошибке, а затем вызывает os.Exit(1), заставляя программу завершить работу.
Panic — это встроенная функция, которая останавливает обычный поток управления и начинает паниковать. Когда функция F вызывает panic, выполнение F останавливается, все отложенные вызовы в F выполняются нормально, затем F возвращает управление вызывающей функции. Для вызывающей функции вызов F ведёт себя как вызов panic. Процесс продолжается вверх по стеку, пока все функции в текущей го-процедуре не завершат выполнение, после чего аварийно останавливается программа. Паника может быть вызвана прямым вызовом panic, а также вследствие ошибок времени выполнения, таких как доступ вне границ массива.

Программа на языке GO с реальным примером ведения журнала логов.
Теперь приведем пример из реального мира и реализуем вышеуказанный пакет log в своей программе.  Проверим, нормально ли работает SMTP-соединение. Для тестового примера я собираюсь подключиться к несуществующему SMTP-серверу smtp.smail.com, поэтому программа завершится с сообщением ошибки.

// Program in GO language with real world example of logging.
package main

import (
"log"
"net/smtp"
)
func init(){
	log.SetPrefix("TRACE: ")
	log.SetFlags(log.Ldate | log.Lmicroseconds | log.Llongfile)
	log.Println("init started")
}
func main() {
// Connect to the remote SMTP server.
client, err := smtp.Dial("smtp.smail.com:25")
	if err != nil {	
		log.Fatalln(err)
	}
client.Data()
}

Вывод:

TRACE: 2017/06/25 14:54:42.662011 C:/golang/example39.go:9: init started
TRACE: 2017/06/25 14:55:03.685213 C:/golang/example39.go:15: dial tcp 23.27.98.252:25: connectex: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond.
exit status 1

еще пример:

package main

import (
    "log"
    "os"
)

var (
    WarningLogger *log.Logger
    InfoLogger    *log.Logger
    ErrorLogger   *log.Logger
)

func init() {
    file, err := os.OpenFile("logs.txt", os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0666)
    if err != nil {
        log.Fatal(err)
    }

    InfoLogger = log.New(file, "INFO: ", log.Ldate|log.Ltime|log.Lshortfile)
    WarningLogger = log.New(file, "WARNING: ", log.Ldate|log.Ltime|log.Lshortfile)
    ErrorLogger = log.New(file, "ERROR: ", log.Ldate|log.Ltime|log.Lshortfile)
}

func main() {
    InfoLogger.Println("Starting the application...")
    InfoLogger.Println("Something noteworthy happened")
    WarningLogger.Println("There is something you should know about")
    ErrorLogger.Println("Something went wrong")
}

Просмотры: 1 353