[OpenSIPS-Users] OpenSIPS 3.2.7 tracer module for sip dialogs leads to an endless loop

Wed Sep 21 16:45:34 UTC 2022

 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, contact=<
sip:opensips at 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,
contact=<sip:opensips at 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, contact=<
sip:opensips at 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>)
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>)
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>)
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>)

________________________________________________________________________________________________________________________
____________172.18.53.131:5060___________172.16.34.91:5060
______________172.16.34.173:5060___________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>:

> 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
>
> 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 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>), 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/20220921/71f2f53e/attachment-0001.html>