Published: Sunday, February 03, 2002
ConvertRsToXml, A Case Study of Timing and Optimizing ASP/ADO Code
By Michael Balloni
Introduction
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 ConvertRsToXml()
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:
<%
Dim date_start
date_start
= Now
' Do something lengthy.
Dim date_end
date_end =
Now
Response.Write "Start=" & dateStart
Response.Write " End=" & dateEnd
Response.Write " Diff=" & DateDiff("s", dateStart, dateEnd)
%>
|
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.
The SlTiming Class Library
The class library, which you can download here, consists
of the following schema:
SlTimer - A thin wrapper for the
Softwing.Profiler component. Supports Start and Stop methods and a
read-only ElapsedMs property. Be aware that Softwing.Profiler's
ProfileStop method returns a value in ticks (tenths of
milliseconds).SlTimerContext -
Provides the bulk of the framework in its
EnterScope and ExitScope methods. 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 SlTimerContext's EnterScope method
from its Enter method and unconditionally
calls the ExitScope method in its destructor, so you can rely on the ExitScope
method being called when you use this system for timing methods that have
multiple Exit statements or even when errors occur. In practice, it's
easier to just call the EnterScope and ExitScope methods 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
SlTimerSontext instance 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,
here.)
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):
