[flake8-logging] Add ExcInfoOutsideExceptionHandler (LOG014)

[snowdrop4]

Summary

Add ExcInfoOutsideExceptionHandler (LOG014) from the flake8-logging plugin (parent issue #7248).

This rule detects the exc_info kwarg being set to True outside of an exception handling block, which results in unwanted logging output.

I did some mild refactoring by adding a helpers.rs in the crate to reduce duplication.

Test Plan

Lots of fixtures.

[github-actions]

ruff-ecosystem results

Linter (stable)

✅ ecosystem check detected no linter changes.

Linter (preview)

ℹ️ ecosystem check detected linter changes. (+15 -0 violations, +0 -0 fixes in 4 projects; 51 projects unchanged)

apache/airflow (+1 -0 violations, +0 -0 fixes)

ruff check --no-cache --exit-zero --ignore RUF9 --output-format concise --preview --select ALL

+ task_sdk/src/airflow/sdk/execution_time/supervisor.py:527:9: LOG014 Use of `exc_info` outside an exception handler

apache/superset (+12 -0 violations, +0 -0 fixes)

ruff check --no-cache --exit-zero --ignore RUF9 --output-format concise --preview --select ALL

+ superset/commands/report/base.py:105:13: LOG014 Use of `exc_info` outside an exception handler
+ superset/db_engine_specs/hive.py:587:9: LOG014 Use of `exc_info` outside an exception handler
+ superset/sql_lab.py:136:5: LOG014 Use of `exc_info` outside an exception handler
+ superset/sql_lab.py:140:5: LOG014 Use of `exc_info` outside an exception handler
+ superset/tasks/cache.py:270:9: LOG014 Use of `exc_info` outside an exception handler
+ superset/utils/core.py:572:9: LOG014 Use of `exc_info` outside an exception handler
+ superset/views/error_handling.py:140:9: LOG014 Use of `exc_info` outside an exception handler
+ superset/views/error_handling.py:145:9: LOG014 Use of `exc_info` outside an exception handler
+ superset/views/error_handling.py:151:9: LOG014 Use of `exc_info` outside an exception handler
+ superset/views/error_handling.py:160:9: LOG014 Use of `exc_info` outside an exception handler
+ superset/views/error_handling.py:187:9: LOG014 Use of `exc_info` outside an exception handler
+ superset/views/error_handling.py:209:9: LOG014 Use of `exc_info` outside an exception handler

rotki/rotki (+1 -0 violations, +0 -0 fixes)

ruff check --no-cache --exit-zero --ignore RUF9 --output-format concise --preview

+ rotkehlchen/api/server.py:431:9: LOG014 Use of `exc_info` outside an exception handler

zulip/zulip (+1 -0 violations, +0 -0 fixes)

ruff check --no-cache --exit-zero --ignore RUF9 --output-format concise --preview --select ALL

+ zerver/lib/push_notifications.py:1330:17: LOG014 Use of `exc_info` outside an exception handler

Changes by rule (1 rules affected)

code	total	+ violation	- violation	+ fix	- fix
LOG014	15	15	0	0	0

[snowdrop4]

The ecosystem checks are turning up a few instances just like this.

Technically in this case, if we are able to tell that banana() is only ever called from inside an exception handling block, then we could mark this as okay. But I don't think it's possible to check all calling sites?

[AlexWaygood]

It's possible, but you'd need to move the rule to crates/ruff_linter/src/checkers/ast/analyze/bindings.rs rather than crates/ruff_linter/src/checkers/ast/analyze/expression.rs. The difference is that the rules executed from bindings.rs are run after the entire semantic model has been built, so they have more information available to them in some ways: they're able to iterate through all the references to a binding as well as looking at the original binding itself. You can see an example of how to do it in a PR I merged this morning: #14661.

[snowdrop4]

Ahh. I'll revise it to include that check then. Thanks.

[AlexWaygood]

no problem, thanks for the PR!

[snowdrop4]

Forgive me if I'm misunderstanding, but I don't think moving it to bindings.rs works?

An expression like logging.info("foo", exc_info=True) isn't a binding, so if I move my lint function call to bindings.rs, then the only situation the lint could possibly apply would be x = logging.info("foo", exc_info=True) or (x := logging.info("foo", exc_info=True)), which no one writes.

Is it possible to make a new version of expression.rs that's called after the entire semantic model has been built? I don't think there's any way around calling the lint function on expressions, since the lint is designed to find bad function calls.

[AlexWaygood]

An expression like logging.info("foo", exc_info=True) isn't a binding, so if I move my lint function call to bindings.rs, then the only situation the lint could possibly apply would be x = logging.info("foo", exc_info=True) or (x := logging.info("foo", exc_info=True)), which no one writes.

ah, you're quite right.

I suppose what would be best would be to collect all logging.(...) calls into a Vec stored on this struct as we traverse the AST in https://github.com/astral-sh/ruff/blob/main/crates/ruff_linter/src/checkers/ast/mod.rs. Then after the AST has been fully visited and the SemanticModel has been fully constructed, we can call this rule on each logging(...) call we stored in the Vec.

[dylwil3]

@snowdrop4 Thanks for working on this!

Would you, by any chance, be able to walk me through (at least some of) the ecosystem results and help me understand why/whether they are true positives?

I'm a little worried (probably unnecessarily) that a library may define a function in a publicly accessible namespace

def foo():
    # <-- function logic here --- >
    
    # exc_info outside of except
    logging.exception(..., exc_info=True)

and then any of the following (or a mixture) may occur:

1. foo is imported in a different file and called inside an except block.
2. foo is called from the body of bar which is called from the body of baz... etc. which is then called inside an except block.
3. foo has a decorator which secretly inserts a try/except.
4. foo is not called in an except block in the whole library, but it is meant to be consumed by users within an except block.

I don't think I know enough about the use-cases for specifying exc_info=True outside of an except block to tell whether people are really doing it by accident or intentionally for something like 1-4.

I don't think there's a problem with performing this lint for functions defined inside another function scope, since they cannot be used elsewhere, but for the above case I'm less sure.

Apologies if I'm making a mountain out of a molehill here - you probably know more than me about Python logging practices and can tell me I'm off base here!

[dylwil3]

@snowdrop4 Sorry again for the added complexity here. What do you think of the following conservative approach to this rule?

1. If the violation is in the module-level scope, emit a lint.
2. If the violation is in a nested function, emit a lint
3. If the violation is in a function and the function is used somewhere in the file not inside an except-handler, emit a lint
4. otherwise, don't emit a lint

As I said in the previous comment, I'm happy to be overruled here if you think the current ecosystem check and scope of the rule seems reasonable given how Python developers use this logging option generally.

Thanks for your patience and your contribution!