logging.py 16 KB

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