Hi folk!
Have a rare issue with tls connections.
Have a server with 100+ active tls connections, that are connected to separate TCP proxy, that listen on port 443. TCP proxy send sip traffic to Kamailio via localhost:5061. In this way all connections in Kamailio are considered from Localhost.
Issue scheme: - UA-A (sip-phone, UDP/TCP/TLS) -> call -> sip server (Kamailio+Asterisk based) -> UA-B (sip phone, transport=TLS) - The troubles happened in part of flow to UA-B: --- kamailio script make lookup(location), find AOR for UA-B (here is OK) --- after t_relay, kamailio make branch_route logic and try to send INVITE to tcp socket --- HERE IS the trouble: connection seems to be opened, but Kamailio cannot send INVITE there (say: no open tcp connection found) --- Kamailio try to open tcp connection from itself, TCP proxy refuse it --- as a result - Kamailio answer 477 to Asterisk, and finish processing
debug level 3 logs (from the point where Kamailio try to send INVITE in opened connection) Jan 25 14:32:43 /usr/sbin/kamailio[4722]: DEBUG: <core> [tcp_main.c:1463]: _tcpconn_find(): tcpconn_find: 0 port 60286 Jan 25 14:32:43 /usr/sbin/kamailio[4722]: DEBUG: <core> [ip_addr.c:243]: print_ip(): tcpconn_find: ip 127.0.0.1 Jan 25 14:32:43 /usr/sbin/kamailio[4722]: DEBUG: <core> [tcp_main.c:1820]: tcp_send(): tcp_send: no open tcp connection found, opening new one Jan 25 14:32:43 /usr/sbin/kamailio[4722]: DEBUG: <core> [ip_addr.c:243]: print_ip(): tcpconn_new: new tcp connection: 127.0.0.1 Jan 25 14:32:43 /usr/sbin/kamailio[4722]: DEBUG: <core> [tcp_main.c:1073]: tcpconn_new(): tcpconn_new: on port 60286, type 3 Jan 25 14:32:43 /usr/sbin/kamailio[4722]: DEBUG: <core> [tcp_main.c:1626]: _tcpconn_add_alias_unsafe(): _tcpconn_add_alias_unsafe: alias port 60286 for hash 2646, id 404319 Jan 25 14:32:43 /usr/sbin/kamailio[4722]: DEBUG: <core> [tcp_main.c:1626]: _tcpconn_add_alias_unsafe(): _tcpconn_add_alias_unsafe: alias port 60286 for hash 2728, id 404319 Jan 25 14:32:43 /usr/sbin/kamailio[4722]: DEBUG: <core> [tcp_main.c:1624]: _tcpconn_add_alias_unsafe(): _tcpconn_add_alias_unsafe: alias already present Jan 25 14:32:43 /usr/sbin/kamailio[4722]: DEBUG: <core> [tcp_main.c:1382]: tcpconn_add(): tcpconn_add: hashes: 2646:2728:0, 863 Jan 25 14:32:43 /usr/sbin/kamailio[4722]: DEBUG: tls [tls_server.c:184]: tls_complete_init(): Using TLS domain TLSc<default> Jan 25 14:32:43 /usr/sbin/kamailio[4722]: DEBUG: tls [tls_domain.c:700]: sr_ssl_ctx_info_callback(): SSL handshake started Jan 25 14:32:43 /usr/sbin/kamailio[4722]: ERROR: <core> [tcp_main.c:2742]: tcpconn_1st_send(): connect 127.0.0.1:60286 failed (RST) Connection refused Jan 25 14:32:43 /usr/sbin/kamailio[4722]: ERROR: <core> [tcp_main.c:2752]: tcpconn_1st_send(): 127.0.0.1:60286: connect & send for 0xb1d3b7e8 failed: Connection refused (111) Jan 25 14:32:43 /usr/sbin/kamailio[4722]: DEBUG: <core> [tcp_main.c:2947]: tcpconn_chld_put(): tcpconn_chld_put: destroying connection 0xb1d3b7e8 (404319, -1) flags 0060 Jan 25 14:32:43 /usr/sbin/kamailio[4722]: ERROR: tm [../../forward.h:247]: msg_send(): tcp_send failed Jan 25 14:32:43 /usr/sbin/kamailio[4722]: DEBUG: tm [t_fwd.c:1591]: t_send_branch(): t_send_branch: send to 127.0.0.1:60286 (3) failed Jan 25 14:32:43 /usr/sbin/kamailio[4722]: WARNING: tm [t_fwd.c:1610]: t_send_branch(): ERROR: t_send_branch: sending request on branch 0 failed Jan 25 14:32:43 /usr/sbin/kamailio[4722]: DEBUG: tm [t_funcs.c:358]: t_relay_to(): ERROR:tm:t_relay_to: t_forward_nonack returned error Jan 25 14:32:43 /usr/sbin/kamailio[4722]: DEBUG: tm [t_funcs.c:375]: t_relay_to(): -477 error reply generation delayed Jan 25 14:32:43 /usr/sbin/kamailio[4722]: DEBUG: tm [t_lookup.c:1526]: t_unref(): t_unref: delayed error reply generation(-477) Jan 25 14:32:43 /usr/sbin/kamailio[4722]: DEBUG: <core> [parser/msg_parser.c:339]: parse_headers(): parse_headers: flags=ffffffffffffffff Jan 25 14:32:43 /usr/sbin/kamailio[4722]: DEBUG: tm [t_reply.c:1670]: cleanup_uac_timers(): DEBUG: cleanup_uac_timers: RETR/FR timers reset Jan 25 14:32:43 /usr/sbin/kamailio[4722]: DEBUG: tm [t_reply.c:728]: _reply_light(): DEBUG: reply sent out. buf=0xb67c000c: SIP/2.0 477 Unfortun..., shmem=0xb1b676cc: SIP/2.0 477 Unfortun Jan 25 14:32:43 /usr/sbin/kamailio[4722]: DEBUG: tm [t_funcs.c:156]: put_on_wait(): DEBUG: put on WAIT Jan 25 14:32:43 /usr/sbin/kamailio[4722]: DEBUG: tm [t_reply.c:738]: _reply_light(): DEBUG: _reply_light: finished
Additionally want to say, that suddenly we don't have clear reproduce, it happened only on 2 production servers, what are common conditions for issue: - transport=TLS - when issued call is done, I checked with netstat, the connection is alive - the issued device is re-REGISTERed as usual, in kamctl ul show I see registration before/during/after issued call - issue appear only when connection through our custom TCP proxy :443 (to Kamailio it is from 127.0.0.1:5061) - if connection switched to Kamailio 5061 directly - issue never (till now) reproduced - in one of the issued server - I noticed big number of tcp id. Doing kamcmd core.tcp_list, I saw e.g. id: 567852 (usually id numbers are not more than 1000). - if kamailio/device reboot - problem disappear
Because of not completely understanding how tcp core is working in kamailio, ask any suggestion, why such could happen. Any idea/hints would be greatly appreciated!
kamailio -v version: kamailio 4.2.5 (i386/linux) flags: STATS: Off, EXTRA_DEBUG, USE_TCP, USE_TLS, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, F_MALLOC, DBG_F_MALLOC, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: unknown compiled on 16:03:38 Jan 12 2016 with gcc 4.3.2
sorry for the long description cheers!
-- View this message in context: http://sip-router.1086192.n5.nabble.com/rare-impossibility-to-send-requests-... Sent from the Users mailing list archive at Nabble.com.