Hello,
We found out the problem, it was out fault. The ACK was dropped because the
was a previous (and incorrect) evaluation of $rU. Being $null for these
calls, the ACK wasn't relayed. We already fixed it; thanks for the
assistance.
Regards,
David.
2012/7/30 Daniel-Constantin Mierla <mico...@gmail.com>
> Hello,
>
> add $si, $ru and $ci in the xlog(...) from the config to compare with
> ngrep trace, maybe there are different ACKs.
>
> Cheers,
> Daniel
>
>
> On 7/30/12 3:55 PM, David Notivol wrote:
>
> Hello,
>
> It looks like the r-uri in the trace is different from the one kamailio
> considers. From the ACK message captured with ngrep:
> ACK sip:200.87.137.150:5060;user=phone SIP/2.0
>
> But form the logs:
> Jul 30 09:15:00 theseus-test /usr/local/kamailio/sbin/kamailio[1577]:
> DEBUG: <core> [parser/msg_parser.c:630]: method: <ACK>
> Jul 30 09:15:00 theseus-test /usr/local/kamailio/sbin/kamailio[1577]:
> DEBUG: <core> [parser/msg_parser.c:632]: uri:
> <sip:59146938249@79.170.68.157:5060;user=phone><sip:59146938249@79.170.68.157:5060;user=phone>
>
>
> Regards,
> David.
>
> 2012/7/30 Daniel-Constantin Mierla <mico...@gmail.com>
>
>> Hello,
>>
>> the log message shows that the transaction is not found. Is the ACK
>> coming late after 200ok ? There is a tm module parameter that you can
>> adjust to prolong the time a transaction is kept after completion, if that
>> is the case.
>>
>> Also, be sure the INVITE is sent using tm functions, not stateless via
>> core function.
>>
>> Then, instead of dropping, you can just try forwarding it if the uri si
>> not myself, like adding:
>>
>> if(uri!=myself) t_relay();
>>
>> before the exit.
>>
>> Cheers,
>> Daniel
>>
>>
>> On 7/30/12 11:10 AM, David Notivol wrote:
>>
>> This is the code that's being executed:
>>
>> route[WITHINDLG] {
>> if (has_totag()) {
>> # sequential request withing a dialog should
>> # take the path determined by record-routing
>> xlog("ESTAMOS EN WITHIN\n");
>> if (loose_route()){
>> xlog("LOOSE ROUTE DETECTED\n");
>> if (is_method("ACK")) {
>> xlog("ES UN ACK\n");
>> }
>> route(BYE);
>> route(RELAY);
>> } else {
>> xlog("NO LOOSE ROUTE\n");
>> if ( is_method("ACK") ) {
>> if ( t_check_trans() ) {
>> xlog("NO LOOSE AND TRANSACTION FOUND\n");
>> # no loose-route, but stateful ACK;
>> # must be an ACK after a 487
>> # or e.g. 404 from upstream server
>> t_relay();
>> exit;
>> } else {
>> xlog("NO LOOSE AND TRANSACTION NOT FOUND\n");
>> # ACK without matching transaction ... ignore and
>> discard
>> exit;
>> }
>> }
>> sl_send_reply("404","Not here");
>> }
>> exit;
>> }
>> }
>>
>>
>> And the call log with cfgtrace. It seems to be clear that the transaction
>> is not matched, but we can't see why.
>>
>> Jul 30 04:58:08 theseus-test /usr/local/kamailio/sbin/kamailio[577]:
>> ERROR: *** cfgtrace: c=[/usr/local/kamailio/etc/kamailio/kamailio.cfg]
>> l=335 a=26 n=xlog
>> Jul 30 04:58:08 theseus-test /usr/local/kamailio/sbin/kamailio[577]:
>> ERROR: <script>: ESTAMOS EN WITHIN
>> Jul 30 04:58:08 theseus-test /usr/local/kamailio/sbin/kamailio[577]:
>> ERROR: *** cfgtrace: c=[/usr/local/kamailio/etc/kamailio/kamailio.cfg]
>> l=360 a=17 n=if
>> Jul 30 04:58:08 theseus-test /usr/local/kamailio/sbin/kamailio[577]:
>> ERROR: *** cfgtrace: c=[/usr/local/kamailio/etc/kamailio/kamailio.cfg]
>> l=336 a=25 n=loose_route
>> Jul 30 04:58:08 theseus-test /usr/local/kamailio/sbin/kamailio[577]:
>> DEBUG: rr [loose.c:108]: No Route headers found
>> Jul 30 04:58:08 theseus-test /usr/local/kamailio/sbin/kamailio[577]:
>> DEBUG: rr [loose.c:838]: There is no Route HF
>> Jul 30 04:58:08 theseus-test /usr/local/kamailio/sbin/kamailio[577]:
>> ERROR: *** cfgtrace: c=[/usr/local/kamailio/etc/kamailio/kamailio.cfg]
>> l=344 a=26 n=xlog
>> Jul 30 04:58:08 theseus-test /usr/local/kamailio/sbin/kamailio[577]:
>> ERROR: <script>: NO LOOSE ROUTE
>> Jul 30 04:58:08 theseus-test /usr/local/kamailio/sbin/kamailio[577]:
>> ERROR: *** cfgtrace: c=[/usr/local/kamailio/etc/kamailio/kamailio.cfg]
>> l=359 a=17 n=if
>> Jul 30 04:58:08 theseus-test /usr/local/kamailio/sbin/kamailio[577]:
>> ERROR: *** cfgtrace: c=[/usr/local/kamailio/etc/kamailio/kamailio.cfg]
>> l=345 a=26 n=is_method
>> Jul 30 04:58:08 theseus-test /usr/local/kamailio/sbin/kamailio[577]:
>> ERROR: *** cfgtrace: c=[/usr/local/kamailio/etc/kamailio/kamailio.cfg]
>> l=357 a=17 n=if
>> Jul 30 04:58:08 theseus-test /usr/local/kamailio/sbin/kamailio[577]:
>> ERROR: *** cfgtrace: c=[/usr/local/kamailio/etc/kamailio/kamailio.cfg]
>> l=346 a=25 n=t_check_trans
>> Jul 30 04:58:08 theseus-test /usr/local/kamailio/sbin/kamailio[577]:
>> DEBUG: tm [t_lookup.c:1079]: DEBUG: t_check_msg: msg id=12 global id=10 T
>> start=(nil)
>> Jul 30 04:58:08 theseus-test /usr/local/kamailio/sbin/kamailio[577]:
>> DEBUG: tm [t_lookup.c:527]: t_lookup_request: start searching: hash=58737,
>> isACK=1
>> Jul 30 04:58:08 theseus-test /usr/local/kamailio/sbin/kamailio[577]:
>> DEBUG: tm [t_lookup.c:485]: DEBUG: RFC3261 transaction matching failed
>> Jul 30 04:58:08 theseus-test /usr/local/kamailio/sbin/kamailio[577]:
>> DEBUG: tm [t_lookup.c:709]: DEBUG: t_lookup_request: no transaction found
>> Jul 30 04:58:08 theseus-test /usr/local/kamailio/sbin/kamailio[577]:
>> DEBUG: tm [t_lookup.c:1148]: DEBUG: t_check_msg: msg id=12 global id=12 T
>> end=(nil)
>> Jul 30 04:58:08 theseus-test /usr/local/kamailio/sbin/kamailio[577]:
>> ERROR: *** cfgtrace: c=[/usr/local/kamailio/etc/kamailio/kamailio.cfg]
>> l=354 a=26 n=xlog
>> Jul 30 04:58:08 theseus-test /usr/local/kamailio/sbin/kamailio[577]:
>> ERROR: <script>: NO LOOSE AND TRANSACTION NOT FOUND
>> Jul 30 04:58:08 theseus-test /usr/local/kamailio/sbin/kamailio[577]:
>> ERROR: *** cfgtrace: c=[/usr/local/kamailio/etc/kamailio/kamailio.cfg]
>> l=356 a=3 n=exit
>> Jul 30 04:58:08 theseus-test /usr/local/kamailio/sbin/kamailio[577]:
>> DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list
>> (nil)
>>
>> 2012/7/30 Daniel-Constantin Mierla <mico...@gmail.com>
>>
>>> Hello,
>>>
>>> if your config is based on the default one, there is a check for
>>> associated INVITE transaction and if that does not exist, then the ACK is
>>> droppend.
>>>
>>> You can use debugger module with cfgtrace set on in order to see what
>>> actions in the config file are executed. That will help to see if it gets
>>> to t_check_trans() and then exit.
>>>
>>> Cheers,
>>> Daniel
>>>
>>>
>>> On 7/30/12 10:35 AM, David Notivol wrote:
>>>
>>> Hi Daniel,
>>>
>>> This is the ACK message:
>>>
>>> U 2012/07/30 04:23:31.604721 79.170.68.151:5060 -> 79.170.68.157:5060
>>> ACK sip:200.87.137.150:5060;user=phone SIP/2.0.
>>> Via: SIP/2.0/UDP 79.170.68.151:5060
>>> ;branch=z9hG4bK334faa4497ll114a52eACK450932302031.
>>> Max-Forwards: 70.
>>> Route: <sip:79.170.68.157;lr;ftag=45093230-co8241-INS033>.
>>> To: <sip:59146292331@79.170.68.157
>>> ;user=phone;noa=international>;tag=ldb0cbn6-CC-23.
>>> From: "Javi Gallart"<sip:34917019888@79.170.68.151
>>> ;user=phone;noa=national>;tag=45093230-co8241-INS033.
>>> Call-ID: 071ae17301d3eb470f5cdde00cd9b...@ens.com.
>>> CSeq: 824101 ACK.
>>> User-Agent: ENSR3.0.66.34-IS33-RMRG106382-RG105488-CPO13110.
>>> Content-Length: 0.
>>>
>>>
>>> 2012/7/30 Daniel-Constantin Mierla <mico...@gmail.com>
>>>
>>>> Hello,
>>>>
>>>> can you add a log message to print the source ip, call id and r-uri?
>>>>
>>>> It may happen that the ACK is looping back if r-uri is pointing to
>>>> itself.
>>>>
>>>> Also, try to get the ngrep on all devices, like:
>>>>
>>>> ngrep -d any -qt -W byline port 5060
>>>>
>>>> Pasting the ACK request here will help to see if something is wrong
>>>> with it.
>>>>
>>>> Cheers,
>>>> Daniel
>>>>
>>>>
>>>> On 7/30/12 8:53 AM, David Notivol wrote:
>>>>
>>>> In a UAC-Kamailio-UAS scenario, we've found a case where the ACK
>>>> coming from uac is not relayed by our proxy to the uas. This is the log for
>>>> the ACK message:
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: DEBUG: <core>
>>>> [parser/msg_parser.c:624]: SIP Request:
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: DEBUG: <core>
>>>> [parser/msg_parser.c:626]: method: <ACK>
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: DEBUG: <core>
>>>> [parser/msg_parser.c:628]: uri:
>>>> <sip:59138553189@79.170.68.157><sip:59138553189@79.170.68.157>
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: DEBUG: <core>
>>>> [parser/msg_parser.c:630]: version: <SIP/2.0>
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: DEBUG: <core>
>>>> [parser/parse_via.c:1286]: Found param type 235, <rport> = <n/a>; state=6
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: DEBUG: <core>
>>>> [parser/parse_via.c:1286]: Found param type 232, <branch> =
>>>> <z9hG4bKKc4gKXyemS9HD>; state=16
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: DEBUG: <core>
>>>> [parser/parse_via.c:2561]: end of header reached, state=5
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: DEBUG: <core>
>>>> [parser/msg_parser.c:511]: parse_headers: Via found, flags=2
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: DEBUG: <core>
>>>> [parser/msg_parser.c:513]: parse_headers: this is the first via
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: DEBUG: <core> [receive.c:149]:
>>>> After parse_msg...
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: DEBUG: <core> [receive.c:190]:
>>>> preparing to run routing scripts...
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: DEBUG: sl [sl_funcs.c:396]: DEBUG
>>>> : sl_filter_ACK: to late to be a local ACK!
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: DEBUG: maxfwd [mf_funcs.c:85]:
>>>> value = 65
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: DEBUG: <core>
>>>> [parser/parse_to.c:178]: DEBUG: add_param: tag=6ne1x6d6-CC-23
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: DEBUG: <core>
>>>> [parser/parse_to.c:802]: end of header reached, state=29
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: DEBUG: <core>
>>>> [parser/msg_parser.c:188]: DEBUG: get_hdr_field: <To> [52]; uri=[
>>>> sip:59138553189@79.170.68.157]
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: DEBUG: <core>
>>>> [parser/msg_parser.c:190]: DEBUG: to body [
>>>> <sip:59138553189@79.170.68.157> <sip:59138553189@79.170.68.157>]
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: DEBUG: <core>
>>>> [parser/msg_parser.c:168]: get_hdr_field: cseq <CSeq>: <31362871> <ACK>
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: DEBUG: <core>
>>>> [parser/msg_parser.c:202]: DEBUG: get_hdr_body : content_length=0
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: DEBUG: <core>
>>>> [parser/msg_parser.c:104]: found end of header
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: DEBUG: <core>
>>>> [parser/parse_to.c:178]: DEBUG: add_param: tag=0cS8trtaF196F
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: DEBUG: <core>
>>>> [parser/parse_to.c:802]: end of header reached, state=29
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: DEBUG: sanity [mod_sanity.c:255]:
>>>> sanity checks result: 1
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: DEBUG: siputils [checks.c:106]:
>>>> totag found
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: ERROR: <script>: ESTAMOS EN
>>>> WITHIN
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: DEBUG: rr [loose.c:108]: No Route
>>>> headers found
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: DEBUG: rr [loose.c:829]: There is
>>>> no Route HF
>>>> Jul 27 10:04:59 theseus-test
>>>> /usr/local/kamailio/sbin/kamailio[17358]: ERROR: <script>: NO LOOSE ROUTE
>>>>
>>>> However, in a pcap trace I clearly see the Route header:
>>>> This is the Record-Route in the 200 message
>>>> Record-Route: <sip:79.170.68.157;lr;ftag=330cdf48-co1022-INS033>
>>>> And this is the Route header in the ACk:
>>>> Route: <sip:79.170.68.157;lr;ftag=330cdf48-co1022-INS033>
>>>>
>>>> I haven't been able to figure out what's going on. We have plenty of
>>>> traffic working in that proxy. What am I missing?
>>>>
>>>> Thanks in advance
>>>> David.
>>>>
>>>>
>>>> _______________________________________________
>>>> SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing
>>>> listsr-us...@lists.sip-router.orghttp://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
>>>>
>>>>
>>>> --
>>>> Daniel-Constantin Mierla -
>>>> http://www.asipto.comhttp://twitter.com/#!/miconda -
>>>> http://www.linkedin.com/in/miconda
>>>> Kamailio Advanced Training, Seattle, USA, Sep 23-26, 2012 -
>>>> http://asipto.com/u/katu
>>>> Kamailio Practical Workshop, Netherlands, Sep 10-12, 2012 -
>>>> http://asipto.com/u/kpw
>>>>
>>>>
>>>
>>>
>>> --
>>> Daniel-Constantin Mierla -
>>> http://www.asipto.comhttp://twitter.com/#!/miconda -
>>> http://www.linkedin.com/in/miconda
>>> Kamailio Advanced Training, Seattle, USA, Sep 23-26, 2012 -
>>> http://asipto.com/u/katu
>>> Kamailio Practical Workshop, Netherlands, Sep 10-12, 2012 -
>>> http://asipto.com/u/kpw
>>>
>>>
>>
>>
>> --
>> Saludos,
>> David Notivol
>> dnoti...@gmail.com
>>
>>
>> --
>> Daniel-Constantin Mierla -
>> http://www.asipto.comhttp://twitter.com/#!/miconda -
>> http://www.linkedin.com/in/miconda
>> Kamailio Advanced Training, Seattle, USA, Sep 23-26, 2012 -
>> http://asipto.com/u/katu
>> Kamailio Practical Workshop, Netherlands, Sep 10-12, 2012 -
>> http://asipto.com/u/kpw
>>
>>
>
> --
> Daniel-Constantin Mierla - http://www.asipto.comhttp://twitter.com/#!/miconda
> - http://www.linkedin.com/in/miconda
> Kamailio Advanced Training, Seattle, USA, Sep 23-26, 2012 -
> http://asipto.com/u/katu
> Kamailio Practical Workshop, Netherlands, Sep 10-12, 2012 -
> http://asipto.com/u/kpw
>
>
_______________________________________________
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
