Tornado: http_server.start multiple instance fails in python3.5

[chrjxj]

the very basic multi instances code fails on python 3.5 env. It works with python2.7 and 3.6.4.

Python 3.5.2

tornado                5.0.1
Flask                  0.12.2
Flask-Cors             3.0.3
gevent                 1.2.2
greenlet               0.4.13
gunicorn               19.7.1
lxml                   4.2.0

from flask import Flask, request, jsonify
from flask_cors import CORS, cross_origin
from tornado.wsgi import WSGIContainer
from tornado.httpserver import HTTPServer
from tornado.ioloop import IOLoop

app = Flask(__name__)
PROD = True
CORS(app)


@app.route('/api/check/alive', methods=['GET'])
def handle_api_alive():
    resp = jsonify(dict(status="OK"))

    return resp


if __name__ == '__main__':
    # start HTTP server
    http_server = HTTPServer(WSGIContainer(app))
    http_server.bind(9999)
    http_server.start(num_processes=2)
    IOLoop.instance().start()

[chrjxj]

part of error log:

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "test_server.py", line 32, in <module>
    http_server.start(num_processes=2)
  File "/home/jin/pyenv/py3DL/lib/python3.5/site-packages/tornado/tcpserver.py", line 223, in start
    self.add_sockets(sockets)
  File "/home/jin/pyenv/py3DL/lib/python3.5/site-packages/tornado/tcpserver.py", line 159, in add_sockets
    sock, self._handle_connection)
  File "/home/jin/pyenv/py3DL/lib/python3.5/site-packages/tornado/netutil.py", line 258, in add_accept_handler
    io_loop.add_handler(sock, accept_handler, IOLoop.READ)
  File "/home/jin/pyenv/py3DL/lib/python3.5/site-packages/tornado/platform/asyncio.py", line 60, in add_handler
    fd, self._handle_events, fd, IOLoop.READ)
  File "/usr/lib/python3.5/asyncio/selector_events.py", line 237, in add_reader
    (handle, None))
  File "/usr/lib/python3.5/selectors.py", line 411, in register
    self._epoll.register(key.fd, epoll_events)
FileExistsError: [Errno 17] File exists
child 1 (pid 23316) exited with status 1, restarting
Traceback (most recent call last):
  File "/usr/lib/python3.5/asyncio/selector_events.py", line 234, in add_reader
    key = self._selector.get_key(fd)
  File "/usr/lib/python3.5/selectors.py", line 191, in get_key
    raise KeyError("{!r} is not registered".format(fileobj)) from None
KeyError: '6 is not registered'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "test_server.py", line 32, in <module>
    http_server.start(num_processes=2)
  File "/home/jin/pyenv/py3DL/lib/python3.5/site-packages/tornado/tcpserver.py", line 223, in start
    self.add_sockets(sockets)
  File "/home/jin/pyenv/py3DL/lib/python3.5/site-packages/tornado/tcpserver.py", line 159, in add_sockets
    sock, self._handle_connection)
  File "/home/jin/pyenv/py3DL/lib/python3.5/site-packages/tornado/netutil.py", line 258, in add_accept_handler
    io_loop.add_handler(sock, accept_handler, IOLoop.READ)
  File "/home/jin/pyenv/py3DL/lib/python3.5/site-packages/tornado/platform/asyncio.py", line 60, in add_handler
    fd, self._handle_events, fd, IOLoop.READ)
  File "/usr/lib/python3.5/asyncio/selector_events.py", line 237, in add_reader
    (handle, None))
  File "/usr/lib/python3.5/selectors.py", line 411, in register
    self._epoll.register(key.fd, epoll_events)
FileExistsError: [Errno 17] File exists
child 1 (pid 23317) exited with status 1, restarting
Traceback (most recent call last):
  File "/usr/lib/python3.5/asyncio/selector_events.py", line 234, in add_reader
    key = self._selector.get_key(fd)
  File "/usr/lib/python3.5/selectors.py", line 191, in get_key
    raise KeyError("{!r} is not registered".format(fileobj)) from None
KeyError: '6 is not registered'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "test_server.py", line 32, in <module>
    http_server.start(num_processes=2)
  File "/home/jin/pyenv/py3DL/lib/python3.5/site-packages/tornado/tcpserver.py", line 223, in start
    self.add_sockets(sockets)
  File "/home/jin/pyenv/py3DL/lib/python3.5/site-packages/tornado/tcpserver.py", line 159, in add_sockets
    sock, self._handle_connection)
  File "/home/jin/pyenv/py3DL/lib/python3.5/site-packages/tornado/netutil.py", line 258, in add_accept_handler
    io_loop.add_handler(sock, accept_handler, IOLoop.READ)
  File "/home/jin/pyenv/py3DL/lib/python3.5/site-packages/tornado/platform/asyncio.py", line 60, in add_handler
    fd, self._handle_events, fd, IOLoop.READ)
  File "/usr/lib/python3.5/asyncio/selector_events.py", line 237, in add_reader
    (handle, None))
  File "/usr/lib/python3.5/selectors.py", line 411, in register
    self._epoll.register(key.fd, epoll_events)
FileExistsError: [Errno 17] File exists
child 1 (pid 23318) exited with status 1, restarting
Traceback (most recent call last):
  File "/usr/lib/python3.5/asyncio/selector_events.py", line 234, in add_reader
    key = self._selector.get_key(fd)
  File "/usr/lib/python3.5/selectors.py", line 191, in get_key
    raise KeyError("{!r} is not registered".format(fileobj)) from None
KeyError: '6 is not registered'

During handling of the above exception, another exception occurred:

[chrjxj]

more specifically, the example code works under the following env:

flask==0.12.2
flask-cors==3.0.3
tornado==4.5.3

[MioYvo]

Same problem here, using Tornado’s web framework and HTTP server, tornado==5.0.2 and Python 3.6.4

def start_application(app, loop, port):
    """Start a tornado application."""
    parse_command_line()
    _app = app()
    _server = HTTPServer(_app)
    _server.bind(port)
    _server.start(2)

    logging.info(f"Running on port {port}")

    tornado.ioloop.IOLoop.current().start()

[I 180620 15:40:08 process:128] Starting 2 processes
Traceback (most recent call last):
  File "/Library/Frameworks/Python.framework/Versions/3.6/lib/python3.6/asyncio/selector_events.py", line 264, in _add_reader
Traceback (most recent call last):
  File "/Library/Frameworks/Python.framework/Versions/3.6/lib/python3.6/asyncio/selector_events.py", line 264, in _add_reader
    key = self._selector.get_key(fd)
    key = self._selector.get_key(fd)
  File "/Library/Frameworks/Python.framework/Versions/3.6/lib/python3.6/selectors.py", line 191, in get_key
  File "/Library/Frameworks/Python.framework/Versions/3.6/lib/python3.6/selectors.py", line 191, in get_key
    raise KeyError("{!r} is not registered".format(fileobj)) from None
    raise KeyError("{!r} is not registered".format(fileobj)) from None
KeyError: '8 is not registered'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/mio/Work/h3c/face_service/web/app.py", line 35, in <module>
KeyError: '8 is not registered'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/mio/Work/h3c/face_service/web/app.py", line 35, in <module>
    run()
  File "/Users/mio/Work/h3c/face_service/web/app.py", line 31, in run
    run()
  File "/Users/mio/Work/h3c/face_service/web/app.py", line 31, in run
    start_application(Configurer, loop, port=APP_PORT)
  File "/Users/mio/Work/h3c/face_service/web/utils/helpers.py", line 41, in start_application
    start_application(Configurer, loop, port=APP_PORT)
  File "/Users/mio/Work/h3c/face_service/web/utils/helpers.py", line 41, in start_application
    _server.start(2)
  File "/Users/mio/Work/h3c/face_service/env/lib/python3.6/site-packages/tornado/tcpserver.py", line 223, in start
    _server.start(2)
  File "/Users/mio/Work/h3c/face_service/env/lib/python3.6/site-packages/tornado/tcpserver.py", line 223, in start
    self.add_sockets(sockets)
    self.add_sockets(sockets)
  File "/Users/mio/Work/h3c/face_service/env/lib/python3.6/site-packages/tornado/tcpserver.py", line 159, in add_sockets
  File "/Users/mio/Work/h3c/face_service/env/lib/python3.6/site-packages/tornado/tcpserver.py", line 159, in add_sockets
    sock, self._handle_connection)
  File "/Users/mio/Work/h3c/face_service/env/lib/python3.6/site-packages/tornado/netutil.py", line 258, in add_accept_handler
    sock, self._handle_connection)
  File "/Users/mio/Work/h3c/face_service/env/lib/python3.6/site-packages/tornado/netutil.py", line 258, in add_accept_handler
    io_loop.add_handler(sock, accept_handler, IOLoop.READ)
  File "/Users/mio/Work/h3c/face_service/env/lib/python3.6/site-packages/tornado/platform/asyncio.py", line 75, in add_handler
    io_loop.add_handler(sock, accept_handler, IOLoop.READ)
  File "/Users/mio/Work/h3c/face_service/env/lib/python3.6/site-packages/tornado/platform/asyncio.py", line 75, in add_handler
    fd, self._handle_events, fd, IOLoop.READ)
    fd, self._handle_events, fd, IOLoop.READ)
  File "/Library/Frameworks/Python.framework/Versions/3.6/lib/python3.6/asyncio/selector_events.py", line 337, in add_reader
  File "/Library/Frameworks/Python.framework/Versions/3.6/lib/python3.6/asyncio/selector_events.py", line 337, in add_reader
    return self._add_reader(fd, callback, *args)
  File "/Library/Frameworks/Python.framework/Versions/3.6/lib/python3.6/asyncio/selector_events.py", line 267, in _add_reader
    return self._add_reader(fd, callback, *args)
  File "/Library/Frameworks/Python.framework/Versions/3.6/lib/python3.6/asyncio/selector_events.py", line 267, in _add_reader
    (handle, None))
  File "/Library/Frameworks/Python.framework/Versions/3.6/lib/python3.6/selectors.py", line 541, in register
    (handle, None))
  File "/Library/Frameworks/Python.framework/Versions/3.6/lib/python3.6/selectors.py", line 541, in register
    self._kqueue.control([kev], 0, 0)
OSError: [Errno 9] Bad file descriptor
    self._kqueue.control([kev], 0, 0)
OSError: [Errno 9] Bad file descriptor
[W 180620 15:40:09 process:163] child 1 (pid 3255) exited with status 1, restarting

[ajayuranakar]

I think the issue in these line of code:

http_server.bind(9999)
http_server.start(num_processes=2)

Both the process you create are binding on the same port.

http_server.listen(9999)
http_server.start(num_processes=2)

[MioYvo]

@ajayuranakar http://www.tornadoweb.org/en/stable/guide/running.html#processes-and-ports

def main():
    app = make_app()
    server = tornado.httpserver.HTTPServer(app)
    server.bind(8888)
    server.start(0)  # forks one process per cpu
    IOLoop.current().start()

BTW, if use listen:

[I 180626 13:38:54 helpers:45] Running on port 8888
    IOLoop.current().start()
  File "/Users/mio/Work/h3c/face_service/env/lib/python3.6/site-packages/tornado/platform/asyncio.py", line 127, in start
    self.asyncio_loop.run_forever()
  File "/Library/Frameworks/Python.framework/Versions/3.6/lib/python3.6/asyncio/base_events.py", line 421, in run_forever
    self._run_once()
  File "/Library/Frameworks/Python.framework/Versions/3.6/lib/python3.6/asyncio/base_events.py", line 1395, in _run_once
    event_list = self._selector.select(timeout)
  File "/Library/Frameworks/Python.framework/Versions/3.6/lib/python3.6/selectors.py", line 577, in select
    kev_list = self._kqueue.control(None, max_ev, timeout)
OSError: [Errno 9] Bad file descriptor
Traceback (most recent call last):
  File "app.py", line 35, in <module>
    run()
  File "app.py", line 31, in run
    start_application(Configurer, loop, port=APP_PORT)
  File "/Users/mio/Work/h3c/face_service/web/utils/helpers.py", line 52, in start_application
    IOLoop.current().start()
  File "/Users/mio/Work/h3c/face_service/env/lib/python3.6/site-packages/tornado/platform/asyncio.py", line 127, in start
    self.asyncio_loop.run_forever()
  File "/Library/Frameworks/Python.framework/Versions/3.6/lib/python3.6/asyncio/base_events.py", line 421, in run_forever
    self._run_once()
  File "/Library/Frameworks/Python.framework/Versions/3.6/lib/python3.6/asyncio/base_events.py", line 1395, in _run_once
    event_list = self._selector.select(timeout)
  File "/Library/Frameworks/Python.framework/Versions/3.6/lib/python3.6/selectors.py", line 577, in select
    kev_list = self._kqueue.control(None, max_ev, timeout)
OSError: [Errno 9] Bad file descriptor
[W 180626 13:38:54 process:163] child 1 (pid 5396) exited with status 1, restarting
[W 180626 13:38:54 process:163] child 0 (pid 5395) exited with status 1, restarting

[MioYvo]

@ajayuranakar on Linux, listen works, i tried on my centos7 server and debian docker container on macOS ; on macOS(10.13.5), listen don't work.

Thank you for your help.

[ploxiln]

The original bind() way is pretty much as is suggested in the docs. I think this is a tricky low-level macOS kqueue related bug.

[chrjxj]

actually I tried above in ubuntu 16.04, not mac OS

[MioYvo]

@chrjxj yeah, the problem is that the bind() way which is suggested in the docs does not work on Linux or macOS; the listen way works on Linux, does not work on macOS.

[bdarnell]

This is a result of the move to asyncio. asyncio is not as multiprocess-friendly as the old Tornado implementation was. I highly recommend using a process manager like supervisord and a separate load balancer instead of Tornado's multi-process mode.

If you want to continue using Tornado's multi-process mode, you must be very careful not to do anything that might initialize the IOLoop before the fork. In particular, this may mean using the "advanced" multi-process instructions so that the only thing that happens before the fork is tornado.netutil.bind_sockets.

It may not be possible to use the non-advanced versions of multi-process mode any more in Python 3. If so, maybe these modes should be removed in Tornado 6.0.

[bdarnell]

I see what happened, at least in @chrjxj 's case. In Tornado 5.0, simply importing tornado.wsgi is enough to initialize the IOLoop and break bind/start.

@MioYvo, I'm not sure if you're seeing the same thing. If you're seeing this error without importing tornado.wsgi, you're probably doing something else that initializes the IOLoop too soon. The most common things that do this are creating an Application with debug=True and creating an AsyncHTTPClient. This is not allowed in older versions of Tornado either, although the move to asyncio in Tornado 5.0 has made it harder to give good error messages.

[MioYvo]

@bdarnell Thanks for helping. As you said, yes I created an unused IOLoop instance using unused = IOLoop.current(), and an Application with debug=True.

In the source code about Application.__init__, debug=True will set autoreload=True if you don't set autoreload=False in the application kwargs. And the autoreload=True call tornado.autoreload.start(), this method initializes the IOLoop as you said "too soon".

So I remove the unused IOLoop instance, and create an Application with debug=True and autoreload=False, it works fine. I've used nginx and docker for load balancing even though it's a bit more complicated than this multi-process mode.

[yannvr]

So autoreload cannot be used with mullti process? Is that a bug or should the server start not ignore this option if it's not supported? Can it be supported?

[mivade]

It is documented that autoreload is not compatible with multiple processes. That's probably a good thing since during development you typically do not need more than a single process and autoreload is a debugging feature that is best not to use in production.

[bdarnell]

It would be a lot of work to support autoreload with multiple processes. It would be nice to at least give an error if you try to combine the two modes but even that is a little tricky because there are so many permutations (sometimes you create the app first, sometimes you fork first).

I do not expect to invest any time into improving multiprocess mode. Now that we have SO_REUSEPORT I think I'd recommend that over multiprocess mode in all cases.