[SR-Users] Kamailio stops processing requests mid script

Joel Serrano joel at textplus.com
Wed Sep 14 10:20:15 CEST 2022 

Bumping this! Any comments? Or suggestions on what to check? I'm feeling it
has to be something stupid but I can't see it :(


On Sun, Sep 11, 2022 at 12:56 AM Joel Serrano <joel at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at sip02.vozelia.com.pa} dialog
> [dlg_hash.c:356]: destroy_dlg(): removed timer for dlg 0x7ff1b4884b48
> [343:8614] with clid '
> 5111a7c71ec485e443099844491ef7d8 at sip02.vozelia.com.pa' and tags
> 'as5d31c96b' ''
> Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE
> 5111a7c71ec485e443099844491ef7d8 at sip02.vozelia.com.pa} dialog
> [dlg_db_handler.c:708]: remove_dialog_from_db(): trying to remove dialog [
> 5111a7c71ec485e443099844491ef7d8 at sip02.vozelia.com.pa], update_flag is
> 1024
> Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE
> 5111a7c71ec485e443099844491ef7d8 at 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 at 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 at sip02.vozelia.com.pa} dialog
> [dlg_db_handler.c:736]: remove_dialog_from_db(): callid was
> 5111a7c71ec485e443099844491ef7d8 at sip02.vozelia.com.pa
> Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE
> 5111a7c71ec485e443099844491ef7d8 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at sip02.vozelia.com.pa} dialog
> [dlg_hash.c:356]: destroy_dlg(): removed timer for dlg 0x7ff1b4884b48
> [343:8614] with clid '
> 5111a7c71ec485e443099844491ef7d8 at sip02.vozelia.com.pa' and tags
> 'as5d31c96b' ''
> Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE
> 5111a7c71ec485e443099844491ef7d8 at sip02.vozelia.com.pa} dialog
> [dlg_db_handler.c:708]: remove_dialog_from_db(): trying to remove dialog [
> 5111a7c71ec485e443099844491ef7d8 at sip02.vozelia.com.pa], update_flag is
> 1024
> Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE
> 5111a7c71ec485e443099844491ef7d8 at 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 at 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 at sip02.vozelia.com.pa} dialog
> [dlg_db_handler.c:736]: remove_dialog_from_db(): callid was
> 5111a7c71ec485e443099844491ef7d8 at sip02.vozelia.com.pa
> Sep 10 12:30:48 sbc03 sbc[956340]: DEBUG: {1 102 INVITE
> 5111a7c71ec485e443099844491ef7d8 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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.
>
>
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-users/attachments/20220914/7564d507/attachment.htm>

More information about the sr-users mailing list