VmX Locater problem with leaving message at unavail prompt

I’m having a problem with vmx locater. I’ve followed the article on using Follow Me with VmX locater and have run into a problem when trying to leave a message at the unavailable prompt.

Currently, when setup up as in the howto, I can call an extension, have it go to voicemail, hit “1” for the follow me settings, get the busy prompt and leave voicemail.

However, when I don’t press “1” at the unavailable prompt and instead want to leave a message, I get no beep, no voicemail, no nothing.except the system hangs up. If I disable VmX Locater, then there is a beep in the unavailable prompt. It seems to me that the timeout destination is not being hit. I’ve not been able to put any values in the General Settings screen for VmX Locater that will stick.

Here’s the last bit of the log after nobody answers and the system goes to the unavailable prompt:

-- Nobody picked up in 15000 ms
-- Executing [[email protected]:8] Set("SIP/64.34.181.47-b7e0d9b8", "DIALSTATUS=NOANSWER") in new stack
-- Executing [[email protected]:10] Set("SIP/64.34.181.47-b7e0d9b8", "SV_DIALSTATUS=NOANSWER") in new stack
-- Executing [[email protected]:11] GosubIf("SIP/64.34.181.47-b7e0d9b8", "0?docfu|1") in new stack
-- Executing [[email protected]:12] GosubIf("SIP/64.34.181.47-b7e0d9b8", "0?docfb|1") in new stack
-- Executing [[email protected]:13] Set("SIP/64.34.181.47-b7e0d9b8", "DIALSTATUS=NOANSWER") in new stack
-- Executing [[email protected]:14] NoOp("SIP/64.34.181.47-b7e0d9b8", "Voicemail is 8617") in new stack
-- Executing [[email protected]:15] GotoIf("SIP/64.34.181.47-b7e0d9b8", "0?s-NOANSWER|1") in new stack
-- Executing [[email protected]:16] NoOp("SIP/64.34.181.47-b7e0d9b8", "Sending to Voicemail box 8617") in new stack
-- Executing [[email protected]:17] Macro("SIP/64.34.181.47-b7e0d9b8", "vm|8617|NOANSWER") in new stack
-- Executing [[email protected]:1] Macro("SIP/64.34.181.47-b7e0d9b8", "user-callerid|SKIPTTL") in new stack
-- Executing [[email protected]:1] NoOp("SIP/64.34.181.47-b7e0d9b8", "user-callerid: John Smith 123456789") in new stack
-- Executing [[email protected]:2] Set("SIP/64.34.181.47-b7e0d9b8", "AMPUSER=6784738617") in new stack
-- Executing [[email protected]:3] GotoIf("SIP/64.34.181.47-b7e0d9b8", "0?report") in new stack
-- Executing [[email protected]:4] ExecIf("SIP/64.34.181.47-b7e0d9b8", "0|Set|REALCALLERIDNUM=1234567890") in new stack
-- Executing [[email protected]:5] NoOp("SIP/64.34.181.47-b7e0d9b8", "REALCALLERIDNUM is 1234567890") in new stack
-- Executing [[email protected]:6] Set("SIP/64.34.181.47-b7e0d9b8", "AMPUSER=") in new stack
-- Executing [[email protected]:7] Set("SIP/64.34.181.47-b7e0d9b8", "AMPUSERCIDNAME=") in new stack
-- Executing [[email protected]:8] GotoIf("SIP/64.34.181.47-b7e0d9b8", "1?report") in new stack
-- Goto (macro-user-callerid,s,13)
-- Executing [[email protected]:13] NoOp("SIP/64.34.181.47-b7e0d9b8", "TTL: 64 ARG1: SKIPTTL") in new stack
-- Executing [[email protected]:14] GotoIf("SIP/64.34.181.47-b7e0d9b8", "1?continue") in new stack
-- Goto (macro-user-callerid,s,23)
-- Executing [[email protected]:23] NoOp("SIP/64.34.181.47-b7e0d9b8", "Using CallerID "John Smith" <1234567890>") in new stack
-- Executing [[email protected]:2] Set("SIP/64.34.181.47-b7e0d9b8", "VMGAIN=g(1)") in new stack
-- Executing [[email protected]:3] GotoIf("SIP/64.34.181.47-b7e0d9b8", "1?vmx|1") in new stack
-- Goto (macro-vm,vmx,1)
-- Executing [[email protected]:1] GotoIf("SIP/64.34.181.47-b7e0d9b8", "0?s-NOANSWER|1") in new stack
-- Executing [[email protected]:2] Set("SIP/64.34.181.47-b7e0d9b8", "MODE=unavail") in new stack
-- Executing [[email protected]:3] GotoIf("SIP/64.34.181.47-b7e0d9b8", "1?notdirect") in new stack
-- Goto (macro-vm,vmx,5)
-- Executing [[email protected]:5] NoOp("SIP/64.34.181.47-b7e0d9b8", "Checking if ext 8617 is enabled: enabled") in new stack
-- Executing [[email protected]:6] GotoIf("SIP/64.34.181.47-b7e0d9b8", "0?s-NOANSWER|1") in new stack
-- Executing [[email protected]:7] Macro("SIP/64.34.181.47-b7e0d9b8", "get-vmcontext|8617") in new stack
-- Executing [[email protected]:1] Set("SIP/64.34.181.47-b7e0d9b8", "VMCONTEXT=default") in new stack
-- Executing [[email protected]:2] GotoIf("SIP/64.34.181.47-b7e0d9b8", "0?200:300") in new stack
-- Goto (macro-get-vmcontext,s,300)
-- Executing [[email protected]:300] NoOp("SIP/64.34.181.47-b7e0d9b8", "") in new stack
-- Executing [[email protected]:8] AGI("SIP/64.34.181.47-b7e0d9b8", "checksound.agi|/var/spool/asterisk/voicemail/default/8617/unavail") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/checksound.agi
-- AGI Script checksound.agi completed, returning 0
-- Executing [[email protected]:9] GotoIf("SIP/64.34.181.47-b7e0d9b8", "0?nofile") in new stack
-- Executing [[email protected]:10] Set("SIP/64.34.181.47-b7e0d9b8", "LOOPCOUNT=0") in new stack
-- Executing [[email protected]:11] GotoIf("SIP/64.34.181.47-b7e0d9b8", "1?vmxtime") in new stack
-- Goto (macro-vm,vmx,13)
-- Executing [[email protected]:13] GotoIf("SIP/64.34.181.47-b7e0d9b8", "1?vmxloops") in new stack
-- Goto (macro-vm,vmx,15)
-- Executing [[email protected]:15] GotoIf("SIP/64.34.181.47-b7e0d9b8", "1?vmxanswer") in new stack
-- Goto (macro-vm,vmx,17)
-- Executing [[email protected]:17] Answer("SIP/64.34.181.47-b7e0d9b8", "") in new stack
-- Executing [[email protected]:18] Read("SIP/64.34.181.47-b7e0d9b8", "ACTION|/var/spool/asterisk/voicemail/default/8617/unavail|1|skip||") in new stack
-- Accepting a maximum of 1 digits.
-- <SIP/64.34.181.47-b7e0d9b8> Playing '/var/spool/asterisk/voicemail/default/8617/unavail' (language 'en')
-- User entered nothing.
-- Executing [[email protected]:19] GotoIf("SIP/64.34.181.47-b7e0d9b8", "0?checkopt") in new stack
-- Executing [[email protected]:20] NoOp("SIP/64.34.181.47-b7e0d9b8", "Timeout: going to timeout dest") in new stack
-- Executing [[email protected]:21] Set("SIP/64.34.181.47-b7e0d9b8", "VMX_OPTS=") in new stack
-- Executing [[email protected]:22] GotoIf("SIP/64.34.181.47-b7e0d9b8", "0?chktime") in new stack
-- Executing [[email protected]:23] Set("SIP/64.34.181.47-b7e0d9b8", "VMX_OPTS=") in new stack
-- Executing [[email protected]:24] GotoIf("SIP/64.34.181.47-b7e0d9b8", "1?dotime") in new stack
-- Goto (macro-vm,vmx,30)
-- Executing [[email protected]:30] Goto("SIP/64.34.181.47-b7e0d9b8", "||") in new stack

== Spawn extension (macro-vm, vmx, 30) exited non-zero on ‘SIP/64.34.181.47-b7e0d9b8’ in macro ‘vm’
== Spawn extension (macro-vm, vmx, 30) exited non-zero on ‘SIP/64.34.181.47-b7e0d9b8’ in macro ‘exten-vm’
== Spawn extension (macro-vm, vmx, 30) exited non-zero on ‘SIP/64.34.181.47-b7e0d9b8’

something looks corrupted to me:

-- Executing [[email protected]:24] GotoIf("SIP/64.34.181.47-b7e0d9b8", "1?dotime") in new stack
-- Goto (macro-vm,vmx,30)
-- Executing [[email protected]:30] Goto("SIP/64.34.181.47-b7e0d9b8", "||") in new stack

see the last goto, with no destination: “||”, not sure what that is about but it is not right.

That looks like it is coming from:

– Executing [[email protected]:18] Read(“SIP/64.34.181.47-b7e0d9b8”, “ACTION|/var/spool/asterisk/voicemail/default/8617/unavail|1|skip||”) in new stack

I have not changed anything under the hood. All I have done is followed the original Follow Me and VmX locater article. I have tried changing the timeout/# default context value under General Settings, but nothing I enter takes. When I hit the “Submit Changes” button, those fields clear.

This behavior is happening with an old existing extension AND with a brand new one I created to test the feature.

I guess I should mention I am using the latest updated 2.4.0.x software, latest PBXinAFlash, asterisk info:
Asterisk 1.4.18 built by root @ sip.carpenter.cx on a i686 running Linux on 2008-03-04 16:02:22 UTC