Skip to content

Commit 0faf143

Browse files
Don't log errors that we end up raising #22557 (#8819)
* don't log errors that we end up raising #22557 Added new rule for this issue to the pylint_guidelines_checker file. Added corresponding tests to the test_pylint_custom_plugins file * test_pylint_custom_plugins - added more tests Added two more tests to check for multiple exception blocks * added visit_functiondef() and visit_classdef() functions to checker class * Changed 'msg' to 'msgs' and removed un-needed functions * Made matches more specific Changed 'warning' to '.warning' etc. Help avoid any false positives e.g. 'print("error")' will now not trigger Pylint * Update README to include rule * Update checker to only include 'warning' and 'error' logging levels Also added another test to test_pylint_custom_plugins.py for 'warning' level. * Update to account for branches within exception blocks Also rename checker to "do-not-log-raised-errors" * Make logging levels case insensitive Added '.lower()' to string being parsed for logging. * Update tools/pylint-extensions/azure-pylint-guidelines-checker/pylint_guidelines_checker.py Co-authored-by: Anna Tisch <antisch@microsoft.com> * Added checking for raises in 'for' branches Also added relevant tests * Altered 'check_for_raise' helper function Refactored function and removed 'isInstance Astroid.For' and associated tests --------- Co-authored-by: Anna Tisch <antisch@microsoft.com>
1 parent f5b251e commit 0faf143

3 files changed

Lines changed: 339 additions & 2 deletions

File tree

tools/pylint-extensions/azure-pylint-guidelines-checker/README.md

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -53,7 +53,7 @@ In the case of a false positive, use the disable command to remove the pylint er
5353
## Rules List
5454

5555
| Pylint checker name | How to fix this | How to disable this rule | Link to python guideline |
56-
| -------------------------------------------------- | -------------------------------------------------------------------------------------------------------------------------------------------------------------------- | ------------------------------------------------------------------- | ------------------------------------------------------------------------------------------------------- |
56+
|----------------------------------------------------|----------------------------------------------------------------------------------------------------------------------------------------------------------------------|---------------------------------------------------------------------| ------------------------------------------------------------------------------------------------------- |
5757
| client-method-should-not-use-static-method | Use module level functions instead. | # pylint:disable=client-method-should-not-use-static-method | [link](https://azure.github.io/azure-sdk/python_implementation.html#method-signatures) |
5858
| missing-client-constructor-parameter-credential | Add a credential parameter to the client constructor. Do not use plural form "credentials". | # pylint:disable=missing-client-constructor-parameter-credential | [link](https://azure.github.io/azure-sdk/python_design.html#client-configuration) |
5959
| missing-client-constructor-parameter-kwargs | Add a \*\*kwargs parameter to the client constructor. | # pylint:disable=missing-client-constructor-parameter-kwargs | [link](https://azure.github.io/azure-sdk/python_design.html#client-configuration) |
@@ -92,4 +92,5 @@ In the case of a false positive, use the disable command to remove the pylint er
9292
| docstring-keyword-should-match-keyword-only | Docstring keyword arguments and keyword-only method arguments should match. | pylint:disable=docstring-keyword-should-match-keyword-only | [link](https://azure.github.io/azure-sdk/python_documentation.html#docstrings) |
9393
| docstring-type-do-not-use-class | Docstring type is formatted incorrectly. Do not use `:class` in docstring type. | pylint:disable=docstring-type-do-not-use-class | [link](https://sphinx-rtd-tutorial.readthedocs.io/en/latest/docstrings.html) |
9494
| no-typing-import-in-type-check | Do not import typing under TYPE_CHECKING. | pylint:disable=no-typing-import-in-type-check | No Link. |
95-
| do-not-use-legacy-typing | Do not use legacy (&lt;Python 3.8) type hinting comments | pylint:disable=do-not-use-legacy-typing | No Link.
95+
| do-not-log-raised-errors | Do not log errors at `error` or `warning` level when error is raised in an exception block. | pylint:disable=do-not-log-raised-errors | No Link. |
96+
| do-not-use-legacy-typing | Do not use legacy (&lt;Python 3.8) type hinting comments | pylint:disable=do-not-use-legacy-typing | No Link.

tools/pylint-extensions/azure-pylint-guidelines-checker/pylint_guidelines_checker.py

Lines changed: 57 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2708,6 +2708,60 @@ def visit_importfrom(self, node):
27082708
)
27092709

27102710

2711+
class DoNotLogErrorsEndUpRaising(BaseChecker):
2712+
2713+
"""Rule to check that errors that get raised aren't logged"""
2714+
2715+
name = "do-not-log-raised-errors"
2716+
priority = -1
2717+
msgs = {"C4762": (
2718+
"Do not log errors that get raised in an exception block.",
2719+
"do-not-log-raised-errors",
2720+
"Do not log errors at error or warning level when error is raised in an exception block",
2721+
),
2722+
}
2723+
2724+
def visit_try(self, node):
2725+
"""Check that raised errors aren't logged at 'error' or 'warning' levels in exception blocks.
2726+
Go through exception block and branches and ensure error hasn't been logged if exception is raised.
2727+
"""
2728+
# Return a list of exception blocks
2729+
except_block = node.handlers
2730+
# Iterate through each exception block
2731+
for nod in except_block:
2732+
# Get the nodes in each block (e.g. nodes Expr and Raise)
2733+
exception_block_body = nod.body
2734+
self.check_for_raise(exception_block_body)
2735+
2736+
def check_for_raise(self, node):
2737+
""" Helper function - checks for instance of 'Raise' node
2738+
Also checks 'If' and nested 'If' branches
2739+
"""
2740+
for i in node:
2741+
if isinstance(i, astroid.Raise):
2742+
self.check_for_logging(node)
2743+
# Check for any nested 'If' branches
2744+
if isinstance(i, astroid.If):
2745+
self.check_for_raise(i.body)
2746+
2747+
# Check any 'elif' or 'else' branches
2748+
self.check_for_raise(i.orelse)
2749+
2750+
def check_for_logging(self, node):
2751+
""" Helper function - checks 'Expr' nodes to see if logging has occurred at 'warning' or 'error'
2752+
levels. Called from 'check_for_raise' function
2753+
"""
2754+
matches = [".warning", ".error", ".exception"]
2755+
for j in node:
2756+
if isinstance(j, astroid.Expr):
2757+
expression = j.as_string().lower()
2758+
if any(x in expression for x in matches):
2759+
self.add_message(
2760+
msgid=f"do-not-log-raised-errors",
2761+
node=j,
2762+
confidence=None,
2763+
)
2764+
27112765

27122766
class NoImportTypingFromTypeCheck(BaseChecker):
27132767

@@ -2811,6 +2865,9 @@ def register(linter):
28112865
# disabled by default, use pylint --enable=check-docstrings if you want to use it
28122866
linter.register_checker(CheckDocstringParameters(linter))
28132867

2868+
2869+
linter.register_checker(DoNotLogErrorsEndUpRaising(linter))
2870+
28142871
# Rules are disabled until false positive rate improved
28152872
# linter.register_checker(CheckForPolicyUse(linter))
28162873
# linter.register_checker(ClientHasApprovedMethodNamePrefix(linter))

tools/pylint-extensions/azure-pylint-guidelines-checker/tests/test_pylint_custom_plugins.py

Lines changed: 279 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4844,6 +4844,285 @@ def test_allowed_import_else(self):
48444844
self.checker.visit_import(imc)
48454845
self.checker.visit_importfrom(imd)
48464846

4847+
4848+
class TestDoNotLogErrorsEndUpRaising(pylint.testutils.CheckerTestCase):
4849+
4850+
"""Test that any errors raised are not logged at 'error' or 'warning' levels in the exception block."""
4851+
4852+
CHECKER_CLASS = checker.DoNotLogErrorsEndUpRaising
4853+
4854+
def test_error_level_not_logged(self):
4855+
"""Check that any exceptions raised aren't logged at error level in the exception block."""
4856+
try_node, expression_node = astroid.extract_node('''
4857+
try: #@
4858+
add = 1 + 2
4859+
except Exception as e:
4860+
logger.ERROR(str(e)) #@
4861+
raise
4862+
'''
4863+
)
4864+
with self.assertAddsMessages(
4865+
pylint.testutils.MessageTest(
4866+
msg_id="do-not-log-raised-errors",
4867+
line=5,
4868+
node=expression_node.parent,
4869+
col_offset=4,
4870+
end_line=5,
4871+
end_col_offset=24,
4872+
)
4873+
):
4874+
self.checker.visit_try(try_node)
4875+
4876+
def test_warning_level_not_logged(self):
4877+
"""Check that any exceptions raised aren't logged at warning level in the exception block."""
4878+
try_node, expression_node = astroid.extract_node('''
4879+
try: #@
4880+
add = 1 + 2
4881+
except Exception as e:
4882+
logger.warning(str(e)) #@
4883+
raise
4884+
'''
4885+
)
4886+
with self.assertAddsMessages(
4887+
pylint.testutils.MessageTest(
4888+
msg_id="do-not-log-raised-errors",
4889+
line=5,
4890+
node=expression_node.parent,
4891+
col_offset=4,
4892+
end_line=5,
4893+
end_col_offset=26,
4894+
)
4895+
):
4896+
self.checker.visit_try(try_node)
4897+
4898+
def test_warning_level_logging_ok_when_no_raise(self):
4899+
"""Check that exceptions can be logged if the exception isn't raised."""
4900+
4901+
try_node = astroid.extract_node('''
4902+
try:
4903+
add = 1 + 2
4904+
except Exception as e:
4905+
logger.warning(str(e))
4906+
'''
4907+
)
4908+
with self.assertNoMessages():
4909+
self.checker.visit_try(try_node)
4910+
4911+
def test_unlogged_exception_block(self):
4912+
"""Check that exceptions raised without logging are allowed."""
4913+
4914+
try_node = astroid.extract_node('''
4915+
try:
4916+
add = 1 + 2
4917+
except Exception as e:
4918+
raise
4919+
'''
4920+
)
4921+
with self.assertNoMessages():
4922+
self.checker.visit_try(try_node)
4923+
4924+
def test_mult_exception_blocks_separate_raise(self):
4925+
"""Check multiple exception blocks with separate raise and logging is allowed."""
4926+
4927+
try_node = astroid.extract_node('''
4928+
try:
4929+
add = 1 + 2
4930+
except Exception as e:
4931+
raise
4932+
except OtherException as x:
4933+
logger.error(str(x))
4934+
'''
4935+
)
4936+
with self.assertNoMessages():
4937+
self.checker.visit_try(try_node)
4938+
4939+
def test_mult_exception_blocks_with_raise(self):
4940+
"""Check that multiple exception blocks with raise and logging is not allowed."""
4941+
4942+
try_node, expression_node = astroid.extract_node('''
4943+
try: #@
4944+
add = 1 + 2
4945+
except Exception as e:
4946+
raise
4947+
except OtherException as x:
4948+
logger.error(str(x)) #@
4949+
raise
4950+
'''
4951+
)
4952+
with self.assertAddsMessages(
4953+
pylint.testutils.MessageTest(
4954+
msg_id="do-not-log-raised-errors",
4955+
line=7,
4956+
node=expression_node.parent,
4957+
col_offset=4,
4958+
end_line=7,
4959+
end_col_offset=24,
4960+
)
4961+
):
4962+
self.checker.visit_try(try_node)
4963+
4964+
def test_implicit_else_exception_logged(self):
4965+
"""Check that any exceptions raised in branches aren't logged at error level."""
4966+
try_node, expression_node = astroid.extract_node(
4967+
'''
4968+
try: #@
4969+
add = 1 + 2
4970+
except Exception as e:
4971+
if e.code == "Retryable":
4972+
logging.warning(f"Retryable failure occurred: {e}, attempting to restart")
4973+
return True
4974+
elif Exception != BaseException:
4975+
logging.error(f"System shutting down due to error: {e}.")
4976+
return False
4977+
logging.error(f"Unexpected error occurred: {e}") #@
4978+
raise SystemError("Uh oh!") from e
4979+
''')
4980+
with self.assertAddsMessages(
4981+
pylint.testutils.MessageTest(
4982+
msg_id="do-not-log-raised-errors",
4983+
line=11,
4984+
node=expression_node.parent,
4985+
col_offset=4,
4986+
end_line=11,
4987+
end_col_offset=52,
4988+
)
4989+
):
4990+
self.checker.visit_try(try_node)
4991+
4992+
def test_branch_exceptions_logged(self):
4993+
"""Check that any exceptions raised in if branches aren't logged at error level."""
4994+
try_node, expression_node_a, expression_node_b, expression_node_c = astroid.extract_node(
4995+
'''
4996+
try: #@
4997+
add = 1 + 2
4998+
except Exception as e:
4999+
if e.code == "Retryable":
5000+
logging.warning(f"Retryable failure occurred: {e}, attempting to restart") #@
5001+
raise SystemError("Uh oh!") from e
5002+
elif Exception != BaseException:
5003+
logging.error(f"System shutting down due to error: {e}.") #@
5004+
raise SystemError("Uh oh!") from e
5005+
elif e.code == "Second elif branch":
5006+
logging.error(f"Second: {e}.") #@
5007+
raise SystemError("Uh oh!") from e
5008+
logging.error(f"Unexpected error occurred: {e}")
5009+
''')
5010+
with self.assertAddsMessages(
5011+
pylint.testutils.MessageTest(
5012+
msg_id="do-not-log-raised-errors",
5013+
line=6,
5014+
node=expression_node_a.parent,
5015+
col_offset=8,
5016+
end_line=6,
5017+
end_col_offset=82,
5018+
),
5019+
pylint.testutils.MessageTest(
5020+
msg_id="do-not-log-raised-errors",
5021+
line=9,
5022+
node=expression_node_b.parent,
5023+
col_offset=8,
5024+
end_line=9,
5025+
end_col_offset=65,
5026+
),
5027+
pylint.testutils.MessageTest(
5028+
msg_id="do-not-log-raised-errors",
5029+
line=12,
5030+
node=expression_node_c.parent,
5031+
col_offset=8,
5032+
end_line=12,
5033+
end_col_offset=38,
5034+
)
5035+
):
5036+
self.checker.visit_try(try_node)
5037+
5038+
def test_explicit_else_branch_exception_logged(self):
5039+
"""Check that any exceptions raised in else branches aren't logged at error level."""
5040+
try_node, expression_node = astroid.extract_node(
5041+
'''
5042+
try: #@
5043+
add = 1 + 2
5044+
except Exception as e:
5045+
if e.code == "Retryable":
5046+
logging.warning(f"Retryable failure occurred: {e}, attempting to restart")
5047+
return True
5048+
elif Exception != BaseException:
5049+
logging.error(f"System shutting down due to error: {e}.")
5050+
return False
5051+
else:
5052+
logging.error(f"Unexpected error occurred: {e}") #@
5053+
raise SystemError("Uh oh!") from e
5054+
5055+
''')
5056+
with self.assertAddsMessages(
5057+
pylint.testutils.MessageTest(
5058+
msg_id="do-not-log-raised-errors",
5059+
line=12,
5060+
node=expression_node.parent,
5061+
col_offset=8,
5062+
end_line=12,
5063+
end_col_offset=56,
5064+
)
5065+
):
5066+
self.checker.visit_try(try_node)
5067+
5068+
def test_extra_nested_branches_exception_logged(self):
5069+
"""Check that any exceptions raised in else branches aren't logged at error level."""
5070+
try_node, expression_node_a, expression_node_b, expression_node_c, expression_node_d = astroid.extract_node(
5071+
'''
5072+
try: #@
5073+
add = 1 + 2
5074+
except Exception as e:
5075+
if e.code == "Retryable":
5076+
if e.code == "A":
5077+
logging.warning(f"A: {e}") #@
5078+
raise SystemError("Uh oh!") from e
5079+
elif e.code == "E":
5080+
logging.warning(f"E: {e}") #@
5081+
raise SystemError("Uh oh!") from e
5082+
else:
5083+
logging.warning(f"F: {e}") #@
5084+
raise SystemError("Uh oh!") from e
5085+
else:
5086+
logging.error(f"Unexpected error occurred: {e}") #@
5087+
raise SystemError("Uh oh!") from e
5088+
''')
5089+
with self.assertAddsMessages(
5090+
pylint.testutils.MessageTest(
5091+
msg_id="do-not-log-raised-errors",
5092+
line=7,
5093+
node=expression_node_a.parent,
5094+
col_offset=12,
5095+
end_line=7,
5096+
end_col_offset=38,
5097+
),
5098+
pylint.testutils.MessageTest(
5099+
msg_id="do-not-log-raised-errors",
5100+
line=10,
5101+
node=expression_node_b.parent,
5102+
col_offset=12,
5103+
end_line=10,
5104+
end_col_offset=38,
5105+
),
5106+
pylint.testutils.MessageTest(
5107+
msg_id="do-not-log-raised-errors",
5108+
line=13,
5109+
node=expression_node_c.parent,
5110+
col_offset=12,
5111+
end_line=13,
5112+
end_col_offset=38,
5113+
),
5114+
pylint.testutils.MessageTest(
5115+
msg_id="do-not-log-raised-errors",
5116+
line=16,
5117+
node=expression_node_d.parent,
5118+
col_offset=8,
5119+
end_line=16,
5120+
end_col_offset=56,
5121+
)
5122+
):
5123+
self.checker.visit_try(try_node)
5124+
5125+
48475126
class TestCheckDoNotUseLegacyTyping(pylint.testutils.CheckerTestCase):
48485127
"""Test that we are blocking disallowed legacy typing practices"""
48495128

0 commit comments

Comments
 (0)