mirror of https://github.com/astral-sh/ruff
[`ruff`] Add `logging-eager-conversion` (`RUF065`) (#19942)
<!-- Thank you for contributing to Ruff/ty! To help us out with reviewing, please consider the following: - Does this pull request include a summary of the change? (See below.) - Does this pull request include a descriptive title? (Please prefix with `[ty]` for ty pull requests.) - Does this pull request include references to any relevant issues? --> ## Summary Fixes #12734 I have started with simply checking if any arguments that are providing extra values to the log message are calls to `str` or `repr`, as suggested in the linked issue. There was a concern that this could cause false positives and the check should be more explicit. I am happy to look into that if I have some further examples to work with. If this is the accepted solution then there are more cases to add to the test and it should possibly also do test for the same behavior via the `extra` keyword. <!-- What's the purpose of the change? What does it do, and why? --> ## Test Plan I have added a new test case and python file to flake8_logging_format with examples of this anti-pattern. <!-- How was it tested? -->
This commit is contained in:
Gary Yendell
GitHub
parent
43cda2dfe9
commit
44fc87f491
|
|
@ -0,0 +1,39 @@
|
|||
import logging
|
||||
|
||||
# %s + str()
|
||||
logging.info("Hello %s", str("World!"))
|
||||
logging.log(logging.INFO, "Hello %s", str("World!"))
|
||||
|
||||
# %s + repr()
|
||||
logging.info("Hello %s", repr("World!"))
|
||||
logging.log(logging.INFO, "Hello %s", repr("World!"))
|
||||
|
||||
# %r + str()
|
||||
logging.info("Hello %r", str("World!"))
|
||||
logging.log(logging.INFO, "Hello %r", str("World!"))
|
||||
|
||||
# %r + repr()
|
||||
logging.info("Hello %r", repr("World!"))
|
||||
logging.log(logging.INFO, "Hello %r", repr("World!"))
|
||||
|
||||
from logging import info, log
|
||||
|
||||
# %s + str()
|
||||
info("Hello %s", str("World!"))
|
||||
log(logging.INFO, "Hello %s", str("World!"))
|
||||
|
||||
# %s + repr()
|
||||
info("Hello %s", repr("World!"))
|
||||
log(logging.INFO, "Hello %s", repr("World!"))
|
||||
|
||||
# %r + str()
|
||||
info("Hello %r", str("World!"))
|
||||
log(logging.INFO, "Hello %r", str("World!"))
|
||||
|
||||
# %r + repr()
|
||||
info("Hello %r", repr("World!"))
|
||||
log(logging.INFO, "Hello %r", repr("World!"))
|
||||
|
||||
def str(s): return f"str = {s}"
|
||||
# Don't flag this
|
||||
logging.info("Hello %s", str("World!"))
|
||||
|
|
@ -1286,6 +1286,9 @@ pub(crate) fn expression(expr: &Expr, checker: &Checker) {
|
|||
if checker.is_rule_enabled(Rule::UnnecessaryEmptyIterableWithinDequeCall) {
|
||||
ruff::rules::unnecessary_literal_within_deque_call(checker, call);
|
||||
}
|
||||
if checker.is_rule_enabled(Rule::LoggingEagerConversion) {
|
||||
ruff::rules::logging_eager_conversion(checker, call);
|
||||
}
|
||||
if checker.is_rule_enabled(Rule::StarmapZip) {
|
||||
ruff::rules::starmap_zip(checker, call);
|
||||
}
|
||||
|
|
|
|||
|
|
@ -1052,6 +1052,8 @@ pub fn code_to_rule(linter: Linter, code: &str) -> Option<(RuleGroup, Rule)> {
|
|||
(Ruff, "061") => (RuleGroup::Preview, rules::ruff::rules::LegacyFormPytestRaises),
|
||||
(Ruff, "063") => (RuleGroup::Preview, rules::ruff::rules::AccessAnnotationsFromClassDict),
|
||||
(Ruff, "064") => (RuleGroup::Preview, rules::ruff::rules::NonOctalPermissions),
|
||||
(Ruff, "065") => (RuleGroup::Preview, rules::ruff::rules::LoggingEagerConversion),
|
||||
|
||||
(Ruff, "100") => (RuleGroup::Stable, rules::ruff::rules::UnusedNOQA),
|
||||
(Ruff, "101") => (RuleGroup::Stable, rules::ruff::rules::RedirectedNOQA),
|
||||
(Ruff, "102") => (RuleGroup::Preview, rules::ruff::rules::InvalidRuleCode),
|
||||
|
|
|
|||
|
|
@ -1,8 +1,9 @@
|
|||
use ruff_python_ast::InterpolatedStringElement;
|
||||
use ruff_python_ast::{self as ast, Arguments, Expr, Keyword, Operator, StringFlags};
|
||||
|
||||
use ruff_python_semantic::analyze::logging;
|
||||
use ruff_python_stdlib::logging::LoggingLevel;
|
||||
use ruff_text_size::Ranged;
|
||||
use ruff_text_size::{Ranged, TextRange};
|
||||
|
||||
use crate::checkers::ast::Checker;
|
||||
use crate::preview::is_fix_f_string_logging_enabled;
|
||||
|
|
@ -198,7 +199,7 @@ fn check_log_record_attr_clash(checker: &Checker, extra: &Keyword) {
|
|||
}
|
||||
|
||||
#[derive(Debug, Copy, Clone)]
|
||||
enum LoggingCallType {
|
||||
pub(crate) enum LoggingCallType {
|
||||
/// Logging call with a level method, e.g., `logging.info`.
|
||||
LevelCall(LoggingLevel),
|
||||
/// Logging call with an integer level as an argument, e.g., `logger.log(level, ...)`.
|
||||
|
|
@ -215,39 +216,41 @@ impl LoggingCallType {
|
|||
}
|
||||
}
|
||||
|
||||
/// Check logging calls for violations.
|
||||
pub(crate) fn logging_call(checker: &Checker, call: &ast::ExprCall) {
|
||||
pub(crate) fn find_logging_call(
|
||||
checker: &Checker,
|
||||
call: &ast::ExprCall,
|
||||
) -> Option<(LoggingCallType, TextRange)> {
|
||||
// Determine the call type (e.g., `info` vs. `exception`) and the range of the attribute.
|
||||
let (logging_call_type, range) = match call.func.as_ref() {
|
||||
match call.func.as_ref() {
|
||||
Expr::Attribute(ast::ExprAttribute { value: _, attr, .. }) => {
|
||||
let Some(call_type) = LoggingCallType::from_attribute(attr.as_str()) else {
|
||||
return;
|
||||
};
|
||||
let call_type = LoggingCallType::from_attribute(attr.as_str())?;
|
||||
if !logging::is_logger_candidate(
|
||||
&call.func,
|
||||
checker.semantic(),
|
||||
&checker.settings().logger_objects,
|
||||
) {
|
||||
return;
|
||||
return None;
|
||||
}
|
||||
(call_type, attr.range())
|
||||
Some((call_type, attr.range()))
|
||||
}
|
||||
Expr::Name(_) => {
|
||||
let Some(qualified_name) = checker
|
||||
let qualified_name = checker
|
||||
.semantic()
|
||||
.resolve_qualified_name(call.func.as_ref())
|
||||
else {
|
||||
return;
|
||||
};
|
||||
.resolve_qualified_name(call.func.as_ref())?;
|
||||
let ["logging", attribute] = qualified_name.segments() else {
|
||||
return;
|
||||
return None;
|
||||
};
|
||||
let Some(call_type) = LoggingCallType::from_attribute(attribute) else {
|
||||
return;
|
||||
};
|
||||
(call_type, call.func.range())
|
||||
let call_type = LoggingCallType::from_attribute(attribute)?;
|
||||
Some((call_type, call.func.range()))
|
||||
}
|
||||
_ => return,
|
||||
_ => None,
|
||||
}
|
||||
}
|
||||
|
||||
/// Check logging calls for violations.
|
||||
pub(crate) fn logging_call(checker: &Checker, call: &ast::ExprCall) {
|
||||
let Some((logging_call_type, range)) = find_logging_call(checker, call) else {
|
||||
return;
|
||||
};
|
||||
|
||||
// G001, G002, G003, G004
|
||||
|
|
|
|||
|
|
@ -112,6 +112,7 @@ mod tests {
|
|||
#[test_case(Rule::LegacyFormPytestRaises, Path::new("RUF061_warns.py"))]
|
||||
#[test_case(Rule::LegacyFormPytestRaises, Path::new("RUF061_deprecated_call.py"))]
|
||||
#[test_case(Rule::NonOctalPermissions, Path::new("RUF064.py"))]
|
||||
#[test_case(Rule::LoggingEagerConversion, Path::new("RUF065.py"))]
|
||||
#[test_case(Rule::RedirectedNOQA, Path::new("RUF101_0.py"))]
|
||||
#[test_case(Rule::RedirectedNOQA, Path::new("RUF101_1.py"))]
|
||||
#[test_case(Rule::InvalidRuleCode, Path::new("RUF102.py"))]
|
||||
|
|
|
|||
|
|
@ -0,0 +1,131 @@
|
|||
use std::str::FromStr;
|
||||
|
||||
use ruff_macros::{ViolationMetadata, derive_message_formats};
|
||||
use ruff_python_ast::{self as ast, Expr};
|
||||
use ruff_python_literal::cformat::{CFormatPart, CFormatString, CFormatType};
|
||||
use ruff_python_literal::format::FormatConversion;
|
||||
use ruff_text_size::Ranged;
|
||||
|
||||
use crate::Violation;
|
||||
use crate::checkers::ast::Checker;
|
||||
use crate::rules::flake8_logging_format::rules::{LoggingCallType, find_logging_call};
|
||||
|
||||
/// ## What it does
|
||||
/// Checks for eager string conversion of arguments to `logging` calls.
|
||||
///
|
||||
/// ## Why is this bad?
|
||||
/// Arguments to `logging` calls will be formatted as strings automatically, so it
|
||||
/// is unnecessary and less efficient to eagerly format the arguments before passing
|
||||
/// them in.
|
||||
///
|
||||
/// ## Known problems
|
||||
///
|
||||
/// This rule detects uses of the `logging` module via a heuristic.
|
||||
/// Specifically, it matches against:
|
||||
///
|
||||
/// - Uses of the `logging` module itself (e.g., `import logging; logging.info(...)`).
|
||||
/// - Uses of `flask.current_app.logger` (e.g., `from flask import current_app; current_app.logger.info(...)`).
|
||||
/// - Objects whose name starts with `log` or ends with `logger` or `logging`,
|
||||
/// when used in the same file in which they are defined (e.g., `logger = logging.getLogger(); logger.info(...)`).
|
||||
/// - Imported objects marked as loggers via the [`lint.logger-objects`] setting, which can be
|
||||
/// used to enforce these rules against shared logger objects (e.g., `from module import logger; logger.info(...)`,
|
||||
/// when [`lint.logger-objects`] is set to `["module.logger"]`).
|
||||
///
|
||||
/// ## Example
|
||||
/// ```python
|
||||
/// import logging
|
||||
///
|
||||
/// logging.basicConfig(format="%(message)s", level=logging.INFO)
|
||||
///
|
||||
/// user = "Maria"
|
||||
///
|
||||
/// logging.info("%s - Something happened", str(user))
|
||||
/// ```
|
||||
///
|
||||
/// Use instead:
|
||||
/// ```python
|
||||
/// import logging
|
||||
///
|
||||
/// logging.basicConfig(format="%(message)s", level=logging.INFO)
|
||||
///
|
||||
/// user = "Maria"
|
||||
///
|
||||
/// logging.info("%s - Something happened", user)
|
||||
/// ```
|
||||
///
|
||||
/// ## Options
|
||||
/// - `lint.logger-objects`
|
||||
///
|
||||
/// ## References
|
||||
/// - [Python documentation: `logging`](https://docs.python.org/3/library/logging.html)
|
||||
/// - [Python documentation: Optimization](https://docs.python.org/3/howto/logging.html#optimization)
|
||||
#[derive(ViolationMetadata)]
|
||||
pub(crate) struct LoggingEagerConversion {
|
||||
pub(crate) format_conversion: FormatConversion,
|
||||
}
|
||||
|
||||
impl Violation for LoggingEagerConversion {
|
||||
#[derive_message_formats]
|
||||
fn message(&self) -> String {
|
||||
let LoggingEagerConversion { format_conversion } = self;
|
||||
let (format_str, call_arg) = match format_conversion {
|
||||
FormatConversion::Str => ("%s", "str()"),
|
||||
FormatConversion::Repr => ("%r", "repr()"),
|
||||
FormatConversion::Ascii => ("%a", "ascii()"),
|
||||
FormatConversion::Bytes => ("%b", "bytes()"),
|
||||
};
|
||||
format!("Unnecessary `{call_arg}` conversion when formatting with `{format_str}`")
|
||||
}
|
||||
}
|
||||
|
||||
/// RUF065
|
||||
pub(crate) fn logging_eager_conversion(checker: &Checker, call: &ast::ExprCall) {
|
||||
let Some((logging_call_type, _range)) = find_logging_call(checker, call) else {
|
||||
return;
|
||||
};
|
||||
|
||||
let msg_pos = match logging_call_type {
|
||||
LoggingCallType::LevelCall(_) => 0,
|
||||
LoggingCallType::LogCall => 1,
|
||||
};
|
||||
|
||||
// Extract a format string from the logging statement msg argument
|
||||
let Some(Expr::StringLiteral(string_literal)) =
|
||||
call.arguments.find_argument_value("msg", msg_pos)
|
||||
else {
|
||||
return;
|
||||
};
|
||||
let Ok(format_string) = CFormatString::from_str(string_literal.value.to_str()) else {
|
||||
return;
|
||||
};
|
||||
|
||||
// Iterate over % placeholders in format string and zip with logging statement arguments
|
||||
for (spec, arg) in format_string
|
||||
.iter()
|
||||
.filter_map(|(_, part)| {
|
||||
if let CFormatPart::Spec(spec) = part {
|
||||
Some(spec)
|
||||
} else {
|
||||
None
|
||||
}
|
||||
})
|
||||
.zip(call.arguments.args.iter().skip(msg_pos + 1))
|
||||
{
|
||||
// Check if the argument is a call to eagerly format a value
|
||||
if let Expr::Call(ast::ExprCall { func, .. }) = arg {
|
||||
let CFormatType::String(format_conversion) = spec.format_type else {
|
||||
continue;
|
||||
};
|
||||
|
||||
// Check for use of %s with str() or %r with repr()
|
||||
if checker.semantic().match_builtin_expr(func.as_ref(), "str")
|
||||
&& matches!(format_conversion, FormatConversion::Str)
|
||||
|| checker.semantic().match_builtin_expr(func.as_ref(), "repr")
|
||||
&& matches!(format_conversion, FormatConversion::Repr)
|
||||
{
|
||||
checker
|
||||
.report_diagnostic(LoggingEagerConversion { format_conversion }, arg.range());
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
|
|
@ -23,6 +23,7 @@ pub(crate) use invalid_index_type::*;
|
|||
pub(crate) use invalid_pyproject_toml::*;
|
||||
pub(crate) use invalid_rule_code::*;
|
||||
pub(crate) use legacy_form_pytest_raises::*;
|
||||
pub(crate) use logging_eager_conversion::*;
|
||||
pub(crate) use map_int_version_parsing::*;
|
||||
pub(crate) use missing_fstring_syntax::*;
|
||||
pub(crate) use mutable_class_default::*;
|
||||
|
|
@ -86,6 +87,7 @@ mod invalid_index_type;
|
|||
mod invalid_pyproject_toml;
|
||||
mod invalid_rule_code;
|
||||
mod legacy_form_pytest_raises;
|
||||
mod logging_eager_conversion;
|
||||
mod map_int_version_parsing;
|
||||
mod missing_fstring_syntax;
|
||||
mod mutable_class_default;
|
||||
|
|
|
|||
|
|
@ -0,0 +1,83 @@
|
|||
---
|
||||
source: crates/ruff_linter/src/rules/ruff/mod.rs
|
||||
assertion_line: 124
|
||||
---
|
||||
RUF065 Unnecessary `str()` conversion when formatting with `%s`
|
||||
--> RUF065.py:4:26
|
||||
|
|
||||
3 | # %s + str()
|
||||
4 | logging.info("Hello %s", str("World!"))
|
||||
| ^^^^^^^^^^^^^
|
||||
5 | logging.log(logging.INFO, "Hello %s", str("World!"))
|
||||
|
|
||||
|
||||
RUF065 Unnecessary `str()` conversion when formatting with `%s`
|
||||
--> RUF065.py:5:39
|
||||
|
|
||||
3 | # %s + str()
|
||||
4 | logging.info("Hello %s", str("World!"))
|
||||
5 | logging.log(logging.INFO, "Hello %s", str("World!"))
|
||||
| ^^^^^^^^^^^^^
|
||||
6 |
|
||||
7 | # %s + repr()
|
||||
|
|
||||
|
||||
RUF065 Unnecessary `repr()` conversion when formatting with `%r`
|
||||
--> RUF065.py:16:26
|
||||
|
|
||||
15 | # %r + repr()
|
||||
16 | logging.info("Hello %r", repr("World!"))
|
||||
| ^^^^^^^^^^^^^^
|
||||
17 | logging.log(logging.INFO, "Hello %r", repr("World!"))
|
||||
|
|
||||
|
||||
RUF065 Unnecessary `repr()` conversion when formatting with `%r`
|
||||
--> RUF065.py:17:39
|
||||
|
|
||||
15 | # %r + repr()
|
||||
16 | logging.info("Hello %r", repr("World!"))
|
||||
17 | logging.log(logging.INFO, "Hello %r", repr("World!"))
|
||||
| ^^^^^^^^^^^^^^
|
||||
18 |
|
||||
19 | from logging import info, log
|
||||
|
|
||||
|
||||
RUF065 Unnecessary `str()` conversion when formatting with `%s`
|
||||
--> RUF065.py:22:18
|
||||
|
|
||||
21 | # %s + str()
|
||||
22 | info("Hello %s", str("World!"))
|
||||
| ^^^^^^^^^^^^^
|
||||
23 | log(logging.INFO, "Hello %s", str("World!"))
|
||||
|
|
||||
|
||||
RUF065 Unnecessary `str()` conversion when formatting with `%s`
|
||||
--> RUF065.py:23:31
|
||||
|
|
||||
21 | # %s + str()
|
||||
22 | info("Hello %s", str("World!"))
|
||||
23 | log(logging.INFO, "Hello %s", str("World!"))
|
||||
| ^^^^^^^^^^^^^
|
||||
24 |
|
||||
25 | # %s + repr()
|
||||
|
|
||||
|
||||
RUF065 Unnecessary `repr()` conversion when formatting with `%r`
|
||||
--> RUF065.py:34:18
|
||||
|
|
||||
33 | # %r + repr()
|
||||
34 | info("Hello %r", repr("World!"))
|
||||
| ^^^^^^^^^^^^^^
|
||||
35 | log(logging.INFO, "Hello %r", repr("World!"))
|
||||
|
|
||||
|
||||
RUF065 Unnecessary `repr()` conversion when formatting with `%r`
|
||||
--> RUF065.py:35:31
|
||||
|
|
||||
33 | # %r + repr()
|
||||
34 | info("Hello %r", repr("World!"))
|
||||
35 | log(logging.INFO, "Hello %r", repr("World!"))
|
||||
| ^^^^^^^^^^^^^^
|
||||
36 |
|
||||
37 | def str(s): return f"str = {s}"
|
||||
|
|
||||
|
|
@ -4058,6 +4058,7 @@
|
|||
"RUF061",
|
||||
"RUF063",
|
||||
"RUF064",
|
||||
"RUF065",
|
||||
"RUF1",
|
||||
"RUF10",
|
||||
"RUF100",
|
||||
|
|
|
|||
Loading…
Reference in New Issue