От философий — к матчасти.
Мы занимаемся разработкой ERP системы, оптимизированной для высоких нагрузок. Как следствие — в системе присутствует кластеризация. И каждый из узлов кластера ведет свой лог. В логе пишутся сообщения об ошибках, различные сообщения о ходе выполнения программ от прикладных разработчиков и так далее.
Как мы реализовали журналирование — под катом.
Для начала, по заветам предков походили по граблям.
У нас было
— Несколько кластеров
— В каждом из которых несколько нод
— Толпа разработчиков
— Сотни клиентских desktop-приложений.
— 20-30мб прикладного и системного кода с трассировкой и дампом данных.
Все приложения через NLog писали в файлы.
Журналирование в файл имело только одно преимущество — очень легко администрировать, и то сомнительное — файлы журналов тоже надо ротировать.
Во всех остальных смыслах это провал:
Итак, нам нужно было решение для журналирования, которое позволило бы легко искать сообщения с учетом различных источников, легко понимать сообщение, сохранять объекты в легкочитаемом структурированном формате и последнее — решение должно легко устанавливаться, поддерживаться, быть удобным.
Перебрав несколько вариантов (Elasticsearch и другие подобные механизмы), остановились на связке SeriLog и MongoDB.
SeriLog отлично решил проблему структурированного хранения событий. MongoDB — простая в администрировании база, имеющая достаточную популярность, удобный интерфейс и поддержка C#, активно развивается.
Несколько расстроило в MongoDB качество документирования драйвера для C#, так что пришлось повозиться, в поисках поддержки ad-hoc запросов. Впрочем, не критично.
В итоге, получили такой интерфейс для просмотра событий, который доступен любому разработчику:
Для простых случаев можно воспользоваться фильтром на первой закладке. А на второй — полноценное окно запросов, где можно писать произвольные запросы.
Приятная особенность — SeriLog сохраняет шаблон сообщения, что позволяет (имея перед глазами код программы) найти все соответствующие сообщения.
Ну и SourceContext позволяет фильтровать по источнику сообщений — с сервера, клиента или SQL запросы.
Последний — удобнейшее средство отслеживания какие SQL запросы выполняются к базе с целью их оптимизации.
Небольшое отступление.
Вообще, для трассировки SQL запросов в нашей платформе существует 2 инструмента
Вернемся к приведенному выше примеру:
В данном случае, к журнальному событию будет прицеплен весь список параметров,
и в логе можно будет найти запись о выполнении команды с определенным значением
нужного параметра.
Пример несколько надуманный, поскольку все SQL запросы и так журналируются.
Вот более реальный:
И вид записи в логе:
При журналировании состояния документа или другого сложно объекта лучше не сохранять его содержимое в сообщение:
Сообщение будет выглядеть так:
Правильнее будет вывести в сообщении только номер документа, и передать содержимое в параметрах. Все параметры можно просмотреть в JSON:
или в структурированном виде в PropertyGrid:
При журналировании исключений будет сохранена их внутренняя структура, в том
числе свойства HResult, CallStack и вся цепочка InnerException (к сожалению, этот
функционал не встроен в Serilog, и его пришлось реализовать самостоятельно).
Чтобы зажурналировать исключение, достаточно передать его первым параметром в методы
журналирования:
Инструмент анализа логов позволяет просматривать в PropertyGrid структуру сообщения:
Все необработанные исключения будут журналированы автоматически. Кстати, все такие инциденты должны быть рассмотрены, и, если действительно есть ошибка, исправлены. Хорошее средство повышения качества приложения.
Описанная функциональность — лучшее, что мы смогли подобрать для наших задач. Гибкость, легкость администрирования, удобство использования, сохранение событий с объектами в структурированном виде.
Надеюсь, эта статья поможет другим разработчикам desktop приложений выбрать свой вариант реализации журналирования.
Мы занимаемся разработкой ERP системы, оптимизированной для высоких нагрузок. Как следствие — в системе присутствует кластеризация. И каждый из узлов кластера ведет свой лог. В логе пишутся сообщения об ошибках, различные сообщения о ходе выполнения программ от прикладных разработчиков и так далее.
Как мы реализовали журналирование — под катом.
Для начала, по заветам предков походили по граблям.
У нас было
— Несколько кластеров
— В каждом из которых несколько нод
— Толпа разработчиков
— Сотни клиентских desktop-приложений.
— 20-30мб прикладного и системного кода с трассировкой и дампом данных.
Все приложения через NLog писали в файлы.
Журналирование в файл имело только одно преимущество — очень легко администрировать, и то сомнительное — файлы журналов тоже надо ротировать.
Во всех остальных смыслах это провал:
- Структурированность данных
Часто, для отладки приложения, требуется сохранить тот или иной объект. Кроме него, сохранить уточняющие сообщения и прочую информацию. Например:
var parameters = new Dictionary<string, object>(); parameters["id"] = id; parameters["limit"] = maxValues; ... Logger.Verbose("Executing command: {SQL} with parameters: {@Parameters}", sqlCommand, parameters); Использовавшийся NLog не позволял сохранять сообщения в удобном формате, так что разработчики писали как вздумается.
- Доступность информации
Логирование в файлах заставляет перебирать файлы журналов на всех серверах в поисках крупиц информации. Умноженное на количество разработчиков, это приводит к тому, что все имеют доступ ко всем серверам и становится перманентной головной болью для администраторов.
Итак, нам нужно было решение для журналирования, которое позволило бы легко искать сообщения с учетом различных источников, легко понимать сообщение, сохранять объекты в легкочитаемом структурированном формате и последнее — решение должно легко устанавливаться, поддерживаться, быть удобным.
Перебрав несколько вариантов (Elasticsearch и другие подобные механизмы), остановились на связке SeriLog и MongoDB.
SeriLog отлично решил проблему структурированного хранения событий. MongoDB — простая в администрировании база, имеющая достаточную популярность, удобный интерфейс и поддержка C#, активно развивается.
Несколько расстроило в MongoDB качество документирования драйвера для C#, так что пришлось повозиться, в поисках поддержки ad-hoc запросов. Впрочем, не критично.
В итоге, получили такой интерфейс для просмотра событий, который доступен любому разработчику:
Для простых случаев можно воспользоваться фильтром на первой закладке. А на второй — полноценное окно запросов, где можно писать произвольные запросы.
Приятная особенность — SeriLog сохраняет шаблон сообщения, что позволяет (имея перед глазами код программы) найти все соответствующие сообщения.
Ну и SourceContext позволяет фильтровать по источнику сообщений — с сервера, клиента или SQL запросы.
Последний — удобнейшее средство отслеживания какие SQL запросы выполняются к базе с целью их оптимизации.
Небольшое отступление.
Вообще, для трассировки SQL запросов в нашей платформе существует 2 инструмента
- Трассировка сессий онлайн
Сообщения будут поступать онлайн в соответствующее окно. Подключится можно к любой сессии в кластере.
Выглядит так:
на второй закладке все параметры перечислены в табличке:
- Централизованный лог со всеми SQL запросами вместе с параметрами
Все сообщения доступны в средстве просмотра централизованного лога в SourceContext SqlStatement
Вернемся к приведенному выше примеру:
var parameters = new Dictionary<string, object>();
parameters["id"] = id;
parameters["limit"] = maxValues;
...
Logger.Verbose("Executing command: {SQL} with parameters: {@Parameters}", sqlCommand, parameters);
В данном случае, к журнальному событию будет прицеплен весь список параметров,
и в логе можно будет найти запись о выполнении команды с определенным значением
нужного параметра.
Пример несколько надуманный, поскольку все SQL запросы и так журналируются.
Вот более реальный:
Logger.Debug("Brand #{BrandID} contents: {@Brand}", brand.ID, brand);
И вид записи в логе:
Brand #12 contents: Brand { ID: 12, Name: "Pineapple" }
При журналировании состояния документа или другого сложно объекта лучше не сохранять его содержимое в сообщение:
Logger.Debug("Document #{DocumentID} is saved. Document contents: {@Document}", doc.ID, doc);
....
Сообщение будет выглядеть так:
Document #101187 is saved. Document contents: SaleDocument { ActualInvoiceDocumentID: null, AgentID: 636, AllowPartialRelease: False, Amount: 5500, AmountDistributionTypeID: null, ArticlesQuantity: 3, ClientDueOnDelivery: 5500, Comments: "noreply", Convertation: null, CreationDate: 02/06/2015 22:21:53, CreatorID: 7, CustomerSupplyContractID: null, DeadDate: 02/11/2015 22:21:53, Deleted: False, DeliveryActive: False, Description: "Sales (Picking) #101187, 2/6/2015"
...
50kb of JSON follows
Правильнее будет вывести в сообщении только номер документа, и передать содержимое в параметрах. Все параметры можно просмотреть в JSON:
или в структурированном виде в PropertyGrid:
При журналировании исключений будет сохранена их внутренняя структура, в том
числе свойства HResult, CallStack и вся цепочка InnerException (к сожалению, этот
функционал не встроен в Serilog, и его пришлось реализовать самостоятельно).
Чтобы зажурналировать исключение, достаточно передать его первым параметром в методы
журналирования:
Logger.Error(ex, "Cannot execute user task: {Message}", ex.Message);
Инструмент анализа логов позволяет просматривать в PropertyGrid структуру сообщения:
Все необработанные исключения будут журналированы автоматически. Кстати, все такие инциденты должны быть рассмотрены, и, если действительно есть ошибка, исправлены. Хорошее средство повышения качества приложения.
В заключение.
Описанная функциональность — лучшее, что мы смогли подобрать для наших задач. Гибкость, легкость администрирования, удобство использования, сохранение событий с объектами в структурированном виде.
Надеюсь, эта статья поможет другим разработчикам desktop приложений выбрать свой вариант реализации журналирования.