srcache_fetch_skip doesn't follow the value changed by access_by_lua

[gaoyuear]

Here is the initial config:

http {
    log_format  gw_main '$remote_addr  [$time_local] "$request" '
    '$status $body_bytes_sent "$http_referer" '
    '"$http_user_agent" $request_time '
    '"$upstream_addr" "$upstream_status" $upstream_response_length $upstream_response_time $upstream_cache_status $srcache_fetch_status $srcache_store_status $cache_skip';

    access_log  ./logs/access.log  gw_main;

    # memcached for page cache
    upstream my_memcached {
        server 10.0.230.19:11211;
        keepalive 10;
    }
        location = /memc {
             internal;
             memc_connect_timeout 100ms;
             memc_send_timeout 100ms;
             memc_read_timeout 100ms;
             memc_ignore_client_abort on;

             set $memc_key $arg_key;
             set $memc_exptime $arg_exptime;

             memc_pass my_memcached;
        }

    # main server
    server {
        location / {
            set $cache_key 'abchaha';
            set $cache_expire 30;
            set $cache_skip 1;

            access_by_lua_block {
                ngx.var.cache_skip = 0
            }

            # proxy
            proxy_ignore_client_abort on;

            # cache
            srcache_fetch_skip $cache_skip;
            srcache_store_skip $cache_skip;
            srcache_fetch GET /memc key=$cache_key;
            srcache_store PUT /memc key=$cache_key&exptime=$cache_expire;
            srcache_store_statuses 200 204;

            # proxy pass
            proxy_pass http://dev-appserver.bj.com:18080;
        }

        include srcache-memcache.conf;
}

1. set $cache_skip=1 then change it value to 0 in lua block, the result of $srcache_fetch_status $srcache_store_status $cache_skip in the access log is :
   ' BYPASS STORE 0'
   scrache_store is STORE, but why the srcache_fetch is BYPASS here?

2. set $cache_skip=1 then set it value to 1 again in lua, the result in access log is:
   'MISS STORE 0'
   as expected.

3. set $cache_skip=1 then set it value to 0 in lua, the result in access log is:
   'BYPASS BYPASS 1'
   as expected.

versions:
openresty/1.13.6.2
srcache-nginx-module-0.31

[root@dev-appserver orange-dev]# /usr/local/openresty/nginx/sbin/nginx -V
nginx version: openresty/1.13.6.2
built by gcc 4.8.5 20150623 (Red Hat 4.8.5-11) (GCC)
built with OpenSSL 1.1.0h 27 Mar 2018
TLS SNI support enabled
configure arguments: --prefix=/usr/local/openresty/nginx --with-cc-opt='-O2 -DNGX_LUA_ABORT_AT_PANIC -I/usr/local/openresty/zlib/include -I/usr/local/openresty/pcre/include -I/usr/local/openresty/openssl/include' --add-module=../ngx_devel_kit-0.3.0 --add-module=../echo-nginx-module-0.61 --add-module=../xss-nginx-module-0.06 --add-module=../ngx_coolkit-0.2rc3 --add-module=../set-misc-nginx-module-0.32 --add-module=../form-input-nginx-module-0.12 --add-module=../encrypted-session-nginx-module-0.08 --add-module=../srcache-nginx-module-0.31 --add-module=../ngx_lua-0.10.13 --add-module=../ngx_lua_upstream-0.07 --add-module=../headers-more-nginx-module-0.33 --add-module=../array-var-nginx-module-0.05 --add-module=../memc-nginx-module-0.19 --add-module=../redis2-nginx-module-0.15 --add-module=../redis-nginx-module-0.3.7 --add-module=../ngx_stream_lua-0.0.5 --with-ld-opt='-Wl,-rpath,/usr/local/openresty/luajit/lib -L/usr/local/openresty/zlib/lib -L/usr/local/openresty/pcre/lib -L/usr/local/openresty/openssl/lib -Wl,-rpath,/usr/local/openresty/zlib/lib:/usr/local/openresty/pcre/lib:/usr/local/openresty/openssl/lib' --with-pcre-jit --with-stream --with-stream_ssl_module --with-stream_ssl_preread_module --with-http_v2_module --without-mail_pop3_module --without-mail_imap_module --without-mail_smtp_module --with-http_stub_status_module --with-http_realip_module --with-http_addition_module --with-http_auth_request_module --with-http_secure_link_module --with-http_random_index_module --with-http_gzip_static_module --with-http_sub_module --with-http_dav_module --with-http_flv_module --with-http_mp4_module --with-http_gunzip_module --with-threads --with-dtrace-probes --add-module=/root/rpmbuild-openresty-1.13/BUILD/openresty-1.13.6.2/../ngx_http_geoip2_module-3.2 --with-stream --with-stream_ssl_module --with-http_ssl_module

[gaoyuear]

debug info

2019/04/04 07:41:29 [debug] 25769#25769: *1 rewrite phase: 5
2019/04/04 07:41:29 [debug] 25769#25769: *1 http script value: "abchaha"
2019/04/04 07:41:29 [debug] 25769#25769: *1 http script set $cache_key
2019/04/04 07:41:29 [debug] 25769#25769: *1 http script value: "30"
2019/04/04 07:41:29 [debug] 25769#25769: *1 http script set $cache_expire
2019/04/04 07:41:29 [debug] 25769#25769: *1 http script value: "1"
2019/04/04 07:41:29 [debug] 25769#25769: *1 http script set $cache_skip
2019/04/04 07:41:29 [debug] 25769#25769: *1 post rewrite phase: 6
2019/04/04 07:41:29 [debug] 25769#25769: *1 generic phase: 7
2019/04/04 07:41:29 [debug] 25769#25769: *1 generic phase: 8
2019/04/04 07:41:29 [debug] 25769#25769: *1 generic phase: 9
2019/04/04 07:41:29 [debug] 25769#25769: *1 access phase: 10
2019/04/04 07:41:29 [debug] 25769#25769: *1 lua access handler, uri:"/vup/v1/tabs/home/pages" c:1
2019/04/04 07:41:29 [debug] 25769#25769: *1 access phase: 10
2019/04/04 07:41:29 [debug] 25769#25769: *1 http script var: "1"
2019/04/04 07:41:29 [debug] 25769#25769: *1 srcache_fetch skipped due to the true value fed into srcache_fetch_skip: "1"
2019/04/04 07:41:29 [debug] 25769#25769: *1 access phase: 11
2019/04/04 07:41:29 [debug] 25769#25769: *1 access phase: 12
2019/04/04 07:41:29 [debug] 25769#25769: *1 access phase: 13
2019/04/04 07:41:29 [debug] 25769#25769: *1 access phase: 14
2019/04/04 07:41:29 [debug] 25769#25769: *1 lua access handler, uri:"/vup/v1/tabs/home/pages" c:1
2019/04/04 07:41:29 [debug] 25769#25769: *1 lua creating new thread
2019/04/04 07:41:29 [debug] 25769#25769: *1 lua reset ctx
2019/04/04 07:41:29 [debug] 25769#25769: *1 http cleanup add: 00000000025ECE90
2019/04/04 07:41:29 [debug] 25769#25769: *1 lua run thread, top:0 c:1
2019/04/04 07:41:29 [debug] 25769#25769: *1 lua resume returned 0
2019/04/04 07:41:29 [debug] 25769#25769: *1 lua light thread ended normally
2019/04/04 07:41:29 [debug] 25769#25769: *1 lua deleting light thread
2019/04/04 07:41:29 [debug] 25769#25769: *1 post access phase: 15

lua block is executed after srcache_fetch ... how to walk around?

[kapouer]

Do not use access_by_lua, but rewrite_by_lua:
https://github.com/openresty/lua-nginx-module/#rewrite_by_lua

[kapouer]

Oddly i'm hit by a similar issue now, with ngx.ctx lost between rewrite_by_lua and balancer_by_lua...

[Lathanderjk]

I have same issue even with access_by_lua_no_postpone on; , according to srcache documentation it should be executed in post-access phase.