Since I asked for this, let me definitely thank you. I've actually created a similar smaller patch, so I am eager to compare mine to yours, since I am using patching and some other activiites to learn more about Trac and Python development.
Jerry On May 10, 3:12 pm, Christian Boos <[email protected]> wrote: > Hello, > > Here is some update on the topic - I removed the print statements > dumping the SQL queries and replaced them with (optional) DEBUG logging. > > See attached patch debug_sql_logging.diff (applies on latest > rework-testing or trunk branch and with some fuzz on 0.11-stable as well). > > Please tell me what you think, I'd like to add this to 0.11-stable. > > > > John Hampton wrote: > > jerry wrote: > > >> So I'm a newbie with trac, ... When I have worked on other database > >> backed web applications, I have found it useful during debugging to > >> have every database query logged. Logging the database queries during > >> actual production is an enormous privacy hole, but logging queries > >> during debugging is so so nice. > > > Generally this should be the domain of the database server. Admittedly, > > I don't believe this is an option for SQLite > > >> I can see that none of the files in the database api do any logging, > >> and some have commented out print statements. > > > Commented out print statements we should probably remove from the code. > > Done. > > > > >> I would like to change that, but before I do so, I am curious if there > >> is any specific reason the trac db does not use logging, or if it is > >> just an outcome of the trac class architecture. That is, were I to > >> add query logging, would that be appreciated, or would it violate some > >> trac design principle? > > > Not sure it would violate some principle, however, it is more overhead > > (even with logging turned off) and the log is pretty noisy as is on > > DEBUG anyway. > > That does make the log extremely noisy, yes, so the feature has to be > turned on explicitly. > It will be a lot easier for us to tell people having an issue where we > think that SQL logging could help that they have to switch a trac.ini > setting ([trac] debug_sql = true) as opposed to tell them to uncomment > some print statements... > > > > > > >> If I do go ahead, I am looking to find what is hopefully the single > >> spot, or the few spots, through which all queries flow. That would > >> seem to be in trac/db/util.py IterableCursor::execute() and > >> IterableCursor::executemany(). > > > Yes, I believe that is where you would need to put logging statements. > > >> Now the log is kept in the Environ. Is there any way in which code in > >> the database api can determine the current Environ? > > > Not easily. You can use inspect to walk back up the call stack and get > > to it. However, I'm not sure that's a great idea > > Like I suggested before in a previous thread on this topic, it is > possible to pass the logger from the environment down to the connector, > then to the connection, then to the cursor wrapper. The db pool in > between (which is process global) makes this even more fun ;-) > > >> If not, then what I think is possible is to add/modify some sort of > >> debug connection wrapper so that the connection wrapper keeps track of > >> the log and somehow (waives hands once more) makes that available to > >> the IterableCursor or a new debug subclass of IterableCursor. > > > I don't want to dissuade you from contributing, or making a patch. > > However, I don't, yet, see the value for comprehensive statement logging. > > As Jerry and Michael have said before me in the same thread, this can be > very helpful in some debugging scenarios. > > -- Christian > > [debug_sql_logging.diff13K ]Index: trac/db/sqlite_backend.py > =================================================================== > --- trac/db/sqlite_backend.py (revision 8172) > +++ trac/db/sqlite_backend.py (working copy) > @@ -117,14 +117,14 @@ > def get_supported_schemes(self): > return [('sqlite', 1)] > > - def get_connection(self, path, params={}): > + def get_connection(self, path, params={}, log=None): > if not self._version: > global sqlite_version_string > self._version = get_pkginfo(sqlite).get( > 'version', '%d.%d.%s' % sqlite.version_info) > self.env.systeminfo.extend([('SQLite', sqlite_version_string), > ('pysqlite', self._version)]) > - return SQLiteConnection(path, params) > + return SQLiteConnection(path, params, log) > > def init_db(cls, path, params={}): > if path != ':memory:': > @@ -165,7 +165,7 @@ > __slots__ = ['_active_cursors'] > poolable = have_pysqlite and os.name == 'nt' and sqlite_version >= 30301 > > - def __init__(self, path, params={}): > + def __init__(self, path, params={}, log=None): > assert have_pysqlite > 0 > self.cnx = None > if path != ':memory:': > @@ -193,7 +193,7 @@ > timeout = int(params.get('timeout', 10000)) > cnx = sqlite.connect(path, timeout=timeout, encoding='utf-8') > > - ConnectionWrapper.__init__(self, cnx) > + ConnectionWrapper.__init__(self, cnx, log) > > if have_pysqlite == 2: > def cursor(self): > Index: trac/db/api.py > =================================================================== > --- trac/db/api.py (revision 8172) > +++ trac/db/api.py (working copy) > @@ -18,7 +18,7 @@ > import urllib > import time > > -from trac.config import Option, IntOption > +from trac.config import BoolOption, IntOption, Option > from trac.core import * > from trac.db.pool import ConnectionPool > from trac.util.text import unicode_passwd > @@ -70,6 +70,10 @@ > """Timeout value for database connection, in seconds. > Use '0' to specify ''no timeout''. ''(Since 0.11)''""") > > + debug_sql = BoolOption('trac', 'debug_sql', False, > + """Show the SQL queries in the Trac log, at DEBUG level. > + ''(Since 0.11.5)''""") > + > def __init__(self): > self._cnx_pool = None > > @@ -102,7 +106,8 @@ > backup_dir = os.path.join(self.env.path, backup_dir) > db_str = self.config.get('trac', 'database') > db_name, db_path = db_str.split(":",1) > - dest_name = '%s.%i.%d.bak' % (db_name, > self.env.get_version(),int(time.time())) > + dest_name = '%s.%i.%d.bak' % (db_name, self.env.get_version(), > + int(time.time())) > dest = os.path.join(backup_dir, dest_name) > else: > backup_dir = os.path.dirname(dest) > @@ -134,6 +139,8 @@ > args['path'] = os.path.join(self.env.path, > args['path'].lstrip('/')) > > + if self.debug_sql: > + args['log'] = self.log > return connector, args > > Index: trac/db/pool.py > =================================================================== > --- trac/db/pool.py (revision 8172) > +++ trac/db/pool.py (working copy) > @@ -36,8 +36,8 @@ > to the pool. > """ > > - def __init__(self, pool, cnx, key, tid): > - ConnectionWrapper.__init__(self, cnx) > + def __init__(self, pool, cnx, key, tid, log=None): > + ConnectionWrapper.__init__(self, cnx, log) > self._pool = pool > self._key = key > self._tid = tid > @@ -46,6 +46,7 @@ > if self.cnx: > self._pool._return_cnx(self.cnx, self._key, self._tid) > self.cnx = None > + self.log = None > > def __del__(self): > self.close() > @@ -79,6 +80,7 @@ > def get_cnx(self, connector, kwargs, timeout=None): > num = 1 > cnx = None > + log = kwargs.get('log') > key = unicode(kwargs) > start = time.time() > tid = threading._get_ident() > @@ -114,7 +116,7 @@ > cnx = connector.get_connection(**kwargs) > if cnx: > self._active[(tid, key)] = (cnx, num) > - return PooledConnection(self, cnx, key, tid) > + return PooledConnection(self, cnx, key, tid, log) > # Worst option: wait until a connection pool slot is > available > if timeout and (time.time() - start) > timeout: > raise TimeoutError(_('Unable to get database ' > Index: trac/db/mysql_backend.py > =================================================================== > --- trac/db/mysql_backend.py (revision 8172) > +++ trac/db/mysql_backend.py (working copy) > @@ -74,8 +74,8 @@ > return [] > > def get_connection(self, path, user=None, password=None, host=None, > - port=None, params={}): > - cnx = MySQLConnection(path, user, password, host, port, params) > + port=None, params={}, log=None): > + cnx = MySQLConnection(path, user, password, host, port, params, log) > if not self._version: > self._version = get_pkginfo(MySQLdb).get('version', > MySQLdb.__version__) > @@ -177,7 +177,7 @@ > poolable = True > > def __init__(self, path, user=None, password=None, host=None, > - port=None, params={}): > + port=None, params={}, log=None): > if path.startswith('/'): > path = path[1:] > if password == None: > @@ -186,7 +186,7 @@ > port = 3306 > cnx = MySQLdb.connect(db=path, user=user, passwd=password, > host=host, port=port, charset='utf8') > - ConnectionWrapper.__init__(self, cnx) > + ConnectionWrapper.__init__(self, cnx, log) > self._is_closed = False > > def cast(self, column, type): > Index: trac/db/postgres_backend.py > =================================================================== > --- trac/db/postgres_backend.py (revision 8172) > +++ trac/db/postgres_backend.py (working copy) > @@ -47,10 +47,11 @@ > return [('postgres', 1)] > > def get_connection(self, path, user=None, password=None, host=None, > - port=None, params={}): > + port=None, params={}, log=None): > global psycopg > global PgSQL > - cnx = PostgreSQLConnection(path, user, password, host, port, params) > + cnx = PostgreSQLConnection(path, user, password, host, port, params, > + log) > if not self._version: > if psycopg: > self._version = get_pkginfo(psycopg).get('version', > @@ -144,7 +145,7 @@ > poolable = True > > def __init__(self, path, user=None, password=None, host=None, port=None, > - params={}): > + params={}, log=None): > if path.startswith('/'): > path = path[1:] > # We support both psycopg and PgSQL but prefer psycopg > @@ -192,7 +193,7 @@ > cnx.commit() > except PGSchemaError: > cnx.rollback() > - ConnectionWrapper.__init__(self, cnx) > + ConnectionWrapper.__init__(self, cnx, log) > > def cast(self, column, type): > # Temporary hack needed for the union of selects in the search module > Index: trac/db/util.py > =================================================================== > --- trac/db/util.py (revision 8172) > +++ trac/db/util.py (working copy) > @@ -17,7 +17,8 @@ > > def sql_escape_percent(sql): > import re > - return re.sub("'((?:[^']|(?:''))*)'", lambda m: m.group(0).replace('%', > '%%'), sql) > + return re.sub("'((?:[^']|(?:''))*)'", > + lambda m: m.group(0).replace('%', '%%'), sql) > > class IterableCursor(object): > @@ -27,10 +28,11 @@ > > Iteration will generate the rows of a SELECT query one by one. > """ > - __slots__ = ['cursor'] > + __slots__ = ['cursor', 'log'] > > - def __init__(self, cursor): > + def __init__(self, cursor, log=None): > self.cursor = cursor > + self.log = log > > def __getattr__(self, name): > return getattr(self.cursor, name) > @@ -43,17 +45,33 @@ > yield row > > def execute(self, sql, args=None): > - # -- In case of SQL errors, uncomment the following 'print' > statements > - # print 'execute', repr(sql) > + if self.log: > + self.log.debug('SQL: %r', sql) > + try: > + if args: > + self.log.debug('args: %r', args) > + return self.cursor.execute(sql_escape_percent(sql), args) > + return self.cursor.execute(sql) > + except Exception, e: > + self.log.debug('execute exception: %r', e) > + raise > if args: > - # print repr(args) > return self.cursor.execute(sql_escape_percent(sql), args) > return self.cursor.execute(sql) > > def executemany(self, sql, args=None): > - # print 'executemany', repr(sql) > + if self.log: > + self.log.debug('SQL: %r', sql) > + try: > + if args: > + self.log.debug('args: %r', args) > + return self.cursor.executemany(sql_escape_percent(sql), > + args) > + return self.cursor.execute(sql) > + except Exception, e: > + self.log.debug('executemany exception: %r', e) > + raise > if args: > - # print repr(args) > return self.cursor.executemany(sql_escape_percent(sql), args) > return self.cursor.executemany(sql) > > @@ -64,10 +82,11 @@ > This wrapper makes cursors produced by the connection iterable using > `IterableCursor`. > """ > - __slots__ = ['cnx'] > + __slots__ = ['cnx', 'log'] > > - def __init__(self, cnx): > ... > > read more » --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Trac Development" group. To post to this group, send email to [email protected] To unsubscribe from this group, send email to [email protected] For more options, visit this group at http://groups.google.com/group/trac-dev?hl=en -~----------~----~----~----~------~----~------~--~---
