Hi all, I'm having trouble with Freeswitch handing a REFER scenario. The following flow is from an actual call where 10.10.10.10 is a Freeswitch machine that should handle the REFER message: 222.22.222.222:5060 10.10.10.10:5060 10.10.10.11:5060 10.10.10.12:5060 ──────────┬───────── ──────────┬───────── ──────────┬───────── ──────────┬───────── │ INVITE (SDP) │ │ │ │ ──────────────────────────> │ │ │ +0.001396 │ 100 Trying │ │ │ │ <────────────────────────── │ │ │ +0.000845 │ 180 Ringing │ │ │ │ <────────────────────────── │ │ │ +0.003244 │ │ INVITE (SDP) │ │ │ │ ──────────────────────────> │ │ +0.005757 │ │ 100 Trying │ │ │ │ <────────────────────────── │ │ +0.115697 │ │ 200 OK (SDP) │ │ │ │ <────────────────────────── │ │ +0.020056 │ 200 OK (SDP) │ │ │ │ <────────────────────────── │ │ │ +0.095132 │ ACK │ │ │ │ ──────────────────────────> │ │ │ +0.000696 │ │ ACK │ │ │ │ ──────────────────────────> │ │ +1.901472 │ │ REFER │ │ │ │ <────────────────────────── │ │ +0.000528 │ │ 202 Accepted │ │ │ │ ──────────────────────────> │ │ +0.000105 │ │ NOTIFY │ │ │ │ ──────────────────────────> │ │ +0.000198 │ INVITE (SDP) │ │ │ │ <────────────────────────── │ │ │ +0.003230 │ │ 200 OK │ │ │ │ <────────────────────────── │ │ +0.000296 │ │ BYE │ │ │ │ ──────────────────────────> │ │ +0.001659 │ 100 Trying │ │ │ │ ──────────────────────────> │ │ │ +0.019175 │ 200 OK (SDP) │ │ │ │ ──────────────────────────> │ │ │ +0.002738 │ ACK │ │ │ │ <────────────────────────── │ │ │ +0.000287 │ INVITE (SDP) │ │ │ │ <────────────────────────── │ │ │ +0.005444 │ 100 Trying │ │ │ │ ──────────────────────────> │ │ │ +0.021372 │ │ INVITE (SDP) │ │ │ ────────────────────────────────────────────────────────> │ +0.007074 │ │ 100 Trying │ │ │ <──────────────────────────────────────────────────────── │ +0.006919 │ │ 200 OK (SDP) │ │ │ <──────────────────────────────────────────────────────── │ +0.036307 │ 200 OK (SDP) │ │ │ │ ──────────────────────────> │ │ │ +0.005278 │ ACK │ │ │ │ <────────────────────────── │ │ │ +0.179349 │ INVITE │ │ │ │ <────────────────────────── │ │ │ +0.003849 │ 100 Trying │ │ │ │ ──────────────────────────> │ │ │ +0.002510 │ 200 OK (SDP) │ │ │ │ ──────────────────────────> │ │ │ +0.007616 │ │ 200 OK │ │ │ │ <────────────────────────── │ │ +0.265244 │ │ 200 OK (SDP) │ │ │ <<<────────────────────────────────────────────────────── │ +0.227210 │ 200 OK (SDP) │ │ │ │ ────────────────────────>>> │ │ │ +0.772969 │ │ 200 OK (SDP) │ │ │ <<<────────────────────────────────────────────────────── │ +0.227103 │ 200 OK (SDP) │ │ │ │ ────────────────────────>>> │ │ │ +1.772828 │ │ 200 OK (SDP) │ │ │ <<<────────────────────────────────────────────────────── │ +0.228480 │ 200 OK (SDP) │ │ │ │ ────────────────────────>>> │ │ │ +3.770628 │ │ 200 OK (SDP) │ │ │ <──────────────────────────────────────────────────────── │ +0.228179 │ 200 OK (SDP) │ │ │ │ ──────────────────────────> │ │ │ +3.772980 │ │ 200 OK (SDP) │ │ │ <<<────────────────────────────────────────────────────── │ +0.227158 │ 200 OK (SDP) │ │ │ │ ────────────────────────>>> │ │ │ +3.773918 │ │ 200 OK (SDP) │ │ │ <<<────────────────────────────────────────────────────── │ +0.225763 │ 200 OK (SDP) │ │ │ │ ────────────────────────>>> │ │ │ +3.775424 │ │ 200 OK (SDP) │ │ │ <<<────────────────────────────────────────────────────── │ +0.224982 │ 200 OK (SDP) │ │ │ │ ────────────────────────>>> │ │ │ +3.776155 │ │ 200 OK (SDP) │ │ │ <<<────────────────────────────────────────────────────── │ +0.223281 │ 200 OK (SDP) │ │ │ │ ────────────────────────>>> │ │ │ +3.776986 │ │ 200 OK (SDP) │ │ │ <<<────────────────────────────────────────────────────── │ +0.223503 │ 200 OK (SDP) │ │ │ │ ────────────────────────>>> │ │ │ +3.777505 │ │ 200 OK (SDP) │ │ │ <<<────────────────────────────────────────────────────── │ +0.223478 │ 200 OK (SDP) │ │ │ │ ────────────────────────>>> │ │ │ +0.271627 │ │ BYE │ │ │ <──────────────────────────────────────────────────────── │ +0.000958 │ │ 200 OK │ │ │ ────────────────────────────────────────────────────────> │ +0.000117 │ │ ACK │ │ │ ────────────────────────────────────────────────────────> │ +0.020239 │ BYE │ │ │ │ <────────────────────────── │ │ │ +0.008562 │ 200 OK │ │ │ │ ──────────────────────────> │ │ │ +0.000251 │ ACK │ │ │ │ <────────────────────────── │ │ │ As you can see the far end sends a BYE because of an ACK timeout. The thing is, I can see in the Freeswitch debug logs that the 200 OK, from both legs, is received by Freeswitch (logs after the last 200 OK from the A leg): tport.c:3052 tport_deliver() tport_deliver(0x7f17c00043d0): msg 0x7f17c0074950 (840 bytes) from udp/222.22.222.222:5060/sip next=(nil) nta.c:3370 agent_recv_response() nta: received 200 OK for INVITE (52572546) nta.c:3437 agent_recv_response() nta: 200 OK is going to a transaction nta.c:9716 outgoing_duplicate() nta: 200 OK is duplicate response to 52572546 INVITE nta.c:9723 outgoing_duplicate() Via: SIP/2.0/UDP 10.10.10.10 ;branch=z9hG4bKprBXUe0Xyc7eH nta.c:7236 _nta_incoming_timer() nta: timer J fired, terminate 202 response nta.c:5896 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7f17e93b3c10) nta.c:7265 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/9 term, 1/9 free nta.c:1308 agent_timer() nta: timer set next to 20 ms nta.c:7236 _nta_incoming_timer() nta: timer J fired, terminate 200 response nta.c:5896 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7f17e93b3c10) nta.c:7265 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/8 term, 1/8 free nta.c:1308 agent_timer() nta: timer set next to 5 ms nta.c:9221 outgoing_timer_dk() nta: timer D fired, terminate INVITE (52572544) nta.c:8893 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7f17e93b3d00) nta.c:9040 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 0/2 tout, 1/4 term, 1/6 free nta.c:1308 agent_timer() nta: timer set next to 2 ms nta.c:9102 outgoing_timer_bf() nta: timer F fired, terminating ACK (52572544) nta.c:8893 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7f17e93b3d00) nta.c:9040 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 1/2 tout, 0/3 term, 1/5 free nta.c:1308 agent_timer() nta: timer set next to 41 ms In the end, after the 200 OK on the BYE transaction, the ACK that should follow the 200 OK for the INVITE transaction is sent. nta.c:6868 incoming_reply() nta: sent 200 OK for BYE (52572561) nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f17c0019a70): removing session usage soa.c:1730 soa_activate() soa_activate(static::0x7f17c000e670, (nil)) called nta.c:2707 nta_tpn_by_url() nta: selecting scheme sip tport.c:3286 tport_tsend() tport_tsend(0x7f17c00043d0) tpn = */10.10.10.12:5060 tport.c:4075 tport_resolve() tport_resolve addrinfo = 10.10.10.12:5060 tport.c:4709 tport_by_addrinfo() tport_by_addrinfo(0x7f17c00043d0): not found by name */10.10.10.12:5060 tport.c:3623 tport_vsend() tport_vsend(0x7f17c00043d0): 498 bytes of 498 to udp/10.10.10.12:5060 tport.c:3521 tport_send_msg() tport_vsend returned 498 2022-06-03 12:38:26.009764 [DEBUG] switch_core_state_machine.c:848 (sofia/Default/2398) Callstate Change ACTIVE -> HANGUP send 498 bytes to udp/[10.10.10.12]:5060 at 12:38:26.027864: ------------------------------------------------------------------------ ACK sip:mailto:2398@10.10.10.50:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 10.10.10.10;rport;branch=z9hG4bKQ14NX9g1UNX1c Route: <sip:10.10.10.12;lr=on;ftag=X8gN4t41XD8Dc;did=56a.da01> Max-Forwards: 70 From: "31761234567" <sip:mailto:31761234567@10.10.10.10>;tag=X8gN4t41XD8Dc To: <sip:mailto:2398@10.10.10.12:5060>;tag=F6g6a1UDjmBXB Call-ID: 57ac2def-8718-4ea9-a70c-74c4acc3ab49 CSeq: 52572545 ACK Contact: <sip:gw+mailto:fs@10.10.10.10:5060;transport=udp;gw=fs> Content-Length: 0 nta.c:8390 outgoing_send() nta: sent ACK (52572545) to */10.10.10.12:5060 nta.c:8816 outgoing_free() nta: outgoing_free(0x7f17c0016ef0) nua_stack.c:301 nua_stack_event() nua(0x7f17c0019a70): event r_invite 481 Call/Transaction Does Not Exist nua_session.c:4140 signal_call_state_change() nua(0x7f17c0019a70): call state changed: completing -> terminated nua_stack.c:301 nua_stack_event() nua(0x7f17c0019a70): event i_state 200 Early Session Terminated nua_stack.c:301 nua_stack_event() nua(0x7f17c0019a70): event i_terminated 200 Early Session Terminated soa.c:356 soa_destroy() soa_destroy(static::0x7f17c000e670) called nta.c:4541 nta_leg_destroy() nta_leg_destroy(0x7f17c0021720) nua_stack.c:599 nua_stack_signal() nua(0x7f17c0019a70): recv signal r_destroy nta.c:4541 nta_leg_destroy() nta_leg_destroy((nil)) 2022-06-03 12:38:26.009764 [DEBUG] switch_core_state_machine.c:850 (sofia/Default/2398) State HANGUP From the logs I can't figure out why the ACK is only sent AFTER the BYE and not immediately after the first 200 OK. Any help would be greatly appreciated. Kind regard, Thomas