Как стать автором
Обновить

И это все о нем? Снова про log4net

Время на прочтение13 мин
Количество просмотров9.5K

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

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

Поговорим о библиотеке Apache log4net, инструменте, помогающем программисту осуществлять аудит приложений. Как известно  Apache Software Foundation более 15 лет назад портировала проект Apache log4j™ для среды Microsoft® .NET.

Заранее прошу не кидаться в меня гнилыми помидорами сообщая, что есть более современные и развитые средства логирования типа NLog или Serilog. Да эти средства очень хороши, но мне по роду своей деятельности приходиться работать с десктопными приложениями для АСУТП. Львиная доля подобных программных решений начинали создаваться очень давно, хотя до сих пор выпускаются все новые версии этих программ. Из отечественных разработок можно упомянуть, например MasterScada. Через мои руки прошел с десяток программных решений, где использовалась платформа .NET и библиотека log4net.dll для логирования. Причем среди поставщиков этого программного обеспечения попадаются довольно известные бренды в мире АСУТП. Подумалось, что рано списывать столь заслуженную библиотеку со счетов. Информации о том, как работает библиотека вроде бы немало, но зачастую найденные мной описания успели устареть, поскольку проект до сих пор развивается, а к тому же эти описания довольно сумбурны и плохо структурированы. Перевода официальной документации на русский язык не нашел, поэтому решил составить собственное небольшое справочное пособие опираясь на документацию и распространяемые с ней примеры программ, а также на независимые источники информации, найденные на просторах интернета. В качестве наглядного примера возьмем самое простое консольное приложение, из учебного пособия которое предоставляет apache.org под названием ConsoleApp. Надо сразу сказать, что в учебном пособии рассматриваются еще 12 примеров на более сложные случаи в жизни. Но на практике вариант простого применения наиболее распространен и это то, что надо всегда иметь под рукой.

Подключить библиотеку к проекту, проще всего через NuGet, но можно скачать из официального сайта https://logging.apache.org/log4net/

Итак, учебный проект состоит из следующих файлов:

1)      packages.config;

вот его содержимое:

<?xml version="1.0" encoding="utf-8"?>
<packages>
  <package id="log4net" version="2.0.14" targetFramework="net48" />
</packages>

Как видим, в нем указана версия самой библиотеки, на момент написания статьи это 2.0.14

И целевая платформа, в данном случае .NET 4.8

Следующий файл

2)      AssemblyInfo.cs

Вот его содержимое:

// Лицензия
// http://www.apache.org/licenses/LICENSE-2.0
//
using System.Reflection;
using System.Runtime.CompilerServices;
//
//Общая информация о сборке управляется с помощью следующего набора //атрибутов.
//Измените значения этих атрибутов, чтобы изменить информацию, связанную //со сборкой.
//
[assembly: AssemblyTitle("log4net - ConsoleApp")]
[assembly: AssemblyDescription("log4net ConsoleApp")]
[assembly: AssemblyConfiguration("")]
[assembly: AssemblyProduct("log4net - ConsoleApp")]
[assembly: AssemblyCulture("")]		
[assembly: AssemblyDelaySign(false)]
[assembly: AssemblyKeyFile("")]
[assembly: AssemblyKeyName("")]

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

Хотя эту строку можно было разместить и здесь, вот ее различные варианты:

//Если файл с настройками лежит в папке config
[assembly: log4net.Config.XmlConfigurator(ConfigFile = "config\\ ConsoleApp.log4net", Watch = true)]

//Если файл настроек находится в папке с программой
[assembly: log4net.Config.XmlConfigurator(ConfigFile =
"ConsoleApp.exe.log4net", Watch = true)]

//Если настройки нужно брать из App.config
[assembly: log4net.Config.XmlConfigurator()]

Теперь собственно сама программа

3)      LoggingExample.cs

В ней и осуществляется логирование (в дальнейшем добавляйте кусочки кода из нее в свои программы).

Посмотрим, как все организовано, вот ее код:

код программы
// Licensed to the Apache Software Foundation (ASF)
// http://www.apache.org/licenses/LICENSE-2.0

// Вот та самая строка теперь здесь
// указывает, что log4net будет брать настройки из .config файла
[assembly: log4net.Config.XmlConfigurator(Watch = true)]
//Эта директива приведет к тому, что log4net будет искать конфигурационный файл
//с именем ConsoleApp.exe.config в базовом
//каталоге приложения (т.е. в каталоге, содержащем ConsoleApp.exe )

namespace ConsoleApp
{
	using System;
	/// <summary>
	/// Пример того, как просто настроить и использовать log4net
	/// </summary>
	public class LoggingExample
	{

		// В каждом классе приложения можно реализовать приватное поле типа ILog и инициализировать его при объявлении.
private static readonly log4net.ILog log = log4net.LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType)pe);

		/// <summary>
		/// Точка входа в приложение
		/// </summary>
		/// <param name="args">аргументы командной строки</param>
		public static void Main(string[] args)
		{
			// Записываем сообщение информационного уровня, если логирование разрешено
			// в документации этим проверкам уделяется много внимания, есть отдельный пример
			// и много рассуждений об увеличении производительности если логирование запретить.

			if (log.IsInfoEnabled) log.Info("Приложение [ConsoleApp] Запущено");

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

			if (log.IsDebugEnabled) log.Debug("Это отладочное сообщение");

			try
			{
				Bar();
			}
			catch (Exception ex)
			{
				// Регистрируем ошибку вызванную исключением
				log.Error("Исключение, вызванное методом Bar", ex);
			}

			log.Error("Эй, это ошибка!");
			 
			// Реализация вложенных диагностических контекстов (NDC)
			using (log4net.NDC.Push("NDC_Сообщение"))
			{
				log.Warn("Здесь содержится сообщение NDC");

				// Установим значение сопоставленного диагностического контекста (MDC)
				log4net.MDC.Set("auth", "auth-none");
				log.Warn("Здесь содержится MDC сообщение для ключа 'auth'");

			} // Сообщение NDC извлекается из стека в конце using {} блока

			log.Warn("Смотрите NDC выскочил! А MDC 'auth' ключ все еще с нами.");
			
			// Снова запишем информационное сообщение на сей раз о завершении работы программы
			if (log.IsInfoEnabled) log.Info("Приложение [ConsoleApp] Завершено");

			Console.Write("Нажмите Enter для выхода...");
			Console.ReadLine();
		}

		// Вспомогательные методы для демонстрации информации о местоположении и вложенных исключений

		private static void Bar()
		{
			Goo();
		}

		private static void Foo()
		{
			throw new Exception("Это исключение");
		}

		private static void Goo()
		{
			try
			{
				Foo();
			}
			catch (Exception ex)
			{
				throw new ArithmeticException("Failed in Goo. Calling Foo. Inner Exception provided", ex);
			}
		}
	}
}

Статистика показывает, что примерно 4% кода программ посвящено ведению журналов. Следовательно, даже приложения среднего размера будут иметь тысячи операторов ведения журнала, встроенных в их код. Учитывая этот факт, возникает необходимость управлять этими операторами записи в журнал без необходимости изменять код приложения. Поэтому существует механизм позволяющий более гибко настроить log4net с помощью конфигурационных файлов. В настоящее время файлы конфигурации записываются в формате XML.

Рассмотрим наш конфигурационный файл:

4)      App.config

Вот его содержимое:

структура конфигурационного файла
<?xml version="1.0" encoding="utf-8"?>
<!--
 License at
   http://www.apache.org/licenses/LICENSE-2.0
-->
<!-- 
		.NET application configuration file  
		Этот файл должен иметь то же имя, что и ваше приложение, с добавленным к нему расширением .config.
		Например, если ваше приложение — ConsoleApp.exe, то файл конфигурации должен быть ConsoleApp.exe.config.
		Он также должен находиться в том же каталоге, что и приложение.		
	-->
<configuration>
	<!-- Регистрируем обработчик раздела для log4net секции -->
	<configSections>
		<section name="log4net" type="System.Configuration.IgnoreSectionHandler"/>
	</configSections>
	<appSettings>
		<!-- Чтобы включить внутреннее ведение журнала log4net, укажите следующий ключ appSettings -->
		<!-- <add key="log4net.Internal.Debug" value="true"/> -->
	</appSettings>
	<!-- Этот раздел содержит настройки конфигурации log4net -->
	<log4net>
		<!-- Создаем RollingFileAppender - шлюз, создающий новый файл с логом, при переполнении текущего -->
		<appender name="RollingLogFileAppender" type="log4net.Appender.RollingFileAppender">
			<file value="rolling-log.txt"/>
			<appendToFile value="true"/>
			<maxSizeRollBackups value="10"/>
			<maximumFileSize value="100"/>
			<rollingStyle value="Size"/>
			<staticLogFileName value="true"/>
			<layout type="log4net.Layout.PatternLayout">
				<header value="[Header]
"/>
				<footer value="[Footer]
"/>
				<conversionPattern value="%date [%thread] %-5level %logger [%ndc] - %message%newline"/>
			</layout>
		</appender>
		<appender name="LogFileAppender" type="log4net.Appender.FileAppender">
			<file value="log-file.txt"/>
			<!-- Пример использования переменных среды в параметрах -->
			<!-- <file value="${TMP}\log-file.txt" /> -->
			<appendToFile value="true"/>
			<!-- Можно указать альтернативную кодировку вывода -->
			<!-- <encoding value="unicodeFFFE" /> -->
			<layout type="log4net.Layout.PatternLayout">
				<header value="[Header]
"/>
				<footer value="[Footer]
"/>
				<conversionPattern value="%date [%thread] %-5level %logger [%ndc] &lt;%property{auth}&gt; - %message%newline"/>
			</layout>
			<!-- Альтернативный макет с использованием XML			
			<layout type="log4net.Layout.XMLLayout" /> -->
		</appender>
		<appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">
			<layout type="log4net.Layout.PatternLayout">
				<conversionPattern value="%date [%thread] %-5level %logger [%ndc] &lt;%property{auth}&gt; - %message%newline"/>
			</layout>
		</appender>
		<appender name="NetSendAppender" type="log4net.Appender.NetSendAppender">
			<threshold value="ERROR"/>
			<server value="SQUARE"/>
			<recipient value="nicko"/>
			<layout type="log4net.Layout.PatternLayout">
				<conversionPattern value="%date [%thread] %-5level %logger [%ndc] - %message%newline"/>
			</layout>
		</appender>
		<!-- Пример того, как конфигурировать AdoNetAppender на примере работы с базой данных MS Access
		<appender name="AdoNetAppender" type="log4net.Appender.AdoNetAppender" >			
			<connectionString value="Driver={Microsoft Access Driver (*.mdb)};DBQ=C:\Work\cvs_root\log4net-1.2\access.mdb;UID=;PWD=;" />
			<layout type="log4net.Layout.PatternLayout">				
				<conversionPattern value="INSERT INTO Log ([Date],[Thread],[Level],[Logger],[Message]) VALUES ('%date','%thread','%level','%logger','%message')" />
			</layout>
		</appender> 
		-->
		<!-- 
		<appender name="A" type="log4net.Appender.ForwardingAppender" >
			<threshold value="WARN"/>			
			<appender-ref ref="ConsoleAppender" />		
		</appender>
		<appender name="B" type="log4net.Appender.ForwardingAppender" >
			<filter type="log4net.Filter.LevelRangeFilter">
				<levelMin value="DEBUG"/>
				<levelMax value="INFO"/>
			</filter>
			<appender-ref ref="ConsoleAppender" />
		</appender> 
		-->
		<!-- Пример настройки AdoNetAppender для подключения к MS Access-->
		<appender name="ADONetAppender_Access" type="log4net.Appender.AdoNetAppender">
			<connectionString value="Provider=Microsoft.Jet.OLEDB.4.0;Data Source=C:\Work\cvs_root\log4net-1.2\access.mdb;User Id=;Password=;"/>
			<commandText value="INSERT INTO Log ([Date],[Thread],[Level],[Logger],[Message]) VALUES (@log_date, @thread, @log_level, @logger, @message)"/>
			<parameter>
				<parameterName value="@log_date"/>
				<dbType value="String"/>
				<size value="255"/>
				<layout type="log4net.Layout.PatternLayout">
					<conversionPattern value="%date"/>
				</layout>
			</parameter>
			<parameter>
				<parameterName value="@thread"/>
				<dbType value="String"/>
				<size value="255"/>
				<layout type="log4net.Layout.PatternLayout">
					<conversionPattern value="%thread"/>
				</layout>
			</parameter>
			<parameter>
				<parameterName value="@log_level"/>
				<dbType value="String"/>
				<size value="50"/>
				<layout type="log4net.Layout.PatternLayout">
					<conversionPattern value="%level"/>
				</layout>
			</parameter>
			<parameter>
				<parameterName value="@logger"/>
				<dbType value="String"/>
				<size value="255"/>
				<layout type="log4net.Layout.PatternLayout">
					<conversionPattern value="%logger"/>
				</layout>
			</parameter>
			<parameter>
				<parameterName value="@message"/>
				<dbType value="String"/>
				<size value="1024"/>
				<layout type="log4net.Layout.PatternLayout">
					<conversionPattern value="%message"/>
				</layout>
			</parameter>
		</appender>
		<!-- Пример настройки AdoNetAppender для подключения к MS SQL Server -->
		<appender name="ADONetAppender_SqlServer" type="log4net.Appender.AdoNetAppender">
			<bufferSize value="1"/>
      <connectionType value="System.Data.SqlClient.SqlConnection, System.Data, Version=1.0.3300.0, Culture=neutral, PublicKeyToken=b77a5c561934e089"/>
<connectionString value="data source=SQLSVR;initial catalog=test_log4net;integrated security=false;persist security info=True;User ID=sa;Password=sa"/>/>
			<commandText value="INSERT INTO Log ([Date],[Thread],[Level],[Logger],[Message]) VALUES (@log_date, @thread, @log_level, @logger, @message)"/>
			<parameter>
				<parameterName value="@log_date"/>
				<dbType value="DateTime"/>
				<!-- 
				<layout type="log4net.Layout.PatternLayout">
					<conversionPattern value="%date{yyyy'-'MM'-'dd HH':'mm':'ss'.'fff}" />
				</layout> 
				-->
				<layout type="log4net.Layout.RawTimeStampLayout"/>
			</parameter>
			<parameter>
				<parameterName value="@thread"/>
				<dbType value="String"/>
				<size value="255"/>
				<layout type="log4net.Layout.PatternLayout">
					<conversionPattern value="%thread"/>
				</layout>
			</parameter>
			<parameter>
				<parameterName value="@log_level"/>
				<dbType value="String"/>
				<size value="50"/>
				<layout type="log4net.Layout.PatternLayout">
					<conversionPattern value="%level"/>
				</layout>
			</parameter>
			<parameter>
				<parameterName value="@logger"/>
				<dbType value="String"/>
				<size value="255"/>
				<layout type="log4net.Layout.PatternLayout">
					<conversionPattern value="%logger"/>
				</layout>
			</parameter>
			<parameter>
				<parameterName value="@message"/>
				<dbType value="String"/>
				<size value="4000"/>
				<layout type="log4net.Layout.PatternLayout">
					<conversionPattern value="%message"/>
				</layout>
			</parameter>
		</appender>
		<!-- Настройте корневую категорию, добавьте appenders и установите уровень по умолчанию, вданном случае WARN -->
		<!-- Бывает, что в живой системе таких предупреждений генерируется много, тогда для сокращения лога можно поставить ERROR  -->
		<root>
			<level value="WARN"/>
			<appender-ref ref="LogFileAppender"/>
			<appender-ref ref="ConsoleAppender"/>
			<!-- <appender-ref ref="ADONetAppender_SqlServer" /> -->
			<appender-ref ref="NetSendAppender"/>
			<!-- <appender-ref ref="A" /> -->
		</root>
		<!-- Укажите уровень для некоторых конкретных категорий -->
		<logger name="ConsoleApp.LoggingExample">
			<!-- <appender-ref ref="B" /> -->
			<level value="ALL"/>
			<appender-ref ref="RollingLogFileAppender"/>
		</logger>
	</log4net>
<startup><supportedRuntime version="v4.0" sku=".NETFramework,Version=v4.8"/></startup></configuration>

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

Чаще всего пользователи хотят настроить не только место назначения вывода, но и формат вывода. Это достигается путем связывания макета с приложением. Макет отвечает за форматирование запроса ведения журнала в соответствии с пожеланиями пользователя, тогда как приложение позаботится об отправке форматированного вывода по назначению. PatternLayout, часть стандартного дистрибутива log4net, позволяет пользователю указать формат вывода в соответствии с шаблонами преобразования, подобными printf языка C.

Например, PatternLayout с шаблоном преобразования "%timestamp [%thread] %-5level %logger - %message%newline" выведет что-то вроде (так написано на официальном сайте, хотя это неправда):

176 [main] INFO Com.Foo.Bar - Located nearest gas station.

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

уровень оператора журнала. Четвертое поле — это имя регистратора, связанного с запросом журнала. Текст после «-» — это сообщение инструкции.

А вот стандартный шаблон, который редко кто меняет.

<layout type="log4net.Layout.PatternLayout">

<conversionPattern value="%date [%thread] %-5level %logger [%ndc] - %message%newline" />

</layout>

Допустим модернизировали шаблон следующим образом:

  <layout type="log4net.Layout.PatternLayout">       <conversionPattern value="%-5p %d{MM-dd hh:mm:ss.ffff} [%thread] %m%n" /> </layout>   

давайте объясним приведенный выше макет: записываем уровень (%p), текущую дату и время (%d), номер потока (%thread), сообщение (%m) и новую строку (%n). «-5» в «%-5p» означает, что ширина поля равна 5 символам.

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

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

Ну вот как такое можно назвать?

<connectionString value="data source=SQLSVR;initial catalog=test_log4net;integrated security=false;persist security info=True;User ID=sa;Password=sa"/>

Методов зашифровать это безобразие не нашел, подскажите пожалуйста если недоглядел?

Разумеется, все, о чем здесь говорилось, это только вершинка айсберга, log4net умеет еще очень много всего.

Спорным является вопрос стоит ли использовать этот инструмент в новых проектах?

Спасибо за внимание, буду благодарен за конструктивную критику.

Вот несколько ссылок на источники информации для этой статьи:

Орберг Николай

ведущий специалист департамента информационных сервисов

Теги:
Хабы:
0
Комментарии5

Публикации

Истории

Работа

Ближайшие события

Weekend Offer в AliExpress
Дата20 – 21 апреля
Время10:00 – 20:00
Место
Онлайн
Конференция «Я.Железо»
Дата18 мая
Время14:00 – 23:59
Место
МоскваОнлайн