[Home]

Summary:ASTERISK-17259: asterisk does not respond with ACK on retransmission of 200 OK after it sent ACK
Reporter:Richard Revels (rrevels)Labels:
Date Opened:2011-01-17 09:31:54.000-0600Date Closed:2011-06-22 16:14:04
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Channels/chan_sip/General
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) ast18633_retrans200_test.xml
Description:Upstream blocking causes the first ACK to be dropped before hitting destination.  Retransmitted 200s show up in network trace on Asterisk server but no ACK response is ever generated
Comments:By: Leif Madsen (lmadsen) 2011-01-18 09:39:13.000-0600

Per the bug guidelines, you need to provide a SIP trace from the Asterisk console along with SIP history enabled. Additionally, you should provide the devices in use, the topology, call flow, and dialplan in use in order to reproduce the issue.
By: Leif Madsen (lmadsen) 2011-02-07 14:18:27.000-0600

No response from reporter. Please reopen when you can provide the required information. Thanks!
By: Richard Revels (rrevels) 2011-02-11 16:00:56.000-0600

Here is a trace off the network.  I'll get one from the asterisk console some time next week.

54315  79.405282 12.x.x.x -> 71.x.x.x SIP/SDP Request: INVITE sip:+19286809743@71.x.x.x, with session description
54337  79.433605 71.x.x.x -> 12.x.x.x SIP Status: 100 Giving a try
55598  80.940023 71.x.x.x -> 12.x.x.x SIP/SDP Status: 180 Ringing, with session description
67894  97.760896 71.x.x.x -> 12.x.x.x SIP/SDP Status: 200 OK, with session description
67895  97.761117 12.x.x.x -> 71.x.x.x SIP Request: ACK sip:+19286809743@71.x.x.x:9060;transport=udp
68272  98.271138 71.x.x.x -> 12.x.x.x SIP/SDP Status: 200 OK, with session description
69011  99.271627 71.x.x.x -> 12.x.x.x SIP/SDP Status: 200 OK, with session description
70513 101.334141 71.x.x.x -> 12.x.x.x SIP/SDP Status: 200 OK, with session description

The calls are initiated via voice T-1 connected to the asterisk server.  The call is then forwarded to the VoIP Provider via SIP.  The asterisk server is on a data T-1.  In the trace above, the asterisk server is the 12.x.x.x IP and the provider is the 71.x.x.x IP.

The dialplan is pretty simple.  

exten => _1X.,1,NoOp(!-- LOGGING - Outbound Call To ${EXTEN} - ${STRFTIME(${EPOCH},GMT-5,%F %T)} --!)
exten => _1X.,n,Set(CALLERID(name)=${siteCNAM})
exten => _1X.,n,Set(CALLERID(num)=${siteCNUM})
exten => _1X.,n,Set(CALLERID(ani)=${siteCNUM})
exten => _1X.,n,Dial(SIP/+${EXTEN}@to-provider,,rM(checkSIPid^${CHANNEL}))
exten => _1X.,n,Goto(result-${DIALSTATUS},${EXTEN},1)
By: Richard Revels (rrevels) 2011-02-14 15:31:07.000-0600

Here is the console trace



   -- Starting simple switch on 'DAHDI/13-1'
   -- Executing [9197023718@outbound:1] NoOp("DAHDI/13-1", "!-- LOGGING - Outbound Call To 9197023718 - 2011-02-15 02:17:20 --!") in new stack
   -- Executing [9197023718@outbound:2] Goto("DAHDI/13-1", "19197023718,1") in new stack
   -- Goto (outbound,19197023718,1)
   -- Executing [19197023718@outbound:1] NoOp("DAHDI/13-1", "!-- LOGGING - Outbound Call To 19197023718 - 2011-02-15 02:17:20 --!") in new stack
   -- Executing [19197023718@outbound:2] Set("DAHDI/13-1", "CALLERID(name)=JOE") in new stack
   -- Executing [19197023718@outbound:3] Set("DAHDI/13-1", "CALLERID(num)=9194397461") in new stack
   -- Executing [19197023718@outbound:4] Set("DAHDI/13-1", "CALLERID(ani)=9194397461") in new stack
   -- Executing [19197023718@outbound:5] Dial("DAHDI/13-1", "SIP/+19197023718@to-provider,,r") in new stack
 == Using SIP RTP CoS mark 5
Audio is at 208.44.174.45 port 12028
Adding codec 0x4 (ulaw) to SDP
Adding codec 0x400 (ilbc) to SDP
Adding non-codec 0x1 (telephone-event) to SDP
Reliably Transmitting (no NAT) to 216.27.87.216:5060:
INVITE sip:+19197023718@216.27.87.216 SIP/2.0
Via: SIP/2.0/UDP 208.44.174.45:5060;branch=z9hG4bK56604b66;rport
Max-Forwards: 70
From: "JOE" <sip:9194397461@208.44.174.45>;tag=as10f5522b
To: <sip:+19197023718@216.27.87.216>
Contact: <sip:9194397461@208.44.174.45>
Call-ID: 70580fae265510cb21ccfd2430e8ed5b@208.44.174.45
CSeq: 102 INVITE
User-Agent: providerVoice
Remote-Party-ID: "JOE" <sip:9194397461@208.44.174.45>;privacy=off;screen=no
Date: Mon, 14 Feb 2011 21:17:20 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 283

v=0
o=root 1358067439 1358067439 IN IP4 208.44.174.45
s=Asterisk PBX 1.6.2.9
c=IN IP4 208.44.174.45
t=0 0
m=audio 12028 RTP/AVP 0 97 101
a=rtpmap:0 PCMU/8000
a=rtpmap:97 iLBC/8000
a=fmtp:97 mode=30
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

---
   -- Called +19197023718@to-provider

<--- SIP read from UDP:216.27.87.216:5060 --->
SIP/2.0 100 Giving a try
Via: SIP/2.0/UDP 208.44.174.45:5060;branch=z9hG4bK56604b66;rport=5060
From: "JOE" <sip:9194397461@208.44.174.45>;tag=as10f5522b
To: <sip:+19197023718@216.27.87.216>
Call-ID: 70580fae265510cb21ccfd2430e8ed5b@208.44.174.45
CSeq: 102 INVITE
Server: provider.com PROXY (core2.test.14)
Content-Length: 0


<------------->
--- (8 headers 0 lines) ---

<--- SIP read from UDP:216.27.87.216:5060 --->
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 208.44.174.45:5060;received=208.44.174.45;branch=z9hG4bK56604b66;rport=5060
Record-Route: <sip:216.27.87.216;lr;ftag=as10f5522b>
From: "JOE" <sip:9194397461@208.44.174.45>;tag=as10f5522b
To: <sip:+19197023718@216.27.87.216>;tag=_2462058652-1042412449
Call-ID: 70580fae265510cb21ccfd2430e8ed5b@208.44.174.45
CSeq: 102 INVITE
Contact: sip:+19197023718@12.34.5.94:5060
Allow: INVITE,ACK,CANCEL,BYE,INFO,NOTIFY,PRACK,UPDATE,OPTIONS,MESSAGE
Content-Length: 0


<------------->
--- (10 headers 0 lines) ---
   -- SIP/to-provider-0000000d is ringing

<--- SIP read from UDP:216.27.87.216:5060 --->
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 208.44.174.45:5060;received=208.44.174.45;branch=z9hG4bK56604b66;rport=5060
Record-Route: <sip:216.27.87.216;lr;ftag=as10f5522b>
From: "JOE" <sip:9194397461@208.44.174.45>;tag=as10f5522b
To: <sip:+19197023718@216.27.87.216>;tag=_2462058652-1042412449
Call-ID: 70580fae265510cb21ccfd2430e8ed5b@208.44.174.45
CSeq: 102 INVITE
Contact: sip:+19197023718@12.34.5.94:5060
Allow: INVITE,ACK,CANCEL,BYE,INFO,NOTIFY,PRACK,UPDATE,OPTIONS,MESSAGE
Content-Disposition: session; handling=required
Content-Type: application/sdp
Content-Length: 229

v=0
o=305419896 305419896 IN IP4 12.34.5.125
s=-
c=IN IP4 12.34.5.125
t=0 0
m=audio 15632 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=maxptime:40
a=sendrecv

<------------->
--- (12 headers 12 lines) ---
Found RTP audio format 0
Found RTP audio format 101
Found audio description format PCMU for ID 0
Found audio description format telephone-event for ID 101
Capabilities: us - 0x404 (ulaw|ilbc), peer - audio=0x4 (ulaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x4 (ulaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
Peer audio RTP is at port 12.34.5.125:15632
   -- SIP/to-provider-0000000d is making progress passing it to DAHDI/13-1

<--- SIP read from UDP:216.27.87.216:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 208.44.174.45:5060;received=208.44.174.45;branch=z9hG4bK56604b66;rport=5060
Record-Route: <sip:216.27.87.216;lr;ftag=as10f5522b>
From: "JOE" <sip:9194397461@208.44.174.45>;tag=as10f5522b
To: <sip:+19197023718@216.27.87.216>;tag=_2462058652-1042412449
Call-ID: 70580fae265510cb21ccfd2430e8ed5b@208.44.174.45
CSeq: 102 INVITE
Contact: sip:+19197023718@12.34.5.94:5060
Accept: application/sdp
Allow: INVITE,ACK,CANCEL,BYE,INFO,NOTIFY,PRACK,UPDATE,OPTIONS,MESSAGE
Content-Disposition: session; handling=required
Content-Type: application/sdp
Content-Length: 229

v=0
o=305419896 305419896 IN IP4 12.34.5.125
s=-
c=IN IP4 12.34.5.125
t=0 0
m=audio 15632 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=maxptime:40
a=sendrecv

<------------->
--- (13 headers 12 lines) ---
list_route: hop: <sip:216.27.87.216;lr;ftag=as10f5522b>
set_destination: Parsing <sip:216.27.87.216;lr;ftag=as10f5522b> for address/port to send to
set_destination: set destination to 216.27.87.216, port 5060
Transmitting (no NAT) to 216.27.87.216:5060:
ACK sip:+19197023718@12.34.5.94:5060 SIP/2.0
Via: SIP/2.0/UDP 208.44.174.45:5060;branch=z9hG4bK30148e3c;rport
Route: <sip:216.27.87.216;lr;ftag=as10f5522b>
Max-Forwards: 70
From: "JOE" <sip:9194397461@208.44.174.45>;tag=as10f5522b
To: <sip:+19197023718@216.27.87.216>;tag=_2462058652-1042412449
Contact: <sip:9194397461@208.44.174.45>
Call-ID: 70580fae265510cb21ccfd2430e8ed5b@208.44.174.45
CSeq: 102 ACK
User-Agent: providerVoice
Remote-Party-ID: "JOE" <sip:9194397461@208.44.174.45>;privacy=off;screen=no
Content-Length: 0


---
   -- SIP/to-provider-0000000d answered DAHDI/13-1

<--- SIP read from UDP:216.27.87.216:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 208.44.174.45:5060;received=208.44.174.45;branch=z9hG4bK56604b66;rport=5060
Record-Route: <sip:216.27.87.216;lr;ftag=as10f5522b>
From: "JOE" <sip:9194397461@208.44.174.45>;tag=as10f5522b
To: <sip:+19197023718@216.27.87.216>;tag=_2462058652-1042412449
Call-ID: 70580fae265510cb21ccfd2430e8ed5b@208.44.174.45
CSeq: 102 INVITE
Contact: sip:+19197023718@12.34.5.94:5060
Accept: application/sdp
Allow: INVITE,ACK,CANCEL,BYE,INFO,NOTIFY,PRACK,UPDATE,OPTIONS,MESSAGE
Content-Disposition: session; handling=required
Content-Type: application/sdp
Content-Length: 229

v=0
o=305419896 305419896 IN IP4 12.34.5.125
s=-
c=IN IP4 12.34.5.125
t=0 0
m=audio 15632 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=maxptime:40
a=sendrecv

<------------->
--- (13 headers 12 lines) ---

<--- SIP read from UDP:216.27.87.216:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 208.44.174.45:5060;received=208.44.174.45;branch=z9hG4bK56604b66;rport=5060
Record-Route: <sip:216.27.87.216;lr;ftag=as10f5522b>
From: "JOE" <sip:9194397461@208.44.174.45>;tag=as10f5522b
To: <sip:+19197023718@216.27.87.216>;tag=_2462058652-1042412449
Call-ID: 70580fae265510cb21ccfd2430e8ed5b@208.44.174.45
CSeq: 102 INVITE
Contact: sip:+19197023718@12.34.5.94:5060
Accept: application/sdp
Allow: INVITE,ACK,CANCEL,BYE,INFO,NOTIFY,PRACK,UPDATE,OPTIONS,MESSAGE
Content-Disposition: session; handling=required
Content-Type: application/sdp
Content-Length: 229

v=0
o=305419896 305419896 IN IP4 12.34.5.125
s=-
c=IN IP4 12.34.5.125
t=0 0
m=audio 15632 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=maxptime:40
a=sendrecv

<------------->
--- (13 headers 12 lines) ---

<--- SIP read from UDP:216.27.87.216:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 208.44.174.45:5060;received=208.44.174.45;branch=z9hG4bK56604b66;rport=5060
Record-Route: <sip:216.27.87.216;lr;ftag=as10f5522b>
From: "JOE" <sip:9194397461@208.44.174.45>;tag=as10f5522b
To: <sip:+19197023718@216.27.87.216>;tag=_2462058652-1042412449
Call-ID: 70580fae265510cb21ccfd2430e8ed5b@208.44.174.45
CSeq: 102 INVITE
Contact: sip:+19197023718@12.34.5.94:5060
Accept: application/sdp
Allow: INVITE,ACK,CANCEL,BYE,INFO,NOTIFY,PRACK,UPDATE,OPTIONS,MESSAGE
Content-Disposition: session; handling=required
Content-Type: application/sdp
Content-Length: 229

v=0
o=305419896 305419896 IN IP4 12.34.5.125
s=-
c=IN IP4 12.34.5.125
t=0 0
m=audio 15632 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=maxptime:40
a=sendrecv

<------------->
--- (13 headers 12 lines) ---

<--- SIP read from UDP:216.27.87.216:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 208.44.174.45:5060;received=208.44.174.45;branch=z9hG4bK56604b66;rport=5060
Record-Route: <sip:216.27.87.216;lr;ftag=as10f5522b>
From: "JOE" <sip:9194397461@208.44.174.45>;tag=as10f5522b
To: <sip:+19197023718@216.27.87.216>;tag=_2462058652-1042412449
Call-ID: 70580fae265510cb21ccfd2430e8ed5b@208.44.174.45
CSeq: 102 INVITE
Contact: sip:+19197023718@12.34.5.94:5060
Accept: application/sdp
Allow: INVITE,ACK,CANCEL,BYE,INFO,NOTIFY,PRACK,UPDATE,OPTIONS,MESSAGE
Content-Disposition: session; handling=required
Content-Type: application/sdp
Content-Length: 229

v=0
o=305419896 305419896 IN IP4 12.34.5.125
s=-
c=IN IP4 12.34.5.125
t=0 0
m=audio 15632 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=maxptime:40
a=sendrecv

<------------->
--- (13 headers 12 lines) ---

<--- SIP read from UDP:216.27.87.216:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 208.44.174.45:5060;received=208.44.174.45;branch=z9hG4bK56604b66;rport=5060
Record-Route: <sip:216.27.87.216;lr;ftag=as10f5522b>
From: "JOE" <sip:9194397461@208.44.174.45>;tag=as10f5522b
To: <sip:+19197023718@216.27.87.216>;tag=_2462058652-1042412449
Call-ID: 70580fae265510cb21ccfd2430e8ed5b@208.44.174.45
CSeq: 102 INVITE
Contact: sip:+19197023718@12.34.5.94:5060
Accept: application/sdp
Allow: INVITE,ACK,CANCEL,BYE,INFO,NOTIFY,PRACK,UPDATE,OPTIONS,MESSAGE
Content-Disposition: session; handling=required
Content-Type: application/sdp
Content-Length: 229

v=0
o=305419896 305419896 IN IP4 12.34.5.125
s=-
c=IN IP4 12.34.5.125
t=0 0
m=audio 15632 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=maxptime:40
a=sendrecv

<------------->
--- (13 headers 12 lines) ---

<--- SIP read from UDP:216.27.87.216:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 208.44.174.45:5060;received=208.44.174.45;branch=z9hG4bK56604b66;rport=5060
Record-Route: <sip:216.27.87.216;lr;ftag=as10f5522b>
From: "JOE" <sip:9194397461@208.44.174.45>;tag=as10f5522b
To: <sip:+19197023718@216.27.87.216>;tag=_2462058652-1042412449
Call-ID: 70580fae265510cb21ccfd2430e8ed5b@208.44.174.45
CSeq: 102 INVITE
Contact: sip:+19197023718@12.34.5.94:5060
Accept: application/sdp
Allow: INVITE,ACK,CANCEL,BYE,INFO,NOTIFY,PRACK,UPDATE,OPTIONS,MESSAGE
Content-Disposition: session; handling=required
Content-Type: application/sdp
Content-Length: 229

v=0
o=305419896 305419896 IN IP4 12.34.5.125
s=-
c=IN IP4 12.34.5.125
t=0 0
m=audio 15632 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=maxptime:40
a=sendrecv

<------------->
--- (13 headers 12 lines) ---

<--- SIP read from UDP:216.27.87.216:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 208.44.174.45:5060;received=208.44.174.45;branch=z9hG4bK56604b66;rport=5060
Record-Route: <sip:216.27.87.216;lr;ftag=as10f5522b>
From: "JOE" <sip:9194397461@208.44.174.45>;tag=as10f5522b
To: <sip:+19197023718@216.27.87.216>;tag=_2462058652-1042412449
Call-ID: 70580fae265510cb21ccfd2430e8ed5b@208.44.174.45
CSeq: 102 INVITE
Contact: sip:+19197023718@12.34.5.94:5060
Accept: application/sdp
Allow: INVITE,ACK,CANCEL,BYE,INFO,NOTIFY,PRACK,UPDATE,OPTIONS,MESSAGE
Content-Disposition: session; handling=required
Content-Type: application/sdp
Content-Length: 229

v=0
o=305419896 305419896 IN IP4 12.34.5.125
s=-
c=IN IP4 12.34.5.125
t=0 0
m=audio 15632 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=maxptime:40
a=sendrecv

<------------->
--- (13 headers 12 lines) ---

<--- SIP read from UDP:216.27.87.216:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 208.44.174.45:5060;received=208.44.174.45;branch=z9hG4bK56604b66;rport=5060
Record-Route: <sip:216.27.87.216;lr;ftag=as10f5522b>
From: "JOE" <sip:9194397461@208.44.174.45>;tag=as10f5522b
To: <sip:+19197023718@216.27.87.216>;tag=_2462058652-1042412449
Call-ID: 70580fae265510cb21ccfd2430e8ed5b@208.44.174.45
CSeq: 102 INVITE
Contact: sip:+19197023718@12.34.5.94:5060
Accept: application/sdp
Allow: INVITE,ACK,CANCEL,BYE,INFO,NOTIFY,PRACK,UPDATE,OPTIONS,MESSAGE
Content-Disposition: session; handling=required
Content-Type: application/sdp
Content-Length: 229

v=0
o=305419896 305419896 IN IP4 12.34.5.125
s=-
c=IN IP4 12.34.5.125
t=0 0
m=audio 15632 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=maxptime:40
a=sendrecv

<------------->
--- (13 headers 12 lines) ---

<--- SIP read from UDP:216.27.87.216:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 208.44.174.45:5060;received=208.44.174.45;branch=z9hG4bK56604b66;rport=5060
Record-Route: <sip:216.27.87.216;lr;ftag=as10f5522b>
From: "JOE" <sip:9194397461@208.44.174.45>;tag=as10f5522b
To: <sip:+19197023718@216.27.87.216>;tag=_2462058652-1042412449
Call-ID: 70580fae265510cb21ccfd2430e8ed5b@208.44.174.45
CSeq: 102 INVITE
Contact: sip:+19197023718@12.34.5.94:5060
Accept: application/sdp
Allow: INVITE,ACK,CANCEL,BYE,INFO,NOTIFY,PRACK,UPDATE,OPTIONS,MESSAGE
Content-Disposition: session; handling=required
Content-Type: application/sdp
Content-Length: 229

v=0
o=305419896 305419896 IN IP4 12.34.5.125
s=-
c=IN IP4 12.34.5.125
t=0 0
m=audio 15632 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=maxptime:40
a=sendrecv

<------------->
--- (13 headers 12 lines) ---

<--- SIP read from UDP:216.27.87.216:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 208.44.174.45:5060;received=208.44.174.45;branch=z9hG4bK56604b66;rport=5060
Record-Route: <sip:216.27.87.216;lr;ftag=as10f5522b>
From: "JOE" <sip:9194397461@208.44.174.45>;tag=as10f5522b
To: <sip:+19197023718@216.27.87.216>;tag=_2462058652-1042412449
Call-ID: 70580fae265510cb21ccfd2430e8ed5b@208.44.174.45
CSeq: 102 INVITE
Contact: sip:+19197023718@12.34.5.94:5060
Accept: application/sdp
Allow: INVITE,ACK,CANCEL,BYE,INFO,NOTIFY,PRACK,UPDATE,OPTIONS,MESSAGE
Content-Disposition: session; handling=required
Content-Type: application/sdp
Content-Length: 229

v=0
o=305419896 305419896 IN IP4 12.34.5.125
s=-
c=IN IP4 12.34.5.125
t=0 0
m=audio 15632 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=maxptime:40
a=sendrecv

<------------->
--- (13 headers 12 lines) ---

<--- SIP read from UDP:216.27.87.216:5060 --->
BYE sip:9194397461@208.44.174.45 SIP/2.0
Record-Route: <sip:216.27.87.216;lr;ftag=_2462058652-1042412449>
Via: SIP/2.0/UDP 216.27.87.216;branch=z9hG4bK0254.1ef20de2.0
Via: SIP/2.0/UDP 12.34.5.94:5060;branch=z9hG4bK2505960949-1995043798
Max-Forwards: 69
From: <sip:+19197023718@216.27.87.216>;tag=_2462058652-1042412449
To: "JOE" <sip:9194397461@208.44.174.45>;tag=as10f5522b
Call-ID: 70580fae265510cb21ccfd2430e8ed5b@208.44.174.45
CSeq: 103 BYE
Content-Length: 0


<------------->
--- (10 headers 0 lines) ---
Sending to 216.27.87.216 : 5060 (no NAT)

<--- Transmitting (no NAT) to 216.27.87.216:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 216.27.87.216;branch=z9hG4bK0254.1ef20de2.0;received=216.27.87.216
Via: SIP/2.0/UDP 12.34.5.94:5060;branch=z9hG4bK2505960949-1995043798
Record-Route: <sip:216.27.87.216;lr;ftag=_2462058652-1042412449>
From: <sip:+19197023718@216.27.87.216>;tag=_2462058652-1042412449
To: "JOE" <sip:9194397461@208.44.174.45>;tag=as10f5522b
Call-ID: 70580fae265510cb21ccfd2430e8ed5b@208.44.174.45
CSeq: 103 BYE
Server: providerVoice
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0


<------------>
   -- Executing [h@outbound:1] NoOp("DAHDI/13-1", "") in new stack
   -- Executing [h@outbound:2] Set("DAHDI/13-1", "CDR(userfield)=") in new stack
   -- Executing [h@outbound:3] NoOp("DAHDI/13-1", "Captured SIP callid header in cdr-userfield") in new stack
 == Spawn extension (outbound, 19197023718, 5) exited non-zero on 'DAHDI/13-1'
   -- Hungup 'DAHDI/13-1'
Really destroying SIP dialog '70580fae265510cb21ccfd2430e8ed5b@208.44.174.45' Method: BYE
By: Richard Revels (rrevels) 2011-02-14 16:27:11.000-0600

This problem does not exist in version 1.8.2.3.
By: Richard Revels (rrevels) 2011-02-15 13:24:54.000-0600

This problem does exist in version 1.6.2.16.1
By: Paul Belanger (pabelanger) 2011-02-15 13:55:25.000-0600

Please upload a debug log, not post it as a note.
--
We require a complete debug log to help triage the issue.

This document will provide instructions on how to collect debugging logs from an Asterisk machine for the purpose of helping bug marshals troubleshoot an issue:

https://wiki.asterisk.org/wiki/display/AST/Collecting+Debug+Information
By: Leif Madsen (lmadsen) 2011-02-16 15:50:33.000-0600

rrevels: OK, so you have told us what version this isn't a problem on, but have not told us what version this *is* a problem on. You've marked this as an older version of 1.6.2, and said more recent versions do not exhibit this problem.

Additionally I do see Asterisk respond to the 200 OK with an ACK in your message:



<--- SIP read from UDP:216.27.87.216:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 208.44.174.45:5060;received=208.44.174.45;branch=z9hG4bK56604b66;rport=5060
Record-Route: <sip:216.27.87.216;lr;ftag=as10f5522b>
From: "JOE" <sip:9194397461@208.44.174.45>;tag=as10f5522b
To: <sip:+19197023718@216.27.87.216>;tag=_2462058652-1042412449
Call-ID: 70580fae265510cb21ccfd2430e8ed5b@208.44.174.45
CSeq: 102 INVITE
Contact: sip:+19197023718@12.34.5.94:5060
Accept: application/sdp
Allow: INVITE,ACK,CANCEL,BYE,INFO,NOTIFY,PRACK,UPDATE,OPTIONS,MESSAGE
Content-Disposition: session; handling=required
Content-Type: application/sdp
Content-Length: 229

v=0
o=305419896 305419896 IN IP4 12.34.5.125
s=-
c=IN IP4 12.34.5.125
t=0 0
m=audio 15632 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=maxptime:40
a=sendrecv

<------------->
--- (13 headers 12 lines) ---
list_route: hop: <sip:216.27.87.216;lr;ftag=as10f5522b>
set_destination: Parsing <sip:216.27.87.216;lr;ftag=as10f5522b> for address/port to send to
set_destination: set destination to 216.27.87.216, port 5060
Transmitting (no NAT) to 216.27.87.216:5060:
ACK sip:+19197023718@12.34.5.94:5060 SIP/2.0
Via: SIP/2.0/UDP 208.44.174.45:5060;branch=z9hG4bK30148e3c;rport
Route: <sip:216.27.87.216;lr;ftag=as10f5522b>
Max-Forwards: 70
From: "JOE" <sip:9194397461@208.44.174.45>;tag=as10f5522b
To: <sip:+19197023718@216.27.87.216>;tag=_2462058652-1042412449
Contact: <sip:9194397461@208.44.174.45>
Call-ID: 70580fae265510cb21ccfd2430e8ed5b@208.44.174.45
CSeq: 102 ACK
User-Agent: providerVoice
Remote-Party-ID: "JOE" <sip:9194397461@208.44.174.45>;privacy=off;screen=no
Content-Length: 0




To me this looks like either Asterisk isn't sending the response to the right spot, or that the other end is behind NAT or something. NAT is typically when I see this type of behaviour.
By: Richard Revels (rrevels) 2011-02-16 20:07:38.000-0600

I have tried revision 1.6.2.9 and 1.6.2.16.1 and both have the problem. I did not have the problem when jumping up to the 1.8 branch but there were too many other config changes needed to make that worth doing for my production servers right now.

I found that I could resolve the problem by forcing a send ack at the bottom of __sip_ack when the function was called with a response to an INVITE and no transaction was matched in the function.

I don't have anything behind NAT upstream.  The first 200 does indeed get a proper ACK and if that makes it all the way through the network the call sets up fine. The problem only occurs when the 200 has to be retransmitted due to the first ACK getting lost. The retransmitted 200s don't get ACKed.
By: Walter Doekes (wdoekes) 2011-02-17 07:48:50.000-0600

Leif: see my sipp scenario file. If you call to the sip-tester from a Linksys phone it will happily create a nice ACK/200-loop, like the scenario prescribes. If you call from asterisk (at least 1.6.2.16.1) asterisk refuses to reply to the 2nd 200 even though it should.

http://tools.ietf.org/html/rfc3261#section-13.2.2.4
  The UAC core MUST generate an ACK request for each 2xx received from
  the transaction layer.
By: Leif Madsen (lmadsen) 2011-02-18 14:24:22.000-0600

Odd.... ok importing.
By: Alan Graham (zerohalo) 2011-02-21 14:47:46.000-0600

check out this patch that has been sitting on the reviewboard for quite a while (and which works for me): https://reviewboard.asterisk.org/r/692/diff/
By: John Covert (jcovert) 2011-04-29 17:24:40

This problem exists in 1.6.2.17.  Please see the uploaded trace.txt.  Cisco Call Manager doesn't see our ACK due to packet loss and times out re-sending OK, since we never respond.

One of my clients (who thought 1.6.2.17 was the latest version and installed it) connected a new VPN to a new remote site and was having about 1% of their calls drop after about 20 seconds.  A ping test shows 1% packet loss.

The patch above looks like it would solve it.  My client will allow me to install the patch after operations stop late tonight, and I will confirm tomorrow.  The patch is also not in 1.6.2.18, but appears to be in most 1.8.x versions.
By: Russell Bryant (russell) 2011-06-22 16:14:04.367-0500

The referenced patch from reviewboard has been committed so I am assuming this has been fixed.  Feel free to reopen if that is not the case.