Комментарии 47
перевод ужасный.
автор несет чушь.
Чтобы было ясно, я не говорю, что вы не должны обрабатывать возникновение условия.
как минимум существует класс ошибок, которые не информация, а именно ошибки, но т.к. они наведены внешними факторами, то устранению не подлежат. Например, ошибки пользователя. И очень хочется иметь возможность их увидеть и увидеть по возможности их первопричину. С другой стороны, для этого могут лучше подойти не средства логирования, а средства трассировок - но автор этот момент вообще обходит стороной, поэтому изначальная статья однобока.
Мое мнение - я счастлив, что во многих системах есть возможность детализации уровня логов. Это позволяет проводить более эффективно отладку и расследование инцидентов. И отбирать этот инструмент... ну, такое себе решение
Статья 2015 года. Лог до сих пор интерфейса не имеет то. Не помню чтобы даже proposal был.
Есть https://github.com/golang/go/issues/13182 Вроде бы руководство не против, но очевидная проблема, которую эта статья и затрагивает - нет консенсуса о функционале этого интерфейса. Если его добавлять, то это окажет сильный эффект на экосистему и многие начнут подстраиваться под него. Люди хотят уровни, разные варианты вывода, структурированный логгинг, минимум аллокаций и т.д. и т.п. Я так понимаю JUL в мире Java как раз стал жертвой этой проблемы. Люди пытались стандартизировать логирование, но в итоге его никто не использует по куче разных причин.
Давненько тоже читал этот пост и тоже с ним не согласен. С одной стороны, количество уровней во многих библиотеках действительно зашкаливает. Мне вот очень нравится zerolog и в нем 7 уровней логирования. Это ну совсем избыточно. С другой, если оставить только info и debug, то непонятно как вообще это парсить.
А что за сложности с парсингом?
Например, уровни логирования позволяют настроить простейший алертинг. Если приложение написано нормально, то error уровень означает что-то, что требует внимания. Если все логируется с уровнем info, то непонятно, как оттуда вытаскивать что-то полезное. Читать эту стену текста никто не будет. Парсить - заранее не знаешь, какого формата сообщение возникнет, если это не твое приложение. Вот и получится, читать это все только постфактум, когда уже все сломалось.
То есть вам нужны не "уровни логирования", а флаг "требует реагирования". То есть и "не ответили вовремя", и "упали при ответе", и "заканчивается квота" и "вам перевели особо крупную сумму" - все тоебуют реагирования, хотя обычно относятся к совершено разным уровням.
Мне достаточно двух уровней логирования - ошибка и все остальное. Первое привлечет мое внимание. Второе будет являться контекстом для расследования причин первого. Если прямо хочется, то можно добавить debug, который повысит детализацию второго. Хотя это скорее verbosity, чем дополнительный уровень.
Я ниже описал мое мнение про warn - это не более чем еще один вариант info. Он не содержит полезной и важной информации, на практике высирается стабильно и много. Тоже самое с разделением error, fatal, critical - это все ошибки. Разделение на кучу уровней не делает их полезнее, зато вносит непонятную путаницу.
В чём избыточность 7 уровней логирования?
В моей практике я не нашел большинству из них применения. Я пользуюсь только info, error и fatal уровнями. Debug как-то пробовал, но оказалось, что очень сильно мусорит код, а толку для отладки все равно мало. Зачем в библиотеке одновременно trace и debug мне непонятно - пул реквест не содержит нормальных аргументов https://github.com/rs/zerolog/pull/158 Зачем нужен warn тоже непонятно - это либо какая-то ошибка, которую код обработал, то юзеру на нее надо посмотреть, либо это информационное сообщение, которое вроде бы важное, а вроде не говорит о том, что что-то плохо работает. Если это первое, то для этого есть error. Если второе, то, опять же, никто это читать не будет. Частенько warn сообщения летят постоянно даже при нормальной работе, что нивелирует их ценность.
Собственно, поэтому слишком много уровней это плохо. Непонятно что использовать, сложно разработать лучшие практики, которым все следуют. В итоге получается, что пользуются большинство одним двумя уровнями, но работать с этим все равно не удобно, потому что кто-то однозначно захочет использовать все 7 уровней. Лучше меньше, но с пользой.
Я пользуюсь, как минимум, 7. Удобно включать совсем детальное логирование(CONSOLEMIN/MAX/DETAILED), когда нужно глянуть чуть ли не каждый пакет данных, приходящих в систему. Плюс в релизных билдах ограничивается уровнем INFO, SERVICE, WARN, ERROR. INFO показывает примерный flow логики. FATAL автоматически в ассертах перед "смертью" процесса пишется.
Как в сложной системе можно обойтись одним уровнем INFO для рабочего логирования мне непонятно.
Умение и правила записи в лог не менее важны и должны соблюдаться, чем другие аспекты разработки.
Я бы сказал логи в сложной системе имеют сомнительную ценность. Метрики - вот главный инструмент диагностики сегодня. Весь алертинг делается именно здесь в нормальных сложных системах. Дальше идет трейсинг - это как бы логи, но намного мощнее, т.к. содержат контекст. А вот уже потом в самом конце логи, которые обычно складываются в систему индексирования и забываются. Авось когда-нибудь понадобится.
Умение и правила записи в лог не менее важны и должны соблюдаться, чем другие аспекты разработки.
Это замечательно, но правил и лучших практик нет. Можно найти десять блог постов о логировании и там будет десять разных мнений, как это нужно правильно делать.
Логирование это более локальный, но зато, потенциально, более полный вариант трассировки. Но если у вас программка которая крутится локально и общается с внешним миром через stdout и stderr, она не может и не должна посылать трассировки на специальный сервер. Тут работает логирование. С другой стороны, обычно можно позволить логировать гораздо больше событий/запросов на локальный диск (часто -- все), чем посылать трассировок на сервер. В системах, где индивидуальные события важны (финансы, е-коммерс, и т. д.) это может быть необходимостью.
Логирование это более локальный, но зато, потенциально, более полный вариант трассировки
Это сейчас такая шутка была? Сейчас во время контейнеров и микросервисов логирование отражает поток выполнения только лишь единого сервиса. А разработчику или devops'у нужен весь стек вызовов между всеми сервисами, участвующими в обработке запроса пользователя. Логирование "починить" можно тем, чтобы сваливать все логи в единую систему и придумать какой-то request id или user Id корелляцию. Ой, мы только что изобрели трейсинг на коленке и лучше бы взяли что-то готовое и уже стандартное (jaeger? Opentracing?)
В системах, где индивидуальные события важны (финансы, е-коммерс, и т. д.) это может быть необходимостью.
Не лукавьте. Это не логи. А события. Это очень большая разница. Логи Вы можете потерять. А события нет. И в случае финансов, е-Коммерс и прочего - если событие не может быть зафиксировано, пользователю будет возвращена ошибка и будет предложено повторить операцию. А в случае логов... нет. Я уж не говорю о том, что схема доставки логов, которая будет надежная и производительная, запросто по цене может превысить стоимость самого решения, которое мы хотим залогировать. Весь вопрос в количестве данных. Логов всегда много )))
Безусловно, когда речь об обычной программке, то там конечно некуда трейсы посылать. Собственно, там некуда наверное и метрики посылать. Но это уже сложно квалифицировать "сложной системой". Последнее в моем понимании это распределенная система, где логи локальны для конкретного сервиса и его экземпляра, что существенно снижает их ценность. Там правят метрики.
Я бы не сказал, что логи более полный вариант трассировки. Если, опять же, речь о сложной системе, то логируются сразу кучи компонентов независимо друг от друга. Да, информации много, но она не коррелирует между собой кроме как по времени. Трассировка это в первую очередь контекст. В этом плане она кратно повышает эффективность против обычных логов.
Варнинги позваляют отличать сообщения, накоторые должен реагировать владелец кода (ошибка), от сообщений, на которые должен/может реагировать его пользователь (нештатная ситуация).
На практике оно так не работает. warn сыпет бесполезной информацией. Частенько о том, что что-то где-то не выключено, не настроено. Как упомянутый esxi - зачем мне warn, что у меня не настроен file service. Я знаю, мне он не нужен. Это можно свалить на vmware и их неграмотных программистов, но скорее это показатель, что экосистема логирования это помойка, в которой нет лучших практик и понимания как что делать. Это повсеместная проблема. И 100500 уровней логирования никак не улучшают ситуацию. ELK же не случайно стал так популярен. Если бы уровни работали как задумано, то можно было бы одни взглядом на warn и error логи все понять. На практике же люди суют весь этот поток сознания в ELK и парсят полнотекстовым поиском.
Сообщения, на которые должен реагировать владелец кода, это то, что влияет на работоспособность системы и ее потребительские характеристики. В этом плане с потребителем софта они едины. Если все работает прекрасно, то никто в эти логи не смотрит. Когда что-то ломается, т.е. происходит ошибка, которую можно залогировать как error, то вот тогда можно читать эту стену логов. И в этой ситуации фильтровать warn нет никакого смысла - все равно нужен полный контекст.
Это одна из причин, почему трейсинг набрал такую популярность, а логи еще дальше ушли в категорию помойки, в которую лезут только в самом крайнем случае.
Простой пример из практики..
У меня есть модуль для виртуализированного рисования HTML. И этот модуль поддерживает лишь ограниченный набор тегов. Тем не менее ничто не мешает пользователю засунуть туда неподдерживаемые теги и удивляться, что они не будут отображаться. Чтобы подсказать ему в чём дело, я вывожу варнинги типа "этот тег не отображён, так как ещё не поддерживается, добавить поддержку можно воон там".
Я не вижу причин, почему это нельзя отображать как ошибку. Человек засунул в модуль тег, он не отображается. Очевидно, что-то работает некорректно. Это не фатальная ошибка, которая кладет приложения, но все равно ошибка. А вообще, такое можно и фатальной ошибкой сделать и переложить на пользователя заботу о том, чтобы все теги были поддерживаемые.
зачем мне warn, что у меня не настроен file service
Это проблема другого уровня. Должна быть настройка, которая укажет системе, что-то типа "file-service.enabled = false" и тогда никаких warning не должно сыпаться. Либо сыпаться, если какой-то модуль системы хочет таки использовать file service, которого нет и вот тут надо разбираться - почему он хочет то, что отключено, так как возможно этот модуль недонастроен или настроен неверно
Сервис этот отключен по-умолчанию, и я его не включал. Но по какой-то причине система продолжает делать какие-то health чеки и натыкается на это. Тоже самое с ipv6 - система постоянно делает health чеки и рапортует уже прямо ошибку с исключением в питоновском скрипте, что что-то не работает, потому что ipv6 нет. Правильно, потому что я его отключил в настройках гипервизора.
И подобное я вижу постоянно, потому что сами разработчики привыкли трактовать логи просто как гору мусора. Логи не считаются публичным интерфейсом приложения, а посему нет никакой ответственности о их содержании. На форумах ответы простые - не обращайте внимание, все ок.
error выводить как info, что в итоге приведёт к выводу ошибок не в stderr, а в stdout. Норм, да.
WARN сделал для того, чтобы можно было обратить внимание на ситуацию. Да, может быть в них никто и не "сммоттрит". Но можно повесить метрику и при накоплении критической массы начать разбор ситуаций
DEBUG/TRACE хороши тем, что выводят "избыточную" информацию, но которая нужна не всегда. Например, если боевой сервис выдал ошибку, то можно такой же входящий запрос перенаправить на отладочный сервис и получить в логах полную картину.
Но можно повесить метрику и при накоплении критической массы начать разбор ситуаций
никаких метрик из логов. Если приложение написано нормально, то в нем должны быть метрики количества событий определенного типа. Например, ошибочных запросов. И вот по ним можно делать алерт. Но делать алерт на логи.... ну, я разработчиков после этого прошу мыть рот и руки :-)
Окей. Возможен кейс, когда у нас стороннее решение, которое мы не можем доработать - там такой подход (логи -> метрики или логи -> алерты) оправдан. Но я вспоминаю каждый раз эти регекспы для парсинга логов и меня просто начинает трясти )))
В стране розовых пони, наверное, всё написано "нормально". Но есть приложения, где никакие метрики из-вне снять нельзя, т.к. они крутятся без доступа "наружу", кроме как через иногда подключающийся клиент. А ресурсов держать внутри окружение для метрик нет. Вот и приходится парсить логи, с чистыми руками и ртом, конечно же.
Вы говорите очень странные вещи. Есть ресурсы под приложение, но нет ресурсов под мониторинг? В нормальных компаниях такого не бывает. К тому же - сами подумайте - что проще хранить одно условное число в виде таймсириз или терабайты логов? Поэтому Ваше утверждение не имеет смысла.
Касательно закрытых периметров - ну, никто не мешает в закрытом периметре прокси для метрик держать. Забикс, прометеус все так умеют. Не вижу проблемы.
Я говорю про реальность, когда разве что snmp будет, кроме проприетарного протокола. Клиент заббикса на таргет никто не собирает, да и ресурсов на него не хватит, особенно оперативной памяти и CPU. Никаких терабайтов логов тоже нет, а анализировать нужно.
Вас перестанет трясти как только начнёте выводить структурированные логи.
Это не решение. Тем более Вам критику по формату tree отгружали. С тем же успехом Вы можете сериализировать логи в любой бинарный формат, раз к нему нужен свой просмотровщик. Ой, мы только что сделали то же самое, что и редхат в journald... На самом деле - если логи - это события, то их и надо обрабатывать как события. С чёткой схемой и типизацией. А если это рандомный поток текста (как это обычно бывает), то все равно ничего толком не сделаешь.
Не перестанет. От того, что логи летят в JSON или любом другом schema-less формате, не делает их более ясными. Поля все равно произвольные и неизвестные. Т.е. это как бы упрощает работу ELK, который умеет динамически обновлять схему индекса и искать по полям, но мало полезно для оператора, для которого это все равно рандомный поток текста. Можно точно так же создать и сохранить какой-то запрос поиска по этим полям, но завтра выйдет новый релиз софта и запрос сломается, потому что поля другие стали. Еще хуже, этот запрос теперь фильтрует что-то, что может быть нам полезно, но мы этого больше не видим. Т.е. мы вернулись к тем же самым регуляркам.
В этом плане хорош journald, потому что он не только структурировал логи, но и дал какую никакую схему. Я хотя бы могу вытащить из сообщений имя процесса и дату и быть уверенным, что это будет всегда работать на любой машине, где стоит journald.
К любому schema-less легко прикручиваются схемы, если в ниих есть потребность. Давайте не выдумывать несуществующих проблем.
А вот в schema-full, особенно, если это бинарный формат, вкорячить дополнительные данные порой невозможно.
А вот в schema-full, особенно, если это бинарный формат, вкорячить дополнительные данные порой невозможно.
Не проблема. И в результате мы имеем json с метаданными. В нем поле msg, которое мы сформировали в нашем приложении. И в нем внутри вложенный json.
К любому schema-less легко прикручиваются схемы,
Тут люди выше говорят о следовании правилам. Давайте, где есть какой-то стандарт, которому следует большое количество людей, которой стандартизирует схему JSON логов. Я таких не знаю. Ниодна библиотека логирования мне такого не советует.
Так что проблема есть. В экосистеме логирования нет правил. Поэтому какие бы ни были структурированные логи, это все равно рандомный текст для меня. Мне все равно приходится для каждого приложения писать свои правила обработки. Вещи вроде logstash и fluentd не случайно были придуманы.
Я поэтому journald упомянул. Там это есть хотя бы в каком-то базовом виде. Это есть в syslog, хотя даже там у меня проблемы были, когда система генерирует syslog сообщения в каком-то кривом формате и на месте имени процесса у меня оказывается кусок даты. В итоге я опять плюнул и стал трактовать все как рандомный текст.
с эластиком все хуже. Вот мы, предположим, поменяли тип старого поля. Все. Ластик перестаёт эти логи принимать, пока мы индекс не пересоздадим. Так что мы в таком решении легко ещё и можем потерять кучу данных и не узнать об этом (!!!). Конечно, когда узнаём - поставим это все на мониторинг. Но в результате выясняется, что под тот же эластик надо выделять целую команду инженеров на поддержку, иначе оно ехать не будет.
Проблема с warn в том, что очень часто его используют как еще один info уровень. Сообщения не содержат никакой важной информации, система работает. Более того, она так работает из коробки. Такие сообщения либо должны быть error, либо info. Алертинг на это не настроишь, потому оно сыпется постоянно. Система по таймеру делает проверку и каждый раз срет этими логами. Их можно фильтровать, но это костыль, который точно сломается на следующем релизе. Нормальное решение, если бы каждый такой лог можно было скрыть, но такого я тоже не видел.
Как пример, esxi. Постоянно срабатывает какой-то таймер, который высирает сотню строчек, чтобы сказать, что в кластере все ок. У меня одна нода в кластере за 6 часов выдала 700 warn сообщений - все это дубликаты. Даже error уровень содержит тонну мусора, который говорит о том, что у меня ipv6 выключен. Вот спасибо.
Статья автора, который и как разработчик странен, судя по описанному, и к эксплуатации серьезных систем отношения не имеет. Если статья переводная - то же можно сказать об авторе публикации, к сожалению. Рекомендация публикатору - просто включить голову и посмотреть за рамки его картины мира. Есть гипотеза, что там есть масса интересного.
Fatal, error, warn, info, debug, trace - оптимальный набор, который позволяет потратить минимум времени как на этапе отладки кода, так и при последующем его maintenance. Просто не нужно держать логи в trace на дефолте. И хорошо, если мы можем управлять этими самыми уровнями в разрезе разных подсистем, а не валить их все в одну кучу.
Ведение логов важно именно в том самом виде, в котором оно существует сегодня. Не могу согласится с мнение автора, т. к он абсолютно не понимает идею логов как таковых.
Причём тут переусложненность? Как прикажите выделять события которые Могут привести к ошибке? Что делать с проблемами которые обрабатывать бессмысленно ( в духе out-of-memory не на микроконтроллерах )?
Лог помогает быстрее ответить на вопрос "что произошло?", и попытка упростить его в духе статьи явно не способствует этому.
Что плохого в пакете логирования на Go?