Repository: tornadoweb/tornado

Issue:
Runner objects can get GCed unexpectedly
Hi,

This is probably a little unusual and I am not sure I understand the whole object graph, but I believe I have reduced my production issue to this test case.

If a coroutine is waiting on a future, and the only hard references to that future are entirely inside the body of the inner generator of the coroutine, a garbage collection run can sweep away the in-progress coroutine and its runner object, leave the coroutine's future unresolved forever, and in some cases leave the application in a stuck state.

Ran on Python 3.4 with Tornado 4.3.

```python
from tornado.ioloop import IOLoop
from tornado.gen import Future, coroutine
import weakref
import gc

wr_fut = None

def count_runners():
    runners = len([
        x for x in gc.get_objects()
        if x.__class__.__name__ == "Runner"
    ])
    print("There are",runners,"Runners")

def resolve_fut():
    count_runners()
    gc.collect(2)
    count_runners()
    fut = wr_fut()
    if not fut:
        print('failure! The app is going to hang forever now')
    else:
        fut.set_result(1)

@coroutine
def main():
    global wr_fut
    my_fut = Future()
    wr_fut = weakref.ref(my_fut)
    IOLoop.current().add_callback(resolve_fut)
    yield my_fut
    print('success!')

IOLoop.current().run_sync(main)
```
This program hangs forever despite using run_sync. That's because the future returned by the coroutine in main() still exists, it just no longer has a Runner object to actually make the future do anything useful. This is _very_ surprising behavior. I would expect the generator/coroutine/Runner/frame objects to be alive for as long as {{run_sync}} is waiting.

Also, note that explicit call to ```gc.collect(2)``` ; this bug actually requires the garbage collector to run for the bug to trigger, which made this bug *very* difficult to track down.

I have managed hack tornado into making it so that the Runner cannot die while its Future is alive which causes my test case to work:

```python
# gen.py line 1241 tornado 4.3
                except (StopIteration, Return) as e:
                    future.set_result(_value_from_stopiteration(e))
                except Exception:
                    future.set_exc_info(sys.exc_info())
                else:
                    # this is the original code below:
                    #Runner(result, future, yielded)
                    # this hack makes the Runner not die and my test case work
                    future._the_runner = Runner(result, future, yielded)
                try:
                    return future
```

So the real-world scenario: I have a proprietary networking library that is using weakrefs for event callbacks and a wrapper library that converts these events into futures. Because I have gone out of my way to avoid creating garbage collection cycles (so that my network client can be GCed when it is no longer in use, unlike a lot of async clients available to tornado), it appears I have discovered this issue.

What is the most appropriate bugfix for this? I personally feel that Runner objects should have their lifecycle tied directly to the future they're driving so that Runners cannot die while their future is alive. However, an argument could also be made that Runner should have a `__del__` method that marks the future as canceled (or `.set_exception(RuntimeError("GCed"))`) instead so that developers can more clearly see that they hit this failure mode.

Please don't tell me the answer is "don't use weakrefs"! I believe it may be possible to create a test case that presents the same problem without using weakrefs but it would have to abuse certain behaviors of sockets, filenos and IOLoop's fd handlers to more closely emulate the actual workings of my network library.

Discussion:
AaronOpfer: Looks like my `__del__` method has some problems, I'll fix them.
AaronOpfer: It looks like implementing the `__del__` method broke various unit tests which expected no consequences of letting half-finished coroutines get garbage collected. These test cases pass but log errors about uncaught future exceptions, failing the overall test. I fixed one instance of this in `queues_test.py` locally but there seems to be many more instances where this can occur.

I can continue to clean up instances like these but first I'd like a Tornado developer to tell me if I'm on the right path with this or if I should just leave the `__del__` change out and quit while I'm ahead.
bdarnell: >  It is difficult to imagine a situation where Runners being garbage collected before the future has a result being a desired behavior, though.

It doesn't make sense for the `Runner` to be collected *before* the `Future`, but they could be collected at the same time. I think that's what's happening in the tests. I think this is legitimate and we want to allow it. Besides, after the first change to use the `WeakKeyDictionary`, what other scenarios would this destructor be guarding against? I'd just get rid of it.

I think I'd make the `WeakKeyDictionary` a global. I'm not seeing any benefit to giving each coroutine function its own dict (which could possibly go out of scope if the decorated function does. 

I'm concerned about the performance impact of a `WeakKeyDictionary` - will it increase GC overhead? I'd like to see some benchmarks showing no significant impact before merging this. 
AaronOpfer: I agree with your points. I'll remove the `__del__` method and make the `WeakKeyDictionary` a global.

I agree that we should test the performance. Does Tornado have any existing performance benchmarking suites we can use for testing performance after my changes?
bdarnell: We don't have great benchmarks. What we do have is in `demos/benchmark/benchmark.py` (and a few other scripts, but benchmark.py is the main one). It should be enough to show the impact of this change. Run it with `--keepalive` since that removes some of the networking overhead. 

    demos/benchmark/benchmark.py --keepalive --quiet --num_runs=5|grep "Requests per second"
AaronOpfer: I ran the performance benchmarks and I saw no differences between my implementation and the previous implementation. The tests were highly variable, I ran each multiple times and they would vary between 1100 req/sec and 1600 req/sec.
AaronOpfer: I believe this changeset addresses all of your concerns @bdarnell , let me know if you'd like to see any other adjustments.

Patch:
diff --git a/.travis.yml b/.travis.yml
index 7d6b79a5..16f61830 100644
--- a/.travis.yml
+++ b/.travis.yml
@@ -30,13 +30,9 @@ install:
     - curl-config --version; pip freeze
 
 script:
-    # Run the tests once from the source directory to detect issues
-    # involving relative __file__ paths; see
-    # https://github.com/tornadoweb/tornado/issues/1780
-    - unset TORNADO_EXTENSION && python -m tornado.test
-    # For all other test variants, get out of the source directory before
-    # running tests to ensure that we get the installed speedups module
-    # instead of the source directory which doesn't have it.
+    # Get out of the source directory before running tests to avoid PYTHONPATH
+    # confusion.  This is necessary to ensure that the speedups module can
+    # be found in the installation directory.
     - cd maint
     # Copy the coveragerc down so coverage.py can find it.
     - cp ../.coveragerc .
diff --git a/demos/chat/static/chat.js b/demos/chat/static/chat.js
index 151a5880..0054c710 100644
--- a/demos/chat/static/chat.js
+++ b/demos/chat/static/chat.js
@@ -16,16 +16,15 @@ $(document).ready(function() {
     if (!window.console) window.console = {};
     if (!window.console.log) window.console.log = function() {};
 
-    $("#messageform").on("submit", function() {
+    $("#messageform").live("submit", function() {
         newMessage($(this));
         return false;
     });
-    $("#messageform").on("keypress", function(e) {
+    $("#messageform").live("keypress", function(e) {
         if (e.keyCode == 13) {
             newMessage($(this));
             return false;
         }
-        return true;
     });
     $("#message").select();
     updater.poll();
@@ -57,13 +56,13 @@ jQuery.postJSON = function(url, args, callback) {
             success: function(response) {
         if (callback) callback(eval("(" + response + ")"));
     }, error: function(response) {
-        console.log("ERROR:", response);
+        console.log("ERROR:", response)
     }});
 };
 
 jQuery.fn.formToDict = function() {
     var fields = this.serializeArray();
-    var json = {};
+    var json = {}
     for (var i = 0; i < fields.length; i++) {
         json[fields[i].name] = fields[i].value;
     }
diff --git a/demos/chat/templates/index.html b/demos/chat/templates/index.html
index 58433b44..8916c350 100644
--- a/demos/chat/templates/index.html
+++ b/demos/chat/templates/index.html
@@ -16,7 +16,7 @@
         <form action="/a/message/new" method="post" id="messageform">
           <table>
             <tr>
-              <td><input type="text" name="body" id="message" style="width:500px"></td>
+              <td><input name="body" id="message" style="width:500px"></td>
               <td style="padding-left:5px">
                 <input type="submit" value="{{ _("Post") }}">
                 <input type="hidden" name="next" value="{{ request.path }}">
@@ -27,7 +27,7 @@
         </form>
       </div>
     </div>
-    <script src="https://ajax.googleapis.com/ajax/libs/jquery/3.1.0/jquery.min.js" type="text/javascript"></script>
+    <script src="http://ajax.googleapis.com/ajax/libs/jquery/1.3/jquery.min.js" type="text/javascript"></script>
     <script src="{{ static_url("chat.js") }}" type="text/javascript"></script>
   </body>
 </html>
diff --git a/demos/tcpecho/README.md b/demos/tcpecho/README.md
deleted file mode 100644
index 60d0b70c..00000000
--- a/demos/tcpecho/README.md
+++ /dev/null
@@ -1,30 +0,0 @@
-TCP echo demo
-=============
-
-This demo shows how to use Tornado's asynchronous TCP client and
-server by implementing `handle_stream` as a coroutine.
-
-To run the server:
-
-```
-$ python server.py
-```
-
-The client will send the message given with the `--message` option
-(which defaults to "ping"), wait for a response, then quit. To run:
-
-```
-$ python client.py --message="your message here"
-```
-
-Alternatively, you can interactively send messages to the echo server
-with a telnet client. For example:
-
-```
-$ telnet localhost 9888
-Trying ::1...
-Connected to localhost.
-Escape character is '^]'.
-ping
-ping
-```
diff --git a/demos/tcpecho/client.py b/demos/tcpecho/client.py
deleted file mode 100644
index a369fa47..00000000
--- a/demos/tcpecho/client.py
+++ /dev/null
@@ -1,23 +0,0 @@
-from __future__ import print_function
-from tornado.ioloop import IOLoop
-from tornado import gen
-from tornado.tcpclient import TCPClient
-from tornado.options import options, define
-
-define("host", default="localhost", help="TCP server host")
-define("port", default=9888, help="TCP port to connect to")
-define("message", default="ping", help="Message to send")
-
-
-@gen.coroutine
-def send_message():
-    stream = yield TCPClient().connect(options.host, options.port)
-    yield stream.write((options.message + "\n").encode())
-    print("Sent to server:", options.message)
-    reply = yield stream.read_until(b"\n")
-    print("Response from server:", reply.decode().strip())
-
-
-if __name__ == "__main__":
-    options.parse_command_line()
-    IOLoop.current().run_sync(send_message)
diff --git a/demos/tcpecho/server.py b/demos/tcpecho/server.py
deleted file mode 100644
index bc0b054a..00000000
--- a/demos/tcpecho/server.py
+++ /dev/null
@@ -1,34 +0,0 @@
-import logging
-from tornado.ioloop import IOLoop
-from tornado import gen
-from tornado.iostream import StreamClosedError
-from tornado.tcpserver import TCPServer
-from tornado.options import options, define
-
-define("port", default=9888, help="TCP port to listen on")
-logger = logging.getLogger(__name__)
-
-
-class EchoServer(TCPServer):
-    @gen.coroutine
-    def handle_stream(self, stream, address):
-        while True:
-            try:
-                data = yield stream.read_until(b"\n")
-                logger.info("Received bytes: %s", data)
-                if not data.endswith(b"\n"):
-                    data = data + b"\n"
-                yield stream.write(data)
-            except StreamClosedError:
-                logger.warning("Lost client at host %s", address[0])
-                break
-            except Exception as e:
-                print(e)
-
-
-if __name__ == "__main__":
-    options.parse_command_line()
-    server = EchoServer()
-    server.listen(options.port)
-    logger.info("Listening on TCP port %d", options.port)
-    IOLoop.current().start()
diff --git a/demos/websocket/static/chat.js b/demos/websocket/static/chat.js
index 4e7ec049..b4bb18a9 100644
--- a/demos/websocket/static/chat.js
+++ b/demos/websocket/static/chat.js
@@ -16,11 +16,11 @@ $(document).ready(function() {
     if (!window.console) window.console = {};
     if (!window.console.log) window.console.log = function() {};
 
-    $("#messageform").on("submit", function() {
+    $("#messageform").live("submit", function() {
         newMessage($(this));
         return false;
     });
-    $("#messageform").on("keypress", function(e) {
+    $("#messageform").live("keypress", function(e) {
         if (e.keyCode == 13) {
             newMessage($(this));
             return false;
diff --git a/demos/websocket/templates/index.html b/demos/websocket/templates/index.html
index 91a45363..cbf2b23d 100644
--- a/demos/websocket/templates/index.html
+++ b/demos/websocket/templates/index.html
@@ -27,7 +27,7 @@
         </form>
       </div>
     </div>
-    <script src="http://ajax.googleapis.com/ajax/libs/jquery/3.1.0/jquery.min.js" type="text/javascript"></script>
+    <script src="http://ajax.googleapis.com/ajax/libs/jquery/1.3/jquery.min.js" type="text/javascript"></script>
     <script src="{{ static_url("chat.js") }}" type="text/javascript"></script>
   </body>
 </html>
diff --git a/docs/releases/v4.1.0.rst b/docs/releases/v4.1.0.rst
index 29ad1914..c38511b8 100644
--- a/docs/releases/v4.1.0.rst
+++ b/docs/releases/v4.1.0.rst
@@ -24,7 +24,7 @@ Backwards-compatibility notes
 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
 
 * `.HTTPServer` now calls ``start_request`` with the correct
-  arguments.  This change is backwards-incompatible, affecting any
+  arguments.  This change is backwards-incompatible, afffecting any
   application which implemented `.HTTPServerConnectionDelegate` by
   following the example of `.Application` instead of the documented
   method signatures.
diff --git a/tornado/gen.py b/tornado/gen.py
index b308ca7d..73f9ba10 100644
--- a/tornado/gen.py
+++ b/tornado/gen.py
@@ -83,6 +83,7 @@ import os
 import sys
 import textwrap
 import types
+import weakref
 
 from tornado.concurrent import Future, TracebackFuture, is_future, chain_future
 from tornado.ioloop import IOLoop
@@ -244,6 +245,24 @@ def coroutine(func, replace_callback=True):
     """
     return _make_coroutine_wrapper(func, replace_callback=True)
 
+# Ties lifetime of runners to their result futures. Github Issue #1769
+# Generators, like any object in Python, must be strong referenced
+# in order to not be cleaned up by the garbage collector. When using
+# coroutines, the Runner object is what strong-refs the inner
+# generator. However, the only item that strong-reffed the Runner
+# was the last Future that the inner generator yielded (via the
+# Future's internal done_callback list). Usually this is enough, but
+# it is also possible for this Future to not have any strong references
+# other than other objects referenced by the Runner object (usually
+# when using other callback patterns and/or weakrefs). In this
+# situation, if a garbage collection ran, a cycle would be detected and
+# Runner objects could be destroyed along with their inner generators
+# and everything in their local scope.
+# This map provides strong references to Runner objects as long as
+# their result future objects also have strong references (typically
+# from the parent coroutine's Runner). This keeps the coroutine's
+# Runner alive.
+_futures_to_runners = weakref.WeakKeyDictionary()
 
 def _make_coroutine_wrapper(func, replace_callback):
     """The inner workings of ``@gen.coroutine`` and ``@gen.engine``.
@@ -294,7 +313,7 @@ def _make_coroutine_wrapper(func, replace_callback):
                 except Exception:
                     future.set_exc_info(sys.exc_info())
                 else:
-                    Runner(result, future, yielded)
+                    _futures_to_runners[future] = Runner(result, future, yielded)
                 try:
                     return future
                 finally:
diff --git a/tornado/platform/asyncio.py b/tornado/platform/asyncio.py
index 9556da61..3fd67dbd 100644
--- a/tornado/platform/asyncio.py
+++ b/tornado/platform/asyncio.py
@@ -14,9 +14,9 @@ loops.
 
 .. note::
 
-   Tornado requires the `~asyncio.AbstractEventLoop.add_reader` family of
-   methods, so it is not compatible with the `~asyncio.ProactorEventLoop` on
-   Windows. Use the `~asyncio.SelectorEventLoop` instead.
+   Tornado requires the `~asyncio.BaseEventLoop.add_reader` family of methods,
+   so it is not compatible with the `~asyncio.ProactorEventLoop` on Windows.
+   Use the `~asyncio.SelectorEventLoop` instead.
 """
 
 from __future__ import absolute_import, division, print_function, with_statement
diff --git a/tornado/tcpserver.py b/tornado/tcpserver.py
index 54837f7a..0839d392 100644
--- a/tornado/tcpserver.py
+++ b/tornado/tcpserver.py
@@ -39,21 +39,7 @@ class TCPServer(object):
     r"""A non-blocking, single-threaded TCP server.
 
     To use `TCPServer`, define a subclass which overrides the `handle_stream`
-    method. For example, a simple echo server could be defined like this::
-
-      from tornado.tcpserver import TCPServer
-      from tornado.iostream import StreamClosedError
-      from tornado import gen
-
-      class EchoServer(TCPServer):
-          @gen.coroutine
-          def handle_stream(self, stream, address):
-              while True:
-                  try:
-                      data = yield stream.read_until(b"\n")
-                      yield stream.write(data)
-                  except StreamClosedError:
-                      break
+    method.
 
     To make this server serve SSL traffic, send the ``ssl_options`` keyword
     argument with an `ssl.SSLContext` object. For compatibility with older
diff --git a/tornado/web.py b/tornado/web.py
index 96b204eb..f54c4d03 100644
--- a/tornado/web.py
+++ b/tornado/web.py
@@ -527,7 +527,7 @@ class RequestHandler(object):
 
         Additional keyword arguments are set on the Cookie.Morsel
         directly.
-        See https://docs.python.org/2/library/cookie.html#Cookie.Morsel
+        See http://docs.python.org/library/cookie.html#morsel-objects
         for available attributes.
         """
         # The cookie library only accepts type str, in both python 2 and 3


Test patch:
diff --git a/tornado/test/gen_test.py b/tornado/test/gen_test.py
index 4c873f4b..bfaba567 100644
--- a/tornado/test/gen_test.py
+++ b/tornado/test/gen_test.py
@@ -1,5 +1,6 @@
 from __future__ import absolute_import, division, print_function, with_statement
 
+import gc
 import contextlib
 import datetime
 import functools
@@ -25,7 +26,6 @@ try:
 except ImportError:
     futures = None
 
-
 class GenEngineTest(AsyncTestCase):
     def setUp(self):
         super(GenEngineTest, self).setUp()
@@ -1368,5 +1368,28 @@ class WaitIteratorTest(AsyncTestCase):
                                gen.WaitIterator(gen.sleep(0)).next())
 
 
+class RunnerGCTest(AsyncTestCase):
+    """Github issue 1769: Runner objects can get GCed unexpectedly"""
+    @gen_test
+    def test_gc(self):
+        """Runners shouldn't GC if future is alive"""
+        # Create the weakref
+        weakref_scope = [None]
+        def callback():
+            gc.collect(2)
+            weakref_scope[0]().set_result(123)
+
+        @gen.coroutine
+        def tester():
+            fut = Future()
+            weakref_scope[0] = weakref.ref(fut)
+            self.io_loop.add_callback(callback)
+            yield fut
+
+        yield gen.with_timeout(
+            datetime.timedelta(seconds=0.2),
+            tester()
+        )
+
 if __name__ == '__main__':
     unittest.main()
diff --git a/tornado/test/options_test.py b/tornado/test/options_test.py
index c050cb64..f7b215c5 100644
--- a/tornado/test/options_test.py
+++ b/tornado/test/options_test.py
@@ -36,7 +36,7 @@ class OptionsTest(unittest.TestCase):
         options.define("port", default=80)
         options.define("username", default='foo')
         options.define("my_path")
-        config_path = os.path.join(os.path.dirname(os.path.abspath(__file__)),
+        config_path = os.path.join(os.path.dirname(__file__),
                                    "options_test.cfg")
         options.parse_config_file(config_path)
         self.assertEqual(options.port, 443)