lua-nginx-module引发的core问题

crasyangel.lhy

#0 ngx_http_lua_run_posted_threads (c=c@entry=0x10dc93c0, L=L@entry=0x4180d378, r=r@entry=0x137b0a10,

ctx=ctx@entry=0x136e0700) at addon/lua-nginx-module-ssl-cert-by-lua/src/ngx_http_lua_util.c:3051

#1 0x00000000004ff26f in ngx_http_lua_rewrite_by_chunk (L=L@entry=0x4180d378, r=r@entry=0x137b0a10)

at addon/lua-nginx-module-ssl-cert-by-lua/src/ngx_http_lua_rewriteby.c:321

#2 0x00000000004ff783 in ngx_http_lua_rewrite_handler_file (r=0x137b0a10)

at addon/lua-nginx-module-ssl-cert-by-lua/src/ngx_http_lua_rewriteby.c:226

#3 0x00000000004ff61c in ngx_http_lua_rewrite_handler (r=0x137b0a10)

at addon/lua-nginx-module-ssl-cert-by-lua/src/ngx_http_lua_rewriteby.c:162

#4 0x000000000047ec23 in ngx_http_core_rewrite_phase (r=0x137b0a10, ph=0x10ac1fa0) at src/http/ngx_http_core_module.c:940

#5 0x000000000047aa63 in ngx_http_core_run_phases (r=r@entry=0x137b0a10) at src/http/ngx_http_core_module.c:886

#6 0x000000000047ab7c in ngx_http_handler (r=r@entry=0x137b0a10) at src/http/ngx_http_core_module.c:869

#7 0x0000000000486290 in ngx_http_process_request (r=r@entry=0x137b0a10) at src/http/ngx_http_request.c:1921

#8 0x000000000048666b in ngx_http_process_request_headers (rev=rev@entry=0x1163cb90) at src/http/ngx_http_request.c:1352

#9 0x0000000000486994 in ngx_http_process_request_line (rev=rev@entry=0x1163cb90) at src/http/ngx_http_request.c:1032

#10 0x0000000000486dc6 in ngx_http_wait_request_handler (rev=0x1163cb90) at src/http/ngx_http_request.c:508

#11 0x0000000000470d5c in ngx_epoll_process_events (cycle=0x140a970, timer=<optimized out>, flags=<optimized out>)

at src/event/modules/ngx_epoll_module.c:822

#12 0x0000000000467bf0 in ngx_process_events_and_timers (cycle=cycle@entry=0x140a970) at src/event/ngx_event.c:248

#13 0x000000000046ed66 in ngx_worker_process_cycle (cycle=0x140a970, data="" out>)

at src/os/unix/ngx_process_cycle.c:769

#14 0x000000000046d39f in ngx_spawn_process (cycle=cycle@entry=0x140a970,

proc=proc@entry=0x46ec6b <ngx_worker_process_cycle>, data="" name=name@entry=0x71428e "worker process",

respawn=respawn@entry=-3) at src/os/unix/ngx_process.c:198

#15 0x000000000046df6e in ngx_start_worker_processes (cycle=cycle@entry=0x140a970, n=6, type=type@entry=-3)

at src/os/unix/ngx_process_cycle.c:358

#16 0x000000000046f6c7 in ngx_master_process_cycle (cycle=cycle@entry=0x140a970) at src/os/unix/ngx_process_cycle.c:130

#17 0x000000000044df46 in main (argc=<optimized out>, argv=<optimized out>) at src/core/nginx.c:419

场景：

lua代码中执行ngx.exec到named location，该named location中执行return 403，小概率引发coredump

分析：

在ngx_http_lua_rewrite_by_chunk函数执行lua代码ngx_http_lua_run_thread之后，

执行ngx_http_named_location，然后执行ngx_http_core_run_phases，然后执行ngx_http_finalize_request（r, 403）

最后执行ngx_http_close_request，发现r->main->count=2，此时--，并return

ngx_http_lua_run_thread在此次执行过程中返回NGX_DONE，然后执行ngx_http_lua_finalize_request(r, NGX_DONE)

有两种情况

1、Connection: close

再次执行ngx_http_close_request，此时r->main->count=1，释放r，并销毁连接c，ngx_http_lua_run_posted_threads函数中，判断c->destroyed，返回NGX_DONE，没有问题

2、Connection: keep-alive

执行ngx_http_set_keepalive，然后执行ngx_http_free_request，b->pos < b->last的情况下（客户端发送的数据还有未解析的），会创建新的request

此时释放之前的r，但不会销毁c，此时ngx_http_lua_run_posted_threads再次使用的ctx来自于r->pool，因为free不会把对应的内存置为0，当该内存再次被使用时，就会引发core

解决思路

1、ngx_http_lua_run_posted_threads之后执行ngx_http_lua_finalize_request(r, NGX_DONE)，这个我没看出来有什么问题

2、lua ctx不在r->pool中申请，而是r->connection->pool中，不过此时r都释放了，感觉意义不大

crasyangel.lhy

漏了一点，ngx_http_free_request中，r->connection->destroyed = 1，而在ngx_http_set_keepalive中，b->pos < b->last的情况下，c->destroyed = 0

所以ngx_http_lua_run_posted_threads中c->destroyed的判断不会起作用

在 2017年9月13日星期三 UTC+8下午12:28:09，高岩写道：

#0 ngx_http_lua_run_posted_threads (c=c@entry=0x10dc93c0, L=L@entry=0x4180d378, r=r@entry=0x137b0a10,
ctx=ctx@entry=0x136e0700) at addon/lua-nginx-module-ssl-cert-by-lua/src/ngx_http_lua_util.c:3051
#1 0x00000000004ff26f in ngx_http_lua_rewrite_by_chunk (L=L@entry=0x4180d378, r=r@entry=0x137b0a10)
at addon/lua-nginx-module-ssl-cert-by-lua/src/ngx_http_lua_rewriteby.c:321
#2 0x00000000004ff783 in ngx_http_lua_rewrite_handler_file (r=0x137b0a10)
at addon/lua-nginx-module-ssl-cert-by-lua/src/ngx_http_lua_rewriteby.c:226
#3 0x00000000004ff61c in ngx_http_lua_rewrite_handler (r=0x137b0a10)
at addon/lua-nginx-module-ssl-cert-by-lua/src/ngx_http_lua_rewriteby.c:162
#4 0x000000000047ec23 in ngx_http_core_rewrite_phase (r=0x137b0a10, ph=0x10ac1fa0) at src/http/ngx_http_core_module.c:940
#5 0x000000000047aa63 in ngx_http_core_run_phases (r=r@entry=0x137b0a10) at src/http/ngx_http_core_module.c:886
#6 0x000000000047ab7c in ngx_http_handler (r=r@entry=0x137b0a10) at src/http/ngx_http_core_module.c:869
#7 0x0000000000486290 in ngx_http_process_request (r=r@entry=0x137b0a10) at src/http/ngx_http_request.c:1921
#8 0x000000000048666b in ngx_http_process_request_headers (rev=rev@entry=0x1163cb90) at src/http/ngx_http_request.c:1352
#9 0x0000000000486994 in ngx_http_process_request_line (rev=rev@entry=0x1163cb90) at src/http/ngx_http_request.c:1032
#10 0x0000000000486dc6 in ngx_http_wait_request_handler (rev=0x1163cb90) at src/http/ngx_http_request.c:508
#11 0x0000000000470d5c in ngx_epoll_process_events (cycle=0x140a970, timer=<optimized out>, flags=<optimized out>)
at src/event/modules/ngx_epoll_module.c:822
#12 0x0000000000467bf0 in ngx_process_events_and_timers (cycle=cycle@entry=0x140a970) at src/event/ngx_event.c:248
#13 0x000000000046ed66 in ngx_worker_process_cycle (cycle=0x140a970, data="" out>)
at src/os/unix/ngx_process_cycle.c:769
#14 0x000000000046d39f in ngx_spawn_process (cycle=cycle@entry=0x140a970,
proc=proc@entry=0x46ec6b <ngx_worker_process_cycle>, data="" name=name@entry=0x71428e "worker process",
respawn=respawn@entry=-3) at src/os/unix/ngx_process.c:198
#15 0x000000000046df6e in ngx_start_worker_processes (cycle=cycle@entry=0x140a970, n=6, type=type@entry=-3)
at src/os/unix/ngx_process_cycle.c:358
#16 0x000000000046f6c7 in ngx_master_process_cycle (cycle=cycle@entry=0x140a970) at src/os/unix/ngx_process_cycle.c:130
#17 0x000000000044df46 in main (argc=<optimized out>, argv=<optimized out>) at src/core/nginx.c:419

场景：
lua代码中执行ngx.exec到named location，该named location中执行return 403，小概率引发coredump

分析：
在ngx_http_lua_rewrite_by_chunk函数执行lua代码ngx_http_lua_run_thread之后，
执行ngx_http_named_location，然后执行ngx_http_core_run_phases，然后执行ngx_http_finalize_request（r, 403）
最后执行ngx_http_close_request，发现r->main->count=2，此时--，并return

ngx_http_lua_run_thread在此次执行过程中返回NGX_DONE，然后执行ngx_http_lua_finalize_request(r, NGX_DONE)
有两种情况
1、Connection: close
再次执行ngx_http_close_request，此时r->main->count=1，释放r，并销毁连接c，ngx_http_lua_run_posted_threads函数中，判断c->destroyed，返回NGX_DONE，没有问题
2、Connection: keep-alive
执行ngx_http_set_keepalive，然后执行ngx_http_free_request，b->pos < b->last的情况下（客户端发送的数据还有未解析的），会创建新的request
此时释放之前的r，但不会销毁c，此时ngx_http_lua_run_posted_threads再次使用的ctx来自于r->pool，因为free不会把对应的内存置为0，当该内存再次被使用时，就会引发core

解决思路
1、ngx_http_lua_run_posted_threads之后执行ngx_http_lua_finalize_request(r, NGX_DONE)，这个我没看出来有什么问题
2、lua ctx不在r->pool中申请，而是r->connection->pool中，不过此时r都释放了，感觉意义不大

zchao1995

看了一下，如果是 pipeline 的情况，确实有这个可能，建议报告到 github issue 吧，顺便搞一个百分百复现的最小化的案例

On Wednesday, September 13, 2017 at 12:39:40 PM UTC+8, 高岩 wrote:

漏了一点，ngx_http_free_request中，r->connection->destroyed = 1，而在ngx_http_set_keepalive中，b->pos < b->last的情况下，c->destroyed = 0
所以ngx_http_lua_run_posted_threads中c->destroyed的判断不会起作用

在 2017年9月13日星期三 UTC+8下午12:28:09，高岩写道：
#0 ngx_http_lua_run_posted_threads (c=c@entry=0x10dc93c0, L=L@entry=0x4180d378, r=r@entry=0x137b0a10,
ctx=ctx@entry=0x136e0700) at addon/lua-nginx-module-ssl-cert-by-lua/src/ngx_http_lua_util.c:3051
#1 0x00000000004ff26f in ngx_http_lua_rewrite_by_chunk (L=L@entry=0x4180d378, r=r@entry=0x137b0a10)
at addon/lua-nginx-module-ssl-cert-by-lua/src/ngx_http_lua_rewriteby.c:321
#2 0x00000000004ff783 in ngx_http_lua_rewrite_handler_file (r=0x137b0a10)
at addon/lua-nginx-module-ssl-cert-by-lua/src/ngx_http_lua_rewriteby.c:226
#3 0x00000000004ff61c in ngx_http_lua_rewrite_handler (r=0x137b0a10)
at addon/lua-nginx-module-ssl-cert-by-lua/src/ngx_http_lua_rewriteby.c:162
#4 0x000000000047ec23 in ngx_http_core_rewrite_phase (r=0x137b0a10, ph=0x10ac1fa0) at src/http/ngx_http_core_module.c:940
#5 0x000000000047aa63 in ngx_http_core_run_phases (r=r@entry=0x137b0a10) at src/http/ngx_http_core_module.c:886
#6 0x000000000047ab7c in ngx_http_handler (r=r@entry=0x137b0a10) at src/http/ngx_http_core_module.c:869
#7 0x0000000000486290 in ngx_http_process_request (r=r@entry=0x137b0a10) at src/http/ngx_http_request.c:1921
#8 0x000000000048666b in ngx_http_process_request_headers (rev=rev@entry=0x1163cb90) at src/http/ngx_http_request.c:1352
#9 0x0000000000486994 in ngx_http_process_request_line (rev=rev@entry=0x1163cb90) at src/http/ngx_http_request.c:1032
#10 0x0000000000486dc6 in ngx_http_wait_request_handler (rev=0x1163cb90) at src/http/ngx_http_request.c:508
#11 0x0000000000470d5c in ngx_epoll_process_events (cycle=0x140a970, timer=<optimized out>, flags=<optimized out>)
at src/event/modules/ngx_epoll_module.c:822
#12 0x0000000000467bf0 in ngx_process_events_and_timers (cycle=cycle@entry=0x140a970) at src/event/ngx_event.c:248
#13 0x000000000046ed66 in ngx_worker_process_cycle (cycle=0x140a970, data="" out>)
at src/os/unix/ngx_process_cycle.c:769
#14 0x000000000046d39f in ngx_spawn_process (cycle=cycle@entry=0x140a970,
proc=proc@entry=0x46ec6b <ngx_worker_process_cycle>, data="" name=name@entry=0x71428e "worker process",
respawn=respawn@entry=-3) at src/os/unix/ngx_process.c:198
#15 0x000000000046df6e in ngx_start_worker_processes (cycle=cycle@entry=0x140a970, n=6, type=type@entry=-3)
at src/os/unix/ngx_process_cycle.c:358
#16 0x000000000046f6c7 in ngx_master_process_cycle (cycle=cycle@entry=0x140a970) at src/os/unix/ngx_process_cycle.c:130
#17 0x000000000044df46 in main (argc=<optimized out>, argv=<optimized out>) at src/core/nginx.c:419

场景：
lua代码中执行ngx.exec到named location，该named location中执行return 403，小概率引发coredump

分析：
在ngx_http_lua_rewrite_by_chunk函数执行lua代码ngx_http_lua_run_thread之后，
执行ngx_http_named_location，然后执行ngx_http_core_run_phases，然后执行ngx_http_finalize_request（r, 403）
最后执行ngx_http_close_request，发现r->main->count=2，此时--，并return

ngx_http_lua_run_thread在此次执行过程中返回NGX_DONE，然后执行ngx_http_lua_finalize_request(r, NGX_DONE)
有两种情况
1、Connection: close
再次执行ngx_http_close_request，此时r->main->count=1，释放r，并销毁连接c，ngx_http_lua_run_posted_threads函数中，判断c->destroyed，返回NGX_DONE，没有问题
2、Connection: keep-alive
执行ngx_http_set_keepalive，然后执行ngx_http_free_request，b->pos < b->last的情况下（客户端发送的数据还有未解析的），会创建新的request
此时释放之前的r，但不会销毁c，此时ngx_http_lua_run_posted_threads再次使用的ctx来自于r->pool，因为free不会把对应的内存置为0，当该内存再次被使用时，就会引发core

解决思路
1、ngx_http_lua_run_posted_threads之后执行ngx_http_lua_finalize_request(r, NGX_DONE)，这个我没看出来有什么问题
2、lua ctx不在r->pool中申请，而是r->connection->pool中，不过此时r都释放了，感觉意义不大

agentzh

Hello!

2017-09-12 21:28 GMT-07:00 高岩:
> 场景：
> lua代码中执行ngx.exec到named location，该named location中执行return 403，小概率引发coredump
>

多谢报告问题！我可以通过下面这个最小化的测试用例来可靠复现这个 bug:

    === TEST 17: pipelined requests
    --- config
        location /t {
            rewrite_by_lua_block {
                ngx.exec("@foo")
            }
        }

        location @foo {
            return 200;
        }
    --- pipelined_requests eval
    ["GET /t", "GET /t"]
    --- error_code eval
    [200, 200]
    --- response_body eval
    ["", ""]
    --- no_error_log
    [error]

使用我们开源的 Test::Nginx::Socket 测试框架的 valgrind 测试模式可以可靠地得到下面的内存错误报告：

    t/023-rewrite/exec.t .. 21/76 TEST 17: pipelined requests
    ==3703== Invalid read of size 8
    ==3703==    at 0x4BC17C: ngx_http_lua_run_posted_threads
(ngx_http_lua_util.c:3068)
    ==3703==    by 0x4BDE2B: ngx_http_lua_rewrite_by_chunk
(ngx_http_lua_rewriteby.c:340)
    ==3703==    by 0x4BDF77: ngx_http_lua_rewrite_handler
(ngx_http_lua_rewriteby.c:162)
    ==3703==    by 0x45396B: ngx_http_core_rewrite_phase
(ngx_http_core_module.c:910)
    ==3703==    by 0x44F234: ngx_http_core_run_phases
(ngx_http_core_module.c:856)
    ==3703==    by 0x459E02: ngx_http_process_request (ngx_http_request.c:1916)
    ==3703==    by 0x45A657: ngx_http_process_request_line
(ngx_http_request.c:1027)
    ==3703==    by 0x444122: ngx_epoll_process_events (ngx_epoll_module.c:900)
    ==3703==    by 0x43BA7A: ngx_process_events_and_timers (ngx_event.c:252)
    ==3703==    by 0x44365A: ngx_single_process_cycle (ngx_process_cycle.c:335)
    ==3703==    by 0x41D750: main (nginx.c:364)
    ==3703==  Address 0x7005678 is 408 bytes inside a block of size 4,096 free'd
    ==3703==    at 0x4C2CD5A: free (vg_replace_malloc.c:530)
    ==3703==    by 0x41FB1E: ngx_destroy_pool (ngx_palloc.c:93)
    ==3703==    by 0x4581A7: ngx_http_free_request (ngx_http_request.c:3516)
    ==3703==    by 0x458970: ngx_http_set_keepalive (ngx_http_request.c:2918)
    ==3703==    by 0x458970: ngx_http_finalize_connection
(ngx_http_request.c:2563)
    ==3703==    by 0x4BDE1A: ngx_http_lua_rewrite_by_chunk
(ngx_http_lua_rewriteby.c:339)
    ==3703==    by 0x4BDF77: ngx_http_lua_rewrite_handler
(ngx_http_lua_rewriteby.c:162)
    ==3703==    by 0x45396B: ngx_http_core_rewrite_phase
(ngx_http_core_module.c:910)
    ==3703==    by 0x44F234: ngx_http_core_run_phases
(ngx_http_core_module.c:856)
    ==3703==    by 0x459E02: ngx_http_process_request (ngx_http_request.c:1916)
    ==3703==    by 0x45A657: ngx_http_process_request_line
(ngx_http_request.c:1027)
    ==3703==    by 0x444122: ngx_epoll_process_events (ngx_epoll_module.c:900)
    ==3703==    by 0x43BA7A: ngx_process_events_and_timers (ngx_event.c:252)
    ==3703==    by 0x44365A: ngx_single_process_cycle (ngx_process_cycle.c:335)
    ==3703==    by 0x41D750: main (nginx.c:364)
    ==3703==  Block was alloc'd at
    ==3703==    at 0x4C2DD89: memalign (vg_replace_malloc.c:857)
    ==3703==    by 0x4C2DE87: posix_memalign (vg_replace_malloc.c:1020)
    ==3703==    by 0x43E870: ngx_memalign (ngx_alloc.c:57)
    ==3703==    by 0x41F891: ngx_palloc_block (ngx_palloc.c:189)
    ==3703==    by 0x4BE05D: ngx_http_lua_create_ctx (ngx_http_lua_util.h:279)
    ==3703==    by 0x4BE05D: ngx_http_lua_rewrite_handler
(ngx_http_lua_rewriteby.c:92)
    ==3703==    by 0x45396B: ngx_http_core_rewrite_phase
(ngx_http_core_module.c:910)
    ==3703==    by 0x44F234: ngx_http_core_run_phases
(ngx_http_core_module.c:856)
    ==3703==    by 0x459E02: ngx_http_process_request (ngx_http_request.c:1916)
    ==3703==    by 0x45A657: ngx_http_process_request_line
(ngx_http_request.c:1027)
    ==3703==    by 0x444122: ngx_epoll_process_events (ngx_epoll_module.c:900)
    ==3703==    by 0x43BA7A: ngx_process_events_and_timers (ngx_event.c:252)
    ==3703==    by 0x44365A: ngx_single_process_cycle (ngx_process_cycle.c:335)
    ==3703==    by 0x41D750: main (nginx.c:364)
    ==3703==

我在这个 pull request 里面利用 c->requests 计数器来修复了这个问题：

    https://github.com/openresty/lua-nginx-module/pull/1154

欢迎评审和测试。

> 2、Connection: keep-alive
> 执行ngx_http_set_keepalive，然后执行ngx_http_free_request，b->pos <
> b->last的情况下（客户端发送的数据还有未解析的），会创建新的request
> 此时释放之前的r，但不会销毁c，此时ngx_http_lua_run_posted_threads再次使用的ctx来自于r->pool，因为free不会把对应的内存置为0，当该内存再次被使用时，就会引发core
>

这是 use-after-free 错误，free 之后是绝不应该去读已经释放掉的内存块内容的，不管是否清零。

> 解决思路
> 1、ngx_http_lua_run_posted_threads之后执行ngx_http_lua_finalize_request(r,
> NGX_DONE)，这个我没看出来有什么问题

这个时序就错了。比如直接返回了 403 错误页就不会再跑其他轻线程的操作了。这么一改就会变成先跑其他轻线程的操作，最后再 403。

> 2、lua ctx不在r->pool中申请，而是r->connection->pool中，不过此时r都释放了，感觉意义不大
>

肯定不能在 c->pool 里面分配 lua ctx 的，那样的话内存就不能及时释放掉了，算是一种内存泄漏了（如果 pipeline 或
keepalive 请求很多的话）。

Regards,
Yichun

crasyangel.lhy

赞，谢谢春哥

在 2017年9月14日星期四 UTC+8上午3:17:37，agentzh写道：

Hello!

2017-09-12 21:28 GMT-07:00 高岩:
> 场景：
> lua代码中执行ngx.exec到named location，该named location中执行return 403，小概率引发coredump
>

多谢报告问题！我可以通过下面这个最小化的测试用例来可靠复现这个 bug:

=== TEST 17: pipelined requests
--- config
location /t {
rewrite_by_lua_block {
ngx.exec("@foo")
}
}

location @foo {
return 200;
}
--- pipelined_requests eval
["GET /t", "GET /t"]
--- error_code eval
[200, 200]
--- response_body eval
["", ""]
--- no_error_log
[error]

使用我们开源的 Test::Nginx::Socket 测试框架的 valgrind 测试模式可以可靠地得到下面的内存错误报告：

t/023-rewrite/exec.t .. 21/76 TEST 17: pipelined requests
==3703== Invalid read of size 8
==3703== at 0x4BC17C: ngx_http_lua_run_posted_threads
(ngx_http_lua_util.c:3068)
==3703== by 0x4BDE2B: ngx_http_lua_rewrite_by_chunk
(ngx_http_lua_rewriteby.c:340)
==3703== by 0x4BDF77: ngx_http_lua_rewrite_handler
(ngx_http_lua_rewriteby.c:162)
==3703== by 0x45396B: ngx_http_core_rewrite_phase
(ngx_http_core_module.c:910)
==3703== by 0x44F234: ngx_http_core_run_phases
(ngx_http_core_module.c:856)
==3703== by 0x459E02: ngx_http_process_request (ngx_http_request.c:1916)
==3703== by 0x45A657: ngx_http_process_request_line
(ngx_http_request.c:1027)
==3703== by 0x444122: ngx_epoll_process_events (ngx_epoll_module.c:900)
==3703== by 0x43BA7A: ngx_process_events_and_timers (ngx_event.c:252)
==3703== by 0x44365A: ngx_single_process_cycle (ngx_process_cycle.c:335)
==3703== by 0x41D750: main (nginx.c:364)
==3703== Address 0x7005678 is 408 bytes inside a block of size 4,096 free'd
==3703== at 0x4C2CD5A: free (vg_replace_malloc.c:530)
==3703== by 0x41FB1E: ngx_destroy_pool (ngx_palloc.c:93)
==3703== by 0x4581A7: ngx_http_free_request (ngx_http_request.c:3516)
==3703== by 0x458970: ngx_http_set_keepalive (ngx_http_request.c:2918)
==3703== by 0x458970: ngx_http_finalize_connection
(ngx_http_request.c:2563)
==3703== by 0x4BDE1A: ngx_http_lua_rewrite_by_chunk
(ngx_http_lua_rewriteby.c:339)
==3703== by 0x4BDF77: ngx_http_lua_rewrite_handler
(ngx_http_lua_rewriteby.c:162)
==3703== by 0x45396B: ngx_http_core_rewrite_phase
(ngx_http_core_module.c:910)
==3703== by 0x44F234: ngx_http_core_run_phases
(ngx_http_core_module.c:856)
==3703== by 0x459E02: ngx_http_process_request (ngx_http_request.c:1916)
==3703== by 0x45A657: ngx_http_process_request_line
(ngx_http_request.c:1027)
==3703== by 0x444122: ngx_epoll_process_events (ngx_epoll_module.c:900)
==3703== by 0x43BA7A: ngx_process_events_and_timers (ngx_event.c:252)
==3703== by 0x44365A: ngx_single_process_cycle (ngx_process_cycle.c:335)
==3703== by 0x41D750: main (nginx.c:364)
==3703== Block was alloc'd at
==3703== at 0x4C2DD89: memalign (vg_replace_malloc.c:857)
==3703== by 0x4C2DE87: posix_memalign (vg_replace_malloc.c:1020)
==3703== by 0x43E870: ngx_memalign (ngx_alloc.c:57)
==3703== by 0x41F891: ngx_palloc_block (ngx_palloc.c:189)
==3703== by 0x4BE05D: ngx_http_lua_create_ctx (ngx_http_lua_util.h:279)
==3703== by 0x4BE05D: ngx_http_lua_rewrite_handler
(ngx_http_lua_rewriteby.c:92)
==3703== by 0x45396B: ngx_http_core_rewrite_phase
(ngx_http_core_module.c:910)
==3703== by 0x44F234: ngx_http_core_run_phases
(ngx_http_core_module.c:856)
==3703== by 0x459E02: ngx_http_process_request (ngx_http_request.c:1916)
==3703== by 0x45A657: ngx_http_process_request_line
(ngx_http_request.c:1027)
==3703== by 0x444122: ngx_epoll_process_events (ngx_epoll_module.c:900)
==3703== by 0x43BA7A: ngx_process_events_and_timers (ngx_event.c:252)
==3703== by 0x44365A: ngx_single_process_cycle (ngx_process_cycle.c:335)
==3703== by 0x41D750: main (nginx.c:364)
==3703==

我在这个 pull request 里面利用 c->requests 计数器来修复了这个问题：

https://github.com/openresty/lua-nginx-module/pull/1154

欢迎评审和测试。

> 2、Connection: keep-alive
> 执行ngx_http_set_keepalive，然后执行ngx_http_free_request，b->pos <
> b->last的情况下（客户端发送的数据还有未解析的），会创建新的request
> 此时释放之前的r，但不会销毁c，此时ngx_http_lua_run_posted_threads再次使用的ctx来自于r->pool，因为free不会把对应的内存置为0，当该内存再次被使用时，就会引发core
>

这是 use-after-free 错误，free 之后是绝不应该去读已经释放掉的内存块内容的，不管是否清零。

> 解决思路
> 1、ngx_http_lua_run_posted_threads之后执行ngx_http_lua_finalize_request(r,
> NGX_DONE)，这个我没看出来有什么问题

这个时序就错了。比如直接返回了 403 错误页就不会再跑其他轻线程的操作了。这么一改就会变成先跑其他轻线程的操作，最后再 403。

> 2、lua ctx不在r->pool中申请，而是r->connection->pool中，不过此时r都释放了，感觉意义不大
>

肯定不能在 c->pool 里面分配 lua ctx 的，那样的话内存就不能及时释放掉了，算是一种内存泄漏了（如果 pipeline 或
keepalive 请求很多的话）。

Regards,
Yichun

crasyangel.lhy

> 1、ngx_http_lua_run_posted_threads之后执行ngx_http_lua_finalize_request(r,
> NGX_DONE)，这个我没看出来有什么问题
这个时序就错了。比如直接返回了 403 错误页就不会再跑其他轻线程的操作了。这么一改就会变成先跑其他轻线程的操作，最后再 403。

如果named location直接返回403，应该不会有其他轻线程的操作了吧，有轻线程的情况下，named location应该还没执行完，finalize NGX_DONE先执行

其实finalize NGX_DONE先执行还是后执行是不一定的，这个时序也不会导致什么问题

crasyangel.lhy

finalize NGX_DONE先执行还是后执行，是和named location执行finalize request来对比的

在 2017年9月15日星期五 UTC+8下午3:40:14，高岩写道：

> 1、ngx_http_lua_run_posted_threads之后执行ngx_http_lua_finalize_request(r,
> NGX_DONE)，这个我没看出来有什么问题
这个时序就错了。比如直接返回了 403 错误页就不会再跑其他轻线程的操作了。这么一改就会变成先跑其他轻线程的操作，最后再 403。

如果named location直接返回403，应该不会有其他轻线程的操作了吧，有轻线程的情况下，named location应该还没执行完，finalize NGX_DONE先执行
其实finalize NGX_DONE先执行还是后执行是不一定的，这个时序也不会导致什么问题

agentzh

Hello!

2017-09-15 0:40 GMT-07:00 高岩:
>
> 如果named location直接返回403，应该不会有其他轻线程的操作了吧，有轻线程的情况下，named
> location应该还没执行完，finalize NGX_DONE先执行
> 其实finalize NGX_DONE先执行还是后执行是不一定的，这个时序也不会导致什么问题
>

这个地方比较复杂，我就不和你沿这条路讨论下去了，毕竟 nginx 的坑比较多。改变调用顺序逻辑上就是错误的，而不改变调用顺序，又解决不了这里的内存问题。

话说，我的那个 pull request 里面的补丁你试了么？

Regards,
Yichun

crasyangel.lhy

还没有，版本升级有一个过程，下周先试着灰度下吧

在 2017年9月16日星期六 UTC+8上午4:33:33，agentzh写道：

Hello!

2017-09-15 0:40 GMT-07:00 高岩:
>
> 如果named location直接返回403，应该不会有其他轻线程的操作了吧，有轻线程的情况下，named
> location应该还没执行完，finalize NGX_DONE先执行
> 其实finalize NGX_DONE先执行还是后执行是不一定的，这个时序也不会导致什么问题
>

这个地方比较复杂，我就不和你沿这条路讨论下去了，毕竟 nginx 的坑比较多。改变调用顺序逻辑上就是错误的，而不改变调用顺序，又解决不了这里的内存问题。

话说，我的那个 pull request 里面的补丁你试了么？

Regards,
Yichun

agentzh

Hello!

2017-09-13 12:17 GMT-07:00 Yichun Zhang (agentzh):
> 我在这个 pull request 里面利用 c->requests 计数器来修复了这个问题：
>
>     https://github.com/openresty/lua-nginx-module/pull/1154
>

已合并到 master。

Regards,
Yichun