thr3ads.net - asterisk users - [asterisk-users] Blind transfers being cancelled by asterisk & hanging up on remote caller [Jan 2012]

If this information is useful, please help other people find it:
Share via:

Douglas Mortensen

2012-Jan-05 20:03 UTC

[asterisk-users] Blind transfers being cancelled by asterisk & hanging up on remote caller

Hello all,

I have a system running AsteriskNOW with asterisk asterisk-1.8.8.1-1_centos5
from AsteriskNOW repository. I just changed our Polycom 335 sip.conf so that
blindpreferred=1 (all transfers default as blind transfers). If a customer calls
in & we answer & transfer, everything works fine. But if we call out to
a customer & then transfer to another internal extension, that extension
quickly rings & then the call is immediately gone & hung up. We are
using Polycom firmware 3.3.3.

In troubleshooting this & analyzing the asterisk logs (& asterisk SIP
debug), I am seeing a few interesting items. Any help would be appreciated.

For the sake of simplicity I am going to say that extension 20 is the original
internal extension & extension 21 is the extension we are trying to transfer
to. Here's what I've learned so far:


1.       Asterisk SIP debugs are clearly showing that the transfer starts &
SIP INVITE is sent to ext 21. Ext 21 then sends a SIP message back to asterisk
indicating that it is ringing. Asterisk then sends a SIP CANCEL to ext 21. Call
is abruptly terminated for all parties.

2.       Asterisk logs are displaying WARNING messages during the transfer phase
as:
WARNING[25423] chan_sip.c: Asked to transmit frame type slin, while native
formats is 0x4 (ulaw) read/write = 0x4 (ulaw)/0x4 (ulaw)
This error repeats 10-11 times quickly (within 1 second) prior to the SIP
CANCEL. (see sample of logs below)

3.       Other interesting lines from the asterisk full log:
VERBOSE[25592] app_dial.c:     -- Connected line update to
SIP/fpbx-1-b0c4ceff-00002104 prevented.
[Jan  5 20:51:30] VERBOSE[25592] app_dial.c:     -- SIP/fpbx-1-b0c4ceff-00002104
requested special control 20, passing it to SIP/21-00002105
[Jan  5 20:51:30] VERBOSE[25592] app_macro.c:   == Spawn extension
(macro-dial-one, s, 42) exited non-zero on
'SIP/fpbx-1-b0c4ceff-00002104' in macro 'dial-one'
[Jan  5 20:51:30] VERBOSE[25592] app_macro.c:   == Spawn extension
(macro-exten-vm, s, 14) exited non-zero on
'SIP/fpbx-1-b0c4ceff-00002104' in macro 'exten-vm'

4.       In looking for the slin codec's use in our system, it is not
permitted in our system.

a.       We use an upstream SIP trunk provider for PSTN connectivity. That
trunk's codes are configured as disallow=all followed by allow=ulaw&g729

b.      Our normal sip.conf settings for all internal phones are: disallow=all
allow=g722 allow=ulaw allow=alaw allow=gsm

5.       So it would seem that slin is not even in use on our system. So why
then does it seem like a sip device is asking to use slin? The only thing I can
find if I grep /var/log/asterisk/full for slin is:
[Jan  5 19:50:40] VERBOSE[24133] file.c:     --
<SIP/fpbx-2-b0c4ceff-000020bf> Playing
'/var/spool/asterisk/voicemail/default/21/unavail.slin' (language
'en')

So it appears that our audio recordings for voicemail are in slin format?

I am not an expert with all of this, but I am doing my best to try to put the
pieces together. So again, just to recap, the problem I need to solve is why are
blind transfers calls getting terminated when the call being transferred
originated as an outbound call from one of our internal Polycom phones.

Any help would be GREATLY appreciated! :)

Just a greater excerpt from the logs:


[Jan  5 20:51:30] VERBOSE[25592] pbx.c:     -- Goto (macro-dial-one,s,30)
[Jan  5 20:51:30] VERBOSE[25592] pbx.c:     -- Executing [s at
macro-dial-one:30] Set("SIP/fpbx-1-b0c4ceff-00002104",
"D_OPTIONStr") in new stack
[Jan  5 20:51:30] VERBOSE[25592] pbx.c:     -- Executing [s at
macro-dial-one:31] ExecIf("SIP/fpbx-1-b0c4ceff-00002104",
"0?SIPAd
dHeader(Alert-Info: )") in new stack
[Jan  5 20:51:30] VERBOSE[25592] pbx.c:     -- Executing [s at
macro-dial-one:32] ExecIf("SIP/fpbx-1-b0c4ceff-00002104",
"0?SIPAd
dHeader()") in new stack
[Jan  5 20:51:30] VERBOSE[25592] pbx.c:     -- Executing [s at
macro-dial-one:33] ExecIf("SIP/fpbx-1-b0c4ceff-00002104",
"0?Set(C
HANNEL(musicclass)=)") in new stack
[Jan  5 20:51:30] VERBOSE[25592] pbx.c:     -- Executing [s at
macro-dial-one:34] GosubIf("SIP/fpbx-1-b0c4ceff-00002104",
"0?qwai
t,1") in new stack
[Jan  5 20:51:30] VERBOSE[25592] pbx.c:     -- Executing [s at
macro-dial-one:35] Set("SIP/fpbx-1-b0c4ceff-00002104",
"__CWIGNORE
=") in new stack
[Jan  5 20:51:30] VERBOSE[25592] pbx.c:     -- Executing [s at
macro-dial-one:36] Set("SIP/fpbx-1-b0c4ceff-00002104",
"__KEEPCIDTRUE") in new stack
[Jan  5 20:51:30] VERBOSE[25592] pbx.c:     -- Executing [s at
macro-dial-one:37] GotoIf("SIP/fpbx-1-b0c4ceff-00002104",
"0?usego
to,1") in new stack
[Jan  5 20:51:30] VERBOSE[25592] pbx.c:     -- Executing [s at
macro-dial-one:38] GotoIf("SIP/fpbx-1-b0c4ceff-00002104",
"0?godia
l") in new stack
[Jan  5 20:51:30] VERBOSE[25592] pbx.c:     -- Executing [s at
macro-dial-one:39] Set("SIP/fpbx-1-b0c4ceff-00002104",
"CONNECTEDL
INE(name,i)=Kyle") in new stack
[Jan  5 20:51:30] VERBOSE[25592] pbx.c:     -- Executing [s at
macro-dial-one:40] Set("SIP/fpbx-1-b0c4ceff-00002104",
"CONNECTEDL
INE(num)=21") in new stack
[Jan  5 20:51:30] VERBOSE[25592] pbx.c:     -- Executing [s at
macro-dial-one:41] Set("SIP/fpbx-1-b0c4ceff-00002104",
"D_OPTIONS=trI") in new stack
[Jan  5 20:51:30] VERBOSE[25592] pbx.c:     -- Executing [s at
macro-dial-one:42] Dial("SIP/fpbx-1-b0c4ceff-00002104",
"SIP/21,15,trI") in new stack
[Jan  5 20:51:30] VERBOSE[25592] netsock2.c:   == Using SIP RTP TOS bits 184
[Jan  5 20:51:30] VERBOSE[25592] netsock2.c:   == Using SIP RTP CoS mark 5
[Jan  5 20:51:30] VERBOSE[25592] app_dial.c:     -- Called SIP/21
[Jan  5 20:51:30] VERBOSE[25592] app_dial.c:     -- Connected line update to
SIP/fpbx-1-b0c4ceff-00002104 prevented.
[Jan  5 20:51:30] WARNING[25592] chan_sip.c: Asked to transmit frame type slin,
while native formats is 0x4 (ulaw) read/write = 0x4 (ulaw)/0x4 (ulaw)
[Jan  5 20:51:30] WARNING[25592] chan_sip.c: Asked to transmit frame type slin,
while native formats is 0x4 (ulaw) read/write = 0x4 (ulaw)/0x4 (ulaw)
[Jan  5 20:51:30] WARNING[25592] chan_sip.c: Asked to transmit frame type slin,
while native formats is 0x4 (ulaw) read/write = 0x4 (ulaw)/0x4 (ulaw)
[Jan  5 20:51:30] WARNING[25592] chan_sip.c: Asked to transmit frame type slin,
while native formats is 0x4 (ulaw) read/write = 0x4 (ulaw)/0x4 (ulaw)
[Jan  5 20:51:30] WARNING[25592] chan_sip.c: Asked to transmit frame type slin,
while native formats is 0x4 (ulaw) read/write = 0x4 (ulaw)/0x4 (ulaw)
[Jan  5 20:51:30] VERBOSE[25592] app_dial.c:     -- SIP/21-00002105 is ringing
[Jan  5 20:51:30] WARNING[25592] chan_sip.c: Asked to transmit frame type slin,
while native formats is 0x4 (ulaw) read/write = 0x4 (ulaw)/0x4 (ulaw)
[Jan  5 20:51:30] WARNING[25592] chan_sip.c: Asked to transmit frame type slin,
while native formats is 0x4 (ulaw) read/write = 0x4 (ulaw)/0x4 (ulaw)
[Jan  5 20:51:30] WARNING[25592] chan_sip.c: Asked to transmit frame type slin,
while native formats is 0x4 (ulaw) read/write = 0x4 (ulaw)/0x4 (ulaw)
[Jan  5 20:51:30] VERBOSE[25592] app_dial.c:     -- SIP/fpbx-1-b0c4ceff-00002104
requested special control 20, passing it to SIP/21-00002105
[Jan  5 20:51:30] VERBOSE[25592] app_macro.c:   == Spawn extension
(macro-dial-one, s, 42) exited non-zero on
'SIP/fpbx-1-b0c4ceff-00002104' in macro 'dial-one'
[Jan  5 20:51:30] VERBOSE[25592] app_macro.c:   == Spawn extension
(macro-exten-vm, s, 14) exited non-zero on
'SIP/fpbx-1-b0c4ceff-00002104' in macro 'exten-vm'
[Jan  5 20:51:30] VERBOSE[25592] pbx.c:   == Spawn extension
(from-internal-xfer, 21, 2) exited non-zero on
'SIP/fpbx-1-b0c4ceff-00002104'
[Jan  5 20:51:30] VERBOSE[25592] pbx.c:     -- Executing [h at
from-internal-xfer:1] Macro("SIP/fpbx-1-b0c4ceff-00002104",
"hangupcall") in new stack
[Jan  5 20:51:30] VERBOSE[25592] pbx.c:     -- Executing [s at
macro-hangupcall:1] GotoIf("SIP/fpbx-1-b0c4ceff-00002104",
"1?theend") in new stack
[Jan  5 20:51:30] VERBOSE[25592] pbx.c:     -- Goto (macro-hangupcall,s,3)
[Jan  5 20:51:30] VERBOSE[25592] pbx.c:     -- Executing [s at
macro-hangupcall:3] Hangup("SIP/fpbx-1-b0c4ceff-00002104",
"") in new stack
[Jan  5 20:51:30] VERBOSE[25592] app_macro.c:   == Spawn extension
(macro-hangupcall, s, 3) exited non-zero on
'SIP/fpbx-1-b0c4ceff-00002104' in macro 'hangupcall'
[Jan  5 20:51:30] VERBOSE[25592] pbx.c:   == Spawn extension
(from-internal-xfer, h, 1) exited non-zero on
'SIP/fpbx-1-b0c4ceff-00002104'


Thanks,
-
Doug Mortensen
Network Consultant
Impala Networks Inc
CCNA, MCSA, Security+, A+
Linux+, Network+, Server+
A.A.S. Information Technology
.
www.impalanetworks.com<http://www.impalanetworks.com/>
P: (505) 327-7300
F: (505) 327-7545

-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<http://lists.digium.com/pipermail/asterisk-users/attachments/20120105/d8741db9/attachment.htm>

Luke Hamburg

2012-Jan-07 10:19 UTC

head link

[asterisk-users] Blind transfers being cancelled by asterisk & hanging up on remote caller

Doug:
for what it's worth I am having the exact same nightmare.  Not sure exactly
when it started but I believe it was a change in 1.8.8.1 / 1.8.9.0-rc1 (I am
running 1.8.9rc1).  I also have Polycom (335, 550, 650)  and blind transfers
are broken.  All legs of the call are dropped when the xfer is executed.  A
calls B, B xfer to C and (C) blips for a split second like its ringing but
then all calls go dead.  I tried to debug myself using some sip tracing but
I didn't get very far.  I even tried mucking around with a few settings in
my Polycom provisioning I thought might be related e.g.

  voIpProt.SIP.allowTransferOnProceeding
  voIpProt.SIP.connectionReuse.useAlias
  voIpProt.SIP.useContactInReferTo
  voIpProt.SIP.conference.parallelRefer
  voIpProt.SIP.strictLineSeize
  voIpProt.SIP.strictUserValidation
  voIpProt.SIP.strictReplacesHeader
  voIpProt.SIP.useContactInReferTo

and also upgraded to the new 3.3.4 firmware which is out yesterday,  didn't
change a thing.
stuck here for now,  Attended xfers seem to work.    I am not sure this is a
Polycom-specific issue because I was seeing this bad behavior even using
some Softphones I set up for testing.

my next recourse is to try rolling back to 1.8.8.0 or earlier and if that
fixes it then I will open a JIRA ticket with more details.

Luke


--
From: asterisk-users-bounces at lists.digium.com
[mailto:asterisk-users-bounces at lists.digium.com] On Behalf Of Douglas
Mortensen
Sent: Thursday, January 05, 2012 3:04 PM
To: Asterisk Users Mailing List - Non-Commercial Discussion
Subject: [asterisk-users] Blind transfers being cancelled by asterisk &
hanging up on remote caller

Hello all,

I have a system running AsteriskNOW with asterisk asterisk-1.8.8.1-1_centos5
from AsteriskNOW repository. I just changed our Polycom 335 sip.conf so that
blindpreferred=1 (all transfers default as blind transfers). If a customer
calls in & we answer & transfer, everything works fine. But if we call
out
to a customer & then transfer to another internal extension, that extension
quickly rings & then the call is immediately gone & hung up. We are
using
Polycom firmware 3.3.3.

In troubleshooting this & analyzing the asterisk logs (& asterisk SIP
debug), I am seeing a few interesting items. Any help would be appreciated.

[...]

Thanks,
-
Doug Mortensen

Maybe Matching Threads

Search for more reasonably related threads

asterisk users - Jan 2012 - Blind transfers being cancelled by asterisk & hanging up on remote caller

[asterisk-users] Blind transfers being cancelled by asterisk & hanging up on remote caller

[asterisk-users] Blind transfers being cancelled by asterisk & hanging up on remote caller

Maybe Matching Threads