Search code examples
pythonpython-3.xloggingalembic

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.

Solution

  • 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.