Application Insights extensibility : tricks worth knowing #2

In my previous post about Application insights, I showed how to drop irrelevant dependency telemetry events. In this post we will do quite the opposite. We will enrich existing HTTP Request Telemetry with some header values.

Context

I recently migrated a project which was using a custom made (and aggressive) http dependency logger to Application Insights. While it was providing a better experience, I quickly realised the information collected was not enough to allow us to perform a proper troubleshooting especially when dealing with SOAP services.

The main reason is that it does not log anything about the http headers, especially the SOAPAction header.

The good news is that .Net core and the Application Insights SDK are providing the extensibility endpoint to fix that.

The first part resides in .Net Framework which offers the capability to hook into the Diagnostic Listener and change what's being logged. In our case, we will save relevant headers in Activity.Tags. Activity is the cornerstone of modern .Net Diagnostics. If you're not familiar with that concept and Diagnostic Listeners I strongly recommend you read about it.

The second part will be to make sure that Application Insights saves tags with our telemetry. This part might not be necessary in the near future as support for tags is planned.

Collecting Http Headers as Activity Tags

In order to attach the http headers as tags, we will need to Write an IObserver<DiagnosticListner>. This is where we will get the chance to subscribe to specific listeners. In our case we are interested in HttpHandlerDiagnosticListener.

void IObserver<DiagnosticListener>.OnNext(DiagnosticListener value)  
        {
            if (value.Name == "HttpHandlerDiagnosticListener")
            {
                this.subscription.Add(value.SubscribeWithAdapter(this));
            }
        }

When subscribing to a listener, you are very likely to want to use Microsoft.Extensions.DiagnosticAdapter package. It will save you from writing ugly reflection based code yourself. Instead, you will be able to use strongly type methods.

For instance, we will intercept the System.Net.Http.HttpRequestOut.Start event and write in the current Activity as follows:

[DiagnosticName("System.Net.Http.HttpRequestOut.Start")]
public virtual void OnHttpRequestOutStart(System.Net.Http.HttpRequestMessage request)  
        {
            if (this.options.HostNames.Contains(request.RequestUri.Host))
            {
                foreach (var header in this.options.Headers)
                {
                    if (request.Headers.TryGetValues(header, out var values))
                    {
                        Activity.Current.AddTag($"x-request-header-{header}", string.Join(", ", values));
                    }
                }


            }
        }

Complete code

HttpRequestActivityEnrichment.cs:

    public class HttpRequestActivityEnrichment : IObserver<DiagnosticListener>, IDisposable
    {
        private List<IDisposable> subscription = new List<IDisposable>();
        private readonly HttpRequestActivityEnrichmentOptions options;

        public HttpRequestActivityEnrichment(
            IOptions<HttpRequestActivityEnrichmentOptions> options)
        {
            this.options = options.Value;
            this.subscription.Add(DiagnosticListener.AllListeners.Subscribe(this));
        }

        [DiagnosticName("System.Net.Http.HttpRequestOut.Start")]
        public virtual void OnHttpRequestOutStart(System.Net.Http.HttpRequestMessage request)
        {
            if (this.options.HostNames.Contains(request.RequestUri.Host))
            {
                foreach (var header in this.options.Headers)
                {
                    if (request.Headers.TryGetValues(header, out var values))
                    {
                        Activity.Current.AddTag($"x-request-header-{header}", string.Join(", ", values));
                    }
                }


            }
        }

        [DiagnosticName("System.Net.Http.HttpRequestOut.Stop")]
        public virtual void OnHttpRequestOutStop(System.Net.Http.HttpRequestMessage request, System.Net.Http.HttpResponseMessage response, TaskStatus requestTaskStatus)
        {
            if (this.options.HostNames.Contains(request.RequestUri.Host))
            {
                foreach (var header in this.options.Headers)
                {
                    if (response.Headers.TryGetValues(header, out var values))
                    {
                        Activity.Current.AddTag($"x-response-header-{header}", string.Join(", ", values));
                    }
                }

            }
        }

        public void Dispose()
        {
            foreach (var sub in subscription)
            {
                sub.Dispose();
            }
        }

        void IObserver<DiagnosticListener>.OnCompleted()
        {

        }

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

        }

        void IObserver<DiagnosticListener>.OnNext(DiagnosticListener value)
        {
            if (value.Name == "HttpHandlerDiagnosticListener")
            {
                this.subscription.Add(value.SubscribeWithAdapter(this));
            }
        }
    }

HttpRequestActivityEnrichmentOptions.cs:

using System;  
using System.Collections.Generic;  
using System.Linq;  
using System.Threading.Tasks;

namespace SaintGobain.Glassol.Web  
{
    public class HttpRequestActivityEnrichmentOptions
    {

        public HashSet<string> HostNames { get; set; }

        public string[] Headers { get; set; }
    }
}

Attach tags to RequestTelemetry

As mentioned earlier, we need to attach the saved tags to our Telemetry objects. We can achieve this writing an ITelemetryInitializer.

using Microsoft.ApplicationInsights.Channel;  
using Microsoft.ApplicationInsights.DataContracts;  
using Microsoft.ApplicationInsights.Extensibility;  
using System;  
using System.Collections.Generic;  
using System.Linq;  
using System.Threading.Tasks;

namespace SaintGobain.Glassol.Web  
{
    public class AppendTagsTelemetryInitializer : ITelemetryInitializer
    {
        public void Initialize(ITelemetry telemetry)
        {
            var activity = System.Diagnostics.Activity.Current;
            var requestTelemetry = telemetry as DependencyTelemetry;
            if (requestTelemetry == null || activity == null) return;

            foreach (var tag in activity.Tags.Where(x=> x.Key.StartsWith("x-")))
            {
                requestTelemetry.Properties[tag.Key] = tag.Value;
            }

        }
    }
}

Configuration

Now to get it working you need to add the initialization logic to your application Startup.

First we need to register Enrichment class and options

public void ConfigureServices(IServiceCollection services)  
{
    // other application services


    services.AddSingleton<HttpRequestActivityEnrichment>();

            services.Configure<HttpRequestActivityEnrichmentOptions>(options =>
            {
                options.LogRequestBody = true;
                options.LogResponseBody = true;
                options.HostNames = new HashSet<string>
                {
                    new Uri(Configuration["Cameleon:SfdcUrl"]).Host,
                    new Uri(Configuration["Cameleon:HostUrl"]).Host,
                };
                options.Headers = new string[] { "SOAPAction" };
            });
}

Then, we need to make sure our Singleton is activated and register AppendTagsTelemetryInitializer in our Application Insights configuration. this will be achieved as part of the Configure method.

  public void Configure(IApplicationBuilder app, IHostingEnvironment env, ILoggerFactory loggerFactory, IServiceProvider serviceProvider)
{
            var enrichment = app.ApplicationServices.GetRequiredService<HttpRequestActivityEnrichment>();
            var configuration = app.ApplicationServices.GetService<TelemetryConfiguration>();
            configuration.TelemetryInitializers.Add(new AppendTagsTelemetryInitializer());

     // remaining application pipeline configuration
}

Conclusion

As we can see, Application Insights is built on top of .Net core builtin diagnostics primitives which makes it quite easy to extend even on more complex scenarios.

That said, not everything is easy. You must be sure that what you do does not have side effects. I'm still working on finding a good solution to trigger body logging on demand without breaking everything or making it slow. And that one is a bit harder.