Timeout when sending over 16k of data with UTF-8 characters

[Maxim Dounin]

Hello!

On Tue, Nov 01, 2011 at 09:13:44AM -0400, Bryan McLellan wrote:

> On Tue, Nov 1, 2011 at 2:21 AM, Igor Sysoev <igor at sysoev.ru> wrote:
> > Could you create debug log:
> > http://nginx.org/en/docs/debugging_log.html
> 
> https://gist.github.com/1330454

2011/11/01 12:44:23 [debug] 13689#0: *129 http header: "Content-Length: 16385"
...
2011/11/01 12:44:23 [debug] 13689#0: *129 http header: "User-Agent: Chef Client/0.10.4 (ruby-1.9.1-p431; ohai-0.6.10; x86_64-linux; +http://opscode.com)"
...

Note: content length is 16385.

...
2011/11/01 12:44:23 [debug] 13689#0: *129 http read client request body
2011/11/01 12:44:23 [debug] 13689#0: *129 SSL_read: -1
2011/11/01 12:44:23 [debug] 13689#0: *129 SSL_get_error: 2
2011/11/01 12:44:23 [debug] 13689#0: *129 http client request body recv -2
2011/11/01 12:44:23 [debug] 13689#0: *129 http client request body rest 16385
...
2011/11/01 12:44:24 [debug] 13689#0: *129 http read client request body
2011/11/01 12:44:24 [debug] 13689#0: *129 SSL_read: 8192
2011/11/01 12:44:24 [debug] 13689#0: *129 http client request body recv 8192
...
2011/11/01 12:44:24 [debug] 13689#0: *129 SSL_read: 8192
2011/11/01 12:44:24 [debug] 13689#0: *129 http client request body recv 8192
2011/11/01 12:44:24 [debug] 13689#0: *129 write: 13, 0870D8E0, 8192, 8192
2011/11/01 12:44:24 [debug] 13689#0: *129 SSL_read: -1
2011/11/01 12:44:24 [debug] 13689#0: *129 SSL_get_error: 2
2011/11/01 12:44:24 [debug] 13689#0: *129 http client request body recv -2
2011/11/01 12:44:24 [debug] 13689#0: *129 http client request body rest 1

Here 16384 bytes has been read from client, and one byte remains 
("rest 1").  OpenSSL doesn't provide any more bytes and claims it 
needs more network input (2, SSL_ERROR_WANT_READ).

2011/11/01 12:44:24 [debug] 13689#0: *129 event timer del: 12: 1596563798
2011/11/01 12:44:24 [debug] 13689#0: *129 event timer add: 12: 60000:1596564354
2011/11/01 12:45:24 [debug] 13689#0: *129 event timer del: 12: 1596564354
2011/11/01 12:45:24 [debug] 13689#0: *129 http run request: "/organizations/opscode-btm/nodes/broken?"
2011/11/01 12:45:24 [debug] 13689#0: *129 http finalize request: 408, "/organizations/opscode-btm/nodes/broken?" a:1, c:1

Though client fails to provide one more byte.

For me, it looks like problem in client.  It's either calculate 
content length incorrectly or fails to properly flush ssl buffers 
on it's side.

Maxim Dounin