[Home]

Summary:ASTERISK-07273: ACK from asterisk still wrong
Reporter:chr (chr)Labels:
Date Opened:2006-07-02 08:59:11Date Closed:2006-07-05 02:13:46
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Channels/chan_sip/Interoperability
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:The Bug 2687 is still present in asterisk.

As no record route headers are present in the ACK despite being present in the "OK", transaction matching fails and the openSER server that is the next hop can not forward the ACK statefully.

<-- SIP read from XXX.XXX.XXX.10:5060:
SIP/2.0 200 OK
ms-asserted-verification-level: ms-source-verified-user=verified
Contact: <sip:someuser@somedomain.org:1253;maddr=XXX.XXX.XXX.35;transport=tls;ms-received-cid=50600>
Via: SIP/2.0/UDP XXX.XXX.XXX.10:5080;branch=z9hG4bK0d027cce;rport=5080
From: "10" <sip:10@ap54gs.somedomain.org>;tag=as4e8e9c1b
To: <sip:someuser@somedomain.org>;epid=be63ef65fc;tag=603399bb6a
Call-ID: 11bb9bdb7f2afc791f2281aa0ffa1ba3@ap54gs.somedomain.org
CSeq: 102 INVITE
Record-Route: <sip:tvpool.somedomain.org:5061;transport=tls;ms-fe=FAST.somedomain.org;lr>
Record-Route: <sip:tv.someotherdomaim.com:5061;transport=tls;epid=be63ef65fc;lr;ms-key-info=GAEAATmzWLRgxVpv153GAQECAAADZgAAAKQAAMYSXAfcn9T9h5zq2qUe1CVoSuTLO_cmRNOM2eYLi39qSrfziuac8Fd0ypgP9tA8fxvgp7IEQQxJk3hxoqwgIOy_wIyDLAKDP8lnFxldj2MsXP3JFFKASliyCnhQMPiZygssPT94didGacPW_EBwo5WOzRU7HN7wcsxmzVSzbSTu2Seh8AMtbOv8ebY2za9FZSJI27vSRp3ih8EeRfWVzktd-PgRxuB2KRqSchaHTPo_aM8Ul2sEReED_m1tGWixl7esXJSe9a_OVCSRavCVJHs5dJ1OFgVnvbFUlbSX2RpzDNehxhahYnitdebAbyMw_IlK9dIrtWor6-0lCSp8jaqvY6heSLlJ4W0HgyayTGW4vG2i6C9qWVPktMTaZkXAc5T5X_45yaZ1lyLJeDQWaXMeHqsdMkTGsnzqwZQ5dKwnKawf7utOi5duI9aIsoB7atYfLJ5uI0sD8lx3clPObFsaa19ONCWAeJ0svQt5ht1XXwZD05b4lxluhbBjK7Bc0m36dRHK3jqWFrYQlqeYnjKm-T89LqmkziCXRLdXY0rfuki_4z8->
Record-Route: <sip:XXX.XXX.XXX.10:5061;transport=tls;r2=on;ftag=as4e8e9c1b;lr>
Record-Route: <sip:XXX.XXX.XXX.10;r2=on;ftag=as4e8e9c1b;lr>
User-Agent: LCC/1.3
Content-Type: application/sdp
Content-Length: 213

v=0
o=- 0 0 IN IP4 XXX.XXX.XXX.35
s=session
c=IN IP4 XXX.XXX.XXX.35
b=CT:1000
t=0 0
m=audio 34546 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16


Transmitting (no NAT) to XXX.XXX.XXX.10:5060:
ACK sip:someuser@somedomain.org:1253;maddr=XXX.XXX.XXX.35;transport=tls;ms-received-cid=50600 SIP/2.0
Via: SIP/2.0/UDP XXX.XXX.XXX.10:5080;branch=z9hG4bK2ad6e73f;rport
Route: <sip:XXX.XXX.XXX.10;r2=on;ftag=as4e8e9c1b;lr>,<sip:XXX.XXX.XXX.10:5061;transport=tls;r2=on;ftag=as4e8e9c1b;lr>
From: "10" <sip:10@ap54gs.somedomain.org>;tag=as4e8e9c1b
To: <sip:someuser@somedomain.org>;tag=603399bb6a
Contact: <sip:10@XXX.XXX.XXX.10:5080>
Call-ID: 11bb9bdb7f2afc791f2281aa0ffa1ba3@ap54gs.somedomain.org
CSeq: 102 ACK
User-Agent: asterisk
Max-Forwards: 70
Content-Length: 0
Comments:By: Olle Johansson (oej) 2006-07-02 10:20:32

May I see the full transaction, please? Also, please take a full SIP debug output with verbose set to 4 and debug set to 4. Thanks.

Any advice for a setup to repeat this?
By: chr (chr) 2006-07-02 10:41:16

setup:

MS Communicator UA <-> LCS <-> LCS edge proxy <-> openSER 1.0.0 <-> asterisk

Call originating from asterisk, going to MS Comm UA. openSer complains that it can not match ACK to transaction, ACK is not delivered.


Verbosity is at least 4
Core debug is at least 4
   -- Executing Dial("SIP/10-fbb4", "SIP/10@10&SIP/someuser@ser&SIP/cheb@cheb|60|t") in new stack
   -- Called 10@10
We're at XXX.XXX.XXX.10 port 31022
Video is at XXX.XXX.XXX.10 port 31016
Adding codec 0x8 (alaw) to SDP
Adding codec 0x4 (ulaw) to SDP
Adding non-codec 0x1 (telephone-event) to SDP
13 headers, 11 lines
Reliably Transmitting (no NAT) to XXX.XXX.XXX.10:5060:
INVITE sip:someuser@somedomain.org SIP/2.0
Via: SIP/2.0/UDP XXX.XXX.XXX.10:5080;branch=z9hG4bK08d2055c;rport
From: "10" <sip:10@pp33nn.somedomain.org>;tag=as52cf69cf
To: <sip:someuser@somedomain.org>
Contact: <sip:10@XXX.XXX.XXX.10:5080>
Call-ID: 1efb4cbd4a8f2bcd252f2bf5130de068@pp33nn.somedomain.org
CSeq: 102 INVITE
User-Agent: eyeBeam release 3004w stamp 16863
Max-Forwards: 70
Date: Sun, 02 Jul 2006 15:35:39 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Content-Type: application/sdp
Content-Length: 236

v=0
o=root 664 664 IN IP4 XXX.XXX.XXX.10
s=session
c=IN IP4 XXX.XXX.XXX.10
t=0 0
m=audio 31022 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -

---
   -- Called someuser@ser
Jul  2 17:35:39 NOTICE[664]: app_dial.c:1029 dial_exec_full: Unable to create channel of type 'SIP' (cause 3 - No route to destination)

<-- SIP read from XXX.XXX.XXX.10:5060:
SIP/2.0 100 Trying
ms-asserted-verification-level: ms-source-verified-user=verified
Via: SIP/2.0/UDP XXX.XXX.XXX.10:5080;branch=z9hG4bK08d2055c;rport=5080
From: "10" <sip:10@pp33nn.somedomain.org>;tag=as52cf69cf
To: <sip:someuser@somedomain.org>
Call-ID: 1efb4cbd4a8f2bcd252f2bf5130de068@pp33nn.somedomain.org
CSeq: 102 INVITE
Content-Length: 0


--- (8 headers 0 lines)---
pp33nn*CLI>
<-- SIP read from XXX.XXX.XXX.10:5060:
SIP/2.0 180 Ringing
ms-asserted-verification-level: ms-source-verified-user=verified
Via: SIP/2.0/UDP XXX.XXX.XXX.10:5080;branch=z9hG4bK08d2055c;rport=5080
From: "10" <sip:10@pp33nn.somedomain.org>;tag=as52cf69cf
To: <sip:someuser@somedomain.org>;epid=be63ef65fc;tag=236e6aedd9
Call-ID: 1efb4cbd4a8f2bcd252f2bf5130de068@pp33nn.somedomain.org
CSeq: 102 INVITE
Record-Route: <sip:XXX.XXX.XXX.10:5061;transport=tls;r2=on;ftag=as52cf69cf;lr>
Record-Route: <sip:XXX.XXX.XXX.10;r2=on;ftag=as52cf69cf;lr>
User-Agent: LCC/1.3
Content-Length: 0


--- (11 headers 0 lines)---
   -- SIP/ser-a73c is ringing
   -- Got SIP response 486 "Busy Here" back from XXX.XXX.XXX.13
   -- SIP/10-73d6 is busy
pp33nn*CLI>
<-- SIP read from XXX.XXX.XXX.10:5060:
SIP/2.0 200 OK
ms-asserted-verification-level: ms-source-verified-user=verified
Contact: <sip:someuser@somedomain.org:2324;maddr=XXX.XXX.XXX.35;transport=tls;ms-received-cid=51300>
Via: SIP/2.0/UDP XXX.XXX.XXX.10:5080;branch=z9hG4bK08d2055c;rport=5080
From: "10" <sip:10@pp33nn.somedomain.org>;tag=as52cf69cf
To: <sip:someuser@somedomain.org>;epid=be63ef65fc;tag=236e6aedd9
Call-ID: 1efb4cbd4a8f2bcd252f2bf5130de068@pp33nn.somedomain.org
CSeq: 102 INVITE
Record-Route: <sip:mvvpool.somedomain.org:5061;transport=tls;ms-fe=someserver.somedomain.org;lr>
Record-Route: <sip:mvv.otherdomain.com:5061;transport=tls;epid=be63ef65fc;lr;ms-key-info=GAEAATmzWLRgxVpv153GAQECAAADZgAAAKQAAMYSXAfcn9T9h5zq2qUe1CVoSuTLO_cmRNOM2eYLi39qSrfziuac8Fd0ypgP9tA8fxvgp7IEQQxJk3hxoqwgIOy_wIyDLAKDP8lnFxldj2MsXP3JFFKASliyCnhQMPiZygssPT94didGacPW_EBwo5WOzRU7HN7wcsxmzVSzbSTu2Seh8AMtbOv8ebY2za9FZSJI27vSRp3ih8EeRfWVzktd-PgRxuB2KRqSchaHTPo_aM8Ul2sEReED_m1tGWixl7esXJSe9a_OVCSRavCVJHs5dJ1OFgVnvbFUlbSX2RpzDNehxhahYnitdebAbyMw_IlK9dIrtWor6-0lCSp8jaqvY6heSLlJ4W0HgyayTGW4vG2i6C9qWVPktMTaZkXAc5T5X_45yaZ1lyLJeDQWaXMeHqsdMkTGsnzqwZQ5dKwnKawf7utOi5duI9aIsoB7atYfLJ5uI0sD8lx3clPObFsaa19ONCWAeJ0svQt5ht1XXwZD05b4lxluhbBjK7Bc0m36dRHK3jqWFrYQlqeYnjKm-T89LqmkziCXRLdXY0rfuki_4z8-Pmv5QduSeVFNx8vckjJOAGaeryCFpbaowwKVH66uTtGhID4H5y6urRthV4wiUKzAGKqRsk2Uhmh99_eWn0Gt1aPfPtyW2Pb7qpK5q1DTCwDmNUz_MFdnPWaG;ms-route-sig=ha9R2QKwTTZDF0RvvbIk8DZQqhQMuO>
Record-Route: <sip:XXX.XXX.XXX.10:5061;transport=tls;r2=on;ftag=as52cf69cf;lr>
Record-Route: <sip:XXX.XXX.XXX.10;r2=on;ftag=as52cf69cf;lr>
User-Agent: LCC/1.3
Content-Type: application/sdp
Content-Length: 213

v=0
o=- 0 0 IN IP4 XXX.XXX.XXX.35
s=session
c=IN IP4 XXX.XXX.XXX.35
b=CT:1000
t=0 0
m=audio 14608 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16

--- (15 headers 11 lines)---
Found RTP audio format 8
Found RTP audio format 0
Found RTP audio format 101
Peer audio RTP is at port XXX.XXX.XXX.35:14608
Peer video RTP is at port XXX.XXX.XXX.35:65535
Found description format PCMA
Found description format PCMU
Found description format telephone-event
Capabilities: us - 0xc (ulaw|alaw), peer - audio=0xc (ulaw|alaw)/video=0x0 (nothing), combined - 0xc (ulaw|alaw)
Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
Transmitting (no NAT) to XXX.XXX.XXX.10:5060:
ACK sip:someuser@somedomain.org:2324;maddr=XXX.XXX.XXX.35;transport=tls;ms-received-cid=51300 SIP/2.0
Via: SIP/2.0/UDP XXX.XXX.XXX.10:5080;branch=z9hG4bK79c83e99;rport
Route: <sip:XXX.XXX.XXX.10;r2=on;ftag=as52cf69cf;lr>,<sip:XXX.XXX.XXX.10:5061;transport=tls;r2=on;ftag=as52cf69cf;lr>
From: "10" <sip:10@pp33nn.somedomain.org>;tag=as52cf69cf
To: <sip:someuser@somedomain.org>;tag=236e6aedd9
Contact: <sip:10@XXX.XXX.XXX.10:5080>
Call-ID: 1efb4cbd4a8f2bcd252f2bf5130de068@pp33nn.somedomain.org
CSeq: 102 ACK
User-Agent: eyeBeam release 3004w stamp 16863
Max-Forwards: 70
Content-Length: 0


---
   -- SIP/ser-a73c answered SIP/10-fbb4
   -- Attempting native bridge of SIP/10-fbb4 and SIP/ser-a73c
By: Olle Johansson (oej) 2006-07-02 11:15:04

You don't want record-route headers in the ack really, but you want the ack's route headers to reflect the ones in the 200 OK, right?
By: chr (chr) 2006-07-02 12:41:26

I am not 100% sure what you mean, but I think yes I want that. ;)
Without the record route headers from the "OK" neither SER nor LCS accept the ACK as valid. The openSER server always replies: Can not match ACK to transaction, forwarding statelessly and if I forward the ACK by explicitly routing it to the LCS server, the LCS server complains because it does not see his RR with the authentication cookie (ms-key-info) that marks the transaction as valid and therfore rejects to forward it.
By: Olle Johansson (oej) 2006-07-02 14:39:52

From your debug we have both record-route headers reflected in the route header and send the packet to the last record-route address... Please help me and say more exactly what's wrong here.
By: chr (chr) 2006-07-02 15:07:48

Both ? The inital request has 4 record route headers, shouldnt all record route headers be included in the route header ?
By: chr (chr) 2006-07-02 16:56:22

Note:
In the full log it says:

User-Agent: eyeBeam release 3004w stamp 16863

but the useragent it asterisk, it is only changed in sip.conf.
By: Olle Johansson (oej) 2006-07-03 09:55:29

Ahh, I see. Please test with latest svn trunk. I expanded the size of the routing table buffer.
By: Olle Johansson (oej) 2006-07-03 09:59:48

Over 900 characters in the routing headers... You might have problems with UDP message size soon....
By: Olle Johansson (oej) 2006-07-03 10:07:08

Committed fix to svn 1.2 - please test. But again, look for warnings that we've exceeded packet size...
By: chr (chr) 2006-07-03 10:29:41

Unfortunately I have only an embedded (WRT54GS with OpenWRT) and a Win32 System at hand and also no build system available, so it is hard for me to test the fix.

Others at www.voip-info.org also have reported this problem (http://www.voip-info.org/wiki/view/MS+LCS+2005+%252F+SER+%252F+Asterisk+Integration), maybe they can jump in and try it out.

I could reduce the message size if there realy was a problem by not routing through the outbound LCS router that attaches the security cookie.
By: Olle Johansson (oej) 2006-07-05 02:13:45

If this is not fixed, then re-open.