I recently set proxy_cache_valid 200 to 1 second, down from 15 minutes to refresh the content more often (With proxy_cache_background_update on; already activated long before that).
Our Web monitoring, checking our site every minute, showed an increase in response time following this change.
After some investigating I pinned it down to a ~200 ms delay coming from using proxy_cache_background_update.
With an EXPIRED cache and proxy_cache_background_update disabled the site takes around 500 ms to load.
With a cache HIT its takes around ~5 ms.
Then I stopped php-fpm, disabled proxy_cache_background_update and got a STALE response (proxy_cache_use_stale error) taking ~6 ms.
The I started php-fpm again and enabled proxy_cache_background_update, wehen the cache expired I get a STALE response taking around ~200 ms
I got the times I measured using curl's time_total on localhost, so network delay is out of the picture. I ran the tests dozens of times and the milliseconds are very consistent.
I have a few sites / server showing this behavior and some that don't.
The server in this example is an AWS EC2 t2.small with SSD storage. Only NGINX and the cache is running on this Instance, PHP ist running on a different server.
Currently I don't now why this is happening an would appreciate any hints.
Example Output from cURL:
================EXPIRED================
HTTP/1.1 200 OK
Server: nginx
Date: Fri, 06 Jul 2018 12:00:46 GMT
Content-Type: text/html; charset=utf-8
Content-Length: 112834
Connection: keep-alive
Vary: Accept-Encoding
Vary: Accept-Encoding
Content-Language: de
X-Cache: EXPIRED
Status Code: 200
Lookup time: 0.004181 s
Connect time (TCP): 0.004236 s
Connect time (SSL): 0.000000 s
Pretransfer time: 0.004259 s
Starttransfer time: 0.503897 s
Size download: 112834 bytes
Speed download: 223248.000 bytes/s
Total time: 0.505418 s
================HIT================
HTTP/1.1 200 OK
Server: nginx
Date: Fri, 06 Jul 2018 12:01:23 GMT
Content-Type: text/html; charset=utf-8
Content-Length: 112834
Connection: keep-alive
Vary: Accept-Encoding
Vary: Accept-Encoding
Content-Language: de
X-Cache: HIT
Status Code: 200
Lookup time: 0.004200 s
Connect time (TCP): 0.004257 s
Connect time (SSL): 0.000000 s
Pretransfer time: 0.004281 s
Starttransfer time: 0.005348 s
Size download: 112834 bytes
Speed download: 20642883.000 bytes/s
Total time: 0.005466 s
================STALE (proxy_cache_background_update on)================
HTTP/1.1 200 OK
Server: nginx
Date: Fri, 06 Jul 2018 12:02:28 GMT
Content-Type: text/html; charset=utf-8
Content-Length: 112834
Connection: keep-alive
Vary: Accept-Encoding
Vary: Accept-Encoding
Content-Language: de
X-Cache: STALE
Status Code: 200
Lookup time: 0.004203 s
Connect time (TCP): 0.004267 s
Connect time (SSL): 0.000000 s
Pretransfer time: 0.004294 s
Starttransfer time: 0.004870 s
Size download: 112834 bytes
Speed download: 537563.000 bytes/s
Total time: 0.209899 s
================STALE (proxy_cache_background_update off)================
HTTP/1.1 200 OK
Server: nginx
Date: Fri, 06 Jul 2018 12:03:03 GMT
Content-Type: text/html; charset=utf-8
Content-Length: 112834
Connection: keep-alive
Vary: Accept-Encoding
Vary: Accept-Encoding
Content-Language: de
X-Cache: STALE
Status Code: 200
Lookup time: 0.004204 s
Connect time (TCP): 0.004262 s
Connect time (SSL): 0.000000 s
Pretransfer time: 0.004289 s
Starttransfer time: 0.005906 s
Size download: 112834 bytes
Speed download: 18752534.000 bytes/s
Total time: 0.006017 s