Welcome! Log In Create A New Profile

Advanced

Too many workers conenction on udp stream

Posted by Agus 
Agus
Too many workers conenction on udp stream
January 02, 2018 06:50PM
Hi guys,

I have an nginx proxying udp/streams to another proxy which handles the
connection to the backend.

The same proxy proxying the udp streams to another proxy is working ok.
But when it proxies it to the other one, it fills with the worker error. I
turned on debugging and what i see, is that nginx aint releasing the udp
connections...
I could use a hand as I cant get it to work.

in the first proxy i have:

server {
listen *:8330 udp;
proxy_responses 1;
proxy_pass second-proxy:8330;
error_log /var/log/nginx/8330udp.log debug;
}



in the second that is the main which receives from various proxies:

server {
listen *:8330 udp;
proxy_responses 1;
proxy_pass server:8302;
error_log /var/log/nginx/udp8330.log debug;
}


This same config in another "third" proxy for a differnet set of backends
works ok.



The main proxy for the working requests logs is like this, it is ending the
connections:

2018/01/02 17:08:01 [debug] 6158#6158: *13 recv: fd:70 183 of 16384
2018/01/02 17:08:01 [debug] 6158#6158: *13 write new buf t:1 f:0
00000000012A6D00, pos 00000000012A7270, size: 183 file: 0, size: 0
2018/01/02 17:08:01 [debug] 6158#6158: *13 stream write filter: l:1 f:1
s:183
2018/01/02 17:08:01 [debug] 6158#6158: *13 sendmsg: 183 of 183
2018/01/02 17:08:01 [debug] 6158#6158: *13 stream write filter
0000000000000000
2018/01/02 17:08:01 [info] 6158#6158: *13 udp upstream disconnected, bytes
from/to client:122/183, bytes from/to upstream:183/122
2018/01/02 17:08:01 [debug] 6158#6158: *13 finalize stream proxy: 200
2018/01/02 17:08:01 [debug] 6158#6158: *13 free rr peer 1 0
2018/01/02 17:08:01 [debug] 6158#6158: *13 close stream proxy upstream
connection: 70
2018/01/02 17:08:01 [debug] 6158#6158: *13 reusable connection: 0
2018/01/02 17:08:01 [debug] 6158#6158: *13 finalize stream session: 200
2018/01/02 17:08:01 [debug] 6158#6158: *13 stream log handler
2018/01/02 17:08:01 [debug] 6158#6158: *13 close stream connection: 41
2018/01/02 17:08:01 [debug] 6158#6158: *13 event timer del: 41:
1514913481260
2018/01/02 17:08:01 [debug] 6158#6158: *13 reusable connection: 0
2018/01/02 17:08:01 [debug] 6158#6158: *13 free: 00000000012A7270
2018/01/02 17:08:01 [debug] 6158#6158: *13 free: 00000000012A70D0
2018/01/02 17:08:01 [debug] 6158#6158: *13 free: 0000000001199550, unused: 0
2018/01/02 17:08:01 [debug] 6158#6158: *13 free: 00000000012A6C90, unused: 0
2018/01/02 17:08:01 [debug] 6158#6158: *13 free: 00000000012A6DA0, unused: 0
2018/01/02 17:08:01 [debug] 6158#6158: *13 free: 00000000012A6EB0, unused:
24



The same proxy for the other non working one is: NO finalize, nor closing
connection
2018/01/02 17:06:30 [debug] 6101#6101: *291 recvmsg: 52.200.231.253:13129
fd:51 n:313
2018/01/02 17:06:30 [info] 6101#6101: *291 udp client 52.200.231.253:13129
connected to 0.0.0.0:8330
2018/01/02 17:06:30 [debug] 6101#6101: *291 posix_memalign:
00000000025DE410:256 @16
2018/01/02 17:06:30 [debug] 6101#6101: *291 posix_memalign:
00000000025DE520:256 @16
2018/01/02 17:06:30 [debug] 6101#6101: *291 generic phase: 0
2018/01/02 17:06:30 [debug] 6101#6101: *291 generic phase: 1
2018/01/02 17:06:30 [debug] 6101#6101: *291 access: FDE7C834 FFFFFFFF
9405CE34
2018/01/02 17:06:30 [debug] 6101#6101: *291 access: FDE7C834 FFFFFFFF
12282534
2018/01/02 17:06:30 [debug] 6101#6101: *291 access: FDE7C834 0000FFFF
00000D0A
2018/01/02 17:06:30 [debug] 6101#6101: *291 access: FDE7C834 FFFFFFFF
2E952734
2018/01/02 17:06:30 [debug] 6101#6101: *291 access: FDE7C834 FFFFFFFF
368A1934
2018/01/02 17:06:30 [debug] 6101#6101: *291 access: FDE7C834 FFFFFFFF
AEEB2C34
2018/01/02 17:06:30 [debug] 6101#6101: *291 access: FDE7C834 FFFFFFFF
FDE7C834
2018/01/02 17:06:30 [debug] 6101#6101: *291 generic phase: 2
2018/01/02 17:06:30 [debug] 6101#6101: *291 proxy connection handler
2018/01/02 17:06:30 [debug] 6101#6101: *291 malloc: 00000000025DE630:400
2018/01/02 17:06:30 [debug] 6101#6101: *291 get rr peer, try: 1
2018/01/02 17:06:30 [debug] 6101#6101: *291 dgram socket 87
2018/01/02 17:06:30 [debug] 6101#6101: *291 epoll add connection: fd:87
ev:80002005
2018/01/02 17:06:30 [debug] 6101#6101: *291 connect to 52.44.235.174:8330,
fd:87 #292
2018/01/02 17:06:30 [debug] 6101#6101: *291 connected
2018/01/02 17:06:30 [debug] 6101#6101: *291 proxy connect: 0
2018/01/02 17:06:30 [info] 6101#6101: *291 udp proxy 10.13.11.74:48173
connected to 52.44.235.174:8330
2018/01/02 17:06:30 [debug] 6101#6101: *291 malloc: 00000000025DE7D0:16384
2018/01/02 17:06:30 [debug] 6101#6101: *291 stream proxy add preread
buffer: 313
2018/01/02 17:06:30 [debug] 6101#6101: *291 posix_memalign:
00000000025E27E0:256 @16
2018/01/02 17:06:30 [debug] 6101#6101: *291 write new buf t:1 f:0
00000000025DE2C0, pos 00000000025DE2C0, size: 313 file: 0, size: 0
2018/01/02 17:06:30 [debug] 6101#6101: *291 stream write filter: l:1 f:1
s:313
2018/01/02 17:06:30 [debug] 6101#6101: *291 sendmsg: 313 of 313
2018/01/02 17:06:30 [debug] 6101#6101: *291 stream write filter
0000000000000000
2018/01/02 17:06:30 [debug] 6101#6101: *291 event timer add: 51:
600000:1514913390811
2018/01/02 17:06:30 [debug] 6101#6101: *291 event timer: 51, old:
1514913390811, new: 1514913390811
2018/01/02 17:06:30 [debug] 6101#6101: *291 event timer: 51, old:
1514913390811, new: 1514913390811
2018/01/02 17:06:31 [debug] 6101#6101: recvmsg on 0.0.0.0:8330, ready: 0
2018/01/02 17:06:31 [debug] 6101#6101: posix_memalign: 00000000025EF740:256
@16
2018/01/02 17:06:31 [debug] 6101#6101: posix_memalign: 00000000025EF850:256
@16
2018/01/02 17:06:31 [debug] 6101#6101: malloc: 00000000025EF960:313
2018/01/02 17:06:31 [debug] 6101#6101: *297 recvmsg: 52.20.21.23:13129
fd:51 n:313
2018/01/02 17:06:31 [info] 6101#6101: *297 udp client 52.20.21.23:13129
connected to 0.0.0.0:8330


Both same nginx version.

Thanks!
_______________________________________________
nginx mailing list
nginx@nginx.org
http://mailman.nginx.org/mailman/listinfo/nginx
Maxim Dounin
Re: Too many workers conenction on udp stream
January 04, 2018 12:20AM
Hello!

On Tue, Jan 02, 2018 at 02:42:53PM -0300, Agus wrote:

> Hi guys,
>
> I have an nginx proxying udp/streams to another proxy which handles the
> connection to the backend.
>
> The same proxy proxying the udp streams to another proxy is working ok.
> But when it proxies it to the other one, it fills with the worker error. I
> turned on debugging and what i see, is that nginx aint releasing the udp
> connections...
> I could use a hand as I cant get it to work.
>
> in the first proxy i have:
>
> server {
> listen *:8330 udp;
> proxy_responses 1;
> proxy_pass second-proxy:8330;
> error_log /var/log/nginx/8330udp.log debug;
> }
>
>
>
> in the second that is the main which receives from various proxies:
>
> server {
> listen *:8330 udp;
> proxy_responses 1;
> proxy_pass server:8302;
> error_log /var/log/nginx/udp8330.log debug;
> }
>
>
> This same config in another "third" proxy for a differnet set of backends
> works ok.
>
>
>
> The main proxy for the working requests logs is like this, it is ending the
> connections:
>
> 2018/01/02 17:08:01 [debug] 6158#6158: *13 recv: fd:70 183 of 16384
> 2018/01/02 17:08:01 [debug] 6158#6158: *13 write new buf t:1 f:0
> 00000000012A6D00, pos 00000000012A7270, size: 183 file: 0, size: 0
> 2018/01/02 17:08:01 [debug] 6158#6158: *13 stream write filter: l:1 f:1
> s:183
> 2018/01/02 17:08:01 [debug] 6158#6158: *13 sendmsg: 183 of 183
> 2018/01/02 17:08:01 [debug] 6158#6158: *13 stream write filter
> 0000000000000000
> 2018/01/02 17:08:01 [info] 6158#6158: *13 udp upstream disconnected, bytes
> from/to client:122/183, bytes from/to upstream:183/122

Here nginx got an UDP response, and based on "proxy_responses 1"
in your configuration closes the session.

[...]

> The same proxy for the other non working one is: NO finalize, nor closing
> connection
> 2018/01/02 17:06:30 [debug] 6101#6101: *291 recvmsg: 52.200.231.253:13129
> fd:51 n:313
> 2018/01/02 17:06:30 [info] 6101#6101: *291 udp client 52.200.231.253:13129
> connected to 0.0.0.0:8330

[...]

> 2018/01/02 17:06:30 [info] 6101#6101: *291 udp proxy 10.13.11.74:48173
> connected to 52.44.235.174:8330
> 2018/01/02 17:06:30 [debug] 6101#6101: *291 malloc: 00000000025DE7D0:16384
> 2018/01/02 17:06:30 [debug] 6101#6101: *291 stream proxy add preread
> buffer: 313
> 2018/01/02 17:06:30 [debug] 6101#6101: *291 posix_memalign:
> 00000000025E27E0:256 @16
> 2018/01/02 17:06:30 [debug] 6101#6101: *291 write new buf t:1 f:0
> 00000000025DE2C0, pos 00000000025DE2C0, size: 313 file: 0, size: 0
> 2018/01/02 17:06:30 [debug] 6101#6101: *291 stream write filter: l:1 f:1
> s:313
> 2018/01/02 17:06:30 [debug] 6101#6101: *291 sendmsg: 313 of 313
> 2018/01/02 17:06:30 [debug] 6101#6101: *291 stream write filter
> 0000000000000000
> 2018/01/02 17:06:30 [debug] 6101#6101: *291 event timer add: 51:
> 600000:1514913390811
> 2018/01/02 17:06:30 [debug] 6101#6101: *291 event timer: 51, old:
> 1514913390811, new: 1514913390811
> 2018/01/02 17:06:30 [debug] 6101#6101: *291 event timer: 51, old:
> 1514913390811, new: 1514913390811

Here nginx got a new UDP client, sent the packet to the upstream
server and started to wait for a response. Once the response is
received, nginx will close the session much like in the above
case.

How long nginx will wait for a response can be controlled using
the "proxy_timeout" directive"

http://nginx.org/en/docs/stream/ngx_stream_proxy_module.html#proxy_timeout

In your configuration it seems to be set to 600 seconds, which is
10 times longer than the default. If you want nginx to better
tolerate non-responding UDP backends, you may want to configure
shorter timeouts instead. Alternatively, consider configuring
more worker connections.

--
Maxim Dounin
http://mdounin.ru/
_______________________________________________
nginx mailing list
nginx@nginx.org
http://mailman.nginx.org/mailman/listinfo/nginx
Sorry, only registered users may post in this forum.

Click here to login