ConvertRsToXml, A Case Study of Timing and Optimizing ASP/ADO CodeBy Michael Balloni
A recent article by David O'Neill, Simplifying
ConvertRStoXML() and Transforming
With XSL, discussed performance enhancements made to a very
useful, and very performance sensitive method, named
ConvertRsToXml(). This method,
which was first presented by author Scott Mitchell in an article
titled Creating a Function to Stream a Recordset to XML
essentially converted the contents of an ADO Recordset into an easy-to-read XML string, which could
then be cached or transformed into HTML. (Of course, ADO's Recordset object can natively save its contents
into an XML file, but the resulting XML file is very ugly and very hard to read.)
I was curious to see what impact David's performance enhancements had made to the system, and emailed
David asking for details on his timing mechanisms. David was nice
enough to give me the source code and the original timing framework, which you can obtain from
this download. Armed with this test suite, I set
out to time the difference in performance of the various versions of the
method and how they stacked up against the Recordset's native
Save method for saving
its contents to (ugly, not directly-useable) XML. I also put some time into making some
optimizations of my own to
ConvertRsToXml(), including moving it into a VB COMponent.
The Low-Tech Approach To Timing
David's original timing framework was of a form that you may be familiar with:
This is a good solution for operations that take longer than a couple seconds, but if you want accurate numbers for ASP operations that take less than a couple seconds, you'll need to make use of a custom component, either one of your own creation or a third-party one. I use Softwing's Profiler component, freely available from http://www.alphasierrapapa.com/IisDev/Components/Profiler/ There's good commentary on that page on the importance of timing performance critical code, too. In fact, there's even an article on using this component here on 4Guys (see Timing ASP Execution using a Profiling Component).
And yet, even with that excellent and free component in hand, it requires a good bit of hand-coding to get information out about what sections of code took what kind of time. In other development environments like VB or C++, professional-grade profiling tools exist which will pin-point exactly which lines of code and which sub-routines are taking the most time, and which ones your system/unit tests are not hitting (you are employing system and unit tests to your VB and C++ code, aren't you?). And I get the sense that the .NET platform will have powerful new facilities for analyzing the performance of your pages and classes. But in lowly old ASP, we have to "roll our own." So I developed a small VBScript class library to do timing in as elegant a way as possible.
SlTiming Class Library
The class library, which you can download here, consists of the following schema:
SlTimer- A thin wrapper for the
Stopmethods and a read-only
ElapsedMsproperty. Be aware that
ProfileStopmethod returns a value in ticks (tenths of milliseconds).
SlTimerContext- Provides the bulk of the framework in its
ExitScopemethods. It maintains a dictionary of "scopes" which are simply hit counts and total elapsed times associated with the descriptive name. When you
EnterScope, the scope gets another hit and a timer starts, when you
ExitScope, the timer stops and the elapsed time is added to the total.
SlTimerScope- Simplifies timing methods by calling the
EnterScopemethod from its
Entermethod and unconditionally calls the
ExitScopemethod in its destructor, so you can rely on the
ExitScopemethod being called when you use this system for timing methods that have multiple
Exitstatements or even when errors occur. In practice, it's easier to just call the
ExitScopemethods for timing sections of code, and it's easier to this class for timing entire sub-routines.
SummarizeTiming- A method for outputting a report on the time taken by the various recorded scopes. Simply pass in your
SlTimerSontextinstance and it will output a nice little table telling you which scopes got hit however many times and took however long.
One enhancement to this system would be for
SlTimerContext to maintain a stack of scope names so that you wouldn't need to
pass a scope name to the
ExitScope method. Maybe another day. Be sure to
download this helpful file for timing the execution of
your ASP scripts.
So I've Got The Time, Now What?
The general idea with this type of hand-timing system is to surround the code you think is taking a long time with timing scopes, and then zero in on which areas are taking the longest. It is very important to not make any assumptions about where the code that needs optimizations is without having the timing numbers to prove it, as premature optimization is one of the biggest sources of software development inefficiencies (C.A.R. Hoare, more good insights at: http://www.vanderburg.org/soft-quotes.html).
So let's use the
ConvertRsToXml example to explore
this further. In this case, we have three versions of the same
ConvertRsToXml method, plus my rogue tweaked version, and a VB method of the
same ilk, and we're trying to determine which one performs the best. We've
made various optimizations to each succssive version, but without the numbers to
prove it, we're better off sticking with the one that's the most
tried-and-true...so let's get those numbers! (You can view my tester code, in text format,
Under no load, these are the numbers I got comparing
the different RsToXml and recordset-getting methods (an explanation of each type
of method is provided after the table):