Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Create diagnosticsource-getting-started.md #29255

Merged
merged 29 commits into from
Jun 2, 2022
Merged
Changes from 11 commits
Commits
Show all changes
29 commits
Select commit Hold shift + click to select a range
1901847
Create diagnosticsource-getting-started.md
mikelle-rogers May 2, 2022
ebf9141
DiagnosticSource Overview page
mikelle-rogers May 3, 2022
d29f7b0
Alter formatting and clarify contents of the file
mikelle-rogers May 3, 2022
3cdb16c
Update diagnosticsource.md
mikelle-rogers May 3, 2022
48c76a0
Fixing lint failures
mikelle-rogers May 3, 2022
012a00d
Fix up the code and finish up the documentation
mikelle-rogers May 5, 2022
14cd364
Not needed
mikelle-rogers May 5, 2022
0e80142
Update the date
mikelle-rogers May 5, 2022
f530c99
Combine into one file
mikelle-rogers May 5, 2022
f1998d9
Not needed
mikelle-rogers May 5, 2022
7bd1010
Remove whitespace
mikelle-rogers May 5, 2022
9e27b55
Fixed suggestions from code review
mikelle-rogers May 9, 2022
672fb48
Two additional edits
mikelle-rogers May 9, 2022
19ebd1e
Response to suggestions
mikelle-rogers May 10, 2022
9a72826
Update to working example
mikelle-rogers May 13, 2022
15c251e
Add a line, remove a space
mikelle-rogers May 13, 2022
3b085cf
Updating from feedback on code review
mikelle-rogers May 23, 2022
5c42c6f
Add DiagnosticSource and DiagnosticListener to toc
mikelle-rogers May 25, 2022
3edf4ce
Add .csproj and .cs files
mikelle-rogers May 25, 2022
5eb2e4f
Add links to the .cs and .csproj folders
mikelle-rogers May 25, 2022
3504d75
Merge branch 'main' into dev/mirogers/diagnosticsource-getting-started
mikelle-rogers May 25, 2022
6f2f3bc
Move the file to the correct place
mikelle-rogers May 25, 2022
d8c5a42
move location, add blocking
mikelle-rogers May 25, 2022
a9b6a75
Moving to correct address for real
mikelle-rogers May 25, 2022
f1550c3
Linking the code to the snippits
mikelle-rogers May 25, 2022
7971595
Correct filepath
mikelle-rogers May 25, 2022
04eb980
Responding to feedback
mikelle-rogers May 25, 2022
2802ddc
Added missing character
mikelle-rogers May 25, 2022
5f0fc2c
removing links
mikelle-rogers Jun 2, 2022
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
326 changes: 326 additions & 0 deletions docs/core/diagnostics/diagnosticsource-diagnosticlistener.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,326 @@
---
title: DiagnosticSource and DiagnosticListener
description: An overview of DiagnosticSource/DiagnosticListener including guidance on logging events, instrumenting code, and consuming data.
ms.date: 05/05/2022
---
# DiagnosticSource and DiagnosticListener

**This article applies to: ✔️** .NET Core 3.1 and later versions **✔️** .NET Framework 4.5 and later versions

<xref:System.Diagnostics.DiagnosticSource?displayProperty=nameWithType> is a module that allows code to be instrumented for production-time
logging of rich data payloads for consumption within the process that was instrumented. At runtime, consumers can dynamically discover
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
data sources and subscribe to the ones of interest. <xref:System.Diagnostics.DiagnosticSource?displayProperty=nameWithType> was designed to allow in-process
tools to access rich data. When using <xref:System.Diagnostics.DiagnosticSource?displayProperty=nameWithType>, the consumer is assumed
to be within the same process and as a result, non-serializable types (e.g. `HttpResponseMessage` or `HttpContext`) can be passed,
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
giving customers plenty of data to work with.

> [!NOTE]
> Many technologies that integrate with DiagnosticSource use the terms 'Tracing' and 'Traces' instead of 'Logging' and 'Logs'.
> The meaning is the same here.
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved

## Getting Started with DiagnosticSource

This walkthrough shows how to create a DiagnosticSource event and instrument code with <xref:System.Diagnostics.DiagnosticSource?displayProperty=nameWithType>.
It then explains how <xref:System.Diagnostics.DiagnosticSource?displayProperty=nameWithType> consumes the data by first
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
finding the specified DiagnosticListeners one is interested in, subscribing to them, and decoding payloads for more specific data.
It finishes by describing filtering, which controls which events pass through the system.

## Log an event

The `DiagnosticSource` type is an abstract base class that defines the methods needed to log events. The class that holds the implementation is `DiagnosticListener`.
The first step in instrumenting code with `DiagnosticSource` is to create a
`DiagnosticListener`. For example:

```C#
private static DiagnosticSource httpLogger = new DiagnosticListener("System.Net.Http");
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
```

Notice that httpLogger is typed as a `DiagnosticSource`.
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
This is because this code
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
only cares about writing events and thus only cares about the `DiagnosticSource` methods that
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
the `DiagnosticListener` implements. `DiagnosticListeners` are given names when they are created
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
and this name should be the name of logical grouping of related events (typically the component).
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
Later this name is used to find the Listener and subscribe to any of its events. `DiagnosticListeners` have a name, which is used to represent the component associated with the event.
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
Thus the event names only need to be unique within a component.

-------------------------------------------

## Instrumenting with DiagnosticSource/DiagnosticListener
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved

We show how to instrument DiagnosticListener using the DiagnosticListener we made in the code above.
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved

The `DiagnosticSource` logging
interface consists of two methods:

```C#
bool IsEnabled(string name)
void Write(string name, object value);
```

A typical call site will look like:

```C#
if (httpLogger.IsEnabled("RequestStart"))
httpLogger.Write("RequestStart", new { Url="http://clr", }); //any object can be the second argument
```

Architectural elements shown in the above code are as follows.
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
Every event has a `string` name (e.g. `RequestStart`), and exactly one `object` as a payload.
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
If you need to send more than one item, you can do so by creating an `object` with all information
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
in it as properties. C#'s [anonymous type](https://docs.microsoft.com/dotnet/csharp/fundamentals/types/anonymous-types)
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
feature is typically used to create a type to pass 'on the fly', and makes this scheme very
convenient. At the instrumentation site, you must guard the call to `Write()` with an `IsEnabled()` check on
the same event name. Without this check, even when the instrumentation is inactive, the rules
of the C# language require all the work of creating the payload `object` and calling `Write()` to be
done, even though nothing is actually listening for the data. By guarding the `Write()` call, we
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
make it efficient when the source is not enabled.

mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
Create a class to house the `DiagnosticListener and call site:

```C#
class MessageSender
{
private static DiagnosticSource httpLogger = new DiagnosticListener("System.Net.Http");

public void SendMessage()
{
if (httpLogger.IsEnabled("RequestStart"))
{
httpLogger.Write("RequestStart", new
{
Url = "http://clr",
});
}

}
}
```

-------------------------------------------

### Discovery of DiagnosticListeners

The first step in receiving events is to discover which `DiagnosticListeners` you are
interested in. `DiagnosticListener` supports a way of discovering `DiagnosticListeners` that are
active in the system at runtime. The API to accomplish this is the `AllListeners`
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
`IObservable<DiagnosticListener>`.
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved

The `IObservable` interface is the 'callback' version of the `IEnumerable` interface. You can learn
more about it at the [Reactive Extensions](https://docs.microsoft.com/dotnet/csharp/fundamentals/types/anonymous-types) site.
An `IObserver` has three callbacks, `OnNext`, `OnComplete`
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
and `OnError`, and an `IObservable` has single method called `Subscribe` which gets passed one of these
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
Observers. Once connected, the Observer gets callbacks (mostly `OnNext` callbacks) when things
happen. By including the `System.Reactive.Core` NuGet package, you can gain access to extensions that work well with `IObservable`.

A typical use of the `AllListeners` static property looks like this:

```C#
class Observer<T> : IObserver<T>
{
public Observer(Action<T> onNext, Action onCompleted)
{
_onNext = onNext ?? new Action<T>(_ => { });
_onCompleted = onCompleted ?? new Action(() => { });
}

public void OnCompleted() { _onCompleted(); }
public void OnError(Exception error) { }
public void OnNext(T value) { _onNext(value); }

private Action<T> _onNext;
private Action _onCompleted;
}

Action<DiagnosticListener> onNewListener = delegate (DiagnosticListener listener)
{
Console.WriteLine($"New Listener discovered: {listener.Name}");
if (listener.Name == "System.Net.Http")
{
// Here is where we put code to subscribe to the Listener.
}
};
IObserver<DiagnosticListener> TheIObserver = new Observer<DiagnosticListener>(onNewListener, null);
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
//when a listener is created, invoke the Observer onNext function which calls the delegate
listenerSubscription = DiagnosticListener.AllListeners.Subscribe(TheIObserver);

// Typically you leave the listenerSubscription subscription active forever.
// However when you no longer want your callback to be called, you can
// call listenerSubscription.Dispose() to cancel your subscription to the IObservable.
```

This code creates a callback delegate and using the `AllListeners.Subscribe` method requests
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
that the delegate be called for every active `DiagnosticListener` in the system. The decision of whether or not to subscribe to the listener
is made by inspecting its name. The code above is looking for our 'System.Net.Http' listener that we created previously.
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved

Like all calls to `Subscribe()`, this one returns an `IDisposable` that represents the subscription itself.
Callbacks will continue to happen as long as nothing calls `Dispose()` on this subscription object.
The above code never calls `Dispose()`, so it will receive callbacks forever.
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved

When you subscribe to `AllListeners`, you get a callback for ALL ACTIVE `DiagnosticListeners`.
Thus, upon subscribing, you get a flurry of callbacks for all existing `DiagnosticListeners`, and as new ones
are created, you receive a callback for those as well. You receive a complete list of everything it is possible
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
to subscribe to.

#### Subscribing to DiagnosticListeners
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved

A `DiagnosticListener` implements the `IObservable<KeyValuePair<string, object>>` interface, so you can
call `Subscribe()` on it as well. We show how to fill out the previous example:
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved

```C#
static IDisposable networkSubscription = null;
static IDisposable listenerSubscription;
Action<KeyValuePair<string, object>> onMessage = delegate (KeyValuePair<string, object> message)
{
Console.WriteLine($"Message received: {message.Key}: {message.Value}");
};
Action<DiagnosticListener> onNewListener = delegate (DiagnosticListener listener)
{
if (listener.Name == "System.Net.Http")
{
lock(allListeners)
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
{
if (networkSubscription != null)
{
networkSubscription.Dispose();
}
IObserver<KeyValuePair<string, object>> iobserver = new Observer<KeyValuePair<string, object>>(onMessage, null);
networkSubscription = listener.Subscribe(iobserver);
}
}
};

// At some point you may wish to dispose the networkSubscription.
```

In the above example, after finding the 'System.Net.Http' `DiagnosticListener`, an action is created that
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
prints out the name of the listener, event, and `payload.ToString()`. Please note the following.
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved

`DiagnosticListener` implements `IObservable<KeyValuePair<string, object>>`. This means
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
on each callback we get a `KeyValuePair`. The key of this pair is the name of the event
and the value is the payload `object`. In the code above we simply log this information
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
to the console.

It is important to keep track of subscriptions to the `DiagnosticListener`. In the above code the
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
networkSubscription variable that remembers this. If another `creation` is formed, one must
unsubscribe the previous listener and subscribe to the new one.

The `DiagnosticSource`/`DiagnosticListener` code is thread safe, but the
callback code also needs to be thread safe. To ensure the callback code is thread safe, locks are used. It is possible to create two `DiagnosticListeners`
with the same name at the same time. To avoid races updates of shared variables are performed under the protection of a lock.
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved

Once the above code is run, the next time a `Write()` is done on 'System.Net.Http' `DiagnosticListener`
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
the information will be logged to the console.

Subscriptions are independent of one another. As a result, other code
can do exactly the same thing as the code above, and generate two 'pipes' of the logging
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
information.

#### Decoding Payloads
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved

The `KeyvaluePair` that is passed to the callback has the event name and payload, but the payload is typed simply as
an `object`. There are two ways of getting more specific data:

1. If the payload is a well known type (e.g. a `string`, or an `HttpMessageRequest`) then you can simply
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
cast the `object` to the expected type (using the `as` operator so as not to cause an exception if
you are wrong) and then access the fields. This is very efficient.

2. Use reflection API. For example, assume the method below is present.
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved

```C#
/// Define a shortcut method that fetches a field of a particular name.
static class PropertyExtensions
{
static object GetProperty(this object _this, string propertyName)
{
return _this.GetType().GetTypeInfo().GetDeclaredProperty(propertyName)?.GetValue(_this);
}
}
```

The `listener.Subscribe()` call above could be replaced with the following code, to decode the payload more fully.
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved

```C#
networkSubscription = listener.Subscribe(delegate(KeyValuePair<string, object> evnt) {
var eventName = evnt.Key;
var payload = evnt.Value;
if (eventName == "RequestStart")
{
var url = payload.GetProperty("Url") as string;
var request = payload.GetProperty("Request");
Console.WriteLine("Got RequestStart with URL {0} and Request {1}", url, request);
}
});
```

Note that using reflection is relatively expensive. However, using reflection is the only
option if the payloads were generated using anonymous types. This overhead can be reduced by
making fast, specialized property fetchers either using `PropertyInfo.CreateDelegate` or
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
`ReflectEmit`, but that is beyond the scope of this document.
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
(See the [PropertySpec](https://github.com/dotnet/runtime/blob/main/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/DiagnosticSourceEventSource.cs#L784)
class used in the `DiagnosticSourceEventSource` for an example of a fast, delegate-based property fetcher.)
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved

#### Filtering

In the example above, the code uses the `IObservable.Subscribe()` method to hook up the callback. This
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
causes all events to be given to the callback. However `DiagnosticListener` has overloads of
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
`Subscribe()` that allow the controller to control which events are given.

The `listener.Subscribe()` call in the previous example can be replaced with the following code to demonstrate.

```C#
// Create the callback delegate
Action<KeyValuePair<string, object>> callback = (KeyValuePair<string, object> evnt) =>
Console.WriteLine("From Listener {0} Received Event {1} with payload {2}", networkListener.Name, evnt.Key, evnt.Value.ToString());

// Turn it into an observer (using System.Reactive.Core's AnonymousObserver)
Observer<KeyValuePair<string, object>> observer = new AnonymousObserver<KeyValuePair<string, object>>(callback);
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved

// Create a predicate (asks only for one kind of event)
Predicate<string> predicate = (string eventName) => eventName == "RequestStart";

// Subscribe with a filter predicate
IDisposable subscription = listener.Subscribe(observer, predicate);

// subscription.Dispose() to stop the callbacks.
```

This very efficiently subscribes to only the 'RequestStart' events. All other events will cause the `DiagnosticSource.IsEnabled()`
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
method to return `false`, and thus be efficiently filtered out.
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved

##### Context-based Filtering
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved

Some scenarios require advanced filtering based on extended context.
Producers may call `DiagnosticSource.IsEnabled()` overloads and supply additional event properties as shown in the code below.
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved

```C#
if (httpLogger.IsEnabled("RequestStart", aRequest, anActivity))
httpLogger.Write("RequestStart", new { Url="http://clr", Request=aRequest });
```
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved

The next code demonstrates that consumers may use such properties to filter events more precisely:
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved

```C#
// Create a predicate (asks only for Requests for certains URIs)
Func<string, object, object, bool> predicate = (string eventName, object context, object activity) =>
{
if (eventName == "RequestStart")
{
HttpRequestMessage request = context as HttpRequestMessage;
if (request != null)
{
return IsUriEnabled(request.RequestUri);
}
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
}
return false;
}

// Subscribe with a filter predicate
IDisposable subscription = listener.Subscribe(observer, predicate);
```

Note that producers are not aware of the filter a consumer has provided. `DiagnosticListener`
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
will invoke the provided filter, omitting additional arguments if necessary, thus the filter
should expect to receive a `null` context.
Producers should enclose `IsEnabled()` calls with event name and context with pure `IsEnabled()`
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
calls for event name, so consumers must ensure that their filter allows events without context
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
mikelle-rogers marked this conversation as resolved.
Show resolved Hide resolved
to pass through.