Repository: tornadoweb/tornado
Pull request #1333 (2015-02-12 04:17:26)

Coroutine exception __context__ leak in python 3
## Background

In Python 3 every exception has an auto-attached `__context__` exception if it was
raised while an existing exception was being handled.  This is often a very
useful property and allows users to see the underlying cause of many problems.

More info about `__context__`: https://www.python.org/dev/peps/pep-3134/

However, when dealing with async code via coroutines this feature can suddenly
become a pretty big issue.  Namely, if you generator.throw back into a coroutine
to raise an exception in the correct scope, and that coroutine raises an
exception at a later time you can have nested exceptions which shouldn't
logically be nested.

This patch resolves this issue in the coroutine code by moving the gen.throw
outside of the exception handler.  By doing this the user-code scope is able to
later raise exceptions without worrying about inheriting prior exception
context.

## Repro

To better understand the problem please play with the following repro.  Without my change, if you run it with python 3 the printed stack will contain a previous iteration's handled exception.  Without inspecting the internals of tornado, this is quite confusing to the end user since their perspective is that they handled the exception.  Once you apply my change the output matches what you expect and we no longer leak exceptions through the `__context__` variable.

```python
#!/usr/bin/env python

import traceback
from tornado import gen
from tornado import ioloop

loop = ioloop.IOLoop.instance()

@gen.coroutine
def test(iteration):
    print("Printing stack inside test for %s" % iteration)
    traceback.print_stack()
    raise Exception(iteration)

@gen.coroutine
def main():
    for i in range(3):
        iteration = "iteration-%d" % i
        print("%s\nStarting %s" % ("-=" * 50, iteration))
        try:
            yield test(iteration)
        except:
            print("Printing exception for %s" % iteration)
            traceback.print_exc()

if __name__ == "__main__":
    loop.run_sync(main)
```

### Notes

 - I could be completely missing something here, and maybe I am just the only person that finds this confusing.  That is fine, just point me in the right direction and I will be on my way
 - I was planning on adding a test to the Tornado test suite, however it seems that it is currently not in a passing state.  At least I couldn't get it to pass on my machine.  I would prefer to understand whether or not my environment is setup correctly for testing Tornado before I build a test that exercises this code.  One thing to note on this: running tests with/without my change are failing for me.  Any tips/tricks on Tornado testing would be appreciated.

Thanks for your time and I hope to get this merged in (or something like it, or just a better understand of the problem) soon.  For now I am going to use my fork of Tornado for the project that crashed due to this "bug" (if it is a bug).

bdarnell: Thanks for the detailed report; your analysis and fix look correct to me. One small change I would make is to set `exc_info = None` after throwing it into the generator to allow the exception (and its traceback) to be freed immediately.

What errors are you seeing when running the tests? I'm not aware of any problems running them (except for the sporadic failures on travis-ci). You can use either `python -m tornado.test` or `tox -e py34` (a full tox run takes a long time). 

Patch:
diff --git a/tornado/gen.py b/tornado/gen.py
index 3d87d717..b405b2f7 100644
--- a/tornado/gen.py
+++ b/tornado/gen.py
@@ -824,13 +824,20 @@ class Runner(object):
                 self.future = None
                 try:
                     orig_stack_contexts = stack_context._state.contexts
+                    exc_info = None
+
                     try:
                         value = future.result()
                     except Exception:
                         self.had_exception = True
-                        yielded = self.gen.throw(*sys.exc_info())
+                        exc_info = sys.exc_info()
+
+                    if exc_info is not None:
+                        yielded = self.gen.throw(*exc_info)
+                        exc_info = None
                     else:
                         yielded = self.gen.send(value)
+
                     if stack_context._state.contexts is not orig_stack_contexts:
                         self.gen.throw(
                             stack_context.StackContextInconsistentError(
diff --git a/tornado/websocket.py b/tornado/websocket.py
index dfde4d1c..b6994942 100644
--- a/tornado/websocket.py
+++ b/tornado/websocket.py
@@ -16,8 +16,7 @@ the protocol (known as "draft 76") and are not compatible with this module.
    Removed support for the draft 76 protocol version.
 """
 
-from __future__ import (absolute_import, division,
-                        print_function, with_statement)
+from __future__ import absolute_import, division, print_function, with_statement
 # Author: Jacob Kristhammar, 2010
 
 import base64
@@ -145,22 +144,16 @@ class WebSocketHandler(tornado.web.RequestHandler):
         # Upgrade header should be present and should be equal to WebSocket
         if self.request.headers.get("Upgrade", "").lower() != 'websocket':
             self.set_status(400)
-            log_msg = "Can \"Upgrade\" only to \"WebSocket\"."
-            self.finish(log_msg)
-            gen_log.debug(log_msg)
+            self.finish("Can \"Upgrade\" only to \"WebSocket\".")
             return
 
-        # Connection header should be upgrade.
-        # Some proxy servers/load balancers
+        # Connection header should be upgrade. Some proxy servers/load balancers
         # might mess with it.
         headers = self.request.headers
-        connection = map(lambda s: s.strip().lower(),
-                         headers.get("Connection", "").split(","))
+        connection = map(lambda s: s.strip().lower(), headers.get("Connection", "").split(","))
         if 'upgrade' not in connection:
             self.set_status(400)
-            log_msg = "\"Connection\" must be \"Upgrade\"."
-            self.finish(log_msg)
-            gen_log.debug(log_msg)
+            self.finish("\"Connection\" must be \"Upgrade\".")
             return
 
         # Handle WebSocket Origin naming convention differences
@@ -177,9 +170,7 @@ class WebSocketHandler(tornado.web.RequestHandler):
         # did not come from a browser and that it can be passed on.
         if origin is not None and not self.check_origin(origin):
             self.set_status(403)
-            log_msg = "Cross origin websockets not allowed"
-            self.finish(log_msg)
-            gen_log.debug(log_msg)
+            self.finish("Cross origin websockets not allowed")
             return
 
         self.stream = self.request.connection.detach()
@@ -520,8 +511,7 @@ class WebSocketProtocol13(WebSocketProtocol):
             self._handle_websocket_headers()
             self._accept_connection()
         except ValueError:
-            gen_log.debug("Malformed WebSocket request received",
-                          exc_info=True)
+            gen_log.debug("Malformed WebSocket request received", exc_info=True)
             self._abort()
             return
 
@@ -557,8 +547,7 @@ class WebSocketProtocol13(WebSocketProtocol):
             selected = self.handler.select_subprotocol(subprotocols)
             if selected:
                 assert selected in subprotocols
-                subprotocol_header = ("Sec-WebSocket-Protocol: %s\r\n"
-                                      % selected)
+                subprotocol_header = "Sec-WebSocket-Protocol: %s\r\n" % selected
 
         extension_header = ''
         extensions = self._parse_extensions_header(self.request.headers)
@@ -726,8 +715,7 @@ class WebSocketProtocol13(WebSocketProtocol):
                 if self._masked_frame:
                     self.stream.read_bytes(4, self._on_masking_key)
                 else:
-                    self.stream.read_bytes(self._frame_length,
-                                           self._on_frame_data)
+                    self.stream.read_bytes(self._frame_length, self._on_frame_data)
             elif payloadlen == 126:
                 self.stream.read_bytes(2, self._on_frame_length_16)
             elif payloadlen == 127:
@@ -761,8 +749,7 @@ class WebSocketProtocol13(WebSocketProtocol):
         self._wire_bytes_in += len(data)
         self._frame_mask = data
         try:
-            self.stream.read_bytes(self._frame_length,
-                                   self._on_masked_frame_data)
+            self.stream.read_bytes(self._frame_length, self._on_masked_frame_data)
         except StreamClosedError:
             self._abort()
 


Test patch:
diff --git a/tornado/test/gen_test.py b/tornado/test/gen_test.py
index 31acadd8..15876d59 100644
--- a/tornado/test/gen_test.py
+++ b/tornado/test/gen_test.py
@@ -844,6 +844,29 @@ class GenCoroutineTest(AsyncTestCase):
         yield gen.sleep(0.01)
         self.finished = True
 
+    @skipBefore33
+    @gen_test
+    def test_py3_leak_exception_context(self):
+        class LeakedException(Exception):
+            pass
+
+        @gen.coroutine
+        def inner(iteration):
+            raise LeakedException(iteration)
+
+        try:
+            yield inner(1)
+        except LeakedException as e:
+            self.assertEqual(str(e), "1")
+            self.assertIsNone(e.__context__)
+
+        try:
+            yield inner(2)
+        except LeakedException as e:
+            self.assertEqual(str(e), "2")
+            self.assertIsNone(e.__context__)
+
+        self.finished = True
 
 class GenSequenceHandler(RequestHandler):
     @asynchronous