[SR-Users] ACK not relayed
Daniel-Constantin Mierla
miconda at gmail.com
Mon Jul 30 16:27:05 CEST 2012
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 at 79.170.68.157:5060;user=phone>
>
>
> Regards,
> David.
>
> 2012/7/30 Daniel-Constantin Mierla <miconda at gmail.com
> <mailto:miconda at 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 <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://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://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/926cc459/attachment-0001.htm>
More information about the sr-users
mailing list