_logger.py 16 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455
  1. # -*- test-case-name: twisted.logger.test.test_logger -*-
  2. # Copyright (c) Twisted Matrix Laboratories.
  3. # See LICENSE for details.
  4. """
  5. Logger class.
  6. """
  7. from __future__ import annotations
  8. from time import time
  9. from types import TracebackType
  10. from typing import Any, Callable, ContextManager, Optional, Protocol, cast
  11. from twisted.python.compat import currentframe
  12. from twisted.python.failure import Failure
  13. from ._interfaces import ILogObserver, LogTrace
  14. from ._levels import InvalidLogLevelError, LogLevel
  15. class Operation(Protocol):
  16. """
  17. An L{Operation} represents the success (or lack thereof) of code performed
  18. within the body of the L{Logger.failureHandler} context manager.
  19. """
  20. @property
  21. def succeeded(self) -> bool:
  22. """
  23. Did the operation succeed? C{True} iff the code completed without
  24. raising an exception; C{False} while the code is running and C{False}
  25. if it raises an exception.
  26. """
  27. @property
  28. def failure(self) -> Failure | None:
  29. """
  30. Did the operation raise an exception? If so, this L{Failure} is that
  31. exception.
  32. """
  33. @property
  34. def failed(self) -> bool:
  35. """
  36. Did the operation fail? C{True} iff the code raised an exception;
  37. C{False} while the code is running and C{False} if it completed without
  38. error.
  39. """
  40. class _FailCtxMgr:
  41. succeeded: bool = False
  42. failure: Failure | None = None
  43. def __init__(self, fail: Callable[[Failure], None]) -> None:
  44. self._fail = fail
  45. @property
  46. def failed(self) -> bool:
  47. return self.failure is not None
  48. def __enter__(self) -> Operation:
  49. return self
  50. def __exit__(
  51. self,
  52. exc_type: type[BaseException] | None,
  53. exc_value: BaseException | None,
  54. traceback: TracebackType | None,
  55. /,
  56. ) -> bool:
  57. if exc_type is not None:
  58. failure = Failure()
  59. self.failure = failure
  60. self._fail(failure)
  61. else:
  62. self.succeeded = True
  63. return True
  64. class _FastFailCtxMgr:
  65. def __init__(self, fail: Callable[[Failure], None]) -> None:
  66. self._fail = fail
  67. def __enter__(self) -> None:
  68. pass
  69. def __exit__(
  70. self,
  71. exc_type: type[BaseException] | None,
  72. exc_value: BaseException | None,
  73. traceback: TracebackType | None,
  74. /,
  75. ) -> bool:
  76. if exc_type is not None:
  77. failure = Failure()
  78. self.failure = failure
  79. self._fail(failure)
  80. return True
  81. class Logger:
  82. """
  83. A L{Logger} emits log messages to an observer. You should instantiate it
  84. as a class or module attribute, as documented in L{this module's
  85. documentation <twisted.logger>}.
  86. @ivar namespace: the namespace for this logger
  87. @ivar source: The object which is emitting events via this logger
  88. @ivar observer: The observer that this logger will send events to.
  89. """
  90. @staticmethod
  91. def _namespaceFromCallingContext() -> str:
  92. """
  93. Derive a namespace from the module containing the caller's caller.
  94. @return: the fully qualified python name of a module.
  95. """
  96. try:
  97. return cast(str, currentframe(2).f_globals["__name__"])
  98. except KeyError:
  99. return "<unknown>"
  100. def __init__(
  101. self,
  102. namespace: Optional[str] = None,
  103. source: Optional[object] = None,
  104. observer: Optional["ILogObserver"] = None,
  105. ) -> None:
  106. """
  107. @param namespace: The namespace for this logger. Uses a dotted
  108. notation, as used by python modules. If not L{None}, then the name
  109. of the module of the caller is used.
  110. @param source: The object which is emitting events via this
  111. logger; this is automatically set on instances of a class
  112. if this L{Logger} is an attribute of that class.
  113. @param observer: The observer that this logger will send events to.
  114. If L{None}, use the L{global log publisher <globalLogPublisher>}.
  115. """
  116. if namespace is None:
  117. namespace = self._namespaceFromCallingContext()
  118. self.namespace = namespace
  119. self.source = source
  120. if observer is None:
  121. from ._global import globalLogPublisher
  122. self.observer: ILogObserver = globalLogPublisher
  123. else:
  124. self.observer = observer
  125. def __get__(self, instance: object, owner: Optional[type] = None) -> "Logger":
  126. """
  127. When used as a descriptor, i.e.::
  128. # File: athing.py
  129. class Something:
  130. log = Logger()
  131. def hello(self):
  132. self.log.info("Hello")
  133. a L{Logger}'s namespace will be set to the name of the class it is
  134. declared on. In the above example, the namespace would be
  135. C{athing.Something}.
  136. Additionally, its source will be set to the actual object referring to
  137. the L{Logger}. In the above example, C{Something.log.source} would be
  138. C{Something}, and C{Something().log.source} would be an instance of
  139. C{Something}.
  140. """
  141. assert owner is not None
  142. if instance is None:
  143. source: Any = owner
  144. else:
  145. source = instance
  146. return self.__class__(
  147. ".".join([owner.__module__, owner.__name__]),
  148. source,
  149. observer=self.observer,
  150. )
  151. def __repr__(self) -> str:
  152. return f"<{self.__class__.__name__} {self.namespace!r}>"
  153. def emit(
  154. self, level: LogLevel, format: Optional[str] = None, **kwargs: object
  155. ) -> None:
  156. """
  157. Emit a log event to all log observers at the given level.
  158. @param level: a L{LogLevel}
  159. @param format: a message format using new-style (PEP 3101)
  160. formatting. The logging event (which is a L{dict}) is
  161. used to render this format string.
  162. @param kwargs: additional key/value pairs to include in the event.
  163. Note that values which are later mutated may result in
  164. non-deterministic behavior from observers that schedule work for
  165. later execution.
  166. """
  167. if level not in LogLevel.iterconstants():
  168. self.failure(
  169. "Got invalid log level {invalidLevel!r} in {logger}.emit().",
  170. Failure(InvalidLogLevelError(level)),
  171. invalidLevel=level,
  172. logger=self,
  173. )
  174. return
  175. event = kwargs
  176. event.update(
  177. log_logger=self,
  178. log_level=level,
  179. log_namespace=self.namespace,
  180. log_source=self.source,
  181. log_format=format,
  182. log_time=time(),
  183. )
  184. if "log_trace" in event:
  185. cast(LogTrace, event["log_trace"]).append((self, self.observer))
  186. self.observer(event)
  187. def failure(
  188. self,
  189. format: str,
  190. failure: Optional[Failure] = None,
  191. level: LogLevel = LogLevel.critical,
  192. **kwargs: object,
  193. ) -> None:
  194. """
  195. Log a failure and emit a traceback.
  196. For example::
  197. try:
  198. frob(knob)
  199. except Exception:
  200. log.failure("While frobbing {knob}", knob=knob)
  201. or::
  202. d = deferredFrob(knob)
  203. d.addErrback(lambda f: log.failure("While frobbing {knob}",
  204. f, knob=knob))
  205. This method is meant to capture unexpected exceptions in code; an
  206. exception that is caught and handled somehow should be logged, if
  207. appropriate, via L{Logger.error} instead. If some unknown exception
  208. occurs and your code doesn't know how to handle it, as in the above
  209. example, then this method provides a means to describe the failure.
  210. This is done at L{LogLevel.critical} by default, since no corrective
  211. guidance can be offered to an user/administrator, and the impact of the
  212. condition is unknown.
  213. @param format: a message format using new-style (PEP 3101) formatting.
  214. The logging event (which is a L{dict}) is used to render this
  215. format string.
  216. @param failure: a L{Failure} to log. If L{None}, a L{Failure} is
  217. created from the exception in flight.
  218. @param level: a L{LogLevel} to use.
  219. @param kwargs: additional key/value pairs to include in the event.
  220. Note that values which are later mutated may result in
  221. non-deterministic behavior from observers that schedule work for
  222. later execution.
  223. @see: L{Logger.failureHandler}
  224. @see: L{Logger.failuresHandled}
  225. """
  226. if failure is None:
  227. failure = Failure()
  228. self.emit(level, format, log_failure=failure, **kwargs)
  229. def debug(self, format: Optional[str] = None, **kwargs: object) -> None:
  230. """
  231. Emit a log event at log level L{LogLevel.debug}.
  232. @param format: a message format using new-style (PEP 3101) formatting.
  233. The logging event (which is a L{dict}) is used to render this
  234. format string.
  235. @param kwargs: additional key/value pairs to include in the event.
  236. Note that values which are later mutated may result in
  237. non-deterministic behavior from observers that schedule work for
  238. later execution.
  239. """
  240. self.emit(LogLevel.debug, format, **kwargs)
  241. def info(self, format: Optional[str] = None, **kwargs: object) -> None:
  242. """
  243. Emit a log event at log level L{LogLevel.info}.
  244. @param format: a message format using new-style (PEP 3101) formatting.
  245. The logging event (which is a L{dict}) is used to render this
  246. format string.
  247. @param kwargs: additional key/value pairs to include in the event.
  248. Note that values which are later mutated may result in
  249. non-deterministic behavior from observers that schedule work for
  250. later execution.
  251. """
  252. self.emit(LogLevel.info, format, **kwargs)
  253. def warn(self, format: Optional[str] = None, **kwargs: object) -> None:
  254. """
  255. Emit a log event at log level L{LogLevel.warn}.
  256. @param format: a message format using new-style (PEP 3101) formatting.
  257. The logging event (which is a L{dict}) is used to render this
  258. format string.
  259. @param kwargs: additional key/value pairs to include in the event.
  260. Note that values which are later mutated may result in
  261. non-deterministic behavior from observers that schedule work for
  262. later execution.
  263. """
  264. self.emit(LogLevel.warn, format, **kwargs)
  265. def error(self, format: Optional[str] = None, **kwargs: object) -> None:
  266. """
  267. Emit a log event at log level L{LogLevel.error}.
  268. @param format: a message format using new-style (PEP 3101) formatting.
  269. The logging event (which is a L{dict}) is used to render this
  270. format string.
  271. @param kwargs: additional key/value pairs to include in the event.
  272. Note that values which are later mutated may result in
  273. non-deterministic behavior from observers that schedule work for
  274. later execution.
  275. """
  276. self.emit(LogLevel.error, format, **kwargs)
  277. def critical(self, format: Optional[str] = None, **kwargs: object) -> None:
  278. """
  279. Emit a log event at log level L{LogLevel.critical}.
  280. @param format: a message format using new-style (PEP 3101) formatting.
  281. The logging event (which is a L{dict}) is used to render this
  282. format string.
  283. @param kwargs: additional key/value pairs to include in the event.
  284. Note that values which are later mutated may result in
  285. non-deterministic behavior from observers that schedule work for
  286. later execution.
  287. """
  288. self.emit(LogLevel.critical, format, **kwargs)
  289. def failuresHandled(
  290. self, format: str, level: LogLevel = LogLevel.critical, **kwargs: object
  291. ) -> ContextManager[Operation]:
  292. """
  293. Run some application code, logging a failure and emitting a traceback
  294. in the event that any of it fails, but continuing on. For example::
  295. log = Logger(...)
  296. def frameworkCode() -> None:
  297. with log.failuresHandled("While frobbing {knob}:", knob=knob) as op:
  298. frob(knob)
  299. if op.succeeded:
  300. log.info("frobbed {knob} successfully", knob=knob)
  301. This method is meant to capture unexpected exceptions from application
  302. code; an exception that is caught and handled somehow should be logged,
  303. if appropriate, via L{Logger.error} instead. If some unknown exception
  304. occurs and your code doesn't know how to handle it, as in the above
  305. example, then this method provides a means to describe the failure.
  306. This is done at L{LogLevel.critical} by default, since no corrective
  307. guidance can be offered to an user/administrator, and the impact of the
  308. condition is unknown.
  309. @param format: a message format using new-style (PEP 3101) formatting.
  310. The logging event (which is a L{dict}) is used to render this
  311. format string.
  312. @param level: a L{LogLevel} to use.
  313. @param kwargs: additional key/value pairs to include in the event, if
  314. it is emitted. Note that values which are later mutated may result
  315. in non-deterministic behavior from observers that schedule work for
  316. later execution.
  317. @see: L{Logger.failure}
  318. @see: L{Logger.failureHandler}
  319. @return: A context manager which yields an L{Operation} which will have
  320. either its C{succeeded} or C{failed} attribute set to C{True} upon
  321. completion of the code within the code within the C{with} block.
  322. """
  323. return _FailCtxMgr(lambda f: self.failure(format, f, level, **kwargs))
  324. def failureHandler(
  325. self,
  326. staticMessage: str,
  327. level: LogLevel = LogLevel.critical,
  328. ) -> ContextManager[None]:
  329. """
  330. For performance-sensitive frameworks that needs to handle potential
  331. failures from frequently-called application code, and do not need to
  332. include detailed structured information about the failure nor inspect
  333. the result of the operation, this method returns a context manager that
  334. will log exceptions and continue, that can be shared across multiple
  335. invocations. It should be instantiated at module scope to avoid
  336. additional object creations.
  337. For example::
  338. log = Logger(...)
  339. ignoringFrobErrors = log.failureHandler("while frobbing:")
  340. def hotLoop() -> None:
  341. with ignoringFrobErrors:
  342. frob()
  343. This method is meant to capture unexpected exceptions from application
  344. code; an exception that is caught and handled somehow should be logged,
  345. if appropriate, via L{Logger.error} instead. If some unknown exception
  346. occurs and your code doesn't know how to handle it, as in the above
  347. example, then this method provides a means to describe the failure in
  348. nerd-speak. This is done at L{LogLevel.critical} by default, since no
  349. corrective guidance can be offered to an user/administrator, and the
  350. impact of the condition is unknown.
  351. @param format: a message format using new-style (PEP 3101) formatting.
  352. The logging event (which is a L{dict}) is used to render this
  353. format string.
  354. @param level: a L{LogLevel} to use.
  355. @see: L{Logger.failure}
  356. @return: A context manager which does not return a value, but will
  357. always exit from exceptions.
  358. """
  359. return _FastFailCtxMgr(lambda f: self.failure(staticMessage, f, level))
  360. _log = Logger()
  361. def _loggerFor(obj: object) -> Logger:
  362. """
  363. Get a L{Logger} instance attached to the given class.
  364. """
  365. return _log.__get__(obj, obj.__class__)