[SR-Users] ACK not relayed
Daniel-Constantin Mierla
miconda at gmail.com
Mon Jul 30 11:38:37 CEST 2012
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 <miconda at gmail.com
> <mailto:miconda at 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
>> <http://79.170.68.151:5060> -> 79.170.68.157:5060
>> <http://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 at 79.170.68.157
>> <mailto:sip%3A59146292331 at 79.170.68.157>;user=phone;noa=international>;tag=ldb0cbn6-CC-23.
>> From: "Javi Gallart"<sip:34917019888 at 79.170.68.151
>> <mailto:sip%3A34917019888 at 79.170.68.151>;user=phone;noa=national>;tag=45093230-co8241-INS033.
>> Call-ID: 071ae17301d3eb470f5cdde00cd9b24b at ens.com
>> <mailto:071ae17301d3eb470f5cdde00cd9b24b at ens.com>.
>> CSeq: 824101 ACK.
>> User-Agent: ENSR3.0.66.34-IS33-RMRG106382-RG105488-CPO13110.
>> Content-Length: 0.
>>
>>
>> 2012/7/30 Daniel-Constantin Mierla <miconda at gmail.com
>> <mailto:miconda at 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 at 79.170.68.157>
>>> <mailto:sip:59138553189 at 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 at 79.170.68.157
>>> <mailto:sip:59138553189 at 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 at 79.170.68.157>
>>> <mailto:sip:59138553189 at 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 list
>>> sr-users at lists.sip-router.org <mailto:sr-users at lists.sip-router.org>
>>> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
>>
>> --
>> Daniel-Constantin Mierla -http://www.asipto.com
>> http://twitter.com/#!/miconda <http://twitter.com/#%21/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.com
> http://twitter.com/#!/miconda <http://twitter.com/#%21/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
> dnotivol at gmail.com <mailto:dnotivol at gmail.com>
>
--
Daniel-Constantin Mierla - http://www.asipto.com
http://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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sip-router.org/pipermail/sr-users/attachments/20120730/48ab69b2/attachment-0001.htm>
More information about the sr-users
mailing list