SIP/2.0 603 Declined, call drops

Hi all,

We just got a new service provider to handle our outgoing calls over a SIP trunk and I am running into some problems. Whenever a call is placed it passes through the trunk but then returns a busy signal and drops. The service provider says that I am experiencing some NAT issues as my Elastix box is behind a firewall. I have been doing a fair bit of reading and testing and from what I can see the error comes from their side. Can someone please look at this call log and let me know if my suspicions are correct and that the call is dropped on their side.

Jun 3 11:09:14] VERBOSE[2663] chan_sip.c:
<— SIP read from UDP:(IP of service provider):5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP My IP:5060;branch=z9hG4bK665ef319;received=My IP;rport=5060
From: “Unknown” <sip:My [email protected] IP>;tag=as639a2202
To: <sip:(IP of service provider)>;tag=as79cc8247
Call-ID: [email protected] IP:5060
CSeq: 102 OPTIONS
Server: voicewire.com
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:(IP of service provider):5060>
Accept: application/sdp
Content-Length: 0

<— SIP read from UDP:(IP of service provider):5060 —>
OPTIONS sip:[email protected] IP:5060 SIP/2.0
Via: SIP/2.0/UDP (IP of service provider):5060;branch=z9hG4bK620ec958
Max-Forwards: 70
From: “asterisk” <sip:[email protected](IP of service provider)>;tag=as5feae3c1
To: <sip:[email protected] IP:5060>
Contact: <sip:[email protected](IP of service provider):5060>
Call-ID: [email protected](IP of service provider):5060
CSeq: 102 OPTIONS
User-Agent: voicewire.com
Date: Wed, 03 Jun 2015 10:07:17 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0

<------------->
[Jun 3 11:09:25] VERBOSE[2663] chan_sip.c: — (13 headers 0 lines) —
[Jun 3 11:09:25] VERBOSE[2663] chan_sip.c: Looking for s in from-sip-external (domain My IP)
[Jun 3 11:09:25] VERBOSE[2663] chan_sip.c:
<— Transmitting (NAT) to (IP of service provider):5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP (IP of service provider):5060;branch=z9hG4bK620ec958;received=(IP of service provider);rport=5060
From: “asterisk” <sip:[email protected](IP of service provider)>;tag=as5feae3c1
To: <sip:[email protected] IP:5060>;tag=as63d9a969
Call-ID: [email protected](IP of service provider):5060
CSeq: 102 OPTIONS
Server: FPBX-2.8.1(1.8.12.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: <sip:My IP:5060>
Accept: application/sdp
Content-Length: 0

<------------>
[Jun 3 11:09:25] VERBOSE[2663] chan_sip.c: Scheduling destruction of SIP dialog ‘[email protected](IP of service provider):5060’ in 32000 ms (Method: OPTIONS)
[Jun 3 11:09:44] VERBOSE[2663] netsock2.c: == Using SIP RTP TOS bits 184
[Jun 3 11:09:44] VERBOSE[2663] netsock2.c: == Using SIP RTP CoS mark 5
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [dailed [email protected]:1] Macro(“SIP/2000-0000009a”, “user-callerid,SKIPTTL,”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:1] Set(“SIP/2000-0000009a”, “AMPUSER=2000”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:2] GotoIf(“SIP/2000-0000009a”, “0?report”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:3] ExecIf(“SIP/2000-0000009a”, “1?Set(REALCALLERIDNUM=2000)”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:4] Set(“SIP/2000-0000009a”, “AMPUSER=2000”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:5] Set(“SIP/2000-0000009a”, “AMPUSERCIDNAME=IT Helpdesk”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:6] GotoIf(“SIP/2000-0000009a”, “0?report”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:7] Set(“SIP/2000-0000009a”, “AMPUSERCID=2000”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:8] Set(“SIP/2000-0000009a”, “CALLERID(all)=“IT Helpdesk” <2000>”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:9] ExecIf(“SIP/2000-0000009a”, “0?Set(CHANNEL(language)=)”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:10] GotoIf(“SIP/2000-0000009a”, “1?continue”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Goto (macro-user-callerid,s,19)
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:19] Set(“SIP/2000-0000009a”, “CALLERID(number)=2000”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:20] Set(“SIP/2000-0000009a”, “CALLERID(name)=IT Helpdesk”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:21] NoOp(“SIP/2000-0000009a”, “Using CallerID “IT Helpdesk” <2000>”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [dailed [email protected]:2] NoOp(“SIP/2000-0000009a”, “Calling Out Route: ITA”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [dailed [email protected]:3] Set(“SIP/2000-0000009a”, “MOHCLASS=default”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [dailed [email protected]:4] Set(“SIP/2000-0000009a”, “_NODEST=”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [dailed [email protected]:5] Macro(“SIP/2000-0000009a”, “record-enable,2000,OUT,”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:1] GotoIf(“SIP/2000-0000009a”, “1?check”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Goto (macro-record-enable,s,4)
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:4] ExecIf(“SIP/2000-0000009a”, “0?MacroExit()”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:5] GotoIf(“SIP/2000-0000009a”, “0?Group:OUT”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Goto (macro-record-enable,s,15)
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:15] GotoIf(“SIP/2000-0000009a”, “0?IN”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:16] ExecIf(“SIP/2000-0000009a”, “1?MacroExit()”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [dailed [email protected]:6] Macro(“SIP/2000-0000009a”, “dialout-trunk,1,dailed number,”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:1] Set(“SIP/2000-0000009a”, “DIAL_TRUNK=1”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:2] GosubIf(“SIP/2000-0000009a”, “0?sub-pincheck,s,1”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:3] GotoIf(“SIP/2000-0000009a”, “0?disabletrunk,1”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:4] Set(“SIP/2000-0000009a”, “DIAL_NUMBER=dailed number”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:5] Set(“SIP/2000-0000009a”, “DIAL_TRUNK_OPTIONS=tr”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:6] Set(“SIP/2000-0000009a”, “OUTBOUND_GROUP=OUT_1”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:7] GotoIf(“SIP/2000-0000009a”, “0?nomax”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:8] GotoIf(“SIP/2000-0000009a”, “0?chanfull”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:9] GotoIf(“SIP/2000-0000009a”, “0?skipoutcid”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:10] Set(“SIP/2000-0000009a”, “DIAL_TRUNK_OPTIONS=”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:11] Macro(“SIP/2000-0000009a”, “outbound-callerid,1”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]nd-callerid:1] ExecIf(“SIP/2000-0000009a”, “0?Set(CALLERPRES()=)”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:2] ExecIf(“SIP/2000-0000009a”, “0?Set(REALCALLERIDNUM=2000)”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:3] GotoIf(“SIP/2000-0000009a”, “1?normcid”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Goto (macro-outbound-callerid,s,6)
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:6] Set(“SIP/2000-0000009a”, “USEROUTCID=”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:7] Set(“SIP/2000-0000009a”, “EMERGENCYCID=”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:8] Set(“SIP/2000-0000009a”, “TRUNKOUTCID=my number”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:9] GotoIf(“SIP/2000-0000009a”, “1?trunkcid”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Goto (macro-outbound-callerid,s,12)
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:12] ExecIf(“SIP/2000-0000009a”, “1?Set(CALLERID(all)=my number)”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:13] ExecIf(“SIP/2000-0000009a”, “0?Set(CALLERID(all)=)”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:14] ExecIf(“SIP/2000-0000009a”, “0?Set(CALLERID(all)=)”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:15] ExecIf(“SIP/2000-0000009a”, “0?Set(CALLERPRES()=prohib_passed_screen)”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:12] GosubIf(“SIP/2000-0000009a”, “0?sub-flp-1,s,1”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:13] Set(“SIP/2000-0000009a”, “OUTNUM=dailed number”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:14] Set(“SIP/2000-0000009a”, “custom=SIP/ITA”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:15] ExecIf(“SIP/2000-0000009a”, “0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default))”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:16] Macro(“SIP/2000-0000009a”, “dialout-trunk-predial-hook,”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:1] MacroExit(“SIP/2000-0000009a”, “”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:17] GotoIf(“SIP/2000-0000009a”, “0?bypass,1”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:18] GotoIf(“SIP/2000-0000009a”, “0?customtrunk”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] pbx.c: – Executing [[email protected]:19] Dial(“SIP/2000-0000009a”, “SIP/ITA/dailed number,300,”) in new stack
[Jun 3 11:09:44] VERBOSE[16617] netsock2.c: == Using SIP RTP TOS bits 184
[Jun 3 11:09:44] VERBOSE[16617] netsock2.c: == Using SIP RTP CoS mark 5
[Jun 3 11:09:44] VERBOSE[16617] chan_sip.c: Audio is at 13930
[Jun 3 11:09:44] VERBOSE[16617] chan_sip.c: Adding codec 0x8 (alaw) to SDP
[Jun 3 11:09:44] VERBOSE[16617] chan_sip.c: Adding codec 0x4 (ulaw) to SDP
[Jun 3 11:09:44] VERBOSE[16617] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP
[Jun 3 11:09:44] VERBOSE[16617] chan_sip.c: Reliably Transmitting (NAT) to (IP of service provider):5060:
INVITE sip:dailed [email protected](IP of service provider) SIP/2.0
Via: SIP/2.0/UDP My IP:5060;branch=z9hG4bK2ceb8c6a;rport
Max-Forwards: 70
From: “my number” <sip:My [email protected](IP of service provider)>;tag=as2cf3d835
To: <sip:dailed [email protected](IP of service provider)>
Contact: <sip:My [email protected] IP:5060>
Call-ID: [email protected](IP of service provider)
CSeq: 102 INVITE
User-Agent: FPBX-2.8.1(1.8.12.0)
Date: Wed, 03 Jun 2015 10:09:44 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 263

v=0
o=root 114303204 114303204 IN IP4 My IP
s=Asterisk PBX 1.8.12.0
c=IN IP4 My IP
t=0 0
m=audio 13930 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv


[Jun 3 11:09:44] VERBOSE[16617] app_dial.c: – Called SIP/ITA/dailed number
[Jun 3 11:09:44] VERBOSE[2663] chan_sip.c:
<— SIP read from UDP:(IP of service provider):5060 —>
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP My IP:5060;branch=z9hG4bK2ceb8c6a;received=My IP;rport=5060
From: “my number” <sip:My [email protected](IP of service provider)>;tag=as2cf3d835
To: <sip:dailed [email protected](IP of service provider)>;tag=as5da417cc
Call-ID: [email protected](IP of service provider)
CSeq: 102 INVITE
Server: voicewire.com
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="(IP of service provider)", nonce="16388c7a"
Content-Length: 0

<------------->
[Jun 3 11:09:44] VERBOSE[2663] chan_sip.c: — (11 headers 0 lines) —
[Jun 3 11:09:44] VERBOSE[2663] chan_sip.c: set_destination: Parsing <sip:dailed [email protected](IP of service provider)> for address/port to send to
[Jun 3 11:09:44] VERBOSE[2663] chan_sip.c: set_destination: set destination to (IP of service provider):5060
[Jun 3 11:09:44] VERBOSE[2663] chan_sip.c: Transmitting (NAT) to (IP of service provider):5060:
ACK sip:dailed [email protected](IP of service provider) SIP/2.0
Via: SIP/2.0/UDP My IP:5060;branch=z9hG4bK2ceb8c6a;rport
Max-Forwards: 70
From: “my number” <sip:My [email protected](IP of service provider)>;tag=as2cf3d835
To: <sip:dailed [email protected](IP of service provider)>;tag=as5da417cc
Contact: <sip:My [email protected] IP:5060>
Call-ID: [email protected](IP of service provider)
CSeq: 102 ACK
User-Agent: FPBX-2.8.1(1.8.12.0)
Content-Length: 0


[Jun 3 11:09:44] VERBOSE[2663] chan_sip.c: Audio is at 13930
[Jun 3 11:09:44] VERBOSE[2663] chan_sip.c: Adding codec 0x8 (alaw) to SDP
[Jun 3 11:09:44] VERBOSE[2663] chan_sip.c: Adding codec 0x4 (ulaw) to SDP
[Jun 3 11:09:44] VERBOSE[2663] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP
[Jun 3 11:09:44] VERBOSE[2663] chan_sip.c: Reliably Transmitting (NAT) to (IP of service provider):5060:
INVITE sip:dailed [email protected](IP of service provider) SIP/2.0
Via: SIP/2.0/UDP My IP:5060;branch=z9hG4bK5a756c1e;rport
Max-Forwards: 70
From: “my number” <sip:My [email protected](IP of service provider)>;tag=as2cf3d835
To: <sip:dailed [email protected](IP of service provider)>
Contact: <sip:My [email protected] IP:5060>
Call-ID: [email protected](IP of service provider)
CSeq: 103 INVITE
User-Agent: FPBX-2.8.1(1.8.12.0)
Authorization: Digest username=“My username”, realm="(IP of service provider)", algorithm=MD5, uri=“sip:dailed [email protected](IP of service provider)”, nonce=“16388c7a”, response="dbfeac01d9e47f52e676d700ba53c5c4"
Date: Wed, 03 Jun 2015 10:09:44 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 263

v=0
o=root 114303204 114303205 IN IP4 My IP
s=Asterisk PBX 1.8.12.0
c=IN IP4 My IP
t=0 0
m=audio 13930 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv


[Jun 3 11:09:44] VERBOSE[2663] chan_sip.c:
<— SIP read from UDP:(IP of service provider):5060 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP My IP:5060;branch=z9hG4bK5a756c1e;received=My IP;rport=5060
From: “my number” <sip:My [email protected](IP of service provider)>;tag=as2cf3d835
To: <sip:dailed [email protected](IP of service provider)>
Call-ID: [email protected](IP of service provider)
CSeq: 103 INVITE
Server: voicewire.com
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Session-Expires: 1800;refresher=uas
Contact: <sip:dailed [email protected](IP of service provider):5060>
Content-Length: 0

<------------->
[Jun 3 11:09:44] VERBOSE[2663] chan_sip.c: — (12 headers 0 lines) —
[Jun 3 11:09:45] VERBOSE[2663] chan_sip.c:
<— SIP read from UDP:(IP of service provider):5060 —>
SIP/2.0 603 Declined
Via: SIP/2.0/UDP My IP:5060;branch=z9hG4bK5a756c1e;received=My IP;rport=5060
From: “my number” <sip:My [email protected](IP of service provider)>;tag=as2cf3d835
To: <sip:dailed [email protected](IP of service provider)>;tag=as3ca5cd07
Call-ID: [email protected](IP of service provider)
CSeq: 103 INVITE
Server: voicewire.com
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0

<------------->
[Jun 3 11:09:45] VERBOSE[2663] chan_sip.c: — (10 headers 0 lines) —
[Jun 3 11:09:45] VERBOSE[2663] chan_sip.c: – Got SIP response 603 “Declined” back from (IP of service provider):5060
[Jun 3 11:09:45] VERBOSE[2663] chan_sip.c: Transmitting (NAT) to (IP of service provider):5060:
ACK sip:dailed [email protected](IP of service provider) SIP/2.0
Via: SIP/2.0/UDP My IP:5060;branch=z9hG4bK5a756c1e;rport
Max-Forwards: 70
From: “my number” <sip:My [email protected](IP of service provider)>;tag=as2cf3d835
To: <sip:dailed [email protected](IP of service provider)>;tag=as3ca5cd07
Contact: <sip:My [email protected] IP:5060>
Call-ID: [email protected](IP of service provider)
CSeq: 103 ACK
User-Agent: FPBX-2.8.1(1.8.12.0)
Content-Length: 0