This commit is contained in:
Mai Gillmann
2019-12-17 14:09:10 +01:00
parent 66e908fc8a
commit 4791d00a43
2122 changed files with 423791 additions and 0 deletions
@@ -0,0 +1,59 @@
# -*- test-case-name: twisted.logger.test.test_buffer -*-
# Copyright (c) Twisted Matrix Laboratories.
# See LICENSE for details.
"""
Log observer that maintains a buffer.
"""
from collections import deque
from zope.interface import implementer
from ._observer import ILogObserver
_DEFAULT_BUFFER_MAXIMUM = 64 * 1024
@implementer(ILogObserver)
class LimitedHistoryLogObserver(object):
"""
L{ILogObserver} that stores events in a buffer of a fixed size::
>>> from twisted.logger import LimitedHistoryLogObserver
>>> history = LimitedHistoryLogObserver(5)
>>> for n in range(10): history({'n': n})
...
>>> repeats = []
>>> history.replayTo(repeats.append)
>>> len(repeats)
5
>>> repeats
[{'n': 5}, {'n': 6}, {'n': 7}, {'n': 8}, {'n': 9}]
>>>
"""
def __init__(self, size=_DEFAULT_BUFFER_MAXIMUM):
"""
@param size: The maximum number of events to buffer. If L{None}, the
buffer is unbounded.
@type size: L{int}
"""
self._buffer = deque(maxlen=size)
def __call__(self, event):
self._buffer.append(event)
def replayTo(self, otherObserver):
"""
Re-play the buffered events to another log observer.
@param otherObserver: An observer to replay events to.
@type otherObserver: L{ILogObserver}
"""
for event in self._buffer:
otherObserver(event)
@@ -0,0 +1,86 @@
# -*- test-case-name: twisted.logger.test.test_file -*-
# Copyright (c) Twisted Matrix Laboratories.
# See LICENSE for details.
"""
File log observer.
"""
from zope.interface import implementer
from twisted.python.compat import ioType, unicode
from ._observer import ILogObserver
from ._format import formatTime
from ._format import timeFormatRFC3339
from ._format import formatEventAsClassicLogText
@implementer(ILogObserver)
class FileLogObserver(object):
"""
Log observer that writes to a file-like object.
"""
def __init__(self, outFile, formatEvent):
"""
@param outFile: A file-like object. Ideally one should be passed which
accepts L{unicode} data. Otherwise, UTF-8 L{bytes} will be used.
@type outFile: L{io.IOBase}
@param formatEvent: A callable that formats an event.
@type formatEvent: L{callable} that takes an C{event} argument and
returns a formatted event as L{unicode}.
"""
if ioType(outFile) is not unicode:
self._encoding = "utf-8"
else:
self._encoding = None
self._outFile = outFile
self.formatEvent = formatEvent
def __call__(self, event):
"""
Write event to file.
@param event: An event.
@type event: L{dict}
"""
text = self.formatEvent(event)
if text is None:
text = u""
if self._encoding is not None:
text = text.encode(self._encoding)
if text:
self._outFile.write(text)
self._outFile.flush()
def textFileLogObserver(outFile, timeFormat=timeFormatRFC3339):
"""
Create a L{FileLogObserver} that emits text to a specified (writable)
file-like object.
@param outFile: A file-like object. Ideally one should be passed which
accepts L{unicode} data. Otherwise, UTF-8 L{bytes} will be used.
@type outFile: L{io.IOBase}
@param timeFormat: The format to use when adding timestamp prefixes to
logged events. If L{None}, or for events with no C{"log_timestamp"}
key, the default timestamp prefix of C{u"-"} is used.
@type timeFormat: L{unicode} or L{None}
@return: A file log observer.
@rtype: L{FileLogObserver}
"""
def formatEvent(event):
return formatEventAsClassicLogText(
event, formatTime=lambda e: formatTime(e, timeFormat)
)
return FileLogObserver(outFile, formatEvent)
@@ -0,0 +1,110 @@
# -*- test-case-name: twisted.logger.test.test_levels -*-
# Copyright (c) Twisted Matrix Laboratories.
# See LICENSE for details.
"""
Log levels.
"""
from constantly import NamedConstant, Names
class InvalidLogLevelError(Exception):
"""
Someone tried to use a L{LogLevel} that is unknown to the logging system.
"""
def __init__(self, level):
"""
@param level: A log level.
@type level: L{LogLevel}
"""
super(InvalidLogLevelError, self).__init__(str(level))
self.level = level
class LogLevel(Names):
"""
Constants describing log levels.
@cvar debug: Debugging events: Information of use to a developer of the
software, not generally of interest to someone running the software
unless they are attempting to diagnose a software issue.
@cvar info: Informational events: Routine information about the status of
an application, such as incoming connections, startup of a subsystem,
etc.
@cvar warn: Warning events: Events that may require greater attention than
informational events but are not a systemic failure condition, such as
authorization failures, bad data from a network client, etc. Such
events are of potential interest to system administrators, and should
ideally be phrased in such a way, or documented, so as to indicate an
action that an administrator might take to mitigate the warning.
@cvar error: Error conditions: Events indicating a systemic failure, such
as programming errors in the form of unhandled exceptions, loss of
connectivity to an external system without which no useful work can
proceed, such as a database or API endpoint, or resource exhaustion.
Similarly to warnings, errors that are related to operational
parameters may be actionable to system administrators and should
provide references to resources which an administrator might use to
resolve them.
@cvar critical: Critical failures: Errors indicating systemic failure (ie.
service outage), data corruption, imminent data loss, etc. which must
be handled immediately. This includes errors unanticipated by the
software, such as unhandled exceptions, wherein the cause and
consequences are unknown.
"""
debug = NamedConstant()
info = NamedConstant()
warn = NamedConstant()
error = NamedConstant()
critical = NamedConstant()
@classmethod
def levelWithName(cls, name):
"""
Get the log level with the given name.
@param name: The name of a log level.
@type name: L{str} (native string)
@return: The L{LogLevel} with the specified C{name}.
@rtype: L{LogLevel}
@raise InvalidLogLevelError: if the C{name} does not name a valid log
level.
"""
try:
return cls.lookupByName(name)
except ValueError:
raise InvalidLogLevelError(name)
@classmethod
def _priorityForLevel(cls, level):
"""
We want log levels to have defined ordering - the order of definition -
but they aren't value constants (the only value is the name). This is
arguably a bug in Twisted, so this is just a workaround for U{until
this is fixed in some way
<https://twistedmatrix.com/trac/ticket/6523>}.
@param level: A log level.
@type level: L{LogLevel}
@return: A numeric index indicating priority (lower is higher level).
@rtype: L{int}
"""
return cls._levelPriorities[level]
LogLevel._levelPriorities = dict(
(level, index) for (index, level) in
(enumerate(LogLevel.iterconstants()))
)
@@ -0,0 +1,275 @@
# -*- test-case-name: twisted.logger.test.test_logger -*-
# Copyright (c) Twisted Matrix Laboratories.
# See LICENSE for details.
"""
Logger class.
"""
from time import time
from twisted.python.compat import currentframe
from twisted.python.failure import Failure
from ._levels import InvalidLogLevelError, LogLevel
class Logger(object):
"""
A L{Logger} emits log messages to an observer. You should instantiate it
as a class or module attribute, as documented in L{this module's
documentation <twisted.logger>}.
@type namespace: L{str}
@ivar namespace: the namespace for this logger
@type source: L{object}
@ivar source: The object which is emitting events via this logger
@type: L{ILogObserver}
@ivar observer: The observer that this logger will send events to.
"""
@staticmethod
def _namespaceFromCallingContext():
"""
Derive a namespace from the module containing the caller's caller.
@return: the fully qualified python name of a module.
@rtype: L{str} (native string)
"""
try:
return currentframe(2).f_globals["__name__"]
except KeyError:
return "<unknown>"
def __init__(self, namespace=None, source=None, observer=None):
"""
@param namespace: The namespace for this logger. Uses a dotted
notation, as used by python modules. If not L{None}, then the name
of the module of the caller is used.
@type namespace: L{str} (native string)
@param source: The object which is emitting events via this
logger; this is automatically set on instances of a class
if this L{Logger} is an attribute of that class.
@type source: L{object}
@param observer: The observer that this logger will send events to.
If L{None}, use the L{global log publisher <globalLogPublisher>}.
@type observer: L{ILogObserver}
"""
if namespace is None:
namespace = self._namespaceFromCallingContext()
self.namespace = namespace
self.source = source
if observer is None:
from ._global import globalLogPublisher
self.observer = globalLogPublisher
else:
self.observer = observer
def __get__(self, oself, type=None):
"""
When used as a descriptor, i.e.::
# File: athing.py
class Something(object):
log = Logger()
def hello(self):
self.log.info("Hello")
a L{Logger}'s namespace will be set to the name of the class it is
declared on. In the above example, the namespace would be
C{athing.Something}.
Additionally, its source will be set to the actual object referring to
the L{Logger}. In the above example, C{Something.log.source} would be
C{Something}, and C{Something().log.source} would be an instance of
C{Something}.
"""
if oself is None:
source = type
else:
source = oself
return self.__class__(
".".join([type.__module__, type.__name__]),
source,
observer=self.observer,
)
def __repr__(self):
return "<%s %r>" % (self.__class__.__name__, self.namespace)
def emit(self, level, format=None, **kwargs):
"""
Emit a log event to all log observers at the given level.
@param level: a L{LogLevel}
@param format: a message format using new-style (PEP 3101)
formatting. The logging event (which is a L{dict}) is
used to render this format string.
@param kwargs: additional key/value pairs to include in the event.
Note that values which are later mutated may result in
non-deterministic behavior from observers that schedule work for
later execution.
"""
if level not in LogLevel.iterconstants():
self.failure(
"Got invalid log level {invalidLevel!r} in {logger}.emit().",
Failure(InvalidLogLevelError(level)),
invalidLevel=level,
logger=self,
)
return
event = kwargs
event.update(
log_logger=self, log_level=level, log_namespace=self.namespace,
log_source=self.source, log_format=format, log_time=time(),
)
if "log_trace" in event:
event["log_trace"].append((self, self.observer))
self.observer(event)
def failure(self, format, failure=None, level=LogLevel.critical, **kwargs):
"""
Log a failure and emit a traceback.
For example::
try:
frob(knob)
except Exception:
log.failure("While frobbing {knob}", knob=knob)
or::
d = deferredFrob(knob)
d.addErrback(lambda f: log.failure("While frobbing {knob}",
f, knob=knob))
This method is generally meant to capture unexpected exceptions in
code; an exception that is caught and handled somehow should be logged,
if appropriate, via L{Logger.error} instead. If some unknown exception
occurs and your code doesn't know how to handle it, as in the above
example, then this method provides a means to describe the failure in
nerd-speak. This is done at L{LogLevel.critical} by default, since no
corrective guidance can be offered to an user/administrator, and the
impact of the condition is unknown.
@param format: a message format using new-style (PEP 3101) formatting.
The logging event (which is a L{dict}) is used to render this
format string.
@param failure: a L{Failure} to log. If L{None}, a L{Failure} is
created from the exception in flight.
@param level: a L{LogLevel} to use.
@param kwargs: additional key/value pairs to include in the event.
Note that values which are later mutated may result in
non-deterministic behavior from observers that schedule work for
later execution.
"""
if failure is None:
failure = Failure()
self.emit(level, format, log_failure=failure, **kwargs)
def debug(self, format=None, **kwargs):
"""
Emit a log event at log level L{LogLevel.debug}.
@param format: a message format using new-style (PEP 3101) formatting.
The logging event (which is a L{dict}) is used to render this
format string.
@param kwargs: additional key/value pairs to include in the event.
Note that values which are later mutated may result in
non-deterministic behavior from observers that schedule work for
later execution.
"""
self.emit(LogLevel.debug, format, **kwargs)
def info(self, format=None, **kwargs):
"""
Emit a log event at log level L{LogLevel.info}.
@param format: a message format using new-style (PEP 3101) formatting.
The logging event (which is a L{dict}) is used to render this
format string.
@param kwargs: additional key/value pairs to include in the event.
Note that values which are later mutated may result in
non-deterministic behavior from observers that schedule work for
later execution.
"""
self.emit(LogLevel.info, format, **kwargs)
def warn(self, format=None, **kwargs):
"""
Emit a log event at log level L{LogLevel.warn}.
@param format: a message format using new-style (PEP 3101) formatting.
The logging event (which is a L{dict}) is used to render this
format string.
@param kwargs: additional key/value pairs to include in the event.
Note that values which are later mutated may result in
non-deterministic behavior from observers that schedule work for
later execution.
"""
self.emit(LogLevel.warn, format, **kwargs)
def error(self, format=None, **kwargs):
"""
Emit a log event at log level L{LogLevel.error}.
@param format: a message format using new-style (PEP 3101) formatting.
The logging event (which is a L{dict}) is used to render this
format string.
@param kwargs: additional key/value pairs to include in the event.
Note that values which are later mutated may result in
non-deterministic behavior from observers that schedule work for
later execution.
"""
self.emit(LogLevel.error, format, **kwargs)
def critical(self, format=None, **kwargs):
"""
Emit a log event at log level L{LogLevel.critical}.
@param format: a message format using new-style (PEP 3101) formatting.
The logging event (which is a L{dict}) is used to render this
format string.
@param kwargs: additional key/value pairs to include in the event.
Note that values which are later mutated may result in
non-deterministic behavior from observers that schedule work for
later execution.
"""
self.emit(LogLevel.critical, format, **kwargs)
_log = Logger()
_loggerFor = lambda obj:_log.__get__(obj, obj.__class__)
@@ -0,0 +1,62 @@
# Copyright (c) Twisted Matrix Laboratories.
# See LICENSE for details.
"""
Test cases for L{twisted.logger._buffer}.
"""
from zope.interface.verify import verifyObject, BrokenMethodImplementation
from twisted.trial import unittest
from .._observer import ILogObserver
from .._buffer import LimitedHistoryLogObserver
class LimitedHistoryLogObserverTests(unittest.TestCase):
"""
Tests for L{LimitedHistoryLogObserver}.
"""
def test_interface(self):
"""
L{LimitedHistoryLogObserver} provides L{ILogObserver}.
"""
observer = LimitedHistoryLogObserver(0)
try:
verifyObject(ILogObserver, observer)
except BrokenMethodImplementation as e:
self.fail(e)
def test_order(self):
"""
L{LimitedHistoryLogObserver} saves history in the order it is received.
"""
size = 4
events = [dict(n=n) for n in range(size//2)]
observer = LimitedHistoryLogObserver(size)
for event in events:
observer(event)
outEvents = []
observer.replayTo(outEvents.append)
self.assertEqual(events, outEvents)
def test_limit(self):
"""
When more events than a L{LimitedHistoryLogObserver}'s maximum size are
buffered, older events will be dropped.
"""
size = 4
events = [dict(n=n) for n in range(size*2)]
observer = LimitedHistoryLogObserver(size)
for event in events:
observer(event)
outEvents = []
observer.replayTo(outEvents.append)
self.assertEqual(events[-size:], outEvents)
@@ -0,0 +1,39 @@
# Copyright (c) Twisted Matrix Laboratories.
# See LICENSE for details.
"""
Test cases for L{twisted.logger._capture}.
"""
from twisted.logger import Logger, LogLevel
from twisted.trial.unittest import TestCase
from .._capture import capturedLogs
class LogCaptureTests(TestCase):
"""
Tests for L{LogCaptureTests}.
"""
log = Logger()
def test_capture(self):
"""
Events logged within context are captured.
"""
foo = object()
with capturedLogs() as captured:
self.log.debug("Capture this, please", foo=foo)
self.log.info("Capture this too, please", foo=foo)
self.assertTrue(len(captured) == 2)
self.assertEqual(captured[0]["log_format"], "Capture this, please")
self.assertEqual(captured[0]["log_level"], LogLevel.debug)
self.assertEqual(captured[0]["foo"], foo)
self.assertEqual(captured[1]["log_format"], "Capture this too, please")
self.assertEqual(captured[1]["log_level"], LogLevel.info)
self.assertEqual(captured[1]["foo"], foo)
@@ -0,0 +1,199 @@
# Copyright (c) Twisted Matrix Laboratories.
# See LICENSE for details.
"""
Test cases for L{twisted.logger._file}.
"""
from io import StringIO
from zope.interface.verify import verifyObject, BrokenMethodImplementation
from twisted.trial.unittest import TestCase
from twisted.python.failure import Failure
from twisted.python.compat import unicode
from .._observer import ILogObserver
from .._file import FileLogObserver
from .._file import textFileLogObserver
class FileLogObserverTests(TestCase):
"""
Tests for L{FileLogObserver}.
"""
def test_interface(self):
"""
L{FileLogObserver} is an L{ILogObserver}.
"""
with StringIO() as fileHandle:
observer = FileLogObserver(fileHandle, lambda e: unicode(e))
try:
verifyObject(ILogObserver, observer)
except BrokenMethodImplementation as e:
self.fail(e)
def test_observeWrites(self):
"""
L{FileLogObserver} writes to the given file when it observes events.
"""
with StringIO() as fileHandle:
observer = FileLogObserver(fileHandle, lambda e: unicode(e))
event = dict(x=1)
observer(event)
self.assertEqual(fileHandle.getvalue(), unicode(event))
def _test_observeWrites(self, what, count):
"""
Verify that observer performs an expected number of writes when the
formatter returns a given value.
@param what: the value for the formatter to return.
@type what: L{unicode}
@param count: the expected number of writes.
@type count: L{int}
"""
with DummyFile() as fileHandle:
observer = FileLogObserver(fileHandle, lambda e: what)
event = dict(x=1)
observer(event)
self.assertEqual(fileHandle.writes, count)
def test_observeWritesNone(self):
"""
L{FileLogObserver} does not write to the given file when it observes
events and C{formatEvent} returns L{None}.
"""
self._test_observeWrites(None, 0)
def test_observeWritesEmpty(self):
"""
L{FileLogObserver} does not write to the given file when it observes
events and C{formatEvent} returns C{u""}.
"""
self._test_observeWrites(u"", 0)
def test_observeFlushes(self):
"""
L{FileLogObserver} calles C{flush()} on the output file when it
observes an event.
"""
with DummyFile() as fileHandle:
observer = FileLogObserver(fileHandle, lambda e: unicode(e))
event = dict(x=1)
observer(event)
self.assertEqual(fileHandle.flushes, 1)
class TextFileLogObserverTests(TestCase):
"""
Tests for L{textFileLogObserver}.
"""
def test_returnsFileLogObserver(self):
"""
L{textFileLogObserver} returns a L{FileLogObserver}.
"""
with StringIO() as fileHandle:
observer = textFileLogObserver(fileHandle)
self.assertIsInstance(observer, FileLogObserver)
def test_outFile(self):
"""
Returned L{FileLogObserver} has the correct outFile.
"""
with StringIO() as fileHandle:
observer = textFileLogObserver(fileHandle)
self.assertIs(observer._outFile, fileHandle)
def test_timeFormat(self):
"""
Returned L{FileLogObserver} has the correct outFile.
"""
with StringIO() as fileHandle:
observer = textFileLogObserver(fileHandle, timeFormat=u"%f")
observer(dict(log_format=u"XYZZY", log_time=112345.6))
self.assertEqual(fileHandle.getvalue(), u"600000 [-#-] XYZZY\n")
def test_observeFailure(self):
"""
If the C{"log_failure"} key exists in an event, the observer appends
the failure's traceback to the output.
"""
with StringIO() as fileHandle:
observer = textFileLogObserver(fileHandle)
try:
1 / 0
except ZeroDivisionError:
failure = Failure()
event = dict(log_failure=failure)
observer(event)
output = fileHandle.getvalue()
self.assertTrue(output.split("\n")[1].startswith("\tTraceback "),
msg=repr(output))
def test_observeFailureThatRaisesInGetTraceback(self):
"""
If the C{"log_failure"} key exists in an event, and contains an object
that raises when you call its C{getTraceback()}, then the observer
appends a message noting the problem, instead of raising.
"""
with StringIO() as fileHandle:
observer = textFileLogObserver(fileHandle)
event = dict(log_failure=object()) # object has no getTraceback()
observer(event)
output = fileHandle.getvalue()
expected = (
"(UNABLE TO OBTAIN TRACEBACK FROM EVENT)"
)
self.assertIn(expected, output)
class DummyFile(object):
"""
File that counts writes and flushes.
"""
def __init__(self):
self.writes = 0
self.flushes = 0
def write(self, data):
"""
Write data.
@param data: data
@type data: L{unicode} or L{bytes}
"""
self.writes += 1
def flush(self):
"""
Flush buffers.
"""
self.flushes += 1
def __enter__(self):
return self
def __exit__(self, exc_type, exc_value, traceback):
pass
@@ -0,0 +1,372 @@
# Copyright (c) Twisted Matrix Laboratories.
# See LICENSE for details.
"""
Test cases for L{twisted.logger._global}.
"""
from __future__ import print_function
import io
from twisted.trial import unittest
from .._file import textFileLogObserver
from .._observer import LogPublisher
from .._logger import Logger
from .._global import LogBeginner
from .._global import MORE_THAN_ONCE_WARNING
from .._levels import LogLevel
from ..test.test_stdlib import nextLine
from twisted.python.failure import Failure
def compareEvents(test, actualEvents, expectedEvents):
"""
Compare two sequences of log events, examining only the the keys which are
present in both.
@param test: a test case doing the comparison
@type test: L{unittest.TestCase}
@param actualEvents: A list of log events that were emitted by a logger.
@type actualEvents: L{list} of L{dict}
@param expectedEvents: A list of log events that were expected by a test.
@type expected: L{list} of L{dict}
"""
if len(actualEvents) != len(expectedEvents):
test.assertEqual(actualEvents, expectedEvents)
allMergedKeys = set()
for event in expectedEvents:
allMergedKeys |= set(event.keys())
def simplify(event):
copy = event.copy()
for key in event.keys():
if key not in allMergedKeys:
copy.pop(key)
return copy
simplifiedActual = [simplify(event) for event in actualEvents]
test.assertEqual(simplifiedActual, expectedEvents)
class LogBeginnerTests(unittest.TestCase):
"""
Tests for L{LogBeginner}.
"""
def setUp(self):
self.publisher = LogPublisher()
self.errorStream = io.StringIO()
class NotSys(object):
stdout = object()
stderr = object()
class NotWarnings(object):
def __init__(self):
self.warnings = []
def showwarning(
self, message, category, filename, lineno,
file=None, line=None
):
"""
Emulate warnings.showwarning.
@param message: A warning message to emit.
@type message: L{str}
@param category: A warning category to associate with
C{message}.
@type category: L{warnings.Warning}
@param filename: A file name for the source code file issuing
the warning.
@type warning: L{str}
@param lineno: A line number in the source file where the
warning was issued.
@type lineno: L{int}
@param file: A file to write the warning message to. If
L{None}, write to L{sys.stderr}.
@type file: file-like object
@param line: A line of source code to include with the warning
message. If L{None}, attempt to read the line from
C{filename} and C{lineno}.
@type line: L{str}
"""
self.warnings.append(
(message, category, filename, lineno, file, line)
)
self.sysModule = NotSys()
self.warningsModule = NotWarnings()
self.beginner = LogBeginner(
self.publisher, self.errorStream, self.sysModule,
self.warningsModule
)
def test_beginLoggingToAddObservers(self):
"""
Test that C{beginLoggingTo()} adds observers.
"""
event = dict(foo=1, bar=2)
events1 = []
events2 = []
o1 = lambda e: events1.append(e)
o2 = lambda e: events2.append(e)
self.beginner.beginLoggingTo((o1, o2))
self.publisher(event)
self.assertEqual([event], events1)
self.assertEqual([event], events2)
def test_beginLoggingToBufferedEvents(self):
"""
Test that events are buffered until C{beginLoggingTo()} is
called.
"""
event = dict(foo=1, bar=2)
events1 = []
events2 = []
o1 = lambda e: events1.append(e)
o2 = lambda e: events2.append(e)
self.publisher(event) # Before beginLoggingTo; this is buffered
self.beginner.beginLoggingTo((o1, o2))
self.assertEqual([event], events1)
self.assertEqual([event], events2)
def _bufferLimitTest(self, limit, beginner):
"""
Verify that when more than C{limit} events are logged to L{LogBeginner},
only the last C{limit} are replayed by L{LogBeginner.beginLoggingTo}.
@param limit: The maximum number of events the log beginner should
buffer.
@type limit: L{int}
@param beginner: The L{LogBeginner} against which to verify.
@type beginner: L{LogBeginner}
@raise: C{self.failureException} if the wrong events are replayed by
C{beginner}.
@return: L{None}
"""
for count in range(limit + 1):
self.publisher(dict(count=count))
events = []
beginner.beginLoggingTo([events.append])
self.assertEqual(
list(range(1, limit + 1)),
list(event["count"] for event in events),
)
def test_defaultBufferLimit(self):
"""
Up to C{LogBeginner._DEFAULT_BUFFER_SIZE} log events are buffered for
replay by L{LogBeginner.beginLoggingTo}.
"""
limit = LogBeginner._DEFAULT_BUFFER_SIZE
self._bufferLimitTest(limit, self.beginner)
def test_overrideBufferLimit(self):
"""
The size of the L{LogBeginner} event buffer can be overridden with the
C{initialBufferSize} initilizer argument.
"""
limit = 3
beginner = LogBeginner(
self.publisher, self.errorStream, self.sysModule,
self.warningsModule, initialBufferSize=limit,
)
self._bufferLimitTest(limit, beginner)
def test_beginLoggingToTwice(self):
"""
When invoked twice, L{LogBeginner.beginLoggingTo} will emit a log
message warning the user that they previously began logging, and add
the new log observers.
"""
events1 = []
events2 = []
fileHandle = io.StringIO()
textObserver = textFileLogObserver(fileHandle)
self.publisher(dict(event="prebuffer"))
firstFilename, firstLine = nextLine()
self.beginner.beginLoggingTo([events1.append, textObserver])
self.publisher(dict(event="postbuffer"))
secondFilename, secondLine = nextLine()
self.beginner.beginLoggingTo([events2.append, textObserver])
self.publisher(dict(event="postwarn"))
warning = dict(
log_format=MORE_THAN_ONCE_WARNING,
log_level=LogLevel.warn,
fileNow=secondFilename, lineNow=secondLine,
fileThen=firstFilename, lineThen=firstLine
)
compareEvents(
self, events1,
[
dict(event="prebuffer"),
dict(event="postbuffer"),
warning,
dict(event="postwarn")
]
)
compareEvents(self, events2, [warning, dict(event="postwarn")])
output = fileHandle.getvalue()
self.assertIn('<{0}:{1}>'.format(firstFilename, firstLine),
output)
self.assertIn('<{0}:{1}>'.format(secondFilename, secondLine),
output)
def test_criticalLogging(self):
"""
Critical messages will be written as text to the error stream.
"""
log = Logger(observer=self.publisher)
log.info("ignore this")
log.critical("a critical {message}", message="message")
self.assertEqual(self.errorStream.getvalue(), u"a critical message\n")
def test_criticalLoggingStops(self):
"""
Once logging has begun with C{beginLoggingTo}, critical messages are no
longer written to the output stream.
"""
log = Logger(observer=self.publisher)
self.beginner.beginLoggingTo(())
log.critical("another critical message")
self.assertEqual(self.errorStream.getvalue(), u"")
def test_beginLoggingToRedirectStandardIO(self):
"""
L{LogBeginner.beginLoggingTo} will re-direct the standard output and
error streams by setting the C{stdio} and C{stderr} attributes on its
sys module object.
"""
x = []
self.beginner.beginLoggingTo([x.append])
print("Hello, world.", file=self.sysModule.stdout)
compareEvents(
self, x, [dict(log_namespace="stdout", log_io="Hello, world.")]
)
del x[:]
print("Error, world.", file=self.sysModule.stderr)
compareEvents(
self, x, [dict(log_namespace="stderr", log_io="Error, world.")]
)
def test_beginLoggingToDontRedirect(self):
"""
L{LogBeginner.beginLoggingTo} will leave the existing stdout/stderr in
place if it has been told not to replace them.
"""
oldOut = self.sysModule.stdout
oldErr = self.sysModule.stderr
self.beginner.beginLoggingTo((), redirectStandardIO=False)
self.assertIs(self.sysModule.stdout, oldOut)
self.assertIs(self.sysModule.stderr, oldErr)
def test_beginLoggingToPreservesEncoding(self):
"""
When L{LogBeginner.beginLoggingTo} redirects stdout/stderr streams, the
replacement streams will preserve the encoding of the replaced streams,
to minimally disrupt any application relying on a specific encoding.
"""
weird = io.TextIOWrapper(io.BytesIO(), "shift-JIS")
weirderr = io.TextIOWrapper(io.BytesIO(), "big5")
self.sysModule.stdout = weird
self.sysModule.stderr = weirderr
x = []
self.beginner.beginLoggingTo([x.append])
self.assertEqual(self.sysModule.stdout.encoding, "shift-JIS")
self.assertEqual(self.sysModule.stderr.encoding, "big5")
self.sysModule.stdout.write(b"\x97\x9B\n")
self.sysModule.stderr.write(b"\xBC\xFC\n")
compareEvents(
self, x, [dict(log_io=u"\u674e"), dict(log_io=u"\u7469")]
)
def test_warningsModule(self):
"""
L{LogBeginner.beginLoggingTo} will redirect the warnings of its
warnings module into the logging system.
"""
self.warningsModule.showwarning(
"a message", DeprecationWarning, __file__, 1
)
x = []
self.beginner.beginLoggingTo([x.append])
self.warningsModule.showwarning(
"another message", DeprecationWarning, __file__, 2
)
f = io.StringIO()
self.warningsModule.showwarning(
"yet another", DeprecationWarning, __file__, 3, file=f
)
self.assertEqual(
self.warningsModule.warnings,
[
("a message", DeprecationWarning, __file__, 1, None, None),
("yet another", DeprecationWarning, __file__, 3, f, None),
]
)
compareEvents(
self, x,
[dict(
warning="another message",
category=(
DeprecationWarning.__module__ + "." +
DeprecationWarning.__name__
),
filename=__file__, lineno=2,
)]
)
def test_failuresAppendTracebacks(self):
"""
The string resulting from a logged failure contains a traceback.
"""
f = Failure(Exception("this is not the behavior you are looking for"))
log = Logger(observer=self.publisher)
log.failure('a failure', failure=f)
msg = self.errorStream.getvalue()
self.assertIn('a failure', msg)
self.assertIn('this is not the behavior you are looking for', msg)
self.assertIn('Traceback', msg)
@@ -0,0 +1,38 @@
# Copyright (c) Twisted Matrix Laboratories.
# See LICENSE for details.
"""
Test cases for L{twisted.logger._levels}.
"""
from twisted.trial import unittest
from .._levels import InvalidLogLevelError
from .._levels import LogLevel
class LogLevelTests(unittest.TestCase):
"""
Tests for L{LogLevel}.
"""
def test_levelWithName(self):
"""
Look up log level by name.
"""
for level in LogLevel.iterconstants():
self.assertIs(LogLevel.levelWithName(level.name), level)
def test_levelWithInvalidName(self):
"""
You can't make up log level names.
"""
bogus = "*bogus*"
try:
LogLevel.levelWithName(bogus)
except InvalidLogLevelError as e:
self.assertIs(e.level, bogus)
else:
self.fail("Expected InvalidLogLevelError.")
@@ -0,0 +1,304 @@
# Copyright (c) Twisted Matrix Laboratories.
# See LICENSE for details.
"""
Test cases for L{twisted.logger._format}.
"""
import sys
from io import BytesIO, TextIOWrapper
import logging as py_logging
from inspect import getsourcefile
from zope.interface.verify import verifyObject, BrokenMethodImplementation
from twisted.python.compat import _PY3, currentframe
from twisted.python.failure import Failure
from twisted.trial import unittest
from .._levels import LogLevel
from .._observer import ILogObserver
from .._stdlib import STDLibLogObserver
def nextLine():
"""
Retrive the file name and line number immediately after where this function
is called.
@return: the file name and line number
@rtype: 2-L{tuple} of L{str}, L{int}
"""
caller = currentframe(1)
return (getsourcefile(sys.modules[caller.f_globals['__name__']]),
caller.f_lineno + 1)
class STDLibLogObserverTests(unittest.TestCase):
"""
Tests for L{STDLibLogObserver}.
"""
def test_interface(self):
"""
L{STDLibLogObserver} is an L{ILogObserver}.
"""
observer = STDLibLogObserver()
try:
verifyObject(ILogObserver, observer)
except BrokenMethodImplementation as e:
self.fail(e)
def py_logger(self):
"""
Create a logging object we can use to test with.
@return: a stdlib-style logger
@rtype: L{StdlibLoggingContainer}
"""
logger = StdlibLoggingContainer()
self.addCleanup(logger.close)
return logger
def logEvent(self, *events):
"""
Send one or more events to Python's logging module, and
capture the emitted L{logging.LogRecord}s and output stream as
a string.
@param events: events
@type events: L{tuple} of L{dict}
@return: a tuple: (records, output)
@rtype: 2-tuple of (L{list} of L{logging.LogRecord}, L{bytes}.)
"""
pl = self.py_logger()
observer = STDLibLogObserver(
# Add 1 to default stack depth to skip *this* frame, since
# tests will want to know about their own frames.
stackDepth=STDLibLogObserver.defaultStackDepth + 1
)
for event in events:
observer(event)
return pl.bufferedHandler.records, pl.outputAsText()
def test_name(self):
"""
Logger name.
"""
records, output = self.logEvent({})
self.assertEqual(len(records), 1)
self.assertEqual(records[0].name, "twisted")
def test_levels(self):
"""
Log levels.
"""
levelMapping = {
None: py_logging.INFO, # Default
LogLevel.debug: py_logging.DEBUG,
LogLevel.info: py_logging.INFO,
LogLevel.warn: py_logging.WARNING,
LogLevel.error: py_logging.ERROR,
LogLevel.critical: py_logging.CRITICAL,
}
# Build a set of events for each log level
events = []
for level, pyLevel in levelMapping.items():
event = {}
# Set the log level on the event, except for default
if level is not None:
event["log_level"] = level
# Remember the Python log level we expect to see for this
# event (as an int)
event["py_levelno"] = int(pyLevel)
events.append(event)
records, output = self.logEvent(*events)
self.assertEqual(len(records), len(levelMapping))
# Check that each event has the correct level
for i in range(len(records)):
self.assertEqual(records[i].levelno, events[i]["py_levelno"])
def test_callerInfo(self):
"""
C{pathname}, C{lineno}, C{exc_info}, C{func} is set properly on
records.
"""
filename, logLine = nextLine()
records, output = self.logEvent({})
self.assertEqual(len(records), 1)
self.assertEqual(records[0].pathname, filename)
self.assertEqual(records[0].lineno, logLine)
self.assertIsNone(records[0].exc_info)
# Attribute "func" is missing from record, which is weird because it's
# documented.
# self.assertEqual(records[0].func, "test_callerInfo")
def test_basicFormat(self):
"""
Basic formattable event passes the format along correctly.
"""
event = dict(log_format="Hello, {who}!", who="dude")
records, output = self.logEvent(event)
self.assertEqual(len(records), 1)
self.assertEqual(str(records[0].msg), u"Hello, dude!")
self.assertEqual(records[0].args, ())
def test_basicFormatRendered(self):
"""
Basic formattable event renders correctly.
"""
event = dict(log_format="Hello, {who}!", who="dude")
records, output = self.logEvent(event)
self.assertEqual(len(records), 1)
self.assertTrue(output.endswith(u":Hello, dude!\n"),
repr(output))
def test_noFormat(self):
"""
Event with no format.
"""
records, output = self.logEvent({})
self.assertEqual(len(records), 1)
self.assertEqual(str(records[0].msg), "")
def test_failure(self):
"""
An event with a failure logs the failure details as well.
"""
def failing_func():
1 / 0
try:
failing_func()
except ZeroDivisionError:
failure = Failure()
event = dict(log_format='Hi mom', who='me', log_failure=failure)
records, output = self.logEvent(event)
self.assertEqual(len(records), 1)
self.assertIn(u'Hi mom', output)
self.assertIn(u'in failing_func', output)
self.assertIn(u'ZeroDivisionError', output)
def test_cleanedFailure(self):
"""
A cleaned Failure object has a fake traceback object; make sure that
logging such a failure still results in the exception details being
logged.
"""
def failing_func():
1 / 0
try:
failing_func()
except ZeroDivisionError:
failure = Failure()
failure.cleanFailure()
event = dict(log_format='Hi mom', who='me', log_failure=failure)
records, output = self.logEvent(event)
self.assertEqual(len(records), 1)
self.assertIn(u'Hi mom', output)
self.assertIn(u'in failing_func', output)
self.assertIn(u'ZeroDivisionError', output)
class StdlibLoggingContainer(object):
"""
Continer for a test configuration of stdlib logging objects.
"""
def __init__(self):
self.rootLogger = py_logging.getLogger("")
self.originalLevel = self.rootLogger.getEffectiveLevel()
self.rootLogger.setLevel(py_logging.DEBUG)
self.bufferedHandler = BufferedHandler()
self.rootLogger.addHandler(self.bufferedHandler)
self.streamHandler, self.output = handlerAndBytesIO()
self.rootLogger.addHandler(self.streamHandler)
def close(self):
"""
Close the logger.
"""
self.rootLogger.setLevel(self.originalLevel)
self.rootLogger.removeHandler(self.bufferedHandler)
self.rootLogger.removeHandler(self.streamHandler)
self.streamHandler.close()
self.output.close()
def outputAsText(self):
"""
Get the output to the underlying stream as text.
@return: the output text
@rtype: L{unicode}
"""
return self.output.getvalue().decode("utf-8")
def handlerAndBytesIO():
"""
Construct a 2-tuple of C{(StreamHandler, BytesIO)} for testing interaction
with the 'logging' module.
@return: handler and io object
@rtype: tuple of L{StreamHandler} and L{io.BytesIO}
"""
output = BytesIO()
stream = output
template = py_logging.BASIC_FORMAT
if _PY3:
stream = TextIOWrapper(output, encoding="utf-8", newline="\n")
formatter = py_logging.Formatter(template)
handler = py_logging.StreamHandler(stream)
handler.setFormatter(formatter)
return handler, output
class BufferedHandler(py_logging.Handler):
"""
A L{py_logging.Handler} that remembers all logged records in a list.
"""
def __init__(self):
"""
Initialize this L{BufferedHandler}.
"""
py_logging.Handler.__init__(self)
self.records = []
def emit(self, record):
"""
Remember the record.
"""
self.records.append(record)