lua location.capture hungs up when upstream response size is a bit big.

mosaafi · 2015-06-12T18:41:27+00:00

Hello! On Fri, Jun 12, 2015 at 6:50 AM, Damian Myerscough wrote: > is it possible to specify two files in init_by_lua_file? I have two files > that ne...

lua location.capture hungs up when upstream response size is a bit big.

mosaafi

Hello.

lua location.capture method hungs up when upstream response size is a bit big. (90kb response causes this case)

I tried to change many configuration and increase buffer sizes, but it doesn't solve the problem.

nginx

content_by_lua_file /hoge.lua;

client_max_body_size 200k;

client_body_buffer_size 200k;

lua_socket_buffer_size 400k;

lua_socket_pool_size 100;

proxy_buffer_size 200k;

proxy_buffers 10 200k;

lua_http10_buffering off;

lua_need_request_body on;

lua

ngx.log(ngx.INFO, 'build request'); # printed.

local res = ngx.location.capture("/fuga", { method = ngx.HTTP_POST body = body });

ngx.log(ngx.INFO, 'finish request'); # not printed. hung up!

upstream size: 90k

How to solve the problem?

Changing configuration can solve? or Should I use socket API for no-buffering reading response?

Do you think 100k is big response?

agentzh

Hello!

On Fri, Jun 12, 2015 at 6:41 PM, Yusuke Enomoto wrote:
> Hello.
> lua location.capture method hungs up when upstream response size is a bit
> big. (90kb response causes this case)
> I tried to change many configuration and increase buffer sizes,  but it
> doesn't  solve the problem.
[...]
> How to solve the problem?

You didn't provide enough information for me to debug for you. Please
see the following document for details you should include:

http://openresty.org/faq.html#how-should-i-report-a-problem

> Changing configuration can solve?

I'm not sure at this point. See above.

> or Should I use socket API for
> no-buffering reading response?

You could though ngx.location.capture should work as long as you do
not disable proxy buffering.

But in general you're encouraged ot use cosockets for big responses
exceeding 1 MB.

> Do you think 100k is big response?
>

Not at all. ngx.location.capture works well with responses of many
many mega bytes in CloudFlare's production environment though we're
going to replace it with cosockets to reduce impact on the Lua/LuaJIT
GC.

Regards,
-agentzh

mosaafi

Hello.

Thank you agentzh.

>You didn't provide enough information for me to debug for you. Please
>see the following document for details you should include:
>http://openresty.org/faq.html#how-should-i-report-a-problem

Here is the minimum example.

location = /fuga {

# return 100kb response

proxy_pass http://127.0.0.1:6001;

}

location = /hoge {

content_by_lua '

local res = ngx.location.capture("/fuga", {});

ngx.say(res.body);

}

nginx version: openresty/1.7.10.1:

The last debug log.

2015/06/14 05:29:34 [debug] 4393#0: *251 event timer del: 22: 1434227394524

2015/06/14 05:29:34 [debug] 4393#0: *251 http upstream request: "/fuga?"

2015/06/14 05:29:34 [debug] 4393#0: *251 http upstream dummy handler

2015/06/14 05:29:34 [debug] 4393#0: *251 http upstream request: "/fuga?"

2015/06/14 05:29:34 [debug] 4393#0: *251 http upstream process upstream

2015/06/14 05:29:34 [debug] 4393#0: *251 pipe read upstream: 1

2015/06/14 05:29:34 [debug] 4393#0: *251 no pipe bufs to read in

2015/06/14 05:29:34 [debug] 4393#0: *251 pipe buf in s:1 t:1 f:0 0000000000BD2930, pos 0000000000BD29CE, size: 3938 file: 0, size: 0

2015/06/14 05:29:34 [debug] 4393#0: *251 pipe buf in s:1 t:1 f:0 0000000000BD3940, pos 0000000000BD3940, size: 4096 file: 0, size: 0

2015/06/14 05:29:34 [debug] 4393#0: *251 pipe buf in s:1 t:1 f:0 0000000000BD4950, pos 0000000000BD4950, size: 4096 file: 0, size: 0

2015/06/14 05:29:34 [debug] 4393#0: *251 pipe buf in s:1 t:1 f:0 0000000000B94720, pos 0000000000B94720, size: 4096 file: 0, size: 0

2015/06/14 05:29:34 [debug] 4393#0: *251 pipe buf in s:1 t:1 f:0 0000000000B95730, pos 0000000000B95730, size: 4096 file: 0, size: 0

2015/06/14 05:29:34 [debug] 4393#0: *251 pipe buf in s:1 t:1 f:0 0000000000B96740, pos 0000000000B96740, size: 4096 file: 0, size: 0

2015/06/14 05:29:34 [debug] 4393#0: *251 pipe buf in s:1 t:1 f:0 0000000000B97750, pos 0000000000B97750, size: 4096 file: 0, size: 0

2015/06/14 05:29:34 [debug] 4393#0: *251 pipe buf in s:1 t:1 f:0 0000000000A6E5A0, pos 0000000000A6E5A0, size: 4096 file: 0, size: 0

2015/06/14 05:29:34 [debug] 4393#0: *251 pipe buf in s:1 t:1 f:0 0000000000A6F5B0, pos 0000000000A6F5B0, size: 4096 file: 0, size: 0

2015/06/14 05:29:34 [debug] 4393#0: *251 pipe length: 63294

2015/06/14 05:29:34 [debug] 4393#0: *251 http upstream request: "/fuga?"

2015/06/14 05:29:34 [debug] 4393#0: *251 http upstream dummy handler

I succeed in solving the problem.

I tried increasing proxy buffers, bad I misunderstood the location which should be change.

I changed buffer size at the location where lua script is running,

location = /hoge {

proxy_buffers 32 48K;

content_by_lua '

local res = ngx.location.capture("/fuga", {});

ngx.say(res.body);

}

but I should have changed it at the endpoint which is requested by location.capture.

location = /fuga {

# return 100kb response

proxy_buffers 32 48K;

proxy_pass http://127.0.0.1:6001;

}

When I changed buffer size of the endpoint, the whole request succeeded.

However, a next question came to mind.

Why the request to "/hoge" using subrequest is hunged up

though the direct request to the endpoint "/fuga" is ok?

I read the source of nginx and lua-nginx-module using gdb, and I think the reason may be the below.

The direct request tries to use buffers firstly, but if buffer size is not enough, nginx read upstream response and write it to downstream with buffers sequentially.

But the subrequst has not the same context to the downstream of the first request, so nginx has no choice but to read upstream's whole response with buffers.

So debug log "no pipe bufs to read in" is printed.

Is the above reason is right?

Regards.

Yusuke Enomoto

2015年6月13日土曜日 12時21分45秒 UTC+9 agentzh:

Hello!

On Fri, Jun 12, 2015 at 6:41 PM, Yusuke Enomoto wrote:
> Hello.
> lua location.capture method hungs up when upstream response size is a bit
> big. (90kb response causes this case)
> I tried to change many configuration and increase buffer sizes, but it
> doesn't solve the problem.
[...]
> How to solve the problem?

You didn't provide enough information for me to debug for you. Please
see the following document for details you should include:

http://openresty.org/faq.html#how-should-i-report-a-problem

> Changing configuration can solve?

I'm not sure at this point. See above.

> or Should I use socket API for
> no-buffering reading response?

You could though ngx.location.capture should work as long as you do
not disable proxy buffering.

But in general you're encouraged ot use cosockets for big responses
exceeding 1 MB.

> Do you think 100k is big response?
>

Not at all. ngx.location.capture works well with responses of many
many mega bytes in CloudFlare's production environment though we're
going to replace it with cosockets to reduce impact on the Lua/LuaJIT
GC.

Regards,
-agentzh

agentzh

Hello!

On Sun, Jun 14, 2015 at 4:41 AM, Yusuke Enomoto wrote:
> Here is the minimum example.
>
>        location = /fuga  {
>             # return 100kb response
>             proxy_pass http://127.0.0.1:6001;
>         }
>         location = /hoge  {
>             content_by_lua '
>                 local res = ngx.location.capture("/fuga", {});
>                 ngx.say(res.body);
>             ';
>         }
>

This example is not standalone. You should provide a way to mock the
127.0.0.1:6001 endpoint via a mocked-up location in the same nginx
server. Otherwise I have to invent this endpoint myself in order to
actually run this example on my side. Also, please ensure you do not
leave out any other nontrivial configurations in the example above
like extra proxy_xxx settings. The goal is that other people (like me)
can reproduce the issue easily on their side.

> nginx version: openresty/1.7.10.1:
>
> The last debug log.
> 2015/06/14 05:29:34 [debug] 4393#0: *251 event timer del: 22: 1434227394524
> 2015/06/14 05:29:34 [debug] 4393#0: *251 http upstream request: "/fuga?"
[...]
> 0000000000A6E5A0, pos 0000000000A6E5A0, size: 4096 file: 0, size: 0
> 2015/06/14 05:29:34 [debug] 4393#0: *251 pipe buf in   s:1 t:1 f:0
> 0000000000A6F5B0, pos 0000000000A6F5B0, size: 4096 file: 0, size: 0
> 2015/06/14 05:29:34 [debug] 4393#0: *251 pipe length: 63294
> 2015/06/14 05:29:34 [debug] 4393#0: *251 http upstream request: "/fuga?"
> 2015/06/14 05:29:34 [debug] 4393#0: *251 http upstream dummy handler
>

Such debug logs are incomplete. You should provide the *complete*
debugging logs for the guilty request as stated in the aforementioned
document. Debugging logs are not so useful if incomplete ;)

> However, a next question came to mind.
> Why the request to "/hoge" using subrequest is hunged up
> though the direct request to the endpoint "/fuga" is ok?
>

Have you configured the following?

    proxy_max_temp_file_size 0;

This also disables buffering like the following

    proxy_buffering off;

Ensure you do not have any of these lines in your nginx.conf.

> The direct request tries to use buffers firstly, but if buffer size is not
> enough,  nginx read upstream response and write it to downstream with
> buffers sequentially.
> But the subrequst has not the same context to the downstream of the first
> request, so nginx has no choice but to read upstream's whole response with
> buffers.

Well, not really.

Basically ngx.location.capture does not work with nginx upstream
modules with buffering off. See the detailed explanation below:

https://github.com/openresty/lua-nginx-module/issues/415

Regards,
-agentzh

mosaafi

Hello.

Sorry for replying too late,

and for no standalone example.

Have you configured the following?
proxy_max_temp_file_size 0;
This also disables buffering like the following
proxy_buffering off;
Ensure you do not have any of these lines in your nginx.conf.

I found out the following configuration

proxy_max_temp_file_size 0;

and proxy_buffers is default value, so my request suspended when upstream response size is bigger than proxy buffers.

Thank you very much for your kindness.

Yusuke

2015年6月14日日曜日 11時47分27秒 UTC+9 agentzh:

Hello!

On Sun, Jun 14, 2015 at 4:41 AM, Yusuke Enomoto wrote:
> Here is the minimum example.
>
> location = /fuga {
> # return 100kb response
> proxy_pass http://127.0.0.1:6001;
> }
> location = /hoge {
> content_by_lua '
> local res = ngx.location.capture("/fuga", {});
> ngx.say(res.body);
> ';
> }
>

This example is not standalone. You should provide a way to mock the
127.0.0.1:6001 endpoint via a mocked-up location in the same nginx
server. Otherwise I have to invent this endpoint myself in order to
actually run this example on my side. Also, please ensure you do not
leave out any other nontrivial configurations in the example above
like extra proxy_xxx settings. The goal is that other people (like me)
can reproduce the issue easily on their side.

> nginx version: openresty/1.7.10.1:
>
> The last debug log.
> 2015/06/14 05:29:34 [debug] 4393#0: *251 event timer del: 22: 1434227394524
> 2015/06/14 05:29:34 [debug] 4393#0: *251 http upstream request: "/fuga?"
[...]
> 0000000000A6E5A0, pos 0000000000A6E5A0, size: 4096 file: 0, size: 0
> 2015/06/14 05:29:34 [debug] 4393#0: *251 pipe buf in s:1 t:1 f:0
> 0000000000A6F5B0, pos 0000000000A6F5B0, size: 4096 file: 0, size: 0
> 2015/06/14 05:29:34 [debug] 4393#0: *251 pipe length: 63294
> 2015/06/14 05:29:34 [debug] 4393#0: *251 http upstream request: "/fuga?"
> 2015/06/14 05:29:34 [debug] 4393#0: *251 http upstream dummy handler
>

Such debug logs are incomplete. You should provide the *complete*
debugging logs for the guilty request as stated in the aforementioned
document. Debugging logs are not so useful if incomplete ;)

> However, a next question came to mind.
> Why the request to "/hoge" using subrequest is hunged up
> though the direct request to the endpoint "/fuga" is ok?
>

Have you configured the following?

proxy_max_temp_file_size 0;

This also disables buffering like the following

proxy_buffering off;

Ensure you do not have any of these lines in your nginx.conf.

> The direct request tries to use buffers firstly, but if buffer size is not
> enough, nginx read upstream response and write it to downstream with
> buffers sequentially.
> But the subrequst has not the same context to the downstream of the first
> request, so nginx has no choice but to read upstream's whole response with
> buffers.

Well, not really.

Basically ngx.location.capture does not work with nginx upstream
modules with buffering off. See the detailed explanation below:

https://github.com/openresty/lua-nginx-module/issues/415

Regards,
-agentzh