Don't log errors that we end up raising #22557

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

@@ -53,7 +53,7 @@ In the case of a false positive, use the disable command to remove the pylint er
 ## Rules List
 
 | Pylint checker name                                | How to fix this                                                                                                                                                      | How to disable this rule                                            | Link to python guideline                                                                                |
-| -------------------------------------------------- | -------------------------------------------------------------------------------------------------------------------------------------------------------------------- | ------------------------------------------------------------------- | ------------------------------------------------------------------------------------------------------- |
+|----------------------------------------------------|----------------------------------------------------------------------------------------------------------------------------------------------------------------------|---------------------------------------------------------------------| ------------------------------------------------------------------------------------------------------- |
 | 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)                  |
 | 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)                       |
 | 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,3 +92,4 @@ In the case of a false positive, use the disable command to remove the pylint er
 | 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)                          |
 | 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)                            |
 | no-typing-import-in-type-check                     | Do not import typing under TYPE_CHECKING.                                                                                                                            | pylint:disable=no-typing-import-in-type-check                       | No Link.                                                                                                |
+| 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.                                                                                                |

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

@@ -2708,6 +2708,68 @@ def visit_importfrom(self, node):
                     )
 
 
+class DoNotLogErrorsEndUpRaising(BaseChecker):
+
+    """Rule to check that errors that get raised aren't logged"""
+
+    name = "do-not-log-raised-errors"
+    priority = -1
+    msgs = {"C4762": (
+            "Do not log errors that get raised in an exception block.",
+            "do-not-log-raised-errors",
+            "Do not log errors at error or warning level when error is raised in an exception block",
+            ),
+            }
+
+    def visit_try(self, node):
+        """Check that raised errors aren't logged at 'error' or 'warning' levels in exception blocks.
+           Go through exception block and branches and ensure error hasn't been logged if exception is raised.
+        """
+        # Return a list of exception blocks
+        except_block = node.handlers
+        # Iterate through each exception block
+        for nod in except_block:
+            # Get the nodes in each block (e.g. nodes Expr and Raise)
+            exception_block_body = nod.body
+            self.check_for_raise(exception_block_body)
+
+    def check_for_raise(self, node):
+        """ Helper function - checks for instance of 'Raise' node
+            Also checks 'If' and nested 'If' branches
+        """
+        for i in node:
+            if isinstance(i, astroid.Raise):
+                self.check_for_logging(node)
+            # Check for any nested 'If' branches
+            if isinstance(i, astroid.If):
+                self.check_for_raise(i.body)
+                # Check any 'elif' and 'else' branches
+                elif_statements = i.orelse
+                while len(elif_statements) == 1:
+                    if isinstance(elif_statements[0], astroid.If):
+                        for x in elif_statements:
+                            self.check_for_raise(x.body)
+                            elif_statements = x.orelse
+                    else:
+                        break
+                # Check 'else' body for raise
+                self.check_for_raise(elif_statements)
+
+    def check_for_logging(self, node):
+        """ Helper function - checks 'Expr' nodes to see if logging has occurred at 'warning' or 'error'
+            levels. Called from 'check_for_raise' function
+        """
+        matches = [".warning", ".error"]
+        for j in node:
+            if isinstance(j, astroid.Expr):
+                expression = j.as_string().lower()
+                if any(x in expression for x in matches):
+                    self.add_message(
+                        msgid=f"do-not-log-raised-errors",
+                        node=j,
+                        confidence=None,
+                    )
+
 
 class NoImportTypingFromTypeCheck(BaseChecker):
 
@@ -2786,6 +2848,9 @@ def register(linter):
     # disabled by default, use pylint --enable=check-docstrings if you want to use it
     linter.register_checker(CheckDocstringParameters(linter))
 
+
+    linter.register_checker(DoNotLogErrorsEndUpRaising(linter))
+
     # Rules are disabled until false positive rate improved
     # linter.register_checker(CheckForPolicyUse(linter))
     # linter.register_checker(ClientHasApprovedMethodNamePrefix(linter))

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

@@ -4829,4 +4829,282 @@ def test_allowed_import_else(self):
             self.checker.visit_importfrom(ima)
             self.checker.visit_import(imb)
             self.checker.visit_import(imc)
-            self.checker.visit_importfrom(imd)
+            self.checker.visit_importfrom(imd)
+
+
+class TestDoNotLogErrorsEndUpRaising(pylint.testutils.CheckerTestCase):
+
+    """Test that any errors raised are not logged at 'error' or 'warning' levels in the exception block."""
+
+    CHECKER_CLASS = checker.DoNotLogErrorsEndUpRaising
+
+    def test_error_level_not_logged(self):
+        """Check that any exceptions raised aren't logged at error level in the exception block."""
+        try_node, expression_node = astroid.extract_node('''
+        try: #@
+            add = 1 + 2
+        except Exception as e:
+            logger.ERROR(str(e)) #@
+            raise
+        '''
+                                              )
+        with self.assertAddsMessages(
+            pylint.testutils.MessageTest(
+                msg_id="do-not-log-raised-errors",
+                line=5,
+                node=expression_node.parent,
+                col_offset=4,
+                end_line=5,
+                end_col_offset=24,
+            )
+        ):
+            self.checker.visit_try(try_node)
+
+    def test_warning_level_not_logged(self):
+        """Check that any exceptions raised aren't logged at warning level in the exception block."""
+        try_node, expression_node = astroid.extract_node('''
+        try: #@
+            add = 1 + 2
+        except Exception as e:
+            logger.warning(str(e)) #@
+            raise
+        '''
+                                                               )
+        with self.assertAddsMessages(
+            pylint.testutils.MessageTest(
+                msg_id="do-not-log-raised-errors",
+                line=5,
+                node=expression_node.parent,
+                col_offset=4,
+                end_line=5,
+                end_col_offset=26,
+            )
+        ):
+            self.checker.visit_try(try_node)
+
+    def test_warning_level_logging_ok_when_no_raise(self):
+        """Check that exceptions can be logged if the exception isn't raised."""
+
+        try_node = astroid.extract_node('''
+        try:
+            add = 1 + 2
+        except Exception as e:
+            logger.warning(str(e))
+        '''
+                                              )
+        with self.assertNoMessages():
+            self.checker.visit_try(try_node)
+
+    def test_unlogged_exception_block(self):
+        """Check that exceptions raised without logging are allowed."""
+
+        try_node = astroid.extract_node('''
+        try:
+            add = 1 + 2
+        except Exception as e:
+            raise
+        '''
+                                              )
+        with self.assertNoMessages():
+            self.checker.visit_try(try_node)
+
+    def test_mult_exception_blocks_separate_raise(self):
+        """Check multiple exception blocks with separate raise and logging is allowed."""
+
+        try_node = astroid.extract_node('''
+        try:
+            add = 1 + 2
+        except Exception as e:
+            raise
+        except OtherException as x:
+            logger.error(str(x))
+        '''
+                                              )
+        with self.assertNoMessages():
+            self.checker.visit_try(try_node)
+
+    def test_mult_exception_blocks_with_raise(self):
+        """Check that multiple exception blocks with raise and logging is not allowed."""
+
+        try_node, expression_node = astroid.extract_node('''
+        try: #@
+            add = 1 + 2
+        except Exception as e:
+            raise
+        except OtherException as x:
+            logger.error(str(x)) #@
+            raise
+        '''
+                                              )
+        with self.assertAddsMessages(
+                pylint.testutils.MessageTest(
+                    msg_id="do-not-log-raised-errors",
+                    line=7,
+                    node=expression_node.parent,
+                    col_offset=4,
+                    end_line=7,
+                    end_col_offset=24,
+                )
+        ):
+            self.checker.visit_try(try_node)
+
+    def test_implicit_else_exception_logged(self):
+        """Check that any exceptions raised in branches aren't logged at error level."""
+        try_node, expression_node = astroid.extract_node(
+            '''
+                try: #@
+                    add = 1 + 2
+                except Exception as e:
+                    if e.code == "Retryable":
+                        logging.warning(f"Retryable failure occurred: {e}, attempting to restart")
+                        return True
+                    elif Exception != BaseException:
+                        logging.error(f"System shutting down due to error: {e}.")
+                        return False
+                    logging.error(f"Unexpected error occurred: {e}") #@
+                    raise SystemError("Uh oh!") from e
+            ''')
+        with self.assertAddsMessages(
+                pylint.testutils.MessageTest(
+                    msg_id="do-not-log-raised-errors",
+                    line=11,
+                    node=expression_node.parent,
+                    col_offset=4,
+                    end_line=11,
+                    end_col_offset=52,
+                )
+        ):
+            self.checker.visit_try(try_node)
+
+    def test_branch_exceptions_logged(self):
+        """Check that any exceptions raised in if branches aren't logged at error level."""
+        try_node, expression_node_a, expression_node_b, expression_node_c = astroid.extract_node(
+            '''
+                try: #@
+                    add = 1 + 2
+                except Exception as e:
+                    if e.code == "Retryable":
+                        logging.warning(f"Retryable failure occurred: {e}, attempting to restart") #@
+                        raise SystemError("Uh oh!") from e
+                    elif Exception != BaseException:
+                        logging.error(f"System shutting down due to error: {e}.") #@
+                        raise SystemError("Uh oh!") from e
+                    elif e.code == "Second elif branch":
+                        logging.error(f"Second: {e}.") #@
+                        raise SystemError("Uh oh!") from e
+                    logging.error(f"Unexpected error occurred: {e}")  
+            ''')
+        with self.assertAddsMessages(
+                pylint.testutils.MessageTest(
+                    msg_id="do-not-log-raised-errors",
+                    line=6,
+                    node=expression_node_a.parent,
+                    col_offset=8,
+                    end_line=6,
+                    end_col_offset=82,
+                ),
+                pylint.testutils.MessageTest(
+                msg_id="do-not-log-raised-errors",
+                line=9,
+                node=expression_node_b.parent,
+                col_offset=8,
+                end_line=9,
+                end_col_offset=65,
+                ),
+                pylint.testutils.MessageTest(
+                msg_id="do-not-log-raised-errors",
+                line=12,
+                node=expression_node_c.parent,
+                col_offset=8,
+                end_line=12,
+                end_col_offset=38,
+                )
+        ):
+            self.checker.visit_try(try_node)
+
+    def test_explicit_else_branch_exception_logged(self):
+        """Check that any exceptions raised in else branches aren't logged at error level."""
+        try_node, expression_node = astroid.extract_node(
+            '''
+                try: #@
+                    add = 1 + 2
+                except Exception as e:
+                    if e.code == "Retryable":
+                        logging.warning(f"Retryable failure occurred: {e}, attempting to restart")
+                        return True
+                    elif Exception != BaseException:
+                        logging.error(f"System shutting down due to error: {e}.")
+                        return False
+                    else:
+                        logging.error(f"Unexpected error occurred: {e}") #@
+                        raise SystemError("Uh oh!") from e 
+
+            ''')
+        with self.assertAddsMessages(
+                pylint.testutils.MessageTest(
+                    msg_id="do-not-log-raised-errors",
+                    line=12,
+                    node=expression_node.parent,
+                    col_offset=8,
+                    end_line=12,
+                    end_col_offset=56,
+                )
+        ):
+            self.checker.visit_try(try_node)
+
+    def test_extra_nested_branches_exception_logged(self):
+        """Check that any exceptions raised in else branches aren't logged at error level."""
+        try_node, expression_node_a, expression_node_b, expression_node_c, expression_node_d = astroid.extract_node(
+            '''
+                try: #@
+                    add = 1 + 2
+                except Exception as e:
+                    if e.code == "Retryable":
+                        if e.code == "A":
+                            logging.warning(f"A: {e}") #@
+                            raise SystemError("Uh oh!") from e
+                        elif e.code == "E":
+                            logging.warning(f"E: {e}") #@
+                            raise SystemError("Uh oh!") from e
+                        else:
+                            logging.warning(f"F: {e}") #@
+                            raise SystemError("Uh oh!") from e
+                    else:
+                        logging.error(f"Unexpected error occurred: {e}") #@
+                        raise SystemError("Uh oh!") from e 
+            ''')
+        with self.assertAddsMessages(
+                pylint.testutils.MessageTest(
+                    msg_id="do-not-log-raised-errors",
+                    line=7,
+                    node=expression_node_a.parent,
+                    col_offset=12,
+                    end_line=7,
+                    end_col_offset=38,
+                ),
+                pylint.testutils.MessageTest(
+                    msg_id="do-not-log-raised-errors",
+                    line=10,
+                    node=expression_node_b.parent,
+                    col_offset=12,
+                    end_line=10,
+                    end_col_offset=38,
+                ),
+                pylint.testutils.MessageTest(
+                    msg_id="do-not-log-raised-errors",
+                    line=13,
+                    node=expression_node_c.parent,
+                    col_offset=12,
+                    end_line=13,
+                    end_col_offset=38,
+                ),
+                pylint.testutils.MessageTest(
+                    msg_id="do-not-log-raised-errors",
+                    line=16,
+                    node=expression_node_d.parent,
+                    col_offset=8,
+                    end_line=16,
+                    end_col_offset=56,
+                )
+        ):
+            self.checker.visit_try(try_node)