|Summary:||ASTERISK-18685: Half Attended Transfers ("Blind Transfers") Fail for No Apparent Reason|
|Reporter:||Greg Nutt (timeshell)||Labels:|
|Date Opened:||2011-10-06 09:58:21||Date Closed:||2016-04-25 17:47:22|
|Versions:||220.127.116.11 Potential Blocker||Frequency of|
|Environment:||CentOS 5.6 64 bit||Attachments:||( 0) debug10.txt|
( 1) HalfAttendTransferToBria
( 2) putty.log
|Description:||Call being blind transferred from Polycom Soundpoint IP501 using UDP transport to Bria softphone using TCP transport. Also blind tranfer UDP from Polycom IP500 to Linksys PAP2. The PAP2/Bria SIP device receives the call notification and rings, however from the originating side the call goes straight to voicemail. When trying to answer the call on the PAP2/Bria side, the call goes to error and disappears. 5321 is the Polycom device below and 5221 is the PAP2 or Bria device. An attempt was made to answer the call and below is what happens in CLI.|
== Spawn extension (DLPN_DialPlan1, 5321, 1) exited non-zero on 'SIP/5321-00002c4b<ZOMBIE>'
- Got SIP response 500 "Internal Server Error" back from (IP REMOVED):37395
- SIP/5221-00002c4c is circuit-busy
|Comments:||By: Greg Nutt (timeshell) 2011-10-06 09:59:39.208-0500|
This behaviour was also observed in 1.8.4.
By: Greg Nutt (timeshell) 2011-10-06 10:36:01.919-0500
I'd also like to note that all other calls in or out from/to Bria or Polycom seem to work fine otherwise.
5321 is the Polycom blind transferring to 5221 which is the Bria.
The call progress is as follows.
1. Exten 5261 (Polycom phone) calls 5321 (Polycom phone).
2. 5321 blind transfers (press transfer, dial number, press transfer, hang up)to 5221 (Bria softphone).
3. 5221 is ringing, 5321 hears ringing.
4. As soon as 5321 presses transfer again to send the call to 5221, 5261 is sent directly to voicemail for 5221 even though 5221 is ringing.
5. 5221 continues to ring. Upon "answering the call", error message appears on 5221.
The same above happens doing a blind transfer to a PAP2.
This does NOT happen when blind transferring to another Polycom phone. Blind transfer to another Polycom phone works fine.
By: Greg Nutt (timeshell) 2011-11-01 07:34:09.699-0500
New situation. Apparently not just issue between the Polycom and Bria phones. I have also had this happen now between a Polycom IP500 and a Linksys PAP2 device; UDP to UDP. The former is on a 64 bit server, the latter on a 32 bit server.
By: Leif Madsen (lmadsen) 2011-11-01 08:13:52.317-0500
Nothing in your log is leading me to believe Asterisk is doing anything wrong -- the dialplan seems to be flowing in a logical manner.
That means additional debugging information is required to move this issue forward. Because you're using SIP, the bug guidelines state that you need to provide the SIP trace from the Asterisk console while reproducing this issue and attach it as a text file.
Additionally, please state if you're using SIP transfers from the phone, or using built-in transfers within' Asterisk.
By: Leif Madsen (lmadsen) 2011-11-01 08:14:18.183-0500
Thank you for taking the time to report this bug and helping to make Asterisk better. Unfortunately, we cannot work on this bug because your description did not include enough information. You may find it helpful to read the Asterisk Issue Guidelines http://www.asterisk.org/developers/bug-guidelines. We would be grateful if you would then provide a more complete description of the problem. At a minimum, we need:
1. the specific steps or actions you took that caused you to encounter the problem,
2. the behavior you expected, and
3. the behavior you actually encountered (in as much detail as possible).
This likely includes output from the console with debug level logging, a SIP trace (if this is SIP related), and configuration information such as dialplan (e.g. extensions.conf) and channel configuration (e.g. sip.conf). Thanks!
By: Greg Nutt (timeshell) 2011-11-01 12:18:29.901-0500
Debug from CLI
By: Greg Nutt (timeshell) 2011-11-01 12:23:56.892-0500
Initial comment changed. Debug added.
By: Leif Madsen (lmadsen) 2011-11-03 14:42:43.998-0500
Not sure what is going on here. The voicemail application is answering for a good reason; you're getting:
-- Got SIP response 500 "Internal Server Error" back from <ip hidden>:56239
Which means the other end can't be contacted for some reason, so the dialplan continues as it should and then calls the Voicemail() application.
What I don't understand is why the other end is not available. You're going to have to provide more information. I guess I'd start with the 'sip show peers' output.
You might also want to enable SIP history in sip.conf per the bug guidelines.
By: Greg Nutt (timeshell) 2011-11-03 15:13:41.460-0500
Perhaps even more interesting is the fact that it only happens on blind transfers. Calling the same extension directly to these devices (or "on the other end") works just fine. So it's not as if there's a registration or communication problem with the device.
I should also point out that I'm quite certain we did not experience this before upgrading from 1.6.x to 1.8.x.
By: Greg Nutt (timeshell) 2011-11-03 15:46:01.230-0500
sip show peers for these specific extens:
5221/5221 <public IP> D N 39561 Unmonitored
5261/5261 192.168.15.184 D N 5060 Unmonitored
5321/5321 192.168.15.187 D N 5060 Unmonitored
By: Greg Nutt (timeshell) 2011-11-08 16:57:31.844-0600
I noticed line 2347 from attachment debug10.txt:
[2011-11-08 17:30:19] DEBUG res_rtp_asterisk.c: Changing ssrc from 1722147589 to 605060448 due to a source change
[2011-11-08 17:30:19] DEBUG rtp_engine.c: rtp-engine-local-bridge: Oooh, something is weird, backing out
By: David Woolley (davidw) 2011-11-09 05:53:13.395-0600
One technicality. This is not a blind transfer as far as what goes over the wire is concerned.
The description of the process was suggestive of this, but looking at the trace it is confirmed by the fact that REFER/replaces is used.
By: Greg Nutt (timeshell) 2011-11-09 07:42:54.457-0600
Not sure what that means, but I neglected to point out that I did 2 tests in the attached debug10.txt file.
The first is doing a call from 5261 to 5321 and then having 5321 transfer the call to 5221. The call was transferred by hitting transfer, dialing the number, and then hitting transfer again without waiting for 5221 to answer.
The second is 5261 dialling 5221 directly to demonstrate that 5221 does indeed receive calls.
I would lastly like to point out that if we do the first scenario but instead of transferring right away but waiting for 5221 to answer and then transfer the call is successfully transferred.
Interestingly "blind transfers" from 5221 to other devices works fine also. The issues seems to specifically occur when "blind transferring" to non-Polycom devices.
By: David Woolley (davidw) 2011-11-09 07:59:13.315-0600
There is only one transfer, and that is an attended transfer:
[2011-11-08 17:30:19] DEBUG chan_sip.c: Header 0 [ 40]: REFER sip:email@example.com:5060 SIP/2.0
[2011-11-08 17:30:19] DEBUG chan_sip.c: Header 9 : Refer-To: <sip:firstname.lastname@example.org:5060;user=phone?Replaces=55659242-cbacca8-e5c8eb75%40192.168.15.187%3Bto-tag%3Das3b2f78b5%3Bfrom-tag%3DF94A270E-80FB35DB>
although done before the target answered. I call these half attended transfers, but the Asterisk community has another name, which I forget, but with more negative connotations.
A blind transfer would have had no replaces parameter on the Refer-To: line. The key difference is that, with a blind transfer, the transferror only has one connection, but with an attended one, the original call is on hold, and a new call is created. The PABX doesn't know that the two are connected until it sees the REFER.
By: Greg Nutt (timeshell) 2011-11-09 09:12:36.650-0600
Ok, so, whatever you call it, I should be able to answer the call on 5221 when it is transferred from 5321, however, 5261 goes to 5221's voicemail instead when transfer is pressed the second time on 5321. 5221 rings however until it is "answered", but is unable to pick up the call because it has already gone to voicemail when it shouldn't have.
This is still a bug. How to resolve it?
By: Greg Nutt (timeshell) 2011-11-14 17:34:53.220-0600
I'd also like to reiterate that the above situation only seems to happen when doing the "half attended" transfer to a non-Polycom phone. When doing the half-attended transfer to another Polycom phone the "half attended transfer" completes successfully. Also, if the party being transferred to (5221) picks up before pressing the transfer button the second time (at 5321), the call does go through successfully. So Asterisk seems to see something different when doing a "half attended transfer" to a non-Polycom (at least that I'm using such as Bria for iPhone or Linksys PAP2-NA) device.
By: David Woolley (davidw) 2011-11-15 06:02:42.928-0600
You will need top provide a trace of a working case.
Having this depend on the destination seems strange as all forms of attended transfer are actually done as an internal manipulation, although they might be followed up by a re-INVITE of the media or, in current versions, the updating of the displayed party information.
You don't seem to have included the verbose logging, so we are not seeing what Asterisk is transmitting, but it looks as though the phone is rejecting the UPDATE of the connected party information, with a 500 status, which is basically saying that the phone firmware is broken. If it were objecting because something that Asterisk had done, it should not have used a 5xx response.
[2011-11-08 17:30:19] DEBUG chan_sip.c: Header 0 [ 33]: SIP/2.0 500 Internal Server Error
This looks like a support issue: either fix the phone's firmware, or configure Asterisk not to use the feature that is breaking it (i.e. avoid the bug in the phone's firmware). This feature is new to 1.8, and I'm not familiar with how to configure itm but I assume one can turn it off.
By: Matt Jordan (mjordan) 2011-11-15 09:55:42.092-0600
Requesting feedback for SIP trace and / or wireshark pcap of issue
By: Greg Nutt (timeshell) 2011-12-13 07:57:51.860-0600
PCAP added for "Confluence Users".
By: Stefan Schmidt (schmidts) 2011-12-14 03:00:50.491-0600
have you tried it with a newer version? something above revision 341366 cause it could be the problem i have fixed there. i also had problems with half attend transfers to spa941 phones where others like spa525 workes fine until i find out that asterisk tries to send out a sip UPDATE request after the masquerade but didnt got a final contact header cause the other side hasnt answer the call so far.
if possible please try 1.8.8 if this problem still exists there.
By: Greg Nutt (timeshell) 2011-12-14 11:38:31.106-0600
I have another interesting issue that I suspect may be related to this. ASTERISK-19039
By: Leif Madsen (lmadsen) 2011-12-15 12:06:20.327-0600
As requested, have you tried the latest 1.8 branch and reproduced?
By: Greg Nutt (timeshell) 2011-12-15 15:59:55.381-0600
Still on my to do list when I get a moment.
By: Leif Madsen (lmadsen) 2011-12-19 12:32:14.064-0600
Assigned to reporter to provide feedback.
By: Greg Nutt (timeshell) 2011-12-20 17:12:43.047-0600
Confirmed problem still occurs in 18.104.22.168
By: Leif Madsen (lmadsen) 2016-04-21 14:33:09.349-0500
Not sure if this is still an issue, so put back to triage and unassigned from myself. Might just be an issue to be closed out.
By: Rusty Newton (rnewton) 2016-04-25 17:47:22.827-0500
Closing this out since 1.8 is no longer supported.
If this issue can be reproduced on 11 or 13, please file a new issue and we'll re-triage it there to see if the behavior is the same and what new data we might need to look into the issue.