APICast 500 Response

[rnavarro]

Our proxy servers are throwing back a 500 error.

In the logs I see this:

2017/10/11 19:10:02 [warn] 24#24: *183669 a client request body is buffered to a temporary file /opt/app-root/src/client_body_temp/0000019328, client: , server: _, request: "POST HTTP/1.1", host: ""
2017/10/11 19:10:02 [error] 24#24: *183669 lua entry thread aborted: runtime error: /opt/app-root/src/src/configuration.lua:80: bad argument #1 to 'setmetatable' (table expected, got nil)
stack traceback:
coroutine 0:
[C]: in function 'setmetatable
/opt/app-root/src/src/configuration.lua:80: in function 'get_auth_params
/opt/app-root/src/src/configuration.lua:183: in function 'extract_usage
/opt/app-root/src/src/proxy.lua:327: in function 'access
/opt/app-root/src/src/apicast.lua:103: in function 'access
access_by_lua(apicast.conf:77):1: in function <access_by_lua(apicast.conf:77):1>, client: , server: _, request: "POST HTTP/1.1", host: "

Version

$ openresty -V
nginx version: openresty/1.11.2.5
built by gcc 4.8.5 20150623 (Red Hat 4.8.5-11) (GCC)
built with OpenSSL 1.0.2k 26 Jan 2017
TLS SNI support enabled
configure arguments: --prefix=/usr/local/openresty/nginx --with-cc-opt='-O2 -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.05 --add-module=../ngx_coolkit-0.2rc3 --add-module=../set-misc-nginx-module-0.31 --add-module=../form-input-nginx-module-0.12 --add-module=../encrypted-session-nginx-module-0.06 --add-module=../srcache-nginx-module-0.31 --add-module=../ngx_lua-0.10.10 --add-module=../ngx_lua_upstream-0.07 --add-module=../headers-more-nginx-module-0.32 --add-module=../array-var-nginx-module-0.05 --add-module=../memc-nginx-module-0.18 --add-module=../redis2-nginx-module-0.14 --add-module=../redis-nginx-module-0.3.7 --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-ipv6 --with-stream --with-stream_ssl_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-file-aio --with-dtrace-probes --with-http_ssl_module

$ docker inspect --format='{{.Created}}' quay.io/3scale/apicast:master
2017-09-29T10:32:25.341211042Z

Steps To Reproduce

We are having a hard time reproducing this from our customer. It works internally however it doesn't work when they attempt it. We'll gather more information as we can.

Current Result

The openresty server returns a 500 error

Expected Result

The openresty server DOES NOT return a 500 error

I am going to try to increase the default size of the client_body_buffer_size nginx variable from 16k to 32k to see if that helps with this issue.

[rnavarro]

Any word on this?

[andrewdavidmackenzie]

hi @rnavarro we've been a bit snowed under recently.

We'll take a look again now, but if you can't reproduce it yourselves it sounds like it will be tough for us to do so.... maybe "by inspection" (gestalt!) we can have some ideas though...

[rnavarro]

Hey @andrewdavidmackenzie so it looks like this error has to do with request size.

We can now successfully reproduce this with large requests.

In my testing it looks like increasing the client_body_buffer_size fixes the issue.

We currently are injecting an additional configuration file that includes client_body_buffer_size 4m; and requests are no longer failing.

From reading here:
https://github.com/openresty/lua-nginx-module#lua_need_request_body

It looks like client_body_buffer_size must be sufficiently large or else $request_body is empty:

To read the request body data within the $request_body variable, client_body_buffer_size must have the same value as client_max_body_size. Because when the content length exceeds client_body_buffer_size but less than client_max_body_size, Nginx will buffer the data into a temporary file on the disk, which will lead to empty value in the $request_body variable

[davidor]

Thanks for reporting this bug @rnavarro . I could reproduce the error.

[davidor]

The method read_body_args in the Service module can also raise this error because it also calls ngx.req.read_body() + ngx.req.get_post_args()

https://github.com/3scale/apicast/blob/dcf449888aa8155812e340e5a6589a138311bdf2/apicast/src/configuration/service.lua#L29

[davidor]

@mikz Do you see any other solution apart from recommending to inject a customized configuration file like explained in https://github.com/3scale/apicast/tree/dcf449888aa8155812e340e5a6589a138311bdf2/examples/custom-config ?

I'm not sure that adding an env to allow users to set client_body_buffer_size according to their needs is a good idea. We would end up with lots of envs if we made everything configurable via envs.

[mikz]

So I think we should come up with some reasonable default buffer size. Then if the body is bigger than the buffer size print a warning that we will not take params because the the body was too big.

Just don't pass the auth in the body if it is big. It would seriously impact performance.

[andrewdavidmackenzie]

I foresee (i.e. they have asked me for it already) people wanting to do inspection of (potentially large) bodies in custom policies they develop (even knowing the performance impact).

So, I would consider a way to make that possible (i.e. access to the body buffered on disk when greater than AM buffer size, from LUA), even if we advise against it for performance reasons.

[mikz]

@andrewdavidmackenzie it is possible now. Just open the file and read it. It is just something that should be part of the authorization flow. Anyone can write custom policy reading the body and doing whatever with it. But if you want to transfer authentication in post body then it should be within some size.

[andrewdavidmackenzie]

David mentioned to me that doing that from LUA with Openresty (when larger than the buffer and hence stored on disk) causes an error.

[mikz]

@andrewdavidmackenzie just because the function returns nil that we don't handle.

there is documentation how to get post body: ngx.req.get_body_data and ngx.req.get_body_data.

We are not going to parse large bodies to look for authentication parameters. It is not a good idea to pass authentication parameters with large bodies. Anyone can read the body and do whatever in their custom module.

[mikz]

https://github.com/3scale/apicast/blob/dcf449888aa8155812e340e5a6589a138311bdf2/apicast/src/configuration.lua#L74-L81 should handle case when ngx.req.get_post_args returns nil and err and print the err to the nginx log (warning, maybe notice or lower level so it does not pollute the log when it happens in normal flow).

[mikz]

Now there is no error now but you'll not be able to get authentication parameters or match mapping rules from big post bodies. It is possible this could be done in the future by some custom policy.

[rnavarro]

Awesome thanks so much guys! We'll kick the tires and see how it goes!