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

11 Aug 2022

Hello,

my concert was related to what happens between 5/6 and 7. If it is a udp
retransmission timeout, then 7 is done in (another) timer process. If it
is tcp/tls connect timeout, it can be another worker (?!?) process. Then
I am not sure if any branch failure route could get executed (I think
there is something on tracker about it or on list discussions) before
add_uac_dns_fallback() where one can add x/avps.

What I wanted to cover is that when the tm x/avps are set back, in the
eventuality that there were other x/avps set in the global core lists,
they are not lost, either by freeing them or restore them after the does
the work related to next address in the DNS-based re-routing.

Usually, doing a x/avps swap should be followed by a swap back to
initial lists. However, in this case could be the case that the core
lists are null always, but I wanted to check if you analysed that and it
is so. Otherwise, maybe just calling ksr_msg_env_reset() before the swap
would make it sure there is no leak and the future will tell if
something else got side effects by losing eventual existing x/avps.

Cheers,
Daniel

On 11.08.22 15:30, Henning Westerholt wrote:
...
  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@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@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@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@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@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@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@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@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 &lt;miconda(a)gmail.com&gt; 
 Sent: Thursday, August 11, 2022 10:47 AM
 To: Kamailio (SER) - Development Mailing List &lt;sr-dev(a)lists.kamailio.org&gt;rg>; Henning
Westerholt &lt;hw(a)gilawa.com&gt;
 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 &lt;hw(a)gilawa.com&gt;
 Committer: Henning Westerholt &lt;hw(a)gilawa.com&gt;
 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(a)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
 -- 
Daniel-Constantin Mierla -- www.asipto.com
www.twitter.com/miconda -- www.linkedin.com/in/miconda

2025

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009

2008

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