fastcgi_cache_lock doesnt work

[Maxim Dounin]

Hello!

On Thu, Nov 17, 2016 at 10:49:58AM -0500, permyakovsv wrote:

> I have further configuration:
>                 fastcgi_cache fastcgi_cache_products;
>                 fastcgi_cache_valid 200 302 304 404 25m;
>                 fastcgi_cache_valid 301 5m;
>                 fastcgi_cache_valid 500 502 20s;
> 
>                 fastcgi_cache_lock on;
>                 fastcgi_cache_lock_timeout 25s;
>                 fastcgi_cache_use_stale updating error timeout
> invalid_header http_500 http_503;
> 
> And I see netx picture:
> date 	                             http_code http_cache_status
> backend_responce
> ...
> 17/Nov/2016:17:19:54 +0200      200     cs=HIT  0
> 17/Nov/2016:17:19:14 +0200      200     cs=EXPIRED      8.041
> 17/Nov/2016:17:18:07 +0200      200     cs=EXPIRED      3.218
> 17/Nov/2016:17:17:24 +0200      200     cs=EXPIRED      3.291
> 17/Nov/2016:17:17:21 +0200      200     cs=UPDATING     0
> 17/Nov/2016:17:16:14 +0200      200     cs=EXPIRED      3.538
> 17/Nov/2016:17:15:53 +0200      200     cs=EXPIRED      2.977
> 17/Nov/2016:17:14:32 +0200      200     cs=EXPIRED      4.119
> 17/Nov/2016:17:13:49 +0200      200     cs=EXPIRED      4.784
> 17/Nov/2016:17:13:04 +0200      200     cs=HIT  0
> ...
> 17/Nov/2016:16:48:44 +0200      200     cs=HIT  0
> 17/Nov/2016:16:48:37 +0200      200     cs=EXPIRED      4.279
> 17/Nov/2016:16:47:57 +0200      200     cs=EXPIRED      3.936
> 17/Nov/2016:16:47:46 +0200      200     cs=EXPIRED      3.447
> 17/Nov/2016:16:46:53 +0200      200     cs=EXPIRED      3.287
> ...
> 
> But I expect only one request to backend, and why first request didn't
> update cache?
> Maybe Anybody faced the same problem?

First of all, the fastcgi_cache_lock directive is unrelated to 
updating existing cache entries, it only works when loading _new_ 
items into cache.  See http://nginx.org/r/fastcgi_cache_lock for 
details.

In case of updating "fastcgi_cache_use_stale updating" is expected 
to work, and "UPDATING" in your logs suggests that it does its job 
just fine: it prevents multiple parallel requests to upstream 
servers.  It clearly prevented multiple requests here:

> 17/Nov/2016:17:17:24 +0200      200     cs=EXPIRED      3.291
> 17/Nov/2016:17:17:21 +0200      200     cs=UPDATING     0

the request at 17:17:21 was served from cache (UPDATING status and 
zero upstream response time) as the request finished at 17:17:24 
was already started at that time. 

Next question is: why requests doesn't update the cache.  But 
"HIT" in logs clearly indicate that cache is updated, and 
correctly used.

What probably looks confusing is that expiration times are clearly 
much shorter than configured in proxy_cache_valid directives.  
This is quite normal though: as long as there are Cache-Control or 
Expires directives, nginx will use them for cache expiration times 
instead of proxy_cache_valid.

-- 
Maxim Dounin
http://nginx.org/