Asterisk Incoming Calls Don't Route to Extensions

Question

We have just setup Asterisk 1.6 with FreePBX 2.8.

We configured SIP Trunks with our Polish SIP Provider (a total of 3 trunks) in the system. Using a softphone registered to the only extension in the system we are able to make calls out. However, calls in do not seem to route to the extension. When voicemail is configured for the extension the call obviously connects because the PBX plays the voicemail greeting. However, even when the softphone is registered the call is not routed to the softphone, it always routes to voicemail.

Any ideas why?

Brent

Asterisk -r Output:

Connected to Asterisk 1.6.2.17.2 currently running on asterisk (pid = 1286)
Verbosity is at least 3
  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
    -- Executing [kkkk001@from-pstn:1] NoOp("SIP/SIP 1-00000003", "Catch-All DID Match - Found kkkk001 - You probably want a DID for this.") in new stack
    -- Executing [kkkk001@from-pstn:2] Goto("SIP/SIP 1-00000003", "ext-did,s,1") in new stack
    -- Goto (ext-did,s,1)
    -- Executing [s@ext-did:1] Set("SIP/SIP 1-00000003", "__FROM_DID=s") in new stack
    -- Executing [s@ext-did:2] ExecIf("SIP/SIP 1-00000003", "0 ?Set(CALLERID(name)=609046099)") in new stack
    -- Executing [s@ext-did:3] SetMusicOnHold("SIP/SIP 1-00000003", "moh") in new stack
    -- Executing [s@ext-did:4] Set("SIP/SIP 1-00000003", "__MOHCLASS=moh") in new stack
    -- Executing [s@ext-did:5] Set("SIP/SIP 1-00000003", "__CALLINGPRES_SV=allowed_not_screened") in new stack
    -- Executing [s@ext-did:6] Set("SIP/SIP 1-00000003", "CALLERPRES()=allowed_not_screened") in new stack
    -- Executing [s@ext-did:7] Goto("SIP/SIP 1-00000003", "from-did-direct,1001,1") in new stack
    -- Goto (from-did-direct,1001,1)
    -- Executing [1001@from-did-direct:1] Macro("SIP/SIP 1-00000003", "exten-vm,1001,1001") in new stack
    -- Executing [s@macro-exten-vm:1] Macro("SIP/SIP 1-00000003", "user-callerid,") in new stack
    -- Executing [s@macro-user-callerid:1] Set("SIP/SIP 1-00000003", "AMPUSER=609046099") in new stack
    -- Executing [s@macro-user-callerid:2] GotoIf("SIP/SIP 1-00000003", "0?report") in new stack
    -- Executing [s@macro-user-callerid:3] ExecIf("SIP/SIP 1-00000003", "1?Set(REALCALLERIDNUM=609046099)") in new stack
    -- Executing [s@macro-user-callerid:4] Set("SIP/SIP 1-00000003", "AMPUSER=") in new stack
    -- Executing [s@macro-user-callerid:5] Set("SIP/SIP 1-00000003", "AMPUSERCIDNAME=") in new stack
    -- Executing [s@macro-user-callerid:6] GotoIf("SIP/SIP 1-00000003", "1?report") in new stack
    -- Goto (macro-user-callerid,s,9)
    -- Executing [s@macro-user-callerid:9] GotoIf("SIP/SIP 1-00000003", "0?continue") in new stack
    -- Executing [s@macro-user-callerid:10] Set("SIP/SIP 1-00000003", "__TTL=64") in new stack
    -- Executing [s@macro-user-callerid:11] GotoIf("SIP/SIP 1-00000003", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,18)
    -- Executing [s@macro-user-callerid:18] Set("SIP/SIP 1-00000003", "CALLERID(number)=609046099") in new stack
    -- Executing [s@macro-user-callerid:19] Set("SIP/SIP 1-00000003", "CALLERID(name)=609046099") in new stack
    -- Executing [s@macro-user-callerid:20] NoOp("SIP/SIP 1-00000003", "Using CallerID "609046099" <609046099>") in new stack
    -- Executing [s@macro-exten-vm:2] Set("SIP/SIP 1-00000003", "RingGroupMethod=none") in new stack
    -- Executing [s@macro-exten-vm:3] Set("SIP/SIP 1-00000003", "VMBOX=1001") in new stack
    -- Executing [s@macro-exten-vm:4] Set("SIP/SIP 1-00000003", "__EXTTOCALL=1001") in new stack
    -- Executing [s@macro-exten-vm:5] Set("SIP/SIP 1-00000003", "CFUEXT=") in new stack
    -- Executing [s@macro-exten-vm:6] Set("SIP/SIP 1-00000003", "CFBEXT=") in new stack
    -- Executing [s@macro-exten-vm:7] Set("SIP/SIP 1-00000003", "RT=15") in new stack
    -- Executing [s@macro-exten-vm:8] Macro("SIP/SIP 1-00000003", "record-enable,1001,IN") in new stack
    -- Executing [s@macro-record-enable:1] GotoIf("SIP/SIP 1-00000003", "1?check") in new stack
    -- Goto (macro-record-enable,s,4)
    -- Executing [s@macro-record-enable:4] ExecIf("SIP/SIP 1-00000003", "0?MacroExit()") in new stack
    -- Executing [s@macro-record-enable:5] GotoIf("SIP/SIP 1-00000003", "0?Group:OUT") in new stack
    -- Goto (macro-record-enable,s,15)
    -- Executing [s@macro-record-enable:15] GotoIf("SIP/SIP 1-00000003", "1?IN") in new stack
    -- Goto (macro-record-enable,s,20)
    -- Executing [s@macro-record-enable:20] ExecIf("SIP/SIP 1-00000003", "1?MacroExit()") in new stack
    -- Executing [s@macro-exten-vm:9] Macro("SIP/SIP 1-00000003", "dial-one,15,tr,1001") in new stack
    -- Executing [s@macro-dial-one:1] Set("SIP/SIP 1-00000003", "DEXTEN=1001") in new stack
    -- Executing [s@macro-dial-one:2] Set("SIP/SIP 1-00000003", "DIALSTATUS_CW=") in new stack
    -- Executing [s@macro-dial-one:3] GosubIf("SIP/SIP 1-00000003", "0?screen,1") in new stack
    -- Executing [s@macro-dial-one:4] GosubIf("SIP/SIP 1-00000003", "0?cf,1") in new stack
    -- Executing [s@macro-dial-one:5] GotoIf("SIP/SIP 1-00000003", "1?skip1") in new stack
    -- Goto (macro-dial-one,s,8)
    -- Executing [s@macro-dial-one:8] GotoIf("SIP/SIP 1-00000003", "0?nodial") in new stack
    -- Executing [s@macro-dial-one:9] GotoIf("SIP/SIP 1-00000003", "0?continue") in new stack
    -- Executing [s@macro-dial-one:10] Set("SIP/SIP 1-00000003", "EXTHASCW=ENABLED") in new stack
    -- Executing [s@macro-dial-one:11] GotoIf("SIP/SIP 1-00000003", "0?next1:cwinusebusy") in new stack
    -- Goto (macro-dial-one,s,23)
    -- Executing [s@macro-dial-one:23] GotoIf("SIP/SIP 1-00000003", "1?next3:continue") in new stack
    -- Goto (macro-dial-one,s,24)
    -- Executing [s@macro-dial-one:24] ExecIf("SIP/SIP 1-00000003", "0?Set(DIALSTATUS_CW=BUSY)") in new stack
    -- Executing [s@macro-dial-one:25] GotoIf("SIP/SIP 1-00000003", "0?nodial") in new stack
    -- Executing [s@macro-dial-one:26] GosubIf("SIP/SIP 1-00000003", "1?dstring,1:dlocal,1") in new stack
    -- Executing [dstring@macro-dial-one:1] Set("SIP/SIP 1-00000003", "DSTRING=") in new stack
    -- Executing [dstring@macro-dial-one:2] Set("SIP/SIP 1-00000003", "DEVICES=1001") in new stack
    -- Executing [dstring@macro-dial-one:3] ExecIf("SIP/SIP 1-00000003", "0?Return()") in new stack
    -- Executing [dstring@macro-dial-one:4] ExecIf("SIP/SIP 1-00000003", "0?Set(DEVICES=001)") in new stack
    -- Executing [dstring@macro-dial-one:5] Set("SIP/SIP 1-00000003", "LOOPCNT=1") in new stack
    -- Executing [dstring@macro-dial-one:6] Set("SIP/SIP 1-00000003", "ITER=1") in new stack
    -- Executing [dstring@macro-dial-one:7] Set("SIP/SIP 1-00000003", "THISDIAL=SIP/1001") in new stack
    -- Executing [dstring@macro-dial-one:8] GosubIf("SIP/SIP 1-00000003", "1?zap2dahdi,1") in new stack
    -- Executing [zap2dahdi@macro-dial-one:1] ExecIf("SIP/SIP 1-00000003", "0?Return()") in new stack
    -- Executing [zap2dahdi@macro-dial-one:2] Set("SIP/SIP 1-00000003", "NEWDIAL=") in new stack
    -- Executing [zap2dahdi@macro-dial-one:3] Set("SIP/SIP 1-00000003", "LOOPCNT2=1") in new stack
    -- Executing [zap2dahdi@macro-dial-one:4] Set("SIP/SIP 1-00000003", "ITER2=1") in new stack
    -- Executing [zap2dahdi@macro-dial-one:5] Set("SIP/SIP 1-00000003", "THISPART2=SIP/1001") in new stack
    -- Executing [zap2dahdi@macro-dial-one:6] ExecIf("SIP/SIP 1-00000003", "0?Set(THISPART2=DAHDI/1001)") in new stack
    -- Executing [zap2dahdi@macro-dial-one:7] Set("SIP/SIP 1-00000003", "NEWDIAL=SIP/1001&") in new stack
    -- Executing [zap2dahdi@macro-dial-one:8] Set("SIP/SIP 1-00000003", "ITER2=2") in new stack
    -- Executing [zap2dahdi@macro-dial-one:9] GotoIf("SIP/SIP 1-00000003", "0?begin2") in new stack
    -- Executing [zap2dahdi@macro-dial-one:10] Set("SIP/SIP 1-00000003", "THISDIAL=SIP/1001") in new stack
    -- Executing [zap2dahdi@macro-dial-one:11] Return("SIP/SIP 1-00000003", "") in new stack
    -- Executing [dstring@macro-dial-one:9] Set("SIP/SIP 1-00000003", "DSTRING=SIP/1001&") in new stack
    -- Executing [dstring@macro-dial-one:10] Set("SIP/SIP 1-00000003", "ITER=2") in new stack
    -- Executing [dstring@macro-dial-one:11] GotoIf("SIP/SIP 1-00000003", "0?begin") in new stack
    -- Executing [dstring@macro-dial-one:12] Set("SIP/SIP 1-00000003", "DSTRING=SIP/1001") in new stack
    -- Executing [dstring@macro-dial-one:13] Return("SIP/SIP 1-00000003", "") in new stack
    -- Executing [s@macro-dial-one:27] GotoIf("SIP/SIP 1-00000003", "0?nodial") in new stack
    -- Executing [s@macro-dial-one:28] GotoIf("SIP/SIP 1-00000003", "1?skiptrace") in new stack
    -- Goto (macro-dial-one,s,30)
    -- Executing [s@macro-dial-one:30] Set("SIP/SIP 1-00000003", "D_OPTIONS=tr") in new stack
    -- Executing [s@macro-dial-one:31] ExecIf("SIP/SIP 1-00000003", "0?SIPAddHeader(Alert-Info: )") in new stack
    -- Executing [s@macro-dial-one:32] ExecIf("SIP/SIP 1-00000003", "0?SIPAddHeader()") in new stack
    -- Executing [s@macro-dial-one:33] ExecIf("SIP/SIP 1-00000003", "1?Set(CHANNEL(musicclass)=)") in new stack
    -- Executing [s@macro-dial-one:34] GosubIf("SIP/SIP 1-00000003", "0?qwait,1") in new stack
    -- Executing [s@macro-dial-one:35] Set("SIP/SIP 1-00000003", "__CWIGNORE=") in new stack
    -- Executing [s@macro-dial-one:36] Set("SIP/SIP 1-00000003", "__KEEPCID=TRUE") in new stack
    -- Executing [s@macro-dial-one:37] Dial("SIP/SIP 1-00000003", "SIP/1001,15,tr") in new stack
  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
    -- Couldn't call 1001
  == Everyone is busy/congested at this time (0:0/0/0)
    -- Executing [s@macro-dial-one:38] ExecIf("SIP/SIP 1-00000003", "0?Set(DIALSTATUS=)") in new stack
    -- Executing [s@macro-dial-one:39] GosubIf("SIP/SIP 1-00000003", "0?s-CHANUNAVAIL,1") in new stack
    -- Executing [s@macro-dial-one:40] MacroExit("SIP/SIP 1-00000003", "") in new stack
    -- Executing [s@macro-exten-vm:10] GotoIf("SIP/SIP 1-00000003", "0?exit") in new stack
    -- Executing [s@macro-exten-vm:11] Set("SIP/SIP 1-00000003", "SV_DIALSTATUS=CHANUNAVAIL") in new stack
    -- Executing [s@macro-exten-vm:12] GosubIf("SIP/SIP 1-00000003", "0?docfu,1") in new stack
    -- Executing [s@macro-exten-vm:13] GosubIf("SIP/SIP 1-00000003", "0?docfb,1") in new stack
    -- Executing [s@macro-exten-vm:14] Set("SIP/SIP 1-00000003", "DIALSTATUS=CHANUNAVAIL") in new stack
    -- Executing [s@macro-exten-vm:15] NoOp("SIP/SIP 1-00000003", "Voicemail is '1001'") in new stack
    -- Executing [s@macro-exten-vm:16] GotoIf("SIP/SIP 1-00000003", "0?s-CHANUNAVAIL,1") in new stack
    -- Executing [s@macro-exten-vm:17] NoOp("SIP/SIP 1-00000003", "Sending to Voicemail box 1001") in new stack
    -- Executing [s@macro-exten-vm:18] Macro("SIP/SIP 1-00000003", "vm,1001,CHANUNAVAIL,") in new stack
    -- Executing [s@macro-vm:1] Macro("SIP/SIP 1-00000003", "user-callerid,SKIPTTL") in new stack
    -- Executing [s@macro-user-callerid:1] Set("SIP/SIP 1-00000003", "AMPUSER=609046099") in new stack
    -- Executing [s@macro-user-callerid:2] GotoIf("SIP/SIP 1-00000003", "0?report") in new stack
    -- Executing [s@macro-user-callerid:3] ExecIf("SIP/SIP 1-00000003", "0?Set(REALCALLERIDNUM=609046099)") in new stack
    -- Executing [s@macro-user-callerid:4] Set("SIP/SIP 1-00000003", "AMPUSER=") in new stack
    -- Executing [s@macro-user-callerid:5] Set("SIP/SIP 1-00000003", "AMPUSERCIDNAME=") in new stack
    -- Executing [s@macro-user-callerid:6] GotoIf("SIP/SIP 1-00000003", "1?report") in new stack
    -- Goto (macro-user-callerid,s,9)
    -- Executing [s@macro-user-callerid:9] GotoIf("SIP/SIP 1-00000003", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,18)
    -- Executing [s@macro-user-callerid:18] Set("SIP/SIP 1-00000003", "CALLERID(number)=609046099") in new stack
    -- Executing [s@macro-user-callerid:19] Set("SIP/SIP 1-00000003", "CALLERID(name)=609046099") in new stack
    -- Executing [s@macro-user-callerid:20] NoOp("SIP/SIP 1-00000003", "Using CallerID "609046099" <609046099>") in new stack
    -- Executing [s@macro-vm:2] Set("SIP/SIP 1-00000003", "VMGAIN=""") in new stack
    -- Executing [s@macro-vm:3] GotoIf("SIP/SIP 1-00000003", "1?vmx,1") in new stack
    -- Goto (macro-vm,vmx,1)
    -- Executing [vmx@macro-vm:1] Set("SIP/SIP 1-00000003", "MEXTEN=1001") in new stack
    -- Executing [vmx@macro-vm:2] Set("SIP/SIP 1-00000003", "MMODE=CHANUNAVAIL") in new stack
    -- Executing [vmx@macro-vm:3] Set("SIP/SIP 1-00000003", "RETVM=") in new stack
    -- Executing [vmx@macro-vm:4] Set("SIP/SIP 1-00000003", "MODE=unavail") in new stack
    -- Executing [vmx@macro-vm:5] GotoIf("SIP/SIP 1-00000003", "1?chknomsg") in new stack
    -- Goto (macro-vm,vmx,7)
    -- Executing [vmx@macro-vm:7] GotoIf("SIP/SIP 1-00000003", "0?s-CHANUNAVAIL,1") in new stack
    -- Executing [vmx@macro-vm:8] GotoIf("SIP/SIP 1-00000003", "1?notdirect") in new stack
    -- Goto (macro-vm,vmx,10)
    -- Executing [vmx@macro-vm:10] NoOp("SIP/SIP 1-00000003", "Checking if ext 1001 is enabled: ") in new stack
    -- Executing [vmx@macro-vm:11] GotoIf("SIP/SIP 1-00000003", "1?s-CHANUNAVAIL,1") in new stack
    -- Goto (macro-vm,s-CHANUNAVAIL,1)
    -- Executing [s-CHANUNAVAIL@macro-vm:1] Macro("SIP/SIP 1-00000003", "get-vmcontext,1001") in new stack
    -- Executing [s@macro-get-vmcontext:1] Set("SIP/SIP 1-00000003", "VMCONTEXT=default") in new stack
    -- Executing [s@macro-get-vmcontext:2] GotoIf("SIP/SIP 1-00000003", "0?200:300") in new stack
    -- Goto (macro-get-vmcontext,s,300)
    -- Executing [s@macro-get-vmcontext:300] NoOp("SIP/SIP 1-00000003", "") in new stack
    -- Executing [s-CHANUNAVAIL@macro-vm:2] VoiceMail("SIP/SIP 1-00000003", "1001@default,u""") in new stack
    -- <SIP/SIP 1-00000003> Playing 'vm-theperson.g729' (language 'en')
    -- <SIP/SIP 1-00000003> Playing 'digits/1.alaw' (language 'en')
    -- <SIP/SIP 1-00000003> Playing 'digits/0.alaw' (language 'en')
    -- <SIP/SIP 1-00000003> Playing 'digits/0.alaw' (language 'en')
    -- <SIP/SIP 1-00000003> Playing 'digits/1.alaw' (language 'en')
    -- <SIP/SIP 1-00000003> Playing 'vm-isunavail.alaw' (language 'en')
  == Spawn extension (macro-vm, s-CHANUNAVAIL, 2) exited non-zero on 'SIP/SIP 1-00000003' in macro 'vm'
  == Spawn extension (macro-exten-vm, s, 18) exited non-zero on 'SIP/SIP 1-00000003' in macro 'exten-vm'
  == Spawn extension (from-did-direct, 1001, 1) exited non-zero on 'SIP/SIP 1-00000003'
    -- Executing [h@from-did-direct:1] Macro("SIP/SIP 1-00000003", "hangupcall,") in new stack
    -- Executing [s@macro-hangupcall:1] GotoIf("SIP/SIP 1-00000003", "1?skiprg") in new stack
    -- Goto (macro-hangupcall,s,4)
    -- Executing [s@macro-hangupcall:4] GotoIf("SIP/SIP 1-00000003", "1?skipblkvm") in new stack
    -- Goto (macro-hangupcall,s,7)
    -- Executing [s@macro-hangupcall:7] GotoIf("SIP/SIP 1-00000003", "1?theend") in new stack
    -- Goto (macro-hangupcall,s,9)
    -- Executing [s@macro-hangupcall:9] Hangup("SIP/SIP 1-00000003", "") in new stack
  == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/SIP 1-00000003' in macro 'hangupcall'
  == Spawn extension (from-did-direct, h, 1) exited non-zero on 'SIP/SIP 1-00000003'

I just noticed the lines: -- Couldn't call 1001 == Everyone is busy/congested at this time (0:0/0/0) Just not sure what to check, we're new to the whole Asterisk thing. — Brent Pabst, Mar 23 '11 at 16:54

score 1 · Accepted Answer · answered Mar 24 '11 at 12:25

1

Apparently the SIP Provider recommends g711a as the default codec. After making the change the calls connected both inbound and outbound.

Thanks for all of the help.

answered Mar 24 '11 at 12:25

Brent Pabst

6,069
2
24
36

score 0 · Answer 2 · answered Mar 23 '11 at 16:34

0

What have you configured as your default incoming route? I would be interested in seeing the output of asterisk -r when you are dialling in.

answered Mar 23 '11 at 16:34

gerryk

181
1

We'll run that in a minute and post it against the original question as an edit. – Brent Pabst Mar 23 '11 at 16:38
Thanks Brent. I see call waiting seems to be set on the softphone, which would indicate that the softphone might be returning BUSY when invited to the call. Can you try the following... create another extension, register another phone to this, and try extension to extension calls. Post the relevant output from asterisk -r Also, can you post the details of your default inbound route. – gerryk Mar 24 '11 at 11:29
We actually got it working last night. It looks like we had some codec problems with our trunk that finally resolved the problem. Apparently the SIP Provider recommends g711a and the default was g729 I think. – Brent Pabst Mar 24 '11 at 12:24
Glad you got it sorted, Brent. – gerryk Mar 25 '11 at 09:40

Asterisk Incoming Calls Don't Route to Extensions

2 Answers2