Этот пост вдохновлен темой в форуме 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.

Комментарии (47)


  1. mayorovp
    14.02.2019 09:32
    +1

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

    Да и человеку при просмотре логов слово ERROR или FATAL проще углядеть среди большого числа INFO.


    1. r3code Автор
      14.02.2019 09:45
      -1

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


      1. netricks
        14.02.2019 11:45

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

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

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


    1. r3code Автор
      14.02.2019 09:49

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


      1. mayorovp
        14.02.2019 09:53

        Ну, в презентации Go Kit как раз есть пример логирования с уровнем Error. Только почему-то слишком многословный.


  1. peresada
    14.02.2019 09:33
    +2

    Аналогично против warning, для меня это как «Ну вроде бы что-то не то, и так быть не должно, ну и ладно, продолжаем», имхо это здоровый такой толчок для появления сложно-отлавливаемых багов.

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

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


    1. bores
      14.02.2019 10:41

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


      1. peresada
        14.02.2019 11:11

        Спасибо, я привел пример из прошлого, когда впервые с этим столкнулся, после этого конечно, изучал вопрос более подробно


  1. r3code Автор
    14.02.2019 09:38
    -2

    Товарищи, не забывайте — это перевод. Прошу вас минусы аргументировать, мне это важно, чтобы пронять как люди относятся к данной идее Дейва Чини (автор известного модуля github.com/pkg/errors).


    1. ZurgInq
      14.02.2019 09:50
      +2

      Оригинальная статья 2015 года, с тех пор даже авторы go lang успели переобуться и изменить своё отношение под давлением общественности к некоторым аспектам языка.


      1. r3code Автор
        14.02.2019 10:01

        Но не к логированию, т.к. Go 2 еще не вышел — этот вопрос еще окончательно не решен.
        Вы бы согласились обменять синтаксический сахар различных логгеров на такой простой интерфейс ради слабой связанности?

        Понятно что программ из одного файла этот вопрос мало относится, речь идет о средних и крупных многокомпонентный системах.


      1. r3code Автор
        14.02.2019 10:09

        Сам автор мнение свое не изменил, как видно по его dave.cheney.net/tag/logging.


    1. sshikov
      14.02.2019 11:15
      +1

      Одна серьезная проблема этого подхода состоит в том, что автор (ну и вы вслед за ним немножко) обобщаете свой (пусть даже и обширный) опыт проектов некоторых видов на проекты всех видов. Это как правило неверно. А так отчего же… всякий подход имеет право на жизнь.


      1. r3code Автор
        14.02.2019 16:37

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


  1. ZurgInq
    14.02.2019 09:45
    +2

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


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


    1. r3code Автор
      14.02.2019 09:58

      Когда вся программа накрылась, код возврата говорит лишь о том, что случилась ошибка, причину ошибки логично поместить в лог с уровнем 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. ZurgInq
        14.02.2019 10:11

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


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


        1. r3code Автор
          14.02.2019 10:17

          Иначе. Все вызовы из разных библиотек и компонентов систем становятся примерно одинаковыми, а как представить запись решает реализация.
          См. пример speakerdeck.com/chrishines/go-kit-log-package?slide=18
          Пример вывода в разных форматах speakerdeck.com/chrishines/go-kit-log-package?slide=20


  1. SirEdvin
    14.02.2019 10:37

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


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

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


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


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

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


  1. ellrion
    14.02.2019 10:41

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


    1. r3code Автор
      14.02.2019 16:48

      С уровнями тут кстати все в порядке. Т.к. интерфейс это абстракция, то автор и не говорит о деталях реализации.
      Я это понял также как разработчик и logr — он сделал Info и Error, и немного ушел от идей Дейва, объяснил он это так:

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


  1. Chaos_Optima
    14.02.2019 14:39

    Очень странная тема, интересно а автор понимает что логирование != обработка ошибки. Логирование нужно для того чтобы дать пользователю информацию о том, что тот скормил что-то не то. И как правильно написали выше, уровни также важны чтобы не захламлять весь лог.


    1. r3code Автор
      14.02.2019 16:41

      Автор разработчик одного из наипопулярнейших пакетов для работы с ошибками github.com/pkg/errors
      Судить о его понимании можно по его работам на github.


      1. gudvinr
        14.02.2019 20:46
        +2

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


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


      1. PrinceKorwin
        15.02.2019 09:11

        Вот оригинальный текст автора:

        The act of logging an error handles the error, hence it is no longer appropriate to log it as an error.

        Судя по этому, да, автор считает что логирование в ERROR уровне = факту обработки этой ошибки. Думаю многие склоны с ним не согласиться.


        1. r3code Автор
          15.02.2019 09:18

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


          1. powerman
            15.02.2019 14:50

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


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


            1. r3code Автор
              15.02.2019 16:02

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


              1. powerman
                15.02.2019 17:19

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


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

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


          1. Bce_npocTo
            15.02.2019 16:02

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

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


            1. r3code Автор
              15.02.2019 16:07

              Как вы разделяете, о какой ошибке нужно уведомлять разработчика, а о какой пользователя, или того и другого?
              Получается одна ошибка — для пользователя должна сообщить, что не так, а пользователь решит как исправить. Вторая, мне кажется, должна зваться «необработанная ошибка», т.к. эта ситуация, которую программист не обрабатывал (тут должен быть стек скорее всего).
              Что тогда третий тип ошибок?


              1. Bce_npocTo
                15.02.2019 20:45

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

                По поводу второго типа: в каких случаях мы не должны уведомлять клиента о «необработанных ошибках», хотя бы теми же кодами http-статусов?


          1. playermet
            15.02.2019 20:10

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


  1. 0xd34df00d
    14.02.2019 17:17
    +2

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

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


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


  1. powerman
    14.02.2019 17:31
    +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.


    1. mayorovp
      14.02.2019 17:56

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


      1. powerman
        14.02.2019 18:21
        +1

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


        1. ainoneko
          14.02.2019 18:53
          +3

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


        1. mayorovp
          14.02.2019 19:33

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


          1. powerman
            14.02.2019 19:40

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


            1. mayorovp
              14.02.2019 20:28

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

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

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


              1. powerman
                14.02.2019 21:45

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


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


                1. mayorovp
                  14.02.2019 22:51
                  -1

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


                1. mayorovp
                  15.02.2019 06:30

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


                  1. powerman
                    15.02.2019 14:57
                    +1

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


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


  1. r3code Автор
    15.02.2019 17:03

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

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

    testbase.ru/235

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

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

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

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


    1. powerman
      15.02.2019 17:27

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