[uWSGI] randomly missing body in POST request

mathieu lacage mathieu.lacage at alcmeon.com
Tue Mar 12 10:14:16 UTC 2019


Hi,

My production servers are deployed as 4 uwsgi instances:

front1 -> admin3+admin4
front2 -> admin3+admin4

front1/2 are load balanced at the DNS level and perform ssl termination
with uwsgi and forward requests to admin3/4 by using an http subscription
server. admin3/4 run my python application within a simple uwsgi master+5
slaves.

Before you ask: on all 4 servers,
$ uwsgi --version
2.0.15-debian

Recently, I became aware of a low-probability bug triggered by multiple
customers across a wide range of access networks that happens when reading
the body of my incoming POST HTTP requests at the application level.

Here is a typical backtrace:

Mar 09 08:32:10 admin3 uwsgi[8246]: admin-5   ERROR       root timeout
during read(2) on wsgi.input
                                    Traceback (most recent call last):
                                      File
"/usr/local/lib/python2.7/dist-packages/webapp2.py", line 1535, in __call__
                                        rv = self.handle_exception(request,
response, e)
                                      File
"/usr/local/lib/python2.7/dist-packages/webapp2.py", line 1529, in __call__
                                        rv = self.router.dispatch(request,
response)
                                      File
"/usr/local/lib/python2.7/dist-packages/webapp2.py", line 1278, in
default_dispatcher
                                        return
route.handler_adapter(request, response)
                                      File
"/usr/local/lib/python2.7/dist-packages/webapp2.py", line 1102, in __call__
                                        return handler.dispatch()
                                      File "admin2/BaseHandler.py", line
99, in dispatch
                                        self._do_dispatch(user)
                                      File "admin2/BaseHandler.py", line
327, in _do_dispatch
                                        self._begin_transaction(company_id,
user)
                                      File "admin2/BaseRequestHandler.py",
line 210, in _begin_transaction
                                        self._data = self.request.body
                                      File
"/usr/lib/python2.7/dist-packages/webob/request.py", line 702, in body
                                        self.make_body_seekable() # we need
this to have content_length
                                      File
"/usr/lib/python2.7/dist-packages/webob/request.py", line 930, in
make_body_seekable
                                        self.copy_body()
                                      File
"/usr/lib/python2.7/dist-packages/webob/request.py", line 954, in copy_body
                                        data = input.read(min(todo, 65535))
                                      File
"/usr/lib/python2.7/dist-packages/webob/request.py", line 1540, in readinto
                                        data = self.file.read(sz0)
                                    IOError: timeout during read(2) on
wsgi.input
Mar 09 08:32:10 admin3 admin[3875]: [uwsgi-body-read] Timeout reading 2
bytes. Content-Length: 2 consumed: 0 left: 2

Ok, I get this: my application is trying to read these damn 2 bytes but
they are not in the wsgi input file so, uwsgi triggers the 4s (default
value) socket timeout.

Now, the issue here is that I'd like to figure out if these damn bytes were
actually received on the application server and if not, where they got lost
so I can blame someone else.

Has anyone any idea on what I could do to debug/trace this further on my
production infrastructure ? (clearly, logging all incoming traffic with
tcpdump is not an option)

Mathieu
-- 
Mathieu Lacage <mathieu.lacage at alcmeon.com>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.unbit.it/pipermail/uwsgi/attachments/20190312/5b29a782/attachment.html>


More information about the uWSGI mailing list