techspot.zzzeek.org

A few people have been asking about this one as of late, it's quite easy to do with a ConnectionProxy. Here's a quick recipe (yes, this is 0.5):

from sqlalchemy.interfaces import ConnectionProxy
import time
import logging
 
logging.basicConfig()
logger = logging.getLogger("myapp.sqltime")
logger.setLevel(logging.DEBUG)
 
class TimerProxy(ConnectionProxy):
    def cursor_execute(self, execute, cursor, statement, parameters, context, executemany):
        now = time.time()
        try:
            return execute(cursor, statement, parameters, context)
        finally:
            total = time.time() - now
            logger.debug("Query: %s" % statement)
            logger.debug("Total Time: %f" % total)
 
if __name__ == '__main__':
    from sqlalchemy import *
 
    engine= create_engine('sqlite://', proxy=TimerProxy())
 
    m1 = MetaData(engine)
    t1 = Table("sometable", m1, 
            Column("id", Integer, primary_key=True),
            Column("data", String(255), nullable=False),
        )
 
    conn = engine.connect()
    m1.create_all(conn)
 
    conn.execute(
        t1.insert(), 
        [{"data":"entry %d" % x} for x in xrange(100000)]
    )
 
    conn.execute(
        t1.select().where(t1.c.data.between("entry 25", "entry 7800")).order_by(desc(t1.c.data))
    )

Output:

DEBUG:myapp.sqltime:Query: PRAGMA table_info("sometable")
DEBUG:myapp.sqltime:Total Time: 0.000233
DEBUG:myapp.sqltime:Query: 
CREATE TABLE sometable (
    id INTEGER NOT NULL, 
    data VARCHAR(255) NOT NULL, 
    PRIMARY KEY (id)
)
 
 
DEBUG:myapp.sqltime:Total Time: 0.000397
DEBUG:myapp.sqltime:Query: INSERT INTO sometable (data) VALUES (?)
DEBUG:myapp.sqltime:Total Time: 1.147780
DEBUG:myapp.sqltime:Query: SELECT sometable.id, sometable.data 
FROM sometable 
WHERE sometable.data BETWEEN ? AND ? ORDER BY sometable.data DESC
DEBUG:myapp.sqltime:Total Time: 1.064579

ConnectionProxy features two methods that can be overridden, execute() and cursor_execute(). The difference is that the former hooks onto the overall execute() method of Connection and is given the application level arguments, such as the ClauseElement and parameter dictionary, whereas the latter is called at the lower level where we have a string SQL statement and bind parameters compiled and formatted against the specific DBAPI in use.