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

DiagnosticContext/IDiagnosticContext #9

Merged
merged 5 commits into from
Jun 24, 2019

Conversation

nblumhardt
Copy link
Member

This one is going to be a little tricky to review without its other half; writing up what I currently have in the hope of getting the ball rolling. This builds on #8 so ideally we'll sort that one out first :-)

What's this?

Infrastructure for extending the payloads of HTTP request completion events with additional properties collected during execution of the request.

// In an ASP.NET Core controller somewhere:
readonly IDiagnosticContext _diagnosticContext;

// Action method
_diagnosticContext.Add("QueryProductCatalogElapsed", sw.ElapsedMilliseconds);

// Later, when the request completes, a summary event from middleware will include
// the `QueryProductCatalogElapsed` property...

Adding properties to the completion event, instead of emitting standalone events to carry associated data, can save bytes and make correlation easier.

Why is it being PR'd here?

It's here because, while some middleware in Serilog.AspNetCore will implement most of the functionality, some DI configuration is needed and we can bundle this into UseSerilog() to keep the configuration experience streamlined.

Relationship to existing features

It's already common practice when using Serilog to replace the (sometimes chatty) HTTP request logging performed by the framework with a single "request completed" event carrying all useful data. The SerilogMiddleware sample I wrote some time back is often the starting point for this.

Serilog doesn't have an equivalent to NLog's MDC/MDLC that can accumulate those values. LogContext is hierarchical, and so values pushed onto the LogContext are generally popped off again before a request completes, making it unsuitable for implementing this pattern. To get around this, the sample mentioned above is published as source code, and it's up to users to customize it in order to add additional detail to the events.

While we could extend LogContext to cover this, it's actually quite a tricky feature to get right, so scoping it back to consider only HTTP request processing (and perhaps other similar hosted request/response transactions) seems like a reasonable first step.

The plan is for Serilog.AspNetCore to take a dependency on this library (for its updated UseSerilog()), and add some middleware based on the above sample, but utilize the DiagnosticContext class in this PR to collect and attach additional properties.

Usage

Consumer code that wishes to attach properties to the completion event can receive an IDiagnosticContext through DI and call Add() to attach properties.

Middleware responsible for writing the completion event takes a dependency on the concrete DiagnosticContext and uses a BeginCollection()/TryComplete() pair to start recording, and then retrieve, the data.

Collection relies on AsyncLocal<T> to track the context; this mirrors the way that the current HttpContext is tracked, but using types that don't require a dependency on the ASP.NET Core HTTP implementation.

Pork barrel changes 😄

This PR adds a registration for ILogger to DI when one is available. There's no reason for controllers and other classes not to use the Serilog version of this interface, if the developer wishes to.

Thoughts?

readonly AmbientDiagnosticContextCollector _ambientCollector;
List<LogEventProperty> _properties = new List<LogEventProperty>();

internal DiagnosticContextCollector(AmbientDiagnosticContextCollector ambientCollector)
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Not ideal that this is internal, but it does save exposing some otherwise useless types.

public sealed class DiagnosticContextCollector : IDisposable
{
readonly AmbientDiagnosticContextCollector _ambientCollector;
List<LogEventProperty> _properties = new List<LogEventProperty>();
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

A list, rather than a dictionary, is used to save unnecessary allocations. There's a bit of a leak risk here, and despite the code jumping through a few hoops to mitigate it, we might end up wanting to pay for a dictionary and an extra allocation or two during completion.

@andrewlock
Copy link
Collaborator

I don't really follow the indirection involved in the AmbientDiagnosticLogger, but that's my failing, I'll take your work for it! 😃 Looks good to me.

It's here because, while some middleware in Serilog.AspNetCore will implement most of the functionality, some DI configuration is needed and we can bundle this into UseSerilog() to keep the configuration experience streamlined.

Theoretically, with .NET Core 3.0, this (or the Serilog.AspNetCore library) should become obsolete with the Generic Host, and we can reduce the amount of duplication required 🤞

@nblumhardt
Copy link
Member Author

Thanks @andrewlock !

I don't really follow the indirection involved in the AmbientDiagnosticLogger

Really minor thing, just a defensive tweak. If code looks like:

var collector = _diagnosticContext.BeginCollection();
var task = SomeMethodAsync();
collector.TryComplete(...);

...then the code that may still be executed via the unawaited SomeMethodAsync() call will inherit AsyncLocals values from the original context, but independently as copies.

Since the collector installed in the AsyncLocal is used to determine whether the contextual property values are stored or not, completing collection in the first context needs to also complete it in the second context that inherits it.

@nblumhardt
Copy link
Member Author

Theoretically, with .NET Core 3.0, this (or the Serilog.AspNetCore library) should become obsolete

The UseSerilog() methods in Serilog.AspNetCore will become obsolete, but by then it will contain some HTTP-specific stuff like the forthcoming middleware, so it will get a new lease on life :-)

@nblumhardt nblumhardt merged commit 83427fe into serilog:dev Jun 24, 2019
@nblumhardt nblumhardt mentioned this pull request Aug 20, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants