2

I have asterisk-Freepbx (Version 12) hosted on a debian 7 server. I have created an extension (Cisco IP phone SPA 504G). I am able to dial in and out. The extension is configured to go to voicemail if unanswered, busy or unavailable. However, if the extension is not answered, it goes to a busy signal and not the voicemail. When I look at the voicemail set up, it says it is 'unactivated'. I cant figure out how to get this to work or activate it.

Many thanks for any suggestions


Thanks - it was already enabled when I switched to Device and user mode. I disabled and then enabled it again - but no change.

When I go to settings>voicemail admin, this is what I see: Jas <101> (default) [unactivated]

And the following:

Number of Accounts: 1 ( 0 / 1 / 0 )

Below is the verbose debug info:

[2014-06-30 20:17:35] DEBUG[3125] acl.c: For destination '888.777.666.111', our source 

address is 111.000.000.111.
[2014-06-30 20:17:35] DEBUG[3125] chan_sip.c: Target address 888.777.666.111:5060 is not 

local, substituting externaddr
[2014-06-30 20:17:35] DEBUG[3125] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 

111.000.000.111:5060
[2014-06-30 20:17:35] DEBUG[3125] chan_sip.c: Allocating new SIP dialog for dac7fd13-

[email protected] - NOTIFY (No RTP)
[2014-06-30 20:17:35] DEBUG[3125] chan_sip.c: **** Received NOTIFY (4) - Command in SIP 

NOTIFY
[2014-06-30 20:17:35] DEBUG[3125] chan_sip.c: Trying to put 'SIP/2.0 489' onto UDP socket 

destined for 888.777.666.111:5060
[2014-06-30 20:17:35] DEBUG[3125] chan_sip.c: SIP message could not be handled, bad request: 

[email protected]
[2014-06-30 20:17:35] DEBUG[3125] chan_sip.c: = Looking for Call ID: 

[email protected]:5060 (Checking To) --From tag as5387a74c --

To-tag 22a0f837d6d0aeb9i0
[2014-06-30 20:17:35] DEBUG[3125] chan_sip.c: Acked pending invite 102
[2014-06-30 20:17:35] DEBUG[3125] chan_sip.c: Stopping retransmission on 

'[email protected]:5060' of Request 102: Match Found
[2014-06-30 20:17:35] VERBOSE[3125] chan_sip.c: -- Got SIP response 486 "Busy Here" back from 

888.777.666.111:5060
[2014-06-30 20:17:35] DEBUG[3125] res_rtp_asterisk.c: Setting RTCP address on RTP instance 

'0x35b7eb8'
[2014-06-30 20:17:35] DEBUG[3125] netsock2.c: Splitting '192.168.10.9:5060' into...
[2014-06-30 20:17:35] DEBUG[3125] netsock2.c: ...host '192.168.10.9' and port '5060'.
[2014-06-30 20:17:35] DEBUG[3125] chan_sip.c: Trying to put 'ACK sip:101' onto UDP socket 

destined for 888.777.666.111:5060
[2014-06-30 20:17:35] DEBUG[3125] chan_sip.c: Setting SIP_ALREADYGONE on dialog 

[email protected]:5060
[2014-06-30 20:17:35] VERBOSE[32392] app_dial.c: -- SIP/101-00004916 is busy
[2014-06-30 20:17:35] DEBUG[32392] channel.c: Hanging up channel 'SIP/101-00004916'
[2014-06-30 20:17:35] DEBUG[32392] chan_sip.c: Hanging up zombie call. Be scared.
[2014-06-30 20:17:35] DEBUG[32392] chan_sip.c: Updating call counter for outgoing call
[2014-06-30 20:17:35] DEBUG[32392] res_rtp_asterisk.c: Setting RTCP address on RTP instance 

'0x35b7eb8'
[2014-06-30 20:17:35] VERBOSE[32392] app_dial.c: == Everyone is busy/congested at this time 

(1:1/0/0)
[2014-06-30 20:17:35] DEBUG[32392] app_dial.c: Exiting with DIALSTATUS=BUSY.
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: Dial
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'DIALSTATUS' is 'BUSY'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'CALLER_DEST' is NULL
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Expression result is '0'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'ExecIf'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-dial-one:43] ExecIf

("SIP/123456-00004915", "0?MacroExit()") in new stack
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: ExecIf
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Evaluating 'DIALSTATUS' (from 

'DIALSTATUS}"="ANSWER" & "${CALLER_DEST}"!=""' len 10)
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'DIALSTATUS' is 'BUSY'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Evaluating 'CALLER_DEST' (from 'CALLER_DEST}"!=""' 

len 11)
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'CALLER_DEST' is NULL
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Expression result is '0'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'DIALSTATUS_CW' is ''
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Expression result is '0'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'DIALSTATUS_CW' is ''
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'ExecIf'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-dial-one:44] ExecIf

("SIP/123456-00004915", "0?Set(DIALSTATUS=)") in new stack
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: ExecIf
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Evaluating 'DIALSTATUS_CW' (from 'DIALSTATUS_CW}"!

=""' len 13)
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'DIALSTATUS_CW' is ''
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Expression result is '0'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Evaluating 'DIALSTATUS_CW' (from 'DIALSTATUS_CW})' 

len 13)
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'DIALSTATUS_CW' is ''
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'SCREEN' is NULL
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'DIALSTATUS' is 'BUSY'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'DIALSTATUS' is 'BUSY'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'DIALSTATUS' is 'BUSY'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Expression result is '0'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'DIALSTATUS' is 'BUSY'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'GosubIf'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-dial-one:45] GosubIf

("SIP/123456-00004915", "0?s-BUSY,1()") in new stack
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: GosubIf
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Evaluating 'SCREEN' (from 'SCREEN}"!=""&

("${DIALSTATUS}"="TORTURE"|"${DIALSTATUS}"="DONTCALL"))|"${DIALSTATUS}"="ANSWER"' len 6)
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'SCREEN' is NULL
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Evaluating 'DIALSTATUS' (from 

'DIALSTATUS}"="TORTURE"|"${DIALSTATUS}"="DONTCALL"))|"${DIALSTATUS}"="ANSWER"' len 10)
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'DIALSTATUS' is 'BUSY'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Evaluating 'DIALSTATUS' (from 

'DIALSTATUS}"="DONTCALL"))|"${DIALSTATUS}"="ANSWER"' len 10)
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'DIALSTATUS' is 'BUSY'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Evaluating 'DIALSTATUS' (from 

'DIALSTATUS}"="ANSWER"' len 10)
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'DIALSTATUS' is 'BUSY'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Expression result is '0'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Evaluating 'DIALSTATUS' (from 'DIALSTATUS},1()' len 

10)
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'DIALSTATUS' is 'BUSY'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'MacroExit'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-dial-one:46] MacroExit

("SIP/123456-00004915", "") in new stack
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: Macro
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'DIALSTATUS' is 'BUSY'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'Set'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-exten-vm:15] Set

("SIP/123456-00004915", "SV_DIALSTATUS=BUSY") in new stack
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: Set
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'SV_DIALSTATUS' is 'BUSY'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'SV_DIALSTATUS' is 'BUSY'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'EXTTOCALL' is '101'
[2014-06-30 20:17:35] DEBUG[32392] db.c: Unable to find key '101' in family 'CFU'
[2014-06-30 20:17:35] DEBUG[32392] func_db.c: DB: CFU/101 not found in database.
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Function result is ''
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'SCREEN' is NULL
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Expression result is '0'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'GosubIf'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-exten-vm:16] GosubIf

("SIP/123456-00004915", "0?docfu,1()") in new stack
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: GosubIf
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Evaluating 'SV_DIALSTATUS' (from 

'SV_DIALSTATUS}"="NOANSWER"|"${SV_DIALSTATUS}"="CHANUNAVAIL") & "${DB(CFU/${EXTTOCALL})}"!="" 

& "${SCREEN}"=""' len 13)
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'SV_DIALSTATUS' is 'BUSY'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Evaluating 'SV_DIALSTATUS' (from 

'SV_DIALSTATUS}"="CHANUNAVAIL") & "${DB(CFU/${EXTTOCALL})}"!="" & "${SCREEN}"=""' len 13)
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'SV_DIALSTATUS' is 'BUSY'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Evaluating 'DB(CFU/${EXTTOCALL})' (from 'DB(CFU/

${EXTTOCALL})}"!="" & "${SCREEN}"=""' len 20)
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Evaluating 'EXTTOCALL' (from 'EXTTOCALL})' len 9)
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'EXTTOCALL' is '101'
[2014-06-30 20:17:35] DEBUG[32392] db.c: Unable to find key '101' in family 'CFU'
[2014-06-30 20:17:35] DEBUG[32392] func_db.c: DB: CFU/101 not found in database.
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Function result is ''
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Evaluating 'SCREEN' (from 'SCREEN}"=""' len 6)
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'SCREEN' is NULL
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Expression result is '0'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'SV_DIALSTATUS' is 'BUSY'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'EXTTOCALL' is '101'
[2014-06-30 20:17:35] DEBUG[32392] db.c: Unable to find key '101' in family 'CFB'
[2014-06-30 20:17:35] DEBUG[32392] func_db.c: DB: CFB/101 not found in database.
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Function result is ''
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'SCREEN' is NULL
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Expression result is '0'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'GosubIf'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-exten-vm:17] GosubIf

("SIP/123456-00004915", "0?docfb,1()") in new stack
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: GosubIf
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Evaluating 'SV_DIALSTATUS' (from 

'SV_DIALSTATUS}"="BUSY" & "${DB(CFB/${EXTTOCALL})}"!="" & "${SCREEN}"=""' len 13)
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'SV_DIALSTATUS' is 'BUSY'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Evaluating 'DB(CFB/${EXTTOCALL})' (from 'DB(CFB/

${EXTTOCALL})}"!="" & "${SCREEN}"=""' len 20)
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Evaluating 'EXTTOCALL' (from 'EXTTOCALL})' len 9)
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'EXTTOCALL' is '101'
[2014-06-30 20:17:35] DEBUG[32392] db.c: Unable to find key '101' in family 'CFB'
[2014-06-30 20:17:35] DEBUG[32392] func_db.c: DB: CFB/101 not found in database.
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Function result is ''
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Evaluating 'SCREEN' (from 'SCREEN}"=""' len 6)
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'SCREEN' is NULL
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Expression result is '0'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'SV_DIALSTATUS' is 'BUSY'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'Set'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-exten-vm:18] Set

("SIP/123456-00004915", "DIALSTATUS=BUSY") in new stack
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: Set
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'DIALSTATUS' is 'BUSY'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'ARG3' is '1'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'DIALSTATUS' is 'BUSY'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'ARG4' is '1'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'DIALSTATUS' is 'BUSY'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'ARG5' is '1'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Expression result is '1'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'ExecIf'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-exten-vm:19] ExecIf

("SIP/123456-00004915", "1?MacroExit()") in new stack
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'Set'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [101@from-did-direct:3] Set

("SIP/123456-00004915", "__PICKUPMARK=") in new stack
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'DIALSTATUS' is 'BUSY'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Expression result is '0'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'GotoIf'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [101@from-did-direct:4] GotoIf

("SIP/123456-00004915", "0?ext-local,vmu101,1") in new stack
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Not taking any branch
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'DIALSTATUS' is 'BUSY'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Expression result is '1'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'GotoIf'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [101@from-did-direct:5] GotoIf

("SIP/123456-00004915", "1?ext-local,vmb101,1") in new stack
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Goto (ext-local,vmb101,1)
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'IVR_RETVM' is NULL
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'Macro'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [vmb101@ext-local:1] Macro

("SIP/123456-00004915", "vm,101,BUSY,") in new stack
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'Macro'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-vm:1] Macro("SIP/123456-

00004915", "user-callerid,SKIPTTL") in new stack
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'UNIQUEID' is '1404159446.4576'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'Set'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-user-callerid:1] Set

("SIP/123456-00004915", "TOUCH_MONITOR=1404159446.4576") in new stack
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: Set
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'AMPUSER' is ''
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Expression result is '1'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Function result is '5401112222'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'AMPUSER' is ''
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Function result is '5401112222'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'Set'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-user-callerid:2] Set

("SIP/123456-00004915", "AMPUSER=5401112222") in new stack
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: Set
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Evaluating 'CHANNEL' (from 'CHANNEL}' len 7)
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'CHANNEL' is 'SIP/123456-00004915'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Function result is ''
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'AMPUSERCIDNAME' is ''
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Function result is '0'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Expression result is '0'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'GotoIf'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-user-callerid:3] GotoIf

("SIP/123456-00004915", "0?report") in new stack
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Not taking any branch
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: GotoIf
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'REALCALLERIDNUM' is '5401112222'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Expression result is '0'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Function result is '5401112222'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'ExecIf'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-user-callerid:4] ExecIf

("SIP/123456-00004915", "0?Set(REALCALLERIDNUM=5401112222)") in new stack
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: ExecIf
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Evaluating 'REALCALLERIDNUM:1:2' (from 

'REALCALLERIDNUM:1:2}" = ""' len 19)
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'REALCALLERIDNUM' is '5401112222'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Expression result is '0'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Evaluating 'CALLERID(number)' (from 'CALLERID

(number)})' len 16)
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Function result is '5401112222'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'REALCALLERIDNUM' is '5401112222'
[2014-06-30 20:17:35] DEBUG[32392] db.c: Unable to find key '5401112222/user' in family 

'DEVICE'
[2014-06-30 20:17:35] DEBUG[32392] func_db.c: DB: DEVICE/5401112222/user not found in 

database.
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Function result is ''
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'Set'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-user-callerid:5] Set

("SIP/123456-00004915", "AMPUSER=") in new stack
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: Set
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'AMPUSER' is ''
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Expression result is '0'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'GotoIf'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-user-callerid:6] GotoIf

("SIP/123456-00004915", "0?limit") in new stack
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Not taking any branch
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: GotoIf
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'AMPUSER' is ''
[2014-06-30 20:17:35] DEBUG[32392] db.c: Unable to find key '/cidname' in family 'AMPUSER'
[2014-06-30 20:17:35] DEBUG[32392] func_db.c: DB: AMPUSER//cidname not found in database.
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Function result is ''
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'Set'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-user-callerid:7] Set

("SIP/123456-00004915", "AMPUSERCIDNAME=") in new stack
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: Set
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'AMPUSERCIDNAME' is ''
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Expression result is '1'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'GotoIf'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-user-callerid:8] GotoIf

("SIP/123456-00004915", "1?report") in new stack
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Goto (macro-user-callerid,s,16)
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: GotoIf
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'ARG1' is 'SKIPTTL'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'ARG1' is 'SKIPTTL'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Expression result is '1'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'GotoIf'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-user-callerid:16] GotoIf

("SIP/123456-00004915", "1?continue") in new stack
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Goto (macro-user-callerid,s,30)
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: GotoIf
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Function result is '5401112222'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'Set'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-user-callerid:30] Set

("SIP/123456-00004915", "CALLERID(number)=5401112222") in new stack
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: Set
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Function result is '+15401112222'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'Set'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-user-callerid:31] Set

("SIP/123456-00004915", "CALLERID(name)=+15401112222") in new stack
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: Set
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Function result is '5401112222'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'Set'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-user-callerid:32] Set

("SIP/123456-00004915", "CDR(cnum)=5401112222") in new stack
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: Set
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Function result is '+15401112222'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'Set'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-user-callerid:33] Set

("SIP/123456-00004915", "CDR(cnam)=+15401112222") in new stack
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: Set
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Evaluating 'CHANNEL(language)' (from 'CHANNEL

(language)}' len 17)
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Function result is 'en'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Function result is 'en'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'Set'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-user-callerid:34] Set

("SIP/123456-00004915", "CHANNEL(language)=en") in new stack
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: Set
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: Macro
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'VM_GAIN' is '12'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Expression result is '1'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'VM_GAIN' is '12'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Function result is 'g(12)'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'Set'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-vm:2] Set("SIP/123456-

00004915", "VMGAIN=g(12)") in new stack
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: Set
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'Macro'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-vm:3] Macro("SIP/123456-

00004915", "blkvm-check,") in new stack
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'BLKVM_CHANNEL' is NULL
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Function result is '(null)'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'Set'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-blkvm-check:1] Set

("SIP/123456-00004915", "GOSUB_RETVAL=") in new stack
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: Set
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'GOSUB_RETVAL' is ''
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'CC_RECALL' is NULL
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Expression result is '0'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'ExecIf'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-blkvm-check:2] ExecIf

("SIP/123456-00004915", "0?Set(GOSUB_RETVAL=TRUE)") in new stack
[2014-06-30 20:17:35] DEBUG[32392] app_macro.c: Executed application: ExecIf
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Evaluating 'GOSUB_RETVAL' (from 'GOSUB_RETVAL}"="" 

& "${CC_RECALL}"="1"' len 12)
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'GOSUB_RETVAL' is ''
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Evaluating 'CC_RECALL' (from 'CC_RECALL}"="1"' len 

9)
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Result of 'CC_RECALL' is NULL
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Expression result is '0'
[2014-06-30 20:17:35] DEBUG[32392] pbx.c: Launching 'MacroExit'
[2014-06-30 20:17:35] VERBOSE[32392] pbx.c: -- Executing [s@macro-blkvm-check:3] MacroExit
1
  • 2
    What did the documentation say?
    – EEAA
    Jun 22, 2014 at 16:59

2 Answers 2

2

First off, you probably want to switch your system to "Device and User" mode (see here).
It is a little more complicated than the default "extensions" mode, but substantially more flexible.

In Device and User mode you will have an option on the User page to enable voicemail:
enter image description here
(I believe you'll have the same option on the "Extension" page).

Set the voicemail status field to "Enabled" and enter a (numeric) password, save the configuration and click "Apply Changes" (which should appear on the FreePBX menu bar right after you save the config).
You may then configure voicemail (including greetings) as you wish.

0
1

You need allow busy message in extensions tab AND press APPLY CHANGES button on top

6
  • I use freepbx GUI - I don see an option to "allow busy message" under application>extension. I am sure I am missing something here..
    – Paul
    Jun 26, 2014 at 2:59
  • Try go voicemail menu(press * while it play, enter password) and record new busy message
    – arheops
    Jun 26, 2014 at 12:09
  • When I press the voicemail menu button on the IP phone SPA 504G, I see the message 'declined' on the screen. And it immediately gives me the busy tone - just as I would get when I dial into that phone. Does this give a clue as to where the problem is? Do I need to set up a database table for the voicemails? Is this a database access issue?
    – Paul
    Jun 26, 2014 at 13:29
  • Problem is: on your phone voicemail number is different. Consult freepbx features page for number(usualy *98), put that number in phone's config. Default voicemail work with files. You just need allow voicemail in extensions tab.
    – arheops
    Jun 26, 2014 at 15:40
  • 1
    You press "apply changes" probably. Sorry, no other though. Maybe you need hire expert
    – arheops
    Jun 28, 2014 at 1:20

You must log in to answer this question.

Not the answer you're looking for? Browse other questions tagged .