connection.wait_until_ready makes the callback lose StackContext, will cause "Cannot send error response after headers written" issue raised in web.py

[corbieli]

To reproduce the issue, the conditions are:

1. Sharing one connection in an asynchronous request handler
2. Raise a error after call tornado-redis method
3. Send requests concurrently

In this case, the second request or following requests will go into connection.wait_until_ready block and wait the connection to be ready, and then callback to the request handler until the connection is ready. Otherwise, wait_until_ready makes the callback lose StackContext, and the callback is actually invoked in the previous StackContext associate with the previous connection.read() operation. So, when a error raised, the exception handling in web.py will use the previous StackContext associated to process exception, that cause the "Cannot send error response after headers written" issue.

To avoid this issue, quoted from stack_context.py "Returns a callable object that will restore the current StackContext when executed. Use this whenever saving a callback to be executed later in a different execution context (either in a different thread or asynchronously in the same thread)", before append the callback to ready_callbacks, it should be wrapped with stack_context.wrap, such as:

def wait_until_ready(self, callback=None):
    if callback:
        if not self.ready():
            callback = stack_context.wrap(callback) # should wrapped for restore StackContext
            self.ready_callbacks.append(callback)
        else:
            callback()
    return self

It is also for ConnectionPool.

The sample code for reproduce the issue as below:

[Server side]

!/usr/bin/env python

import logging import json

import tornadoredis import tornado.httpserver import tornado.ioloop import tornado.web import tornado.gen as gen from tornado.options import define, options

rds = tornadoredis.Client(host="127.0.0.1", port=6379, selected_db=0)

@gen.engine def get_data(key, callback=None): try: result = yield tornado.gen.Task(rds.get, key) except Exception, e: callback(None) return callback(result)

class TestHandler(tornado.web.RequestHandler):

def initialize(self, **kwargs):
    super(TestHandler, self).initialize(**kwargs)
    self.set_header("Content-Type", "text/json")
    self.set_header("Content-Type", "application/json")

@tornado.web.asynchronous
@gen.engine
def get(self):
    # make sure there is a key 0 in redis
    value = yield gen.Task(get_data, 0)
    raise tornado.web.HTTPError(400, "always return this error")
    self.finish(json.dumps({"key":key}))

handlers = [ tornado.web.URLSpec(r"/test", TestHandler, name="Test"), ]

settings = { "debug": True, }

define("port", default=8888, help="run on the given port", type=int)

if name == "main": application = tornado.web.Application(handlers, **settings) http_server = tornado.httpserver.HTTPServer(application, xheaders=True) http_server.listen(options.port) logging.info('Listening on port %s' % options.port) tornado.ioloop.IOLoop.instance().start()

[Client side]

!/usr/bin/env python

from tornado.httpclient import AsyncHTTPClient from tornado.ioloop import IOLoop

def debug_case: http_client = AsyncHTTPClient()

def handle_request(response):
   # mock up concurrent requests
    http_client.fetch("http://localhost:8888/test",
                      handle_request,
                      method = "GET")
    if response.error:
        print "Error:", response.error
    else:
        print response.body
    IOLoop.instance().stop()

http_client.fetch("http://localhost:8888/test",
                  handle_request,
                  method = "GET")
IOLoop.instance().start()

if name == "main": for i in range(1, 100): debug_case()

[leporo]

Such a great bug report and detailed analysis! Thank you. I'll fix it.

[leporo]

I wrapped callbacks in some of recent library versions. This issue seem to be fixed. I tried running your code and I feel it worked as expected.

I've got these messages on server side:

...
WARNING:tornado.general:400 GET /test (127.0.0.1): always return this error
WARNING:tornado.access:400 GET /test (127.0.0.1) 11.30ms

And these on client side:

Error: HTTP 400: Bad Request
Error: HTTP 400: Bad Request