diff --git a/config/galaxy.ini.sample b/config/galaxy.ini.sample index 1fa4cb63684..336be53393b 100644 --- a/config/galaxy.ini.sample +++ b/config/galaxy.ini.sample @@ -117,6 +117,11 @@ paste.app_factory = galaxy.web.buildapp:app_factory # 'galaxy.model.orm.logging_connection_proxy' #database_query_profiling_proxy = False +# Slow query logging. Queries slower than the threshold indicated below will +# be logged to debug. A value of '0' is disabled. For example, you would set +# this to .005 to log all queries taking longer than 5 milliseconds +# slow_query_log_threshold = 0 + # By default, Galaxy will use the same database to track user data and # tool shed install data. There are many situations in which it is # valuable to separate these - for instance bootstrapping fresh Galaxy diff --git a/lib/galaxy/config.py b/lib/galaxy/config.py index 4fb2a53a8ac..de66ec47a00 100644 --- a/lib/galaxy/config.py +++ b/lib/galaxy/config.py @@ -123,6 +123,7 @@ class Configuration( object ): 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 @@ class ConfiguresGalaxyMixin: 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.") diff --git a/lib/galaxy/model/mapping.py b/lib/galaxy/model/mapping.py index 890262232a4..c691eba0128 100644 --- a/lib/galaxy/model/mapping.py +++ b/lib/galaxy/model/mapping.py @@ -2564,7 +2564,8 @@ model.WorkflowInvocation.update = _workflow_invocation_update 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 diff --git a/lib/galaxy/model/orm/engine_factory.py b/lib/galaxy/model/orm/engine_factory.py index 4183e985e54..16133de1ba0 100644 --- a/lib/galaxy/model/orm/engine_factory.py +++ b/lib/galaxy/model/orm/engine_factory.py @@ -1,10 +1,13 @@ import logging +import time + +from sqlalchemy import create_engine, event +from sqlalchemy.engine import Engine + log = logging.getLogger( __name__ ) -from sqlalchemy import create_engine - -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 +18,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 )