﻿id	summary	reporter	owner	description	type	status	priority	milestone	component	version	resolution	keywords	cc	uname	nginx_version
1005	client_body_timeout does not send 408 as advertised	simonhf@…		"client_body_timeout [1] docs says ""If a client does not transmit anything within this time, the 408 (Request Time-out) error is returned to the client."" but this is not true. What happens is that nginx logs a 408 to the access log, but does not send a 408 to client, instead just ungracefully closing the connection. This dropping behavior causes problems with some clients, for example, the Amazon Elastic Load Balancer AKA ELB. 

Here is how to reproduce:

Use the attached nginx.conf file (minimally modified from the default) and restart nginx.

Send 2 healthy POST requests to ensure that the nginx.conf is working:

$ perl -e '$|++; $request = qq[POST http://127.0.0.1:80/logpost HTTP/1.1\r\nhost: 127.0.0.1\r\nContent-length: 10\r\nConnection: keep-alive\r\n\r\n0123456789]; print $request; sleep 5; print $request; sleep 5;' | nc -v 127.0.0.1 80 2>&1 | perl -MTime::HiRes -lane 'printf qq[%f %s\n], Time::HiRes::time(), $_;'
1466811503.325930 Connection to 127.0.0.1 80 port [tcp/http] succeeded!
1466811503.325998 HTTP/1.1 200 OK
1466811503.326008 Server: nginx/1.9.3 (Ubuntu)
1466811503.326017 Date: Fri, 24 Jun 2016 23:38:23 GMT
1466811503.326023 Content-Type: application/octet-stream
1466811503.326030 Content-Length: 0
1466811503.326035 Connection: keep-alive
1466811503.326041 
1466811508.323207 HTTP/1.1 200 OK
1466811508.323417 Server: nginx/1.9.3 (Ubuntu)
1466811508.323446 Date: Fri, 24 Jun 2016 23:38:28 GMT
1466811508.323461 Content-Type: application/octet-stream
1466811508.323474 Content-Length: 0
1466811508.323486 Connection: keep-alive
1466811508.323498

Check that they got logged correctly:

$ sudo tail -n 4 /var/log/nginx/access.log
127.0.0.1 - - [24/Jun/2016:16:38:23 -0700] ""POST http://127.0.0.1:80/logpost HTTP/1.1"" 200 0 ""-"" ""-""
0123456789
127.0.0.1 - - [24/Jun/2016:16:38:28 -0700] ""POST http://127.0.0.1:80/logpost HTTP/1.1"" 200 0 ""-"" ""-""
0123456789

Now send 2 unhealthy POST requests where the body is incomplete thus triggering the client_body_timeout:

$ perl -e '$|++; $request = qq[POST http://127.0.0.1:80/logpost HTTP/1.1\r\nhost: 127.0.0.1\r\nContent-length: 10\r\nConnection: keep-alive\r\n\r\n0]; print $request; sleep 5; print $request; sleep 5;' | nc -v 127.0.0.1 80 2>&1 | perl -MTime::HiRes -lane 'printf qq[%f %s\n], Time::HiRes::time(), $_;'
1466811649.281460 Connection to 127.0.0.1 80 port [tcp/http] succeeded!
$

According to the docs then we expect a 408 response, but no 408 response is returned.

However, the access log incorrectly states that a 408 response was made:

$ sudo tail -n 6 /var/log/nginx/access.log
127.0.0.1 - - [24/Jun/2016:16:38:23 -0700] ""POST http://127.0.0.1:80/logpost HTTP/1.1"" 200 0 ""-"" ""-""
0123456789
127.0.0.1 - - [24/Jun/2016:16:38:28 -0700] ""POST http://127.0.0.1:80/logpost HTTP/1.1"" 200 0 ""-"" ""-""
0123456789
127.0.0.1 - - [24/Jun/2016:16:40:50 -0700] ""POST http://127.0.0.1:80/logpost HTTP/1.1"" 408 0 ""-"" ""-""
0

The RFC [2] clearly says that ""When a client or server wishes to time-out it SHOULD issue a graceful close on the transport connection."" and further says ""A client, server, or proxy MAY close the transport connection at any time."" implying that a graceful close is a ""Connection: close"" response. 

Further it says ""Servers SHOULD always respond to at least one request per connection, if at all possible. Servers SHOULD NOT close a connection in the middle of transmitting a response, unless a network or client failure is suspected.""

Therefore, I submit that nginx not responding with a 408 response is a bug. And a bug which should be fixed sooner, because it is known to cause the Amazon ELB to further behave in a buggy way.

[1] http://nginx.org/en/docs/http/ngx_http_core_module.html#client_body_timeout
[2] https://tools.ietf.org/html/rfc2616#section-8.1.4"	defect	closed	major		documentation	1.9.x	fixed			Linux ubuntu 4.2.0-30-generic #36-Ubuntu SMP Fri Feb 26 00:58:07 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux	"nginx version: nginx/1.9.3 (Ubuntu)
built with OpenSSL 1.0.2d 9 Jul 2015
TLS SNI support enabled
configure arguments: --with-cc-opt='-g -O2 -fPIE -fstack-protector-strong -Wformat -Werror=format-security -D_FORTIFY_SOURCE=2' --with-ld-opt='-Wl,-Bsymbolic-functions -fPIE -pie -Wl,-z,relro -Wl,-z,now' --prefix=/usr/share/nginx --conf-path=/etc/nginx/nginx.conf --http-log-path=/var/log/nginx/access.log --error-log-path=/var/log/nginx/error.log --lock-path=/var/lock/nginx.lock --pid-path=/run/nginx.pid --http-client-body-temp-path=/var/lib/nginx/body --http-fastcgi-temp-path=/var/lib/nginx/fastcgi --http-proxy-temp-path=/var/lib/nginx/proxy --http-scgi-temp-path=/var/lib/nginx/scgi --http-uwsgi-temp-path=/var/lib/nginx/uwsgi --with-debug --with-pcre-jit --with-ipv6 --with-http_ssl_module --with-http_stub_status_module --with-http_realip_module --with-http_auth_request_module --with-http_addition_module --with-http_dav_module --with-http_geoip_module --with-http_gunzip_module --with-http_gzip_static_module --with-http_image_filter_module --with-http_spdy_module --with-http_sub_module --with-http_xslt_module --with-stream --with-stream_ssl_module --with-mail --with-mail_ssl_module --with-threads --add-module=/build/nginx-fcyDbp/nginx-1.9.3/debian/modules/nginx-auth-pam --add-module=/build/nginx-fcyDbp/nginx-1.9.3/debian/modules/nginx-dav-ext-module --add-module=/build/nginx-fcyDbp/nginx-1.9.3/debian/modules/nginx-echo --add-module=/build/nginx-fcyDbp/nginx-1.9.3/debian/modules/nginx-upstream-fair --add-module=/build/nginx-fcyDbp/nginx-1.9.3/debian/modules/ngx_http_substitutions_filter_module"
