Joel Brown's Weblog

Logging Database Access

Last Friday I received a bug that was very vague in it's description - "Creator pages seem slow".  My first guess was that it was an application issue, but there wasn't a way to prove it.  We need to see what sql is being executed and when.

So I went through our CachedRowSet implementation to beef up the logging.  Now I know my esteemed co-workers opinion is to don't log, debug.  I'll just say I disagree.  There are reasons to log at run time and "cross-boundary" tracking (such as shipping sql off to a database) is a common one.  With the FCS version, you'll be able to see

• when a query is executed, including it's actual SELECT statement and any input parameters
  
• what actually happens within acceptChanges().  You might  be surprised - a select will precede every update or delete of a row.

What it doesn't show is the actual time it takes to execute the statement.  To see this information, check the rowset property "printStatements".  Oh, and the output is rather ugly as I'm more substance over style.

Back to the bug.   Yuck.  I've just exposed a performance problem.  It turns out we were executing rowsets when we didn't need to, sometimes multiple times.  So if you think your web pages that access your database is slow in EA or EA2, it'll be better with the production release.

Posted at 07:02AM Oct 11, 2005 by jfbrown in Database Stuff  |  Comments[1]