Entry Point Logging allows you to track all your API calls and the calls they make from a single place

In the first part of this series I gave a brief overview of Serilog and Seq and what differentiates them from logging you may have done in the past.  One of the most useful aspects of structured logging is the ability to trace the path of any particular call to your site, including key variables along the way. This post will explain how to set that up using Owin and middleware.

A key requirement in entry point logging is standardisation – all entry point logs should be generated by the same code if they are to be universally searchable (as well as being good SOLID practice!).

Example

Here is an example of a static entry point logger we are using, it is very simple code and uses the class SiteAccessDetails (which is added to our ClaimsPrincipal in middleware – see this blog for details on how to do that) to supply a shopName to be used as additional context.

public static class EntryPointLogger
{
	public static IDisposable AddEntryPointContext(ILogger logger, SiteAccessDetails siteAccessDetails, string entryPointName)
	{
		var disposable = LogContext.PushProperty("HttpRequestId", Guid.NewGuid());

		if (!string.IsNullOrWhiteSpace(siteAccessDetails?.ShopName))
			LogContext.PushProperty("Shop", siteAccessDetails.ShopName);

		if (!string.IsNullOrWhiteSpace(entryPointName))
			LogContext.PushProperty("entryPointName", entryPointName);

		logger.Information("Entry Point: {entryPointName} called", entryPointName);

		return disposable;
	}

	public static IDisposable AddEntryPointContext(ILogger logger, string shopNameOrUrl, string entryPointName)
	{
		var userSiteDetails = new SiteAccessDetails(shopNameOrUrl, null, null);
		return AddEntryPointContext(logger, userSiteDetails, entryPointName);
	}

	public static IDisposable AddEntryPointContext(ILogger logger, string entryPointName)
	{
		return AddEntryPointContext(logger, (SiteAccessDetails)null, entryPointName);
	}
}

We can call this manually from entry points in our code (Web API controllers etc) by adding a line like the following

var disposableLogContext = EntryPointLogger.AddEntryPointContext(logger, siteAccessDetails, "/api/customer/info");

to the start of the controller action and

disposableLogContext.Dispose();

to the end, where logger has been defined in the constructor and passed in by IOC  or defined directly in the class as a private variable by using

private readonly ILogger logger = Log.ForContext<CustomerController>();

Using Owin

..but this means remembering to add it to every entry point that you create.  A better way if you are using Owin is to define a piece of middleware that calls it for you. Using the standard template for adding middleware…

public class AppendEntryPointToSerilogContextMiddleware
{
	private readonly Func<IDictionary<string, object>, Task> _next;
	private readonly ILogger logger = Log.ForContext<AppendEntryPointToSerilogContextMiddleware>();

	public AppendEntryPointToSerilogContextMiddleware(Func<IDictionary<string, object>, Task> next)
	{
		_next = next;
	}

	public async Task Invoke(IDictionary<string, object> env)
	{
		var userSiteDetails = ClaimsPrincipal.Current.GetSiteDetails();
		object requestPath;
		env.TryGetValue("owin.RequestPath", out requestPath);

		using (EntryPointLogger.AddEntryPointContext(logger, userSiteDetails, requestPath?.ToString()))
		{
			await _next(env);
		}
}

Which is invoked in the configuration method of your startup.cs class

 public void Configuration(IAppBuilder app)
{
  ...
  app.Use(typeof(AppendEntryPointToSerilogContextMiddleware));
  ...
}

Notice that my code gets the site details from the ClaimsPrincipal as mentioned above and gets the path of the entry point from the Owin  RequestPath.

You will now get every call to your API fully logged with the path and in this case, the shop.

If you have entry points to your code that do not go through a request – we have subscriptions to an Azure Service Bus Topic for instance – you can just add the manual call to the entry point logger at the start.

Try it!

This is an extremely useful method for tracking live code which we now use extensively. If it has given you food for thought, give it a try, it’s really simple to use.

Get Serilog from here, get Seq from here