Dec 082015
 

azureappinsightsIn the first part of this series I wrote about what Azure Application Insights (AI) can do and how to add extra information to the tracking telemetry your application sends to AI.

The solution that I wanted to add AI tracking to was a Windows Service with self-hosted WCF services. One service is the server side of a SOAP service where the caller defined the SOAP WSDL, and the other WCF service is a single method that receives raw XML as a http POST message. To track each request to the WCF service, I decided to use a message inspector.

WCF message inspectors can be attached to any WCF service and are called before and after each call to the WCF service. The message inspector needs to implement the IDispatchMessageInspector interface. That is described at https://msdn.microsoft.com/en-us/library/system.servicemodel.dispatcher.idispatchmessageinspector(v=vs.110).aspx and there are plenty of resources on the internet to help you get started implementing one.

Retrieve WCF request information

The message inspector is called after the request has been received, but before the service implementation is invoked. The method is called AfterReceiveRequest. My implementation looks like this:

public object AfterReceiveRequest(ref Message request, IClientChannel channel, InstanceContext instanceContext)
{
	// return value from AfterReceiveRequest is given as parameter to BeforeSendReply
	var messageTrackingInfo = new AiTrackingMessageStateInfo
	{
		RequestedUri = WebOperationContext.Current?.IncomingRequest.UriTemplateMatch?.RequestUri,
		Method = WebOperationContext.Current?.IncomingRequest.Method,
		Name = OperationContext.Current.IncomingMessageHeaders.Action
	};

	CallContext.LogicalSetData(ItemCorrelationTelemetryInitializer.CORRELATION_ID, Guid.NewGuid().ToString());

	// set the requested URI if not already present
	if (null == messageTrackingInfo.RequestedUri)
	{
		messageTrackingInfo.RequestedUri = channel.LocalAddress.Uri;
	}
	if (null == messageTrackingInfo.RequestedUri)
	{
		var svcInstance = instanceContext.GetServiceInstance();
		if (svcInstance != null)
		{
			// final fallback of the URI is the class name of the WCF service instance
			messageTrackingInfo.RequestedUri = new Uri(svcInstance.GetType().Name, UriKind.Relative);
		}
	}

	// set the operation name if not already present
	if (null == messageTrackingInfo.Name)
	{
		messageTrackingInfo.Name =
		WebOperationContext.Current?.IncomingRequest.UriTemplateMatch?.Template.ToString();
	}
	if (null == messageTrackingInfo.Name)
	{
		messageTrackingInfo.Name =
		WebOperationContext.Current?.IncomingRequest.UriTemplateMatch?.BaseUri.AbsolutePath;
	}

	return messageTrackingInfo;
}

The method can return an object which will be passed to the BeforeSendReply method described below.

This is useful to retrieve information about the request and store it so it can be used later on in BeforeSendReply to send the request tracking information to AI. My return type is called MessageTrackingInfo and it looks like this:

class AiTrackingMessageStateInfo
{
	private readonly Stopwatch stopWatch = new Stopwatch();

	public AiTrackingMessageStateInfo()
	{
		this.StartTime = DateTimeOffset.Now;
		stopWatch.Start();
	}

	public DateTimeOffset StartTime { get; private set; }
	public Uri RequestedUri { get; set; }
	public string Name { get; set; }
	public long ElapsedTimeMs => stopWatch.ElapsedMilliseconds;
	public string Method { get; set; }
}

It contains information about timing, the requested URI, the request name and the http method (GET/POST). The information is used in AI’s TelemetryClient.TrackRequest method.

As you can see in the implementation of the AfterReceiveRequest method above, it’s not that simple figuring out which URL was requested. That is because WCF can be invoked over several transport layers, not just http. So WCF itself doesn’t actually have a notion of the server URL. So I’m using WebOperationContext to try and get the URL and if that doesn’t work, then in the last case, I’m using the name of the class that will be invoked by the WCF operation.

The same applies to the operation name. But there is a different way to get the actual method name that will be invoked by the WCF operation. You can implement the IParameterInspector interface which works like IDispatchMessageInspector, but is called a little later in the pipeline and takes the operation name as a parameter. My implementation of IParameterInspector is described in the next post in the series.

If the SOAP service implemented was a SOAP 1.2 service, it would have a SOAP-Action header, from which it operation could have been retrieved. Unfortunately, that isn’t the case, so even if the code reads OperationContext.Current.IncomingMessageHeaders.Action, it won’t get the operation name from there.

Tracking Request

The actual request tracking is done in the BeforeSendReply method.

public void BeforeSendReply(ref Message reply, object correlationState)
{
	var requestInfo = (AiTrackingMessageStateInfo) correlationState;
	var name = requestInfo.Name;
	// AfterReceiveRequest may not have been able to get the operation name. In that case, get it from
	// CallContext where the IParameterInspector's OnAfterCall method has set it.
	if (String.IsNullOrEmpty(name))
	{
		name = (string)CallContext.LogicalGetData(ItemCorrelationTelemetryInitializer.OPERATION_NAME);
	}
	telemetryClient.TrackRequest(new RequestTelemetry()
	{
		StartTime = requestInfo.StartTime,
		Duration = TimeSpan.FromMilliseconds(requestInfo.ElapsedTimeMs),
		Url = requestInfo.RequestedUri,
		Name = name,
		HttpMethod = requestInfo.Method,
		ResponseCode = WebOperationContext.Current?.OutgoingResponse.StatusCode.ToString(),
		Success = !reply.IsFault
	});
}

The telemetryClient.TrackRequest method will send information about this request to AI. In an ASP.net web site, it would contain information about a page view. I want to track requests to my WCF service with each service operation’s name as the request name. So the parameters I use for the TrackRequest method contain that operation name that has been retrieved either in AfterReceiveRequest or in the IParameterInspector implementation described in the next post in the series.

Event correlation

You may have noticed this line in the AfterReceiveRequest method and wondered what it does.

CallContext.LogicalSetData(ItemCorrelationTelemetryInitializer.CORRELATION_ID, Guid.NewGuid().ToString());

In the first part of this series I described the Telemetry Initializer feature of AI. With that it is possible to add information to every single tracking request that is made by AI. Even if you don’t trigger the request in your own code. My telemetry initializer implementation will set the Correlation ID of the AI tracking request using the GUID generated in this line. This makes it possible to see related tracking events in the Azure portal when looking at requests.

In the next part of the series I’ll add my implemenation of IParameterInspector which track the time spent on each WCF operation and stores the operation name for use in the request tracking.

 Leave a Reply

You may use these HTML tags and attributes: <a href="" title=""> <abbr title=""> <acronym title=""> <b> <blockquote cite=""> <cite> <code> <del datetime=""> <em> <i> <q cite=""> <s> <strike> <strong>

(required)

(required)