Opened 7 years ago
Closed 7 years ago
#1550 closed defect (invalid)
Slice module closes connection unexpectedly
Reported by: | Xin Liu | Owned by: | |
---|---|---|---|
Priority: | minor | Milestone: | |
Component: | nginx-module | Version: | 1.13.x |
Keywords: | ngx_http_slice_module | Cc: | |
uname -a: | Linux bionic 4.15.0-20-generic #21-Ubuntu SMP Tue Apr 24 06:16:15 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux | ||
nginx -V: |
nginx version: nginx/1.14.0 (Ubuntu)
built with OpenSSL 1.1.0g 2 Nov 2017 TLS SNI support enabled configure arguments: --with-cc-opt='-g -O2 -fdebug-prefix-map=/build/nginx-mcUg8N/nginx-1.14.0=. -fstack-protector-strong -Wformat -Werror=format-security -fPIC -Wdate-time -D_FORTIFY_SOURCE=2' --with-ld-opt='-Wl,-Bsymbolic-functions -Wl,-z,relro -Wl,-z,now -fPIC' --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 --modules-path=/usr/lib/nginx/modules --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-http_ssl_module --with-http_stub_status_module --with-http_realip_module --with-http_auth_request_module --with-http_v2_module --with-http_dav_module --with-http_slice_module --with-threads --with-http_addition_module --with-http_flv_module --with-http_geoip_module=dynamic --with-http_gunzip_module --with-http_gzip_static_module --with-http_image_filter_module=dynamic --with-http_mp4_module --with-http_perl_module=dynamic --with-http_random_index_module --with-http_secure_link_module --with-http_sub_module --with-http_xslt_module=dynamic --with-mail=dynamic --with-mail_ssl_module --with-stream=dynamic --with-stream_ssl_module --with-stream_ssl_preread_module --add-dynamic-module=/build/nginx-mcUg8N/nginx-1.14.0/debian/modules/http-headers-more-filter --add-dynamic-module=/build/nginx-mcUg8N/nginx-1.14.0/debian/modules/http-auth-pam --add-dynamic-module=/build/nginx-mcUg8N/nginx-1.14.0/debian/modules/http-cache-purge --add-dynamic-module=/build/nginx-mcUg8N/nginx-1.14.0/debian/modules/http-dav-ext --add-dynamic-module=/build/nginx-mcUg8N/nginx-1.14.0/debian/modules/http-ndk --add-dynamic-module=/build/nginx-mcUg8N/nginx-1.14.0/debian/modules/http-echo --add-dynamic-module=/build/nginx-mcUg8N/nginx-1.14.0/debian/modules/http-fancyindex --add-dynamic-module=/build/nginx-mcUg8N/nginx-1.14.0/debian/modules/nchan --add-dynamic-module=/build/nginx-mcUg8N/nginx-1.14.0/debian/modules/http-lua --add-dynamic-module=/build/nginx-mcUg8N/nginx-1.14.0/debian/modules/rtmp --add-dynamic-module=/build/nginx-mcUg8N/nginx-1.14.0/debian/modules/http-uploadprogress --add-dynamic-module=/build/nginx-mcUg8N/nginx-1.14.0/debian/modules/http-upstream-fair --add-dynamic-module=/build/nginx-mcUg8N/nginx-1.14.0/debian/modules/http-subs-filter |
Description
With slice module enabled, this curl command can always trigger the problem:
curl -v -o /dev/null -H "Host: demo.ogslb.com" -H "Range: bytes=4000001-5000000" http://10.1.0.108/sample.mp4
curl output:
% Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0* Trying 10.1.0.108... * TCP_NODELAY set * Connected to 10.1.0.108 (10.1.0.108) port 80 (#0) > GET /sample.mp4 HTTP/1.1 > Host: demo.ogslb.com > User-Agent: curl/7.54.0 > Accept: */* > Range: bytes=4000001-5000000 > < HTTP/1.1 206 Partial Content < Server: nginx/1.14.0 (Ubuntu) < Date: Thu, 10 May 2018 07:12:14 GMT < Content-Type: video/mp4 < Content-Length: 1000000 < Connection: keep-alive < Last-Modified: Sun, 28 Feb 2016 19:56:29 GMT < ETag: "56d350ed-3208b07" < Expires: Thu, 07 Jun 2018 07:12:14 GMT < Cache-Control: max-age=2419200 < X-Cache: HIT from bionic < Content-Range: bytes 4000001-5000000/52464391 < { [8297 bytes data] * transfer closed with 855591 bytes remaining to read * stopped the pause stream! 14 976k 14 141k 0 0 5817k 0 --:--:-- --:--:-- --:--:-- 5876k * Closing connection 0 curl: (18) transfer closed with 855591 bytes remaining to read
When this problem occurs, this can be observed in the debug error log:
2018/05/10 07:12:14 [debug] 13724#13724: *32 http slice response range: 0-4194304/52464391 2018/05/10 07:12:14 [error] 13724#13724: *32 unexpected range in slice response: 0-4194304, client: 10.1.0.45, server: demo.ogslb.com, request: "GET /sample.mp4 HTTP/1.1", subrequest: "/sample.mp4", host: "demo.ogslb.com"
While the error log above stated "0-4194304", the actual Content-Range from upstream is 1 byte fewer, also can be observed earlier in the debug error log:
2018/05/10 07:12:14 [debug] 13724#13724: *32 http proxy header: "Content-Range: bytes 0-4194303/52464391"
The full debug error log regarding this one request is attached.
NGINX config for this server:
proxy_cache_path /data/demo levels=1:2 keys_zone=demo:64m max_size=8g inactive=14d; upstream demo_backend { server 192.254.90.134:80 max_fails=0 fail_timeout=0; keepalive 4; } server { listen 80; server_name demo.ogslb.com; access_log /var/log/nginx/demo.access.log; error_log /var/log/nginx/demo.error.log debug; location / { slice 4m; proxy_set_header Range $slice_range; proxy_http_version 1.1; proxy_set_header Connection ""; proxy_set_header Host "demo.ogslb.com"; proxy_cache demo; proxy_cache_revalidate off; set $demo_cache_key $scheme://demo.ogslb.com$uri$is_args$args$slice_range; proxy_cache_valid 200 206 2419200s; expires 2419200s; proxy_cache_valid 301 302 2419200s; proxy_cache_key $demo_cache_key; proxy_cache_min_uses 1; proxy_cache_valid 403 404 500 0s; add_header X-Cache "$upstream_cache_status from $hostname"; proxy_pass http://demo_backend; } }
Attachments (1)
Change History (4)
by , 7 years ago
Attachment: | demo.error.log added |
---|
follow-up: 2 comment:1 by , 7 years ago
This line
set $demo_cache_key $scheme://demo.ogslb.com$uri$is_args$args$slice_range;
is evaluated only once - at main request's rewrite phase. Slice subrequests retain the old value of this key with the initial $slice_range
equal to bytes=0-4194303
. That's why for the second slice in fact the first slice is fetched again, which causes the error.
To fix the issue, eliminate the variable and set proxy_cache_key
directly.
comment:3 by , 7 years ago
Resolution: | → invalid |
---|---|
Status: | new → closed |
debug error log