Skip to content

Commit 9a90495

Browse files
sonar-nigel[bot]Sonar Vibe BotSeppli11
authored and
sonartech
committed
SONARPY-4043 Rule S8554 Logging statements should follow Python best practices (#1085)
Co-authored-by: Sonar Vibe Bot <vibe-bot@sonarsource.com> Co-authored-by: Sebastian Zumbrunn <sebastian.zumbrunn@sonarsource.com> GitOrigin-RevId: c27ebb0da4f66b0bb54a3429d55eb262654b80a0
1 parent 8a45969 commit 9a90495

7 files changed

Lines changed: 404 additions & 0 deletions

File tree

‎python-checks/src/main/java/org/sonar/python/checks/LoggingBestPracticesCheck.java‎

Lines changed: 148 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,148 @@
1+
/*
2+
* SonarQube Python Plugin
3+
* Copyright (C) SonarSource Sàrl
4+
* mailto:info AT sonarsource DOT com
5+
*
6+
* You can redistribute and/or modify this program under the terms of
7+
* the Sonar Source-Available License Version 1, as published by SonarSource Sàrl.
8+
*
9+
* This program is distributed in the hope that it will be useful,
10+
* but WITHOUT ANY WARRANTY; without even the implied warranty of
11+
* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.
12+
* See the Sonar Source-Available License for more details.
13+
*
14+
* You should have received a copy of the Sonar Source-Available License
15+
* along with this program; if not, see https://sonarsource.com/license/ssal/
16+
*/
17+
package org.sonar.python.checks;
18+
19+
import java.util.Arrays;
20+
import java.util.HashSet;
21+
import java.util.List;
22+
import java.util.Locale;
23+
import java.util.Set;
24+
import org.sonar.check.Rule;
25+
import org.sonar.plugins.python.api.PythonSubscriptionCheck;
26+
import org.sonar.plugins.python.api.SubscriptionContext;
27+
import org.sonar.plugins.python.api.tree.BinaryExpression;
28+
import org.sonar.plugins.python.api.tree.CallExpression;
29+
import org.sonar.plugins.python.api.tree.DictionaryLiteral;
30+
import org.sonar.plugins.python.api.tree.DictionaryLiteralElement;
31+
import org.sonar.plugins.python.api.tree.Expression;
32+
import org.sonar.plugins.python.api.tree.KeyValuePair;
33+
import org.sonar.plugins.python.api.tree.RegularArgument;
34+
import org.sonar.plugins.python.api.tree.StringLiteral;
35+
import org.sonar.plugins.python.api.tree.Tree;
36+
import org.sonar.plugins.python.api.types.v2.matchers.TypeMatcher;
37+
import org.sonar.plugins.python.api.types.v2.matchers.TypeMatchers;
38+
import org.sonar.python.tree.TreeUtils;
39+
40+
@Rule(key = "S8554")
41+
public class LoggingBestPracticesCheck extends PythonSubscriptionCheck {
42+
43+
private static final TypeMatcher LOGGING_CALL_MATCHER = TypeMatchers.any(
44+
TypeMatchers.isType("logging.debug"),
45+
TypeMatchers.isType("logging.info"),
46+
TypeMatchers.isType("logging.warning"),
47+
TypeMatchers.isType("logging.warn"),
48+
TypeMatchers.isType("logging.error"),
49+
TypeMatchers.isType("logging.exception"),
50+
TypeMatchers.isType("logging.critical"),
51+
TypeMatchers.isType("logging.Logger.debug"),
52+
TypeMatchers.isType("logging.Logger.info"),
53+
TypeMatchers.isType("logging.Logger.warning"),
54+
TypeMatchers.isType("logging.Logger.warn"),
55+
TypeMatchers.isType("logging.Logger.error"),
56+
TypeMatchers.isType("logging.Logger.exception"),
57+
TypeMatchers.isType("logging.Logger.critical")
58+
);
59+
60+
private static final TypeMatcher DEPRECATED_WARN_MATCHER = TypeMatchers.any(
61+
TypeMatchers.isType("logging.warn"),
62+
TypeMatchers.isType("logging.Logger.warn")
63+
);
64+
65+
private static final TypeMatcher STR_FORMAT_MATCHER = TypeMatchers.isType("str.format");
66+
67+
private static final Set<String> LOG_RECORD_ATTRIBUTES = new HashSet<>(Arrays.asList(
68+
"name", "msg", "args", "created", "filename", "funcName", "levelname", "levelno",
69+
"lineno", "module", "msecs", "message", "pathname", "process", "processName",
70+
"relativeCreated", "thread", "threadName", "exc_info", "exc_text", "stack_info",
71+
"taskName", "asctime"
72+
));
73+
74+
private static final String EAGER_FORMAT_MESSAGE =
75+
"Pass formatting arguments to the logging call instead of pre-formatting the message string.";
76+
private static final String DEPRECATED_WARN_MESSAGE =
77+
"Use \"warning\" instead of the deprecated \"warn\" method.";
78+
private static final String EXTRA_COLLISION_MESSAGE =
79+
"Remove or rename this key; it overrides a built-in LogRecord attribute.";
80+
81+
@Override
82+
public void initialize(Context context) {
83+
context.registerSyntaxNodeConsumer(Tree.Kind.CALL_EXPR, LoggingBestPracticesCheck::checkLoggingCall);
84+
}
85+
86+
private static void checkLoggingCall(SubscriptionContext ctx) {
87+
CallExpression call = (CallExpression) ctx.syntaxNode();
88+
if (!LOGGING_CALL_MATCHER.isTrueFor(call.callee(), ctx)) {
89+
return;
90+
}
91+
92+
if (DEPRECATED_WARN_MATCHER.isTrueFor(call.callee(), ctx)) {
93+
ctx.addIssue(call.callee(), DEPRECATED_WARN_MESSAGE);
94+
}
95+
96+
List<RegularArgument> positionalArgs = call.arguments().stream()
97+
.flatMap(TreeUtils.toStreamInstanceOfMapper(RegularArgument.class))
98+
.filter(arg -> arg.keywordArgument() == null)
99+
.toList();
100+
101+
if (!positionalArgs.isEmpty()) {
102+
checkEagerFormatting(ctx, positionalArgs.get(0).expression());
103+
}
104+
105+
checkExtraAttributeCollision(ctx, call);
106+
}
107+
108+
private static void checkEagerFormatting(SubscriptionContext ctx, Expression expr) {
109+
if (expr instanceof StringLiteral literal) {
110+
boolean isFString = literal.stringElements().stream()
111+
.anyMatch(e -> e.prefix().toLowerCase(Locale.ENGLISH).contains("f") && !e.formattedExpressions().isEmpty());
112+
if (isFString) {
113+
ctx.addIssue(expr, EAGER_FORMAT_MESSAGE);
114+
}
115+
} else if (expr instanceof CallExpression innerCall && STR_FORMAT_MATCHER.isTrueFor(innerCall.callee(), ctx)) {
116+
ctx.addIssue(expr, EAGER_FORMAT_MESSAGE);
117+
} else if (expr.is(Tree.Kind.MODULO) && containsStringLiteral(((BinaryExpression) expr).leftOperand())) {
118+
ctx.addIssue(expr, EAGER_FORMAT_MESSAGE);
119+
} else if (expr.is(Tree.Kind.PLUS) && containsStringLiteral(expr)) {
120+
ctx.addIssue(expr, EAGER_FORMAT_MESSAGE);
121+
}
122+
}
123+
124+
private static boolean containsStringLiteral(Expression expr) {
125+
if (expr instanceof StringLiteral) {
126+
return true;
127+
}
128+
if (expr.is(Tree.Kind.PLUS)) {
129+
BinaryExpression plus = (BinaryExpression) expr;
130+
return containsStringLiteral(plus.leftOperand()) || containsStringLiteral(plus.rightOperand());
131+
}
132+
return false;
133+
}
134+
135+
private static void checkExtraAttributeCollision(SubscriptionContext ctx, CallExpression call) {
136+
RegularArgument extraArg = TreeUtils.argumentByKeyword("extra", call.arguments());
137+
if (extraArg == null || !(extraArg.expression() instanceof DictionaryLiteral dict)) {
138+
return;
139+
}
140+
for (DictionaryLiteralElement element : dict.elements()) {
141+
if (element instanceof KeyValuePair kvp
142+
&& kvp.key() instanceof StringLiteral key
143+
&& LOG_RECORD_ATTRIBUTES.contains(key.trimmedQuotesValue())) {
144+
ctx.addIssue(key, EXTRA_COLLISION_MESSAGE);
145+
}
146+
}
147+
}
148+
}

‎python-checks/src/main/java/org/sonar/python/checks/OpenSourceCheckList.java‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -314,6 +314,7 @@ public Stream<Class<?>> getChecks() {
314314
LocalVariableAndParameterNameConventionCheck.class,
315315
LoggersConfigurationCheck.class,
316316
LoggingExceptionCheck.class,
317+
LoggingBestPracticesCheck.class,
317318
LongIntegerWithLowercaseSuffixUsageCheck.class,
318319
LoopExecutingAtMostOnceCheck.class,
319320
LoopOverDictKeyValuesCheck.class,

‎python-checks/src/main/resources/org/sonar/l10n/py/rules/python/S8554.html‎

Lines changed: 69 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,69 @@
1+
<p>This rule raises an issue when logging statements violate established Python logging best practices, including using eager string formatting,
2+
deprecated methods, or attribute name collisions in the 'extra' parameter.</p>
3+
<h2>Why is this an issue?</h2>
4+
<p>Python’s logging module has specific patterns that ensure correctness, performance, and maintainability. Violating these patterns can lead to
5+
several problems:</p>
6+
<h2>Eager String Formatting</h2>
7+
<p>When you format strings before passing them to logging methods (using f-strings, <code>.format()</code>, <code>%</code> operator, or <code>+</code>
8+
concatenation), Python performs the string formatting operation immediately, even if the log message won’t be output due to the current log level.
9+
This wastes CPU cycles on string operations that may never be used.</p>
10+
<p>The logging module supports lazy formatting by accepting format arguments as separate parameters. The formatting only occurs when the logging
11+
framework confirms the message will actually be logged based on the configured log level.</p>
12+
<h2>Deprecated Methods</h2>
13+
<p>The <code>logging.warn()</code> and <code>logging.Logger.warn()</code> methods are deprecated. While they still function, they may be removed in
14+
future Python versions. The recommended methods are <code>logging.warning()</code> and <code>logging.Logger.warning()</code>, which are functionally
15+
equivalent.</p>
16+
<h2>Attribute Name Collisions</h2>
17+
<p>The logging module’s <code>extra</code> keyword argument allows passing additional values to be included in log records. However, if the keys in
18+
the <code>extra</code> dictionary clash with built-in <code>LogRecord</code> attributes (such as 'name', 'msg', 'args', 'created', 'filename',
19+
'funcName', 'levelname', 'levelno', 'lineno', 'module', 'msecs', 'message', 'pathname', 'process', 'processName', 'relativeCreated', 'thread',
20+
'threadName'), a <code>KeyError</code> will be raised when the <code>LogRecord</code> is constructed, causing the logging statement to fail at
21+
runtime.</p>
22+
<h3>What is the potential impact?</h3>
23+
<h2>Performance Degradation</h2>
24+
<p>Eager string formatting can significantly impact application performance, especially in code paths with frequent logging statements. When log
25+
levels are configured to filter out certain messages (e.g., DEBUG messages in production), the application still pays the cost of formatting strings
26+
that will never be logged.</p>
27+
<h2>Runtime Errors</h2>
28+
<p>Attribute name collisions in the <code>extra</code> parameter raise <code>KeyError</code> exceptions, causing logging statements to fail
29+
unexpectedly.</p>
30+
<h2>Maintenance Issues</h2>
31+
<p>Using deprecated methods creates technical debt. When these methods are eventually removed from Python, code using them will break. Additionally,
32+
mixing deprecated and non-deprecated methods across a codebase creates inconsistency and confusion.</p>
33+
<h2>Inconsistent Logging</h2>
34+
<p>Eager formatting can lead to inconsistent behavior across different log handlers. When using lazy formatting with the <code>extra</code> parameter,
35+
all handlers receive the same structured data and can format it consistently according to their configuration.</p>
36+
<h2>How to fix it</h2>
37+
<p>Use lazy formatting by passing format arguments as separate parameters to logging methods instead of formatting strings before the call. Replace
38+
f-strings, <code>.format()</code>, <code>%</code> operator, and <code>+</code> concatenation with %-style placeholders and separate arguments.</p>
39+
<h3>Code examples</h3>
40+
<h4>Noncompliant code example</h4>
41+
<pre data-diff-id="1" data-diff-type="noncompliant">
42+
import logging
43+
44+
user = "Maria"
45+
logging.info(f"{user} - Something happened") # Noncompliant: f-string formatting
46+
47+
logging.info("{} - Something happened".format(user)) # Noncompliant: .format() method
48+
49+
logging.info("%s - Something happened" % user) # Noncompliant: % operator formatting
50+
51+
logging.info(user + " - Something happened") # Noncompliant: string concatenation
52+
</pre>
53+
<h4>Compliant solution</h4>
54+
<pre data-diff-id="1" data-diff-type="compliant">
55+
import logging
56+
57+
user = "Maria"
58+
logging.info("%s - Something happened", user) # Compliant: lazy formatting with separate argument
59+
</pre>
60+
<h2>Resources</h2>
61+
<h3>Documentation</h3>
62+
<ul>
63+
<li>Python Logging Documentation - <a href="https://docs.python.org/3/library/logging.html">Official Python documentation for the logging
64+
module</a></li>
65+
<li>Python Logging HOWTO - <a href="https://docs.python.org/3/howto/logging.html">Tutorial on using Python’s logging facility</a></li>
66+
<li>LogRecord Attributes - <a href="https://docs.python.org/3/library/logging.html#logrecord-attributes">List of built-in LogRecord attributes that
67+
should not be used in the extra parameter</a></li>
68+
</ul>
69+

‎python-checks/src/main/resources/org/sonar/l10n/py/rules/python/S8554.json‎

Lines changed: 26 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,26 @@
1+
{
2+
"title": "Logging statements should follow Python best practices",
3+
"type": "CODE_SMELL",
4+
"status": "ready",
5+
"remediation": {
6+
"func": "Constant\/Issue",
7+
"constantCost": "5min"
8+
},
9+
"tags": [
10+
"convention",
11+
"performance",
12+
"pitfall"
13+
],
14+
"defaultSeverity": "Major",
15+
"ruleSpecification": "RSPEC-8554",
16+
"sqKey": "S8554",
17+
"scope": "All",
18+
"quickfix": "unknown",
19+
"code": {
20+
"impacts": {
21+
"RELIABILITY": "LOW",
22+
"MAINTAINABILITY": "HIGH"
23+
},
24+
"attribute": "CONVENTIONAL"
25+
}
26+
}

‎python-checks/src/main/resources/org/sonar/l10n/py/rules/python/Sonar_way_profile.json‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -344,6 +344,7 @@
344344
"S8519",
345345
"S8520",
346346
"S8521",
347+
"S8554",
347348
"S8572"
348349
]
349350
}

‎python-checks/src/test/java/org/sonar/python/checks/LoggingBestPracticesCheckTest.java‎

Lines changed: 28 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,28 @@
1+
/*
2+
* SonarQube Python Plugin
3+
* Copyright (C) SonarSource Sàrl
4+
* mailto:info AT sonarsource DOT com
5+
*
6+
* You can redistribute and/or modify this program under the terms of
7+
* the Sonar Source-Available License Version 1, as published by SonarSource Sàrl.
8+
*
9+
* This program is distributed in the hope that it will be useful,
10+
* but WITHOUT ANY WARRANTY; without even the implied warranty of
11+
* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.
12+
* See the Sonar Source-Available License for more details.
13+
*
14+
* You should have received a copy of the Sonar Source-Available License
15+
* along with this program; if not, see https://sonarsource.com/license/ssal/
16+
*/
17+
package org.sonar.python.checks;
18+
19+
import org.junit.jupiter.api.Test;
20+
import org.sonar.python.checks.utils.PythonCheckVerifier;
21+
22+
class LoggingBestPracticesCheckTest {
23+
24+
@Test
25+
void test() {
26+
PythonCheckVerifier.verify("src/test/resources/checks/loggingBestPractices.py", new LoggingBestPracticesCheck());
27+
}
28+
}

0 commit comments

Comments
 (0)