Merge branch 'master' into 386.pyinstaller

docs/source/generating/actions.rst

@@ -132,6 +132,31 @@ You can add fields to both the start message and the success message of an actio
 If you want to include some extra information in case of failures beyond the exception you can always log a regular message with that information.
 Since the message will be recorded inside the context of the action its information will be clearly tied to the result of the action by the person (or code!) reading the logs later on.
 
+Using Generators
+----------------
+
+Generators (functions with ``yield``) and context managers (``with X:``) don't mix well in Python.
+So if you're going to use ``with start_action()`` in a generator, just make sure it doesn't wrap a ``yield`` and you'll be fine.
+
+Here's what you SHOULD NOT DO:
+
+.. code-block:: python
+
+   def generator():
+       with start_action(action_type="x"):
+           # BAD! DO NOT yield inside a start_action() block:
+           yield make_result()
+
+Here's what can do instead:
+
+.. code-block:: python
+
+   def generator():
+       with start_action(action_type="x"):
+           result = make_result()
+       # This is GOOD, no yield inside the start_action() block:
+       yield result
+
 
 Non-Finishing Contexts
 ----------------------

docs/source/generating/twisted.rst

@@ -63,6 +63,41 @@ Logging Failures
             d.addErrback(writeFailure)
 
 
+Actions and inlineCallbacks
+---------------------------
+
+Eliot provides a decorator that is compatible with Twisted's ``inlineCallbacks`` but which also behaves well with Eliot's actions.
+Simply substitute ``eliot.twisted.inline_callbacks`` for ``twisted.internet.defer.inlineCallbacks`` in your code.
+
+To understand why, consider the following example:
+
+.. code-block:: python
+
+     from eliot import start_action
+     from twisted.internet.defer import inlineCallbacks
+
+     @inlineCallbacks  # don't use this in real code, use eliot.twisted.inline_callbacks
+     def go():
+         with start_action(action_type=u"yourapp:subsystem:frob"):
+	     d = some_deferred_api()
+	     x = yield d
+	     Message.log(message_type=u"some-report", x=x)
+
+The action started by this generator remains active as ``yield d`` gives up control to the ``inlineCallbacks`` controller.
+The next bit of code to run will be considered to be a child of ``action``.
+Since that code may be any arbitrary code that happens to get scheduled,
+this is certainly wrong.
+
+Additionally,
+when the ``inlineCallbacks`` controller resumes the generator,
+it will most likely do so with no active action at all.
+This means that the log message following the yield will be recorded with no parent action,
+also certainly wrong.
+
+These problems are solved by using ``eliot.twisted.inline_callbacks`` instead of ``twisted.internet.defer.inlineCallbacks``.
+The behavior of the two decorators is identical except that Eliot's version will preserve the generator's action context and contain it within the generator.
+This extends the ``inlineCallbacks`` illusion of "synchronous" code to Eliot actions.
+
 Actions and Deferreds
 ---------------------
 

docs/source/news.rst

@@ -6,18 +6,20 @@ What's New
 
 Documentation:
 
-* Eliot has an API for testing your logs were output correctly. Until now, however, the documentation was overly focused on requiring usage of types, which are optional, so it has been rewritten to be more generic: :doc:`read more about the testing API here<generating/testing>`.
+* Eliot has an API for testing that your logs were output correctly. Until now, however, the documentation was overly focused on requiring usage of types, which are optional, so it has been rewritten to be more generic: :doc:`read more about the testing API here<generating/testing>`.
 
 Features:
 
 * Generating messages is much faster.
-* ``eliot.ValidationError``, as raised by e.g. ``capture_logging``, is now part of the public API. Fixed issue #146.
 * Eliot now works with PyInstaller. Thanks to Jean-Paul Calderone for the bug report. Fixes issue #386.
-* ``eliot.twisted.DeferredContext.addCallbacks`` now supports omitting the errback, for compatibility with Twisted's ``Deferred``. Thanks to Jean-Paul Calderone for the fix. Fixed issue #366.
 * The testing infrastructure now has slightly more informative error messages. Thanks to Jean-Paul Calderone for the bug report. Fixes issue #373.
-* ``@validate_logging`` and ``@capture_logging`` now make it clearer what caused validation errors by printing the original traceback. Thanks to Jean-Paul Calderone for the bug report. Fixes issue #365.
 * Added lower-level testing infrastructure—``eliot.testing.swap_logger`` and ``eliot.testing.check_for_errors``—which is useful for cases when the ``@capture_logging`` decorator is insufficient. For example, test methods that are async, or return Twisted ``Deferred``. See the :doc:`testing documentation<generating/testing>` for details. Thanks to Jean-Paul Calderone for the feature request. Fixes #364.
-* The testing API now has slightly more informative error messages. Thanks to Jean-Paul Calderone for the bug report. Fixes issue #373.
+* ``eliot.ValidationError``, as raised by e.g. ``capture_logging``, is now part of the public API. Fixed issue #146.
+
+Twisted-related features:
+
+* New decorator, ``@eliot.twisted.inline_callbacks`` , which is like Twisted's ``inlineCallbacks`` but which also manages the Eliot context. Thanks to Jean-Paul Calderone for the fix. Fixed issue #259.
+* ``eliot.twisted.DeferredContext.addCallbacks`` now supports omitting the errback, for compatibility with Twisted's ``Deferred``. Thanks to Jean-Paul Calderone for the fix. Fixed issue #366.
 
 Bug fixes:
 
@@ -27,6 +29,7 @@ Bug fixes:
   is now thread-safe. Thanks to Jean-Paul Calderone for the patch. Fixes issue
   #382.
 
+
 1.6.0
 ^^^^^
 

eliot/_action.py

@@ -65,7 +65,8 @@ def __init__(self):
 
     def _get_stack(self):
         """
-        Get the stack for the current context.
+        Get the stack for the current thread, or the sub-stack if sub-stacks
+        are enabled.
         """
         stack = self.get_sub_context()
         if stack is None:

eliot/_generators.py

@@ -0,0 +1,177 @@
+"""
+Support for maintaining an action context across generator suspension.
+"""
+
+from __future__ import unicode_literals, absolute_import
+
+from sys import exc_info
+from functools import wraps
+from contextlib import contextmanager
+from weakref import WeakKeyDictionary
+
+from ._action import _context_owner, _ExecutionContext
+from . import Message
+
+
+class _GeneratorContext(object):
+    """Generator sub-context for C{_ExecutionContext}."""
+
+    def __init__(self, execution_context):
+        self._execution_context = execution_context
+        self._contexts = WeakKeyDictionary()
+        self._current_generator = None
+
+    def init_stack(self, generator):
+        """Create a new stack for the given generator."""
+        stack = list(self._execution_context._get_stack())
+        self._contexts[generator] = stack
+
+    def get_stack(self):
+        """Return the sub-stack for the current generator."""
+        if self._current_generator is None:
+            # If there is no currently active generator then we have no
+            # special stack to supply.  Let the execution context figure out a
+            # different answer on its own.
+            return None
+        # Otherwise, give back the action context stack we've been tracking
+        # for the currently active generator.  It must have been previously
+        # initialized (it's too late to do it now)!
+        return self._contexts[self._current_generator]
+
+    @contextmanager
+    def in_generator(self, generator):
+        """Context manager: set the given generator as the current generator."""
+        previous_generator = self._current_generator
+        try:
+            self._current_generator = generator
+            yield
+        finally:
+            self._current_generator = previous_generator
+
+
+class GeneratorExecutionContext(_ExecutionContext):
+    """Generator-specific C{_ExecutionContext} subclass."""
+
+    def __init__(self):
+        """This will run per-thread!"""
+        _ExecutionContext.__init__(self)
+        self.generator_context = _GeneratorContext(self)
+        self.get_sub_context = self.generator_context.get_stack
+
+
+def use_generator_context():
+    """
+    Make L{eliot_friendly_generator_function} work correctly.
+    """
+    _context_owner.set(GeneratorExecutionContext)
+
+
+def _installed():
+    return isinstance(_context_owner.context, GeneratorExecutionContext)
+
+
+class GeneratorSupportNotEnabled(Exception):
+    """
+    An attempt was made to use a decorated generator without first turning on
+    the generator context manager.
+    """
+
+
+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):
+        # This isn't going to work if you don't have the generator context
+        # manager installed.
+        if not _installed():
+            raise GeneratorSupportNotEnabled()
+
+        # 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
+
+        # 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)
+
+        # Initialize the per-generator Eliot action context stack to the
+        # current action stack.  This might be the main stack or, if another
+        # decorated generator is running, it might be the stack for that
+        # generator.  Not our business.
+        generator_context = _context_owner.context.generator_context
+        generator_context.init_stack(gen)
+        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.
+                #
+                # Regarding the support of Twisted's inlineCallbacks-like
+                # functionality (see eliot.twisted.inline_callbacks):
+                #
+                # The invocation may raise the inlineCallbacks internal
+                # control flow exception _DefGen_Return.  It is not wrong to
+                # just let that propagate upwards here but inlineCallbacks
+                # does think it is wrong.  The behavior triggers a
+                # DeprecationWarning to try to get us to fix our code.  We
+                # could explicitly handle and re-raise the _DefGen_Return but
+                # only at the expense of depending on a private Twisted API.
+                # For now, I'm opting to try to encourage Twisted to fix the
+                # situation (or at least not worsen it):
+                # https://twistedmatrix.com/trac/ticket/9590
+                #
+                # Alternatively, _DefGen_Return is only required on Python 2.
+                # When Python 2 support is dropped, this concern can be
+                # eliminated by always using `return value` instead of
+                # `returnValue(value)` (and adding the necessary logic to the
+                # StopIteration handler below).
+                with generator_context.in_generator(gen):
+                    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 is noisy, enable only for debugging:
+                    if wrapper.debug:
+                        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.  This could possibly include GeneratorExit
+                    # which turns out to be just fine because throwing it into
+                    # the inner generator effectively propagates the close
+                    # (and with the right context!) just as you would want.
+                    # True, the GeneratorExit does get re-throwing out of the
+                    # gen.throw call and hits _the_generator_context's
+                    # contextmanager.  But @contextmanager extremely
+                    # conveniently eats it for us!  Thanks, @contextmanager!
+                    ok = False
+                    value_in = exc_info()
+                else:
+                    ok = True
+
+    wrapper.debug = False
+    return wrapper