[sr-dev] [kamailio/kamailio] Kamailio-Master tcp request relaying problem (EAGAIN) (#1836)

Sun Feb 10 22:54:04 CET 2019

I have same issue over TCP trasport.
Also same config on 5.2 and on 5.1 branch is works
my debug logs
```
14(22) DEBUG: dispatcher [dispatch.c:2043]: ds_manage_routes(): set [1]
14(22) DEBUG: dispatcher [dispatch.c:2147]: ds_manage_routes(): using alg [4] hash [0]
14(22) DEBUG: dispatcher [dispatch.c:2186]: ds_manage_routes(): selected [4-1-0/0] <sip:pbx.rcsnet.ru:7000;transport=tcp>
14(22) DEBUG: dispatcher [dispatch.c:2207]: ds_manage_routes(): using first entry [1/0]
14(22) DEBUG: dispatcher [dispatch.c:2005]: ds_select_dst_limit(): selected target destinations: 1
14(22) exec: *** cfgtrace:request_route=[DISPATCH] c=[/etc/kamailio/kamailio.cfg] l=334 a=25 n=xdbg
14(22) DEBUG: <script>: --- SCRIPT: going to <sip:rcsnet.ru> via <sip:pbx.rcsnet.ru:7000;transport=tcp> (attrs:  )
14(22) exec: *** cfgtrace:request_route=[DISPATCH] c=[/etc/kamailio/kamailio.cfg] l=335 a=25 n=t_on_failure
14(22) exec: *** cfgtrace:request_route=[DISPATCH] c=[/etc/kamailio/kamailio.cfg] l=336 a=5 n=route
14(22) exec: *** cfgtrace:request_route=[RELAY] c=[/etc/kamailio/kamailio.cfg] l=252 a=16 n=if
14(22) exec: *** cfgtrace:request_route=[RELAY] c=[/etc/kamailio/kamailio.cfg] l=249 a=24 n=t_relay
14(22) DEBUG: tm [t_lookup.c:1320]: t_newtran(): msg id=2 , global msg id=2 , T on entrance=0
14(22) DEBUG: tm [t_lookup.c:477]: t_lookup_request(): start searching: hash=58321, isACK=0
14(22) DEBUG: tm [t_lookup.c:436]: matching_3261(): RFC3261 transaction matching failed
14(22) DEBUG: tm [t_lookup.c:660]: t_lookup_request(): no transaction found
14(22) DEBUG: tm [t_hooks.c:348]: run_reqin_callbacks_internal(): trans=0x7fc67c6698a8, callback type 1, id 0 entered
14(22) DEBUG: <core> [core/md5utils.c:67]: MD5StringArray(): MD5 calculated: 304be5a21ec5fd4786116faca8adf918
14(22) DEBUG: <core> [core/dns_cache.c:527]: _dns_hash_find(): (pbx.rcsnet.ru(13), 1), h=1005
14(22) DEBUG: <core> [core/tcp_main.c:1977]: tcp_send(): no open tcp connection found, opening new one
14(22) DEBUG: <core> [core/ip_addr.c:229]: print_ip(): tcpconn_new: new tcp connection: 217.12.247.98
14(22) DEBUG: <core> [core/tcp_main.c:1229]: tcpconn_new(): on port 7000, type 2
14(22) DEBUG: <core> [core/tcp_main.c:1535]: tcpconn_add(): hashes: 2231:0:0, 3
14(22) DEBUG: <core> [core/tcp_main.c:2871]: tcpconn_1st_send(): pending write on new connection 0x7fc67c692180 (-1/811 bytes written) (err: 11 - Resource temporarily unavailable)
14(22) ERROR: <core> [core/tcp_main.c:2890]: tcpconn_1st_send(): 217.12.247.98:7000: EAGAIN and write queue full or failed for 0x7fc67c692180
14(22) DEBUG: <core> [core/tcp_main.c:3152]: tcpconn_chld_put(): destroying connection 0x7fc67c692180 (3, -1) flags 0060
14(22) ERROR: tm [../../core/forward.h:251]: msg_send_buffer(): tcp_send failed
14(22) DEBUG: tm [t_fwd.c:1547]: t_send_branch(): send to 217.12.247.98:7000 (2) failed
14(22) WARNING: tm [t_fwd.c:1567]: t_send_branch(): sending request on branch 0 failed
14(22) DEBUG: tm [t_funcs.c:334]: t_relay_to(): t_forward_nonack returned error -1 (-477)
14(22) DEBUG: tm [t_funcs.c:352]: t_relay_to(): -477 error reply generation delayed 
14(22) exec: *** cfgtrace:request_route=[RELAY] c=[/etc/kamailio/kamailio.cfg] l=250 a=24 n=sl_reply_error
14(22) DEBUG: websocket [ws_conn.c:452]: wsconn_get(): wsconn_get for id [2]
14(22) DEBUG: websocket [ws_conn.c:458]: wsconn_get(): wsconn_get returns wsc [0x7fc67c682058] refcnt [2]
14(22) DEBUG: websocket [ws_frame.c:738]: ws_frame_transmit(): Tx message:
SIP/2.0 477 Unfortunately error on sending to next hop occurred (477/SL)
Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bK1T8IU9SPqhTVtPkfa8ZcmNATMyZhZoXS;rport=51976;received=192.168.100.31
From: "Sergey Safarov"<sip:2496 at rcsnet.ru>;tag=4zUV2R25QizRCe3FWVXG
To: "Sergey Safarov"<sip:2496 at rcsnet.ru>;tag=52bcac7a84e52c398793b50c505689c5.7db8
Call-ID: 94ce71ed-0e53-d627-7cc2-39133bd30985
CSeq: 51999 REGISTER
Server: kamailio (5.3.0-dev2 (x86_64/linux))
Content-Length: 0

14(22) DEBUG: websocket [ws_frame.c:144]: encode_and_send_ws_frame(): encoding WebSocket frame
14(22) DEBUG: websocket [ws_frame.c:170]: encode_and_send_ws_frame(): supported non-control frame: 0x1
14(22) DEBUG: <core> [core/tcp_main.c:2455]: tcpconn_send_put(): send from reader (22 (14)), reusing fd
14(22) DEBUG: <core> [core/tcp_main.c:2690]: tcpconn_do_send(): sending...
14(22) DEBUG: <core> [core/tcp_main.c:2724]: tcpconn_do_send(): after real write: c= 0x7fc67c663c88 n=517 fd=7
14(22) DEBUG: <core> [core/tcp_main.c:2725]: tcpconn_do_send(): buf=

14(22) DEBUG: websocket [ws_conn.c:416]: wsconn_put_mode(): wsconn_put start for [0x7fc67c682058] refcnt [2]
14(22) DEBUG: websocket [ws_conn.c:430]: wsconn_put_mode(): wsconn_put end for [0x7fc67c682058] refcnt [1]
14(22) ERROR: sl [sl_funcs.c:372]: sl_reply_error(): stateless error reply used: Unfortunately error on sending to next hop occurred (477/SL)
14(22) exec: *** cfgtrace:request_route=[RELAY] c=[/etc/kamailio/kamailio.cfg] l=252 a=2 n=exit
14(22) DEBUG: <core> [core/receive.c:353]: receive_msg(): request-route executed in: 957 usec
14(22) DEBUG: tm [t_lookup.c:1484]: t_unref(): delayed error reply generation(-477)
14(22) DEBUG: tm [t_reply.c:1650]: cleanup_uac_timers(): RETR/FR timers reset
14(22) DEBUG: websocket [ws_conn.c:452]: wsconn_get(): wsconn_get for id [2]
14(22) DEBUG: websocket [ws_conn.c:458]: wsconn_get(): wsconn_get returns wsc [0x7fc67c682058] refcnt [2]
14(22) DEBUG: websocket [ws_frame.c:738]: ws_frame_transmit(): Tx message:
SIP/2.0 477 Unfortunately error on sending to next hop occurred (477/TM)
Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bK1T8IU9SPqhTVtPkfa8ZcmNATMyZhZoXS;rport=51976;received=192.168.100.31
From: "Sergey Safarov"<sip:2496 at rcsnet.ru>;tag=4zUV2R25QizRCe3FWVXG
To: "Sergey Safarov"<sip:2496 at rcsnet.ru>;tag=1bb77df00a25769725961c2385ab007f-7db8
Call-ID: 94ce71ed-0e53-d627-7cc2-39133bd30985
CSeq: 51999 REGISTER
Server: kamailio (5.3.0-dev2 (x86_64/linux))
Content-Length: 0

14(22) DEBUG: websocket [ws_frame.c:144]: encode_and_send_ws_frame(): encoding WebSocket frame
14(22) DEBUG: websocket [ws_frame.c:170]: encode_and_send_ws_frame(): supported non-control frame: 0x1
14(22) DEBUG: <core> [core/tcp_main.c:2455]: tcpconn_send_put(): send from reader (22 (14)), reusing fd
14(22) DEBUG: <core> [core/tcp_main.c:2690]: tcpconn_do_send(): sending...
14(22) DEBUG: <core> [core/tcp_main.c:2724]: tcpconn_do_send(): after real write: c= 0x7fc67c663c88 n=517 fd=7
14(22) DEBUG: <core> [core/tcp_main.c:2725]: tcpconn_do_send(): buf=

14(22) DEBUG: websocket [ws_conn.c:416]: wsconn_put_mode(): wsconn_put start for [0x7fc67c682058] refcnt [2]
14(22) DEBUG: websocket [ws_conn.c:430]: wsconn_put_mode(): wsconn_put end for [0x7fc67c682058] refcnt [1]
14(22) DEBUG: tm [t_reply.c:596]: _reply_light(): reply sent out. buf=0x7fc6806cb328: SIP/2.0 477 Unfortun..., shmem=0x7fc67c680348: SIP/2.0 477 Unfortun
14(22) DEBUG: tm [t_reply.c:607]: _reply_light(): finished
14(22) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list 0
14(22) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list 0
14(22) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list 0
14(22) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list 0
14(22) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list 0
14(22) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list 0
14(22) DEBUG: <core> [core/xavp.c:497]: xavp_destroy_list(): destroying xavp list 0
14(22) DEBUG: <core> [core/receive.c:457]: receive_msg(): cleaning up
```

-- 
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/1836#issuecomment-462178067
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-dev/attachments/20190210/b8ec462f/attachment-0001.html>