proxy cache lock responses always has 500ms delay

[Roman Arutyunyan]

Hello,

On Wed, Sep 13, 2017 at 06:07:34AM -0400, sivasara wrote:
> Greetings everbody,
> 
> I have the following config. I give 3 simulatneous requests and 1 goes back
> to the upstream and the 2 of them are in proxy_cache_lock. After the first
> request completes, I am always seeing 500ms delay with proxy_cache_locked
> requests. Is this expected behavior or am i missing something. 
> Any help would be appreciated.

Yes, this is the expected behavior.  Each proxy_cache_locked request waits for
cache entry to be unlocked by 500ms intervals.  If you're unlucky, you'll get
additional near-500ms delay for locked requests.

> -nginx config:
> user  nginx;
> worker_processes  1;
> error_log  logs/error.log;
> pid        /var/run/nginx.pid;
> events {}
> http {
>     proxy_cache_path /tmp/local_cache keys_zone=local_cache:250m levels=1:2
> inactive=8s;
>     proxy_temp_path /tmp/proxy_temp;
> 
>     log_format  main  '$remote_addr - $remote_user [$time_local] "$request"
> '
>                       '$status $body_bytes_sent "$http_referer" '
>                       '"$http_user_agent" "$http_x_forwarded_for" '
>                       '$upstream_addr $upstream_response_time $request_time
> $upstream_cache_status';
> 
>     access_log  logs/access.log  main;
>     server {
>         listen       80;
>         server_name  localhost;
> 
>         location / {
>                 proxy_cache local_cache;
>                 proxy_cache_valid 200 1m;
>                 proxy_cache_lock on;
>                 proxy_pass http://192.168.126.22:9095;
>         }
> 
>     }
> }
> 
> ab -n 4 -c 3 http://192.168.126.22/test
> access.log:
> 192.168.126.22 - - [13/Sep/2017:15:14:36 +0530] "GET /test HTTP/1.0" 200 12
> "-" "ApacheBench/2.3" "-" 192.168.126.22:9095 0.003 0.004 MISS
> 192.168.126.22 - - [13/Sep/2017:15:14:36 +0530] "GET /test HTTP/1.0" 200 12
> "-" "ApacheBench/2.3" "-" - - 0.000 HIT
> 192.168.126.22 - - [13/Sep/2017:15:14:36 +0530] "GET /test HTTP/1.0" 200 12
> "-" "ApacheBench/2.3" "-" - - 0.502 HIT
> 192.168.126.22 - - [13/Sep/2017:15:14:36 +0530] "GET /test HTTP/1.0" 200 12
> "-" "ApacheBench/2.3" "-" - - 0.502 HIT
> 
> upstream:
> curl http://192.168.126.22:9095/test
> Hello world!
> 
> nginx:
> nginx -V
> nginx version: nginx/1.10.2
> built by gcc 4.8.5 20150623 (Red Hat 4.8.5-4) (GCC)
> built with OpenSSL 1.0.1e-fips 11 Feb 2013
> TLS SNI support enabled
> configure arguments: --prefix=/usr/share/nginx --sbin-path=/usr/sbin/nginx
> --modules-path=/usr/lib64/nginx/modules --conf-path=/etc/nginx/nginx.conf
> --error-log-path=/var/log/nginx/error.log
> --http-log-path=/var/log/nginx/access.log
> --http-client-body-temp-path=/var/lib/nginx/tmp/client_body
> --http-proxy-temp-path=/var/lib/nginx/tmp/proxy
> --http-fastcgi-temp-path=/var/lib/nginx/tmp/fastcgi
> --http-uwsgi-temp-path=/var/lib/nginx/tmp/uwsgi
> --http-scgi-temp-path=/var/lib/nginx/tmp/scgi --pid-path=/run/nginx.pid
> --lock-path=/run/lock/subsys/nginx --user=nginx --group=nginx
> --with-file-aio --with-ipv6 --with-http_ssl_module --with-http_v2_module
> --with-http_realip_module --with-http_addition_module
> --with-http_xslt_module=dynamic --with-http_image_filter_module=dynamic
> --with-http_geoip_module=dynamic --with-http_sub_module
> --with-http_dav_module --with-http_flv_module --with-http_mp4_module
> --with-http_gunzip_module --with-http_gzip_static_module
> --with-http_random_index_module --with-http_secure_link_module
> --with-http_degradation_module --with-http_slice_module
> --with-http_stub_status_module --with-http_perl_module=dynamic
> --with-mail=dynamic --with-mail_ssl_module --with-pcre --with-pcre-jit
> --with-stream=dynamic --with-stream_ssl_module
> --with-google_perftools_module --with-debug --with-cc-opt='-O2 -g -pipe
> -Wall -Wp,-D_FORTIFY_SOURCE=2 -fexceptions -fstack-protector-strong
> --param=ssp-buffer-size=4 -grecord-gcc-switches
> -specs=/usr/lib/rpm/redhat/redhat-hardened-cc1 -m64 -mtune=generic'
> --with-ld-opt='-Wl,-z,relro -specs=/usr/lib/rpm/redhat/redhat-hardened-ld
> -Wl,-E'
> 
> Posted at Nginx Forum: https://forum.nginx.org/read.php?2,276344,276344#msg-276344
> 
> _______________________________________________
> nginx mailing list
> nginx at nginx.org
> http://mailman.nginx.org/mailman/listinfo/nginx

-- 
Roman Arutyunyan