<!-- Kamailio Project uses GitHub Issues only for bugs in the code or feature requests. Please use this template only for bug reports.
If you have questions about using Kamailio or related to its configuration file, ask on sr-users mailing list:
* http://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
If you have questions about developing extensions to Kamailio or its existing C code, ask on sr-dev mailing list:
* http://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-dev
Please try to fill this template as much as possible for any issue. It helps the developers to troubleshoot the issue.
If there is no content to be filled in a section, the entire section can be removed.
You can delete the comments from the template sections when filling.
You can delete next line and everything above before submitting (it is a comment). -->
### Description
I'm appending two contacts / branches upon receiving a call. This is a snippet of the config I'm using to debug: ``` xlog ("=== branch 0: $(branch(uri)[0]), $(branch(q)[0])\n"); xlog ("=== branch 1: $(branch(uri)[1]), $(branch(q)[1])\n"); revert_uri(); t_load_contacts(); while (t_next_contacts()) { xlog ("==== $ru\n"); } ``` We expect that the branches are rearranged by weight. When t_next_contacts() is called, the $ru is being rewritten with the branch having the highest q value. This behavior changed after upgrading to v5.4.0. The order of the branches is now being reversed.
### Troubleshooting
#### Reproduction
<!-- If the issue can be reproduced, describe how it can be done. -->
#### Debugging Data
<!-- If you got a core dump, use gdb to extract troubleshooting data - full backtrace, local variables and the list of the code at the issue location.
gdb /path/to/kamailio /path/to/corefile bt full info locals list
If you are familiar with gdb, feel free to attach more of what you consider to be relevant. -->
``` (paste your debugging data here) ```
#### Log Messages
In v5.4.0, this is what we're seeing in the logs ``` ERROR: IBG_LOG: sipp-ci1-20200819163846-1-22@172.18.1.21: === branch 0: sip:1001@gateway2.carrierB.com;transport=udp, 200 ERROR: IBG_LOG: sipp-ci1-20200819163846-1-22@172.18.1.21: === branch 1: sip:1001@gateway1.carrierB.com;transport=tcp, 300 DEBUG: IBG_LOG: sipp-ci1-20200819163846-1-22@172.18.1.21: tm [t_serial.c:526]: t_load_contacts(): load_contact mode not selected, using: 0 DEBUG: IBG_LOG: sipp-ci1-20200819163846-1-22@172.18.1.21: tm [t_serial.c:340]: ki_t_load_contacts_mode(): nr_branches is 2 DEBUG: IBG_LOG: sipp-ci1-20200819163846-1-22@172.18.1.21: <core> [core/xavp.c:539]: xavp_destroy_list(): destroying xavp list 0x7fcbe3103e20 DEBUG: IBG_LOG: sipp-ci1-20200819163846-1-22@172.18.1.21: tm [t_serial.c:890]: ki_t_next_contacts(): Appending branch uri-'sip:1001@gateway1.carrierB.com;transport=tcp' dst-'' path-'' inst-'' ruid-'' location_ua-'' DEBUG: IBG_LOG: sipp-ci1-20200819163846-1-22@172.18.1.21: <core> [core/xavp.c:539]: xavp_destroy_list(): destroying xavp list 0x7fcbe3103b68 ERROR: IBG_LOG: sipp-ci1-20200819163846-1-22@172.18.1.21: ==== sip:1001@carrierB DEBUG: IBG_LOG: sipp-ci1-20200819163846-1-22@172.18.1.21: <core> [core/xavp.c:539]: xavp_destroy_list(): destroying xavp list 0x7fcbe3103890 ERROR: IBG_LOG: sipp-ci1-20200819163846-1-22@172.18.1.21: ==== sip:1001@gateway2.carrierB.com;transport=udp DEBUG: IBG_LOG: sipp-ci1-20200819163846-1-22@172.18.1.21: tm [t_serial.c:627]: ki_t_next_contacts(): no contacts in contacts_avp - we are done! ```
This was the behavior in v.5.3.4 ``` ERROR: IBG_LOG: sipp-ci1-20200819172941-1-22@172.18.1.21: === branch 0: sip:1001@gateway2.carrierB.com;transport=udp, 200 ERROR: IBG_LOG: sipp-ci1-20200819172941-1-22@172.18.1.21: === branch 1: sip:1001@gateway1.carrierB.com;transport=tcp, 300 DEBUG: IBG_LOG: sipp-ci1-20200819172941-1-22@172.18.1.21: tm [t_serial.c:191]: ki_t_load_contacts(): nr_branches is 2 DEBUG: IBG_LOG: sipp-ci1-20200819172941-1-22@172.18.1.21: <core> [core/xavp.c:529]: xavp_destroy_list(): destroying xavp list 0x7f55bdf0c1d8 ERROR: IBG_LOG: sipp-ci1-20200819172941-1-22@172.18.1.21: ==== sip:1001@gateway1.carrierB.com;transport=tcp DEBUG: IBG_LOG: sipp-ci1-20200819172941-1-22@172.18.1.21: <core> [core/xavp.c:529]: xavp_destroy_list(): destroying xavp list 0x7f55bdf0bf00 ERROR: IBG_LOG: sipp-ci1-20200819172941-1-22@172.18.1.21: ==== sip:1001@gateway2.carrierB.com;transport=udp DEBUG: IBG_LOG: sipp-ci1-20200819172941-1-22@172.18.1.21: <core> [core/xavp.c:529]: xavp_destroy_list(): destroying xavp list 0x7f55bdf0bc28 ERROR: IBG_LOG: sipp-ci1-20200819172941-1-22@172.18.1.21: ==== sip:1001@carrierB DEBUG: IBG_LOG: sipp-ci1-20200819172941-1-22@172.18.1.21: tm [t_serial.c:460]: ki_t_next_contacts(): no contacts in contacts_avp - we are done! ```
#### SIP Traffic
<!-- If the issue is exposed by processing specific SIP messages, grab them with ngrep or save in a pcap file, then add them next, or attach to issue, or provide a link to download them (e.g., to a pastebin site). -->
``` (paste your sip traffic here) ```
### Possible Solutions
<!-- If you found a solution or workaround for the issue, describe it. Ideally, provide a pull request with a fix. -->
### Additional Information
* **Kamailio Version** - output of `kamailio -v`
``` (paste your output here) ```
* **Operating System**:
<!-- Details about the operating system, the type: Linux (e.g.,: Debian 8.4, Ubuntu 16.04, CentOS 7.1, ...), MacOS, xBSD, Solaris, ...; Kernel details (output of `uname -a`) -->
``` (paste your output here) ```
@marcocapetta - based on history, the commit 1399714fbba63732f94eb8034dabb1e565ca832a seems to be the only one with major changes in this code between 5.3 and 5.4. Can you check if it broke the existing behaviour?
Also, maybe @juha-h can comment on this issue, being the initial developer of these functions, to see what is the expected behaviour and if there is an unwanted change in the last version.
Daniel-Constantin Mierla writes:
Also, maybe @juha-h can comment on this issue, being the initial developer of these functions, to see what is the expected behaviour and if there is an unwanted change in the last version.
Version of tm README before mode param was added tells what the expected behavior of t_load_contacts() is:
Function t_load_contacts() removes all branches from the current destination set and stores them into the XAVP whose name is configured with the parameter contacts_avp. ... If the current destination set contains more than one branch, the function sorts them according to increasing value of the q parameter and then stores the branches in reverse order into the XAVP.
The q parameter of a branch contains a value from range 0-1.0 and it expresses relative preference of the branch among all branches in the destination set. The higher the q value the more preference the user agent gave to the branch. Branches with higher q values will be tried before branches with lower ones when serial forking takes place.
If the behavior is not that anymore, there is a bug that needs to be fixed.
I see no changes in behavior.
My investigation details:
``` root@10f12270eb57:/etc/kamailio# diff -uN kamailio.cfg.orig kamailio.cfg --- kamailio.cfg.orig 2020-08-26 07:10:34.436758338 +0000 +++ kamailio.cfg 2020-08-26 07:40:20.605192222 +0000 @@ -320,6 +320,8 @@ modparam("tm", "fr_timer", 30000) # default invite retransmission timeout after 1xx: 120sec modparam("tm", "fr_inv_timer", 120000) +modparam("tm", "contacts_avp", "tm_contacts") +modparam("tm", "contact_flows_avp", "tm_contacts_flows")
# ----- rr params ----- # set next param to 1 to add value to ;lr param (helps with some UAs) @@ -457,6 +459,11 @@ # ----- debugger params ----- modparam("debugger", "cfgtrace", 1) modparam("debugger", "log_level_name", "exec") +modparam("debugger", "mod_level_mode", 1) +modparam("debugger", "mod_hash_size", 4) +modparam("debugger", "mod_level", "core=1") +modparam("debugger", "mod_level", "xlog=3") +modparam("debugger", "mod_level", "tm=3") #!endif
####### Routing Logic ######## @@ -698,11 +705,25 @@ if (is_method("INVITE")) { setflag(FLT_ACCMISSED); } - + route(TEST); route(RELAY); exit; }
+route[TEST] { + xlog("==== $$ru:$ru\n"); + $var(i) = 0; + while($var(i) < 10) { + xlog ("=== $$branch $var(i): uri:$(branch(uri)[$var(i)]), q:$(branch(q)[$var(i)])\n"); + $var(i) = $var(i) + 1; + } + t_load_contacts(); + while (t_next_contacts()) { + xlog ("==== $$ru:$ru\n"); + } + drop; +} + # Presence server processing route[PRESENCE] { if(!is_method("PUBLISH|SUBSCRIBE")) return; ```
create locations for alice, higher the number, higher the value of q: ``` root@10f12270eb57:/etc/kamailio# for i in 1 2 3 4 5 6 7 8 9; do kamcmd ul.add location alice sip:alice$i@127.0.0.$i:508$i 0 0.$i . 0 0 6111 . .; done ```
kamailio **5.3.4** output: lookup loads the 9 contacts ``` 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[LOCATION] c=[/etc/kamailio/kamailio.cfg] l=689 a=25 n=lookup 2(461) DEBUG: {1 1 INVITE 1-500@172.17.0.3} registrar [lookup.c:306]: lookup_helper(): contact for [alice] found by address 2(461) DEBUG: {1 1 INVITE 1-500@172.17.0.3} registrar [lookup.c:510]: lookup_helper(): instance is 2(461) DEBUG: {1 1 INVITE 1-500@172.17.0.3} registrar [lookup.c:510]: lookup_helper(): instance is 2(461) DEBUG: {1 1 INVITE 1-500@172.17.0.3} registrar [lookup.c:510]: lookup_helper(): instance is 2(461) DEBUG: {1 1 INVITE 1-500@172.17.0.3} registrar [lookup.c:510]: lookup_helper(): instance is 2(461) DEBUG: {1 1 INVITE 1-500@172.17.0.3} registrar [lookup.c:510]: lookup_helper(): instance is 2(461) DEBUG: {1 1 INVITE 1-500@172.17.0.3} registrar [lookup.c:510]: lookup_helper(): instance is 2(461) DEBUG: {1 1 INVITE 1-500@172.17.0.3} registrar [lookup.c:510]: lookup_helper(): instance is 2(461) DEBUG: {1 1 INVITE 1-500@172.17.0.3} registrar [lookup.c:510]: lookup_helper(): instance is ``` checking the branches values and calling t_load_contacts(): ``` 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=714 a=25 n=xlog 2(461) ERROR: {1 1 INVITE 1-500@172.17.0.3} <script>: ==== $ru:sip:alice9@127.0.0.9:5089 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=715 a=63 n=assign 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=719 a=23 n=while 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=717 a=25 n=xlog 2(461) ERROR: {1 1 INVITE 1-500@172.17.0.3} <script>: === $branch 0: uri:sip:alice8@127.0.0.8:5088, q:800 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=718 a=63 n=assign 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=717 a=25 n=xlog 2(461) ERROR: {1 1 INVITE 1-500@172.17.0.3} <script>: === $branch 1: uri:sip:alice7@127.0.0.7:5087, q:700 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=718 a=63 n=assign 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=717 a=25 n=xlog 2(461) ERROR: {1 1 INVITE 1-500@172.17.0.3} <script>: === $branch 2: uri:sip:alice6@127.0.0.6:5086, q:600 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=718 a=63 n=assign 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=717 a=25 n=xlog 2(461) ERROR: {1 1 INVITE 1-500@172.17.0.3} <script>: === $branch 3: uri:sip:alice5@127.0.0.5:5085, q:500 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=718 a=63 n=assign 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=717 a=25 n=xlog 2(461) ERROR: {1 1 INVITE 1-500@172.17.0.3} <script>: === $branch 4: uri:sip:alice4@127.0.0.4:5084, q:400 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=718 a=63 n=assign 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=717 a=25 n=xlog 2(461) ERROR: {1 1 INVITE 1-500@172.17.0.3} <script>: === $branch 5: uri:sip:alice3@127.0.0.3:5083, q:300 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=718 a=63 n=assign 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=717 a=25 n=xlog 2(461) ERROR: {1 1 INVITE 1-500@172.17.0.3} <script>: === $branch 6: uri:sip:alice2@127.0.0.2:5082, q:200 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=718 a=63 n=assign 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=717 a=25 n=xlog 2(461) ERROR: {1 1 INVITE 1-500@172.17.0.3} <script>: === $branch 7: uri:sip:alice1@127.0.0.1:5081, q:100 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=718 a=63 n=assign 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=717 a=25 n=xlog 2(461) ERROR: {1 1 INVITE 1-500@172.17.0.3} <script>: === $branch 8: uri:<null>, q:<null> 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=718 a=63 n=assign 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=717 a=25 n=xlog 2(461) ERROR: {1 1 INVITE 1-500@172.17.0.3} <script>: === $branch 9: uri:<null>, q:<null> 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=718 a=63 n=assign 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=720 a=24 n=t_load_contacts 2(461) DEBUG: {1 1 INVITE 1-500@172.17.0.3} tm [t_serial.c:191]: ki_t_load_contacts(): nr_branches is 8 ``` t_next_contacts() loop: ``` 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=723 a=23 n=while 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=721 a=24 n=t_next_contacts 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=722 a=25 n=xlog 2(461) ERROR: {1 1 INVITE 1-500@172.17.0.3} <script>: ==== $ru:sip:alice9@127.0.0.9:5089 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=721 a=24 n=t_next_contacts 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=722 a=25 n=xlog 2(461) ERROR: {1 1 INVITE 1-500@172.17.0.3} <script>: ==== $ru:sip:alice8@127.0.0.8:5088 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=721 a=24 n=t_next_contacts 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=722 a=25 n=xlog 2(461) ERROR: {1 1 INVITE 1-500@172.17.0.3} <script>: ==== $ru:sip:alice7@127.0.0.7:5087 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=721 a=24 n=t_next_contacts 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=722 a=25 n=xlog 2(461) ERROR: {1 1 INVITE 1-500@172.17.0.3} <script>: ==== $ru:sip:alice6@127.0.0.6:5086 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=721 a=24 n=t_next_contacts 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=722 a=25 n=xlog 2(461) ERROR: {1 1 INVITE 1-500@172.17.0.3} <script>: ==== $ru:sip:alice5@127.0.0.5:5085 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=721 a=24 n=t_next_contacts 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=722 a=25 n=xlog 2(461) ERROR: {1 1 INVITE 1-500@172.17.0.3} <script>: ==== $ru:sip:alice4@127.0.0.4:5084 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=721 a=24 n=t_next_contacts 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=722 a=25 n=xlog 2(461) ERROR: {1 1 INVITE 1-500@172.17.0.3} <script>: ==== $ru:sip:alice3@127.0.0.3:5083 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=721 a=24 n=t_next_contacts 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=722 a=25 n=xlog 2(461) ERROR: {1 1 INVITE 1-500@172.17.0.3} <script>: ==== $ru:sip:alice2@127.0.0.2:5082 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=721 a=24 n=t_next_contacts 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=722 a=25 n=xlog 2(461) ERROR: {1 1 INVITE 1-500@172.17.0.3} <script>: ==== $ru:sip:alice1@127.0.0.1:5081 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=721 a=24 n=t_next_contacts 2(461) DEBUG: {1 1 INVITE 1-500@172.17.0.3} tm [t_serial.c:460]: ki_t_next_contacts(): no contacts in contacts_avp - we are done! 2(461) exec: {1 1 INVITE 1-500@172.17.0.3} *** cfgtrace:request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=724 a=2 n=drop ```
So, everything as expected, q value order is obey.
kamailio **5.4.0** output: lookup loads the 9 contacts ``` 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[LOCATION] c=[/etc/kamailio/kamailio.cfg] l=726 a=25 n=lookup 1(793) DEBUG: {1 1 INVITE 1-834@172.17.0.2} registrar [lookup.c:321]: lookup_helper(): contact for [alice] found by address 1(793) DEBUG: {1 1 INVITE 1-834@172.17.0.2} registrar [lookup.c:525]: lookup_helper(): instance is 1(793) DEBUG: {1 1 INVITE 1-834@172.17.0.2} registrar [lookup.c:525]: lookup_helper(): instance is 1(793) DEBUG: {1 1 INVITE 1-834@172.17.0.2} registrar [lookup.c:525]: lookup_helper(): instance is 1(793) DEBUG: {1 1 INVITE 1-834@172.17.0.2} registrar [lookup.c:525]: lookup_helper(): instance is 1(793) DEBUG: {1 1 INVITE 1-834@172.17.0.2} registrar [lookup.c:525]: lookup_helper(): instance is 1(793) DEBUG: {1 1 INVITE 1-834@172.17.0.2} registrar [lookup.c:525]: lookup_helper(): instance is 1(793) DEBUG: {1 1 INVITE 1-834@172.17.0.2} registrar [lookup.c:525]: lookup_helper(): instance is 1(793) DEBUG: {1 1 INVITE 1-834@172.17.0.2} registrar [lookup.c:525]: lookup_helper(): instance is ``` checking the branches values and calling t_load_contacts(): ``` 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=751 a=25 n=xlog 1(793) ERROR: {1 1 INVITE 1-834@172.17.0.2} <script>: ==== $ru:sip:alice9@127.0.0.9:5089 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=752 a=63 n=assign 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=756 a=23 n=while 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=754 a=25 n=xlog 1(793) ERROR: {1 1 INVITE 1-834@172.17.0.2} <script>: === $branch 0: uri:sip:alice8@127.0.0.8:5088, q:800 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=755 a=63 n=assign 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=754 a=25 n=xlog 1(793) ERROR: {1 1 INVITE 1-834@172.17.0.2} <script>: === $branch 1: uri:sip:alice7@127.0.0.7:5087, q:700 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=755 a=63 n=assign 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=754 a=25 n=xlog 1(793) ERROR: {1 1 INVITE 1-834@172.17.0.2} <script>: === $branch 2: uri:sip:alice6@127.0.0.6:5086, q:600 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=755 a=63 n=assign 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=754 a=25 n=xlog 1(793) ERROR: {1 1 INVITE 1-834@172.17.0.2} <script>: === $branch 3: uri:sip:alice5@127.0.0.5:5085, q:500 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=755 a=63 n=assign 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=754 a=25 n=xlog 1(793) ERROR: {1 1 INVITE 1-834@172.17.0.2} <script>: === $branch 4: uri:sip:alice4@127.0.0.4:5084, q:400 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=755 a=63 n=assign 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=754 a=25 n=xlog 1(793) ERROR: {1 1 INVITE 1-834@172.17.0.2} <script>: === $branch 5: uri:sip:alice3@127.0.0.3:5083, q:300 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=755 a=63 n=assign 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=754 a=25 n=xlog 1(793) ERROR: {1 1 INVITE 1-834@172.17.0.2} <script>: === $branch 6: uri:sip:alice2@127.0.0.2:5082, q:200 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=755 a=63 n=assign 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=754 a=25 n=xlog 1(793) ERROR: {1 1 INVITE 1-834@172.17.0.2} <script>: === $branch 7: uri:sip:alice1@127.0.0.1:5081, q:100 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=755 a=63 n=assign 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=754 a=25 n=xlog 1(793) ERROR: {1 1 INVITE 1-834@172.17.0.2} <script>: === $branch 8: uri:<null>, q:<null> 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=755 a=63 n=assign 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=754 a=25 n=xlog 1(793) ERROR: {1 1 INVITE 1-834@172.17.0.2} <script>: === $branch 9: uri:<null>, q:<null> 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=755 a=63 n=assign 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=757 a=24 n=t_load_contacts 1(793) DEBUG: {1 1 INVITE 1-834@172.17.0.2} tm [t_serial.c:526]: t_load_contacts(): load_contact mode not selected, using: 0 1(793) DEBUG: {1 1 INVITE 1-834@172.17.0.2} tm [t_serial.c:340]: ki_t_load_contacts_mode(): nr_branches is 8 ``` t_next_contacts() loop: ``` 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=760 a=23 n=while 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=758 a=24 n=t_next_contacts 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=759 a=25 n=xlog 1(793) ERROR: {1 1 INVITE 1-834@172.17.0.2} <script>: ==== $ru:sip:alice9@127.0.0.9:5089 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=758 a=24 n=t_next_contacts 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=759 a=25 n=xlog 1(793) ERROR: {1 1 INVITE 1-834@172.17.0.2} <script>: ==== $ru:sip:alice8@127.0.0.8:5088 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=758 a=24 n=t_next_contacts 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=759 a=25 n=xlog 1(793) ERROR: {1 1 INVITE 1-834@172.17.0.2} <script>: ==== $ru:sip:alice7@127.0.0.7:5087 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=758 a=24 n=t_next_contacts 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=759 a=25 n=xlog 1(793) ERROR: {1 1 INVITE 1-834@172.17.0.2} <script>: ==== $ru:sip:alice6@127.0.0.6:5086 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=758 a=24 n=t_next_contacts 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=759 a=25 n=xlog 1(793) ERROR: {1 1 INVITE 1-834@172.17.0.2} <script>: ==== $ru:sip:alice5@127.0.0.5:5085 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=758 a=24 n=t_next_contacts 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=759 a=25 n=xlog 1(793) ERROR: {1 1 INVITE 1-834@172.17.0.2} <script>: ==== $ru:sip:alice4@127.0.0.4:5084 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=758 a=24 n=t_next_contacts 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=759 a=25 n=xlog 1(793) ERROR: {1 1 INVITE 1-834@172.17.0.2} <script>: ==== $ru:sip:alice3@127.0.0.3:5083 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=758 a=24 n=t_next_contacts 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=759 a=25 n=xlog 1(793) ERROR: {1 1 INVITE 1-834@172.17.0.2} <script>: ==== $ru:sip:alice2@127.0.0.2:5082 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=758 a=24 n=t_next_contacts 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=759 a=25 n=xlog 1(793) ERROR: {1 1 INVITE 1-834@172.17.0.2} <script>: ==== $ru:sip:alice1@127.0.0.1:5081 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=758 a=24 n=t_next_contacts 1(793) DEBUG: {1 1 INVITE 1-834@172.17.0.2} tm [t_serial.c:627]: ki_t_next_contacts(): no contacts in contacts_avp - we are done! 1(793) exec: {1 1 INVITE 1-834@172.17.0.2} *** cfgtrace:dbg_cfg_trace(): request_route=[TEST] c=[/etc/kamailio/kamailio.cfg] l=761 a=2 n=drop ```
Everything as expected, q value order is obey, same behavior as I can see
Is it possible that the branches are handled differently when they're added by `append_branch()`?
``` append_branch("sip:1001@gateway1.carrierB.com;transport=tcp", "0.3"); append_branch("sip:1001@gateway2.carrierB.com;transport=tcp", "0.2"); append_branch("sip:1001@gateway3.carrierB.com;transport=tcp", "0.7"); append_branch("sip:1001@gateway4.carrierB.com;transport=tcp", "0.5"); append_branch("sip:1001@gateway5.carrierB.com;transport=tcp", "0.6"); xlog ("=== $(branch(uri)[0]), $(branch(q)[0])\n"); xlog ("=== $(branch(uri)[1]), $(branch(q)[1])\n"); xlog ("=== $(branch(uri)[2]), $(branch(q)[2])\n"); xlog ("=== $(branch(uri)[3]), $(branch(q)[3])\n"); xlog ("=== $(branch(uri)[4]), $(branch(q)[4])\n"); t_load_contacts(); while (t_next_contacts()) { xlog ("==== $ru\n"); } ```
Output: ``` ERROR: sipp-ci1-20200826182056-1-23@172.18.1.21: === sip:1001@gateway1.carrierB.com;transport=tcp, 300 ERROR: sipp-ci1-20200826182056-1-23@172.18.1.21: === sip:1001@gateway2.carrierB.com;transport=tcp, 200 ERROR: sipp-ci1-20200826182056-1-23@172.18.1.21: === sip:1001@gateway3.carrierB.com;transport=tcp, 700 ERROR: sipp-ci1-20200826182056-1-23@172.18.1.21: === sip:1001@gateway4.carrierB.com;transport=tcp, 500 ERROR: sipp-ci1-20200826182056-1-23@172.18.1.21: === sip:1001@gateway5.carrierB.com;transport=tcp, 600 DEBUG: sipp-ci1-20200826182056-1-23@172.18.1.21: tm [t_serial.c:526]: t_load_contacts(): load_contact mode not selected, using: 0 DEBUG: sipp-ci1-20200826182056-1-23@172.18.1.21: tm [t_serial.c:340]: ki_t_load_contacts_mode(): nr_branches is 5 DEBUG: sipp-ci1-20200826182056-1-23@172.18.1.21: <core> [core/xavp.c:539]: xavp_destroy_list(): destroying xavp list 0x7fe88ec9e248 DEBUG: sipp-ci1-20200826182056-1-23@172.18.1.21: tm [t_serial.c:890]: ki_t_next_contacts(): Appending branch uri-'sip:1001@gateway3.carrierB.com;transport=tcp' dst-'' path-'' inst-'' ruid-'' location_ua-'' DEBUG: sipp-ci1-20200826182056-1-23@172.18.1.21: <core> [core/xavp.c:539]: xavp_destroy_list(): destroying xavp list 0x7fe88ec9df90 ERROR: sipp-ci1-20200826182056-1-23@172.18.1.21: ==== sip:1001@carrierB DEBUG: sipp-ci1-20200826182056-1-23@172.18.1.21: <core> [core/xavp.c:539]: xavp_destroy_list(): destroying xavp list 0x7fe88ec9dcb8 ERROR: sipp-ci1-20200826182056-1-23@172.18.1.21: ==== sip:1001@gateway5.carrierB.com;transport=tcp DEBUG: sipp-ci1-20200826182056-1-23@172.18.1.21: <core> [core/xavp.c:539]: xavp_destroy_list(): destroying xavp list 0x7fe88ec9d9e0 ERROR: sipp-ci1-20200826182056-1-23@172.18.1.21: ==== sip:1001@gateway4.carrierB.com;transport=tcp DEBUG: sipp-ci1-20200826182056-1-23@172.18.1.21: <core> [core/xavp.c:539]: xavp_destroy_list(): destroying xavp list 0x7fe88ec9d708 ERROR: sipp-ci1-20200826182056-1-23@172.18.1.21: ==== sip:1001@gateway1.carrierB.com;transport=tcp DEBUG: sipp-ci1-20200826182056-1-23@172.18.1.21: <core> [core/xavp.c:539]: xavp_destroy_list(): destroying xavp list 0x7fe88ec9d430 ERROR: sipp-ci1-20200826182056-1-23@172.18.1.21: ==== sip:1001@gateway2.carrierB.com;transport=tcp DEBUG: sipp-ci1-20200826182056-1-23@172.18.1.21: tm [t_serial.c:627]: ki_t_next_contacts(): no contacts in contacts_avp - we are done! ```
Hi,
El mié., 26 ago. 2020 20:25, Cindy Leung notifications@github.com escribió:
Is it possible that the branches are handled differently when they're added by append_branch()?
append_branch("sip:1001@gateway1.carrierB.com;transport=tcp", "0.3"); append_branch("sip:1001@gateway2.carrierB.com;transport=tcp", "0.2"); append_branch("sip:1001@gateway3.carrierB.com;transport=tcp", "0.7"); append_branch("sip:1001@gateway4.carrierB.com;transport=tcp", "0.5"); append_branch("sip:1001@gateway5.carrierB.com;transport=tcp", "0.6"); xlog ("=== $(branch(uri)[0]), $(branch(q)[0])\n"); xlog ("=== $(branch(uri)[1]), $(branch(q)[1])\n"); xlog ("=== $(branch(uri)[2]), $(branch(q)[2])\n"); xlog ("=== $(branch(uri)[3]), $(branch(q)[3])\n"); xlog ("=== $(branch(uri)[4]), $(branch(q)[4])\n"); t_load_contacts(); while (t_next_contacts()) { xlog ("==== $ru\n"); }
https://www.kamailio.org/docs/modules/devel/modules/tm.html#tm.f.t_load_cont...
Function t_load_contacts() **removes all branches** from the current destination set and stores them into the XAVP whose name is configured with the parameter contacts_avp
It doesn't matter how you're adding branches before. t_load_contacts() will remove them.
So I applied Victor's `route[TEST]` at the beginning of my config and added the usrloc entries. The problem with branches could not be reproduced. Instead of `drop` at the end of `route[TEST]`, I `revert_uri()` so I could continue with my `append_branch` portion. Same result. Here's the log (DEBUG=2).
``` ERROR: sipp-ci1-20200827020223-1-21@172.19.1.21: Entering test route ERROR: sipp-ci1-20200827020223-1-21@172.19.1.21: ==== $ru:sip:alice5@127.0.0.5:5085 ERROR: sipp-ci1-20200827020223-1-21@172.19.1.21: === $branch 0: uri:sip:alice4@127.0.0.4:5084, q:400 ERROR: sipp-ci1-20200827020223-1-21@172.19.1.21: === $branch 1: uri:sip:alice3@127.0.0.3:5083, q:300 ERROR: sipp-ci1-20200827020223-1-21@172.19.1.21: === $branch 2: uri:sip:alice2@127.0.0.2:5082, q:200 ERROR: sipp-ci1-20200827020223-1-21@172.19.1.21: === $branch 3: uri:sip:alice1@127.0.0.1:5081, q:100 ERROR: sipp-ci1-20200827020223-1-21@172.19.1.21: === $branch 4: uri:<null>, q:<null> ERROR: sipp-ci1-20200827020223-1-21@172.19.1.21: ==== $ru:sip:alice5@127.0.0.5:5085 ERROR: sipp-ci1-20200827020223-1-21@172.19.1.21: ==== $ru:sip:alice4@127.0.0.4:5084 ERROR: sipp-ci1-20200827020223-1-21@172.19.1.21: ==== $ru:sip:alice3@127.0.0.3:5083 ERROR: sipp-ci1-20200827020223-1-21@172.19.1.21: ==== $ru:sip:alice2@127.0.0.2:5082 ERROR: sipp-ci1-20200827020223-1-21@172.19.1.21: ==== $ru:sip:alice1@127.0.0.1:5081 ERROR: sipp-ci1-20200827020223-1-21@172.19.1.21: Starting append_branch() sequence ERROR: sipp-ci1-20200827020223-1-21@172.19.1.21: === sip:1001@gateway1.carrierB.com;transport=tcp, 300 ERROR: sipp-ci1-20200827020223-1-21@172.19.1.21: === sip:1001@gateway2.carrierB.com;transport=tcp, 200 ERROR: sipp-ci1-20200827020223-1-21@172.19.1.21: === sip:1001@gateway3.carrierB.com;transport=tcp, 700 ERROR: sipp-ci1-20200827020223-1-21@172.19.1.21: === sip:1001@gateway4.carrierB.com;transport=tcp, 500 ERROR: sipp-ci1-20200827020223-1-21@172.19.1.21: === sip:1001@gateway5.carrierB.com;transport=tcp, 600 ERROR: sipp-ci1-20200827020223-1-21@172.19.1.21: Starting t_next_contacts ERROR: sipp-ci1-20200827020223-1-21@172.19.1.21: ==== sip:alice@carrierB ERROR: sipp-ci1-20200827020223-1-21@172.19.1.21: ==== sip:1001@gateway5.carrierB.com;transport=tcp ERROR: sipp-ci1-20200827020223-1-21@172.19.1.21: ==== sip:1001@gateway4.carrierB.com;transport=tcp ERROR: sipp-ci1-20200827020223-1-21@172.19.1.21: ==== sip:1001@gateway1.carrierB.com;transport=tcp ERROR: sipp-ci1-20200827020223-1-21@172.19.1.21: ==== sip:1001@gateway2.carrierB.com;transport=tcp ```
@cleung-tpn so you could not reproduce it and this issue can be closed?
@henningw That's not what I said. The problem is reproducible if the branches are added using append_branch.
@cleung-tpn can you provide a minimal kamailio.cfg reproducing the issue? You already provided snippets in comments, but somehow I got lost in use of drop or revert_uri() in different places vs what @linuxmaniac tried. When I get some time I can test it with such config and see if I can spot something.
Thanks @miconda, here you go.
``` ####### Global Parameters ######### debug = 2 log_stderror = no log_facility = LOG_LOCAL6 listen = eth0
####### Modules Section ######## # mpath="/usr/lib64/kamailio/modules/"
loadmodule "kex.so" loadmodule "corex.so" loadmodule "tm.so" loadmodule "tmx.so" loadmodule "sl.so" loadmodule "rr.so" loadmodule "pv.so" loadmodule "maxfwd.so" loadmodule "textops.so" loadmodule "siputils.so" loadmodule "xlog.so" loadmodule "sanity.so" loadmodule "ctl.so" loadmodule "debugger.so" loadmodule "htable.so"
# ----- tm params ----- modparam("tm", "failure_reply_mode", 3) modparam("tm", "remap_503_500", 0) modparam("tm", "contacts_avp", "tm_contacts") modparam("tm", "contact_flows_avp", "tm_contact_flows")
# ----- rr params ----- modparam("rr", "enable_full_lr", 0) modparam("rr", "append_fromtag", 1)
# ----- htable params ----- modparam("htable", "htable", "gateways=>size=4")
request_route { if (!is_method("ACK")) { if(t_precheck_trans()) { t_check_trans(); exit; } t_check_trans(); }
if (!sanity_check("1535", "7")) { exit; }
if ( msg:len >= 8192 ) { send_reply("513", "Message too big"); exit; }
if (!mf_process_maxfwd_header("10")) { send_reply("483", "Too Many Hops"); exit; }
if (is_method("OPTIONS")) { send_reply("200","OK"); exit; }
if (has_totag()) { if (is_method("INVITE")) { record_route(); } if (loose_route()) { route(RELAY); } if (is_method("ACK")) { if (t_check_trans()) { route(RELAY); } exit; } send_reply("481", "Call Leg/Transaction Does Not Exist"); exit; }
if (is_method("CANCEL")) { if (t_check_trans()) { route(RELAY); } else { send_reply("481", "Call leg/transaction does not exist"); } exit; } else if (is_method("ACK")) { if (t_check_trans()) { route(RELAY); } exit; }
remove_hf("Route"); record_route();
$var(i) = 1; while ($var(i) < 10) { $sht(gateways=>$var(i)) = "host=" + $_s($var(i).$var(i).$var(i).$var(i)) + ";priority=" + $var(i); xlog ("==== Storing: $sht(gateways=>$var(i))\n"); $var(i) = $var(i) + 1; }
sht_iterator_start("i", "gateways"); while(sht_iterator_next("i")) { append_branch("sip:$rU@$(shtitval(i){param.value,host})", "$_s(0.$(shtitval(i){param.value,priority}))"); } sht_iterator_end("i"); t_load_contacts(); xlog ("Route order:\n"); while (t_next_contacts()) { xlog ("==== $rd\n"); } route(RELAY); }
route[RELAY] { xlog ("L_INFO", "Routing to $rd/$du\n"); t_on_failure("OB_FAILURE"); if (!t_relay()) { sl_reply_error(); } exit; }
failure_route[OB_FAILURE] { if (t_is_canceled()) { xlog("L_INFO", "Transaction cancelled\n"); exit; } if (!t_next_contacts() && $ru==$ou) { send_reply("503", "Service Unavailable"); exit; } t_on_failure("OB_FAILURE"); route(RELAY); exit; } ```
I can confirm there is a change in behaviour between 5.3 and 5.4 (I tested with master, but it is the same code).
I made some small changes to the config to have more debug messages and be able to test with OPTIONS sent by sipsak -- the full config is next:
```
####### Global Parameters ######### debug = 2 log_stderror = no children = 2
####### Modules Section ######## # mpath="/usr/lib64/kamailio/modules/"
loadmodule "jsonrpcs.so" loadmodule "kex.so" loadmodule "corex.so" loadmodule "tm.so" loadmodule "tmx.so" loadmodule "sl.so" loadmodule "rr.so" loadmodule "pv.so" loadmodule "maxfwd.so" loadmodule "textops.so" loadmodule "siputils.so" loadmodule "xlog.so" loadmodule "sanity.so" loadmodule "ctl.so" loadmodule "debugger.so" loadmodule "htable.so"
# ----- tm params ----- modparam("tm", "failure_reply_mode", 3) modparam("tm", "remap_503_500", 0) modparam("tm", "contacts_avp", "tm_contacts") modparam("tm", "contact_flows_avp", "tm_contact_flows")
# ----- rr params ----- modparam("rr", "enable_full_lr", 0) modparam("rr", "append_fromtag", 1)
# ----- htable params ----- modparam("htable", "htable", "gateways=>size=4")
request_route { if (!is_method("ACK")) { if(t_precheck_trans()) { t_check_trans(); exit; } t_check_trans(); }
if (!sanity_check("1535", "7")) { exit; }
if (!mf_process_maxfwd_header("10")) { send_reply("483", "Too Many Hops"); exit; }
if (has_totag()) { if (is_method("INVITE")) { record_route(); } if (loose_route()) { route(RELAY); } if (is_method("ACK")) { if (t_check_trans()) { route(RELAY); } exit; } send_reply("481", "Call Leg/Transaction Does Not Exist"); exit; }
if (is_method("CANCEL")) { if (t_check_trans()) { route(RELAY); } else { send_reply("481", "Call leg/transaction does not exist"); } exit; } else if (is_method("ACK")) { if (t_check_trans()) { route(RELAY); } exit; }
remove_hf("Route"); record_route();
$var(i) = 1; while ($var(i) < 10) { $sht(gateways=>$var(i)) = "host=" + $_s($var(i).$var(i).$var(i).$var(i)) + ";priority=" + $var(i); xnotice("==== Storing: $sht(gateways=>$var(i))\n"); $var(i) = $var(i) + 1; }
sht_iterator_start("i", "gateways"); while(sht_iterator_next("i")) { xnotice("==== Appending: sip:$rU@$(shtitval(i){param.value,host}) - p: $_s(0.$(shtitval(i){param.value,priority}))\n"); append_branch("sip:$rU@$(shtitval(i){param.value,host})", "$_s(0.$(shtitval(i){param.value,priority}))"); } sht_iterator_end("i"); t_load_contacts(); xwarn("Route order:\n"); $var(i) = 1; while (t_next_contacts()) { xinfo("==== $var(i): $ru\n"); $var(i) = $var(i) + 1; } sl_send_reply("404", "Not routing"); exit; route(RELAY); }
route[RELAY] { xlog ("L_INFO", "Routing to $rd/$du\n"); t_on_failure("OB_FAILURE"); if (!t_relay()) { sl_reply_error(); } exit; }
failure_route[OB_FAILURE] { if (t_is_canceled()) { xlog("L_INFO", "Transaction cancelled\n"); exit; } if (!t_next_contacts() && $ru==$ou) { send_reply("503", "Service Unavailable"); exit; } t_on_failure("OB_FAILURE"); route(RELAY); exit; } ```
The output with 5.3 branch was:
``` 1(42162) NOTICE: <script>: ==== Storing: host=1.1.1.1;priority=1 1(42162) NOTICE: <script>: ==== Storing: host=2.2.2.2;priority=2 1(42162) NOTICE: <script>: ==== Storing: host=3.3.3.3;priority=3 1(42162) NOTICE: <script>: ==== Storing: host=4.4.4.4;priority=4 1(42162) NOTICE: <script>: ==== Storing: host=5.5.5.5;priority=5 1(42162) NOTICE: <script>: ==== Storing: host=6.6.6.6;priority=6 1(42162) NOTICE: <script>: ==== Storing: host=7.7.7.7;priority=7 1(42162) NOTICE: <script>: ==== Storing: host=8.8.8.8;priority=8 1(42162) NOTICE: <script>: ==== Storing: host=9.9.9.9;priority=9 1(42162) NOTICE: <script>: ==== Appending: sip:1234@6.6.6.6 - p: 0.6 1(42162) NOTICE: <script>: ==== Appending: sip:1234@7.7.7.7 - p: 0.7 1(42162) NOTICE: <script>: ==== Appending: sip:1234@4.4.4.4 - p: 0.4 1(42162) NOTICE: <script>: ==== Appending: sip:1234@5.5.5.5 - p: 0.5 1(42162) NOTICE: <script>: ==== Appending: sip:1234@2.2.2.2 - p: 0.2 1(42162) NOTICE: <script>: ==== Appending: sip:1234@3.3.3.3 - p: 0.3 1(42162) NOTICE: <script>: ==== Appending: sip:1234@1.1.1.1 - p: 0.1 1(42162) NOTICE: <script>: ==== Appending: sip:1234@9.9.9.9 - p: 0.9 1(42162) NOTICE: <script>: ==== Appending: sip:1234@8.8.8.8 - p: 0.8 1(42162) WARNING: <script>: Route order: 1(42162) INFO: <script>: ==== 1: sip:1234@9.9.9.9 1(42162) INFO: <script>: ==== 2: sip:1234@8.8.8.8 1(42162) INFO: <script>: ==== 3: sip:1234@7.7.7.7 1(42162) INFO: <script>: ==== 4: sip:1234@6.6.6.6 1(42162) INFO: <script>: ==== 5: sip:1234@5.5.5.5 1(42162) INFO: <script>: ==== 6: sip:1234@4.4.4.4 1(42162) INFO: <script>: ==== 7: sip:1234@3.3.3.3 1(42162) INFO: <script>: ==== 8: sip:1234@2.2.2.2 1(42162) INFO: <script>: ==== 9: sip:1234@1.1.1.1 1(42162) INFO: <script>: ==== 10: sip:1234@127.0.0.1 ```
The output with 5.4 (master) is:
``` 1(41335) NOTICE: <script>: ==== Storing: host=1.1.1.1;priority=1 1(41335) NOTICE: <script>: ==== Storing: host=2.2.2.2;priority=2 1(41335) NOTICE: <script>: ==== Storing: host=3.3.3.3;priority=3 1(41335) NOTICE: <script>: ==== Storing: host=4.4.4.4;priority=4 1(41335) NOTICE: <script>: ==== Storing: host=5.5.5.5;priority=5 1(41335) NOTICE: <script>: ==== Storing: host=6.6.6.6;priority=6 1(41335) NOTICE: <script>: ==== Storing: host=7.7.7.7;priority=7 1(41335) NOTICE: <script>: ==== Storing: host=8.8.8.8;priority=8 1(41335) NOTICE: <script>: ==== Storing: host=9.9.9.9;priority=9 1(41335) NOTICE: <script>: ==== Appending: sip:1234@6.6.6.6 - p: 0.6 1(41335) NOTICE: <script>: ==== Appending: sip:1234@7.7.7.7 - p: 0.7 1(41335) NOTICE: <script>: ==== Appending: sip:1234@4.4.4.4 - p: 0.4 1(41335) NOTICE: <script>: ==== Appending: sip:1234@5.5.5.5 - p: 0.5 1(41335) NOTICE: <script>: ==== Appending: sip:1234@2.2.2.2 - p: 0.2 1(41335) NOTICE: <script>: ==== Appending: sip:1234@3.3.3.3 - p: 0.3 1(41335) NOTICE: <script>: ==== Appending: sip:1234@1.1.1.1 - p: 0.1 1(41335) NOTICE: <script>: ==== Appending: sip:1234@9.9.9.9 - p: 0.9 1(41335) NOTICE: <script>: ==== Appending: sip:1234@8.8.8.8 - p: 0.8 1(41335) WARNING: <script>: Route order: 1(41335) INFO: <script>: ==== 1: sip:1234@127.0.0.1 1(41335) INFO: <script>: ==== 2: sip:1234@8.8.8.8 1(41335) INFO: <script>: ==== 3: sip:1234@7.7.7.7 1(41335) INFO: <script>: ==== 4: sip:1234@6.6.6.6 1(41335) INFO: <script>: ==== 5: sip:1234@5.5.5.5 1(41335) INFO: <script>: ==== 6: sip:1234@4.4.4.4 1(41335) INFO: <script>: ==== 7: sip:1234@3.3.3.3 1(41335) INFO: <script>: ==== 8: sip:1234@2.2.2.2 1(41335) INFO: <script>: ==== 9: sip:1234@1.1.1.1 ```
I run kamailio from source directory of each version with the command:
``` ./src/kamailio -f ../kamailio-t-load-contacts-order.cfg -L src/modules/ -w . -a no -E -e -dd ```
The sent an OPTIONS with sipsak:
``` sipsak -s sip:1234@127.0.0.1 ```
The 5.3 keeps the original R-URI, but becomes the last destination, having the priority 0. The 5.4 keeps the original URI on the top of the list and loses the address with highest priority added by append branch.
Checking in to see if a solution is in the works. Thanks.
@cleung-tpn Have you tried to see if reverting the commit 1399714 restore the previous behaviour for you?
@marcocapetta - based on history, the commit [1399714](https://github.com/kamailio/kamailio/commit/1399714fbba63732f94eb8034dabb1e5...) seems to be the only one with major changes in this code between 5.3 and 5.4. Can you check if it broke the existing behaviour?
@marcocapetta - any comments about this?
@henningw, pulled the latest v5.4.2 and reverted 1399714 and tried again. The original behavior is restored.
Not using t_load_contacts() was not giving me a chance earlier to investigate deeply, but finally I got some time and I went on troubleshooting by diff-ing the code and behaviour between the versions and came up with the commit referenced above.
The result of debug messages now looks like in the branch 5.3, based on the tests done before with output posted in one of my comments above, so I haven't spent more time on understanding the changes introduced by proportional mode with the use of q_index field.
Now it prints:
``` 1(5011) WARNING: <script>: Route order: 1(5011) INFO: <script>: ==== 1: sip:101@9.9.9.9 1(5011) INFO: <script>: ==== 2: sip:101@8.8.8.8 1(5011) INFO: <script>: ==== 3: sip:101@7.7.7.7 1(5011) INFO: <script>: ==== 4: sip:101@6.6.6.6 1(5011) INFO: <script>: ==== 5: sip:101@5.5.5.5 1(5011) INFO: <script>: ==== 6: sip:101@4.4.4.4 1(5011) INFO: <script>: ==== 7: sip:101@3.3.3.3 1(5011) INFO: <script>: ==== 8: sip:101@2.2.2.2 1(5011) INFO: <script>: ==== 9: sip:101@1.1.1.1 1(5011) INFO: <script>: ==== 10: sip:101@127.0.0.1 ```
The patch is only in master branch for now.
@cleung-tpn -- if you can test and confirm works as you expect, then I will backport to branch 5.3.
@miconda, it works perfectly!
@cleung-tpn - thanks for testing and feedback! Commit is now backported to branch 5.4.
Closed #2449.
-
Cindy Leung -
Daniel-Constantin Mierla
-
Henning Westerholt
-
juha-h
-
Victor Seva