[sr-dev] git:master:d6b1c20d: tm: restore X/AVP values from initial transaction in DNS failover processing

Henning Westerholt hw at gilawa.com
Thu Aug 11 15:30:55 CEST 2022


Hi Daniel,

Thanks for the feedback. I have done a lot of tests on my setup, but of course it’s a complicated module.

The relevant function part is called when the DNS failover is executed, to my understanding like this:

1. INVITE is sent to proxy (auth challenge etc..)
2. proxy is sending to DNS domain
3. DNS domain is resolved to two A records, first IP is chosen
4. proxy sends INVITE to first IP
5. IP does not reply, tm timeout is triggered
6. X/AVP context gets lost, probably due to cleanup from core (this will cleanup internal X/AVP list)
7. add_uac_dns_fallback function is executed, restore X/AVP list from transaction
8. INVITE is sent to second IP
9. Call is established
10. Cleanup is done again to delete internal X/AVP list

See below for an example call log with added local debugging before the fix. TM timeout is 5s.

First INVITE:

Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <script>: got request INVITE to sip:customer-2 at sip01.tst.nbg.domain.net from 116.203.XX.XX:5095
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <core> [core/xavp.c:1258]: xavu_get_internal(): name _tps_, list (nil), prv (nil)
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <core> [core/xavp.c:1258]: xavu_get_internal(): name _tps_, list (nil), prv (nil)
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <core> [core/xavp.c:1258]: xavu_get_internal(): name b_contact, list 0x7ffd5e5e9570, prv (nil)
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <script>: set XAVPs
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <script>: received call customer-2 from customer group 0 (116.203.XX.XX)
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24655]: INFO: {1 14601 ACK Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <script>: received call customer-2 from customer group 0 (116.203.XX.XX)
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24655]: INFO: {1 14601 ACK Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <core> [core/xavp.c:1222]: xavu_reset_list(): resetting list
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24655]: INFO: {1 14601 ACK Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <core> [core/receive.c:628]: receive_msg(): cleaning up
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} tm [t_funcs.c:244]: t_relay_to(): 1
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} tm [h_table.c:373]: build_cell(): setting list in new context
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <core> [core/xavp.c:1236]: xavu_set_list(): setting list 0x7fc9a0421c68
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} tm [t_hooks.c:344]: run_reqin_callbacks_internal(): backup AVPs
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <core> [core/xavp.c:1236]: xavu_set_list(): setting list 0x7fc9a0421c68
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} tm [t_hooks.c:360]: run_reqin_callbacks_internal(): restore backup AVPs
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <core> [core/xavp.c:1236]: xavu_set_list(): setting list 0x7fc9a0421c68
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} tm [t_funcs.c:289]: t_relay_to(): 2: T 0x7fc9a0421a30, XAVU 0x7fc9a041ebb0
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} tm [t_funcs.c:342]: t_relay_to(): 3: T 0x7fc9a0421a30, XAVU 0x7fc9a041ebb0
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} tm [t_fwd.c:1642]: t_forward_nonack(): 1, T: 0x7fc9a0421a30, XAVU 0x7fc9a041ebb0
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} tm [t_fwd.c:1690]: t_forward_nonack(): 2, T: 0x7fc9a0421a30, XAVU 0x7fc9a041ebb0
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} tm [t_fwd.c:1776]: t_forward_nonack(): 3, T: 0x7fc9a0421a30, XAVU 0x7fc9a041ebb0
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <core> [core/xavp.c:1258]: xavu_get_internal(): name _tps_, list (nil), prv (nil)
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <core> [core/xavp.c:1559]: xavu_get_child(): ravp 0x7fc9a041ebb0, xavu current list 0x7fc9a0421c68
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <core> [core/xavp.c:1562]: xavu_get_child(): ravp 0x7fc9a041ebb0, type 6, xavu current list 0x7fc9a0421c68
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <core> [core/xavp.c:1258]: xavu_get_internal(): name a_contact, list 0x7ffd5e5e11f0, prv (nil)
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <core> [core/xavp.c:1258]: xavu_get_internal(): name _tps_, list (nil), prv (nil)
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <core> [core/xavp.c:1559]: xavu_get_child(): ravp 0x7fc9a041ebb0, xavu current list 0x7fc9a0421c68
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <core> [core/xavp.c:1562]: xavu_get_child(): ravp 0x7fc9a041ebb0, type 6, xavu current list 0x7fc9a0421c68
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <core> [core/xavp.c:1258]: xavu_get_internal(): name contact_host, list 0x7ffd5e5e11f0, prv (nil)
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <core> [core/xavp.c:1258]: xavu_get_internal(): name _tps_, list (nil), prv (nil)
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <core> [core/xavp.c:1559]: xavu_get_child(): ravp 0x7fc9a041ebb0, xavu current list 0x7fc9a0421c68
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <core> [core/xavp.c:1562]: xavu_get_child(): ravp 0x7fc9a041ebb0, type 6, xavu current list 0x7fc9a0421c68
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <core> [core/xavp.c:1258]: xavu_get_internal(): name b_contact, list 0x7ffd5e5e11f0, prv (nil)
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <core> [core/xavp.c:1258]: xavu_get_internal(): name _tps_, list (nil), prv (nil)
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <core> [core/xavp.c:1559]: xavu_get_child(): ravp 0x7fc9a041ebb0, xavu current list 0x7fc9a0421c68
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <core> [core/xavp.c:1562]: xavu_get_child(): ravp 0x7fc9a041ebb0, type 6, xavu current list 0x7fc9a0421c68
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <core> [core/xavp.c:1258]: xavu_get_internal(): name contact_host, list 0x7ffd5e5e11f0, prv (nil)
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <core> [core/xavp.c:1222]: xavu_reset_list(): resetting list
Aug  9 09:56:09 kam01 /usr/local/kamailio-devel/sbin/kamailio[24652]: INFO: {1 14602 INVITE Kt5POLYd9pvtxqx1idXSgNqZ4OFkSxOS} <core> [core/receive.c:628]: receive_msg(): cleaning up

DNS failover:

Aug  9 09:56:11 kam01 /usr/local/kamailio-devel/sbin/kamailio[24672]: INFO: <core> [core/xavp.c:1222]: xavu_reset_list(): resetting list
Aug  9 09:56:11 kam01 /usr/local/kamailio-devel/sbin/kamailio[24672]: INFO: <core> [core/receive.c:628]: receive_msg(): cleaning up
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24665]: INFO: tm [h_table.c:132]: free_cell_helper(): freeing transaction 0x7fc9a041b288 from timer.c:650
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24665]: INFO: tm [t_hooks.c:247]: run_trans_callbacks_internal(): backup AVPs
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24665]: INFO: <core> [core/xavp.c:1236]: xavu_set_list(): setting list 0x7fc9a041b4c0
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24665]: INFO: tm [t_hooks.c:269]: run_trans_callbacks_internal(): restore backup AVPs
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24665]: INFO: <core> [core/xavp.c:1236]: xavu_set_list(): setting list 0x561157559088
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24664]: INFO: tm [t_fwd.c:1012]: add_uac_dns_fallback(): 1: T 0x7fc9a0421a30, XAVU list 0x7fc9a041ebb0
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24664]: INFO: tm [t_fwd.c:1047]: add_uac_dns_fallback(): 2: T 0x7fc9a0421a30, XAVU list 0x7fc9a041ebb0
(Print the transaction X/AVP list below)
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24664]: INFO: <core> [core/xavp.c:689]: xavx_print_list_content(): +++++ start XAVU list: 0x7fc9a041ebb0 (0x7fc9a0421c68) (level=0)
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24664]: INFO: <core> [core/xavp.c:693]: xavx_print_list_content():      *** (l:0 - 0x7fc9a041ebb0) XAVU name: _tps_
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24664]: INFO: <core> [core/xavp.c:694]: xavx_print_list_content():      XAVU id: 1420310448
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24664]: INFO: <core> [core/xavp.c:695]: xavx_print_list_content():      XAVU value type: 6
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24664]: INFO: <core> [core/xavp.c:717]: xavx_print_list_content():      XAVU value: <xavp:0x7fc9a0421428>
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24664]: INFO: <core> [core/xavp.c:689]: xavx_print_list_content(): +++++ start XAVU list: 0x7fc9a0421428 (0x7fc9a041ebd0) (level=1)
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24664]: INFO: <core> [core/xavp.c:693]: xavx_print_list_content():      *** (l:1 - 0x7fc9a0421428) XAVU name: b_contact
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24664]: INFO: <core> [core/xavp.c:694]: xavx_print_list_content():      XAVU id: 3522184920
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24664]: INFO: <core> [core/xavp.c:695]: xavx_print_list_content():      XAVU value type: 2
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24664]: INFO: <core> [core/xavp.c:704]: xavx_print_list_content():      XAVU value (str): sbc_b
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24664]: INFO: <core> [core/xavp.c:730]: xavx_print_list_content():      *** (l:1 - 0x7fc9a0421428) end
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24664]: INFO: <core> [core/xavp.c:693]: xavx_print_list_content():      *** (l:1 - 0x7fc9a041eb00) XAVU name: a_contact
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24664]: INFO: <core> [core/xavp.c:694]: xavx_print_list_content():      XAVU id: 3511692759
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24664]: INFO: <core> [core/xavp.c:695]: xavx_print_list_content():      XAVU value type: 2
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24664]: INFO: <core> [core/xavp.c:704]: xavx_print_list_content():      XAVU value (str): sbc_a
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24664]: INFO: <core> [core/xavp.c:730]: xavx_print_list_content():      *** (l:1 - 0x7fc9a041eb00) end
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24664]: INFO: <core> [core/xavp.c:733]: xavx_print_list_content(): ----- end XAVU list: 0x7fc9a0421428 (level=1)
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24664]: INFO: <core> [core/xavp.c:730]: xavx_print_list_content():      *** (l:0 - 0x7fc9a041ebb0) end
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24664]: INFO: <core> [core/xavp.c:733]: xavx_print_list_content(): ----- end XAVU list: 0x7fc9a041ebb0 (level=0)
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24664]: INFO: <core> [core/xavp.c:1258]: xavu_get_internal(): name _tps_, list (nil), prv (nil)
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24664]: INFO: <core> [core/xavp.c:1559]: xavu_get_child(): ravp (nil), xavu current list 0x561157559088
(Topos does not find any AVPs)
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24664]: ERROR: topos [tps_storage.c:331]: tps_storage_fill_contact(): could not evaluate a_contact xavu
Aug  9 09:56:14 kam01 /usr/local/kamailio-devel/sbin/kamailio[24664]: ERROR: topos [tps_storage.c:615]: tps_storage_record(): failed to store


For completeness here a successful call after the fix, here the trace shows that the cleanup is called after every INVITE (only added one log to the cleanup):

First INVITE:

Aug 11 13:05:00 kam01 /usr/local/kamailio-devel/sbin/kamailio[30646]: INFO: {2 14468 INVITE Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <script>: incoming reply 407 - Proxy Authentication Required in reply_route
Aug 11 13:05:00 kam01 /usr/local/kamailio-devel/sbin/kamailio[30646]: ERROR: {2 14468 INVITE Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <core> [core/receive.c:628]: receive_msg(): cleaning up
Aug 11 13:05:00 kam01 /usr/local/kamailio-devel/sbin/kamailio[30661]: INFO: {1 14468 ACK Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <script>: got request ACK to sip:customer-2 at sip01.tst.nbg.domain.net from 116.203.XX.XX:5095
Aug 11 13:05:00 kam01 /usr/local/kamailio-devel/sbin/kamailio[30661]: INFO: {1 14468 ACK Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <script>: set XAVPs
Aug 11 13:05:00 kam01 /usr/local/kamailio-devel/sbin/kamailio[30661]: ERROR: {1 14468 ACK Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <core> [core/receive.c:628]: receive_msg(): cleaning up
Aug 11 13:05:00 kam01 /usr/local/kamailio-devel/sbin/kamailio[30661]: INFO: {1 14469 INVITE Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <script>: got request INVITE to sip:customer-2 at sip01.tst.nbg.domain.net from 116.203.XX.XX:5095
Aug 11 13:05:00 kam01 /usr/local/kamailio-devel/sbin/kamailio[30661]: INFO: {1 14469 INVITE Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <script>: set XAVPs
Aug 11 13:05:00 kam01 /usr/local/kamailio-devel/sbin/kamailio[30661]: ERROR: {1 14469 INVITE Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <core> [core/receive.c:628]: receive_msg(): cleaning up

DNS Failover:

Aug 11 13:05:05 kam01 /usr/local/kamailio-devel/sbin/kamailio[30643]: INFO: {2 14469 INVITE Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <script>: incoming reply 100 - trying -- your call is important to us in reply_route
Aug 11 13:05:05 kam01 /usr/local/kamailio-devel/sbin/kamailio[30643]: ERROR: {2 14469 INVITE Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <core> [core/receive.c:628]: receive_msg(): cleaning up
Aug 11 13:05:05 kam01 /usr/local/kamailio-devel/sbin/kamailio[30642]: INFO: {1 14469 INVITE Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <script>: got request INVITE to sip:customer-2 at 116.203.XX.XX:5066;ob from 116.203.YY.YY:5060
Aug 11 13:05:05 kam01 /usr/local/kamailio-devel/sbin/kamailio[30642]: INFO: {1 14469 INVITE Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <script>: set XAVPs
Aug 11 13:05:05 kam01 /usr/local/kamailio-devel/sbin/kamailio[30642]: ERROR: {1 14469 INVITE Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <script>: routing out
Aug 11 13:05:05 kam01 /usr/local/kamailio-devel/sbin/kamailio[30642]: INFO: {1 14469 INVITE Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <script>: relayed INVITE to sip:customer-2 at 116.203.XX.XX:5066;ob over <null> with udp:116.203.YY.YY:5060
Aug 11 13:05:05 kam01 /usr/local/kamailio-devel/sbin/kamailio[30642]: ERROR: {1 14469 INVITE Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <core> [core/receive.c:628]: receive_msg(): cleaning up
Aug 11 13:05:05 kam01 /usr/local/kamailio-devel/sbin/kamailio[30657]: INFO: {2 14469 INVITE Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <script>: incoming reply 100 - Trying in reply_route
Aug 11 13:05:05 kam01 /usr/local/kamailio-devel/sbin/kamailio[30657]: ERROR: {2 14469 INVITE Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <core> [core/receive.c:628]: receive_msg(): cleaning up
Aug 11 13:05:07 kam01 /usr/local/kamailio-devel/sbin/kamailio[30658]: INFO: {2 14469 INVITE Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <script>: incoming reply 603 - Decline in reply_route
Aug 11 13:05:07 kam01 /usr/local/kamailio-devel/sbin/kamailio[30658]: ERROR: {2 14469 INVITE Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <core> [core/receive.c:628]: receive_msg(): cleaning up
Aug 11 13:05:07 kam01 /usr/local/kamailio-devel/sbin/kamailio[30640]: INFO: {1 14469 ACK Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <script>: got request ACK to sip:customer-2 at 116.203.XX.XX:5066;ob from 116.203.YY.YY:5060
Aug 11 13:05:07 kam01 /usr/local/kamailio-devel/sbin/kamailio[30640]: INFO: {1 14469 ACK Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <script>: set XAVPs
Aug 11 13:05:07 kam01 /usr/local/kamailio-devel/sbin/kamailio[30640]: INFO: {1 14469 ACK Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <script>: relayed ACK to sip:customer-2 at 116.203.XX.XX:5066;ob over <null> with udp:116.203.YY.YY:5060
Aug 11 13:05:07 kam01 /usr/local/kamailio-devel/sbin/kamailio[30640]: ERROR: {1 14469 ACK Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <core> [core/receive.c:628]: receive_msg(): cleaning up
Aug 11 13:05:07 kam01 /usr/local/kamailio-devel/sbin/kamailio[30641]: INFO: {2 14469 INVITE Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <script>: incoming reply 603 - Decline in reply_route
Aug 11 13:05:07 kam01 /usr/local/kamailio-devel/sbin/kamailio[30641]: ERROR: {2 14469 INVITE Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <core> [core/receive.c:628]: receive_msg(): cleaning up
Aug 11 13:05:07 kam01 /usr/local/kamailio-devel/sbin/kamailio[30659]: INFO: {1 14469 ACK Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <script>: got request ACK to sip:customer-2 at sip01.tst.nbg.domain.net from 116.203.XX.XX:5095
Aug 11 13:05:07 kam01 /usr/local/kamailio-devel/sbin/kamailio[30659]: INFO: {1 14469 ACK Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <script>: set XAVPs
Aug 11 13:05:07 kam01 /usr/local/kamailio-devel/sbin/kamailio[30659]: ERROR: {1 14469 ACK Y0VBO45pTjq3fmfpSLGngyq2F6UMaR5f} <core> [core/receive.c:628]: receive_msg(): cleaning up

Cheers,

Henning

-- 
Henning Westerholt – https://skalatan.de/blog/
Kamailio services – https://gilawa.com

-----Original Message-----
From: Daniel-Constantin Mierla <miconda at gmail.com> 
Sent: Thursday, August 11, 2022 10:47 AM
To: Kamailio (SER) - Development Mailing List <sr-dev at lists.kamailio.org>; Henning Westerholt <hw at gilawa.com>
Subject: Re: [sr-dev] git:master:d6b1c20d: tm: restore X/AVP values from initial transaction in DNS failover processing

Hello,

I haven't looked in the code to try to figure out the execution paths to this function and where ends up afterwards, so more for safety: have you checked that there are no other X/AVPs set at that moment, or if they are they are restored later?

Usually when setting x/avps lists, the old ones have to be restored in order to be sure it does not end up in memory leaks (or the old ones have to be cleaned up).

Cheers,
Daniel

On 09.08.22 16:16, Henning Westerholt wrote:
> Module: kamailio
> Branch: master
> Commit: d6b1c20d3ad94d9136cf247e67b7fc0d32b18d3b
> URL: 
> https://github.com/kamailio/kamailio/commit/d6b1c20d3ad94d9136cf247e67
> b7fc0d32b18d3b
>
> Author: Henning Westerholt <hw at gilawa.com>
> Committer: Henning Westerholt <hw at gilawa.com>
> Date: 2022-08-09T14:11:59Z
>
> tm: restore X/AVP values from initial transaction in DNS failover 
> processing
>
> - restore X/AVP values from initial transaction in DNS failover 
> processing
> - the X/AVP context gets lost, so we need to re-create it from the 
> transaction
> - otherwise modules that depends on the X/AVPs, e.g. topology hiding 
> will not work
> - tested with one load-balancer and two proxy servers
>
> ---
>
> Modified: src/modules/tm/t_fwd.c
>
> ---
>
> Diff:  
> https://github.com/kamailio/kamailio/commit/d6b1c20d3ad94d9136cf247e67
> b7fc0d32b18d3b.diff
> Patch: 
> https://github.com/kamailio/kamailio/commit/d6b1c20d3ad94d9136cf247e67
> b7fc0d32b18d3b.patch
>
> ---
>
> diff --git a/src/modules/tm/t_fwd.c b/src/modules/tm/t_fwd.c index 
> fbcf1b3e02..6b26f28f6a 100644
> --- a/src/modules/tm/t_fwd.c
> +++ b/src/modules/tm/t_fwd.c
> @@ -1042,6 +1042,8 @@ int add_uac_dns_fallback(struct cell *t, struct sip_msg* msg,
>  		t->uac[t->nr_of_outgoings].on_branch_failure = old_uac->on_branch_failure;
>  		/* copy branch flags */
>  		t->uac[t->nr_of_outgoings].branch_flags = old_uac->branch_flags;
> +		/* restore X/AVP values from initial transaction */
> +		tm_xdata_swap(t, 0, 0);
>  
>  		if (cfg_get(tm, tm_cfg, reparse_on_dns_failover)){
>  			/* Reuse the old buffer and only replace the via header.
>
>
> _______________________________________________
> Kamailio (SER) - Development Mailing List sr-dev at lists.kamailio.org 
> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-dev

--
Daniel-Constantin Mierla -- www.asipto.com www.twitter.com/miconda -- www.linkedin.com/in/miconda



More information about the sr-dev mailing list