From 6085042c3109ff3c59cf27dce0127566710417cf Mon Sep 17 00:00:00 2001 From: Itamar Turner-Trauring Date: Sun, 11 Aug 2019 14:30:47 -0400 Subject: [PATCH 1/5] Sketch of py.test fixture. --- eliot/tests/conftest.py | 2 + eliot/tests/test_pytest.py | 339 +++++++++++++++++++++++++++++++++++++ setup.py | 5 +- 3 files changed, 345 insertions(+), 1 deletion(-) create mode 100644 eliot/tests/conftest.py create mode 100644 eliot/tests/test_pytest.py diff --git a/eliot/tests/conftest.py b/eliot/tests/conftest.py new file mode 100644 index 0000000..1df0963 --- /dev/null +++ b/eliot/tests/conftest.py @@ -0,0 +1,2 @@ +# Enable pytester, so we can test fixtures/plugins: +pytest_plugins = ["pytester"] diff --git a/eliot/tests/test_pytest.py b/eliot/tests/test_pytest.py new file mode 100644 index 0000000..ee7a06f --- /dev/null +++ b/eliot/tests/test_pytest.py @@ -0,0 +1,339 @@ +"""Tests for py.test plugins/fixtures.""" + + +class ValidateLoggingTestsMixin(object): + """ + Tests for L{validateLogging} and L{capture_logging}. + """ + + validate = None + + def test_decoratedFunctionCalledWithMemoryLogger(self): + """ + The underlying function decorated with L{validateLogging} is called with + a L{MemoryLogger} instance. + """ + result = [] + + class MyTest(TestCase): + @self.validate(None) + def test_foo(this, logger): + result.append((this, logger.__class__)) + + theTest = MyTest("test_foo") + theTest.run() + self.assertEqual(result, [(theTest, MemoryLogger)]) + + def test_decorated_function_passthrough(self): + """ + Additional arguments are passed to the underlying function. + """ + result = [] + + def another_wrapper(f): + def g(this): + f(this, 1, 2, c=3) + + return g + + class MyTest(TestCase): + @another_wrapper + @self.validate(None) + def test_foo(this, a, b, logger, c=None): + result.append((a, b, c)) + + theTest = MyTest("test_foo") + theTest.debug() + self.assertEqual(result, [(1, 2, 3)]) + + def test_newMemoryLogger(self): + """ + The underlying function decorated with L{validateLogging} is called with + a new L{MemoryLogger} every time the wrapper is called. + """ + result = [] + + class MyTest(TestCase): + @self.validate(None) + def test_foo(this, logger): + result.append(logger) + + theTest = MyTest("test_foo") + theTest.run() + theTest.run() + self.assertIsNot(result[0], result[1]) + + def test_returns(self): + """ + The result of the underlying function is returned by wrapper when called. + """ + + class MyTest(TestCase): + @self.validate(None) + def test_foo(self, logger): + return 123 + + self.assertEqual(MyTest("test_foo").test_foo(), 123) + + def test_raises(self): + """ + The exception raised by the underlying function is passed through by the + wrapper when called. + """ + exc = Exception() + + class MyTest(TestCase): + @self.validate(None) + def test_foo(self, logger): + raise exc + + raised = None + try: + MyTest("test_foo").debug() + except Exception as e: + raised = e + self.assertIs(exc, raised) + + def test_name(self): + """ + The wrapper has the same name as the wrapped function. + """ + + class MyTest(TestCase): + @self.validate(None) + def test_foo(self, logger): + pass + + self.assertEqual(MyTest.test_foo.__name__, "test_foo") + + def test_addCleanupValidate(self): + """ + When a test method is decorated with L{validateLogging} it has + L{MemoryLogger.validate} registered as a test cleanup. + """ + MESSAGE = MessageType("mymessage", [], "A message") + + class MyTest(TestCase): + @self.validate(None) + def runTest(self, logger): + self.logger = logger + logger.write({"message_type": "wrongmessage"}, MESSAGE._serializer) + + test = MyTest() + with self.assertRaises(ValidationError) as context: + test.debug() + # Some reference to the reason: + self.assertIn("wrongmessage", str(context.exception)) + # Some reference to which file caused the problem: + self.assertIn("test_testing.py", str(context.exception)) + + def test_addCleanupTracebacks(self): + """ + When a test method is decorated with L{validateLogging} it has has a + check unflushed tracebacks in the L{MemoryLogger} registered as a + test cleanup. + """ + + class MyTest(TestCase): + @self.validate(None) + def runTest(self, logger): + try: + 1 / 0 + except ZeroDivisionError: + write_traceback(logger) + + test = MyTest() + self.assertRaises(UnflushedTracebacks, test.debug) + + def test_assertion(self): + """ + If a callable is passed to L{validateLogging}, it is called with the + L{TestCase} instance and the L{MemoryLogger} passed to the test + method. + """ + result = [] + + class MyTest(TestCase): + def assertLogging(self, logger): + result.append((self, logger)) + + @self.validate(assertLogging) + def runTest(self, logger): + self.logger = logger + + test = MyTest() + test.run() + self.assertEqual(result, [(test, test.logger)]) + + def test_assertionArguments(self): + """ + If a callable together with additional arguments and keyword arguments are + passed to L{validateLogging}, the callable is called with the additional + args and kwargs. + """ + result = [] + + class MyTest(TestCase): + def assertLogging(self, logger, x, y): + result.append((self, logger, x, y)) + + @self.validate(assertLogging, 1, y=2) + def runTest(self, logger): + self.logger = logger + + test = MyTest() + test.run() + self.assertEqual(result, [(test, test.logger, 1, 2)]) + + def test_assertionAfterTest(self): + """ + If a callable is passed to L{validateLogging}, it is called with the + after the main test code has run, allowing it to make assertions + about log messages from the test. + """ + + class MyTest(TestCase): + def assertLogging(self, logger): + self.result.append(2) + + @self.validate(assertLogging) + def runTest(self, logger): + self.result = [1] + + test = MyTest() + test.run() + self.assertEqual(test.result, [1, 2]) + + def test_assertionBeforeTracebackCleanup(self): + """ + If a callable is passed to L{validateLogging}, it is called with the + before the check for unflushed tracebacks, allowing it to flush + traceback log messages. + """ + + class MyTest(TestCase): + def assertLogging(self, logger): + logger.flushTracebacks(ZeroDivisionError) + self.flushed = True + + @self.validate(assertLogging) + def runTest(self, logger): + self.flushed = False + try: + 1 / 0 + except ZeroDivisionError: + write_traceback(logger) + + test = MyTest() + test.run() + self.assertTrue(test.flushed) + + +class ValidateLoggingTests(ValidateLoggingTestsMixin, TestCase): + """ + Tests for L{validate_logging}. + """ + + validate = staticmethod(validate_logging) + + +class CaptureLoggingTests(ValidateLoggingTestsMixin, TestCase): + """ + Tests for L{capture_logging}. + """ + + validate = staticmethod(capture_logging) + + def setUp(self): + # Since we're not always calling the test method via the TestCase + # infrastructure, sometimes cleanup methods are not called. This + # means the original default logger is not restored. So we do so + # manually. If the issue is a bug in capture_logging itself the + # tests below will catch that. + original_logger = _output._DEFAULT_LOGGER + + def cleanup(): + _output._DEFAULT_LOGGER = original_logger + + self.addCleanup(cleanup) + + def test_default_logger(self): + """ + L{capture_logging} captures messages from logging that + doesn't specify a L{Logger}. + """ + + class MyTest(TestCase): + @capture_logging(None) + def runTest(self, logger): + Message.log(some_key=1234) + self.logger = logger + + test = MyTest() + test.run() + self.assertEqual(test.logger.messages[0]["some_key"], 1234) + + def test_global_cleanup(self): + """ + After the function wrapped with L{capture_logging} finishes, + logging that doesn't specify a logger is logged normally. + """ + + class MyTest(TestCase): + @capture_logging(None) + def runTest(self, logger): + pass + + test = MyTest() + test.run() + messages = [] + add_destination(messages.append) + self.addCleanup(remove_destination, messages.append) + Message.log(some_key=1234) + self.assertEqual(messages[0]["some_key"], 1234) + + def test_global_cleanup_exception(self): + """ + If the function wrapped with L{capture_logging} throws an exception, + logging that doesn't specify a logger is logged normally. + """ + + class MyTest(TestCase): + @capture_logging(None) + def runTest(self, logger): + raise RuntimeError() + + test = MyTest() + test.run() + messages = [] + add_destination(messages.append) + self.addCleanup(remove_destination, messages.append) + Message.log(some_key=1234) + self.assertEqual(messages[0]["some_key"], 1234) + + def test_validationNotRunForSkip(self): + """ + If the decorated test raises L{SkipTest} then the logging validation is + also skipped. + """ + + class MyTest(TestCase): + recorded = False + + def record(self, logger): + self.recorded = True + + @validateLogging(record) + def runTest(self, logger): + raise SkipTest("Do not run this test.") + + test = MyTest() + result = TestResult() + test.run(result) + + # Verify that the validation function did not run and that the test was + # nevertheless marked as a skip with the correct reason. + self.assertEqual( + (test.recorded, result.skipped, result.errors, result.failures), + (False, [(test, "Do not run this test.")], [], []), + ) diff --git a/setup.py b/setup.py index e6fe980..50e6d84 100644 --- a/setup.py +++ b/setup.py @@ -14,6 +14,7 @@ def read(path): setup( classifiers=[ "Intended Audience :: Developers", + "Framework :: Pytest", "License :: OSI Approved :: Apache Software License", "Operating System :: OS Independent", "Programming Language :: Python", @@ -67,7 +68,9 @@ def read(path): "black", ], }, - entry_points={"console_scripts": ["eliot-prettyprint = eliot.prettyprint:_main"]}, + entry_points={"console_scripts": ["eliot-prettyprint = eliot.prettyprint:_main"], + "pytest11": ["eliot = eliot.pytest"]}, + }, keywords="logging", license="Apache 2.0", packages=["eliot", "eliot.tests"], From 25f0ffb6e5ceda11ad942868315a4255959ab2fa Mon Sep 17 00:00:00 2001 From: Itamar Turner-Trauring Date: Sun, 11 Aug 2019 15:15:24 -0400 Subject: [PATCH 2/5] Move exclusively() into util module. --- eliot/_output.py | 17 +---------------- eliot/_util.py | 15 +++++++++++++++ 2 files changed, 16 insertions(+), 16 deletions(-) diff --git a/eliot/_output.py b/eliot/_output.py index b322ed4..da3bdb4 100644 --- a/eliot/_output.py +++ b/eliot/_output.py @@ -7,7 +7,6 @@ import inspect import json as pyjson from threading import Lock -from functools import wraps from io import IOBase from pyrsistent import PClass, field @@ -17,7 +16,7 @@ from ._traceback import write_traceback, TRACEBACK_MESSAGE from ._message import Message, EXCEPTION_FIELD, MESSAGE_TYPE_FIELD, REASON_FIELD -from ._util import saferepr, safeunicode +from ._util import saferepr, safeunicode, exclusively from .json import EliotJSONEncoder from ._validation import ValidationError @@ -224,20 +223,6 @@ def write(self, dictionary, serializer=None): pass -def exclusively(f): - """ - Decorate a function to make it thread-safe by serializing invocations - using a per-instance lock. - """ - - @wraps(f) - def exclusively_f(self, *a, **kw): - with self._lock: - return f(self, *a, **kw) - - return exclusively_f - - @implementer(ILogger) class MemoryLogger(object): """ diff --git a/eliot/_util.py b/eliot/_util.py index 38768c4..02a59b2 100644 --- a/eliot/_util.py +++ b/eliot/_util.py @@ -8,6 +8,7 @@ from types import ModuleType from six import exec_, text_type as unicode, PY3 +from boltons.functools import wraps def safeunicode(o): @@ -68,3 +69,17 @@ def load_module(name, original_module): source = f.read() exec_(source, module.__dict__, module.__dict__) return module + + +def exclusively(f): + """ + Decorate a function to make it thread-safe by serializing invocations + using a per-instance lock. + """ + + @wraps(f) + def exclusively_f(self, *a, **kw): + with self._lock: + return f(self, *a, **kw) + + return exclusively_f From d65708a815c2e93af9317b968af133ae186eb20a Mon Sep 17 00:00:00 2001 From: Itamar Turner-Trauring Date: Sun, 11 Aug 2019 19:34:28 -0400 Subject: [PATCH 3/5] Sketch of new testing API. --- eliot/_traceback.py | 12 +++-- eliot/pytest.py | 30 +++++++++++ eliot/testutil.py | 119 ++++++++++++++++++++++++++++++++++++++++++++ 3 files changed, 156 insertions(+), 5 deletions(-) create mode 100644 eliot/pytest.py create mode 100644 eliot/testutil.py diff --git a/eliot/_traceback.py b/eliot/_traceback.py index 08e90a5..9825236 100644 --- a/eliot/_traceback.py +++ b/eliot/_traceback.py @@ -13,16 +13,18 @@ from ._validation import MessageType, Field from ._errors import _error_extraction + +def class_fqpn(typ): + """Convert a class to it's fully-qualified name.""" + return "%s.%s" % (typ.__module__, typ.__name__) + + TRACEBACK_MESSAGE = MessageType( "eliot:traceback", [ Field(REASON_FIELD, safeunicode, "The exception's value."), Field("traceback", safeunicode, "The traceback."), - Field( - EXCEPTION_FIELD, - lambda typ: "%s.%s" % (typ.__module__, typ.__name__), - "The exception type's FQPN.", - ), + Field(EXCEPTION_FIELD, class_fqpn, "The exception type's FQPN."), ], "An unexpected exception indicating a bug.", ) diff --git a/eliot/pytest.py b/eliot/pytest.py new file mode 100644 index 0000000..3d183fa --- /dev/null +++ b/eliot/pytest.py @@ -0,0 +1,30 @@ +"""Plugins for py.test.""" + +import json + +import pytest + +from .testutil import _capture_logs +from .json import EliotJSONEncoder + + +@pytest.fixture +def eliot_logs(request): + """ + Capture log messages for the duration of the test. + + 1. The fixture object is a L{eliot.testutil.TestingDestination}. + + 2. All messages logged during the test are validated at the end of + the test. + + 3. Any unflushed logged tracebacks will cause the test to fail. If you + expect a particular tracekbac, you can flush it by calling + C{remove_expected_tracebacks} on the C{TestingDestination} instance. + """ + + def logs_for_pyttest(encode=EliotJSONEncoder().encode, decode=json.loads): + return _capture_logs(request.addfinalizer, encode, decode) + + +__all__ = ["eliot_logs"] diff --git a/eliot/testutil.py b/eliot/testutil.py new file mode 100644 index 0000000..cf08f72 --- /dev/null +++ b/eliot/testutil.py @@ -0,0 +1,119 @@ +"""Utilities for testing.""" + +import json +from unittest import TestCase +from typing import Type + +from .json import EliotJSONEncoder +from ._message import MESSAGE_TYPE_FIELD +from ._traceback import REASON_FIELD, class_fqpn +from ._util import exclusively + + +__all__ = ["TestingDestination", "UnexpectedTracebacks", "logs_for_pyunit"] + + +class UnexpectedTracebacks(Exception): + """ + A test had some tracebacks logged which were not marked as expected. + + If you expected the traceback then you will need to flush it using + C{TestingDestination.flush_tracebacks}. + """ + + +class TestingDestination: + """ + A destination that stores messages for testing purposes. + + Unexpected tracebacks are considered errors (your code logging a traceback + typically indicates a bug), so you will need to remove expected tracebacks + by calling C{remove_expected_tracebacks}. + """ + + def __init__(self, encode, decode): + """ + @param encode: Take an unserialized message, serialize it. + @param decode: Take an serialized message, deserialize it. + """ + self.messages = [] + self._traceback_messages = [] + self._encode = encode + self._decode = decode + + @exclusively + def write(self, message): + if message.get(MESSAGE_TYPE_FIELD) == "eliot:traceback": + self._traceback_messages.append(message) + self.messages.append(self._decode(self._encode(message))) + + @exclusively + def remove_expected_tracebacks(self, exceptionType: Type[Exception]): + """ + Remove all logged tracebacks whose exception is of the given type. + + This means they are expected tracebacks and should not cause the test + to fail. + + @param exceptionType: A subclass of L{Exception}. + + @return: C{list} of flushed messages. + """ + result = [] + remaining = [] + for message in self._traceback_messages: + if message[REASON_FIELD] == class_fqpn(exceptionType): + result.append(message) + else: + remaining.append(message) + self.traceback_messages = remaining + return result + + def _ensure_no_bad_messages(self): + """ + Raise L{UnexpectedTracebacks} if there are any unexpected tracebacks. + + Raise L{ValueError} if there are serialization failures from the Eliot + type system, or serialization errors from the encoder/decoder + (typically JSON). + + If you expect a traceback to be logged, remove it using + C{remove_expected_tracebacks}. + """ + if self._traceback_messages: + raise UnexpectedTracebacks(self._traceback_messages) + serialization_failures = [ + m + for m in self.messages + if m.get(MESSAGE_TYPE_FIELD) + in ("eliot:serialization_failure", "eliot:destination_failure") + ] + if serialization_failures: + raise ValueError(serialization_failures) + + +def _capture_logs(addfinalizer, encode, decode): + test_dest = TestingDestination(encode, decode) + from . import add_destinations, remove_destination + + add_destinations(test_dest) + addfinalizer(remove_destination, test_dest) + addfinalizer(test_dest._ensure_no_bad_messages) + + return test_dest + + +def logs_for_pyunit( + test_case: TestCase, encode=EliotJSONEncoder().encode, decode=json.loads +) -> TestingDestination: + """Capture the logs for a C{unittest.TestCase}. + + 1. Captures all log messages. + + 2. At the end of the test, raises an exception if there are any + unexpected tracebacks, or any of the messages couldn't be + serialized. + + @returns: The L{TestingDestination} that will capture the log messages. + """ + return _capture_logs(test_case.addCleanup, encode, decode) From 7c03541e5e5bd90cc8715f515d23f45d41b48331 Mon Sep 17 00:00:00 2001 From: Itamar Turner-Trauring Date: Sun, 11 Aug 2019 19:35:40 -0400 Subject: [PATCH 4/5] We'll start from scratch. --- eliot/tests/test_pytest.py | 339 ------------------------------------- 1 file changed, 339 deletions(-) delete mode 100644 eliot/tests/test_pytest.py diff --git a/eliot/tests/test_pytest.py b/eliot/tests/test_pytest.py deleted file mode 100644 index ee7a06f..0000000 --- a/eliot/tests/test_pytest.py +++ /dev/null @@ -1,339 +0,0 @@ -"""Tests for py.test plugins/fixtures.""" - - -class ValidateLoggingTestsMixin(object): - """ - Tests for L{validateLogging} and L{capture_logging}. - """ - - validate = None - - def test_decoratedFunctionCalledWithMemoryLogger(self): - """ - The underlying function decorated with L{validateLogging} is called with - a L{MemoryLogger} instance. - """ - result = [] - - class MyTest(TestCase): - @self.validate(None) - def test_foo(this, logger): - result.append((this, logger.__class__)) - - theTest = MyTest("test_foo") - theTest.run() - self.assertEqual(result, [(theTest, MemoryLogger)]) - - def test_decorated_function_passthrough(self): - """ - Additional arguments are passed to the underlying function. - """ - result = [] - - def another_wrapper(f): - def g(this): - f(this, 1, 2, c=3) - - return g - - class MyTest(TestCase): - @another_wrapper - @self.validate(None) - def test_foo(this, a, b, logger, c=None): - result.append((a, b, c)) - - theTest = MyTest("test_foo") - theTest.debug() - self.assertEqual(result, [(1, 2, 3)]) - - def test_newMemoryLogger(self): - """ - The underlying function decorated with L{validateLogging} is called with - a new L{MemoryLogger} every time the wrapper is called. - """ - result = [] - - class MyTest(TestCase): - @self.validate(None) - def test_foo(this, logger): - result.append(logger) - - theTest = MyTest("test_foo") - theTest.run() - theTest.run() - self.assertIsNot(result[0], result[1]) - - def test_returns(self): - """ - The result of the underlying function is returned by wrapper when called. - """ - - class MyTest(TestCase): - @self.validate(None) - def test_foo(self, logger): - return 123 - - self.assertEqual(MyTest("test_foo").test_foo(), 123) - - def test_raises(self): - """ - The exception raised by the underlying function is passed through by the - wrapper when called. - """ - exc = Exception() - - class MyTest(TestCase): - @self.validate(None) - def test_foo(self, logger): - raise exc - - raised = None - try: - MyTest("test_foo").debug() - except Exception as e: - raised = e - self.assertIs(exc, raised) - - def test_name(self): - """ - The wrapper has the same name as the wrapped function. - """ - - class MyTest(TestCase): - @self.validate(None) - def test_foo(self, logger): - pass - - self.assertEqual(MyTest.test_foo.__name__, "test_foo") - - def test_addCleanupValidate(self): - """ - When a test method is decorated with L{validateLogging} it has - L{MemoryLogger.validate} registered as a test cleanup. - """ - MESSAGE = MessageType("mymessage", [], "A message") - - class MyTest(TestCase): - @self.validate(None) - def runTest(self, logger): - self.logger = logger - logger.write({"message_type": "wrongmessage"}, MESSAGE._serializer) - - test = MyTest() - with self.assertRaises(ValidationError) as context: - test.debug() - # Some reference to the reason: - self.assertIn("wrongmessage", str(context.exception)) - # Some reference to which file caused the problem: - self.assertIn("test_testing.py", str(context.exception)) - - def test_addCleanupTracebacks(self): - """ - When a test method is decorated with L{validateLogging} it has has a - check unflushed tracebacks in the L{MemoryLogger} registered as a - test cleanup. - """ - - class MyTest(TestCase): - @self.validate(None) - def runTest(self, logger): - try: - 1 / 0 - except ZeroDivisionError: - write_traceback(logger) - - test = MyTest() - self.assertRaises(UnflushedTracebacks, test.debug) - - def test_assertion(self): - """ - If a callable is passed to L{validateLogging}, it is called with the - L{TestCase} instance and the L{MemoryLogger} passed to the test - method. - """ - result = [] - - class MyTest(TestCase): - def assertLogging(self, logger): - result.append((self, logger)) - - @self.validate(assertLogging) - def runTest(self, logger): - self.logger = logger - - test = MyTest() - test.run() - self.assertEqual(result, [(test, test.logger)]) - - def test_assertionArguments(self): - """ - If a callable together with additional arguments and keyword arguments are - passed to L{validateLogging}, the callable is called with the additional - args and kwargs. - """ - result = [] - - class MyTest(TestCase): - def assertLogging(self, logger, x, y): - result.append((self, logger, x, y)) - - @self.validate(assertLogging, 1, y=2) - def runTest(self, logger): - self.logger = logger - - test = MyTest() - test.run() - self.assertEqual(result, [(test, test.logger, 1, 2)]) - - def test_assertionAfterTest(self): - """ - If a callable is passed to L{validateLogging}, it is called with the - after the main test code has run, allowing it to make assertions - about log messages from the test. - """ - - class MyTest(TestCase): - def assertLogging(self, logger): - self.result.append(2) - - @self.validate(assertLogging) - def runTest(self, logger): - self.result = [1] - - test = MyTest() - test.run() - self.assertEqual(test.result, [1, 2]) - - def test_assertionBeforeTracebackCleanup(self): - """ - If a callable is passed to L{validateLogging}, it is called with the - before the check for unflushed tracebacks, allowing it to flush - traceback log messages. - """ - - class MyTest(TestCase): - def assertLogging(self, logger): - logger.flushTracebacks(ZeroDivisionError) - self.flushed = True - - @self.validate(assertLogging) - def runTest(self, logger): - self.flushed = False - try: - 1 / 0 - except ZeroDivisionError: - write_traceback(logger) - - test = MyTest() - test.run() - self.assertTrue(test.flushed) - - -class ValidateLoggingTests(ValidateLoggingTestsMixin, TestCase): - """ - Tests for L{validate_logging}. - """ - - validate = staticmethod(validate_logging) - - -class CaptureLoggingTests(ValidateLoggingTestsMixin, TestCase): - """ - Tests for L{capture_logging}. - """ - - validate = staticmethod(capture_logging) - - def setUp(self): - # Since we're not always calling the test method via the TestCase - # infrastructure, sometimes cleanup methods are not called. This - # means the original default logger is not restored. So we do so - # manually. If the issue is a bug in capture_logging itself the - # tests below will catch that. - original_logger = _output._DEFAULT_LOGGER - - def cleanup(): - _output._DEFAULT_LOGGER = original_logger - - self.addCleanup(cleanup) - - def test_default_logger(self): - """ - L{capture_logging} captures messages from logging that - doesn't specify a L{Logger}. - """ - - class MyTest(TestCase): - @capture_logging(None) - def runTest(self, logger): - Message.log(some_key=1234) - self.logger = logger - - test = MyTest() - test.run() - self.assertEqual(test.logger.messages[0]["some_key"], 1234) - - def test_global_cleanup(self): - """ - After the function wrapped with L{capture_logging} finishes, - logging that doesn't specify a logger is logged normally. - """ - - class MyTest(TestCase): - @capture_logging(None) - def runTest(self, logger): - pass - - test = MyTest() - test.run() - messages = [] - add_destination(messages.append) - self.addCleanup(remove_destination, messages.append) - Message.log(some_key=1234) - self.assertEqual(messages[0]["some_key"], 1234) - - def test_global_cleanup_exception(self): - """ - If the function wrapped with L{capture_logging} throws an exception, - logging that doesn't specify a logger is logged normally. - """ - - class MyTest(TestCase): - @capture_logging(None) - def runTest(self, logger): - raise RuntimeError() - - test = MyTest() - test.run() - messages = [] - add_destination(messages.append) - self.addCleanup(remove_destination, messages.append) - Message.log(some_key=1234) - self.assertEqual(messages[0]["some_key"], 1234) - - def test_validationNotRunForSkip(self): - """ - If the decorated test raises L{SkipTest} then the logging validation is - also skipped. - """ - - class MyTest(TestCase): - recorded = False - - def record(self, logger): - self.recorded = True - - @validateLogging(record) - def runTest(self, logger): - raise SkipTest("Do not run this test.") - - test = MyTest() - result = TestResult() - test.run(result) - - # Verify that the validation function did not run and that the test was - # nevertheless marked as a skip with the correct reason. - self.assertEqual( - (test.recorded, result.skipped, result.errors, result.failures), - (False, [(test, "Do not run this test.")], [], []), - ) From 5662130e7f8d9856c789a573e2ca740ab38db1c1 Mon Sep 17 00:00:00 2001 From: Itamar Turner-Trauring Date: Sun, 11 Aug 2019 19:36:07 -0400 Subject: [PATCH 5/5] Start deprecating. --- eliot/testing.py | 20 ++++++++++++++++++-- 1 file changed, 18 insertions(+), 2 deletions(-) diff --git a/eliot/testing.py b/eliot/testing.py index 4e0ba2c..6507f8d 100644 --- a/eliot/testing.py +++ b/eliot/testing.py @@ -1,5 +1,7 @@ """ Utilities to aid unit testing L{eliot} and code that uses it. + +DEPRECATED. Use L{eliot.testutil} instead. """ from __future__ import unicode_literals @@ -19,11 +21,25 @@ ) from ._message import MESSAGE_TYPE_FIELD, TASK_LEVEL_FIELD, TASK_UUID_FIELD from ._output import MemoryLogger +from ._util import exclusively from . import _output + COMPLETED_STATUSES = (FAILED_STATUS, SUCCEEDED_STATUS) +__all__ = [ + "assertHasAction", + "assertHasMessage", + "assertContainsFields", + "MemoryLogger", + "LoggedAction", + "LoggedMessage", + "capture_logging", + "UnflushedTracebacks", +] + + def issuperset(a, b): """ Use L{assertContainsFields} instead. @@ -262,11 +278,11 @@ def of_type(klass, messages, messageType): class UnflushedTracebacks(Exception): """ - The L{MemoryLogger} had some tracebacks logged which were not flushed. + A test had some tracebacks logged which were not flushed. This means either your code has a bug and logged an unexpected traceback. If you expected the traceback then you will need to flush it - using L{MemoryLogger.flushTracebacks}. + using C{flush_tracebacks}. """