Tracing plays an important part in keeping track of how things are flowing through in your Application Services. Configuring tracing to collate system output is invaluable in gathering correct information about what the service is actually doing other than throwing a HTTP 5xx or HTTP 4xx error.
If you want to implement a TraceWriter of your own, you can implement the ITraceWriter and register it as the required or you could use the Microsoft.AspNet.WebApi.Tracing package from Nuget and simply turn on Tracing.
Before we look into tracing let’s take a sneak peek behind the ‘interesting’ implementation of Tracing in Web API.
Behind the Scenes with Web API Tracing
Web API’s tracing implementation looks for the presence of an ITraceWriter instance in its services during startup. If an ITraceWriter implementation is available, it is used. if not, no tracing is attempted.The beauty of Web API’s design is that it doesn’t suffer any major penalty if no ITraceWriters are available. Usually Tracing involves checking for tracing support for every attempt. However Web API core does not contain any tracing aware code. If it detects availability of a TraceWriter, it wraps the registered services in their respective trace-aware wrappers. This implementation helps avoid performance penalty of having trace aware code in the core of the framework.
What does the Framework trace
The Framework by default traces most services that are registered with it in the HttpConfiguration.Services. It also traces the execution flow of objects returned from any of these services’ methods and is not restricted to framework code only. The above mentioned wrapper technique ensures that even custom service implementations are traced. Of course only public and protected methods that provide the implementation of the API Interfaces are auto-traced. Custom Public and Protected methods are not traced automatically.The Begin and End Format of tracing
Going back to the trace-wrapper type of implementation, Framework traces the Begin and the End of every operation. It writes to trace once the execution enters a method and then irrespective of success or failure, writes to trace after the method has returned. This enables pretty verbose Trace logging if desired.A Web API TraceWriter
Originally Web API did not ship with a default implementation of ITraceWriter and left it to the community to develop various logging specific TraceWriters. However as of date, with .NET Framework 4.5 and Web Tools Update 2, you get the package installed out of the box if you start with a new WebAPI project. Tracing is now enabled by default and if you naviagate to the App_Start\WebApiConfig.cs file, you will see the following lineconfig.EnableSystemDiagnosticsTracing();
This enables tracing using the SystemDiagnosticsTraceWriter. This logs Info level traces to the Output window in Visual Studio while debugging.
Enabling Tracing in a non-Web API Project Template
However if you started with a Basic Project template or an Internet Template etc. tracing is not enabled by default and neither do you have references to the Tracing package.Step 1: We have to start off by installing the Tracing dependencies from Nuget
PM> install-package Microsoft.AspNet.WebApi.Tracing
Step 2: At this point there is a short route and a long route to enabling the default TraceWriter. Simply add the config.EnableSystemDiagnosticsTracing() line in Global.asax.cs for the shorter route.
The Long Route however sets you up so that you can swap out the default TraceWriter with your own rather easily. Let’s see the long route also. In the App_Start folder, add a class called TracingConfig.cs. This is just a static class that will have the initialization code for the TraceWriter.
Step 3: Add a Static Method called Register that takes an input parameter of type HttpConfiguration.
public static void Register(HttpConfiguration config)
{
…
}
Step 4: In the Register method, we first ensure config is not null and if it is, throw an exception. Next we create a new instance of the SystemDiagnosticsTraceWriter. This is the default TraceWriter that comes with the Tracing package mentioned above and it uses System.Diagnostics to do the trace logging. So while debugging, we can see the Logs in the Output windows itself.
As seen below we are setting up the Logger with Tracing level to Info (so it will trace and log pretty much everything) and the IsVerbose is set to false. The complete Register method is as follows
public static void Register(HttpConfiguration config)
{
if (config == null)
{
throw new ArgumentNullException("config",
@"Expected type HttpConfiguration.");
}
SystemDiagnosticsTraceWriter writer = new SystemDiagnosticsTraceWriter()
{
MinimumLevel = TraceLevel.Info,
IsVerbose = false
};
}
Step 5: The Register method will be invoked where the rest of the Configurations are invoked from i.e. Global.asax’s Application_Start event.
protected void Application_Start()
{
AreaRegistration.RegisterAllAreas();
WebApiConfig.Register(GlobalConfiguration.Configuration);
FilterConfig.RegisterGlobalFilters(GlobalFilters.Filters);
RouteConfig.RegisterRoutes(RouteTable.Routes);
BundleConfig.RegisterBundles(BundleTable.Bundles);
TracingConfig.Register(GlobalConfiguration.Configuration);
}
Step 6: With Tracing configured, let’s run the default application and navigate to the URL http://localhost:[port#]/api/values . As we can see below, a big bunch of Information logs came in with the details of the Operation, the path of execution as well as Response status.
Writing into Trace Logs from Custom Code
So we saw above how the Web API framework detection of the ITraceWriter has started writing Tracing information. What if we wanted to piggy back the same TraceWriter to write our own logs as well?It’s pretty easy actually; however we should be diligent with our code to maximize reuse. So we’ll wrap the Tracing method in the following WriteToTrace method. This method takes in a string for categorizing your traces, the actual string that you want to log and the TraceLevel at which you want to log.
private void WriteToTrace(
string category,
string log,
System.Web.Http.Tracing.TraceLevel level)
{
System.Web.Http.Tracing.ITraceWriter writer =
Configuration.Services.GetTraceWriter();
if (writer != null)
{
writer.Trace(
Request, category, level,
(traceRecord) =>
{
traceRecord.Message =
String.Format("Inside CustomCode with param = {0}", log);
});
}
}
From the Get method we call our WriteToTrace method that specifies the Trace as a part of the Category called Controllers with the log string specifying how many elements being returned and the TraceLevel is set to Info.
// GET api/values
public IEnumerable<string> Get()
{
WriteToTrace(
"Controllers",
"There are 2 elements in the return array",
System.Web.Http.Tracing.TraceLevel.Info);
return new string[] { "value1", "value2" };
}
If we run the Application again and hit the api/values URL, we will see the additional trace information in our output trace.
Implementing your own TraceWriter
Now that we have seen the default TraceWriter in action, we can very well imagine writing TraceLogs to SQL Server, and Log4Net logs and NLog and basically our favorite Logging platform. Well, implementing a custom TraceWriter is easy to get started with and can get as involved as you would like it to be.Step 1: We add a folder called Infrastructure and add a class CustomTraceWriter. This has to implement the System.Web.Http.Tracing.ITraceWriter interface. The interface as we can see has only one method - Trace.
public class CustomTraceWriter : ITraceWriter
{
public void Trace(
System.Net.Http.HttpRequestMessage request,
string category,
TraceLevel level,
Action<TraceRecord> traceAction)
{
…
}
}
Step 2: In the trace method we could practically use any logging framework to Write our trace to, but for simplicity, let’s say we want to Write to an XML file that we are going to save in the App_Data folder. The implementation would be similar to the following:
public void Trace(System.Net.Http.HttpRequestMessage request, string category, TraceLevel level, Action<TraceRecord> traceAction)
{
TraceRecord rec = new TraceRecord(request, category, level);
traceAction(rec);
string path =
Path.Combine(AppDomain.CurrentDomain.GetData("DataDirectory").ToString(),
"log.xml");
using (Stream xmlFile = new FileStream(path, FileMode.Append))
{
using (XmlTextWriter writer = new XmlTextWriter(xmlFile, Encoding.UTF8))
{
writer.Formatting = Formatting.Indented;
writer.WriteStartElement("trace");
writer.WriteElementString("ts", rec.Timestamp.ToString());
writer.WriteElementString("oper", rec.Operation);
writer.WriteElementString("user", rec.Operator);
writer.WriteElementString("log", rec.Message);
writer.WriteElementString("category", rec.Category);
writer.WriteEndElement();
writer.WriteString(Environment.NewLine);
}
}
}
The key here is, the first line in the method, where we are creating an instance of the TraceRecord.
Note the TraceRecord class is a part of Web API. When implementing Tracing, if we use the TraceRecord it manages the User information, Operation, TimeStamp etc. from the Request Message giving us a clean encapsulation of relevant data.
We then open up an XmlWriter in our App_Data folder called log.xml and dump the content of the TraceRecord into it.
Step 3: Now let’s replace the default TraceWriter with our own Writer. At this point if you are in a Web API project you can add the following code to the WebApiConfig.cs to replace the default writer.
CustomTraceWriter writer = new CustomTraceWriter();
config.Services.Replace(typeof(ITraceWriter), new CustomTraceWriter());
On the other hand if you are in a Non-Web API project template, you can update the Register method of TracingConfig.cs as follows
public static void Register(HttpConfiguration config)
{
if (config == null)
{
throw new ArgumentNullException("config",
@"Expected type HttpConfiguration.");
}
//SystemDiagnosticsTraceWriter writer = new SystemDiagnosticsTraceWriter()
//{
// MinimumLevel = TraceLevel.Info,
// IsVerbose = false
//};
CustomTraceWriter writer = new CustomTraceWriter();
config.Services.Replace(typeof(ITraceWriter), new CustomTraceWriter());
}
Step 4: With our Trace Writer in place, let’s run the application again and visit the api/values path. Once we get the download notice in browser, let’s switch back to Visual Studio.
In Solution Explorer, toggle the ‘Show All’ button so that files that are not a part of the solution are also visible.
Expand the App_Data folder and open the log.xml file. Scroll down and you will see our Custom Trace has been logged here too. Nice and easy!
Conclusion
Tracing is an important tool for debugging and tracking System behavior. We took a quick peek at ASP.NET Web API’s Tracing implementation and its unique features. We also saw how we could enable Tracing in non-Web API template based MVC Apps that use Web API.Finally we wrote a quick and dirty Xml Trace Writer that produces XML Trace Output.
Download the entire source code of this article (Github)
Fantastic Article...Implemented it and works like a charm
ReplyDelete