_format.py 8.2 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289
  1. # -*- test-case-name: twisted.logger.test.test_format -*-
  2. # Copyright (c) Twisted Matrix Laboratories.
  3. # See LICENSE for details.
  4. """
  5. Tools for formatting logging events.
  6. """
  7. from datetime import datetime as DateTime
  8. from twisted.python.compat import unicode
  9. from twisted.python.failure import Failure
  10. from twisted.python.reflect import safe_repr
  11. from twisted.python._tzhelper import FixedOffsetTimeZone
  12. from ._flatten import flatFormat, aFormatter
  13. timeFormatRFC3339 = "%Y-%m-%dT%H:%M:%S%z"
  14. def formatEvent(event):
  15. """
  16. Formats an event as a L{unicode}, using the format in
  17. C{event["log_format"]}.
  18. This implementation should never raise an exception; if the formatting
  19. cannot be done, the returned string will describe the event generically so
  20. that a useful message is emitted regardless.
  21. @param event: A logging event.
  22. @type event: L{dict}
  23. @return: A formatted string.
  24. @rtype: L{unicode}
  25. """
  26. try:
  27. if "log_flattened" in event:
  28. return flatFormat(event)
  29. format = event.get("log_format", None)
  30. if format is None:
  31. return u""
  32. # Make sure format is unicode.
  33. if isinstance(format, bytes):
  34. # If we get bytes, assume it's UTF-8 bytes
  35. format = format.decode("utf-8")
  36. elif not isinstance(format, unicode):
  37. raise TypeError(
  38. "Log format must be unicode or bytes, not {0!r}".format(format)
  39. )
  40. return formatWithCall(format, event)
  41. except Exception as e:
  42. return formatUnformattableEvent(event, e)
  43. def formatUnformattableEvent(event, error):
  44. """
  45. Formats an event as a L{unicode} that describes the event generically and a
  46. formatting error.
  47. @param event: A logging event.
  48. @type event: L{dict}
  49. @param error: The formatting error.
  50. @type error: L{Exception}
  51. @return: A formatted string.
  52. @rtype: L{unicode}
  53. """
  54. try:
  55. return (
  56. u"Unable to format event {event!r}: {error}"
  57. .format(event=event, error=error)
  58. )
  59. except BaseException:
  60. # Yikes, something really nasty happened.
  61. #
  62. # Try to recover as much formattable data as possible; hopefully at
  63. # least the namespace is sane, which will help you find the offending
  64. # logger.
  65. failure = Failure()
  66. text = u", ".join(
  67. u" = ".join((safe_repr(key), safe_repr(value)))
  68. for key, value in event.items()
  69. )
  70. return (
  71. u"MESSAGE LOST: unformattable object logged: {error}\n"
  72. u"Recoverable data: {text}\n"
  73. u"Exception during formatting:\n{failure}"
  74. .format(error=safe_repr(error), failure=failure, text=text)
  75. )
  76. def formatTime(when, timeFormat=timeFormatRFC3339, default=u"-"):
  77. """
  78. Format a timestamp as text.
  79. Example::
  80. >>> from time import time
  81. >>> from twisted.logger import formatTime
  82. >>>
  83. >>> t = time()
  84. >>> formatTime(t)
  85. u'2013-10-22T14:19:11-0700'
  86. >>> formatTime(t, timeFormat="%Y/%W") # Year and week number
  87. u'2013/42'
  88. >>>
  89. @param when: A timestamp.
  90. @type then: L{float}
  91. @param timeFormat: A time format.
  92. @type timeFormat: L{unicode} or L{None}
  93. @param default: Text to return if C{when} or C{timeFormat} is L{None}.
  94. @type default: L{unicode}
  95. @return: A formatted time.
  96. @rtype: L{unicode}
  97. """
  98. if (timeFormat is None or when is None):
  99. return default
  100. else:
  101. tz = FixedOffsetTimeZone.fromLocalTimeStamp(when)
  102. datetime = DateTime.fromtimestamp(when, tz)
  103. return unicode(datetime.strftime(timeFormat))
  104. def formatEventAsClassicLogText(event, formatTime=formatTime):
  105. """
  106. Format an event as a line of human-readable text for, e.g. traditional log
  107. file output.
  108. The output format is C{u"{timeStamp} [{system}] {event}\\n"}, where:
  109. - C{timeStamp} is computed by calling the given C{formatTime} callable
  110. on the event's C{"log_time"} value
  111. - C{system} is the event's C{"log_system"} value, if set, otherwise,
  112. the C{"log_namespace"} and C{"log_level"}, joined by a C{u"#"}. Each
  113. defaults to C{u"-"} is not set.
  114. - C{event} is the event, as formatted by L{formatEvent}.
  115. Example::
  116. >>> from __future__ import print_function
  117. >>> from time import time
  118. >>> from twisted.logger import formatEventAsClassicLogText
  119. >>> from twisted.logger import LogLevel
  120. >>>
  121. >>> formatEventAsClassicLogText(dict()) # No format, returns None
  122. >>> formatEventAsClassicLogText(dict(log_format=u"Hello!"))
  123. u'- [-#-] Hello!\\n'
  124. >>> formatEventAsClassicLogText(dict(
  125. ... log_format=u"Hello!",
  126. ... log_time=time(),
  127. ... log_namespace="my_namespace",
  128. ... log_level=LogLevel.info,
  129. ... ))
  130. u'2013-10-22T17:30:02-0700 [my_namespace#info] Hello!\\n'
  131. >>> formatEventAsClassicLogText(dict(
  132. ... log_format=u"Hello!",
  133. ... log_time=time(),
  134. ... log_system="my_system",
  135. ... ))
  136. u'2013-11-11T17:22:06-0800 [my_system] Hello!\\n'
  137. >>>
  138. @param event: an event.
  139. @type event: L{dict}
  140. @param formatTime: A time formatter
  141. @type formatTime: L{callable} that takes an C{event} argument and returns
  142. a L{unicode}
  143. @return: A formatted event, or L{None} if no output is appropriate.
  144. @rtype: L{unicode} or L{None}
  145. """
  146. eventText = formatEvent(event)
  147. if "log_failure" in event:
  148. try:
  149. traceback = event["log_failure"].getTraceback()
  150. except:
  151. traceback = u"(UNABLE TO OBTAIN TRACEBACK FROM EVENT)\n"
  152. eventText = u"\n".join((eventText, traceback))
  153. if not eventText:
  154. return None
  155. eventText = eventText.replace(u"\n", u"\n\t")
  156. timeStamp = formatTime(event.get("log_time", None))
  157. system = event.get("log_system", None)
  158. if system is None:
  159. level = event.get("log_level", None)
  160. if level is None:
  161. levelName = u"-"
  162. else:
  163. levelName = level.name
  164. system = u"{namespace}#{level}".format(
  165. namespace=event.get("log_namespace", u"-"),
  166. level=levelName,
  167. )
  168. else:
  169. try:
  170. system = unicode(system)
  171. except Exception:
  172. system = u"UNFORMATTABLE"
  173. return u"{timeStamp} [{system}] {event}\n".format(
  174. timeStamp=timeStamp,
  175. system=system,
  176. event=eventText,
  177. )
  178. class CallMapping(object):
  179. """
  180. Read-only mapping that turns a C{()}-suffix in key names into an invocation
  181. of the key rather than a lookup of the key.
  182. Implementation support for L{formatWithCall}.
  183. """
  184. def __init__(self, submapping):
  185. """
  186. @param submapping: Another read-only mapping which will be used to look
  187. up items.
  188. """
  189. self._submapping = submapping
  190. def __getitem__(self, key):
  191. """
  192. Look up an item in the submapping for this L{CallMapping}, calling it
  193. if C{key} ends with C{"()"}.
  194. """
  195. callit = key.endswith(u"()")
  196. realKey = key[:-2] if callit else key
  197. value = self._submapping[realKey]
  198. if callit:
  199. value = value()
  200. return value
  201. def formatWithCall(formatString, mapping):
  202. """
  203. Format a string like L{unicode.format}, but:
  204. - taking only a name mapping; no positional arguments
  205. - with the additional syntax that an empty set of parentheses
  206. correspond to a formatting item that should be called, and its result
  207. C{str}'d, rather than calling C{str} on the element directly as
  208. normal.
  209. For example::
  210. >>> formatWithCall("{string}, {function()}.",
  211. ... dict(string="just a string",
  212. ... function=lambda: "a function"))
  213. 'just a string, a function.'
  214. @param formatString: A PEP-3101 format string.
  215. @type formatString: L{unicode}
  216. @param mapping: A L{dict}-like object to format.
  217. @return: The string with formatted values interpolated.
  218. @rtype: L{unicode}
  219. """
  220. return unicode(
  221. aFormatter.vformat(formatString, (), CallMapping(mapping))
  222. )