Давайте поговорим о ведении логов

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

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


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

image

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.
Поделиться публикацией
AdBlock похитил этот баннер, но баннеры не зубы — отрастут

Подробнее
Реклама

Комментарии 59

    +1
    Кажется, автор забыл, что лог может читаться не только человеком, но и автоматическими системами. Которым важно знать, является ли очередное сообщение сообщением об ошибке или просто информационным.

    Да и человеку при просмотре логов слово ERROR или FATAL проще углядеть среди большого числа INFO.
      0
      Заметьте автор — Дейв Чини, достаточно опытный разработчик, много его пакетов используется большинством разработчиков, например, github.com/pkg/errors. Думаю, он имеет причины к такому подходу.

        0
        Фактически здесь на уровень логирования переноситься идея сборок Debug/Release. Строго говоря, он, вероятно, прав когда ставит под сомнения схему trace/debug/info/warn/error/fatal, как единственно возможную, но схема info/debug буквально требует второй уровень приоритетов.

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

        Вероятно, стоит задуматься над более гибкой схемой настройки уровней логирования.

        0
        И кстати тут автор не уточняет какова должна быть реализации, а вот некоторые разработчики пошли по его идеям. Автор github.com/go-log/log сделал интерфейс, как пишет Дейв.
        Конечно автор идет на пролом к идеальному, но по факту в реализации разработчики понимают эту идею, как намеренное сокращение интерфейса в угоду слабой связанности.
        Посмотрите на реализацию логера в Go Kit, описанную в данной презентации speakerdeck.com/chrishines/go-kit-log-package возможно это внесет больше ясности.
          –1
          Ну, в презентации Go Kit как раз есть пример логирования с уровнем Error. Только почему-то слишком многословный.
        +3
        Аналогично против warning, для меня это как «Ну вроде бы что-то не то, и так быть не должно, ну и ладно, продолжаем», имхо это здоровый такой толчок для появления сложно-отлавливаемых багов.

        Из примера сложно-отлавливаемых багов в той же Mysql:
        Если в поле занести данные, которые больше указанного типа, то эта субд выдаст warning, но проведет операцию заменив значение, на максимально допустимое (то есть, если поле имеет тип varchar(10), а попытаться впихнуть в него 11 символов, то последний символ он просто обрежет, но данные впихнет). Насколько я знаю, в других субд при подобном поведение будет ошибка.

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

          Думаю вам будет полезно прочитать статью

            0
            Спасибо, я привел пример из прошлого, когда впервые с этим столкнулся, после этого конечно, изучал вопрос более подробно
          0
          Товарищи, не забывайте — это перевод. Прошу вас минусы аргументировать, мне это важно, чтобы пронять как люди относятся к данной идее Дейва Чини (автор известного модуля github.com/pkg/errors).
            +2
            Оригинальная статья 2015 года, с тех пор даже авторы go lang успели переобуться и изменить своё отношение под давлением общественности к некоторым аспектам языка.
              0
              Но не к логированию, т.к. Go 2 еще не вышел — этот вопрос еще окончательно не решен.
              Вы бы согласились обменять синтаксический сахар различных логгеров на такой простой интерфейс ради слабой связанности?

              Понятно что программ из одного файла этот вопрос мало относится, речь идет о средних и крупных многокомпонентный системах.
                0
                Сам автор мнение свое не изменил, как видно по его dave.cheney.net/tag/logging.
                +1
                Одна серьезная проблема этого подхода состоит в том, что автор (ну и вы вслед за ним немножко) обобщаете свой (пусть даже и обширный) опыт проектов некоторых видов на проекты всех видов. Это как правило неверно. А так отчего же… всякий подход имеет право на жизнь.
                  0
                  Это так, вы верно подметили. Я думаю этот подход имеет место быть. Но когда знаешь, что проект будет сделан единожды или он простой и небольшой, то смысла во всех этих абстракциях нет, оно лишь отвлекает от дела.
                  Но на крупном проекте, я думаю, это окупит накладные расходы на этот подход.
                +2

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


                • info\debug — информационный уровень, который никто не читает, пока не произойдёт ошибка.
                • waring\error — это уже сигнал для системы мониторинга, что в программе что то идёт не так и вероятно нужна реакция от человека. Но в целом программа продолжает работать.
                • fatal — это уже пожарная сигнализация, программа столкнулась с ошибкой, на которую не предусмотрена обработка.
                  0
                  Когда вся программа накрылась, код возврата говорит лишь о том, что случилась ошибка, причину ошибки логично поместить в лог с уровнем fatal.

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


                  Лично мне больше нравится подход logr и go-kit-log, там тоже есть интерфейс логгера сильно ограниченный. В logr есть вывод с уровнем важности, V(verboseLevel int), чем больше verboseLevel тем ниже важность сообщения и больше сообщений у вас в логе.
                  В go-kit-log никто не запрещает вам указывать название уровней для записи журнала, но вы это передаете как параметр вызова.
                  Интерфейс тут такой:
                  type Logger interface {
                  	Log(keyvals ...interface{}) error
                  }
                  

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


                    И мы будем вручную формировать шаблон сообщения лога, вместо того, что бы это сделать через логгер? Крайне странная позиция.
                +4

                В целом, как обычно, ребята из go приходят к тому, что надо навелосипедить с нуля, что бы оно было еще хуже, зато свое.


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

                А вы вообще, пишите, ну не знаю, веб сервисы например? Или автор из тех, кто любит возвращать ответ 200 и в теле "что-то пошло не так", что бы программисты потом часами пытались узнать "а что именно пошло не так", ведь никакой больше инфы нет.


                Ну и да. Даже если вы обработали ошибку в духе "файла нет и потому я верну пустую строку вместо содержимого", вывести это тоже, не нужно, разумеется. Что бы программист гадал, что это за веселый баг, когда возвращется пустая строка.


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

                Ну, может автор и не читает, а вот я читаю. Там бывает полезная инфа, например, про performance проблемы. В том же odoo, например, сообщения в духе "вы сравниваете несравнимое", которые появляются при сравнении рекордсетов и списков интов (не смотря на то, что это таки работает) позволяют делать код чище.

                  +2

                  Помимо наличия уровней логирования при вызове логера есть еще и уровень у самого логера выставляя который мы пропускаем запись всего что ниже. Это позволяет нам иметь разную детализацию логов на разном окружении. Я хочу видеть Debug при разработке локально, но не хочу на стейдж сервере (или открытой бетте). Я хочу видеть Warning на стейдж сервере, но на продакшене не хочу. А помимо этого логгеров может быть не один (stdout и sentry например), вызываемые по цепочке, и я хочу там разный уровень логирования. Именно по этому и нужны уровни Warning И Critical (Fatal). Больше уровней — больше пространства для маневра.
                  Ах да, и эти уровни это стандарт дефакто, на большинстве систем и языков они есть. Снова кто то из го разрабов хочет быть не таким как все...

                    0
                    С уровнями тут кстати все в порядке. Т.к. интерфейс это абстракция, то автор и не говорит о деталях реализации.
                    Я это понял также как разработчик и logr — он сделал Info и Error, и немного ушел от идей Дейва, объяснил он это так:
                    Info логи это то что вы хотите показать пользователю, и что не является ошибкой. А ошибки, то ошибки. Если ваш код получил ошибку из подфункуции записывает эту ошибку в лог и не возвращает ее вызвавшему — используйте error логи.
                    0
                    Очень странная тема, интересно а автор понимает что логирование != обработка ошибки. Логирование нужно для того чтобы дать пользователю информацию о том, что тот скормил что-то не то. И как правильно написали выше, уровни также важны чтобы не захламлять весь лог.
                      0
                      Автор разработчик одного из наипопулярнейших пакетов для работы с ошибками github.com/pkg/errors
                      Судить о его понимании можно по его работам на github.
                        +4

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


                        Собственно в том числе после прочтения этой статьи несколько лет назад, я в своих проектах начал использовать самописную обёртку над стандартным пакетом log, в которой уровни выше info отключить нельзя, но и error не исключён.

                          +2
                          Вот оригинальный текст автора:
                          The act of logging an error handles the error, hence it is no longer appropriate to log it as an error.

                          Судя по этому, да, автор считает что логирование в ERROR уровне = факту обработки этой ошибки. Думаю многие склоны с ним не согласиться.
                            –2
                            Если ошибка записана в лог, а после этого не произведено действий по ее исправлению — значит это и есть обработка ошибки. Ведь если мы более ничего с ней не делаем, значит нам этого достаточно, а сам факт такой обработки ошибки означает, как мне кажется, что действия по ее исправлению должны ложиться не на программу (на другую систему или на пользователя).
                            Как думаете? Интересно этот момент обсудить.
                              0

                              Если представить себе ситуацию, в которой возникшая на низком уровне ошибка прошла несколько if err != nil { return err } до высокого уровня, на котором её изучили, и решили что она не мешает работе системы и не нуждается в какой-либо обработке, но её стоит записать в лог на всякий случай — то Dave прав, её не нужно логировать с уровнем Error, обычно используют Warning или даже Debug (если такие ошибки случаются слишком часто и засирают лог), а если их нет то сойдёт и Info.


                              Проблема в том, что такая ситуация является скорее исключением, нежели правилом, и в большинстве случаев логирование ошибки не эквивалентно её обработке. Действия по исправлению ошибки тоже встречаются не так часто, как хотелось бы — частично потому, что это сильно усложнит код и экономически не оправдано в большинстве случаев, частично потому, что многие ошибки никак исправить нельзя в принципе. Чаще всего обработкой ошибки является возврат этой ошибки выше, причём не только в рамках одного приложения, но и между приложениями — ядро ОС возвращает ошибку веб-сервису, веб-сервис возвращает HTTP-ошибку в браузер, браузер возвращает её юзеру, и фактической обработкой ошибки занимается юзер. Но в рамках веб-сервиса обработкой ошибки является возврат HTTP-ошибки отправившему запрос клиенту, а вовсе не логирование.

                                –2
                                Вы логируете ошибку, если отправляете ее в ответе на запрос? Мне кажется нет, тут как раз пользователь решает, как ее обработать, а не код программы.
                                Что тогда ошибка, которую не показывают пользователю, но пишут в лог?
                                  +2

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


                                  Что тогда ошибка, которую не показывают пользователю, но пишут в лог?

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

                                    –1
                                    Т.е. есть разделение на публичные ошибки и приватные так сказать?
                                    Я такое видел Gin-gonic, там автор предлагает пользователю отдавать ошибки помеченные как публичные, а приватные нет.
                                    В вашем примере получается как бы «неважная ошибка», не та «важная», которую пользователю показать бы.
                                    В логе их по смыслу только отличать получается можно, т.е. они все будут ERROR.
                                    Мне кажется такая «неважная ошибка» должна быть вовсе не ошибка, a DEBUG сообщение, или Info, в котором видно прогресс операции, т.к. выходит для цельной операции это как бы не сбой, а нормальная ситуация, которую код обрабатывает. А если после 5 попыток не удалось, тогда это реально сбой операции и об этом нужно пользователя уведомить.
                                      +2

                                      Уровень логирования выбирается не из каких-то высших философских соображений, а чисто из практичности:


                                      • Error выделен отдельно потому, что это почти всегда ошибка полученная пользователем, т.е. сбой нашего сервиса который помешал работе юзера. (Хуже только креш из-за паники.) В идеале их в логе быть вообще не должно.
                                      • Warning выделен потому, что произошла ошибка, которой, зачастую, не должно было быть. Сервис с ней справился сам, юзеры не пострадали, но когда у команды есть немного свободного времени стоит исследовать причины Warning-ов в логе и, возможно, поправить код чтобы часть из них пофиксить.
                                      • Info выделен потому, что сервис работает в фоне, и хочется знать, чем он там сейчас занят, какие задачи выполняет. В идеале в логе кроме Info больше ничего не должно быть. Но в реальной жизни Info очень помогает расследовать причины Warning и Error.
                                      • Debug выделен потому, что таких сообщений обычно во много (десятки) раз больше, чем Info, они содержат слишком низкоуровневые подробности происходящего, и на проде (т.е. на достаточно стабильной версии) не несут никакой ценности, зато заметно вредят во-первых замусориванием лога, и во-вторых тормозами из-за высокого рейта записи в лог.

                                      Иными словами при чтении лога у нас бывают разные задачи. Когда нужно решить проблему юзера мы ищем Error. Когда хочется оптимизировать или исследовать странное поведение мы ищем Warning. Когда нужно отлаживаться мы включаем Debug. А в Info попадает всё остальное, главное, чтобы этих записей было не слишком много (лог станет нечитабельным, для этого есть Debug), но и не слишком мало (лог станет бесполезным).

                                0
                                Как уведомлять разработчика программы, о том что произошла ошибка? Разработчик другой системы, получив респанс с ошибкой, должен писать в суппорт вашей программы? Или все таки само приложение должно залогировать ошибку(в файл, базу, сентри или что-нибудь похожее), а разработчик, получив уведомление от какой-либо системы мониторинга, должен сесть и разбираться с ним?

                                Кроме того, рассматривать сообщение об ошибке в отрыве от логов других уровней может быть очень неудобным, т.к. прийдется по таймпшампу\id сессии или реквеста узнавать что именно приложение делало в определенный момент времени и строить теории относительно того, на каком именно этапе произошла ошибка. Сохранить всю эту информацию в самой ошибке может быть невозможным в силу особенностей алгоритма\архитектуры\неожиданностью появления конкретно этой ошибки.
                                  –1
                                  Как вы разделяете, о какой ошибке нужно уведомлять разработчика, а о какой пользователя, или того и другого?
                                  Получается одна ошибка — для пользователя должна сообщить, что не так, а пользователь решит как исправить. Вторая, мне кажется, должна зваться «необработанная ошибка», т.к. эта ситуация, которую программист не обрабатывал (тут должен быть стек скорее всего).
                                  Что тогда третий тип ошибок?
                                    0
                                    По поводу первого типа: почему мы не должны сохранять у себя информацию о том, что от клиента пришел запрос с невалидными параметрами, о чем он был соответствующим образом уведомлен? Я вижу только один случай, при котором такой подход может быть оправдан: клиентский сервис — это какой-то из ваших микросервисов и он сам залоггирует ошибку, полученную от другого сервиса. В противном случае логгирование и мониторинг подобных ошибок как минимум понадобится при коммуникации с командой разработчиков другого сервиса.

                                    По поводу второго типа: в каких случаях мы не должны уведомлять клиента о «необработанных ошибках», хотя бы теми же кодами http-статусов?
                                      0
                                      Второй случай — это как исключение, которое отловил обработчик ошибок высшего уровня и выдал пользователю 500 Ошибка обслуживания, а для разработчика записал в лог подробности (стек).
                                      Мы уведомляем клиента о всех сбоях в операциях, которые не удалось восстановить программе без помощи клиента и нужно его действие.
                                        0
                                        Т.е. ошибка так или иначе возвращается клиенту. Получается, что первый и второй случаи с точки зрения клиента отличаются лишь подробностью описания ошибки, а с точки зрения сервиса — уровнем логирования ошибки: в первом случае WARN — потому что система сама предотвратила некорректное поведение программы, отвалидировав входящие параметры; во втором случае — ERROR, потому что несмотря на наши усилия некорректное поведение все таки произошло.
                                        Но в обоих случаях способ обработки ошибки один и тот же — возврат этой самой ошибки клиенту, для того чтобы он самостоятельно обработал ее на своей стороне (сделал ретрай\поправил код\написал вашему суппорту). И это противоречит вашему утверждению, что запись в лог является обработкой ошибки.

                                          0
                                          «запись в лог является обработкой ошибки» — это утверждение, автора

                                          Меня как раз интересовало, что думает по этому поводу читатель, т.к. у меня однозначного отношения к этому утверждению не сложилось.
                                            0
                                            Спасибо за ваши пояснения, это помогло мне немного привести все к общему знаменателю.
                                    +3
                                    По такой логике и пустой catch в других языках — это обработка ошибки. Только вот регистрация факта ошибки и ее обработка — не одно и то же. Обработка ошибки это код, который делает так, словно ошибки не было, либо признает что это невозможно и завершает работу.
                              +3
                              Если вы решите обработать ошибку, записав ее в лог, то по определению это больше уже не ошибка — вы ее обработали.

                              Хорошее утверждение. Можно пойти дальше и сказать, что если я решил обработать ошибку, проигнорировав её, то по определению это больше уже не ошибка — я её обработал.


                              Короче, ошибок не существует.

                                0
                                Спасибо за вашу точку зрения.
                                +2

                                Debug, Info, Warning и Error — необходимы и достаточны. Больше не нужно по описанным в статье соображениям, но и меньше тоже не подходит:


                                • Debug нужен для вывода сообщений, которых либо очень много и которые замусоривают логи, либо для вывода сообщений с большим количеством мелких деталей (а-ля дампы структур). Такие сообщения нужны при отладке, удалять их все из кода при релизе не лучшая идея, но и выводить их на проде тоже не лучшая идея (хотя возможность включить их вывод на проде изредка очень помогает).
                                • Info нужен для того, что описано в статье. Таких сообщений не должно быть очень много, и они должны информировать о том, что происходит в системе при штатной работе.
                                • Warning нужен для ситуаций, когда вызванная функция/пакет могут самостоятельно обработать обнаруженную ошибку и всё-таки сделать то, зачем их вызвали. Это может быть автоматический повтор сетевого запроса, могут быть обнаруженные проблемы производительности, etc. Если вместо Warning использовать Error, то это затруднит различение реальных ошибок, с которыми надо что-то делать, или которые являются причиной других проблем, от мелких/потенциальных проблем, с которыми система справилась самостоятельно, и изучать которые полезно скорее для более полного понимания происходящего или поиска узких мест для оптимизации системы. Если вместо Warning использовать Info, то информация о мелких/потенциальных проблемах просто потеряется в большой массе сообщений о штатном поведении системы.
                                • Error нужен для ситуаций, когда вызванная функция/пакет не может сделать то, зачем её вызвали. Для неё это — критическая ошибка, но для вызывающего её кода — эта ошибка вполне может быть штатной ситуацией, недостойной даже уровня Warning. Тем не менее, такие ситуации необходимо логировать там, где они изначально произошли, и именно как Error — потому что только на этом уровне есть все необходимые низкоуровневые детали возникшей ошибки. (В качестве альтернативы логированию как Error в месте возникновения можно "завернуть" все эти детали в саму ошибку так, чтобы их можно было отлогировать не менее подробно в вызывающем коде — но у этого подхода есть свои недостатки.)

                                Помимо необходимости в 4-х уровнях и возможности отключать как минимум Debug и Info, библиотеке для логирования нужны ещё некоторые фичи:


                                • возможность выводить как текст (для мелких проектов) так и структурированные данные в json (для крупных проектов)
                                • возможность автоматически добавлять контекст (какая строка/функция/пакет выдала это сообщение, в контексте обработки какого запроса и какого юзера произошла эта ситуация)

                                И я не согласен с идеей статьи о том, что логирование ошибки является её обработкой.


                                Я всегда двумя руками за минимализм, но стандартная библиотека логирования и описанное в статье нарушают "но не проще" из принципа "Всё должно быть изложено так просто, как только возможно, но не проще.". Ну и помимо минимализма ещё должно быть удобно, например иметь возможность лениво логировать ошибку в defer v.Close()… поэтому я написал structlog.

                                  0
                                  Я бы всё-таки не выкидывал уровень Fatal. Если Error означает ситуацию, когда компонент не может выполнить запрошенное действие — то Fatal является ситуацией, когда компонент не может продолжать работу.
                                    +1

                                    Проблема с Fatal в том, что критичная ошибка в любом модуле приложения (как нашем, так и сторонней библиотеке) не всегда является критичной для приложения в целом — это зависит от природы приложения, которую отдельные модули заранее знать физически не могут. Плюс Fatal сильно усложняет написание юнит-тестов. Поэтому крайне нежелательно, чтобы код вызывающий os.Exit находился в каких-либо модулях, он должен быть только в main(). А на крайний случай, когда Fatal нужен любой ценой — можно написать os.Exit на следующей строке после вызова log.Error.

                                      +4
                                      Я не специалист в Go, но мне кажется странной идея, что операция логирования имеет право завершать программу.
                                        –1
                                        А при чём тут os.Exit? Откуда вообще взялась идея о том, что уровень Fatal должен обрабатываться библиотекой логирования как-то по-особенному? Это такой же уровень как и Error, только называется Fatal.
                                          +1

                                          Идея взялась из поведения одноимённой функции стандартной библиотеки. Но раз Вы не имели в виду os.Exit, тогда можно более конкретный пример, "когда компонент не может продолжать работу", но при этом необходимости завершить всё приложение нет?

                                            0
                                            Ну, один из вариантов вы назвали сами — тесты.

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

                                            Третий вариант — можно попытаться возобновить работу компонента спустя некоторое время.
                                              0

                                              Каким боком тесты могут быть компонентом, который во-первых используется при штатной работе приложения, и во-вторых ещё и внезапно может выйти из строя?


                                              Если компонент сломался временно, и его можно продолжить использовать позднее, то это, по Вашему же определению, Error, а не Fatal. Поэтому, ещё раз — можете привести пример конкретного функционала в известном Вам реальном проекте, где может произойти и Error, и Fatal, и их важно различать между собой, но при этом Fatal не приводит к остановке всего приложения?

                                                –1
                                                Тесты тут таким боком, что там тот же самый код исполняется, что и в реальном приложении.
                                                  0
                                                  Да, вот придумал вам пример. Программа может следить за изменениями в своём конфиге и пытаться перезапустить свои компоненты обнаружив эти самые изменения.
                                                    +1

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


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

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

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


                                                        Почему она не может просто работать, во всех случаях, включая самые экзотические?

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


                                                        Например, Вам захотелось добавить один уровень выше Error — Fatal. А разработчикам syslog захотелось добавить три таких: Crit, Alert и Emerg. И я не уверен, что Ваш Fatal по своей сути идентичен одному из этих трёх, и какому конкретно. Предположим, мы добавим их все, чтобы не "решать как должна вести себя программа". Ну и заодно ещё Notice из syslog-овских, вдруг он тоже кому-то нужен, кто понимает в чём разница между Warning, Notice и Info. В результате у нас получится 10 уровней, на которых программа может сообщить о происходящем в лог:


                                                        1. паника
                                                        2. Emerg
                                                        3. Fatal
                                                        4. Alert
                                                        5. Crit
                                                        6. Error
                                                        7. Warning
                                                        8. Notice
                                                        9. Info
                                                        10. Debug

                                                        Стало ли проще и понятнее пользоваться такой библиотекой? Нет. Почему? Потому, что всё должно быть насколько просто, насколько возможно, но не проще.


                                                        Для сетевого сервиса (типичного приложения на Go) 4 уровня логирования (плюс ещё паника) дают более чем достаточно гибкости, и при этом не превращают выбор правильного уровня для текущей строчки кода в интеллектуальную загадку с несколькими приемлемыми вариантами ответа. Хотя, скажу честно, даже с 4-мя я изредка не уверен, что правильнее использовать в текущей строчке — Warning или Debug.

                                      –2
                                      Мне кажется термин «ошибка» слишком широко трактуется, следует разделять error/bug.

                                      Разработчики допускают ошибки(bugs) при написании кода и в программе затаивается дефект. И даже если дефект не нашли и о нем никто не знает, он все равно есть! Сидит и ждет своего часа. И когда пользователь натыкается на ошибочный код, происходит сбой(error).

                                      testbase.ru/235

                                      Мы сообщаем пользователю о чем? О сбое. Сбой может быть восстановимым или фатальным.

                                      При восстановимом сбое, пользователь например получит сообщение «Устройство не отвечает на запрос», пользователь сам решает, что он будет делать при этом сбое.

                                      Стоит ли это писать в лог? Ведь это нормальное поведение программы, этот сбой обрабатывается, пользователь видит сообщение на экране.
                                      Я считаю, в лог тут эту ошибку нужно писать через Debug, и в продакшн их быть не должно, при отладке, да они должны быть. Пользуясь структурированным логгировнием, я бы записал «type=ProcessFlowError processFlow=DeviceConnect и сообщение».
                                      Как это записать в лог — решение разработчика. Кто-то может запишет как уровень Info, а кто-то Warn, а кто-то Error. Это уже детали реализации.

                                      О фатальном сбое нам сообщает вылет/неожиданное завершение работы программы. Мы увидим или сообщение в консоли, или в логе «Неожиданное завершение программы: <тут стек>»
                                        +1

                                        Ошибки бывают самые разные, и они далеко не всегда связаны с дефектами в коде. Например, любое сетевое соединение может вернуть ошибку по не зависящим от нас причинам, место на диске может кончиться в любой момент, как и доступная память, на вход нашей программе могут поступить некорректные данные, etc. Любую такую фигню надо логировать, вне зависимости от того, показали мы ошибку юзеру или нет — потому что такой лог позволит позднее проанализировать произошедшее и понять как (и надо ли вообще) чинить приложение. Для такого анализа в логе полезно видеть всё, что происходило, как нормальное поведение, так и аномальное — и не менее полезно если лог использует разные уровни (Debug/Info/Warning/Error) чтобы его было легче и быстрее анализировать.

                                          0
                                          Да мы вставляем этот код для логированния, но все равно мы не всегда пишем лог с уровнем DEBUG. Т.е. обычно для приложений, чтобы логи не раздувались лог ведется на уровне ERROR и при возникновении подозрения на ошибку пользователь выставляет лог на DEBUG и пытается повторить ошибку, после чего разработчик по потоку событий пытается понять, что произошло и почему. Конечно так не всегда, в некоторых приложениях обязательно каждый чих знать.

                                          Короче я прихожу к выводу, что общеподходящего решения нет. Как сказал мне мой друг «У нас на проекте 5 разных реализаций логгеров, т.к. приходили разные разработчики и каждому нужно было что-то свое».

                                          Где-то хватит и Debug, Info для приложения. А где-то нужно вести структурированные логи, где уровни могут быль лишь мелкой деталью.
                                            +1

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


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

                                              0
                                              Мне ваше точка зрения понятна. Спасибо за пояснения.

                                      Только полноправные пользователи могут оставлять комментарии. Войдите, пожалуйста.

                                      Самое читаемое