Какова ваша философия ведения журнала?

https://stackoverflow.com/questions/44554

logging

09-06-2019
|

Вопрос

Как Спросил Джефф Этвуд:"Какова ваша философия ведения журнала?Должен ли весь код быть усеян .logthis() и .logthat() звонки?Или вы каким-то образом вводите логирование постфактум?"

Решение

Моя философия ведения журнала довольно легко сводится к четырем частям:

Аудит или ведение журнала бизнес-логики

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

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

Ведение журнала программы

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

Как правило, это ведение журнала включается и выключается по мере необходимости для сеансов отладки.

Ведение журнала производительности

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

Ведение журнала безопасности

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

Другие советы

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

Я разрабатываю системы, которые способны регистрировать практически все, но я не включаю все по умолчанию.Отладочная информация отправляется в скрытое диалоговое окно отладки, которое помечает ее временем и выводит в список (до удаления не более 500 строк), и диалоговое окно позволяет мне остановить его, автоматически сохранить в файл журнала или перенаправить в подключенный отладчик, такой как DBWin32.Это перенаправление позволяет мне видеть отладочные выходные данные из нескольких приложений, все аккуратно сериализованные, что иногда может спасти жизнь.Файлы журналов автоматически удаляются каждые N дней.Я использованный использовать числовые уровни ведения журнала (чем выше вы устанавливаете уровень, тем больше вы фиксируете):

ВЫКЛ
только ошибки
Базовые модели
подробный
все

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

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

#define DEBUG_ERROR          1
#define DEBUG_BASIC          2
#define DEBUG_DETAIL         4
#define DEBUG_MSG_BASIC      8
#define DEBUG_MSG_POLL       16
#define DEBUG_MSG_STATUS     32
#define DEBUG_METRICS        64
#define DEBUG_EXCEPTION      128
#define DEBUG_STATE_CHANGE   256
#define DEBUG_DB_READ        512
#define DEBUG_DB_WRITE       1024
#define DEBUG_SQL_TEXT       2048
#define DEBUG_MSG_CONTENTS   4096

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

Программное обеспечение обычно поставляется с включенными параметрами ERROR, BASIC, STATE_CHANGE и EXCEPTION, но это можно изменить в поле с помощью диалогового окна debug (или настройки реестра / ini / cfg, где эти параметры сохраняются).

Да, и еще одно - моя система отладки генерирует по одному файлу в день.Ваши требования могут отличаться.Но убедитесь, что ваш отладочный код запущен каждый файл с датой, версией кода, который вы запускаете, и, если возможно, каким-либо маркером для идентификатора клиента, местоположения системы или чего-либо еще.Вы можете получить мешанину лог-файлов, поступающих с мест, и вам нужна какая-то запись о том, что пришло, откуда и какая версия системы, которую они запускали, которая на самом деле содержится в самих данных, и вы не можете доверять клиенту / инженеру на местах, который скажет вам, какая версия у них есть - они могут просто сказать вам, какая версия, по их МНЕНИЮ, у них есть.Хуже того, они могут сообщить о версии exe, которая есть на диске, но старая версия все еще запущена, потому что они забыли перезагрузить компьютер после замены.Пусть ваш код расскажет вам сам.

Это мой выброшенный мозг...

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

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

Другие полезные вещи для регистрации - это если у вас есть утверждения, и ваши утверждения терпят неудачу, то запишите их...например, в этом запросе должно быть меньше 10 результатов, если оно больше, может возникнуть проблема, поэтому запишите его.Конечно, если оператор log в конечном итоге заполняет журналы, это, вероятно, подсказка либо перевести его на какой-то уровень "отладки", либо скорректировать или удалить оператор log.Если журналы вырастут слишком большими, вы часто будете их игнорировать.

Я использую то, что считаю традиционным подходом;некоторое протоколирование, окруженное условными определениями.Для производственных сборок я отключаю defines.

Я намеренно регистрируюсь по ходу работы, поскольку это означает, что данные журнала имеют смысл:

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

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

Я начинаю с утверждения множества условий в моем коде (на C #, используя System.Diagnostics.Assert), но я добавляю ведение журнала только там, где я обнаруживаю, во время отладки или подвергая систему стрессу, что мне действительно нужен способ следить за тем, что происходит внутри моего кода, без постоянного подключения отладчика.

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

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

Кроме того, это помогает вам точно определить, где возникает ошибка.

Запишите их все, и пусть Grep с ними разберется.

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

Я определяю различные уровни и передаю настройку с помощью config / invocation.

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

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

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

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

В качестве примера случая, когда ведение журнала спасло мою задницу, однажды у меня был странный пользователь с прототипом компьютера Intel, который выходил из строя.Мы перечислили минимальные требования для машин, которые должны поддерживать SSE 4, но эта конкретная машина соответствовала этим минимальным требованиям и по-прежнему не поддерживала потоковые расширения SIMD после SSE 3, несмотря на то, что была 16-ядерной машиной.Быстрое обнаружение этого стало возможным благодаря просмотру его журнала, в котором был указан точный номер строки, где использовались инструкции SSE 4.Никто из нас в нашей команде не смог воспроизвести проблему, не говоря уже об одном другом пользователе, который участвовал в проверке отчета.В идеале нам следовало бы написать код для старых версий SIMD или, по крайней мере, выполнить некоторые ветвления и проверки, чтобы убедиться, что оборудование поддерживает минимальные требования, но мы хотели сделать твердое предположение, что минимальные требования к оборудованию передаются для простоты и экономичности.Здесь, возможно, можно утверждать, что "сбой" произошел именно в наших минимальных системных требованиях.

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

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

Я не разбрасываю выходные данные журнала повсюду (я мог бы, если бы у меня было время).Обычно я оставляю их для областей, которые кажутся мне наиболее опасными:код, вызывающий шейдеры GLSL, например(Производители графических процессоров здесь сильно различаются с точки зрения возможностей и даже того, как они компилируют код), код, использующий встроенные функции SIMD, код очень низкого уровня, код, который неизбежно должен полагаться на поведение, зависящее от конкретной ОС, низкоуровневый код, делающий предположения о представлении модулей (например:код, который принимает 8 бит к байту) - это те случаи, когда мы бы аналогичным образом разбросали множество утверждений и проверок на работоспособность, а также написали наибольшее количество модульных тестов.Обычно этого достаточно, и ведение журнала много раз спасало мою задницу, когда в противном случае я бы столкнулся с невоспроизводимой проблемой и мне пришлось бы наносить слепые удары по проблеме, требуя множества итераций, отбрасывающих попытки решения единственному пользователю в мире, который мог бы воспроизвести проблему.

Лицензировано под: CC-BY-SA с атрибуция

Не связан с StackOverflow