web2py FORM, concurrency and failed requests
David Marko
appear with Rokcet and with wsgi as well.
You can simply benchmark FORM examples running on your site. The same
for my local tests.
See below:
-n = number of requests
-c = number of concurrent requests
debian:~# ab -n 100 -c 10 http://web2py.com/examples/form_examples/form
This is ApacheBench, Version 2.3 <$Revision: 655654 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/
Benchmarking web2py.com (be patient).....done
Server Software: Apache/2.2.8
Server Hostname: web2py.com
Server Port: 80
Document Path: /examples/form_examples/form
Document Length: 24043 bytes
Concurrency Level: 10
Time taken for tests: 14.161 seconds
Complete requests: 100
Failed requests: 19
(Connect: 0, Receive: 0, Length: 19, Exceptions: 0)
Write errors: 0
Total transferred: 2449290 bytes
HTML transferred: 2404325 bytes
Requests per second: 7.06 [#/sec] (mean)
Time per request: 1416.149 [ms] (mean)
Time per request: 141.615 [ms] (mean, across all concurrent
requests)
Transfer rate: 168.90 [Kbytes/sec] received
mdipierro
I have performed the following test:
I modified gluon/main.py function app_with_loggin() and added
import random
k = str(random.random())[2:]
line='%s request arrived\n' % k
open(logfilename, 'a').write(line)
... do web2py stuff ...
line='%s request completed %s\n' % (k, status_headers[0])[:3])
open(logfilename, 'a').write(line)
Turns out every request received by the wsgi app is completed and
returns a 200OK. Yet ab measures 11% failures. I see only two
possibilities:
1) the failures occur somehow in the web server (but why only with
this action?)
2) occasionally what web2py interprets as a 200OK, ab interprets as a
failure.
Is there a way see how a failed response look like? Whether it is a
tcp level failure or a http level failure?
For now I am going to try with tcpdump....
Massimo
On Aug 12, 10:44 am, David Marko <dma...@tiscali.cz> wrote:
> Massimo I just created a new thread for this problem. Failed requests
> appear with Rokcet and with wsgi as well.
> You can simply benchmark FORM examples running on your site. The same
> for my local tests.
>
> See below:
> -n = number of requests
> -c = number of concurrent requests
>
> Licensed to The Apache Software Foundation,http://www.apache.org/
Jonathan Lundell
> Is there a way see how a failed response look like? Whether it is a
> tcp level failure or a http level failure?
ab has a -v option for verbosity level.
http://httpd.apache.org/docs/2.0/programs/ab.html
-v verbosity
Set verbosity level - 4 and above prints information on headers, 3 and above prints response codes (404, 200, etc.), 2 and above prints warnings and info.
This seems suggestive:
Failed requests: 19
(Connect: 0, Receive: 0, Length: 19, Exceptions: 0)
I'm not familiar with ab error reporting. Is this saying that the request was OK but had an unexpected length?
Jonathan Lundell
> Failed requests: 19
> (Connect: 0, Receive: 0, Length: 19, Exceptions: 0)
http://www.celebrazio.net/tech/unix/apache_bench.html
> In the above example, if the server returns dynamic content, the file size may be different from one request to another. One difference, for example, is ads on the page - they vary per request and have different byte size. When this happens, Apache bench notes it as "Failed request" for Length (byte size) being different. We can ignore that.
Jonathan Lundell
> Failed requests: 19
> (Connect: 0, Receive: 0, Length: 19, Exceptions: 0)
> May not actually be a problem. Reason? It might be a site that serves dynamic context (such as different cookie IDs mentioned) where the file size changes between each query.
>
> http://www.celebrazio.net/tech/unix/apache_bench.html
>
> Easy way to verify:
>
> Code: $ wget <url>
>
> Repeat that twice, then:
>
> Code: $ diff <retrieved filename> <retrieved filename>.1
>
> See if there are differences. If yes, then you can ignore the length-related failures. If no, it's some other cause and need to investigate further.
>
http://www.linode.com/forums/archive/o_t/t_1633/apache_benchmark_high_
Jonathan Lundell
> Failed requests: 19
> (Connect: 0, Receive: 0, Length: 19, Exceptions: 0)
Even more reassurance:
http://alwaysthecritic.typepad.com/atc/2009/04/apache-bench-notes.html
The length variation should be checked, of course, but it may well be harmless.
If the length variation is under our control (cookie format, maybe?), perhaps we could make an effort to make it the same.
mdipierro
For the page I am considering the fail requests are not a real failure
but declare a content-length of 19383 (wrong) instead of 19384
(correct). Let's continue investigate...
Massimo
On Aug 12, 11:53 am, Jonathan Lundell <jlund...@pobox.com> wrote:
> On Aug 12, 2010, at 8:44 AM, David Marko wrote:
>
> > Failed requests: 19
> > (Connect: 0, Receive: 0, Length: 19, Exceptions: 0)
>
> Even more reassurance:
>
Jonathan Lundell
> You are the man.
>
> For the page I am considering the fail requests are not a real failure
> but declare a content-length of 19383 (wrong) instead of 19384
> (correct). Let's continue investigate...
I'm seeing two variations (using curl -i).
One is harmless:
<div>datetime.datetime(2010, 8, 12, 18, 0, 36, 68094)</div>
vs
<div>datetime.datetime(2010, 8, 12, 18, 3, 15, 325125)</div>
However, the other is odd:
tmp $ grep -i Transfer-Encoding ?
2:Transfer-Encoding: chunked
4:Transfer-Encoding: chunked
5:Transfer-Encoding: chunked
6:Transfer-Encoding: chunked
tmp $ grep -i Transfer-Length ?
tmp $ grep -i Content-Length ?
1:Content-Length: 24163
3:Content-Length: 24164
(filenames 1-6 are my curl -i captures)
Apparently at random, I see chunked returns.
My request is: curl -i http://web2py.com/examples/form_examples/form
Jonathan Lundell
> For the page I am considering the fail requests are not a real failure
> but declare a content-length of 19383 (wrong) instead of 19384
> (correct). Let's continue investigate...
Once the chunked encoding question is answered, it seems to me that we ought to create some pages (in examples?) expressly for the purpose of benchmarking. Make sure they're the same length, so we don't get the bogus errors, and create some variations: with and without session.forget, with and without a database access, etc.
mdipierro
not computed by web2py but it is computed by the web server and it is
computed correctly.
The length is actually different at each request.
This is because:
1) in forms it contains the CSRF token with is a uuid and is different
at each request
2) forms that contain a date may have different rounding for seconds
3) pages with display [request], [response], etc also contain datetime
info which have different length at every request
The second link Jonathan posted says:
"Quite often you may see in the statistics "Failed requests: 5" or
similar, followed by a list of the types of failure: "(Connect: 0,
Receive: 0, Length: 5, Exceptions: 0)". If the only type of failure
that actually occurred is 'Length' then don't be alarmed. This simply
means that each request (for the same URL) returned a different length
response, which ab regards as suspicious. However it's perfectly
normal for dynamic webpages, especially if they include the time or
other very dynamic data on the page. "
This our case.
Case closed?
Massimo
Thadeus Burgess
not content length issues. These pages were dynamic in that they
returned information from the database, but it was always the exact
same 10 records. The content length was not one of the reported failed
requests types. I can even replicate this with the welcome app, just
add a friends table, and a sqltable on the default/index page, insert
some records, then run ab on the index page, it always return sthe
same thing, but will generate roughly 15% error ratios not related to
content length (since it stays the same)
--
Thadeus
mdipierro
apache? I also noticed rocket responds always with http/1.1 which
(allows the server to decide on the option of chunked encoding and it
may decide based on the length of content). The problem is that ab - I
think - asks for 1.0 since according to the docs does not support 1.x
fully.
Massimo
mdipierro
Massimo
On Aug 12, 12:48 pm, Thadeus Burgess <thade...@thadeusb.com> wrote:
> In my testings the errors were actually 500 internal server errors,
> not content length issues. These pages were dynamic in that they
> returned information from the database, but it was always the exact
> same 10 records. The content length was not one of the reported failed
> requests types. I can even replicate this with the welcome app, just
> add a friends table, and a sqltable on the default/index page, insert
> some records, then run ab on the index page, it always return sthe
> same thing, but will generate roughly 15% error ratios not related to
> content length (since it stays the same)
>
> --
> Thadeus
>
mdipierro
which database?
if sqlite... you cannot use concurrent requests because sqlite locks
entire file.
if not sqlite... did you set pool_size=n where n is the number of
concurrent requests you test?
if so, did you look for tickets in the yourapp/error folder?
If none, did you look for tickets in admin/error folder?
Thadeus Burgess
logs also have various errors related to the connection dropping or
the application crashing.
--
Thadeus
mdipierro
On Aug 12, 2:21 pm, Thadeus Burgess <thade...@thadeusb.com> wrote:
> postgresql, 10, tickets consist of IOErrors and then the WSGI/apache
> logs also have various errors related to the connection dropping or
> the application crashing.
>
> --
> Thadeus
>
Thadeus Burgess
--
Thadeus
mdipierro
and the ab parameters you use for testing.
Massimo
mdipierro
1) it always responds with HTTP/1.1 even if client is HTTP/1.0. I am
not sure this is allowed. I think not. A response must follow a
protocol that is same or lower then requested protocol
2) it seems Rocket responds with chunked encoding in two cases: a) the
request was chunked; b) if the wsgi app returns a list with more than
one element (web2py can do this but normally does not do it).
There is one caveat abdou 2) There is this code
def write(self, data, sections=None):
""" Write the data to the output socket. """
....
if not self.headers_sent:
self.send_headers(data, sections)
If it happens that self.send_headers(data, None) is called, it will
force chunked-encoding. I do not see how that can happen but I cannot
exclude since I do not see the logic behind calling send_headers in
two places.
On Aug 12, 12:48 pm, Thadeus Burgess <thade...@thadeusb.com> wrote:
> In my testings the errors were actually 500 internal server errors,
> not content length issues. These pages were dynamic in that they
> returned information from the database, but it was always the exact
> same 10 records. The content length was not one of the reported failed
> requests types. I can even replicate this with the welcome app, just
> add a friends table, and a sqltable on the default/index page, insert
> some records, then run ab on the index page, it always return sthe
> same thing, but will generate roughly 15% error ratios not related to
> content length (since it stays the same)
>
> --
> Thadeus
>
Jonathan Lundell
> The chunked issue needs to be investigated. Are you using rocket or
> apache? I also noticed rocket responds always with http/1.1 which
> (allows the server to decide on the option of chunked encoding and it
> may decide based on the length of content). The problem is that ab - I
> think - asks for 1.0 since according to the docs does not support 1.x
> fully.
curl -i http://web2py.com/examples/form_examples/form
You'd know better than I. According to the headers, Apache and http 1.1:
HTTP/1.1 200 OK
Date: Thu, 12 Aug 2010 17:00:36 GMT
Server: Apache/2.2.8 (Ubuntu) mod_wsgi/3.2-BRANCH Python/2.5.2 mod_ssl/2.2.8 OpenSSL/0.9.8g
Expires: Thu, 12 Aug 2010 17:00:36 GMT^M
Pragma: no-cache
Cache-Control: no-store, no-cache, must-revalidate, post-check=0, pre-check=0
Set-Cookie: session_id_examples=70-0-249-65-52b1ec97-d08b-435e-a1b7-ddc1f87e0ddd; Path=/
Content-Length: 24163
Content-Type: text/html; charset=utf-8
HTTP/1.1 200 OK
Date: Thu, 12 Aug 2010 17:00:39 GMT
Server: Apache/2.2.8 (Ubuntu) mod_wsgi/3.2-BRANCH Python/2.5.2 mod_ssl/2.2.8 OpenSSL/0.9.8g
Expires: Thu, 12 Aug 2010 17:00:39 GMT
Pragma: no-cache
Cache-Control: no-store, no-cache, must-revalidate, post-check=0, pre-check=0
Set-Cookie: session_id_examples=70-0-249-65-3139077f-0ef8-4e39-8ddf-6bc40690414f; Path=/
Transfer-Encoding: chunked
Content-Type: text/html; charset=utf-8
Jonathan Lundell
> I looked at the Rocket web server:
>
> 1) it always responds with HTTP/1.1 even if client is HTTP/1.0. I am
> not sure this is allowed. I think not. A response must follow a
> protocol that is same or lower then requested protocol
> 2) it seems Rocket responds with chunked encoding in two cases: a) the
> request was chunked; b) if the wsgi app returns a list with more than
> one element (web2py can do this but normally does not do it).
>
> There is one caveat abdou 2) There is this code
>
> def write(self, data, sections=None):
> """ Write the data to the output socket. """
> ....
> if not self.headers_sent:
> self.send_headers(data, sections)
>
> If it happens that self.send_headers(data, None) is called, it will
> force chunked-encoding. I do not see how that can happen but I cannot
> exclude since I do not see the logic behind calling send_headers in
> two places.
What's odd is that we see the different cases on identical calls to the same URL.
I found the chunked logic a little confusing, probably because I don't really understand what it's trying to do, or how it gets called.
At least it seems easy to reproduce.
At least in my tests (through web2py.com), I'm seeing Apache. Is that mod_proxy?
mdipierro
Rocket. web2py.com runs on Apache+mod_wsgi.
In this case Apache decides on chunking, not web2py.
It is strange but I do not know what is the Apache policy in this
respect.
Massimo
mdipierro
Jonathan Lundell
> I originally misunderstood the issue. I thought the problem was with
> Rocket. web2py.com runs on Apache+mod_wsgi.
> In this case Apache decides on chunking, not web2py.
>
> It is strange but I do not know what is the Apache policy in this
> respect.
There's a bit of explanation here, along with a fragment of relevant Apache source (in the comments):
http://bytes.com/topic/php/answers/10395-chunked-encoding-php-apache2