On Sun, Sep 11, 2022 at 12:56 AM Joel Serrano <joel@textplus.com> wrote:

Hello,

I have a cluster of 2 kamailios v5.5 on debian 9 working flawlessly.

We have added a third node, also on v5.5 but debian 11. Kamailio doesn't work correctly for some reason that I'm not seeing.

The symptoms are:

1- Kamailio receives INVITEs and starts to process them per routing script.
2- There is a specific place where something happens and the calls are dropped (Kamailio is not even replying to the source). Note that the config is exactly the same on all 3 servers, only one of the three is having the issue.

I enabled debug logs and I could see:

[...]
Sep 10 12:30:48 sbc03 sbc[956340]: exec: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.example.com} *** cfgtrace:dbg_cfg_trace(): request_route=[GET_OUTBOUND_API_DATA] c=[/etc/kamailio/sbc/api.cfg] l=61 a=5 n=route
Sep 10 12:30:48 sbc03 sbc[956340]: exec: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.example.com} *** cfgtrace:dbg_cfg_trace(): request_route=[APPLY_REWRITE_RULE] c=[/etc/kamailio/sbc/extras.cfg] l=211 a=26 n=xlog
Sep 10 12:30:48 sbc03 sbc[956340]: INFO: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <script>: Applying local to toll-free rewrite rules on callee number using dpid '20'
Sep 10 12:30:48 sbc03 sbc[956340]: exec: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} *** cfgtrace:dbg_cfg_trace(): request_route=[APPLY_REWRITE_RULE] c=[/etc/kamailio/sbc/extras.cfg] l=212 a=63 n=assign
Sep 10 12:30:48 sbc03 sbc[956340]: exec: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} *** cfgtrace:dbg_cfg_trace(): request_route=[APPLY_REWRITE_RULE] c=[/etc/kamailio/sbc/extras.cfg] l=219 a=16 n=if
Sep 10 12:30:48 sbc03 sbc[956340]: exec: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} *** cfgtrace:dbg_cfg_trace(): request_route=[APPLY_REWRITE_RULE] c=[/etc/kamailio/sbc/extras.cfg] l=213 a=26 n=dp_translate
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dialplan.c:237]: dp_get_ivalue(): searching 15
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dialplan.c:245]: dp_get_ivalue(): dpid is 20 from pv argument
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dialplan.c:254]: dp_get_svalue(): searching 15
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dialplan.c:350]: dp_translate_f(): input is 67339924
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dp_repl.c:605]: dp_translate_helper(): regex operator testing over [67339924]
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dp_repl.c:605]: dp_translate_helper(): regex operator testing over [67339924]
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dp_repl.c:605]: dp_translate_helper(): regex operator testing over [67339924]
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dp_repl.c:605]: dp_translate_helper(): regex operator testing over [67339924]
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dp_repl.c:605]: dp_translate_helper(): regex operator testing over [67339924]
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dp_repl.c:605]: dp_translate_helper(): regex operator testing over [67339924]
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dp_repl.c:605]: dp_translate_helper(): regex operator testing over [67339924]
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dp_repl.c:605]: dp_translate_helper(): regex operator testing over [67339924]
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dp_repl.c:605]: dp_translate_helper(): regex operator testing over [67339924]
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dp_repl.c:605]: dp_translate_helper(): regex operator testing over [67339924]
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dp_repl.c:605]: dp_translate_helper(): regex operator testing over [67339924]
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dp_repl.c:605]: dp_translate_helper(): regex operator testing over [67339924]
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dp_repl.c:605]: dp_translate_helper(): regex operator testing over [67339924]
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dp_repl.c:605]: dp_translate_helper(): regex operator testing over [67339924]
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dp_repl.c:605]: dp_translate_helper(): regex operator testing over [67339924]
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dp_repl.c:605]: dp_translate_helper(): regex operator testing over [67339924]
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dp_repl.c:605]: dp_translate_helper(): regex operator testing over [67339924]
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dp_repl.c:605]: dp_translate_helper(): regex operator testing over [67339924]
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dp_repl.c:605]: dp_translate_helper(): regex operator testing over [67339924]
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dp_repl.c:605]: dp_translate_helper(): regex operator testing over [67339924]
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dp_repl.c:605]: dp_translate_helper(): regex operator testing over [67339924]
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dp_repl.c:605]: dp_translate_helper(): regex operator testing over [67339924]
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dp_repl.c:605]: dp_translate_helper(): regex operator testing over [67339924]
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dp_repl.c:676]: dp_translate_helper(): no matching rule
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialplan [dialplan.c:354]: dp_translate_f(): could not translate 67339924 with dpid 20
Sep 10 12:30:48 sbc03 sbc[956340]: exec: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} *** cfgtrace:dbg_cfg_trace(): request_route=[APPLY_REWRITE_RULE] c=[/etc/kamailio/sbc/extras.cfg] l=217 a=26 n=xlog
Sep 10 12:30:48 sbc03 sbc[956340]: INFO: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <script>: No matching rewrite rules for '67339924' found
Sep 10 12:30:48 sbc03 sbc[956340]: exec: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} *** cfgtrace:dbg_cfg_trace(): request_route=[APPLY_REWRITE_RULE] c=[/etc/kamailio/sbc/extras.cfg] l=218 a=2 n=return
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <core> [core/receive.c:514]: receive_msg(): request-route executed in: 12245 usec
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialog [dlg_hash.c:785]: dlg_lookup_mode(): ref dlg 0x7ff1b4884b48 with 1 -> 2
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialog [dlg_hash.c:789]: dlg_lookup_mode(): dialog id=8614 found on entry 343
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialog [dlg_var.c:63]: dlg_cfg_cb(): new dialog with no transaction after config execution
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialog [dlg_hash.c:1091]: dlg_unref_helper(): unref op on 0x7ff1b4884b48 with 1 from dlg_hash.c:1109
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialog [dlg_hash.c:1095]: dlg_unref_helper(): unref dlg 0x7ff1b4884b48 with 1 -> 1
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialog [dlg_hash.c:1091]: dlg_unref_helper(): unref op on 0x7ff1b4884b48 with 1 from dlg_hash.c:1109
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialog [dlg_hash.c:1095]: dlg_unref_helper(): unref dlg 0x7ff1b4884b48 with 1 -> 0
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialog [dlg_hash.c:1095]: dlg_unref_helper(): ref <=0 for dialog 0x7ff1b4884b48
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialog [dlg_hash.c:345]: destroy_dlg(): destroying dialog 0x7ff1b4884b48 (ref 0)
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialog [dlg_hash.c:356]: destroy_dlg(): removed timer for dlg 0x7ff1b4884b48 [343:8614] with clid '5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa' and tags 'as5d31c96b' ''
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialog [dlg_db_handler.c:708]: remove_dialog_from_db(): trying to remove dialog [5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa], update_flag is 1024
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <core> [db_query.c:72]: db_do_submit_query(): submitted query: delete from `dialog` where `hash_entry`=343 AND `hash_id`=8614, result 0
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <core> [db_query.c:72]: db_do_submit_query(): submitted query: delete from `dialog_vars` where `hash_entry`=343 AND `hash_id`=8614, result 0
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialog [dlg_db_handler.c:736]: remove_dialog_from_db(): callid was 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <core> [core/usr_avp.c:637]: destroy_avp_list(): destroying list 0x7ff1b4880370
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <core> [core/usr_avp.c:637]: destroy_avp_list(): destroying list (nil)
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <core> [core/usr_avp.c:637]: destroy_avp_list(): destroying list (nil)
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <core> [core/usr_avp.c:637]: destroy_avp_list(): destroying list (nil)
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <core> [core/usr_avp.c:637]: destroy_avp_list(): destroying list (nil)
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <core> [core/usr_avp.c:637]: destroy_avp_list(): destroying list (nil)
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <core> [core/xavp.c:541]: xavp_destroy_list(): destroying xavp list (nil)
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <core> [core/xavp.c:541]: xavp_destroy_list(): destroying xavp list (nil)
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <core> [core/xavp.c:541]: xavp_destroy_list(): destroying xavp list (nil)
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <core> [core/receive.c:606]: receive_msg(): cleaning up

If I go to line 61 from route GET_OUTBOUND_API_DATA, I have this:

if(route(APPLY_REWRITE_RULE)) {
$rU = $var(dp_user);
$avp(icx_real_number) = $var(dp_user);
}

The very next thing is:

# Query API
$avp(apiUrl) = "{{ call_api_url }}/outbound/" + $avp(icx_src_number) + "/" + $avp(icx_real_number);
http_client_query("$avp(apiUrl)", "$avp(apiResponseBody)");
$avp(apiResponseCode) = $rc;

I see the GET_OUTBOUND_API_DATA route calling APPLY_REWRITE_RULE, and APPLY_REWRITE_RULE returning correctly then finished:

Sep 10 12:30:48 sbc03 sbc[956340]: exec: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} *** cfgtrace:dbg_cfg_trace(): request_route=[APPLY_REWRITE_RULE] c=[/etc/kamailio/sbc/extras.cfg] l=218 a=2 n=return

But then Kamailio is apparently just tearing down the call and ending it.

Can someone help me understand what this part of the logs means or what can be causing them?

Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <core> [core/receive.c:514]: receive_msg(): request-route executed in: 12245 usec
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialog [dlg_hash.c:785]: dlg_lookup_mode(): ref dlg 0x7ff1b4884b48 with 1 -> 2
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialog [dlg_hash.c:789]: dlg_lookup_mode(): dialog id=8614 found on entry 343
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialog [dlg_var.c:63]: dlg_cfg_cb(): new dialog with no transaction after config execution
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialog [dlg_hash.c:1091]: dlg_unref_helper(): unref op on 0x7ff1b4884b48 with 1 from dlg_hash.c:1109
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialog [dlg_hash.c:1095]: dlg_unref_helper(): unref dlg 0x7ff1b4884b48 with 1 -> 1
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialog [dlg_hash.c:1091]: dlg_unref_helper(): unref op on 0x7ff1b4884b48 with 1 from dlg_hash.c:1109
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialog [dlg_hash.c:1095]: dlg_unref_helper(): unref dlg 0x7ff1b4884b48 with 1 -> 0
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialog [dlg_hash.c:1095]: dlg_unref_helper(): ref <=0 for dialog 0x7ff1b4884b48
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialog [dlg_hash.c:345]: destroy_dlg(): destroying dialog 0x7ff1b4884b48 (ref 0)
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialog [dlg_hash.c:356]: destroy_dlg(): removed timer for dlg 0x7ff1b4884b48 [343:8614] with clid '5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa' and tags 'as5d31c96b' ''
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialog [dlg_db_handler.c:708]: remove_dialog_from_db(): trying to remove dialog [5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa], update_flag is 1024
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <core> [db_query.c:72]: db_do_submit_query(): submitted query: delete from `dialog` where `hash_entry`=343 AND `hash_id`=8614, result 0
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <core> [db_query.c:72]: db_do_submit_query(): submitted query: delete from `dialog_vars` where `hash_entry`=343 AND `hash_id`=8614, result 0
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} dialog [dlg_db_handler.c:736]: remove_dialog_from_db(): callid was 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <core> [core/usr_avp.c:637]: destroy_avp_list(): destroying list 0x7ff1b4880370
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <core> [core/usr_avp.c:637]: destroy_avp_list(): destroying list (nil)
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <core> [core/usr_avp.c:637]: destroy_avp_list(): destroying list (nil)
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <core> [core/usr_avp.c:637]: destroy_avp_list(): destroying list (nil)
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <core> [core/usr_avp.c:637]: destroy_avp_list(): destroying list (nil)
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <core> [core/usr_avp.c:637]: destroy_avp_list(): destroying list (nil)
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <core> [core/xavp.c:541]: xavp_destroy_list(): destroying xavp list (nil)
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <core> [core/xavp.c:541]: xavp_destroy_list(): destroying xavp list (nil)
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <core> [core/xavp.c:541]: xavp_destroy_list(): destroying xavp list (nil)
Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE 5111a7c71ec485e443099844491ef7d8@sip02.vozelia.com.pa} <core> [core/receive.c:606]: receive_msg(): cleaning up

I can see it's related to the dialogs, but is this a cause or a consequence? I have checked the API access logs, and Kamailio doesn't get to send the request, I've also noticed that normally Kamailio replies with a 100-Trying almost instantly, in the case of this server I don't see a single 100-Trying from Kamailio.

I'm pretty lost here so any tips are more than welcome.

NOTE: I tried with debian11 + Kamailio 5.6 and the same issue happens too.

Thanks,
Joel.