Hello Jeffrey K,
On Fri, Feb 27, 2015 at 09:16:27AM +0100, Jeffrey K. wrote:
> 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
> [email protected]
> http://mailman.nginx.org/mailman/listinfo/nginx-devel
Thanks for your report.
We've just committed a fix for this.
--
Roman Arutyunyan
_______________________________________________
nginx-devel mailing list
[email protected]
http://mailman.nginx.org/mailman/listinfo/nginx-devel
