Logging for .NET with SmartInspect

This article demonstrates how to use SmartInspect .NET Logging. SmartInspect helps you to find and solve bugs in your software and makes it easier to identify security issues and performance bottlenecks.

Logging is a technique used in many programs and by many developers to find configuration problems and software bugs at run-time without using a traditional software debugger. Logging involves recording messages, errors, and other system parameters. The information stored in the log is then used to build an audit trail of a software application, to identify and fix problems, and to find security holes and performance bottlenecks. This is especially useful on production systems and at customer sites where a debugger or performance profiler is problematic or even impossible to use.

Several logging libraries and frameworks are available for .NET. But right now I'd like to highlight an advanced logging tool called SmartInspect .NET Logging. SmartInspect consists of two parts. The first part is a logging library that can be used by a software application to record messages. The other part is a viewer application called the SmartInspect Console which is used to analyze and filter the log data.

Most logging tools can only record simple text messages, but that's not the case with SmartInspect. With it you can log messages, exceptions, objects, variable values, call stack information, files, and a lot more. This expanded ability combined with the graphical viewer application makes SmartInspect an interesting and unique tool.

Getting Started with SmartInspect for .NET

Although SmartInspect comes with logging libraries for .NET, Java and Delphi, the focus of this tutorial is on .NET. But don't worry; the three libraries all share the same core features so usage doesn't differ much. If you haven't yet downloaded SmartInspect, click here to download it now.

To get started with SmartInspect, first add a reference to the Gurock.SmartInspect.dll assembly to the project in Visual Studio. The SmartInspect setup typically registers the assembly with Visual Studio, so this is really easy. I will use a simple WinForms application in this tutorial.

Notice the SiAuto.Si object? This is an instance of the SmartInspect class. The SiAuto class is providing some default instances that are ready to be used for logging. We could easily create the SmartInspect and related instances ourselves. But for most applications, including our example, the default instances are sufficient.

Let's now log some messages and variable values and display them in the SmartInspect Console. The SmartInspect logging library contains various logging methods for all kinds of data, but let's start with some simple text messages and value types. Add a button to the main form and add the following code:

Now when you start the SmartInspect Console, run the test application, and press the button, the following log messages appear in the Console:

Pretty easy, wasn't it? Now let's use some of SmartInspect's more advanced log methods to log exceptions, objects, images, and call stack information. I added another button to the form and added the following code to the new button's event handler:

Most of the code should be self-explanatory. The EnterMethod and LeaveMethod calls are used to tell the Console which methods are called and in what order. This allows the Console to indent the log messages and build a call stack. If you run the example program and view the result in the Console, it should look something like this:

The above screen shot already shows another feature of the Console: the Viewers. Various specialized viewers are available to display the different data types that can be sent to the Console. The above screenshot shows the Graphic Viewer in action displaying the attached data of the selected log entry.

Several other viewers are available for displaying tabular data, properties, binary data, text, source code (and SQL queries) and even HTML. The Console screenshot also shows the Call Stack toolbox that is displaying the call stack of the selected log entry.

Protocols and Configuration Files

Logging in real-time to the local Console via named pipes is great when you want to debug an application locally. When you need to debug an application over the network or when you need to create log files, you can configure SmartInspect to use other logging connections. To tell SmartInspect to use log files, you can simply assign an appropriate connections string:

SiAuto.Si.Connections = "file(filename=log.sil)";

Different protocols are available for different needs. The following examples show several logging protocol options and combinations:

// Use high-performance named pipe protocol for local logging
SiAuto.Si.Connections = "pipe()";
// Use a binary log file that is rotated hourly
SiAuto.Si.Connections = "file(filename=log.sil, rotate=hourly)";
// Log to another machine on the network
SiAuto.Si.Connections = "tcp(host=192.168.1.100)";
// Use a text log file for end-users that only shows errors, and a
// detailed encrypted binary log file for developers
SiAuto.Si.Connections = "text(filename=errors.txt, level=error), " +
"file(filename=debug.sil, encrypt=true, key=SECRET, level=debug)";
// Log to memory (we can then get the logging data later when a
// crash occurs, for example. This is really great performance-wise).
SiAuto.Si.Connections = "mem(maxsize=2048)";
// Now comes a complicated one, just to show the possibilities:
// Log to memory, and when an error occurs, automatically write
// the last 2MB of log data to the file and rotate the file hourly.
// This is really, really useful for production systems.
SiAuto.Si.Connections = "file(filename=log.sil, rotate=hourly, " +
"backlog.enabled=true, backlog.queue=2048, " +
"backlog.flushon=error)";
// Log asynchronously via TCP/IP so that the application isn't
// blocked when the connection times out
SiAuto.Si.Connections = "tcp(host=192.168.1.100, " +
"async.enabled=true, async.queue=2048)";

As an alternative to assigning the connections string and enabling logging hard coded in your application, you can use SmartInspect configuration files to dynamically change the logging configuration. This allows you the option of keeping logging off by default and only enabling logging on a specific machine or for a specific customer when needed. It's also possible to configure the connections and the log levels via configuration files. I'll talk more about log levels later. To use a configuration file, just call the LoadConfiguration method. If the specified configuration file doesn't exist, logging remains disabled:

SiAuto.Si.LoadConfiguration("logging.sic");

You can easily create configuration files and connection strings using the SmartInspect Configuration Builder to configure the various settings and protocol options. You don't even have to remember the exact connection options:

SmartInspect also includes a feature to automatically reload the configuration file at run-time. That means you don't need to restart an application to pick up configuration file changes. This is really important for production systems or web applications that shouldn't be restarted.

Views and Filters

Another useful concept of the SmartInspect Console is the View concept. The views occupy the main space of the Console and show the log entries. You can create multiple views and configure them to filter for certain log entry types, for the source machine, or the source application. You could, for example, create a view that only shows errors and warnings, enabling you to see all errors at a glance. Another scenario could show only the log entries of a specific thread, making it easy to see what a particular thread is doing. You can also group views in View Categories which can be seen at a glance in the View Categories toolbox.

For more complex scenarios like a distributed system or multi-threaded application, the Console allows you to automatically create new views for certain parameters. For example, you could configure the AutoView Rules to generate a new View for every new thread that sends logging data to the Console. In seconds you can figure out exactly what each thread or process is doing.

Sessions and Log Levels

In instances when tens of thousands of log entries exist in a single log file, it's often important to distinguish log entries from the different application modules that generated them. The SmartInspect sessions feature can be used for exactly this purpose. With it you can create separate SmartInspect sessions for your application modules and easily filter for them in the Console.

For example, if you want to see only the log entries generated by the database module of your application, simply create a SmartInspect session for that module and use it to log related log entries. The following example demonstrates how to create two SmartInspect sessions and assign them different background colors.

The SiAuto.Main instance is actually such a session. You can easily create new session objects, assign names to them, and then filter for sessions in the Console. You can also give log entries of a particular session a different background color making it easy to distinguish between them in the Console.

Using log levels is another way to filter and reduce log entries. Log levels are library-side filters used to specify the types of messages that should be logged and which should be discarded. You can, for example, specify that only warnings and errors should be logged. In this example, all other messages are automatically discarded and not written to the actual log file or sent to the Console.

Log levels are especially useful for production systems where you want to see only the most important messages such as errors by default. When problems occur and you need to dig deeper, simply enable more detailed logging by changing the log level. Just like connections, the log level can easily be set via configuration files or programmatically:

Advanced Features

Two more advanced features that I would like to quickly introduce are the Watches Graph and the Process Flow toolbox.

The Watches Graph tracks numeric values and displays them in a convenient time graph. It is especially useful for tracking and visualizing application resources like databases connections, file handles or the amount of allocated objects. The Watches Graph makes it easy to detect resource leaks, bottlenecks or wasteful resource usage.

The Process Flow toolbox displays all processes and threads of your log, their corresponding hostnames, start times and durations. With a press of a button you can create a new view for each entity and inspect the log entries independently from the rest of your log. This is especially useful for multi-threaded and distributed applications.

Summary

I hope this article was useful in explaining what logging is, how it can help debug your applications, and how you can implement logging in .NET, Java and Delphi applications with SmartInspect. If you're interested in learning more about SmartInspect and all of its other features not mentioned here, please visit the SmartInspect website. Once there you can take the tour or download it.