I'm sorry, an error has occurred - voice mail - new install

When ever voicemail should be picking up, a message is played: “I’m sorry, an error has occurred” instead of voice mail picking up. It happens on all extensions, even after reset.

CentOS 5.2
Kernel version 2.6.18-92.1.18.el5 (SMP)
Free PBX

Can anyone point me in the right direction?

please provide the following information:

version of FreePBX, Version of Asterisk, this a distro build or hand build?

Lastly a call trace showing the problem.

It sounds like a permissions problem but it’s hard to tell with what you have provided.

Thank you for the quick response!
FreePBX 2.5.1
Trixbox CE distro
I’m not sure how to check the asterisk version, but here’s the log file:

[Mar 5 14:26:42] VERBOSE[4199] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Mar 5 14:26:42] VERBOSE[4199] logger.c: Found
[Mar 5 14:26:42] VERBOSE[4199] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Mar 5 14:26:42] VERBOSE[4199] logger.c: Found
[Mar 5 14:26:42] VERBOSE[4199] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Mar 5 14:26:42] VERBOSE[4199] logger.c: Found
[Mar 5 14:26:42] VERBOSE[4199] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Mar 5 14:26:42] VERBOSE[4199] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Mar 5 14:26:56] VERBOSE[4203] logger.c: – Executing [[email protected]:1] ResetCDR(“SIP/503-08e76d68”, “”) in new stack
[Mar 5 14:26:56] VERBOSE[4203] logger.c: – Executing [[email protected]:2] NoCDR(“SIP/503-08e76d68”, “”) in new stack
[Mar 5 14:26:56] VERBOSE[4203] logger.c: – Executing [[email protected]:3] Wait(“SIP/503-08e76d68”, “1”) in new stack
[Mar 5 14:26:57] VERBOSE[4203] logger.c: == Spawn extension (from-internal, 11, 3) exited non-zero on ‘SIP/503-08e76d68’
[Mar 5 14:26:57] VERBOSE[4203] logger.c: – Executing [[email protected]:1] Macro(“SIP/503-08e76d68”, “hangupcall”) in new stack
[Mar 5 14:26:57] VERBOSE[4203] logger.c: – Executing [[email protected]:1] ResetCDR(“SIP/503-08e76d68”, “w”) in new stack
[Mar 5 14:26:57] DEBUG[4203] app_macro.c: Executed application: ResetCDR
[Mar 5 14:26:57] VERBOSE[4203] logger.c: – Executing [[email protected]:2] NoCDR(“SIP/503-08e76d68”, “”) in new stack
[Mar 5 14:26:57] DEBUG[4203] app_macro.c: Executed application: NoCDR
[Mar 5 14:26:57] VERBOSE[4203] logger.c: – Executing [[email protected]:3] GotoIf(“SIP/503-08e76d68”, “1?skiprg”) in new stack
[Mar 5 14:26:57] VERBOSE[4203] logger.c: – Goto (macro-hangupcall,s,6)
[Mar 5 14:26:57] DEBUG[4203] app_macro.c: Executed application: GotoIf
[Mar 5 14:26:57] VERBOSE[4203] logger.c: – Executing [[email protected]:6] GotoIf(“SIP/503-08e76d68”, “1?skipblkvm”) in new stack
[Mar 5 14:26:57] VERBOSE[4203] logger.c: – Goto (macro-hangupcall,s,9)
[Mar 5 14:26:57] DEBUG[4203] app_macro.c: Executed application: GotoIf
[Mar 5 14:26:57] VERBOSE[4203] logger.c: – Executing [[email protected]:9] GotoIf(“SIP/503-08e76d68”, “1?theend”) in new stack
[Mar 5 14:26:57] VERBOSE[4203] logger.c: – Goto (macro-hangupcall,s,11)
[Mar 5 14:26:57] DEBUG[4203] app_macro.c: Executed application: GotoIf
[Mar 5 14:26:57] VERBOSE[4203] logger.c: – Executing [[email protected]:11] Hangup(“SIP/503-08e76d68”, “”) in new stack
[Mar 5 14:26:57] VERBOSE[4203] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘SIP/503-08e76d68’ in macro ‘hangupcall’
[Mar 5 14:26:57] VERBOSE[4203] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘SIP/503-08e76d68’
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:1] Macro(“SIP/503-08e76d68”, “exten-vm|500|500”) in new stack
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:1] Macro(“SIP/503-08e76d68”, “user-callerid”) in new stack
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:1] Set(“SIP/503-08e76d68”, “AMPUSER=503”) in new stack
[Mar 5 14:27:03] DEBUG[4207] app_macro.c: Executed application: Set
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:2] GotoIf(“SIP/503-08e76d68”, “0?report”) in new stack
[Mar 5 14:27:03] DEBUG[4207] app_macro.c: Executed application: GotoIf
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:3] ExecIf(“SIP/503-08e76d68”, “1|Set|REALCALLERIDNUM=503”) in new stack
[Mar 5 14:27:03] DEBUG[4207] app_macro.c: Executed application: ExecIf
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:4] Set(“SIP/503-08e76d68”, “AMPUSER=503”) in new stack
[Mar 5 14:27:03] DEBUG[4207] app_macro.c: Executed application: Set
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:5] Set(“SIP/503-08e76d68”, “AMPUSERCIDNAME=Office”) in new stack
[Mar 5 14:27:03] DEBUG[4207] app_macro.c: Executed application: Set
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:6] GotoIf(“SIP/503-08e76d68”, “0?report”) in new stack
[Mar 5 14:27:03] DEBUG[4207] app_macro.c: Executed application: GotoIf
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:7] Set(“SIP/503-08e76d68”, “AMPUSERCID=503”) in new stack
[Mar 5 14:27:03] DEBUG[4207] app_macro.c: Executed application: Set
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:8] Set(“SIP/503-08e76d68”, “CALLERID(all)=“Office” <503>”) in new stack
[Mar 5 14:27:03] DEBUG[4207] app_macro.c: Executed application: Set
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:9] Set(“SIP/503-08e76d68”, “REALCALLERIDNUM=503”) in new stack
[Mar 5 14:27:03] DEBUG[4207] app_macro.c: Executed application: Set
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:10] ExecIf(“SIP/503-08e76d68”, “0|Set|CHANNEL(language)=”) in new stack
[Mar 5 14:27:03] DEBUG[4207] app_macro.c: Executed application: ExecIf
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:11] GotoIf(“SIP/503-08e76d68”, “0?continue”) in new stack
[Mar 5 14:27:03] DEBUG[4207] app_macro.c: Executed application: GotoIf
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:12] Set(“SIP/503-08e76d68”, “__TTL=64”) in new stack
[Mar 5 14:27:03] DEBUG[4207] app_macro.c: Executed application: Set
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:13] GotoIf(“SIP/503-08e76d68”, “1?continue”) in new stack
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Goto (macro-user-callerid,s,20)
[Mar 5 14:27:03] DEBUG[4207] app_macro.c: Executed application: GotoIf
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:20] NoOp(“SIP/503-08e76d68”, “Using CallerID “Office” <503>”) in new stack
[Mar 5 14:27:03] DEBUG[4207] app_macro.c: Executed application: Noop
[Mar 5 14:27:03] DEBUG[4207] app_macro.c: Executed application: Macro
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:2] Set(“SIP/503-08e76d68”, “RingGroupMethod=none”) in new stack
[Mar 5 14:27:03] DEBUG[4207] app_macro.c: Executed application: Set
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:3] Set(“SIP/503-08e76d68”, “VMBOX=500”) in new stack
[Mar 5 14:27:03] DEBUG[4207] app_macro.c: Executed application: Set
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:4] Set(“SIP/503-08e76d68”, “EXTTOCALL=500”) in new stack
[Mar 5 14:27:03] DEBUG[4207] app_macro.c: Executed application: Set
[Mar 5 14:27:03] DEBUG[4207] func_db.c: DB: CFU/500 not found in database.
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:5] Set(“SIP/503-08e76d68”, “CFUEXT=”) in new stack
[Mar 5 14:27:03] DEBUG[4207] app_macro.c: Executed application: Set
[Mar 5 14:27:03] DEBUG[4207] func_db.c: DB: CFB/500 not found in database.
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:6] Set(“SIP/503-08e76d68”, “CFBEXT=”) in new stack
[Mar 5 14:27:03] DEBUG[4207] app_macro.c: Executed application: Set
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:7] Set(“SIP/503-08e76d68”, “RT=15”) in new stack
[Mar 5 14:27:03] DEBUG[4207] app_macro.c: Executed application: Set
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:8] Macro(“SIP/503-08e76d68”, “record-enable|500|IN”) in new stack
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:1] GotoIf(“SIP/503-08e76d68”, “1?check”) in new stack
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Goto (macro-record-enable,s,4)
[Mar 5 14:27:03] DEBUG[4207] app_macro.c: Executed application: GotoIf
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:4] AGI(“SIP/503-08e76d68”, “recordingcheck|20090305-142703|1236281223.11”) in new stack
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
[Mar 5 14:27:03] VERBOSE[4207] logger.c: recordingcheck|20090305-142703|1236281223.11: Inbound recording not enabled
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – AGI Script recordingcheck completed, returning 0
[Mar 5 14:27:03] DEBUG[4207] app_macro.c: Executed application: AGI
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:5] MacroExit(“SIP/503-08e76d68”, “”) in new stack
[Mar 5 14:27:03] DEBUG[4207] app_macro.c: Executed application: Macro
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:9] Macro(“SIP/503-08e76d68”, “dial|15|tr|500”) in new stack
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:1] GotoIf(“SIP/503-08e76d68”, “1?dial”) in new stack
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Goto (macro-dial,s,3)
[Mar 5 14:27:03] DEBUG[4207] app_macro.c: Executed application: GotoIf
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:3] AGI(“SIP/503-08e76d68”, “dialparties.agi”) in new stack
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[Mar 5 14:27:03] VERBOSE[4207] logger.c: dialparties.agi: Starting New Dialparties.agi
[Mar 5 14:27:03] VERBOSE[4210] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Mar 5 14:27:03] VERBOSE[4210] logger.c: Found
[Mar 5 14:27:03] VERBOSE[4210] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Mar 5 14:27:03] VERBOSE[4210] logger.c: Found
[Mar 5 14:27:03] VERBOSE[4210] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Mar 5 14:27:03] VERBOSE[4210] logger.c: Found
[Mar 5 14:27:03] VERBOSE[4210] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Mar 5 14:27:03] VERBOSE[4207] logger.c: dialparties.agi: Caller ID name is ‘Office’ number is ‘503’
[Mar 5 14:27:03] VERBOSE[4207] logger.c: dialparties.agi: Methodology of ring is ‘none’
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – dialparties.agi: Added extension 500 to extension map
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – dialparties.agi: Extension 500 cf is disabled
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – dialparties.agi: Extension 500 do not disturb is disabled
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – dialparties.agi: dbset CALLTRACE/500 to 503
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – dialparties.agi: Filtered ARG3: 500
[Mar 5 14:27:03] VERBOSE[4210] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – AGI Script dialparties.agi completed, returning 0
[Mar 5 14:27:03] DEBUG[4207] app_macro.c: Executed application: AGI
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Executing [[email protected]:7] Dial(“SIP/503-08e76d68”, “SIP/500|15|tr”) in new stack
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – Called 500
[Mar 5 14:27:03] VERBOSE[4207] logger.c: – SIP/500-08f1e140 is ringing
[Mar 5 14:27:18] VERBOSE[4207] logger.c: – Nobody picked up in 15000 ms
[Mar 5 14:27:18] DEBUG[4207] app_macro.c: Executed application: Dial
[Mar 5 14:27:18] VERBOSE[4207] logger.c: – Executing [[email protected]:8] Set(“SIP/503-08e76d68”, “DIALSTATUS=NOANSWER”) in new stack

I trimmed your post as we didn’t need the top 3/4 of it. It also looks like you didn’t get the very end of it either as the last line is where it is about to dial the extension.

you can get the asterisk version by typing asterisk -r at the linux command line and it will show it when it opens the connection to asterisk. It looks like a 1.4.x version.

A more complete trace to the end (basically the next 50 lines or so) would help. But first at the linus prompt type “amportal chown” without the quotes and see if that solves the problem.

I tried the amportal chown but it did not help. I noticed in the log dump recording is not enabled, if that is significant.

Here’s the latest dump. Thanks again!

[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:1] Macro(“SIP/503-08f1a1c8”, “exten-vm|500|500”) in new stack
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:1] Macro(“SIP/503-08f1a1c8”, “user-callerid”) in new stack
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:1] Set(“SIP/503-08f1a1c8”, “AMPUSER=503”) in new stack
[Mar 5 17:22:09] DEBUG[5159] app_macro.c: Executed application: Set
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:2] GotoIf(“SIP/503-08f1a1c8”, “0?report”) in new stack
[Mar 5 17:22:09] DEBUG[5159] app_macro.c: Executed application: GotoIf
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:3] ExecIf(“SIP/503-08f1a1c8”, “1|Set|REALCALLERIDNUM=503”) in new stack
[Mar 5 17:22:09] DEBUG[5159] app_macro.c: Executed application: ExecIf
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:4] Set(“SIP/503-08f1a1c8”, “AMPUSER=503”) in new stack
[Mar 5 17:22:09] DEBUG[5159] app_macro.c: Executed application: Set
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:5] Set(“SIP/503-08f1a1c8”, “AMPUSERCIDNAME=Office”) in new stack
[Mar 5 17:22:09] DEBUG[5159] app_macro.c: Executed application: Set
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:6] GotoIf(“SIP/503-08f1a1c8”, “0?report”) in new stack
[Mar 5 17:22:09] DEBUG[5159] app_macro.c: Executed application: GotoIf
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:7] Set(“SIP/503-08f1a1c8”, “AMPUSERCID=503”) in new stack
[Mar 5 17:22:09] DEBUG[5159] app_macro.c: Executed application: Set
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:8] Set(“SIP/503-08f1a1c8”, “CALLERID(all)=“Office” <503>”) in new stack
[Mar 5 17:22:09] DEBUG[5159] app_macro.c: Executed application: Set
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:9] Set(“SIP/503-08f1a1c8”, “REALCALLERIDNUM=503”) in new stack
[Mar 5 17:22:09] DEBUG[5159] app_macro.c: Executed application: Set
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:10] ExecIf(“SIP/503-08f1a1c8”, “0|Set|CHANNEL(language)=”) in new stack
[Mar 5 17:22:09] DEBUG[5159] app_macro.c: Executed application: ExecIf
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:11] GotoIf(“SIP/503-08f1a1c8”, “0?continue”) in new stack
[Mar 5 17:22:09] DEBUG[5159] app_macro.c: Executed application: GotoIf
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:12] Set(“SIP/503-08f1a1c8”, “__TTL=64”) in new stack
[Mar 5 17:22:09] DEBUG[5159] app_macro.c: Executed application: Set
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:13] GotoIf(“SIP/503-08f1a1c8”, “1?continue”) in new stack
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Goto (macro-user-callerid,s,20)
[Mar 5 17:22:09] DEBUG[5159] app_macro.c: Executed application: GotoIf
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:20] NoOp(“SIP/503-08f1a1c8”, “Using CallerID “Office” <503>”) in new stack
[Mar 5 17:22:09] DEBUG[5159] app_macro.c: Executed application: Noop
[Mar 5 17:22:09] DEBUG[5159] app_macro.c: Executed application: Macro
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:2] Set(“SIP/503-08f1a1c8”, “RingGroupMethod=none”) in new stack
[Mar 5 17:22:09] DEBUG[5159] app_macro.c: Executed application: Set
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:3] Set(“SIP/503-08f1a1c8”, “VMBOX=500”) in new stack
[Mar 5 17:22:09] DEBUG[5159] app_macro.c: Executed application: Set
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:4] Set(“SIP/503-08f1a1c8”, “EXTTOCALL=500”) in new stack
[Mar 5 17:22:09] DEBUG[5159] app_macro.c: Executed application: Set
[Mar 5 17:22:09] DEBUG[5159] func_db.c: DB: CFU/500 not found in database.
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:5] Set(“SIP/503-08f1a1c8”, “CFUEXT=”) in new stack
[Mar 5 17:22:09] DEBUG[5159] app_macro.c: Executed application: Set
[Mar 5 17:22:09] DEBUG[5159] func_db.c: DB: CFB/500 not found in database.
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:6] Set(“SIP/503-08f1a1c8”, “CFBEXT=”) in new stack
[Mar 5 17:22:09] DEBUG[5159] app_macro.c: Executed application: Set
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:7] Set(“SIP/503-08f1a1c8”, “RT=15”) in new stack
[Mar 5 17:22:09] DEBUG[5159] app_macro.c: Executed application: Set
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:8] Macro(“SIP/503-08f1a1c8”, “record-enable|500|IN”) in new stack
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:1] GotoIf(“SIP/503-08f1a1c8”, “1?check”) in new stack
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Goto (macro-record-enable,s,4)
[Mar 5 17:22:09] DEBUG[5159] app_macro.c: Executed application: GotoIf
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:4] AGI(“SIP/503-08f1a1c8”, “recordingcheck|20090305-172209|1236291729.13”) in new stack
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
[Mar 5 17:22:09] VERBOSE[5159] logger.c: recordingcheck|20090305-172209|1236291729.13: Inbound recording not enabled
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – AGI Script recordingcheck completed, returning 0
[Mar 5 17:22:09] DEBUG[5159] app_macro.c: Executed application: AGI
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:5] MacroExit(“SIP/503-08f1a1c8”, “”) in new stack
[Mar 5 17:22:09] DEBUG[5159] app_macro.c: Executed application: Macro
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:9] Macro(“SIP/503-08f1a1c8”, “dial|15|tr|500”) in new stack
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:1] GotoIf(“SIP/503-08f1a1c8”, “1?dial”) in new stack
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Goto (macro-dial,s,3)
[Mar 5 17:22:09] DEBUG[5159] app_macro.c: Executed application: GotoIf
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:3] AGI(“SIP/503-08f1a1c8”, “dialparties.agi”) in new stack
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[Mar 5 17:22:09] VERBOSE[5159] logger.c: dialparties.agi: Starting New Dialparties.agi
[Mar 5 17:22:09] VERBOSE[5162] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Mar 5 17:22:09] VERBOSE[5162] logger.c: Found
[Mar 5 17:22:09] VERBOSE[5162] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Mar 5 17:22:09] VERBOSE[5162] logger.c: Found
[Mar 5 17:22:09] VERBOSE[5162] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Mar 5 17:22:09] VERBOSE[5162] logger.c: Found
[Mar 5 17:22:09] VERBOSE[5162] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Mar 5 17:22:09] VERBOSE[5159] logger.c: dialparties.agi: Caller ID name is ‘Office’ number is ‘503’
[Mar 5 17:22:09] VERBOSE[5159] logger.c: dialparties.agi: Methodology of ring is ‘none’
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – dialparties.agi: Added extension 500 to extension map
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – dialparties.agi: Extension 500 cf is disabled
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – dialparties.agi: Extension 500 do not disturb is disabled
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – dialparties.agi: dbset CALLTRACE/500 to 503
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – dialparties.agi: Filtered ARG3: 500
[Mar 5 17:22:09] VERBOSE[5162] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – AGI Script dialparties.agi completed, returning 0
[Mar 5 17:22:09] DEBUG[5159] app_macro.c: Executed application: AGI
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Executing [[email protected]:7] Dial(“SIP/503-08f1a1c8”, “SIP/500|15|tr”) in new stack
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – Called 500
[Mar 5 17:22:09] VERBOSE[5159] logger.c: – SIP/500-08f1e140 is ringing
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Nobody picked up in 15000 ms
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: Dial
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:8] Set(“SIP/503-08f1a1c8”, “DIALSTATUS=NOANSWER”) in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: Set
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:9] GosubIf(“SIP/503-08f1a1c8”, “0?NOANSWER|1”) in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: GosubIf
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: Macro
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:10] GotoIf(“SIP/503-08f1a1c8”, “0?exit|return”) in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: GotoIf
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:11] Set(“SIP/503-08f1a1c8”, “SV_DIALSTATUS=NOANSWER”) in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: Set
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:12] GosubIf(“SIP/503-08f1a1c8”, “0?docfu|1”) in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: GosubIf
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:13] GosubIf(“SIP/503-08f1a1c8”, “0?docfb|1”) in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: GosubIf
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:14] Set(“SIP/503-08f1a1c8”, “DIALSTATUS=NOANSWER”) in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: Set
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:15] NoOp(“SIP/503-08f1a1c8”, “Voicemail is 500”) in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: NoOp
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:16] GotoIf(“SIP/503-08f1a1c8”, “0?s-NOANSWER|1”) in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: GotoIf
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:17] NoOp(“SIP/503-08f1a1c8”, “Sending to Voicemail box 500”) in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: NoOp
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:18] Macro(“SIP/503-08f1a1c8”, “vm|500|NOANSWER|”) in new stack
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:1] Macro(“SIP/503-08f1a1c8”, “user-callerid|SKIPTTL”) in new stack
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:1] Set(“SIP/503-08f1a1c8”, “AMPUSER=503”) in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: Set
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:2] GotoIf(“SIP/503-08f1a1c8”, “0?report”) in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: GotoIf
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:3] ExecIf(“SIP/503-08f1a1c8”, “0|Set|REALCALLERIDNUM=503”) in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: ExecIf
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:4] Set(“SIP/503-08f1a1c8”, “AMPUSER=503”) in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: Set
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:5] Set(“SIP/503-08f1a1c8”, “AMPUSERCIDNAME=Office”) in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: Set
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:6] GotoIf(“SIP/503-08f1a1c8”, “0?report”) in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: GotoIf
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:7] Set(“SIP/503-08f1a1c8”, “AMPUSERCID=503”) in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: Set
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:8] Set(“SIP/503-08f1a1c8”, “CALLERID(all)=“Office” <503>”) in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: Set
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:9] Set(“SIP/503-08f1a1c8”, “REALCALLERIDNUM=503”) in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: Set
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:10] ExecIf(“SIP/503-08f1a1c8”, “0|Set|CHANNEL(language)=”) in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: ExecIf
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:11] GotoIf(“SIP/503-08f1a1c8”, “1?continue”) in new stack
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Goto (macro-user-callerid,s,20)
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: GotoIf
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:20] NoOp(“SIP/503-08f1a1c8”, “Using CallerID “Office” <503>”) in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: Noop
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: Macro
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:2] Set(“SIP/503-08f1a1c8”, “VMGAIN=”"") in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: Set
[Mar 5 17:22:24] WARNING[5159] func_db.c: DB requires an argument, DB(/)
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:3] GotoIf(“SIP/503-08f1a1c8”, “1?vmx|1”) in new stack
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Goto (macro-vm,vmx,1)
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: GotoIf
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:1] GotoIf(“SIP/503-08f1a1c8”, “0?s-NOANSWER|1”) in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: GotoIf
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:2] Set(“SIP/503-08f1a1c8”, “MODE=unavail”) in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: Set
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:3] GotoIf(“SIP/503-08f1a1c8”, “1?notdirect”) in new stack
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Goto (macro-vm,vmx,5)
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: GotoIf
[Mar 5 17:22:24] DEBUG[5159] func_db.c: DB: AMPUSER/500/vmx/unavail/state not found in database.
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:5] NoOp(“SIP/503-08f1a1c8”, "Checking if ext 500 is enabled: ") in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: Noop
[Mar 5 17:22:24] DEBUG[5159] func_db.c: DB: AMPUSER/500/vmx/unavail/state not found in database.
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:6] GotoIf(“SIP/503-08f1a1c8”, “1?s-NOANSWER|1”) in new stack
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Goto (macro-vm,s-NOANSWER,1)
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: GotoIf
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:1] Macro(“SIP/503-08f1a1c8”, “get-vmcontext|500”) in new stack
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:1] Set(“SIP/503-08f1a1c8”, “VMCONTEXT=default”) in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: Set
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:2] GotoIf(“SIP/503-08f1a1c8”, “0?200:300”) in new stack
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Goto (macro-get-vmcontext,s,300)
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: GotoIf
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:300] NoOp(“SIP/503-08f1a1c8”, “”) in new stack
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: NoOp
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: Macro
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:2] VoiceMail(“SIP/503-08f1a1c8”, “[email protected]|u”) in new stack
[Mar 5 17:22:24] WARNING[5159] app_voicemail.c: No entry in voicemail config file for ‘500’
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: Voicemail
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:3] Goto(“SIP/503-08f1a1c8”, “exit-FAILED|1”) in new stack
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Goto (macro-vm,exit-FAILED,1)
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: Goto
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – Executing [[email protected]:1] Playback(“SIP/503-08f1a1c8”, “im-sorry&an-error-has-occured”) in new stack
[Mar 5 17:22:24] VERBOSE[5159] logger.c: – <SIP/503-08f1a1c8> Playing ‘im-sorry’ (language ‘en’)
[Mar 5 17:22:25] VERBOSE[5159] logger.c: – <SIP/503-08f1a1c8> Playing ‘an-error-has-occured’ (language ‘en’)
[Mar 5 17:22:27] DEBUG[5159] app_macro.c: Executed application: Playback
[Mar 5 17:22:27] VERBOSE[5159] logger.c: – Executing [[email protected]:2] GotoIf(“SIP/503-08f1a1c8”, “0?exit-RETURN|1”) in new stack
[Mar 5 17:22:27] DEBUG[5159] app_macro.c: Executed application: GotoIf
[Mar 5 17:22:27] VERBOSE[5159] logger.c: – Executing [[email protected]:3] Hangup(“SIP/503-08f1a1c8”, “”) in new stack
[Mar 5 17:22:27] VERBOSE[5159] logger.c: == Spawn extension (macro-vm, exit-FAILED, 3) exited non-zero on ‘SIP/503-08f1a1c8’ in macro ‘vm’
[Mar 5 17:22:27] VERBOSE[5159] logger.c: == Spawn extension (macro-vm, exit-FAILED, 3) exited non-zero on ‘SIP/503-08f1a1c8’ in macro ‘exten-vm’
[Mar 5 17:22:27] VERBOSE[5159] logger.c: == Spawn extension (macro-vm, exit-FAILED, 3) exited non-zero on ‘SIP/503-08f1a1c8’
[Mar 5 17:23:27] VERBOSE[5165] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Mar 5 17:23:27] VERBOSE[5165] logger.c: Found
[Mar 5 17:23:27] VERBOSE[5165] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Mar 5 17:23:27] VERBOSE[5165] logger.c: Found
[Mar 5 17:23:27] VERBOSE[5165] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Mar 5 17:23:27] VERBOSE[5165] logger.c: Found
[Mar 5 17:23:27] VERBOSE[5165] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Mar 5 17:23:27] VERBOSE[5166] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Mar 5 17:23:27] VERBOSE[5166] logger.c: Found
[Mar 5 17:23:27] VERBOSE[5166] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Mar 5 17:23:27] VERBOSE[5166] logger.c: Found
[Mar 5 17:23:27] VERBOSE[5166] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Mar 5 17:23:27] VERBOSE[5166] logger.c: Found
[Mar 5 17:23:27] VERBOSE[5166] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Mar 5 17:23:27] VERBOSE[5166] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Mar 5 17:23:27] VERBOSE[5156] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Mar 5 17:24:27] VERBOSE[5169] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Mar 5 17:24:27] VERBOSE[5169] logger.c: Found
[Mar 5 17:24:27] VERBOSE[5169] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Mar 5 17:24:27] VERBOSE[5169] logger.c: Found
[Mar 5 17:24:27] VERBOSE[5169] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Mar 5 17:24:27] VERBOSE[5169] logger.c: Found
[Mar 5 17:24:27] VERBOSE[5169] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Mar 5 17:24:27] VERBOSE[5170] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Mar 5 17:24:27] VERBOSE[5170] logger.c: Found
[Mar 5 17:24:27] VERBOSE[5170] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Mar 5 17:24:27] VERBOSE[5170] logger.c: Found
[Mar 5 17:24:27] VERBOSE[5170] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Mar 5 17:24:27] VERBOSE[5170] logger.c: Found
[Mar 5 17:24:27] VERBOSE[5170] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Mar 5 17:24:27] VERBOSE[5170] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Mar 5 17:24:27] VERBOSE[5165] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Mar 5 17:25:27] VERBOSE[5171] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Mar 5 17:25:27] VERBOSE[5171] logger.c: Found
[Mar 5 17:25:27] VERBOSE[5171] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Mar 5 17:25:27] VERBOSE[5171] logger.c: Found
[Mar 5 17:25:27] VERBOSE[5171] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Mar 5 17:25:27] VERBOSE[5171] logger.c: Found
[Mar 5 17:25:27] VERBOSE[5171] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Mar 5 17:25:27] VERBOSE[5172] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Mar 5 17:25:27] VERBOSE[5172] logger.c: Found
[Mar 5 17:25:27] VERBOSE[5172] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Mar 5 17:25:27] VERBOSE[5172] logger.c: Found
[Mar 5 17:25:27] VERBOSE[5172] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Mar 5 17:25:27] VERBOSE[5172] logger.c: Found
[Mar 5 17:25:27] VERBOSE[5172] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Mar 5 17:25:27] VERBOSE[5172] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Mar 5 17:25:27] VERBOSE[5169] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Mar 5 17:26:27] VERBOSE[5171] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Mar 5 17:26:27] VERBOSE[5175] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Mar 5 17:26:27] VERBOSE[5175] logger.c: Found
[Mar 5 17:26:27] VERBOSE[5175] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Mar 5 17:26:27] VERBOSE[5175] logger.c: Found
[Mar 5 17:26:27] VERBOSE[5175] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Mar 5 17:26:27] VERBOSE[5175] logger.c: Found
[Mar 5 17:26:27] VERBOSE[5175] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Mar 5 17:26:27] VERBOSE[5176] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Mar 5 17:26:27] VERBOSE[5176] logger.c: Found
[Mar 5 17:26:27] VERBOSE[5176] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Mar 5 17:26:27] VERBOSE[5176] logger.c: Found
[Mar 5 17:26:27] VERBOSE[5176] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Mar 5 17:26:27] VERBOSE[5176] logger.c: Found
[Mar 5 17:26:27] VERBOSE[5176] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Mar 5 17:26:27] VERBOSE[5176] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Mar 5 17:27:27] VERBOSE[5179] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Mar 5 17:27:27] VERBOSE[5179] logger.c: Found
[Mar 5 17:27:27] VERBOSE[5179] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Mar 5 17:27:27] VERBOSE[5179] logger.c: Found
[Mar 5 17:27:27] VERBOSE[5179] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Mar 5 17:27:27] VERBOSE[5179] logger.c: Found
[Mar 5 17:27:27] VERBOSE[5179] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Mar 5 17:27:27] VERBOSE[5180] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Mar 5 17:27:27] VERBOSE[5180] logger.c: Found
[Mar 5 17:27:27] VERBOSE[5180] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Mar 5 17:27:27] VERBOSE[5180] logger.c: Found
[Mar 5 17:27:27] VERBOSE[5180] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Mar 5 17:27:27] VERBOSE[5180] logger.c: Found
[Mar 5 17:27:27] VERBOSE[5180] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Mar 5 17:27:27] VERBOSE[5180] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Mar 5 17:27:27] VERBOSE[5175] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Mar 5 17:28:27] VERBOSE[5183] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Mar 5 17:28:27] VERBOSE[5183] logger.c: Found
[Mar 5 17:28:27] VERBOSE[5183] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Mar 5 17:28:27] VERBOSE[5183] logger.c: Found
[Mar 5 17:28:27] VERBOSE[5183] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Mar 5 17:28:27] VERBOSE[5183] logger.c: Found
[Mar 5 17:28:27] VERBOSE[5183] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Mar 5 17:28:27] VERBOSE[5184] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Mar 5 17:28:27] VERBOSE[5184] logger.c: Found
[Mar 5 17:28:27] VERBOSE[5184] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Mar 5 17:28:27] VERBOSE[5184] logger.c: Found
[Mar 5 17:28:27] VERBOSE[5184] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Mar 5 17:28:27] VERBOSE[5184] logger.c: Found
[Mar 5 17:28:27] VERBOSE[5184] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Mar 5 17:28:27] VERBOSE[5184] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Mar 5 17:28:27] VERBOSE[5179] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Mar 5 17:29:27] VERBOSE[5187] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Mar 5 17:29:27] VERBOSE[5187] logger.c: Found
[Mar 5 17:29:27] VERBOSE[5187] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Mar 5 17:29:27] VERBOSE[5187] logger.c: Found
[Mar 5 17:29:27] VERBOSE[5187] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Mar 5 17:29:27] VERBOSE[5187] logger.c: Found
[Mar 5 17:29:27] VERBOSE[5187] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Mar 5 17:29:27] VERBOSE[5188] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Mar 5 17:29:27] VERBOSE[5188] logger.c: Found
[Mar 5 17:29:27] VERBOSE[5188] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Mar 5 17:29:27] VERBOSE[5188] logger.c: Found
[Mar 5 17:29:27] VERBOSE[5188] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Mar 5 17:29:27] VERBOSE[5188] logger.c: Found
[Mar 5 17:29:27] VERBOSE[5188] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Mar 5 17:29:27] VERBOSE[5188] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Mar 5 17:29:27] VERBOSE[5183] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Mar 5 17:30:27] VERBOSE[5189] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Mar 5 17:30:27] VERBOSE[5189] logger.c: Found
[Mar 5 17:30:27] VERBOSE[5189] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Mar 5 17:30:27] VERBOSE[5189] logger.c: Found
[Mar 5 17:30:27] VERBOSE[5189] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Mar 5 17:30:27] VERBOSE[5189] logger.c: Found
[Mar 5 17:30:27] VERBOSE[5189] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Mar 5 17:30:27] VERBOSE[5190] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Mar 5 17:30:27] VERBOSE[5190] logger.c: Found
[Mar 5 17:30:27] VERBOSE[5190] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Mar 5 17:30:27] VERBOSE[5190] logger.c: Found
[Mar 5 17:30:27] VERBOSE[5190] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Mar 5 17:30:27] VERBOSE[5190] logger.c: Found
[Mar 5 17:30:27] VERBOSE[5190] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Mar 5 17:30:27] VERBOSE[5190] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Mar 5 17:30:27] VERBOSE[5187] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Mar 5 17:31:27] VERBOSE[5193] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Mar 5 17:31:27] VERBOSE[5193] logger.c: Found
[Mar 5 17:31:27] VERBOSE[5193] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Mar 5 17:31:27] VERBOSE[5193] logger.c: Found
[Mar 5 17:31:27] VERBOSE[5193] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Mar 5 17:31:27] VERBOSE[5193] logger.c: Found
[Mar 5 17:31:27] VERBOSE[5193] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Mar 5 17:31:27] VERBOSE[5194] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Mar 5 17:31:27] VERBOSE[5194] logger.c: Found
[Mar 5 17:31:27] VERBOSE[5194] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Mar 5 17:31:27] VERBOSE[5194] logger.c: Found
[Mar 5 17:31:27] VERBOSE[5194] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Mar 5 17:31:27] VERBOSE[5194] logger.c: Found
[Mar 5 17:31:27] VERBOSE[5194] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Mar 5 17:31:27] VERBOSE[5194] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Mar 5 17:31:27] VERBOSE[5189] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Mar 5 17:32:27] VERBOSE[5197] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Mar 5 17:32:27] VERBOSE[5197] logger.c: Found
[Mar 5 17:32:27] VERBOSE[5197] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Mar 5 17:32:27] VERBOSE[5197] logger.c: Found
[Mar 5 17:32:27] VERBOSE[5197] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Mar 5 17:32:27] VERBOSE[5197] logger.c: Found

Yes, it’s 1.4.22-3

Ok I see the error, why it is happening I don’t know. But let’s show you how to read the logs a bit so you can chase it down.

First off see these lines:

[Mar 5 17:27:27] VERBOSE[5180] logger.c: == Parsing '/etc/asterisk/manager.conf': [Mar 5 17:27:27] VERBOSE[5180] logger.c: Found
[Mar 5 17:27:27] VERBOSE[5180] logger.c: == Parsing '/etc/asterisk/manager_additional.conf': [Mar 5 17:27:27] VERBOSE[5180] logger.c: Found
[Mar 5 17:27:27] VERBOSE[5180] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': [Mar 5 17:27:27] VERBOSE[5180] logger.c: Found
[Mar 5 17:27:27] VERBOSE[5180] logger.c: == Manager 'admin' logged on from 127.0.0.1
[Mar 5 17:27:27] VERBOSE[5180] logger.c: == Manager 'admin' logged off from 127.0.0.1

unless you are having AMI (asterisk management interface) issues they are not important. It’s just showing that it get’s a login request, it walks the files to valid users, checks and allows the admin to login and then it logs out (it’s a part of the dashboard checking that asterisk is ok when it displays the status).

Next below is where the error is. So that you know 95% of all of the standard audio is named exactly what say’s so if you searched for the word sorry you’d find it playing the audio. Then you work backwards as it determined the error before playing the audio…

[Mar 5 17:22:24] WARNING[5159] app_voicemail.c: No entry in voicemail config file for '500'
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: Voicemail
[Mar 5 17:22:24] VERBOSE[5159] logger.c: -- Executing [[email protected]:3] Goto("SIP/503-08f1a1c8", "exit-FAILED|1") in new stack
[Mar 5 17:22:24] VERBOSE[5159] logger.c: -- Goto (macro-vm,exit-FAILED,1)
[Mar 5 17:22:24] DEBUG[5159] app_macro.c: Executed application: Goto
[Mar 5 17:22:24] VERBOSE[5159] logger.c: -- Executing [[email protected]:1] Playback("SIP/503-08f1a1c8", "im-sorry&an-error-has-occured") in new stack
[Mar 5 17:22:24] VERBOSE[5159] logger.c: -- Playing 'im-sorry' (language 'en')
[Mar 5 17:22:25] VERBOSE[5159] logger.c: -- Playing 'an-error-has-occured' (language 'en')
[Mar 5 17:22:27] DEBUG[5159] app_macro.c: Executed application: Playback

Now working backwards look for something that does not look right and I made it easy but the first line I started with is the error. You configured extension 500 for voicemail but when the system went to read the voicemail.conf file which contains the info about voicemail for all extensions it didn’t find a entry in the file for it. That’s why you are getting the error. Something is wrong with the file and/or when you created the extensions it could not write the data to the file.

1 Like

I wonder if the permissions are not set correctly on the voicemail.conf file, because I am having this issue with all extensions. Can you tell me what the correct permissions are and how one goes about setting them? I really appreciate all your help! Thank you.

My version is 1.4.23.1 on CentOS 5.2. I looked at the voicemail.conf and I do see all the extentions… Please help. I am using AsteriskNow and I am also new to AsteriskNOw/FreePBX. I have not made any manual changes to voicemail.conf. All the ext are giving the same message “sorry, an error has occurred”.

rmalerman,
Sorry I lost track of this thread when I was away from the office for a few days. Did you solve it? rights for the file are asterisk:asterisk and permissions are 664. You never provided your voicemail.conf file which if there is a formatting error in it someplace can easly cause all kinds of issues.

voicemail will not work until the extension has has gone in and accessed it once, preferably recording a greeting so that one can be played when it is put into action.

Thanx for the feedback… I try to setup a voice mail by using *98 and *97 and I am keep getting “login incorrect” voicemail.conf has the entry for all the extentions under defualt. I also made sure that rfc2833 is set for DTMFMode on FreePBX/Ext. as well as on one of the softphone which did allow an option to pick under setting. I also tired few different softphone software including x-lite,sjphone, global IP, etc and they are doing the same thing. I am having this problem on all the ext. and they are just created. This is a new install with CentOS 5.2.

Thank you fskrotzki for leading me into the right direction. I updated the voicemail.conf and removed two lines after [defualt], which were blank [] and added [general] and [default] on the last two lines. After that I went to one of the extention disable voice mail - reload and then enable the voice mail - reload and that seem to fix it. I am very new to this, so I am not sure what all happen and why it didn’t work to start with. I didn’t make any changes to any conf files before until now so I would think that it should work right out of the box, but oh well we dont’ live in perfect world :)… Thanx Asterisk and FreePBX for the great! product and for havng this forum.

voicemail has a huge problem with a empty context (the [] line). You should not have needed to reload anything as every time voicemail is started inside asterisk it reloads the voicemail.conf file.

if AsteriskNow started with a blank voicemail.conf file that had one it’s a bug and needs to get reported. (I’m loading a copy on test box currently and will find out in a bit if that is the case).

ok I have a test copy of AsteriskNow 1.5 Beta2 running and if all you do it install it, apply changes and create extensions with voicemail yes it will have a problem.

Specifically the issue is that it creates a blank context in the voicemail.conf file and once that happens voicemail has issues.

So step one is to upgrade the FreePBX modules to current before you go creating anything as the ISO is using a older verison of FreePBX that happens to have that bug in it and was fixed already.

I have the same issue but I can’t figure out how to get to the file system from the CentOS login. Is there some command I need to use to get past the limited login screen? I can only see 3 files when I login as root!

To login to your CentOS
At the login screen type: root :Hit Enter
type in your password:*******:Hit Enter

Once logged in type:
cd /etc/asterisk/

Hit Enter

now type:

vi voicemail.conf

Hit Enter

Go to “[]” and delete this. With “DELETE”

Type “:x” hit Enter

and your done.

Just reset your voicemail in the “Extension” menu…

Thanks fskrotzki I was having the same problem, that worked for me.

\Mark

Using FreePBX 2.10 RC, and was having same issues, but the last post sorted it out - Thank You!

I’m running FreePBX 2.10 on Asterisk 1.8.12.0, and somehow my VM began to issue the same errors in this thread. System has been working flawlessly for 5 weeks, and I’m just about ready to put it into full production this week. Surprised when the errors started coming. I tried everything, but it wasn’t until I got to the post from nighthawks80 that I had success.

I just wanted everyone to know that this erros is still a possibility, although I’m not really sure why. Nice to know there’s a relatively simple fix.

I appreciate this community!

– emcompnut a.k.a. Ed