A stab at Eliot support for inlineCallbacks

This commit is contained in:
Jean-Paul Calderone 2019-02-21 12:06:36 -05:00
parent 9ad8e21530
commit 15ae31bf23
2 changed files with 447 additions and 16 deletions

View File

@ -2,15 +2,21 @@
Tools aimed at the interaction between tests and Eliot.
"""
from sys import exc_info
from functools import wraps
from contextlib import contextmanager
from eliot import (
Message,
ActionType,
Field,
)
from eliot.testing import capture_logging
from twisted.internet.defer import maybeDeferred
from twisted.internet.defer import (
maybeDeferred,
inlineCallbacks,
)
_NAME = Field.for_types(
u"name",
@ -26,7 +32,7 @@ RUN_TEST = ActionType(
)
def with_eliot(f):
def eliot_logged_test(f):
"""
Decorate a test method to run in a dedicated Eliot action context.
@ -43,7 +49,7 @@ def with_eliot(f):
pass
@wraps(f)
def run_and_republish(self):
def run_and_republish(self, *a, **kw):
def republish():
# This is called as a cleanup function after capture_logging has
# restored the global/default logger to its original state. We
@ -69,7 +75,7 @@ def with_eliot(f):
def run(self, logger):
# Record the MemoryLogger for later message extraction.
storage.logger = logger
return f(self)
return f(self, *a, **kw)
# Arrange for all messages written to the memory logger that
# `capture_logging` installs to be re-written to the global/default
@ -84,10 +90,6 @@ def with_eliot(f):
# Begin an action that should comprise all messages from the decorated
# test method.
with RUN_TEST(name=self.id().decode("utf-8")).context() as action:
# Support both Deferred-returning and non-Deferred-returning
# tests.
d = maybeDeferred(run, self)
# When the test method Deferred fires, the RUN_TEST action is
# done. However, we won't have re-published the MemoryLogger
# messages into the global/default logger when this Deferred
@ -95,7 +97,114 @@ def with_eliot(f):
# happened. Record the action so we can do that.
storage.action = action
# Support both Deferred-returning and non-Deferred-returning
# tests.
d = maybeDeferred(run, self)
# Let the test runner do its thing.
return d
return run_and_republish
@contextmanager
def _substitute_stack(substitute, target):
# Save whatever is there to begin with, making a copy ensures we don't get
# affected by any mutations that might happen while the substitute is in
# place.
saved = list(target)
# Put the substitute in place. Preserve the identity of the target for no
# concrete reason but maybe it's a good idea.
target[:] = substitute
try:
# Let some code run.
yield
finally:
# Save whatever substitute state we ended up with back to the
# substitute. Copying again, here.
substitute[:] = list(target)
# Restore the target to its original state. Again, preserving
# identity.
target[:] = saved
def eliot_friendly_generator_function(original):
"""
Decorate a generator function so that the Eliot action context is
preserved across ``yield`` expressions.
"""
@wraps(original)
def wrapper(*a, **kw):
# Keep track of whether the next value to deliver to the generator is
# a non-exception or an exception.
ok = True
# Keep track of the next value to deliver to the generator.
value_in = None
# Start tracking our desired inward-facing action context stack. This
# really wants some more help from Eliot.
from eliot._action import _context
context_in = list(_context._get_stack())
# Create the generator with a call to the generator function. This
# happens with whatever Eliot action context happens to be active,
# which is fine and correct and also irrelevant because no code in the
# generator function can run until we call send or throw on it.
gen = original(*a, **kw)
try:
while True:
try:
# Whichever way we invoke the generator, we will do it
# with the Eliot action context stack we've saved for it.
# Then the context manager will re-save it and restore the
# "outside" stack for us.
with _substitute_stack(context_in, _context._get_stack()):
if ok:
value_out = gen.send(value_in)
else:
value_out = gen.throw(*value_in)
# We have obtained a value from the generator. In
# giving it to us, it has given up control. Note this
# fact here. Importantly, this is within the
# generator's action context so that we get a good
# indication of where the yield occurred.
#
# This might be too noisy, consider dropping it or
# making it optional.
Message.log(message_type=u"yielded")
except StopIteration:
# When the generator raises this, it is signaling
# completion. Leave the loop.
break
else:
try:
# Pass the generator's result along to whoever is
# driving. Capture the result as the next value to
# send inward.
value_in = yield value_out
except:
# Or capture the exception if that's the flavor of the
# next value.
ok = False
value_in = exc_info()
else:
ok = True
except GeneratorExit:
# Is this the right scope for handling this exception? Something
# to check on. Anyhow, if we get it, propagate it inward so the
# generator we're driving knows we're done with it.
gen.close()
return wrapper
def inline_callbacks(original):
"""
Decorate a function like ``inlineCallbacks`` would but in a more
Eliot-friendly way. Use it just like ``inlineCallbacks`` but where you
want Eliot action contexts to Do The Right Thing inside the decorated
function.
"""
return inlineCallbacks(
eliot_friendly_generator_function(original)
)

View File

@ -2,34 +2,356 @@
Tests for ``allmydata.test.eliotutil``.
"""
from pprint import pformat
from eliot import (
Message,
start_action,
)
from eliot.twisted import DeferredContext
from eliot.testing import (
capture_logging,
assertHasAction,
assertContainsFields,
)
from twisted.trial.unittest import TestCase
from twisted.internet.defer import succeed
from twisted.internet.defer import (
Deferred,
succeed,
)
from twisted.internet.task import deferLater
from twisted.internet import reactor
from .eliotutil import with_eliot
from .eliotutil import (
eliot_logged_test,
eliot_friendly_generator_function,
inline_callbacks,
)
class WithEliotTests(TestCase):
@with_eliot
class EliotLoggedTestTests(TestCase):
@eliot_logged_test
def test_returns_none(self):
Message.log(hello="world")
@with_eliot
@eliot_logged_test
def test_returns_fired_deferred(self):
Message.log(hello="world")
return succeed(None)
@with_eliot
@eliot_logged_test
def test_returns_unfired_deferred(self):
Message.log(hello="world")
# @with_eliot automatically gives us an action context but it's still
# our responsibility to maintain it across stack-busting operations.
# @eliot_logged_test automatically gives us an action context but it's
# still our responsibility to maintain it across stack-busting
# operations.
d = DeferredContext(deferLater(reactor, 0.0, lambda: None))
d.addCallback(lambda ignored: Message.log(goodbye="world"))
# We didn't start an action. We're not finishing an action.
return d.result
def assert_logged_messages_contain_fields(testcase, logged_messages, expected_fields):
testcase.assertEqual(len(logged_messages), len(expected_fields))
actual_fields = list(
{key: msg.message[key] for key in expected if key in msg.message}
for (msg, expected)
in zip(logged_messages, expected_fields)
)
testcase.assertEqual(actual_fields, expected_fields)
def assert_logged_action_contains_messages(testcase, logger, expected_action, expected_fields):
action = assertHasAction(
testcase,
logger,
expected_action,
True,
)
assert_logged_messages_contain_fields(
testcase,
action.children,
expected_fields,
)
def assert_expected_action_tree(testcase, logger, expected_action_type, expected_type_tree):
logged_action = assertHasAction(
testcase,
logger,
expected_action_type,
True,
)
type_tree = logged_action.type_tree()
testcase.assertEqual(
{expected_action_type: expected_type_tree},
type_tree,
"Logger had messages:\n{}".format(pformat(logger.messages, indent=4)),
)
def assert_generator_logs_action_tree(testcase, generator_function, logger, expected_action_type, expected_type_tree):
list(eliot_friendly_generator_function(generator_function)())
assert_expected_action_tree(
testcase,
logger,
expected_action_type,
expected_type_tree,
)
class EliotFriendlyGeneratorFunctionTests(TestCase):
# Get our custom assertion failure messages *and* the standard ones.
longMessage = True
@capture_logging(None)
def test_yield_none(self, logger):
@eliot_friendly_generator_function
def g():
Message.log(message_type=u"hello")
yield
Message.log(message_type=u"goodbye")
with start_action(action_type=u"the-action"):
list(g())
assert_expected_action_tree(
self,
logger,
u"the-action",
[u"hello", u"yielded", u"goodbye"],
)
@capture_logging(None)
def test_yield_value(self, logger):
expected = object()
@eliot_friendly_generator_function
def g():
Message.log(message_type=u"hello")
yield expected
Message.log(message_type=u"goodbye")
with start_action(action_type=u"the-action"):
self.assertEqual([expected], list(g()))
assert_expected_action_tree(
self,
logger,
u"the-action",
[u"hello", u"yielded", u"goodbye"],
)
@capture_logging(None)
def test_yield_inside_another_action(self, logger):
@eliot_friendly_generator_function
def g():
Message.log(message_type=u"a")
with start_action(action_type=u"confounding-factor"):
Message.log(message_type=u"b")
yield None
Message.log(message_type=u"c")
Message.log(message_type=u"d")
with start_action(action_type=u"the-action"):
list(g())
assert_expected_action_tree(
self,
logger,
u"the-action",
[u"a",
{u"confounding-factor": [u"b", u"yielded", u"c"]},
u"d",
],
)
@capture_logging(None)
def test_yield_inside_nested_actions(self, logger):
@eliot_friendly_generator_function
def g():
Message.log(message_type=u"a")
with start_action(action_type=u"confounding-factor"):
Message.log(message_type=u"b")
yield None
with start_action(action_type=u"double-confounding-factor"):
yield None
Message.log(message_type=u"c")
Message.log(message_type=u"d")
Message.log(message_type=u"e")
with start_action(action_type=u"the-action"):
list(g())
assert_expected_action_tree(
self,
logger,
u"the-action", [
u"a",
{u"confounding-factor": [
u"b",
u"yielded",
{u"double-confounding-factor": [
u"yielded",
u"c",
]},
u"d",
]},
u"e",
],
)
@capture_logging(None)
def test_generator_and_non_generator(self, logger):
@eliot_friendly_generator_function
def g():
Message.log(message_type=u"a")
yield
with start_action(action_type=u"action-a"):
Message.log(message_type=u"b")
yield
Message.log(message_type=u"c")
Message.log(message_type=u"d")
yield
with start_action(action_type=u"the-action"):
generator = g()
next(generator)
Message.log(message_type=u"0")
next(generator)
Message.log(message_type=u"1")
next(generator)
Message.log(message_type=u"2")
self.assertRaises(StopIteration, lambda: next(generator))
assert_expected_action_tree(
self,
logger,
u"the-action", [
u"a",
u"yielded",
u"0",
{
u"action-a": [
u"b",
u"yielded",
u"c",
],
},
u"1",
u"d",
u"yielded",
u"2",
],
)
@capture_logging(None)
def test_concurrent_generators(self, logger):
@eliot_friendly_generator_function
def g(which):
Message.log(message_type=u"{}-a".format(which))
with start_action(action_type=which):
Message.log(message_type=u"{}-b".format(which))
yield
Message.log(message_type=u"{}-c".format(which))
Message.log(message_type=u"{}-d".format(which))
gens = [g(u"1"), g(u"2")]
with start_action(action_type=u"the-action"):
while gens:
for g in gens[:]:
try:
next(g)
except StopIteration:
gens.remove(g)
assert_expected_action_tree(
self,
logger,
u"the-action", [
u"1-a",
{u"1": [
u"1-b",
u"yielded",
u"1-c",
]},
u"2-a",
{u"2": [
u"2-b",
u"yielded",
u"2-c",
]},
u"1-d",
u"2-d",
],
)
class InlineCallbacksTests(TestCase):
# Get our custom assertion failure messages *and* the standard ones.
longMessage = True
def _a_b_test(self, logger, g):
with start_action(action_type=u"the-action"):
self.assertIs(
None,
self.successResultOf(g()),
)
assert_expected_action_tree(
self,
logger,
u"the-action", [
u"a",
u"yielded",
u"b",
],
)
@capture_logging(None)
def test_yield_none(self, logger):
@inline_callbacks
def g():
Message.log(message_type=u"a")
yield
Message.log(message_type=u"b")
self._a_b_test(logger, g)
@capture_logging(None)
def test_yield_fired_deferred(self, logger):
@inline_callbacks
def g():
Message.log(message_type=u"a")
yield succeed(None)
Message.log(message_type=u"b")
self._a_b_test(logger, g)
@capture_logging(None)
def test_yield_unfired_deferred(self, logger):
waiting = Deferred()
@inline_callbacks
def g():
Message.log(message_type=u"a")
yield waiting
Message.log(message_type=u"b")
with start_action(action_type=u"the-action"):
d = g()
self.assertNoResult(waiting)
waiting.callback(None)
self.assertIs(
None,
self.successResultOf(d),
)
assert_expected_action_tree(
self,
logger,
u"the-action", [
u"a",
u"yielded",
u"b",
],
)