Summary: | ASTERISK-22436: [patch] No BYE to masqueraded channel on INVITE with replaces | ||
Reporter: | Eelco Brolman (eelcob) | Labels: | |
Date Opened: | 2013-09-02 07:55:00 | Date Closed: | 2015-02-08 20:45:53.000-0600 |
Priority: | Major | Regression? | |
Status: | Closed/Complete | Components: | Channels/chan_sip/General |
Versions: | 1.8.23.1 | Frequency of Occurrence | Constant |
Related Issues: | |||
Environment: | Attachments: | ( 0) asterisk-1.8-hangup-replaced.diff ( 1) asterisk-1.8-hangup-replaced-2.diff ( 2) asterisk-11-hangup-replaced.diff ( 3) asterisk-11-hangup-replaced-2.diff ( 4) asterisk-11-hangup-replaced-3.diff ( 5) asterisk-debug.log ( 6) atrujillo-asterisk1-full-log.txt ( 7) atrujillo-asterisk1-packets.pcap ( 8) atrujillo-asterisk2-full-log.txt ( 9) atrujillo-asterisk2-packets.pcap | |
Description: | Consider the flow as in http://www.in2eps.com/fo-sip/tk-fo-sip-service-05.html. Carol is the asterisk server in this case, Alice and Bob 2 (external) sip phones (i.e. NOT registered with asterisk). Asterisk acts for example as an application server. Bob wants to attended transfer Alice to this application.
When Bob refers Alice to Carol (asterisk), Carol (asterisk) correctly accepts the invite, and masquerades the channels into the new Invited channel. The original channel to Bob becomes a Zombie, which is Hangup (see logging), but Asterisk fails to send out the BYE to Bob (message 22 in http://www.in2eps.com/fo-sip/tk-fo-sip-service-05.html#fig22). This result in Bob assuming the transfer is not complete yet, and keeping the call as "on hold" on his phone. Any thought on this issue? {code} [Sep 2 14:11:33] DEBUG[7190] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 172.29.19.13:5060 [Sep 2 14:11:33] DEBUG[7190] channel.c: Planning to masquerade channel SIP/alice-00000152 into the structure of SIP/bob-0000014f [Sep 2 14:11:33] DEBUG[7190] channel.c: Done planning to masquerade channel SIP/alice-00000152 into the structure of SIP/bob-0000014f [Sep 2 14:11:33] DEBUG[7190] channel.c: Putting channel SIP/alice-00000152 in alaw/alaw formats [Sep 2 14:11:33] DEBUG[7190] chan_sip.c: SIP Fixup: New owner for dialogue 2063187328: SIP/alice-00000152 (Old parent: SIP/bob-0000014f<ZOMBIE>) [Sep 2 14:11:33] DEBUG[7190] chan_sip.c: SIP Fixup: New owner for dialogue 54c78f06-534c5fb7-9fe652e0@172.30.19.102: SIP/bob-0000014f<ZOMBIE> (Old parent: SIP/alice-00000152) [Sep 2 14:11:33] VERBOSE[7190] chan_sip.c: Scheduling destruction of SIP dialog '54c78f06-534c5fb7-9fe652e0@172.30.19.102' in 6400 ms (Method: ACK) [Sep 2 14:11:33] DEBUG[7190] chan_sip.c: Session timer stopped: 68528 - 54c78f06-534c5fb7-9fe652e0@172.30.19.102 [Sep 2 14:11:33] DEBUG[7190] channel.c: Done Masquerading SIP/alice-00000152 (6) [Sep 2 14:11:33] DEBUG[7190] res_rtp_asterisk.c: Not changing SSRC since we haven't sent any RTP yet [Sep 2 14:11:33] DEBUG[7190] channel.c: Hanging up zombie 'SIP/bob-0000014f<ZOMBIE>' {code} | ||
Comments: | By: Rusty Newton (rnewton) 2013-09-05 19:09:08.063-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! Specifically please provide a packet capture of the complete SIP dialog, long with an Asterisk full log (VERBOSE and DEBUG) covering the whole scenario. https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines#AsteriskIssueGuidelines-Submittingthebugreport-informationrequirements By: Rusty Newton (rnewton) 2013-09-26 16:07:32.574-0500 Eelco, are you able to provide the additional requested information? Specifically the configuration files, full debug and packet capture? By: Rusty Newton (rnewton) 2013-10-18 15:43:00.168-0500 Suspended due to lack of activity. Please request a bug marshal in #asterisk-bugs on the IRC network irc.freenode.net to reopen the issue should you have the additional information requested. Further information can be found at http://www.asterisk.org/developers/bug-guidelines By: Peter Jannesen (pjannesen) 2014-02-15 19:03:35.163-0600 In a mixed environment with multiple asterisk servers and sipxecs. We have a problem with transferring a call to a asterisk server. After analyzing SIP traces I think that asterisk is the source of the problem. RFC 5359 2.5 Transfer Attended gives sequence of sip messages for a attended transfer. (http://www.in2eps.com/fo-sip/tk-fo-sip-service-05.html) In our case Alice = asterisk1, Bob = Sipxecs / tel100, Carol = asterisk2 The problem is that asterisk2 is not sending a ‘BYE’ (step 22)! So Bob (sipxecs / tel100) thinks that the transfer hangs. If Alice and Carol are on the same asterisk server, asterisk sends a ‘BYE’! (This is the reason that the problem only happens in a mixed environment). This is the SIP trace (using tcpdump) of asterisk2 {noformat} 12:46:30.841478 IP (tos 0xb8, ttl 62, id 30444, offset 0, flags [none], proto UDP (17), length 1425) sipxecs1.5060 > asterisk2.5060: SIP, length: 1397 INVITE sip:290@asterisk2;sipxecs-lineid=6 SIP/2.0 Record-Route: <sip:sipxecs1:5060;lr;sipXecs-CallDest=UNK%2CCUST;sipXecs-rs=%2Aauth%7E.%2Afrom%7EYXM3NGI1OWQzMA%60%60%21a96cde46c4d9296fc16bc8af8b566cac> Via: SIP/2.0/UDP sipxecs1;branch=z9hG4bK-XX-6a8ay0sqEMEg7wr3PB5qUjbieQ Via: SIP/2.0/UDP sipxecs1;branch=z9hG4bK-XX-6a84WvyYTvnLCCxmGLtOh06DCQ~o9NK7RwdzsL13kThcGLS5Q Via: SIP/2.0/UDP sipxecs1;branch=z9hG4bK-XX-6a7bICVjhq0LXNSxCLRsexUzGg~nbM4RjAJQR56Dqn3zdL5TQ Via: SIP/2.0/UDP 10.31.84.41:5060;branch=z9hG4bK1a7bd0b9;rport=5060 Max-Forwards: 65 From: "PJannese" <sip:Unknown@10.31.84.41>;tag=as74b59d30 To: <sip:290@sipxecs1:5060> Contact: <sip:Unknown@10.31.84.41:5060;x-sipX-nonat> Call-Id: 06bc46fd27fb13e447d28a6e60f57fd8@10.31.84.41:5060 Cseq: 102 INVITE User-Agent: FPBX-2.9.0(1.8.17.0) Date: Sat, 15 Feb 2014 11:46:30 GMT Replaces: 7dda4502-d5ea9303-64f9de18@192.168.202.228;to-tag=as5e0e9abc;from-tag=D6F4F7B0-F96CE149 Require: replaces Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Type: application/sdp Content-Length: 237 Expires: 7200 v=0 o=root 1823065412 1823065412 IN IP4 10.31.84.41 s=Asterisk PBX 1.8.17.0-3 c=IN IP4 10.31.84.41 t=0 0 m=audio 15752 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv 12:46:30.841958 IP (tos 0x60, ttl 64, id 5956, offset 0, flags [none], proto UDP (17), length 945) asterisk2.5060 > sipxecs1.5060: SIP, length: 917 SIP/2.0 100 Trying Via: SIP/2.0/UDP sipxecs1;branch=z9hG4bK-XX-6a8ay0sqEMEg7wr3PB5qUjbieQ;received=sipxecs1;rport=5060 Via: SIP/2.0/UDP sipxecs1;branch=z9hG4bK-XX-6a84WvyYTvnLCCxmGLtOh06DCQ~o9NK7RwdzsL13kThcGLS5Q Via: SIP/2.0/UDP sipxecs1;branch=z9hG4bK-XX-6a7bICVjhq0LXNSxCLRsexUzGg~nbM4RjAJQR56Dqn3zdL5TQ Via: SIP/2.0/UDP 10.31.84.41:5060;branch=z9hG4bK1a7bd0b9;rport=5060 Record-Route: <sip:sipxecs1:5060;lr;sipXecs-CallDest=UNK%2CCUST;sipXecs-rs=%2Aauth%7E.%2Afrom%7EYXM3NGI1OWQzMA%60%60%21a96cde46c4d9296fc16bc8af8b566cac> From: "PJannese" <sip:Unknown@10.31.84.41>;tag=as74b59d30 To: <sip:290@sipxecs1:5060> Call-ID: 06bc46fd27fb13e447d28a6e60f57fd8@10.31.84.41:5060 CSeq: 102 INVITE Server: FPBX-2.9.0(1.8.17.0) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: <sip:290@asterisk2:5060> Content-Length: 0 12:46:30.842099 IP (tos 0x60, ttl 64, id 5957, offset 0, flags [none], proto UDP (17), length 1226) asterisk2.5060 > sipxecs1.5060: SIP, length: 1198 SIP/2.0 200 OK Via: SIP/2.0/UDP sipxecs1;branch=z9hG4bK-XX-6a8ay0sqEMEg7wr3PB5qUjbieQ;received=sipxecs1;rport=5060 Via: SIP/2.0/UDP sipxecs1;branch=z9hG4bK-XX-6a84WvyYTvnLCCxmGLtOh06DCQ~o9NK7RwdzsL13kThcGLS5Q Via: SIP/2.0/UDP sipxecs1;branch=z9hG4bK-XX-6a7bICVjhq0LXNSxCLRsexUzGg~nbM4RjAJQR56Dqn3zdL5TQ Via: SIP/2.0/UDP 10.31.84.41:5060;branch=z9hG4bK1a7bd0b9;rport=5060 Record-Route: <sip:sipxecs1:5060;lr;sipXecs-CallDest=UNK%2CCUST;sipXecs-rs=%2Aauth%7E.%2Afrom%7EYXM3NGI1OWQzMA%60%60%21a96cde46c4d9296fc16bc8af8b566cac> From: "PJannese" <sip:Unknown@10.31.84.41>;tag=as74b59d30 To: <sip:290@sipxecs1:5060>;tag=as06c41dcb Call-ID: 06bc46fd27fb13e447d28a6e60f57fd8@10.31.84.41:5060 CSeq: 102 INVITE Server: FPBX-2.9.0(1.8.17.0) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: <sip:290@asterisk2:5060> Content-Type: application/sdp Content-Length: 237 v=0 o=root 2079365558 2079365558 IN IP4 asterisk2 s=Asterisk PBX 1.8.17.0-3 c=IN IP4 asterisk2 t=0 0 m=audio 11386 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv 12:46:30.884290 IP (tos 0xb8, ttl 62, id 30445, offset 0, flags [none], proto UDP (17), length 555) sipxecs1.5060 > asterisk2.5060: SIP, length: 527 ACK sip:290@asterisk2:5060 SIP/2.0 Via: SIP/2.0/UDP sipxecs1;branch=z9hG4bK-XX-6a91ST2tBteB34L13142KZ7mDA Via: SIP/2.0/UDP 10.31.84.41:5060;branch=z9hG4bK542179db;rport=5060 Max-Forwards: 69 From: "PJannese" <sip:Unknown@10.31.84.41>;tag=as74b59d30 To: <sip:290@sipxecs1:5060>;tag=as06c41dcb Contact: <sip:Unknown@10.31.84.41:5060;x-sipX-nonat> Call-Id: 06bc46fd27fb13e447d28a6e60f57fd8@10.31.84.41:5060 Cseq: 102 ACK User-Agent: FPBX-2.9.0(1.8.17.0) Content-Length: 0 Date: Sat, 15 Feb 2014 11:46:30 GMT ..... 12:47:27.493215 IP (tos 0xb8, ttl 62, id 30447, offset 0, flags [none], proto UDP (17), length 904) sipxecs1.5060 > asterisk2.5060: SIP, length: 876 BYE sip:290@asterisk2:5060 SIP/2.0 Via: SIP/2.0/UDP sipxecs1;branch=z9hG4bK-XX-6ac0ubbst47evIg`IrWHGf1Bgw Via: SIP/2.0/UDP 192.168.202.228;branch=z9hG4bK8ab3cacb4B715980 From: "Peter Test1" <sip:301@voip.XXXX.local>;tag=D6F4F7B0-F96CE149 To: <sip:290@voip.XXXX.local;user=phone>;tag=as5e0e9abc Cseq: 3 BYE Call-Id: 7dda4502-d5ea9303-64f9de18@192.168.202.228 Contact: <sip:301@192.168.202.228;x-sipX-nonat> User-Agent: PolycomSoundPointIP-SPIP_450-UA/3.2.6.0314 Accept-Language: nl-nl,nl;q=0.9,en;q=0.8 Max-Forwards: 69 Content-Length: 0 Date: Sat, 15 Feb 2014 11:47:27 GMT 12:47:27.493398 IP (tos 0x60, ttl 64, id 5959, offset 0, flags [none], proto UDP (17), length 603) asterisk2.5060 > sipxecs1.5060: SIP, length: 575 SIP/2.0 481 Call leg/transaction does not exist Via: SIP/2.0/UDP sipxecs1;branch=z9hG4bK-XX-6ac0ubbst47evIg`IrWHGf1Bgw;received=sipxecs1;rport=5060 Via: SIP/2.0/UDP 192.168.202.228;branch=z9hG4bK8ab3cacb4B715980 From: "Peter Test1" <sip:301@voip.XXXX.local>;tag=D6F4F7B0-F96CE149 To: <sip:290@voip.XXXX.local;user=phone>;tag=as5e0e9abc Call-ID: 7dda4502-d5ea9303-64f9de18@192.168.202.228 CSeq: 3 BYE Server: FPBX-2.9.0(1.8.17.0) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 {noformat} By: Matt Jordan (mjordan) 2014-02-15 21:14:11.691-0600 A SIP trace in the comment unfortunately doesn't tell us enough. Please attach a DEBUG log with 'sip set debug on' enabled to this issue from the Asterisk instance that fails to send the BYE request. I can reopen this issue when the log file is attached. By: Peter Jannesen (pjannesen) 2014-02-16 16:09:15.768-0600 I have made a debug log as requested. Hopefully you find something By: Matt Jordan (mjordan) 2014-02-16 17:45:48.050-0600 Thanks for the log - that contains the information the issue needed. By: Kristian Høgh (kfhdk) 2014-07-03 06:35:39.849-0500 When INVITE/Replaces is accepted, the old thannel should be hung up by sending BYE. At line 4219 in chan_sip.c (in asterisk-1.8.23.1) {noformat} } else if (p->refer && !p->alreadygone) { ast_debug(3, "Finally hanging up channel after transfer: %s\n", p->callid); stop_media_flows(p); transmit_request_with_auth(p, SIP_BYE, 0, XMIT_RELIABLE, 1); append_history(p, "ReferBYE", "Sending BYE on transferer call leg %s", p->callid); sip_scheddestroy(p, DEFAULT_TRANS_TIMEOUT); {noformat} The problem is it's the other way around. The channel we want to hang up, is referred to by another channel. a is talking to b. c sends INVITE/Replaces. p->refer->refer_call on c, is set to a. a should be hung up, but a->refer is NULL By: Jeremiah Gowdy (jgowdy) 2014-10-27 17:36:44.351-0500 We have experienced the same issue. I'm asking one of our engineers to attach a full log to this case. By: Alejandro Trujillo (atrujillo) 2014-10-27 18:09:15.479-0500 Jeremiah, Here I'm attaching full logs and packet captures on UDP and port 5060 for trying to perform an attended transfer using 2 asterisk instances and not getting BYE after INVITE with replaces. Consider the flow as in: http://www.in2eps.com/fo-sip/tk-fo-sip-service-05.html Based in our logs: Alice is Extension: 80 DID: 2132013020 Bob is Extension: 81 DID: 2132013013 Carol is Extension: 87 DID: 7609336033 Our asterisk1 instance handles the communication between Alice and Bob while our asterisk2 instance handles the communication between Bob and Carol By: Jeremiah Gowdy (jgowdy) 2014-10-28 18:45:59.301-0500 We found it. I'll submit a diff tomorrow. The bug is not the code Kristian has referenced above code, which triggers on the auto-destroy. If you patch in a flag that fixes it for the auto-destroy case, all that does is hang up on the channel 30 seconds later when the scheduler gets around to it. What we want is for the channel to be hung up after invite replaces does the masq. To fix the bug we simply add an ast_hangup(p->refer->refer_call->owner) to the end up handle_invite_replaces after sip_pvt_lock(p) on line 24912. I've been advised by Corey Farrell to run the test suite since it's a patch to chan_sip.c before submitting it. So we'll do that and then make our diff for Asterisk 1.8 and Asterisk 11. I looked at the handle_invite_replaces code in trunk and it looks a bit different so we'll have to see if the same patch works on that version. Thanks to Alejandro Trujillo who helped me debug this issue today. By: Jeremiah Gowdy (jgowdy) 2014-10-29 12:13:47.507-0500 This is a small patch to hang up on the replaced channel in an Invite: Replaces scenario. Applies to branch Asterisk 11. By: Jeremiah Gowdy (jgowdy) 2014-10-29 12:16:14.914-0500 This is a small patch to hang up on the replaced channel in an Invite: Replaces scenario. Applies to branch Asterisk 1.8. By: Kristian Høgh (kfhdk) 2014-10-30 08:39:34.588-0500 When trying to compile 1.8.29 and (yes, I know its old) 11.6, I get the following: chan_sip.c: In function ‘handle_invite_replaces’: chan_sip.c:23033: warning: implicit declaration of function ‘ast_channel_hangup’ Am I doing something wrong? By: Jeremiah Gowdy (jgowdy) 2014-10-30 18:54:46.740-0500 Sorry when I manually redid the patch for the different versions I typed ast_channel_hangup instead of ast_hangup. By: Jeremiah Gowdy (jgowdy) 2014-10-30 18:56:00.740-0500 Here is the updated patch for Asterisk 11 By: Jeremiah Gowdy (jgowdy) 2014-10-30 19:13:32.551-0500 Fixed Asterisk 1.8 patch By: Jeremiah Gowdy (jgowdy) 2014-10-31 11:24:15.494-0500 Our testing is still showing issues with this patch, just FYI. Don't consider it production worthy yet. By: Jeremiah Gowdy (jgowdy) 2014-10-31 14:29:52.992-0500 So the problem seems to be twofold and not really addressed by our attempted one line fix. When we do an Invite: Replaces, we're calling ast_hangup in handle_invite_replaces on the replaced channel "c", but the ast_hangup code is checking for SIP_DEFER_BYE_ON_TRANSFER and delaying the SIP BYE for 32 seconds per DEFAULT_TRANS_TIMEOUT. When the SIP autodestruct finally triggers 32 seconds later, p->refer is not set on the replaced channel, causing the SIP BYE to be skipped altogether. By: Jeremiah Gowdy (jgowdy) 2014-11-03 17:59:33.737-0600 This seems to fix the issue. By: Kristian Høgh (kfhdk) 2014-11-04 02:08:14.592-0600 asterisk-11-hangup-replaced-3.diff works for me too By: Matt Jordan (mjordan) 2014-11-05 17:00:56.553-0600 [~jgowdy]: Do you mind putting this up for peer review on [Review Board|https://wiki.asterisk.org/wiki/display/AST/Code+Review]? Given the complexity of this one - and the fact that it involves a new flag on the {{sip_pvt}} - it feels like this needs some more eyes on it. By: Jeremiah Gowdy (jgowdy) 2014-11-05 17:03:53.991-0600 I agree, I'm stuck dealing with my product release deadline at the moment, but I'll get it submitted and also take a deeper look at it myself as soon as I can. Thanks. By: Matt Jordan (mjordan) 2015-01-19 20:10:52.161-0600 [~jgowdy]: Any chance you'd like to put this up for review? It is a new year... :-) By: Jeremiah Gowdy (jgowdy) 2015-01-20 12:05:10.117-0600 Yeah, let me make sure what's posted here matches what we put into production. By: Matt Jordan (mjordan) 2015-02-08 21:06:53.278-0600 [~jgowdy]: Thanks for fixing this issue - it was certainly a very tricky part of {{chan_sip}}! |