Hello, I have a newly installed FreePBX 13 setup. Latest updates applied. Using Yealink T46G SIP phones, chan_sip driver
The problem – certain extensions cannot call each other. The Yealink phones report “Service Unavailable”.
Specifically when dialling extension 2206 from 2207, here is the log:
[root@localhost ~]# asterisk -rvvvvvvv
Asterisk 13.4.0, Copyright (C) 1999 - 2014, 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 13.4.0 currently running on localhost (pid = 1628)
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
-- Executing [2206@from-internal:1] Set("SIP/2207-000000ce", "__RINGTIMER=15") in new stack
-- Executing [2206@from-internal:2] Macro("SIP/2207-000000ce", "exten-vm,novm,2206,0,0,0") in new stack
-- Executing [s@macro-exten-vm:1] Macro("SIP/2207-000000ce", "user-callerid,") in new stack
-- Executing [s@macro-user-callerid:1] Set("SIP/2207-000000ce", "TOUCH_MONITOR=1438978270.8748") in new stack
-- Executing [s@macro-user-callerid:2] Set("SIP/2207-000000ce", "AMPUSER=2207") in new stack
-- Executing [s@macro-user-callerid:3] GotoIf("SIP/2207-000000ce", "0?report") in new stack
-- Executing [s@macro-user-callerid:4] ExecIf("SIP/2207-000000ce", "1?Set(REALCALLERIDNUM=2207)") in new stack
-- Executing [s@macro-user-callerid:5] Set("SIP/2207-000000ce", "AMPUSER=2207") in new stack
-- Executing [s@macro-user-callerid:6] GotoIf("SIP/2207-000000ce", "0?limit") in new stack
-- Executing [s@macro-user-callerid:7] Set("SIP/2207-000000ce", "AMPUSERCIDNAME=Room 2") in new stack
-- Executing [s@macro-user-callerid:8] GotoIf("SIP/2207-000000ce", "0?report") in new stack
-- Executing [s@macro-user-callerid:9] Set("SIP/2207-000000ce", "AMPUSERCID=2207") in new stack
-- Executing [s@macro-user-callerid:10] Set("SIP/2207-000000ce", "__DIAL_OPTIONS=Ttr") in new stack
-- Executing [s@macro-user-callerid:11] Set("SIP/2207-000000ce", "CALLERID(all)="Room 2" <2207>") in new stack
-- Executing [s@macro-user-callerid:12] GotoIf("SIP/2207-000000ce", "0?limit") in new stack
-- Executing [s@macro-user-callerid:13] ExecIf("SIP/2207-000000ce", "0?Set(GROUP(concurrency_limit)=2207)") in new stack
-- Executing [s@macro-user-callerid:14] GosubIf("SIP/2207-000000ce", "7?sub-ccss,s,1(macro-exten-vm,2206)") in new stack
-- Executing [s@sub-ccss:1] ExecIf("SIP/2207-000000ce", "0?Return()") in new stack
-- Executing [s@sub-ccss:2] Set("SIP/2207-000000ce", "CCSS_SETUP=TRUE") in new stack
-- Executing [s@sub-ccss:3] GosubIf("SIP/2207-000000ce", "0?monitor_config,1(macro-exten-vm,2206):monitor_default,1(macro-exten-vm,2206)") in new stack
-- Executing [monitor_default@sub-ccss:1] GotoIf("SIP/2207-000000ce", "1?is_exten") in new stack
-- Goto (sub-ccss,monitor_default,4)
-- Executing [monitor_default@sub-ccss:4] Set("SIP/2207-000000ce", "CALLCOMPLETION(cc_monitor_policy)=generic") in new stack
-- Executing [monitor_default@sub-ccss:5] Set("SIP/2207-000000ce", "CALLCOMPLETION(cc_max_monitors)=5") in new stack
-- Executing [monitor_default@sub-ccss:6] Return("SIP/2207-000000ce", "TRUE") in new stack
-- Executing [s@sub-ccss:4] GosubIf("SIP/2207-000000ce", "7?agent_config,1():agent_default,1()") in new stack
-- Executing [agent_config@sub-ccss:1] Set("SIP/2207-000000ce", "CALLCOMPLETION(cc_agent_policy)=generic") in new stack
-- Executing [agent_config@sub-ccss:2] Set("SIP/2207-000000ce", "CALLCOMPLETION(cc_offer_timer)=30") in new stack
-- Executing [agent_config@sub-ccss:3] Set("SIP/2207-000000ce", "CALLCOMPLETION(ccbs_available_timer)=") in new stack
-- Executing [agent_config@sub-ccss:4] Set("SIP/2207-000000ce", "CALLCOMPLETION(ccnr_available_timer)=") in new stack
-- Executing [agent_config@sub-ccss:5] Set("SIP/2207-000000ce", "CALLCOMPLETION(cc_callback_macro)=ccss-default") in new stack
[2015-08-07 14:11:10] WARNING[14243][C-00001114]: ccss.c:1012 ast_set_cc_callback_macro: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead.
-- Executing [agent_config@sub-ccss:6] ExecIf("SIP/2207-000000ce", "1?Set(CALLCOMPLETION(cc_recall_timer)=)") in new stack
-- Executing [agent_config@sub-ccss:7] ExecIf("SIP/2207-000000ce", "1?Set(CALLCOMPLETION(cc_max_agents)=)") in new stack
-- Executing [agent_config@sub-ccss:8] ExecIf("SIP/2207-000000ce", "0?Set(CALLCOMPLETION(cc_agent_dialstring)=Local/2207_2206@from-ccss-)") in new stack
-- Executing [agent_config@sub-ccss:9] Set("SIP/2207-000000ce", "CALLCOMPLETION(cc_callback_macro)=ccss-default") in new stack
[2015-08-07 14:11:10] WARNING[14243][C-00001114]: ccss.c:1012 ast_set_cc_callback_macro: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead.
-- Executing [agent_config@sub-ccss:10] Return("SIP/2207-000000ce", "") in new stack
-- Executing [s@sub-ccss:5] Set("SIP/2207-000000ce", "DB(AMPUSER/2207/ccss/last_number)=2206") in new stack
-- Executing [s@sub-ccss:6] Return("SIP/2207-000000ce", "") in new stack
-- Executing [s@macro-user-callerid:15] ExecIf("SIP/2207-000000ce", "0?Set(CHANNEL(language)=)") in new stack
-- Executing [s@macro-user-callerid:16] GotoIf("SIP/2207-000000ce", "0?continue") in new stack
-- Executing [s@macro-user-callerid:17] ExecIf("SIP/2207-000000ce", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
-- Executing [s@macro-user-callerid:18] Set("SIP/2207-000000ce", "__TTL=64") in new stack
-- Executing [s@macro-user-callerid:19] GotoIf("SIP/2207-000000ce", "1?continue") in new stack
-- Goto (macro-user-callerid,s,30)
-- Executing [s@macro-user-callerid:30] Set("SIP/2207-000000ce", "CALLERID(number)=2207") in new stack
-- Executing [s@macro-user-callerid:31] Set("SIP/2207-000000ce", "CALLERID(name)=Room 2") in new stack
-- Executing [s@macro-user-callerid:32] Set("SIP/2207-000000ce", "CDR(cnum)=2207") in new stack
-- Executing [s@macro-user-callerid:33] Set("SIP/2207-000000ce", "CDR(cnam)=Room 2") in new stack
-- Executing [s@macro-user-callerid:34] Set("SIP/2207-000000ce", "CHANNEL(language)=en") in new stack
-- Executing [s@macro-exten-vm:2] Set("SIP/2207-000000ce", "RingGroupMethod=none") in new stack
-- Executing [s@macro-exten-vm:3] Set("SIP/2207-000000ce", "__EXTTOCALL=2206") in new stack
-- Executing [s@macro-exten-vm:4] Set("SIP/2207-000000ce", "__PICKUPMARK=2206") in new stack
-- Executing [s@macro-exten-vm:5] Set("SIP/2207-000000ce", "RT=") in new stack
-- Executing [s@macro-exten-vm:6] Gosub("SIP/2207-000000ce", "sub-record-check,s,1(exten,2206,dontcare)") in new stack
-- Executing [s@sub-record-check:1] GotoIf("SIP/2207-000000ce", "0?initialized") in new stack
-- Executing [s@sub-record-check:2] Set("SIP/2207-000000ce", "__REC_STATUS=INITIALIZED") in new stack
-- Executing [s@sub-record-check:3] Set("SIP/2207-000000ce", "NOW=1438978271") in new stack
-- Executing [s@sub-record-check:4] Set("SIP/2207-000000ce", "__DAY=07") in new stack
-- Executing [s@sub-record-check:5] Set("SIP/2207-000000ce", "__MONTH=08") in new stack
-- Executing [s@sub-record-check:6] Set("SIP/2207-000000ce", "__YEAR=2015") in new stack
-- Executing [s@sub-record-check:7] Set("SIP/2207-000000ce", "__TIMESTR=20150807-141111") in new stack
-- Executing [s@sub-record-check:8] Set("SIP/2207-000000ce", "__FROMEXTEN=2207") in new stack
-- Executing [s@sub-record-check:9] Set("SIP/2207-000000ce", "__MON_FMT=wav") in new stack
-- Executing [s@sub-record-check:10] NoOp("SIP/2207-000000ce", "Recordings initialized") in new stack
-- Executing [s@sub-record-check:11] ExecIf("SIP/2207-000000ce", "0?Set(ARG3=dontcare)") in new stack
-- Executing [s@sub-record-check:12] Set("SIP/2207-000000ce", "REC_POLICY_MODE_SAVE=") in new stack
-- Executing [s@sub-record-check:13] ExecIf("SIP/2207-000000ce", "0?Set(REC_STATUS=NO)") in new stack
-- Executing [s@sub-record-check:14] GotoIf("SIP/2207-000000ce", "5?checkaction") in new stack
-- Goto (sub-record-check,s,17)
-- Executing [s@sub-record-check:17] GotoIf("SIP/2207-000000ce", "1?sub-record-check,exten,1") in new stack
-- Goto (sub-record-check,exten,1)
-- Executing [exten@sub-record-check:1] NoOp("SIP/2207-000000ce", "Exten Recording Check between 2207 and 2206") in new stack
-- Executing [exten@sub-record-check:2] Set("SIP/2207-000000ce", "CALLTYPE=internal") in new stack
-- Executing [exten@sub-record-check:3] ExecIf("SIP/2207-000000ce", "0?Set(CALLTYPE=)") in new stack
-- Executing [exten@sub-record-check:4] Set("SIP/2207-000000ce", "CALLEE=dontcare") in new stack
-- Executing [exten@sub-record-check:5] ExecIf("SIP/2207-000000ce", "0?Set(CALLEE=dontcare)") in new stack
-- Executing [exten@sub-record-check:6] GotoIf("SIP/2207-000000ce", "0?callee") in new stack
-- Executing [exten@sub-record-check:7] GotoIf("SIP/2207-000000ce", "1?caller") in new stack
-- Goto (sub-record-check,exten,13)
-- Executing [exten@sub-record-check:13] Set("SIP/2207-000000ce", "RECMODE=dontcare") in new stack
-- Executing [exten@sub-record-check:14] ExecIf("SIP/2207-000000ce", "0?Set(RECMODE=dontcare)") in new stack
-- Executing [exten@sub-record-check:15] ExecIf("SIP/2207-000000ce", "1?Set(RECMODE=dontcare)") in new stack
-- Executing [exten@sub-record-check:16] Gosub("SIP/2207-000000ce", "recordcheck,1(dontcare,internal,2206)") in new stack
-- Executing [recordcheck@sub-record-check:1] NoOp("SIP/2207-000000ce", "Starting recording check against dontcare") in new stack
-- Executing [recordcheck@sub-record-check:2] Goto("SIP/2207-000000ce", "dontcare") in new stack
-- Goto (sub-record-check,recordcheck,3)
-- Executing [recordcheck@sub-record-check:3] Return("SIP/2207-000000ce", "") in new stack
-- Executing [exten@sub-record-check:17] Return("SIP/2207-000000ce", "") in new stack
-- Executing [s@macro-exten-vm:7] GotoIf("SIP/2207-000000ce", "1?macrodial") in new stack
-- Goto (macro-exten-vm,s,13)
-- Executing [s@macro-exten-vm:13] GosubIf("SIP/2207-000000ce", "0?clrheader,1()") in new stack
-- Executing [s@macro-exten-vm:14] Macro("SIP/2207-000000ce", "dial-one,,Ttr,2206") in new stack
-- Executing [s@macro-dial-one:1] Set("SIP/2207-000000ce", "DEXTEN=2206") in new stack
-- Executing [s@macro-dial-one:2] Set("SIP/2207-000000ce", "DIALSTATUS_CW=") in new stack
-- Executing [s@macro-dial-one:3] GosubIf("SIP/2207-000000ce", "0?screen,1()") in new stack
-- Executing [s@macro-dial-one:4] GosubIf("SIP/2207-000000ce", "0?cf,1()") in new stack
-- Executing [s@macro-dial-one:5] GotoIf("SIP/2207-000000ce", "1?skip1") in new stack
-- Goto (macro-dial-one,s,8)
-- Executing [s@macro-dial-one:8] GotoIf("SIP/2207-000000ce", "0?nodial") in new stack
-- Executing [s@macro-dial-one:9] GotoIf("SIP/2207-000000ce", "0?continue") in new stack
-- Executing [s@macro-dial-one:10] Set("SIP/2207-000000ce", "EXTHASCW=ENABLED") in new stack
-- Executing [s@macro-dial-one:11] GotoIf("SIP/2207-000000ce", "0?next1:cwinusebusy") in new stack
-- Goto (macro-dial-one,s,23)
-- Executing [s@macro-dial-one:23] GotoIf("SIP/2207-000000ce", "0?next3:continue") in new stack
-- Goto (macro-dial-one,s,25)
-- Executing [s@macro-dial-one:25] GotoIf("SIP/2207-000000ce", "0?nodial") in new stack
-- Executing [s@macro-dial-one:26] GosubIf("SIP/2207-000000ce", "1?dstring,1():dlocal,1()") in new stack
-- Executing [dstring@macro-dial-one:1] Set("SIP/2207-000000ce", "DSTRING=") in new stack
-- Executing [dstring@macro-dial-one:2] Set("SIP/2207-000000ce", "DEVICES=") in new stack
-- Executing [dstring@macro-dial-one:3] ExecIf("SIP/2207-000000ce", "1?Return()") in new stack
-- Executing [s@macro-dial-one:27] GotoIf("SIP/2207-000000ce", "1?nodial") in new stack
-- Goto (macro-dial-one,s,48)
-- Executing [s@macro-dial-one:48] ExecIf("SIP/2207-000000ce", "1?Set(DIALSTATUS=NOANSWER)") in new stack
-- Executing [s@macro-dial-one:49] NoOp("SIP/2207-000000ce", "Returned from dial-one with nothing to call and DIALSTATUS: NOANSWER") in new stack
-- Executing [s@macro-dial-one:50] MacroExit("SIP/2207-000000ce", "") in new stack
-- Executing [s@macro-exten-vm:15] Set("SIP/2207-000000ce", "SV_DIALSTATUS=NOANSWER") in new stack
-- Executing [s@macro-exten-vm:16] GosubIf("SIP/2207-000000ce", "0?docfu,1()") in new stack
-- Executing [s@macro-exten-vm:17] GosubIf("SIP/2207-000000ce", "0?docfb,1()") in new stack
-- Executing [s@macro-exten-vm:18] Set("SIP/2207-000000ce", "DIALSTATUS=NOANSWER") in new stack
-- Executing [s@macro-exten-vm:19] ExecIf("SIP/2207-000000ce", "0?MacroExit()") in new stack
-- Executing [s@macro-exten-vm:20] GotoIf("SIP/2207-000000ce", "1?s-NOANSWER,1") in new stack
-- Goto (macro-exten-vm,s-NOANSWER,1)
-- Executing [s-NOANSWER@macro-exten-vm:1] GotoIf("SIP/2207-000000ce", "0?exit,1") in new stack
-- Executing [s-NOANSWER@macro-exten-vm:2] PlayTones("SIP/2207-000000ce", "congestion") in new stack
-- Executing [s-NOANSWER@macro-exten-vm:3] Congestion("SIP/2207-000000ce", "10") in new stack
== Spawn extension (macro-exten-vm, s-NOANSWER, 3) exited non-zero on 'SIP/2207-000000ce' in macro 'exten-vm'
== Spawn extension (from-internal, 2206, 2) exited non-zero on 'SIP/2207-000000ce'
-- Executing [h@from-internal:1] Hangup("SIP/2207-000000ce", "") in new stack
== Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/2207-000000ce'
And here is an excerpt from sip show peers for the affected extensions:
localhost*CLI> sip show peers
Name/username Host Dyn Forcerport Comedia ACL Port Status Description
2206/2206 10.100.2.7 D No No A 5061 OK (77 ms)
2207/2207 10.100.2.3 D No No A 5061 OK (73 ms)
Both extensions can dial out fine - they just can’t call each other.
Note that the phones are on a different subnet (10.100.0.x) from the FreePBX server (10.0.100.12) but they are all connected via VPN so all IPs are ‘local’ to each other and can ping between each other.
The extensions are configured with commercial Endpoint Manager and do not have voicemail enabled.
Any suggestions?