Why not ORM: OpenAccess Watcher, Part 3

In part 1 of this ongoing series, we dispelled ORM myths, shaking the errant assumptions that many developers still hold about ORM. In part 2, we took a deeper look at why and how you can learn to trust the SQL an ORM produces. In part 3, we'll examine a simple tool I've crafted to help with that SQL visualization when using Telerik's OpenAccess ORM.

WHAT DOES THE TOOL DO?

The goal for this tool is simple: make it simple to visualize and summarize in real-time the SQL output from any OpenAccess-powered application. My self-imposed requirements were simple, too:

• The tool must add value above and beyond what OpenAccess' built-in logging provides
• The tool must be easy to setup with any application (win or web)
• At most, 1 assembly reference, 1 line of "initialization" code
• The tool must work with "new" (Visual Designer) and "classic" (IObjectScope) OpenAccess

THE RESULT: OPENACESS WATCHER

The tool, which I've dubbed OpenAccess Watcher, is composed of two parts:

1. The Watcher- This is a simple WinForms application built with the Telerik RadControls for WinForms and the SharpDevelop TextEditor (for syntax highlighting) that "listens" for messages from OpenAccess applications.
2. The Sender- This is a custom OpenAccess TraceListener that builds on the built-in OpenAccess logging to format and send messages in real-time to The Watcher, which in turn handles the visualization. There is also some advanced use of JustMock's CodeWeaver, but more on that in a moment.

The key thing to understand is that (for the most part) this tool is working with the same data you might find in the OpenAccess logs. It's value is in the summary stats it provides, the easier data navigation and visualization, and the "real-time" nature of the log output.

USING OPENACCESS WATCHER

Sticking to my requirements, OpenAccess Watcher requires minimal setup. To use it in an OpenAccess-powered app, you must simply:

1. Add a reference to the assembly that contains "The Sender" (OpenAccessWatcher.Listeners.dll)
2. Initialize the custom TraceListener during your application startup
• For Web, this means 1 line of code in Application_Start in Global.asax
• For Win, this means 1 line of code in your Program's Main method

That's it! Two steps. Now all you need to do is open "The Watcher" and start your application. If everything is working, you'll start seeing OpenAccess generated SQL show-up in The Watcher. (A complete "Getting Started" readme is available with the code.)

UNDERSTANDING THE LOG DATA

Since this tool does depend heavily on the OpenAccess log data, it's important to understand what's available. First, what's available is directly connected to the level of logging you've configured. The three common modes are:

• Normal - This is good for capturing the basic SQL statements, but omits most of the log data that can be used to interpret other behaviors (like row count).
• Verbose - This is good for capturing most SQL behavior, including connections, but it can significantly slow the execution of some applications.
• All - This gives you maximum logging data and enables you to measure things like total rows returned and total data readers opened. Unfortunately, this can really slow down bigger apps.

My suggestion: Start with verbose. If that makes your app unbearably slow, try using normal. If your app runs tolerably with verbose and you want to try to get event more data, then give all a try.

It should also go without saying, these are not settings for production or for measuring application speed. These are settings specifically designed for visualizing SQL behavior during development, with the goal being to use the info for tuning ORM performance configuration.

EXAMPLE APP

To test OpenAccess Watcher, I've got a simple WinForms application with a RadGrid that loads data using the OpenAccessDataSource. When I open the page with this grid, I see the following in Watcher:

There are three primary areas of information:

1. SQL Activity Log (A) - This is a raw log of the SQL queries generated by OpenAccess (pulled from the OpenAccess logs). This data is displayed in a RadGrid for WinForms, so you have the complete ability to sort, filter, and group this data.
2. SQL Visualizer (B) - Using the open source ShareDevelop TextBox, this area better visualizes the selected SQL statement so that you can easily review the SQL with syntax highlighting.
3. Statistics Summary (C) - This area displays the values from various logging counters that summarize OpenAccess database activity. The version of OpenAccess you're using and your logging settings will impact that values that are available here.

While I'll save a full discussion of how to work with this data for Part 4, it's worth noting now that there is not a one-to-one relationship between SQL queries and database connections. OpenAccess typically prepares and executes multiple queries in batch, so don't freak out if you see larger numbers of queries.

ADVANCED LOGGING: CODE INJECTION

As I alluded to above, I am making use of Telerik's very cool CodeWeaver library, available with JustMock, to do IL injection with OpenAccess assemblies. This allows the custom TraceListener to go beyond tracking OpenAccess log data and inject code in to key OpenAccess methods that is used for gathering statistics.

Newer versions of OpenAccess (Q3 2010+) have convenient IntelliTrace and CommandWrapper classes through which all OpenAccess connections and transactions pass, so by injecting some counters in these methods I am able to report on connections and transactions even when logging is tuned-down or disabled.

For older versions OpenAccess, I am not able to do counters as easily, but there is still some injection in to the very low-level Transaction and Connection runtime implementations to help gather as many stats as possible for the visualizer.

In all cases, the code injection tooling will only work when the JustMock profiler is enabled. When not available, you'll get fewer stats.

IT WORKS ON MY MACHINE DISCLAIMER

This is an experimental project. It is not guaranteed to work with your setup. If it doesn't, I'm sorry. Send me feedback and I'll see what I can do to make it cover more scenarios. Known caveats with this preview:

• I'm primarily focusing on SQL Server scenarios today. It should work for other OpenAccess providers, but I haven't tested that yet.
• I've only tested this with .NET 4.0 projects. I'm not sure what will happen if you try to use the custom TraceListener with older .NET versions.
• Your application probably needs to be running in full trust to support the reflection and code injection tooling that's going on.
• The UI of the WinForms app can "hang" when huge volumes of logging data are being collected. Just wait a few seconds and it should become more responsive.

THE BITS

Disclaimer out of the way, here are the bits. Enjoy and share your feedback.

In Part 4, I'll show you how you can use The Watcher to start learning and optimizing the SQL generated by OpenAccess. Since OpenAccess has powerful configuration and optimization options, it's surprisingly easy (compared to other ORMs) to tweak once you have a clear understanding of what's happening.