[OpenSIPS-Users] OpenSIPS 3.2.7 tracer module for sip dialogs leads to an endless loop
Bogdan-Andrei Iancu
bogdan at opensips.org
Mon Oct 17 06:42:10 UTC 2022
Hi Pavel,
try removing the SIP tid (the second one) - as you see that tid forces
the tracer module to resend the copy of the message back to opensips
itself (172.16.34.91:5060 is opensips listener, afaiu). Just remove it
and see if it works ok.
Regards,
Bogdan-Andrei Iancu
OpenSIPS Founder and Developer
https://www.opensips-solutions.com
OpenSIPS Summit 27-30 Sept 2022, Athens
https://www.opensips.org/events/Summit-2022Athens/
On 10/12/22 7:23 PM, Pavel Ekshin wrote:
> Hi Bogdan!
>
> Thanks for the answer! I tried this one:
>
> #### TRACE module
> loadmodule "tracer.so"
> modparam("tracer", "trace_on", 1)
> modparam("tracer",
> "trace_id","[tid]uri=mysql://XXXXX:XXXXXXX@localhost/opensips;table=sip_trace;")
> modparam("tracer", "trace_id","[tid]uri=sip:172.16.34.91:5060
> <http://172.16.34.91:5060>")
> modparam("tracer", "trace_local_ip", "172.16.34.91")
>
> I use the constant string "tid" inside the trace(), no specific variable.
>
> route{
> script_trace( 1, "$rm from $si, ruri=$ru, contact=$ct",
> "script_trace");
> #trace("tid", "d", "sip");
> #xlog("here_trace");
>
> #if (!has_totag()) {
> # if(is_method("INVITE") ) {
> # # We need to use the dialog module to have the
> outgoing ACK traced
> # # trace("tid", "d", "sip");
> #}
> #}
> #else {
> # match_dialog();
> #}
>
> #if (!is_method("INVITE,ACK,BYE,PRACK")) {
> # Requests that are not part of an established dialog will be
> transaction base traced
> # trace("tid", "t", "sip");
> # xlog("Message not in dialog - $rm\n");
> #}
> #trace("tid", "t", "sip");
> ..
>
> BR, Pavel
>
> вт, 11 окт. 2022 г. в 14:58, Bogdan-Andrei Iancu <bogdan at opensips.org
> <mailto:bogdan at opensips.org>>:
>
> Hi PAvel,
>
> How do you define the tid you use for tracing ?
>
> Regards,
>
> Bogdan-Andrei Iancu
>
> OpenSIPS Founder and Developer
> https://www.opensips-solutions.com <https://www.opensips-solutions.com>
> OpenSIPS Summit 27-30 Sept 2022, Athens
> https://www.opensips.org/events/Summit-2022Athens/ <https://www.opensips.org/events/Summit-2022Athens/>
>
> On 9/21/22 7:45 PM, Pavel Ekshin wrote:
>> Hi Bogdan,
>>
>> Thanks for the answer.
>> I tried this module, but nothing weird was found. On reply ACK
>> messages in sngrep capture I see the correct "To/Contact''
>> header, but in log the "To" header looks different, but it's not
>> lead to any loop.
>>
>> Sep 20 16:51:55 openSIPS /usr/sbin/opensips[15619]: [Script
>> Trace][/etc/opensips/opensips_residential.cfg:430][script_trace][core
>> if] -> (INVITE from 172.18.53.131,
>> ruri=sip:4002 at 172.16.34.173:5060
>> <http://sip:4002@172.16.34.173:5060>,
>> contact=<sip:opensips at 172.18.53.131:5060
>> <http://sip:opensips@172.18.53.131:5060>>)
>> Sep 20 16:51:55 openSIPS /usr/sbin/opensips[15619]: [Script
>> Trace][/etc/opensips/opensips_residential.cfg:427][script_trace][module
>> t_relay] -> (INVITE from 172.18.53.131,
>> ruri=sip:4002 at 172.16.34.173:5060
>> <http://sip:4002@172.16.34.173:5060>,
>> contact=<sip:opensips at 172.18.53.131:5060
>> <http://sip:opensips@172.18.53.131:5060>>)
>> Sep 20 16:51:55 openSIPS /usr/sbin/opensips[15619]: [Script
>> Trace][/etc/opensips/opensips_residential.cfg:430][script_trace][core
>> exit] -> (INVITE from 172.18.53.131,
>> ruri=sip:4002 at 172.16.34.173:5060
>> <http://sip:4002@172.16.34.173:5060>,
>> contact=<sip:opensips at 172.18.53.131:5060
>> <http://sip:opensips@172.18.53.131:5060>>)
>> Sep 20 16:51:55 openSIPS /usr/sbin/opensips[15619]: [Script
>> Trace][/etc/opensips/opensips_residential.cfg:221][script_trace][core
>> if] -> (ACK from 172.18.53.131,
>> ruri=sip:172.16.34.173:5060;transport=udp,
>> contact=<sip:opensips at 172.18.53.131:5060
>> <http://sip:opensips@172.18.53.131:5060>>)
>> Sep 20 16:51:55 openSIPS /usr/sbin/opensips[15619]: [Script
>> Trace][/etc/opensips/opensips_residential.cfg:214][script_trace][module
>> mf_process_maxfwd_header] -> (ACK from 172.18.53.131,
>> ruri=sip:172.16.34.173:5060;transport=udp,
>> contact=<sip:opensips at 172.18.53.131:5060
>> <http://sip:opensips@172.18.53.131:5060>>)
>> Sep 20 16:51:55 openSIPS /usr/sbin/opensips[15619]: [Script
>> Trace][/etc/opensips/opensips_residential.cfg:258][script_trace][core
>> if] -> (ACK from 172.18.53.131,
>> ruri=sip:172.16.34.173:5060;transport=udp,
>> contact=<sip:opensips at 172.18.53.131:5060
>> <http://sip:opensips@172.18.53.131:5060>>)
>> Sep 20 16:51:55 openSIPS /usr/sbin/opensips[15619]: [Script
>> Trace][/etc/opensips/opensips_residential.cfg:221][script_trace][module
>> has_totag] -> (ACK from 172.18.53.131,
>> ruri=sip:172.16.34.173:5060;transport=udp,
>> contact=<sip:opensips at 172.18.53.131:5060
>> <http://sip:opensips@172.18.53.131:5060>>)
>>
>> ________________________________________________________________________________________________________________________
>> ____________172.18.53.131:5060___________172.16.34.91:5060______________172.16.34.173:5060___________172.16.34.173:64087
>> <http://172.16.34.173:64087>
>> __________qqqqqqqqqqwqqqqqqqqq__________qqqqqqqqqqwqqqqqqqqq__________qqqqqqqqqqwqqqqqqqqq__________qqqqqqqqqqwqqqqqqqqqx
>> __16:06:48.772459___x________INVITE_(SDP)_________x_____________________________x_____________________________x_________
>> ________+0.001900___x_qqqqqqqqqqqqqqqqqqqqqqqqqq>_x_____________________________x_____________________________x_________
>> __16:06:48.774359___x__407_Proxy_Authentication_R_x_____________________________x_____________________________x_________
>> ________+0.014197___x_<qqqqqqqqqqqqqqqqqqqqqqqqqq_x_____________________________x_____________________________x_________
>> __16:06:48.788556___x_____________ACK_____________x_____________________________x_____________________________x________
>> ________+0.000103___x_qqqqqqqqqqqqqqqqqqqqqqqqqq>_x_____________________________x_____________________________x_________
>> __16:06:48.788659___x________INVITE_(SDP)_________x_____________________________x_____________________________x_________
>> ________+0.005221___x_qqqqqqqqqqqqqqqqqqqqqqqqqq>_x_____________________________x_____________________________x_________
>> __16:06:48.793880___x_____100_Giving_it_a_try_____x_____________________________x_____________________________x_________
>> ________+0.000664___x_<qqqqqqqqqqqqqqqqqqqqqqqqqq_x_____________________________x_____________________________x_________
>> __16:06:48.794544___x_____________________________x________INVITE_(SDP)_________x_____________________________x_________
>> ________+0.004555___x_____________________________x_qqqqqqqqqqqqqqqqqqqqqqqqqq>_x_____________________________x_________
>> __16:06:48.799099___x_____________________________x________________________100_Trying_________________________x_________
>> ________+0.039449___x_____________________________x_<qqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqq_x_________
>> __16:06:48.838548___x_____________________________x_______________________200_Ok_(SDP)________________________x_________
>> ________+0.000493___x_____________________________x_<qqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqq_x_________
>> __16:06:48.839041___x________200_Ok_(SDP)_________x_____________________________x_____________________________x_________
>> ________+0.012395___x_<qqqqqqqqqqqqqqqqqqqqqqqqqq_x_____________________________x_____________________________x_________
>> __16:06:48.851436___x_____________ACK_____________x_____________________________x_____________________________x_________
>> ________+0.000488___x_qqqqqqqqqqqqqqqqqqqqqqqqqq>_x_____________________________x_____________________________x_________
>> __16:06:48.851924___x_____________________________x_____________ACK_____________x_____________________________x_________
>> ________+8.768408___x_____________________________x_qqqqqqqqqqqqqqqqqqqqqqqqqq>_x_____________________________x_________
>> __16:06:57.620332___x_____________BYE_____________x_____________________________x_____________________________x_________
>> ________+0.000966___x_qqqqqqqqqqqqqqqqqqqqqqqqqq>_x_____________________________x_____________________________x_________
>> __16:06:57.621298___x_____________________________x_____________BYE_____________x_____________________________x_________
>> ________+0.003895___x_____________________________x_qqqqqqqqqqqqqqqqqqqqqqqqqq>_x_____________________________x________
>> __16:06:57.625193___x_____________________________x__________________________200_Ok___________________________x_________
>> ________+0.000271___x_____________________________x_<qqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqq_x_________
>> __16:06:57.625464___x___________200_Ok____________x_____________________________x_____________________________x_________
>> ____________________x_<qqqqqqqqqqqqqqqqqqqqqqqqqq_x_____________________________x_____________________________x_________
>> ____________________x_____________________________x_____________________________x_____________________________x_________
>> ____________________x_____________________________x_____________________________x_____________________________x_________
>>
>> If I disable trace("tid", "d/t/m", "sip") module at route level,
>> I never faced with loop.I also found that trace("tid", "m",
>> "sip") is worked for specific messages, f.e INVITE, and not
>> looped too.
>> If I have something wrong with the route, it should also be
>> looped without enabled trace(), but it's not happen. I think it's
>> around the rules of trace() module and rules there this module
>> may be enabled. Maybe you have an example for enabling the
>> trace() module globally?
>>
>> BR, Pavel
>>
>> вт, 6 сент. 2022 г. в 11:53, Bogdan-Andrei Iancu
>> <bogdan at opensips.org <mailto:bogdan at opensips.org>>:
>>
>> Hi Pavel,
>>
>> The tracing part has nothing to do with the routing on the
>> SIP side. And
>> usually you end up with SIP loops if, without changing the
>> RURI, you
>> send the SIP request out, making OpenSIPS to send the request
>> back to
>> itself (as the destination in RURI still points to OpenSIPS).
>>
>> I advice you to try to understand the execution flow via your
>> script by
>> using the script_trace[1] function and logging the RURI (as $ru)
>>
>> [1]
>> https://www.opensips.org/Documentation/Script-CoreFunctions-3-2#script_trace
>> <https://www.opensips.org/Documentation/Script-CoreFunctions-3-2#script_trace>
>>
>> Regards,
>>
>> Bogdan-Andrei Iancu
>>
>> OpenSIPS Founder and Developer
>> https://www.opensips-solutions.com
>> <https://www.opensips-solutions.com>
>> OpenSIPS Summit 27-30 Sept 2022, Athens
>> https://www.opensips.org/events/Summit-2022Athens/
>> <https://www.opensips.org/events/Summit-2022Athens/>
>>
>> On 8/30/22 9:31 PM, Pavel Ekshin wrote:
>> > Hi there,
>> > I try very basic scenario with tracing sip dialogs in
>> OpenSIPS 3.2.7,
>> > and this scenario leads in an endless loop inside Opensips
>> for SIP
>> > messages.
>> > Maybe someone is similarly affected or can point to the
>> error on the
>> > route scenario? I use out of box residential configuration.
>> I read the
>> > tracer module doc
>> (https://opensips.org/docs/modules/devel/tracer.html
>> <https://opensips.org/docs/modules/devel/tracer.html>
>> > <https://opensips.org/docs/modules/devel/tracer.html
>> <https://opensips.org/docs/modules/devel/tracer.html>>), but
>> dialog
>> > examples from doc also lead to loops.
>> > I also tried with transactions, but they are looped too.
>> Trace for
>> > messages works fine. I think I miss some points.
>> >
>> > MariaDB [opensips]> select method,COUNT(*) from sip_trace
>> group by method;
>> > +--------+----------+
>> > | method | COUNT(*) |
>> > +--------+----------+
>> > | ACK | 2625 |
>> > | BYE | 2270 |
>> > | INVITE | 219 |
>> > +--------+----------+
>> >
>> > Below my config:
>> [...]
>>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opensips.org/pipermail/users/attachments/20221017/9fdb9c3c/attachment-0001.html>
More information about the Users
mailing list