Ticket #2842 (closed Bugs: worksforme)

Opened 4 years ago

Last modified 4 years ago

system locks up when a voicemail is left on an unregistered extension

Reported by: mojvij Assigned to:
Priority: crash Milestone: 2.5
Component: Voicemail Version: 2.4.0
Keywords: Cc:
Confirmation: Need Feedback SVN Revision (if applicable):
Backend Engine: Asterisk 1.4.x Backend Engine Version:

Description (Last modified by p_lindheimer)

We have a extension used for company mailbox. So theres no phone. When a person leaves the voicemail the system goes into some kind of loop taking up all the resources, and causes it to lock up. Heres the cli output:

  -- Executing [s@macro-vm:2] Set("SIP/125-08c07e98", "VMGAIN=""") in new stack
[Jun  9 08:54:41] WARNING[2836]: func_db.c:58 function_db_read: DB requires an argument, DB(<family>/<key>)
    -- Executing [s@macro-vm:3] GotoIf("SIP/125-08c07e98", "1?vmx|1") in new stack
    -- Goto (macro-vm,vmx,1)
    -- Executing [vmx@macro-vm:1] GotoIf("SIP/125-08c07e98", "0?s-CHANUNAVAIL|1") in new stack
    -- Executing [vmx@macro-vm:2] Set("SIP/125-08c07e98", "MODE=unavail") in new stack
    -- Executing [vmx@macro-vm:3] GotoIf("SIP/125-08c07e98", "1?notdirect") in new stack
    -- Goto (macro-vm,vmx,5)
    -- Executing [vmx@macro-vm:5] NoOp("SIP/125-08c07e98", "Checking if ext 800 is enabled: blocked") in new stack
    -- Executing [vmx@macro-vm:6] GotoIf("SIP/125-08c07e98", "1?s-CHANUNAVAIL|1") in new stack
    -- Goto (macro-vm,s-CHANUNAVAIL,1)
    -- Executing [s-CHANUNAVAIL@macro-vm:1] Macro("SIP/125-08c07e98", "get-vmcontext|800") in new stack
    -- Executing [s@macro-get-vmcontext:1] Set("SIP/125-08c07e98", "VMCONTEXT=default") in new stack
    -- Executing [s@macro-get-vmcontext:2] GotoIf("SIP/125-08c07e98", "0?200:300") in new stack
    -- Goto (macro-get-vmcontext,s,300)
    -- Executing [s@macro-get-vmcontext:300] NoOp("SIP/125-08c07e98", "") in new stack
    -- Executing [s@macro-vm:2] Set("SIP/125-08c07e98", "VMGAIN=""") in new stack
[Jun  9 08:54:41] WARNING[2836]: func_db.c:58 function_db_read: DB requires an argument, DB(<family>/<key>)
    -- Executing [s@macro-vm:3] GotoIf("SIP/125-08c07e98", "1?vmx|1") in new stack
    -- Goto (macro-vm,vmx,1)
    -- Executing [vmx@macro-vm:1] GotoIf("SIP/125-08c07e98", "0?s-CHANUNAVAIL|1") in new stack
    -- Executing [vmx@macro-vm:2] Set("SIP/125-08c07e98", "MODE=unavail") in new stack
    -- Executing [vmx@macro-vm:3] GotoIf("SIP/125-08c07e98", "1?notdirect") in new stack
    -- Goto (macro-vm,vmx,5)
    -- Executing [vmx@macro-vm:5] NoOp("SIP/125-08c07e98", "Checking if ext 800 is enabled: blocked") in new stack
    -- Executing [vmx@macro-vm:6] GotoIf("SIP/125-08c07e98", "1?s-CHANUNAVAIL|1") in new stack
    -- Goto (macro-vm,s-CHANUNAVAIL,1)
    -- Executing [s-CHANUNAVAIL@macro-vm:1] Macro("SIP/125-08c07e98", "get-vmcontext|800") in new stack
    -- Executing [s@macro-get-vmcontext:1] Set("SIP/125-08c07e98", "VMCONTEXT=default") in new stack
    -- Executing [s@macro-get-vmcontext:2] GotoIf("SIP/125-08c07e98", "0?200:300") in new stack
    -- Goto (macro-get-vmcontext,s,300)
    -- Executing [s@macro-get-vmcontext:300] NoOp("SIP/125-08c07e98", "") in new stack
    -- Executing [s@macro-vm:2] Set("SIP/125-08c07e98", "VMGAIN=""") in new stack
[Jun  9 08:54:41] WARNING[2836]: func_db.c:58 function_db_read: DB requires an argument, DB(<family>/<key>)
    -- Executing [s@macro-vm:3] GotoIf("SIP/125-08c07e98", "1?vmx|1") in new stack
    -- Goto (macro-vm,vmx,1)
    -- Executing [vmx@macro-vm:1] GotoIf("SIP/125-08c07e98", "0?s-CHANUNAVAIL|1") in new stack
    -- Executing [vmx@macro-vm:2] Set("SIP/125-08c07e98", "MODE=unavail") in new stack
    -- Executing [vmx@macro-vm:3] GotoIf("SIP/125-08c07e98", "1?notdirect") in new stack
    -- Goto (macro-vm,vmx,5)
    -- Executing [vmx@macro-vm:5] NoOp("SIP/125-08c07e98", "Checking if ext 800 is enabled: blocked") in new stack
    -- Executing [vmx@macro-vm:6] GotoIf("SIP/125-08c07e98", "1?s-CHANUNAVAIL|1") in new stack
    -- Goto (macro-vm,s-CHANUNAVAIL,1)
    -- Executing [s-CHANUNAVAIL@macro-vm:1] Macro("SIP/125-08c07e98", "get-vmcontext|800") in new stack
    -- Executing [s@macro-get-vmcontext:1] Set("SIP/125-08c07e98", "VMCONTEXT=default") in new stack
    -- Executing [s@macro-get-vmcont

Change History

06/09/08 09:46:18 changed by p_lindheimer

  • confirmation changed from Unreviewed to Need Feedback.
  • description changed.
  • milestone changed from Cut Line to 3.0.

I do this all the time and it should work fine. You have something really odd going on with your system. When you exit "macro-get-vmcontext" instead of returning to the dialplan where it was called, you are jumping back to priority 2 of macro-vm (thus the infinite loop):

    -- Executing [s@macro-get-vmcontext:1] Set("SIP/125-08c07e98", "VMCONTEXT=default") in new stack
    -- Executing [s@macro-get-vmcontext:2] GotoIf("SIP/125-08c07e98", "0?200:300") in new stack
    -- Goto (macro-get-vmcontext,s,300)
    -- Executing [s@macro-get-vmcontext:300] NoOp("SIP/125-08c07e98", "") in new stack
    -- Executing [s@macro-vm:2] Set("SIP/125-08c07e98", "VMGAIN=""") in new stack

This is where the macro is called and as you can see the next thing it shoudl do is to call the voicemail system, which it is not because of where it is jumping to.

exten => _s-.,1,Macro(get-vmcontext,${ARG1})                                                                                                
exten => _s-.,n,Voicemail(${ARG1}@${VMCONTEXT},${VM_OPTS}u${VMGAIN})     ; Voicemail Unavailable message                                    
exten => _s-.,n,Goto(exit-${VMSTATUS},1)                                                                                                    

If the above has been removed, you may find Asterisk resorting back to looking for the 's' context resulting in what you saw, make sure it is there. Also, you should check your macro-get-vmcontext. You can try modifying it to this, the exit are not necessary but you can add them to see if it changes anything, it may be some weird bug in Asterisk that is manifesting itself:

[macro-get-vmcontext]
exten => s,1,Set(VMCONTEXT=${DB(AMPUSER/${ARG1}/voicemail)})                                                                                
exten => s,2,GotoIf($["foo${VMCONTEXT}" = "foo"]?200:300)                                                                                   
exten => s,200,Set(VMCONTEXT=default)
exten => s,n,MacroExit()
exten => s,300,NoOp()
exten => s,n,MacroExit()

you can also do a sanity check by typing "dialplan show macro-get-vmcontext" and seeing if it sees what you think you are seeing.

I'll leave this open for now so you can try and provide additional data, but it is clear that something odd is going on, this is not normal behavior.

06/09/08 09:59:23 changed by mojvij

the exit didnt work. I noticed that when I enable vmx locater it does not go into the loop. But when I enable vmx locator, I get an "unable to authenticate message constantly. I dont know if this is all related.

06/09/08 10:06:47 changed by p_lindheimer

this clearly looks like an issue peculiar to your system. You should do a "dialplan show s-CHANUNAVAIL@macro-vm" and see what it says, I suspect for some reason your system may be missing priority 2. Anyhow - I'm running off to the airport so you won't here back from me until the end of the week, I'll leave it open for now to see if there is any other useful data that surfaces.

06/09/08 10:08:46 changed by mojvij

[ Context 'macro-vm' created by 'pbx_config' ]

'_s-.' => 1. Macro(get-vmcontext|${ARG1}) [pbx_config]

  1. Voicemail(${ARG1}@${VMCONTEXT}|${VM_OPTS}u${VMGAIN}) [pbx_config]
  2. Goto(exit-${VMSTATUS}|1) [pbx_config]

-= 1 extension (3 priorities) in 1 context. =-

there looks to be a priority 2

06/09/08 10:27:27 changed by p_lindheimer

yes there does, I may be looking to quick, I'm headed out the door to the airport right now. As you can see, exiting that macro should be executing the Voicemail command and it is not, so something really odd is going on. Maybe you can find someone on the IRC to take a closer look in the meantime.

06/21/08 17:30:13 changed by p_lindheimer

  • status changed from new to closed.
  • resolution set to worksforme.

can not repro and worksforme and other testers.