Troubleshooting .NET Applications

In this article I will show you how to implement an XslTransform wrapper to trace and profile XSLT transformations at runtime in .NET applications. The source code and supporting files can be downloaded from www.sys-con.com/dotnet/sourcec.cfm.

Tests executed and results obtained to verify the execution and performance of XSLT transformations during development and testing are often not fully representative of production use case scenarios encountered in a live environment. Troubleshooting XSLT transformations that performed well during the development and testing phases but later exhibit unexpected behavior in a production environment can be a daunting task.

Random exceptions, access violations, generation of unexpected/ incorrect output, and inconsistent drops in query execution perfor- mance (prolonged high CPU usage or idle times) are examples of common problems that you can encounter when executing XSLT transformations in production environments. Such problems are most commonly caused by the design of the XSLT style sheet(s) used to execute the transformations. These problems can be difficult to reproduce and troubleshoot when the source XML data is generated dynamically and varies by user, e.g., dynamically generated queries to retrieve source XML data from a SQL Server back end, or data retrieved dynamically from external Web services.

In such situations the availability of the following diagnostic data can help significantly reduce the time to identify the cause of the problem in an XSLT transformation and take the required corrective action:
1. The context source XML data
2. The XSLT style sheet used to execute the transformation
3. An XSLT transformation trace/profiler log to the point of failure, manual termination, or completion

The context source XML data can be difficult to obtain in dynamic environments without source code modifications. The availability of this item combined with the style sheet (which is usually easily attainable, as style sheets are commonly loaded from the disk) will provide users the data they will need to recreate the problem on a development/test server.

An XSLT transformation trace/profiler log will help execute a time- and resource-efficient post mortem analysis of the failed/problematic XSLT transformation to determine the progress to the point of failure/manual termination/completion, isolate the cause of an observed problematic behavior, and take the required corrective action.

These items should be obtainable without having to resort to executing time-consuming troubleshooting steps that require the use of advanced debugging tools and/or the implementation of source code modifications. Being able to obtain diagnostic data representative of a live use case in a timely manner will facilitate faster problem isolation and resolution.

In the .NET Framework, the XslTransform type in the System.Xml.Xsl namespace implements the API to execute XSLT transformations using the .NET XSLT processor. This article details an implementation architecture that can be used to implement a wrapper for this type to trace and profile XSLT transformations at runtime in .NET applications.

XSLT Tracing Goals
Design Goals
1. The tracing functionality should be fully configurable without requiring source code modifications. This is mandatory if a feature like this is to be useful in production environments. Specifically, the following aspects should be configurable:

Enable/disable tracing. By default XSLT Tracing should be disabled. The feature is meant to be enabled and used only in troubleshooting and/or profiling scenarios.

Configure (enable/disable) XSLT elements/instructions to be traced, e.g., trace only xsl:template instructions.

Enable/disable the persisting of source XML data used in XSLT transformations. This option, when enabled, will help obtain the source XML data transformed by problematic XSLT transformations in dynamic environments.

Enable/disable the deletion of trace logs and source XML data persisted by successful XSLT transformations (to prevent logs related to successful transformations from cluttering the disk).

Specify the physical path of the disk and folder where the trace log and source XML data should be persisted.

2. There should be no requirement to mix trace points and tracing code with the core query processor implementation. Users will not have access to the source code of the XslTransform type and will therefore not be able to instrument its implementation to achieve the desired tracing.
3. It should generate a trace log with useful data that can be easily interpreted by an XSLT developer. Third-party application profilers that profile managed code execution in .NET applications are available. The data generated by these profilers reflect the execution and performance of API calls executed on the .NET assemblies used during the course of the transformation. A user will need to be familiar with the internal XslTransform implementation to map its API calls to corresponding XSLT instructions in a style sheet. This level of expertise and skill is currently possessed only by the Microsoft developers who implemented the XslTransform type. An XSLT transformation trace log should reflect the execution of the style sheet using a format that is independent of implementation specifics and that can be easily interpreted by an XSLT developer.

User Goals
1. Enable users to easily obtain live source XML data in dynamic environments in order to recreate and troubleshoot XSLT transformation failures.
2. Eliminate the need to install/configure advanced debugging tools to troubleshoot XSLT transformation problems and failures.
3. Enable experienced XSLT developers to efficiently and independently troubleshoot and resolve .NET XSLT transformation problems. The feature can also be used to obtain and provide Microsoft product support services with live data to reproduce an observed problem when encountering a potential anomaly that requires confirmation.
4. Enable inexperienced XSLT developers to efficiently gather and provide Microsoft Product Support Services with the data (source XML + style sheet + trace log) required to troubleshoot the cause of an observed .NET XSLT transformation problem.

Non-Goals
1. High performance when XSLT tracing is enabled is not a design goal. Tracing functionality of any kind is meant to be used only in troubleshooting/profiling scenarios. ODBC tracing is a perfect example of this. When enabled, it significantly slows down the execution of ODBC applications. XSLT tracing is no different, and its benefits come with an associated performance trade-off.
2. Tracing will be configurable only for specific XSLT instructions. Tracing every XSLT instruction is not required to isolate the cause of an XSLT problem in the vast majority of the use cases. The ability to trace a few core XSLT instructions (e.g., xsl:template, xsl:for-each, and xsl:value-of) should be sufficient to aid in the problem isolation process. Additionally, the requirement to trace each supported XSLT instruction should be configurable.

Architecture
Figure 1 is a high-level diagram of the architecture that will be used and implemented by the XslTransform wrapper to trace XSLT transformations in .NET applications. The following aspects of the architecture will help achieve the design and user goals.
1. Application configuration files will be used to configure XSLT tracing. This is the preferred approach to be able to dynamically configure the aspects of XSLT tracing described in the design goals without requiring source code modifications. This flexibility comes at the cost of the configured settings having an application-wide impact. In this context, when XSLT tracing is enabled, all XSLT transformations executed by an application will be traced. When it is disabled, none of the XSLT transformations will be traced.

2. The code to generate the trace log will be implemented in a CLR type. When tracing is enabled, object instances of this type will be instantiated and supplied as extension objects to trace XSLT transformations.
3.
When the option to trace XSLT transformations is enabled, the XSLT processor will instrument XSLT style sheets to add the required trace points. The trace points in the instrumented style sheet will be extension object method calls to the tracing extension object. Each extension object method call will supply parameters that reflect the following:

XSLT instruction to be traced

Values specified in the original style sheet for the common attributes of the XSLT instruction being traced, e.g., the value specified for the selected attributes of xsl:value-of and xsl:for-each instructions

The context node processed by the instruction (when applicable)

The context node data (when applicable)

The tracing extension object method will log these parameters in a tab-delimited text file, thereby generating an execution trace log as the transformation is processed and executed. For each instruction, the time elapsed since the execution of the previous traced instruction and the total cumulative time elapsed since the transformation began will also be reported. These values will serve as simple but useful profiling data that can help identify performance bottlenecks in the style sheet execution.

Instrumenting the style sheet to add trace points eliminates the need to have access to the query processor's implementation to implement tracing functionality. The goal is to treat XSLT as an XML transformation/query programming language that can be instrumented and whose execution can be traced like any other regular programming language.

4. The generated trace log can be opened and viewed using Microsoft Excel. This will contain an instruction trace to the point of failure, manual termination (hang scenarios), or completion. In failure and manual termination scenarios, the trace log can be used to study the execution sequence of the transformation and isolate the cause of the problem. In scenarios where the transformations run to completion, the profiling information in the trace log can be used to evaluate the performance and identify any significant bottlenecks that may exist. Figure 2 is a snapshot from a trace log generated by the XslTransform wrapper.

5. When the option to persist the source XML is enabled, the XSLT processor will write the source XML to a dynamically generated XML document that will be persisted in the trace output folder. The persisted source XML can be matched with its instruction trace log using the timestamp value used to construct the names of these files.
6. When tracing is disabled, there will be no performance hit and the XSLT processor will execute XSLT transformations in a regular mode as depicted in Figure 3. This is very important to ensure that there is no additional overhead when XSLT tracing is disabled (the default).

Implementation
Note: The implementation discussed in this section and provided as a download with this article is an unsupported sample. Do not use it directly in production environments. The objective of this implementation is to illustrate how tracing functionality can be implemented to trace XSLT transformations in .NET applications. You are encouraged to study the source code of the sample XslTransform wrapper, add additional features as required, and use it in development/testing environments to troubleshoot and profile XSLT transformations executed by your .NET applications. You are also encouraged to invest additional development and testing efforts to implement/enhance and fully test an identical custom XslTransform wrapper for use in your production environments.

This section will explain the implementation of the sample XslTransform wrapper to trace and profile XSLT transformations in .NET applications. The implementation will be based on the architecture detailed in the previous section. An understanding of the design goals and the architecture is required to comprehend the implementation specifics.

Prior to getting started, you will first need to download and set up the sample project files provided with this article. Execute the following steps to do this:
1. Download TracingSample.zip from www.sys-con.com/dotnet/sourcec.cfm and save it on your local hard disk.
2. Extract the contents of the zip file to the root folder of your hard drive (C:\). This will create two subfolders, named TracingDemo and TraceOutput. The Xslt-Diagnostics solution in the TracingDemo\XsltDiagnostics folder contains the Visual Studio .NET 2003 project files for the XslTransform wrapper class and the XSLT tracing extension object. The TracingClient solution in the TracingDemo\Tracing-Client folder contains the project files for a sample console EXE client application that will be used to illustrate the XSLT tracing functionality implemented by the XslTransform wrapper. Trace-Output is configured as the XSLT tracing output folder in the TracingClient application configuration file.

Open TracingClient.sln (located in the TracingDemo\TracingClient folder) and XsltDiagnostics.sln (located in the Tracing-Demo\XsltDiagnostics folder) in two instances of the Visual Studio .NET 2003 IDE. Enable the option to Show all files in the Solution Explorer window of both instances.

With the sample files set up, we will now see how the architecture described in the previous section maps to the implementation of the sample XslTransform wrapper.

The XSLT Processor
The sample XslTransform wrapper type will be used as the XSLT processor in this implementation. The XsltDiagnostics.XslTransform2 type implements this wrapper. Wrapper implementations are required in order for the XslTransform constructor, the Load method, and the Transform method to implement the desired tracing functionality. To keep things simple and to be able to focus on the implementation of the tracing functionality, the XslTransform2 type implements wrapper methods for only the following Load and Transform method overloads:

Load(string url)
Transform(IXPathNavigable,XsltArgumentList,TextWriter)

Don't worry about understanding the functionality of the code in these wrapper methods at this point. I will get into this as we dig deeper into the implementation specifics of the tracing functionality. For now it is sufficient that you understand that the code written to use the XsltDiagnostics.Xsl- Transform2 wrapper type to execute XSLT transformations (using the supported Load and Transform wrapper overloads) will be identical to the code required to use the System.Xml.Xsl.XslTransform type for the same purpose. The following code taken from the Main method of the TracingClient.StaticClient type illustrates this:

XslTransform2 stylesheet = new XslTransform2();
stylesheet.Load("people.xsl");

XPathDocument data = new XPathDocument("people.xml");

System.IO.StreamWriter output = new System.IO.StreamWriter("output.html");

stylesheet.Transform(data,null,output);

The XSLT tracing functionality is configured using an application configuration file (discussed next) and used by the XslTransform2 Load and Transform wrapper methods. No source code modifications or setting of additional properties is required in the client applications to trace XSLT transformations executed by them. Subsequent references in this article to the term XSLT processor refer to the XsltDiagnostics.XslTransform2 type and/or object instances of it.

Configuring XSLT Tracing
In this implementation, regular .NET application configuration files will be used to configure XSLT tracing. For EXE applications, this will be the <AppName>.exe.config file located in the executable folder, and for ASP.NET applications it will be the Web.config file. Keys to configure the aspects of tracing described in the design goals will be defined in an <appSettings> section. The XslTransform wrapper will read in these configuration settings on instantiation to determine the XSLT tracing options that must be applied when executing transformations.

Listing 1 is a sample <appSettings> section (taken from the TracingClient application configuration file) used to configure XSLT tracing in this implementation. (All of the code referenced in this article can be downloaded from below.) The use of the configuration options is described in Table 1.

On instantiation the XSLT processor will read in these settings from the application configuration file. The settings specified for each of these configuration parameters will control the subsequent tracing functionality.

Listing 2 shows the code in the constructor of the XsltDiagnostics .XslTransform2 type to read in the settings specified for the XSLT tracing configuration parameters. The code in the constructor instantiates the wrapped System.Xml.Xsl.Xsl Transform object, and uses an instance of the System.Configuration. AppSettingsReader .NET Framework class to read and store the values of the XSLT tracing configuration parameters defined in the application configuration file. The configuration parameter names are case sensitive (by virtue of being specified as XML). An attempt to read a missing parameter (not defined in the configuration file, misspelled, or typed using the wrong case) will generate an InvalidOperationException. Each GetValue method call is wrapped in a distinct tryScatch block to prevent a missing/misspelled configuration parameter from hindering the attempt to read subsequent configuration parameters. The TraceXSLTStyleSheets parameter is used to determine whether or not to enable XSLT Tracing. Tracing will be disabled when this parameter is set to false (the default) or is missing/misspelled.

Instrumenting the XSLT Style Sheet
XSLT style sheet instrumentation is the process used to add trace points to an XSLT style sheet to trace its execution. In the sample implementation, the instrumentation process can be configured to add trace points to trace the execution of the following XSLT instructions. Tracing these instructions should in most cases help you narrow down on the problematic style sheet segment/instruction:

xsl:template
xsl:for-each
xsl:value-of

You can extend the implementation to trace the execution of additional XSLT instructions using the implementation technique described in this section.

When the style sheet is initially loaded, the value of the TraceXSLT- StyleSheets configuration parameter is used to determine whether or not it should be instrumented. Trace points will be introduced in the style sheet to trace its execution when this option is enabled (disabled by default). When disabled, the original style sheet is loaded as is with no modification.

The trace points in the instrumented style sheet are calls to a tracing extension object method that takes the parameters shown in Table 2 (as applicable to an instruction being traced) and uses them to generate the execution trace log. The instrumentation routine parses each XSLT instruction for which tracing is enabled to extract the values that must be supplied for the match, name, and select parameters. The local-name XPath function and the period (.) context node XPath operator are used to supply the last two parameters. The tracing extension object method will use these parameters to generate a tab-delimited execution trace log as the transformation is executed. For each instruction, the time elapsed since the execution of the previous traced instruction and the total cumulative time elapsed since the transformation began will also be reported. These values are close approximations and will serve as simple but useful profiling data that can help identify performance bottlenecks in the style sheet execution.

xsl:value-of elements are used to insert the extension object method calls to trace the style sheet execution. The extension object method will return an empty string for xsl:template and xsl:for-each instructions after logging their execution. For xsl:value-of instructions, it will evaluate the select expression and return the result as a string. This makes it possible to completely replace an xsl:value-of instruction with a call to the extension object method. The position of a generated xsl:value-of trace point in relation to the XSLT instruction being traced is summarized in Table 3.

The sample implementation does not automatically resolve and instrument style sheets imported (xsl:import) and/or included (xsl:include) by the main style sheet loaded into the XSLT processor. The source code for the sample implementation can be downloaded from www.sys-con.com/dotnet/sourcec.cfm. Study the inline comments to understand the implementation specifics.

Executing the Style Sheet and Tracing the Transformation
When an XSLT transformation is executed with the tracing option enabled, an object instance of the XSLTDiagnostics.XSLTTracer type is instantiated and associated with the context of the XSLT processor. The XSLTDiagnostics.XSLTTracer type implements the functionality of generating the XSLT execution trace logs. As explained in the previous section, the trace points in the instrumented style sheets are calls to the traceInstruction method implemented by this type. This method is invoked by the XSLT processor for each configured instruction as the transformation is executed. Suitable parameter values required to generate a trace line for each instruction will be passed to the method when it is invoked.

Listing 3 shows the code used to implement the Transform wrapper method in the XsltDiagnostics. XslTransform2 type. Study the inline comments to understand its functionality.

The code to persist the XML data is implemented in the private RecursivelyWalkAndPersistData method. You can examine this method at your convenience to see how code can be written to persist data loaded into an IXPath-Navigable object that does not implement a Save method (e.g., XPathDocument).

The generated trace log and the persisted XML data will be deleted if the option to delete logs for successful transformations (XSLTTrace-DeleteLogsWhenSuccessful) is enabled. The default setting for this parameter is True to prevent the logs generated for successful transformations from cluttering the disk. When profiling the performance of XSLT transformations that execute to completion you should disable this option to be able to view the generated trace log.

Note: When tracing is disabled, the transformation will be executed in a regular mode without accruing any of the overheads associated with tracing its execution.

Conclusion
Instrumenting and tracing XSLT transformations by treating XSLT as a regular programming language can provide very useful diagnostic data to help analyze and troubleshoot related problems. The sample implementation discussed in this article is a proof of concept "scratch the surface" prototype to illustrate how this can be done and the value of XSLT tracing. In Part 2 of this series I will walk you through a couple sample scenarios to illustrate the use of the XSLT tracing implementation discussed here.

I hope that I have managed to whet your appetite on this subject and get your creative juices flowing on ways to further enhance this base implementation to address additional specific requirements that you might have. I am also very interested in hearing your feedback on the value of a feature like this being built into the .NET System.Xml and MSXML stacks.

Author Bio
Karthik Ravindran is a supportability program manager in the Microsoft WebData Product Support Services group. His core responsibilities include helping enterprise customers successfully implement solutions using Microsoft's WebData XML technologies, evaluating and communicating customer product feedback to product groups, and working with product groups to review and provide input on the implementation of supportability/usability features.

Source Code for this Article zip file ~187 KB