NGINX does not update cached response of POST requests

[azhuchkov@…]

Recently I configured caching of POST requests. It's not user input, it is AJAX queries to build quite heavy UI, so I have just a few POST requests to cache. So, it works as expected, but NGINX does not update stale responses locking them forever (at least for days) and constantly returning x-cache-status: UPDATING.

What I've figured out:

Error records in log files (actually these are just several records that repeat):

... 2018/12/27 13:38:17 [alert] 28874#28874: ignore long locked inactive cache entry e1d0fe4a523e1b5245e4eb950e298ce0, count:1 2018/12/27 13:45:06 [alert] 28874#28874: ignore long locked inactive cache entry 56fc903ed9a8dccc1a788a42d4d93b0a, count:1 2018/12/27 13:45:06 [alert] 28874#28874: ignore long locked inactive cache entry c70cb1ddbef6ae13f513bfe14a5e430f, count:1 2018/12/27 13:45:08 [alert] 28874#28874: ignore long locked inactive cache entry 2f05b9d5547e361d6a3d910636b96948, count:1 2018/12/27 13:51:41 [alert] 28874#28874: ignore long locked inactive cache entry dc6f7d0f964d54df80f82c5728161ff0, count:1 2018/12/27 14:10:38 [alert] 28874#28874: ignore long locked inactive cache entry 81ef90871e9bbc0f9574054f0729933e, count:1 2018/12/27 14:11:05 [alert] 28874#28874: ignore long locked inactive cache entry d2e93972c8f7e14c29a837ff005e2648, count:1 2018/12/27 14:15:26 [alert] 28874#28874: ignore long locked inactive cache entry 1cef9ddcef8ba3cc6cc7b87dc0edc3d4, count:1 2018/12/27 14:38:17 [alert] 28874#28874: ignore long locked inactive cache entry e1d0fe4a523e1b5245e4eb950e298ce0, count:1 2018/12/27 14:45:06 [alert] 28874#28874: ignore long locked inactive cache entry 56fc903ed9a8dccc1a788a42d4d93b0a, count:1 2018/12/27 14:45:06 [alert] 28874#28874: ignore long locked inactive cache entry c70cb1ddbef6ae13f513bfe14a5e430f, count:1 ... 

Output of the sudo lsof | grep -i /tmp/nginx (I store my cache under /tmp):

nginx 28873 nginx 19r REG 254,0 682 388945 /tmp/nginx/a/b0/56fc903ed9a8dccc1a788a42d4d93b0a nginx 28873 nginx 22r REG 254,0 128435 388951 /tmp/nginx/f/30/c70cb1ddbef6ae13f513bfe14a5e430f nginx 28873 nginx 23r REG 254,0 124038 389010 /tmp/nginx/8/94/2f05b9d5547e361d6a3d910636b96948 nginx 28873 nginx 24r REG 254,0 127621 389411 /tmp/nginx/4/3d/1cef9ddcef8ba3cc6cc7b87dc0edc3d4 nginx 28873 nginx 25r REG 254,0 119371 389441 /tmp/nginx/8/64/d2e93972c8f7e14c29a837ff005e2648 nginx 28873 nginx 26r REG 254,0 113245 389451 /tmp/nginx/e/33/81ef90871e9bbc0f9574054f0729933e nginx 28873 nginx 27r REG 254,0 96842 389500 /tmp/nginx/0/ce/e1d0fe4a523e1b5245e4eb950e298ce0 nginx 28873 nginx 28r REG 254,0 106964 389494 /tmp/nginx/0/ff/dc6f7d0f964d54df80f82c5728161ff0 

Here we see that NGINX has opened cache entries and holds them (most likely) forever (all of them are POST responses).

Here is the output of the sudo pgrep -a nginx:

28871 nginx: master process /usr/sbin/nginx -c /etc/nginx/nginx.conf 28873 nginx: worker process 28874 nginx: cache manager process 

Here is my config:

... server { server_name app; access_log /var/log/nginx/app/prod/access.log; error_log /var/log/nginx/app/prod/error.log; location / { set $ae ""; if ($http_accept_encoding ~* gzip) { set $ae "gzip"; } proxy_pass http://prod_backend; proxy_redirect off; proxy_set_header Host $host; proxy_set_header X-Real-IP $remote_addr; proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for; proxy_set_header X-Forwarded-Proto $scheme; proxy_cache app; proxy_cache_use_stale error timeout updating http_500 http_502 http_503 http_504; proxy_cache_methods POST; proxy_cache_background_update on; #proxy_cache_lock on; proxy_cache_valid 5s; proxy_cache_key $ae$scheme$proxy_host$request_uri$request_body; add_header X-Cache-Status $upstream_cache_status; expires 5m; } ... (SSL stuff ommited) 

So, I tried both options of the proxy_cache_lock and it did not help.

After restarting NGINX I still have stale responses with header x-cache-status: UPDATING. To get fresh values I need to drop the cache and restart NGINX.

Example of the POST request body:

{"output":{"id":"page-content","property":"children"},"inputs":[{"id":"url","property":"pathname"}]} 

[azhuchkov@…]

Sorry, forgot to put cache and backend configs. Here they are:

upstream prod_backend { server unix:/tmp/app.prod.sock; } proxy_cache_path /tmp/nginx levels=1:2 keys_zone=app:1m max_size=100m inactive=60m use_temp_path=off; 

[azhuchkov@…]

I confirm the same issue for mainline version nginx/1.15.8: files of cached POST responses are shown as opened after first 2-3 site loadings.

[Maxim Dounin]

Could you please:

1. Make sure there are no 3rd party modules loaded. If there are any, please reproduce the problem without any 3rd party modules loaded.
2. Check if disabling proxy_cache_background_update changes anything. If you are able to reproduce the problem without background updates, please keep it disabled for the remaining steps.
3. Provide full configuration which triggers the problem, as printed by "nginx -T". (Please also consider reproducing the problem in test environment to minimize configuration needed.)
4. Provide ​debug log with at least one request which demonstrates the problem.

[Maxim Dounin]

Feedback timeout.