workers problem
Closed this issue · 13 comments
wsbmilk commented
if i use custom event loop below:
loop = uvloop.new_event_loop()
and then:
app.run(workers=4, loop=loop)
log will be:
2016-12-21 20:34:56,993: INFO: Spinning up 4 workers...
python: src/unix/linux-core.c:336: uv__io_poll: Assertion `(unsigned) fd < loop->nwatchers' failed.
and actually just 1 cpu core is working...
but when use default loop.
workers=4 will work.
os: ubuntu16.04 x64 and python 3.5.2
why?
edevil commented
I actually have a similar problem and I'm not even changing the event loop. I tried the example from the documentation and set the workers to 4:
from sanic import Sanic
from sanic.response import json
app = Sanic()
@app.route("/")
async def test(request):
return json({"hello": "world"})
if __name__ == "__main__":
app.run(host="0.0.0.0", port=8000, workers=4)
When I start it, it logs that it is spawning 4 workers, which it does:
2016-12-21 14:27:41,936: INFO: Goin' Fast @ http://0.0.0.0:8000
2016-12-21 14:27:41,936: INFO: Spinning up 4 workers...
But when I use wrk specifying 100 connections and 100 threads, still only one of the processes is handling the requests:
~ ps xau |grep sanic
andre 6351 93.6 0.1 2463520 15224 s002 R+ 2:27PM 1:00.47 python hello_sanic.py
andre 6353 0.0 0.1 2463264 8488 s002 S+ 2:27PM 0:00.02 python hello_sanic.py
andre 6352 0.0 0.0 2463264 8336 s002 S+ 2:27PM 0:00.02 python hello_sanic.py
andre 6350 0.0 0.1 2463264 8540 s002 S+ 2:27PM 0:00.02 python hello_sanic.py
andre 6349 0.0 0.1 2431400 17248 s002 S+ 2:27PM 0:00.22 python hello_sanic.py
Sanic version 0.1.8.
wsbmilk commented
here is mine:
code:
from sanic import Sanic
from sanic.response import json
app = Sanic(__name__)
@app.route("/")
async def test(request):
return json({"test": True})
app.run(host="0.0.0.0", port=8000, debug=True, workers=4)
result:
➜ ~ ps aux|grep simple_server.py
troy 20963 0.0 0.2 78908 21272 ? S Dec21 0:00
troy 20964 10.2 0.2 178404 20108 ? Rl Dec21 0:22
troy 20965 10.0 0.2 178408 20008 ? Rl Dec21 0:22
troy 20966 10.0 0.2 178408 20032 ? Rl Dec21 0:21
it worked well.
but when i change it to:
from sanic import Sanic
from sanic.response import json
import asyncio
import uvloop
asyncio.set_event_loop_policy(uvloop.EventLoopPolicy())
loop = asyncio.get_event_loop()
app = Sanic(__name__)
@app.route("/")
async def test(request):
return json({"test": True})
app.run(host="0.0.0.0", port=8000, debug=True, workers=4, loop=loop)
result:
➜ ~ ps aux|grep simple_server.py
troy 23156 0.4 0.2 79160 21696 ? S 00:08
troy 23159 6.8 0.2 179564 20880 ? Rl 00:08
only one works well ,other three processes never spawn.
logs as below:
2016-12-22 00:08:32,310: INFO: Goin' Fast @ http://0.0.0.0:8000
2016-12-22 00:08:32,310: INFO: Spinning up 4 workers...
python: src/unix/linux-core.c:336: uv__io_poll: Assertion `(unsigned) fd < loop->nwatchers' failed.
python: src/unix/linux-core.c:336: uv__io_poll: Assertion `(unsigned) fd < loop->nwatchers' failed.
python: src/unix/linux-core.c:336: uv__io_poll: Assertion `(unsigned) fd < loop->nwatchers' failed.
marcosfede commented
Same here on macOS ,
code
from sanic import Sanic
from sanic.response import json
app = Sanic(__name__)
@app.route("/")
async def test(request):
return json({"hi": "hello"})
if __name__ == "__main__":
app.run(host="0.0.0.0", port=3333, debug=True, workers=4)
it says
2016-12-24 07:29:52,104: INFO: Goin' Fast @ http://0.0.0.0:3333
2016-12-24 07:29:52,105: INFO: Spinning up 4 workers...
but ps xau | grep server.py shows
fede 28188 100.0 0.1 2591252 11312 s000 R+ 7:29AM 0:04.76 python3 server.py
fede 28233 0.0 0.0 2434840 800 s002 S+ 7:30AM 0:00.00 grep --color=auto server.py
fede 28191 0.0 0.1 2591252 10172 s000 S+ 7:29AM 0:00.02 python3 server.py
fede 28190 0.0 0.1 2591252 10036 s000 S+ 7:29AM 0:00.03 python3 server.py
fede 28189 0.0 0.1 2591252 10056 s000 S+ 7:29AM 0:00.02 python3 server.py
fede 28187 0.0 1.2 2551196 120764 s000 S+ 7:29AM 0:02.86 python3 server.py
blazzman commented
Here is mine on MacOS 10.11.6 with explicit loop:
import asyncio
from sanic import Sanic
from sanic.response import json
loop = asyncio.get_event_loop()
app = Sanic(__name__)
@app.route('/hello')
async def hello(request):
return json({'errors': None, 'data': True})
app.run(host='0.0.0.0', port=8080, workers=2, loop=loop, debug=True)
Output:
➜ python test_sanic.py
2016-12-24 14:02:24,540: DEBUG:
▄▄▄▄▄
▀▀▀██████▄▄▄ _______________
▄▄▄▄▄ █████████▄ / \
▀▀▀▀█████▌ ▀▐▄ ▀▐█ | Gotta go fast! |
▀▀█████▄▄ ▀██████▄██ | _________________/
▀▄▄▄▄▄ ▀▀█▄▀█════█▀ |/
▀▀▀▄ ▀▀███ ▀ ▄▄
▄███▀▀██▄████████▄ ▄▀▀▀▀▀▀█▌
██▀▄▄▄██▀▄███▀ ▀▀████ ▄██
▄▀▀▀▄██▄▀▀▌████▒▒▒▒▒▒███ ▌▄▄▀
▌ ▐▀████▐███▒▒▒▒▒▐██▌
▀▄▄▄▄▀ ▀▀████▒▒▒▒▄██▀
▀▀█████████▀
▄▄██▀██████▀█
▄██▀ ▀▀▀ █
▄█ ▐▌
▄▄▄▄█▌ ▀█▄▄▄▄▀▀▄
▌ ▐ ▀▀▄▄▄▀
▀▀▄▄▀
2016-12-24 14:02:24,540: INFO: Goin' Fast @ http://0.0.0.0:8080
2016-12-24 14:02:24,540: INFO: Spinning up 2 workers...
2016-12-24 14:02:24,548: ERROR: Unable to start server
Traceback (most recent call last):
File "/Users/andrey/work/.venv/sanic/lib/python3.5/site-packages/sanic/server.py", line 262, in serve
http_server = loop.run_until_complete(server_coroutine)
File "/opt/local/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/asyncio/base_events.py", line 375, in run_until_complete
self.run_forever()
File "/opt/local/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/asyncio/base_events.py", line 345, in run_forever
self._run_once()
File "/opt/local/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/asyncio/base_events.py", line 1276, in _run_once
event_list = self._selector.select(timeout)
File "/opt/local/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/selectors.py", line 569, in select
kev_list = self._kqueue.control(None, max_ev, timeout)
OSError: [Errno 9] Bad file descriptor
2016-12-24 14:02:24,549: ERROR: Unable to start server
Traceback (most recent call last):
File "/Users/andrey/work/.venv/sanic/lib/python3.5/site-packages/sanic/server.py", line 262, in serve
http_server = loop.run_until_complete(server_coroutine)
File "/opt/local/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/asyncio/base_events.py", line 375, in run_until_complete
self.run_forever()
File "/opt/local/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/asyncio/base_events.py", line 345, in run_forever
self._run_once()
File "/opt/local/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/asyncio/base_events.py", line 1276, in _run_once
event_list = self._selector.select(timeout)
File "/opt/local/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/selectors.py", line 569, in select
kev_list = self._kqueue.control(None, max_ev, timeout)
OSError: [Errno 9] Bad file descriptor
Another try with explicit uvloop:
import asyncio
import uvloop
from sanic import Sanic
from sanic.response import json
asyncio.set_event_loop_policy(uvloop.EventLoopPolicy())
loop = asyncio.get_event_loop()
app = Sanic(__name__)
@app.route('/hello')
async def hello(request):
return json({'errors': None, 'data': True})
app.run(host='0.0.0.0', port=8080, workers=2, loop=loop, debug=True)
output:
➜ python test_sanic.py
2016-12-24 14:08:26,085: DEBUG:
▄▄▄▄▄
▀▀▀██████▄▄▄ _______________
▄▄▄▄▄ █████████▄ / \
▀▀▀▀█████▌ ▀▐▄ ▀▐█ | Gotta go fast! |
▀▀█████▄▄ ▀██████▄██ | _________________/
▀▄▄▄▄▄ ▀▀█▄▀█════█▀ |/
▀▀▀▄ ▀▀███ ▀ ▄▄
▄███▀▀██▄████████▄ ▄▀▀▀▀▀▀█▌
██▀▄▄▄██▀▄███▀ ▀▀████ ▄██
▄▀▀▀▄██▄▀▀▌████▒▒▒▒▒▒███ ▌▄▄▀
▌ ▐▀████▐███▒▒▒▒▒▐██▌
▀▄▄▄▄▀ ▀▀████▒▒▒▒▄██▀
▀▀█████████▀
▄▄██▀██████▀█
▄██▀ ▀▀▀ █
▄█ ▐▌
▄▄▄▄█▌ ▀█▄▄▄▄▀▀▄
▌ ▐ ▀▀▄▄▄▀
▀▀▄▄▀
2016-12-24 14:08:26,085: INFO: Goin' Fast @ http://0.0.0.0:8080
2016-12-24 14:08:26,085: INFO: Spinning up 2 workers...
2016-12-24 14:08:26,101: ERROR: Unable to start server
Traceback (most recent call last):
File "uvloop/loop.pyx", line 568, in uvloop.loop.Loop._add_reader (uvloop/loop.c:13938)
KeyError: 18
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/Users/andrey/work/.venv/sanic/lib/python3.5/site-packages/sanic/server.py", line 262, in serve
http_server = loop.run_until_complete(server_coroutine)
File "uvloop/loop.pyx", line 1198, in uvloop.loop.Loop.run_until_complete (uvloop/loop.c:24089)
File "uvloop/loop.pyx", line 1191, in uvloop.loop.Loop.run_until_complete (uvloop/loop.c:23933)
File "uvloop/loop.pyx", line 1100, in uvloop.loop.Loop.run_forever (uvloop/loop.c:22703)
File "uvloop/loop.pyx", line 363, in uvloop.loop.Loop._run (uvloop/loop.c:11184)
File "uvloop/loop.pyx", line 216, in uvloop.loop.Loop._setup_signals (uvloop/loop.c:8816)
File "uvloop/loop.pyx", line 570, in uvloop.loop.Loop._add_reader (uvloop/loop.c:132016-12-24 14:08:26,101: ERROR: Unable to start server
Traceback (most recent call last):
File "uvloop/loop.pyx", line 568, in uvloop.loop.Loop._add_reader (uvloop/loop.c:13938)
KeyError: 17
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/Users/andrey/work/.venv/sanic/lib/python3.5/site-packages/sanic/server.py", line 262, in serve
http_server = loop.run_until_complete(server_coroutine)
File "uvloop/loop.pyx", line 1198, in uvloop.loop.Loop.run_until_complete (uvloop/loop.c:24089)
File "uvloop/loop.pyx", line 1191, in uvloop.loop.Loop.run_until_complete (uvloop/loop.c:23933)
File "uvloop/loop.pyx", line 1100, in uvloop.loop.Loop.run_forever (uvloop/loop.c:22703)
File "uvloop/loop.pyx", line 363, in uvloop.loop.Loop._run (uvloop/loop.c:11184)
File "uvloop/loop.pyx", line 216, in uvloop.loop.Loop._setup_signals (uvloop/loop.c:8816)
File "uvloop/loop.pyx", line 570, in uvloop.loop.Loop._add_reader (uvloop/loop.c:13986)
File "uvloop/handles/poll.pyx", line 30, in uvloop.loop.UVPoll.new (uvloop/loop.c:58062)
File "uvloop/handles/poll.pyx", line 18, in uvloop.loop.UVPoll._init (uvloop/loop.c:57949)
OSError: [Errno 9] Bad file descriptor986)
File "uvloop/handles/poll.pyx", line 30, in uvloop.loop.UVPoll.new (uvloop/loop.c:58062)
File "uvloop/handles/poll.pyx", line 18, in uvloop.loop.UVPoll._init (uvloop/loop.c:57949)
OSError: [Errno 9] Bad file descriptor
My environment:
➜ uname -a
Darwin andreyb-mbp.local 15.6.0 Darwin Kernel Version 15.6.0: Wed Nov 2 20:30:56 PDT 2016; root:xnu-3248.60.11.1.2~2/RELEASE_X86_64 x86_64
➜ python -V
Python 3.5.2
virtualenv:
➜ pip freeze
-f /Users/andrey/.wheels
aiofiles==0.3.0
httptools==0.0.9
multidict==2.1.4
Sanic==0.1.8
ujson==1.35
uvloop==0.7.0
Worked fine without explicit loop, like:
app.run(host='0.0.0.0', port=8080, workers=2, loop=None, debug=True)
output:
...
2016-12-24 14:13:33,306: INFO: Goin' Fast @ http://0.0.0.0:8080
2016-12-24 14:13:33,306: INFO: Spinning up 2 workers...
➜ curl -X POST http:/localhost:8080/hello
{"errors":null,"data":true}
neoblackcap commented
I guess libuv can't simple use with fork()
import asyncio
import uvloop
from sanic import Sanic
from sanic.response import json
def start_server(host, port, workers):
asyncio.set_event_loop_policy(uvloop.EventLoopPolicy())
app = Sanic(__name__)
@app.route('/hello')
async def hello(request):
loop = asyncio.get_event_loop()
print(type(loop))
return json({'errors': None, 'data': True})
app.run(host=host, port=port, debug=True, workers=workers)
if __name__ == '__main__':
start_server('0.0.0.0', 8000, 5)
work perfect, and visit /hello, the stdio output
<class 'uvloop.Loop'>
marcosfede commented
@neoblackcap the output shows no errors but I suspect that the additional workers are not being used, since there is no performance gain when you benchmark it with wrk -d10s -t8 -c100 http://0.0.0.0:3333/ and the additional workers show 0 percent utilization when you run ps xau | grep server.py
neoblackcap commented
@marcosfede I rerun the test by you without uvloop and get the same result as yours. I think this not a bug of uvloop.
here is my code:
import asyncio
import os
from sanic import Sanic
from sanic.response import json
def start_server(host, port, workers):
app = Sanic(__name__)
@app.route('/hello')
async def hello(request):
loop = asyncio.get_event_loop()
print(os.getpid())
return json({'errors': None, 'data': True})
app.run(host=host, port=port, debug=True, workers=workers)
if __name__ == '__main__':
start_server('0.0.0.0', 8000, 5)
test method
wrk -t100 -c100 -d10s http://127.0.0.1:8000/hello
stdio output
62678
62678
62678
62678
...
same pid
seemethere commented
Yes I'm noticing the same behavior as well, currently investigating although I think it would be better to just abandon the multiple workers implementation once we make Sanic WSGI compliant as pointed out in #250, so we can use Sanic with gunicorn, uwsgi, etc and use their multiple workers implementations.
dutradda commented
@seemethere, how are you running multiple workers?
You will abandon the stand alone web server implementation? Running with wsgi dont decrease the performance?
easydaniel commented
I wonder if the issue is that different process can't share same uvloop.
I made a try when not explicit define loop, each worker will create a new loop however when explicit define loop with specific loop, only the first worker success to create_server while others failed with this error message
Traceback (most recent call last):
File "/usr/local/lib/python3.6/site-packages/sanic/server.py", line 287, in serve
http_server = loop.run_until_complete(server_coroutine)
File "uvloop/loop.pyx", line 1198, in uvloop.loop.Loop.run_until_complete (uvloop/loop.c:25480)
File "uvloop/loop.pyx", line 1191, in uvloop.loop.Loop.run_until_complete (uvloop/loop.c:25324)
File "uvloop/loop.pyx", line 1100, in uvloop.loop.Loop.run_forever (uvloop/loop.c:24056)
File "uvloop/loop.pyx", line 363, in uvloop.loop.Loop._run (uvloop/loop.c:11491)
File "uvloop/loop.pyx", line 216, in uvloop.loop.Loop._setup_signals (uvloop/loop.c:9069)
File "uvloop/loop.pyx", line 570, in uvloop.loop.Loop._add_reader (uvloop/loop.c:14440)
File "uvloop/handles/poll.pyx", line 30, in uvloop.loop.UVPoll.new (uvloop/loop.c:61297)
File "uvloop/handles/poll.pyx", line 18, in uvloop.loop.UVPoll._init (uvloop/loop.c:61184)
OSError: [Errno 9] Bad file descriptor
My environment
Python 3.6.0
Darwin <hostname> 15.5.0 Darwin Kernel Version 15.5.0: Tue Apr 19 18:36:36 PDT 2016; root:xnu-3248.50.21~8/RELEASE_X86_64 x86_64
seemethere commented
I believe this was fixed with #276, if it hasn't I'll reopen the issue.