From 6906107b299cc31feaf793417ec6d040eb8269ae Mon Sep 17 00:00:00 2001
From: mmichalek <mmichalek@jumpmind.com>
Date: Thu, 22 Sep 2016 13:22:45 -0400
Subject: [PATCH] 0002571: Improve SQL Logging

---
 .../main/java/org/jumpmind/db/sql/LogSqlBuilder.java  |  8 ++++++++
 .../java/org/jumpmind/db/sql/JdbcSqlTransaction.java  | 11 +++++++----
 2 files changed, 15 insertions(+), 4 deletions(-)

diff --git a/symmetric-db/src/main/java/org/jumpmind/db/sql/LogSqlBuilder.java b/symmetric-db/src/main/java/org/jumpmind/db/sql/LogSqlBuilder.java
index fff71b16b3..fed30ea555 100644
--- a/symmetric-db/src/main/java/org/jumpmind/db/sql/LogSqlBuilder.java
+++ b/symmetric-db/src/main/java/org/jumpmind/db/sql/LogSqlBuilder.java
@@ -47,6 +47,10 @@ public class LogSqlBuilder {
     protected boolean logSqlParametersInline = true;    
     
     public void logSql(Logger loggerArg, String sql, Object[] args, int[] types, long executionTime) {
+        logSql(loggerArg, null, sql, args, types, executionTime);
+    }
+    
+    public void logSql(Logger loggerArg, String message, String sql, Object[] args, int[] types, long executionTime) {
         boolean longRunning = executionTime >= logSlowSqlThresholdMillis;
         if (loggerArg.isDebugEnabled() || longRunning) {
             StringBuilder logEntry = new StringBuilder();
@@ -55,6 +59,10 @@ public void logSql(Logger loggerArg, String sql, Object[] args, int[] types, lon
             } 
             logEntry.append("(" + executionTime + "ms.) ");
             
+            if (message != null) {
+                logEntry.append(message).append(" ");
+            }
+             
             if (logSqlParametersInline) {
                 logEntry.append(buildDynamicSqlForLog(sql, args, types));
             } else {
diff --git a/symmetric-jdbc/src/main/java/org/jumpmind/db/sql/JdbcSqlTransaction.java b/symmetric-jdbc/src/main/java/org/jumpmind/db/sql/JdbcSqlTransaction.java
index 8656d74ac4..df8ac34214 100644
--- a/symmetric-jdbc/src/main/java/org/jumpmind/db/sql/JdbcSqlTransaction.java
+++ b/symmetric-jdbc/src/main/java/org/jumpmind/db/sql/JdbcSqlTransaction.java
@@ -429,10 +429,6 @@ public void prepare(String sql) {
     public int addRow(Object marker, Object[] args, int[] argTypes) {
         int rowsUpdated = 0;
         try {
-            if (log.isDebugEnabled()) {
-                log.debug("Adding {} {}", ArrayUtils.toString(args), inBatchMode ? " in batch mode"
-                        : "");
-            }
             if (args != null) {
                 jdbcSqlTemplate.setValues(pstmt, args, argTypes, jdbcSqlTemplate.getLobHandler().getDefaultHandler());
             }
@@ -441,12 +437,19 @@ public int addRow(Object marker, Object[] args, int[] argTypes) {
                     marker = new Integer(markers.size() + 1);
                 }
                 markers.add(marker);
+                long start = System.currentTimeMillis();
                 pstmt.addBatch();
+                long end = System.currentTimeMillis();
+                logSqlBuilder.logSql(log, "addBatch()", psql, args, argTypes, (end-start));
+                
                 if (markers.size() >= jdbcSqlTemplate.getSettings().getBatchSize()) {
                     rowsUpdated = flush();
                 }
             } else {
+                long start = System.currentTimeMillis();
                 pstmt.execute();
+                long end = System.currentTimeMillis();
+                logSqlBuilder.logSql(log, psql, args, argTypes, (end-start));
                 rowsUpdated = pstmt.getUpdateCount();
             }
         } catch (SQLException ex) {