Hello all,

Just started using v5.4.0 on our system and I noticed a change in behavior when doing the append_branch, t_load_contacts, and t_next_contacts combo.  Previously using v5.3.4 and it appears to be fine.

Here's the call scenario: Kamailio receives a call to sip:1001@carrierB.  Kamailio sees carrierB and appends 2 contacts: gateway1.carrierB.com;q=0.3 and gateway2.carrierB.com;q=0.2.  After t_load_branches(0), I expect to see $rd to be changed to gateway1.carrierB.com, but it's not.

This is the piece of config I'm trying to debug:
        xlog ("=== branch 0: $(branch(uri)[0]), $(branch(q)[0])\n");
    xlog ("=== branch 1: $(branch(uri)[1]), $(branch(q)[1])\n");
    t_load_contacts(0);
    while (t_next_contacts()) {
        xlog ("=== rd = $rd\n");
    }


This is the log I get.  It appears to use the backup contact first.
ERROR: IBG_LOG: sipp-ci1-20200818053427-1-23@172.18.1.21: === branch 0: sip:1001@gateway2.carrierB.com;transport=udp, 200
ERROR: IBG_LOG: sipp-ci1-20200818053427-1-23@172.18.1.21: === branch 1: sip:1001@gateway1.carrierB.com;transport=tcp, 300
DEBUG: IBG_LOG: sipp-ci1-20200818053427-1-23@172.18.1.21: tm [t_serial.c:522]: t_load_contacts(): load_contact mode selected: 0
DEBUG: IBG_LOG: sipp-ci1-20200818053427-1-23@172.18.1.21: tm [t_serial.c:340]: ki_t_load_contacts_mode(): nr_branches is 2
DEBUG: IBG_LOG: sipp-ci1-20200818053427-1-23@172.18.1.21: <core> [core/xavp.c:539]: xavp_destroy_list(): destroying xavp list 0x7f983cb66608
DEBUG: IBG_LOG: sipp-ci1-20200818053427-1-23@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-20200818053427-1-23@172.18.1.21: <core> [core/xavp.c:539]: xavp_destroy_list(): destroying xavp list 0x7f983cb66350
ERROR: IBG_LOG: sipp-ci1-20200818053427-1-23@172.18.1.21: === rd = carrierB
DEBUG: IBG_LOG: sipp-ci1-20200818053427-1-23@172.18.1.21: <core> [core/xavp.c:539]: xavp_destroy_list(): destroying xavp list 0x7f983cb66078
ERROR: IBG_LOG: sipp-ci1-20200818053427-1-23@172.18.1.21: === rd = gateway2.carrierB.com
DEBUG: IBG_LOG: sipp-ci1-20200818053427-1-23@172.18.1.21: tm [t_serial.c:627]: ki_t_next_contacts(): no contacts in contacts_avp - we are done!


t_load_contacts(1) works a little better.  But we don't need the probability feature.
ERROR: IBG_LOG: sipp-ci1-20200818054736-1-21@172.18.1.21: === branch 0: sip:1001@gateway2.carrierB.com;transport=udp, 200
ERROR: IBG_LOG: sipp-ci1-20200818054736-1-21@172.18.1.21: === branch 1: sip:1001@gateway1.carrierB.com;transport=tcp, 300
DEBUG: IBG_LOG: sipp-ci1-20200818054736-1-21@172.18.1.21: tm [t_serial.c:522]: t_load_contacts(): load_contact mode selected: 1
DEBUG: IBG_LOG: sipp-ci1-20200818054736-1-21@172.18.1.21: tm [t_serial.c:340]: ki_t_load_contacts_mode(): nr_branches is 2
DEBUG: IBG_LOG: sipp-ci1-20200818054736-1-21@172.18.1.21: tm [t_serial.c:280]: t_load_contacts_proportional(): proportionally selected contact with uri: sip:1001@gateway1.carrierB.com;transport=tcp (q: 300, random: 287, q_index: 500, q_total: 500)
DEBUG: IBG_LOG: sipp-ci1-20200818054736-1-21@172.18.1.21: tm [t_serial.c:280]: t_load_contacts_proportional(): proportionally selected contact with uri: sip:1001@gateway2.carrierB.com;transport=udp (q: 200, random: 157, q_index: 200, q_total: 200)
DEBUG: IBG_LOG: sipp-ci1-20200818054736-1-21@172.18.1.21: tm [t_serial.c:303]: t_load_contacts_proportional(): proportionally added backup contact with uri: sip:1001@carrierB SIP/2.0#015#012Via: SIP/2.0/UDP 172.18.1.21:5060;branch=z9hG4bK-21-1-0 blah blah blah (q: -1)
DEBUG: IBG_LOG: sipp-ci1-20200818054736-1-21@172.18.1.21: <core> [core/xavp.c:539]: xavp_destroy_list(): destroying xavp list 0x7f6e457ec078
ERROR: IBG_LOG: sipp-ci1-20200818054736-1-21@172.18.1.21: === rd = gateway1.carrierB.com
DEBUG: IBG_LOG: sipp-ci1-20200818054736-1-21@172.18.1.21: <core> [core/xavp.c:539]: xavp_destroy_list(): destroying xavp list 0x7f6e457ec350
ERROR: IBG_LOG: sipp-ci1-20200818054736-1-21@172.18.1.21: === rd = gateway2.carrierB.com
DEBUG: IBG_LOG: sipp-ci1-20200818054736-1-21@172.18.1.21: <core> [core/xavp.c:539]: xavp_destroy_list(): destroying xavp list 0x7f6e457ec608
ERROR: IBG_LOG: sipp-ci1-20200818054736-1-21@172.18.1.21: === rd = carrierB
DEBUG: IBG_LOG: sipp-ci1-20200818054736-1-21@172.18.1.21: tm [t_serial.c:627]: ki_t_next_contacts(): no contacts in contacts_avp - we are done!


As a comparison, this is what we've been getting in 5.3.4
ERROR: IBG_LOG: sipp-ci1-20200818055736-1-21@172.18.1.21: === branch 0: sip:1001@gateway2.carrierB.com;transport=udp, 200
ERROR: IBG_LOG: sipp-ci1-20200818055736-1-21@172.18.1.21: === branch 1: sip:1001@gateway1.carrierB.com;transport=tcp, 300
DEBUG: IBG_LOG: sipp-ci1-20200818055736-1-21@172.18.1.21: tm [t_serial.c:191]: ki_t_load_contacts(): nr_branches is 2
DEBUG: IBG_LOG: sipp-ci1-20200818055736-1-21@172.18.1.21: <core> [core/xavp.c:529]: xavp_destroy_list(): destroying xavp list 0x7fe13146a680
ERROR: IBG_LOG: sipp-ci1-20200818055736-1-21@172.18.1.21: === rd = gateway1.carrierB.com
DEBUG: IBG_LOG: sipp-ci1-20200818055736-1-21@172.18.1.21: <core> [core/xavp.c:529]: xavp_destroy_list(): destroying xavp list 0x7fe13146a3a8
ERROR: IBG_LOG: sipp-ci1-20200818055736-1-21@172.18.1.21: === rd = gateway2.carrierB.com
DEBUG: IBG_LOG: sipp-ci1-20200818055736-1-21@172.18.1.21: <core> [core/xavp.c:529]: xavp_destroy_list(): destroying xavp list 0x7fe13146a0d0
ERROR: IBG_LOG: sipp-ci1-20200818055736-1-21@172.18.1.21: === rd = carrierB
DEBUG: IBG_LOG: sipp-ci1-20200818055736-1-21@172.18.1.21: tm [t_serial.c:460]: ki_t_next_contacts(): no contacts in contacts_avp - we are done!


Is there anything else that's been changed in branch building that we should pay attention to?  Thanks.



Cindy