Transfer/Blind transfer voicemail issue

Asterisk Asterisk Support
1

Aloha,

We are running into a unusual problem, and I couldn’t find any information during my search. I recently upgraded to Asterisk 1.4.23.1 and this problem did not exist on our 1.2 server.

If a called is transferred, and the dialed extension does not pick up, the transferred call gets the voicemail of the person who transferred the call, instead of the appropriate extension’s voicemail.

This problem does not occur if we utilize the Blind transfer function. Only with the regular transfer function.

We have Cisco 7940/7960 phones, and are utilizing the transfer/blind tranfer keys on said phones.

I’m puzzled at the moment and hoping that someone can provide me with some insight.

Much thanks in advance,
Herb

2

Think I figured it out. Updated macro functions syntax and variables. Reworking my macros and hoping I can get it working.

Update, and I think I narrowed it down to the variable ${MACRO_EXTEN} and for some reason this is not getting passed correctly.

Still working on it and any help would be appreciated.

Thanks!

3

Hi

I assume you have a std_exten macro or similar. if you post that it may help people see whats happening as many systems use a different method of calling an extension.

Ian

4

Here they are:

Basic here: Calling extention 100 triggers the voicemail macro.
[extensions]
exten => 100,1,Macro(vm,100)

Old macro from 1.2 server. This works except for transfers. Transferred calls get the voicemail of the transferree.

[macro-vm]
include => default
exten => s,1,Dial(SIP/${ARG1},15,tT)
exten => s,n,Goto(s-${DIALSTATUS},1)
exten => s-NOANSWER,1,Voicemail(${ARG1}|su)
exten => s-NOANSWER,n,Goto(default,s,1)
exten => s-BUSY,1,Voicemail(${ARG1}|sb)
exten => s-BUSY,n,Goto(default,s,1)
exten => _s-.,1,Goto(s-NOANSWER,1)

New macro that doesn’t work at all. ${MACRO_EXTEN} is not being set for some reason.
[macro-vm]
include => default
exten => s,1,Dial(SIP/${ARG1},15,tT)
exten => s,n,Goto(s-${DIALSTATUS},1)
exten => s-NOANSWER,1,Voicemail(${MACRO_EXTEN}|su)
exten => s-NOANSWER,n,Goto(default,s,1)
exten => s-BUSY,1,Voicemail(${MACRO_EXTEN}|sb)
exten => s-BUSY,n,Goto(default,s,1)
exten => _s-.,1,Goto(s-NOANSWER,1)

Thanks,
Herb

5

Hi

Ok V1 should work, could you post the debug of a call.

Ian

6

[Feb 17 10:44:04] DEBUG[4760] pbx.c: Launching ‘Macro’
[Feb 17 10:44:04] DEBUG[4760] pbx.c: Launching ‘Dial’
[Feb 17 10:44:04] DEBUG[4760] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw)
[Feb 17 10:44:04] DEBUG[4760] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP)
[Feb 17 10:44:04] DEBUG[4760] chan_sip.c: Setting NAT on RTP to Off
[Feb 17 10:44:04] DEBUG[4760] rtp.c: Seeded SDP of ‘SIP/178-08295528’ with that of ‘SIP/143-0826db50’
[Feb 17 10:44:04] DEBUG[4760] channel.c: Not copying variable DIALEDTIME.
[Feb 17 10:44:04] DEBUG[4760] channel.c: Not copying variable ANSWEREDTIME.
[Feb 17 10:44:04] DEBUG[4760] channel.c: Not copying variable DIALEDPEERNAME.
[Feb 17 10:44:04] DEBUG[4760] channel.c: Not copying variable DIALEDPEERNUMBER.
[Feb 17 10:44:04] DEBUG[4760] channel.c: Not copying variable DIALSTATUS.
[Feb 17 10:44:04] DEBUG[4760] channel.c: Not copying variable MACRO_DEPTH.
[Feb 17 10:44:04] DEBUG[4760] channel.c: Not copying variable ARG1.
[Feb 17 10:44:04] DEBUG[4760] channel.c: Not copying variable MACRO_PRIORITY.
[Feb 17 10:44:04] DEBUG[4760] channel.c: Not copying variable MACRO_CONTEXT.
[Feb 17 10:44:04] DEBUG[4760] channel.c: Not copying variable MACRO_EXTEN.
[Feb 17 10:44:04] DEBUG[4760] channel.c: Not copying variable SIPCALLID.
[Feb 17 10:44:04] DEBUG[4760] channel.c: Not copying variable SIPUSERAGENT.
[Feb 17 10:44:04] DEBUG[4760] channel.c: Not copying variable SIPDOMAIN.
[Feb 17 10:44:04] DEBUG[4760] channel.c: Not copying variable SIPURI.
[Feb 17 10:44:04] DEBUG[4760] chan_sip.c: Outgoing Call for 178
[Feb 17 10:44:04] VERBOSE[4760] logger.c: Audio is at 192.168.1.100 port 10590
[Feb 17 10:44:04] VERBOSE[4760] logger.c: Adding codec 0x4 (ulaw) to SDP
[Feb 17 10:44:04] VERBOSE[4760] logger.c: Adding codec 0x2 (gsm) to SDP
[Feb 17 10:44:04] VERBOSE[4760] logger.c: Adding codec 0x8 (alaw) to SDP
[Feb 17 10:44:04] VERBOSE[4760] logger.c: Adding non-codec 0x1 (telephone-event) to SDP
[Feb 17 10:44:04] VERBOSE[4760] logger.c: Reliably Transmitting (no NAT) to 192.168.1.5:5060:
[Feb 17 10:44:04] DEBUG[4760] rtp.c: Setting early bridge SDP of ‘SIP/143-0826db50’ with that of ‘SIP/178-08295528’
[Feb 17 10:44:04] VERBOSE[4760] logger.c:
[Feb 17 10:44:06] DEBUG[4760] chan_sip.c: Hangup call DAHDI/12-1, SIP callid 001a2fcb-80b000a2-295a984d-72c28788@192.168.1.2)
[Feb 17 10:44:06] VERBOSE[4760] logger.c: Scheduling destruction of SIP dialog ‘001a2fcb-80b000a2-295a984d-72c28788@192.168.1.2’ in 32000 ms (Method: INVITE)
[Feb 17 10:44:06] DEBUG[4760] chan_sip.c: AST hangup cause 16 (no match found in SIP)
[Feb 17 10:44:06] VERBOSE[4760] logger.c:
[Feb 17 10:44:06] DEBUG[4760] channel.c: Set channel DAHDI/12-1 to write format ulaw
[Feb 17 10:44:06] DEBUG[4760] channel.c: Set channel DAHDI/12-1 to read format ulaw
[Feb 17 10:44:06] DEBUG[4760] channel.c: Putting channel DAHDI/12-1 in 4/4 formats
[Feb 17 10:44:06] DEBUG[4760] chan_dahdi.c: New owner for channel 12 is DAHDI/12-1
[Feb 17 10:44:06] DEBUG[4760] chan_dahdi.c: Updated conferencing on 12, with 0 conference users
[Feb 17 10:44:06] DEBUG[4760] chan_dahdi.c: Updated conferencing on 12, with 0 conference users
[Feb 17 10:44:06] DEBUG[4760] chan_dahdi.c: Requested indication 3 on channel DAHDI/12-1
[Feb 17 10:44:06] DEBUG[4760] channel.c: Released clone lock on ‘SIP/143-0826db50’
[Feb 17 10:44:06] DEBUG[4760] channel.c: Done Masquerading DAHDI/12-1 (6)
[Feb 17 10:44:20] DEBUG[4760] chan_dahdi.c: Requested indication -1 on channel DAHDI/12-1
[Feb 17 10:44:20] DEBUG[4760] rtp.c: Channel ‘DAHDI/12-1’ has no RTP, not doing anything
[Feb 17 10:44:20] DEBUG[4760] channel.c: Hanging up channel ‘SIP/178-08295528’
[Feb 17 10:44:20] DEBUG[4760] chan_sip.c: Hangup call SIP/178-08295528, SIP callid 78d14ccb6004964540a49b011ddaa662@192.168.1.100)
[Feb 17 10:44:20] VERBOSE[4760] logger.c: Scheduling destruction of SIP dialog ‘78d14ccb6004964540a49b011ddaa662@192.168.1.100’ in 32000 ms (Method: INVITE)
[Feb 17 10:44:20] DEBUG[4760] chan_sip.c: Acked pending invite 102
[Feb 17 10:44:20] DEBUG[4760] chan_sip.c: Stopping retransmission on ‘78d14ccb6004964540a49b011ddaa662@192.168.1.100’ of Request 102: Match Found
[Feb 17 10:44:20] VERBOSE[4760] logger.c: Reliably Transmitting (no NAT) to 192.168.1.5:5060:
[Feb 17 10:44:20] VERBOSE[4760] logger.c: Scheduling destruction of SIP dialog ‘78d14ccb6004964540a49b011ddaa662@192.168.1.100’ in 32000 ms (Method: INVITE)
[Feb 17 10:44:20] DEBUG[4760] app_dial.c: Exiting with DIALSTATUS=NOANSWER.
[Feb 17 10:44:20] DEBUG[4760] app_macro.c: Executed application: Dial
[Feb 17 10:44:20] DEBUG[4760] pbx.c: Launching ‘Goto’
[Feb 17 10:44:20] DEBUG[4760] app_macro.c: Executed application: Goto
[Feb 17 10:44:20] DEBUG[4760] pbx.c: Launching ‘VoiceMail’
[Feb 17 10:44:20] DEBUG[4760] channel.c: Set channel DAHDI/12-1 to write format slin
[Feb 17 10:44:20] DEBUG[4760] channel.c: Scheduling timer at 160 sample intervals
[Feb 17 10:44:21] DEBUG[4760] app_voicemail.c: Hang up during prefile playback
[Feb 17 10:44:21] DEBUG[4760] app_macro.c: Spawn extension (macro-vm,s-NOANSWER,1) exited non-zero on ‘DAHDI/12-1’ in macro ‘vm’
[Feb 17 10:44:21] DEBUG[4760] pbx.c: Spawn extension (default,178,1) exited non-zero on ‘DAHDI/12-1’
[Feb 17 10:44:21] DEBUG[4760] channel.c: Soft-Hanging up channel ‘DAHDI/12-1’
[Feb 17 10:44:21] DEBUG[4760] channel.c: Scheduling timer at 0 sample intervals
[Feb 17 10:44:21] DEBUG[4760] channel.c: Hanging up channel ‘DAHDI/12-1’
[Feb 17 10:44:21] DEBUG[4760] chan_dahdi.c: dahdi_hangup(DAHDI/12-1)
[Feb 17 10:44:21] DEBUG[4760] chan_dahdi.c: Set option AUDIO MODE, value: ON(1) on DAHDI/12-1
[Feb 17 10:44:21] DEBUG[4760] chan_dahdi.c: Hangup: channel: 12 index = 0, normal = 20, callwait = -1, thirdcall = -1
[Feb 17 10:44:21] DEBUG[4760] chan_dahdi.c: Not yet hungup… Calling hangup once with icause, and clearing call
[Feb 17 10:44:21] DEBUG[4760] chan_dahdi.c: disabled echo cancellation on channel 12
[Feb 17 10:44:21] DEBUG[4760] chan_dahdi.c: Set option TDD MODE, value: OFF(0) on DAHDI/12-1
[Feb 17 10:44:21] DEBUG[4760] chan_dahdi.c: Updated conferencing on 12, with 0 conference users
[Feb 17 10:44:21] DEBUG[4760] chan_dahdi.c: Set option AUDIO MODE, value: OFF(0) on DAHDI/12-1
[Feb 17 10:44:21] DEBUG[4760] chan_dahdi.c: disabled echo cancellation on channel 12
[Feb 17 10:44:21] DEBUG[4760] pbx.c: Function result is ‘8085551212’
[Feb 17 10:44:21] DEBUG[4760] pbx.c: Function result is ‘8085551212’
[Feb 17 10:44:21] DEBUG[4760] pbx.c: Function result is ‘178’
[Feb 17 10:44:21] DEBUG[4760] pbx.c: Function result is ‘default’
[Feb 17 10:44:21] DEBUG[4760] pbx.c: Function result is ‘DAHDI/12-1’
[Feb 17 10:44:21] DEBUG[4760] pbx.c: Function result is ‘SIP/143-b6904538’
[Feb 17 10:44:21] DEBUG[4760] pbx.c: Function result is ‘VoiceMail’
[Feb 17 10:44:21] DEBUG[4760] pbx.c: Function result is ‘143|su’
[Feb 17 10:44:21] DEBUG[4760] pbx.c: Function result is ‘2009-02-17 10:44:06’
[Feb 17 10:44:21] DEBUG[4760] pbx.c: Function result is ‘(null)’
[Feb 17 10:44:21] DEBUG[4760] pbx.c: Function result is ‘2009-02-17 10:44:21’
[Feb 17 10:44:21] DEBUG[4760] pbx.c: Function result is ‘15’
[Feb 17 10:44:21] DEBUG[4760] pbx.c: Function result is ‘0’
[Feb 17 10:44:21] DEBUG[4760] pbx.c: Function result is ‘NO ANSWER’
[Feb 17 10:44:21] DEBUG[4760] pbx.c: Function result is ‘DOCUMENTATION’
[Feb 17 10:44:21] DEBUG[4760] pbx.c: Function result is ‘(null)’
[Feb 17 10:44:21] DEBUG[4760] pbx.c: Function result is ‘1234903434.243’
[Feb 17 10:44:21] DEBUG[4760] pbx.c: Function result is ‘(null)’

Thanks again,
Herb

7

Wondering if these bugs/patches applies to my problem?

bugs.digium.com/view.php?id=14350

-or-

bugs.digium.com/view.php?id=14356

8

I never did figure out what exactly was causing the problem, however I did resolve the issue, by downgrading to version 1.4.22.2