How to use diagnosticsource in. Net

Time:2021-1-9

preface

Diagnosticsource is a very interesting and useful API. For these APIs, they allow different libraries to send named events, and they also allow applications to subscribe to these events and process them. It enables our consumers to dynamically discover data sources at runtime and subscribe to their related data sources.

Diagnosticsource is used in aspnetcore, entityframeworkcore, httpclient and SqlClient. In our actual development process, it enables us to intercept HTTP requests, database queries, access to httpcontext, dbconnection, dbcommand, httprequestmessage and other objects, and even modify these pairs when necessary Elephant to deal with our business.

Let’s learn about it with the following simple example

The difference between diagnosticsource and eventsource

Diagnosticsource and eventsource are very similar in architecture design. Their main difference is that eventsource records serializable data, which will be consumed out of process. Therefore, the recorded objects must be serializable. Diagnosticsource is designed to process data in the process, so we can get more abundant data information through it. It supports non serialized objects, such as httpcontext, httpresponsemessage, etc. In addition, if you want to get the event data in diagnosticsource in eventsource, you can bridge the data through diagnosticsourceeventsource.

Here comes the demand

To better understand how diagnosticsource works, the following example will intercept database requests. Suppose we have a simple console application that makes requests to the database and outputs the results to the console.


class Program
{
  public const string ConnectionString =
    @"Server=localhost;Database=master;Trusted_Connection=True;";
  static async Task Main(string[] args)
  {
    var result = await Get();
    Console.WriteLine(result);

  }
  public static async Task<int> Get() {
    using (var connection=new SqlConnection(ConnectionString)) 
    {
      return await connection.QuerySingleAsync<int>("SELECT 42;");
    }
  }
}

Let’s think about it again. Suppose there is a requirement: we need to get the execution time of all database queries, or we need to get some SQL statements or data to be executed and stored as records. What should we do?
Well, next we’ll try to implement this requirement using diagnosticsource.

use System.Diagnostics.DiagnosticSource

Let’s first create a class as the handler or consumer of the event.


public sealed class ExampleDiagnosticObserver
{}

Next, we will handle this event. We need to instantiate this class and register it into the observer in the static object DiagnosticListener.AllListeners , the code is as follows:


static async Task Main(string[] args)
{
  var observer = new ExampleDiagnosticObserver();
  IDisposable subscription = DiagnosticListener.AllListeners.Subscribe(observer);
  var result = await Get();
  Console.WriteLine(result);
}

Next, let’s modify our examplediagnosticobserver class. In fact, in the above code fragment, the compiler has reminded us to implement the interface IObserver < diagnosticslistener >, so let’s implement it


public sealed class ExampleDiagnosticObserver : IObserver<DiagnosticListener>
{
  public void OnCompleted()
  { 
  }

  public void OnError(Exception error)
  { 
  }

  public void OnNext(DiagnosticListener value)
  {
    Console.WriteLine(value.Name);
  }
}

Next, we run the program, and the results will be printed on the console as follows:

SqlClientDiagnosticListener
SqlClientDiagnosticListener
42

Looking at the above results, this means that we have registered two objects of type diagnosticlistener, named sqlclientdiagnosticlistener, somewhere in our current application.

For each instance diagnosticlistener created in the application, the IObserver < diagnosticlistener >. Onnext method will be called once when it is used for the first time. Now we just output the name of the instance to the console, but in the actual situation, let’s think about what we should do for the instance name? Yes, yes, we need to check these instance names. If we want to check some events in this instance, we only need to use the subscribe method to subscribe to it.

Let’s implement IObserver < diagnosticlistener >:


public class ExampleDiagnosticObserver1 : IObserver<DiagnosticListener>,
     IObserver<KeyValuePair<string, object>>
{
  private readonly List<IDisposable> _subscriptions = new List<IDisposable>();

  public void OnCompleted()
  {
  }

  public void OnError(Exception error)
  {
  }

  public void OnNext(KeyValuePair<string, object> value)
  {
    Write(value.Key, value.Value);
  }

  public void OnNext(DiagnosticListener value)
  {
    if (value.Name == "SqlClientDiagnosticListener")
    {
      var subscription = value.Subscribe(this);
      _subscriptions.Add(subscription);
    }
  }

  private void Write(string name, object value)
  {
    Console.WriteLine(name);
    Console.WriteLine(value);
    Console.WriteLine();
  }
}

In the above code fragment, we implement the IObserver < keyvaluepair < string, Object > >. Onnext method of IObserver < keyvaluepair < string, Object > > interface. The parameter is keyvaluepair < string, Object >, where key is the name of the event and value is an anonymous object

The output of the running program is as follows:

System.Data.SqlClient.WriteConnectionOpenBefore
{ OperationId = f5f4d4f0-7aa1-46e6-bd48-78acca3dac0a, Operation = OpenAsync, Connection = System.Data.SqlClient.SqlConnection, Timestamp = 1755845041766 }

System.Data.SqlClient.WriteCommandBefore
{ OperationId = 3d8617d1-0317-4f75-bffd-5b0fddf5cc12, Operation = ExecuteReaderAsync, ConnectionId = 554f4ee4-47c3-44ff-a967-cc343d1d5019, Command = System.Data.SqlClient.SqlCommand }

System.Data.SqlClient.WriteConnectionOpenAfter
{ OperationId = f5f4d4f0-7aa1-46e6-bd48-78acca3dac0a, Operation = OpenAsync, ConnectionId = 554f4ee4-47c3-44ff-a967-cc343d1d5019, Connection = System.Data.SqlClient.SqlConnection, Statistics = System.Data.SqlClient.SqlStatistics+StatisticsDictionary, Timestamp = 1755851869508 }

System.Data.SqlClient.WriteCommandAfter
{ OperationId = 3d8617d1-0317-4f75-bffd-5b0fddf5cc12, Operation = ExecuteReaderAsync, ConnectionId = 554f4ee4-47c3-44ff-a967-cc343d1d5019, Command = System.Data.SqlClient.SqlCommand, Statistics = System.Data.SqlClient.SqlStatistics+StatisticsDictionary, Timestamp = 1755853467664 }

System.Data.SqlClient.WriteConnectionCloseBefore
{ OperationId = ed240163-c43a-4394-aa2d-3fede4b27488, Operation = Close, ConnectionId = 554f4ee4-47c3-44ff-a967-cc343d1d5019, Connection = System.Data.SqlClient.SqlConnection, Statistics = System.Data.SqlClient.SqlStatistics+StatisticsDictionary, Timestamp = 1755854169373 }

System.Data.SqlClient.WriteConnectionCloseAfter
{ OperationId = ed240163-c43a-4394-aa2d-3fede4b27488, Operation = Close, ConnectionId = 554f4ee4-47c3-44ff-a967-cc343d1d5019, Connection = System.Data.SqlClient.SqlConnection, Statistics = System.Data.SqlClient.SqlStatistics+StatisticsDictionary, Timestamp = 1755854291040 }

42

From the above results, we can clearly see that there are six events. We can see that two are executed before and after opening the database, two are executed before and after executing the command, and two are executed before and after closing the database connection.

In addition, we can see that each event contains a set of parameters, such as operationid, operation, connectionid, etc. these parameters are usually transmitted as anonymous object properties. We can get the typed values of these properties through reflection.

Now that we have solved our initial requirements, we need to obtain the execution time of all queries in the database and output them to the console. We need to modify the code as follows:


private readonly AsyncLocal<Stopwatch> _stopwatch = new AsyncLocal<Stopwatch>();

private void Write(string name, object value)
{
  switch (name)
  {
    case "System.Data.SqlClient.WriteCommandBefore":
    {
      _stopwatch.Value = Stopwatch.StartNew();
      break;
    }
    case "System.Data.SqlClient.WriteCommandAfter":
    {
    var stopwatch = _stopwatch.Value;
    stopwatch.Stop();
    var command = GetProperty<SqlCommand>(value, "Command");
    Console.WriteLine($"CommandText: {command.CommandText}");
    Console.WriteLine($"Elapsed: {stopwatch.Elapsed}");
    Console.WriteLine();
    break;
    }
  }
}

private static T GetProperty<T>(object value, string name)
{
  return (T)value.GetType()
        .GetProperty(name)
        .GetValue(value);
}

Here, we will intercept the start and end events of the query in the database. Before execution, we create and start stopwatch, store it in asynclocal < stopwatch > and return it later. After execution, we get the previously started stopwatch, stop it, get the execution command from the parameter value through reflection, and output the result to the console.

The results are as follows:

CommandText: SELECT 42;
Elapsed: 00:00:00.1509086

42

Now we have solved our requirements, but there is still a small problem. When we subscribe to the event diagnosticlistener, we will receive all events from it, including those we don’t need. However, each event sent will create an anonymous object with parameters, which will cause extra pressure on GC.

We need to solve the above problem to avoid dealing with all events. We need to specify the special delegate type predict < string > and declare the isenabled method to filter the consumers with the corresponding name.

Next, let’s modify the method IObserver < diagnosticlistener >. Onnext


public void OnNext(DiagnosticListener value)
{
  if (value.Name == "SqlClientDiagnosticListener")
  {
    var subscription = value.Subscribe(this, IsEnabled);
    _subscriptions.Add(subscription);
  }
}
    
private bool IsEnabled(string name)
{
  return name == "System.Data.SqlClient.WriteCommandBefore"
    || name == "System.Data.SqlClient.WriteCommandAfter";
}

Now we’re only going to talk about events System.Data.SqlClient . writecommandbefore and System.Data.SqlClient . writecommandafter calls the write method.

use Microsoft.Extensions.DiagnosticAdapter

Although we have implemented the requirements above, we can also find that the event parameters we receive from diagnosticlistener are usually passed as anonymous objects, so we have to deal with these parameters through reflection, which causes us more expensive consumption. However, the development team has also considered this problem and provided us with some suggestions Microsoft.Extensions.DiagnosticAdapter To finish us The operation of.

Next, we need to change subscribe to subscribe with adapter. In addition, in this case, we do not need to implement IObserver < keyvaluepair < string, Object > > interface. On the contrary, we need to declare a separate method for each event and use the [diagnosticnameattribute] feature to annotate it

As follows:


public class ExampleDiagnosticObserver4 : IObserver<DiagnosticListener>
{
  private readonly List<IDisposable> _subscriptions = new List<IDisposable>();
  private readonly AsyncLocal<Stopwatch> _stopwatch = new AsyncLocal<Stopwatch>();

  public void OnCompleted()
  {
  }

  public void OnError(Exception error)
  {
  }

  public void OnNext(DiagnosticListener value)
  {
    if (value.Name == "SqlClientDiagnosticListener")
    {
      var subscription = value.SubscribeWithAdapter(this);
      _subscriptions.Add(subscription);
    }
  }

  [DiagnosticName("System.Data.SqlClient.WriteCommandBefore")]
  public void OnCommandBefore()
  {
    _stopwatch.Value = Stopwatch.StartNew();
  }

  [DiagnosticName("System.Data.SqlClient.WriteCommandAfter")]
  public void OnCommandAfter(DbCommand command)
  {
    var stopwatch = _stopwatch.Value;
    stopwatch.Stop();
    Console.WriteLine($"CommandText: {command.CommandText}");
    Console.WriteLine($"Elapsed: {stopwatch.Elapsed}");
    Console.WriteLine();
  }
}

Now we have realized the function of monitoring or intercepting the data execution, and we can also record the execution time of our database. In particular, we have not modified the application itself, which also reduces a lot of redundancy and saves a lot of coding time. It’s a great programming experience.

Create diagnosticlistener instance

In most cases, we will subscribe to existing events for diagnosticsource. Basically, we don’t need to create our own diagnosticlistener to send events. Of course, it’s better to learn about this feature. Please continue to read on

Create your own instance


private static readonly DiagnosticSource diagnosticSource =
  new DiagnosticListener("MyLibraty");

Send event, we will call write to write event


if (diagnosticSource.IsEnabled("MyEvent"))
  diagnosticSource.Write("MyEvent", new { /* parameters */ });

reference resources

https://github.com/dotnet/corefx/blob/master/src/System.Diagnostics.DiagnosticSource/src/DiagnosticSourceUsersGuide.md

https://sudonull.com/post/3671-Using-the-DiagnosticSource-in-NET-Core-Theory

https://github.com/dotnet/runtime/issues/20992

https://github.com/hueifeng/BlogSample/tree/master/src/DiagnosticDemo

Here is the article about how to use diagnosticsource in. Net. For more information about how to use diagnosticsource in. Net, please search previous articles of developer or continue to browse the following articles. I hope you can support developer more in the future!