Nginx 1.2: static file truncated with HTTP status code 200

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
1.2.0 we just noticed that access log shows file truncating with HTTP
status code 200. Looking forward to your help, thank you.


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.


System info:

$ uname -a
Linux debian 2.6.26-1-amd64 #1 SMP Sat Jan 10 17:57:00 UTC 2009 x86_64
GNU/Linux

CPU: Intel(R) Xeon™ CPU 3.00GHz * 2, 8 cores.

$ nginx -V
nginx version: nginx/1.2.0
built by gcc 4.3.2 (Debian 4.3.2-1.1)
TLS SNI support enabled
configure arguments: --prefix=/usr/local/nginx
–error-log-path=/var/log/nginx/error.log --http-log-path=/var/log/nginx
–user=www-data --group=www-data --with-http_ssl_module
–with-cpu-opt=CPU --with-http_stub_status_module --with-pcre
–add-module=…/nginx-sticky-module-1.0


nginx.conf:

user www-data www-data;
worker_processes 16;
error_log /var/log/nginx/error.log error;
pid logs/nginx.pid;
worker_rlimit_nofile 65535;

events {
use epoll;
worker_connections 4096;
epoll_events 1024;
accept_mutex off;
}
http {
include mime.types;
default_type application/octet-stream;
charset utf-8;

server_names_hash_bucket_size 128;
client_header_buffer_size 32k;
large_client_header_buffers 4 32k;

client_max_body_size 300m;
client_body_buffer_size 512k;

open_file_cache max=10000 inactive=300s;
open_file_cache_valid 300s;
open_file_cache_min_uses 1;
open_file_cache_errors on;

gzip  on;
gzip_min_length 1k;
gzip_buffers 4 16k;
gzip_http_version 1.1;
gzip_comp_level 2;
gzip_types text/plain application/x-javascript text/css

application/xml;
gzip_vary on;

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  /var/log/nginx/access.log  main;

sendfile       on;
tcp_nopush     on;
tcp_nodelay    on;

upstream mgt_tomcats {
  sticky path=/;
  server 192.168.0.40:8080 max_fails=2 fail_timeout=60s;
  server 192.168.0.45:8080 max_fails=2 fail_timeout=60s;
  keepalive 64;
}

server {
    listen x.x.x.x:80;
    include common.conf
}

server {
listen x.x.x.x:443;
ssl on;
ssl_certificate server.crt;
ssl_certificate_key server.key;

    ssl_session_timeout  5m;
    ssl_session_cache shared:SSL:10m;

    ssl_protocols  SSLv2 SSLv3 TLSv1;
    ssl_ciphers  HIGH:!aNULL:!MD5;
    ssl_prefer_server_ciphers   on;

    include common.conf

   # snip, snip, other configurations

}
}

common.conf:

keepalive_timeout 10;

    server_name x.x.x;
    root /var/www/html/mgt;

    proxy_connect_timeout 60;
    proxy_read_timeout 60;
    proxy_send_timeout 10;
    proxy_buffer_size 16k;
    proxy_buffers 4 64k;
    proxy_busy_buffers_size 128k;

    proxy_http_version 1.1;
    proxy_set_header   Connection "";

    proxy_redirect off;
    proxy_set_header Host $host;
    proxy_set_header X-Real-IP $remote_addr;
    proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
    proxy_pass_header User-Agent;

    location ~* ^/(mgt|Apps|mgt-system)/(image|styles|scripts)/ {
            expires 30d;
            if (!-e $request_filename) {
                    proxy_pass http://mgt_tomcats;
                    break;
            }
    }

Posted at Nginx Forum:

Hi,

On Wed, May 16, 2012 at 9:40 PM, mengqy [email protected] 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
1.2.0 we just noticed that access log shows file truncating with HTTP
status code 200. Looking forward to your help, thank you.

Why do you think the file was truncated by Nginx? There’re other reasons
which might cause $body_bytes_sent less than the real size of the file.
For
instance, it can be true when the client closes the connection before
downloading the file completely.

Regards,

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.


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

Sorry for the late thanks to all of you hackers, great job :slight_smile:

Posted at Nginx Forum: