BizTalk Server 2013 R2: Instrumenting a custom pipeline component with ETW

Article
1/17/2024

Introduction

The BizTalk CAT Instrumentation Framework provides a reusable framework intended to help BizTalk developers enrich their solutions with high-performance instrumentation based on the Event Tracing for Windows (ETW) infrastructure. As a developer you can instrument your BizTalk artefact, WCF/WF component, or custom component (.NET) for the purpose of logging, tracing or testing to observe the behavior. ETW enables you to log kernel or application events to a log file. An application can be seen in a broad view, meaning that a BizTalk solution containing custom pipeline components, mappings, and an orchestration can be logged from end to end. This can also be done using log4net or System.Diagnostics namespace.

The framework was built as a result of research within Microsoft which found both log4net and System.Diagnostics did not deliver enough agility or acceptable performance. ETW infrastructure within the Microsoft OS provided a high-speed tracing facility and combined with a TracePovider in from the Microsoft.BizTalk.Diagnostics namespace in Microsoft.BizTalk.Tracing.dll are basically the main ingredients of the framework. The most important part within the framework is the ComponentTraceProvider class. This class is a wrapper around the TraceProvider providing various tracing methods for common logging requirements such as information, warning, and exceptions. In addition to these methods the team also enriched the framework with support for tracing method calls, measuring durations using high-resolution timers and ability to correlate events using GUID-based tokens.

Scenario

The BizTalk CAT Instrumentation Framework can be used to instrument the following BizTalk artifacts:

Custom Pipeline Components
BizTalk Mapping
Orchestrations
Business Rules
BAM Activity Tracking Components

The following scenario will demonstrate how to instrument a pipeline component that archives incoming messages to file. In the scenario below a client application will send a request for the status of an airport as a soap/xml message. BizTalk route this request to a GET operation to the Restful service endpoint. The request message contains the airport code that is marked as the property by applying a property schema. That property will mapped to the outgoing request URL to call the Restful endpoint. The endpoint on its turn will process the request and provide the status of a given airport based upon the airport code provided within the request URL as a JSON format response. The JSON response will be archived by a custom pipeline component, which will be reused within a custom pipeline to also archive the XML message after the JSON has been decoded into XML by the JSON decoder pipeline component. BizTalk CAT Instrumentation Framework will be leveraged in the custom archive component. Basically the response will be tracked (i.e. archived to file). The XML response message will be routed back to the client:

http://i208.photobucket.com/albums/bb152/Steef-Jan/ETW/scenario_zpsdcip1lvf.png

Picture 1. Scenario using ETW with a pipeline.

This scenario based on the TechNet Wiki article BizTalk Server 2013 R2 JSON support and integration with Cloud API’s and the custom archive component is derived from the MSDN Code Gallery BizTalk stream based archiving pipeline component.

Prerequisites

To leverage ETW for BizTalk you will to download the BizTalk CAT Instrumentation Framework v1.4 and build it locally on your machine with Visual Studio 2013. You will need to open the solution with Visual Studio 2013 to migrate to newer version of the .NET framework. To build the project the following code in class IcomponentTraceProvider needs to be commented out:

void TraceInfo(Func<string> expensiveDataProvider);

Next to the Instrumentation Framework you can download the BizTalk CAT Instrumentation Framework Controller, which is an easy-to-use GUI for the BizTalk CAT Instrumentation Framework. This will let you start and stop a traces and adjust filter options. It can easily enable real-time tracing to the Microsoft SysInternals DebugView (or other debuggers), or to a log file or to do both at the same time.

Instrumenting a custom pipeline component with the BizTalk CAT Instrumentation Framework

A custom pipeline component can be can be instrumented using TraceManager.PipelineComponent, which is designed for the purpose this BizTalk artefact. The TraceManager can be useful to test:

Tracing calls to the core methods such as Execute, Disassemble, GetNext, et cetera for the various types of pipelinecomponent depending for targeted pipeline phase using TraceIn and TraceOut;
Measuring the duration of the above methods using TraceStartScope and TraceEndScope, which will be demonstrated by code sample below of the custom archiving component;
Tracing the internal state of the in this case custom archiving pipeline component, which could in turn assist with troubleshooting using TraceInfo;
Writing detailed information about a runtime exception using TraceError in case the custom archiving pipeline fails.

/// <summary>
        /// Implements IComponent.Execute method.
        /// </summary>
        /// <param name="pc">Pipeline context</param>
        /// <param name="inmsg">Input message</param>
        /// <returns>Original input message</returns>
        /// <remarks>
        /// IComponent.Execute method is used to initiate
        /// the processing of the message in this pipeline component.
        /// </remarks>
        public Microsoft.BizTalk.Message.Interop.IBaseMessage Execute(Microsoft.BizTalk.Component.Interop.IPipelineContext pc, Microsoft.BizTalk.Message.Interop.IBaseMessage inmsg)
        {
            var callToken = TraceManager.PipelineComponent.TraceIn(pc.PipelineID, pc.PipelineName, pc.StageID, pc.StageIndex, pc.ComponentIndex);
 
            TraceManager.PipelineComponent.TraceInfo("1. Enter pipeline." + " Guid : " +  callToken);
            TraceManager.PipelineComponent.TraceInfo("2. Archive files is set to : " + _ArchiveFiles.ToString() + " Guid : " + callToken);
 
            var scopeStarted = TraceManager.PipelineComponent.TraceStartScope(pc.PipelineName, callToken);
 
            try
            {
                //if archiving is true
                if (_ArchiveFiles)
                {
                    //set file name
                    string archiveFileName = inmsg.MessageID.ToString();
 
                    TraceManager.PipelineComponent.TraceInfo("3. The archiveFileName is : " + archiveFileName + " Guid : " + callToken);
 
                    //check if filename is not empty
                    if (archiveFileName != null && !string.IsNullOrEmpty(archiveFileName))
                    {
 
                        TraceManager.PipelineComponent.TraceInfo("4. The FileNameExtension is : " + _FileNameExtension + " Guid : " + callToken);
 
                        //set archive name with extension
                        archiveFileName = archiveFileName + _FileNameExtension;
 
                        //archive
                        ArchivingStream archivingStream = new  ArchivingStream(inmsg.BodyPart.Data, _ArchivePath + "\\" + archiveFileName);
 
                        TraceManager.PipelineComponent.TraceInfo("5. The path is : " + _ArchivePath + " Guid : " + callToken);
 
                        pc.ResourceTracker.AddResource(archivingStream);
                        inmsg.BodyPart.Data = archivingStream;
 
                        TraceManager.PipelineComponent.TraceInfo("6. Archive the message" + "Guid : " + callToken);
                    }
                }
 
                 
            }
            catch (Exception ex)
            {
                //Use Trace error and log error and stack trace
                TraceManager.PipelineComponent.TraceError(ex, true);
            }
 
            TraceManager.PipelineComponent.TraceEndScope(pc.PipelineName, scopeStarted, callToken);
 
            return inmsg;
        }
        #endregion
    }

The BizTalk CAT Instrumentation Framework in action

To capture and review the behavior of the custom archive pipeline component the client will send a request message to BizTalk. Before the message is sent the BizTalk CAT Instrumentation Framework Controller will be launched. Selecting the Pipeline Components trace filter setting:

http://i208.photobucket.com/albums/bb152/Steef-Jan/ETW/catcontroller_zpszolrzjbg.png

Picture 2. BizTalk CAT Instrumentation Controller.

DebugView will be launched. The message will be sent from the client application. The debug trace will look like below in the DebugView:

http://i208.photobucket.com/albums/bb152/Steef-Jan/ETW/debugview_zpslbakkm9f.png

Picture 3. DebugView capturing the traces.

When the text editor will be opened that the same trace information displayed in debugview can be found.

http://i208.photobucket.com/albums/bb152/Steef-Jan/ETW/texteditor_zpswepynurf.png

Picture 4. Captured trace information in text editor notepad++.

The calltoken (see code) is used in each TraceInfo statement, TraceStartScope and TraceEndScope to correlate the tracing statements.

Wrap up

This article demonstrated how to instrument a custom pipeline component with the BizTalk CAT Instrumentation Framework that leverages Event Tracing for Windows (ETW), which is able to trace in a very performant way to a log file. ETW is suitable to be used with mappings, orchestrations, BRE and BAM. Examples on how to instrument them are similar to a custom pipeline component. Various samples can be found online demonstrating that like the excellent blog post Best Practices for Instrumenting High Performance BizTalk Solutions written by the team that build the BizTalk CAT Instrumentation Framework. The BizTalk CAT Instrumentation Framework Controller can be seen as a add-on for the framework to stop/start traces and specify options for enabling debugview and a texteditor.

Share via