CHANUNAVAIL and HANGUPCAUSE = 20

Hi!

My outbound routes failed to work after I added a failover trunk.
I have temporarily been able to make it work by changing the order of “Trunk Sequence for Matched Routes” under my outbound route settings. However, changing it back to the original sequence then re-changing it back to the working configuration failed to work.

When I call, I hear the “All circuits are busy now” message and then the call fails with error CHANUNAVAIL and HANGUPCAUSE = 20

Internal SIP/IAX2 calls work fine, only outgoing calls fail.
Incoming calls work fine as well.
Outgoing calls fail on all extension (SIP and IAX2) registered from inside the same subnet, from VPN and from the exterior.

After some reading on the forums, some where talking about a bug with dns resolution, so I changed the voip.freephoneline.ca and voip2.freephoneline.ca for their numeric value. Didn’t work.
I tried playing with the callerid settings, didn’t work.
I tried resaving my configs, didn’t work.

I just don’t know why it’s been failing on my like this, it’s just weird.

Thanks for helping me, i truly appreciate it.

JS

The trunks are registered to the sip provider, it seems to be an internal problem
SIP Registry:
Host dnsmgr Username Refresh State Reg.Time
208.65.240.165:5060 N 1514447#### 345 Registered Sun, 21 Apr 2013 13:48:13
208.65.240.44:5060 N 1514447#### 345 Registered Sun, 21 Apr 2013 13:48:27
2 SIP registrations.

Sip Channel(s):

Peer User/ANR Call ID Format Hold Last Message Expiry Peer
208.65.240.44 1514447#### 7d859ab759e0eff (nothing) No
208.65.240.165 151444#### 461ee0404a25211 (nothing) No
208.65.240.44 (None) 3824309178062be (nothing) No Init: OPTIONS Clinique
3 active SIP dialogs

Peer settings

context=from-pstn
type=peer
insecure=very
qualify=yes
sendrpid=yes
trustrpid=yes
dtmfmode=rfc2833
username=1514447####
secret=•••••••••
host=208.65.240.44
disallow=all
allow=ulaw
nat=yes

NAT settings:
dynamic ip
dynamic host: myip.dyndns.org
refresh =600
local networks 192.168.1.0 /255.255.255.0

My SIP provider is Freephoneline
I’m running freepbx, running on Centos 6.2 (final) (got the install disks on asterisk.org)
yum updated. All modules updated.

Linux localhost.localdomain 2.6.32-220.13.1.el6.i686 #1 SMP Tue Apr 17 22:09:08 BST 2012 i686 i686 i386 GNU/Linux

PBX Firmware: 1.88.210.57-1
PBX Service Pack: 1.0.0.0

and the error from the console

== Everyone is busy/congested at this time (1:0/0/1) -- Executing [s@macro-dialout-trunk:23] NoOp("SIP/101-00000002", "Dial failed for some reason with DIALSTATUS = CHANUNAVAIL and HANGUPCAUSE = 20") in new stack -- Executing [s@macro-dialout-trunk:24] Goto("SIP/101-00000002", "s-CHANUNAVAIL,1") in new stack -- Goto (macro-dialout-trunk,s-CHANUNAVAIL,1) -- Executing [s-CHANUNAVAIL@macro-dialout-trunk:1] Set("SIP/101-00000002", "RC=20") in new stack -- Executing [s-CHANUNAVAIL@macro-dialout-trunk:2] Goto("SIP/101-00000002", "20,1") in new stack -- Goto (macro-dialout-trunk,20,1) -- Executing [20@macro-dialout-trunk:1] Goto("SIP/101-00000002", "continue,1") in new stack -- Goto (macro-dialout-trunk,continue,1) -- Executing [continue@macro-dialout-trunk:1] GotoIf("SIP/101-00000002", "1?noreport") in new stack -- Goto (macro-dialout-trunk,continue,3) -- Executing [continue@macro-dialout-trunk:3] NoOp("SIP/101-00000002", "TRUNK Dial failed due to CHANUNAVAIL HANGUPCAUSE: 20 - failing through to other trunks") in new stack -- Executing [continue@macro-dialout-trunk:4] Set("SIP/101-00000002", "CALLERID(number)=101") in new stack -- Executing [5148858443@outbound-3:6] Macro("SIP/101-00000002", "outisbusy,") in new stack -- Executing [s@macro-outisbusy:1] Progress("SIP/101-00000002", "") in new stack -- Executing [s@macro-outisbusy:2] GotoIf("SIP/101-00000002", "0?emergency,1") in new stack -- Executing [s@macro-outisbusy:3] GotoIf("SIP/101-00000002", "0?intracompany,1") in new stack -- Executing [s@macro-outisbusy:4] Playback("SIP/101-00000002", "all-circuits-busy-now&pls-try-call-later, noanswer") in new stack -- <SIP/101-00000002> Playing 'all-circuits-busy-now.ulaw' (language 'fr') -- <SIP/101-00000002> Playing 'pls-try-call-later.ulaw' (language 'fr') -- Executing [s@macro-outisbusy:5] Congestion("SIP/101-00000002", "20") in new stack == Spawn extension (macro-outisbusy, s, 5) exited non-zero on 'SIP/101-00000002' in macro 'outisbusy' == Spawn extension (outbound-3, 5148858443, 6) exited non-zero on 'SIP/101-00000002'

How are you posting all that log entry without pagination? That should not be happening.

sorry about that, i guess the filtered html text format got rid of the line breaks

is there any way to decongest it? I don’t understand why it fails, as it is not being used by any extension and both trunks are registered

It’s not supposed to and I just upgraded that module. I guess I need to play with it.

Need more intense debug to see why the failover is not working. SIP trace would be handy.

Alright,
I enabled debug on peer 205 on which i tried to call a outgoing call
205 has ip address 192.168.1.201
server has ip address 192.168.1.10
(server.myserver.com is just a placeholder)

<--- SIP read from UDP:192.168.1.201:60605 ---> INVITE sip:[email protected] SIP/2.0 Via: SIP/2.0/UDP 192.168.1.201:60605;rport;branch=z9hG4bKPj.Rlb5O.KJZNY2RHRNgG-tQXGjeo8eiPV Max-Forwards: 70 From: "test" ;tag=LP9JchKmny8IYU1w5M7B7sHf1FAjqraF To: Contact: ;+sip.ice Call-ID: u9Y.2tayU4wjeUQMI.Ui1JhN1J9e8UEK CSeq: 16851 INVITE Route: Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Supported: replaces, 100rel, timer, norefersub Session-Expires: 1800 Min-SE: 90 User-Agent: Telephone 1.0.4 Content-Type: application/sdp Content-Length: 903

v=0
o=- 3575566289 3575566289 IN IP4 70.55.62.217
s=pjmedia
c=IN IP4 70.55.62.217
t=0 0
a=X-nat:8
m=audio 56327 RTP/AVP 103 102 104 109 3 0 8 9 101
a=rtcp:64213 IN IP4 70.55.62.217
a=rtpmap:103 speex/16000
a=rtpmap:102 speex/8000
a=rtpmap:104 speex/32000
a=rtpmap:109 iLBC/8000
a=fmtp:109 mode=30
a=rtpmap:3 GSM/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=sendrecv
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ice-ufrag:3f5126fb
a=ice-pwd:68d64936
a=candidate:Hc0a80012 1 UDP 1694498815 192.168.0.18 56327 typ host
a=candidate:Had33702 1 UDP 1694498815 10.211.55.2 56327 typ host
a=candidate:Ha258102 1 UDP 1694498815 10.37.129.2 56327 typ host
a=candidate:Hc0a80012 2 UDP 1694498814 192.168.0.18 64213 typ host
a=candidate:Had33702 2 UDP 1694498814 10.211.55.2 64213 typ host
a=candidate:Ha258102 2 UDP 1694498814 10.37.129.2 64213 typ host
<------------->
— (16 headers 28 lines) —
Sending to 192.168.1.201:60605 (NAT)
Using INVITE request as basis request - u9Y.2tayU4wjeUQMI.Ui1JhN1J9e8UEK
Found peer ‘205’ for ‘205’ from 192.168.1.201:60605

<— Reliably Transmitting (NAT) to 192.168.1.201:60605 —>
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.1.201:60605;branch=z9hG4bKPj.Rlb5O.KJZNY2RHRNgG-tQXGjeo8eiPV;received=192.168.1.201;rport=60605
From: “test” sip:[email protected];tag=LP9JchKmny8IYU1w5M7B7sHf1FAjqraF
To: sip:[email protected];tag=as22a503e6
Call-ID: u9Y.2tayU4wjeUQMI.Ui1JhN1J9e8UEK
CSeq: 16851 INVITE
Server: FPBX-2.10.1(10.5.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm=“asterisk”, nonce="0a9a7f2f"
Content-Length: 0

<------------>
Scheduling destruction of SIP dialog ‘u9Y.2tayU4wjeUQMI.Ui1JhN1J9e8UEK’ in 6400 ms (Method: INVITE)

<— SIP read from UDP:192.168.1.201:60605 —>
ACK sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.1.201:60605;rport;branch=z9hG4bKPj.Rlb5O.KJZNY2RHRNgG-tQXGjeo8eiPV
Max-Forwards: 70
From: “test” sip:[email protected];tag=LP9JchKmny8IYU1w5M7B7sHf1FAjqraF
To: sip:[email protected];tag=as22a503e6
Call-ID: u9Y.2tayU4wjeUQMI.Ui1JhN1J9e8UEK
CSeq: 16851 ACK
Route: sip:192.168.1.10;lr
Content-Length: 0

<------------->
— (9 headers 0 lines) —

<— SIP read from UDP:192.168.1.201:60605 —>
INVITE sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.1.201:60605;rport;branch=z9hG4bKPjGX.tmQs4oDb3SVQlA5DuIsVjFyq84oSg
Max-Forwards: 70
From: “test” sip:[email protected];tag=LP9JchKmny8IYU1w5M7B7sHf1FAjqraF
To: sip:[email protected]
Contact: sip:[email protected]:60605;transport=UDP;ob;+sip.ice
Call-ID: u9Y.2tayU4wjeUQMI.Ui1JhN1J9e8UEK
CSeq: 16852 INVITE
Route: sip:192.168.1.10;lr
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800
Min-SE: 90
User-Agent: Telephone 1.0.4
Authorization: Digest username=“205”, realm=“asterisk”, nonce=“0a9a7f2f”, uri="sip:[email protected]", response=“d4925ad01117b9a918d082b9858061e1”, algorithm=MD5
Content-Type: application/sdp
Content-Length: 903

v=0
o=- 3575566289 3575566289 IN IP4 70.55.62.217
s=pjmedia
c=IN IP4 70.55.62.217
t=0 0
a=X-nat:8
m=audio 56327 RTP/AVP 103 102 104 109 3 0 8 9 101
a=rtcp:64213 IN IP4 70.55.62.217
a=rtpmap:103 speex/16000
a=rtpmap:102 speex/8000
a=rtpmap:104 speex/32000
a=rtpmap:109 iLBC/8000
a=fmtp:109 mode=30
a=rtpmap:3 GSM/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=sendrecv
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ice-ufrag:3f5126fb
a=ice-pwd:68d64936
a=candidate:Hc0a80012 1 UDP 1694498815 192.168.0.18 56327 typ host
a=candidate:Had33702 1 UDP 1694498815 10.211.55.2 56327 typ host
a=candidate:Ha258102 1 UDP 1694498815 10.37.129.2 56327 typ host
a=candidate:Hc0a80012 2 UDP 1694498814 192.168.0.18 64213 typ host
a=candidate:Had33702 2 UDP 1694498814 10.211.55.2 64213 typ host
a=candidate:Ha258102 2 UDP 1694498814 10.37.129.2 64213 typ host
<------------->
— (17 headers 28 lines) —
Sending to 192.168.1.201:60605 (NAT)
Using INVITE request as basis request - u9Y.2tayU4wjeUQMI.Ui1JhN1J9e8UEK
Found peer ‘205’ for ‘205’ from 192.168.1.201:60605
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
Found RTP audio format 103
Found RTP audio format 102
Found RTP audio format 104
Found RTP audio format 109
Found RTP audio format 3
Found RTP audio format 0
Found RTP audio format 8
Found RTP audio format 9
Found RTP audio format 101
Found audio description format speex for ID 103
Found audio description format speex for ID 102
Found audio description format speex for ID 104
Found audio description format iLBC for ID 109
Found audio description format GSM for ID 3
Found audio description format PCMU for ID 0
Found audio description format PCMA for ID 8
Found audio description format G722 for ID 9
Found audio description format telephone-event for ID 101
Capabilities: us - (gsm|ulaw), peer - audio=(gsm|ulaw|alaw|speex|speex16|ilbc|g722|speex32)/video=(nothing)/text=(nothing), combined - (gsm|ulaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
Peer audio RTP is at port 70.55.62.217:56327
Looking for 5148858443 in from-internal (domain server.myserver.com)
list_route: hop: sip:[email protected]:60605;transport=UDP;ob

<— Transmitting (NAT) to 192.168.1.201:60605 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.201:60605;branch=z9hG4bKPjGX.tmQs4oDb3SVQlA5DuIsVjFyq84oSg;received=192.168.1.201;rport=60605
From: “test” sip:[email protected];tag=LP9JchKmny8IYU1w5M7B7sHf1FAjqraF
To: sip:[email protected]
Call-ID: u9Y.2tayU4wjeUQMI.Ui1JhN1J9e8UEK
CSeq: 16852 INVITE
Server: FPBX-2.10.1(10.5.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Session-Expires: 1800;refresher=uas
Contact: sip:[email protected]:5060
Content-Length: 0

<------------>
– Executing [5148858443@from-internal:1] Macro(“SIP/205-00000012”, “user-callerid,LIMIT”) in new stack
– Executing [s@macro-user-callerid:1] Set(“SIP/205-00000012”, “AMPUSER=205”) in new stack
– Executing [s@macro-user-callerid:2] GotoIf(“SIP/205-00000012”, “0?report”) in new stack
– Executing [s@macro-user-callerid:3] ExecIf(“SIP/205-00000012”, “1?Set(REALCALLERIDNUM=205)”) in new stack
– Executing [s@macro-user-callerid:4] Set(“SIP/205-00000012”, “AMPUSER=205”) in new stack
– Executing [s@macro-user-callerid:5] Set(“SIP/205-00000012”, “AMPUSERCIDNAME=205”) in new stack
– Executing [s@macro-user-callerid:6] GotoIf(“SIP/205-00000012”, “0?report”) in new stack
– Executing [s@macro-user-callerid:7] Set(“SIP/205-00000012”, “AMPUSERCID=205”) in new stack
– Executing [s@macro-user-callerid:8] Set(“SIP/205-00000012”, “CALLERID(all)=“205” <205>”) in new stack
– Executing [s@macro-user-callerid:9] GotoIf(“SIP/205-00000012”, “0?limit”) in new stack
– Executing [s@macro-user-callerid:10] ExecIf(“SIP/205-00000012”, “1?Set(GROUP(concurrency_limit)=205)”) in new stack
– Executing [s@macro-user-callerid:11] ExecIf(“SIP/205-00000012”, “0?Set(CHANNEL(language)=)”) in new stack
– Executing [s@macro-user-callerid:12] GosubIf(“SIP/205-00000012”, “7?sub-ccss,s,1(from-internal,5148858443)”) in new stack
– Executing [s@sub-ccss:1] ExecIf(“SIP/205-00000012”, “0?Return()”) in new stack
– Executing [s@sub-ccss:2] Set(“SIP/205-00000012”, “CCSS_SETUP=TRUE”) in new stack
– Executing [s@sub-ccss:3] GosubIf(“SIP/205-00000012”, “0?monitor_config,1(from-internal,5148858443):monitor_default,1(from-internal,5148858443)”) in new stack
– Executing [monitor_default@sub-ccss:1] GotoIf(“SIP/205-00000012”, “0?is_exten”) in new stack
– Executing [monitor_default@sub-ccss:2] StackPop(“SIP/205-00000012”, “”) in new stack
– Executing [monitor_default@sub-ccss:3] Return(“SIP/205-00000012”, “FALSE”) in new stack
– Executing [s@macro-user-callerid:13] GotoIf(“SIP/205-00000012”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,26)
– Executing [s@macro-user-callerid:26] Set(“SIP/205-00000012”, “CALLERID(number)=205”) in new stack
– Executing [s@macro-user-callerid:27] Set(“SIP/205-00000012”, “CALLERID(name)=205”) in new stack
– Executing [s@macro-user-callerid:28] Set(“SIP/205-00000012”, “CHANNEL(language)=fr”) in new stack
– Executing [5148858443@from-internal:2] Set(“SIP/205-00000012”, “ROUTEUSER=205”) in new stack
– Executing [5148858443@from-internal:3] GotoIf(“SIP/205-00000012”, “1?outbound-2-3,5148858443,2:outbound-allroutes,5148858443,2”) in new stack
– Goto (outbound-2-3,5148858443,2)
Scheduling destruction of SIP dialog ‘u9Y.2tayU4wjeUQMI.Ui1JhN1J9e8UEK’ in 6400 ms (Method: INVITE)

<— Reliably Transmitting (NAT) to 192.168.1.201:60605 —>
SIP/2.0 603 Declined
Via: SIP/2.0/UDP 192.168.1.201:60605;branch=z9hG4bKPjGX.tmQs4oDb3SVQlA5DuIsVjFyq84oSg;received=192.168.1.201;rport=60605
From: “test” sip:[email protected];tag=LP9JchKmny8IYU1w5M7B7sHf1FAjqraF
To: sip:[email protected];tag=as77a9e45e
Call-ID: u9Y.2tayU4wjeUQMI.Ui1JhN1J9e8UEK
CSeq: 16852 INVITE
Server: FPBX-2.10.1(10.5.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

<------------>
Retransmitting #1 (NAT) to 192.168.1.201:60605:
SIP/2.0 603 Declined
Via: SIP/2.0/UDP 192.168.1.201:60605;branch=z9hG4bKPjGX.tmQs4oDb3SVQlA5DuIsVjFyq84oSg;received=192.168.1.201;rport=60605
From: “test” sip:[email protected];tag=LP9JchKmny8IYU1w5M7B7sHf1FAjqraF
To: sip:[email protected];tag=as77a9e45e
Call-ID: u9Y.2tayU4wjeUQMI.Ui1JhN1J9e8UEK
CSeq: 16852 INVITE
Server: FPBX-2.10.1(10.5.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0


<— SIP read from UDP:192.168.1.201:60605 —>
ACK sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.1.201:60605;rport;branch=z9hG4bKPjGX.tmQs4oDb3SVQlA5DuIsVjFyq84oSg
Max-Forwards: 70
From: “test” sip:[email protected];tag=LP9JchKmny8IYU1w5M7B7sHf1FAjqraF
To: sip:[email protected];tag=as77a9e45e
Call-ID: u9Y.2tayU4wjeUQMI.Ui1JhN1J9e8UEK
CSeq: 16852 ACK
Route: sip:192.168.1.10;lr
Content-Length: 0

<------------->
— (9 headers 0 lines) —

<— SIP read from UDP:192.168.1.201:60605 —>
ACK sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.1.201:60605;rport;branch=z9hG4bKPjGX.tmQs4oDb3SVQlA5DuIsVjFyq84oSg
Max-Forwards: 70
From: “test” sip:[email protected];tag=LP9JchKmny8IYU1w5M7B7sHf1FAjqraF
To: sip:[email protected];tag=as77a9e45e
Call-ID: u9Y.2tayU4wjeUQMI.Ui1JhN1J9e8UEK
CSeq: 16852 ACK
Route: sip:192.168.1.10;lr
Content-Length: 0

<------------->
— (9 headers 0 lines) —

<— SIP read from UDP:192.168.1.201:60605 —>

<------------->

<— SIP read from UDP:192.168.1.201:60605 —>

<------------->
Really destroying SIP dialog ‘u9Y.2tayU4wjeUQMI.Ui1JhN1J9e8UEK’ Method: ACK

here’s another trace using the “sip set debug on” command

localhost*CLI> sip set debug on SIP Debugging enabled Really destroying SIP dialog '50b1c2ae2cbff82e465ba0e0237fe5ca@[::1]' Method: REGISTER Really destroying SIP dialog '35a767604a8da45958aa3f6847a8cadf@[::1]' Method: REGISTER

<— SIP read from UDP:208.65.240.44:5060 —>

<------------->

<— SIP read from UDP:192.168.1.201:60605 —>

<------------->

<— SIP read from UDP:192.168.1.201:60605 —>

<------------->

<— SIP read from UDP:70.53.148.59:1024 —>

<------------->

<— SIP read from UDP:70.53.148.59:5062 —>

<------------->

<— SIP read from UDP:192.168.1.201:60605 —>

<------------->

<— SIP read from UDP:192.168.1.201:60605 —>

<------------->

<— SIP read from UDP:70.53.148.59:5062 —>
SUBSCRIBE sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 10.65.54.112:5062;branch=z9hG4bK839803702;rport
From: sip:[email protected];tag=314875637
To: sip:[email protected]
Call-ID: [email protected]
CSeq: 25540 SUBSCRIBE
Contact: sip:[email protected]:5062
X-Grandstream-PBX: true
Max-Forwards: 70
User-Agent: Grandstream GXP2100 1.0.5.15
Expires: 3600
Supported: replaces, path, timer
Event: message-summary
Accept: application/simple-message-summary
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0

<------------->
— (16 headers 0 lines) —
Creating new subscription
Sending to 70.53.148.59:5062 (NAT)
list_route: hop: sip:[email protected]:5062
Found peer ‘204’ for ‘204’ from 70.53.148.59:5062

<— Transmitting (NAT) to 70.53.148.59:5062 —>
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 10.65.54.112:5062;branch=z9hG4bK839803702;received=70.53.148.59;rport=5062
From: sip:[email protected];tag=314875637
To: sip:[email protected];tag=as7e26a241
Call-ID: [email protected]
CSeq: 25540 SUBSCRIBE
Server: FPBX-2.10.1(10.5.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm=“asterisk”, nonce="2ce9b232"
Content-Length: 0

<------------>
Scheduling destruction of SIP dialog ‘[email protected]’ in 6400 ms (Method: SUBSCRIBE)

<— SIP read from UDP:70.53.148.59:5062 —>
SUBSCRIBE sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 10.65.54.112:5062;branch=z9hG4bK972130476;rport
From: sip:[email protected];tag=314875637
To: sip:[email protected]
Call-ID: [email protected]
CSeq: 25541 SUBSCRIBE
Contact: sip:[email protected]:5062
Authorization: Digest username=“204”, realm=“asterisk”, nonce=“2ce9b232”, uri="sip:[email protected]", response=“0eeb0dbd2a0327776dc10310334b7c6b”, algorithm=MD5
X-Grandstream-PBX: true
Max-Forwards: 70
User-Agent: Grandstream GXP2100 1.0.5.15
Expires: 3600
Supported: replaces, path, timer
Event: message-summary
Accept: application/simple-message-summary
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0

<------------->
— (17 headers 0 lines) —
Creating new subscription
Sending to 70.53.148.59:5062 (NAT)
Found peer ‘204’ for ‘204’ from 70.53.148.59:5062

<— Transmitting (NAT) to 70.53.148.59:5062 —>
SIP/2.0 404 Not found (no mailbox)
Via: SIP/2.0/UDP 10.65.54.112:5062;branch=z9hG4bK972130476;received=70.53.148.59;rport=5062
From: sip:[email protected];tag=314875637
To: sip:[email protected];tag=as7e26a241
Call-ID: [email protected]
CSeq: 25541 SUBSCRIBE
Server: FPBX-2.10.1(10.5.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

<------------>
Really destroying SIP dialog ‘[email protected]’ Method: SUBSCRIBE

<— SIP read from UDP:70.53.148.59:5062 —>
SUBSCRIBE sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 10.65.54.112:5062;branch=z9hG4bK1547941088;rport
From: sip:[email protected];tag=1340664703
To: sip:[email protected]
Call-ID: [email protected]
CSeq: 25550 SUBSCRIBE
Contact: sip:[email protected]:5062
X-Grandstream-PBX: true
Max-Forwards: 70
User-Agent: Grandstream GXP2100 1.0.5.15
Expires: 3600
Supported: replaces, path, timer
Event: message-summary
Accept: application/simple-message-summary
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0

<------------->
— (16 headers 0 lines) —
Creating new subscription
Sending to 70.53.148.59:5062 (NAT)
list_route: hop: sip:[email protected]:5062
Found peer ‘204’ for ‘204’ from 70.53.148.59:5062

<— Transmitting (NAT) to 70.53.148.59:5062 —>
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 10.65.54.112:5062;branch=z9hG4bK1547941088;received=70.53.148.59;rport=5062
From: sip:[email protected];tag=1340664703
To: sip:[email protected];tag=as72f6eb05
Call-ID: [email protected]
CSeq: 25550 SUBSCRIBE
Server: FPBX-2.10.1(10.5.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm=“asterisk”, nonce="55ea54ab"
Content-Length: 0

<------------>
Scheduling destruction of SIP dialog ‘[email protected]’ in 6400 ms (Method: SUBSCRIBE)

<— SIP read from UDP:70.53.148.59:5062 —>
SUBSCRIBE sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 10.65.54.112:5062;branch=z9hG4bK75217291;rport
From: sip:[email protected];tag=1340664703
To: sip:[email protected]
Call-ID: [email protected]
CSeq: 25551 SUBSCRIBE
Contact: sip:[email protected]:5062
Authorization: Digest username=“204”, realm=“asterisk”, nonce=“55ea54ab”, uri="sip:[email protected]", response=“1794486e00beaae84282d554217d7b1f”, algorithm=MD5
X-Grandstream-PBX: true
Max-Forwards: 70
User-Agent: Grandstream GXP2100 1.0.5.15
Expires: 3600
Supported: replaces, path, timer
Event: message-summary
Accept: application/simple-message-summary
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0

<------------->
— (17 headers 0 lines) —
Creating new subscription
Sending to 70.53.148.59:5062 (NAT)
Found peer ‘204’ for ‘204’ from 70.53.148.59:5062

<— Transmitting (NAT) to 70.53.148.59:5062 —>
SIP/2.0 404 Not found (no mailbox)
Via: SIP/2.0/UDP 10.65.54.112:5062;branch=z9hG4bK75217291;received=70.53.148.59;rport=5062
From: sip:[email protected];tag=1340664703
To: sip:[email protected];tag=as72f6eb05
Call-ID: [email protected]
CSeq: 25551 SUBSCRIBE
Server: FPBX-2.10.1(10.5.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

<------------>
Really destroying SIP dialog ‘[email protected]’ Method: SUBSCRIBE

<— SIP read from UDP:192.168.1.201:60605 —>
INVITE sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.1.201:60605;rport;branch=z9hG4bKPjmuUy97QILAbokF9THZ6o4oismpVlfaQj
Max-Forwards: 70
From: “test” sip:[email protected];tag=sR2dsdWjJvfD3H7ay2KmQJzVzlE8P44i
To: sip:[email protected]
Contact: sip:[email protected]:60605;transport=UDP;ob;+sip.ice
Call-ID: A05sY7WvhQgHybVHxLVE31wlyzzXeAdI
CSeq: 16535 INVITE
Route: sip:192.168.1.10;lr
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800
Min-SE: 90
User-Agent: Telephone 1.0.4
Content-Type: application/sdp
Content-Length: 903

v=0
o=- 3575566978 3575566978 IN IP4 70.55.62.217
s=pjmedia
c=IN IP4 70.55.62.217
t=0 0
a=X-nat:8
m=audio 53909 RTP/AVP 103 102 104 109 3 0 8 9 101
a=rtcp:50784 IN IP4 70.55.62.217
a=rtpmap:103 speex/16000
a=rtpmap:102 speex/8000
a=rtpmap:104 speex/32000
a=rtpmap:109 iLBC/8000
a=fmtp:109 mode=30
a=rtpmap:3 GSM/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=sendrecv
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ice-ufrag:04e1dbea
a=ice-pwd:082ce227
a=candidate:Hc0a80012 1 UDP 1694498815 192.168.0.18 53909 typ host
a=candidate:Had33702 1 UDP 1694498815 10.211.55.2 53909 typ host
a=candidate:Ha258102 1 UDP 1694498815 10.37.129.2 53909 typ host
a=candidate:Hc0a80012 2 UDP 1694498814 192.168.0.18 50784 typ host
a=candidate:Had33702 2 UDP 1694498814 10.211.55.2 50784 typ host
a=candidate:Ha258102 2 UDP 1694498814 10.37.129.2 50784 typ host
<------------->
— (16 headers 28 lines) —
Sending to 192.168.1.201:60605 (NAT)
Using INVITE request as basis request - A05sY7WvhQgHybVHxLVE31wlyzzXeAdI
Found peer ‘230’ for ‘230’ from 192.168.1.201:60605

<— Reliably Transmitting (NAT) to 192.168.1.201:60605 —>
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.1.201:60605;branch=z9hG4bKPjmuUy97QILAbokF9THZ6o4oismpVlfaQj;received=192.168.1.201;rport=60605
From: “test” sip:[email protected];tag=sR2dsdWjJvfD3H7ay2KmQJzVzlE8P44i
To: sip:[email protected];tag=as777c4c40
Call-ID: A05sY7WvhQgHybVHxLVE31wlyzzXeAdI
CSeq: 16535 INVITE
Server: FPBX-2.10.1(10.5.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm=“asterisk”, nonce="35070c4b"
Content-Length: 0

<------------>
Scheduling destruction of SIP dialog ‘A05sY7WvhQgHybVHxLVE31wlyzzXeAdI’ in 6912 ms (Method: INVITE)

<— SIP read from UDP:192.168.1.201:60605 —>
ACK sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.1.201:60605;rport;branch=z9hG4bKPjmuUy97QILAbokF9THZ6o4oismpVlfaQj
Max-Forwards: 70
From: “test” sip:[email protected];tag=sR2dsdWjJvfD3H7ay2KmQJzVzlE8P44i
To: sip:[email protected];tag=as777c4c40
Call-ID: A05sY7WvhQgHybVHxLVE31wlyzzXeAdI
CSeq: 16535 ACK
Route: sip:192.168.1.10;lr
Content-Length: 0

<------------->
— (9 headers 0 lines) —

<— SIP read from UDP:192.168.1.201:60605 —>
INVITE sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.1.201:60605;rport;branch=z9hG4bKPjL9GQ3FputCqqncAHO8pVPkELhdIYIUhY
Max-Forwards: 70
From: “test” sip:[email protected];tag=sR2dsdWjJvfD3H7ay2KmQJzVzlE8P44i
To: sip:[email protected]
Contact: sip:[email protected]:60605;transport=UDP;ob;+sip.ice
Call-ID: A05sY7WvhQgHybVHxLVE31wlyzzXeAdI
CSeq: 16536 INVITE
Route: sip:192.168.1.10;lr
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800
Min-SE: 90
User-Agent: Telephone 1.0.4
Authorization: Digest username=“230”, realm=“asterisk”, nonce=“35070c4b”, uri="sip:[email protected]", response=“988ef10ea92a15900dcaa9161c78329e”, algorithm=MD5
Content-Type: application/sdp
Content-Length: 903

v=0
o=- 3575566978 3575566978 IN IP4 70.55.62.217
s=pjmedia
c=IN IP4 70.55.62.217
t=0 0
a=X-nat:8
m=audio 53909 RTP/AVP 103 102 104 109 3 0 8 9 101
a=rtcp:50784 IN IP4 70.55.62.217
a=rtpmap:103 speex/16000
a=rtpmap:102 speex/8000
a=rtpmap:104 speex/32000
a=rtpmap:109 iLBC/8000
a=fmtp:109 mode=30
a=rtpmap:3 GSM/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=sendrecv
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ice-ufrag:04e1dbea
a=ice-pwd:082ce227
a=candidate:Hc0a80012 1 UDP 1694498815 192.168.0.18 53909 typ host
a=candidate:Had33702 1 UDP 1694498815 10.211.55.2 53909 typ host
a=candidate:Ha258102 1 UDP 1694498815 10.37.129.2 53909 typ host
a=candidate:Hc0a80012 2 UDP 1694498814 192.168.0.18 50784 typ host
a=candidate:Had33702 2 UDP 1694498814 10.211.55.2 50784 typ host
a=candidate:Ha258102 2 UDP 1694498814 10.37.129.2 50784 typ host
<------------->
— (17 headers 28 lines) —
Sending to 192.168.1.201:60605 (NAT)
Using INVITE request as basis request - A05sY7WvhQgHybVHxLVE31wlyzzXeAdI
Found peer ‘230’ for ‘230’ from 192.168.1.201:60605
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
Found RTP audio format 103
Found RTP audio format 102
Found RTP audio format 104
Found RTP audio format 109
Found RTP audio format 3
Found RTP audio format 0
Found RTP audio format 8
Found RTP audio format 9
Found RTP audio format 101
Found audio description format speex for ID 103
Found audio description format speex for ID 102
Found audio description format speex for ID 104
Found audio description format iLBC for ID 109
Found audio description format GSM for ID 3
Found audio description format PCMU for ID 0
Found audio description format PCMA for ID 8
Found audio description format G722 for ID 9
Found audio description format telephone-event for ID 101
Capabilities: us - (gsm|ulaw), peer - audio=(gsm|ulaw|alaw|speex|speex16|ilbc|g722|speex32)/video=(nothing)/text=(nothing), combined - (gsm|ulaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
Peer audio RTP is at port 70.55.62.217:53909
Looking for 5148858443 in from-internal (domain server.myserver.com)
list_route: hop: sip:[email protected]:60605;transport=UDP;ob

<— Transmitting (NAT) to 192.168.1.201:60605 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.201:60605;branch=z9hG4bKPjL9GQ3FputCqqncAHO8pVPkELhdIYIUhY;received=192.168.1.201;rport=60605
From: “test” sip:[email protected];tag=sR2dsdWjJvfD3H7ay2KmQJzVzlE8P44i
To: sip:[email protected]
Call-ID: A05sY7WvhQgHybVHxLVE31wlyzzXeAdI
CSeq: 16536 INVITE
Server: FPBX-2.10.1(10.5.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Session-Expires: 1800;refresher=uas
Contact: sip:[email protected]:5060
Content-Length: 0

<------------>
– Executing [5148858443@from-internal:1] Macro(“SIP/230-00000014”, “user-callerid,LIMIT”) in new stack
– Executing [s@macro-user-callerid:1] Set(“SIP/230-00000014”, “AMPUSER=230”) in new stack
– Executing [s@macro-user-callerid:2] GotoIf(“SIP/230-00000014”, “0?report”) in new stack
– Executing [s@macro-user-callerid:3] ExecIf(“SIP/230-00000014”, “1?Set(REALCALLERIDNUM=230)”) in new stack
– Executing [s@macro-user-callerid:4] Set(“SIP/230-00000014”, “AMPUSER=230”) in new stack
– Executing [s@macro-user-callerid:5] Set(“SIP/230-00000014”, “AMPUSERCIDNAME=Francine Maison”) in new stack
– Executing [s@macro-user-callerid:6] GotoIf(“SIP/230-00000014”, “0?report”) in new stack
– Executing [s@macro-user-callerid:7] Set(“SIP/230-00000014”, “AMPUSERCID=230”) in new stack
– Executing [s@macro-user-callerid:8] Set(“SIP/230-00000014”, “CALLERID(all)=“Francine Maison” <230>”) in new stack
– Executing [s@macro-user-callerid:9] GotoIf(“SIP/230-00000014”, “0?limit”) in new stack
– Executing [s@macro-user-callerid:10] ExecIf(“SIP/230-00000014”, “1?Set(GROUP(concurrency_limit)=230)”) in new stack
– Executing [s@macro-user-callerid:11] ExecIf(“SIP/230-00000014”, “1?Set(CHANNEL(language)=fr)”) in new stack
– Executing [s@macro-user-callerid:12] GosubIf(“SIP/230-00000014”, “7?sub-ccss,s,1(from-internal,5148858443)”) in new stack
– Executing [s@sub-ccss:1] ExecIf(“SIP/230-00000014”, “0?Return()”) in new stack
– Executing [s@sub-ccss:2] Set(“SIP/230-00000014”, “CCSS_SETUP=TRUE”) in new stack
– Executing [s@sub-ccss:3] GosubIf(“SIP/230-00000014”, “0?monitor_config,1(from-internal,5148858443):monitor_default,1(from-internal,5148858443)”) in new stack
– Executing [monitor_default@sub-ccss:1] GotoIf(“SIP/230-00000014”, “0?is_exten”) in new stack
– Executing [monitor_default@sub-ccss:2] StackPop(“SIP/230-00000014”, “”) in new stack
– Executing [monitor_default@sub-ccss:3] Return(“SIP/230-00000014”, “FALSE”) in new stack
– Executing [s@macro-user-callerid:13] GotoIf(“SIP/230-00000014”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,26)
– Executing [s@macro-user-callerid:26] Set(“SIP/230-00000014”, “CALLERID(number)=230”) in new stack
– Executing [s@macro-user-callerid:27] Set(“SIP/230-00000014”, “CALLERID(name)=Francine Maison”) in new stack
– Executing [s@macro-user-callerid:28] Set(“SIP/230-00000014”, “CHANNEL(language)=fr”) in new stack
– Executing [5148858443@from-internal:2] Set(“SIP/230-00000014”, “ROUTEUSER=230”) in new stack
– Executing [5148858443@from-internal:3] GotoIf(“SIP/230-00000014”, “1?outbound-2-3,5148858443,2:outbound-allroutes,5148858443,2”) in new stack
– Goto (outbound-2-3,5148858443,2)
Scheduling destruction of SIP dialog ‘A05sY7WvhQgHybVHxLVE31wlyzzXeAdI’ in 6912 ms (Method: INVITE)

<— Reliably Transmitting (NAT) to 192.168.1.201:60605 —>
SIP/2.0 603 Declined
Via: SIP/2.0/UDP 192.168.1.201:60605;branch=z9hG4bKPjL9GQ3FputCqqncAHO8pVPkELhdIYIUhY;received=192.168.1.201;rport=60605
From: “test” sip:[email protected];tag=sR2dsdWjJvfD3H7ay2KmQJzVzlE8P44i
To: sip:[email protected];tag=as6f017828
Call-ID: A05sY7WvhQgHybVHxLVE31wlyzzXeAdI
CSeq: 16536 INVITE
Server: FPBX-2.10.1(10.5.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

<------------>
Retransmitting #1 (NAT) to 192.168.1.201:60605:
SIP/2.0 603 Declined
Via: SIP/2.0/UDP 192.168.1.201:60605;branch=z9hG4bKPjL9GQ3FputCqqncAHO8pVPkELhdIYIUhY;received=192.168.1.201;rport=60605
From: “test” sip:[email protected];tag=sR2dsdWjJvfD3H7ay2KmQJzVzlE8P44i
To: sip:[email protected];tag=as6f017828
Call-ID: A05sY7WvhQgHybVHxLVE31wlyzzXeAdI
CSeq: 16536 INVITE
Server: FPBX-2.10.1(10.5.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0


<— SIP read from UDP:192.168.1.201:60605 —>
ACK sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.1.201:60605;rport;branch=z9hG4bKPjL9GQ3FputCqqncAHO8pVPkELhdIYIUhY
Max-Forwards: 70
From: “test” sip:[email protected];tag=sR2dsdWjJvfD3H7ay2KmQJzVzlE8P44i
To: sip:[email protected];tag=as6f017828
Call-ID: A05sY7WvhQgHybVHxLVE31wlyzzXeAdI
CSeq: 16536 ACK
Route: sip:192.168.1.10;lr
Content-Length: 0

<------------->
— (9 headers 0 lines) —

<— SIP read from UDP:192.168.1.201:60605 —>
ACK sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.1.201:60605;rport;branch=z9hG4bKPjL9GQ3FputCqqncAHO8pVPkELhdIYIUhY
Max-Forwards: 70
From: “test” sip:[email protected];tag=sR2dsdWjJvfD3H7ay2KmQJzVzlE8P44i
To: sip:[email protected];tag=as6f017828
Call-ID: A05sY7WvhQgHybVHxLVE31wlyzzXeAdI
CSeq: 16536 ACK
Route: sip:192.168.1.10;lr
Content-Length: 0

<------------->
— (9 headers 0 lines) —

<— SIP read from UDP:70.53.148.59:1024 —>

<------------->

<— SIP read from UDP:70.53.148.59:5062 —>

<------------->
Really destroying SIP dialog ‘A05sY7WvhQgHybVHxLVE31wlyzzXeAdI’ Method: ACK

<— SIP read from UDP:208.65.240.44:5060 —>

<------------->

<— SIP read from UDP:192.168.1.201:60605 —>

<------------->

<— SIP read from UDP:192.168.1.201:60605 —>

<------------->
Reliably Transmitting (NAT) to 70.53.148.59:5062:
OPTIONS sip:[email protected]:5062 SIP/2.0
Via: SIP/2.0/UDP 70.51.11.220:5060;branch=z9hG4bK2bd23d90;rport
Max-Forwards: 70
From: “Unknown” sip:[email protected];tag=as56f95cfd
To: sip:[email protected]:5062
Contact: sip:[email protected]:5060
Call-ID: [email protected]:5060
CSeq: 102 OPTIONS
User-Agent: FPBX-2.10.1(10.5.0)
Date: Sun, 21 Apr 2013 21:03:05 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0


localhost*CLI> sip set debug off

Clearly the peer you are sending the call out on can’t authenticate you.

SIP/2.0 401 Unauthorized

That’s the response you are getting then FreePBX fails to next route destination.

I just tested, it does that with all my extensions…
in that case, is that a setting problem with my trunk?

I am worried about the unauthorized, not the declined. Declined is probably just CODEC’s or something else you have mismatched between your phones and Asterisk.

The unauthorized looks like it came from your provider.

You can narrow the debug by just debugging the provider peer.

i just did a debug on my trunk and there is no error whatsoever… all seems fine. It looks like it’s internal.

== Using SIP RTP TOS bits 184 == Using SIP RTP CoS mark 5 -- Executing [5148858443@from-internal:1] Macro("SIP/230-00000002", "user-callerid,LIMIT") in new stack -- Executing [s@macro-user-callerid:1] Set("SIP/230-00000002", "AMPUSER=230") in new stack -- Executing [s@macro-user-callerid:2] GotoIf("SIP/230-00000002", "0?report") in new stack -- Executing [s@macro-user-callerid:3] ExecIf("SIP/230-00000002", "1?Set(REALCALLERIDNUM=230)") in new stack -- Executing [s@macro-user-callerid:4] Set("SIP/230-00000002", "AMPUSER=230") in new stack -- Executing [s@macro-user-callerid:5] Set("SIP/230-00000002", "AMPUSERCIDNAME=Francine Maison") in new stack -- Executing [s@macro-user-callerid:6] GotoIf("SIP/230-00000002", "0?report") in new stack -- Executing [s@macro-user-callerid:7] Set("SIP/230-00000002", "AMPUSERCID=230") in new stack -- Executing [s@macro-user-callerid:8] Set("SIP/230-00000002", "CALLERID(all)="Francine Maison" <230>") in new stack -- Executing [s@macro-user-callerid:9] GotoIf("SIP/230-00000002", "0?limit") in new stack -- Executing [s@macro-user-callerid:10] ExecIf("SIP/230-00000002", "1?Set(GROUP(concurrency_limit)=230)") in new stack -- Executing [s@macro-user-callerid:11] ExecIf("SIP/230-00000002", "1?Set(CHANNEL(language)=fr)") in new stack -- Executing [s@macro-user-callerid:12] GosubIf("SIP/230-00000002", "7?sub-ccss,s,1(from-internal,5148858443)") in new stack -- Executing [s@sub-ccss:1] ExecIf("SIP/230-00000002", "0?Return()") in new stack -- Executing [s@sub-ccss:2] Set("SIP/230-00000002", "CCSS_SETUP=TRUE") in new stack -- Executing [s@sub-ccss:3] GosubIf("SIP/230-00000002", "0?monitor_config,1(from-internal,5148858443):monitor_default,1(from-internal,5148858443)") in new stack -- Executing [monitor_default@sub-ccss:1] GotoIf("SIP/230-00000002", "0?is_exten") in new stack -- Executing [monitor_default@sub-ccss:2] StackPop("SIP/230-00000002", "") in new stack -- Executing [monitor_default@sub-ccss:3] Return("SIP/230-00000002", "FALSE") in new stack -- Executing [s@macro-user-callerid:13] GotoIf("SIP/230-00000002", "1?continue") in new stack -- Goto (macro-user-callerid,s,26) -- Executing [s@macro-user-callerid:26] Set("SIP/230-00000002", "CALLERID(number)=230") in new stack -- Executing [s@macro-user-callerid:27] Set("SIP/230-00000002", "CALLERID(name)=Francine Maison") in new stack -- Executing [s@macro-user-callerid:28] Set("SIP/230-00000002", "CHANNEL(language)=fr") in new stack -- Executing [5148858443@from-internal:2] Set("SIP/230-00000002", "ROUTEUSER=230") in new stack -- Executing [5148858443@from-internal:3] GotoIf("SIP/230-00000002", "1?outbound-2-3,5148858443,2:outbound-allroutes,5148858443,2") in new stack -- Goto (outbound-2-3,5148858443,2)

<— SIP read from UDP:208.65.240.44:5060 —>

OK, an update over here:
since I run my asterisk server from a virtualbox, i decided to check if i could restart from a snapshot I took. All was great until i did the following:

•duplicated my trunk and changed the sip server for their alternate site
•enabled it after renaming it
•added the new trunk in the Trunk Sequence for Matched Routes under outbound routes.

Then i called and it failed. Doing the reverse operations do not work either, which is very very weird.
Seems like a bug to me…