How to change the format of SQLAlchemy engine 'echo' messages?

Viewed 1287

IIUC, the format is set in log.py (lines 33..38 in 1.4.7):

def _add_default_handler(logger):
    handler = logging.StreamHandler(sys.stdout)
    handler.setFormatter(
        logging.Formatter("%(asctime)s %(levelname)s %(name)s %(message)s")
    )
    logger.addHandler(handler)

But all my attempts to set the format to a bare '%(message)s' have failed. For example,

logging.StreamHandler(sys.stdout).setFormatter('%(message)s')

has no effect.

When developing a program in SQLAlchemy, I want to see only the query executed by engine, and these extra fields asctime, levelname and name are distracting.

There is an entire subchapter about engine logging in SQLAlchemy documentation, but it talks only about levels and says nothing about formatting. On the other hand, I guess changing formatting should be possible, because in SQLAlchemy tutorial (see, e.g., here), the logging messages are presented just the way I would like them.

1 Answers

First some remarks:

  1. When you write : logging.StreamHandler(sys.stdout) you're calling a constructor, i.e. you're getting a new instance of logging.StreamHandler class, not the same handler which could have been used in sqla's log module: _add_default_handler(). Modifying it won't have any effect as long as you don't add this handler to some active logger.

  2. It you read carefully the docs page you mentionned (https://docs.sqlalchemy.org/en/14/core/engines.html#configuring-logging), you'll find some hints :

It’s important to note that these two flags work independently of any existing logging configuration, and will make use of logging.basicConfig() unconditionally. This has the effect of being configured in addition to any existing logger configurations. Therefore, when configuring logging explicitly, ensure all echo flags are set to False at all times, to avoid getting duplicate log lines.

logging.basicConfig() accepts a good set of parameters, but deals only with the root logger, from which other loggers will inherit settings.

As a first step I suggest you keep the level and logger name in output, to let you know who is speaking in your messages.

>>> import logging
>>> # 1. Get rid of timestamp for all modules, and set other defaults
... logging.basicConfig(format="%(levelname)s %(name)s %(message)s", level="INFO")
... logging.info("Root logger talking")
... 
INFO root Root logger talking
>>> # 2. Preset top level logger for SQLAlchemy
... logging.getLogger('sqlalchemy').setLevel("INFO")
... 
>>> # 4. Run your code
... import sqlalchemy as sqla
... engine = sqla.create_engine('sqlite:///:memory:')
... 
>>> from sqlalchemy.ext.declarative import declarative_base
... 
... Base = declarative_base()
... from sqlalchemy import Column, Integer, String
>>> class User(Base):
...     __tablename__ = 'users'
... 
...     id = Column(Integer, primary_key=True)
...     name = Column(String)
... 
INFO sqlalchemy.orm.mapper.Mapper (User|users) _configure_property(id, Column)
INFO sqlalchemy.orm.mapper.Mapper (User|users) _configure_property(name, Column)
INFO sqlalchemy.orm.mapper.Mapper (User|users) Identified primary key columns: ColumnSet([Column('id', Integer(), table=<users>, primary_key=True, nullable=False)])
INFO sqlalchemy.orm.mapper.Mapper (User|users) constructed
>>> Base.metadata.create_all(engine)
INFO sqlalchemy.engine.base.Engine SELECT CAST('test plain returns' AS VARCHAR(60)) AS anon_1
INFO sqlalchemy.engine.base.Engine ()
INFO sqlalchemy.engine.base.Engine SELECT CAST('test unicode returns' AS VARCHAR(60)) AS anon_1
INFO sqlalchemy.engine.base.Engine ()
INFO sqlalchemy.engine.base.Engine PRAGMA main.table_info("users")
INFO sqlalchemy.engine.base.Engine ()
INFO sqlalchemy.engine.base.Engine PRAGMA temp.table_info("users")
INFO sqlalchemy.engine.base.Engine ()
INFO sqlalchemy.engine.base.Engine 
CREATE TABLE users (
    id INTEGER NOT NULL, 
    name VARCHAR, 
    PRIMARY KEY (id)
)


INFO sqlalchemy.engine.base.Engine ()
INFO sqlalchemy.engine.base.Engine COMMIT
>>> 

To answer your question more specifically, here's a solution:

      import logging, sys

      sql_logger = logging.getLogger("sqlalchemy.engine.base.Engine")
      hdlr = logging.StreamHandler(sys.stdout)
      hdlr.setFormatter(logging.Formatter("[SQL] %(message)s"))
      sql_logger.addHandler(hdlr)
      sql_logger.setLevel(logging.INFO)

      import sqlalchemy as sqla
      engine = sqla.create_engine('sqlite:///:memory:')

      from sqlalchemy.ext.declarative import declarative_base

      Base = declarative_base()
      from sqlalchemy import Column, Integer, String
      class User(Base):
          __tablename__ = 'users'

          id = Column(Integer, primary_key=True)
          name = Column(String)

      Base.metadata.create_all(engine)

You'll need some more work to handle other modules log messages, while avoiding duplicates

Related