friendly query logging in SQLAlchemy

Question

From a user's perspective, SQLAlchemy's query logging seems a little too verbose and even somewhat cryptic at times:

2015-10-02 13:51:39,500 INFO sqlalchemy.engine.base.Engine BEGIN (implicit)
2015-10-02 13:51:39,502 INFO sqlalchemy.engine.base.Engine SELECT anon_1.shelves_title AS anon_1_shelves_title, ..., anon_1.shelves_created_at AS anon_1_shelves_created_at, anon_1.shelves_updated_at AS anon_1_shelves_updated_at, products_1.id AS products_1_id, products_1.title AS products_1_title
FROM (SELECT shelves.title AS shelves_title, ..., shelves.created_at AS shelves_created_at, shelves.updated_at AS shelves_updated_at
FROM shelves
WHERE shelves.title = ?
 LIMIT ? OFFSET ?) AS anon_1 LEFT OUTER JOIN products AS products_1 ON anon_1.shelves_title = products_1.shelf_title
2015-10-02 13:51:39,502 INFO sqlalchemy.engine.base.Engine ('sample', 1, 0)
2015-10-02 13:51:39,503 INFO sqlalchemy.engine.base.Engine ROLLBACK

(not necessarily representative, but hopefully sufficient to illustrate the issue)

Arguably Ruby on Rails is a good reference here, providing concise and colorized output of the actual database queries:

(via https://code.google.com/p/pylonsquerybar/#What_Others_Have_Done)

Is there a simple way to get similar output for SQLAlchemy? (The aforementioned Pylons Query Bar doesn't seem to be designed for framework-agnostic reuse.)

score 4 · Answer 1 · answered Oct 21 '15 at 08:34

4

you can set any format to logger, you can get logger:

import logging
logging.basicConfig(filename='db.log')
logging.getLogger('sqlalchemy.engine').setLevel(logging.INFO)

how to set colors and format see here:
How can I color Python logging output?

answered Oct 21 '15 at 08:34

kain64b

2,258
2
15
27

I'm afraid this doesn't really address the core issue of formatting the actual SQL queries, removing noise and providing some easier to comprehend structure. – AnC Nov 01 '15 at 09:01
what is "noise"?
2015-10-02 13:51:39,503 INFO sqlalchemy.engine.base.Engine ROLLBACK
2015-10-02 13:51:39,500 INFO sqlalchemy.engine.base.Engine BEGIN (implicit) ? – kain64b Nov 01 '15 at 12:26
Yeah; pretty much anything that isn't the actual SQL query. Ideally, that query should also be displayed exactly as it's being sent to the database. – AnC Nov 01 '15 at 19:33
sqlalchemy.engine.base.Engine BEGIN -- related to transactions, good to have such info in the logs. about: "WHERE shelves.title = ? LIMIT ? OFFSET ?)" vs ruby picture: " where (person.id=7)", here you see 2 different query types. "?"--"sql parameter ". you can check sql statements in the sql profiler, you will see 2 different types. statement with parameters is better(because of server sql parser cache). generally you see exactly what sql server do with sqlalchemy call – kain64b Nov 02 '15 at 09:25

AnC · Answer 2 · 2015-11-01T09:58:44.433

FWIW, below's what we came up with. It adds alternating colorization, which doesn't solve the noise issue, but at least provides some visual distinction.

import logging

import colorama


def configure_sql_logging():
    sqla_logger = logging.getLogger("sqlalchemy.engine.base.Engine")
    sqla_logger.propagate = False
    sqla_logger.addHandler(SQLLogger(colors=["MAGENTA", "CYAN"]))


class SQLLogger(logging.StreamHandler):

    def __init__(self, *args, colors, **kwargs):
        super().__init__(*args, **kwargs)
        self.colors = colors
        self.colorizer = Colorizer(self.stream, colors[0])

    def emit(self, *args, **kwargs):
        with self.colorizer:
            super().emit(*args, **kwargs)

        # cycle colors
        if self.colorizer.active:
            self.colors.append(self.colors.pop(0))
            self.colorizer.color = self.colors[0]


class Colorizer:

    def __init__(self, stream, color):
        self.stream = stream
        self.active = stream.isatty()
        if self.active:
            colorama.init()
            self.color = color

    def __enter__(self):
        if self.active:
            self.stream.write(getattr(colorama.Fore, self.color))

    def __exit__(self, type, value, traceback):
        if self.active:
            self.stream.write(colorama.Fore.RESET)

friendly query logging in SQLAlchemy

2 Answers2