Extensions Don't Ring

We are using FreePBX 2.7.0.10 with AsteriskNOW (Asterisk core 1.4.40).

We configured an outbound route that allows us to call out using our VOIP trunk. We set up a couple of extensions and were able to make calls out and from extension to extension.

I started configuring inbound routes and building an IVR, and at some point the extensions stopped ringing. If you dial an extension (either from the main IVR when calling in or from another extension), it goes immediately to voicemail, or to a fast busy signal if voicemail is not enabled on that extension.

I deleted the IVR and all inbound routes, but nothing changed. All extensions can still dial out no problem.

Here is what asterisk logs for a call to an extension with voicemail enabled:

[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:1] Macro(“SIP/124-0000002f”, “exten-vm|112|112”) in new stack
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:1] Macro(“SIP/124-0000002f”, “user-callerid|”) in new stack
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:1] Set(“SIP/124-0000002f”, “AMPUSER=124”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:2] GotoIf(“SIP/124-0000002f”, “0?report”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: GotoIf
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:3] ExecIf(“SIP/124-0000002f”, “1|Set|REALCALLERIDNUM=124”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: ExecIf
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:4] Set(“SIP/124-0000002f”, “AMPUSER=124”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:5] Set(“SIP/124-0000002f”, “AMPUSERCIDNAME=Ian Gustafson”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:6] GotoIf(“SIP/124-0000002f”, “0?report”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: GotoIf
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:7] Set(“SIP/124-0000002f”, “AMPUSERCID=124”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:8] Set(“SIP/124-0000002f”, “CALLERID(all)=“Ian Gustafson” <124>”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:9] ExecIf(“SIP/124-0000002f”, “0|Set|CHANNEL(language)=”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: ExecIf
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:10] GotoIf(“SIP/124-0000002f”, “0?continue”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: GotoIf
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:11] Set(“SIP/124-0000002f”, “__TTL=64”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:12] GotoIf(“SIP/124-0000002f”, “1?continue”) in new stack
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Goto (macro-user-callerid,s,19)
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: GotoIf
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:19] Set(“SIP/124-0000002f”, “CALLERID(number)=124”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:20] Set(“SIP/124-0000002f”, “CALLERID(name)=Ian Gustafson”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:21] NoOp(“SIP/124-0000002f”, “Using CallerID “Ian Gustafson” <124>”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Noop
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Macro
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:2] Set(“SIP/124-0000002f”, “RingGroupMethod=none”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:3] Set(“SIP/124-0000002f”, “VMBOX=112”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:4] Set(“SIP/124-0000002f”, “EXTTOCALL=112”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] DEBUG[13777] func_db.c: DB: CFU/112 not found in database.
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:5] Set(“SIP/124-0000002f”, “CFUEXT=”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] DEBUG[13777] func_db.c: DB: CFB/112 not found in database.
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:6] Set(“SIP/124-0000002f”, “CFBEXT=”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:7] Set(“SIP/124-0000002f”, “RT=15”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:8] Macro(“SIP/124-0000002f”, “record-enable|112|IN”) in new stack
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:1] GotoIf(“SIP/124-0000002f”, “1?check”) in new stack
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Goto (macro-record-enable,s,4)
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: GotoIf
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:4] ExecIf(“SIP/124-0000002f”, “0|MacroExit|”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: ExecIf
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:5] GotoIf(“SIP/124-0000002f”, “0?Group:OUT”) in new stack
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Goto (macro-record-enable,s,15)
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: GotoIf
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:15] GotoIf(“SIP/124-0000002f”, “1?IN”) in new stack
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Goto (macro-record-enable,s,20)
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: GotoIf
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:20] ExecIf(“SIP/124-0000002f”, “1|MacroExit|”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Macro
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:9] Macro(“SIP/124-0000002f”, “dial|15|tr|112”) in new stack
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:1] GotoIf(“SIP/124-0000002f”, “1?dial”) in new stack
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Goto (macro-dial,s,3)
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: GotoIf
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:3] AGI(“SIP/124-0000002f”, “dialparties.agi”) in new stack
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[Apr 5 17:57:11] VERBOSE[13777] logger.c: dialparties.agi: Starting New Dialparties.agi
[Apr 5 17:57:11] VERBOSE[13779] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Apr 5 17:57:11] VERBOSE[13779] logger.c: Found
[Apr 5 17:57:11] VERBOSE[13779] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Apr 5 17:57:11] VERBOSE[13779] logger.c: Found
[Apr 5 17:57:11] VERBOSE[13779] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Apr 5 17:57:11] VERBOSE[13779] logger.c: Found
[Apr 5 17:57:11] VERBOSE[13779] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Apr 5 17:57:11] VERBOSE[13777] logger.c: dialparties.agi: Caller ID name is ‘Ian Gustafson’ number is ‘124’
[Apr 5 17:57:11] VERBOSE[13777] logger.c: dialparties.agi: Methodology of ring is ‘none’
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – dialparties.agi: Added extension 112 to extension map
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – dialparties.agi: Extension 112 cf is disabled
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – dialparties.agi: Extension 112 do not disturb is disabled
[Apr 5 17:57:11] VERBOSE[13777] logger.c: dialparties.agi: ExtensionState: 0
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – dialparties.agi: dbset CALLTRACE/112 to 124
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – dialparties.agi: Filtered ARG3: 112
[Apr 5 17:57:11] VERBOSE[13779] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – AGI Script dialparties.agi completed, returning 0
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: AGI
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:7] Dial(“SIP/124-0000002f”, “SIP/112|15|tr”) in new stack
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Called 112
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – SIP/112-00000030 is circuit-busy
[Apr 5 17:57:11] VERBOSE[13777] logger.c: == Everyone is busy/congested at this time (1:0/1/0)
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Dial
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:8] Set(“SIP/124-0000002f”, “DIALSTATUS=CONGESTION”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:9] GosubIf(“SIP/124-0000002f”, “0?CONGESTION|1”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: GosubIf
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Macro
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:10] GotoIf(“SIP/124-0000002f”, “0?exit|return”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: GotoIf
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:11] Set(“SIP/124-0000002f”, “SV_DIALSTATUS=CONGESTION”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:12] GosubIf(“SIP/124-0000002f”, “0?docfu|1”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: GosubIf
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:13] GosubIf(“SIP/124-0000002f”, “0?docfb|1”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: GosubIf
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:14] Set(“SIP/124-0000002f”, “DIALSTATUS=CONGESTION”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:15] NoOp(“SIP/124-0000002f”, “Voicemail is 112”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Noop
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:16] GotoIf(“SIP/124-0000002f”, “0?s-CONGESTION|1”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: GotoIf
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:17] NoOp(“SIP/124-0000002f”, “Sending to Voicemail box 112”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Noop
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:18] Macro(“SIP/124-0000002f”, “vm|112|CONGESTION|”) in new stack
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:1] Macro(“SIP/124-0000002f”, “user-callerid|SKIPTTL”) in new stack
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:1] Set(“SIP/124-0000002f”, “AMPUSER=124”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:2] GotoIf(“SIP/124-0000002f”, “0?report”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: GotoIf
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:3] ExecIf(“SIP/124-0000002f”, “0|Set|REALCALLERIDNUM=124”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: ExecIf
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:4] Set(“SIP/124-0000002f”, “AMPUSER=124”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:5] Set(“SIP/124-0000002f”, “AMPUSERCIDNAME=Ian Gustafson”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:6] GotoIf(“SIP/124-0000002f”, “0?report”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: GotoIf
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:7] Set(“SIP/124-0000002f”, “AMPUSERCID=124”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:8] Set(“SIP/124-0000002f”, “CALLERID(all)=“Ian Gustafson” <124>”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:9] ExecIf(“SIP/124-0000002f”, “0|Set|CHANNEL(language)=”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: ExecIf
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:10] GotoIf(“SIP/124-0000002f”, “1?continue”) in new stack
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Goto (macro-user-callerid,s,19)
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: GotoIf
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:19] Set(“SIP/124-0000002f”, “CALLERID(number)=124”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:20] Set(“SIP/124-0000002f”, “CALLERID(name)=Ian Gustafson”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:21] NoOp(“SIP/124-0000002f”, “Using CallerID “Ian Gustafson” <124>”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Noop
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Macro
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:2] Set(“SIP/124-0000002f”, “VMGAIN=”"") in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] WARNING[13777] func_db.c: DB requires an argument, DB(/)
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:3] GotoIf(“SIP/124-0000002f”, “1?vmx|1”) in new stack
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Goto (macro-vm,vmx,1)
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: GotoIf
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:1] Set(“SIP/124-0000002f”, “MEXTEN=112”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:2] Set(“SIP/124-0000002f”, “MMODE=CONGESTION”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:3] Set(“SIP/124-0000002f”, “RETVM=”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:4] Set(“SIP/124-0000002f”, “MODE=unavail”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:5] GotoIf(“SIP/124-0000002f”, “1?chknomsg”) in new stack
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Goto (macro-vm,vmx,7)
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: GotoIf
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:7] GotoIf(“SIP/124-0000002f”, “0?s-CONGESTION|1”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: GotoIf
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:8] GotoIf(“SIP/124-0000002f”, “1?notdirect”) in new stack
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Goto (macro-vm,vmx,10)
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: GotoIf
[Apr 5 17:57:11] DEBUG[13777] func_db.c: DB: AMPUSER/112/vmx/unavail/state not found in database.
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:10] NoOp(“SIP/124-0000002f”, "Checking if ext 112 is enabled: ") in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Noop
[Apr 5 17:57:11] DEBUG[13777] func_db.c: DB: AMPUSER/112/vmx/unavail/state not found in database.
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:11] GotoIf(“SIP/124-0000002f”, “1?s-CONGESTION|1”) in new stack
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Goto (macro-vm,s-CONGESTION,1)
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: GotoIf
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:1] Macro(“SIP/124-0000002f”, “get-vmcontext|112”) in new stack
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:1] Set(“SIP/124-0000002f”, “VMCONTEXT=default”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Set
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:2] GotoIf(“SIP/124-0000002f”, “0?200:300”) in new stack
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Goto (macro-get-vmcontext,s,300)
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: GotoIf
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:300] NoOp(“SIP/124-0000002f”, “”) in new stack
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: NoOp
[Apr 5 17:57:11] DEBUG[13777] app_macro.c: Executed application: Macro
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – Executing [[email protected]:2] VoiceMail(“SIP/124-0000002f”, “[email protected]|u”) in new stack
[Apr 5 17:57:11] VERBOSE[13777] logger.c: – <SIP/124-0000002f> Playing ‘vm-theperson’ (language ‘en’)
[Apr 5 17:57:13] VERBOSE[13777] logger.c: – <SIP/124-0000002f> Playing ‘digits/1’ (language ‘en’)
[Apr 5 17:57:13] VERBOSE[13777] logger.c: == Spawn extension (macro-vm, s-CONGESTION, 2) exited non-zero on ‘SIP/124-0000002f’ in macro ‘vm’
[Apr 5 17:57:13] VERBOSE[13777] logger.c: == Spawn extension (macro-exten-vm, s, 18) exited non-zero on ‘SIP/124-0000002f’ in macro ‘exten-vm’
[Apr 5 17:57:13] VERBOSE[13777] logger.c: == Spawn extension (from-internal, 112, 1) exited non-zero on ‘SIP/124-0000002f’
[Apr 5 17:57:13] VERBOSE[13777] logger.c: – Executing [[email protected]:1] Macro(“SIP/124-0000002f”, “hangupcall”) in new stack
[Apr 5 17:57:13] VERBOSE[13777] logger.c: – Executing [[email protected]:1] GotoIf(“SIP/124-0000002f”, “1?skiprg”) in new stack
[Apr 5 17:57:13] VERBOSE[13777] logger.c: – Goto (macro-hangupcall,s,4)
[Apr 5 17:57:13] DEBUG[13777] app_macro.c: Executed application: GotoIf
[Apr 5 17:57:13] VERBOSE[13777] logger.c: – Executing [[email protected]:4] GotoIf(“SIP/124-0000002f”, “1?skipblkvm”) in new stack
[Apr 5 17:57:13] VERBOSE[13777] logger.c: – Goto (macro-hangupcall,s,7)
[Apr 5 17:57:13] DEBUG[13777] app_macro.c: Executed application: GotoIf
[Apr 5 17:57:13] VERBOSE[13777] logger.c: – Executing [[email protected]:7] GotoIf(“SIP/124-0000002f”, “1?theend”) in new stack
[Apr 5 17:57:13] VERBOSE[13777] logger.c: – Goto (macro-hangupcall,s,9)
[Apr 5 17:57:13] DEBUG[13777] app_macro.c: Executed application: GotoIf
[Apr 5 17:57:13] VERBOSE[13777] logger.c: – Executing [[email protected]:9] Hangup(“SIP/124-0000002f”, “”) in new stack
[Apr 5 17:57:13] VERBOSE[13777] logger.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘SIP/124-0000002f’ in macro ‘hangupcall’
[Apr 5 17:57:13] VERBOSE[13777] logger.c: == Spawn extension (from-internal, h, 1) exited non-zero on ‘SIP/124-0000002f’
[Apr 5 17:57:15] VERBOSE[13795] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Apr 5 17:57:15] VERBOSE[13795] logger.c: Found
[Apr 5 17:57:15] VERBOSE[13795] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Apr 5 17:57:15] VERBOSE[13795] logger.c: Found
[Apr 5 17:57:15] VERBOSE[13795] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Apr 5 17:57:15] VERBOSE[13795] logger.c: Found
[Apr 5 17:57:15] VERBOSE[13795] logger.c: == Manager ‘admin’ logged on from 127.0.0.1

WARNING[13777] func_db.c: DB requires an argument, DB(/) is the only warning, with no errors. Now for a call to an extension with voicemail disabled:

[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:1] Macro(“SIP/124-00000031”, “exten-vm|novm|111”) in new stack
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:1] Macro(“SIP/124-00000031”, “user-callerid|”) in new stack
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:1] Set(“SIP/124-00000031”, “AMPUSER=124”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: Set
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:2] GotoIf(“SIP/124-00000031”, “0?report”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: GotoIf
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:3] ExecIf(“SIP/124-00000031”, “1|Set|REALCALLERIDNUM=124”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: ExecIf
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:4] Set(“SIP/124-00000031”, “AMPUSER=124”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: Set
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:5] Set(“SIP/124-00000031”, “AMPUSERCIDNAME=Ian Gustafson”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: Set
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:6] GotoIf(“SIP/124-00000031”, “0?report”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: GotoIf
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:7] Set(“SIP/124-00000031”, “AMPUSERCID=124”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: Set
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:8] Set(“SIP/124-00000031”, “CALLERID(all)=“Ian Gustafson” <124>”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: Set
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:9] ExecIf(“SIP/124-00000031”, “0|Set|CHANNEL(language)=”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: ExecIf
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:10] GotoIf(“SIP/124-00000031”, “0?continue”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: GotoIf
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:11] Set(“SIP/124-00000031”, “__TTL=64”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: Set
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:12] GotoIf(“SIP/124-00000031”, “1?continue”) in new stack
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Goto (macro-user-callerid,s,19)
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: GotoIf
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:19] Set(“SIP/124-00000031”, “CALLERID(number)=124”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: Set
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:20] Set(“SIP/124-00000031”, “CALLERID(name)=Ian Gustafson”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: Set
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:21] NoOp(“SIP/124-00000031”, “Using CallerID “Ian Gustafson” <124>”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: Noop
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: Macro
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:2] Set(“SIP/124-00000031”, “RingGroupMethod=none”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: Set
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:3] Set(“SIP/124-00000031”, “VMBOX=novm”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: Set
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:4] Set(“SIP/124-00000031”, “EXTTOCALL=111”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: Set
[Apr 5 18:10:27] DEBUG[19519] func_db.c: DB: CFU/111 not found in database.
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:5] Set(“SIP/124-00000031”, “CFUEXT=”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: Set
[Apr 5 18:10:27] DEBUG[19519] func_db.c: DB: CFB/111 not found in database.
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:6] Set(“SIP/124-00000031”, “CFBEXT=”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: Set
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:7] Set(“SIP/124-00000031”, “RT=”"") in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: Set
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:8] Macro(“SIP/124-00000031”, “record-enable|111|IN”) in new stack
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:1] GotoIf(“SIP/124-00000031”, “1?check”) in new stack
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Goto (macro-record-enable,s,4)
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: GotoIf
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:4] ExecIf(“SIP/124-00000031”, “0|MacroExit|”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: ExecIf
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:5] GotoIf(“SIP/124-00000031”, “0?Group:OUT”) in new stack
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Goto (macro-record-enable,s,15)
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: GotoIf
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:15] GotoIf(“SIP/124-00000031”, “1?IN”) in new stack
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Goto (macro-record-enable,s,20)
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: GotoIf
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:20] ExecIf(“SIP/124-00000031”, “1|MacroExit|”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: Macro
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:9] Macro(“SIP/124-00000031”, “dial||tr|111”) in new stack
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:1] GotoIf(“SIP/124-00000031”, “1?dial”) in new stack
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Goto (macro-dial,s,3)
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: GotoIf
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:3] AGI(“SIP/124-00000031”, “dialparties.agi”) in new stack
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[Apr 5 18:10:27] VERBOSE[19519] logger.c: dialparties.agi: Starting New Dialparties.agi
[Apr 5 18:10:27] VERBOSE[19521] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Apr 5 18:10:27] VERBOSE[19521] logger.c: Found
[Apr 5 18:10:27] VERBOSE[19521] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Apr 5 18:10:27] VERBOSE[19521] logger.c: Found
[Apr 5 18:10:27] VERBOSE[19521] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Apr 5 18:10:27] VERBOSE[19521] logger.c: Found
[Apr 5 18:10:27] VERBOSE[19521] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Apr 5 18:10:27] VERBOSE[19519] logger.c: dialparties.agi: Caller ID name is ‘Ian Gustafson’ number is ‘124’
[Apr 5 18:10:27] VERBOSE[19519] logger.c: dialparties.agi: Methodology of ring is ‘none’
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – dialparties.agi: Added extension 111 to extension map
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – dialparties.agi: Extension 111 cf is disabled
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – dialparties.agi: Extension 111 do not disturb is disabled
[Apr 5 18:10:27] VERBOSE[19519] logger.c: dialparties.agi: ExtensionState: 4
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – dialparties.agi: dbset CALLTRACE/111 to 124
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – dialparties.agi: Filtered ARG3: 111
[Apr 5 18:10:27] VERBOSE[19521] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – AGI Script dialparties.agi completed, returning 0
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: AGI
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:7] Dial(“SIP/124-00000031”, “SIP/111||tr”) in new stack
[Apr 5 18:10:27] WARNING[19519] app_dial.c: Unable to create channel of type ‘SIP’ (cause 20 - Unknown)
[Apr 5 18:10:27] VERBOSE[19519] logger.c: == Everyone is busy/congested at this time (1:0/0/1)
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: Dial
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:8] Set(“SIP/124-00000031”, “DIALSTATUS=CHANUNAVAIL”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: Set
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:9] GosubIf(“SIP/124-00000031”, “0?CHANUNAVAIL|1”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: GosubIf
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: Macro
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:10] GotoIf(“SIP/124-00000031”, “0?exit|return”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: GotoIf
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:11] Set(“SIP/124-00000031”, “SV_DIALSTATUS=CHANUNAVAIL”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: Set
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:12] GosubIf(“SIP/124-00000031”, “0?docfu|1”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: GosubIf
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:13] GosubIf(“SIP/124-00000031”, “0?docfb|1”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: GosubIf
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:14] Set(“SIP/124-00000031”, “DIALSTATUS=CHANUNAVAIL”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: Set
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:15] NoOp(“SIP/124-00000031”, “Voicemail is novm”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: Noop
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:16] GotoIf(“SIP/124-00000031”, “1?s-CHANUNAVAIL|1”) in new stack
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Goto (macro-exten-vm,s-CHANUNAVAIL,1)
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: GotoIf
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:1] NoOp(“SIP/124-00000031”, "IVR_RETVM: IVR_CONTEXT: ") in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: Noop
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:2] GotoIf(“SIP/124-00000031”, “0?exit|1”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: GotoIf
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:3] PlayTones(“SIP/124-00000031”, “congestion”) in new stack
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: Playtones
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:4] Congestion(“SIP/124-00000031”, “10”) in new stack
[Apr 5 18:10:27] VERBOSE[19519] logger.c: == Spawn extension (macro-exten-vm, s-CHANUNAVAIL, 4) exited non-zero on ‘SIP/124-00000031’ in macro ‘exten-vm’
[Apr 5 18:10:27] VERBOSE[19519] logger.c: == Spawn extension (from-internal, 111, 1) exited non-zero on ‘SIP/124-00000031’
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:1] Macro(“SIP/124-00000031”, “hangupcall”) in new stack
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:1] GotoIf(“SIP/124-00000031”, “1?skiprg”) in new stack
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Goto (macro-hangupcall,s,4)
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: GotoIf
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:4] GotoIf(“SIP/124-00000031”, “1?skipblkvm”) in new stack
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Goto (macro-hangupcall,s,7)
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: GotoIf
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:7] GotoIf(“SIP/124-00000031”, “1?theend”) in new stack
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Goto (macro-hangupcall,s,9)
[Apr 5 18:10:27] DEBUG[19519] app_macro.c: Executed application: GotoIf
[Apr 5 18:10:27] VERBOSE[19519] logger.c: – Executing [[email protected]:9] Hangup(“SIP/124-00000031”, “”) in new stack
[Apr 5 18:10:27] VERBOSE[19519] logger.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘SIP/124-00000031’ in macro ‘hangupcall’
[Apr 5 18:10:27] VERBOSE[19519] logger.c: == Spawn extension (from-internal, h, 1) exited non-zero on ‘SIP/124-00000031’
[Apr 5 18:10:30] NOTICE[11704] chan_sip.c: Peer ‘112’ is now Reachable. (76ms / 2000ms)
[Apr 5 18:10:30] NOTICE[11704] chan_sip.c: Peer ‘111’ is now Reachable. (74ms / 2000ms)
[Apr 5 18:10:31] VERBOSE[19548] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Apr 5 18:10:31] VERBOSE[19548] logger.c: Found
[Apr 5 18:10:31] VERBOSE[19548] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Apr 5 18:10:31] VERBOSE[19548] logger.c: Found
[Apr 5 18:10:31] VERBOSE[19548] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Apr 5 18:10:31] VERBOSE[19548] logger.c: Found
[Apr 5 18:10:31] VERBOSE[19548] logger.c: == Manager ‘admin’ logged on from 127.0.0.1

Still no errors, but now the only warning is WARNING[19519] app_dial.c: Unable to create channel of type ‘SIP’ (cause 20 - Unknown).

Do you guys have any idea what could be going on here?

I’ve exact same issue, need help.