Question

How can I stop the alembic logger from deactivating my own loggers after using an alembic command in code?

I'm using alembic in my code to apply database migrations at application start. I'm also using Python's builtin logging lib to log to the terminal. After applying the migrations (or running any alembic command that prints to stdout it seems) my loggers stop working, though.

Code:

import logging

import alembic.command
from alembic.config import Config as AlembicConfig

logging.basicConfig(level=logging.DEBUG)
logger = logging.getLogger("app")

logger.debug("Applying alembic migrations.")

alembic_config = AlembicConfig("alembic.ini")
alembic_config.attributes["sqlalchemy.url"] = connection_string
alembic.command.upgrade(alembic_config, "head", tag="from_app")

logger.debug("Terminating app.")

Expected output:

DEBUG:app:Applying alembic migrations.
INFO  [alembic.runtime.migration] Context impl PostgresqlImpl.
INFO  [alembic.runtime.migration] Will assume transactional DDL.
DEBUG:app:Terminating app.

Actual output:

DEBUG:app:Applying alembic migrations.
INFO  [alembic.runtime.migration] Context impl PostgresqlImpl.
INFO  [alembic.runtime.migration] Will assume transactional DDL.

The last line is missing.

I've tried setting the log level again after applying the migrations (I thought maybe it changed the root logger log level):

...
alembic.command.upgrade(alembic_config, "head", tag="from_app")

logger.setLevel(logging.DEBUG)
logger.debug("Terminating app.")

In fact, even logger.critical("blah") won't log anything anymore.

I've also tried applying the basic config again and getting the logger again:

...
alembic.command.upgrade(alembic_config, "head", tag="from_app")

logging.basicConfig(level=logging.DEBUG)
logger = logging.getLogger("app")
logger.debug("Terminating app.")

But to no avail. Even the root logger isn't logging anymore:

...
alembic.command.upgrade(alembic_config, "head", tag="from_app")

logging.basicConfig(level=logging.DEBUG)
logging.debug("Terminating app.")

Is there anything I can do to make sure that my loggers are logging? I'd like to keep using the builtin logging functionality, but I'm also open to using some lib for that.

 2  44  2
1 Jan 1970

Solution

 2

The answer will be found in your alembic.ini file.

You're running a command which was intended to be a script, not an API call, so alembic is configuring its own logging using logging.fileConfig, which by default uses disable_existing_loggers=True. That option will disable any existing non-root loggers unless they or their ancestors are explicitly named in the logging configuration file.

So, the path of least resistance will be to setup your logging configuration in there too. There will be a section with the logging configuration in alembic.ini - look for a [loggers] section header. You'll want to modify the content so that your own loggers remain visible - add a [logger_app] section with the desired handlers, formatters etc.

For consistency's sake, you may want to switch to using fileConfig from your own script too, instead of the logging.basicConfig.

An alternative option would be to run alembic scripts in a subprocess, so that their logging configuration doesn't concern you. The stdout/stderr of the subprocess can always be captured and re-emitted as log events from your main process.

2024-07-22
wim

Solution

 0

Although wim's answer led me to the solution, I'll add an answer for the solution I implemented in the end. Taking this approach, I didn't have to duplicate my logger settings in the alembic.ini and necessary changes to the code were limited to a single line.

Edit the env.py generated by alembic

In the env.py by alembic there's a section close to the imports, where their loggers get configurated:

# Interpret the config file for Python logging.
# This line sets up loggers basically.
if config.config_file_name is not None:
    fileConfig(config.config_file_name)

Changing the 4th line to include the keyword parameter disable_existing_loggers=False will allow your own loggers to keep running and logging:

# Interpret the config file for Python logging.
# This line sets up loggers basically.
if config.config_file_name is not None:
    fileConfig(config.config_file_name, disable_existing_loggers=False)

The logging docs mention that this parameter is set to True by default for backwards compatibility:

Warning

The fileConfig() function takes a default parameter, disable_existing_loggers, which defaults to True for reasons of backward compatibility. This may or may not be what you want, since it will cause any non-root loggers existing before the fileConfig() call to be disabled unless they (or an ancestor) are explicitly named in the configuration. Please refer to the reference documentation for more information, and specify False for this parameter if you wish.

It doesn't mention what exactly constitutes this compatibility, and using Python 3.12 for my app I'm not sure, if I even need it.

2024-07-23
Tim