You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@cayenne.apache.org by jo...@apache.org on 2013/07/22 22:13:20 UTC

svn commit: r1505789 - in /cayenne/main/trunk: docs/doc/src/main/resources/ framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/access/jdbc/ framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/access/trans/ framework/cay...

Author: johnthuss
Date: Mon Jul 22 20:13:20 2013
New Revision: 1505789

URL: http://svn.apache.org/r1505789
Log:
CAY-1840 Conditionally log slow / long-running queries

Modified:
    cayenne/main/trunk/docs/doc/src/main/resources/RELEASE-NOTES.txt
    cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/access/jdbc/SelectAction.java
    cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/access/trans/QueryAssembler.java
    cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/access/trans/SelectTranslator.java
    cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/configuration/Constants.java
    cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/dba/JdbcAdapter.java
    cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/log/CommonsJdbcEventLogger.java
    cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/log/FormattedCommonsJdbcEventLogger.java
    cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/log/JdbcEventLogger.java
    cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/log/NoopJdbcEventLogger.java
    cayenne/main/trunk/framework/cayenne-core-unpublished/src/test/java/org/apache/cayenne/configuration/server/DefaultDbAdapterFactoryTest.java
    cayenne/main/trunk/framework/cayenne-core-unpublished/src/test/java/org/apache/cayenne/log/CommonsJdbcEventLoggerTest.java
    cayenne/main/trunk/framework/cayenne-core-unpublished/src/test/java/org/apache/cayenne/unit/UnitDbAdapter.java

Modified: cayenne/main/trunk/docs/doc/src/main/resources/RELEASE-NOTES.txt
URL: http://svn.apache.org/viewvc/cayenne/main/trunk/docs/doc/src/main/resources/RELEASE-NOTES.txt?rev=1505789&r1=1505788&r2=1505789&view=diff
==============================================================================
--- cayenne/main/trunk/docs/doc/src/main/resources/RELEASE-NOTES.txt (original)
+++ cayenne/main/trunk/docs/doc/src/main/resources/RELEASE-NOTES.txt Mon Jul 22 20:13:20 2013
@@ -74,6 +74,7 @@ CAY-1828 SQLSelect - generics friendly f
 CAY-1829 Make ResultIterator implement Iterable<T>, create ObjectContext.iterate method
 CAY-1836 Firebird Adapter 
 CAY-1838 Deprecate EntityResolver.indexedByClassProperty
+CAY-1840 Conditionally log slow / long-running queries
 
 Bug Fixes:
 

Modified: cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/access/jdbc/SelectAction.java
URL: http://svn.apache.org/viewvc/cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/access/jdbc/SelectAction.java?rev=1505789&r1=1505788&r2=1505789&view=diff
==============================================================================
--- cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/access/jdbc/SelectAction.java (original)
+++ cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/access/jdbc/SelectAction.java Mon Jul 22 20:13:20 2013
@@ -175,7 +175,9 @@ public class SelectAction extends BaseSQ
 
             adapter.getJdbcEventLogger().logSelectCount(
                     resultRows.size(),
-                    System.currentTimeMillis() - t1);
+                    System.currentTimeMillis() - t1,
+                    translator.createSqlString());
+            
             observer.nextRows(query, resultRows);
         }
         else {

Modified: cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/access/trans/QueryAssembler.java
URL: http://svn.apache.org/viewvc/cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/access/trans/QueryAssembler.java?rev=1505789&r1=1505788&r2=1505789&view=diff
==============================================================================
--- cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/access/trans/QueryAssembler.java (original)
+++ cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/access/trans/QueryAssembler.java Mon Jul 22 20:13:20 2013
@@ -44,6 +44,7 @@ public abstract class QueryAssembler {
 
     protected Query query;
     protected QueryMetadata queryMetadata;
+    protected String cachedSqlString;
     protected Connection connection;
     protected DbAdapter adapter;
     protected EntityResolver entityResolver;
@@ -135,6 +136,7 @@ public abstract class QueryAssembler {
         else {
             queryMetadata = null;
         }
+        cachedSqlString = null;
     }
 
     public DbEntity getRootDbEntity() {

Modified: cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/access/trans/SelectTranslator.java
URL: http://svn.apache.org/viewvc/cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/access/trans/SelectTranslator.java?rev=1505789&r1=1505788&r2=1505789&view=diff
==============================================================================
--- cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/access/trans/SelectTranslator.java (original)
+++ cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/access/trans/SelectTranslator.java Mon Jul 22 20:13:20 2013
@@ -109,7 +109,9 @@ public class SelectTranslator extends Qu
      */
     @Override
     public String createSqlString() throws Exception {
-
+    	if (cachedSqlString != null)
+    		return cachedSqlString;
+    	
         DataMap dataMap = queryMetadata.getDataMap();
         JoinStack joins = getJoinStack();
 
@@ -196,7 +198,8 @@ public class SelectTranslator extends Qu
             appendLimitAndOffsetClauses(queryBuf);
         }
 
-        return queryBuf.toString();
+        cachedSqlString = queryBuf.toString();
+        return cachedSqlString;
     }
 
     /**

Modified: cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/configuration/Constants.java
URL: http://svn.apache.org/viewvc/cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/configuration/Constants.java?rev=1505789&r1=1505788&r2=1505789&view=diff
==============================================================================
--- cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/configuration/Constants.java (original)
+++ cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/configuration/Constants.java Mon Jul 22 20:13:20 2013
@@ -139,4 +139,17 @@ public interface Constants {
      * clause size limitations and memory usage efficiency.
      */
     public static final String SERVER_MAX_ID_QUALIFIER_SIZE_PROPERTY = "cayenne.server.max_id_qualifier_size";
+
+    /** Defines if database uses case-insensitive collation */
+    public final static String CI_PROPERTY = "cayenne.runtime.db.collation.assume.ci";
+    
+    /** 
+     * A integer property that enables logging for just long running queries (rather than all queries). 
+     * The value is the minimum number of milliseconds a query must run before is logged. 
+     * A value less than or equal to zero (the default) disables this feature. 
+     * 
+     * @since 3.2 
+     * */
+    public final static String QUERY_EXECUTION_TIME_LOGGING_THRESHOLD_PROPERTY = "cayenne.server.query_execution_time_logging_threshold";
+    
 }

Modified: cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/dba/JdbcAdapter.java
URL: http://svn.apache.org/viewvc/cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/dba/JdbcAdapter.java?rev=1505789&r1=1505788&r2=1505789&view=diff
==============================================================================
--- cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/dba/JdbcAdapter.java (original)
+++ cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/dba/JdbcAdapter.java Mon Jul 22 20:13:20 2013
@@ -60,9 +60,6 @@ import org.apache.cayenne.util.Util;
  */
 public class JdbcAdapter implements DbAdapter {
 
-    // defines if database uses case-insensitive collation
-    public final static String CI_PROPERTY = "cayenne.runtime.db.collation.assume.ci";
-
     private PkGenerator pkGenerator;
     protected QuotingStrategy quotingStrategy;
 
@@ -96,8 +93,8 @@ public class JdbcAdapter implements DbAd
         // init defaults
         this.setSupportsBatchUpdates(false);
         this.setSupportsUniqueConstraints(true);
-        this.caseInsensitiveCollations = runtimeProperties.getBoolean(CI_PROPERTY, false);
-
+        this.caseInsensitiveCollations = runtimeProperties.getBoolean(Constants.CI_PROPERTY, false);
+        
         // TODO: andrus 05.02.2010 - ideally this should be injected
         this.resourceLocator = new ClassLoaderResourceLocator();
 
@@ -581,4 +578,5 @@ public class JdbcAdapter implements DbAd
     public void setBatchQueryBuilderFactory(BatchQueryBuilderFactory batchQueryBuilderFactory) {
         this.batchQueryBuilderFactory = batchQueryBuilderFactory;
     }
+    
 }

Modified: cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/log/CommonsJdbcEventLogger.java
URL: http://svn.apache.org/viewvc/cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/log/CommonsJdbcEventLogger.java?rev=1505789&r1=1505788&r2=1505789&view=diff
==============================================================================
--- cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/log/CommonsJdbcEventLogger.java (original)
+++ cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/log/CommonsJdbcEventLogger.java Mon Jul 22 20:13:20 2013
@@ -23,9 +23,14 @@ import java.sql.SQLException;
 import java.util.Iterator;
 import java.util.List;
 
+import org.apache.cayenne.CayenneRuntimeException;
 import org.apache.cayenne.ExtendedEnumeration;
 import org.apache.cayenne.access.jdbc.ParameterBinding;
+import org.apache.cayenne.configuration.CayenneRuntime;
+import org.apache.cayenne.configuration.Constants;
+import org.apache.cayenne.configuration.RuntimeProperties;
 import org.apache.cayenne.conn.DataSourceInfo;
+import org.apache.cayenne.di.Inject;
 import org.apache.cayenne.map.DbAttribute;
 import org.apache.cayenne.util.IDUtil;
 import org.apache.cayenne.util.Util;
@@ -43,6 +48,12 @@ public class CommonsJdbcEventLogger impl
 
     private static final int TRIM_VALUES_THRESHOLD = 30;
 
+    protected long queryExecutionTimeLoggingThreshold;
+    
+    public CommonsJdbcEventLogger(@Inject RuntimeProperties runtimeProperties) {
+    	this.queryExecutionTimeLoggingThreshold = runtimeProperties.getLong(Constants.QUERY_EXECUTION_TIME_LOGGING_THRESHOLD_PROPERTY, 0);
+    }
+
     void sqlLiteralForObject(StringBuilder buffer, Object object) {
         if (object == null) {
             buffer.append("NULL");
@@ -314,7 +325,11 @@ public class CommonsJdbcEventLogger impl
     }
 
     public void logSelectCount(int count, long time) {
-        if (isLoggable()) {
+    	logSelectCount(count, time, null);
+    }
+    
+    public void logSelectCount(int count, long time, String sql) {
+        if (isLoggable() || (queryExecutionTimeLoggingThreshold > 0 && time > queryExecutionTimeLoggingThreshold)) {
             StringBuilder buf = new StringBuilder();
 
             if (count == 1) {
@@ -329,6 +344,14 @@ public class CommonsJdbcEventLogger impl
             }
 
             logger.info(buf.toString());
+
+            buf.setLength(0);
+            if (queryExecutionTimeLoggingThreshold > 0 && time > queryExecutionTimeLoggingThreshold) {
+            	buf.append("Query time exceeded threshold (").append(time).append(" ms): ");
+            	buf.append(sql);
+            	String message = buf.toString();
+            	logger.warn(message, new CayenneRuntimeException(message));
+            }
         }
     }
 

Modified: cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/log/FormattedCommonsJdbcEventLogger.java
URL: http://svn.apache.org/viewvc/cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/log/FormattedCommonsJdbcEventLogger.java?rev=1505789&r1=1505788&r2=1505789&view=diff
==============================================================================
--- cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/log/FormattedCommonsJdbcEventLogger.java (original)
+++ cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/log/FormattedCommonsJdbcEventLogger.java Mon Jul 22 20:13:20 2013
@@ -24,6 +24,8 @@ import java.util.List;
 import java.util.Map;
 import java.util.TreeMap;
 
+import org.apache.cayenne.configuration.RuntimeProperties;
+import org.apache.cayenne.di.Inject;
 import org.apache.cayenne.map.DbAttribute;
 
 /**
@@ -52,6 +54,10 @@ public class FormattedCommonsJdbcEventLo
         KEYWORDS.put(" case ", "CASE");
     }
 
+    public FormattedCommonsJdbcEventLogger(@Inject RuntimeProperties runtimeProperties) {
+    	super(runtimeProperties);
+    }
+    
     private String formatQuery(String sql) {
         Map<Integer, String> scanResult = scanQuery(sql);
         Iterator<Integer> iter = scanResult.keySet().iterator();

Modified: cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/log/JdbcEventLogger.java
URL: http://svn.apache.org/viewvc/cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/log/JdbcEventLogger.java?rev=1505789&r1=1505788&r2=1505789&view=diff
==============================================================================
--- cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/log/JdbcEventLogger.java (original)
+++ cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/log/JdbcEventLogger.java Mon Jul 22 20:13:20 2013
@@ -64,7 +64,17 @@ public interface JdbcEventLogger {
             boolean isInserting);
 
     void logSelectCount(int count, long time);
-
+    
+    /**
+     * 
+     * @param count
+     * @param time (milliseconds) time query took to run
+     * @param sql SQL that was executed, printed when time exceeds timeThreshold
+     * 
+     * @since 3.2
+     */
+    void logSelectCount(int count, long time, String sql);
+    
     void logUpdateCount(int count);
 
     void logBeginTransaction(String transactionLabel);

Modified: cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/log/NoopJdbcEventLogger.java
URL: http://svn.apache.org/viewvc/cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/log/NoopJdbcEventLogger.java?rev=1505789&r1=1505788&r2=1505789&view=diff
==============================================================================
--- cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/log/NoopJdbcEventLogger.java (original)
+++ cayenne/main/trunk/framework/cayenne-core-unpublished/src/main/java/org/apache/cayenne/log/NoopJdbcEventLogger.java Mon Jul 22 20:13:20 2013
@@ -75,6 +75,9 @@ public class NoopJdbcEventLogger impleme
     public void logSelectCount(int count, long time) {
     }
 
+    public void logSelectCount(int count, long time, String sql) {
+    }
+	
     public void logUpdateCount(int count) {
     }
 

Modified: cayenne/main/trunk/framework/cayenne-core-unpublished/src/test/java/org/apache/cayenne/configuration/server/DefaultDbAdapterFactoryTest.java
URL: http://svn.apache.org/viewvc/cayenne/main/trunk/framework/cayenne-core-unpublished/src/test/java/org/apache/cayenne/configuration/server/DefaultDbAdapterFactoryTest.java?rev=1505789&r1=1505788&r2=1505789&view=diff
==============================================================================
--- cayenne/main/trunk/framework/cayenne-core-unpublished/src/test/java/org/apache/cayenne/configuration/server/DefaultDbAdapterFactoryTest.java (original)
+++ cayenne/main/trunk/framework/cayenne-core-unpublished/src/test/java/org/apache/cayenne/configuration/server/DefaultDbAdapterFactoryTest.java Mon Jul 22 20:13:20 2013
@@ -73,8 +73,11 @@ public class DefaultDbAdapterFactoryTest
         Module testModule = new Module() {
 
             public void configure(Binder binder) {
+                binder.bindMap(Constants.PROPERTIES_MAP);
+
                 binder.bind(JdbcEventLogger.class).to(CommonsJdbcEventLogger.class);
                 binder.bind(AdhocObjectFactory.class).to(DefaultAdhocObjectFactory.class);
+                binder.bind(RuntimeProperties.class).to(DefaultRuntimeProperties.class);
             }
         };
 
@@ -171,8 +174,11 @@ public class DefaultDbAdapterFactoryTest
         Module testModule = new Module() {
 
             public void configure(Binder binder) {
+                binder.bindMap(Constants.PROPERTIES_MAP);
+
                 binder.bind(JdbcEventLogger.class).to(CommonsJdbcEventLogger.class);
                 binder.bind(AdhocObjectFactory.class).to(DefaultAdhocObjectFactory.class);
+                binder.bind(RuntimeProperties.class).to(DefaultRuntimeProperties.class);
             }
         };
 

Modified: cayenne/main/trunk/framework/cayenne-core-unpublished/src/test/java/org/apache/cayenne/log/CommonsJdbcEventLoggerTest.java
URL: http://svn.apache.org/viewvc/cayenne/main/trunk/framework/cayenne-core-unpublished/src/test/java/org/apache/cayenne/log/CommonsJdbcEventLoggerTest.java?rev=1505789&r1=1505788&r2=1505789&view=diff
==============================================================================
--- cayenne/main/trunk/framework/cayenne-core-unpublished/src/test/java/org/apache/cayenne/log/CommonsJdbcEventLoggerTest.java (original)
+++ cayenne/main/trunk/framework/cayenne-core-unpublished/src/test/java/org/apache/cayenne/log/CommonsJdbcEventLoggerTest.java Mon Jul 22 20:13:20 2013
@@ -18,8 +18,11 @@
  ****************************************************************/
 package org.apache.cayenne.log;
 
+import java.util.Collections;
+
 import junit.framework.TestCase;
 
+import org.apache.cayenne.configuration.DefaultRuntimeProperties;
 import org.apache.cayenne.util.IDUtil;
 
 public class CommonsJdbcEventLoggerTest extends TestCase {
@@ -28,7 +31,7 @@ public class CommonsJdbcEventLoggerTest 
         StringBuilder buf = new StringBuilder();
 
         // test unsupported type
-        new CommonsJdbcEventLogger().sqlLiteralForObject(buf, new Object());
+        new CommonsJdbcEventLogger(new DefaultRuntimeProperties(Collections.EMPTY_MAP)).sqlLiteralForObject(buf, new Object());
         assertTrue(buf.length() > 0);
     }
 

Modified: cayenne/main/trunk/framework/cayenne-core-unpublished/src/test/java/org/apache/cayenne/unit/UnitDbAdapter.java
URL: http://svn.apache.org/viewvc/cayenne/main/trunk/framework/cayenne-core-unpublished/src/test/java/org/apache/cayenne/unit/UnitDbAdapter.java?rev=1505789&r1=1505788&r2=1505789&view=diff
==============================================================================
--- cayenne/main/trunk/framework/cayenne-core-unpublished/src/test/java/org/apache/cayenne/unit/UnitDbAdapter.java (original)
+++ cayenne/main/trunk/framework/cayenne-core-unpublished/src/test/java/org/apache/cayenne/unit/UnitDbAdapter.java Mon Jul 22 20:13:20 2013
@@ -34,9 +34,9 @@ import java.util.HashSet;
 import java.util.Map;
 
 import org.apache.cayenne.CayenneRuntimeException;
+import org.apache.cayenne.configuration.Constants;
 import org.apache.cayenne.configuration.RuntimeProperties;
 import org.apache.cayenne.dba.DbAdapter;
-import org.apache.cayenne.dba.JdbcAdapter;
 import org.apache.cayenne.dba.QuotingStrategy;
 import org.apache.cayenne.di.Inject;
 import org.apache.cayenne.map.DataMap;
@@ -218,7 +218,7 @@ public class UnitDbAdapter {
     }
 
     public boolean supportsCaseSensitiveLike() {
-        return !runtimeProperties.getBoolean(JdbcAdapter.CI_PROPERTY, false);
+        return !runtimeProperties.getBoolean(Constants.CI_PROPERTY, false);
     }
 
     public boolean supportsCaseInsensitiveOrder() {