Calls to local extensions fail

I have a fresh install of asterisknow 1.7.1 and got as far as getting cisco 7960 sip phones on the local network in place. I can see them when I run sip show peers.

But for some reason (and I know its going to be something trivial) I cant get extension A to call extension B! Here is the dump from the command line.

Any pointers would be appreciated.

localhostCLI> sip show peers
Name/username Host Dyn Nat ACL Port Status
110101 10.101.2.110 A 5060 OK (90 ms)
110102 10.101.2.111 A 5060 OK (93 ms)
SIP_OUT2_SBC/userid 10.101.0.2 5060 Unmonitored
3 sip peers [Monitored: 2 online, 0 offline Unmonitored: 1 online, 0 offline]
localhost
CLI>
localhostCLI>
localhost
CLI>
localhostCLI>
localhost
CLI>
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
– Executing [[email protected]:1] Macro(“SIP/110102-0000000c”, “user-callerid,SKIPTTL,”) in new stack
– Executing [[email protected]:1] Set(“SIP/110102-0000000c”, “AMPUSER=110102”) in new stack
– Executing [[email protected]:2] GotoIf(“SIP/110102-0000000c”, “0?report”) in new stack
– Executing [[email protected]:3] ExecIf(“SIP/110102-0000000c”, “1?Set(REALCALLERIDNUM=110102)”) in new stack
– Executing [[email protected]:4] Set(“SIP/110102-0000000c”, “AMPUSER=110102”) in new stack
– Executing [[email protected]:5] Set(“SIP/110102-0000000c”, “AMPUSERCIDNAME=110102”) in new stack
– Executing [[email protected]:6] GotoIf(“SIP/110102-0000000c”, “0?report”) in new stack
– Executing [[email protected]:7] Set(“SIP/110102-0000000c”, “AMPUSERCID=110102”) in new stack
– Executing [[email protected]:8] Set(“SIP/110102-0000000c”, “CALLERID(all)=“110102” <110102>”) in new stack
– Executing [[email protected]:9] GotoIf(“SIP/110102-0000000c”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,18)
– Executing [[email protected]:18] NoOp(“SIP/110102-0000000c”, “Using CallerID “110102” <110102>”) in new stack
– Executing [[email protected]:2] Set(“SIP/110102-0000000c”, “_NODEST=”) in new stack
– Executing [[email protected]:3] Macro(“SIP/110102-0000000c”, “record-enable,110102,OUT,”) in new stack
– Executing [[email protected]:1] GotoIf(“SIP/110102-0000000c”, “1?check”) in new stack
– Goto (macro-record-enable,s,4)
– Executing [[email protected]:4] ExecIf(“SIP/110102-0000000c”, “0?MacroExit()”) in new stack
– Executing [[email protected]:5] GotoIf(“SIP/110102-0000000c”, “0?Group:OUT”) in new stack
– Goto (macro-record-enable,s,16)
– Executing [[email protected]:16] GotoIf(“SIP/110102-0000000c”, “0?IN”) in new stack
– Executing [[email protected]:17] ExecIf(“SIP/110102-0000000c”, “1?MacroExit()”) in new stack
– Executing [[email protected]:4] Macro(“SIP/110102-0000000c”, “dialout-trunk,2,110121,”) in new stack
– Executing [[email protected]:1] Set(“SIP/110102-0000000c”, “DIAL_TRUNK=2”) in new stack
– Executing [[email protected]:2] GosubIf(“SIP/110102-0000000c”, “0?sub-pincheck,s,1”) in new stack
– Executing [[email protected]:3] GotoIf(“SIP/110102-0000000c”, “0?disabletrunk,1”) in new stack
– Executing [[email protected]:4] Set(“SIP/110102-0000000c”, “DIAL_NUMBER=110121”) in new stack
– Executing [[email protected]:5] Set(“SIP/110102-0000000c”, “DIAL_TRUNK_OPTIONS=tr”) in new stack
– Executing [[email protected]:6] Set(“SIP/110102-0000000c”, “OUTBOUND_GROUP=OUT_2”) in new stack
– Executing [[email protected]:7] GotoIf(“SIP/110102-0000000c”, “1?nomax”) in new stack
– Goto (macro-dialout-trunk,s,9)
– Executing [[email protected]:9] GotoIf(“SIP/110102-0000000c”, “0?skipoutcid”) in new stack
– Executing [[email protected]:10] Set(“SIP/110102-0000000c”, “DIAL_TRUNK_OPTIONS=”) in new stack
– Executing [[email protected]:11] Macro(“SIP/110102-0000000c”, “outbound-callerid,2”) in new stack
– Executing [[email protected]:1] ExecIf(“SIP/110102-0000000c”, “0?Set(CALLERPRES()=)”) in new stack
– Executing [[email protected]:2] ExecIf(“SIP/110102-0000000c”, “0?Set(REALCALLERIDNUM=110102)”) in new stack
– Executing [[email protected]:3] GotoIf(“SIP/110102-0000000c”, “1?normcid”) in new stack
– Goto (macro-outbound-callerid,s,6)
– Executing [[email protected]cro-outbound-callerid:6] Set(“SIP/110102-0000000c”, “USEROUTCID=”) in new stack
– Executing [[email protected]:7] Set(“SIP/110102-0000000c”, “EMERGENCYCID=”) in new stack
– Executing [[email protected]:8] Set(“SIP/110102-0000000c”, “TRUNKOUTCID=”) in new stack
– Executing [[email protected]:9] GotoIf(“SIP/110102-0000000c”, “1?trunkcid”) in new stack
– Goto (macro-outbound-callerid,s,12)
– Executing [[email protected]:12] ExecIf(“SIP/110102-0000000c”, “0?Set(CALLERID(all)=)”) in new stack
– Executing [[email protected]:13] ExecIf(“SIP/110102-0000000c”, “0?Set(CALLERID(all)=)”) in new stack
– Executing [[email protected]:14] ExecIf(“SIP/110102-0000000c”, “0?Set(CALLERID(all)=)”) in new stack
– Executing [[email protected]:15] ExecIf(“SIP/110102-0000000c”, “0?Set(CALLERPRES()=prohib_passed_screen)”) in new stack
– Executing [[email protected]:12] ExecIf(“SIP/110102-0000000c”, “0?AGI(fixlocalprefix)”) in new stack
– Executing [[email protected]:13] Set(“SIP/110102-0000000c”, “OUTNUM=110121”) in new stack
– Executing [[email protected]:14] Set(“SIP/110102-0000000c”, “custom=SIP/SIP_OUT2_SBC”) in new stack
– Executing [[email protected]:15] ExecIf(“SIP/110102-0000000c”, “0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^))”) in new stack
– Executing [[email protected]:16] Macro(“SIP/110102-0000000c”, “dialout-trunk-predial-hook,”) in new stack
– Executing [[email protected]:1] MacroExit(“SIP/110102-0000000c”, “”) in new stack
– Executing [[email protected]:17] GotoIf(“SIP/110102-0000000c”, “0?bypass,1”) in new stack
– Executing [[email protected]:18] GotoIf(“SIP/110102-0000000c”, “0?customtrunk”) in new stack
– Executing [[email protected]:19] Dial(“SIP/110102-0000000c”, “SIP/SIP_OUT2_SBC/110121,300,”) in new stack
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
– Called SIP_OUT2_SBC/110121
– SIP/SIP_OUT2_SBC-0000000d is circuit-busy
== Everyone is busy/congested at this time (1:0/1/0)
– Executing [[email protected]:20] NoOp(“SIP/110102-0000000c”, “Dial failed for some reason with DIALSTATUS = CONGESTION and HANGUPCAUSE = 127”) in new stack
– Executing [[email protected]:21] Goto(“SIP/110102-0000000c”, “s-CONGESTION,1”) in new stack
– Goto (macro-dialout-trunk,s-CONGESTION,1)
– Executing [[email protected]:1] Set(“SIP/110102-0000000c”, “RC=127”) in new stack
– Executing [[email protected]:2] Goto(“SIP/110102-0000000c”, “127,1”) in new stack
– Goto (macro-dialout-trunk,127,1)
– Executing [[email protected]:1] Goto(“SIP/110102-0000000c”, “continue,1”) in new stack
– Goto (macro-dialout-trunk,continue,1)
– Executing [[email protected]:1] GotoIf(“SIP/110102-0000000c”, “1?noreport”) in new stack
– Goto (macro-dialout-trunk,continue,3)
– Executing [[email protected]:3] NoOp(“SIP/110102-0000000c”, “TRUNK Dial failed due to CONGESTION HANGUPCAUSE: 127 - failing through to other trunks”) in new stack
– Executing [[email protected]:5] Macro(“SIP/110102-0000000c”, “outisbusy,”) in new stack
– Executing [[email protected]:1] Progress(“SIP/110102-0000000c”, “”) in new stack
– Executing [[email protected]:2] Playback(“SIP/110102-0000000c”, “all-circuits-busy-now,noanswer”) in new stack
– <SIP/110102-0000000c> Playing ‘all-circuits-busy-now.gsm’ (language ‘en’)
– Executing [[email protected]:3] Playback(“SIP/110102-0000000c”, “pls-try-call-later,noanswer”) in new stack
– <SIP/110102-0000000c> Playing ‘pls-try-call-later.gsm’ (language ‘en’)
– Executing [[email protected]:4] Macro(“SIP/110102-0000000c”, “hangupcall”) in new stack
– Executing [[email protected]:1] GotoIf(“SIP/110102-0000000c”, “1?skiprg”) in new stack
– Goto (macro-hangupcall,s,4)
– Executing [[email protected]:4] GotoIf(“SIP/110102-0000000c”, “1?skipblkvm”) in new stack
– Goto (macro-hangupcall,s,7)
– Executing [[email protected]:7] GotoIf(“SIP/110102-0000000c”, “1?theend”) in new stack
– Goto (macro-hangupcall,s,9)
– Executing [[email protected]:9] Hangup(“SIP/110102-0000000c”, “”) in new stack
== Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘SIP/110102-0000000c’ in macro ‘hangupcall’
== Spawn extension (macro-outisbusy, s, 4) exited non-zero on ‘SIP/110102-0000000c’ in macro ‘outisbusy’
== Spawn extension (from-internal, 8110121, 5) exited non-zero on ‘SIP/110102-0000000c’
– Executing [[email protected]:1] Macro(“SIP/110102-0000000c”, “hangupcall”) in new stack
– Executing [[email protected]:1] GotoIf(“SIP/110102-0000000c”, “1?skiprg”) in new stack
– Goto (macro-hangupcall,s,4)
– Executing [[email protected]:4] GotoIf(“SIP/110102-0000000c”, “1?skipblkvm”) in new stack
– Goto (macro-hangupcall,s,7)
– Executing [[email protected]:7] GotoIf(“SIP/110102-0000000c”, “1?theend”) in new stack
– Goto (macro-hangupcall,s,9)
– Executing [[email protected]:9] Hangup(“SIP/110102-0000000c”, “”) in new stack
== Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘SIP/110102-0000000c’ in macro ‘hangupcall’
== Spawn extension (from-internal, h, 1) exited non-zero on ‘SIP/110102-0000000c’

I can confirm that the issue was with the new SIP (CUCM -callmanager 7.1) phone image thats causing the problem. Issue was resolved when I reverted to a using an old phone that has as SIP image from an earlier version of CUCM.

Make sure that the extension has nat set to no.

Thanks guys. I am headed in the direction your have suggested and trying to confirm that the phones have actually registered. Surprisingly the “sip show peers” shows me the two phones I have. So to reconfirm this I added a softphone and as usual the sip show peers lists the three phones.

What is surprising is that I can now make calls from the two cisco 7960s to the softphone but the reverse does not work. This I believe points to the 7969s not being registered with asterisk. But then how come dialling *56 from the phone makes asterisk tell me the extension number of the phone? Could the phones be partly registered?

I found another thread (http://www.freepbx.org/forum/freepbx/users/cisco-7960-7940-sip-fails-to-register-401-403) which seems to suggest that there is a problem with using 7960s with asterisk 1.6.1. But this one (http://minded.ca/2009-12-16/configure-cisco-ip-phones-with-asterisk/) seems to give me some hope. Not sure if thats a show stopper but I hope to be able to investigate this a bit more across the next few days and update ASAP.

Thanks for all the helpful suggestions.

Another way to check for registration:

From Astersk CLI.

sip show peers

Circuit busy. Are you sure the two extensions are registered? If you can run wireshark in your envrionment and reboot the phones and see the registration sent from the phone to asterisk

You are dialing 8110121 instead of 110101

Thanks for pointing that out but that was not the correct trace :-((

Actually that was what I dialled at the very end (out of frustration)… a set of random numbers. And I made things worse by pasting the wrong trace out there. That was a me - foot in the mouth!!

Since querying the forum I have deleted and rebuild the extension. Created inbound routes and the phones show up when I run - sip show peers AND hit the same problem.

I have gathered a new set of traces and hope that this time you will be abel to nail it to more than error between chair and keyboard.

[[email protected] asterisk]# asterisk -r
Asterisk 1.6.2.11, Copyright © 1999 - 2010 Digium, Inc. and others.
Created by Mark Spencer [email protected]
Asterisk comes with ABSOLUTELY NO WARRANTY; type ‘core 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 ‘core show license’ for details.

Connected to Asterisk 1.6.2.11 currently running on localhost (pid = 2655)
Verbosity is at least 100
localhostCLI>
localhost
CLI>
localhostCLI>
localhost
CLI>
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
– Executing [[email protected]:1] Macro(“SIP/110102-0000004f”, “exten-vm,novm,110101”) in new stack
– Executing [[email protected]:1] Macro(“SIP/110102-0000004f”, “user-callerid,”) in new stack
– Executing [[email protected]:1] Set(“SIP/110102-0000004f”, “AMPUSER=110102”) in new stack
– Executing [[email protected]:2] GotoIf(“SIP/110102-0000004f”, “0?report”) in new stack
– Executing [[email protected]:3] ExecIf(“SIP/110102-0000004f”, “1?Set(REALCALLERIDNUM=110102)”) in new stack
– Executing [[email protected]:4] Set(“SIP/110102-0000004f”, “AMPUSER=110102”) in new stack
– Executing [[email protected]:5] Set(“SIP/110102-0000004f”, “AMPUSERCIDNAME=110102”) in new stack
– Executing [[email protected]:6] GotoIf(“SIP/110102-0000004f”, “0?report”) in new stack
– Executing [[email protected]:7] Set(“SIP/110102-0000004f”, “AMPUSERCID=110102”) in new stack
– Executing [[email protected]:8] Set(“SIP/110102-0000004f”, “CALLERID(all)=“110102” <110102>”) in new stack
– Executing [[email protected]:9] GotoIf(“SIP/110102-0000004f”, “0?continue”) in new stack
– Executing [[email protected]:10] Set(“SIP/110102-0000004f”, “__TTL=64”) in new stack
– Executing [[email protected]:11] GotoIf(“SIP/110102-0000004f”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,18)
– Executing [[email protected]:18] NoOp(“SIP/110102-0000004f”, “Using CallerID “110102” <110102>”) in new stack
– Executing [[email protected]:2] Set(“SIP/110102-0000004f”, “RingGroupMethod=none”) in new stack
– Executing [[email protected]:3] Set(“SIP/110102-0000004f”, “VMBOX=novm”) in new stack
– Executing [[email protected]:4] Set(“SIP/110102-0000004f”, “EXTTOCALL=110101”) in new stack
– Executing [[email protected]:5] Set(“SIP/110102-0000004f”, “CFUEXT=”) in new stack
– Executing [[email protected]:6] Set(“SIP/110102-0000004f”, “CFBEXT=”) in new stack
– Executing [[email protected]:7] Set(“SIP/110102-0000004f”, “RT=”"") in new stack
– Executing [[email protected]:8] Macro(“SIP/110102-0000004f”, “record-enable,110101,IN”) in new stack
– Executing [[email protected]:1] GotoIf(“SIP/110102-0000004f”, “1?check”) in new stack
– Goto (macro-record-enable,s,4)
– Executing [[email protected]:4] ExecIf(“SIP/110102-0000004f”, “0?MacroExit()”) in new stack
– Executing [[email protected]:5] GotoIf(“SIP/110102-0000004f”, “0?Group:OUT”) in new stack
– Goto (macro-record-enable,s,16)
– Executing [[email protected]:16] GotoIf(“SIP/110102-0000004f”, “1?IN”) in new stack
– Goto (macro-record-enable,s,21)
– Executing [[email protected]:21] ExecIf(“SIP/110102-0000004f”, “1?MacroExit()”) in new stack
– Executing [[email protected]:9] Macro(“SIP/110102-0000004f”, “dial,tr,110101”) in new stack
– Executing [[email protected]:1] GotoIf(“SIP/110102-0000004f”, “1?dial”) in new stack
– Goto (macro-dial,s,3)
– Executing [[email protected]:3] AGI(“SIP/110102-0000004f”, “dialparties.agi”) in new stack
– Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
dialparties.agi: Starting New Dialparties.agi
dialparties.agi: Caller ID name is ‘110102’ number is ‘110102’
> dialparties.agi: USE_CONFIRMATION: ‘FALSE’
> dialparties.agi: RINGGROUP_INDEX: ''
dialparties.agi: Methodology of ring is ‘none’
– dialparties.agi: Added extension 110101 to extension map
– dialparties.agi: Extension 110101 cf is disabled
– dialparties.agi: Extension 110101 do not disturb is disabled
> dialparties.agi: extnum 110101 has: cw: 1; hascfb: 0 [] hascfu: 0 []
dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
– dialparties.agi: dbset CALLTRACE/110101 to 110102
– dialparties.agi: Filtered ARG3: 110101
– <SIP/110102-0000004f>AGI Script dialparties.agi completed, returning 0
– Executing [[email protected]:7] Dial(“SIP/110102-0000004f”, “SIP/110101,tr”) in new stack
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
– Called 110101
– SIP/110101-00000050 is circuit-busy
== Everyone is busy/congested at this time (1:0/1/0)
– Executing [[email protected]:8] Set(“SIP/110102-0000004f”, “DIALSTATUS=CONGESTION”) in new stack
– Executing [[email protected]:9] GosubIf(“SIP/110102-0000004f”, “0?CONGESTION,1”) in new stack
– Executing [[email protected]:10] GotoIf(“SIP/110102-0000004f”, “0?exit,return”) in new stack
– Executing [[email protected]:11] Set(“SIP/110102-0000004f”, “SV_DIALSTATUS=CONGESTION”) in new stack
– Executing [[email protected]:12] GosubIf(“SIP/110102-0000004f”, “0?docfu,1”) in new stack
– Executing [[email protected]:13] GosubIf(“SIP/110102-0000004f”, “0?docfb,1”) in new stack
– Executing [[email protected]:14] Set(“SIP/110102-0000004f”, “DIALSTATUS=CONGESTION”) in new stack
– Executing [[email protected]:15] NoOp(“SIP/110102-0000004f”, “Voicemail is ‘novm’”) in new stack
– Executing [[email protected]:16] GotoIf(“SIP/110102-0000004f”, “1?s-CONGESTION,1”) in new stack
– Goto (macro-exten-vm,s-CONGESTION,1)
– Executing [[email protected]:1] NoOp(“SIP/110102-0000004f”, "IVR_RETVM: IVR_CONTEXT: ") in new stack
– Executing [[email protected]:2] GotoIf(“SIP/110102-0000004f”, “0?exit,1”) in new stack
– Executing [[email protected]:3] PlayTones(“SIP/110102-0000004f”, “congestion”) in new stack
– Executing [[email protected]:4] Congestion(“SIP/110102-0000004f”, “10”) in new stack
== Spawn extension (macro-exten-vm, s-CONGESTION, 4) exited non-zero on ‘SIP/110102-0000004f’ in macro ‘exten-vm’
== Spawn extension (from-internal, 110101, 1) exited non-zero on ‘SIP/110102-0000004f’
– Executing [[email protected]:1] Macro(“SIP/110102-0000004f”, “hangupcall”) in new stack
– Executing [[email protected]:1] GotoIf(“SIP/110102-0000004f”, “1?skiprg”) in new stack
– Goto (macro-hangupcall,s,4)
– Executing [[email protected]:4] GotoIf(“SIP/110102-0000004f”, “1?skipblkvm”) in new stack
– Goto (macro-hangupcall,s,7)
– Executing [[email protected]:7] GotoIf(“SIP/110102-0000004f”, “1?theend”) in new stack
– Goto (macro-hangupcall,s,9)
– Executing [[email protected]:9] Hangup(“SIP/110102-0000004f”, “”) in new stack
== Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘SIP/110102-0000004f’ in macro ‘hangupcall’
== Spawn extension (from-internal, h, 1) exited non-zero on ‘SIP/110102-0000004f’

Thanks again for your time.