logging.py 16 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428
  1. # Licensed under the GPL: https://www.gnu.org/licenses/old-licenses/gpl-2.0.html
  2. # For details: https://github.com/PyCQA/pylint/blob/main/LICENSE
  3. # Copyright (c) https://github.com/PyCQA/pylint/blob/main/CONTRIBUTORS.txt
  4. """Checker for use of Python logging."""
  5. from __future__ import annotations
  6. import string
  7. import sys
  8. from typing import TYPE_CHECKING
  9. import astroid
  10. from astroid import bases, nodes
  11. from astroid.typing import InferenceResult
  12. from pylint import checkers
  13. from pylint.checkers import utils
  14. from pylint.checkers.utils import infer_all
  15. from pylint.typing import MessageDefinitionTuple
  16. if sys.version_info >= (3, 8):
  17. from typing import Literal
  18. else:
  19. from typing_extensions import Literal
  20. if TYPE_CHECKING:
  21. from pylint.lint import PyLinter
  22. MSGS: dict[
  23. str, MessageDefinitionTuple
  24. ] = { # pylint: disable=consider-using-namedtuple-or-dataclass
  25. "W1201": (
  26. "Use %s formatting in logging functions",
  27. "logging-not-lazy",
  28. "Used when a logging statement has a call form of "
  29. '"logging.<logging method>(format_string % (format_args...))". '
  30. "Use another type of string formatting instead. "
  31. "You can use % formatting but leave interpolation to "
  32. "the logging function by passing the parameters as arguments. "
  33. "If logging-fstring-interpolation is disabled then "
  34. "you can use fstring formatting. "
  35. "If logging-format-interpolation is disabled then "
  36. "you can use str.format.",
  37. ),
  38. "W1202": (
  39. "Use %s formatting in logging functions",
  40. "logging-format-interpolation",
  41. "Used when a logging statement has a call form of "
  42. '"logging.<logging method>(format_string.format(format_args...))". '
  43. "Use another type of string formatting instead. "
  44. "You can use % formatting but leave interpolation to "
  45. "the logging function by passing the parameters as arguments. "
  46. "If logging-fstring-interpolation is disabled then "
  47. "you can use fstring formatting. "
  48. "If logging-not-lazy is disabled then "
  49. "you can use % formatting as normal.",
  50. ),
  51. "W1203": (
  52. "Use %s formatting in logging functions",
  53. "logging-fstring-interpolation",
  54. "Used when a logging statement has a call form of "
  55. '"logging.<logging method>(f"...")".'
  56. "Use another type of string formatting instead. "
  57. "You can use % formatting but leave interpolation to "
  58. "the logging function by passing the parameters as arguments. "
  59. "If logging-format-interpolation is disabled then "
  60. "you can use str.format. "
  61. "If logging-not-lazy is disabled then "
  62. "you can use % formatting as normal.",
  63. ),
  64. "E1200": (
  65. "Unsupported logging format character %r (%#02x) at index %d",
  66. "logging-unsupported-format",
  67. "Used when an unsupported format character is used in a logging "
  68. "statement format string.",
  69. ),
  70. "E1201": (
  71. "Logging format string ends in middle of conversion specifier",
  72. "logging-format-truncated",
  73. "Used when a logging statement format string terminates before "
  74. "the end of a conversion specifier.",
  75. ),
  76. "E1205": (
  77. "Too many arguments for logging format string",
  78. "logging-too-many-args",
  79. "Used when a logging format string is given too many arguments.",
  80. ),
  81. "E1206": (
  82. "Not enough arguments for logging format string",
  83. "logging-too-few-args",
  84. "Used when a logging format string is given too few arguments.",
  85. ),
  86. }
  87. CHECKED_CONVENIENCE_FUNCTIONS = {
  88. "critical",
  89. "debug",
  90. "error",
  91. "exception",
  92. "fatal",
  93. "info",
  94. "warn",
  95. "warning",
  96. }
  97. MOST_COMMON_FORMATTING = frozenset(["%s", "%d", "%f", "%r"])
  98. def is_method_call(
  99. func: bases.BoundMethod, types: tuple[str, ...] = (), methods: tuple[str, ...] = ()
  100. ) -> bool:
  101. """Determines if a BoundMethod node represents a method call.
  102. Args:
  103. func: The BoundMethod AST node to check.
  104. types: Optional sequence of caller type names to restrict check.
  105. methods: Optional sequence of method names to restrict check.
  106. Returns:
  107. true if the node represents a method call for the given type and
  108. method names, False otherwise.
  109. """
  110. return (
  111. isinstance(func, astroid.BoundMethod)
  112. and isinstance(func.bound, astroid.Instance)
  113. and (func.bound.name in types if types else True)
  114. and (func.name in methods if methods else True)
  115. )
  116. class LoggingChecker(checkers.BaseChecker):
  117. """Checks use of the logging module."""
  118. name = "logging"
  119. msgs = MSGS
  120. options = (
  121. (
  122. "logging-modules",
  123. {
  124. "default": ("logging",),
  125. "type": "csv",
  126. "metavar": "<comma separated list>",
  127. "help": "Logging modules to check that the string format "
  128. "arguments are in logging function parameter format.",
  129. },
  130. ),
  131. (
  132. "logging-format-style",
  133. {
  134. "default": "old",
  135. "type": "choice",
  136. "metavar": "<old (%) or new ({)>",
  137. "choices": ["old", "new"],
  138. "help": "The type of string formatting that logging methods do. "
  139. "`old` means using % formatting, `new` is for `{}` formatting.",
  140. },
  141. ),
  142. )
  143. def visit_module(self, _: nodes.Module) -> None:
  144. """Clears any state left in this checker from last module checked."""
  145. # The code being checked can just as easily "import logging as foo",
  146. # so it is necessary to process the imports and store in this field
  147. # what name the logging module is actually given.
  148. self._logging_names: set[str] = set()
  149. logging_mods = self.linter.config.logging_modules
  150. self._format_style = self.linter.config.logging_format_style
  151. self._logging_modules = set(logging_mods)
  152. self._from_imports = {}
  153. for logging_mod in logging_mods:
  154. parts = logging_mod.rsplit(".", 1)
  155. if len(parts) > 1:
  156. self._from_imports[parts[0]] = parts[1]
  157. def visit_importfrom(self, node: nodes.ImportFrom) -> None:
  158. """Checks to see if a module uses a non-Python logging module."""
  159. try:
  160. logging_name = self._from_imports[node.modname]
  161. for module, as_name in node.names:
  162. if module == logging_name:
  163. self._logging_names.add(as_name or module)
  164. except KeyError:
  165. pass
  166. def visit_import(self, node: nodes.Import) -> None:
  167. """Checks to see if this module uses Python's built-in logging."""
  168. for module, as_name in node.names:
  169. if module in self._logging_modules:
  170. self._logging_names.add(as_name or module)
  171. def visit_call(self, node: nodes.Call) -> None:
  172. """Checks calls to logging methods."""
  173. def is_logging_name() -> bool:
  174. return (
  175. isinstance(node.func, nodes.Attribute)
  176. and isinstance(node.func.expr, nodes.Name)
  177. and node.func.expr.name in self._logging_names
  178. )
  179. def is_logger_class() -> tuple[bool, str | None]:
  180. for inferred in infer_all(node.func):
  181. if isinstance(inferred, astroid.BoundMethod):
  182. parent = inferred._proxied.parent
  183. if isinstance(parent, nodes.ClassDef) and (
  184. parent.qname() == "logging.Logger"
  185. or any(
  186. ancestor.qname() == "logging.Logger"
  187. for ancestor in parent.ancestors()
  188. )
  189. ):
  190. return True, inferred._proxied.name
  191. return False, None
  192. if is_logging_name():
  193. name = node.func.attrname
  194. else:
  195. result, name = is_logger_class()
  196. if not result:
  197. return
  198. self._check_log_method(node, name)
  199. def _check_log_method(self, node: nodes.Call, name: str) -> None:
  200. """Checks calls to logging.log(level, format, *format_args)."""
  201. if name == "log":
  202. if node.starargs or node.kwargs or len(node.args) < 2:
  203. # Either a malformed call, star args, or double-star args. Beyond
  204. # the scope of this checker.
  205. return
  206. format_pos: Literal[0, 1] = 1
  207. elif name in CHECKED_CONVENIENCE_FUNCTIONS:
  208. if node.starargs or node.kwargs or not node.args:
  209. # Either no args, star args, or double-star args. Beyond the
  210. # scope of this checker.
  211. return
  212. format_pos = 0
  213. else:
  214. return
  215. format_arg = node.args[format_pos]
  216. if isinstance(format_arg, nodes.BinOp):
  217. binop = format_arg
  218. emit = binop.op == "%"
  219. if binop.op == "+" and not self._is_node_explicit_str_concatenation(binop):
  220. total_number_of_strings = sum(
  221. 1
  222. for operand in (binop.left, binop.right)
  223. if self._is_operand_literal_str(utils.safe_infer(operand))
  224. )
  225. emit = total_number_of_strings > 0
  226. if emit:
  227. self.add_message(
  228. "logging-not-lazy",
  229. node=node,
  230. args=(self._helper_string(node),),
  231. )
  232. elif isinstance(format_arg, nodes.Call):
  233. self._check_call_func(format_arg)
  234. elif isinstance(format_arg, nodes.Const):
  235. self._check_format_string(node, format_pos)
  236. elif isinstance(format_arg, nodes.JoinedStr):
  237. if str_formatting_in_f_string(format_arg):
  238. return
  239. self.add_message(
  240. "logging-fstring-interpolation",
  241. node=node,
  242. args=(self._helper_string(node),),
  243. )
  244. def _helper_string(self, node: nodes.Call) -> str:
  245. """Create a string that lists the valid types of formatting for this node."""
  246. valid_types = ["lazy %"]
  247. if not self.linter.is_message_enabled(
  248. "logging-fstring-formatting", node.fromlineno
  249. ):
  250. valid_types.append("fstring")
  251. if not self.linter.is_message_enabled(
  252. "logging-format-interpolation", node.fromlineno
  253. ):
  254. valid_types.append(".format()")
  255. if not self.linter.is_message_enabled("logging-not-lazy", node.fromlineno):
  256. valid_types.append("%")
  257. return " or ".join(valid_types)
  258. @staticmethod
  259. def _is_operand_literal_str(operand: InferenceResult | None) -> bool:
  260. """Return True if the operand in argument is a literal string."""
  261. return isinstance(operand, nodes.Const) and operand.name == "str"
  262. @staticmethod
  263. def _is_node_explicit_str_concatenation(node: nodes.NodeNG) -> bool:
  264. """Return True if the node represents an explicitly concatenated string."""
  265. if not isinstance(node, nodes.BinOp):
  266. return False
  267. return (
  268. LoggingChecker._is_operand_literal_str(node.left)
  269. or LoggingChecker._is_node_explicit_str_concatenation(node.left)
  270. ) and (
  271. LoggingChecker._is_operand_literal_str(node.right)
  272. or LoggingChecker._is_node_explicit_str_concatenation(node.right)
  273. )
  274. def _check_call_func(self, node: nodes.Call) -> None:
  275. """Checks that function call is not format_string.format()."""
  276. func = utils.safe_infer(node.func)
  277. types = ("str", "unicode")
  278. methods = ("format",)
  279. if (
  280. isinstance(func, astroid.BoundMethod)
  281. and is_method_call(func, types, methods)
  282. and not is_complex_format_str(func.bound)
  283. ):
  284. self.add_message(
  285. "logging-format-interpolation",
  286. node=node,
  287. args=(self._helper_string(node),),
  288. )
  289. def _check_format_string(self, node: nodes.Call, format_arg: Literal[0, 1]) -> None:
  290. """Checks that format string tokens match the supplied arguments.
  291. Args:
  292. node: AST node to be checked.
  293. format_arg: Index of the format string in the node arguments.
  294. """
  295. num_args = _count_supplied_tokens(node.args[format_arg + 1 :])
  296. if not num_args:
  297. # If no args were supplied the string is not interpolated and can contain
  298. # formatting characters - it's used verbatim. Don't check any further.
  299. return
  300. format_string = node.args[format_arg].value
  301. required_num_args = 0
  302. if isinstance(format_string, bytes):
  303. format_string = format_string.decode()
  304. if isinstance(format_string, str):
  305. try:
  306. if self._format_style == "old":
  307. keyword_args, required_num_args, _, _ = utils.parse_format_string(
  308. format_string
  309. )
  310. if keyword_args:
  311. # Keyword checking on logging strings is complicated by
  312. # special keywords - out of scope.
  313. return
  314. elif self._format_style == "new":
  315. (
  316. keyword_arguments,
  317. implicit_pos_args,
  318. explicit_pos_args,
  319. ) = utils.parse_format_method_string(format_string)
  320. keyword_args_cnt = len(
  321. {k for k, _ in keyword_arguments if not isinstance(k, int)}
  322. )
  323. required_num_args = (
  324. keyword_args_cnt + implicit_pos_args + explicit_pos_args
  325. )
  326. except utils.UnsupportedFormatCharacter as ex:
  327. char = format_string[ex.index]
  328. self.add_message(
  329. "logging-unsupported-format",
  330. node=node,
  331. args=(char, ord(char), ex.index),
  332. )
  333. return
  334. except utils.IncompleteFormatString:
  335. self.add_message("logging-format-truncated", node=node)
  336. return
  337. if num_args > required_num_args:
  338. self.add_message("logging-too-many-args", node=node)
  339. elif num_args < required_num_args:
  340. self.add_message("logging-too-few-args", node=node)
  341. def is_complex_format_str(node: nodes.NodeNG) -> bool:
  342. """Return whether the node represents a string with complex formatting specs."""
  343. inferred = utils.safe_infer(node)
  344. if inferred is None or not (
  345. isinstance(inferred, nodes.Const) and isinstance(inferred.value, str)
  346. ):
  347. return True
  348. try:
  349. parsed = list(string.Formatter().parse(inferred.value))
  350. except ValueError:
  351. # This format string is invalid
  352. return False
  353. return any(format_spec for (_, _, format_spec, _) in parsed)
  354. def _count_supplied_tokens(args: list[nodes.NodeNG]) -> int:
  355. """Counts the number of tokens in an args list.
  356. The Python log functions allow for special keyword arguments: func,
  357. exc_info and extra. To handle these cases correctly, we only count
  358. arguments that aren't keywords.
  359. Args:
  360. args: AST nodes that are arguments for a log format string.
  361. Returns:
  362. Number of AST nodes that aren't keywords.
  363. """
  364. return sum(1 for arg in args if not isinstance(arg, nodes.Keyword))
  365. def str_formatting_in_f_string(node: nodes.JoinedStr) -> bool:
  366. """Determine whether the node represents an f-string with string formatting.
  367. For example: `f'Hello %s'`
  368. """
  369. # Check "%" presence first for performance.
  370. return any(
  371. "%" in val.value and any(x in val.value for x in MOST_COMMON_FORMATTING)
  372. for val in node.values
  373. if isinstance(val, nodes.Const)
  374. )
  375. def register(linter: PyLinter) -> None:
  376. linter.register_checker(LoggingChecker(linter))