From ad0031c7fbfd0461b4b804b3a75a48212d5c9e9f Mon Sep 17 00:00:00 2001 From: Devananda van der Veen Date: Fri, 1 Jun 2012 12:54:22 -0700 Subject: implement sql-comment-string stack traces Implements solution for bug 1007648. Add python stack traces to all sql comment strings so that someone looking at database query logs can immediately see what code generated each query. This is especially powerful when combined with pt-query-digest to get per-file or per-method aggregates. Change-Id: Ieda5cf4d70cc2643d27fb00efb48de14ca2abe52 --- Authors | 1 + nova/db/sqlalchemy/session.py | 47 +++++++++++++++++++++++++++++++++++++++++++ nova/flags.py | 11 ++++++---- 3 files changed, 55 insertions(+), 4 deletions(-) diff --git a/Authors b/Authors index 3448eb055..92aae922e 100644 --- a/Authors +++ b/Authors @@ -51,6 +51,7 @@ David Subiros Dean Troyer Deepak Garg Derek Higgins +Devananda van der Veen Devdeep Singh Devendra Modium Devin Carlen diff --git a/nova/db/sqlalchemy/session.py b/nova/db/sqlalchemy/session.py index 3f206323e..bdf9bce9e 100644 --- a/nova/db/sqlalchemy/session.py +++ b/nova/db/sqlalchemy/session.py @@ -124,6 +124,12 @@ def get_engine(): _ENGINE = sqlalchemy.create_engine(FLAGS.sql_connection, **engine_args) + if (FLAGS.sql_connection_trace and + _ENGINE.dialect.dbapi.__name__ == 'MySQLdb'): + import MySQLdb.cursors + _do_query = debug_mysql_do_query() + setattr(MySQLdb.cursors.BaseCursor, '_do_query', _do_query) + try: _ENGINE.connect() except OperationalError, e: @@ -154,3 +160,44 @@ def get_maker(engine, autocommit=True, expire_on_commit=False): return sqlalchemy.orm.sessionmaker(bind=engine, autocommit=autocommit, expire_on_commit=expire_on_commit) + + +def debug_mysql_do_query(): + """Return a debug version of MySQLdb.cursors._do_query""" + import MySQLdb.cursors + import traceback + + old_mysql_do_query = MySQLdb.cursors.BaseCursor._do_query + + def _do_query(self, q): + stack = '' + for file, line, method, function in traceback.extract_stack(): + # exclude various common things from trace + if file.endswith('session.py') and method == '_do_query': + continue + if file.endswith('api.py') and method == 'wrapper': + continue + if file.endswith('utils.py') and method == '_inner': + continue + if file.endswith('exception.py') and method == '_wrap': + continue + # nova/db/api is just a wrapper around nova/db/sqlalchemy/api + if file.endswith('nova/db/api.py'): + continue + # only trace inside nova + index = file.rfind('nova') + if index == -1: + continue + stack += "File:%s:%s Method:%s() Line:%s | " \ + % (file[index:], line, method, function) + + # strip trailing " | " from stack + if stack: + stack = stack[:-3] + qq = "%s /* %s */" % (q, stack) + else: + qq = q + old_mysql_do_query(self, qq) + + # return the new _do_query method + return _do_query diff --git a/nova/flags.py b/nova/flags.py index 25d5e0be7..9e4467989 100644 --- a/nova/flags.py +++ b/nova/flags.py @@ -94,10 +94,6 @@ core_opts = [ default='sqlite:///$state_path/$sqlite_db', help='The SQLAlchemy connection string used to connect to the ' 'database'), - cfg.IntOpt('sql_connection_debug', - default=0, - help='Verbosity of SQL debugging information. 0=None, ' - '100=Everything'), cfg.StrOpt('api_paste_config', default="api-paste.ini", help='File name for the paste.deploy config for nova-api'), @@ -120,6 +116,13 @@ debug_opts = [ cfg.BoolOpt('fake_network', default=False, help='If passed, use fake network devices and addresses'), + cfg.IntOpt('sql_connection_debug', + default=0, + help='Verbosity of SQL debugging information. 0=None, ' + '100=Everything'), + cfg.BoolOpt('sql_connection_trace', + default=False, + help='Add python stack traces to SQL as comment strings'), ] FLAGS.register_cli_opts(log_opts) -- cgit