Deleted no longer needed libraries.

doc/CHANGES

@@ -0,0 +1,20 @@
+2007-05-29 1.1 alpha 1 Release
+
+           o Fixed problem where when sql timing log was the only log turned on, log4jdbc would not recognize that
+             logging was on at all.
+
+           o report sql exceptions in the sql timing log as well (when they occured during sql execution) and
+             prominently show that the sql FAILED, and display how long it tried to chug on the sql
+             before the exception was thrown
+
+           o Switch to Simple Logging Facade for Java SLF4J instead of using log4j directly, so that any underlying
+             logging system can be easily used.
+
+           o option added to ant build script to generate javadoc with ydoc to include UML diagrams within the javadoc.
+
+           o dump batched sql correctly.
+
+           o add simple command line program (PostLogProfilerProcessor) for processing sqltiming log files to create
+             a simple profiling report from log data.
+
+2007-04-21 Initial 1.0 Release

doc/README

@@ -1,132 +1,5 @@
 [this software is open source, released under the Apache License, Version 2.0:  see LICENSE file]
 
-log4jdbc Version 1.0
-Release Date:  2007-04-21
-=========================
-
-log4jdbc is a JDBC driver that can log SQL and/or JDBC calls (and optionally SQL timing information)
-for other jdbc drivers using the log4j 1.2.x logging system.
-
-Features:
-=========
-
-* Easy to drop in and use in existing systems, because it's a standard jdbc driver.  
-  The only other requirement is to have the log4j 1.2.x jar and your jdbc driver for your
-  database.
-  
-* Easy to configure, in most cases all you need to do is change the driver class name 
-  and prepend "jdbc:log4" to your existing jdbc url, set up your log4j categories and
-  you're ready to go!
-  
-* In the logged output, for prepared statements, the bind arguments are automatically 
-  inserted into the SQL output.  This greatly Improves readability and debugging for
-  many cases.
-  
-* SQL timing information can be generated to help identify how long SQL statements take 
-  to run, helping to identify statements that are running too slowly.
-  
-* SQL connection number information is generated to help identify connection pooling or 
-  threading problems.
-
-* Works with any JDBC 3.0 driver, JDK 1.4 and above, and log4j 1.2.x.
-
-This jdbc driver can be "dropped in" to log the SQL and jdbc calls of another JDBC driver.
-
-Usage:
-======
-
-1.  Set your jdbc driver class to net.sf.log4jdbc.DriverSpy
-
-    The underlying driver that is being spied on in many cases will be loaded automatically
-    without any additional configuration.
-
-    The log4jdbc "spy" driver will try and load the following popular jdbc drivers:
-    
-        oracle.jdbc.driver.OracleDriver              (oracle)
-        com.sybase.jdbc2.jdbc.SybDriver              (sybase)
-        net.sourceforge.jtds.jdbc.Driver             (sourceforge ms sql server driver)
-        com.microsoft.jdbc.sqlserver.SQLServerDriver (microsoft ms sql server driver)
-        weblogic.jdbc.sqlserver.SQLServerDriver      (weblogic ms sql server driver)
-        com.informix.jdbc.IfxDriver                  (informix)
-        org.apache.derby.jdbc.ClientDriver           (apache derby client/server driver)
-        org.apache.derby.jdbc.EmbeddedDriver         (apache derby embedded driver)
-
-    If you want to use a different underlying jdbc driver that is not already in the above supported list,
-    set a system property, log4jdbc.drivers to the class name of the additional driver.  This
-    can also be a comma separated list of driver class names.
-
-    (optional) -Dlog4jdbc.drivers=<driver>[,<driver>...]   If your driver is not one of the common preloaded drivers.
-    
-2.  Prepend "jdbc:log4" to the normal jdbc url that you are using.
-
-    For example, if your normal jdbc url is "jdbc:derby://localhost:1527//db-derby-10.2.2.0-bin/databases/MyDatabase"
-    You would change it to:  "jdbc:log4jdbc:derby://localhost:1527//db-derby-10.2.2.0-bin/databases/MyDatabase" to use the
-    log4jdbc spy driver.
-
-3.  Make sure log4jdbc-1.0.jar and the log4j jar (v1.2x) are in the classpath, as well as the jar file(s) for the
-    actual jdbc driver that is being spied upon.
-
-    Use the following command line options to initialize log4j:
-    
-    (optional) -Dlog4j.debug 
-               -Dlog4j.configuration=log4j.xml (make sure that log4j.xml is also in the classpath).
-    
-    or alternatively initialize the log4j system in code.
-
-5.  Set up your log4j logging categories.  There are 4 categories that are used by log4jdbc,
-    If all 4 loggers are set to the FATAL level, then log4jdbc will not log anything, and in fact the actual (real)
-    connection to the underlying database will be returned by the driver (thus allowing log4jdbc to be installed and
-    available without imposing any performance loss).  If any of the 4 logs are set to ERROR or higher, then log4jdbc
-    will be activated, wrapping and logging all activity in the jdbc connections returned by the driver.
-
-
-    Each of these logs can be set at either DEBUG, INFO or ERROR
-    DEBUG includes the class name and line number (if available) at which the sql was executed.
-    INFO  includes the sql (or other information as applicable)
-    ERROR will show the stack traces in the log output when sql exceptions occur.
-
-    jdbc.sqlonly   shows only SQL in the log.  SQL executed within a prepared statement is automatically shown with
-                   it's bind arguments replaced with the data bound at that position, for greatly increased readability.
-
-    jdbc.sqltiming shows the SQL, post-execution, including timing statistics on how long the sql took to execute.
-
-    jdbc.audit     Logs ALL jdbc calls except for ResultSets.  This is a very voluminous output, and is not normally
-                   needed unless tracking down a specific jdbc problem.
-
-    jdbc.resultset Even more voluminous, because all calls to ResultSet objects are logged.
-
-
-    Additionally, there is one logger named log4jdbc.debug which is for use with internal debugging of log4jdbc.
-    At this time it just prints out information on which underlying drivers were found and not found when the
-    spy driver loads.
-
-    In a typical usage scenario, you might turn on only the jdbc.sqlonly logging at INFO level,
-    just to view the sql coming out of your program.
-
-    Then if you wanted to view how long each sql statement is taking to execute, you might use jdbc.sqltiming.
-
-    jdbc.audit and jdbc.resultset are used for more in depth diagnosis of what is going on under the hood with jdbc
-    as potentially almost every single call to jdbc could be logged (logs can grow very large very quickly with this.)
-
-    See the sample files log4j.xml and log4j.properties for more information.
-
-6.  Adjust debugging options.  When logging at the DEBUG level, the class file and line number (if available) for the
-    class that invoked jdbc is logged after each log statement.  This is enormously useful for finding where in the
-    code the SQL is generated.  Be careful when using this on a production system because there is a small, but
-    potentially significant penalty performance for generating this data on each logging statement.
-
-    In many cases, this call stack data is not very useful because the calling class into log4jdbc is a connection pool,
-    object-persistance layer or other layer between log4jdbc and your application code-- but the class file and
-    line number information you really are interested in seeing is where in your application the SQL was generated from.
-
-    There are a couple of very useful system properties you can set for log4jdc to help get around this problem.
-
-    (optional) -Dlog4jdbc.debug.stack.prefix=<package.prefix> <-- a String that is the partial (or full) package
-       prefix for the package name of your application.  The call stack will be searched down to the first occurence
-       of a class that has the matching prefix.  If this is not set, the actual class that called into log4jdbc is used
-       in the debug output (in many cases this will be a connection pool class)
-
-
-
-
-
+Please see the main log4jdbc web page at http://log4jdbc.sourceforge.net for detailed features and usage information.
+There should also be in this folder, a copy of the main web page as it existed when this release was made.
+See index.html.

doc/TODO

@@ -0,0 +1,17 @@
+x switch to SLF4J logging facade so that any kind of logging system can be used with log4jdbc --
+  not just log4j
+
+x need a way to report exceptions in the sql timing log as well as the sql that failed and how long it took to fail.
+
+x include ydoc within javadoc
+
+x NEED TO LOOK INTO how to support isJdbcLoggingEnabled method call for Slf4jSpyLogDelegator
+
+o NEED to test & build for jdk 1.5&1.6 and jdbc 4
+
+o  log4layers product?  log4jdbc + servlet layer logging, struts layer logging, json-rpc layer logging, request header dump?
+
+o  configuration that doesn't rely on system properties (jdbc parms?)
+
+o  PostLogProfilerProcessor needs to be able to handle exceptions in log, & needs to be more efficient, also needs command
+   line switches to control the thresholds & counts, etc.

doc/index.html

@@ -13,7 +13,7 @@
 
 <h1><a name="top"/><img class="logo" src="log4jdbc-logo-gray.png"><br>
 
-<a href="http://sourceforge.net/project/showfiles.php?group_id=194500&package_id=229335&release_id=502834">download</a> |
+<a href="http://sourceforge.net/project/showfiles.php?group_id=194500">download</a> |
 <a href="#news">news</a> |
 <a href="#features">features</a> |
 <a href="#usage">usage</a> |
@@ -24,12 +24,12 @@
 
 <p>
 <b>log4jdbc</b> is a JDBC driver that can log SQL and/or JDBC calls (and optionally SQL timing information)
-for other jdbc drivers using the <a href="http://logging.apache.org/log4j/docs/">log4j</a> 1.2.x logging system.
+for other jdbc drivers using the <a href="http://www.slf4j.org/">Simple Logging Facade For Java</a> (SLF4J) logging system.
 </p>
 
-
 <h2><a name="news"/>news</h2>
-<p class="left"><b>2007-04-21:</b> log4jdbc 1.0 has been released!  <a href="http://sourceforge.net/project/showfiles.php?group_id=194500&package_id=229335&release_id=502834">Download it</a> and give it a try!</p>
+<p class="left"><b>2007-05-29:</b> <a href="http://sourceforge.net/forum/forum.php?forum_id=700185">log4jdbc 1.1 alpha 1 released.</a>  Most notable change is that the simple logging facade for java is now used instead of log4j directly.  See <a href="CHANGES">CHANGES</a> for all the release details.</p>
+<p class="left"><b>2007-04-21:</b> <a href="http://sourceforge.net/forum/forum.php?forum_id=688372">log4jdbc 1.0 has been released!</a>  Download it and give it a try!</p>
 
 <p class="right"><a href="#top">[back to top]</a></p>
 <h2><a name="features"/>features</h2>
@@ -37,13 +37,13 @@ for other jdbc drivers using the <a href="http://logging.apache.org/log4j/docs/"
 <ul class="left">
 <li>
   Easy to drop in and use in existing systems, because it's a standard jdbc driver.
-  The only other requirement is to have the log4j 1.2.x jar and your jdbc driver for your
+  The only other requirement is to have the SLF4J jars and your jdbc driver for your
   database.
 </li>
 
 <li>
   Easy to configure, in most cases all you need to do is change the driver class name
-  and prepend "jdbc:log4" to your existing jdbc url, set up your log4j categories and
+  and prepend "jdbc:log4" to your existing jdbc url, set up your logging categories and
   you're ready to go!
 </li>
 
@@ -55,16 +55,18 @@ for other jdbc drivers using the <a href="http://logging.apache.org/log4j/docs/"
 
 <li>
   SQL timing information can be generated to help identify how long SQL statements take
-  to run, helping to identify statements that are running too slowly.
+  to run, helping to identify statements that are running too slowly and this data can
+  be post processed with an included tool to produce profiling report data for quickly
+  identifying slow SQL in your application..
 </li>
-
+  
 <li>
   SQL connection number information is generated to help identify connection pooling or
   threading problems.
 </li>
 
 <li>
-  Works with any JDBC 3.0 driver, JDK 1.4 and above, and log4j 1.2.x.
+  Works with any JDBC 3.0 driver, JDK 1.4 and above, and SLF4J 1.x.
 </li>
 
 </ul>
@@ -111,23 +113,19 @@ This jdbc driver can be "dropped in" to log the SQL and jdbc calls of another JD
     You would change it to:  <code>jdbc:log4jdbc:derby://localhost:1527//db-derby-10.2.2.0-bin/databases/MyDatabase</code> to use the
     log4jdbc spy driver.</p>
 </li>
-<li><p>Make sure <span class="file">log4jdbc-1.0.jar</span> and the <span class="file">log4j jar</span> (v1.2x) are in
-  the classpath, as well as the jar file(s) for the actual jdbc driver that is being spied upon.</p>
-  <p>
-    Use the following command line options to initialize log4j:
+<li><p>Make sure <span class="file">log4jdbc-1.1alpha1.jar</span> and the <span class="file">slf4j</span> jar files (v1.x) are in
+  the classpath, as well as the jar file for the logging system that SLF4J forwards to and the jar file(s) for the actual
+  jdbc driver that is being spied upon.  Please refer the the <a href="http://www.slf4j.org/">SLF4J documentation</a>
+  for information on setting up SLF4J.  It's really easy!
   </p>
-  <pre>
-
-    (optional) -Dlog4j.debug
-               -Dlog4j.configuration=log4j.xml (make sure that log4j.xml is also in the classpath).
-  </pre>
-    <p>or alternatively initialize the log4j system in code. </p>
 </li>
-<li> <p> Set up your log4j logging categories.  There are 4 categories that are used by log4jdbc,
-    If all 4 loggers are set to the FATAL level, then log4jdbc will not log anything, and in fact the actual (real)
-    connection to the underlying database will be returned by the driver (thus allowing log4jdbc to be installed and
-    available without imposing any performance loss).  If any of the 4 logs are set to ERROR or higher, then log4jdbc
-    will be activated, wrapping and logging all activity in the jdbc connections returned by the driver.</p>
+<li> <p> Set up your logging categories.  There are 4 categories that are used by log4jdbc,
+    If all 4 loggers are set to a level less than error (such as the FATAL level), then log4jdbc will not log
+    anything, and in fact the actual (real) connection to the underlying database will be returned by the log4jdbc
+    driver (thus allowing log4jdbc to be installed and available to turn on at runtime at a moment's notice,
+    without imposing any actual performance loss when not being used).  If any of the 4 logs are set to ERROR,INFO or
+    DEBUG, then log4jdbc will be activated, wrapping and logging all activity in the jdbc connections returned by the
+    underlying driver.</p>
     <pre>
 
     Each of these logs can be set at either DEBUG, INFO or ERROR
@@ -148,7 +146,7 @@ This jdbc driver can be "dropped in" to log the SQL and jdbc calls of another JD
 
     <p>Additionally, there is one logger named log4jdbc.debug which is for use with internal debugging of log4jdbc.
     At this time it just prints out information on which underlying drivers were found and not found when the
-    spy driver loads.</p>
+    log4jdbc spy driver loads.</p>
 
     <p>In a typical usage scenario, you might turn on only the jdbc.sqlonly logging at INFO level,
     just to view the sql coming out of your program.</p>
@@ -156,9 +154,11 @@ This jdbc driver can be "dropped in" to log the SQL and jdbc calls of another JD
     <p>Then if you wanted to view how long each sql statement is taking to execute, you might use jdbc.sqltiming.</p>
 
     <p>jdbc.audit and jdbc.resultset are used for more in depth diagnosis of what is going on under the hood with jdbc
-    as potentially almost every single call to jdbc could be logged (logs can grow very large very quickly with this.)</p>
+    as potentially almost every single call to jdbc could be logged (logs can grow very large, very quickly with this!)</p>
 
-    <p>See the sample files <a href="log4j.xml">log4j.xml</a> and <a href="log4j.properties">log4j.properties</a> for more information.</p>
+    <p>SLF4J is a logging facade that can be used with many popular java logging systems.  The setup for the logging
+      categories will vary depending on which underlying logger you use.  Sample configuration files for log4j are
+      provided here:  <a href="log4j.xml">log4j.xml</a> and <a href="log4j.properties">log4j.properties</a>.</p>
 </li>
 <li><p>Adjust debugging options.  When logging at the DEBUG level, the class file and line number (if available) for the
     class that invoked jdbc is logged after each log statement.  This is enormously useful for finding where in the
@@ -169,13 +169,27 @@ This jdbc driver can be "dropped in" to log the SQL and jdbc calls of another JD
     object-persistance layer or other layer between log4jdbc and your application code-- but the class file and
     line number information you really are interested in seeing is where in your application the SQL was generated from.</p>
 
-    <p>There are a couple of very useful system properties you can set for log4jdc to help get around this problem.</p>
+    <p>Set the <code>log4jdbc.debug.stack.prefix</code> System property for log4jdc to help get around this problem:</p>
 
     <p>
     (optional) <code>-Dlog4jdbc.debug.stack.prefix=&lt;package.prefix&gt;</code>  a String that is the partial (or full) package
        prefix for the package name of your application.  The call stack will be searched down to the first occurence
        of a class that has the matching prefix.  If this is not set, the actual class that called into log4jdbc is used
        in the debug output (in many cases this will be a connection pool class)</p>
+     <p>
+     For example, setting a system property such as this:  <code>-Dlog4jdbc.debug.stack.prefix=com.mycompany.myapp</code>
+     Would cause the call stack to be searched for the first call that came from code in the com.mycompany.myapp package or below,
+     thus if all of your sql generating code was in code located in the com.mycompany.myapp package or any subpackages,
+     this would be printed in the debug information, rather than the package name for a connection pool, object relational system, etc.
+     </p>
+</li>
+<li>With the 1.1 alpha 1 release, a new tool is included which you can use to post-process sql timing logs produced by log4jdbc
+  to produce simple profiling reports with statistics and a dump of the sql statements that ran the slowest within the log.
+  To invoke the tool, use the profsql.sh (for unix/linux) and profsql.cmd (for windows) scripts located in the scripts
+  folder.  These scripts take as one argument, the filename of a sql timing log (generated from the
+  <code>jdbc.sqltiming</code> log category.  They produce a profiling report to stdout.
+  At this point the tool is experimental and I expect it to evolve quite a bit over the next few releases.
+  Nevertheless, it has already been very useful to me for tracking down SQL performance problems.
 </li>
 </ol>
 
@@ -194,7 +208,7 @@ log4jdbc is open source software, licensed under the <b>Apache 2.0 license:</b>
 <p class="right"><a href="#top">[back to top]</a></p>
 <h1>
 
-<a href="http://sourceforge.net/project/showfiles.php?group_id=194500&package_id=229335&release_id=502834">download</a> |
+<a href="http://sourceforge.net/project/showfiles.php?group_id=194500">download</a> |
 <a href="#news">news</a> |
 <a href="#features">features</a> |
 <a href="#usage">usage</a> |
@@ -202,11 +216,16 @@ log4jdbc is open source software, licensed under the <b>Apache 2.0 license:</b>
 <a href="#license">license</a> |
 <a href="#feedback">feedback</a>
 <br>
- 
+
 <img class="logo" src="log4jdbc-logo-gray.png">
 
 </h1>
-
-
+<p class="ad">
+YourKit is kindly supporting open source projects with its full-featured Java Profiler.
+YourKit, LLC is creator of innovative and intelligent tools for profiling
+Java and .NET applications. Take a look at YourKit's leading software products:
+<a href="http://www.yourkit.com/java/profiler/index.jsp">YourKit Java Profiler</a> and
+<a href="http://www.yourkit.com/.net/profiler/index.jsp">YourKit .NET Profiler</a>.
+</p>
 </body>
 </html>

doc/log4jdbc.css

@@ -23,4 +23,6 @@ li p {margin-left:0;}
 
 code,pre {color:navy;background-color:beige;font-size:11pt;}
 
-pre {border:2px dashed navy;margin-left:3em;margin-right:4em;margin-top:1em;margin-bottom:1em;white-space:pre-line;}
+pre {border:2px dashed navy;margin-left:3em;margin-right:4em;margin-top:1em;margin-bottom:1em;white-space:pre-line;}
+
+p.ad {font-size:1em;color:blue;}

scripts/build.xml

@@ -1,15 +1,25 @@
 <?xml version='1.0' encoding='ISO-8859-1' ?>
 
 <!--
-  Very basic ant build script.
-  tested with Apache Ant version 1.6.5
+  Ant build script for log4jdbc
+
+  Tested with Apache Ant version 1.6.5
+
+  built with jdk 1.4.2_13
 -->
 
 <project name="log4jdbc" default="all" basedir="..">
 
   <target name="all" depends="cleancompile,compile,cleanjar,jar"/>
 
-  <property name="version" value="1.0"/>
+  <!-- release version -->
+  <property name="version" value="1.1alpha1"/>
+
+  <!-- ydoc.home is only used for ydoc target for producing javadoc with generated UML
+       requires the NON-FREE ydoc utility
+       (use the javadoc target to generate regular javadoc)
+  -->
+  <property name="ydoc.home" value="/ydoc-2.2_04"/>
 
   <target name="compile" description="compile all the source code">
     <javac srcdir="src" destdir="classes" deprecation="true" debug="true">
@@ -36,7 +46,32 @@
     <delete file="build/log4jdbc-${version}.jar" description="delete the jar file"/>
   </target>
 
-  <target name="javadoc" description="generate the javadoc" >
+
+  <target name="cleanjavadoc">
+    <delete dir="doc/apidocs" />
+    <mkdir dir="doc/apidocs" />
+  </target>
+
+  <target name="cleanrelease">
+    <delete file="../log4jdbc-${version}.zip"/>
+    <delete file="../log4jdbc-${version}.tar"/>
+    <delete file="../log4jdbc-${version}.tar.gz"/>
+  </target>
+
+  <target name="release" depends="cleanrelease,all,ydoc" description="make a complete release distribution (a .jar zip and tar.gz file for release)">
+    <zip destfile="../log4jdbc-${version}.zip">
+      <zipfileset dir="." prefix="log4jdbc-${version}" excludes="*.zip,*.tar.gz,*,iml,*.ipr,*.iws,thirdparty-stuff/**,classes/**"/>
+    </zip>
+    <tar destfile="../log4jdbc-${version}.tar">
+      <tarfileset dir="." prefix="log4jdbc-${version}" excludes="*.zip,*.tar.gz,*,iml,*.ipr,*.iws,thirdparty-stuff/**,classes/**"/>
+    </tar>
+    <gzip destfile="../log4jdbc-${version}.tar.gz" src="../log4jdbc-${version}.tar"/>
+    <delete file="../log4jdbc-${version}.tar"/>
+  </target>
+
+  <!-- make the javadoc (or ydoc which includes UML diagrams) -->
+
+  <target name="javadoc" description="generate the javadoc" depends="cleanjavadoc">
     <delete dir="doc/apidocs" />
     <mkdir dir="doc/apidocs" />
     <javadoc destdir="doc/apidocs" packagenames="net.sf.log4jdbc.*"
@@ -56,7 +91,50 @@
       <sourcepath path="/j2sdk1.4.2_13/src"/>
       <link href="http://java.sun.com/j2se/1.4.2/docs/api/"/>
       <link href="http://java.sun.com/j2ee/1.4/docs/api/"/>
-      <link href="http://logging.apache.org/log4j/docs/api/"/>
+      <link href="http://www.slf4j.org/api/"/>
+    </javadoc>
+  </target>
+
+  <target name="ydoc" description="create javadoc using ydoc doclet to include UML diagrams" depends="cleanjavadoc">
+
+    <property name="ps" value="${path.separator}"/>
+
+    <javadoc destdir="doc/apidocs" packagenames="net.sf.log4jdbc.*"
+      Windowtitle="log4jdbc ${version}"
+      Header="&lt;b&gt;&lt;a href=&quot;http://log4jdbc.sourceforge.net&quot;&gt;log4jdbc ${version}&lt;/a&gt;&lt;/b&gt;"
+      Use="true" breakiterator="true">
+      <classpath>
+        <pathelement location="$src"/>
+        <fileset dir="lib">
+          <include name="**/*.jar"/>
+        </fileset>
+      </classpath>
+      <sourcepath path="src"/>
+
+      <!-- note that the jdk source code is referenced here so that javadoc will be generated from
+          interface class methods when none is specified in the implementation -->
+      <sourcepath path="/j2sdk1.4.2_13/src"/>
+      <link href="http://java.sun.com/j2se/1.4.2/docs/api/"/>
+      <link href="http://java.sun.com/j2ee/1.4/docs/api/"/>
+      <link href="http://www.slf4j.org/api/"/>
+
+      <!-- ydoc doclet for UML diagrams, see http://www.yworks.com/en/products_ydoc.htm -->
+      <doclet name="ydoc.doclets.YStandard"
+              path="${ydoc.home}/lib/ydoc.jar${ps}${ydoc.home}/lib/class2svg.jar${ps}${ydoc.home}/resources${ps}${ydoc.home}/doc${ps}./classes">
+        <param name="-author"/>
+        <param name="-generic"/>
+        <param name="-umlautogen"/>
+        <param name="-filterpath" value="${ydoc.home}/lib/ydoc.jar"/>
+        <param name="-filter" value="ydoc.filters.ExcludeFilter"/>
+        <param name="-tag" value="y.precondition"/>
+        <param name="-tag" value="y.postcondition"/>
+        <param name="-tag" value="y.complexity"/>
+        <param name="-tag" value="param"/>
+        <param name="-tag" value="return"/>
+        <param name="-tag" value="see"/>
+        <param name="-tag" value="y.uml"/>
+        <param name="-linksource" value="true"/>
+      </doclet>
     </javadoc>
   </target>
 

scripts/profsql.cmd

@@ -0,0 +1,28 @@
+@echo off
+
+rem *************************************************************************************************
+rem *                                                                                               *
+rem *  Copyright 2007 Arthur Blake                                                                  *
+rem *                                                                                               *
+rem *  Licensed under the Apache License, Version 2.0 (the "License");                              *
+rem *  you may not use this file except in compliance with the License.                             *
+rem *  You may obtain a copy of the License at                                                      *
+rem *                                                                                               *
+rem *     http://www.apache.org/licenses/LICENSE-2.0                                                *
+rem *                                                                                               *
+rem *  Unless required by applicable law or agreed to in writing, software                          *
+rem *  distributed under the License is distributed on an "AS IS" BASIS,                            *
+rem *  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.                     *
+rem *  See the License for the specific language governing permissions and                          *
+rem *  limitations under the License.                                                               *
+rem *                                                                                               *
+rem *************************************************************************************************
+
+rem *************************************************************************************************
+rem *                                                                                               *
+rem *  Invoke the PostLogProfilerProcessor to process sqltiming log information into a simple       *
+rem *  profiling output report.                                                                     *
+rem *                                                                                               *
+rem *************************************************************************************************
+
+java -Xmx1024m -classpath ..\build\log4jdbc-1.1alpha1.jar net.sf.log4jdbc.PostLogProfilerProcessor %*

scripts/profsql.sh

@@ -0,0 +1,28 @@
+#! /bin/sh
+
+# *************************************************************************************************
+# *                                                                                               *
+# *  Copyright 2007 Arthur Blake                                                                  *
+# *                                                                                               *
+# *  Licensed under the Apache License, Version 2.0 (the "License");                              *
+# *  you may not use this file except in compliance with the License.                             *
+# *  You may obtain a copy of the License at                                                      *
+# *                                                                                               *
+# *     http://www.apache.org/licenses/LICENSE-2.0                                                *
+# *                                                                                               *
+# *  Unless required by applicable law or agreed to in writing, software                          *
+# *  distributed under the License is distributed on an "AS IS" BASIS,                            *
+# *  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.                     *
+# *  See the License for the specific language governing permissions and                          *
+# *  limitations under the License.                                                               *
+# *                                                                                               *
+# *************************************************************************************************
+
+# *************************************************************************************************
+# *                                                                                               *
+# *  Invoke the PostLogProfilerProcessor to process sqltiming log information into a simple       *
+# *  profiling output report.                                                                     *
+# *                                                                                               *
+# *************************************************************************************************
+
+java -Xmx1024m -classpath ../build/log4jdbc-1.1alpha1.jar net.sf.log4jdbc.PostLogProfilerProcessor $@

src/net/sf/log4jdbc/ConnectionSpy.java

@@ -93,12 +93,12 @@ public class ConnectionSpy implements Connection, Spy
 
   protected void reportException(String methodCall, SQLException exception, String sql)
   {
-    log.exceptionOccured(this, methodCall, exception, sql);
+    log.exceptionOccured(this, methodCall, exception, sql, -1L);
   }
 
   protected void reportException(String methodCall, SQLException exception)
   {
-    log.exceptionOccured(this, methodCall, exception, null);
+    log.exceptionOccured(this, methodCall, exception, null, -1L);
   }
 
   protected void reportAllReturns(String methodCall, String returnValue)

src/net/sf/log4jdbc/PostLogProfilerProcessor.java

@@ -0,0 +1,265 @@
+/**
+ * Copyright 2007 Arthur Blake
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *    http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+package net.sf.log4jdbc;
+
+import java.io.FileReader;
+import java.io.LineNumberReader;
+import java.io.PrintStream;
+import java.util.List;
+import java.util.LinkedList;
+import java.util.Arrays;
+
+/**
+ * Post processes an existing sqltiming log, and creates a profiling report from it.
+ * Name of log file is passed in on the command line as the only argument.
+ *
+ * Assumptions:
+ * 
+ * 1. Each sql statement in the log is separated by a blank line.
+ * 2. Each sql statement is terminated with the timing string "{executed in N msec}" where N is the number of
+ *    milliseconds that the sql executed in.
+ *
+ */
+public class PostLogProfilerProcessor {
+
+  //todo:  needs to be able to gracefully handle sql exceptions in log output
+
+  /**
+   * Post Process log4jdbc sqltiming log data.
+   *
+   * @param args command line arguments.  Expects one argument, the name of the file to post process.
+   * @throws Exception if something goes wrong during processing.
+   */
+  public static void main(String[] args) throws Exception
+  {
+    if (args.length < 1)
+    {
+      System.out.println("usage: java PostLogProfilerProcessor <log-file>");
+      System.exit(1);
+    }
+    new PostLogProfilerProcessor(args[0], System.out);
+  }
+
+  /**
+   * Total number of sql statements processed.
+   */
+  private long totalSql = 0L;
+
+  /**
+   * Number of lines processed.
+   */
+  private long lineNo = 0L;
+
+  /**
+   * Total number of milliseconds that all processed sql took to run.
+   */
+  private long totalMsec = 0L;
+
+  /**
+   * Milliseconds of the worst single offending sql statement.
+   */
+  private long maxMsec = 0L;
+
+  /**
+   * Total combined milliseconds of all flagged sql statements.
+   */
+  private long flaggedSqlTotalMsec = 0L;
+
+  /**
+   * Threshold at which sql is deemed to be running slow enough to be flagged.
+   */
+  private long threshold = 100L;
+
+  /**
+   * How many top offender sql statements to display in final report
+   */
+  private long topOffenderCount = 1000L;
+
+  /**
+   * Collection of all sql that took longer than "threshold" msec to run.
+   */
+  private List flaggedSql = new LinkedList();
+
+  /**
+   * Process given filename, and produce sql profiling report to given PrintStream.
+   *
+   * @param filename sqltiming log to process.
+   * @param out PrintStream to write profiling report to.
+   * @throws Exception if reading error occurs.
+   */
+  public PostLogProfilerProcessor (String filename, PrintStream out) throws Exception
+  {
+    FileReader f= new FileReader(filename);
+    LineNumberReader l = new LineNumberReader(f);
+
+    String line;
+    boolean blankLine;
+
+    StringBuffer sql = new StringBuffer();
+
+    do
+    {
+      line = l.readLine();
+
+      if (line != null)
+      {
+        blankLine = line.length()==0;
+        lineNo++;
+/*
+        if (lineNo%100000L==0L)
+        {
+          out.println("" + lineNo + " lines...");
+        }
+*/
+        if (blankLine)
+        {
+          processSql(sql);
+          sql = new StringBuffer();
+        }
+        else
+        {
+          sql.append(line);
+        }
+
+      }
+    } while (line != null);
+
+    out.println("processed " + lineNo + " lines.");
+
+    f.close();
+
+    // display report to stdout
+
+    out.println("Number of sql statements:  " + totalSql);
+    out.println("Total number of msec    :  " + totalMsec);
+    if (totalMsec>0)
+    {
+      out.println("Average msec/statement  :  " + totalSql/totalMsec);
+    }
+
+    int flaggedSqlStmts = flaggedSql.size();
+
+    if (flaggedSqlStmts>0)
+    {
+      out.println("Sql statements that took more than "+ threshold + " msec were flagged.");
+      out.println("Flagged sql statements              :  " + flaggedSqlStmts);
+      out.println("Flagged sql Total number of msec    :  " + flaggedSqlTotalMsec);
+      out.println("Flagged sql Average msec/statement  :  " + flaggedSqlTotalMsec/flaggedSqlStmts);
+
+      out.println("sorting...");
+
+      Object[] flaggedSqlArray = flaggedSql.toArray();
+      Arrays.sort(flaggedSqlArray);
+
+      int execTimeSize = ("" + maxMsec).length();
+
+
+      if (topOffenderCount > flaggedSqlArray.length)
+      {
+        topOffenderCount = flaggedSqlArray.length;
+      }
+
+      out.println("top " + topOffenderCount + " offender"+ (topOffenderCount==1?"":"s") + ":");
+
+      ProfiledSql p;
+
+      for (int i=0; i < topOffenderCount; i++)
+      {
+        p = (ProfiledSql) flaggedSqlArray[i];
+        out.println(Utilities.rightJustify(execTimeSize,""+p.getExecTime()) + " " + p.getSql());
+      }
+    }
+  }
+
+
+  private void processSql(StringBuffer sql)
+  {
+    if (sql.length()>0)
+    {
+      totalSql++;
+      String sqlStr = sql.toString();
+      if (sqlStr.endsWith("msec}"))
+      {
+        int executedIn = sqlStr.indexOf("{executed in ");
+        if (executedIn == -1)
+        {
+          System.err.println("WARNING:  sql w/o timing info found at line " + lineNo);
+          return;
+        }
+
+        //todo: proper error handling for parse
+        String msecStr = sqlStr.substring(executedIn+13, sqlStr.length()-6);
+        long msec = Long.parseLong(msecStr);
+        totalMsec +=msec;
+        if (msec > maxMsec)
+        {
+          maxMsec = msec;
+        }
+
+        if (msec >threshold)
+        {
+          flagSql(msec,sqlStr);
+          flaggedSqlTotalMsec += msec;
+        }
+      }
+      else
+      {
+        System.err.println("WARNING:  sql w/o timing info found at line " + lineNo);
+      }
+    }
+  }
+
+  private void flagSql(long msec, String sql)
+  {
+    flaggedSql.add(new ProfiledSql(msec,sql));
+  }
+
+  private class ProfiledSql implements Comparable {
+    private Long execTime;
+    private String sql;
+
+    public ProfiledSql (long msec, String sql)
+    {
+      this.execTime= new Long(msec);
+      this.sql = sql;
+    }
+
+    /**
+     * Compares this object with the specified object for order.  Returns a
+     * negative integer, zero, or a positive integer as this object is less
+     * than, equal to, or greater than the specified object.<p>
+     *
+     * In this case the comparison is used to sort flagged sql in descending order.
+     * @param o ProfiledSql Object to compare to this ProfiledSql.  Must not be null. 
+     */
+    public int compareTo(Object o) {
+      return ((ProfiledSql)o).execTime.compareTo(execTime);
+    }
+
+    public Long getExecTime() {
+      return execTime;
+    }
+
+    public String getSql() {
+      return sql;
+    }
+
+    public String toString()
+    {
+      return this.execTime + " msec:  " + this.sql;
+    }
+  }
+}

src/net/sf/log4jdbc/PreparedStatementSpy.java

@@ -405,19 +405,18 @@ public class PreparedStatementSpy extends StatementSpy implements PreparedStatem
   public boolean execute() throws SQLException
   {
     String methodCall = "execute()";
-    String dumpedSql = null;
+    String dumpedSql = dumpedSql();
+    reportSql(dumpedSql, methodCall);
+    long tstart = System.currentTimeMillis();
     try
     {
-      dumpedSql = dumpedSql();
-      reportSql(dumpedSql, methodCall);
-      long tstart = System.currentTimeMillis();
       boolean result = realPreparedStatement.execute();
       reportSqlTiming(System.currentTimeMillis() - tstart, dumpedSql, methodCall);
       return reportReturn(methodCall, result);
     }
     catch (SQLException s)
     {
-      reportException(methodCall, s, dumpedSql);
+      reportException(methodCall, s, dumpedSql, System.currentTimeMillis() - tstart);
       throw s;
     }
   }
@@ -604,12 +603,11 @@ public class PreparedStatementSpy extends StatementSpy implements PreparedStatem
   public ResultSet executeQuery() throws SQLException
   {
     String methodCall = "executeQuery()";
-    String dumpedSql = null;
+    String dumpedSql = dumpedSql();
+    reportSql(dumpedSql, methodCall);
+    long tstart = System.currentTimeMillis();
     try
     {
-      dumpedSql = dumpedSql();
-      reportSql(dumpedSql, methodCall);
-      long tstart = System.currentTimeMillis();
       ResultSet r = realPreparedStatement.executeQuery();
       reportSqlTiming(System.currentTimeMillis() - tstart, dumpedSql, methodCall);
       ResultSetSpy rsp = new ResultSetSpy(this, r);
@@ -617,7 +615,7 @@ public class PreparedStatementSpy extends StatementSpy implements PreparedStatem
     }
     catch (SQLException s)
     {
-      reportException(methodCall, s, dumpedSql);
+      reportException(methodCall, s, dumpedSql, System.currentTimeMillis() - tstart);
       throw s;
     }
   }
@@ -706,19 +704,18 @@ public class PreparedStatementSpy extends StatementSpy implements PreparedStatem
   public int executeUpdate() throws SQLException
   {
     String methodCall = "executeUpdate()";
-    String dumpedSql = null;
+    String dumpedSql = dumpedSql();
+    reportSql(dumpedSql, methodCall);
+    long tstart = System.currentTimeMillis();
     try
     {
-      dumpedSql = dumpedSql();
-      reportSql(dumpedSql, methodCall);
-      long tstart = System.currentTimeMillis();
       int result = realPreparedStatement.executeUpdate();
       reportSqlTiming(System.currentTimeMillis() - tstart, dumpedSql, methodCall);
       return reportReturn(methodCall, result);
     }
     catch (SQLException s)
     {
-      reportException(methodCall, s, dumpedSql);
+      reportException(methodCall, s, dumpedSql, System.currentTimeMillis() - tstart);
       throw s;
     }
   }
@@ -793,6 +790,7 @@ public class PreparedStatementSpy extends StatementSpy implements PreparedStatem
   public void addBatch() throws SQLException
   {
     String methodCall = "addBatch()";
+    currentBatch.add(dumpedSql());
     try
     {
       realPreparedStatement.addBatch();

src/net/sf/log4jdbc/ResultSetSpy.java

@@ -51,7 +51,7 @@ public class ResultSetSpy implements ResultSet, Spy
    */
   protected void reportException(String methodCall, SQLException exception)
   {
-    log.exceptionOccured(this, methodCall, exception, null);
+    log.exceptionOccured(this, methodCall, exception, null, -1L);
   }
 
   /**

src/net/sf/log4jdbc/Slf4jSpyLogDelegator.java

@@ -15,20 +15,20 @@
  */
 package net.sf.log4jdbc;
 
-import org.apache.log4j.Level;
-import org.apache.log4j.Logger;
+import org.slf4j.LoggerFactory;
+import org.slf4j.Logger;
 
 /**
- * Delegates JDBC spy events to the log4j logger.
+ * Delegates JDBC spy logging events to the the Simple Logging Facade for Java (slf4j).
  *
  * @author Arthur Blake
  */
-public class Log4jSpyLogDelegator implements SpyLogDelegator
+public class Slf4jSpyLogDelegator implements SpyLogDelegator
 {
   /**
-   * Create a SpyLogDelegator specific to the log4j logging system. 
+   * Create a SpyLogDelegator specific to the Simple Logging Facade for Java (slf4j).
    */
-  public Log4jSpyLogDelegator()
+  public Slf4jSpyLogDelegator()
   {
   }
 
@@ -37,39 +37,40 @@ public class Log4jSpyLogDelegator implements SpyLogDelegator
   /**
    * Logger that shows all JDBC calls on INFO level (exception ResultSet calls)
    */
-  public static final Logger jdbcLogger = Logger.getLogger("jdbc.audit");
+  private final Logger jdbcLogger = LoggerFactory.getLogger("jdbc.audit");
 
   /**
    * Logger that shows JDBC calls for ResultSet operations
    */
-  public static final Logger resultSetLogger = Logger.getLogger("jdbc.resultset");
+  private final Logger resultSetLogger = LoggerFactory.getLogger("jdbc.resultset");
 
   /**
    * Logger that shows only the SQL that is occuring
    */
-  public static final Logger sqlOnlyLogger = Logger.getLogger("jdbc.sqlonly");
+  private final Logger sqlOnlyLogger = LoggerFactory.getLogger("jdbc.sqlonly");
 
   /**
    * Logger that shows the SQL timing, post execution
    */
-  public static final Logger sqlTimingLogger = Logger.getLogger("jdbc.sqltiming");
+  private final Logger sqlTimingLogger = LoggerFactory.getLogger("jdbc.sqltiming");
 
   // admin/setup logging for log4jdbc.
 
   /**
    * Logger just for debugging things within log4jdbc itself (admin, setup, etc.)
    */
-  public static final Logger debugLogger = Logger.getLogger("log4jdbc.debug");
+  private final Logger debugLogger = LoggerFactory.getLogger("log4jdbc.debug");
 
   /**
-   * Determine if any of the spy loggers are turned on.
+   * Determine if any of the 4 log4jdbc spy loggers are turned on (jdbc.audit | jdbc.resultset |
+   * jdbc.sqlonly | jdbc.sqltiming.)
    *
-   * @return true if any of the spy jdbc/sql loggers are enabled at error level or higher.
+   * @return true if any of the 4 spy jdbc/sql loggers are enabled at debug info or error level.
    */
   public boolean isJdbcLoggingEnabled()
   {
-    return jdbcLogger.isEnabledFor(Level.ERROR) || resultSetLogger.isEnabledFor(Level.ERROR) ||
-      sqlOnlyLogger.isEnabledFor(Level.ERROR);
+    return jdbcLogger.isErrorEnabled() || resultSetLogger.isErrorEnabled() || sqlOnlyLogger.isErrorEnabled() ||
+      sqlTimingLogger.isErrorEnabled();
   }
 
   /**
@@ -79,20 +80,43 @@ public class Log4jSpyLogDelegator implements SpyLogDelegator
    * @param methodCall a description of the name and call parameters of the method generated the Exception.
    * @param e          the Exception that was thrown.
    * @param sql        optional sql that occured just before the exception occured.
+   * @param execTime   optional amount of time that passed before an exception was thrown when sql was being executed.
+   *                   caller should pass -1 if not used
    */
-  public void exceptionOccured(Spy spy, String methodCall, Exception e, String sql)
+  public void exceptionOccured(Spy spy, String methodCall, Exception e, String sql, long execTime)
   {
     String classType = spy.getClassType();
     int spyNo = spy.getConnectionNumber();
+    String header = spyNo + ". " + classType + "." + methodCall;
     if (sql == null)
     {
-      jdbcLogger.error(spyNo + ". " + classType + "." + methodCall, e);
-      sqlOnlyLogger.error(spyNo + ". " + classType + "." + methodCall, e);
+      jdbcLogger.error(header, e);
+      sqlOnlyLogger.error(header, e);
+      sqlTimingLogger.error(header, e);
     }
     else
     {
-      jdbcLogger.error(spyNo + ". " + classType + "." + methodCall + " " + sql, e);
-      sqlOnlyLogger.error(spyNo + ". " + classType + "." + methodCall + " " + sql, e);
+      jdbcLogger.error(header + " " + sql, e);
+
+      // if at debug level, display debug info to error log
+      if (sqlOnlyLogger.isDebugEnabled())
+      {
+        sqlOnlyLogger.error(getDebugInfo() + nl + spyNo + ". " + sql, e);
+      }
+      else
+      {
+        sqlOnlyLogger.error(header + " " + sql, e);
+      }
+
+      // if at debug level, display debug info to error log
+      if (sqlTimingLogger.isDebugEnabled())
+      {
+        sqlTimingLogger.error(getDebugInfo() + nl + spyNo + ". " + sql + " {FAILED after " + execTime + " msec}", e);
+      }
+      else
+      {
+        sqlTimingLogger.error(header + " FAILED! " + sql + " {FAILED after " + execTime + " msec}", e);
+      }
     }
   }
 
@@ -109,28 +133,27 @@ public class Log4jSpyLogDelegator implements SpyLogDelegator
   {
     String classType = spy.getClassType();
     int spyNo = spy.getConnectionNumber();
+    String header = spyNo + ". " + classType + "." + methodCall + " returned " + returnMsg;
     if (ResultSetSpy.classTypeDescription.equals(classType))
     {
       if (resultSetLogger.isDebugEnabled())
       {
-        resultSetLogger.debug(
-          spyNo + ". " + classType + "." + methodCall + " returned " + returnMsg + " " + getDebugInfo());
+        resultSetLogger.debug(header + " " + getDebugInfo());
       }
       else if (resultSetLogger.isInfoEnabled())
       {
-        resultSetLogger.info(spyNo + ". " + classType + "." + methodCall + " returned " + returnMsg);
+        resultSetLogger.info(header);
       }
     }
     else
     {
       if (jdbcLogger.isDebugEnabled())
       {
-        jdbcLogger.debug(
-          spyNo + ". " + classType + "." + methodCall + " returned " + returnMsg + " " + getDebugInfo());
+        jdbcLogger.debug(header + " " + getDebugInfo());
       }
       else if (jdbcLogger.isInfoEnabled())
       {
-        jdbcLogger.info(spyNo + ". " + classType + "." + methodCall + " returned " + returnMsg);
+        jdbcLogger.info(header);
       }
     }
   }
@@ -188,7 +211,7 @@ public class Log4jSpyLogDelegator implements SpyLogDelegator
     }
     else if (sqlTimingLogger.isInfoEnabled())
     {
-      sqlTimingLogger.info(sql);
+      sqlTimingLogger.info(sql + " {executed in " + execTime + " msec}");
     }
   }
 
@@ -258,3 +281,4 @@ public class Log4jSpyLogDelegator implements SpyLogDelegator
     debugLogger.debug(msg);
   }
 }
+

src/net/sf/log4jdbc/Spy.java

@@ -16,7 +16,9 @@
 package net.sf.log4jdbc;
 
 /**
- * Common interface that all Spy classes can implement
+ * Common interface that all Spy classes can implement.
+ * This is used so that any class that is being spied upon can transmit generic information about
+ * itself to the whoever is doing the spying.
  *
  * @author Arthur Blake
  */

src/net/sf/log4jdbc/SpyLogDelegator.java

@@ -39,8 +39,10 @@ public interface SpyLogDelegator
    * @param methodCall a description of the name and call parameters of the method generated the Exception.
    * @param e          the Exception that was thrown.
    * @param sql        optional sql that occured just before the exception occured.
+   * @param execTime   optional amount of time that passed before an exception was thrown when sql was being executed.
+   *                   caller should pass -1 if not used
    */
-  public void exceptionOccured(Spy spy, String methodCall, Exception e, String sql);
+  public void exceptionOccured(Spy spy, String methodCall, Exception e, String sql, long execTime);
 
   /**
    * Called when spied upon method call returns.

src/net/sf/log4jdbc/SpyLogFactory.java

@@ -19,8 +19,8 @@ package net.sf.log4jdbc;
  * A provider for a SpyLogDelegator.  This allows a single switch point to abstract
  * away which logging system to use for spying on JDBC calls.
  *
- * At this point, only the log4j system can be used, but it would be trivial to extend the system
- * for use with any other logging system, by creating new implementations of SpyLogDelegator.
+ * The SLF4J logging facade is used, which is a very good general purpose facade for plugging into
+ * numerous java logging systems, simply and easily.
  *
  * @author Arthur Blake
  */
@@ -34,7 +34,8 @@ public class SpyLogFactory
   /**
    * The logging system of choice.
    */
-  private static final SpyLogDelegator logger = new Log4jSpyLogDelegator();
+  private static final SpyLogDelegator logger = new Slf4jSpyLogDelegator();
+  //new Log4jSpyLogDelegator();
 
   /**
    * Get the default SpyLogDelegator for logging to the logger.

src/net/sf/log4jdbc/StatementSpy.java

@@ -20,6 +20,8 @@ import java.sql.ResultSet;
 import java.sql.SQLException;
 import java.sql.SQLWarning;
 import java.sql.Statement;
+import java.util.List;
+import java.util.ArrayList;
 
 /**
  * Wraps a Statement and reports method calls, returns and exceptions.
@@ -73,6 +75,18 @@ public class StatementSpy implements Statement, Spy
     return connectionSpy.getConnectionNumber();
   }
 
+  /**
+   * Report an exception to be logged which includes timing data on a sql failure.
+   * @param methodCall description of method call and arguments passed to it that generated the exception.
+   * @param exception exception that was generated
+   * @param sql SQL associated with the call.
+   * @param execTime amount of time that the jdbc driver was chugging on the SQL before it threw an exception.
+   */
+  protected void reportException(String methodCall, SQLException exception, String sql, long execTime)
+  {
+    log.exceptionOccured(this, methodCall, exception, sql, execTime);
+  }
+
   /**
    * Report an exception to be logged.
    * @param methodCall description of method call and arguments passed to it that generated the exception.
@@ -81,7 +95,7 @@ public class StatementSpy implements Statement, Spy
    */
   protected void reportException(String methodCall, SQLException exception, String sql)
   {
-    log.exceptionOccured(this, methodCall, exception, sql);
+    log.exceptionOccured(this, methodCall, exception, sql, -1L);
   }
 
   /**
@@ -92,7 +106,7 @@ public class StatementSpy implements Statement, Spy
    */
   protected void reportException(String methodCall, SQLException exception)
   {
-    log.exceptionOccured(this, methodCall, exception, null);
+    log.exceptionOccured(this, methodCall, exception, null, -1L);
   }
 
   /**
@@ -220,6 +234,12 @@ public class StatementSpy implements Statement, Spy
     reportAllReturns(methodCall, "");
   }
 
+  /**
+   * Running one-off statement sql is generally inefficient and a bad idea for various reasons,
+   * so give a warning when this is done.
+   */
+  private static final String StatementSqlWarning = "{WARNING: Statement used to run SQL} ";
+
   /**
    * Report SQL for logging with a warning that it was generated from a statement.
    *
@@ -230,7 +250,7 @@ public class StatementSpy implements Statement, Spy
   {
     // redirect to one more method call ONLY so that stack trace search is consistent
     // with the reportReturn calls
-    _reportSql("{WARNING: Statement used to run SQL} " + sql, methodCall);
+    _reportSql(StatementSqlWarning + sql, methodCall);
   }
 
   /**
@@ -244,7 +264,7 @@ public class StatementSpy implements Statement, Spy
   {
     // redirect to one more method call ONLY so that stack trace search is consistent
     // with the reportReturn calls
-    _reportSqlTiming(execTime, "{WARNING: Statement used to run SQL} " + sql, methodCall);
+    _reportSqlTiming(execTime, StatementSqlWarning + sql, methodCall);
   }
 
   /**
@@ -303,16 +323,16 @@ public class StatementSpy implements Statement, Spy
   {
     String methodCall = "executeUpdate(" + sql + ", " + columnNames + ")";
     reportStatementSql(sql, methodCall);
+    long tstart = System.currentTimeMillis();
     try
     {
-      long tstart = System.currentTimeMillis();
       int result = realStatement.executeUpdate(sql, columnNames);
       reportStatementSqlTiming(System.currentTimeMillis() - tstart, sql, methodCall);
       return reportReturn(methodCall, result);
     }
     catch (SQLException s)
     {
-      reportException(methodCall, s, sql);
+      reportException(methodCall, s, sql, System.currentTimeMillis() - tstart);
       throw s;
     }
   }
@@ -321,16 +341,16 @@ public class StatementSpy implements Statement, Spy
   {
     String methodCall = "execute(" + sql + ", " + columnNames + ")";
     reportStatementSql(sql, methodCall);
+    long tstart = System.currentTimeMillis();
     try
     {
-      long tstart = System.currentTimeMillis();
       boolean result = realStatement.execute(sql, columnNames);
       reportStatementSqlTiming(System.currentTimeMillis() - tstart, sql, methodCall);
       return reportReturn(methodCall, result);
     }
     catch (SQLException s)
     {
-      reportException(methodCall, s, sql);
+      reportException(methodCall, s, sql, System.currentTimeMillis() - tstart);
       throw s;
     }
   }
@@ -380,19 +400,24 @@ public class StatementSpy implements Statement, Spy
     reportReturn(methodCall);
   }
 
+  /**
+   * Tracking of current batch (see addBatch, clearBatch and executeBatch)
+   * //todo: should access to this List be synchronized?
+   */
+  protected List currentBatch = new ArrayList();
+
   public void addBatch(String sql) throws SQLException
   {
     String methodCall = "addBatch(" + sql + ")";
-    reportStatementSql(sql, methodCall);
+
+    currentBatch.add(StatementSqlWarning + sql);
     try
     {
-      long tstart = System.currentTimeMillis();
       realStatement.addBatch(sql);
-      reportStatementSqlTiming(System.currentTimeMillis() - tstart, sql, methodCall);
     }
     catch (SQLException s)
     {
-      reportException(methodCall, s, sql);
+      reportException(methodCall,s);
       throw s;
     }
     reportReturn(methodCall);
@@ -424,6 +449,7 @@ public class StatementSpy implements Statement, Spy
       reportException(methodCall, s);
       throw s;
     }
+    currentBatch.clear();
     reportReturn(methodCall);
   }
 
@@ -445,15 +471,38 @@ public class StatementSpy implements Statement, Spy
   public int[] executeBatch() throws SQLException
   {
     String methodCall = "executeBatch()";
+
+    int j=currentBatch.size();
+    StringBuffer batchReport = new StringBuffer("batching " + j + " statements:");
+
+    int fieldSize = (""+j).length();
+
+    String sql;
+    for (int i=0; i < j;)
+    {
+      sql = (String) currentBatch.get(i);
+      batchReport.append("\n");
+      batchReport.append(Utilities.rightJustify(fieldSize,""+(++i)));
+      batchReport.append(":  ");
+      batchReport.append(sql);
+    }
+
+    sql = batchReport.toString();
+    reportSql(sql, methodCall);
+    long tstart = System.currentTimeMillis();
+
+    int[] updateResults;
     try
     {
-      return (int[]) reportReturn(methodCall, realStatement.executeBatch());
+      updateResults = realStatement.executeBatch();
+      reportSqlTiming(System.currentTimeMillis()-tstart, sql, methodCall);
     }
     catch (SQLException s)
     {
-      reportException(methodCall, s);
+      reportException(methodCall, s, sql, System.currentTimeMillis()-tstart);
       throw s;
     }
+    return (int[])reportReturn(methodCall,updateResults);
   }
 
   public void setFetchSize(int rows) throws SQLException
@@ -576,9 +625,9 @@ public class StatementSpy implements Statement, Spy
   {
     String methodCall = "executeQuery(" + sql + ")";
     reportStatementSql(sql, methodCall);
+    long tstart = System.currentTimeMillis();
     try
     {
-      long tstart = System.currentTimeMillis();
       ResultSet result = realStatement.executeQuery(sql);
       reportStatementSqlTiming(System.currentTimeMillis() - tstart, sql, methodCall);
       ResultSetSpy r = new ResultSetSpy(this, result);
@@ -586,7 +635,7 @@ public class StatementSpy implements Statement, Spy
     }
     catch (SQLException s)
     {
-      reportException(methodCall, s, sql);
+      reportException(methodCall, s, sql, System.currentTimeMillis() - tstart);
       throw s;
     }
   }
@@ -609,16 +658,16 @@ public class StatementSpy implements Statement, Spy
   {
     String methodCall = "executeUpdate(" + sql + ")";
     reportStatementSql(sql, methodCall);
+    long tstart = System.currentTimeMillis();
     try
     {
-      long tstart = System.currentTimeMillis();
       int result = realStatement.executeUpdate(sql);
       reportStatementSqlTiming(System.currentTimeMillis() - tstart, sql, methodCall);
       return reportReturn(methodCall, result);
     }
     catch (SQLException s)
     {
-      reportException(methodCall, s, sql);
+      reportException(methodCall, s, sql, System.currentTimeMillis() - tstart);
       throw s;
     }
   }
@@ -714,16 +763,16 @@ public class StatementSpy implements Statement, Spy
   {
     String methodCall = "execute(" + sql + ")";
     reportStatementSql(sql, methodCall);
+    long tstart = System.currentTimeMillis();
     try
     {
-      long tstart = System.currentTimeMillis();
       boolean result = realStatement.execute(sql);
       reportStatementSqlTiming(System.currentTimeMillis() - tstart, sql, methodCall);
       return reportReturn(methodCall, result);
     }
     catch (SQLException s)
     {
-      reportException(methodCall, s, sql);
+      reportException(methodCall, s, sql, System.currentTimeMillis() - tstart);
       throw s;
     }
   }
@@ -732,16 +781,16 @@ public class StatementSpy implements Statement, Spy
   {
     String methodCall = "executeUpdate(" + sql + ", " + autoGeneratedKeys + ")";
     reportStatementSql(sql, methodCall);
+    long tstart = System.currentTimeMillis();
     try
     {
-      long tstart = System.currentTimeMillis();
       int result = realStatement.executeUpdate(sql, autoGeneratedKeys);
       reportStatementSqlTiming(System.currentTimeMillis() - tstart, sql, methodCall);
       return reportReturn(methodCall, result);
     }
     catch (SQLException s)
     {
-      reportException(methodCall, s, sql);
+      reportException(methodCall, s, sql, System.currentTimeMillis() - tstart);
       throw s;
     }
   }
@@ -750,16 +799,16 @@ public class StatementSpy implements Statement, Spy
   {
     String methodCall = "execute(" + sql + ", " + autoGeneratedKeys + ")";
     reportStatementSql(sql, methodCall);
+    long tstart = System.currentTimeMillis();
     try
     {
-      long tstart = System.currentTimeMillis();
       boolean result = realStatement.execute(sql, autoGeneratedKeys);
       reportStatementSqlTiming(System.currentTimeMillis() - tstart, sql, methodCall);
       return reportReturn(methodCall, result);
     }
     catch (SQLException s)
     {
-      reportException(methodCall, s, sql);
+      reportException(methodCall, s, sql, System.currentTimeMillis() - tstart);
       throw s;
     }
   }
@@ -768,16 +817,16 @@ public class StatementSpy implements Statement, Spy
   {
     String methodCall = "executeUpdate(" + sql + ", " + columnIndexes + ")";
     reportStatementSql(sql, methodCall);
+    long tstart = System.currentTimeMillis();
     try
     {
-      long tstart = System.currentTimeMillis();
       int result = realStatement.executeUpdate(sql, columnIndexes);
       reportStatementSqlTiming(System.currentTimeMillis() - tstart, sql, methodCall);
       return reportReturn(methodCall, result);
     }
     catch (SQLException s)
     {
-      reportException(methodCall, s, sql);
+      reportException(methodCall, s, sql, System.currentTimeMillis() - tstart);
       throw s;
     }
   }
@@ -786,16 +835,16 @@ public class StatementSpy implements Statement, Spy
   {
     String methodCall = "execute(" + sql + ", " + columnIndexes + ")";
     reportStatementSql(sql, methodCall);
+    long tstart = System.currentTimeMillis();
     try
     {
-      long tstart = System.currentTimeMillis();
       boolean result = realStatement.execute(sql, columnIndexes);
       reportStatementSqlTiming(System.currentTimeMillis() - tstart, sql, methodCall);
       return reportReturn(methodCall, result);
     }
     catch (SQLException s)
     {
-      reportException(methodCall, s, sql);
+      reportException(methodCall, s, sql, System.currentTimeMillis() - tstart);
       throw s;
     }
   }

src/net/sf/log4jdbc/Utilities.java

@@ -0,0 +1,43 @@
+/**
+ * Copyright 2007 Arthur Blake
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *    http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+package net.sf.log4jdbc;
+
+/**
+ * Static utility methods for use throughout the project.
+ */
+public class Utilities {
+  /**
+   * Right justify a field within a certain number of spaces.
+   * @param fieldSize field size to right justify field within.
+   * @param field contents to right justify within field.
+   * @return the field, right justified within the requested size.
+   */
+  public static String rightJustify(int fieldSize, String field)
+  {
+    if (field==null)
+    {
+      field="";
+    }
+    StringBuffer output = new StringBuffer();
+    for (int i=0, j = fieldSize-field.length(); i < j; i++)
+    {
+      output.append(' ');
+    }
+    output.append(field);
+    return output.toString();
+  }
+
+}