Вводная

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

В первой статье (IoC-контейнер) мы поговорили про то, почему это круто — иметь реализацию DI-контейнера по умолчанию, и почему в большинстве случаев стоит использовать именно его. Также написали простую реализацию биндинга по атрибутам.

Во второй (Конфигурация) я рассказал про недостатки старого способа конфигурирования приложения (через app.config/web.config) и про то, как они исправлены в новом подходе.

В этой — третьей — посмотрим на стандартный интерфейс логирования и прикрутим к нему привычный NLog.

Далее следует план статей по очереди их публикации. Все статьи доступны в нашем блоге.

План

  1. IoC-контейнер.
  2. Конфигурация.
  3. Логирование.

Текущая статья посвящена третьей теме плана — Логирование.

Логирование

Зачем вообще новый инструмент для логирования?

У нас уже есть NLog, log4net, Serilog. Все это замечательные инструменты, но очень грустно, когда в большом решении встречаются они все. Тогда приходится либо переводить все на один, либо впиливать какую-то абстракцию. Еще не очень хорошо использовать конкретное решение без прослойки в распространяемой библиотеке, потому что это опять приведет конечных потребителей к необходимости использовать ваш инструмент (а они уже могут использовать другой).

У нас уже есть Common.Logging, если мы хотим отвязаться от конкретного инструмента (например, в библиотеках).  Common.Logging — это, конечно, хорошо, но не факт, что конечные потребители вашей библиотеки захотят его использовать. Еще большой минус, что вы не будете использовать Common.Logging по умолчанию везде, гораздо чаще просто возьмете NLog и забудете о проблеме, пока она не всплывет.

Microsoft.Extensions.Logging отлично решает эти проблемы. Это такой Common.Logging, который используется по умолчанию в Core приложениях, что приводит нас к тому, что мы точно будем использовать этот способ. Теперь не абстракция подстраивается под инструменты (как Common.Logging), а инструмент под абстракцию.

Посмотрим, как это работает. Создадим консольное приложение .NET Core и установим пакеты:

Install-Package Microsoft.Extensions.Logging
Install-Package Microsoft.Extensions.Logging.Console
Install-Package Microsoft.Extensions.Logging.Debug

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

static void Main(string[] args)
{
    var loggerFactory = new LoggerFactory()
            .AddConsole((log, logLevel) => true)
            .AddDebug(LogLevel.Debug);
    var logger = loggerFactory.CreateLogger<Program>();
    logger.LogTrace("Test trace");
    logger.LogDebug("Test debug");
    logger.LogInformation("Test info");
    Console.ReadLine();
}

Здесь мы используем самый простой способ инициализации и использования логирования.
Сначала создается фабрика логов LoggerFactory. Затем добавляются провайдеры через методы-расширения AddConsole (вывод на консоль) и AddDebug (вывод в отладочную консоль). Параметры задают предикат записи логов в провайдер. В случае AddConsole мы передали лямбду, которая принимает строку сообщения и уровень протоколирования, а возвращает bool. В AddDebug — передали минимально возможный уровень. В выводе консоли отладки увидим:

Logging.Program:Debug: Test debug
Logging.Program:Information: Test info

В консоль выведется:

Все правильно, для консоли пишем все, для отладки — только Debug и выше

AddConsole и AddDebug — это просто обертки над void AddProvider(ILoggerProvider provider), который добавляет провайдер к этой фабрике логгеров. Соответственно, мы можем добавить консольный логгер следующим образом:

loggerFactory.AddProvider(new ConsoleLoggerProvider((s, level) => true, true));

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

Еще стоит упомянуть такую вещь, как Scopes. Они позволяют лучше привязать логирование к бизнес-задачам. Как пример, напишем такую программу:

static void Main(string[] args)
{
    var loggerFactory = new LoggerFactory().AddConsole(true);
    var logger = loggerFactory.CreateLogger<Program>();
    logger.LogInformation("Not in scope");
    using (logger.BeginScope("outer"))
    {
        logger.LogInformation("On outer scope");
        using (logger.BeginScope("inner"))
        {
            loggerFactory.CreateLogger("123").LogInformation("On inner scope another logger");
            logger.LogInformation("On inner scope");
        }
    }
    Console.ReadLine();
}

Вывод на консоль будет таким:

Видно, что скоупы влияют на вывод, причем влияют на все логгеры.

Теперь попробуем прикрутить NLog в ASP.NET Core-приложение. Для начала создадим проект  по шаблону «Web-приложение ASP.NET Core», «Пустой».

На момент написания статьи NLog для .NET Core находится в бете, поэтому ставим следующей командой:

Install-Package NLog -Pre

После этого поставим пакет NLog.Web.AspNetCore, который содержит рендереры для веб-приложений.

Install-Package NLog.Web.AspNetCore

Создадим в корне проекта файл NLog.config и выставим ему правило копирования в выходной каталог — Всегда копировать. Содержимое файла:

 <?xml version="1.0" encoding="utf-8"?>

<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
 internalLogFile="C:/tmp/LogsTests/WebInternalLog.txt"
 autoReload="true">

 <extensions>
 <add assembly="NLog.Web.AspNetCore"/>
 </extensions>
 
 <variable name="logDirectory" value="C:/tmp/LogsTests" />

 <targets>
 <target xsi:type="File" name="allfile" fileName="${logDirectory}/log.txt"
 encoding="UTF-8"
 autoFlush="false"
 layout="${longdate:universalTime=true}|${event-properties:item=EventId.Id}|${uppercase:${level}}|${logger}| ${message} ${exception}|url: ${aspnet-request-url}|action: ${aspnet-mvc-action}|TraceIdentifier: ${aspnet-TraceIdentifier}" />
 </targets>

 <rules>
 <logger name="*" minlevel="Trace" maxlevel="Fatal" writeTo="allfile" />
 </rules>
</nlog>

В layout мы использовали несколько ASP.NET-специфичных рендереров — например,
${aspnet-request-url}
, для отображения URL запроса.

Теперь изменим наш Startup.cs, добавив туда поддержку NLog.

В метод ConfigureServices добавим:

 services.AddSingleton<IHttpContextAccessor, HttpContextAccessor>();

Это позволит нам инжектить IHttpContextAccessor в singleton-сервисы и иметь доступ к текущему HttpContext.

А в метод Configure добавим следующее:

 app.AddNLogWeb();
 loggerFactory.AddNLog();

Метод
AddNLogWeb
 сохраняет в статическую переменную DI-контейнер (ServiceProvider), из которого NLog будет доставать требуемые ему вещи (например, тот же IHttpContextAccessor).


loggerFactory.AddNlog
 — добавляет провайдер Nlog-а

После запуска приложения и выполнения любого запроса мы увидим в нашем файле строки, типа такой:

 2017-08-07 09:43:47.0065|1|INFO|Microsoft.AspNetCore.Hosting.Internal.WebHost|  Request starting HTTP/1.1 DEBUG http://localhost:51069/  0 |url: http://localhost/|action: |TraceIdentifier: 0HL6TF36F15T9

Здесь мы видим все, что требуется для понимания, какой это был запрос.

Сами логгеры органично встроены в инфраструктуру ASP.NET Core — вы можете инжектить ILogger<T> в любой сервис, и он разрезолвится. Если вы хотите работать как в классических приложениях и создавать логгер руками, то просто сохраните экземпляр ILoggerFactory в статическое поле и дергайте CreateLogger, когда вам захочется. Желательно не создавать статических логгеров, а иметь индивидуальный экземпляр логгера на экземпляр класса.

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

С первой и второй частями цикла можно ознакомиться по ссылкам:

  1. IoC-контейнер — первая часть цикла.
  2. Конфигурация — вторая часть цикла.