Re: [SR-Users] Problem with Kamailio not routing ACK to a 200 OK

Daniel-Constantin Mierla Mon, 15 Nov 2010 07:22:28 -0800

Hello,

I got the pcap file and had the time too check it. There seems to be anextra LF at the end of ACK:


0230  73 65 72 2d 41 67 65 6e  74 3a 20 41 61 73 74 72   ser-Agen t: Aastr
0240  61 20 49 6e 74 65 6c 6c  69 67 61 74 65 0d 0a 43   a Intell igate..C
0250  6f 6e 74 65 6e 74 2d 4c  65 6e 67 74 68 3a 20 30   ontent-L ength: 0
0260  0d 0a 0d 0a 0a                                     .....

Once the last header is finished and ended with CRLF, there must beanother CRLF and that's it if content length is 0.

According to wireshark and the capture you sent, there is an extra 0x0a(LF), so instead of ending in CRLFCRLF, the ACK ends in CRLFCRLFLF

You can remove the content-length check in sanity function, but Irecomend you report to vendor to get the issue fixed there.


Cheers,
Daniel


On 11/11/10 11:28 PM, Daniel-Constantin Mierla wrote:

Hello,

On 11/11/10 11:02 PM, Morten Isaksen wrote:

Hi Daniel,

The Via line is OK, it was the email formating.

I am using Kamailio 3.0.3 and the sanity docs says:

This function makes a row of sanity checks on the given request. The
function returns false (-1) if one of the checks failed. If one of the
checks fails the module sends a precise error reply via sl_send_reply.
Thus there is no need to reply with a generic error message.

it happens sometime that some module parameters control the behaviorof exported functions and it is not mentioned in description. This onewas discovered pretty recently and the description of sanity_check()don't refer to autodrop parameter. I will try to update asap.

I have solved the problem by removing the sanity_check.

I am just a bit curious why it failed.

That should be found to see where is the failure. As a second guessbased on checks, it may be that the ACK has some whitespace in thebody. Do you have pcap version of this ACK trace?


Daniel

But thank you very much for your help.

/Morten

On Thu, Nov 11, 2010 at 8:20 PM, Daniel-Constantin Mierla
<mico...@gmail.com>  wrote:

Hello,

looking now again at the trace you sent first time, the ACK is:

U 2010/10/28 10:51:13.267863 178.21.248.20:5060 ->    178.21.248.7:5060
ACKsip:1...@178.21.248.56:5060  SIP/2.0.
Record-Route:<sip:178.21.248.20;lr;ftag=AI8DA85D59B9B6634F>.
Via: SIP/2.0/UDP 178.21.248.20;branch=z9hG4bK690c.97354e4.2.
Via: SIP/2.0/UDP

87.104.233.108:5060;rport=5060;branch=z9hG4bK07103fe69c8af048b9b8216eb2f7233f.

To:<sip:86987...@sip.uni-tel.dk>;tag=1c2073920452.
From:<sip:87776...@sip.uni-tel.dk>;tag=AI8DA85D59B9B6634F.
Call-ID:ai231ca9bd0a4a1...@10.0.0.150.
CSeq: 2 ACK.
Max-Forwards: 69.

Route:<sip:178.21.248.7;lr=on;ftag=AI8DA85D59B9B6634F;did=f48.5fd1db02>.

User-Agent: Aastra Intelligate.
Content-Length: 0.

I thought that it may be the email body formatting so that thesecond Viaheader body gets on next line after SIP/2.0/UDP. Can you check yourtrace,is it on next line (i.e., there is a new line)? If the Via is on twolineslike it is presented, then it is invalid. A header body can continueon a

new line, but it as to start with whitespace.

Regarding sanity, the module drops silently broken messages if youdon't set

autodrop to 0:
http://kamailio.org/docs/modules/stable/modules/sanity.html#autodrop

Note that you need latest version of branch 3.1/master for it.

Cheers,
Daniel

On 11/11/10 1:50 PM, Morten Isaksen wrote:

Hi,

I narrowed it down to the sanity_check.

        if(!sanity_check("1511", "7"))
        {
                xlog("L_WARN", "sanity check - M=$rm RURI=$ru F=$fu
T=$tu IP=$si ID=$ci\n");
                exit;
        }

The sanity_check fails but does not send a reply back or log the above
line. I have commented it out and now the ACK is forwarded.

/Morten

On Mon, Nov 8, 2010 at 3:00 PM, Morten Isaksen<mi...@misak.dk>wrote:

Hi,

On Fri, Oct 29, 2010 at 10:59 AM, Daniel-Constantin Mierla
<mico...@gmail.com>    wrote:

Hello,

On 10/28/10 1:37 PM, Morten Isaksen wrote:

Hi,

I have a strange problem with Kamailio 3.0.2. When one of our end
users makes a call Kamailio does not route the ACK (in responseto the
200 OK). For all other end users it works fine.
For me it looks the the has_totag() checks for some reason failsand
then t_check_trans() thinks it is a ACK to a local transactions and
then terminates the script. Otherwise there should be more lines in
the log file.

if you add an xlog() after the if with has_totag(), do you get the
message
in the logs?

Sorry for the delay, but a had to wait for the customer to make atest

call.

I placed a xlog("L_WARN", "has_totag after - M=$rm RURI=$ru F=$fu

T=$tu IP=$si ID=$ci\n"); just after the if (has_totag()) { .. }and it

does not show in the log.

It looks very strange to me. Do you have any ideas what is wrong.

/Morten

Cheers,
Daniel

The conf is pretty standard.

route{

         xlog("L_WARN", "New request - M=$rm RURI=$ru F=$fu T=$tu
IP=$si ID=$ci\n");
         xlog("L_WARN", "ua=$ua");
         if (!mf_process_maxfwd_header("10")) {
                 sl_send_reply("483","Too Many Hops");
                 exit;
         }

         if(!sanity_check("1511", "7"))
         {
                 xlog("Malformed SIP message from $si:$sp\n");
                 exit;
         }


         if (has_totag()) {

xlog("L_WARN", "has_totag start - M=$rmRURI=$ru F=$fu

T=$tu IP=$si ID=$ci\n");
                 # sequential request withing a dialog should
                 # take the path determined by record-routing
                 if (loose_route()) {

xlog("L_WARN", "loose_route - M=$rmRURI=$ru

F=$fu T=$tu IP=$si ID=$ci\n");
                         route(RELAY);
                 } else {

if (is_method("SUBSCRIBE")&& uri== myself)

{
                                 # in-dialog subscribe requests
                                 #route(PRESENCE);
                                 exit;
                         }
                         if ( is_method("ACK") ) {
                                 if ( t_check_trans() ) {
                                         xlog("L_WARN", "ACK
t_check_trans - M=$rm RURI=$ru F=$fu T=$tu IP=$si ID=$ci\n");
                                         # non loose-route, but
stateful ACK; must be an ACK after a 487 or e.g. 404 from upstream
server
                                         t_relay();
                                         exit;
                                 } else {
                                         xlog("Ignoring ACK - M=$rm
RURI=$ru F=$fu T=$tu IP=$si ID=$ci\n");
                                         # ACK without matching
transaction ... ignore and discard.\n");
                                         exit;
                                 }
                         }
                         sl_send_reply("404","Not here");
                 }

xlog("L_WARN", "has_totag end - M=$rm RURI=$ruF=$fu

T=$tu IP=$si ID=$ci\n");
                 exit;
         }

         #initial requests

         # CANCEL processing
         if (is_method("CANCEL"))
         {
                 if (t_check_trans())
                         t_relay();
                 exit;
         }

         setflag(4);
         t_check_trans();

...

The log files show:

Oct 28 10:51:13 sip-core-1 /usr/local/sbin/kamailio[10503]:WARNING:

<script>: New request - M=ACK RURI=sip:1...@178.21.248.56:5060
F=sip:87776...@sip.uni-tel.dk T=sip:869

87...@sip.uni-tel.dk IP=178.21.248.20id=ai231ca9bd0a4a1...@10.0.0.150Oct 28 10:51:13 sip-core-1 /usr/local/sbin/kamailio[10503]:WARNING:

<script>: ua=Aastra Intelligate




The trace

U 2010/10/28 10:51:02.616337 178.21.248.7:5060 ->178.21.248.56:5060

INVITE sip:86987...@178.21.248.56 SIP/2.0.

Record-Route:<sip:178.21.248.7;lr;ftag=AI8DA85D59B9B6634F;did=f48.5fd1db02>.

Record-Route:<sip:178.21.248.20;lr;ftag=AI8DA85D59B9B6634F>.
Via: SIP/2.0/UDP 178.21.248.7;branch=z9hG4bK690c.9cfea506.0.
Via: SIP/2.0/UDP 178.21.248.20;branch=z9hG4bK690c.97354e4.0.
Via: SIP/2.0/UDP

87.104.233.108:5060;rport=5060;branch=z9hG4bK3c70fae55c8b362ff34e6c782cc21592.

To:<sip:86987...@sip.uni-tel.dk>.
From:<sip:87776...@sip.uni-tel.dk>;tag=AI8DA85D59B9B6634F.
Call-ID: ai231ca9bd0a4a1...@10.0.0.150.
CSeq: 2 INVITE.
Max-Forwards: 68.
Contact:<sip:87776...@87.104.233.108:5060;line=AI7EFC34995E724DD7>.
Accept: application/sdp.
Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER.
P-Preferred-Identity:<sip:87776...@sip.uni-tel.dk>.
Privacy: none.
User-Agent: Aastra Intelligate.
Content-Type: application/sdp.
Content-Length: 280.
X-trunktype: IC.
.
v=0.
o=intelligate 1194032777 1194032777 IN IP4 87.104.233.106.
s=call.
c=IN IP4 178.21.248.22.
t=0 0.
m=audio 60984 RTP/AVP 8 0 18 101.
a=rtpmap:8 PCMA/8000.
a=rtpmap:0 PCMU/8000.
a=rtpmap:18 G729/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-15.
a=sendrecv.
a=ptime:20.

#

U 2010/10/28 10:51:02.636854 178.21.248.56:5060 ->178.21.248.7:5060

SIP/2.0 100 Trying.
Via: SIP/2.0/UDP 178.21.248.7;branch=z9hG4bK690c.9cfea506.0.
Via: SIP/2.0/UDP 178.21.248.20;branch=z9hG4bK690c.97354e4.0.
Via: SIP/2.0/UDP

87.104.233.108:5060;rport=5060;branch=z9hG4bK3c70fae55c8b362ff34e6c782cc21592.

From:<sip:87776...@sip.uni-tel.dk>;tag=AI8DA85D59B9B6634F.
To:<sip:86987...@sip.uni-tel.dk>;tag=1c2073920452.
Call-ID: ai231ca9bd0a4a1...@10.0.0.150.
CSeq: 2 INVITE.
Supported: em,timer,replaces,path,early-session,resource-priority.
Allow:

REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE.

Server: Audiocodes-Sip-Gateway-Mediant 2000/v.5.60A.035.002.
Content-Length: 0.
.

#####

U 2010/10/28 10:51:04.134445 178.21.248.56:5060 ->178.21.248.7:5060

SIP/2.0 183 Session Progress.
Via: SIP/2.0/UDP 178.21.248.7;branch=z9hG4bK690c.9cfea506.0.
Via: SIP/2.0/UDP 178.21.248.20;branch=z9hG4bK690c.97354e4.0.
Via: SIP/2.0/UDP

87.104.233.108:5060;rport=5060;branch=z9hG4bK3c70fae55c8b362ff34e6c782cc21592.

From:<sip:87776...@sip.uni-tel.dk>;tag=AI8DA85D59B9B6634F.
To:<sip:86987...@sip.uni-tel.dk>;tag=1c2073920452.
Call-ID: ai231ca9bd0a4a1...@10.0.0.150.
CSeq: 2 INVITE.
Contact:<sip:1...@178.21.248.56:5060>.

Record-Route:<sip:178.21.248.7;lr;ftag=AI8DA85D59B9B6634F;did=f48.5fd1db02>,<sip:178.21.248.20;lr;ftag=AI8DA85D59B9B6634F>.

Supported: em,timer,replaces,path,early-session,resource-priority.
Allow:

REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE.

Server: Audiocodes-Sip-Gateway-Mediant 2000/v.5.60A.035.002.
Content-Type: application/sdp.
Content-Length: 259.
.
v=0.
o=AudiocodesGW 2073965634 2073965290 IN IP4 178.21.248.56.
s=Phone-Call.
c=IN IP4 178.21.248.56.
t=0 0.
m=audio 6050 RTP/AVP 8 101.
c=IN IP4 178.21.248.56.
a=rtpmap:8 PCMA/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-15.
a=ptime:20.
a=sendrecv.

#

U 2010/10/28 10:51:04.134748 178.21.248.7:5060 ->178.21.248.20:5060

SIP/2.0 183 Session Progress.
Via: SIP/2.0/UDP 178.21.248.20;branch=z9hG4bK690c.97354e4.0.
Via: SIP/2.0/UDP

87.104.233.108:5060;rport=5060;branch=z9hG4bK3c70fae55c8b362ff34e6c782cc21592.

From:<sip:87776...@sip.uni-tel.dk>;tag=AI8DA85D59B9B6634F.
To:<sip:86987...@sip.uni-tel.dk>;tag=1c2073920452.
Call-ID: ai231ca9bd0a4a1...@10.0.0.150.
CSeq: 2 INVITE.
Contact:<sip:1...@178.21.248.56:5060>.

Record-Route:<sip:178.21.248.7;lr;ftag=AI8DA85D59B9B6634F;did=f48.5fd1db02>,<sip:178.21.248.20;lr;ftag=AI8DA85D59B9B6634F>.

Supported: em,timer,replaces,path,early-session,resource-priority.
Allow:

REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE.

Server: Audiocodes-Sip-Gateway-Mediant 2000/v.5.60A.035.002.
Content-Type: application/sdp.
Content-Length: 259.
.
v=0.
o=AudiocodesGW 2073965634 2073965290 IN IP4 178.21.248.56.
s=Phone-Call.
c=IN IP4 178.21.248.56.
t=0 0.
m=audio 6050 RTP/AVP 8 101.
c=IN IP4 178.21.248.56.
a=rtpmap:8 PCMA/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-15.
a=ptime:20.
a=sendrecv.

#

U 2010/10/28 10:51:04.136586 178.21.248.56:5060 ->178.21.248.7:5060

SIP/2.0 180 Ringing.
Via: SIP/2.0/UDP 178.21.248.7;branch=z9hG4bK690c.9cfea506.0.
Via: SIP/2.0/UDP 178.21.248.20;branch=z9hG4bK690c.97354e4.0.
Via: SIP/2.0/UDP

87.104.233.108:5060;rport=5060;branch=z9hG4bK3c70fae55c8b362ff34e6c782cc21592.

From:<sip:87776...@sip.uni-tel.dk>;tag=AI8DA85D59B9B6634F.
To:<sip:86987...@sip.uni-tel.dk>;tag=1c2073920452.
Call-ID: ai231ca9bd0a4a1...@10.0.0.150.
CSeq: 2 INVITE.
Contact:<sip:1...@178.21.248.56:5060>.

Record-Route:<sip:178.21.248.7;lr;ftag=AI8DA85D59B9B6634F;did=f48.5fd1db02>,<sip:178.21.248.20;lr;ftag=AI8DA85D59B9B6634F>.

Supported: em,timer,replaces,path,early-session,resource-priority.
Allow:

REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE.

Server: Audiocodes-Sip-Gateway-Mediant 2000/v.5.60A.035.002.
Content-Type: application/sdp.
Content-Length: 259.
.
v=0.
o=AudiocodesGW 2073965634 2073965290 IN IP4 178.21.248.56.
s=Phone-Call.
c=IN IP4 178.21.248.56.
t=0 0.
m=audio 6050 RTP/AVP 8 101.
c=IN IP4 178.21.248.56.
a=rtpmap:8 PCMA/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-15.
a=ptime:20.
a=sendrecv.

#

U 2010/10/28 10:51:04.136837 178.21.248.7:5060 ->178.21.248.20:5060

SIP/2.0 180 Ringing.
Via: SIP/2.0/UDP 178.21.248.20;branch=z9hG4bK690c.97354e4.0.
Via: SIP/2.0/UDP

87.104.233.108:5060;rport=5060;branch=z9hG4bK3c70fae55c8b362ff34e6c782cc21592.

From:<sip:87776...@sip.uni-tel.dk>;tag=AI8DA85D59B9B6634F.
To:<sip:86987...@sip.uni-tel.dk>;tag=1c2073920452.
Call-ID: ai231ca9bd0a4a1...@10.0.0.150.
CSeq: 2 INVITE.
Contact:<sip:1...@178.21.248.56:5060>.

Record-Route:<sip:178.21.248.7;lr;ftag=AI8DA85D59B9B6634F;did=f48.5fd1db02>,<sip:178.21.248.20;lr;ftag=AI8DA85D59B9B6634F>.

Supported: em,timer,replaces,path,early-session,resource-priority.
Allow:

REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE.

Server: Audiocodes-Sip-Gateway-Mediant 2000/v.5.60A.035.002.
Content-Type: application/sdp.
Content-Length: 259.
.
v=0.
o=AudiocodesGW 2073965634 2073965290 IN IP4 178.21.248.56.
s=Phone-Call.
c=IN IP4 178.21.248.56.
t=0 0.
m=audio 6050 RTP/AVP 8 101.
c=IN IP4 178.21.248.56.
a=rtpmap:8 PCMA/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-15.
a=ptime:20.
a=sendrecv.

##############################

U 2010/10/28 10:51:12.881179 178.21.248.56:5060 ->178.21.248.7:5060

SIP/2.0 200 OK.
Via: SIP/2.0/UDP 178.21.248.7;branch=z9hG4bK690c.9cfea506.0.
Via: SIP/2.0/UDP 178.21.248.20;branch=z9hG4bK690c.97354e4.0.
Via: SIP/2.0/UDP

87.104.233.108:5060;rport=5060;branch=z9hG4bK3c70fae55c8b362ff34e6c782cc21592.

From:<sip:87776...@sip.uni-tel.dk>;tag=AI8DA85D59B9B6634F.
To:<sip:86987...@sip.uni-tel.dk>;tag=1c2073920452.
Call-ID: ai231ca9bd0a4a1...@10.0.0.150.
CSeq: 2 INVITE.
Contact:<sip:1...@178.21.248.56:5060>.

Record-Route:<sip:178.21.248.7;lr;ftag=AI8DA85D59B9B6634F;did=f48.5fd1db02>,<sip:178.21.248.20;lr;ftag=AI8DA85D59B9B6634F>.

Supported: em,timer,replaces,path,early-session,resource-priority.
Allow:

REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE.

Server: Audiocodes-Sip-Gateway-Mediant 2000/v.5.60A.035.002.
Content-Type: application/sdp.
Content-Length: 259.
.
v=0.
o=AudiocodesGW 2073965634 2073965290 IN IP4 178.21.248.56.
s=Phone-Call.
c=IN IP4 178.21.248.56.
t=0 0.
m=audio 6050 RTP/AVP 8 101.
c=IN IP4 178.21.248.56.
a=rtpmap:8 PCMA/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-15.
a=ptime:20.
a=sendrecv.

#

U 2010/10/28 10:51:12.882388 178.21.248.7:5060 ->178.21.248.20:5060

SIP/2.0 200 OK.
Via: SIP/2.0/UDP 178.21.248.20;branch=z9hG4bK690c.97354e4.0.
Via: SIP/2.0/UDP

87.104.233.108:5060;rport=5060;branch=z9hG4bK3c70fae55c8b362ff34e6c782cc21592.

From:<sip:87776...@sip.uni-tel.dk>;tag=AI8DA85D59B9B6634F.
To:<sip:86987...@sip.uni-tel.dk>;tag=1c2073920452.
Call-ID: ai231ca9bd0a4a1...@10.0.0.150.
CSeq: 2 INVITE.
Contact:<sip:1...@178.21.248.56:5060>.

Record-Route:<sip:178.21.248.7;lr;ftag=AI8DA85D59B9B6634F;did=f48.5fd1db02>,<sip:178.21.248.20;lr;ftag=AI8DA85D59B9B6634F>.

Supported: em,timer,replaces,path,early-session,resource-priority.
Allow:

REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE.

Server: Audiocodes-Sip-Gateway-Mediant 2000/v.5.60A.035.002.
Content-Type: application/sdp.
Content-Length: 259.
.
v=0.
o=AudiocodesGW 2073965634 2073965290 IN IP4 178.21.248.56.
s=Phone-Call.
c=IN IP4 178.21.248.56.
t=0 0.
m=audio 6050 RTP/AVP 8 101.
c=IN IP4 178.21.248.56.
a=rtpmap:8 PCMA/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-15.
a=ptime:20.
a=sendrecv.

#####<<<<<<<<<<<<<<<<<<<<<<       This is the problem
packet>>>>>>>>>>>>>>>>>>>>>

U 2010/10/28 10:51:13.267863 178.21.248.20:5060 ->178.21.248.7:5060

ACK sip:1...@178.21.248.56:5060 SIP/2.0.
Record-Route:<sip:178.21.248.20;lr;ftag=AI8DA85D59B9B6634F>.
Via: SIP/2.0/UDP 178.21.248.20;branch=z9hG4bK690c.97354e4.2.
Via: SIP/2.0/UDP

87.104.233.108:5060;rport=5060;branch=z9hG4bK07103fe69c8af048b9b8216eb2f7233f.

To:<sip:86987...@sip.uni-tel.dk>;tag=1c2073920452.
From:<sip:87776...@sip.uni-tel.dk>;tag=AI8DA85D59B9B6634F.
Call-ID: ai231ca9bd0a4a1...@10.0.0.150.
CSeq: 2 ACK.
Max-Forwards: 69.

Route:<sip:178.21.248.7;lr=on;ftag=AI8DA85D59B9B6634F;did=f48.5fd1db02>.

User-Agent: Aastra Intelligate.
Content-Length: 0.

--
Daniel-Constantin Mierla
http://www.asipto.com


_______________________________________________

SIP Express Router (SER) and Kamailio (OpenSER) - sr-usersmailing list

sr-users@lists.sip-router.org
http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users


--
Morten Isaksen

--
Daniel-Constantin Mierla
http://www.asipto.com


_______________________________________________
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
sr-users@lists.sip-router.org
http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users


--
Daniel-Constantin Mierla
http://www.asipto.com


_______________________________________________
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
sr-users@lists.sip-router.org
http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users

Re: [SR-Users] Problem with Kamailio not routing ACK to a 200 OK

Reply via email to