Trixbox v2.2.3
FreePBX 2.3.1.3
Problem: freepbx drops calls when they reach voicemail from a specific route.
Inbound route workflow:
incoming -> from-pstn -> business hours time condition -> ring group -> queue -> dial by name directory -> select name -> confirm -> ring extension -> voicemail
The incoming call follows the route correctly throught the ring group (the group times out), falls over to the queue, the caller selects the dial by name directory, dials the recipient, and the recipient's phone rings, then it is supposed to fall over to voicemail. At that point the call is disconnected. I've also received feedback from callers that this occurs through other routes as well, but always from the dial by name directory.
Call path:
[code]Incoming call
|
Time condition (no match)-> off hours IVR -> voicemail or queue depending on selection (this path works fine)
|
(time condition matched)
|
Queue (no breakout allowed)
|
Queue -> # -> dial by name -> # -> user's voicemail
|
General voicemail
Log:
Quote:
dialparties.agi: Starting New Dialparties.agi
== Parsing '/etc/asterisk/manager.conf': Found
== Parsing '/etc/asterisk/manager_additional.conf': Found
== Parsing '/etc/asterisk/manager_custom.conf': Found
== Manager 'admin' logged on from 127.0.0.1
dialparties.agi: Caller ID name is 'WEB:KIMBER' number is '5085555555'
dialparties.agi: USE_CONFIRMATION: 'FALSE'
dialparties.agi: RINGGROUP_INDEX: ''
dialparties.agi: Methodology of ring is 'none'
-- dialparties.agi: Added extension 1002 to extension map
-- dialparties.agi: Extension 1002 cf is disabled
-- dialparties.agi: Extension 1002 do not disturb is disabled
> dialparties.agi: extnum 1002 has: cw: 1; hascfb: 0 [] hascfu: 0 []
> dialparties.agi: ExtensionState: 0
-- dialparties.agi: dbset CALLTRACE/1002 to 5085555555
> dialparties.agi: NODEST: 9001 blkvm enabled macro already in dialopts: trM(auto-blkvm)
> dialparties.agi: NODEST: 9001 blkvm enabled macro already in dialopts: trM(auto-blkvm)
== Manager 'admin' logged off from 127.0.0.1
-- AGI Script dialparties.agi completed, returning 0
-- Executing Dial("Local/1002@from-internal-a418,2", "SIP/1002|15|trM(auto-blkvm)") in new stack
-- Called 1002
-- Local/1002@from-internal-a418,1 is ringing
-- SIP/1002-09e09508 is ringing
-- User pressed digit: #
-- Stopped music on hold on Zap/1-1
== Spawn extension (macro-dial, s, 10) exited non-zero on 'Local/1004@from-internal-0101,2' in macro 'dial'
== Spawn extension (macro-dial, s, 10) exited non-zero on 'Local/1004@from-internal-0101,2' in macro 'exten-vm'
== Spawn extension (macro-dial, s, 10) exited non-zero on 'Local/1004@from-internal-0101,2'
== Spawn extension (macro-dial, s, 10) exited non-zero on 'Local/1003@from-internal-8a7c,2' in macro 'dial'
== Spawn extension (macro-dial, s, 10) exited non-zero on 'Local/1003@from-internal-8a7c,2' in macro 'exten-vm'
== Spawn extension (macro-dial, s, 10) exited non-zero on 'Local/1003@from-internal-8a7c,2'
-- Executing Macro("Local/1003@from-internal-8a7c,2", "hangupcall") in new stack
-- Executing ResetCDR("Local/1003@from-internal-8a7c,2", "w") in new stack
== Spawn extension (macro-dial, s, 10) exited non-zero on 'Local/1002@from-internal-a418,2' in macro 'dial'
== Spawn extension (macro-dial, s, 10) exited non-zero on 'Local/1002@from-internal-a418,2' in macro 'exten-vm'
== Spawn extension (macro-dial, s, 10) exited non-zero on 'Local/1002@from-internal-a418,2'
-- Executing Macro("Local/1002@from-internal-a418,2", "hangupcall") in new stack
-- Executing ResetCDR("Local/1002@from-internal-a418,2", "w") in new stack
-- Executing Goto("Zap/1-1", "app-directory|#|1") in new stack
-- Executing Macro("Local/1004@from-internal-0101,2", "hangupcall") in new stack
-- Executing ResetCDR("Local/1004@from-internal-0101,2", "w") in new stack
-- Goto (app-directory,#,1)
== Spawn extension (macro-dial, s, 10) exited non-zero on 'Local/1001@from-internal-90ac,2' in macro 'dial'
-- Executing Answer("Zap/1-1", "") in new stack
== Spawn extension (macro-dial, s, 10) exited non-zero on 'Local/1001@from-internal-90ac,2' in macro 'exten-vm'
-- Executing Wait("Zap/1-1", "1") in new stack
== Spawn extension (macro-dial, s, 10) exited non-zero on 'Local/1001@from-internal-90ac,2'
-- Executing Macro("Local/1001@from-internal-90ac,2", "hangupcall") in new stack
-- Executing ResetCDR("Local/1001@from-internal-90ac,2", "w") in new stack
-- Executing NoCDR("Local/1003@from-internal-8a7c,2", "") in new stack
-- Executing GotoIf("Local/1003@from-internal-8a7c,2", "1?skiprg") in new stack
-- Goto (macro-hangupcall,s,6)
-- Executing GotoIf("Local/1003@from-internal-8a7c,2", "1?skipblkvm") in new stack
-- Goto (macro-hangupcall,s,9)
-- Executing GotoIf("Local/1003@from-internal-8a7c,2", "1?theend") in new stack
-- Goto (macro-hangupcall,s,11)
-- Executing Hangup("Local/1003@from-internal-8a7c,2", "") in new stack
== Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'Local/1003@from-internal-8a7c,2' in macro 'hangupcall'
== Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'Local/1003@from-internal-8a7c,2'
== End MixMonitor Recording Local/1003@from-internal-8a7c,2
-- Executing NoCDR("Local/1002@from-internal-a418,2", "") in new stack
-- Executing GotoIf("Local/1002@from-internal-a418,2", "1?skiprg") in new stack
-- Goto (macro-hangupcall,s,6)
-- Executing GotoIf("Local/1002@from-internal-a418,2", "1?skipblkvm") in new stack
-- Goto (macro-hangupcall,s,9)
-- Executing GotoIf("Local/1002@from-internal-a418,2", "1?theend") in new stack
-- Goto (macro-hangupcall,s,11)
-- Executing Hangup("Local/1002@from-internal-a418,2", "") in new stack
== Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'Local/1002@from-internal-a418,2' in macro 'hangupcall'
== Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'Local/1002@from-internal-a418,2'
== End MixMonitor Recording Local/1002@from-internal-a418,2
-- Executing NoCDR("Local/1004@from-internal-0101,2", "") in new stack
-- Executing GotoIf("Local/1004@from-internal-0101,2", "1?skiprg") in new stack
-- Goto (macro-hangupcall,s,6)
-- Executing GotoIf("Local/1004@from-internal-0101,2", "1?skipblkvm") in new stack
-- Goto (macro-hangupcall,s,9)
-- Executing GotoIf("Local/1004@from-internal-0101,2", "1?theend") in new stack
-- Goto (macro-hangupcall,s,11)
-- Executing Hangup("Local/1004@from-internal-0101,2", "") in new stack
== Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'Local/1004@from-internal-0101,2' in macro 'hangupcall'
-- Executing NoCDR("Local/1001@from-internal-90ac,2", "") in new stack
== Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'Local/1004@from-internal-0101,2'
-- Executing GotoIf("Local/1001@from-internal-90ac,2", "1?skiprg") in new stack
-- Goto (macro-hangupcall,s,6)
== End MixMonitor Recording Local/1004@from-internal-0101,2
-- Executing GotoIf("Local/1001@from-internal-90ac,2", "1?skipblkvm") in new stack
-- Goto (macro-hangupcall,s,9)
-- Executing GotoIf("Local/1001@from-internal-90ac,2", "1?theend") in new stack
-- Goto (macro-hangupcall,s,11)
-- Executing Hangup("Local/1001@from-internal-90ac,2", "") in new stack
== Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'Local/1001@from-internal-90ac,2' in macro 'hangupcall'
== Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'Local/1001@from-internal-90ac,2'
== End MixMonitor Recording Local/1001@from-internal-90ac,2
-- Executing AGI("Zap/1-1", "directory||from-did-direct|le") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/directory
directory||from-did-direct|le: Notice: vm-context not specified. Using 'default'
-- Playing 'dir-intro' (language 'en')
== directory||from-did-direct|le: Found /var/spool/asterisk/voicemail/default/1002/greet.wav
directory||from-did-direct|le: -- Playing 'dir-instr' (language 'en')
-- Playing 'digits/1' (language 'en')
-- Playing 'digits/0' (language 'en')
-- Playing 'digits/0' (language 'en')
-- Playing 'digits/2' (language 'en')
-- AGI Script directory completed, returning 0
-- Executing Macro("Zap/1-1", "exten-vm|1002|1002") in new stack
-- Executing Macro("Zap/1-1", "user-callerid") in new stack
-- Executing NoOp("Zap/1-1", "user-callerid: WEB:KIMBER 5085555555") in new stack
-- Executing Set("Zap/1-1", "AMPUSER=5085555555") in new stack
-- Executing GotoIf("Zap/1-1", "0?report") in new stack
-- Executing GotoIf("Zap/1-1", "1?start") in new stack
-- Goto (macro-user-callerid,s,6)
-- Executing NoOp("Zap/1-1", "REALCALLERIDNUM is 5085555555") in new stack
-- Executing Set("Zap/1-1", "AMPUSER=") in new stack
-- Executing Set("Zap/1-1", "AMPUSERCIDNAME=") in new stack
-- Executing GotoIf("Zap/1-1", "1?report") in new stack
-- Goto (macro-user-callerid,s,13)
-- Executing NoOp("Zap/1-1", "TTL: 63 ARG1: 1002") in new stack
-- Executing GotoIf("Zap/1-1", "0?continue") in new stack
-- Executing Set("Zap/1-1", "__TTL=62") in new stack
-- Executing GotoIf("Zap/1-1", "1?continue") in new stack
-- Goto (macro-user-callerid,s,23)
-- Executing NoOp("Zap/1-1", "Using CallerID "WEB:KIMBER" <5085555555>") in new stack
-- Executing Set("Zap/1-1", "FROMCONTEXT=exten-vm") in new stack
-- Executing Set("Zap/1-1", "VMBOX=1002") in new stack
-- Executing Set("Zap/1-1", "EXTTOCALL=1002") in new stack
-- Executing Set("Zap/1-1", "CFUEXT=") in new stack
-- Executing Set("Zap/1-1", "CFBEXT=") in new stack
-- Executing Set("Zap/1-1", "RT=15") in new stack
-- Executing Macro("Zap/1-1", "record-enable|1002|IN") in new stack
-- Executing GotoIf("Zap/1-1", "0?2:4") in new stack
-- Goto (macro-record-enable,s,4)
-- Executing AGI("Zap/1-1", "recordingcheck|20080207-182254|1202426508.6513") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
recordingcheck|20080207-182254|1202426508.6513: Inbound recording enabled.
recordingcheck|20080207-182254|1202426508.6513: CALLFILENAME=20080207-182254-1202426508.6513
-- AGI Script recordingcheck completed, returning 0
-- Executing MixMonitor("Zap/1-1", "20080207-182254-1202426508.6513.wav") in new stack
-- Executing Macro("Zap/1-1", "dial|15|trM(auto-blkvm)|1002") in new stack
-- Executing GotoIf("Zap/1-1", "0?dial") in new stack
-- Executing SetMusicOnHold("Zap/1-1", "default") in new stack
-- Executing AGI("Zap/1-1", "dialparties.agi") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
== Begin MixMonitor Recording Zap/1-1
dialparties.agi: Starting New Dialparties.agi
== Parsing '/etc/asterisk/manager.conf': Found
== Parsing '/etc/asterisk/manager_additional.conf': Found
== Parsing '/etc/asterisk/manager_custom.conf': Found
== Manager 'admin' logged on from 127.0.0.1
dialparties.agi: Caller ID name is 'WEB:KIMBER' number is '5085555555'
dialparties.agi: USE_CONFIRMATION: 'FALSE'
dialparties.agi: RINGGROUP_INDEX: ''
dialparties.agi: Methodology of ring is 'none'
-- dialparties.agi: Added extension 1002 to extension map
-- dialparties.agi: Extension 1002 cf is disabled
-- dialparties.agi: Extension 1002 do not disturb is disabled
> dialparties.agi: extnum 1002 has: cw: 1; hascfb: 0 [] hascfu: 0 []
> dialparties.agi: ExtensionState: 0
-- dialparties.agi: dbset CALLTRACE/1002 to 5085555555
> dialparties.agi: NODEST: 9001 blkvm enabled macro already in dialopts: trM(auto-blkvm)
> dialparties.agi: NODEST: 9001 blkvm enabled macro already in dialopts: trM(auto-blkvm)
== Manager 'admin' logged off from 127.0.0.1
-- AGI Script dialparties.agi completed, returning 0
-- Executing Dial("Zap/1-1", "SIP/1002|15|trM(auto-blkvm)") in new stack
-- Called 1002
-- SIP/1002-b7209948 is ringing
-- Nobody picked up in 15000 ms
-- Executing Set("Zap/1-1", "DIALSTATUS=NOANSWER") in new stack
-- Executing Set("Zap/1-1", "SV_DIALSTATUS=NOANSWER") in new stack
-- Executing GosubIf("Zap/1-1", "0?docfu|1") in new stack
-- Executing GosubIf("Zap/1-1", "0?docfb|1") in new stack
-- Executing Set("Zap/1-1", "DIALSTATUS=NOANSWER") in new stack
-- Executing NoOp("Zap/1-1", "Voicemail is 1002") in new stack
-- Executing GotoIf("Zap/1-1", "0?s-NOANSWER|1") in new stack
-- Executing NoOp("Zap/1-1", "Sending to Voicemail box 1002") in new stack
-- Executing Macro("Zap/1-1", "vm|1002|NOANSWER") in new stack
-- Executing Macro("Zap/1-1", "user-callerid|SKIPTTL") in new stack
-- Executing NoOp("Zap/1-1", "user-callerid: WEB:KIMBER 5085555555") in new stack
-- Executing Set("Zap/1-1", "AMPUSER=5085555555") in new stack
-- Executing GotoIf("Zap/1-1", "0?report") in new stack
-- Executing GotoIf("Zap/1-1", "1?start") in new stack
-- Goto (macro-user-callerid,s,6)
-- Executing NoOp("Zap/1-1", "REALCALLERIDNUM is 5085555555") in new stack
-- Executing Set("Zap/1-1", "AMPUSER=") in new stack
-- Executing Set("Zap/1-1", "AMPUSERCIDNAME=") in new stack
-- Executing GotoIf("Zap/1-1", "1?report") in new stack
-- Goto (macro-user-callerid,s,13)
-- Executing NoOp("Zap/1-1", "TTL: 62 ARG1: SKIPTTL") in new stack
-- Executing GotoIf("Zap/1-1", "1?continue") in new stack
-- Goto (macro-user-callerid,s,23)
-- Executing NoOp("Zap/1-1", "Using CallerID "WEB:KIMBER" <5085555555>") in new stack
-- Executing Set("Zap/1-1", "VMGAIN=") in new stack
-- Executing GotoIf("Zap/1-1", "0?vmx|1") in new stack
-- Executing NoOp("Zap/1-1", "CAME FROM: 9001 - Blocking VM cause of key: ") in new stack
-- Executing Hangup("Zap/1-1", "") in new stack
== Spawn extension (from-did-direct, 1002, 2) exited non-zero on 'Zap/1-1'
-- Hungup 'Zap/1-1'
== End MixMonitor Recording Zap/1-1
== End MixMonitor Recording Zap/1-1In this section is it that the queue is 9001 (begins with a 9) messing it up?
Quote:
-- Executing Set("Zap/1-1", "VMGAIN=") in new stack
-- Executing GotoIf("Zap/1-1", "0?vmx|1") in new stack
-- Executing NoOp("Zap/1-1", "CAME FROM: 9001 - Blocking VM cause of key: ") in new stack
-- Executing Hangup("Zap/1-1", "") in new stack
== Spawn extension (from-did-direct, 1002, 2) exited non-zero on 'Zap/1-1'
-- Hungup 'Zap/1-1'
is the IVR associated with the queue so that they can break out of the queue and dial by name?
Philippe Lindheimer - FreePBX Project Leader
FreePBX Training Opportunities - Click Here
Get Official Paid Support - Click Here
yes
But let your communication be, Yea, yea; Nay, nay: for whatsoever is more than these cometh of evil.
Can you try this patch (from IVR's functions.inc.php):
Index: functions.inc.php =================================================================== --- functions.inc.php (revision 5686) +++ functions.inc.php (working copy) @@ -167,6 +167,8 @@ $ext->addInclude($id,'app-directory'); $dir = featurecodes_getFeatureCode('infoservices', 'directory'); $ext->add($id, '#', '', new ext_goto("app-directory,$dir,1")); + $ext->add($id, '#' ,'', new ext_dbdel('${BLKVM_OVERRIDE}')); + $ext->add($id, '#' ,'', new ext_setvar('__NODEST', '')); } $ext->add($id, 'h', '', new ext_hangup(''));Philippe Lindheimer - FreePBX Project Leader
FreePBX Training Opportunities - Click Here
Get Official Paid Support - Click Here
Hello Phillippe,
I applied the change and did an amportal restart, no change in behavior.
I then created a new IVR, changed the inbound route to use the new IVR, and I still see the same behavior.
(deleted incorrect log info)
But let your communication be, Yea, yea; Nay, nay: for whatsoever is more than these cometh of evil.
that does not look like the correct part of the log. I don't see where the call is being blocked or even attempting to go to voicemail.
Philippe Lindheimer - FreePBX Project Leader
FreePBX Training Opportunities - Click Here
Get Official Paid Support - Click Here
Sorry about that. :(
I captured the log again, this time I am making sure I copy the right thing!
Moment of disconnect:
Initially I thought this may have been due to the queue's having had an extension beginning with 9, however I replaced the queue with another one in another range (the 6000 range) and obtained the same results, so I put it back the way it was. " Blocking VM cause of key: " - I am querying google for that now, but what is it?
But let your communication be, Yea, yea; Nay, nay: for whatsoever is more than these cometh of evil.
oops - got my added instructions in the wrong place. Try this version of the patch (you need to apply it to the original file, or if you want you can just manually edit the currently patched file. The two instructions with the + should come before, not after the goto.
Index: functions.inc.php =================================================================== --- functions.inc.php (revision 5686) +++ functions.inc.php (working copy) @@ -166,6 +166,8 @@ if (!empty($details['enable_directory'])) { $ext->addInclude($id,'app-directory'); $dir = featurecodes_getFeatureCode('infoservices', 'directory'); + $ext->add($id, '#' ,'', new ext_dbdel('${BLKVM_OVERRIDE}')); + $ext->add($id, '#' ,'', new ext_setvar('__NODEST', '')); $ext->add($id, '#', '', new ext_goto("app-directory,$dir,1")); }Philippe Lindheimer - FreePBX Project Leader
FreePBX Training Opportunities - Click Here
Get Official Paid Support - Click Here
That did it! Thanks a ton!
But let your communication be, Yea, yea; Nay, nay: for whatsoever is more than these cometh of evil.
glad to hear it. Would be great if you cold open up a ticket in the bug tracker. I can then get the fix into both 2.3 and 2.4 and published.
Philippe Lindheimer - FreePBX Project Leader
FreePBX Training Opportunities - Click Here
Get Official Paid Support - Click Here
Will do - I'll try to log it this evening
But let your communication be, Yea, yea; Nay, nay: for whatsoever is more than these cometh of evil.
took care of it: #2687
r5712 (2.4), r5714 (2.3)
Philippe Lindheimer - FreePBX Project Leader
FreePBX Training Opportunities - Click Here
Get Official Paid Support - Click Here
Hmm, I just logged it (I got SWAMPED the last two days and didn't get a chance until now) and checked back here. Sorry about the dupe!
But let your communication be, Yea, yea; Nay, nay: for whatsoever is more than these cometh of evil.
Hi,
I have a similar problem, except that mine occurs when a queue member answers a call, and they tries to transfer it to another extension. I see from the logs that it is blocking voicemail because the call came out of a queue - but the transferred call should go to voicemail.
CAME FROM: 575 - Blocking VM cause of key:
Will the patch above fix this? I see that the change was made to the ivr module, so I'm thinking not as mine does not go through an IVR. Thanks!
I opened a bug for this: http://freepbx.org/trac/ticket/2696
awells,
your scenario should not happen. What sort of 'agents' are you using? The mechanisms in place are specifically designed to allow your scenario to work. When the call gets answered, the flag gets cleared. If you are using 'agents.conf' agents then that would be a problem as they are not supported in the FreePBX environment and your described behavior would happen.
Philippe Lindheimer - FreePBX Project Leader
FreePBX Training Opportunities - Click Here
Get Official Paid Support - Click Here
So yeah 4 years old now but I, too am having the exact same trouble.
FreePBX 2.9.0.7, Asterisk 1.6.2.20
I created my entire configuration through the GUI, so there shouldn't be any surprises in the config. The scenario:
Someone calls one of three queues via an IVR. Agent answers, sends the caller to an extension. If the extension is using follow me no matter what you set the timers to it will never go to voicemail. The call is simply dropped instead.
Any thoughts? I've looked and this is the only thread I saw of this kind, so I hope I'm not duplicating something answered somewhere else!