Duplicate Command Messaging / Logging

[jteppinette]

Describe the bug

I have noticed that some alembic command messaging is duplicated where one message goes through the python logger and one around (direct to stdout).

at=ERROR name=alembic.util.messaging msg="Can't locate revision identified by '1'"
  FAILED: Can't locate revision identified by '1'

Expected behavior

Since Alembic leans into configuring all logging via the python logger (alembic.ini), I don't think there should be any messaging that goes around that mechanism.

Of course, I am not an expert in Alembic, so I could be totally missing something.

To Reproduce

Here is a snippet from my logging config.

...
"loggers": {
    "": {"handlers": ["console"]},
    "alembic": {"level": "INFO"},
},
...

Versions.

• OS: MacOS 12.4
• Python: 3.10.0
• Alembic: 1.8.1
• SQLAlchemy: 1.4.42

[CaselIT]

Hi,

This seems a duplicate handler in the logging module.
All logging configuration happens in the env file. Could you share your env.py so see what handler are registered in the logging module?

the only handler that's added by alembic is a null handler that will not print anywhere

[zzzeek]

the FAILED looks like logging from your enclosing application as Alembic raises a CommandError for this case. Alembic doesn't log the exception being raised. (Edit: no, this is how msg() is designed to work: log.error() + stdout for all contingencies).

it's not uncommon for logging in integrated environments to have a little bit of artifacts like this so I dont see it as much of a problem, and in any case there's no action to take on the Alembic side as the end-user can configure logging in any way they'd like.

[zzzeek]

OK it actually prints the message with the "FAILED" prefix from the command line. regardless, that's not logging. this is an aesthetic concern and Alembic wants things in the logs for when it is integrated into larger environments.

[zzzeek]

and similarly, when logging is not configured, if the program fails, it needs to print an error message, so not printing the FAILED message is not an option either. I will accept PRs for a -q /--quiet option

[jteppinette]

Thanks for looking into it. That all makes sense. The quiet flag seems like a good option for people wanting to keep all messaging going through the Python logging system.

[CaselIT]

I will accept PRs for a -q /--quiet option

should we re-open for this feature or a new issue would be better to track it?

[zzzeek]

Just a PR is fine, dont need an issue for this

[sqla-tester]

CaselIT has proposed a fix for this issue in the main branch:

Added quiet option to command line https://gerrit.sqlalchemy.org/c/sqlalchemy/alembic/+/4543