Welcome! Log In Create A New Profile

Advanced

cache revalidation bug

February 27, 2015 03:18AM
I’m experiencing an issue that cached 404 responses are revalidated when the requested file are available again on the backend server with an older time stamp. Hereby the details of my issue.



Nginx version/build details

# nginx -V
nginx version: nginx/1.7.10
built by gcc 4.8.2 (Ubuntu 4.8.2-19ubuntu1)
TLS SNI support enabled
configure arguments: --prefix=/usr/share/nginx --sbin-path=/usr/sbin/nginx --conf-path=/etc/nginx/nginx.conf --error-log-path=/var/log/nginx/error.log --http-client-body-temp-path=/var/lib/nginx/body --http-log-path=/var/log/nginx/access.log --http-proxy-temp-path=/tmp --lock-path=/var/lock/nginx.lock --pid-path=/var/run/nginx.pid --without-http_fastcgi_module --without-http_uwsgi_module --without-http_scgi_module --with-http_flv_module --with-http_geoip_module --with-http_gzip_static_module --with-http_mp4_module --with-http_realip_module --with-http_secure_link_module --with-http_stub_status_module --with-http_ssl_module --with-ipv6 --with-sha1=/usr/include/openssl --with-md5=/usr/include/openssl --with-aio_module --with-file-aio --with-http_spdy_module --with-debug


vhost is configured with

server {
listen 80;

server_name test.domain.tld;
set $origin backend.domain.tld;

expires off;

location /
{
client_max_body_size 0;
client_body_buffer_size 8k;
proxy_connect_timeout 60;
proxy_send_timeout 60;
proxy_read_timeout 60;
proxy_buffer_size 16k;
proxy_buffers 256 16k;
proxy_buffering on;
proxy_max_temp_file_size 1m;
proxy_ignore_client_abort on;
proxy_intercept_errors on;
proxy_next_upstream error timeout invalid_header;

proxy_cache one;
proxy_cache_min_uses 1;
proxy_cache_lock off;
proxy_cache_lock_timeout 5s;

proxy_cache_valid 200 302 301 1m;
proxy_cache_valid 404 5s;
proxy_cache_revalidate on;

proxy_set_header Host $origin;
proxy_pass_header Set-Cookie;

proxy_set_header Range "";
proxy_set_header Request-Range "";
proxy_set_header If-Range "";

proxy_cache_key "$scheme://$host$uri";
proxy_pass http://$origin$uri;
proxy_redirect off;
}
}




Log format used

¦$bytes_sent¦$remote_addr¦$msec¦$status¦$http_referer¦$http_user_agent¦$request_time¦$request_method $request_uri $server_protocol¦$server_port¦$upstream_cache_status¦$upstream_status¦$upstream_response_time¦$request_completion¦$backend_server¦



Requesting non-existen file. 404 will be cached for 5 second
after 5 seconds its expires, file is fetched from backend that gives 404 again

¦469¦[remote.ip.addr]¦1424963103.586¦404¦-¦curl/7.35.0¦0.027¦GET /pica.jpg HTTP/1.1¦80¦MISS¦404¦0.027¦OK¦[backend.server]¦
¦469¦[remote.ip.addr]¦1424963104.605¦404¦-¦curl/7.35.0¦0.000¦GET /pica.jpg HTTP/1.1¦80¦HIT¦-¦-¦OK¦[backend.server]¦
¦469¦[remote.ip.addr]¦1424963108.679¦404¦-¦curl/7.35.0¦0.000¦GET /pica.jpg HTTP/1.1¦80¦HIT¦-¦-¦OK¦[backend.server]¦
¦469¦[remote.ip.addr]¦1424963109.724¦404¦-¦curl/7.35.0¦0.027¦GET /pica.jpg HTTP/1.1¦80¦EXPIRED¦404¦0.027¦OK¦[backend.server]¦
¦469¦[remote.ip.addr]¦1424963110.742¦404¦-¦curl/7.35.0¦0.000¦GET /pica.jpg HTTP/1.1¦80¦HIT¦-¦-¦OK¦[backend.server]¦
¦469¦[remote.ip.addr]¦1424963114.815¦404¦-¦curl/7.35.0¦0.000¦GET /pica.jpg HTTP/1.1¦80¦HIT¦-¦-¦OK¦[backend.server]¦
¦469¦[remote.ip.addr]¦1424963115.860¦404¦-¦curl/7.35.0¦0.027¦GET /pica.jpg HTTP/1.1¦80¦EXPIRED¦404¦0.027¦OK¦[backend.server]¦
¦469¦[remote.ip.addr]¦1424963116.879¦404¦-¦curl/7.35.0¦0.000¦GET /pica.jpg HTTP/1.1¦80¦HIT¦-¦-¦OK¦[backend.server]¦
¦469¦[remote.ip.addr]¦1424963120.952¦404¦-¦curl/7.35.0¦0.000¦GET /pica.jpg HTTP/1.1¦80¦HIT¦-¦-¦OK¦[backend.server]¦


[Placed file on backend server (move), file has timestamp of year 2013]
404 expires, file is fetched from backend and cached

¦49166¦[remote.ip.addr]¦1424963122.033¦200¦-¦curl/7.35.0¦0.063¦GET /pica.jpg HTTP/1.1¦80¦EXPIRED¦200¦0.063¦OK¦[backend.server]¦
¦49162¦[remote.ip.addr]¦1424963123.037¦200¦-¦curl/7.35.0¦0.000¦GET /pica.jpg HTTP/1.1¦80¦HIT¦-¦-¦OK¦[backend.server]¦
¦49162¦[remote.ip.addr]¦1424963181.036¦200¦-¦curl/7.35.0¦0.000¦GET /pica.jpg HTTP/1.1¦80¦HIT¦-¦-¦OK¦[backend.server]¦


File expires, revalidation is send to backend and cached file is updated

¦49170¦[remote.ip.addr]¦1424963182.081¦200¦-¦curl/7.35.0¦0.027¦GET /pica.jpg HTTP/1.1¦80¦REVALIDATED¦304¦0.027¦OK¦[backend.server]¦
¦49162¦[remote.ip.addr]¦1424963183.098¦200¦-¦curl/7.35.0¦0.000¦GET /pica.jpg HTTP/1.1¦80¦HIT¦-¦-¦OK¦[backend.server]¦
¦49162¦[remote.ip.addr]¦1424963242.103¦200¦-¦curl/7.35.0¦0.000¦GET /pica.jpg HTTP/1.1¦80¦HIT¦-¦-¦OK¦[backend.server]¦


[File is removed from backend]
File expires, file is fetched from backend that gives 404

¦469¦[remote.ip.addr]¦1424963243.148¦404¦-¦curl/7.35.0¦0.027¦GET /pica.jpg HTTP/1.1¦80¦EXPIRED¦404¦0.027¦OK¦[backend.server]¦
¦469¦[remote.ip.addr]¦1424963244.167¦404¦-¦curl/7.35.0¦0.000¦GET /pica.jpg HTTP/1.1¦80¦HIT¦-¦-¦OK¦[backend.server]¦
¦469¦[remote.ip.addr]¦1424963248.240¦404¦-¦curl/7.35.0¦0.000¦GET /pica.jpg HTTP/1.1¦80¦HIT¦-¦-¦OK¦[backend.server]¦
¦469¦[remote.ip.addr]¦1424963249.285¦404¦-¦curl/7.35.0¦0.027¦GET /pica.jpg HTTP/1.1¦80¦EXPIRED¦404¦0.027¦OK¦[backend.server]¦
¦469¦[remote.ip.addr]¦1424963250.304¦404¦-¦curl/7.35.0¦0.000¦GET /pica.jpg HTTP/1.1¦80¦HIT¦-¦-¦OK¦[backend.server]¦
¦469¦[remote.ip.addr]¦1424963254.376¦404¦-¦curl/7.35.0¦0.000¦GET /pica.jpg HTTP/1.1¦80¦HIT¦-¦-¦OK¦[backend.server]¦


[Placed file back on backend server (move), file has timestamp of year 2013]
404 expires, revalidation is done, because times stamp of file is older then time the 404 was fetched/cached it revalidates??
- bug? it should not revalidate 404, just expire and fetch actual file!

¦469¦[remote.ip.addr]¦1424963255.421¦404¦-¦curl/7.35.0¦0.027¦GET /pica.jpg HTTP/1.1¦80¦REVALIDATED¦304¦0.027¦OK¦[backend.server]¦
¦469¦[remote.ip.addr]¦1424963256.439¦404¦-¦curl/7.35.0¦0.000¦GET /pica.jpg HTTP/1.1¦80¦HIT¦-¦-¦OK¦[backend.server]¦
¦469¦[remote.ip.addr]¦1424963260.514¦404¦-¦curl/7.35.0¦0.000¦GET /pica.jpg HTTP/1.1¦80¦HIT¦-¦-¦OK¦[backend.server]¦
¦469¦[remote.ip.addr]¦1424963261.559¦404¦-¦curl/7.35.0¦0.027¦GET /pica.jpg HTTP/1.1¦80¦REVALIDATED¦304¦0.027¦OK¦[backend.server]¦
¦469¦[remote.ip.addr]¦1424963262.577¦404¦-¦curl/7.35.0¦0.000¦GET /pica.jpg HTTP/1.1¦80¦HIT¦-¦-¦OK¦[backend.server]¦
¦469¦[remote.ip.addr]¦1424963266.650¦404¦-¦curl/7.35.0¦0.000¦GET /pica.jpg HTTP/1.1¦80¦HIT¦-¦-¦OK¦[backend.server]¦
¦469¦[remote.ip.addr]¦1424963267.697¦404¦-¦curl/7.35.0¦0.029¦GET /pica.jpg HTTP/1.1¦80¦REVALIDATED¦304¦0.029¦OK¦[backend.server]¦
¦469¦[remote.ip.addr]¦1424963268.715¦404¦-¦curl/7.35.0¦0.000¦GET /pica.jpg HTTP/1.1¦80¦HIT¦-¦-¦OK¦[backend.server]¦
¦469¦[remote.ip.addr]¦1424963272.788¦404¦-¦curl/7.35.0¦0.000¦GET /pica.jpg HTTP/1.1¦80¦HIT¦-¦-¦OK¦[backend.server]¦


[File is removed from backend]
Now the File expires, file is fetched from backend that gives 404 (probably because timestamp is newer?)

¦469¦[remote.ip.addr]¦1424963291.224¦404¦-¦curl/7.35.0¦0.027¦GET /pica.jpg HTTP/1.1¦80¦EXPIRED¦404¦0.027¦OK¦[backend.server]¦
¦469¦[remote.ip.addr]¦1424963292.242¦404¦-¦curl/7.35.0¦0.000¦GET /pica.jpg HTTP/1.1¦80¦HIT¦-¦-¦OK¦[backend.server]¦
¦469¦[remote.ip.addr]¦1424963296.315¦404¦-¦curl/7.35.0¦0.000¦GET /pica.jpg HTTP/1.1¦80¦HIT¦-¦-¦OK¦[backend.server]¦
¦469¦[remote.ip.addr]¦1424963297.360¦404¦-¦curl/7.35.0¦0.027¦GET /pica.jpg HTTP/1.1¦80¦EXPIRED¦404¦0.027¦OK¦[backend.server]¦
¦469¦[remote.ip.addr]¦1424963298.379¦404¦-¦curl/7.35.0¦0.000¦GET /pica.jpg HTTP/1.1¦80¦HIT¦-¦-¦OK¦[backend.server]¦
¦469¦[remote.ip.addr]¦1424963302.457¦404¦-¦curl/7.35.0¦0.000¦GET /pica.jpg HTTP/1.1¦80¦HIT¦-¦-¦OK¦[backend.server]¦


[Placed file back on backend server (copy), file has timestamp of current time
404 expires, revalidation is done??, because times stamp of file is newer then time the 404 was fetched/cached it actually fetches the file

¦49166¦[remote.ip.addr]¦1424963303.537¦200¦-¦curl/7.35.0¦0.059¦GET /pica.jpg HTTP/1.1¦80¦EXPIRED¦200¦0.059¦OK¦[backend.server]¦
¦49162¦[remote.ip.addr]¦1424963304.544¦200¦-¦curl/7.35.0¦0.000¦GET /pica.jpg HTTP/1.1¦80¦HIT¦-¦-¦OK¦[backend.server]¦


Regards,

Jeffrey K.



_______________________________________________
nginx-devel mailing list
nginx-devel@nginx.org
http://mailman.nginx.org/mailman/listinfo/nginx-devel
Subject Author Views Posted

cache revalidation bug

tehmaniax 999 February 27, 2015 03:18AM

Re: cache revalidation bug

Roman Arutyunyan 510 March 02, 2015 11:54AM

Re: cache revalidation bug

tehmaniax 711 March 02, 2015 12:38PM



Sorry, you do not have permission to post/reply in this forum.

Online Users

Guests: 307
Record Number of Users: 8 on April 13, 2023
Record Number of Guests: 421 on December 02, 2018
Powered by nginx      Powered by FreeBSD      PHP Powered      Powered by MariaDB      ipv6 ready