forgot to add these details:
####### Global Parameters #########
debug=2
log_stderror=no
memdbg=3
memlog=3
log_facility=LOG_LOCAL0
fork=yes
children=8
log_prefix_mode = 1
log_prefix="{$TV(Sn) $pp $mt $hdr(CSeq) $ci} "
disable_sctp = yes
force_rport = yes
rundir="/tmp"
pv_buffer_size=65536
# This must be less than or equal to global 'debug' level to be visible.
latency_cfg_log = 2 #
# Logs if request_route or reply_route takes longer than this value.
latency_limit_cfg = 100 #
# Logs if a specific function call (ex.: t_relay, sleep) takes longer than
this.
latency_limit_action = 100 #
# Logs if a DB query takes longer than this value.
latency_limit_db = 100 #
Any suggestions are welcome.
Atenciosamente / Kind Regards / Cordialement / Un saludo,
*Sérgio Charrua*
*www.kahea.ai <http://www.kahea.ai> / www.voip.pt <http://www.voip.pt>*
*OpenTelecom* - Consulting for Telecoms, Lda
Tel.: +351 <callto:+351+91+104+12+66>91 631 11 44
Email : *[email protected] <[email protected]>*
This message and any files or documents attached are strictly confidential
or otherwise legally protected.
It is intended only for the individual or entity named. If you are not the
named addressee or have received this email in error, please inform the
sender immediately, delete it from your system and do not copy or disclose
it or its contents or use it for any purpose. Please also note that
transmission cannot be guaranteed to be secure or error-free.
On Wed, Jan 14, 2026 at 3:58 PM Sergio Charrua <[email protected]>
wrote:
> Hi Daniel!
>
> Thanks for the suggestion.
> I enabled latency statistics, and this is what I get:
>
> Jan 14 15:26:07 ire-lab-kamailio1 kamailio[1473608]: INFO:
> {1768400767.695436 1473608 1 102 INVITE
> [email protected]:5060} <script>:
> HEADERS_TO_JSON - Processing INVITE from 10.20.0.5:5060 to
> sip:[email protected]
> Jan 14 15:26:07 ire-lab-kamailio1 kamailio[1473608]: ERROR:
> {1768400767.696483 1473608 1 102 INVITE
> [email protected]:5060} <core>
> [core/action.c:1629]: run_actions(): alert - action [jsdt_run (25)] cfg
> [/usr/local/etc/kamailio/kamailio_ire1_2.cfg:445] took too long [1020 us]
> Jan 14 15:26:07 ire-lab-kamailio1 kamailio[1473608]: ERROR:
> {1768400767.696516 1473608 1 102 INVITE
> [email protected]:5060} <core>
> [core/action.c:1629]: run_actions(): alert - action [corefunc (16)] cfg
> [/usr/local/etc/kamailio/kamailio_ire1_2.cfg:454] took too long [1051 us]
> Jan 14 15:26:07 ire-lab-kamailio1 kamailio[1473608]: ERROR:
> {1768400767.696629 1473608 1 102 INVITE
> [email protected]:5060} <core>
> [core/action.c:1629]: run_actions(): alert - action [jansson_set (28)] cfg
> [/usr/local/etc/kamailio/kamailio_ire1_2.cfg:454] took too long [107 us]
> Jan 14 15:26:07 ire-lab-kamailio1 kamailio[1473608]: ERROR:
> {1768400767.696914 1473608 1 102 INVITE
> [email protected]:5060} <core>
> [core/action.c:1629]: run_actions(): alert - action [corefunc (5)] cfg
> [/usr/local/etc/kamailio/kamailio_ire1_2.cfg:469] took too long [1481 us]
> Jan 14 15:26:07 ire-lab-kamailio1 kamailio[1473608]: INFO:
> {1768400767.697365 1473608 2 102 INVITE
> [email protected]:5060} <script>: local-response
> - replied locally
> Jan 14 15:26:07 ire-lab-kamailio1 kamailio[1473608]: ERROR:
> {1768400767.697441 1473608 1 102 INVITE
> [email protected]:5060} <core>
> [core/action.c:1629]: run_actions(): alert - action [evapi_async_relay
> (25)] cfg [/usr/local/etc/kamailio/kamailio_ire1_2.cfg:476] took too long
> [448 us]
> Jan 14 15:26:07 ire-lab-kamailio1 kamailio[1473608]: INFO: {
> 1768400767.697466 1473608 1 102 INVITE
> [email protected]:5060} <script>: HANDLE_INVITE
> - suspended transaction for INVITE / CALL_ATTEMPT. Index: 57894 - Label:
> 1377620424
> Jan 14 15:26:07 ire-lab-kamailio1 kamailio[1473608]: INFO:
> {1768400767.697474 1473608 1 102 INVITE
> [email protected]:5060} <core>
> [core/receive.c:531]: receive_msg(): request-route executed in: 2978 usec
> Jan 14 15:26:07 ire-lab-kamailio1 kamailio[1473635]: INFO: {
> 1768400767.999605 1473635 1 1 OPTIONS 123} <script>:
> evapi:message-received - Received EVAPI message:
> RESPONSE:57894:1377620424:{"action": "ROUTE", "call_id": "
> [email protected]:5060",
> "max_number_of_crankbacks": 1, "method": "INVITE", "retry_on_failure":
> "true", "routes": [{"crankback_profile": [{"next_tkg_eid": "20001",
> "sip_errors": [402, 502]}, {"next_tkg_eid": "10003", "sip_errors": [403,
> 503]}], "dst_uri": "sip:10.20.0.6:5060", "headers": {"from": {"uri": "
> sip:[email protected]:5060"}, "to": {"uri": "
> sip:[email protected]:5060"}}, "max_call_duration": 1000,
> "tkg_eid": "10002", "uri": "sip:[email protected]:5060"},
> {"crankback_profile": [{"next_tkg_eid": "10003", "sip_errors": [404, 504]},
> {"next_tkg_eid": "10003", "sip_errors": [403, 503]}], "dst_uri": "sip:
> 10.20.0.6:5060", "headers": {"from": {"uri": "
> sip:[email protected]:5060"}, "to": {"uri": "
> sip:[email protected]:5060"}}, "max_call_duration": 1000,
> "tkg_eid": "20001", "uri": "sip:[email protected]:5060"},
> {"crankback_profile": [], "dst_uri": "sip:10.20.0.6:5060", "headers":
> {"from": {"uri": "sip:[email protected]:5060"}, "to": {"uri": "
> sip:[email protected]:5060"}}, "max_call_duration": 1000,
> "tkg_eid": "10003", "uri": "sip:[email protected]:5060"}],
> "routing": "serial", "version": "1.0"}
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: INFO:
> {1768400767.999787 1473635 1 1 OPTIONS 123} <script>: Part 0: 'RESPONSE'
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: INFO:
> {1768400767.999808 1473635 1 1 OPTIONS 123} <script>: Part 1: '57894'
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: INFO:
> {1768400767.999816 1473635 1 1 OPTIONS 123} <script>: Part 2: '1377620424'
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: INFO:
> {1768400767.999982 1473635 1 1 OPTIONS 123} <script>: Part 3: '{"action":
> "ROUTE", "call_id": "[email protected]:5060",
> "max_number_of_crankbacks": 1, "method": "INVITE", "retry_on_failure":
> "true", "routes": [{"crankback_profile": [{"next_tkg_eid": "20001",
> "sip_errors": [402, 502]}, {"next_tkg_eid": "10003", "sip_errors": [403,
> 503]}], "dst_uri": "sip:10.20.0.6:5060", "headers": {"from": {"uri": "
> sip:[email protected]:5060"}, "to": {"uri": "
> sip:[email protected]:5060"}}, "max_call_duration": 1000,
> "tkg_eid": "10002", "uri": "sip:[email protected]:5060"},
> {"crankback_profile": [{"next_tkg_eid": "10003", "sip_errors": [404, 504]},
> {"next_tkg_eid": "10003", "sip_errors": [403, 503]}], "dst_uri": "sip:
> 10.20.0.6:5060", "headers": {"from": {"uri": "
> sip:[email protected]:5060"}, "to": {"uri": "
> sip:[email protected]:5060"}}, "max_call_duration": 1000,
> "tkg_eid": "20001", "uri": "sip:[email protected]:5060"},
> {"crankback_profile": [], "dst_uri": "sip:10.20.0.6:5060", "headers":
> {"from": {"uri": "sip:[email protected]:5060"}, "to": {"uri": "
> sip:[email protected]:5060"}}, "max_call_duration": 1000,
> "tkg_eid": "10003", "uri": "sip:[email protected]:5060"}],
> "routing": "serial", "version": "1.0"}'
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: ERROR:
> {1768400768.000196 1473635 1 1 OPTIONS 123} <core> [core/action.c:1629]:
> run_actions(): alert - action [jansson_get (34)] cfg
> [/usr/local/etc/kamailio/kamailio_ire1_2.cfg:1439] took too long [202 us]
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: INFO:
> {1768400768.000218 1473635 1 1 OPTIONS 123} <script>:
> evapi:message-received - t_continue for 57894/1377620424
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: INFO:
> {1768400768.000450 1473635 1 102 INVITE
> [email protected]:5060} <script>: EVAPIRESPONSE
> - TRANSACTION 57894|1377620424
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: INFO:
> {1768400768.000491 1473635 1 102 INVITE
> [email protected]:5060} <script>: EVAPIRESPONSE
> - Resumed with RESPONSE {"action": "ROUTE", "call_id": "
> [email protected]:5060",
> "max_number_of_crankbacks": 1, "method": "INVITE", "retry_on_failure":
> "true", "routes": [{"crankback_profile": [{"next_tkg_eid": "20001",
> "sip_errors": [402, 502]}, {"next_tkg_eid": "10003", "sip_errors": [403,
> 503]}], "dst_uri": "sip:10.20.0.6:5060", "headers": {"from": {"uri": "
> sip:[email protected]:5060"}, "to": {"uri": "
> sip:[email protected]:5060"}}, "max_call_duration": 1000,
> "tkg_eid": "10002", "uri": "sip:[email protected]:5060"},
> {"crankback_profile": [{"next_tkg_eid": "10003", "sip_errors": [404, 504]},
> {"next_tkg_eid": "10003", "sip_errors": [403, 503]}], "dst_uri": "sip:
> 10.20.0.6:5060", "headers": {"from": {"uri": "
> sip:[email protected]:5060"}, "to": {"uri": "
> sip:[email protected]:5060"}}, "max_call_duration": 1000,
> "tkg_eid": "20001", "uri": "sip:[email protected]:5060"},
> {"crankback_profile": [], "dst_uri": "sip:10.20.0.6:5060", "headers":
> {"from": {"uri": "sip:[email protected]:5060"}, "to": {"uri": "
> sip:[email protected]:5060"}}, "max_call_duration": 1000,
> "tkg_eid": "10003", "uri": "sip:[email protected]:5060"}],
> "routing": "serial", "version": "1.0"}
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: ERROR:
> {1768400768.000676 1473635 1 102 INVITE
> [email protected]:5060} <core>
> [core/action.c:1629]: run_actions(): alert - action [jansson_get (34)] cfg
> [/usr/local/etc/kamailio/kamailio_ire1_2.cfg:669] took too long [126 us]
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: INFO:
> {1768400768.000819 1473635 1 102 INVITE
> [email protected]:5060} <script>: EVAPIRESPONSE
> - ROUTE action
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: ERROR:
> {1768400768.000983 1473635 1 102 INVITE
> [email protected]:5060} <core>
> [core/action.c:1629]: run_actions(): alert - action [corefunc (63)] cfg
> [/usr/local/etc/kamailio/kamailio_ire1_2.cfg:708] took too long [132 us]
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: INFO:
> {1768400768.001009 1473635 1 102 INVITE
> [email protected]:5060} <script>: EVAPIRESPONSE
> - has retry_on_failure
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: INFO:
> {1768400768.001066 1473635 1 102 INVITE
> [email protected]:5060} <script>: EVAPIRESPONSE
> - retry_on_failure = 1
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: ERROR:
> {1768400768.001168 1473635 1 102 INVITE
> [email protected]:5060} <core>
> [core/action.c:1629]: run_actions(): alert - action [corefunc (16)] cfg
> [/usr/local/etc/kamailio/kamailio_ire1_2.cfg:718] took too long [150 us]
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: ERROR:
> {1768400768.001187 1473635 1 102 INVITE
> [email protected]:5060} <core>
> [core/action.c:1629]: run_actions(): alert - action [corefunc (16)] cfg
> [/usr/local/etc/kamailio/kamailio_ire1_2.cfg:719] took too long [185 us]
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: ERROR:
> {1768400768.001312 1473635 1 102 INVITE
> [email protected]:5060} <core>
> [core/action.c:1629]: run_actions(): alert - action [jansson_get (34)] cfg
> [/usr/local/etc/kamailio/kamailio_ire1_2.cfg:723] took too long [117 us]
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: ERROR:
> {1768400768.001334 1473635 1 102 INVITE
> [email protected]:5060} <core>
> [core/action.c:1629]: run_actions(): alert - action [corefunc (16)] cfg
> [/usr/local/etc/kamailio/kamailio_ire1_2.cfg:726] took too long [141 us]
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: ERROR:
> {1768400768.001506 1473635 1 102 INVITE
> [email protected]:5060} <core>
> [core/action.c:1629]: run_actions(): alert - action [jansson_get (34)] cfg
> [/usr/local/etc/kamailio/kamailio_ire1_2.cfg:726] took too long [168 us]
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: ERROR:
> {1768400768.001722 1473635 1 102 INVITE
> [email protected]:5060} <core>
> [core/action.c:1629]: run_actions(): alert - action [jansson_get (34)] cfg
> [/usr/local/etc/kamailio/kamailio_ire1_2.cfg:729] took too long [144 us]
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: INFO:
> {1768400768.001749 1473635 1 102 INVITE
> [email protected]:5060} <script>: EVAPIRESPONSE
> - retry_on_failure = 1 max_number_of_crankbacks = 1
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: INFO:
> {1768400768.001839 1473635 1 102 INVITE
> [email protected]:5060} <script>: RTJSON_PROCESS
> - Initializing RTJSON routes
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: INFO:
> {1768400768.001893 1473635 1 102 INVITE
> [email protected]:5060} <script>: RTJSON_PROCESS
> -
> {"version":"1.0","routing":"serial","routes":[{"crankback_profile":[{"next_tkg_eid":"20001","sip_errors":[402,502]},{"next_tkg_eid":"10003","sip_errors":[403,503]}],"dst_uri":"sip:
> 10.20.0.6:5060","headers":{"from":{"uri":"sip:[email protected]:5060
> "},"to":{"uri":"sip:[email protected]:5060
> "}},"max_call_duration":1000,"tkg_eid":"10002","uri":"
> sip:[email protected]:5060
> "},{"crankback_profile":[{"next_tkg_eid":"10003","sip_errors":[404,504]},{"next_tkg_eid":"10003","sip_errors":[403,503]}],"dst_uri":"sip:
> 10.20.0.6:5060","headers":{"from":{"uri":"sip:[email protected]:5060
> "},"to":{"uri":"sip:[email protected]:5060
> "}},"max_call_duration":1000,"tkg_eid":"20001","uri":"
> sip:[email protected]:5060
> "},{"crankback_profile":[],"dst_uri":"sip:10.20.0.6:5060
> ","headers":{"from":{"uri":"sip:[email protected]:5060
> "},"to":{"uri":"sip:[email protected]:5060
> "}},"max_call_duration":1000,"tkg_eid":"10003","uri":"
> sip:[email protected]:5060"}]}
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: ERROR:
> {1768400768.002023 1473635 1 102 INVITE
> [email protected]:5060} <core>
> [core/action.c:1629]: run_actions(): alert - action [rtjson_init_routes
> (25)] cfg [/usr/local/etc/kamailio/kamailio_ire1_2.cfg:755] took too long
> [116 us]
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: ERROR:
> {1768400768.002051 1473635 1 102 INVITE
> [email protected]:5060} <core>
> [core/action.c:1629]: run_actions(): alert - action [corefunc (16)] cfg
> [/usr/local/etc/kamailio/kamailio_ire1_2.cfg:761] took too long [145 us]
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: INFO:
> {1768400768.002082 1473635 1 102 INVITE
> [email protected]:5060} <script>: RTJSON_PROCESS
> - Processing new route
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: INFO:
> {1768400768.002143 1473635 1 102 INVITE
> [email protected]:5060} <script>: RTJSON_PROCESS
> - routes assigned as index = 1 JSON =
> {"version":"1.0","routing":"serial","routes":[{"crankback_profile":[{"next_tkg_eid":"20001","sip_errors":[402,502]},{"next_tkg_eid":"10003","sip_errors":[403,503]}],"dst_uri":"sip:
> 10.20.0.6:5060","headers":{"from":{"uri":"sip:[email protected]:5060
> "},"to":{"uri":"sip:[email protected]:5060
> "}},"max_call_duration":1000,"tkg_eid":"10002","uri":"
> sip:[email protected]:5060
> "},{"crankback_profile":[{"next_tkg_eid":"10003","sip_errors":[404,504]},{"next_tkg_eid":"10003","sip_errors":[403,503]}],"dst_uri":"sip:
> 10.20.0.6:5060","headers":{"from":{"uri":"sip:[email protected]:5060
> "},"to":{"uri":"sip:[email protected]:5060
> "}},"max_call_duration":1000,"tkg_eid":"20001","uri":"
> sip:[email protected]:5060
> "},{"crankback_profile":[],"dst_uri":"sip:10.20.0.6:5060
> ","headers":{"from":{"uri":"sip:[email protected]:5060
> "},"to":{"uri":"sip:[email protected]:5060
> "}},"max_call_duration":1000,"tkg_eid":"10003","uri":"
> sip:[email protected]:5060"}]}
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: ERROR:
> {1768400768.002342 1473635 1 102 INVITE
> [email protected]:5060} <core>
> [core/action.c:1629]: run_actions(): alert - action [jansson_get (34)] cfg
> [/usr/local/etc/kamailio/kamailio_ire1_2.cfg:838] took too long [120 us]
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: ERROR:
> {1768400768.002509 1473635 1 102 INVITE
> [email protected]:5060} <core>
> [core/action.c:1629]: run_actions(): alert - action [jansson_get (34)] cfg
> [/usr/local/etc/kamailio/kamailio_ire1_2.cfg:839] took too long [135 us]
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: ERROR:
> {1768400768.002666 1473635 1 102 INVITE
> [email protected]:5060} <core>
> [core/action.c:1629]: run_actions(): alert - action [jansson_get (34)] cfg
> [/usr/local/etc/kamailio/kamailio_ire1_2.cfg:840] took too long [132 us]
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: INFO:
> {1768400768.002691 1473635 1 102 INVITE
> [email protected]:5060} <script>: RELAY -
> Modifying SIP headers from INVITE - route 10002 index 0
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: INFO:
> {1768400768.002713 1473635 1 102 INVITE
> [email protected]:5060} <script>: RELAY - route
> is =
> {"crankback_profile":[{"next_tkg_eid":"20001","sip_errors":[402,502]},{"next_tkg_eid":"10003","sip_errors":[403,503]}],"dst_uri":"sip:
> 10.20.0.6:5060","headers":{"from":{"uri":"sip:[email protected]:5060
> "},"to":{"uri":"sip:[email protected]:5060
> "}},"max_call_duration":1000,"tkg_eid":"10002","uri":"
> sip:[email protected]:5060"} to sip:10.20.0.6:5060
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: ERROR:
> {1768400768.002870 1473635 1 102 INVITE
> [email protected]:5060} <core>
> [core/action.c:1629]: run_actions(): alert - action [jsdt_run (27)] cfg
> [/usr/local/etc/kamailio/kamailio_ire1_2.cfg:844] took too long [143 us]
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: ERROR:
> {1768400768.002956 1473635 1 102 INVITE
> [email protected]:5060} <core>
> [core/action.c:1629]: run_actions(): alert - action [corefunc (16)] cfg
> [/usr/local/etc/kamailio/kamailio_ire1_2.cfg:849] took too long [783 us]
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: ERROR:
> {1768400768.002990 1473635 1 102 INVITE
> [email protected]:5060} <core>
> [core/action.c:1629]: run_actions(): alert - action [corefunc (16)] cfg
> [/usr/local/etc/kamailio/kamailio_ire1_2.cfg:851] took too long [830 us]
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: INFO:
> {1768400768.003109 1473635 1 102 INVITE
> [email protected]:5060} <script>: PIN_SOCKET -
> stored dlg_sock=udp:10.20.0.4:5060
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: INFO:
> {1768400768.003195 1473635 1 102 INVITE
> [email protected]:5060} <script>: PIN_SOCKET -
> forcing <udp:10.20.0.4:5060> (recv udp:10.20.0.4:5060)
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: ERROR:
> {1768400768.003245 1473635 1 102 INVITE
> [email protected]:5060} <core>
> [core/action.c:1629]: run_actions(): alert - action [corefunc (16)] cfg
> [/usr/local/etc/kamailio/kamailio_ire1_2.cfg:822] took too long [225 us]
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: ERROR:
> {1768400768.003268 1473635 1 102 INVITE
> [email protected]:5060} <core>
> [core/action.c:1629]: run_actions(): alert - action [corefunc (5)] cfg
> [/usr/local/etc/kamailio/kamailio_ire1_2.cfg:858] took too long [249 us]
> Jan 14 15:26:08 ire-lab-kamailio1 kamailio[1473635]: INFO:
> {1768400768.003329 1473635 1 102 INVITE
> [email protected]:5060} <script>: MANAGE_BRANCH
> - initializing new branch
>
> Highlighted in yellow background, the times of the request to EVAPI client
> (1768400767.697466) and the EVAPI response to Kamailio (1768400767.999605),
> which is ~300ms.
> However, on EVAPI client's logs, I can see that receiving the message from
> Kamailio + request to REST service + the response back to Kamailio takes
> less than 20ms!
> It is like Kamailio got stuck during 280ms for no reason (IMHO).
> Already check, this is not constant (sometimes whole process takes 50ms,
> other times takes more than 1 second) and it was verified in multiple
> servers.
>
> Note that there was only 1 Call Attempt, nothing else.
> Part of the code is below. I hope it helps.
>
> FYI:
> - route(HEADERS_TO_JSON); is a route block that calls a KEMI script via
> jsdt_app, and converts SIP headers to JSON object, supporting repeated
> headers (converts to Array of strings). The javascript uses var raw =
> KSR.pv.get("$mb") || ""; to get the SIP Headers and then loops
> through each header, converting it to JSON. If there is a better way, I'm
> open for suggestions. This will generate a JSON structure, saved on
> $var(json_headers) , that is then sent to EVAPI client
> via evapi_async_relay in route[HANDLE_INVITE]
> - the EVAPI client (python) will take the received JSON and POST it to
> REST service. EVAPI script was created because it also monitors,
> distributes load and does failover between multiple REST servers, between
> other functionalities...It is really fast, processing in less than 30ms
> each request.
>
>
> route[HANDLE_INVITE] {
> # Convert headers to JSON
> route(HEADERS_TO_JSON);
>
> # Send to Python via EVAPI
> $var(evmsg) = "INVITE:" + $T(id_index) + ":" + $T(id_label) + ":" +
> $var(json_headers);
>
> // no need to t_suspend() request as evapi_async_relay already
> suspends the request
>
> evapi_async_relay("CALL_ATTEMPT:$T(id_index):$T(id_label):$var(json_headers)");
> xlog("L_INFO", "HANDLE_INVITE - suspended transaction for INVITE /
> CALL_ATTEMPT. Index: $T(id_index) - Label: $T(id_label) \n" );
> exit;
> }
>
> route[HEADERS_TO_JSON]
> {
> xlog("L_INFO", "HEADERS_TO_JSON - Processing INVITE from $si:$sp to
> $ru\n");
> # Get the full SIP message
> # Use JavaScript for complex header parsing
> if (!jsdt_run("headers_to_json")) {
> xlog("L_ERR", "HEADERS_TO_JSON - Failed to convert headers to
> JSON\n");
> $var(json_headers) = "{}";
> sl_reply_error();
> exit;
> }
>
> # Result is stored in $var(headers_json)
> #$var(json_headers) = $var(headers_json);
> jansson_set("object" , "sip_invite" , "$var(headers_json)" ,
> "$var(json_headers)" );
> jansson_set("string" , "remote_ip_port" , "$si:$sp" ,
> "$var(json_headers)" );
> jansson_set("string" , "local_ip_port" , "$RAi:$RAp" ,
> "$var(json_headers)" );
> jansson_set("string" , "protocol" , "$pr" ,
> "$var(json_headers)" );
> jansson_set("integer", "retry" , "$var(retry)" ,
> "$var(json_headers)" );
> jansson_set("string" , "timestamp" , "$TV(Sn)" ,
> "$var(json_headers)" );
>
> xlog("L_DBG","HEADERS_TO_JSON - json generated $var(json_headers) ...
> \n");
> }
>
> # Tiny helper to reply correctly inside/outside TM
> route[REPLY_SAFE] {
> # validate code (default to 480 if bad/empty)
> if (!($var(code) =~ "^[1-6][0-9][0-9]$"))
> $var(code) = "480";
> if ($var(text) == "")
> $var(text) = "Temporarily Unavailable";
>
> if (t_check_trans()) {
> xlog("L_INFO", "REPLY_SAFE - replying with t_reply\n");
> t_reply( "$var(code)" , "$var(text)");
> } else {
> xlog("L_INFO", "REPLY_SAFE - replying with send_reply\n");
> sl_send_reply("$var(code)", "$var(text)");
> }
> xlog("L_INFO", "REPLY_SAFE - replied $var(code) - $var(text)\n");
> exit;
> }
>
> route[EVAPIRESPONSE] {
>
> xlog("L_INFO", "EVAPIRESPONSE - TRANSACTION $T(id_index)|$T(id_label)
> \n" );
> xlog("L_INFO", "EVAPIRESPONSE - Resumed with RESPONSE $var(response)
> \n" );
>
> if ($var(response) == $null || $var(response) == "") {
> xlog("L_INFO", "EVAPIRESPONSE - missing cached EVAPI response;
> replying 500\n");
> $var(code) = 500;
> $var(text) = "Internal Server Error - 1";
> route(REPLY_SAFE);
> exit;
> }
>
> # Test each condition individually
> if ($var(response) == "FALSE" || $var(response) == "NO_ROUTES")
> {
> # Check if response is FALSE (drop the call)
> xlog("L_INFO", "EVAPIRESPONSE - Python script returned FALSE or NO
> ROUTES, dropping call\n");
> $var(code) = 500;
> $var(text) = "Internal Server Error";
> route(REPLY_SAFE);
> exit;
> }
>
> jansson_get("retry_on_failure", $var(response),
> "$var(retry_on_failure)");
> if (jansson_get("action", $var(response), "$var(action)"))
> {
> if ($var(action) == "DROP") {
> jansson_get("error_code", $var(response), "$var(error_code)");
> jansson_get("error_text", $var(response), "$var(error_text)");
> xlog("L_INFO", "EVAPIRESPONSE - DROP $var(error_code) -
> $var(error_text)\n");
> $var(code)=$var(error_code);
> $var(text)=$var(error_text);
> route(REPLY_SAFE);
> exit;
> }
>
> else if ($var(action) == "CALL_REJECT") {
> # Prefer nested object: { "action":"CALL_REJECT", "reject": {
> "error_code":480, "error_text":"..." } }
> $var(error_code) = $null; $var(error_text) = $null;
> if (jansson_get("reject.error_code", $var(response),
> "$var(error_code)")) ;
> if (jansson_get("reject.error_text", $var(response),
> "$var(error_text)")) ;
> if ($var(error_code) == $null)
> jansson_get("error_code", $var(response),
> "$var(error_code)");
> if ($var(error_text) == $null)
> jansson_get("error_text", $var(response),
> "$var(error_text)");
>
> if ($var(error_code) == $null || $var(error_text) == $null) {
> xlog("L_INFO", "EVAPIRESPONSE - CALL_REJECT missing
> fields, defaults to 480\n");
> $var(code)=480;
> $var(text)="Temporarily Unavailable";
> } else {
> xlog("L_INFO", "EVAPIRESPONSE - CALL_REJECT
> $var(error_code) - $var(error_text)\n");
> $var(code)=$var(error_code);
> $var(text)=$var(error_text);
> }
> route(REPLY_SAFE);
> exit;
> }
> # Process RTJSON routing, action = ROUTE
> else if ($var(action) == "ROUTE") {
> xlog("L_INFO", "EVAPIRESPONSE - ROUTE action\n");
>
> $dlg_var(retry_on_failure) = "0";
>
> if ($var(retry_on_failure) != "")
> {
> xlog("L_INFO", "EVAPIRESPONSE - has retry_on_failure \n");
> if ( $var(retry_on_failure) =~ "^(1|[Tt]rue)$")
> {
> xlog("L_INFO", "EVAPIRESPONSE - retry_on_failure = 1
> \n");
> $dlg_var(retry_on_failure) = "1";
> }
> }else
> xlog("L_INFO", "EVAPIRESPONSE - NO retry_on_failure FOUND
> or retry_on_failure = 0 !\n");
>
>
>
> if (!jansson_get("max_number_of_crankbacks" , $var(response),
> "$xavp(max_number_of_crankbacks)") )
> $xavp(max_number_of_crankbacks) = 3; // default value
>
> jansson_get("routes", $var(response), "$dlg_var(routing)");
>
> $xavp(crb=>doc) = $var(response);
> jansson_get("routes", $xavp(crb=>doc), "$var(routes_arr)");
>
> xlog("L_INFO", "EVAPIRESPONSE - retry_on_failure =
> $dlg_var(retry_on_failure) max_number_of_crankbacks =
> $xavp(max_number_of_crankbacks) \n");
> $dlg_var(rtjson_str) = $var(response);
> # Process routes from RTJSON
> route(RTJSON_PROCESS);
> }
>
> } else {
> xlog("L_ERR", "EVAPIRESPONSE - Invalid response format from
> Python\n");
> $var(code) = 500;
> $var(text) = "Internal Server Error";
> route(REPLY_SAFE);
> exit;
> }
> }
>
> # Handle responses from Python script
> event_route[evapi:message-received] {
> $var(msg) = $evapi(msg);
> xlog("L_INFO", "evapi:message-received - Received EVAPI message:
> $var(msg)\n");
>
> # fast-path heartbeat (exact match)
> if ($var(msg) == "HEARTBEAT" || $var(msg) == "heartbeat") {
> #route(EVAPI_HEARTBEAT);
> exit;
> }
>
> # parse only as much as needed
> $var(type) = $(var(msg){s.select,0,:});
> $var(tindex) = $(var(msg){s.select,1,:}{s.int});
> $var(tlabel) = $(var(msg){s.select,2,:}{s.int});
>
> # Calculate the offset where the JSON payload begins
> # Offset = Length(Type) + Length(Index) + Length(Label) + 3 (the
> colons)
> $var(offset) = $(var(type){s.len}) + $(var(tindex){s.len}) +
> $(var(tlabel){s.len}) + 3;
>
> xlog("L_INFO", "Part 0: '$var(type)'\n");
> xlog("L_INFO", "Part 1: '$var(tindex)'\n");
> xlog("L_INFO", "Part 2: '$var(tlabel)'\n");
>
>
> if ($var(type) == "RESPONSE" && $var(tindex) =~ "^[0-9]+$" &&
> $var(tlabel) =~ "^[0-9]+$") {
> # strip "<type>:<tindex>:<tlabel>:" prefix (payload may contain
> ':')
> # Extract the remaining value (JSON) using substring
> # 0 as the second parameter means "until the end of the string"
> $var(response) = $(var(msg){s.substr,$var(offset),0});
> xlog("L_INFO", "Part 3: '$var(response)'\n");
> # Stash the JSON by transaction key so we can read it after resume
> #$var(key) = "$var(tindex)|$var(tlabel)";
>
> jansson_get("action", $var(response), "$var(action)");
>
> xlog("L_INFO", "evapi:message-received - t_continue for
> $var(tindex)/$var(tlabel)\n");
> t_continue("$var(tindex)", "$var(tlabel)", "EVAPIRESPONSE");
>
> exit;
> }
>
> xlog("L_ERR", "evapi:message-received - invalid EVAPI message,
> replying 500\n");
> # No transaction context here; just drop.
> # actually, as we're not in a SIP context yet, the t_reply should not
> be called here
> # FIX ME - to be further tested
> # t_reply("500", "Internal Server Error");
> exit;
> }
>
> Atenciosamente / Kind Regards / Cordialement / Un saludo,
>
>
> *Sérgio Charrua*
>
> *www.kahea.ai <http://www.kahea.ai> / www.voip.pt <http://www.voip.pt>*
>
> *OpenTelecom* - Consulting for Telecoms, Lda
> Tel.: +351 <callto:+351+91+104+12+66>91 631 11 44
>
> Email : *[email protected] <[email protected]>*
>
> This message and any files or documents attached are strictly confidential
> or otherwise legally protected.
>
> It is intended only for the individual or entity named. If you are not the
> named addressee or have received this email in error, please inform the
> sender immediately, delete it from your system and do not copy or disclose
> it or its contents or use it for any purpose. Please also note that
> transmission cannot be guaranteed to be secure or error-free.
>
>
>
>
>
>
>
>
> On Wed, Jan 14, 2026 at 9:12 AM Daniel-Constantin Mierla <
> [email protected]> wrote:
>
>> Hello,
>>
>> if you watched the network traffic and the communication with the
>> external application is very fast, then you have to investigate what action
>> is slow in Kamailio config. You can set the latency-related core parameter
>> and see if anyone is reported to take long to execute.
>>
>> Cheers,
>> Daniel
>> On 13.01.26 17:36, Sergio Charrua via sr-users wrote:
>>
>> Hello all,
>>
>> using Kamilio 5.8.2 with EVAPI module, connecting to a Python client.
>> Kamailio is using following modules:
>>
>> jsonrpcs.so
>> db_mysql.so
>> db_cluster.so
>> kex.so
>> corex.so
>> tm.so
>> tmx.so
>> sl.so
>> rr.so
>> pv.so
>> maxfwd.so
>> textops.so
>> textopsx.so
>> siputils.so
>> xlog.so
>> sanity.so
>> ctl.so
>> cfg_rpc.so
>> evapi.so
>> jansson.so
>> rtjson.so
>> dispatcher.so
>> permissions.s
>> app_jsdt.so
>> uac.so
>> xhttp.so
>> xhttp_rpc.so
>> dmq.so
>> dialog.so
>> htable.so
>>
>> The (very reduced) logic is:
>> 1 - INVITE received
>> 2 - send request to EVAPI client with SIP headers transformed into JSON
>> object
>> 3 - receive response from EVAPI client
>> 4 - depending on response type, relay the call with routes supplied in
>> response using RTJSON
>>
>> On its side, EVAPI Client upon receiving request from Kamailio (step #2)
>> 1 - sends request to HTTP REST service requesting routes
>> 2 - receives full RTJSON object (may include custom headers to add or
>> update or remove)
>> 3 - return full RTJSON to Kamailio as a response
>>
>> All this is working fine. *Except* that we noticed that, under testing at
>> 1 Call per minute (not performance testing yet), the delay betway EVAPI
>> step #3 and Kamailio step #3 goes anything between 200ms up to 1.2 seconds!
>> EVAPI client is running on the same node where Kamailio is running too,
>> using 127.0.0.1:8448 for connection.
>> Knowing that there is nothing else running on the server, and that the
>> CAPS is like 1 call per minute, there is no load, no traffic, so why these
>> delays?!
>>
>> Additional settings:
>> # ----- evapi params -----
>> modparam("evapi", "workers", 4)
>> modparam("evapi", "bind_addr", "127.0.0.1:8448")
>> modparam("evapi", "netstring_format", 1)
>>
>> Some logs:
>> Jan 13 14:25:58 bl1642 /usr/local/sbin/kamailio[1949838]: INFO:
>> {1768314358.181270 1949838 2 1 INVITE
>> [email protected]} <script>: local-response
>> - replied locally
>> Jan 13 14:25:58 bl1642 /usr/local/sbin/kamailio[1949838]: INFO:
>> {1768314358.181325 1949838 1 1 INVITE
>> [email protected]} <script>: HANDLE_INVITE -
>> suspended transaction 5701 - Label: 625621129
>> Jan 13 14:25:58 bl1642 /usr/local/sbin/kamailio[1949871]: INFO:
>> {1768314358.761888 1949871 1 1 OPTIONS 123} <script>: Part 0: 'RESPONSE'
>> Jan 13 14:25:58 bl1642 /usr/local/sbin/kamailio[1949871]: INFO:
>> {1768314358.761928 1949871 1 1 OPTIONS 123} <script>: Part 1: '5701'
>> Jan 13 14:25:58 bl1642 /usr/local/sbin/kamailio[1949871]: INFO:
>> {1768314358.761936 1949871 1 1 OPTIONS 123} <script>: Part 2: '625621129'
>> Jan 13 14:25:58 bl1642 /usr/local/sbin/kamailio[1949871]: INFO:
>> {1768314358.761943 1949871 1 1 OPTIONS 123} <script>: Part 3: '{"action":
>> "ROUTE", "routes": ...
>> Jan 13 14:25:58 bl1642 /usr/local/sbin/kamailio[1949871]: INFO:
>> {1768314358.762018 1949871 1 1 OPTIONS 123} <script>:
>> evapi:message-received - t_continue for 5701/625621129
>> Jan 13 14:25:58 bl1642 /usr/local/sbin/kamailio[1949871]: INFO:
>> {1768314358.762078 1949871 1 1 INVITE
>> [email protected]} <script>: EVAPIRESPONSE -
>> TRANSACTION 5701|6256
>> Jan 13 14:25:58 bl1642 /usr/local/sbin/kamailio[1949871]: INFO:
>> {1768314358.762089 1949871 1 1 INVITE
>> [email protected]} <script>: EVAPIRESPONSE -
>> Resumed with RESPONSE ...
>>
>> Above, we can see that Kamailio sends a request to EVAPI client
>> at 1768314358.181325 and response is received by EVAPI client
>> at 1768314358.761888, about 600ms later, which is too much!
>> On the other hand, EVAPI client takes less than 20ms to receive the
>> request, query REST service and reply back to Kamailio.
>> If there were anything else between Kamailio and EVAPI client, I would
>> probably assume there was some network delay somewhere, but both services
>> are running on the same server, which is mostly idle, so no network delay
>> can be found.
>> I even captured packets with tcpdump , on port 8448, and indeed,
>> communications between Kamailio and EVAPI client is like 20 to 30ms max!
>> So, why Kamailio is taking between 500ms to 1sec to process the response
>> received from EVAPI client? at least, this is what it seems doing....
>>
>> Any clue? Any advice?
>>
>> Greatly appreciated.
>>
>> Atenciosamente / Kind Regards / Cordialement / Un saludo,
>>
>>
>> *Sérgio Charrua*
>>
>> *www.kahea.ai <http://www.kahea.ai> / www.voip.pt <http://www.voip.pt>*
>>
>> *OpenTelecom* - Consulting for Telecoms, Lda
>> Tel.: +351 <callto:+351+91+104+12+66>91 631 11 44
>>
>> Email : *[email protected] <[email protected]>*
>>
>> This message and any files or documents attached are strictly
>> confidential or otherwise legally protected.
>>
>> It is intended only for the individual or entity named. If you are not
>> the named addressee or have received this email in error, please inform the
>> sender immediately, delete it from your system and do not copy or disclose
>> it or its contents or use it for any purpose. Please also note that
>> transmission cannot be guaranteed to be secure or error-free.
>>
>>
>>
>>
>>
>>
>>
>> __________________________________________________________
>> Kamailio - Users Mailing List - Non Commercial Discussions --
>> [email protected]
>> To unsubscribe send an email to [email protected]
>> Important: keep the mailing list in the recipients, do not reply only to the
>> sender!
>>
>> --
>> Daniel-Constantin Mierla (@ asipto.com)twitter.com/miconda --
>> linkedin.com/in/miconda
>> Kamailio Consultancy, Training and Development Services -- asipto.com
>> Kamailio World Conference, May 7-8, 2026 - Berlin, Germany --
>> kamailioworld.com
>>
>>
__________________________________________________________
Kamailio - Users Mailing List - Non Commercial Discussions --
[email protected]
To unsubscribe send an email to [email protected]
Important: keep the mailing list in the recipients, do not reply only to the
sender!
