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

Morten Isaksen misak at misak.dk
Thu Nov 11 13:50:37 CET 2010


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 <misak at misak.dk> wrote:
> Hi,
>
> On Fri, Oct 29, 2010 at 10:59 AM, Daniel-Constantin Mierla
> <miconda at 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 response to the
>>> 200 OK). For all other end users it works fine.
>>>
>>> For me it looks the the has_totag() checks for some reason fails and
>>> 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 a test 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=$rm RURI=$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=$rm RURI=$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=$ru F=$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:1105 at 178.21.248.56:5060
>>> F=sip:87776688 at sip.uni-tel.dk T=sip:869
>>> 87106 at sip.uni-tel.dk IP=178.21.248.20 ID=AI231CA9BD0A4A1C53 at 10.0.0.150
>>> Oct 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:86987106 at 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:86987106 at sip.uni-tel.dk>.
>>> From:<sip:87776688 at sip.uni-tel.dk>;tag=AI8DA85D59B9B6634F.
>>> Call-ID: AI231CA9BD0A4A1C53 at 10.0.0.150.
>>> CSeq: 2 INVITE.
>>> Max-Forwards: 68.
>>> Contact:<sip:87776688 at 87.104.233.108:5060;line=AI7EFC34995E724DD7>.
>>> Accept: application/sdp.
>>> Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER.
>>> P-Preferred-Identity:<sip:87776688 at 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:87776688 at sip.uni-tel.dk>;tag=AI8DA85D59B9B6634F.
>>> To:<sip:86987106 at sip.uni-tel.dk>;tag=1c2073920452.
>>> Call-ID: AI231CA9BD0A4A1C53 at 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:87776688 at sip.uni-tel.dk>;tag=AI8DA85D59B9B6634F.
>>> To:<sip:86987106 at sip.uni-tel.dk>;tag=1c2073920452.
>>> Call-ID: AI231CA9BD0A4A1C53 at 10.0.0.150.
>>> CSeq: 2 INVITE.
>>> Contact:<sip:1105 at 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:87776688 at sip.uni-tel.dk>;tag=AI8DA85D59B9B6634F.
>>> To:<sip:86987106 at sip.uni-tel.dk>;tag=1c2073920452.
>>> Call-ID: AI231CA9BD0A4A1C53 at 10.0.0.150.
>>> CSeq: 2 INVITE.
>>> Contact:<sip:1105 at 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:87776688 at sip.uni-tel.dk>;tag=AI8DA85D59B9B6634F.
>>> To:<sip:86987106 at sip.uni-tel.dk>;tag=1c2073920452.
>>> Call-ID: AI231CA9BD0A4A1C53 at 10.0.0.150.
>>> CSeq: 2 INVITE.
>>> Contact:<sip:1105 at 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:87776688 at sip.uni-tel.dk>;tag=AI8DA85D59B9B6634F.
>>> To:<sip:86987106 at sip.uni-tel.dk>;tag=1c2073920452.
>>> Call-ID: AI231CA9BD0A4A1C53 at 10.0.0.150.
>>> CSeq: 2 INVITE.
>>> Contact:<sip:1105 at 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:87776688 at sip.uni-tel.dk>;tag=AI8DA85D59B9B6634F.
>>> To:<sip:86987106 at sip.uni-tel.dk>;tag=1c2073920452.
>>> Call-ID: AI231CA9BD0A4A1C53 at 10.0.0.150.
>>> CSeq: 2 INVITE.
>>> Contact:<sip:1105 at 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:87776688 at sip.uni-tel.dk>;tag=AI8DA85D59B9B6634F.
>>> To:<sip:86987106 at sip.uni-tel.dk>;tag=1c2073920452.
>>> Call-ID: AI231CA9BD0A4A1C53 at 10.0.0.150.
>>> CSeq: 2 INVITE.
>>> Contact:<sip:1105 at 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:1105 at 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:86987106 at sip.uni-tel.dk>;tag=1c2073920452.
>>> From:<sip:87776688 at sip.uni-tel.dk>;tag=AI8DA85D59B9B6634F.
>>> Call-ID: AI231CA9BD0A4A1C53 at 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-users mailing list
>> sr-users at lists.sip-router.org
>> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
>>
>
>
>
> --
> Morten Isaksen
>



-- 
Morten Isaksen



More information about the sr-users mailing list