Greetings from a newbie. I am setting up a new install of FreePBX 12. As I was creating my extensions etc, at first I was able to call from 4113 > 4006 with no problem. Somehow I must have changed something because now when I dial ext > ext I get the system voice saying that the party is not available, sometimes instantly, other times after a ring or two. Can anyone point me in the direction of where to look for this fix? I am able to call outbound without issue. Thanks!
It’s always logs, logs, logs , nobody can diagnose without them.
Ah, excellent point. Umm, now where does the newbie find the logs?
OK I did find the log files and here is where I am attempting to call from 4444002 > 4113
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [ctset@macro-dial-one:2] Return(“SIP/4444002-00000006”, “”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-dial-one:30] Set(“SIP/4444002-00000006”, “D_OPTIONS=Ttr”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-dial-one:31] ExecIf(“SIP/4444002-00000006”, “0?SIPAddHeader(Alert-Info: )”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-dial-one:32] ExecIf(“SIP/4444002-00000006”, “0?SIPAddHeader()”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-dial-one:33] ExecIf(“SIP/4444002-00000006”, “0?Set(CHANNEL(musicclass)=)”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-dial-one:34] GosubIf(“SIP/4444002-00000006”, “0?qwait,1()”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-dial-one:35] Set(“SIP/4444002-00000006”, “__CWIGNORE=”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-dial-one:36] Set(“SIP/4444002-00000006”, “__KEEPCID=TRUE”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-dial-one:37] GotoIf(“SIP/4444002-00000006”, “0?usegoto,1”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-dial-one:38] GotoIf(“SIP/4444002-00000006”, “0?godial”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-dial-one:39] Gosub(“SIP/4444002-00000006”, “sub-presencestate-display,s,1(4113)”) in new stack
[2018-01-31 15:04:50] WARNING[19743][C-000000ea] func_presencestate.c: PRESENCE_STATE unknown
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@sub-presencestate-display:1] Goto(“SIP/4444002-00000006”, “state-,1”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Goto (sub-presencestate-display,state-,1)
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [state-@sub-presencestate-display:1] Set(“SIP/4444002-00000006”, “PRESENCESTATE_DISPLAY=”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [state-@sub-presencestate-display:2] Return(“SIP/4444002-00000006”, “”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-dial-one:40] Set(“SIP/4444002-00000006”, “CONNECTEDLINE(name,i)=Racheal Woodall”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-dial-one:41] Set(“SIP/4444002-00000006”, “CONNECTEDLINE(num)=4113”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-dial-one:42] Set(“SIP/4444002-00000006”, “D_OPTIONS=TtrI”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-dial-one:43] Macro(“SIP/4444002-00000006”, “dialout-one-predial-hook,”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-dialout-one-predial-hook:1] MacroExit(“SIP/4444002-00000006”, “”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-dial-one:44] ExecIf(“SIP/4444002-00000006”, “0?Set(D_OPTIONS=trII)”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-dial-one:45] Dial(“SIP/4444002-00000006”, “SIP/113,15,TtrI”) in new stack
[2018-01-31 15:04:50] WARNING[19743][C-000000ea] chan_sip.c: Purely numeric hostname (113), and not a peer–rejecting!
[2018-01-31 15:04:50] WARNING[19743][C-000000ea] app_dial.c: Unable to create channel of type ‘SIP’ (cause 20 - Subscriber absent)
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] app_dial.c: == Everyone is busy/congested at this time (1:0/0/1)
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-dial-one:46] ExecIf(“SIP/4444002-00000006”, “0?MacroExit()”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-dial-one:47] ExecIf(“SIP/4444002-00000006”, “0?Set(DIALSTATUS=)”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-dial-one:48] GosubIf(“SIP/4444002-00000006”, “0?s-CHANUNAVAIL,1()”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-dial-one:49] MacroExit(“SIP/4444002-00000006”, “”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-exten-vm:10] Set(“SIP/4444002-00000006”, “SV_DIALSTATUS=CHANUNAVAIL”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-exten-vm:11] GosubIf(“SIP/4444002-00000006”, “0?docfu,1()”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-exten-vm:12] GosubIf(“SIP/4444002-00000006”, “0?docfb,1()”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-exten-vm:13] Set(“SIP/4444002-00000006”, “DIALSTATUS=CHANUNAVAIL”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-exten-vm:14] ExecIf(“SIP/4444002-00000006”, “0?MacroExit()”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-exten-vm:15] GotoIf(“SIP/4444002-00000006”, “0?s-CHANUNAVAIL,1”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-exten-vm:16] Macro(“SIP/4444002-00000006”, “vm,4113,CHANUNAVAIL,”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-vm:1] Macro(“SIP/4444002-00000006”, “user-callerid,SKIPTTL”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/4444002-00000006”, “TOUCH_MONITOR=1517432690.464”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-user-callerid:2] Set(“SIP/4444002-00000006”, “AMPUSER=4444002”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-user-callerid:3] GotoIf(“SIP/4444002-00000006”, “7?report”) in new stack
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Goto (macro-user-callerid,s,16)
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] pbx.c: – Executing [s@macro-user-callerid:16] GotoIf(“SIP/4444002-00000006”, “1?continue”) in new stack
Looks like a netowk problem
[2018-01-31 15:04:50] WARNING[19743][C-000000ea] app_dial.c: Unable to create channel of type ‘SIP’ (cause 20 - Subscriber absent)
[2018-01-31 15:04:50] VERBOSE[19743][C-000000ea] app_dial.c: == Everyone is busy/congested at this time (1:0/0/1)
from bash
rasterisk -x “sip show peers” do you notice that you have both 4113 and 113 in the log and SIP/113 is not available and eventually goes to the voicemail of 4113, does that jog any memories?
Yes I see that. I had modified some extensions going from ‘113’ to 4113 but it seems as if the old 113 remained in the config and was causing a problem. I exported all of my extensions, checked them over for accuracy and then deleted all the existing extensions. Rebooted and reloaded bulk extensions. That fixed most of my problems. However some extensions have DID’s and I matched those to their extension. Others are simple extensions. Now I can call 4 digit extensions from any phone but not 7 digit extensions, they go straight to The person is not available message. Is there something that prohibits 7 digit extensions?
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [s@macro-user-callerid:30] Set(“SIP/4113-00000011”, “CALLERID(number)=4113”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [s@macro-user-callerid:31] Set(“SIP/4113-00000011”, “CALLERID(name)=Racheal Woodall”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [s@macro-user-callerid:32] Set(“SIP/4113-00000011”, “CDR(cnum)=4113”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [s@macro-user-callerid:33] Set(“SIP/4113-00000011”, “CDR(cnam)=Racheal Woodall”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [s@macro-user-callerid:34] Set(“SIP/4113-00000011”, “CHANNEL(language)=en”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [s@macro-vm:2] Set(“SIP/4113-00000011”, “VMGAIN=”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [s@macro-vm:3] Macro(“SIP/4113-00000011”, “blkvm-check,”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [s@macro-blkvm-check:1] Set(“SIP/4113-00000011”, “GOSUB_RETVAL=”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [s@macro-blkvm-check:2] ExecIf(“SIP/4113-00000011”, “0?Set(GOSUB_RETVAL=TRUE)”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [s@macro-blkvm-check:3] MacroExit(“SIP/4113-00000011”, “”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [s@macro-vm:4] GotoIf(“SIP/4113-00000011”, “1?vmx,1”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Goto (macro-vm,vmx,1)
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [vmx@macro-vm:1] Set(“SIP/4113-00000011”, “MEXTEN=4444012”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [vmx@macro-vm:2] Set(“SIP/4113-00000011”, “MMODE=CHANUNAVAIL”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [vmx@macro-vm:3] Set(“SIP/4113-00000011”, “RETVM=”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [vmx@macro-vm:4] Set(“SIP/4113-00000011”, “MODE=unavail”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [vmx@macro-vm:5] Macro(“SIP/4113-00000011”, “get-vmcontext,4444012”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [s@macro-get-vmcontext:1] Set(“SIP/4113-00000011”, “VMCONTEXT=default”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [s@macro-get-vmcontext:2] GotoIf(“SIP/4113-00000011”, “0?200:300”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Goto (macro-get-vmcontext,s,300)
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [s@macro-get-vmcontext:300] NoOp(“SIP/4113-00000011”, “”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [vmx@macro-vm:6] Set(“SIP/4113-00000011”, “MODE=unavail”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [vmx@macro-vm:7] NoOp(“SIP/4113-00000011”, “MODE IS: unavail”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [vmx@macro-vm:8] GotoIf(“SIP/4113-00000011”, “1?chknomsg”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Goto (macro-vm,vmx,10)
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [vmx@macro-vm:10] GotoIf(“SIP/4113-00000011”, “0?s-CHANUNAVAIL,1”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [vmx@macro-vm:11] GotoIf(“SIP/4113-00000011”, “1?notdirect”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Goto (macro-vm,vmx,13)
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [vmx@macro-vm:13] NoOp(“SIP/4113-00000011”, "Checking if ext 4444012 is enabled: ") in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [vmx@macro-vm:14] GotoIf(“SIP/4113-00000011”, “1?s-CHANUNAVAIL,1”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Goto (macro-vm,s-CHANUNAVAIL,1)
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [s-CHANUNAVAIL@macro-vm:1] Macro(“SIP/4113-00000011”, “get-vmcontext,4444012”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [s@macro-get-vmcontext:1] Set(“SIP/4113-00000011”, “VMCONTEXT=default”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [s@macro-get-vmcontext:2] GotoIf(“SIP/4113-00000011”, “0?200:300”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Goto (macro-get-vmcontext,s,300)
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [s@macro-get-vmcontext:300] NoOp(“SIP/4113-00000011”, “”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] pbx.c: – Executing [s-CHANUNAVAIL@macro-vm:2] VoiceMail(“SIP/4113-00000011”, “4444012@default,u”) in new stack
[2018-02-01 08:59:20] VERBOSE[5432][C-00000024] file.c: – <SIP/4113-00000011> Playing ‘vm-theperson.alaw’ (language ‘en’)
[2018-02-01 08:59:22] VERBOSE[5432][C-00000024] file.c: – <SIP/4113-00000011> Playing ‘digits/4.alaw’ (language ‘en’)
[2018-02-01 08:59:22] VERBOSE[5432][C-00000024] file.c: – <SIP/4113-00000011> Playing ‘digits/4.alaw’ (language ‘en’)
[2018-02-01 08:59:23] VERBOSE[5432][C-00000024] file.c: – <SIP/4113-00000011> Playing ‘digits/4.alaw’ (language ‘en’)
[2018-02-01 08:59:24] VERBOSE[5432][C-00000024] file.c: – <SIP/4113-00000011> Playing ‘digits/4.alaw’ (language ‘en’)
[2018-02-01 08:59:24] VERBOSE[5432][C-00000024] file.c: – <SIP/4113-00000011> Playing ‘digits/0.alaw’ (language ‘en’)
[2018-02-01 08:59:25] VERBOSE[5432][C-00000024] file.c: – <SIP/4113-00000011> Playing ‘digits/1.alaw’ (language ‘en’)
[2018-02-01 08:59:26] VERBOSE[5432][C-00000024] file.c: – <SIP/4113-00000011> Playing ‘digits/2.alaw’ (language ‘en’)
[2018-02-01 08:59:27] VERBOSE[5432][C-00000024] file.c: – <SIP/4113-00000011> Playing ‘vm-isunavail.alaw’ (language ‘en’)
[2018-02-01 08:59:28] VERBOSE[5432][C-00000024] file.c: – <SIP/4113-00000011> Playing ‘vm-intro.alaw’ (language ‘en’)
[2018-02-01 08:59:33] VERBOSE[5432][C-00000024] file.c: – <SIP/4113-00000011> Playing ‘beep.alaw’ (language ‘en’)
[2018-02-01 08:59:34] VERBOSE[5432][C-00000024] app_voicemail.c: – Recording the message
[2018-02-01 08:59:34] VERBOSE[5432][C-00000024] app.c: – x=0, open writing: /var/spool/asterisk/voicemail/default/4444012/tmp/SxRFPS format: wav, 0x7f5cb400ae08
[2018-02-01 08:59:37] VERBOSE[5432][C-00000024] app.c: – User ended message by pressing #
[2018-02-01 08:59:37] VERBOSE[5432][C-00000024] file.c: – <SIP/4113-00000011> Playing ‘auth-thankyou.alaw’ (language ‘en’)
[2018-02-01 08:59:38] VERBOSE[5432][C-00000024] config.c: == Parsing ‘/var/spool/asterisk/voicemail/default/4444012/INBOX/msg0000.txt’: Found
[2018-02-01 08:59:38] VERBOSE[5432][C-00000024] pbx.c: – Executing [s-CHANUNAVAIL@macro-vm:3] Goto(“SIP/4113-00000011”, “exit-SUCCESS,1”) in new stack
[2018-02-01 08:59:38] VERBOSE[5432][C-00000024] pbx.c: – Goto (macro-vm,exit-SUCCESS,1)
[2018-02-01 08:59:38] VERBOSE[5432][C-00000024] pbx.c: – Executing [exit-SUCCESS@macro-vm:1] GotoIf(“SIP/4113-00000011”, “0?exit-RETURN,1”) in new stack
[2018-02-01 08:59:38] VERBOSE[5432][C-00000024] pbx.c: – Executing [exit-SUCCESS@macro-vm:2] Playback(“SIP/4113-00000011”, “goodbye”) in new stack
[2018-02-01 08:59:38] VERBOSE[5432][C-00000024] file.c: – <SIP/4113-00000011> Playing ‘goodbye.alaw’ (language ‘en’)
[2018-02-01 08:59:39] VERBOSE[5432][C-00000024] pbx.c: – Executing [exit-SUCCESS@macro-vm:3] Hangup(“SIP/4113-00000011”, “”) in new stack
[2018-02-01 08:59:39] VERBOSE[5432][C-00000024] app_macro.c: == Spawn extension (macro-vm, exit-SUCCESS, 3) exited non-zero on ‘SIP/4113-00000011’ in macro ‘vm’
[2018-02-01 08:59:39] VERBOSE[5432][C-00000024] app_macro.c: == Spawn extension (macro-exten-vm, s, 16) exited non-zero on ‘SIP/4113-00000011’ in macro ‘exten-vm’
[2018-02-01 08:59:39] VERBOSE[5432][C-00000024] pbx.c: == Spawn extension (from-internal, 4444012, 2) exited non-zero on ‘SIP/4113-00000011’
[2018-02-01 08:59:39] VERBOSE[5432][C-00000024] pbx.c: – Executing [h@from-internal:1] Hangup(“SIP/4113-00000011”, “”) in new stack
[2018-02-01 08:59:39] VERBOSE[5432][C-00000024] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on ‘SIP/4113-00000011’
Extension 4444012 isn’t available. Perhaps there’s no phone attached, or the phone is off-hook.
That is the clinker, Under the Peers listing, it shows that it is there:
4444012/4444012 10.113.2.162 D No No A 5060 OK (11 ms)
and I can call 4113 as well as outbound from it, but I cannot go to 4113 and call 4444012, which are both sitting on my desk. This applies to all 7 digit extensions.
The problem was with the routing rules. The way 4 digit verses 7 digit extensions were dialed was getting confused with outbound routes. I just scrapped 7 digit extensions and all is well now.
Thanks everyone