Asterisk - CallManager via SIP Trunk

I’m working on getting our asterisk phone systems in Germany talking with our Cisco CallManagers in the US. I’ve configured a SIP trunk and the appropriate dial plan on the CMs and can place a call from the US to an extension on one of the asterisk servers in Germany. However, when I try to call one of the US extensions I get a fast busy and this is what is capture in the debug:

[code]am-pbx:~ # asterisk -r
Asterisk 1.2.9.1, Copyright © 1999 - 2006 Digium, Inc. and others.
Created by Mark Spencer markster@digium.com
Asterisk comes with ABSOLUTELY NO WARRANTY; type ‘show warranty’ for details.
This is free software, with components licensed under the GNU General Public
License version 2 and other licenses; you are welcome to redistribute it under
certain conditions. Type ‘show license’ for details.

Connected to Asterisk 1.2.9.1 currently running on am-pbx (pid = 29176)
Verbosity is at least 3
Apr 23 19:33:19 DEBUG[29188]: chan_sip.c:1401 __sip_ack: Stopping retransmission on ‘649c35642584baa004e799bd49710075@192.168.110.40’ of Request 102: Match Found
Apr 23 19:33:20 DEBUG[29188]: chan_sip.c:1401 __sip_ack: Stopping retransmission on ‘667132c94508e45f6f4ff7c96c9a10f5@192.168.110.40’ of Request 102: Match Found
Apr 23 19:33:25 DEBUG[29183]: chan_iax2.c:7170 socket_read: Peer lastms 15, historicms 15, maxms 2000
Apr 23 19:33:32 DEBUG[29188]: chan_sip.c:7242 check_user_full: Setting NAT on RTP to 524288
Apr 23 19:33:32 DEBUG[29188]: chan_sip.c:1401 __sip_ack: Stopping retransmission on ‘MjlkNWY4YzUxZjYwYzc3OGU5YzViMDliM2VlMGE1YzQ.’ of Response 1: Match Found
Apr 23 19:33:33 DEBUG[29188]: chan_sip.c:7242 check_user_full: Setting NAT on RTP to 524288
Apr 23 19:33:33 DEBUG[29188]: chan_sip.c:10497 handle_request_invite: Checking SIP call limits for device 697
Apr 23 19:33:33 DEBUG[29188]: chan_sip.c:6137 build_route: build_route: Contact hop: sip:697@172.20.1.22:54134
– Executing Macro(“SIP/697-85c5”, “dialout-callmanager|4877”) in new stack
– Executing ChanIsAvail(“SIP/697-85c5”, “SIP/cm2”) in new stack
Apr 23 19:33:33 DEBUG[15301]: chan_sip.c:1874 create_addr_from_peer: Setting NAT on RTP to 0
Apr 23 19:33:33 DEBUG[15301]: chan_sip.c:2426 sip_hangup: update_call_counter() - decrement call limit counter
– Executing Cut(“SIP/697-85c5”, “AVAILCHAN=AVAILCHAN||1”) in new stack
– Executing NoOp(“SIP/697-85c5”, “CCM Dialing 4877”) in new stack
– Executing Dial(“SIP/697-85c5”, “SIP/cm2/4877”) in new stack
Apr 23 19:33:33 DEBUG[15301]: chan_sip.c:1874 create_addr_from_peer: Setting NAT on RTP to 0
Apr 23 19:33:33 DEBUG[15301]: chan_sip.c:2068 sip_call: Outgoing Call for 4877
– Called cm2/4877
Apr 23 19:33:33 DEBUG[29188]: chan_sip.c:1454 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on ‘6c3af3427d3ecb697cf922536e4a6cbc@192.168.110.40’ Request 102: Found
Apr 23 19:33:33 DEBUG[29188]: chan_sip.c:1379 __sip_ack: Acked pending invite 102
Apr 23 19:33:33 DEBUG[29188]: chan_sip.c:1401 __sip_ack: Stopping retransmission on ‘6c3af3427d3ecb697cf922536e4a6cbc@192.168.110.40’ of Request 102: Match Found
– SIP/cm2-0239 is circuit-busy
Apr 23 19:33:33 DEBUG[15301]: chan_sip.c:2426 sip_hangup: update_call_counter(4877) - decrement call limit counter
== Everyone is busy/congested at this time (1:0/1/0)
Apr 23 19:33:33 DEBUG[15301]: app_dial.c:1619 dial_exec_full: Exiting with DIALSTATUS=CONGESTION.
– Executing Hangup(“SIP/697-85c5”, “”) in new stack
== Spawn extension (macro-dialout-callmanager, s, 5) exited non-zero on ‘SIP/697-85c5’ in macro ‘dialout-callmanager’
== Spawn extension (macro-dialout-callmanager, s, 5) exited non-zero on 'SIP/697-85c5’
Apr 23 19:33:33 DEBUG[15301]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '“D. Cameron” <697>'
Apr 23 19:33:33 DEBUG[15301]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '697’
Apr 23 19:33:33 DEBUG[15301]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '4877’
Apr 23 19:33:33 DEBUG[15301]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'sip_desks’
Apr 23 19:33:33 DEBUG[15301]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'SIP/697-85c5’
Apr 23 19:33:33 DEBUG[15301]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'SIP/cm2-0239’
Apr 23 19:33:33 DEBUG[15301]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'Hangup’
Apr 23 19:33:33 DEBUG[15301]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '(null)'
Apr 23 19:33:33 DEBUG[15301]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2007-04-23 19:33:33’
Apr 23 19:33:33 DEBUG[15301]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '(null)'
Apr 23 19:33:33 DEBUG[15301]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2007-04-23 19:33:33’
Apr 23 19:33:33 DEBUG[15301]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '0’
Apr 23 19:33:33 DEBUG[15301]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '0’
Apr 23 19:33:33 DEBUG[15301]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'FAILED’
Apr 23 19:33:33 DEBUG[15301]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION’
Apr 23 19:33:33 DEBUG[15301]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '(null)'
Apr 23 19:33:33 DEBUG[15301]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '1177349613.749’
Apr 23 19:33:33 DEBUG[15301]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '(null)'
Apr 23 19:33:33 DEBUG[15301]: chan_sip.c:2426 sip_hangup: update_call_counter(697) - decrement call limit counter
Apr 23 19:33:33 DEBUG[29188]: chan_sip.c:1401 __sip_ack: Stopping retransmission on ‘MjlkNWY4YzUxZjYwYzc3OGU5YzViMDliM2VlMGE1YzQ.’ of Response 2: Match Found
Apr 23 19:33:44 DEBUG[29188]: chan_sip.c:7242 check_user_full: Setting NAT on RTP to 0
Apr 23 19:33:44 DEBUG[29188]: chan_sip.c:10497 handle_request_invite: Checking SIP call limits for device
Apr 23 19:33:44 DEBUG[29188]: chan_sip.c:6137 build_route: build_route: Contact hop: sip:4877@172.20.6.11:5060
– Executing Dial(“SIP/172.20.6.11-08287308”, “|600|Ttr”) in new stack
Apr 23 19:33:44 WARNING[15306]: app_dial.c:803 dial_exec_full: Dial requires an argument (technology/number)
== Spawn extension (from_us, 697, 1) exited non-zero on 'SIP/172.20.6.11-08287308’
Apr 23 19:33:44 DEBUG[15306]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '“Don Cameron” <4877>'
Apr 23 19:33:44 DEBUG[15306]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '4877’
Apr 23 19:33:44 DEBUG[15306]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '697’
Apr 23 19:33:44 DEBUG[15306]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'from_us’
Apr 23 19:33:44 DEBUG[15306]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'SIP/172.20.6.11-08287308’
Apr 23 19:33:44 DEBUG[15306]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '(null)'
Apr 23 19:33:44 DEBUG[15306]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'Dial’
Apr 23 19:33:44 DEBUG[15306]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '|600|Ttr’
Apr 23 19:33:44 DEBUG[15306]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2007-04-23 19:33:44’
Apr 23 19:33:44 DEBUG[15306]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '(null)'
Apr 23 19:33:44 DEBUG[15306]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2007-04-23 19:33:44’
Apr 23 19:33:44 DEBUG[15306]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '0’
Apr 23 19:33:44 DEBUG[15306]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '0’
Apr 23 19:33:44 DEBUG[15306]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'NO ANSWER’
Apr 23 19:33:44 DEBUG[15306]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION’
Apr 23 19:33:44 DEBUG[15306]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '(null)'
Apr 23 19:33:44 DEBUG[15306]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '1177349624.752’
Apr 23 19:33:44 DEBUG[15306]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '(null)'
Apr 23 19:33:44 DEBUG[15306]: chan_sip.c:2426 sip_hangup: update_call_counter() - decrement call limit counter
Apr 23 19:33:44 DEBUG[29188]: chan_sip.c:1401 __sip_ack: Stopping retransmission on ‘c76f9180-1dd10fc3-32f7-b0614ac@172.20.6.11’ of Response 101: Match Found
am-pbx*CLI>
[/code]

I’m new to Asterisk (the systems in Germany came as part of an acquisition) so I followed the instructions at voip-info.org and ended up making the following changes to sip.conf:

[cm1]
type=friend
context=incoming
host=172.20.6.10
disallow=all
allow=ulaw
allow=alaw
nat=no
canreinvite=yes
qualify=yes

[cm2]
type=friend
context=incoming
host=172.20.6.11
disallow=all
allow=ulaw
allow=alaw
nat=no
canreinvite=yes
qualify=yes

and extensions.conf:

[macro-dialout-callmanager]

exten => s,1,ChanIsAvail(SIP/cm1&SIP/cm2)
exten => s,2,Cut(AVAILCHAN=AVAILCHAN,,1)
exten => s,3,Dial(${AVAILCHAN}/${ARG1})
exten => s,4,Hangup
exten => s,102,Congestion

[outgoing]

exten => _[234]XXX,1,Macro(dialout-callmanager,${EXTEN})
exten => i,1,Congestion

Any ideas on what the problem may be or where I should start looking?

Thanks!

Well, i see one warning line:

Apr 23 19:33:44 WARNING[15306]: app_dial.c:803 dial_exec_full: Dial requires an argument (technology/number)

and corresponding dial:

Dial(“SIP/697-85c5”, “SIP/cm2/4877”)

So, what you should use instead is

Dial(SIP/4887@cm2)

So should I change it to

exten => s,1,Dial(SIP/${ARG1}@cm2)
exten => s,2,Hangup
exten => 2,102,Congestion

If that’s the case how should I write the macro to try one CallManager and if it’s not available try the other (sorry for all the questions … I’m still learning Asterisk)?

Ended up changing the macro to

[macro-dialout-callmanager]
exten => s,1,Dial(SIP/${ARG1}@cm1)
exten => s,1,Dial(SIP/${ARG1}@cm2)
exten => s,2,Hangup
exten => s,102,Congestion 

and setting the Calling Search Space in CallManager to internal on the SIP trunk config and it worked. Whoohoo!

Last question: Can I safely assume that if CM1 is unavailable then the macro above will then try CM2? If not, is there a better way to write that macro?

Go ahead with your macro,no proble