ngx.location.capture and sendfile #603

cmaion · 2015-11-16T18:47:31Z

Hi,

Got bitten by workers crashes in LUA due to ngx.location.capture requesting a location that has the ability to sendfile large files.

Found out that if subrequests makes use of the X-Accel-Redirect, the actual file content gets fully loaded within the subrequest, and then sent back to LUA at once, as a single large chunk of memory... and potentially blowing stuff in the LUA VM.

This is actually understandable, but a quick note in the doc might help as it's easy to overlook this!

My fix in my case is to:

push a different sendfile header from the backend (ie, something different than X-Accel-Redirect) in order to prevent the ngx.location.capture subrequest from loading the file,
test this header when returning from ngx.location.capture() and,
if found, use return ngx.exec(header value) to exit from LUA and stream the file back to the client

Not sure if a better/nicer way exists though!

Cedric

agentzh · 2015-11-17T02:06:12Z

@cmaion Crashing is not acceptable and must be fixed. Will you please provide a minimal and self-contained test case that can reproduce it easily on our side?

agentzh · 2015-11-17T02:07:14Z

@cmaion And BTW, it's Lua, not LUA. Please see http://www.lua.org/about.html#name

cmaion · 2015-11-17T09:19:55Z

OK ;)

The crashes left the following traces in the logs:

nginx: lua atpanic: Lua VM crashed, reason: string length overflow
*** stack smashing detected ***: nginx: worker process terminated
2015/11/16 10:53:17 [alert] 9556#0: worker process 10195 exited on signal 6 (core dumped)

or

nginx: lua atpanic: Lua VM crashed, reason: string length overflow
*** longjmp causes uninitialized stack frame ***: nginx: worker process terminated
======= Backtrace: =========
/lib/x86_64-linux-gnu/libc.so.6(+0x7338f)[0x7f5b56e7538f]
[...]

I ran gdb on one of the core file I got: it confirmed that it was related to a huge body being sent back from the subrequest (due to a subrequest serving a file with sendfile which got fully buffered within the subrequest):

Core was generated by `nginx: worker process'.
Program terminated with signal SIGABRT, Aborted.
#0  0x00007f6c3eab8cc9 in raise () from ./lib/x86_64-linux-gnu/libc.so.6
(gdb) bt
#0  0x00007f6c3eab8cc9 in raise () from ./lib/x86_64-linux-gnu/libc.so.6
#1  0x00007f6c3eabc0d8 in abort () from ./lib/x86_64-linux-gnu/libc.so.6
#2  0x00007f6c3eaf5394 in ?? () from ./lib/x86_64-linux-gnu/libc.so.6
#3  0x00007f6c3eb8cc9c in __fortify_fail () from ./lib/x86_64-linux-gnu/libc.so.6
#4  0x00007f6c3eb8cc40 in __stack_chk_fail () from ./lib/x86_64-linux-gnu/libc.so.6
#5  0x00000000004b7f9b in ngx_http_lua_run_thread (L=<optimized out>, r=<optimized out>, ctx=<optimized out>, nrets=<optimized out>)
    at ../lua-nginx-module-0.9.18/src/ngx_http_lua_util.c:1493
#6  0x00007f6c3fbf579b in lua_pushlstring () from ./opt/luajit/lib/libluajit-5.1.so.2
#7  0x00000000004a0fa9 in ngx_http_lua_handle_subreq_responses (ctx=0x95f2a8, r=0x95e4c0) at ../lua-nginx-module-0.9.18/src/ngx_http_lua_subrequest.c:1257
#8  ngx_http_lua_subrequest_resume (r=0x95e4c0) at ../lua-nginx-module-0.9.18/src/ngx_http_lua_subrequest.c:1579
#9  0x00000000004b9edb in ngx_http_lua_content_wev_handler (r=<optimized out>) at ../lua-nginx-module-0.9.18/src/ngx_http_lua_contentby.c:131
#10 0x000000000044a0d8 in ngx_http_run_posted_requests (c=c@entry=0x88b298) at src/http/ngx_http_request.c:2224
#11 0x000000000045bad9 in ngx_http_upstream_handler (ev=0x8f6c08) at src/http/ngx_http_upstream.c:980
#12 0x000000000042f0e8 in ngx_event_process_posted (cycle=cycle@entry=0x74f5f0, posted=0x7224a8 <ngx_posted_events>) at src/event/ngx_event_posted.c:40
#13 0x000000000042ec80 in ngx_process_events_and_timers (cycle=cycle@entry=0x74f5f0) at src/event/ngx_event.c:275
#14 0x0000000000435bca in ngx_worker_process_cycle (cycle=0x74f5f0, data=<optimized out>) at src/os/unix/ngx_process_cycle.c:816
#15 0x000000000043453f in ngx_spawn_process (cycle=cycle@entry=0x74f5f0, proc=proc@entry=0x435adb <ngx_worker_process_cycle>, data=data@entry=0x0, 
    name=name@entry=0x4d91b6 "worker process", respawn=respawn@entry=-3) at src/os/unix/ngx_process.c:198
#16 0x0000000000435d23 in ngx_start_worker_processes (cycle=cycle@entry=0x74f5f0, n=4, type=type@entry=-3) at src/os/unix/ngx_process_cycle.c:364
#17 0x00000000004367ac in ngx_master_process_cycle (cycle=cycle@entry=0x74f5f0) at src/os/unix/ngx_process_cycle.c:136
#18 0x00000000004169b3 in main (argc=<optimized out>, argv=<optimized out>) at src/core/nginx.c:407
(gdb) up
#1  0x00007f6c3eabc0d8 in abort () from ./lib/x86_64-linux-gnu/libc.so.6
(gdb) up
#2  0x00007f6c3eaf5394 in ?? () from ./lib/x86_64-linux-gnu/libc.so.6
(gdb) up
#3  0x00007f6c3eb8cc9c in __fortify_fail () from ./lib/x86_64-linux-gnu/libc.so.6
(gdb) up
#4  0x00007f6c3eb8cc40 in __stack_chk_fail () from ./lib/x86_64-linux-gnu/libc.so.6
(gdb) up
#5  0x00000000004b7f9b in ngx_http_lua_run_thread (L=<optimized out>, r=<optimized out>, ctx=<optimized out>, nrets=<optimized out>)
    at ../lua-nginx-module-0.9.18/src/ngx_http_lua_util.c:1493
1493    }
(gdb) up
#6  0x00007f6c3fbf579b in lua_pushlstring () from ./opt/luajit/lib/libluajit-5.1.so.2
(gdb) up
#7  0x00000000004a0fa9 in ngx_http_lua_handle_subreq_responses (ctx=0x95f2a8, r=0x95e4c0) at ../lua-nginx-module-0.9.18/src/ngx_http_lua_subrequest.c:1257
1257            lua_pushlstring(co, (char *) body_str->data, body_str->len);
(gdb) p body_str->len
$1 = 2563661604
(gdb) up
#8  ngx_http_lua_subrequest_resume (r=0x95e4c0) at ../lua-nginx-module-0.9.18/src/ngx_http_lua_subrequest.c:1579
1579        ngx_http_lua_handle_subreq_responses(r, ctx);

As you can see, a 2563661604 bytes body as the subrequest response is probably not recommended ;)

Are you sure that a minimal test case would be necessary?
Testing for such a large subrequest body might be pointless, no? -- unless you see something that should not happen even in that case?

Thanks,
Cedric

doujiang24 · 2015-11-17T14:59:38Z

Hello,

Yes, 2563661604 is too large
there is a memory limit in GC-managed memory in each LuaJIT VM (which
is per worker). The limit is 4GB on i386 and 1GB on x86_64(with the
luajit-mm plugin, the limit can be 2 GB on x86_64).

You can also use lua-resty-http[1] which support streaming way (avoid all
buffered in nginx and Lua)

https://github.com/pintsized/lua-resty-http

2015-11-17 17:19 GMT+08:00 cmaion [email protected]:

OK ;)

The crashes left the following traces in the logs:

nginx: lua atpanic: Lua VM crashed, reason: string length overflow
*** stack smashing detected ***: nginx: worker process terminated
2015/11/16 10:53:17 [alert] 9556#0: worker process 10195 exited on signal 6 (core dumped)

or

nginx: lua atpanic: Lua VM crashed, reason: string length overflow
*** longjmp causes uninitialized stack frame ***: nginx: worker process terminated
======= Backtrace: =========
/lib/x86_64-linux-gnu/libc.so.6(+0x7338f)[0x7f5b56e7538f]
[...]

I ran gdb on one of the core file I got: it confirmed that it was related
to a huge body being sent back from the subrequest (due to a subrequest
serving a file with sendfile which got fully buffered within the
subrequest):

Core was generated by `nginx: worker process'.
Program terminated with signal SIGABRT, Aborted.
#0 0x00007f6c3eab8cc9 in raise () from ./lib/x86_64-linux-gnu/libc.so.6
(gdb) bt
#0 0x00007f6c3eab8cc9 in raise () from ./lib/x86_64-linux-gnu/libc.so.6
#1 0x00007f6c3eabc0d8 in abort () from ./lib/x86_64-linux-gnu/libc.so.6
#2 0x00007f6c3eaf5394 in ?? () from ./lib/x86_64-linux-gnu/libc.so.6
#3 0x00007f6c3eb8cc9c in __fortify_fail () from ./lib/x86_64-linux-gnu/libc.so.6
#4 0x00007f6c3eb8cc40 in __stack_chk_fail () from ./lib/x86_64-linux-gnu/libc.so.6
#5 0x00000000004b7f9b in ngx_http_lua_run_thread (L=, r=, ctx=, nrets=)
at ../lua-nginx-module-0.9.18/src/ngx_http_lua_util.c:1493
#6 0x00007f6c3fbf579b in lua_pushlstring () from ./opt/luajit/lib/libluajit-5.1.so.2
#7 0x00000000004a0fa9 in ngx_http_lua_handle_subreq_responses (ctx=0x95f2a8, r=0x95e4c0) at ../lua-nginx-module-0.9.18/src/ngx_http_lua_subrequest.c:1257
#8 ngx_http_lua_subrequest_resume (r=0x95e4c0) at ../lua-nginx-module-0.9.18/src/ngx_http_lua_subrequest.c:1579
#9 0x00000000004b9edb in ngx_http_lua_content_wev_handler (r=) at ../lua-nginx-module-0.9.18/src/ngx_http_lua_contentby.c:131
#10 0x000000000044a0d8 in ngx_http_run_posted_requests (c=c@entry=0x88b298) at src/http/ngx_http_request.c:2224
#11 0x000000000045bad9 in ngx_http_upstream_handler (ev=0x8f6c08) at src/http/ngx_http_upstream.c:980
#12 0x000000000042f0e8 in ngx_event_process_posted (cycle=cycle@entry=0x74f5f0, posted=0x7224a8 <ngx_posted_events>) at src/event/ngx_event_posted.c:40
#13 0x000000000042ec80 in ngx_process_events_and_timers (cycle=cycle@entry=0x74f5f0) at src/event/ngx_event.c:275
#14 0x0000000000435bca in ngx_worker_process_cycle (cycle=0x74f5f0, data=) at src/os/unix/ngx_process_cycle.c:816
#15 0x000000000043453f in ngx_spawn_process (cycle=cycle@entry=0x74f5f0, proc=proc@entry=0x435adb <ngx_worker_process_cycle>, data=data@entry=0x0,
name=name@entry=0x4d91b6 "worker process", respawn=respawn@entry=-3) at src/os/unix/ngx_process.c:198
#16 0x0000000000435d23 in ngx_start_worker_processes (cycle=cycle@entry=0x74f5f0, n=4, type=type@entry=-3) at src/os/unix/ngx_process_cycle.c:364
#17 0x00000000004367ac in ngx_master_process_cycle (cycle=cycle@entry=0x74f5f0) at src/os/unix/ngx_process_cycle.c:136
#18 0x00000000004169b3 in main (argc=, argv=) at src/core/nginx.c:407
(gdb) up
#1 0x00007f6c3eabc0d8 in abort () from ./lib/x86_64-linux-gnu/libc.so.6
(gdb) up
#2 0x00007f6c3eaf5394 in ?? () from ./lib/x86_64-linux-gnu/libc.so.6
(gdb) up
#3 0x00007f6c3eb8cc9c in __fortify_fail () from ./lib/x86_64-linux-gnu/libc.so.6
(gdb) up
#4 0x00007f6c3eb8cc40 in __stack_chk_fail () from ./lib/x86_64-linux-gnu/libc.so.6
(gdb) up
#5 0x00000000004b7f9b in ngx_http_lua_run_thread (L=, r=, ctx=, nrets=)
at ../lua-nginx-module-0.9.18/src/ngx_http_lua_util.c:1493
1493 }
(gdb) up
#6 0x00007f6c3fbf579b in lua_pushlstring () from ./opt/luajit/lib/libluajit-5.1.so.2
(gdb) up
#7 0x00000000004a0fa9 in ngx_http_lua_handle_subreq_responses (ctx=0x95f2a8, r=0x95e4c0) at ../lua-nginx-module-0.9.18/src/ngx_http_lua_subrequest.c:1257
1257 lua_pushlstring(co, (char *) body_str->data, body_str->len);
(gdb) p body_str->len
$1 = 2563661604
(gdb) up
#8 ngx_http_lua_subrequest_resume (r=0x95e4c0) at ../lua-nginx-module-0.9.18/src/ngx_http_lua_subrequest.c:1579
1579 ngx_http_lua_handle_subreq_responses(r, ctx);

As you can see, a 2563661604 bytes body as the subrequest response is
probably not recommended ;)

Are you sure that a minimal test case would be necessary?
Testing for such a large subrequest body might be pointless, no? -- unless
you see something that should not happen even in that case?

Thanks,
Cedric

—
Reply to this email directly or view it on GitHub
#603 (comment)
.

cmaion · 2015-11-17T16:08:59Z

Hi @doujiang24, thanks for this clarification.

Didn't know about lua-resty-http, looks handy -- I believe that I the Nginx/sendfile code path is more appropriate in my case (I just need Lua to detect & manage the internal redirection), but nice to know!

agentzh · 2015-11-17T18:05:08Z

@cmaion Yeah, it's pointless to use sendfile with ngx.location.capture since the latter always fully buffer the whole subrequest response body. In addition, if your subrequest's response body is indeed 2GB-ish, then the LuaJIT VM crash is expected due to the (default) GC-managed memory limit of LuaJIT on x86_64.

cmaion · 2015-11-17T19:01:44Z

Yes, exactly.

Crashes "as expected" -- expected, as long as one understand that the response body is fully buffered within the subrequest (and that a sendfile performed from the subrequest naturally happens within the subrequest).
So my suggestion was merely to add a note in the documentation to warn future users about this ;)

Thanks again for your work & support!

agentzh · 2015-11-23T09:28:06Z

@cmaion Yeah, a note is good. Mind to submit a patch? ;)

cmaion · 2015-11-23T12:56:36Z

@agentzh sure. Something like that?

cmaion · 2015-12-14T07:35:23Z

Closing: note added by @agentzh c9b629a.

cmaion mentioned this issue Nov 23, 2015

Note concerning ngx.location.capture buffering all subrequest c… #607

Closed

cmaion closed this as completed Dec 14, 2015

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

ngx.location.capture and sendfile #603

ngx.location.capture and sendfile #603

cmaion commented Nov 16, 2015

agentzh commented Nov 17, 2015

agentzh commented Nov 17, 2015

cmaion commented Nov 17, 2015

doujiang24 commented Nov 17, 2015

cmaion commented Nov 17, 2015

agentzh commented Nov 17, 2015

cmaion commented Nov 17, 2015

agentzh commented Nov 23, 2015

cmaion commented Nov 23, 2015

cmaion commented Dec 14, 2015

ngx.location.capture and sendfile #603

ngx.location.capture and sendfile #603

Comments

cmaion commented Nov 16, 2015

agentzh commented Nov 17, 2015

agentzh commented Nov 17, 2015

cmaion commented Nov 17, 2015

doujiang24 commented Nov 17, 2015

cmaion commented Nov 17, 2015

agentzh commented Nov 17, 2015

cmaion commented Nov 17, 2015

agentzh commented Nov 23, 2015

cmaion commented Nov 23, 2015

cmaion commented Dec 14, 2015