waitress locks up with high connection counts #301
Description
Given a trivial wsgi server:
def application(environ, start_response): """WSGI callable.""" print('start') encoded_response = b'{"status":"ok"}\n' start_response( "200 OK", [ ("Content-Type", "application/json"), ("Content-Length", str(len(encoded_response))), ], ) ret = [encoded_response] print('done') return retWhen run with default options:
$ waitress-serve simple:applicationThen testing connections with a separate python script:
import requests, time sessions = [requests.Session() for _ in range(100)] for idx, s in enumerate(sessions): print(idx, s.get('http://localhost:8080').json(), time.time())The expected output would be lines like this, all the way to 99:
0 {'status': 'ok'} 1590161909.722591 1 {'status': 'ok'} 1590161909.7260928 2 {'status': 'ok'} 1590161909.729814 ... However the actual output stops at 97, waiting for the server to respond.
A similar issue can be observed by running curl at this point:
$ curl localhost:8080 -vvv * Rebuilt URL to: localhost:8080/ * Trying 127.0.0.1... * TCP_NODELAY set * Connected to localhost (127.0.0.1) port 8080 (#0) > GET / HTTP/1.1 > Host: localhost:8080 > User-Agent: curl/7.58.0 > Accept: */* > Locally the freeze being at 97 is very reproducible, though it wouldn't surprise me if it was different on other machines (however I have not tested this).
Attaching strace to the server process shows it selecting on the open sockets, but no other activity.
After a while (~minutes) the server will eventually respond:
94 {'status': 'ok'} 1590161910.1553152 95 {'status': 'ok'} 1590161910.1605425 96 {'status': 'ok'} 1590161910.165632 97 {'status': 'ok'} 1590161910.1702456 98 {'status': 'ok'} 1590162048.4171915 99 {'status': 'ok'} 1590162048.4208531 The return to responding aligns with a change in the response to strace's output:
select(105, [5 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104], [], [5 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104], {tv_sec=1, tv_usec=0}) = 0 (Timeout) ... <many identical lines> select(105, [5 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104], [], [5 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104], {tv_sec=1, tv_usec=0}) = 0 (Timeout) select(105, [5], [7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104], [5 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104], {tv_sec=1, tv_usec=0}) = 98 (out [7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104], left {tv_sec=0, tv_usec=999982}) close(7) = 0 close(8) = 0 close(9) = 0 close(10) = 0 ... <rest of the other open connections being close()d> close(104) = 0 select(7, [5 6], [], [5 6], {tv_sec=1, tv_usec=0}) = 1 (in [6], left {tv_sec=0, tv_usec=999996}) accept4(6, {sa_family=AF_INET, sin_port=htons(47452), sin_addr=inet_addr("127.0.0.1")}, [16], SOCK_CLOEXEC) = 7 setsockopt(7, SOL_TCP, TCP_NODELAY, [1], 4) = 0 getsockopt(7, SOL_SOCKET, SO_SNDBUF, [2626560], [4]) = 0 ... so it's possible that this isn't directly an issue in waitress, however I'm not familiar enough with waitress to debug this further.
--
I reproduced this by installing via pip 20 in a virtualenv (version 1.4.3), on Python 3.6 on Ubuntu 18.04 LTS, however the original issue was observed on Python 3.5 on Debian Stretch using the python3-waitress package (version 1.0.1-1).