Комментарии 24
[4] pry(main)> log = Logger.new STDERR, level: :info;
[5] pry(main)> log.debug "МанаМана#{ print 'Нелениво'; 1+2 }"
Нелениво=> true
[6] pry(main)> log.debug { "МанаМана#{ print 'Нелениво'; 1+2 }" }
=> trueСпасибо. Не знал.
Немного не в контексте статьи, но тем не менее есть еще один пункт к выводам:
- думайте, куда вы пишете
При использовании накопителей на флэш-памяти особо удачливый логгер может протереть в памяти дырку за время, намного меньшее ожидаемого времени жизни системы
Логируйте с избытком. Никогда заранее не известно сколько и какой информации в логах понадобиться в критический момент.
А потом копайтесь несколько часов в логах в попытках найти нужное. Мне кажется, лучше все-таки соблюдать баланс.
Вот потому и есть уровни логирования (например, 5), когда всё ок — можно настроить чуть не минимум, когда нужно разобраться — включаем mode=DEBUG в конфиге и он пишет всё, включая содержимое запросов и поток данных с устройств, разбираться придётся часы, но без этого — недели.
Возможно, зависит от проекта, но у меня есть для таких случаев дебаг.
А для случаев, где один сбой за месяц, то копать такие логи нужно будет ооооочень долго.
даже если на продакшине всегда включен DEBUG — кому-то использовать grep религия не позволяет?
если вы копаетесь в логах несколько часов — значит вы их неправильно пишите.
Писать логи "правильно" довольно сложно. Ну и как их правильно не пиши, парсинг в духе ELK прикрутить все равно нужно.
даже если на продакшине всегда включен DEBUG — кому-то использовать grep религия не позволяет?
В результате все равно гиганские стены текста.
> В результате все равно гиганские стены текста.
Простите, не понимаю. Лог, а по-русски, «протокол» — это такой поток записей. Причем, в общем случае, на эти записи накладываются совсем небольшие требования, типа «иметь отметку времени» и «иметь loglevel». Если вам этих требований для структурирования мало — никто не мешает в log message добавить то, что облегчит вам фильтрацию. Хоть grep'ом, хоть ELK, хоть еще чем-то.
Не вижу вообще никаких проблем. Если это ваш продукт — вы сами пишите логи для себя.
Когда люди готовят для себя еду, они же не насыпают туда килограммы соли или перца, что есть невозможно? Бывает, в первый раз сыпанул, но есть же второй раз, третий раз…
Простите, не понимаю. Лог, а по-русски, «протокол» — это такой поток записей.
А теперь представьте, что у вас в системе куча различных документов с которыми происходит куча различных событий.
Скажем, для 6-7 типов документов по 50 событий в минуту. Причем для каждого документа различные источники изменений, различные действия и так далее. И все идея "правильного логгирования" без чего-то в духе ELK превращается в тыкву, потому что разобрать это через grep — практически невозможно.
Правильно писать логи — это очень не просто, а поэтому совет "пишите больше" похож на совет "резать двумя руками хлеб быстрее". Он далеко не для всех.
10 типов документов, 60 событий в минуту (1 в секунду). 3600*10 строк в час? 24 часа?
864000 строк в сутки?
Взял навскидку из багрепорта посылку, там логи порядка 100М за сутки — 440803 строки, например. Похоже на вашу ситуацию? Всего в два раза меньше.
У нас «правильное логгиирование» обязует разработчика использовать loglevel'ы, вполне опредленным образом
* DEBUG — то, что будет читать только разработчик
* INFO — то, что может почитать инженер поддержки, но не факт
* WARNING — то, что читает инженер поддержки
* ERROR — то, что обязательно читает инженер поддержки, и на что реагируют алерты.
итак, из этик 440К строк:
* DEBUG — ~356K
* INFO — ~81K
* WARNING — 3K
* ERROR — 86 строк
Еще раз — я не против ELK. Даже очень за. Но вот сейчас мне хватило просто grep и wc -l, что бы выдать вам эти цифры. Ровно так-же, зная имена модулей, и дальше по архитектуре приложения, я могу получать простым grep'ом нужные срезы. Вот, например, есть у нас некий «ServiceManager» — он в этот лог написал ~253K строк. И в то же время, было всего 123 строки, когда этот самый «ServiceManager» писал «Can't connect to host».
Это просто одна команда:
grep ServiceManager" some.log | grep «Can't connect to host» | less
Вы говорите, что практически невозможно написать такую команду?
Помимо того, что ваш пример немного… странный, так как не у всех такая архитектура, что бы ее можно было разбить на части (например, вы кастомизируете CRM или ERP системы, и тогда у вас проблемки), меня очень смущает, что когда ServiceManager пишет "Can't connect to host" это не ошибка.
Более реальный пример того, для чего реально нужны логи привели мне выше, но там все равно нужно выбирать.
Для того, что бы понять, о каких проблемах я говорю, гляньте, например, систему модулей в odoo. Там очень много мест, где меняются документы и вместе с их изменениями нужно писать стек трейс и кучу другого мусора. И разберать это через grep (а ведь там многострочные сообщения!) это все равно, что стрелять с пращи по дракону.
При четко поставленной цели, гораздо проще из множества вариантов выбрать те, которые именно вам нужны.
Инструмент разработки — не важен, даже если никаких удобных библиотек нет, и у вас просто вывод строк в stdout, туда можно и нужно писать так, что бы достигать цель. Навскидку, целей две:
* оперативное оповещение о проблемах
* разбор инцидентов
После того, как с целями разобрались, нужно выяснить, кто пользователи. Опять-же, навскидку
* дежурный службы поддержки
* сервисный инженер
* разработчик
Далее, для известных целей и пользователей, нужно определить объем и характер информации в логе, который необходим, и объем и характер информации, который достаточен.
Например, можно предположить, что для оперативного оповещения о проблеме дежурного инженера поддержки, подробности проблемы не так важны, в отличии от понимания важности проблемы, и места, где эта проблема возникла.
Аналогично можно предположить, что для сервисного инженера, который будет разбираться с инцидентом, километровые traceback'и мало что скажут, а вот возможность четко понять какой модуль (с прикладной точки зрения) и в какой момент поломался, или что именно сделал «не так» — важно.
И точно так же можно предположить, что разработчику, который будет чинить баг в коде, километровый traceback с номерами строк в исходниках, может облегчить локализацию проблемы, а так-же значения аргументов при вызове функций и что там ему еще нужно будет, что бы смоделировать у себя ловить трудновоспроизводимую ошибку, написать для неё тест, починить, и отдать исправление в релиз.
Когда вы распишите эти три момента (цели, пользователи, требования каждого пользователя), будет более-менее четка картина, что, когда и как писать логи.
Какие сообщения на какой loglevel выводить, нужны ли логах traceback'и или нет, и вот это всё.
После «пилота», непременно нужно провести фазу тестирования: смоделировать проблемы, взять пользователя, выдать ему лог с зафиксированной проблемой и получить обратную связь.
Спасибо за статью.
Есть ещё тонкий момент, когда вы пишите что то вроде logger.debug(entity.values) — то при выставленном уровне логирования выше debug содержимое entity.values не попадёт в лог, но оно каждый раз будет вычисляться отъедая ресурсы.
Тут нужны эксперименты. Для каждого логера свой правильный путь. Если для получения уровня логирования компилятор задействует inline-преобразование, то при таком коде получения entity.values не будет:
if (logger.IsDebug) logger.debug(entity.values);Если надежды на inline нет, то нужно добавлять переменную — это плохой стиль, но будет быстро.
bool isDebug = logger.IsDebug;
// bool isDebug = logger.isDebug();
if(isDebug) logger.debug(entity.values);
Как правильно писать логи (?)