id	summary	reporter	owner	description	type	status	priority	milestone	component	version	resolution	keywords	cc	uname	nginx_version
1723	proxy_cache_background_update does not really do updates in the background	Nathalie Sautou		"When successively requesting multiple stale urls '''using the same connection''' on a location with `proxy_cache_background_update on`, the update time of each request delays the processing of the next one.

To reproduce, you can use this simple site configuration:

{{{
proxy_cache_path  /srv/test_cache
                  keys_zone=keyz:32m
                  inactive=30s
                  max_size=1g;

server {
    listen 8080 default_server;

    location / {
        proxy_pass http://httpbin.org;
        proxy_set_header Host httpbin.org;

        proxy_cache keyz;
        proxy_cache_valid 200 10s;
        proxy_cache_background_update on;
        proxy_cache_use_stale updating;

        add_header X-Cache-Status $upstream_cache_status;
    }
}
}}}

And the following test script:

{{{
CURL_OPTIONS='-so /dev/null -w ""%{time_total} %{http_code} %{url_effective}\n""'
NGINX_HOST='test-cache-host:8080'

# Populate cache
eval ""curl ${CURL_OPTIONS} http://${NGINX_HOST}/delay/2 ${CURL_OPTIONS} http://${NGINX_HOST}/delay/3""
echo ""Waiting for the cache to become stale...""
sleep 11
# Make the same requests (using a unique session)
eval ""curl ${CURL_OPTIONS} http://${NGINX_HOST}/delay/2 ${CURL_OPTIONS} http://${NGINX_HOST}/delay/3""
}}}

Running the script against this configuration gives an output like the following. For the sake of brevity headers are not included in the output, but the cache status is correct: MISS for the 2 first requests, STALE for the others.

{{{
2,182513 200 http://test-cache-host:8080/delay/2
3,223398 200 http://test-cache-host:8080/delay/3
Waiting for the cache to become stale...
0,208964 200 http://test-cache-host:8080/delay/2
2,184092 200 http://test-cache-host:8080/delay/3
}}}

As you can see, the last request took 2 seconds to get an answer even though the stale version was used!

From the debug log and the client behavior, it looks like the following is happening:
- the client requests http://test-cache-host:8080/delay/2
- nginx immediately serves the stale version
- nginx ""background"" updates its cache - but in fact, it is still ""processing"" the first request and it won't start looking into the next one until it is finished
- the client requests http://test-cache-host:8080/delay/3 in the same session
- nginx is still updating its cache
- http://httpbin.org/delay/2 answers after 2 seconds
- the cache for the first request is up to date
- nginx finally starts processing the second request
- ...

Adding `keepalive_timeout 0;` in the `location` of the above configuration forces the client to setup a new session after getting the first response. As the 2 requests come from different sessions, the second request is not delayed:

{{{
2,180887 200 http://test-cache-host:8080/delay/2
3,179635 200 http://test-cache-host:8080/delay/3
Waiting for the cache to become stale...
0,208349 200 http://test-cache-host:8080/delay/2
0,203867 200 http://test-cache-host:8080/delay/3
}}}"	defect	closed	minor		nginx-module	1.14.x	wontfix	cache		Linux test-cache-host 4.9.0-8-amd64 #1 SMP Debian 4.9.130-2 (2018-10-27) x86_64 GNU/Linux	"nginx version: nginx/1.14.1
built with OpenSSL 1.1.0f  25 May 2017 (running with OpenSSL 1.1.0j  20 Nov 2018)
TLS SNI support enabled
configure arguments: --with-cc-opt='-g -O2 -fdebug-prefix-map=/build/nginx-jqo7Nx/nginx-1.14.1=. -fstack-protector-strong -Wformat -Werror=format-security -fPIC -Wdate-time -D_FORTIFY_SOURCE=2' --with-ld-opt='-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_geoip_module=dynamic --with-http_gunzip_module --with-http_gzip_static_module --with-http_image_filter_module=dynamic --with-http_sub_module --with-http_xslt_module=dynamic --with-stream=dynamic --with-stream_ssl_module --with-stream_ssl_preread_module --with-mail=dynamic --with-mail_ssl_module --add-dynamic-module=/build/nginx-jqo7Nx/nginx-1.14.1/debian/modules/http-auth-pam --add-dynamic-module=/build/nginx-jqo7Nx/nginx-1.14.1/debian/modules/http-dav-ext --add-dynamic-module=/build/nginx-jqo7Nx/nginx-1.14.1/debian/modules/http-echo --add-dynamic-module=/build/nginx-jqo7Nx/nginx-1.14.1/debian/modules/http-upstream-fair --add-dynamic-module=/build/nginx-jqo7Nx/nginx-1.14.1/debian/modules/http-subs-filter
"