[asterisk-bugs] [JIRA] (ASTERISK-23313) ACK sent to wrong destination in CANCEL dialog
Matt Jordan (JIRA)
noreply at issues.asterisk.org
Fri Feb 14 16:15:03 CST 2014
[ https://issues.asterisk.org/jira/browse/ASTERISK-23313?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=215270#comment-215270 ]
Matt Jordan commented on ASTERISK-23313:
----------------------------------------
Based on the logs, I don't see the bug you've described. Asterisk appears to be doing the correct thing:
# We transmit the INVITE request to 64.2.142.93:5060:
{noformat}
[2014-02-14 13:05:43] VERBOSE[15926][C-000000f4] chan_sip.c: Reliably Transmitting (no NAT) to 64.2.142.93:5060:
�INVITE sip:12032649261 at 64.2.142.93 SIP/2.0
�Via: SIP/2.0/UDP 108.244.232.196:5060;branch=z9hG4bK0deea205
�Max-Forwards: 70
�From: "BORRELLINET IT L1" <sip:8609150274 at 108.244.232.196>;tag=as7cabff0c
�To: <sip:12032649261 at 64.2.142.93>
�Contact: <sip:8609150274 at 108.244.232.196:5060>
�Call-ID: 461c637f587aa81f64b6316c73e221fe at 108.244.232.196:5060
�CSeq: 102 INVITE
�User-Agent: FPBX-2.11.0(11.7.0)
�Date: Fri, 14 Feb 2014 18:05:43 GMT
�Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
�Supported: replaces, timer
�Remote-Party-ID: "BORRELLINET IT L1" <sip:8609150274 at 108.244.232.196>;party=calling;privacy=off;screen=no
�Content-Type: application/sdp
�Content-Length: 241
�
�v=0
�o=root 1068114121 1068114121 IN IP4 108.244.232.196
�s=Asterisk PBX 11.7.0
�c=IN IP4 108.244.232.196
�t=0 0
�m=audio 11836 RTP/AVP 0 101
�a=rtpmap:0 PCMU/8000
�a=rtpmap:101 telephone-event/8000
�a=fmtp:101 0-16
�a=ptime:20
�a=sendrecv
�
�---
{noformat}
# When the INVITE request is cancelled due to the inbound channel terminating the dial attempt, we transmit the CANCEL request to 64.2.142.93:
{noformat}
[2014-02-14 13:05:58] VERBOSE[15926][C-000000f4] chan_sip.c: Reliably Transmitting (no NAT) to 64.2.142.93:5060:
�CANCEL sip:12032649261 at 64.2.142.93 SIP/2.0
�Via: SIP/2.0/UDP 108.244.232.196:5060;branch=z9hG4bK0deea205
�Max-Forwards: 70
�From: "BORRELLINET IT L1" <sip:8609150274 at 108.244.232.196>;tag=as7cabff0c
�To: <sip:12032649261 at 64.2.142.93>
�Call-ID: 461c637f587aa81f64b6316c73e221fe at 108.244.232.196:5060
�CSeq: 102 CANCEL
�User-Agent: FPBX-2.11.0(11.7.0)
�Content-Length: 0
{noformat}
# We read back from 64.2.142.93:5060 a 200 OK to our CANCEL request:
{noformat}
�<--- SIP read from UDP:64.2.142.93:5060 --->
�SIP/2.0 200 canceling
�Via: SIP/2.0/UDP 108.244.232.196:5060;branch=z9hG4bK0deea205;rport=5060
�From: "BORRELLINET IT L1" <sip:8609150274 at 108.244.232.196>;tag=as7cabff0c
�To: <sip:12032649261 at 64.2.142.93>;tag=d8ec4bef69e0ea2b5541b4b24b7b56ef-9b77
�Call-ID: 461c637f587aa81f64b6316c73e221fe at 108.244.232.196:5060
�CSeq: 102 CANCEL
�Server: OpenSIPS (1.6.4-2-notls (x86_64/linux))
�Content-Length: 0
{noformat}
# We then read a 487 for the INVITE request:
{noformat}
�<--- SIP read from UDP:64.2.142.93:5060 --->
�SIP/2.0 487 Request Terminated
�Via: SIP/2.0/UDP 108.244.232.196:5060;rport=5060;received=108.244.232.196;branch=z9hG4bK0deea205
�From: "BORRELLINET IT L1" <sip:8609150274 at 108.244.232.196>;tag=as7cabff0c
�To: <sip:12032649261 at 64.2.142.93>;tag=as10ab2210
�Call-ID: 461c637f587aa81f64b6316c73e221fe at 108.244.232.196:5060
�CSeq: 102 INVITE
�User-Agent: packetrino
�Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
�Supported: replaces
�Content-Length: 0
�
�<------------->
{noformat}
# We then correctly send the ACK to the INVITE request's 487 response to 64.2.142.93:5060:
{noformat}
[2014-02-14 13:05:58] VERBOSE[2013][C-000000f4] chan_sip.c: Transmitting (no NAT) to 64.2.142.93:5060:
�ACK sip:12032649261 at 66.241.96.140 SIP/2.0
�Via: SIP/2.0/UDP 108.244.232.196:5060;branch=z9hG4bK0deea205
�Max-Forwards: 70
�From: "BORRELLINET IT L1" <sip:8609150274 at 108.244.232.196>;tag=as7cabff0c
�To: <sip:12032649261 at 64.2.142.93>;tag=as10ab2210
�Contact: <sip:8609150274 at 108.244.232.196:5060>
�Call-ID: 461c637f587aa81f64b6316c73e221fe at 108.244.232.196:5060
�CSeq: 102 ACK
�User-Agent: FPBX-2.11.0(11.7.0)
�Content-Length: 0
�
�
�---
{noformat}
Based on your bug description, I would expect that the ACK sent to the 487 response would have been sent to a different address than the INVITE request that resulted in the 487 response; however, the log file does not show that.
> ACK sent to wrong destination in CANCEL dialog
> ----------------------------------------------
>
> Key: ASTERISK-23313
> URL: https://issues.asterisk.org/jira/browse/ASTERISK-23313
> Project: Asterisk
> Issue Type: Bug
> Security Level: None
> Components: Channels/chan_sip/General
> Affects Versions: 11.7.0
> Environment: FreePBX 2.11.0.23, CentOS 6.5 (2.6.32-431.el6.i686), Asterisk 11.7.0
> Reporter: Gregory J Borrelli
> Severity: Critical
> Attachments: ack_issue.pcap, asterisk_debug_log.txt, sip_only.txt
>
>
> I've run into an issue that appears to be a bug within Asterisk. The issue surfaces when interfacing with a SIP trunk provider that uses different servers for SIP/signaling and RTP/media. I've tested against two different providers that have this type of setup and was able to consistently reproduce the problem every time.
> The issue occurs when an extension on the Asterisk box makes an external call and then hangs up during the ring phase (originator cancel). All goes as expected until the very last exchange... Provider's proxy sends "487 Request Terminated" to Asterisk. It appears that Asterisk knows it’s supposed to send the ACK back to the proxy, and from a network routing perspective the packet does get sent there, but when actually constructing the ACK statement in the SIP dialog it uses the wrong IP (the IP of the provider's media server rather than the proxy server).
> As per RFC 3261, Section 17.1.1.2:
> "...reception of a response with status code from 300-699 MUST cause the client transaction to transition to "Completed." ... and the client transaction must generate an ACK request ... The ACK MUST be sent to the same address, port, and transport to which the original request was sent."
> So it appears that asterisk is not following protocol here.
> I've pasted the relevant parts of the SIP dialog and asterisk logs below for quick reference and will attach the full files as well. Let me know if any additional information is needed.
> SIP DIALOG:
> {noformat}
> SIP/2.0 487 Request Terminated
> Via: SIP/2.0/UDP 108.244.232.196:5060;rport=5060;received=108.244.232.196;branch=z9hG4bK0deea205
> From: "BORRELLINET IT L1" <sip:8609150274 at 108.244.232.196>;tag=as7cabff0c
> To: <sip:12032649261 at 64.2.142.93>;tag=as10ab2210
> Call-ID: 461c637f587aa81f64b6316c73e221fe at 108.244.232.196:5060
> CSeq: 102 INVITE
> User-Agent: packetrino
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
> Supported: replaces
> Content-Length: 0
> ACK sip:12032649261 at 66.241.96.140 SIP/2.0
> Via: SIP/2.0/UDP 108.244.232.196:5060;branch=z9hG4bK0deea205
> Max-Forwards: 70
> From: "BORRELLINET IT L1" <sip:8609150274 at 108.244.232.196>;tag=as7cabff0c
> To: <sip:12032649261 at 64.2.142.93>;tag=as10ab2210
> Contact: <sip:8609150274 at 108.244.232.196:5060>
> Call-ID: 461c637f587aa81f64b6316c73e221fe at 108.244.232.196:5060
> CSeq: 102 ACK
> User-Agent: FPBX-2.11.0(11.7.0)
> Content-Length: 0
> {noformat}
> ASTERISK DEBUG LOG:
> {noformat}
> [2014-02-14 13:05:58] DEBUG[2013] chan_sip.c: Header 0 [ 30]: SIP/2.0 487 Request Terminated
> [2014-02-14 13:05:58] DEBUG[2013] chan_sip.c: Header 1 [ 96]: Via: SIP/2.0/UDP 108.244.232.196:5060;rport=5060;received=108.244.232.196;branch=z9hG4bK0deea205
> [2014-02-14 13:05:58] DEBUG[2013] chan_sip.c: Header 2 [ 73]: From: "BORRELLINET IT L1" <sip:8609150274 at 108.244.232.196>;tag=as7cabff0c
> [2014-02-14 13:05:58] DEBUG[2013] chan_sip.c: Header 3 [ 48]: To: <sip:12032649261 at 64.2.142.93>;tag=as10ab2210
> [2014-02-14 13:05:58] DEBUG[2013] chan_sip.c: Header 4 [ 62]: Call-ID: 461c637f587aa81f64b6316c73e221fe at 108.244.232.196:5060
> [2014-02-14 13:05:58] DEBUG[2013] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE
> [2014-02-14 13:05:58] DEBUG[2013] chan_sip.c: Header 6 [ 22]: User-Agent: packetrino
> [2014-02-14 13:05:58] DEBUG[2013] chan_sip.c: Header 7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
> [2014-02-14 13:05:58] DEBUG[2013] chan_sip.c: Header 8 [ 19]: Supported: replaces
> [2014-02-14 13:05:58] DEBUG[2013] chan_sip.c: Header 9 [ 17]: Content-Length: 0
> [2014-02-14 13:05:58] VERBOSE[2013] chan_sip.c: --- (10 headers 0 lines) ---
> [2014-02-14 13:05:58] DEBUG[2013] chan_sip.c: = Looking for Call ID: 461c637f587aa81f64b6316c73e221fe at 108.244.232.196:5060 (Checking To) --From tag as7cabff0c --To-tag as10ab2210
> [2014-02-14 13:05:58] DEBUG[2013][C-000000f4] chan_sip.c: Stopping retransmission on '461c637f587aa81f64b6316c73e221fe at 108.244.232.196:5060' of Request 102: Match Found
> [2014-02-14 13:05:58] DEBUG[2013][C-000000f4] chan_sip.c: SIP response 487 to standard invite
> [2014-02-14 13:05:58] VERBOSE[2013][C-000000f4] chan_sip.c: Transmitting (no NAT) to 64.2.142.93:5060:
> ÿACK sip:12032649261 at 66.241.96.140 SIP/2.0
> ÿVia: SIP/2.0/UDP 108.244.232.196:5060;branch=z9hG4bK0deea205
> ÿMax-Forwards: 70
> ÿFrom: "BORRELLINET IT L1" <sip:8609150274 at 108.244.232.196>;tag=as7cabff0c
> ÿTo: <sip:12032649261 at 64.2.142.93>;tag=as10ab2210
> ÿContact: <sip:8609150274 at 108.244.232.196:5060>
> ÿCall-ID: 461c637f587aa81f64b6316c73e221fe at 108.244.232.196:5060
> ÿCSeq: 102 ACK
> ÿUser-Agent: FPBX-2.11.0(11.7.0)
> ÿContent-Length: 0
> ÿ
> ÿ
> ÿ---
> [2014-02-14 13:05:58] DEBUG[2013][C-000000f4] chan_sip.c: Trying to put 'ACK sip:120' onto UDP socket destined for 64.2.142.93:5060
> [2014-02-14 13:05:58] DEBUG[2013][C-000000f4] chan_sip.c: Updating call counter for outgoing call
> [2014-02-14 13:05:58] VERBOSE[2013][C-000000f4] chan_sip.c: Scheduling destruction of SIP dialog '461c637f587aa81f64b6316c73e221fe at 108.244.232.196:5060' in 6400 ms (Method: INVITE)
> {noformat}
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.asterisk.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira
More information about the asterisk-bugs
mailing list