test_global.py 11 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358
  1. # Copyright (c) Twisted Matrix Laboratories.
  2. # See LICENSE for details.
  3. """
  4. Test cases for L{twisted.logger._global}.
  5. """
  6. from __future__ import print_function
  7. import io
  8. from twisted.trial import unittest
  9. from .._file import textFileLogObserver
  10. from .._observer import LogPublisher
  11. from .._logger import Logger
  12. from .._global import LogBeginner
  13. from .._global import MORE_THAN_ONCE_WARNING
  14. from .._levels import LogLevel
  15. from ..test.test_stdlib import nextLine
  16. def compareEvents(test, actualEvents, expectedEvents):
  17. """
  18. Compare two sequences of log events, examining only the the keys which are
  19. present in both.
  20. @param test: a test case doing the comparison
  21. @type test: L{unittest.TestCase}
  22. @param actualEvents: A list of log events that were emitted by a logger.
  23. @type actualEvents: L{list} of L{dict}
  24. @param expectedEvents: A list of log events that were expected by a test.
  25. @type expected: L{list} of L{dict}
  26. """
  27. if len(actualEvents) != len(expectedEvents):
  28. test.assertEqual(actualEvents, expectedEvents)
  29. allMergedKeys = set()
  30. for event in expectedEvents:
  31. allMergedKeys |= set(event.keys())
  32. def simplify(event):
  33. copy = event.copy()
  34. for key in event.keys():
  35. if key not in allMergedKeys:
  36. copy.pop(key)
  37. return copy
  38. simplifiedActual = [simplify(event) for event in actualEvents]
  39. test.assertEqual(simplifiedActual, expectedEvents)
  40. class LogBeginnerTests(unittest.TestCase):
  41. """
  42. Tests for L{LogBeginner}.
  43. """
  44. def setUp(self):
  45. self.publisher = LogPublisher()
  46. self.errorStream = io.StringIO()
  47. class NotSys(object):
  48. stdout = object()
  49. stderr = object()
  50. class NotWarnings(object):
  51. def __init__(self):
  52. self.warnings = []
  53. def showwarning(
  54. self, message, category, filename, lineno,
  55. file=None, line=None
  56. ):
  57. """
  58. Emulate warnings.showwarning.
  59. @param message: A warning message to emit.
  60. @type message: L{str}
  61. @param category: A warning category to associate with
  62. C{message}.
  63. @type category: L{warnings.Warning}
  64. @param filename: A file name for the source code file issuing
  65. the warning.
  66. @type warning: L{str}
  67. @param lineno: A line number in the source file where the
  68. warning was issued.
  69. @type lineno: L{int}
  70. @param file: A file to write the warning message to. If
  71. L{None}, write to L{sys.stderr}.
  72. @type file: file-like object
  73. @param line: A line of source code to include with the warning
  74. message. If L{None}, attempt to read the line from
  75. C{filename} and C{lineno}.
  76. @type line: L{str}
  77. """
  78. self.warnings.append(
  79. (message, category, filename, lineno, file, line)
  80. )
  81. self.sysModule = NotSys()
  82. self.warningsModule = NotWarnings()
  83. self.beginner = LogBeginner(
  84. self.publisher, self.errorStream, self.sysModule,
  85. self.warningsModule
  86. )
  87. def test_beginLoggingToAddObservers(self):
  88. """
  89. Test that C{beginLoggingTo()} adds observers.
  90. """
  91. event = dict(foo=1, bar=2)
  92. events1 = []
  93. events2 = []
  94. o1 = lambda e: events1.append(e)
  95. o2 = lambda e: events2.append(e)
  96. self.beginner.beginLoggingTo((o1, o2))
  97. self.publisher(event)
  98. self.assertEqual([event], events1)
  99. self.assertEqual([event], events2)
  100. def test_beginLoggingToBufferedEvents(self):
  101. """
  102. Test that events are buffered until C{beginLoggingTo()} is
  103. called.
  104. """
  105. event = dict(foo=1, bar=2)
  106. events1 = []
  107. events2 = []
  108. o1 = lambda e: events1.append(e)
  109. o2 = lambda e: events2.append(e)
  110. self.publisher(event) # Before beginLoggingTo; this is buffered
  111. self.beginner.beginLoggingTo((o1, o2))
  112. self.assertEqual([event], events1)
  113. self.assertEqual([event], events2)
  114. def _bufferLimitTest(self, limit, beginner):
  115. """
  116. Verify that when more than C{limit} events are logged to L{LogBeginner},
  117. only the last C{limit} are replayed by L{LogBeginner.beginLoggingTo}.
  118. @param limit: The maximum number of events the log beginner should
  119. buffer.
  120. @type limit: L{int}
  121. @param beginner: The L{LogBeginner} against which to verify.
  122. @type beginner: L{LogBeginner}
  123. @raise: C{self.failureException} if the wrong events are replayed by
  124. C{beginner}.
  125. @return: L{None}
  126. """
  127. for count in range(limit + 1):
  128. self.publisher(dict(count=count))
  129. events = []
  130. beginner.beginLoggingTo([events.append])
  131. self.assertEqual(
  132. list(range(1, limit + 1)),
  133. list(event["count"] for event in events),
  134. )
  135. def test_defaultBufferLimit(self):
  136. """
  137. Up to C{LogBeginner._DEFAULT_BUFFER_SIZE} log events are buffered for
  138. replay by L{LogBeginner.beginLoggingTo}.
  139. """
  140. limit = LogBeginner._DEFAULT_BUFFER_SIZE
  141. self._bufferLimitTest(limit, self.beginner)
  142. def test_overrideBufferLimit(self):
  143. """
  144. The size of the L{LogBeginner} event buffer can be overridden with the
  145. C{initialBufferSize} initilizer argument.
  146. """
  147. limit = 3
  148. beginner = LogBeginner(
  149. self.publisher, self.errorStream, self.sysModule,
  150. self.warningsModule, initialBufferSize=limit,
  151. )
  152. self._bufferLimitTest(limit, beginner)
  153. def test_beginLoggingToTwice(self):
  154. """
  155. When invoked twice, L{LogBeginner.beginLoggingTo} will emit a log
  156. message warning the user that they previously began logging, and add
  157. the new log observers.
  158. """
  159. events1 = []
  160. events2 = []
  161. fileHandle = io.StringIO()
  162. textObserver = textFileLogObserver(fileHandle)
  163. self.publisher(dict(event="prebuffer"))
  164. firstFilename, firstLine = nextLine()
  165. self.beginner.beginLoggingTo([events1.append, textObserver])
  166. self.publisher(dict(event="postbuffer"))
  167. secondFilename, secondLine = nextLine()
  168. self.beginner.beginLoggingTo([events2.append, textObserver])
  169. self.publisher(dict(event="postwarn"))
  170. warning = dict(
  171. log_format=MORE_THAN_ONCE_WARNING,
  172. log_level=LogLevel.warn,
  173. fileNow=secondFilename, lineNow=secondLine,
  174. fileThen=firstFilename, lineThen=firstLine
  175. )
  176. compareEvents(
  177. self, events1,
  178. [
  179. dict(event="prebuffer"),
  180. dict(event="postbuffer"),
  181. warning,
  182. dict(event="postwarn")
  183. ]
  184. )
  185. compareEvents(self, events2, [warning, dict(event="postwarn")])
  186. output = fileHandle.getvalue()
  187. self.assertIn('<{0}:{1}>'.format(firstFilename, firstLine),
  188. output)
  189. self.assertIn('<{0}:{1}>'.format(secondFilename, secondLine),
  190. output)
  191. def test_criticalLogging(self):
  192. """
  193. Critical messages will be written as text to the error stream.
  194. """
  195. log = Logger(observer=self.publisher)
  196. log.info("ignore this")
  197. log.critical("a critical {message}", message="message")
  198. self.assertEqual(self.errorStream.getvalue(), u"a critical message\n")
  199. def test_criticalLoggingStops(self):
  200. """
  201. Once logging has begun with C{beginLoggingTo}, critical messages are no
  202. longer written to the output stream.
  203. """
  204. log = Logger(observer=self.publisher)
  205. self.beginner.beginLoggingTo(())
  206. log.critical("another critical message")
  207. self.assertEqual(self.errorStream.getvalue(), u"")
  208. def test_beginLoggingToRedirectStandardIO(self):
  209. """
  210. L{LogBeginner.beginLoggingTo} will re-direct the standard output and
  211. error streams by setting the C{stdio} and C{stderr} attributes on its
  212. sys module object.
  213. """
  214. x = []
  215. self.beginner.beginLoggingTo([x.append])
  216. print("Hello, world.", file=self.sysModule.stdout)
  217. compareEvents(
  218. self, x, [dict(log_namespace="stdout", log_io="Hello, world.")]
  219. )
  220. del x[:]
  221. print("Error, world.", file=self.sysModule.stderr)
  222. compareEvents(
  223. self, x, [dict(log_namespace="stderr", log_io="Error, world.")]
  224. )
  225. def test_beginLoggingToDontRedirect(self):
  226. """
  227. L{LogBeginner.beginLoggingTo} will leave the existing stdout/stderr in
  228. place if it has been told not to replace them.
  229. """
  230. oldOut = self.sysModule.stdout
  231. oldErr = self.sysModule.stderr
  232. self.beginner.beginLoggingTo((), redirectStandardIO=False)
  233. self.assertIs(self.sysModule.stdout, oldOut)
  234. self.assertIs(self.sysModule.stderr, oldErr)
  235. def test_beginLoggingToPreservesEncoding(self):
  236. """
  237. When L{LogBeginner.beginLoggingTo} redirects stdout/stderr streams, the
  238. replacement streams will preserve the encoding of the replaced streams,
  239. to minimally disrupt any application relying on a specific encoding.
  240. """
  241. weird = io.TextIOWrapper(io.BytesIO(), "shift-JIS")
  242. weirderr = io.TextIOWrapper(io.BytesIO(), "big5")
  243. self.sysModule.stdout = weird
  244. self.sysModule.stderr = weirderr
  245. x = []
  246. self.beginner.beginLoggingTo([x.append])
  247. self.assertEqual(self.sysModule.stdout.encoding, "shift-JIS")
  248. self.assertEqual(self.sysModule.stderr.encoding, "big5")
  249. self.sysModule.stdout.write(b"\x97\x9B\n")
  250. self.sysModule.stderr.write(b"\xBC\xFC\n")
  251. compareEvents(
  252. self, x, [dict(log_io=u"\u674e"), dict(log_io=u"\u7469")]
  253. )
  254. def test_warningsModule(self):
  255. """
  256. L{LogBeginner.beginLoggingTo} will redirect the warnings of its
  257. warnings module into the logging system.
  258. """
  259. self.warningsModule.showwarning(
  260. "a message", DeprecationWarning, __file__, 1
  261. )
  262. x = []
  263. self.beginner.beginLoggingTo([x.append])
  264. self.warningsModule.showwarning(
  265. "another message", DeprecationWarning, __file__, 2
  266. )
  267. f = io.StringIO()
  268. self.warningsModule.showwarning(
  269. "yet another", DeprecationWarning, __file__, 3, file=f
  270. )
  271. self.assertEqual(
  272. self.warningsModule.warnings,
  273. [
  274. ("a message", DeprecationWarning, __file__, 1, None, None),
  275. ("yet another", DeprecationWarning, __file__, 3, f, None),
  276. ]
  277. )
  278. compareEvents(
  279. self, x,
  280. [dict(
  281. warning="another message",
  282. category=(
  283. DeprecationWarning.__module__ + "." +
  284. DeprecationWarning.__name__
  285. ),
  286. filename=__file__, lineno=2,
  287. )]
  288. )