openresty, passenger, subrequest SIGSEGV

[sychevyi]

Hello,
I'm experiencing reproducible crash while using lua-nginx-module's ngx.location.capture request to access ruby application.

I'm using self-made docker image, based on ubuntu:trusty.
OS:

docker run openresty-passenger:with-ssl lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 14.04.3 LTS
Release:        14.04
Codename:       trusty

Ruby (from BrightBox PPA):

docker run openresty-passenger:with-ssl ruby -v
ruby 2.2.4p230 (2015-12-16 revision 53155) [x86_64-linux-gnu]

Nginx/Passenger version:

docker run openresty-passenger:with-ssl nginx -V
nginx version: openresty/1.9.3.2
built by gcc 4.8.4 (Ubuntu 4.8.4-2ubuntu1~14.04) 
built with OpenSSL 1.0.1f 6 Jan 2014
TLS SNI support enabled
configure arguments: --prefix=/opt/openresty/nginx --with-debug 
--with-cc-opt='-DNGX_LUA_USE_ASSERT -DNGX_LUA_ABORT_AT_PANIC -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.19 --add-module=../ngx_lua_upstream-0.04 
--add-module=../headers-more-nginx-module-0.28 
--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,/opt/openresty/luajit/lib 
--http-client-body-temp-path=/var/nginx/client_body_temp 
--http-proxy-temp-path=/var/nginx/proxy_temp --http-log-path=/var/nginx/access.log 
--error-log-path=/var/nginx/error.log --pid-path=/var/nginx/nginx.pid 
--lock-path=/var/nginx/nginx.lock --with-pcre-jit 
--add-module=/var/lib/gems/2.2.0/gems/passenger-5.0.23/src/nginx_module 
--with-http_ssl_module --without-http_ssi_module 
--without-http_userid_module --without-http_uwsgi_module --without-http_scgi_module

Crash is only reproducible when nginx build with SSL support (--with-http_ssl_module).

Steps to reproduce:

• Add location to nginx.conf:

    location /lua-capture-passenger {
      content_by_lua '
         local res = ngx.location.capture("/")

         if res then
             ngx.say("status: ", res.status)
             ngx.say("body:")
             ngx.print(res.body)
         end
      ';
    }

• Start nginx
• Make GET request to /lua-capture-passenger. Nginx worker will crash and you will get 'Connection was reset' error in browser, instead of "status: 200 body: hello world".

error_log around the crash:

2016/01/17 15:24:54 [debug] 31#0: *1 http process request line
2016/01/17 15:24:54 [debug] 31#0: *1 http request line: "GET /lua-capture-passenger HTTP/1.1"
2016/01/17 15:24:54 [debug] 31#0: *1 http uri: "/lua-capture-passenger"
2016/01/17 15:24:54 [debug] 31#0: *1 http args: ""
2016/01/17 15:24:54 [debug] 31#0: *1 http exten: ""
2016/01/17 15:24:54 [debug] 31#0: *1 http process request header line
2016/01/17 15:24:54 [debug] 31#0: *1 http header: "User-Agent: curl/7.35.0"
2016/01/17 15:24:54 [debug] 31#0: *1 http header: "Host: localhost:8181"
2016/01/17 15:24:54 [debug] 31#0: *1 http header: "Accept: */*"
2016/01/17 15:24:54 [debug] 31#0: *1 http header done
2016/01/17 15:24:54 [debug] 31#0: *1 event timer del: 3: 1453044354306
2016/01/17 15:24:54 [debug] 31#0: *1 rewrite phase: 0
2016/01/17 15:24:54 [debug] 31#0: *1 rewrite phase: 1
2016/01/17 15:24:54 [debug] 31#0: *1 test location: "/"
2016/01/17 15:24:54 [debug] 31#0: *1 test location: "lua-capture-static"
2016/01/17 15:24:54 [debug] 31#0: *1 test location: "lua-capture-passenger"
2016/01/17 15:24:54 [debug] 31#0: *1 using configuration "/lua-capture-passenger"
2016/01/17 15:24:54 [debug] 31#0: *1 http cl:-1 max:1048576
2016/01/17 15:24:54 [debug] 31#0: *1 rewrite phase: 3
2016/01/17 15:24:54 [debug] 31#0: *1 rewrite phase: 4
2016/01/17 15:24:54 [debug] 31#0: *1 post rewrite phase: 5
2016/01/17 15:24:54 [debug] 31#0: *1 generic phase: 6
2016/01/17 15:24:54 [debug] 31#0: *1 generic phase: 7
2016/01/17 15:24:54 [debug] 31#0: *1 access phase: 8
2016/01/17 15:24:54 [debug] 31#0: *1 access phase: 9
2016/01/17 15:24:54 [debug] 31#0: *1 post access phase: 10
2016/01/17 15:24:54 [debug] 31#0: *1 lua content handler, uri:"/lua-capture-passenger" c:1
2016/01/17 15:24:54 [debug] 31#0: *1 posix_memalign: 00000000022F3670:4096 @16
2016/01/17 15:24:54 [debug] 31#0: *1 lua reset ctx
2016/01/17 15:24:54 [debug] 31#0: *1 lua creating new thread
2016/01/17 15:24:54 [debug] 31#0: *1 http cleanup add: 00000000022F3560
2016/01/17 15:24:54 [debug] 31#0: *1 lua run thread, top:0 c:1
2016/01/17 15:24:54 [debug] 31#0: *1 lua location capture, uri:"/lua-capture-passenger" c:1
2016/01/17 15:24:54 [debug] 31#0: *1 http subrequest "/?"
2016/01/17 15:24:54 [debug] 31#0: *1 posix_memalign: 000000000231EB60:4096 @16
2016/01/17 15:24:54 [debug] 31#0: *1 lua resume returned 1
2016/01/17 15:24:54 [debug] 31#0: *1 lua thread yielded
2016/01/17 15:24:54 [debug] 31#0: *1 http finalize request: -4, "/lua-capture-passenger?" a:1, c:3
2016/01/17 15:24:54 [debug] 31#0: *1 http request count:3 blk:0
2016/01/17 15:24:54 [debug] 31#0: *1 http posted request: "/?"
2016/01/17 15:24:54 [debug] 31#0: *1 rewrite phase: 0
2016/01/17 15:24:54 [debug] 31#0: *1 rewrite phase: 1
2016/01/17 15:24:54 [debug] 31#0: *1 test location: "/"
2016/01/17 15:24:54 [debug] 31#0: *1 using configuration "/"
2016/01/17 15:24:54 [debug] 31#0: *1 http cl:-1 max:1048576
2016/01/17 15:24:54 [debug] 31#0: *1 rewrite phase: 3
2016/01/17 15:24:54 [debug] 31#0: *1 rewrite phase: 4
2016/01/17 15:24:54 [debug] 31#0: *1 post rewrite phase: 5
2016/01/17 15:24:54 [debug] 31#0: *1 generic phase: 6
2016/01/17 15:24:54 [debug] 31#0: *1 generic phase: 7
2016/01/17 15:24:54 [debug] 31#0: *1 http init upstream, client timer: 0
2016/01/17 15:24:54 [debug] 31#0: *1 epoll add event: fd:3 op:3 ev:80002005
2016/01/17 15:24:54 [notice] 1#0: signal 17 (SIGCHLD) received
2016/01/17 15:24:54 [alert] 1#0: worker process 31 exited on signal 11 (core dumped)

I've tried to analyze core dump, here is GDB output:

root@6a6d83720930:/tmp# gdb /opt/openresty/nginx/sbin/nginx 43\ 11\ 524288000\ 3297 
GNU gdb (Ubuntu 7.7.1-0ubuntu5~14.04.2) 7.7.1
Copyright (C) 2014 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /opt/openresty/nginx/sbin/nginx...done.
Illegal process-id: 43 11 524288000 3297.
[New LWP 43]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `nginx: worker process                            '.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x000000000051126d in construct_request_buffer (r=r@entry=0x967f60, slcf=slcf@entry=0x977ff8, context=context@entry=0x968a38, state=state@entry=0x7fffd2fd0300, b=b@entry=0x0)
    at /var/lib/gems/2.2.0/gems/passenger-5.0.23/src/nginx_module/ContentHandler.c:745
745             if (r->http_connection->ssl) {
Traceback (most recent call last):
  File "/usr/share/gdb/auto-load/usr/lib/x86_64-linux-gnu/libstdc++.so.6.0.19-gdb.py", line 63, in <module>
    from libstdcxx.v6.printers import register_libstdcxx_printers
ImportError: No module named 'libstdcxx'
(gdb) quit

Also I've prepared Dockerfiles with nginx configuration and simple application to reproduce this problem: https://github.com/sychevyi/docker-openresty-passenger-bug. It contains additional test locations, but only /lua-capture-passenger has problem, as it directly dispatches subrequest to Passenger.

[OnixGH]

Thanks for reporting. The line in question is wrapped in an #if (NGX_HTTP_SSL), so the observation that it only happens with the ssl module enabled makes sense. We'll look into it and see if we need more info to reproduce.

[OnixGH]

@sychevyi using the branch with the fix mentioned above I don't get a crash anymore in your containers. Can you confirm it's working for you?

[sychevyi]

Yes, it works now. Thank you very much!
Please advice, when those changes will be available in passenger gem?

[FooBarWidget]

In the next release 5.0.25. We typically release every few weeks.