CODEWITHSUNDEEP
pythonloggingsqlalchemy
Milind Dalvi
Milind Dalvi

Reputation: 846

Logging SQLAlchemy in a separate file

I am trying to keep my SQL alchemy logs separate from my custom logs

LOG_LEVEL = 20
LOG_FORMAT = "%(asctime)s %(name)s %(levelname)s %(message)s"
logging.basicConfig(filename='my_log.log', format=LOG_FORMAT, level=LOG_LEVEL)

handler_sql = logging.FileHandler('my_alchemy_log.log')
handler_sql.setFormatter(logging.Formatter(LOG_FORMAT))
sql_logger = logging.getLogger('sqlalchemy.engine')
sql_logger.setLevel(LOG_LEVEL)
sql_logger.addHandler(handler_sql)

logger = logging.getLogger(__name__)
logger.info("this belongs to my_log")

s = sessionmaker(bind=create_engine(CONN_STRING, poolclass=NullPool))
result = s.query(SomeTableModel).filter_by(**kwargs).first()
s.close()

What's happening is two files are created and they look like below,

my_log.log

2018-10-24 23:35:01,589 main INFO this belongs to my_log
2018-10-24 23:35:01,650 sqlalchemy.engine.base.Engine INFO SHOW VARIABLES LIKE 'sql_mode'
2018-10-24 23:35:01,650 sqlalchemy.engine.base.Engine INFO {}
2018-10-24 23:35:01,689 sqlalchemy.engine.base.Engine INFO SELECT DATABASE()
2018-10-24 23:35:01,689 sqlalchemy.engine.base.Engine INFO {}
2018-10-24 23:35:01,725 sqlalchemy.engine.base.Engine INFO SELECT CAST('test plain returns' AS CHAR(60)) AS anon_1
2018-10-24 23:35:01,725 sqlalchemy.engine.base.Engine INFO {}
2018-10-24 23:35:01,742 sqlalchemy.engine.base.Engine INFO SELECT CAST('test unicode returns' AS CHAR(60)) AS anon_1
2018-10-24 23:35:01,743 sqlalchemy.engine.base.Engine INFO {}
2018-10-24 23:35:01,756 sqlalchemy.engine.base.Engine INFO BEGIN (implicit)
2018-10-24 23:35:01,770 sqlalchemy.engine.base.Engine INFO SELECT ..............

my_alchemy_log.log

2018-10-24 23:35:01,650 sqlalchemy.engine.base.Engine INFO SHOW VARIABLES LIKE 'sql_mode'
2018-10-24 23:35:01,650 sqlalchemy.engine.base.Engine INFO {}
2018-10-24 23:35:01,689 sqlalchemy.engine.base.Engine INFO SELECT DATABASE()
2018-10-24 23:35:01,689 sqlalchemy.engine.base.Engine INFO {}
2018-10-24 23:35:01,725 sqlalchemy.engine.base.Engine INFO SELECT CAST('test plain returns' AS CHAR(60)) AS anon_1
2018-10-24 23:35:01,725 sqlalchemy.engine.base.Engine INFO {}
2018-10-24 23:35:01,742 sqlalchemy.engine.base.Engine INFO SELECT CAST('test unicode returns' AS CHAR(60)) AS anon_1
2018-10-24 23:35:01,743 sqlalchemy.engine.base.Engine INFO {}
2018-10-24 23:35:01,756 sqlalchemy.engine.base.Engine INFO BEGIN (implicit)
2018-10-24 23:35:01,770 sqlalchemy.engine.base.Engine INFO SELECT ..............

The queries repeat in my_log.log too! That's not expected!!! What's expected is, that my_log.log should only contain "this belongs to my_log" and no queries. Queries should only end up in my_alchemy_log.log

Upvotes: 1

Views: 1231

Answers (1)

Vinay Sajip
Vinay Sajip

Reputation: 99365

You can do

sql_logger.propagate = False

which will stop events logged there being propagated to handlers of ancestor loggers (and hence the root logger, which writes to my_log.log).

To turn off all SQLAlchemy logging (not just from sqlalchemy.engine) from my_log.log, you might need to do

logging.getLogger('sqlalchemy').propagate = False

The propagate flag is documented here.

Upvotes: 1

Related Questions