I’ve searched the forums and internet around this issue and still can’t resolve things. I’ve spent 4 full days on this maybe someone can point me in the right direction. I’m sure it’s some config problem. Basically all outbound is working perfectly fine but inbound is dropped after 7 seconds with the error:
[Nov 27 04:44:51] DEBUG[994] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 69.90.209.57:5060
[Nov 27 04:44:51] WARNING[994] chan_sip.c: Retransmission timeout reached on transmission KCJO3TWFLZE4NCACTOIELKUUJQ@81.201.84.195 for seqno 102 (Critical Response) -- See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 6400ms with no response
[Nov 27 04:44:51] WARNING[994] chan_sip.c: Hanging up call KCJO3TWFLZE4NCACTOIELKUUJQ@81.201.84.195 - no reply to our critical packet (see https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions).
I basically have the following deployment:
Asterisk (Public IP 4.xxx.xxx.186) — PfSense (Public IP 4.xxx.xxx.116) — Internet — VoIP Provider
My Asterisk server is configured with a public IP address behind a PfSense firewall in a route fashion (no NAT). I’ve already opened inbound ports of 4569, 5060, and 10000-20000 to Asterisk. I’ve also opened outbound ports.
Here is my sip.conf:
[general]
context=default
allowoverlap=no
udpbindaddr=0.0.0.0
bindport=5060
bindaddr=0.0.0.0
tcpenable=yes
tcpbindaddr=0.0.0.0
srvlookup=yes
notifyhold=yes
nat=no
directmedia=no
Looks like Asterisk is returning the 200 to the provider but not getting a response and keeps trying until it times out. Debug logs show the following:
[code][Nov 27 04:44:48] VERBOSE[994] chan_sip.c:
<— Transmitting (no NAT) to 69.90.209.57:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 69.90.209.57:5060;branch=0;received=69.90.209.57
From: sip:natping@voipvoip.com;tag=73a4a5c6
To: sip:4.xxx.xxx.186:45817;tag=as350754ea
Call-ID: 45922f97-d17e6d05-21d86@69.90.209.57
CSeq: 1 OPTIONS
Server: Asterisk PBX 1.8.12.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:4.xxx.xxx.116:5060
Accept: application/sdp
Content-Length: 0
<------------>
[Nov 27 04:44:48] DEBUG[994] chan_sip.c: Trying to put ‘SIP/2.0 200’ onto UDP socket destined for 69.90.209.57:5060
[Nov 27 04:44:48] VERBOSE[994] chan_sip.c: Scheduling destruction of SIP dialog ‘45922f97-d17e6d05-21d86@69.90.209.57’ in 32000 ms (Method: OPTIONS)
[Nov 27 04:44:49] VERBOSE[994] chan_sip.c:
<— SIP read from UDP:69.90.209.57:5060 —>
OPTIONS sip:4.xxx.xxx.186:45817 SIP/2.0
Via: SIP/2.0/UDP 69.90.209.57:5060;branch=0
From: sip:natping@voipvoip.com;tag=94a4a5c6
To: sip:4.xxx.xxx.186:45817
Call-ID: 45922f97-f27e6d05-31d86@69.90.209.57
CSeq: 1 OPTIONS
Content-Length: 0
<------------->
[Nov 27 04:44:49] DEBUG[994] chan_sip.c: Header 0 [ 38]: OPTIONS sip:4.xxx.xxx.186:45817 SIP/2.0
[Nov 27 04:44:49] DEBUG[994] chan_sip.c: Header 1 [ 43]: Via: SIP/2.0/UDP 69.90.209.57:5060;branch=0
[Nov 27 04:44:49] DEBUG[994] chan_sip.c: Header 2 [ 43]: From: sip:natping@voipvoip.com;tag=94a4a5c6
[Nov 27 04:44:49] DEBUG[994] chan_sip.c: Header 3 [ 26]: To: sip:4.xxx.xxx.186:45817
[Nov 27 04:44:49] DEBUG[994] chan_sip.c: Header 4 [ 45]: Call-ID: 45922f97-f27e6d05-31d86@69.90.209.57
[Nov 27 04:44:49] DEBUG[994] chan_sip.c: Header 5 [ 15]: CSeq: 1 OPTIONS
[Nov 27 04:44:49] DEBUG[994] chan_sip.c: Header 6 [ 17]: Content-Length: 0
[Nov 27 04:44:49] VERBOSE[994] chan_sip.c: — (7 headers 0 lines) —
[Nov 27 04:44:49] DEBUG[994] chan_sip.c: = Looking for Call ID: 45922f97-f27e6d05-31d86@69.90.209.57 (Checking From) --From tag 94a4a5c6 --To-tag
[Nov 27 04:44:49] DEBUG[994] acl.c: For destination ‘69.90.209.57’, our source address is ‘4.xxx.xxx.116’.
[Nov 27 04:44:49] DEBUG[994] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 4.xxx.xxx.116:5060
[Nov 27 04:44:49] DEBUG[994] chan_sip.c: Allocating new SIP dialog for 45922f97-f27e6d05-31d86@69.90.209.57 - OPTIONS (No RTP)
[Nov 27 04:44:49] DEBUG[994] chan_sip.c: **** Received OPTIONS (3) - Command in SIP OPTIONS
[Nov 27 04:44:49] DEBUG[994] netsock2.c: Splitting ‘4.xxx.xxx.186:45817’ into…
[Nov 27 04:44:49] DEBUG[994] netsock2.c: …host ‘4.xxx.xxx.186’ and port ‘’.
[Nov 27 04:44:49] DEBUG[994] netsock2.c: Splitting ‘voipvoip.com’ into…
[Nov 27 04:44:49] DEBUG[994] netsock2.c: …host ‘voipvoip.com’ and port ‘’.
[Nov 27 04:44:49] VERBOSE[994] chan_sip.c: Looking for s in default (domain 4.xxx.xxx.186)
[Nov 27 04:44:49] VERBOSE[994] chan_sip.c:
<— Transmitting (no NAT) to 69.90.209.57:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 69.90.209.57:5060;branch=0;received=69.90.209.57
From: sip:natping@voipvoip.com;tag=94a4a5c6
To: sip:4.xxx.xxx.186:45817;tag=as47787bd1
Call-ID: 45922f97-f27e6d05-31d86@69.90.209.57
CSeq: 1 OPTIONS
Server: Asterisk PBX 1.8.12.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:4.xxx.xxx.116:5060
Accept: application/sdp
Content-Length: 0
<------------>
[Nov 27 04:44:49] DEBUG[994] chan_sip.c: Trying to put ‘SIP/2.0 200’ onto UDP socket destined for 69.90.209.57:5060
[Nov 27 04:44:49] VERBOSE[994] chan_sip.c: Scheduling destruction of SIP dialog ‘45922f97-f27e6d05-31d86@69.90.209.57’ in 32000 ms (Method: OPTIONS)
[Nov 27 04:44:50] DEBUG[994] chan_sip.c: Auto destroying SIP dialog ‘45922f97-014e6d05-4fc86@69.90.209.57’
[Nov 27 04:44:50] DEBUG[994] chan_sip.c: Destroying SIP dialog 45922f97-014e6d05-4fc86@69.90.209.57
[Nov 27 04:44:50] VERBOSE[994] chan_sip.c: Really destroying SIP dialog ‘45922f97-014e6d05-4fc86@69.90.209.57’ Method: OPTIONS
[Nov 27 04:44:51] DEBUG[994] chan_sip.c: Auto destroying SIP dialog ‘45922f97-224e6d05-5fc86@69.90.209.57’
[Nov 27 04:44:51] DEBUG[994] chan_sip.c: Destroying SIP dialog 45922f97-224e6d05-5fc86@69.90.209.57
[Nov 27 04:44:51] VERBOSE[994] chan_sip.c: Really destroying SIP dialog ‘45922f97-224e6d05-5fc86@69.90.209.57’ Method: OPTIONS
[Nov 27 04:44:51] DEBUG[1345] channel.c: Scheduling timer at (100 requested / 100 actual) timer ticks per second
[Nov 27 04:44:51] DEBUG[1345] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Nov 27 04:44:51] DEBUG[1345] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Nov 27 04:44:51] DEBUG[1345] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Nov 27 04:44:51] DEBUG[1345] pbx.c: Launching ‘Playback’
[Nov 27 04:44:51] VERBOSE[1345] pbx.c: – Executing [s@attendant_menu_no_ext:4] Playback(“SIP/to_VoIP_VoIP_BTT-00000004”, “BTT/MWWW-welcome-servicing-customers”) in new stack
[Nov 27 04:44:51] DEBUG[1345] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[Nov 27 04:44:51] VERBOSE[1345] file.c: – <SIP/to_VoIP_VoIP_BTT-00000004> Playing ‘BTT/MWWW-welcome-servicing-customers.ulaw’ (language ‘en’)
[Nov 27 04:44:51] DEBUG[990] res_timing_timerfd.c: Expected to acknowledge 1 ticks but got 2 instead
[Nov 27 04:44:51] DEBUG[994] chan_sip.c: SIP TIMER: Rescheduling retransmission #547 (6) SIP/2.0 - 1
[Nov 27 04:44:51] DEBUG[994] chan_sip.c: ** SIP timers: Rescheduling retransmission 7 to 4000 ms (t1 100 ms (Retrans id #547))
[Nov 27 04:44:51] VERBOSE[994] chan_sip.c: Retransmitting #6 (no NAT) to 69.90.209.57:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 69.90.209.57;branch=z9hG4bK2f4b.8c5c71d5.0;received=69.90.209.57
Via: SIP/2.0/UDP 81.201.84.195:5060;rport=5060;branch=z9hG4bKa3ca0c49654a8997d033842bffe0e9e0
Record-Route: sip:69.90.209.57;lr;ftag=35134;nat=yes;did=3e2.50e9c366
From: “14251111111” sip:14251111111@voxbone.com;tag=35134
To: sip:12069999999@sipdid.voipvoip.com;tag=as60ca33a1
Call-ID: KCJO3TWFLZE4NCACTOIELKUUJQ@81.201.84.195
CSeq: 102 INVITE
Server: Asterisk PBX 1.8.12.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:5551005403@4.xxx.xxx.116:5060
Content-Type: application/sdp
Content-Length: 237
v=0
o=root 2109672711 2109672711 IN IP4 4.xxx.xxx.116
s=Asterisk PBX 1.8.12.0
c=IN IP4 4.xxx.xxx.116
t=0 0
m=audio 16212 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv[/code]
When I look at the firewall, I am showing it looks like the provider is resonding to 4.xxx.xxx.186 (PfSense) rather than 4.xxx.xxx.116 (Asterisk) and these packets are getting blocked and dropped.
Any idea why it’s not routing back to the Asterisk box since I do not have NAT configured at all?