[OpenSIPS-Devel] [opensips] opensips allways release TCP connection after tcp_max_msg_time number of seconds (#714)

[Artem Chalkov]

version: opensips 2.1.1 (x86_64/linux)
flags: STATS: On, DISABLE_NAGLE, USE_MCAST, SHM_MMAP, PKG_MALLOC, F_MALLOC, FAST_LOCK-ADAPTIVE_WAIT
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
git revision: 21b2728
main.c compiled on 02:46:31 Nov 24 2015 with gcc 4.4.7


Global parameters:
tcp_listen_backlog=1024
tcp_accept_aliases=yes
tcp_connect_timeout=5000
tcp_max_msg_time=4
tcp_connection_lifetime=3600
tcp_max_connections=65535
tcp_keepalive = 1
tcp_keepcount = 5
tcp_keepidle = 30
tcp_keepinterval = 10


I trying to register via TCP from many instances and all time opensips release connection after tcp_max_msg_time  number of seconds.
There is a log with debug=4:

Dec  3 11:35:31 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcp_read_req: Using the global ( per process ) buff
Dec  3 11:35:31 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcp_handle_req: content-length= 0
Dec  3 11:35:31 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcp_handle_req: Nothing more to read on TCP conn 0x7fc8785160f8, currently in state 0
Dec  3 11:35:31 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcp_conn_get: con found in state 0
Dec  3 11:35:31 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcp_conn_get: tcp connection found (0x7fc8785160f8) already in this process ( 37 ) , fd = 59
Dec  3 11:35:31 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcp_read_req: tcp_read_req end
Dec  3 11:35:31 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcp_read_req: Using the global ( per process ) buff
Dec  3 11:35:31 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcp_handle_req: We didn't manage to read a full request
Dec  3 11:35:31 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcp_read_req: tcp_read_req end
Dec  3 11:35:31 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcp_read_req: Using the per connection buff
Dec  3 11:35:31 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcp_handle_req: content-length= 0
Dec  3 11:35:31 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcp_handle_req: Nothing more to read on TCP conn 0x7fc8785160f8, currently in state 0
Dec  3 11:35:32 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcp_conn_get: con found in state 0
Dec  3 11:35:32 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcp_conn_get: tcp connection found (0x7fc8785160f8) already in this process ( 37 ) , fd = 59
Dec  3 11:35:32 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcp_read_req: tcp_read_req end
Dec  3 11:35:32 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcp_read_req: Using the global ( per process ) buff
Dec  3 11:35:32 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcp_handle_req: We didn't manage to read a full request
Dec  3 11:35:32 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcp_read_req: tcp_read_req end
Dec  3 11:35:35 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcp_receive_timeout: 0x7fc8785160f8 expired - (22, 22) lt=3618
Dec  3 11:35:35 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcpconn_release:  releasing con 0x7fc8785160f8, state -2, fd=-1, id=1
Dec  3 11:35:35 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcpconn_release:  extra_data (nil)
Dec  3 11:36:06 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcp_read_req: Using the global ( per process ) buff
Dec  3 11:36:06 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcp_handle_req: We didn't manage to read a full request
Dec  3 11:36:06 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcp_read_req: tcp_read_req end
Dec  3 11:36:06 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcp_read_req: Using the per connection buff
Dec  3 11:36:06 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcp_read_req: tcp_read_req end
Dec  3 11:36:10 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcp_receive_timeout: 0x7fc87854ddc8 expired - (56, 56) lt=3652
Dec  3 11:36:10 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcpconn_release:  releasing con 0x7fc87854ddc8, state -2, fd=-1, id=2
Dec  3 11:36:10 opensips-dev-2-1 /usr/sbin/opensips[38485]: DBG:core:tcpconn_release:  extra_data (nil)


I tried to send requests via TCP from many instances with diferent IP, and all time opensips receives requests and handle it successfully, but still drop connection after 4 seconds. 

Is that correct behavior or some sort of error?


---
Reply to this email directly or view it on GitHub:
https://github.com/OpenSIPS/opensips/issues/714
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opensips.org/pipermail/devel/attachments/20151202/2637a643/attachment.htm>