Implementation of slow query logging. Disabled by default.

lib/galaxy/config.py

@@ -123,6 +123,7 @@ def __init__( self, **kwargs ):
         self.database_engine_options = get_database_engine_options( kwargs )
         self.database_create_tables = string_as_bool( kwargs.get( "database_create_tables", "True" ) )
         self.database_query_profiling_proxy = string_as_bool( kwargs.get( "database_query_profiling_proxy", "False" ) )
+        self.slow_query_log_threshold = float(kwargs.get("slow_query_log_threshold", 0))
 
         # Don't set this to true for production databases, but probably should
         # default to True for sqlite databases.
@@ -1037,7 +1038,8 @@ def _configure_models( self, check_migrate_databases=False, check_migrate_tools=
                                    database_query_profiling_proxy=self.config.database_query_profiling_proxy,
                                    object_store=self.object_store,
                                    trace_logger=getattr(self, "trace_logger", None),
-                                   use_pbkdf2=self.config.get_bool( 'use_pbkdf2', True ) )
+                                   use_pbkdf2=self.config.get_bool( 'use_pbkdf2', True ),
+                                   slow_query_log_threshold = self.config.slow_query_log_threshold )
 
         if combined_install_database:
             log.info("Install database targetting Galaxy's database configuration.")

lib/galaxy/model/mapping.py

@@ -2564,7 +2564,8 @@ def _workflow_invocation_update( self ):
 
 
 def init( file_path, url, engine_options={}, create_tables=False, map_install_models=False,
-        database_query_profiling_proxy=False, object_store=None, trace_logger=None, use_pbkdf2=True ):
+        database_query_profiling_proxy=False, object_store=None, trace_logger=None, use_pbkdf2=True,
+        slow_query_log_threshold=0):
     """Connect mappings to the database"""
     # Connect dataset to the file path
     model.Dataset.file_path = file_path
@@ -2573,7 +2574,7 @@ def init( file_path, url, engine_options={}, create_tables=False, map_install_mo
     # Use PBKDF2 password hashing?
     model.User.use_pbkdf2 = use_pbkdf2
     # Load the appropriate db module
-    engine = build_engine( url, engine_options, database_query_profiling_proxy, trace_logger )
+    engine = build_engine( url, engine_options, database_query_profiling_proxy, trace_logger, slow_query_log_threshold )
 
     # Connect the metadata to the database.
     metadata.bind = engine

lib/galaxy/model/orm/engine_factory.py

@@ -1,10 +1,11 @@
 import logging
-log = logging.getLogger( __name__ )
-
-from sqlalchemy import create_engine
+import time
+from sqlalchemy import create_engine, event
+from sqlalchemy.engine import Engine
 
+log = logging.getLogger( __name__ )
 
-def build_engine(url, engine_options, database_query_profiling_proxy=False, trace_logger=None):
+def build_engine(url, engine_options, database_query_profiling_proxy=False, trace_logger=None, slow_query_log_threshold=0):
     # Should we use the logging proxy?
     if database_query_profiling_proxy:
         import galaxy.model.orm.logging_connection_proxy as logging_connection_proxy
@@ -15,6 +16,18 @@ def build_engine(url, engine_options, database_query_profiling_proxy=False, trac
         proxy = logging_connection_proxy.TraceLoggerProxy( trace_logger )
     else:
         proxy = None
+    if slow_query_log_threshold:
+        @event.listens_for(Engine, "before_cursor_execute")
+        def before_cursor_execute(conn, cursor, statement,
+                                parameters, context, executemany):
+            conn.info.setdefault('query_start_time', []).append(time.time())
+
+        @event.listens_for(Engine, "after_cursor_execute")
+        def after_cursor_execute(conn, cursor, statement,
+                                parameters, context, executemany):
+            total = time.time() - conn.info['query_start_time'].pop(-1)
+            if total > slow_query_log_threshold:
+                log.debug("Slow query: %f(s) for %s" % (total, statement))
 
     # Create the database engine
     engine = create_engine( url, proxy=proxy, **engine_options )