When you think ASP, think...
Recent Articles
All Articles
ASP.NET Articles
ASPFAQs.com
Message Board
Related Web Technologies
User Tips!
Coding Tips

Sections:
Sample Chapters
Commonly Asked Message Board Questions
JavaScript Tutorials
MSDN Communities Hub
Official Docs
Security
Stump the SQL Guru!
XML Info
Information:
Feedback
Author an Article
ASP ASP.NET ASP FAQs Message Board Feedback
Print this page.
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.) 

- continued -

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):

Scope Total Time (ms) Total Hits Time Per Hit (ms/hit)
firehose_orig 288.36 1 288.36
firehose_july 145.83 1 145.83
firehose_v2 85.93 1 85.93
firehose_v3 74.42 1 74.42
firehose_v3_vb 42.51 1 42.51
firehose_save 78.78 1 78.78
firehose_save_xml 40.84 1 40.84
static_orig 363.1 1 363.1
static_july 190.56 1 190.56
static_v2 129.77 1 129.77
static_v3 119.55 1 119.55
static_v3_vb 89.54 1 89.54
static_save 114.24 1 114.24
static_save_xml 89.01 1 89.01
client_orig 294.59 1 294.59
client_july 146.18 1 146.18
client_v2 81.82 1 81.82
client_v3 77.95 1 77.95
client_v3_vb 41.58 1 41.58
client_save 67.44 1 67.44
client_save_xml 35.67 1 35.67

The results are ordered first by what method the recordset was fetched using - either a standard read-only, forward-only "firehose" (non-)cursor, or a server-side static read-only cursor, or a client-side static read-only cursor - then by the XML conversion method, ordered chronologically - orig is Scott's original implementation, July is David's first go at improving the ConvertRSToXML() method's performance (see Increasing ConvertRStoXML() Performance) , v2 is David's highly optimized effort (see Simplifying ConvertRStoXML() and Transforming With XSL, and v3 and v3_vb are my rogue final versions. The above table shows how these cursors perform under a no-load situation, but how would these fare with a loaded server? We'll examine this, plus delve into why each method is likely faster or slower than the others, in Part 2.

  • Read Part 2!


  • ASP.NET [1.x] [2.0] | ASPMessageboard.com | ASPFAQs.com | Advertise | Feedback | Author an Article