[uWSGI] randomly missing body in POST request

mathieu lacage mathieu.lacage at alcmeon.com
Wed Mar 13 16:58:52 UTC 2019


I bisected the bug to the frontal: the attached script capture the live TCP
connections from the frontal to the application server upon status 500
errors and I can confirm that the request body payload is missing from
these sessions so, the frontal did not send the bytes to the application
server.

Now, it could be that I do not receive the missing bytes on my frontal or
the frontal is dropping them. I can't reuse the same script because my
frontal's traffic is encrypted.

Is there a way to make uwsgi dump somewhere the decryption keys for an ssl
session so I could decrypt the associated traffic on the fly and dump the
traffic for later inspection when I see a 500 ?

Mathieu

Le mar. 12 mars 2019 à 11:14, mathieu lacage <mathieu.lacage at alcmeon.com> a
écrit :

> 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>
>


-- 
Mathieu Lacage <mathieu.lacage at alcmeon.com>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.unbit.it/pipermail/uwsgi/attachments/20190313/87808501/attachment.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: uwsgi-cap.py
Type: text/x-python
Size: 1980 bytes
Desc: not available
URL: <http://lists.unbit.it/pipermail/uwsgi/attachments/20190313/87808501/attachment.py>


More information about the uWSGI mailing list