Opened 7 years ago

Last modified 7 years ago

#1329 new defect

Blocking STALE requests when using fastcgi_cache_background_update

Reported by: nixelsolutions@… Owned by:
Priority: minor Milestone:
Component: other Version: 1.13.x
Keywords: Cc: manel@…
uname -a: Linux aaba177d5494 3.16.0-77-generic #99~14.04.1-Ubuntu SMP Tue Jun 28 19:17:10 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux
nginx -V: nginx version: nginx/1.13.3
built with OpenSSL 1.1.0f 25 May 2017
TLS SNI support enabled
configure arguments: --with-cc-opt='-g -O2 -fPIE -fstack-protector --param=ssp-buffer-size=4 -Wformat -Werror=format-security -fPIC -D_FORTIFY_SOURCE=2' --with-ld-opt='-Wl,-Bsymbolic-functions -fPIE -pie -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-SvfEre/nginx-1.13.3/debian/modules/headers-more-nginx-module --add-dynamic-module=/build/nginx-SvfEre/nginx-1.13.3/debian/modules/nginx-auth-pam --add-dynamic-module=/build/nginx-SvfEre/nginx-1.13.3/debian/modules/nginx-cache-purge --add-dynamic-module=/build/nginx-SvfEre/nginx-1.13.3/debian/modules/nginx-dav-ext-module --add-dynamic-module=/build/nginx-SvfEre/nginx-1.13.3/debian/modules/nginx-development-kit --add-dynamic-module=/build/nginx-SvfEre/nginx-1.13.3/debian/modules/nginx-echo --add-dynamic-module=/build/nginx-SvfEre/nginx-1.13.3/debian/modules/ngx-fancyindex --add-dynamic-module=/build/nginx-SvfEre/nginx-1.13.3/debian/modules/nchan --add-dynamic-module=/build/nginx-SvfEre/nginx-1.13.3/debian/modules/nginx-lua --add-dynamic-module=/build/nginx-SvfEre/nginx-1.13.3/debian/modules/nginx-rtmp --add-dynamic-module=/build/nginx-SvfEre/nginx-1.13.3/debian/modules/nginx-upload-progress --add-dynamic-module=/build/nginx-SvfEre/nginx-1.13.3/debian/modules/nginx-upstream-fair --add-dynamic-module=/build/nginx-SvfEre/nginx-1.13.3/debian/modules/ngx_http_substitutions_filter_module

Description

When using fastcgi_cache_background_update nginx will immediately send the STALE response to the client but it will keep client connection open until fastcgi upstream responds. The effect is that the client is waiting until upstream closes its connection.

I first thought it was due to ticket #1249 but apparently this is another problem: before 1.13.1 version the effect was that client received the STALE response (headers+body) after upstream closed the connection, resulting in a high TTFB and fast content download time. After 1.13.1 version, the client receives the STALE response (headers+body) immediately, but the connection is closed after upstream closes its own connection, resulting in a low TTFB but a high content download time.

It is easy to reproduce with a PHP script like this:

Code highlighting:

<?php

echo date("c");

sleep(5);

I'm also using nginx within a Docker container and bridged networking.

Attached you will find the debug log for the request.

Attachments (1)

nginx_background_stale_request.txt (34.0 KB ) - added by nixelsolutions@… 7 years ago.
Request debug log

Download all attachments as: .zip

Change History (3)

by nixelsolutions@…, 7 years ago

Request debug log

comment:1 by Maxim Dounin, 7 years ago

The fastcgi_cache_background_update directives update allows updating an expired cache item while the stale cached response is being returned to the client. If, however, the response is fully returned, but updating is not yet finished, it will delay subsequent actions, including processing of additional requests on the same connection, and/or closing the connection. This behaviour ensures that

  • a client cannot impose uncontrolled load on the server, assuming various limitations like limit_conn in place, and
  • the overall operation is usually better, and in the worst case is no worse than without background update.

Note that this behaviour is intentional and is unlikely to be changed.

In the particular case shown in the debug log, client uses HTTP/1.0 and there is no Content-Length in the response, hence the client doesn't know if the response is complete or not till the connection is closed. Hence, trivial workaround to improve the behaviour would be to use HTTP/1.1 and/or provide Content-Length. We may consider adding a shutdown() call to facilitate this particular case, though I don't think it worth the effort.

comment:2 by nixelsolutions@…, 7 years ago

@mdounin you are right! This nginx server is behing a nginx proxy and I was missing the proxy_http_version parameter. After forcing proxy_http_version to 1.1 the connection is inmediatelly closed. Thanks for the clue! I think we can close this.

Note: See TracTickets for help on using tickets.