reinvite ignored when right after bridge completes
Hi, I am getting a re-invite message right after a bridge is setup in my FS. when re-invite arrives before bridge event, it seems FS ignores it. does anyone hit this issue before ? how did you fix it? FS 1.4.20 more details about call flow: 1) leg1 invite 2) bridge leg2 invite is sent 3) leg2 200 OK 4) leg2 ACK 5) leg1 200 OK (it seems that this is triggered by bridge cmd completion) 6) leg1 ACK So far, it is good. then 7) leg1 re-invite. sometime FS drops this msg. After (6), I can see in the logs that FS sends 2 events ANSWERED_EVENT (leg1) and CHANNELS_BRIDGED_EVENT (leg1) I observed that if (7) happens before FS sends the CHANNELS_BRIDGED_EVENT, then re-invite is dropped. I also observed that the following log entries are not printed when failure occurs ========= nua.c:633 nua_invite() nua: nua_invite: entering nua_stack.c:529 nua_signal() nua(0x7f73140019d0): sent signal r_invite 2017-01-30 21:14:10.906746 [DEBUG] switch_core_session.c:912 Send signal sofia/sip-ua/5555000@XXXXXX.net:5085 [BREAK] nua_stack.c:569 nua_stack_signal() nua(0x7f73140019d0): recv signal r_invite nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f72f34307f0, ...) called soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7f72f34307f0, (nil), 0x7f7314005167, -1) called soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f72f34307f0) called soa.c:1426 soa_generate_offer() soa_generate_offer(static::0x7f72f34307f0, 0) called soa_static.c:1146 offer_answer_step() soa_static_offer_answer_action(0x7f72f34307f0, soa_generate_offer): called soa_static.c:1215 offer_answer_step() soa_static(0x7f72f34307f0, soa_generate_offer): upgrade with local description soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f7399457940, (nil), ""): called soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f72f34307f0, [(nil)], [0x7f7399457aa0], [0x7f7399457aac]) called nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip tport.c:4588 tport_by_name() tport(0x7f73740067b0): found 0x7f72f028e130 by name tls/10.191.209.144:5085 tport.c:3257 tport_tsend() tport_tsend(0x7f72f028e130) tpn = tls/ 10.191.209.144:5085 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f72f028ed30 0x7f72f34579b0 958 (958) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f72f028ed30 0x7f72f345c880 315 (315) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f72f028ed30 0x7f72f344cfa0 132 (132) tport.c:3594 tport_vsend() tport_vsend(0x7f72f028e130): 1405 bytes of 1405 to tls/10.191.209.144:5085 tport.c:3492 tport_send_msg() tport_vsend returned 1405 ========= I see this instead ========= nua.c:633 nua_invite() nua: nua_invite: entering nua_stack.c:529 nua_signal() nua(0x7f7314011980): sent signal r_invite 2017-01-30 21:14:43.406714 [DEBUG] switch_core_session.c:912 Send signal sofia/sip-ua/5555000@XXXXXXXXXX.net:5085 [BREAK] nua_stack.c:569 nua_stack_signal() nua(0x7f7314011980): recv signal r_invite tport.c:2773 tport_wakeup() tport_wakeup(0x7f72f028e130): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f72f028e130) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f72f028e130): tls_read() returned 93 tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f72f028e130) msg 0x7f72f3457f50 from (tls/10.191.209.144:5085) has 93 bytes, veclen = 1 tport.c:2296 tport_set_secondary_timer() tport(0x7f72f028e130): reset timer tport.c:2773 tport_wakeup() tport_wakeup(0x7f72f028e130): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f72f028e130) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f72f028e130): tls_read() returned 729 tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f72f028e130) msg 0x7f72f3457f50 from (tls/10.191.209.144:5085) has 729 bytes, veclen = 1 tport.c:2296 tport_set_secondary_timer() tport(0x7f72f028e130): reset timer tport.c:2773 tport_wakeup() tport_wakeup(0x7f72f028e130): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f72f028e130) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f72f028e130): tls_read() returned 175 tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f72f028e130) msg 0x7f72f3457f50 from (tls/10.191.209.144:5085) has 175 bytes, veclen = 1 ========= Thanks in advance Rafael
1.4 is EOL so if 1.4.26 (the final release) does not help you, then you will have to move to 1.6 or master as no further patches will be made on 1.4 On Mon, Jan 30, 2017 at 4:02 PM, Rafael Kaihatu <rafael.kaihatu@8x8.com> wrote:
Hi,
I am getting a re-invite message right after a bridge is setup in my FS. when re-invite arrives before bridge event, it seems FS ignores it.
does anyone hit this issue before ? how did you fix it?
FS 1.4.20
more details about call flow:
1) leg1 invite 2) bridge leg2 invite is sent 3) leg2 200 OK 4) leg2 ACK 5) leg1 200 OK (it seems that this is triggered by bridge cmd completion) 6) leg1 ACK
So far, it is good. then
7) leg1 re-invite. sometime FS drops this msg.
After (6), I can see in the logs that FS sends 2 events ANSWERED_EVENT (leg1) and CHANNELS_BRIDGED_EVENT (leg1)
I observed that if (7) happens before FS sends the CHANNELS_BRIDGED_EVENT, then re-invite is dropped.
I also observed that the following log entries are not printed when failure occurs ========= nua.c:633 nua_invite() nua: nua_invite: entering nua_stack.c:529 nua_signal() nua(0x7f73140019d0): sent signal r_invite 2017-01-30 21:14:10.906746 [DEBUG] switch_core_session.c:912 Send signal sofia/sip-ua/5555000@XXXXXX.net:5085 [BREAK] nua_stack.c:569 nua_stack_signal() nua(0x7f73140019d0): recv signal r_invite nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f72f34307f0, ...) called soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7f72f34307f0, (nil), 0x7f7314005167, -1) called soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f72f34307f0) called soa.c:1426 soa_generate_offer() soa_generate_offer(static::0x7f72f34307f0, 0) called soa_static.c:1146 offer_answer_step() soa_static_offer_answer_action(0x7f72f34307f0, soa_generate_offer): called soa_static.c:1215 offer_answer_step() soa_static(0x7f72f34307f0, soa_generate_offer): upgrade with local description soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f7399457940, (nil), ""): called soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f72f34307f0, [(nil)], [0x7f7399457aa0], [0x7f7399457aac]) called nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip tport.c:4588 tport_by_name() tport(0x7f73740067b0): found 0x7f72f028e130 by name tls/10.191.209.144:5085 tport.c:3257 tport_tsend() tport_tsend(0x7f72f028e130) tpn = tls/ 10.191.209.144:5085 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f72f028ed30 0x7f72f34579b0 958 (958) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f72f028ed30 0x7f72f345c880 315 (315) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f72f028ed30 0x7f72f344cfa0 132 (132) tport.c:3594 tport_vsend() tport_vsend(0x7f72f028e130): 1405 bytes of 1405 to tls/10.191.209.144:5085 tport.c:3492 tport_send_msg() tport_vsend returned 1405 =========
I see this instead ========= nua.c:633 nua_invite() nua: nua_invite: entering nua_stack.c:529 nua_signal() nua(0x7f7314011980): sent signal r_invite 2017-01-30 21:14:43.406714 [DEBUG] switch_core_session.c:912 Send signal sofia/sip-ua/5555000@XXXXXXXXXX.net:5085 [BREAK] nua_stack.c:569 nua_stack_signal() nua(0x7f7314011980): recv signal r_invite tport.c:2773 tport_wakeup() tport_wakeup(0x7f72f028e130): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f72f028e130) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f72f028e130): tls_read() returned 93 tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f72f028e130) msg 0x7f72f3457f50 from (tls/10.191.209.144:5085) has 93 bytes, veclen = 1 tport.c:2296 tport_set_secondary_timer() tport(0x7f72f028e130): reset timer tport.c:2773 tport_wakeup() tport_wakeup(0x7f72f028e130): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f72f028e130) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f72f028e130): tls_read() returned 729 tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f72f028e130) msg 0x7f72f3457f50 from (tls/10.191.209.144:5085) has 729 bytes, veclen = 1 tport.c:2296 tport_set_secondary_timer() tport(0x7f72f028e130): reset timer tport.c:2773 tport_wakeup() tport_wakeup(0x7f72f028e130): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f72f028e130) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f72f028e130): tls_read() returned 175 tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f72f028e130) msg 0x7f72f3457f50 from (tls/10.191.209.144:5085) has 175 bytes, veclen = 1 =========
Thanks in advance Rafael
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
-- Anthony Minessale II ♬ @anthmfs ♬ @FreeSWITCH ♬ ☞ http://freeswitch.org/ ☞ http://cluecon.com/ ☞ http://twitter.com/FreeSWITCH ☞ irc.freenode.net #freeswitch ☞ *http://freeswitch.org/g+ <http://freeswitch.org/g+>* ClueCon Weekly Development Call ☎ sip:888@conference.freeswitch.org ☎ +19193869900 https://www.youtube.com/watch?v=9XXgW34t40s https://www.youtube.com/watch?v=NLaDpGQuZDA
participants (2)
-
Anthony Minessale
-
Rafael Kaihatu