7 new commits in galaxy-central: https://bitbucket.org/galaxy/galaxy-central/commits/67379010fc77/ changeset: 67379010fc77 user: james_taylor date: 2012-10-02 17:03:48 summary: tracing: first pass trace logging to fluentd affected #: 9 files diff -r 0445cd851094b8bad61d2a96f399538f74e5db03 -r 67379010fc77b462178e3d580e660df220d20634 eggs.ini --- a/eggs.ini +++ b/eggs.ini @@ -29,6 +29,7 @@ simplejson = 2.1.1 threadframe = 0.2 guppy = 0.1.8 +msgpack_python = 0.2.2 [eggs:noplatform] amqplib = 0.6.1 @@ -65,6 +66,7 @@ Babel = 0.9.4 wchartype = 0.1 Whoosh = 0.3.18 +fluent_logger = 0.3.3 ; extra version information [tags] diff -r 0445cd851094b8bad61d2a96f399538f74e5db03 -r 67379010fc77b462178e3d580e660df220d20634 lib/galaxy/app.py --- a/lib/galaxy/app.py +++ b/lib/galaxy/app.py @@ -28,6 +28,7 @@ self.config = config.Configuration( **kwargs ) self.config.check() config.configure_logging( self.config ) + self.configure_fluent_log() # Determine the database url if self.config.database_connection: db_url = self.config.database_connection @@ -53,7 +54,8 @@ db_url, self.config.database_engine_options, database_query_profiling_proxy = self.config.database_query_profiling_proxy, - object_store = self.object_store ) + object_store = self.object_store, + trace_logger=self.trace_logger ) # Manage installed tool shed repositories. self.installed_repository_manager = galaxy.tool_shed.InstalledRepositoryManager( self ) # Create an empty datatypes registry. @@ -143,6 +145,7 @@ self.job_stop_queue = self.job_manager.job_stop_queue # Initialize the external service types self.external_service_types = external_service_types.ExternalServiceTypesCollection( self.config.external_service_type_config_file, self.config.external_service_type_path, self ) + def shutdown( self ): self.job_manager.shutdown() self.object_store.shutdown() @@ -155,3 +158,10 @@ os.unlink( self.datatypes_registry.integrated_datatypes_configs ) except: pass + + def configure_fluent_log( self ): + if self.config.fluent_log: + from galaxy.util.log.fluent_log import FluentTraceLogger + self.trace_logger = FluentTraceLogger( 'galaxy', self.config.fluent_host, self.config.fluent_port ) + else: + self.trace_logger = None diff -r 0445cd851094b8bad61d2a96f399538f74e5db03 -r 67379010fc77b462178e3d580e660df220d20634 lib/galaxy/config.py --- a/lib/galaxy/config.py +++ b/lib/galaxy/config.py @@ -232,6 +232,11 @@ for k, v in amqp_config: self.amqp[k] = v self.running_functional_tests = string_as_bool( kwargs.get( 'running_functional_tests', False ) ) + # Logging with fluentd + self.fluent_log = string_as_bool( kwargs.get( 'fluent_log', False ) ) + self.fluent_host = kwargs.get( 'fluent_host', 'localhost' ) + self.fluent_port = int( kwargs.get( 'fluent_port', 24224 ) ) + def __read_tool_job_config( self, global_conf_parser, section, key ): try: tool_runners_config = global_conf_parser.items( section ) diff -r 0445cd851094b8bad61d2a96f399538f74e5db03 -r 67379010fc77b462178e3d580e660df220d20634 lib/galaxy/model/mapping.py --- a/lib/galaxy/model/mapping.py +++ b/lib/galaxy/model/mapping.py @@ -1868,7 +1868,7 @@ # Let this go, it could possibly work with db's we don't support log.error( "database_connection contains an unknown SQLAlchemy database dialect: %s" % dialect ) -def init( file_path, url, engine_options={}, create_tables=False, database_query_profiling_proxy=False, object_store=None ): +def init( file_path, url, engine_options={}, create_tables=False, database_query_profiling_proxy=False, object_store=None, trace_logger=None ): """Connect mappings to the database""" # Connect dataset to the file path Dataset.file_path = file_path @@ -1876,10 +1876,10 @@ Dataset.object_store = object_store # Load the appropriate db module load_egg_for_url( url ) - # Should we use the logging proxy? - if database_query_profiling_proxy: + # If metlog is enabled, do micrologging + if trace_logger: import galaxy.model.orm.logging_connection_proxy as logging_connection_proxy - proxy = logging_connection_proxy.LoggingProxy() + proxy = logging_connection_proxy.TraceLoggerProxy( trace_logger ) else: proxy = None # Create the database engine diff -r 0445cd851094b8bad61d2a96f399538f74e5db03 -r 67379010fc77b462178e3d580e660df220d20634 lib/galaxy/model/orm/logging_connection_proxy.py --- a/lib/galaxy/model/orm/logging_connection_proxy.py +++ b/lib/galaxy/model/orm/logging_connection_proxy.py @@ -18,13 +18,31 @@ rval = [] for frame, fname, line, funcname, _, _ in inspect.stack()[2:]: rval.append( "%s:%s@%d" % ( stripwd( fname ), funcname, line ) ) - return " > ".join( rval ) + return rval class LoggingProxy(ConnectionProxy): + """ + Logs SQL statements using standard logging module + """ def cursor_execute(self, execute, cursor, statement, parameters, context, executemany): start = time.clock() rval = execute(cursor, statement, parameters, context) duration = time.clock() - start log.debug( "statement: %r parameters: %r executemany: %r duration: %r stack: %r", - statement, parameters, executemany, duration, pretty_stack() ) + statement, parameters, executemany, duration, " > ".join( pretty_stack() ) ) return rval + +class TraceLoggerProxy(ConnectionProxy): + """ + Logs SQL statements using a metlog client + """ + def __init__( self, trace_logger ): + self.trace_logger = trace_logger + def cursor_execute(self, execute, cursor, statement, parameters, context, executemany): + start = time.clock() + rval = execute(cursor, statement, parameters, context) + duration = time.clock() - start + self.trace_logger.log( "sqlalchemy_query", + message="Query executed", statement=statement, parameters=parameters, + executemany=executemany, duration=duration, stack=pretty_stack() ) + return rval \ No newline at end of file diff -r 0445cd851094b8bad61d2a96f399538f74e5db03 -r 67379010fc77b462178e3d580e660df220d20634 lib/galaxy/util/log/__init__.py --- /dev/null +++ b/lib/galaxy/util/log/__init__.py @@ -0,0 +1,5 @@ +class TraceLogger( object ): + def __init__( self, name ): + self.name = name + def log( **kwargs ): + raise TypeError( "Abstract Method" ) \ No newline at end of file diff -r 0445cd851094b8bad61d2a96f399538f74e5db03 -r 67379010fc77b462178e3d580e660df220d20634 lib/galaxy/util/log/fluent_log.py --- /dev/null +++ b/lib/galaxy/util/log/fluent_log.py @@ -0,0 +1,37 @@ +import time +import threading + +import galaxy.eggs +galaxy.eggs.require( "fluent-logger" ) +galaxy.eggs.require( "msgpack_python" ) + + +from fluent.sender import FluentSender + + +class FluentTraceLogger( object ): + def __init__( self, name, host='localhost', port=24224 ): + self.lock = threading.Lock() + self.thread_local = threading.local() + self.name = name + self.sender = FluentSender( self.name, host=host, port=port ) + + def context_push( self, value ): + self.lock.acquire() + if not hasattr( self.thread_local, 'context' ): + self.thread_local.context = [] + self.thread_local.context.append( value ) + self.lock.release() + + def context_pop( self ): + self.lock.acquire() + self.thread_local.context.pop() + self.lock.release() + + def log( self, label, **kwargs ): + self.lock.acquire() + if not hasattr( self.thread_local, 'context' ): + self.thread_local.context = [] + self.lock.release() + kwargs['log_context'] = self.thread_local.context + self.sender.emit_with_time( label, int(time.time()), kwargs ) \ No newline at end of file diff -r 0445cd851094b8bad61d2a96f399538f74e5db03 -r 67379010fc77b462178e3d580e660df220d20634 lib/galaxy/web/framework/base.py --- a/lib/galaxy/web/framework/base.py +++ b/lib/galaxy/web/framework/base.py @@ -8,6 +8,8 @@ import os.path import sys import tarfile +import threading +import uuid from Cookie import SimpleCookie @@ -68,6 +70,9 @@ self.mapper.explicit = False self.api_mapper = routes.Mapper() self.transaction_factory = DefaultWebTransaction + # Each request will have a unique id. Since we are assuming + # a threaded model for the moment we can store that here + self.request_id = threading.local() def add_ui_controller( self, controller_name, controller ): """ Add a controller class to this application. A controller class has @@ -106,12 +111,20 @@ # Create/compile the regular expressions for route mapping self.mapper.create_regs( self.controllers.keys() ) self.api_mapper.create_regs( self.api_controllers.keys() ) + def trace( self, **fields ): + if self.trace_logger: + self.trace_logger.log( "WebApplication", **fields ) def __call__( self, environ, start_response ): """ Call interface as specified by WSGI. Wraps the environment in user friendly objects, finds the appropriate method to handle the request and calls it. """ + # Immediately create request_id which we will use for logging + self.request_id = request_id = uuid.uuid1().hex + if self.trace_logger: + self.trace_logger.context_push( dict( request_id = request_id ) ) + self.trace( message= "Starting request" ) # Map url using routes path_info = environ.get( 'PATH_INFO', '' ) map = self.mapper.match( path_info, environ ) @@ -125,6 +138,7 @@ controllers = self.controllers if map == None: raise httpexceptions.HTTPNotFound( "No route for " + path_info ) + self.trace( path_info=path_info, map=map ) # Setup routes rc = routes.request_config() rc.mapper = mapper diff -r 0445cd851094b8bad61d2a96f399538f74e5db03 -r 67379010fc77b462178e3d580e660df220d20634 lib/galaxy/webapps/galaxy/buildapp.py --- a/lib/galaxy/webapps/galaxy/buildapp.py +++ b/lib/galaxy/webapps/galaxy/buildapp.py @@ -110,7 +110,13 @@ webapp.api_mapper.connect("import_workflow", "/api/workflows/upload", controller="workflows", action="import_new_workflow", conditions=dict(method=["POST"])) webapp.api_mapper.connect("workflow_dict", '/api/workflows/download/{workflow_id}', controller='workflows', action='workflow_dict', conditions=dict(method=['GET'])) + # Connect logger from app + if app.trace_logger: + webapp.trace_logger = app.trace_logger + + # Indicate that all configuration settings have been provided webapp.finalize_config() + # Wrap the webapp in some useful middleware if kwargs.get( 'middleware', True ): webapp = wrap_in_middleware( webapp, global_conf, **kwargs ) https://bitbucket.org/galaxy/galaxy-central/commits/33d256f3121a/ changeset: 33d256f3121a user: james_taylor date: 2013-01-03 22:54:14 summary: merge affected #: 9 files diff -r d7475647cbb6a1c70218049fadc24ed1651d845a -r 33d256f3121a7f32aaa87b4e34a110fcea57a36e eggs.ini --- a/eggs.ini +++ b/eggs.ini @@ -29,6 +29,7 @@ simplejson = 2.1.1 threadframe = 0.2 guppy = 0.1.8 +msgpack_python = 0.2.2 [eggs:noplatform] amqplib = 0.6.1 @@ -65,6 +66,7 @@ Babel = 0.9.4 wchartype = 0.1 Whoosh = 0.3.18 +fluent_logger = 0.3.3 ; extra version information [tags] diff -r d7475647cbb6a1c70218049fadc24ed1651d845a -r 33d256f3121a7f32aaa87b4e34a110fcea57a36e lib/galaxy/app.py --- a/lib/galaxy/app.py +++ b/lib/galaxy/app.py @@ -29,6 +29,7 @@ self.config = config.Configuration( **kwargs ) self.config.check() config.configure_logging( self.config ) + self.configure_fluent_log() # Determine the database url if self.config.database_connection: db_url = self.config.database_connection @@ -54,7 +55,8 @@ db_url, self.config.database_engine_options, database_query_profiling_proxy = self.config.database_query_profiling_proxy, - object_store = self.object_store ) + object_store = self.object_store, + trace_logger=self.trace_logger ) # Manage installed tool shed repositories. self.installed_repository_manager = galaxy.tool_shed.InstalledRepositoryManager( self ) # Create an empty datatypes registry. @@ -149,6 +151,7 @@ self.job_stop_queue = self.job_manager.job_stop_queue # Initialize the external service types self.external_service_types = external_service_types.ExternalServiceTypesCollection( self.config.external_service_type_config_file, self.config.external_service_type_path, self ) + def shutdown( self ): self.job_manager.shutdown() self.object_store.shutdown() @@ -161,3 +164,10 @@ os.unlink( self.datatypes_registry.integrated_datatypes_configs ) except: pass + + def configure_fluent_log( self ): + if self.config.fluent_log: + from galaxy.util.log.fluent_log import FluentTraceLogger + self.trace_logger = FluentTraceLogger( 'galaxy', self.config.fluent_host, self.config.fluent_port ) + else: + self.trace_logger = None diff -r d7475647cbb6a1c70218049fadc24ed1651d845a -r 33d256f3121a7f32aaa87b4e34a110fcea57a36e lib/galaxy/config.py --- a/lib/galaxy/config.py +++ b/lib/galaxy/config.py @@ -261,6 +261,10 @@ self.api_folders = string_as_bool( kwargs.get( 'api_folders', False ) ) # This is for testing new library browsing capabilities. self.new_lib_browse = string_as_bool( kwargs.get( 'new_lib_browse', False ) ) + # Logging with fluentd + self.fluent_log = string_as_bool( kwargs.get( 'fluent_log', False ) ) + self.fluent_host = kwargs.get( 'fluent_host', 'localhost' ) + self.fluent_port = int( kwargs.get( 'fluent_port', 24224 ) ) def __read_tool_job_config( self, global_conf_parser, section, key ): try: diff -r d7475647cbb6a1c70218049fadc24ed1651d845a -r 33d256f3121a7f32aaa87b4e34a110fcea57a36e lib/galaxy/model/mapping.py --- a/lib/galaxy/model/mapping.py +++ b/lib/galaxy/model/mapping.py @@ -1950,7 +1950,7 @@ # Let this go, it could possibly work with db's we don't support log.error( "database_connection contains an unknown SQLAlchemy database dialect: %s" % dialect ) -def init( file_path, url, engine_options={}, create_tables=False, database_query_profiling_proxy=False, object_store=None ): +def init( file_path, url, engine_options={}, create_tables=False, database_query_profiling_proxy=False, object_store=None, trace_logger=None ): """Connect mappings to the database""" # Connect dataset to the file path Dataset.file_path = file_path @@ -1958,10 +1958,10 @@ Dataset.object_store = object_store # Load the appropriate db module load_egg_for_url( url ) - # Should we use the logging proxy? - if database_query_profiling_proxy: + # If metlog is enabled, do micrologging + if trace_logger: import galaxy.model.orm.logging_connection_proxy as logging_connection_proxy - proxy = logging_connection_proxy.LoggingProxy() + proxy = logging_connection_proxy.TraceLoggerProxy( trace_logger ) else: proxy = None # Create the database engine diff -r d7475647cbb6a1c70218049fadc24ed1651d845a -r 33d256f3121a7f32aaa87b4e34a110fcea57a36e lib/galaxy/model/orm/logging_connection_proxy.py --- a/lib/galaxy/model/orm/logging_connection_proxy.py +++ b/lib/galaxy/model/orm/logging_connection_proxy.py @@ -18,13 +18,31 @@ rval = [] for frame, fname, line, funcname, _, _ in inspect.stack()[2:]: rval.append( "%s:%s@%d" % ( stripwd( fname ), funcname, line ) ) - return " > ".join( rval ) + return rval class LoggingProxy(ConnectionProxy): + """ + Logs SQL statements using standard logging module + """ def cursor_execute(self, execute, cursor, statement, parameters, context, executemany): start = time.clock() rval = execute(cursor, statement, parameters, context) duration = time.clock() - start log.debug( "statement: %r parameters: %r executemany: %r duration: %r stack: %r", - statement, parameters, executemany, duration, pretty_stack() ) + statement, parameters, executemany, duration, " > ".join( pretty_stack() ) ) return rval + +class TraceLoggerProxy(ConnectionProxy): + """ + Logs SQL statements using a metlog client + """ + def __init__( self, trace_logger ): + self.trace_logger = trace_logger + def cursor_execute(self, execute, cursor, statement, parameters, context, executemany): + start = time.clock() + rval = execute(cursor, statement, parameters, context) + duration = time.clock() - start + self.trace_logger.log( "sqlalchemy_query", + message="Query executed", statement=statement, parameters=parameters, + executemany=executemany, duration=duration, stack=pretty_stack() ) + return rval \ No newline at end of file diff -r d7475647cbb6a1c70218049fadc24ed1651d845a -r 33d256f3121a7f32aaa87b4e34a110fcea57a36e lib/galaxy/util/log/__init__.py --- /dev/null +++ b/lib/galaxy/util/log/__init__.py @@ -0,0 +1,5 @@ +class TraceLogger( object ): + def __init__( self, name ): + self.name = name + def log( **kwargs ): + raise TypeError( "Abstract Method" ) \ No newline at end of file diff -r d7475647cbb6a1c70218049fadc24ed1651d845a -r 33d256f3121a7f32aaa87b4e34a110fcea57a36e lib/galaxy/util/log/fluent_log.py --- /dev/null +++ b/lib/galaxy/util/log/fluent_log.py @@ -0,0 +1,37 @@ +import time +import threading + +import galaxy.eggs +galaxy.eggs.require( "fluent-logger" ) +galaxy.eggs.require( "msgpack_python" ) + + +from fluent.sender import FluentSender + + +class FluentTraceLogger( object ): + def __init__( self, name, host='localhost', port=24224 ): + self.lock = threading.Lock() + self.thread_local = threading.local() + self.name = name + self.sender = FluentSender( self.name, host=host, port=port ) + + def context_push( self, value ): + self.lock.acquire() + if not hasattr( self.thread_local, 'context' ): + self.thread_local.context = [] + self.thread_local.context.append( value ) + self.lock.release() + + def context_pop( self ): + self.lock.acquire() + self.thread_local.context.pop() + self.lock.release() + + def log( self, label, **kwargs ): + self.lock.acquire() + if not hasattr( self.thread_local, 'context' ): + self.thread_local.context = [] + self.lock.release() + kwargs['log_context'] = self.thread_local.context + self.sender.emit_with_time( label, int(time.time()), kwargs ) \ No newline at end of file diff -r d7475647cbb6a1c70218049fadc24ed1651d845a -r 33d256f3121a7f32aaa87b4e34a110fcea57a36e lib/galaxy/web/framework/base.py --- a/lib/galaxy/web/framework/base.py +++ b/lib/galaxy/web/framework/base.py @@ -8,6 +8,8 @@ import os.path import sys import tarfile +import threading +import uuid from Cookie import SimpleCookie @@ -68,6 +70,9 @@ self.mapper.explicit = False self.api_mapper = routes.Mapper() self.transaction_factory = DefaultWebTransaction + # Each request will have a unique id. Since we are assuming + # a threaded model for the moment we can store that here + self.request_id = threading.local() def add_ui_controller( self, controller_name, controller ): """ Add a controller class to this application. A controller class has @@ -106,12 +111,20 @@ # Create/compile the regular expressions for route mapping self.mapper.create_regs( self.controllers.keys() ) self.api_mapper.create_regs( self.api_controllers.keys() ) + def trace( self, **fields ): + if self.trace_logger: + self.trace_logger.log( "WebApplication", **fields ) def __call__( self, environ, start_response ): """ Call interface as specified by WSGI. Wraps the environment in user friendly objects, finds the appropriate method to handle the request and calls it. """ + # Immediately create request_id which we will use for logging + self.request_id = request_id = uuid.uuid1().hex + if self.trace_logger: + self.trace_logger.context_push( dict( request_id = request_id ) ) + self.trace( message= "Starting request" ) # Map url using routes path_info = environ.get( 'PATH_INFO', '' ) map = self.mapper.match( path_info, environ ) @@ -125,6 +138,7 @@ controllers = self.controllers if map == None: raise httpexceptions.HTTPNotFound( "No route for " + path_info ) + self.trace( path_info=path_info, map=map ) # Setup routes rc = routes.request_config() rc.mapper = mapper diff -r d7475647cbb6a1c70218049fadc24ed1651d845a -r 33d256f3121a7f32aaa87b4e34a110fcea57a36e lib/galaxy/webapps/galaxy/buildapp.py --- a/lib/galaxy/webapps/galaxy/buildapp.py +++ b/lib/galaxy/webapps/galaxy/buildapp.py @@ -130,7 +130,13 @@ webapp.api_mapper.connect("import_workflow", "/api/workflows/upload", controller="workflows", action="import_new_workflow", conditions=dict(method=["POST"])) webapp.api_mapper.connect("workflow_dict", '/api/workflows/download/{workflow_id}', controller='workflows', action='workflow_dict', conditions=dict(method=['GET'])) + # Connect logger from app + if app.trace_logger: + webapp.trace_logger = app.trace_logger + + # Indicate that all configuration settings have been provided webapp.finalize_config() + # Wrap the webapp in some useful middleware if kwargs.get( 'middleware', True ): webapp = wrap_in_middleware( webapp, global_conf, **kwargs ) https://bitbucket.org/galaxy/galaxy-central/commits/33750f347be2/ changeset: 33750f347be2 user: james_taylor date: 2013-01-04 20:26:22 summary: update msgpack_python version for trace logging, don't log entire stack with each query affected #: 2 files diff -r 33d256f3121a7f32aaa87b4e34a110fcea57a36e -r 33750f347be2aef72fe4e32d5c2197dd82f2b45a eggs.ini --- a/eggs.ini +++ b/eggs.ini @@ -29,7 +29,7 @@ simplejson = 2.1.1 threadframe = 0.2 guppy = 0.1.8 -msgpack_python = 0.2.2 +msgpack_python = 0.2.4 [eggs:noplatform] amqplib = 0.6.1 diff -r 33d256f3121a7f32aaa87b4e34a110fcea57a36e -r 33750f347be2aef72fe4e32d5c2197dd82f2b45a lib/galaxy/model/orm/logging_connection_proxy.py --- a/lib/galaxy/model/orm/logging_connection_proxy.py +++ b/lib/galaxy/model/orm/logging_connection_proxy.py @@ -44,5 +44,5 @@ duration = time.clock() - start self.trace_logger.log( "sqlalchemy_query", message="Query executed", statement=statement, parameters=parameters, - executemany=executemany, duration=duration, stack=pretty_stack() ) + executemany=executemany, duration=duration ) return rval \ No newline at end of file https://bitbucket.org/galaxy/galaxy-central/commits/8331f2af6a90/ changeset: 8331f2af6a90 user: james_taylor date: 2013-01-04 22:48:35 summary: trace logging: flatten context affected #: 2 files diff -r 33750f347be2aef72fe4e32d5c2197dd82f2b45a -r 8331f2af6a9092f4528fb01ca7baf3d7999838a0 lib/galaxy/util/log/fluent_log.py --- a/lib/galaxy/util/log/fluent_log.py +++ b/lib/galaxy/util/log/fluent_log.py @@ -1,3 +1,7 @@ +""" +Provides a `TraceLogger` implementation that logs to a fluentd collector +""" + import time import threading @@ -5,33 +9,31 @@ galaxy.eggs.require( "fluent-logger" ) galaxy.eggs.require( "msgpack_python" ) - from fluent.sender import FluentSender class FluentTraceLogger( object ): - def __init__( self, name, host='localhost', port=24224 ): - self.lock = threading.Lock() - self.thread_local = threading.local() - self.name = name - self.sender = FluentSender( self.name, host=host, port=port ) + def __init__( self, name, host='localhost', port=24224 ): + self.lock = threading.Lock() + self.thread_local = threading.local() + self.name = name + self.sender = FluentSender( self.name, host=host, port=port ) - def context_push( self, value ): - self.lock.acquire() - if not hasattr( self.thread_local, 'context' ): - self.thread_local.context = [] - self.thread_local.context.append( value ) - self.lock.release() + def context_set( self, key, value ): + self.lock.acquire() + if not hasattr( self.thread_local, 'context' ): + self.thread_local.context = {} + self.thread_local.context[key] = value + self.lock.release() - def context_pop( self ): - self.lock.acquire() - self.thread_local.context.pop() - self.lock.release() + def context_remove( self, key ): + self.lock.acquire() + del self.thread_local.context[key] + self.lock.release() - def log( self, label, **kwargs ): - self.lock.acquire() - if not hasattr( self.thread_local, 'context' ): - self.thread_local.context = [] - self.lock.release() - kwargs['log_context'] = self.thread_local.context - self.sender.emit_with_time( label, int(time.time()), kwargs ) \ No newline at end of file + def log( self, label, **kwargs ): + self.lock.acquire() + if hasattr( self.thread_local, 'context' ): + kwargs.update( self.thread_local.context ) + self.lock.release() + self.sender.emit_with_time( label, int(time.time()), kwargs ) \ No newline at end of file diff -r 33750f347be2aef72fe4e32d5c2197dd82f2b45a -r 8331f2af6a9092f4528fb01ca7baf3d7999838a0 lib/galaxy/web/framework/base.py --- a/lib/galaxy/web/framework/base.py +++ b/lib/galaxy/web/framework/base.py @@ -123,8 +123,16 @@ # Immediately create request_id which we will use for logging self.request_id = request_id = uuid.uuid1().hex if self.trace_logger: - self.trace_logger.context_push( dict( request_id = request_id ) ) - self.trace( message= "Starting request" ) + self.trace_logger.context_set( "request_id", request_id ) + self.trace( message="Starting request" ) + try: + return self.handle_request( environ, start_response ) + finally: + self.trace( message="Handle request finished" ) + if self.trace_logger: + self.trace_logger.context_remove( "request_id" ) + + def handle_request( self, environ, start_response ): # Map url using routes path_info = environ.get( 'PATH_INFO', '' ) map = self.mapper.match( path_info, environ ) https://bitbucket.org/galaxy/galaxy-central/commits/26f38d9bd3ee/ changeset: 26f38d9bd3ee user: james_taylor date: 2013-01-07 21:07:16 summary: Restore support for logging connection proxy affected #: 1 file diff -r 8331f2af6a9092f4528fb01ca7baf3d7999838a0 -r 26f38d9bd3ee9902aa5661d046604f6fb2bb96b3 lib/galaxy/model/mapping.py --- a/lib/galaxy/model/mapping.py +++ b/lib/galaxy/model/mapping.py @@ -1958,8 +1958,12 @@ Dataset.object_store = object_store # Load the appropriate db module load_egg_for_url( url ) + # Should we use the logging proxy? + if database_query_profiling_proxy: + import galaxy.model.orm.logging_connection_proxy as logging_connection_proxy + proxy = logging_connection_proxy.LoggingProxy() # If metlog is enabled, do micrologging - if trace_logger: + elif trace_logger: import galaxy.model.orm.logging_connection_proxy as logging_connection_proxy proxy = logging_connection_proxy.TraceLoggerProxy( trace_logger ) else: https://bitbucket.org/galaxy/galaxy-central/commits/5622f8127e9d/ changeset: 5622f8127e9d user: james_taylor date: 2013-01-07 21:12:18 summary: tracing: fix for when trace logger is disabled affected #: 1 file diff -r 26f38d9bd3ee9902aa5661d046604f6fb2bb96b3 -r 5622f8127e9ddf52baba4ad901e32deacd378f7c lib/galaxy/web/framework/base.py --- a/lib/galaxy/web/framework/base.py +++ b/lib/galaxy/web/framework/base.py @@ -73,6 +73,8 @@ # Each request will have a unique id. Since we are assuming # a threaded model for the moment we can store that here self.request_id = threading.local() + # Set if trace logging is enabled + self.trace_logger = None def add_ui_controller( self, controller_name, controller ): """ Add a controller class to this application. A controller class has @@ -114,6 +116,7 @@ def trace( self, **fields ): if self.trace_logger: self.trace_logger.log( "WebApplication", **fields ) + def __call__( self, environ, start_response ): """ Call interface as specified by WSGI. Wraps the environment in user https://bitbucket.org/galaxy/galaxy-central/commits/09cf28408702/ changeset: 09cf28408702 user: james_taylor date: 2013-01-07 21:12:47 summary: Automated merge with ssh://bitbucket.org/galaxy/galaxy-central affected #: 9 files diff -r 395bfeb484ae0f69bdd7be2115ed007b4c01dd90 -r 09cf284087021586ad08656b7ea444959c6c49bf eggs.ini --- a/eggs.ini +++ b/eggs.ini @@ -29,6 +29,7 @@ simplejson = 2.1.1 threadframe = 0.2 guppy = 0.1.8 +msgpack_python = 0.2.4 [eggs:noplatform] amqplib = 0.6.1 @@ -65,6 +66,7 @@ Babel = 0.9.4 wchartype = 0.1 Whoosh = 0.3.18 +fluent_logger = 0.3.3 ; extra version information [tags] diff -r 395bfeb484ae0f69bdd7be2115ed007b4c01dd90 -r 09cf284087021586ad08656b7ea444959c6c49bf lib/galaxy/app.py --- a/lib/galaxy/app.py +++ b/lib/galaxy/app.py @@ -29,6 +29,7 @@ self.config = config.Configuration( **kwargs ) self.config.check() config.configure_logging( self.config ) + self.configure_fluent_log() # Determine the database url if self.config.database_connection: db_url = self.config.database_connection @@ -54,7 +55,8 @@ db_url, self.config.database_engine_options, database_query_profiling_proxy = self.config.database_query_profiling_proxy, - object_store = self.object_store ) + object_store = self.object_store, + trace_logger=self.trace_logger ) # Manage installed tool shed repositories. self.installed_repository_manager = galaxy.tool_shed.InstalledRepositoryManager( self ) # Create an empty datatypes registry. @@ -149,6 +151,7 @@ self.job_stop_queue = self.job_manager.job_stop_queue # Initialize the external service types self.external_service_types = external_service_types.ExternalServiceTypesCollection( self.config.external_service_type_config_file, self.config.external_service_type_path, self ) + def shutdown( self ): self.job_manager.shutdown() self.object_store.shutdown() @@ -161,3 +164,10 @@ os.unlink( self.datatypes_registry.integrated_datatypes_configs ) except: pass + + def configure_fluent_log( self ): + if self.config.fluent_log: + from galaxy.util.log.fluent_log import FluentTraceLogger + self.trace_logger = FluentTraceLogger( 'galaxy', self.config.fluent_host, self.config.fluent_port ) + else: + self.trace_logger = None diff -r 395bfeb484ae0f69bdd7be2115ed007b4c01dd90 -r 09cf284087021586ad08656b7ea444959c6c49bf lib/galaxy/config.py --- a/lib/galaxy/config.py +++ b/lib/galaxy/config.py @@ -261,6 +261,10 @@ self.api_folders = string_as_bool( kwargs.get( 'api_folders', False ) ) # This is for testing new library browsing capabilities. self.new_lib_browse = string_as_bool( kwargs.get( 'new_lib_browse', False ) ) + # Logging with fluentd + self.fluent_log = string_as_bool( kwargs.get( 'fluent_log', False ) ) + self.fluent_host = kwargs.get( 'fluent_host', 'localhost' ) + self.fluent_port = int( kwargs.get( 'fluent_port', 24224 ) ) def __read_tool_job_config( self, global_conf_parser, section, key ): try: diff -r 395bfeb484ae0f69bdd7be2115ed007b4c01dd90 -r 09cf284087021586ad08656b7ea444959c6c49bf lib/galaxy/model/mapping.py --- a/lib/galaxy/model/mapping.py +++ b/lib/galaxy/model/mapping.py @@ -1950,7 +1950,7 @@ # Let this go, it could possibly work with db's we don't support log.error( "database_connection contains an unknown SQLAlchemy database dialect: %s" % dialect ) -def init( file_path, url, engine_options={}, create_tables=False, database_query_profiling_proxy=False, object_store=None ): +def init( file_path, url, engine_options={}, create_tables=False, database_query_profiling_proxy=False, object_store=None, trace_logger=None ): """Connect mappings to the database""" # Connect dataset to the file path Dataset.file_path = file_path @@ -1962,6 +1962,10 @@ if database_query_profiling_proxy: import galaxy.model.orm.logging_connection_proxy as logging_connection_proxy proxy = logging_connection_proxy.LoggingProxy() + # If metlog is enabled, do micrologging + elif trace_logger: + import galaxy.model.orm.logging_connection_proxy as logging_connection_proxy + proxy = logging_connection_proxy.TraceLoggerProxy( trace_logger ) else: proxy = None # Create the database engine diff -r 395bfeb484ae0f69bdd7be2115ed007b4c01dd90 -r 09cf284087021586ad08656b7ea444959c6c49bf lib/galaxy/model/orm/logging_connection_proxy.py --- a/lib/galaxy/model/orm/logging_connection_proxy.py +++ b/lib/galaxy/model/orm/logging_connection_proxy.py @@ -18,13 +18,31 @@ rval = [] for frame, fname, line, funcname, _, _ in inspect.stack()[2:]: rval.append( "%s:%s@%d" % ( stripwd( fname ), funcname, line ) ) - return " > ".join( rval ) + return rval class LoggingProxy(ConnectionProxy): + """ + Logs SQL statements using standard logging module + """ def cursor_execute(self, execute, cursor, statement, parameters, context, executemany): start = time.clock() rval = execute(cursor, statement, parameters, context) duration = time.clock() - start log.debug( "statement: %r parameters: %r executemany: %r duration: %r stack: %r", - statement, parameters, executemany, duration, pretty_stack() ) + statement, parameters, executemany, duration, " > ".join( pretty_stack() ) ) return rval + +class TraceLoggerProxy(ConnectionProxy): + """ + Logs SQL statements using a metlog client + """ + def __init__( self, trace_logger ): + self.trace_logger = trace_logger + def cursor_execute(self, execute, cursor, statement, parameters, context, executemany): + start = time.clock() + rval = execute(cursor, statement, parameters, context) + duration = time.clock() - start + self.trace_logger.log( "sqlalchemy_query", + message="Query executed", statement=statement, parameters=parameters, + executemany=executemany, duration=duration ) + return rval \ No newline at end of file diff -r 395bfeb484ae0f69bdd7be2115ed007b4c01dd90 -r 09cf284087021586ad08656b7ea444959c6c49bf lib/galaxy/util/log/__init__.py --- /dev/null +++ b/lib/galaxy/util/log/__init__.py @@ -0,0 +1,5 @@ +class TraceLogger( object ): + def __init__( self, name ): + self.name = name + def log( **kwargs ): + raise TypeError( "Abstract Method" ) \ No newline at end of file diff -r 395bfeb484ae0f69bdd7be2115ed007b4c01dd90 -r 09cf284087021586ad08656b7ea444959c6c49bf lib/galaxy/util/log/fluent_log.py --- /dev/null +++ b/lib/galaxy/util/log/fluent_log.py @@ -0,0 +1,39 @@ +""" +Provides a `TraceLogger` implementation that logs to a fluentd collector +""" + +import time +import threading + +import galaxy.eggs +galaxy.eggs.require( "fluent-logger" ) +galaxy.eggs.require( "msgpack_python" ) + +from fluent.sender import FluentSender + + +class FluentTraceLogger( object ): + def __init__( self, name, host='localhost', port=24224 ): + self.lock = threading.Lock() + self.thread_local = threading.local() + self.name = name + self.sender = FluentSender( self.name, host=host, port=port ) + + def context_set( self, key, value ): + self.lock.acquire() + if not hasattr( self.thread_local, 'context' ): + self.thread_local.context = {} + self.thread_local.context[key] = value + self.lock.release() + + def context_remove( self, key ): + self.lock.acquire() + del self.thread_local.context[key] + self.lock.release() + + def log( self, label, **kwargs ): + self.lock.acquire() + if hasattr( self.thread_local, 'context' ): + kwargs.update( self.thread_local.context ) + self.lock.release() + self.sender.emit_with_time( label, int(time.time()), kwargs ) \ No newline at end of file diff -r 395bfeb484ae0f69bdd7be2115ed007b4c01dd90 -r 09cf284087021586ad08656b7ea444959c6c49bf lib/galaxy/web/framework/base.py --- a/lib/galaxy/web/framework/base.py +++ b/lib/galaxy/web/framework/base.py @@ -8,6 +8,8 @@ import os.path import sys import tarfile +import threading +import uuid from Cookie import SimpleCookie @@ -68,6 +70,11 @@ self.mapper.explicit = False self.api_mapper = routes.Mapper() self.transaction_factory = DefaultWebTransaction + # Each request will have a unique id. Since we are assuming + # a threaded model for the moment we can store that here + self.request_id = threading.local() + # Set if trace logging is enabled + self.trace_logger = None def add_ui_controller( self, controller_name, controller ): """ Add a controller class to this application. A controller class has @@ -106,12 +113,29 @@ # Create/compile the regular expressions for route mapping self.mapper.create_regs( self.controllers.keys() ) self.api_mapper.create_regs( self.api_controllers.keys() ) + def trace( self, **fields ): + if self.trace_logger: + self.trace_logger.log( "WebApplication", **fields ) + def __call__( self, environ, start_response ): """ Call interface as specified by WSGI. Wraps the environment in user friendly objects, finds the appropriate method to handle the request and calls it. """ + # Immediately create request_id which we will use for logging + self.request_id = request_id = uuid.uuid1().hex + if self.trace_logger: + self.trace_logger.context_set( "request_id", request_id ) + self.trace( message="Starting request" ) + try: + return self.handle_request( environ, start_response ) + finally: + self.trace( message="Handle request finished" ) + if self.trace_logger: + self.trace_logger.context_remove( "request_id" ) + + def handle_request( self, environ, start_response ): # Map url using routes path_info = environ.get( 'PATH_INFO', '' ) map = self.mapper.match( path_info, environ ) @@ -125,6 +149,7 @@ controllers = self.controllers if map == None: raise httpexceptions.HTTPNotFound( "No route for " + path_info ) + self.trace( path_info=path_info, map=map ) # Setup routes rc = routes.request_config() rc.mapper = mapper diff -r 395bfeb484ae0f69bdd7be2115ed007b4c01dd90 -r 09cf284087021586ad08656b7ea444959c6c49bf lib/galaxy/webapps/galaxy/buildapp.py --- a/lib/galaxy/webapps/galaxy/buildapp.py +++ b/lib/galaxy/webapps/galaxy/buildapp.py @@ -130,7 +130,13 @@ webapp.api_mapper.connect("import_workflow", "/api/workflows/upload", controller="workflows", action="import_new_workflow", conditions=dict(method=["POST"])) webapp.api_mapper.connect("workflow_dict", '/api/workflows/download/{workflow_id}', controller='workflows', action='workflow_dict', conditions=dict(method=['GET'])) + # Connect logger from app + if app.trace_logger: + webapp.trace_logger = app.trace_logger + + # Indicate that all configuration settings have been provided webapp.finalize_config() + # Wrap the webapp in some useful middleware if kwargs.get( 'middleware', True ): webapp = wrap_in_middleware( webapp, global_conf, **kwargs ) Repository URL: https://bitbucket.org/galaxy/galaxy-central/ -- This is a commit notification from bitbucket.org. You are receiving this because you have the service enabled, addressing the recipient of this email.