BizTalk Instrumentation – An Initial Foray into the CAT Framework
I have spent some time recently looking into the Windows Server AppFabric Customer Advisory Teams (herein “CAT”) BizTalk instrumentation framework and I will report here on some of my findings… In short, I have become quite excited about the potential if offers not only to instrument BizTalk solutions (in development and production environments) but also as the basis of a unit testing framework. In this brief initial look into the framework, I will focus on tracing in orchestrations but it’s possible to introduce tracing into all BizTalk artefacts (and also non BizTalk/custom components).
The framework itself has been around for sometime now (since May 2010?) – this blog entry from the CAT is a well written article introducing the tracing facilities it provides (at the end of the article is a link to the framework source code). This white paper looks to have been heavily based on the blog article (or vice-versa) and is similarly well written and easy to follow.
I have to confess and admit that in the past, like a lot of developers, I have used the System.Diagnostics.Trace .NET class in conjunction with DebugView to trace execution of orchestrations during development. One thing I have observed is that CPU utilization increases dramatically whilst DebugView runs: it’s not a tool that should be run outside of a development environment. The CAT observed this and came up with a framework leveraging the Event Tracing for Windows (ETW) facility. The framework is a wrapper around the TraceProvider class from the Microsoft.BizTalk.Diagnostics namespace in Microsoft.BizTalk.Tracing.dll. As CAT mention, this is a “hidden gem” and is utilised in all major components in the BizTalk runtime (you can observe this by running DebugView while the BizTalk engine is executing – heaps of trace events are outputted).
Now the framework doesn’t mean you should run DebugView outside of a development environment: instead, it allows rapid and efficient tracing to a log file. This means that it won’t crash your development VM and also it permits tracing in Production and Production like environments.
I will briefly describe here how I setup the framework to trace orchestration execution…
After downloading the framework from the CAT blog, I opened the solution using Visual Studio 2012 and successfully ran the Conversion Wizard.
There are 3 projects:
The Microsoft.BizTalk.CAT.BestPractices.Framework project is the one I will need to reference in my solution.
A few immediate/gut observations about the Microsoft.BizTalk.CAT.BestPractices.Framework project that piqued my interest:
- Pre processor directives have been specified that output trace statements using System.Diagnostics.Trace .NET class for a debug build only. So one could infer from this that this is designed for development, where a debug build of the framework could be used for outputting to DebugView. A release build will not include the calls to System.Diagnostics.Trace, precluding the use of DebugView in Production for example.
- Lots of passing of object arrays – no generic collections evident: possibly a boxing/unboxing overhead here.
In order to get the Microsoft.BizTalk.CAT.BestPractices.Framework project to build (under .NET 4.5), I had to specify the full namespace (Microsoft.BizTalk.CAT.BestPractices.Framework) for the Func<string> delegate in the ComponentTraceProvider class.
Next I selected the option to sign the project assembly and created a strong name key then installed the assembly in the GAC.
It’s then a matter of adding a reference to Microsoft.BizTalk.CAT.BestPractices.Framework.dll in my orchestrations project in my BizTalk solution.
The white paper indicated in the introduction to this post presents usage of the framework well but I will demonstrate here how I implemented tracing in my orchestration…
Expression shapes containing tracing statements should be strategically added to the orchestration.
- Tracing should kick off with a call to the TraceIn method immediately after orchestration activation. The method returns a GUID that can be used to trace specific instances (the GUID can be prefixed to the trace output for example – thanks Johann for this tip!).
- Message body content can be outputted using the TraceInfo method. Note that the variable debugMessage is of type System.XML.XMLDocument.
- It’s possible to trace scope execution using the TraceStartScope and TraceEndScope methods. The framework will output scope execution time.
- Tracing should be added into exception blocks like so, using the TraceError method (passing in the exception object):
- Finally the orchestration should end with a call to TraceOut, passing in the GUID (stored in the callToken variable below) returned from calling the TraceIn method.
The BizTalk CAT Instrumentation Framework Controller available on CodePlex is an excellent GUI based tool for starting and stopping traces. It has options to write tracing to DebugView and/or a log file (DebugView shouldn’t be used in Production though, just development environments). It has a bit of a limitation in that the log file is not human readable until a trace is stopped.
Here’s an example of a trace written to DebugView:
I have an example BizTalk 2013 solution here that is available for download under the terms of the MIT licence where tracing has been implemented. The example screenshots above are taken from this solution.
Now 2 things have got me really excited about the BizTalk CAT instrumentation framework:
- The opportunity to log real time tracing events from Production environments in an efficient way – this has implications for monitoring solutions in Production, parsing tracing events to trigger other events e.g. error alerting, reporting. Tracing could be written to Azure providing a central repository of data that could be analysed and reported on.
- The facility to track flow through an orchestration would be the excellent basis for a unit testing framework. Tests could be run by writing trace events to a queue (Windows service bus?) to preserve the order in which events have been triggered. The BizUnit testing framework could then be extended to monitor the events on the queue and compare against expected execution flow configured in the business rules engine (BRE). Events associated with each test run could also be persisted to a database and provide the basis for analysis of test coverage (i.e. have all paths of execution been tested in a given orchestration?).
In regards to point 1, this facility looks similar to recent functionality added to the BizTalk360 monitoring solution.
The Testing inside BizTalk by using ETW Tracing project on CodePlex looks almost a perfect fit for point 2 and something I intend to explore soon!
In summary, I hope this post provides a good introduction to the CAT tracing framework and how it could be used during development (as a unit testing tool) and subsequently in Production (real time tracing and monitoring).