Skip to content

Commit

Permalink
Check for usage of exceptions in logging arguments
Browse files Browse the repository at this point in the history
  • Loading branch information
m-burst committed Aug 17, 2018
1 parent a400738 commit d9a188a
Show file tree
Hide file tree
Showing 4 changed files with 333 additions and 0 deletions.
3 changes: 3 additions & 0 deletions README.md
Expand Up @@ -50,6 +50,9 @@ In some cases you may want to log sensitive data only in debugging senarios. Th
- `G004` Logging statements should not use `f"..."` for their first argument (only in Python 3.6+)
- `G010` Logging statements should not use `warn` (use `warning` instead)
- `G100` Logging statements should not use `extra` arguments unless whitelisted
- `G200` Logging statements should not include the exception in logged string (use `exception` or `exc_info=True`)
- `G201` Logging statements should not use `error(..., exc_info=True)` (use `exception(...)` instead)
- `G202` Logging statements should not use redundant `exc_info=True` in `exception`

These violations are disabled by default. To enable them for your project, specify the code(s) in your `setup.cfg`:

Expand Down
231 changes: 231 additions & 0 deletions logging_format/tests/test_visitor.py
Expand Up @@ -22,6 +22,9 @@
FSTRING_VIOLATION,
WARN_VIOLATION,
WHITELIST_VIOLATION,
EXCEPTION_VIOLATION,
ERROR_EXC_INFO_VIOLATION,
REDUNDANT_EXC_INFO_VIOLATION,
)
from logging_format.visitor import LoggingVisitor
from logging_format.whitelist import Whitelist
Expand Down Expand Up @@ -328,3 +331,231 @@ def test_warnings():
visitor.visit(tree)

assert_that(visitor.violations, is_(empty()))


def test_exception_standard():
"""
In an except block, exceptions should be logged using .exception().
"""
tree = parse(dedent("""\
import logging
try:
pass
except Exception:
logging.exception('Something bad has happened')
"""))
visitor = LoggingVisitor()
visitor.visit(tree)

assert_that(visitor.violations, is_(empty()))


def test_exception_warning():
"""
In an except block, logging exceptions using exc_info=True is ok.
"""
tree = parse(dedent("""\
import logging
try:
pass
except Exception:
logging.warning('Something bad has happened', exc_info=True)
"""))
visitor = LoggingVisitor()
visitor.visit(tree)

assert_that(visitor.violations, is_(empty()))


def test_exception_attribute_as_main_arg():
"""
In an except block, passing an exception attribute into logging as main argument is ok.
"""
tree = parse(dedent("""\
import logging
class CustomException(Exception):
def __init__(self, custom_arg):
self.custom_arg = custom_arg
try:
pass
except CustomException as e:
logging.error(e.custom_arg)
"""))
visitor = LoggingVisitor()
visitor.visit(tree)

assert_that(visitor.violations, is_(empty()))


def test_exception_attribute_as_formatting_arg():
"""
In an except block, passing an exception attribute into logging as a formatting argument is ok.
"""
tree = parse(dedent("""\
import logging
class CustomException(Exception):
def __init__(self, custom_arg):
self.custom_arg = custom_arg
try:
pass
except CustomException as e:
logging.error('Custom exception has occurred: %s', e.custom_arg)
"""))
visitor = LoggingVisitor()
visitor.visit(tree)

assert_that(visitor.violations, is_(empty()))


def test_exception_attribute_in_extra():
"""
In an except block, passing an exception attribute into logging as a value of extra dict is ok.
"""
tree = parse(dedent("""\
import logging
class CustomException(Exception):
def __init__(self, custom_arg):
self.custom_arg = custom_arg
try:
pass
except CustomException as e:
logging.error('Custom exception has occurred: {custom_arg}', extra=dict(custom_arg=e.custom_arg))
"""))
visitor = LoggingVisitor()
visitor.visit(tree)

assert_that(visitor.violations, is_(empty()))


def test_exception_as_main_arg():
"""
In an except block, passing the exception into logging as main argument is not ok.
"""
tree = parse(dedent("""\
import logging
try:
pass
except Exception as e:
logging.exception(e)
"""))
visitor = LoggingVisitor()
visitor.visit(tree)

assert_that(visitor.violations, has_length(1))
assert_that(visitor.violations[0][1], is_(equal_to(EXCEPTION_VIOLATION)))


def test_exception_as_formatting_arg():
"""
In an except block, passing the exception into logging as a formatting argument is not ok.
"""
tree = parse(dedent("""\
import logging
try:
pass
except Exception as e:
logging.exception('Exception occurred: %s', str(e))
"""))
visitor = LoggingVisitor()
visitor.visit(tree)

assert_that(visitor.violations, has_length(1))
assert_that(visitor.violations[0][1], is_(equal_to(EXCEPTION_VIOLATION)))


def test_exception_in_extra():
"""
In an except block, passing the exception into logging as a value of extra dict is not ok.
"""
tree = parse(dedent("""\
import logging
try:
pass
except Exception as e:
logging.exception('Exception occurred: {exc}', extra=dict(exc=e))
"""))
visitor = LoggingVisitor()
visitor.visit(tree)

assert_that(visitor.violations, has_length(1))
assert_that(visitor.violations[0][1], is_(equal_to(EXCEPTION_VIOLATION)))


def test_nested_exception():
"""
In a nested except block, using the exception from an outer except block is not ok.
"""
tree = parse(dedent("""\
import logging
try:
pass
except Exception as e1:
try:
pass
except Exception as e2:
logging.exception(e1)
logging.exception(e1)
"""))
visitor = LoggingVisitor()
visitor.visit(tree)

assert_that(visitor.violations, has_length(2))
assert_that(visitor.violations[0][1], is_(equal_to(EXCEPTION_VIOLATION)))
assert_that(visitor.violations[1][1], is_(equal_to(EXCEPTION_VIOLATION)))


def test_error_exc_info():
"""
.error(..., exc_info=True) should not be used in favor of .exception(...).
"""

tree = parse(dedent("""\
import logging
logging.error('Hello World', exc_info=True)
"""))
visitor = LoggingVisitor()
visitor.visit(tree)

assert_that(visitor.violations, has_length(1))
assert_that(visitor.violations[0][1], is_(equal_to(ERROR_EXC_INFO_VIOLATION)))


def test_exception_exc_info():
"""
.exception(..., exc_info=True) is redundant.
"""

tree = parse(dedent("""\
import logging
logging.exception('Hello World', exc_info=True)
"""))
visitor = LoggingVisitor()
visitor.visit(tree)

assert_that(visitor.violations, has_length(1))
assert_that(visitor.violations[0][1], is_(equal_to(REDUNDANT_EXC_INFO_VIOLATION)))
5 changes: 5 additions & 0 deletions logging_format/violations.py
Expand Up @@ -14,3 +14,8 @@
WARN_VIOLATION = "G010 Logging statement uses 'warn' instead of 'warning'"

WHITELIST_VIOLATION = "G100 Logging statement uses non-whitelisted extra keyword argument: {}"

EXCEPTION_VIOLATION = "G200 Logging statement uses exception in arguments"

ERROR_EXC_INFO_VIOLATION = "G201 Logging: .exception(...) should be used instead of .error(..., exc_info=True)"
REDUNDANT_EXC_INFO_VIOLATION = "G202 Logging statement has redundant exc_info"

0 comments on commit d9a188a

Please sign in to comment.