Freeswitch outbound calls dropping after about 30 seconds due to ACK timeout

Issue Description

Freeswitch not sending SIP ACK when call answer event (200 OK) is received from the remote gateway. The gateway repeatedly sends 200 OK for 30 seconds and then drops the call due to a ACK timeout.
This is resulting in all outbound calls through the gateway dropping after 32-33 seconds even though 2-way media is established.
All incoming calls through the same gateway work fine.
Outbound calls to registered extensions also work fine. The extensions are also registering to the Freeswitch over the internet using the external IP of Freeswitch server.

Setup

Freeswitch 1.10.8-dev running on an AWS EC2 instance with an elastic IP.
Variables external_sip_ip and external_rtp_ip are both set to be deduced via STUN.
Remote gateway reached over the internet. Transport used is TCP. SRTP/ZRTP disabled.
acl.conf.xml whitelists the remote gateway IP under "domains".
Security group/Firewall rules allow full communication with remote gateway (0-65353 on both UDP and TCP) for the time being.

Expected behaviour

Outbound calls through the gateway should work seamlessly just like inbound calls through gateway and extension calls. Outbound calls through gateway should not drop after about 30 seconds.

Freeswitch version

1.10.8-dev

Gateway xml

<include>
  <gateway name="airtel">
    <param name="username" value=""/>
    <param name="password" value=""/>
    <param name="realm" value="remote.gateway.ip.addr:6060"/>
    <param name="proxy" value="remote.gateway.ip.addr:6060;transport=tcp"/>
    <param name="from-user" value="+917654321098"/>
    <param name="from-domain" value="fs.ext.ip.addr"/>
    <param name="register-transport" value="tcp" />
    <param name="register" value="false" />
    <param name="auth-calls" value="false"/>
    <param name="caller-id-in-from" value="true"/>
        <param name="vad" value="both"/>
    <variables>
        <variable name="rtp_secure_media" value="false"/>
    </variables>
  </gateway>
</include>

Trace logs

INVITE sip:+919876543210@remote.gateway.ip.addr:6060;transport=tcp SIP/2.0
Via: SIP/2.0/TCP fs.ext.ip.addr;rport;branch=z9hG4bKXyZrZU4jZUjve
Max-Forwards: 70
From: <sip:0000000000@fs.ext.ip.addr>;tag=SmjU29t0HXt2g
To: <sip:+919876543210@remote.gateway.ip.addr:6060;transport=tcp>
Call-ID: 0bbd8929-ae0f-123b-08b9-02e5070a49dd
CSeq: 56984975 INVITE
Contact: <sip:gw+airtel@fs.ext.ip.addr:5060;transport=tcp;gw=airtel>
User-Agent: FreeSWITCH-mod_sofia/1.10.8-dev+git~20220427T172338Z~7e2d6384bc~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 266
X-HiveName: nithish_kubernetes
X-FS-Support: update_display,send_info
Remote-Party-ID: <sip:0000000000@fs.ext.ip.addr>;party=calling;screen=yes;privacy=off
v=0
o=FreeSWITCH 1663056732 1663056733 IN IP4 fs.ext.ip.addr
s=FreeSWITCH
c=IN IP4 fs.ext.ip.addr
t=0 0
m=audio 20802 RTP/AVP 0 8 9 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20


SIP/2.0 100 Trying
Via: SIP/2.0/TCP fs.ext.ip.addr;rport=57679;branch=z9hG4bKXyZrZU4jZUjve
From: <sip:0000000000@fs.ext.ip.addr>;tag=SmjU29t0HXt2g
To: <sip:+919876543210@remote.gateway.ip.addr:6060;transport=tcp>
Call-ID: 0bbd8929-ae0f-123b-08b9-02e5070a49dd
CSeq: 56984975 INVITE
Content-Length: 0


SIP/2.0 183 Session Progress
Via: SIP/2.0/TCP fs.ext.ip.addr;rport=57679;branch=z9hG4bKXyZrZU4jZUjve
From: <sip:0000000000@fs.ext.ip.addr>;tag=SmjU29t0HXt2g
To: <sip:+919876543210@remote.gateway.ip.addr:6060;transport=tcp>;tag=007d7ff6a00e45fe15ffbb8ea6137e87
Call-ID: 0bbd8929-ae0f-123b-08b9-02e5070a49dd
CSeq: 56984975 INVITE
Contact: <sip:+919876543210@remote.gateway.ip.addr:17828;transport=TCP>
Supported: replaces
Content-Type: application/sdp
Content-Length:   199
v=0
o=host 321988 321989 IN IP4 remote.gateway.ip.addr
s=-
c=IN IP4 remote.gateway.ip.addr
t=0 0
m=audio 41860 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11
a=ptime:20


SIP/2.0 200 OK
Via: SIP/2.0/TCP fs.ext.ip.addr;rport=57679;branch=z9hG4bKXyZrZU4jZUjve
From: <sip:0000000000@fs.ext.ip.addr>;tag=SmjU29t0HXt2g
To: <sip:+919876543210@remote.gateway.ip.addr:6060;transport=tcp>;tag=007d7ff6a00e45fe15ffbb8ea6137e87
Call-ID: 0bbd8929-ae0f-123b-08b9-02e5070a49dd
CSeq: 56984975 INVITE
Contact: <sip:+919876543210@remote.gateway.ip.addr:17828;transport=TCP>
Supported: replaces
Allow: INVITE, ACK, CANCEL, BYE, OPTIONS, INFO, UPDATE, NOTIFY, REFER
Content-Type: application/sdp
Content-Length:   199
v=0
o=host 322940 322941 IN IP4 remote.gateway.ip.addr
s=-
c=IN IP4 remote.gateway.ip.addr
t=0 0
m=audio 41860 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11
a=ptime:20


SIP/2.0 200 OK
Via: SIP/2.0/TCP fs.ext.ip.addr;rport=57679;branch=z9hG4bKXyZrZU4jZUjve
From: <sip:0000000000@fs.ext.ip.addr>;tag=SmjU29t0HXt2g
To: <sip:+919876543210@remote.gateway.ip.addr:6060;transport=tcp>;tag=007d7ff6a00e45fe15ffbb8ea6137e87
Call-ID: 0bbd8929-ae0f-123b-08b9-02e5070a49dd
CSeq: 56984975 INVITE
Contact: <sip:+919876543210@remote.gateway.ip.addr:17828;transport=TCP>
Supported: replaces
Allow: INVITE, ACK, CANCEL, BYE, OPTIONS, INFO, UPDATE, NOTIFY, REFER
Content-Type: application/sdp
Content-Length:   199
v=0
o=host 322940 322941 IN IP4 remote.gateway.ip.addr
s=-
c=IN IP4 remote.gateway.ip.addr
t=0 0
m=audio 41860 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11
a=ptime:20


SIP/2.0 200 OK
Via: SIP/2.0/TCP fs.ext.ip.addr;rport=57679;branch=z9hG4bKXyZrZU4jZUjve
From: <sip:0000000000@fs.ext.ip.addr>;tag=SmjU29t0HXt2g
To: <sip:+919876543210@remote.gateway.ip.addr:6060;transport=tcp>;tag=007d7ff6a00e45fe15ffbb8ea6137e87
Call-ID: 0bbd8929-ae0f-123b-08b9-02e5070a49dd
CSeq: 56984975 INVITE
Contact: <sip:+919876543210@remote.gateway.ip.addr:17828;transport=TCP>
Supported: replaces
Allow: INVITE, ACK, CANCEL, BYE, OPTIONS, INFO, UPDATE, NOTIFY, REFER
Content-Type: application/sdp
Content-Length:   199
v=0
o=host 322940 322941 IN IP4 remote.gateway.ip.addr
s=-
c=IN IP4 remote.gateway.ip.addr
t=0 0
m=audio 41860 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11
a=ptime:20


SIP/2.0 200 OK
Via: SIP/2.0/TCP fs.ext.ip.addr;rport=57679;branch=z9hG4bKXyZrZU4jZUjve
From: <sip:0000000000@fs.ext.ip.addr>;tag=SmjU29t0HXt2g
To: <sip:+919876543210@remote.gateway.ip.addr:6060;transport=tcp>;tag=007d7ff6a00e45fe15ffbb8ea6137e87
Call-ID: 0bbd8929-ae0f-123b-08b9-02e5070a49dd
CSeq: 56984975 INVITE
Contact: <sip:+919876543210@remote.gateway.ip.addr:17828;transport=TCP>
Supported: replaces
Allow: INVITE, ACK, CANCEL, BYE, OPTIONS, INFO, UPDATE, NOTIFY, REFER
Content-Type: application/sdp
Content-Length:   199
v=0
o=host 322940 322941 IN IP4 remote.gateway.ip.addr
s=-
c=IN IP4 remote.gateway.ip.addr
t=0 0
m=audio 41860 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11
a=ptime:20


SIP/2.0 200 OK
Via: SIP/2.0/TCP fs.ext.ip.addr;rport=57679;branch=z9hG4bKXyZrZU4jZUjve
From: <sip:0000000000@fs.ext.ip.addr>;tag=SmjU29t0HXt2g
To: <sip:+919876543210@remote.gateway.ip.addr:6060;transport=tcp>;tag=007d7ff6a00e45fe15ffbb8ea6137e87
Call-ID: 0bbd8929-ae0f-123b-08b9-02e5070a49dd
CSeq: 56984975 INVITE
Contact: <sip:+919876543210@remote.gateway.ip.addr:17828;transport=TCP>
Supported: replaces
Allow: INVITE, ACK, CANCEL, BYE, OPTIONS, INFO, UPDATE, NOTIFY, REFER
Content-Type: application/sdp
Content-Length:   199
v=0
o=host 322940 322941 IN IP4 remote.gateway.ip.addr
s=-
c=IN IP4 remote.gateway.ip.addr
t=0 0
m=audio 41860 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11
a=ptime:20


SIP/2.0 200 OK
Via: SIP/2.0/TCP fs.ext.ip.addr;rport=57679;branch=z9hG4bKXyZrZU4jZUjve
From: <sip:0000000000@fs.ext.ip.addr>;tag=SmjU29t0HXt2g
To: <sip:+919876543210@remote.gateway.ip.addr:6060;transport=tcp>;tag=007d7ff6a00e45fe15ffbb8ea6137e87
Call-ID: 0bbd8929-ae0f-123b-08b9-02e5070a49dd
CSeq: 56984975 INVITE
Contact: <sip:+919876543210@remote.gateway.ip.addr:17828;transport=TCP>
Supported: replaces
Allow: INVITE, ACK, CANCEL, BYE, OPTIONS, INFO, UPDATE, NOTIFY, REFER
Content-Type: application/sdp
Content-Length:   199
v=0
o=host 322940 322941 IN IP4 remote.gateway.ip.addr
s=-
c=IN IP4 remote.gateway.ip.addr
t=0 0
m=audio 41860 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11
a=ptime:20


SIP/2.0 200 OK
Via: SIP/2.0/TCP fs.ext.ip.addr;rport=57679;branch=z9hG4bKXyZrZU4jZUjve
From: <sip:0000000000@fs.ext.ip.addr>;tag=SmjU29t0HXt2g
To: <sip:+919876543210@remote.gateway.ip.addr:6060;transport=tcp>;tag=007d7ff6a00e45fe15ffbb8ea6137e87
Call-ID: 0bbd8929-ae0f-123b-08b9-02e5070a49dd
CSeq: 56984975 INVITE
Contact: <sip:+919876543210@remote.gateway.ip.addr:17828;transport=TCP>
Supported: replaces
Allow: INVITE, ACK, CANCEL, BYE, OPTIONS, INFO, UPDATE, NOTIFY, REFER
Content-Type: application/sdp
Content-Length:   199
v=0
o=host 322940 322941 IN IP4 remote.gateway.ip.addr
s=-
c=IN IP4 remote.gateway.ip.addr
t=0 0
m=audio 41860 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11
a=ptime:20


SIP/2.0 200 OK
Via: SIP/2.0/TCP fs.ext.ip.addr;rport=57679;branch=z9hG4bKXyZrZU4jZUjve
From: <sip:0000000000@fs.ext.ip.addr>;tag=SmjU29t0HXt2g
To: <sip:+919876543210@remote.gateway.ip.addr:6060;transport=tcp>;tag=007d7ff6a00e45fe15ffbb8ea6137e87
Call-ID: 0bbd8929-ae0f-123b-08b9-02e5070a49dd
CSeq: 56984975 INVITE
Contact: <sip:+919876543210@remote.gateway.ip.addr:17828;transport=TCP>
Supported: replaces
Allow: INVITE, ACK, CANCEL, BYE, OPTIONS, INFO, UPDATE, NOTIFY, REFER
Content-Type: application/sdp
Content-Length:   199
v=0
o=host 322940 322941 IN IP4 remote.gateway.ip.addr
s=-
c=IN IP4 remote.gateway.ip.addr
t=0 0
m=audio 41860 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11
a=ptime:20


BYE sip:gw+airtel@fs.ext.ip.addr:5060;transport=tcp;gw=airtel SIP/2.0
Via: SIP/2.0/TCP remote.gateway.ip.addr:17828;branch=z9hG4bKe8b79e46b92fba58ddd0040c8952552b;rport
From: <sip:+919876543210@remote.gateway.ip.addr:6060;transport=tcp>;tag=007d7ff6a00e45fe15ffbb8ea6137e87
To: <sip:0000000000@fs.ext.ip.addr>;tag=SmjU29t0HXt2g
Call-ID: 0bbd8929-ae0f-123b-08b9-02e5070a49dd
CSeq: 56984976 BYE
Supported: replaces
Max-Forwards: 70
Content-Length: 0


SIP/2.0 200 OK
Via: SIP/2.0/TCP remote.gateway.ip.addr:17828;branch=z9hG4bKe8b79e46b92fba58ddd0040c8952552b;rport=6060
From: <sip:+919876543210@remote.gateway.ip.addr:6060;transport=tcp>;tag=007d7ff6a00e45fe15ffbb8ea6137e87
To: <sip:0000000000@fs.ext.ip.addr>;tag=SmjU29t0HXt2g
Call-ID: 0bbd8929-ae0f-123b-08b9-02e5070a49dd
CSeq: 56984976 BYE
User-Agent: FreeSWITCH-mod_sofia/1.10.8-dev+git~20220427T172338Z~7e2d6384bc~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Content-Length: 0

Findings from SIP traces

External IP is correctly deduced through STUN and the same is being sent in the SIP messages.
For call through gateway, while the 200 OK for the INVITE is not being acknowledged by Freeswitch, the BYE sent from the remote gateway is being acknowledged.
For call to registered user on softphone, Freeswitch responds with SIP ACK when 200 OK is received for the invite.

Configurations already tried

Uncommenting the line setting param "aggressive-nat-detection" to "true" in the SIP profile did not make any difference.
Uncommenting the line setting param "enable-timer" to "false" in the SIP profile did not make any difference.

Any help or pointers to resolve this issue will be greatly appreciated.

Solution

Me and my team managed to fix the issue a couple of weeks ago and everything has been working fine since then. Sharing the details below to help others who face similar problems in the future.

I noticed that ACK timeout was not the only issue my Freeswitch installation faced. There was also no SIP BYE being sent when Freeswitch hangs up the call resulting in the remote end retaining the call. The BYE issue was affecting both inbound and outbound calls. This indicated that Freeswitch was failing to start any new SIP transaction like ACK, BYE etc.

Since the SIP trace enabled by sofia global siptrace on was not showing the ACK being sent, I was initially under the impression that this was a Freeswitch bug. However when I noticed that the SIP trace also did not show BYE being sent even though the call was ending in Freeswitch, it made me think in other directions.

That’s when I discovered that we can enable sofia stack debugging to see error messages within the stack. The command to do so is:

sofia loglevel all 9

Diagnosis

log_snippet.txt

fs_cli now showed that Freeswitch attempted to send the ACK but failed to establish a TCP socket connection with a connection refused error. Since the TCP socket itself was not established, the SIP message was never sent. This happened since the source port of the 200 OK message was different from the port mentioned in the Contact header. The port in the Contact header is the port the remote gateway got through NAT. It appears that the remote gateway closes the TCP socket after the INVITE transaction ends once it sends a 200 OK. When Freeswitch attempts the next SIP transaction (ACK, BYE etc) on the IP and port advertised in the Contact header, it gets rejected by the remote firewall.

Solution

Rewrite the Contact header. Refer NDLB-connectile-dysfunction

I added the below variable to the gateway xml.

<variable name="sip-force-contact" value="NDLB-connectile-dysfunction"/>

I also defined the same in the vars.xml so that the same is applied for incoming calls too.

<X-PRE-PROCESS cmd="set" data="sip-force-contact=NDLB-connectile-dysfunction"/>

Doing this will make Freeswitch rewrite the Contact header IP and port to the whatever source port the request comes from. In my case, the Contact header gets rewritten to 6060 and thus the newer SIP transactions work fine.