> Thanks for taking the time to help.
>
> Except the strace and the listen queue size, I don't see the difference
> with what I'm doing so I don't understand what I'm doing wrong.
>
> But basically, are you saying that whatever I do, I won't get a connection
> refused when the queue is full? Or it may depend on the kernel settings,
> which will either make it timeout after a while or close it right away, or
> just succeed sometimes as my test shows it?
>
> So here is the new test pretty close to what I was doing:
>
> $ uwsgi --http-socket :9090 --wsgi-file test.py --single-interpreter
> --master --die-on-term --pyhome ~/tmp/testenv --harakiri 55 -l 2
>
> startup logs:
>
> *** Starting uWSGI 2.0.6 (64bit) on [Tue Aug 19 14:14:15 2014] ***
> compiled with version: 4.8.1 on 18 August 2014 15:19:17
> os: Linux-3.11.0-20-generic #35-Ubuntu SMP Fri May 2 21:32:49 UTC 2014
> nodename: ptfga
> machine: x86_64
> clock source: unix
> detected number of CPU cores: 4
> current working directory: /home/fga/tmp
> detected binary path: /home/fga/tmp/testenv/bin/uwsgi
> !!! no internal routing support, rebuild with pcre support !!!
> your processes number limit is 30632
> your memory page size is 4096 bytes
> *** WARNING: you have enabled harakiri without post buffering. Slow
> upload
> could be rejected on post-unbuffered webservers ***
> detected max file descriptor number: 1024
> lock engine: pthread robust mutexes
> thunder lock: disabled (you can enable it with --thunder-lock)
> uwsgi socket 0 bound to TCP address :9090 fd 3
> Python version: 2.7.5+ (default, Feb 27 2014, 19:40:54) [GCC 4.8.1]
> Set PythonHome to /home/fga/tmp/testenv
> *** Python threads support is disabled. You can enable it with
> --enable-threads ***
> Python main interpreter initialized at 0x1641f80
> your server socket listen backlog is limited to 2 connections
> your mercy for graceful operations on workers is 60 seconds
> mapped 145536 bytes (142 KB) for 1 cores
> *** Operational MODE: single process ***
> WSGI app 0 (mountpoint='') ready in 0 seconds on interpreter 0x1641f80
> pid:
> 21370 (default app)
> spawned uWSGI master process (pid: 21370)
> spawned uWSGI worker 1 (pid: 21371, cores: 1)
>
> before launching the test, it loops as you said:
>
> $ sudo strace -s 2000 -p 21370 -p 21371
> Process 21370 attached
> Process 21371 attached
> [pid 21371] epoll_wait(4, <unfinished ...>
> [pid 21370] wait4(-1, 0x7fff65fbd868, WNOHANG, NULL) = 0
> [pid 21370] epoll_wait(8, {}, 1, 1000) = 0
> [pid 21370] getsockopt(3, SOL_TCP, TCP_INFO,
> "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\0\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0x\v=\7\0\0\0\0x\v=\7x\v=\7\0\0\0\0\0\0\0\0\0\0\0\0\220\320\3\0\377\377\377\177\n\0\0\0\0\0\0\0\3\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0",
> [104]) = 0
> [pid 21370] wait4(-1, 0x7fff65fbd868, WNOHANG, NULL) = 0
> [pid 21370] epoll_wait(8, {}, 1, 1000) = 0
> [pid 21370] getsockopt(3, SOL_TCP, TCP_INFO,
> "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\0\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0`\17=\7\0\0\0\0`\17=\7`\17=\7\0\0\0\0\0\0\0\0\0\0\0\0\220\320\3\0\377\377\377\177\n\0\0\0\0\0\0\0\3\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0",
> [104]) = 0
> [pid 21370] wait4(-1, 0x7fff65fbd868, WNOHANG, NULL) = 0
> [pid 21370] epoll_wait(8, {}, 1, 1000) = 0
> [pid 21370] getsockopt(3, SOL_TCP, TCP_INFO,
> "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\0\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0H\23=\7\0\0\0\0H\23=\7H\23=\7\0\0\0\0\0\0\0\0\0\0\0\0\220\320\3\0\377\377\377\177\n\0\0\0\0\0\0\0\3\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0",
> [104]) = 0
>
> my test script is now:
>
> import time, random
>
> def application(env, start_response):
> thread_id = random.randint(1, 1000)
> start_response('200 OK', [('Content-Type','text/html')])
> for i in range(10):
> print 'sleeping (%d)' % (thread_id)
> time.sleep(5)
> return ["Hello World (%d)" % (thread_id)]
>
> Launching 11 curl requests in parallel, logs show:
>
> sleeping (302)
> Tue Aug 19 14:21:30 2014 - *** uWSGI listen queue of socket ":9090" (fd:
> 3)
> full !!! (3/2) ***
> Tue Aug 19 14:21:31 2014 - *** uWSGI listen queue of socket ":9090" (fd:
> 3)
> full !!! (3/2) ***
> Tue Aug 19 14:21:32 2014 - *** uWSGI listen queue of socket ":9090" (fd:
> 3)
> full !!! (3/2) ***
> sleeping (302)
> Tue Aug 19 14:21:33 2014 - *** uWSGI listen queue of socket ":9090" (fd:
> 3)
> full !!! (3/2) ***
> Tue Aug 19 14:21:34 2014 - *** uWSGI listen queue of socket ":9090" (fd:
> 3)
> full !!! (3/2) ***
> Tue Aug 19 14:21:35 2014 - *** uWSGI listen queue of socket ":9090" (fd:
> 3)
> full !!! (3/2) ***
> Tue Aug 19 14:21:36 2014 - *** uWSGI listen queue of socket ":9090" (fd:
> 3)
> full !!! (3/2) ***
> Tue Aug 19 14:21:37 2014 - *** uWSGI listen queue of socket ":9090" (fd:
> 3)
> full !!! (3/2) ***
> sleeping (302)
> Tue Aug 19 14:21:38 2014 - *** uWSGI listen queue of socket ":9090" (fd:
> 3)
> full !!! (3/2) ***
> Tue Aug 19 14:21:39 2014 - *** uWSGI listen queue of socket ":9090" (fd:
> 3)
> full !!! (3/2) ***
> Tue Aug 19 14:21:40 2014 - *** uWSGI listen queue of socket ":9090" (fd:
> 3)
> full !!! (3/2) ***
> Tue Aug 19 14:21:41 2014 - *** uWSGI listen queue of socket ":9090" (fd:
> 3)
> full !!! (3/2) ***
> Tue Aug 19 14:21:42 2014 - *** uWSGI listen queue of socket ":9090" (fd:
> 3)
> full !!! (3/2) ***
> [ ... ]
> Tue Aug 19 14:22:15 2014 - *** uWSGI listen queue of socket ":9090" (fd:
> 3)
> full !!! (3/2) ***
> Tue Aug 19 14:22:16 2014 - *** uWSGI listen queue of socket ":9090" (fd:
> 3)
> full !!! (3/2) ***
> Tue Aug 19 14:22:17 2014 - *** uWSGI listen queue of socket ":9090" (fd:
> 3)
> full !!! (3/2) ***
> [pid: 21371|app: 0|req: 1/1] 127.0.0.1 () {24 vars in 247 bytes} [Tue Aug
> 19 14:21:28 2014] GET / => generated 17 bytes in 50047 msecs (HTTP/1.1
> 200)
> 1 headers in 44 bytes (1 switches on core 0)
> sleeping (63)
> Tue Aug 19 14:22:18 2014 - *** uWSGI listen queue of socket ":9090" (fd:
> 3)
> full !!! (2/2) ***
> Tue Aug 19 14:22:19 2014 - *** uWSGI listen queue of socket ":9090" (fd:
> 3)
> full !!! (2/2) ***
> Tue Aug 19 14:22:20 2014 - *** uWSGI listen queue of socket ":9090" (fd:
> 3)
> full !!! (2/2) ***
> Tue Aug 19 14:22:21 2014 - *** uWSGI listen queue of socket ":9090" (fd:
> 3)
> full !!! (2/2) ***
> Tue Aug 19 14:22:22 2014 - *** uWSGI listen queue of socket ":9090" (fd:
> 3)
> full !!! (2/2) ***
> sleeping (63)
> Tue Aug 19 14:22:23 2014 - *** uWSGI listen queue of socket ":9090" (fd:
> 3)
> full !!! (2/2) ***
> Tue Aug 19 14:22:24 2014 - *** uWSGI listen queue of socket ":9090" (fd:
> 3)
> full !!! (2/2) ***
>
>
> *When I do the telnet, I don't notice anything:*
>
> pid 21370] wait4(-1, 0x7fff65fbd868, WNOHANG, NULL) = 0
> [pid 21370] epoll_wait(8, {}, 1, 1000) = 0
> [pid 21370] getsockopt(3, SOL_TCP, TCP_INFO,
> "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\3\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0T\375J\7\0\0\0\0T\375J\7T\375J\7\0\0\0\0\0\0\0\0\0\0\0\0\220\320\3\0\377\377\377\177\n\0\0\0\0\0\0\0\3\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0",
> [104]) = 0
> [pid 21370] write(2, "Tue Aug 19 14:34:19 2014 - *** uWSGI listen queue of
> socket \":9090\" (fd: 3) full !!! (3/2) ***\n", 95) = 95
> [pid 21370] wait4(-1, 0x7fff65fbd868, WNOHANG, NULL) = 0
> [pid 21370] epoll_wait(8, <unfinished ...>
> [pid 21371] <... select resumed> ) = 0 (Timeout)
> [pid 21371] write(1, "sleeping (14)\n", 14) = 14
> [pid 21371] select(0, NULL, NULL, NULL, {5, 0} <unfinished ...>
> [pid 21370] <... epoll_wait resumed> {}, 1, 1000) = 0
> [pid 21370] getsockopt(3, SOL_TCP, TCP_INFO,
> "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\3\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0<\1K\7\0\0\0\0<\1K\7<\1K\7\0\0\0\0\0\0\0\0\0\0\0\0\220\320\3\0\377\377\377\177\n\0\0\0\0\0\0\0\3\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0",
> [104]) = 0
> [pid 21370] write(2, "Tue Aug 19 14:34:20 2014 - *** uWSGI listen queue of
> socket \":9090\" (fd: 3) full !!! (3/2) ***\n", 95) = 95
> [pid 21370] wait4(-1, 0x7fff65fbd868, WNOHANG, NULL) = 0
> [pid 21370] epoll_wait(8, {}, 1, 1000) = 0
> [pid 21370] getsockopt(3, SOL_TCP, TCP_INFO,
> "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\3\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0$\5K\7\0\0\0\0$\5K\7$\5K\7\0\0\0\0\0\0\0\0\0\0\0\0\220\320\3\0\377\377\377\177\n\0\0\0\0\0\0\0\3\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0",
> [104]) = 0
> [pid 21370] write(2, "Tue Aug 19 14:34:21 2014 - *** uWSGI listen queue of
> socket \":9090\" (fd: 3) full !!! (3/2) ***\n", 95) = 95
> [pid 21370] wait4(-1, 0x7fff65fbd868, WNOHANG, NULL) = 0
> [pid 21370] epoll_wait(8, {}, 1, 1000) = 0
> [pid 21370] getsockopt(3, SOL_TCP, TCP_INFO,
> "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\3\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\20\tK\7\0\0\0\0\20\tK\7\20\tK\7\0\0\0\0\0\0\0\0\0\0\0\0\220\320\3\0\377\377\377\177\n\0\0\0\0\0\0\0\3\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0",
> [104]) = 0
> [pid 21370] write(2, "Tue Aug 19 14:34:22 2014 - *** uWSGI listen queue of
> socket \":9090\" (fd: 3) full !!! (3/2) ***\n", 95) = 95
> [pid 21370] wait4(-1, 0x7fff65fbd868, WNOHANG, NULL) = 0
> [pid 21370] epoll_wait(8, {}, 1, 1000) = 0
> [pid 21370] getsockopt(3, SOL_TCP, TCP_INFO,
> "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\3\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\370\fK\7\0\0\0\0\370\fK\7\370\fK\7\0\0\0\0\0\0\0\0\0\0\0\0\220\320\3\0\377\377\377\177\n\0\0\0\0\0\0\0\3\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0",
> [104]) = 0
> [pid 21370] write(2, "Tue Aug 19 14:34:23 2014 - *** uWSGI listen queue of
> socket \":9090\" (fd: 3) full !!! (3/2) ***\n", 95) = 95
> [pid 21370] wait4(-1, 0x7fff65fbd868, WNOHANG, NULL) = 0
> [pid 21370] epoll_wait(8, {}, 1, 1000) = 0
> [pid 21370] getsockopt(3, SOL_TCP, TCP_INFO,
> "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\3\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\340\20K\7\0\0\0\0\340\20K\7\340\20K\7\0\0\0\0\0\0\0\0\0\0\0\0\220\320\3\0\377\377\377\177\n\0\0\0\0\0\0\0\3\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0",
> [104]) = 0
> [pid 21370] write(2, "Tue Aug 19 14:34:24 2014 - *** uWSGI listen queue of
> socket \":9090\" (fd: 3) full !!! (3/2) ***\n", 95) = 95
> [pid 21370] wait4(-1, 0x7fff65fbd868, WNOHANG, NULL) = 0
> [pid 21370] epoll_wait(8, <unfinished ...>
> [pid 21371] <... select resumed> ) = 0 (Timeout)
> [pid 21371] write(1, "sleeping (14)\n", 14) = 14
> [pid 21371] select(0, NULL, NULL, NULL, {5, 0} <unfinished ...>
> [pid 21370] <... epoll_wait resumed> {}, 1, 1000) = 0
> [pid 21370] getsockopt(3, SOL_TCP, TCP_INFO,
> "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\3\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\310\24K\7\0\0\0\0\310\24K\7\310\24K\7\0\0\0\0\0\0\0\0\0\0\0\0\220\320\3\0\377\377\377\177\n\0\0\0\0\0\0\0\3\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0",
> [104]) = 0
> [pid 21370] write(2, "Tue Aug 19 14:34:25 2014 - *** uWSGI listen queue of
> socket \":9090\" (fd: 3) full !!! (3/2) ***\n", 95) = 95
> [pid 21370] wait4(-1, 0x7fff65fbd868, WNOHANG, NULL) = 0
> [pid 21370] epoll_wait(8, {}, 1, 1000) = 0
> [pid 21370] getsockopt(3, SOL_TCP, TCP_INFO,
> "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\3\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\264\30K\7\0\0\0\0\264\30K\7\264\30K\7\0\0\0\0\0\0\0\0\0\0\0\0\220\320\3\0\377\377\377\177\n\0\0\0\0\0\0\0\3\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0",
> [104]) = 0
> [pid 21370] write(2, "Tue Aug 19 14:34:26 2014 - *** uWSGI listen queue of
> socket \":9090\" (fd: 3) full !!! (3/2) ***\n", 95) = 95
> [pid 21370] wait4(-1, 0x7fff65fbd868, WNOHANG, NULL) = 0
> [pid 21370] epoll_wait(8, {}, 1, 1000) = 0
> [pid 21370] getsockopt(3, SOL_TCP, TCP_INFO,
> "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\3\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\234\34K\7\0\0\0\0\234\34K\7\234\34K\7\0\0\0\0\0\0\0\0\0\0\0\0\220\320\3\0\377\377\377\177\n\0\0\0\0\0\0\0\3\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0",
> [104]) = 0
> [pid 21370] write(2, "Tue Aug 19 14:34:27 2014 - *** uWSGI listen queue of
> socket \":9090\" (fd: 3) full !!! (3/2) ***\n", 95) = 95
> [pid 21370] wait4(-1, 0x7fff65fbd868, WNOHANG, NULL) = 0
>
> *Then at some point, it accepts the telnet connection:*
>
> [pid 21371] epoll_wait(4, {{EPOLLIN, {u32=3, u64=3}}}, 1, -1) = 1
> [pid 21371] accept4(3, {sa_family=AF_INET, sin_port=htons(59113),
> sin_addr=inet_addr("127.0.0.1")}, [16], SOCK_NONBLOCK) = 6
> [pid 21371] read(6, "GET /test HTTP/1.1\r\n\r\n", 4096) = 22
> [pid 21371] write(1, "sleeping (43)\n", 14) = 14
> [pid 21371] select(0, NULL, NULL, NULL, {5, 0} <unfinished ...>
> [pid 21370] <... epoll_wait resumed> {}, 1, 1000) = 0
> [pid 21370] getsockopt(3, SOL_TCP, TCP_INFO,
> "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\0\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\270\206M\7\0\0\0\0\270\206M\7\270\206M\7\0\0\0\0\0\0\0\0\0\0\0\0\220\320\3\0\377\377\377\177\n\0\0\0\0\0\0\0\3\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0",
> [104]) = 0
> [pid 21370] wait4(-1, 0x7fff65fbd868, WNOHANG, NULL) = 0
> [pid 21370] epoll_wait(8, {}, 1, 1000) = 0
>
>
> *Eventually, the telnet request returned, successfully this time:*
>
> time telnet localhost 9090
> Trying 127.0.0.1...
> Connected to localhost.
> Escape character is '^]'.
> GET /test HTTP/1.1
>
> HTTP/1.1 200 OK
> Content-Type: text/html
>
> Hello World (43)Connection closed by foreign host.
>
> real 3m49.293s
> user 0m0.002s
> sys 0m0.003s
>
>
> [pid 21370] wait4(-1, 0x7fff65fbd868, WNOHANG, NULL) = 0
> [pid 21370] epoll_wait(8, {}, 1, 1000) = 0
> [pid 21370] getsockopt(3, SOL_TCP, TCP_INFO,
> "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\0\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0dFN\7\0\0\0\0dFN\7dFN\7\0\0\0\0\0\0\0\0\0\0\0\0\220\320\3\0\377\377\377\177\n\0\0\0\0\0\0\0\3\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0",
> [104]) = 0
> [pid 21370] wait4(-1, 0x7fff65fbd868, WNOHANG, NULL) = 0
> [pid 21370] epoll_wait(8, <unfinished ...>
> [pid 21371] <... select resumed> ) = 0 (Timeout)
> [pid 21371] writev(6, [{"HTTP/1.1 200 OK\r\nContent-Type:
> text/html\r\n\r\n", 44}, {"Hello World (43)", 16}], 2) = 60
> [pid 21371] close(6) = 0
> [pid 21371] writev(2, [{"[pid: 21371|app: 0|req: 9/9] 127.0.0.1 () {18
> vars
> in 180 bytes} [Tue Aug 19 14:37:04 2014] GET /test => generated 16 bytes
> in
> 50032 msecs (HTTP/1.1 200) 1 headers in 44 bytes (1 switches on core
> 0)\n",
> 199}], 1) = 199
> [pid 21371] epoll_wait(4, <unfinished ...>
> [pid 21370] <... epoll_wait resumed> {}, 1, 1000) = 0
> [pid 21370] getsockopt(3, SOL_TCP, TCP_INFO,
> "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\0\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0PJN\7\0\0\0\0PJN\7PJN\7\0\0\0\0\0\0\0\0\0\0\0\0\220\320\3\0\377\377\377\177\n\0\0\0\0\0\0\0\3\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0",
> [104]) = 0
> [pid 21370] wait4(-1, 0x7fff65fbd868, WNOHANG, NULL) = 0
> [pid 21370] epoll_wait(8, {}, 1, 1000) = 0
> [pid 21370] getsockopt(3, SOL_TCP, TCP_INFO,
> "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\0\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0008NN\7\0\0\0\0008NN\0078NN\7\0\0\0\0\0\0\0\0\0\0\0\0\220\320\3\0\377\377\377\177\n\0\0\0\0\0\0\0\3\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0",
> [104]) = 0
> [pid 21370] wait4(-1, 0x7fff65fbd868, WNOHANG, NULL) = 0
>
>
this is teh strace of the master, you have to strace the worker, as it is
the one calling accept()
--
Roberto De Ioris
http://unbit.it
_______________________________________________
uWSGI mailing list
[email protected]
http://lists.unbit.it/cgi-bin/mailman/listinfo/uwsgi
