proxy_pass 失败后，log_by_lua 不会执行的问题

xiaooolooong · 2016-01-22T10:11:33+00:00

对 nginx 自身的正则限制，我不是很熟悉。 locati...

proxy_pass 失败后，log_by_lua 不会执行的问题

xiaooolooong

proxy_pass 到后端，当后端失败，nginx 直接返回 5xx错误

同一个location内定义的

header_filter_by_lua

body_filter_by_lua

log_by_lua

均不会被执行，求解

agentzh

Hello!

2016-01-21 18:11 GMT-08:00 xiaooloong:
> proxy_pass 到后端，当后端失败，nginx 直接返回 5xx错误
>
> 同一个location内定义的
> header_filter_by_lua
> body_filter_by_lua
> log_by_lua
> 均不会被执行，求解
>

请提供一个最小化的完整示例以便我们可以复现问题。另外，临时开启 nginx 调试日志可以得到更多信息，见

    http://nginx.org/en/docs/debugging_log.html

同时的操作步骤也适用于 OpenResty.

Regards,
-agentzh

xiaooolooong

nginx version: openresty/1.9.7.1

built by gcc 4.4.7 20120313 (Red Hat 4.4.7-16) (GCC)

built with OpenSSL 1.0.1e-fips 11 Feb 2013

TLS SNI support enabled

configure arguments: --prefix=/usr/local/nginx --with-cc-opt=-O2 --add-module=../ngx_devel_kit-0.2.19 --add-module=../echo-nginx-module-0.58 --add-module=../xss-nginx-module-0.05 --add-module=../ngx_coolkit-0.2rc3 --add-module=../set-misc-nginx-module-0.29 --add-module=../form-input-nginx-module-0.11 --add-module=../encrypted-session-nginx-module-0.04 --add-module=../srcache-nginx-module-0.30 --add-module=../ngx_lua-0.9.20 --add-module=../ngx_lua_upstream-0.04 --add-module=../headers-more-nginx-module-0.29 --add-module=../array-var-nginx-module-0.04 --add-module=../memc-nginx-module-0.16 --add-module=../redis2-nginx-module-0.12 --add-module=../redis-nginx-module-0.3.7 --add-module=../rds-json-nginx-module-0.14 --add-module=../rds-csv-nginx-module-0.07 --with-ld-opt=-Wl,-rpath,/usr/local/luajit/lib --with-http_ssl_module

默认配置下加入location：

location ^~ /test/ {

rewrite_by_lua_block {

ngx.log(ngx.ALERT, 'rewrite')

}

access_by_lua_block {

ngx.log(ngx.ALERT, 'access')

}

#并没有哪个程序监听这个端口

proxy_pass http://127.0.0.1:65535;

header_filter_by_lua_block {

ngx.log(ngx.ALERT, 'header_filter')

}

body_filter_by_lua_block {

ngx.log(ngx.ALERT, 'body_filter')

}

log_by_lua_block {

ngx.log(ngx.ALERT, 'log')

}

此时访问http://localhost/test/，可在error观察到如下日志：

2016/01/22 14:03:22 [alert] 3148#0: *1 [lua] rewrite_by_lua(nginx.conf:20):2: rewrite, client: 127.0.0.1, server: localhost, request: "GET /test/ HTTP/1.1", host: "localhost"

2016/01/22 14:03:22 [alert] 3148#0: *1 [lua] access_by_lua(nginx.conf:23):2: access, client: 127.0.0.1, server: localhost, request: "GET /test/ HTTP/1.1", host: "localhost"

2016/01/22 14:03:22 [error] 3148#0: *1 connect() failed (111: Connection refused) while connecting to upstream, client: 127.0.0.1, server: localhost, request: "GET /test/ HTTP/1.1", upstream: "http://127.0.0.1:65535/test/", host: "localhost"

在 2016年1月22日星期五 UTC+8下午12:47:31，agentzh写道：

Hello!

2016-01-21 18:11 GMT-08:00 xiaooloong:
> proxy_pass 到后端，当后端失败，nginx 直接返回 5xx错误
>
> 同一个location内定义的
> header_filter_by_lua
> body_filter_by_lua
> log_by_lua
> 均不会被执行，求解
>

请提供一个最小化的完整示例以便我们可以复现问题。另外，临时开启 nginx 调试日志可以得到更多信息，见

http://nginx.org/en/docs/debugging_log.html

同时的操作步骤也适用于 OpenResty.

Regards,
-agentzh

Attachment: nginx_conf.tgz
Description: GNU Unix tar archive

doujiang24

Hello,

我使用你一样的版本，一样的 nginx.conf 并不能复现你的问题，该有的日志都出来了

在 2016年1月22日下午2:10，xiaooloong <xiaoo...@gmail.com>写道：

nginx version: openresty/1.9.7.1
built by gcc 4.4.7 20120313 (Red Hat 4.4.7-16) (GCC)
built with OpenSSL 1.0.1e-fips 11 Feb 2013
TLS SNI support enabled
configure arguments: --prefix=/usr/local/nginx --with-cc-opt=-O2 --add-module=../ngx_devel_kit-0.2.19 --add-module=../echo-nginx-module-0.58 --add-module=../xss-nginx-module-0.05 --add-module=../ngx_coolkit-0.2rc3 --add-module=../set-misc-nginx-module-0.29 --add-module=../form-input-nginx-module-0.11 --add-module=../encrypted-session-nginx-module-0.04 --add-module=../srcache-nginx-module-0.30 --add-module=../ngx_lua-0.9.20 --add-module=../ngx_lua_upstream-0.04 --add-module=../headers-more-nginx-module-0.29 --add-module=../array-var-nginx-module-0.04 --add-module=../memc-nginx-module-0.16 --add-module=../redis2-nginx-module-0.12 --add-module=../redis-nginx-module-0.3.7 --add-module=../rds-json-nginx-module-0.14 --add-module=../rds-csv-nginx-module-0.07 --with-ld-opt=-Wl,-rpath,/usr/local/luajit/lib --with-http_ssl_module

默认配置下加入location：
location ^~ /test/ {
rewrite_by_lua_block {
ngx.log(ngx.ALERT, 'rewrite')
}
access_by_lua_block {
ngx.log(ngx.ALERT, 'access')
}

#并没有哪个程序监听这个端口
proxy_pass http://127.0.0.1:65535;

header_filter_by_lua_block {
ngx.log(ngx.ALERT, 'header_filter')
}
body_filter_by_lua_block {
ngx.log(ngx.ALERT, 'body_filter')
}
log_by_lua_block {
ngx.log(ngx.ALERT, 'log')
}
}

此时访问http://localhost/test/，可在error观察到如下日志：

2016/01/22 14:03:22 [alert] 3148#0: *1 [lua] rewrite_by_lua(nginx.conf:20):2: rewrite, client: 127.0.0.1, server: localhost, request: "GET /test/ HTTP/1.1", host: "localhost"
2016/01/22 14:03:22 [alert] 3148#0: *1 [lua] access_by_lua(nginx.conf:23):2: access, client: 127.0.0.1, server: localhost, request: "GET /test/ HTTP/1.1", host: "localhost"
2016/01/22 14:03:22 [error] 3148#0: *1 connect() failed (111: Connection refused) while connecting to upstream, client: 127.0.0.1, server: localhost, request: "GET /test/ HTTP/1.1", upstream: "http://127.0.0.1:65535/test/", host: "localhost"

在 2016年1月22日星期五 UTC+8下午12:47:31，agentzh写道：
Hello!

2016-01-21 18:11 GMT-08:00 xiaooloong:
> proxy_pass 到后端，当后端失败，nginx 直接返回 5xx错误
>
> 同一个location内定义的
> header_filter_by_lua
> body_filter_by_lua
> log_by_lua
> 均不会被执行，求解
>

请提供一个最小化的完整示例以便我们可以复现问题。另外，临时开启 nginx 调试日志可以得到更多信息，见

http://nginx.org/en/docs/debugging_log.html

同时的操作步骤也适用于 OpenResty.

Regards,
-agentzh

--

xiaooolooong

找到问题了，error_page的问题。upsteam无法连接，nginx产生5xx错误，因为存在error_page配置，去location /50x.html执行内部请求了，所以body_filter header_filter log都没有执行。

在 2016年1月22日星期五 UTC+8下午3:40:53，doujiang写道：

Hello,

我使用你一样的版本，一样的 nginx.conf 并不能复现你的问题，该有的日志都出来了

在 2016年1月22日下午2:10，xiaooloong <xiaooo...@gmail.com>写道：
nginx version: openresty/1.9.7.1
built by gcc 4.4.7 20120313 (Red Hat 4.4.7-16) (GCC)
built with OpenSSL 1.0.1e-fips 11 Feb 2013
TLS SNI support enabled
configure arguments: --prefix=/usr/local/nginx --with-cc-opt=-O2 --add-module=../ngx_devel_kit-0.2.19 --add-module=../echo-nginx-module-0.58 --add-module=../xss-nginx-module-0.05 --add-module=../ngx_coolkit-0.2rc3 --add-module=../set-misc-nginx-module-0.29 --add-module=../form-input-nginx-module-0.11 --add-module=../encrypted-session-nginx-module-0.04 --add-module=../srcache-nginx-module-0.30 --add-module=../ngx_lua-0.9.20 --add-module=../ngx_lua_upstream-0.04 --add-module=../headers-more-nginx-module-0.29 --add-module=../array-var-nginx-module-0.04 --add-module=../memc-nginx-module-0.16 --add-module=../redis2-nginx-module-0.12 --add-module=../redis-nginx-module-0.3.7 --add-module=../rds-json-nginx-module-0.14 --add-module=../rds-csv-nginx-module-0.07 --with-ld-opt=-Wl,-rpath,/usr/local/luajit/lib --with-http_ssl_module

默认配置下加入location：
location ^~ /test/ {
rewrite_by_lua_block {
ngx.log(ngx.ALERT, 'rewrite')
}
access_by_lua_block {
ngx.log(ngx.ALERT, 'access')
}

#并没有哪个程序监听这个端口
proxy_pass http://127.0.0.1:65535;

header_filter_by_lua_block {
ngx.log(ngx.ALERT, 'header_filter')
}
body_filter_by_lua_block {
ngx.log(ngx.ALERT, 'body_filter')
}
log_by_lua_block {
ngx.log(ngx.ALERT, 'log')
}
}

此时访问http://localhost/test/，可在error观察到如下日志：

2016/01/22 14:03:22 [alert] 3148#0: *1 [lua] rewrite_by_lua(nginx.conf:20):2: rewrite, client: 127.0.0.1, server: localhost, request: "GET /test/ HTTP/1.1", host: "localhost"
2016/01/22 14:03:22 [alert] 3148#0: *1 [lua] access_by_lua(nginx.conf:23):2: access, client: 127.0.0.1, server: localhost, request: "GET /test/ HTTP/1.1", host: "localhost"
2016/01/22 14:03:22 [error] 3148#0: *1 connect() failed (111: Connection refused) while connecting to upstream, client: 127.0.0.1, server: localhost, request: "GET /test/ HTTP/1.1", upstream: "http://127.0.0.1:65535/test/", host: "localhost"

在 2016年1月22日星期五 UTC+8下午12:47:31，agentzh写道：
Hello!

2016-01-21 18:11 GMT-08:00 xiaooloong:
> proxy_pass 到后端，当后端失败，nginx 直接返回 5xx错误
>
> 同一个location内定义的
> header_filter_by_lua
> body_filter_by_lua
> log_by_lua
> 均不会被执行，求解
>

请提供一个最小化的完整示例以便我们可以复现问题。另外，临时开启 nginx 调试日志可以得到更多信息，见

http://nginx.org/en/docs/debugging_log.html

同时的操作步骤也适用于 OpenResty.

Regards,
-agentzh

--

yuansheng

前两天刚有人在交流群里面也碰到了因为 error_page 导致 log_by_lua 没有执行的情况。可以考虑放到 wiki 中说明一下。

2016-01-25 11:58 GMT+08:00 xiaooloong <xiaoo...@gmail.com>:

找到问题了，error_page的问题。upsteam无法连接，nginx产生5xx错误，因为存在error_page配置，去location /50x.html执行内部请求了，所以body_filter header_filter log都没有执行。

在 2016年1月22日星期五 UTC+8下午3:40:53，doujiang写道：
Hello,

我使用你一样的版本，一样的 nginx.conf 并不能复现你的问题，该有的日志都出来了

在 2016年1月22日下午2:10，xiaooloong <xiaooo...@gmail.com>写道：
nginx version: openresty/1.9.7.1
built by gcc 4.4.7 20120313 (Red Hat 4.4.7-16) (GCC)
built with OpenSSL 1.0.1e-fips 11 Feb 2013
TLS SNI support enabled
configure arguments: --prefix=/usr/local/nginx --with-cc-opt=-O2 --add-module=../ngx_devel_kit-0.2.19 --add-module=../echo-nginx-module-0.58 --add-module=../xss-nginx-module-0.05 --add-module=../ngx_coolkit-0.2rc3 --add-module=../set-misc-nginx-module-0.29 --add-module=../form-input-nginx-module-0.11 --add-module=../encrypted-session-nginx-module-0.04 --add-module=../srcache-nginx-module-0.30 --add-module=../ngx_lua-0.9.20 --add-module=../ngx_lua_upstream-0.04 --add-module=../headers-more-nginx-module-0.29 --add-module=../array-var-nginx-module-0.04 --add-module=../memc-nginx-module-0.16 --add-module=../redis2-nginx-module-0.12 --add-module=../redis-nginx-module-0.3.7 --add-module=../rds-json-nginx-module-0.14 --add-module=../rds-csv-nginx-module-0.07 --with-ld-opt=-Wl,-rpath,/usr/local/luajit/lib --with-http_ssl_module

默认配置下加入location：
location ^~ /test/ {
rewrite_by_lua_block {
ngx.log(ngx.ALERT, 'rewrite')
}
access_by_lua_block {
ngx.log(ngx.ALERT, 'access')
}

#并没有哪个程序监听这个端口
proxy_pass http://127.0.0.1:65535;

header_filter_by_lua_block {
ngx.log(ngx.ALERT, 'header_filter')
}
body_filter_by_lua_block {
ngx.log(ngx.ALERT, 'body_filter')
}
log_by_lua_block {
ngx.log(ngx.ALERT, 'log')
}
}

此时访问http://localhost/test/，可在error观察到如下日志：

2016/01/22 14:03:22 [alert] 3148#0: *1 [lua] rewrite_by_lua(nginx.conf:20):2: rewrite, client: 127.0.0.1, server: localhost, request: "GET /test/ HTTP/1.1", host: "localhost"
2016/01/22 14:03:22 [alert] 3148#0: *1 [lua] access_by_lua(nginx.conf:23):2: access, client: 127.0.0.1, server: localhost, request: "GET /test/ HTTP/1.1", host: "localhost"
2016/01/22 14:03:22 [error] 3148#0: *1 connect() failed (111: Connection refused) while connecting to upstream, client: 127.0.0.1, server: localhost, request: "GET /test/ HTTP/1.1", upstream: "http://127.0.0.1:65535/test/", host: "localhost"

在 2016年1月22日星期五 UTC+8下午12:47:31，agentzh写道：
Hello!

2016-01-21 18:11 GMT-08:00 xiaooloong:
> proxy_pass 到后端，当后端失败，nginx 直接返回 5xx错误
>
> 同一个location内定义的
> header_filter_by_lua
> body_filter_by_lua
> log_by_lua
> 均不会被执行，求解
>

请提供一个最小化的完整示例以便我们可以复现问题。另外，临时开启 nginx 调试日志可以得到更多信息，见

http://nginx.org/en/docs/debugging_log.html

同时的操作步骤也适用于 OpenResty.

Regards,
-agentzh

--

--

YuanSheng Wang

---------------------------------------

My Github: https://github.com/membphis

OpenResty lover ^_^

agentzh

Hello!

2016-01-24 21:19 GMT-08:00 YuanSheng Wang:
> 前两天刚有人在交流群里面也碰到了因为 error_page 导致 log_by_lua 没有执行的情况。可以考虑放到 wiki 中说明一下。
>

error_page 会发起内部跳转，所以不仅原 location 的 log_by_lua 不会执行，其余的 log 阶段的指令，比如
access_log 和 log_format 也与当前请求无关了。可以在 log_by_lua*
的文档中加一笔，虽然我感觉并不是特别相关。欢迎贡献文档补丁 :)

Regards,
-agentzh