Bug while using "proxy_cache_use_stale updating"

[Jérôme Loyet]

Hi everybody,

I come up with a strange bug. I'm using nginx as a proxy cache to apache.

I'm using the following conf (only useful line):
  proxy_buffering on;
  proxy_buffers 4 8k;
  proxy_cache_use_stale updating error timeout invalid_header http_500
http_502 http_503 http_504;
  proxy_cache_key $scheme$host$request_uri;
  proxy_send_timeout 5;
  proxy_read_timeout 120;
  proxy_connect_timeout 5;
  proxy_hide_header X-Powered-By;
  proxy_cache_path /LIBRE/nginx/cache levels=1:2
keys_zone=cache.www:10m inactive=1d max_size=4g;
  proxy_ignore_headers Expires Cache-Control;

  ...

  upstream backend.www {
    server 10.26.49.71:8004;
    server 10.26.49.71:8005;
    server 10.26.49.71:8006;
    server 10.26.49.71:8007;
    server 10.26.49.71:8011;
    server 10.26.49.71:8012;
    server 10.26.49.71:8015;
    server 10.26.49.71:8016;
  }

  server {
    proxy_cache cache.www;
    location / {
      proxy_cache_valid 200 302 1m;
      gzip on;
      proxy_pass http://backend.www;
    }
...
Until now everything was working great. But a bug come up to me.

It seems that for an unknown reason, an "update cache" request didn't
go well. And it stays as is (state: UPDATING). So every next request
are served from cache because for nginx there is still a request to
the backend running for this request. So even hours after having
removing a page in the backend, nginx is still serving the old and
valid (not 404) content.

Here is what I have in the access log.

17:19:26 /pid21838/test.html 200 MISS
17:20:32 /pid21838/test.html 200 EXPIRED <-- more than one minute
later, the backend is requested to update the cache
17:20:49 /pid21838/test.html 200 HIT <-- less than one minute later,
the cache is served
17:20:49 /pid21838/test.html 200 HIT <-- the same
17:21:40 /pid21838/test.html 404 EXPIRED <-- The cache is expired,
request backend. The backend answers with a 404. But the cache does
not seem to be updated
17:21:42 /pid21838/test.html 200 UPDATING <-- all the next requests
are served from stale cache.
17:22:09 /pid21838/test.html 200 UPDATING
17:23:06 /pid21838/test.html 200 UPDATING
17:27:00 /pid21838/test.html 200 UPDATING
17:32:16 /pid21838/test.html 200 UPDATING
17:41:20 /pid21838/test.html 200 UPDATING
17:44:06 /pid21838/test.html 200 UPDATING
17:45:09 /pid21838/test.html 200 UPDATING
17:47:01 /pid21838/test.html 200 UPDATING
17:52:06 /pid21838/test.html 200 UPDATING
17:52:08 /pid21838/test.html 200 UPDATING
19:12:08 /pid21838/test.html 200 UPDATING
19:20:59 /pid21838/test.html 200 UPDATING
19:34:36 /pid21838/test.html 200 UPDATING
19:58:00 /pid21838/test.html 200 UPDATING
20:11:55 /pid21838/test.html 200 UPDATING <-- 3 hours later: still the same


I can reproduce the problem:

1- create a page on the backend (say /test.html)
2- request the frontend for /test.html --> MISS 200
3- request the frontend for /test.html before it expires --> HIT 200
4- request the frontend for /test.html after it expires --> EXPIRED 200
5- remove /test.html from the backend
6- request the frontend for /test.html after it expires --> EXPIRED 404
6- request the frontend for /test.html any time you want --> UPDATING
200 (the old /test.html is still served)

I'm using nginx 0.8.4.

I didn't have time to test with newer releases.

Hope it helps

++ Jerome