Hi all,

I've dug into this a bit more. Firstly I enabled debug logs and spotted the following record-route header being loaded from redis:

21(28) DEBUG: PY3 {ACK}: topos_redis [topos_redis_storage.c:1079]: tps_redis_load_dialog(): r[5]: s[<sip:172.24.0.10:5070;sn=internal;r2=on;lr;ftag=2023101722345500002;did=c1f.18b1;nat=yes>,<sip:127.0.0.8;line=sr-N6IAzBFlWJZLWxP7WBN7z.VXN6ZQNUKJoSIBzwVLHRQ7z6fLz6g43RNQMByLMlFAM.NLMBM4W.jAMxyAMB1qCRPQ3ltEOBFZ3BFXoEt4H9IINA**>]

127.0.0.8 is the wrong IP which explains why the ACK was not being forwarded correctly. A quick look in the source shows it's related to topoh.

I had modparam("topoh", "mask_callid", 1) in my config so I disabled it and sure enough the ACK worked as expected which gets me a bit closer to finding the issue.

Looking at the docs for topos and topoh it looks like things have changed since I used it last and I should be using the following instead:

modparam("topoh", "use_mode", 1)
modparam("topos", "mask_callid", 1)

But with those configured things go really wrong:

18(25) CRITICAL: PY3 {INVITE}: <core> [core/mem/q_malloc.c:501]: qm_free(): BUG: bad pointer 0x7ffc73e3ca90 (out of memory block!) called from core: core/data_lump.c: free_lump(470) - ignoring
5(11) ERROR: <core> [core/msg_translator.c:2241]: build_req_buf_from_sip_req(): could not allocate private memory from pkg pool
5(11) ERROR: topos [topos_mod.c:518]: tps_msg_received(): not enough pkg memory for new message
5(11) CRITICAL: <core> [core/mem/q_malloc.c:501]: qm_free(): BUG: bad pointer 0x2 (out of memory block!) called from core: core/data_lump.c: free_lump(470) - ignoring
5(11) INFO: <core> [core/parser/parse_fline.c:80]: parse_first_line(): message too short: 0 []
5(11) ERROR: <core> [core/parser/parse_fline.c:271]: parse_first_line(): parse_first_line: bad message (offset: 0)
5(11) ERROR: <core> [core/parser/msg_parser.c:748]: parse_msg(): ERROR: parse_msg: message=<>
5(11) ERROR: <core> [core/receive.c:376]: receive_msg(): core parsing of SIP message failed (172.24.0.21:5070/1)
3(9) ERROR: <core> [core/msg_translator.c:2241]: build_req_buf_from_sip_req(): could not allocate private memory from pkg pool
3(9) ERROR: topos [topos_mod.c:518]: tps_msg_received(): not enough pkg memory for new message
3(9) CRITICAL: <core> [core/mem/q_malloc.c:501]: qm_free(): BUG: bad pointer 0x2 (out of memory block!) called from core: core/data_lump.c: free_lump(470) - ignoring
3(9) INFO: <core> [core/parser/parse_fline.c:80]: parse_first_line(): message too short: 0 []

Does anyone have any ideas what's going on here?

Thanks

Matthew

On Tue, Oct 17, 2023 at 6:30 PM Marrold <kamailio@marrold.co.uk> wrote:

Hi all,

I am using Kamailio (5.7.2, Debian 11, Python KEMI) in a mutli-homed environment with the topos module to hide the topology.

I have noticed that when I use `set_send_socket` or `$fsn` to force the socket it's sent from, it breaks topos and the ACK is not proxied to the other leg of the call. I am calling record_route() after forcing the socket.

If I disable TOPOS the ACK works as expected, and the signalling looks correct.
Or, with TOPOS enabled, if I comment out set_send_socket TOPOS works as expected.
If I disable enable_double_rr, TOPOS works as expected and the ACK is forwarded, but without the double RR subsequent in-dialog requests use the wrong socket.

One other observation, when I change the send socket I also see these warnings in the logs:

24(32) WARNING: PY3 {ACK}: dialog [dlg_handlers.c:1348]: dlg_onroute(): tight matching failed for ACK with callid='!!:MByLMlFAM.NfWxFAM.cAMxyfWjyLz.yAO.y6MxF1MxVZWG4ZMy**'/55, ftag='2023101714101800015'/19, ttag='2f55349a-2c59-4e37-bf58-fd84fb69ece9'/36 and direction=0
24(32) WARNING: PY3 {ACK}: dialog [dlg_handlers.c:1355]: dlg_onroute(): dialog identification elements are callid='2023101714101800015@2900-0601-0284-80'/37, caller tag='2023101714101800015'/19, callee tag='2f55349a-2c59-4e37-bf58-fd84fb69ece9'/36

Is anyone using TOPOS + forcing the socket, or could someone advise where I am going wrong?

Thanks in advance
Matthew