> 2010/9/23 Roberto De Ioris <[email protected]>: >> >> Il giorno 23/set/2010, alle ore 16.07, Jean-Baptiste Quenot ha scritto: > >>> If I had >>> connection bursts so that the delay between connect() and accept() >>> would get longer, my server would have very slow average response >>> times, but this is not the case, the average response time is 400ms 24 >>> hours a day, and I don't have a lot of concurrent connections (about >>> 15 in average). >> >> average ? the rate of bad response (empty) is so little that i really >> have doubt >> that it can be accounted in the average. You have little times when the >> workers are overloaded, >> no one can respond in a reasonable time. > > I meant average for all requests. All response times are monitored > there is no overload at all anytime. > >> The matter is all on how uWSGI and flup manages workers, if you want to >> have a similar result >> of Flup, spawn 50 workers >> >> http://trac.saddi.com/flup/browser/flup/server/preforkserver.py > > FYI I used the threading model with Flup and it is limited to > sys.maxint: See > http://trac.saddi.com/flup/browser/flup/server/threadedserver.py and > http://trac.saddi.com/flup/browser/flup/server/threadpool.py > > > Now, let's assume I have an overloaded backend, either because > application is too slow, or because there are too many connections. > > I made a test with haproxy timeout set to 10s and uwsgi harakiri at 9s. > > In the first test, application does this: > > if uri == "/": > self.startResponse("200 OK") > time.sleep(11) > return "" > > I run uwsgi with only one worker: /usr/bin/uwsgi -b 25000 -s > 127.0.0.1:25555 -t 9 -A1 -M -p1 -C -i -w server --pythonpath core -L > > I access haproxy with ab -c1 -n1 and get this in nginx logs: > > Sep 23 17:54:24 placardo nginx: 127.0.0.1 - 0 10.011 - "GET / > HTTP/1.0" 499 0 "-" "ApacheBench/2.3" "-" "fr.nomao.com" > > Upstream response time is not indicated, and status code is 499 > (client abort), not 200. > > Now I change application to have a "normal" response time: > > if uri == "/": > self.startResponse("200 OK") > time.sleep(.4) > return "" > > I raise the concurrency of requests with ab -c100 -n100, here is what I > have: > > Sep 23 18:03:29 placardo nginx: 127.0.0.1 - 153 0.401 0.401 "GET / > HTTP/1.0" 200 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:30 placardo nginx: 127.0.0.1 - 153 0.802 0.802 "GET / > HTTP/1.0" 200 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:30 placardo nginx: 127.0.0.1 - 153 1.203 1.203 "GET / > HTTP/1.0" 200 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:31 placardo nginx: 127.0.0.1 - 153 1.604 1.604 "GET / > HTTP/1.0" 200 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:31 placardo nginx: 127.0.0.1 - 153 2.004 2.004 "GET / > HTTP/1.0" 200 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:31 placardo nginx: 127.0.0.1 - 153 2.405 2.405 "GET / > HTTP/1.0" 200 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:32 placardo nginx: 127.0.0.1 - 153 2.806 2.806 "GET / > HTTP/1.0" 200 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:32 placardo nginx: 127.0.0.1 - 153 3.207 3.207 "GET / > HTTP/1.0" 200 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:33 placardo nginx: 127.0.0.1 - 153 3.607 3.607 "GET / > HTTP/1.0" 200 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:33 placardo nginx: 127.0.0.1 - 153 4.009 4.009 "GET / > HTTP/1.0" 200 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:33 placardo nginx: 127.0.0.1 - 153 4.409 4.409 "GET / > HTTP/1.0" 200 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:34 placardo nginx: 127.0.0.1 - 153 4.810 4.810 "GET / > HTTP/1.0" 200 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:34 placardo nginx: 127.0.0.1 - 153 5.211 5.211 "GET / > HTTP/1.0" 200 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:35 placardo nginx: 127.0.0.1 - 153 5.612 5.612 "GET / > HTTP/1.0" 200 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:35 placardo nginx: 127.0.0.1 - 153 6.013 6.013 "GET / > HTTP/1.0" 200 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:35 placardo nginx: 127.0.0.1 - 153 6.414 6.414 "GET / > HTTP/1.0" 200 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:36 placardo nginx: 127.0.0.1 - 153 6.814 6.814 "GET / > HTTP/1.0" 200 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:36 placardo nginx: 127.0.0.1 - 153 7.214 7.214 "GET / > HTTP/1.0" 200 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:37 placardo nginx: 127.0.0.1 - 153 7.615 7.615 "GET / > HTTP/1.0" 200 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:37 placardo nginx: 127.0.0.1 - 153 8.016 8.016 "GET / > HTTP/1.0" 200 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:37 placardo nginx: 127.0.0.1 - 153 8.417 8.417 "GET / > HTTP/1.0" 200 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:38 placardo nginx: 127.0.0.1 - 153 8.818 8.818 "GET / > HTTP/1.0" 200 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:38 placardo nginx: 127.0.0.1 - 153 9.219 9.219 "GET / > HTTP/1.0" 200 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:39 placardo nginx: 127.0.0.1 - 153 9.620 9.620 "GET / > HTTP/1.0" 200 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:39 placardo nginx: 127.0.0.1 - 0 10.014 - "GET / > HTTP/1.0" 499 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:39 placardo nginx: 127.0.0.1 - 0 10.013 - "GET / > HTTP/1.0" 499 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:39 placardo nginx: 127.0.0.1 - 0 10.013 - "GET / > HTTP/1.0" 499 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:39 placardo nginx: 127.0.0.1 - 0 9.977 - "GET / HTTP/1.0" > 499 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:39 placardo nginx: 127.0.0.1 - 0 9.977 - "GET / HTTP/1.0" > 499 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:39 placardo nginx: 127.0.0.1 - 0 9.977 - "GET / HTTP/1.0" > 499 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:39 placardo nginx: 127.0.0.1 - 0 9.977 - "GET / HTTP/1.0" > 499 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:39 placardo nginx: 127.0.0.1 - 0 9.977 - "GET / HTTP/1.0" > 499 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:39 placardo nginx: 127.0.0.1 - 0 9.977 - "GET / HTTP/1.0" > 499 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:39 placardo nginx: 127.0.0.1 - 0 9.977 - "GET / HTTP/1.0" > 499 0 "-" "ApacheBench/2.3" "-" "-" > Sep 23 18:03:39 placardo nginx: 127.0.0.1 - 0 9.977 - "GET / HTTP/1.0" > 499 0 "-" "ApacheBench/2.3" "-" "-" > > Again, only 499 status code and no upstream server time when timeout is > reached. > > To be safe I also tried the same tests with curl and HTTP/1.1, the > results are the same. >
I have modified nginx to reproduce your problem, i am using 0.8.50, i have managed to do it, but in the nginx error.log the timeout is reported (even if the access_log report a 0 response) It is not so easy as if i sleep a milliseconds more the connect timeout come out. Does your nginx error log contains something ? In the mean time i started thinking on all the motivation a request could return 0 bytes. Normally i would think about an exception, but in that case it should be logged to stderr. Are you sure you cannot enable full-logging for abount 24 hours ? it would be very useful to avoid going in the wrong direction. -- Roberto De Ioris http://unbit.it _______________________________________________ uWSGI mailing list [email protected] http://lists.unbit.it/cgi-bin/mailman/listinfo/uwsgi
