nginx 1.2: static file truncated with HTTP status code 200

[Maxim Dounin]

Hello!

On Wed, May 16, 2012 at 09:40:37AM -0400, mengqy wrote:

> We've been running nginx 1.1.18, 1.1.19, 1.2.0, with both HTTP/HTTPS
> enabled. Our static files are loaded from nginx root, but since 1.1.18
> $request_time of static files some times gets 10+ seconds, recardless
> the actual file size. Various optimizing were tried with little gain,
> and the problem seems irrelavent to browsers as of access log. With

The $request_time variable includes request reading times, as well 
as request sending times.  It may be big even for relatively small 
files if client is slow (and/or just silently gone without closing 
connection).

> 1.2.0 we just noticed that access log shows file truncating with HTTP
> status code 200.  Looking forward to your help, thank you.

Size recorded in $body_bytes_sent / $bytes_sent represents actuall
data size sent to a socket, not a real file size.  I.e. if transfer 
is aborted, e.g. due to timeout and/or connection close by a 
client, it will be smaller than real file size (as long as file is 
bigger than socket's send buffer).

Status code will still be 200 as it represents status sent to 
client.

> 
> ------------------
> Log format:
> ------------------
> 
> log_format  main  '$remote_addr - $remote_user [$time_local]
> [$request_time] [$upstream_response_time] "$request" $request_length ' '
> $status $upstream_addr $body_bytes_sent "$http_referer" '
> '"$http_user_agent" "$http_x_forwarded_for"';
> 
> ---------------------
> access log:
> ---------------------
> 
> 27.129.164.208 - - [16/May/2012:06:44:12 +0800] [15.511] [-] "GET
> /mgt/images/v3/common/f4.gif?v=6 HTTP/1.1" 950  200 - 57756
> "http://x.x.x/mgt/frame.jsp?url=RA9" "Mozilla/4.0 (compatible; MSIE 6.0;
> Windows NT 5.1; SV1; .NET CLR 2.0.50727; 360SE)" "-"
> 27.129.164.208 - - [16/May/2012:06:45:33 +0800] [11.194] [-] "GET
> /mgt/images/v3/common/f4.gif?v=6 HTTP/1.1" 950  200 - 106455
> "http://x.x.x/mgt/frame.jsp?url=RA9" "Mozilla/4.0 (compatible; MSIE 6.0;
> Windows NT 5.1; SV1; .NET CLR 2.0.50727; 360SE)" "-"
> 
> $ ls -l /var/www/html/mgt/mgt/images/v3/common/f4.gif
> -rw-r--r-- 1 root root 106455 2012-04-20 23:09
> /var/www/html/mgt/mgt/images/v3/common/f4.gif
> 
> Actual file size is 106455 bytes, yet the first log shows 57756 bytes.

This is usually just means that client wasn't able to get full 
response for some reason, see above.  In your case it looks like 
send_timeout was triggered, as it's set 10 seconds in your config.  
(Just a side note: client timeouts are logged at "info" level to 
error log.)

This may be a result of some problem in nginx, but highly 
unlikely.  I would rather suggest it's network connectivity 
problems either on your side or on the client's side.

[...]

Maxim Dounin