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


В настоящее время DiagnosticSource уже используется в AspNetCore, EntityFrameworkCore, HttpClient и SqlClient — каждый из них отправляет собственные события, которые могут быть перехвачены и обработаны.


В этой статье я хочу рассмотреть несколько примеров того, как можно на практике использовать DiagnosticSource в приложениях ASP.NET Core.


  • CorrelationID и пробрасывание заголовков между сервисами
  • Сбор метрик и трассировок
  • Логирование

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


Существующие события


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


Поэтому самый простой способ понять, какие события существуют — создать класс, реализующий интерфейсы IObserver<DiagnosticListener> и IObserver<KeyValuePair<string, object>>, подписаться в нём на любые экземпляры DiagnosticListener и посмотреть, какие события будут перехватываться в приложении. Таким же способом можно определить параметры, передаваемые с каждым событием.


Чтобы упростить вам задачу, я уже собрал некоторые наиболее полезные события (это далеко не полный список) для четырёх компонентов:


Microsoft.AspNetCore

События компонента Microsoft.AspNetCore позволяют перехватывать события жизненного цикла обработки http запроса в ASP.NET Core.


  • Microsoft.AspNetCore.Hosting.HttpRequestIn.Start
  • Microsoft.AspNetCore.Hosting.HttpRequestIn.Stop

Эти события происходят самом начале и самом конце обработки http запроса.


  • Microsoft.AspNetCore.Diagnostics.UnhandledException

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


  • Microsoft.AspNetCore.Mvc.BeforeAction
  • Microsoft.AspNetCore.Mvc.AfterAction

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


  • Microsoft.AspNetCore.Mvc.BeforeOnAuthorization
  • Microsoft.AspNetCore.Mvc.AfterOnAuthorization

Происходят до и после авторизации.


  • Microsoft.AspNetCore.Mvc.BeforeActionMethod
  • Microsoft.AspNetCore.Mvc.AfterActionMethod

Происходят до и после выполнения метода контроллера.


  • Microsoft.AspNetCore.Mvc.BeforeActionResult
  • Microsoft.AspNetCore.Mvc.AfterActionResult

Происходят до и после вызова ExecuteResultAsync у экземпляра IActionResult, который был возвращён из метода контроллера. Сюда, например, может входить сериализация результата в json.


  • Microsoft.AspNetCore.Mvc.BeforeHandlerMethod
  • Microsoft.AspNetCore.Mvc.AfterHandlerMethod

Используются в ASP.NET Pages. Происходят до и после выполнения метода модели страницы.


  • Microsoft.AspNetCore.Mvc.BeforeView
  • Microsoft.AspNetCore.Mvc.AfterView

Происходят до и после рендеринга представления.


Microsoft.EntityFrameworkCore

События компонента Microsoft.EntityFrameworkCore позволяют перехватывать события обращения к базе данных через EntityFrameworkCore.


  • Microsoft.EntityFrameworkCore.Infrastructure.ContextInitialized
  • Microsoft.EntityFrameworkCore.Infrastructure.ContextDisposed

Происходят до и после использования экземпляра DbContext


  • Microsoft.EntityFrameworkCore.Database.Connection.ConnectionOpening
  • Microsoft.EntityFrameworkCore.Database.Connection.ConnectionOpened
  • Microsoft.EntityFrameworkCore.Database.Connection.ConnectionError

Происходят до и после открытия подключения к базе данных. Если подключение было успешно открыто, происходит событие ConnectionOpened. Если при открытии подключения возникла ошибка, происходит событие ConnectionError.


  • Microsoft.EntityFrameworkCore.Database.Connection.ConnectionClosing
  • Microsoft.EntityFrameworkCore.Database.Connection.ConnectionClosed
  • Microsoft.EntityFrameworkCore.Database.Connection.ConnectionError

Аналогично происходят до и после закрытия подключения к базе данных.


  • Microsoft.EntityFrameworkCore.Database.Command.CommandExecuting
  • Microsoft.EntityFrameworkCore.Database.Command.CommandExecuted
  • Microsoft.EntityFrameworkCore.Database.Command.CommandError

Аналогично происходят до и после выполнения запроса к базе данных.


  • Microsoft.EntityFrameworkCore.Database.Command.DataReaderDisposing

Происходит после завершения чтения из экземпляра DbDataReader.


SqlClientDiagnosticListener

События компонента SqlClientDiagnosticListener позволяют перехватывать события обращения к базе данных SQL Server через соответствующий ADO.NET провайдер.


  • System.Data.SqlClient.WriteConnectionOpenBefore
  • System.Data.SqlClient.WriteConnectionOpenAfter
  • System.Data.SqlClient.WriteConnectionOpenError

Происходят до и после открытия подключения к базе данных. Если подключение было успешно открыто, происходит событие WriteConnectionOpenAfter. Если при открытии подключения возникла ошибка, происходит событие WriteConnectionOpenError.


  • System.Data.SqlClient.WriteConnectionCloseBefore
  • System.Data.SqlClient.WriteConnectionCloseAfter
  • System.Data.SqlClient.WriteConnectionCloseError

Аналогично происходят до и после закрытия подключения к базе данных.


  • System.Data.SqlClient.WriteCommandBefore
  • System.Data.SqlClient.WriteCommandAfter
  • System.Data.SqlClient.WriteCommandError

Аналогично происходят до и после выполнения запроса к базе данных.


HttpHandlerDiagnosticListener

События компонента HttpHandlerDiagnosticListener позволяют перехватывать исходящие http запросы, например, при использовании класса HttpClient.


  • System.Net.Http.HttpRequestOut.Start
  • System.Net.Http.HttpRequestOut.Stop

Происходят до и после исходящего http запроса.


  • System.Net.Http.Exception

Происходит, если при исходящем http запроса возникла ошибка.


Кстати, существует даже DiagnosticSource User's Guide, в котором описаны рекомендации и соглашения по именованию событий для DiagnosticSource.


Как можно легко догадаться, Microsoft не следует этим рекомендациям и делает всё наоборот =) (Ладно, я преувеличиваю. Просто DiagnosticSource начал использоваться в компонентах .NET Core раньше, чем появился DiagnosticSource User's Guide)


Общий код


Предполагается, что все примеры, которые я буду рассматривать ниже, будут использоваться в приложении ASP.NET Core (хотя это не обязательно), и будут использовать базовый класс DiagnosticObserverBase для подписки на события от DiagnosticSource и их обработки.


Этот класс основан на классе ExampleDiagnosticObserver из моей предыдущей статьи, где можно найти описание его работы. Для подписки и обработки событий этот класс будет использовать метод SubscribeWithAdapter из NuGet пакета Microsoft.Extensions.DiagnosticAdapter.


public abstract class DiagnosticObserverBase : IObserver<DiagnosticListener>
{
    private readonly List<IDisposable> _subscriptions = new List<IDisposable>();

    protected abstract bool IsMatch(string name);

    void IObserver<DiagnosticListener>.OnNext(DiagnosticListener diagnosticListener)
    {
        if (IsMatch(diagnosticListener.Name))
        {
            var subscription = diagnosticListener.SubscribeWithAdapter(this);
            _subscriptions.Add(subscription);
        }
    }

    void IObserver<DiagnosticListener>.OnError(Exception error)
    { }

    void IObserver<DiagnosticListener>.OnCompleted()
    {
        _subscriptions.ForEach(x => x.Dispose());
        _subscriptions.Clear();
    }
}

Чтобы подписаться на события от определённых компонентов, необходимо создать новый класс, унаследовать его от DiagnosticObserverBase, переопределить метод IsMatch, чтобы он возвращал true для тех компонентов, на которые мы хотим подписаться, добавить методы для обработки событий и пометить их атрибутами DiagnosticNameAttribute, где указать название обрабатываемого события. Например:


public sealed class SomeDiagnosticObserver : DiagnosticObserverBase
{
    protected override bool IsMatch(string name)
    {
        return name == "SomeComponent";
    }

    [DiagnosticName("SomeEvent")]
    public void OnSomeEvent(/* EventParameters */)
    {
        // ...
    }
}

Для того, чтобы зарегистрировать в DI контейнере обработчики, основанные на классе DiagnosticObserverBase, мы воспользуемся методом-расширением AddDiagnosticObserver, которое будет использовать в методе ConfigureServices в файле Startup.cs:


public static class DiagnosticServiceCollectionExtensions
{
    public static void AddDiagnosticObserver<TDiagnosticObserver>(
        this IServiceCollection services)
        where TDiagnosticObserver : DiagnosticObserverBase
    {
        services.TryAddEnumerable(ServiceDescriptor
            .Transient<DiagnosticObserverBase, TDiagnosticObserver>());
    }
}

А для того, чтобы подписаться на события от DiagnosticSource, добавим в метод Configure следующие строки:


public void Configure(IApplicationBuilder app, IHostingEnvironment env)
{
    var diagnosticObservers = app
        .ApplicationServices.GetServices<DiagnosticObserverBase>();
    foreach (var diagnosticObserver in diagnosticObservers)
    {
        DiagnosticListener.AllListeners.Subscribe(diagnosticObserver);
    }

    // ...

    app.UseMvc();
}

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


Некоторые подводные камни


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


Иногда могут потребоваться фиктивные обработчики для несуществующих событий


Обычно, если какой-то компонент отправляет события о свой работе, код отправки события выглядит следующим образом:


if (_diagnosticSource.IsEnabled("SomeEvent"))
    _diagnosticSource.Write("SomeEvent", new { /* parameters */ });

Это позволяет не создавать объект с параметрами, если событие никто не собирается обрабатывать, и немного сэкономить на сборке мусора.


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


 // События нет, но подписка на него проверяется.
var someEventIsEnabled = _diagnosticSource.IsEnabled("SomeEvent");

if (someEventIsEnabled && _diagnosticSource.IsEnabled("SomeEvent.Start"))
    _diagnosticSource.Write("SomeEvent.Start", new { /* parameters */ });

// ...

if (someEventIsEnabled && _diagnosticSource.IsEnabled("SomeEvent.Stop"))
    _diagnosticSource.Write("SomeEvent.Stop", new { /* parameters */ });

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


Некоторые события парные, а некоторые тройные


Некоторые события являются парными, например System.Net.Http.HttpRequestOut.Start и System.Net.Http.HttpRequestOut.Stop. Это означает, что событие с суффиксом .Start будет вызвано до начала какой-то операции, а событие с суффиксом .Stop — в конце. При этом последнее событие будет гарантированно вызвано (если есть соответствующие обработчики) вне зависимости от того, закончилась ли операция ошибкой или нет.


Однако, некоторые события являются тройными, например System.Data.SqlClient.WriteCommandBefore, System.Data.SqlClient.WriteCommandAfter и System.Data.SqlClient.WriteCommandError, где последнее событие зависит от результата опреации. В этом случае, если операция была завершена успешно, будет вызвано только событие System.Data.SqlClient.WriteCommandAfter, а если во время операции возникла ошибка — только событие System.Data.SqlClient.WriteCommandError.


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


Примеры использования DiagnosticSource


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


CorrelationID и пробрасывание заголовков между сервисами


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


Для ASP.NET Core существует NuGet пакет CorrelationId, однако он требует того, чтобы разработчики вручную добавляли соответствующий заголовок во все исходящие запросы, поэтому не очень удобен в использовании.


Реализуем CorrelationId через DiagnosticSource. Для начала, добавим класс CorrelationId который будет отвечать за хранение нашего идентификатора:


public static class CorrelationId
{
    private static readonly AsyncLocal<Guid?> _current = new AsyncLocal<Guid?>();

    public static Guid Current
    {
        get
        {
            var value = _current.Value;
            if (value == null)
                throw new InvalidOperationException("CorrelationId isn't assigned.");

            return value.Value;
        }

        set { _current.Value = value; }
    }
}

Этот класс использует экземпляр типа AsyncLocal<T> для хранения текущего значения CorrelationId, которое будет уникально для каждого запроса, но при этом будет корректно передаваться от одного потока из ThreadPool к другому при работе с асинхронным кодом.


Следующим шагом добавим обработчик событий от DiagnosticSource, который будет перехватывать входящие и исходящие http запросы. Во входящих запросах мы будем проверять наличие заголовка X-Correlation-ID и, если его нет будем генерировать новый идентификатор через Guid.NewGuid(). В исходящих запросах мы будем просто добавлять заголовок, используя CorrelationId.Current.


public sealed class CorrelationIdHandler : DiagnosticObserverBase
{
    protected override bool IsMatch(string name)
    {
        return name == "Microsoft.AspNetCore"
            || name == "HttpHandlerDiagnosticListener";
    }

    // Обработка входящих http запросов

    [DiagnosticName("Microsoft.AspNetCore.Hosting.HttpRequestIn")]
    public void OnHttpRequestIn()
    { }

    [DiagnosticName("Microsoft.AspNetCore.Hosting.HttpRequestIn.Start")]
    public void OnHttpRequestInStart(HttpContext httpContext)
    {
        // Пробуем получить текущий CorrelationId из заголовков текущего http запроса.
        var headers = httpContext.Request.Headers;
        if (headers.TryGetValue("X-Correlation-ID", out var header))
        {
            if (Guid.TryParse(header, out var correlationId))
            {
                CorrelationId.Current = correlationId;
                return;
            }
        }

        // Или создаём новый CorrelationId.
        CorrelationId.Current = Guid.NewGuid();
    }

    // Обработка исходящих http запросов

    [DiagnosticName("System.Net.Http.HttpRequestOut")]
    public void OnHttpRequestOut()
    { }

    [DiagnosticName("System.Net.Http.HttpRequestOut.Start")]
    public void OnHttpRequestOutStart(HttpRequestMessage request)
    {
        // Добавляем во все исходящие http запросы заголовок с CorrelationId
        var correlationId = CorrelationId.Current.ToString();
        request.Headers.Add("X-Correlation-ID", correlationId);
    }
}

В этом классе в методе IsMatch мы сообщаем, что хотим обрабатывать события от компонентов Microsoft.AspNetCore (отвечает за входящие http запросы) и HttpHandlerDiagnosticListener (отвечает за исходящие http запросы). Непосредственная обработка заголовков происходит в методах OnHttpRequestInStart и OnHttpRequestOutStart.


Кроме этого нам пришлось добавить два фиктивных метода OnHttpRequestIn и OnHttpRequestOut. Они не будут вызываться при обработке, но используются для определения того, нужно ли вызывать пару обработчиков Start и Stop. Без них эти события не будут вызваны.


Осталось только зарегистрировать наш обработчик в файле Startup.cs:


services.AddDiagnosticObserver<CorrelationIdHandler>();

На практике бывает также полезно пробрасывать не один, а несколько заголовков с определённым префиксом (например "X-Api-"), реализуя тем самым так называемый Context Propagation. Этот механизм позволяет задать значение с определённым ключом в одном сервисе и прочитать в другом, не передавая это значение явно через тело запроса. Подобный механизм можно легко реализовать на базе описанного выше класса CorrelationIdHandler.


Сбор метрик и трассировок


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


Мы в OZON.ru для сбора метрик используем Prometheus и, для ASP.NET Core сервисов, NuGet пакет Prometheus.Client.AspNetCore.


Для сбора трассировок мы используем OpenTracing и Jaeger. (При желании вы можете посмотреть мой доклад "Использование OpenTracing в .NET" с DotNetMsk Meetut #30)


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


К счастью, большинство компонентов, отдающих события через DiagnosticSource, отдают парные события, первое из которых обозначает начало определённой операции, а второе — её завершение. Это позволяет, например, сначала запустить секундомер, а после остановить его и отдать определённую метрику.


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


public sealed class AspNetCoreMetricsHandler : DiagnosticObserverBase
{
    private readonly Histogram requestDurationSeconds;

    public MetricsHandler(MetricFactory metricFactory)
    {
        // Создаём метрику, используя NuGet пакет Prometheus.Client.
        // Метки помогут различать время выполнения по каждому действию.
        requestDurationSeconds = metricFactory.CreateHistogram(
            "request_duration_seconds", "",
            labelNames: new[] {"action_name"});
    }

    protected override bool IsMatch(string name)
    {
        return name == "Microsoft.AspNetCore";
    }

    [DiagnosticName("Microsoft.AspNetCore.Hosting.HttpRequestIn")]
    public void OnHttpRequestIn()
    { }

    [DiagnosticName("Microsoft.AspNetCore.Hosting.HttpRequestIn.Start")]
    public void OnHttpRequestInStart(HttpContext httpContext)
    {
        // В самом начале обработки http запроса запускаем секундомер.
        httpContext.Items["Stopwatch"] = Stopwatch.StartNew();
    }

    [DiagnosticName("Microsoft.AspNetCore.Mvc.BeforeAction")]
    public void OnBeforeAction(HttpContext httpContext, ActionDescriptor actionDescriptor)
    {
        // Дополнительно запоминаем действие контроллера,
        // которое использовалось для обработки запроса.
        httpContext.Items["ActionName"] = actionDescriptor.DisplayName;
    }

    [DiagnosticName("Microsoft.AspNetCore.Hosting.HttpRequestIn.Stop")]
    public void OnHttpRequestInStop(HttpContext httpContext)
    {
        // В самом конце обработки http запроса останавливаем секундомер
        // и отдаём метрику по вызванному действию.

        if (!httpContext.Items.TryGetValue("Stopwatch", out object stopwatch))
            return;

        if (!httpContext.Items.TryGetValue("ActionName", out object actionName))
            actionName = "Unknown";

        var duration = ((Stopwatch) stopwatch).Elapsed.TotalSeconds;

        requestDurationSeconds
            .WithLabels(actionName.ToString())
            .Observe(duration);
    }
}

Здесь мы в конструкторе объявляем метрику типа "Гистограмма" из NuGet пакета Prometheus.Client. Этой метрике мы добавляем метку "action_name", которая позволит отличать метрики, собранные в разных действиях контроллеров.


В начале обработки событий (метод OnHttpRequestInStart) мы запускаем секундомер, чтобы измерить время выполнения запроса. Также мы запоминаем название обрабатываемого действия (метод OnBeforeAction). И наконец после обработки запроса (метод OnHttpRequestInStop) снова получаем все данные из коллекции httpContext.Items и записываем их в метрику.


Осталось только зарегистрировать наш обработчик и экземпляр MetricFactory в файле Startup.cs:


services.AddSingleton(Prometheus.Client.Metrics.DefaultFactory);
services.AddDiagnosticObserver<AspNetCoreMetricsHandler>();

Похожая техника может использоваться и при сборе трассировок с использованием NuGet пакета OpenTracing.


Логирование


Ещё одно очень полезное применение DiagnosticSource — логирование исключений. Но может возникнуть вопрос: "Зачем это нужно?". Ведь можно просто обернуть свой код в блок try-catch или вообще настроить один глобальный обработчик для всех необработанных исключений.


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


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


public sealed class SqlClientLoggingHandler : DiagnosticObserverBase
{
    private readonly ILogger<SqlClientLoggingHandler> _logger;

    public SqlClientLoggingHandler(ILogger<SqlClientLoggingHandler> logger)
    {
        _logger = logger;
    }

    protected override bool IsMatch(string name)
    {
        return name == "SqlClientDiagnosticListener";
    }

    [DiagnosticName("System.Data.SqlClient.WriteCommandError")]
    public void OnCommandError(DbCommand command, Exception exception)
    {
        var sb = new StringBuilder();
        sb.AppendLine("Command: " + command.CommandText);

        if (command.Parameters.Count > 0)
        {
            sb.AppendLine("Parameters: ");

            foreach (DbParameter parameter in command.Parameters)
            {
                sb.AppendLine($"\t{parameter.ParameterName}: {parameter.Value}");
            }
        }

        _logger.LogError(exception, sb.ToString());
    }
}

В методе IsMatch мы указываем, что хотим обрабатывать события от компонента SqlClientDiagnosticListener, а в методе OnCommandError формируем сообщения с телом запроса и параметрами и записываем его в лог.


Зарегистрировать наш обработчик исключений в файле Startup.cs можно следующим образом:


services.AddDiagnosticObserver<SqlClientLoggingHandler>();

Заключение


В этой статье я рассмотрел практические примеры использования DiagnosticSource. Возможно, достаточно поверхностно, но этого достаточно для общего понимания того, что представляет собой DiagnosticSource, какие возможности он предоставляет и как его его можно использовать в приложениях на ASP.NET Core.


Мы в OZON.ru активно используем этот механизм в наших сервисах для решения похожих задач. Это позволяет, буквально подключив один NuGet пакет и написав одну строчку кода, получить автоматический сбор метрик с приложений, мониторинг и многое другое.


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

Комментарии (11)


  1. RomanPokrovskij
    30.01.2019 01:35

    Я правильно понял что вы при помощи CorrelationId решаете проблему «сопоставления логов» только для «пользовательских сообщений» микросервисов? А связать SqlClient и HttpClient события публикуемые в DiagnosticSource порожденные «одним конкретным запросом одного конкретного юзера» возможности нет, это невозможно. Т.е. невозможно SqlClient и HttpClient задать CorrelationId и сказать — вот с ним и публикуй в этом потоке и во всех порожденных?


    1. Ordos Автор
      30.01.2019 08:02
      +1

      Возможно я не совсем правильно понял ваш вопрос.


      Связать события публикуемые в DiagnosticSource порожденные «одним конкретным запросом одного конкретного юзера» — как раз таки это и делается в примере с CorrelationId. Т.е. когда в сервис приходит запрос, он помечается CorrelationId (либо через заголовок, либо генерируется новый). Этот CorrelationId доступен через статическое свойство, его можно получить где угодно и он будет отличаться для разных запросов разных пользователей, но будет одинаковый в рамках одного запроса одного пользователя.


      И я не понял про «сопоставления логов» только для «пользовательских сообщений» микросервисов. Что понимается под "только пользовательскими сообщениями". Если поясните на примере, то постараюсь более внятно ответить =)


      1. RomanPokrovskij
        30.01.2019 13:28

        Спасибо. Я рассуждаю так. SqlClient публикует события и мы очень хотим чтобы он публиковал их с CorrelationId. Но SqlClient писали не мы а MS как же он будет публиковать события с CorrelationId если в нем этой публикации просто нет — он публикует вообще все события процесса. Можно поставить фильтр на этот поток из «всех событий» что-то типа`if(CorrelationId.Current == thisHttpContext.Request.CorrelationId) log(...)` но я такого когда у вас не нашел (извиняюсь заранее, частенько у меня «тунелька»).

        Про микросервисы — вы с них начали и вот в них с ними как раз все ясно — это наш код, что хотим то и публикуем. Решили публиковать все наши события с CorrelationId — берем и публкуем — и мы красавчики.


        1. Ordos Автор
          30.01.2019 13:49
          +1

          SqlClient само собой публикует события только с теми параметрами, которые у него есть. Но в обработчике мы можем получить доступ куда угодно, хоть к CorrelationId, хоть к IHttpContextAccessor (через конструктор заинжектить) и там уже можно придумать любую логику.


          Зависит от задачи, которую вы хотели бы решить.


          1. RomanPokrovskij
            30.01.2019 14:43

            Спасибо, это я и имел ввиду говоря «можно поставить фильтр». Но хотелось бы код увидеть. Он наверняка есть на я на GitHub Prometheus но я сходу не нашел.

            Я не нашел чтобы github.com/stevejgordon/CorrelationId как-то решал это и вообще как-то взаимодействовал с DiagnosticSource поэтому вообще не очень понимаю почему он в одном ряду был приведен. Добавляет токены в хеадер это немного другая задача…

            Задачу можно поставить так: c HttpRequest пришел Header c X-CorrelationId и если имя юзера выславшего request = «Test» надо логить все порожденные этим HttpRequest'ом и только им события SqlClient и HttpClinet, и логить с данным X-CorrelationId.


            1. Ordos Автор
              30.01.2019 14:50
              +1

              github.com/stevejgordon/CorrelationId никак не связан с DiagnosticSource. Я просто привёл альтернативную реализацию этого механизма (CorrelationId) через DiagnosticSource.

              Ну вот как раз эту задачу вы можете решить через DiagnosticSource. Нужно сделать наблюдатель, который на входящем http запросе будет проверять необходимость логирования через httpcontext. А на остальных событиях от SqlClient и HttpClinet нужно проверять этот признак и делать логирование. Если я правильно понял.


              1. RomanPokrovskij
                30.01.2019 16:16

                Наконец понял вашу задачу а заодно и при чем github.com/stevejgordon/CorrelationId. Действительно «тунелька», думал вы решаете туже задачу что и я. Спасибо за терпение.

                Да ваша статья показывает что можно решить и мою задачу, но один риск виден: как поведут себя множественные обсерверы ведь на каждый request от «тестеровщика» я бы создавал свой обсервер (и инжектирвала его значеним CorrelationId при этом в потоке реквеста назначал и AsyncLocal<Guid?> далее решая логить или нет сравнивая ижектированное значение с полученным от AsyncLocal<Guid?>) а после окончания requestа убирал бы.

                И еще же остается неопределенным насколько гарантировано что все обсерверы во всех конфигурациях и для всех NnnClient работают правильно с AsyncLocal<Guid?> — это установленно эмпирически как я понимаю, в документации ничего об этом нет? Ведь чисто теоритически контекст исполнения метода обсервара может быть совсем «оторванным» таким что AsyncLocal<Guid?> вернет null.


                1. Ordos Автор
                  30.01.2019 16:34

                  Каждый обсервер — синглтон, он создаётся один раз на старте приложения, подписывается на DiagnosticListerer.AllListeners, получает и обрабатывает все события.


                  AsyncLocal<T> это просто класс, который умеет хранить состояние в асинхронном коде (в логическом потоке выполнения, который реально может обрабатываться разными потоками).


                  Если в начале обработки http запроса установить значение в AsyncLocal, то его можно прочитать где угодно из этого же экземпляра до окончания http запроса. Для разных (параллельно выполняющихся) http запросов это значение будет своё.


                  1. RomanPokrovskij
                    30.01.2019 16:49

                    «Каждый обсервер — синглтон… на старте приложения»
                    ну это же не обязательно, по крайей мере я ожидаю от архитектруы что скорее всего можно когда хочу тогда и создаю и убираю, вель тоже самое можно и с EFCore LoggerFactory (для реквеста нужного юзера создал вребозе LoggerFactory и убрал с окончанием реквеста — это реализовано stackoverflow.com/questions/43680174/entity-framework-core-log-queries-for-a-single-db-context-instance/47490737#47490737 ).

                    Для разных (параллельно выполняющихся) http запросов это значение будет своё
                    это да, можно ожидать от обсервера, но не факт со всеми NnnClient'ами. Я просто примерно представляю как можно написать код который выполнется в том же логическом потоке но ломает `AsyncLocal` и хотелось бы гарантий документации что вызов «методов обсервера» происходит так что `AsyncLocal` «не ломается». Ну ладно это такое.

                    Спасибо за идеи.


                    1. Ordos Автор
                      30.01.2019 19:16

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


                      1. RomanPokrovskij
                        30.01.2019 19:29

                        Да вы правы можно и синглтоном обойтись все равно за AsyncLocal ходить. И даже не correlatioId получать из AsyncLocal а функцию лога (делегат). Если null — то и не логишь. А устанавливать делегат только для юзеров-тестеров. Надо пробовать.