On Aug 8, 2012, at 6:34 PM, André Cruz <[email protected]> wrote:

> I'm using uWSGI to serve requests directly, using the HTTP plugin. Sometimes, 
> I still haven't found a pattern, the server stops responding to requests for 
> some minutes. It accepts the connection, but does not seem to do anything 
> with it.

This has happened again, and this time I have more information.

During an HTTP upload, it seems read()ing the data from the client failed and 
an exception was raised. Django's exception handler produced the usual 
traceback to send back to the client but it seems uWSGI blocked while trying to 
send it back to the client. The connection was still in the "ESTABLISHED" state 
but clearly the client did not seem to be ACKing the data. The problem is that 
uWSGI seems to block while doing this.

Here is the uWSGI log:

2012-08-14 11:54:53.867498500   File 
"/servers/python-environments/discosite/local/lib/python2.7/site-packages/django/core/handlers/wsgi.py",
 line 92, in _read_limited
2012-08-14 11:54:53.867501500     result = self.stream.read(size)
2012-08-14 11:54:53.867502500 IOError: error waiting for wsgi.input data
2012-08-14 11:54:54.025669500 [uWSGI DEBUG] called 0x508fcf8 0x7f0c3537a050 8
2012-08-14 11:54:54.027207500 [uWSGI DEBUG] called 0x508fcf8 0x7f0c3537a050 8
2012-08-14 11:54:54.027771500 [uWSGI DEBUG] called 0x508fcf8 0x7f0c3537a050 8
2012-08-14 11:54:54.051595500 [uWSGI DEBUG] called 0x508fcf8 0x7f0c3537a050 8
2012-08-14 11:54:54.051637500 [uWSGI DEBUG] called 0x5e30750 0x61dce18 1
2012-08-14 11:54:54.051731500 [uWSGI DEBUG] called 0x5085488 0x7f0c3537a050 
21894
2012-08-14 11:54:54.052630500 [uWSGI DEBUG] called 0x5085488 0x7f0c3537a050 
21895
2012-08-14 11:54:54.052660500 calling close() for 
/Storage/VID_20120803_174705.m4v 0x967e190 0x7f0c3537a050
2012-08-14 11:54:54.052716500 [pid: 24685|app: 0|req: 1717/4847] x.x.x.x () {32 
vars in 1218 bytes} [Tue Aug 14 11:54:25 2012] PUT 
/Storage/VID_20120803_174705.m4v => generated 213116 bytes in 28173 msecs 
(HTTP/1.1 500) 2 headers in 92 bytes (2 switches on core 9999)
2012-08-14 12:29:39.083605500 send(): Connection timed out [plugins/http/http.c 
line 896]


>From here we can see that Django itself was done with the request at 11:54, 
>but only at 12:29 did uWSGI's http router gave up on sending the response 
>back. No requests could be served during this time. Here is the strace log:

# strace -p 24688
Process 24688 attached - interrupt to quit
sendto(9, "f8\\xf9T\\xc0:\\xaa\\xdfj\\xfe\\xa7\\xb"..., 60532, 0, NULL, 0) = -1 
ETIMEDOUT (Connection timed out)
write(2, "send(): Connection timed out [pl"..., 60) = 60
close(10)                               = 0
close(9)                                = 0
epoll_wait(8, {{EPOLLIN, {u32=4, u64=4}}}, 64, 4294967295) = 1

FD 9 is a socket to the HTTP client which was at the time in the ESTABLISHED 
state, but which was clearly malfunctioning:

uwsgi   24688 www-data    9u  IPv4            4761478      0t0     TCP 
y.y.y.y:www->x.x.x.x:56707 (ESTABLISHED)


I'm using uWSGI (2474:09dd33784cb2) with the Gevent loop and the timeout occurs 
in the uwsgi_http_simple_send() function. Shouldn't this call be nonblocking or 
at least have an aggressive timeout?

Best regards,
André Cruz
_______________________________________________
uWSGI mailing list
[email protected]
http://lists.unbit.it/cgi-bin/mailman/listinfo/uwsgi

Reply via email to