Issues

Issue #79 resolved

Improve logging in SQLAlchemy

Anonymous created an issue

Here is a small patch for SQLAlchemy which improves the logging capabilities, including the connection id, a timestamp, and the engine passing the logger to the Pool class in order to get all logging into the same file, if using SQLAlchemy on a daemon process.

Index: sqlalchemy/pool.py

--- sqlalchemy/pool.py (revisión: 1041) +++ sqlalchemy/pool.py (copia de trabajo) @@ -10,13 +10,16 @@ be managed automatically, based on module type and connect arguments, simply by calling regular DBAPI connect() methods."""

-import Queue, weakref, string, cPickle +import sys, Queue, weakref, string, cPickle

try: import thread except: import dummythread as thread

+import util + + proxies = {}

def manage(module, **params): @@ -69,10 +72,11 @@

class Pool(object): - def init(self, echo = False, use_threadlocal = True): + def init(self, echo = False, use_threadlocal = True, logger = None): self._threadconns = weakref.WeakValueDictionary() self._use_threadlocal = use_threadlocal self._echo = echo + self._logger = logger or sys.stdout

 def connect(self):
     if not self._use_threadlocal:

@@ -115,7 +119,7 @@ raise NotImplementedError()

 def log(self, msg):
  • print msg
  • util.log(self._logger, msg, 'Pool')

class ConnectionFairy(object): def init(self, pool): Index: sqlalchemy/util.py =================================================================== --- sqlalchemy/util.py (revisión: 1041) +++ sqlalchemy/util.py (copia de trabajo) @@ -5,7 +5,7 @@ # the MIT License: http://www.opensource.org/licenses/mit-license.php

all = 'OrderedDict', 'generic_repr', 'HashSet', 'AttrProp' -import thread, weakref, UserList,string, inspect +import thread, threading, weakref, UserList, time, string, inspect from exceptions import *

def to_list(x): @@ -23,7 +23,7 @@ return HashSet(to_list(x)) else: return x - +
class AttrProp(object): """a quick way to stick a property accessor on an object""" def init(self, key): @@ -447,4 +447,23 @@ raise AssertionError("instance has no attribute '%s'" % arg)

 return newparams
  • \ Sin fin-de-l¡nea al final del archivo + + +def log(logger, message, origin, timestamp=True):
  • "Writes a log message into the logger"
  • try:
  • logwrite = logger.write
  • except AttributeError:
  • return +
  • if timestamp:
  • t = time.time()
  • ms = (t - long(t)) * 1000
  • timestamp = time.strftime("%Y-%m-%d %H:%M:%S", time.localtime(t))
  • timestamp = "%s,%03d" % (timestamp, ms)
  • else:
  • timestamp = ""
  • threadname = threading.currentThread().getName()
  • threadname = threadname + ' '*(8-len(threadname))
  • logwrite('%(timestamp)s %(origin)-8s/%(threadname)s: %(message)s\n' % locals()) + Index: sqlalchemy/engine.py =================================================================== --- sqlalchemy/engine.py (revisión: 1041) +++ sqlalchemy/engine.py (copia de trabajo) @@ -174,6 +174,7 @@ (cargs, cparams) = self.connect_args() if pool is None: params'echo' = echo_pool
  • params'logger' = logger self._pool = sqlalchemy.pool.manage(self.dbapi(), params).get_pool(*cargs, cparams) else: self._pool = pool @@ -184,10 +185,7 @@ self.tables = {} self._ischema = None self._figure_paramstyle()
  • if logger is None:
  • self.logger = sys.stdout
  • else:
  • self.logger = logger
  • self.logger = logger or sys.stdout

    def _get_ischema(self): # We use a property for ischema so that the accessor @@ -523,7 +521,7 @@ else: parameters = parameters.values()

  • self.execute(statement, parameters, connection=connection, cursor=cursor, return_raw=True)

  • self.execute(statement, parameters, connection=connection, cursor=cursor, return_raw=True) return cursor

     self.pre_exec(proxy, compiled, parameters, **kwargs)
    

    @@ -572,15 +570,19 @@

     try:
         if echo is True or self.echo is not False:
    
    • self.log(statement)
    • self.log(repr(parameters))
    • self.log(connection, statement)
    • self.log(connection, repr(parameters)) if parameters is not None and isinstance(parameters, list) and len(parameters) > 0 and (isinstance(parameters0, list) or isinstance(parameters0, dict)):
    • self.log(connection, 'ExecuteMany') self._executemany(cursor, statement, parameters) else:
    • self.log(connection, 'Execute') self._execute(cursor, statement, parameters) if self.context.transaction is None:
    • self.log(connection, 'COMMIT') self.do_commit(connection) except:
    • self.log(connection, 'ROLLBACK') self.do_rollback(connection) raise if return_raw: @@ -598,9 +600,9 @@ c.executemany(statement, parameters) self.context.rowcount = c.rowcount
  • def log(self, msg):

  • def log(self, connection, msg): """logs a message using this SQLEngine's logger stream."""
  • self.logger.write(msg + "\n")
  • return util.log(self.logger, msg, '0x%x' % id(connection))

class ResultProxy:

Comments (5)

  1. Mike Bayer repo owner

    1084 commits a degree of this functionality via a util.Logger object which can be configured or replaced upon sending a new one to engine/pool. that way you can tailor if you want the timestamps, threadnames (which I usually dont). not sure what you gain by the id of the connection entry and it takes up too much room on my console...would rather keep it simple.

  2. Mike Bayer repo owner
    • removed status
    • changed status to open
    • marked as

    though this solution is hardly better than just the print statments we already had; a real logging solution here would require a lot more thought than this, including registration/filtering of areas for logging (i.e. engine, unit of work, pool), log levels, probably usage of the python logging module to wrap it all together.

  3. Log in to comment