Improving performance documentation.

.gitignore

@@ -9,3 +9,4 @@
 /derby.log
 /performance.txt
 /performance_db.txt
+/performance_sql.txt

build.xml

@@ -110,8 +110,11 @@
 		<echo>Executing iciql ${iq.version} test suite</echo>
 		<java classpath="${project.build.dir}" classname="com.iciql.test.IciqlSuite">
 			<classpath refid="master-classpath" />
-			<arg value="--outputFile" />
+			<arg value="--dbFile" />
 			<arg value="${basedir}/performance_db.txt" />
+				
+			<arg value="--sqlFile" />
+			<arg value="${basedir}/performance_sql.txt" />
 		</java>
 		
 		<!-- Build Standard Javadoc -->

docs/03_performance.mkd

@@ -5,7 +5,7 @@ The information provided here may be based on flawed test procedures.  You have
 
 ### iciql statement generation
 
-Performance of iciql statement generation is not currently benchmarked but that is planned.
+Performance of iciql statement generation is not currently benchmarked.
 
 ### iciql+database performance comparison
 

src/com/iciql/util/StatementLogger.java

@@ -18,6 +18,8 @@ package com.iciql.util;
 
 import java.text.DecimalFormat;
 import java.util.Set;
+import java.util.concurrent.ExecutorService;
+import java.util.concurrent.Executors;
 import java.util.concurrent.atomic.AtomicLong;
 
 /**
@@ -43,6 +45,7 @@ public class StatementLogger {
 		void logStatement(StatementType type, String statement);
 	}
 
+	private static final ExecutorService EXEC = Executors.newSingleThreadExecutor();
 	private static final Set<StatementListener> LISTENERS = Utils.newHashSet();
 	private static final StatementListener CONSOLE = new StatementListener() {
 
@@ -121,12 +124,13 @@ public class StatementLogger {
 		logStatement(StatementType.SELECT, statement);
 	}
 
-	private static void logStatement(StatementType type, String statement) {
-		for (StatementListener listener : LISTENERS) {
-			try {
-				listener.logStatement(type, statement);
-			} catch (Throwable t) {
-			}
+	private static void logStatement(final StatementType type, final String statement) {
+		for (final StatementListener listener : LISTENERS) {
+			EXEC.execute(new Runnable() {
+				public void run() {
+					listener.logStatement(type, statement);
+				}
+			});
 		}
 	}
 

tests/com/iciql/test/IciqlSuite.java

@@ -15,6 +15,8 @@
  */
 package com.iciql.test;
 
+import java.io.FileWriter;
+import java.io.IOException;
 import java.io.PrintStream;
 import java.sql.SQLException;
 import java.text.MessageFormat;
@@ -38,6 +40,9 @@ import com.beust.jcommander.ParameterException;
 import com.beust.jcommander.Parameters;
 import com.iciql.Constants;
 import com.iciql.Db;
+import com.iciql.util.StatementLogger;
+import com.iciql.util.StatementLogger.StatementListener;
+import com.iciql.util.StatementLogger.StatementType;
 import com.iciql.util.StringUtils;
 
 /**
@@ -56,7 +61,8 @@ import com.iciql.util.StringUtils;
 		RuntimeQueryTest.class, SamplesTest.class, UpdateTest.class, UUIDTest.class })
 public class IciqlSuite {
 
-	private static final TestDb[] TEST_DBS = { new TestDb("H2", "jdbc:h2:mem:db{0,number,000}"),
+	private static final TestDb[] TEST_DBS = {
+			new TestDb("H2", "jdbc:h2:mem:db{0,number,000}"),
 			new TestDb("HSQL", "jdbc:hsqldb:mem:db{0,number,000}"),
 			new TestDb("Derby", "jdbc:derby:memory:db{0,number,000};create=true") };
 
@@ -171,11 +177,35 @@ public class IciqlSuite {
 		}
 
 		// Replace System.out with a file
-		if (!StringUtils.isNullOrEmpty(params.outputFile)) {
-			out = new PrintStream(params.outputFile);
+		if (!StringUtils.isNullOrEmpty(params.dbPerformanceFile)) {
+			out = new PrintStream(params.dbPerformanceFile);
 			System.setErr(out);
 		}
 
+		// Statement logging
+		final FileWriter statementWriter;
+		if (StringUtils.isNullOrEmpty(params.sqlStatementsFile)) {
+			statementWriter = null;
+		} else {
+			statementWriter = new FileWriter(params.sqlStatementsFile);			
+		}
+		StatementListener statementListener = new StatementListener() {
+			@Override
+			public void logStatement(StatementType type, String statement) {
+				if (statementWriter == null) {
+					return;
+				}
+				try {
+					statementWriter.append(statement);
+					statementWriter.append('\n');
+				} catch (IOException e) {
+					e.printStackTrace();
+				}
+			}
+		};		
+		StatementLogger.registerListener(statementListener);
+		
+		
 		SuiteClasses suiteClasses = IciqlSuite.class.getAnnotation(SuiteClasses.class);
 		long quickestDatabase = Long.MAX_VALUE;
 		String dividerMajor = buildDivider('*', 70);
@@ -193,7 +223,9 @@ public class IciqlSuite {
 		showProperty("java.vm.name");
 		showProperty("os.name");
 		showProperty("os.version");
-		showProperty("os.arch");
+		showProperty("os.arch");		
+		showProperty("available processors", "" + Runtime.getRuntime().availableProcessors());
+		showProperty("available memory", MessageFormat.format("{0,number,#.0} GB", ((double) Runtime.getRuntime().maxMemory())/(1024*1024)));
 		out.println();
 
 		// Test a database
@@ -201,6 +233,16 @@ public class IciqlSuite {
 			out.println(dividerMinor);
 			out.println("Testing " + testDb.name + " " + testDb.getVersion());
 			out.println(dividerMinor);
+			
+			// inject a database section delimiter in the statement log
+			if (statementWriter != null) {
+				statementWriter.append("\n\n");
+				statementWriter.append("# ").append(dividerMinor).append('\n');
+				statementWriter.append("# ").append("Testing " + testDb.name + " " + testDb.getVersion()).append('\n');
+				statementWriter.append("# ").append(dividerMinor).append('\n');
+				statementWriter.append("\n\n");
+			}
+			
 			System.setProperty("iciql.url", testDb.url);
 			Result result = JUnitCore.runClasses(suiteClasses.value());
 			testDb.runtime = result.getRunTime();
@@ -247,13 +289,23 @@ public class IciqlSuite {
 		}
 
 		// close PrintStream and restore System.err
+		StatementLogger.unregisterListener(statementListener);
 		out.close();
 		System.setErr(ERR);
+		if (statementWriter != null) {
+			statementWriter.close();
+		}
+		System.exit(0);
 	}
 
 	private static void showProperty(String name) {
+		showProperty(name, System.getProperty(name));
+	}
+
+	private static void showProperty(String name, String value) {
+		out.print(' ');
 		out.print(StringUtils.pad(name, 25, " ", true));
-		out.println(System.getProperty(name));
+		out.println(value);
 	}
 
 	private static void usage(JCommander jc, ParameterException t) {
@@ -312,7 +364,10 @@ public class IciqlSuite {
 	@Parameters(separators = " ")
 	private static class Params {
 
-		@Parameter(names = { "--outputFile" }, description = "Results text file", required = false)
-		public String outputFile;
+		@Parameter(names = { "--dbFile" }, description = "Database performance results text file", required = false)
+		public String dbPerformanceFile;
+		
+		@Parameter(names = { "--sqlFile" }, description = "SQL statements log file", required = false)
+		public String sqlStatementsFile;
 	}
 }

tests/com/iciql/test/UUIDTest.java

@@ -42,7 +42,7 @@ public class UUIDTest {
 
 	@Before
 	public void setup() {
-		db = Db.open("jdbc:h2:mem:", "sa", "sa");
+		db = IciqlSuite.openNewDb();
 	}
 
 	@After
@@ -52,6 +52,10 @@ public class UUIDTest {
 
 	@Test
 	public void testUUIDs() throws Exception {
+		if (!IciqlSuite.isH2(db)) {
+			// do not test non-H2 databases
+			return;
+		}
 		List<UUIDRecord> originals = UUIDRecord.getList();
 		db.insertAll(originals);
 		UUIDRecord u = new UUIDRecord();