[sr-dev] [kamailio/kamailio] The tm.cancel function immediately deletes the transaction. (Issue #4011)

Hello I use the ‘**tm.t_uac_star**t’ function to send an INVITE and then the **‘tm.cancel**’ function to cancel the INVITE. But the ‘**tm.cancel**’ function immediately deletes the transaction. Kamailio can't acknowledge message 487 because the transaction has been deleted. **Callflow description:** ‘tm.t_uac_start’ Kamailio: INVITE ---> Kamailio: <--- 180 Ringing 'tm.cancel' Kamailio: CANCEL ---> Kamailio: <--- 200 OK (CANCEL) Kamailio: <--- 487 Request Terminated (INVITE) Kamailio can't send "ACK" because the transaction has been deleted **Below trace:** 21(45279) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: exec is str: {"params":["INVITE","sip:2345@sip.osp.com","sip:10.192.117.5:5049","udp:10.192.117.6:5084","From: <sip:+336111111111@fqfn-incoming.com>;tag=a5507eec786ec44a0aa7ec48e98248e4\r\nTo: <sip:2345@sip.osp.com>\r\nCSeq: 1 INVITE\r\nCall-ID: 68443192-0f66b617ce5917df\r\nContact: sip:Kasuar@10.192.117.6:5084\r\nContent-Type: application\/sdp\r\nSupported: gruu,replaces,norefersub\r\nAllow: INVITE,ACK,BYE,CANCEL,OPTIONS,NOTIFY,SUBSCRIBE,INFO,MESSAGE,UPDATE,REFER\r\nUser-Agent: tm.cancel\r\n","v=0\r\no=- 3218051986 1337943000 IN IP4 10.192.117.5\r\ns=-\r\nc=IN IP4 10.192.117.5\r\nt=0 0\r\nm=audio 5936 RTP\/AVP 0 8 101\r\na=rtpmap:0 PCMU\/8000\r\na=rtpmap:8 PCMA\/8000\r\na=rtpmap:101 telephone-event\/8000\r\na=fmtp:101 0-15\r\na=sendrecv\r\na=rtcp-rsize\r\na=ssrc:2797071403 cname:sip:1234@sip.osp.com\r\na=mid:0\r\na=minptime:20\r\na=ptime:20\r\na=label:1\r\n"],"jsonrpc":"2.0","method":"**tm.t_uac_start**","id":1} 21(45279) DEBUG: <core> [core/socket_info.c:740]: grep_sock_info(): checking if host==us: 12==12 && [10.192.117.6] == [10.192.117.6] 21(45279) DEBUG: <core> [core/socket_info.c:744]: grep_sock_info(): checking if port 5084 (advertise 0) matches port 5084 21(45279) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [From] type 4 21(45279) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [To] type 3 21(45279) DEBUG: <core> [core/parser/parse_addr_spec.c:904]: parse_addr_spec(): end of header reached, state=10 21(45279) DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): <To> [24]; uri=[sip:2345@sip.osp.com] 21(45279) DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body (24)[<sip:2345@sip.osp.com> ], to tag (0)[] 3(45261) INFO: <script>: 2024-10-31 10-54-06 [debug] /opt/kamailio/callbasic.lua:154: COMMANDE {"jsonrpc":"2.0","method":"**tm.cancel**","id":1,"params":["68443192-0f66b617ce5917df","1"]} 3(45261) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: exec is str: {"jsonrpc":"2.0","method":"tm.cancel","id":1,"params":["68443192-0f66b617ce5917df","1"]} 3(45261) DEBUG: tm [t_lookup.c:2285]: t_lookup_callid(): just locked hash index 43770, looking for transactions there: 3(45261) DEBUG: tm [t_lookup.c:2310]: t_lookup_callid(): we have a match: callid=>>Call-ID: 68443192-0f66b617ce5917df << cseq=>>CSeq: 1<< 3(45261) DEBUG: tm [t_lookup.c:2317]: t_lookup_callid(): t_lookup_callid: transaction found. 3(45261) DEBUG: tm [t_cancel.c:427]: rpc_cancel(): Now calling cancel_uacs 3(45261) DEBUG: tm [t_cancel.c:337]: cancel_branch(): sending cancel... 3(45261) DEBUG: <core> [core/parser/parse_fline.c:247]: parse_first_line(): first line type 1 (request) flags 1 3(45261) DEBUG: <core> [core/parser/msg_parser.c:722]: parse_msg(): SIP Request: 3(45261) DEBUG: <core> [core/parser/msg_parser.c:723]: parse_msg(): method: <CANCEL> 3(45261) DEBUG: <core> [core/parser/msg_parser.c:725]: parse_msg(): uri: <sip:2345@sip.osp.com> 3(45261) DEBUG: <core> [core/parser/msg_parser.c:727]: parse_msg(): version: <SIP/2.0> 3(45261) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Via] type 1 3(45261) DEBUG: <core> [core/parser/parse_via.c:1309]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKafaa.fe4571d3000000000000000000000000.0>; state=16 3(45261) DEBUG: <core> [core/parser/parse_via.c:2663]: parse_via(): end of header reached, state=5 3(45261) DEBUG: <core> [core/parser/msg_parser.c:592]: parse_headers(): Via found, flags=2 3(45261) DEBUG: <core> [core/parser/msg_parser.c:594]: parse_headers(): this is the first via 3(45261) DEBUG: app_lua [app_lua_api.c:511]: sr_lua_reload_script(): No need to reload [/opt/kamailio/kamailio.lua] is version 0 3(45261) DEBUG: app_lua [app_lua_api.c:688]: app_lua_run_ex(): executing Lua function: [[ksr_tm_event]] 3(45261) DEBUG: app_lua [app_lua_api.c:690]: app_lua_run_ex(): lua top index is: 1 3(45261) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: xinfo is str: 2024-10-31 10-54-06 [debug] /opt/kamailio/kamailio.lua:143: --> Sending request: $rm 3(45261) DEBUG: <core> [core/pvapi.c:410]: pv_cache_lookup(): pvar [$rm] found in cache 3(45261) INFO: <script>: 2024-10-31 10-54-06 [debug] /opt/kamailio/kamailio.lua:143: --> Sending request: CANCEL 3(45261) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $hdr(Hexarb) 3(45261) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $hdr(Hexarb) 3(45261) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Hexarb] type 0 3(45261) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$hdr(Hexarb)] added in cache 3(45261) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [To] type 3 3(45261) DEBUG: <core> [core/parser/parse_addr_spec.c:904]: parse_addr_spec(): end of header reached, state=10 3(45261) DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): <To> [24]; uri=[sip:2345@sip.osp.com] 3(45261) DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body (24)[<sip:2345@sip.osp.com> ], to tag (0)[] 3(45261) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [From] type 4 3(45261) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [CSeq] type 5 3(45261) DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <1> <CANCEL> 3(45261) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Call-ID] type 6 3(45261) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Max-Forwards] type 8 3(45261) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Content-Length] type 12 3(45261) DEBUG: <core> [core/parser/msg_parser.c:187]: get_hdr_field(): content_length=0 3(45261) DEBUG: <core> [core/parser/msg_parser.c:91]: get_hdr_field(): found end of header 3(45261) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Via] type 1 3(45261) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Hexarb] type 0 3(45261) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [To] type 3 3(45261) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Hexarb] type 0 3(45261) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [From] type 4 3(45261) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Hexarb] type 0 3(45261) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [CSeq] type 5 3(45261) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Hexarb] type 0 3(45261) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Call-ID] type 6 3(45261) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Hexarb] type 0 3(45261) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Max-Forwards] type 8 3(45261) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Hexarb] type 0 3(45261) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Content-Length] type 12 3(45261) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Hexarb] type 0 3(45261) DEBUG: app_lua [app_lua_mod.c:166]: sr_kemi_config_engine_lua(): execution of route type 513 with name [ksr_tm_event] returned 1 3(45261) DEBUG: jsonrpcs [jsonrpcs_mod.c:443]: jsonrpc_send_mode(): sending response with body: (nil) - 200 OK 4(45262) DEBUG: <core> [core/udp_server.c:715]: udp_rcv_loop(): received on udp socket: (106/100/329) [[SIP/2.0 200 OK 0D 0A Via: SIP/2.0/UDP 10.192.117.6:5084;branch=z9hG4bKafaa.fe4571d30000000000000000000000]] 4(45262) DEBUG: <core> [core/parser/parse_fline.c:247]: parse_first_line(): first line type 2 (reply(status)) flags 1 4(45262) DEBUG: <core> [core/parser/msg_parser.c:732]: parse_msg(): SIP Reply (status): 4(45262) DEBUG: <core> [core/parser/msg_parser.c:733]: parse_msg(): version: <SIP/2.0> 4(45262) DEBUG: <core> [core/parser/msg_parser.c:735]: parse_msg(): status: <200> 4(45262) DEBUG: <core> [core/parser/msg_parser.c:737]: parse_msg(): reason: <OK> 4(45262) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Via] type 1 4(45262) DEBUG: <core> [core/parser/parse_via.c:1309]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKafaa.fe4571d3000000000000000000000000.0>; state=16 4(45262) DEBUG: <core> [core/parser/parse_via.c:2663]: parse_via(): end of header reached, state=5 4(45262) DEBUG: <core> [core/parser/msg_parser.c:592]: parse_headers(): Via found, flags=2 4(45262) DEBUG: <core> [core/parser/msg_parser.c:594]: parse_headers(): this is the first via 4(45262) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [To] type 3 4(45262) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=501b95048bf50805 4(45262) DEBUG: <core> [core/parser/parse_addr_spec.c:904]: parse_addr_spec(): end of header reached, state=29 4(45262) DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): <To> [45]; uri=[sip:2345@sip.osp.com] 4(45262) DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body (22)[<sip:2345@sip.osp.com>], to tag (16)[501b95048bf50805] 4(45262) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [From] type 4 4(45262) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [CSeq] type 5 4(45262) DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <1> <CANCEL> 4(45262) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Call-ID] type 6 4(45262) DEBUG: <core> [core/receive.c:392]: receive_msg(): --- received sip message - reply - call-id: [68443192-0f66b617ce5917df] - cseq: [1 CANCEL] 4(45262) DEBUG: <core> [core/receive.c:263]: ksr_evrt_pre_routing(): event route core:pre-routing not defined 6(45264) DEBUG: <core> [core/udp_server.c:715]: udp_rcv_loop(): received on udp socket: (106/100/345) [[SIP/2.0 487 Request Terminated 0D 0A Via: SIP/2.0/UDP 10.192.117.6:5084;branch=z9hG4bKafaa.fe4571d3000000]] 6(45264) DEBUG: <core> [core/parser/parse_fline.c:247]: parse_first_line(): first line type 2 (reply(status)) flags 1 6(45264) DEBUG: <core> [core/parser/msg_parser.c:732]: parse_msg(): SIP Reply (status): 6(45264) DEBUG: <core> [core/parser/msg_parser.c:733]: parse_msg(): version: <SIP/2.0> 4(45262) DEBUG: app_lua [app_lua_api.c:511]: sr_lua_reload_script(): No need to reload [/opt/kamailio/kamailio.lua] is version 6(45264) DEBUG: <core> [core/parser/msg_parser.c:735]: parse_msg(): status: <487> 3(45261) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: xinfo is str: 2024-10-31 10-54-06 [debug] /opt/kamailio/kamailio.lua:56: ksr_request_route: 21.28 ms 0 4(45262) DEBUG: app_lua [app_lua_api.c:688]: app_lua_run_ex(): executing Lua function: [[ksr_reply_route]] 6(45264) DEBUG: <core> [core/parser/msg_parser.c:737]: parse_msg(): reason: <Request Terminated> 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Via] type 1 3(45261) INFO: <script>: 2024-10-31 10-54-06 [debug] /opt/kamailio/kamailio.lua:56: ksr_request_route: 21.28 ms 6(45264) DEBUG: <core> [core/parser/parse_via.c:1309]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKafaa.fe4571d 4(45262) DEBUG: app_lua [app_lua_api.c:690]: app_lua_run_ex(): lua top index is: 17 3(45261) DEBUG: app_lua [app_lua_mod.c:169]: sr_kemi_config_engine_lua(): execution of route type 1 with no name returned 1 3(45261) DEBUG: <core> [core/receive.c:531]: receive_msg(): request-route executed in: 24264 usec 3000000000000000000000000.0>; state=16 6(45264) DEBUG: <core> [core/parser/parse_via.c:2663]: parse_via(): end of header reached, state=5 6(45264) DEBUG: <core> [core/parser/msg_parser.c:592]: parse_headers(): Via found, flags=2 6(45264) DEBUG: <core> [core/parser/msg_parser.c:594]: parse_headers(): this is the first via 3(45261) DEBUG: tm [h_table.c:133]: free_cell_helper(): freeing transaction 0x735e6229d610 from t_lookup.c:2059 3(45261) WARNING: tm [h_table.c:141]: free_cell_helper(): removed cell 0x735e6229d610 is still linked in hash table (t_lookup.c:2059) 3(45261) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [To] type 3 6(45264) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=501b95048bf50805 6(45264) DEBUG: <core> [core/parser/parse_addr_spec.c:904]: parse_addr_spec(): end of header reached, state=29 6(45264) DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): <To> [45]; uri=[sip:2345@sip.osp.com] 6(45264) DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body (22)[<sip:2345@sip.osp.com>], to tag (16)[501b95048bf50805] 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [From] type 4 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [CSeq] type 5 6(45264) DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <1> <INVITE> 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Call-ID] type 6 6(45264) DEBUG: <core> [core/receive.c:392]: receive_msg(): --- received sip message - reply - call-id: [68443192-0f66b617ce5917df] - cseq: [1 INVITE] 6(45264) DEBUG: <core> [core/receive.c:263]: ksr_evrt_pre_routing(): event route core:pre-routing not defined 6(45264) DEBUG: app_lua [app_lua_api.c:511]: sr_lua_reload_script(): No need to reload [/opt/kamailio/kamailio.lua] is version 0 6(45264) DEBUG: app_lua [app_lua_api.c:688]: app_lua_run_ex(): executing Lua function: [[ksr_reply_route]] 6(45264) DEBUG: app_lua [app_lua_api.c:690]: app_lua_run_ex(): lua top index is: 17 6(45264) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: xinfo is str: 2024-10-31 10-54-06 [debug] /opt/kamailio/kamailio.lua:67: ++ Reply received $rs $rr 6(45264) DEBUG: <core> [core/pvapi.c:502]: pv_spec_lookup(): PV <$rs> is not in cache 6(45264) DEBUG: <core> [core/pvapi.c:352]: pv_cache_add(): PV cache not initialized, doing it now 6(45264) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$rs] added in cache 6(45264) DEBUG: <core> [core/pvapi.c:502]: pv_spec_lookup(): PV <$rr> is not in cache 6(45264) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$rr] added in cache 6(45264) INFO: <script>: 2024-10-31 10-54-06 [debug] /opt/kamailio/kamailio.lua:67: ++ Reply received 487 Request Terminated 6(45264) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $ci 4(45262) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: xinfo is str: 2024-10-31 10-54-06 [debug] /opt/kamailio/kamailio.lua:67: ++ Reply received $rs $rr 4(45262) DEBUG: <core> [core/pvapi.c:502]: pv_spec_lookup(): PV <$rs> is not in cache 4(45262) DEBUG: <core> [core/pvapi.c:352]: pv_cache_add(): PV cache not initialized, doing it now 4(45262) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$rs] added in cache 4(45262) DEBUG: <core> [core/pvapi.c:502]: pv_spec_lookup(): PV <$rr> is not in cache 4(45262) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$rr] added in cache 4(45262) INFO: <script>: 2024-10-31 10-54-06 [debug] /opt/kamailio/kamailio.lua:67: ++ Reply received 200 OK 4(45262) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $ci 4(45262) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $ci 3(45261) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 3(45261) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 3(45261) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 3(45261) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 3(45261) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 3(45261) DEBUG: <core> [core/xavp.c:630]: xavp_destroy_list(): destroying xavp list (nil) 3(45261) DEBUG: <core> [core/xavp.c:630]: xavp_destroy_list(): destroying xavp list (nil) 3(45261) DEBUG: <core> [core/xavp.c:630]: xavp_destroy_list(): destroying xavp list (nil) 3(45261) DEBUG: <core> [core/receive.c:635]: receive_msg(): cleaning up 4(45262) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$ci] added in cache 6(45264) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $ci 6(45264) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$ci] added in cache 4(45262) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $mb 4(45262) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $mb 6(45264) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $mb 4(45262) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$mb] added in cache 4(45262) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $mb 4(45262) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $mb 4(45262) DEBUG: <core> [core/pvapi.c:410]: pv_cache_lookup(): pvar [$mb] found in cache 4(45262) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $ci 4(45262) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $ci 4(45262) DEBUG: <core> [core/pvapi.c:410]: pv_cache_lookup(): pvar [$ci] found in cache 6(45264) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $mb 6(45264) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$mb] added in cache 6(45264) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $mb 6(45264) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $mb 6(45264) DEBUG: <core> [core/pvapi.c:410]: pv_cache_lookup(): pvar [$mb] found in cache 6(45264) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $ci 6(45264) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $ci 6(45264) DEBUG: <core> [core/pvapi.c:410]: pv_cache_lookup(): pvar [$ci] found in cache 4(45262) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: xinfo is str: 2024-10-31 10-54-06 [debug] /opt/kamailio/routing.lua:181: $rs $rm Type: term State: callout Callid: 68443192-0f66b617ce5917df 4(45262) DEBUG: <core> [core/pvapi.c:410]: pv_cache_lookup(): pvar [$rs] found in cache 4(45262) DEBUG: <core> [core/pvapi.c:502]: pv_spec_lookup(): PV <$rm> is not in cache 4(45262) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$rm] added in cache 4(45262) INFO: <script>: 2024-10-31 10-54-06 [debug] /opt/kamailio/routing.lua:181: 200 CANCEL Type: term State: callout Callid: 68443192-0f66b617ce5917df 4(45262) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $rs 4(45262) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $rs 4(45262) DEBUG: <core> [core/pvapi.c:410]: pv_cache_lookup(): pvar [$rs] found in cache 4(45262) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $rs 4(45262) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $rs 4(45262) DEBUG: <core> [core/pvapi.c:410]: pv_cache_lookup(): pvar [$rs] found in cache 4(45262) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $rs 4(45262) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $rs 4(45262) DEBUG: <core> [core/pvapi.c:410]: pv_cache_lookup(): pvar [$rs] found in cache 4(45262) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $rs 4(45262) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $rs 4(45262) DEBUG: <core> [core/pvapi.c:410]: pv_cache_lookup(): pvar [$rs] found in cache 4(45262) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $rs 4(45262) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $rs 4(45262) DEBUG: <core> [core/pvapi.c:410]: pv_cache_lookup(): pvar [$rs] found in cache 4(45262) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $rs 4(45262) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $rs 4(45262) DEBUG: <core> [core/pvapi.c:410]: pv_cache_lookup(): pvar [$rs] found in cache 4(45262) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $rm 4(45262) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $rm 4(45262) DEBUG: <core> [core/pvapi.c:410]: pv_cache_lookup(): pvar [$rm] found in cache 4(45262) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $rs 4(45262) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $rs 4(45262) DEBUG: <core> [core/pvapi.c:410]: pv_cache_lookup(): pvar [$rs] found in cache 4(45262) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $rm 4(45262) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $rm 4(45262) DEBUG: <core> [core/pvapi.c:410]: pv_cache_lookup(): pvar [$rm] found in cache 4(45262) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: xinfo is str: 2024-10-31 10-54-06 [debug] /opt/kamailio/kamailio.lua:71: ksr_reply_route: 13.63 ms 4(45262) INFO: <script>: 2024-10-31 10-54-06 [debug] /opt/kamailio/kamailio.lua:71: ksr_reply_route: 13.63 ms EBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: xinfo is str: 2024-10-31 10-54-07 0m 4(45262) DEBUG: app_lua [app_lua_mod.c:169]: sr_kemi_config_engine_lua(): execution of route type 128 with no name returned 1 [debug] /opt/kamailio/routing.lua:181: $rs $rm Type: term State: callout Callid: 68443192-0f66b617ce5917df 6(45264) DEBUG: <core> [core/pvapi.c:410]: pv_cache_lookup(): pvar [$rs] found in cache 6(45264) DEBUG: <core> [core/pvapi.c:502]: pv_spec_lookup(): PV <$rm> is not in cache 6(45264) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$rm] added in cache 4(45262) DEBUG: tm [t_lookup.c:1565]: t_check_msg(): msg (0x735e6b5b91d0) id=1/45262 global id=0/0 T start=0xffffffffffffffff 4(45262) DEBUG: tm [t_lookup.c:1410]: t_reply_matching(): t_reply_matching: hash 43770 label 0 branch 0 4(45262) DEBUG: tm [t_lookup.c:1539]: t_reply_matching(): no matching transaction exists 4(45262) DEBUG: tm [t_lookup.c:1542]: t_reply_matching(): failure to match a transaction 4(45262) DEBUG: tm [t_lookup.c:1637]: t_check_msg(): msg (0x735e6b5b91d0) id=1/45262 global id=1/45262 T end=(nil) 4(45262) DEBUG: tm [t_reply.c:2376]: reply_received(): **transaction not found** - (branch -1) 4(45262) DEBUG: app_lua [app_lua_api.c:511]: sr_lua_reload_script(): No need to reload [/opt/kamailio/kamailio.lua] is version 0 4(45262) DEBUG: app_lua [app_lua_api.c:688]: app_lua_run_ex(): executing Lua function: [[ksr_slreply]] 4(45262) DEBUG: app_lua [app_lua_api.c:690]: app_lua_run_ex(): lua top index is: 17 4(45262) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: xinfo is str: 2024-10-31 10-54-07 [debug] /opt/kamailio/kamailio.lua:169: Reply received on_sl_reply 4(45262) INFO: <script>: 2024-10-31 10-54-07 [debug] /opt/kamailio/kamailio.lua:169: Reply received on_sl_reply 4(45262) DEBUG: app_lua [app_lua_mod.c:166]: sr_kemi_config_engine_lua(): execution of route type 513 with name [ksr_slreply] returned 1 4(45262) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Server] type 29 4(45262) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Content-Length] type 12 4(45262) DEBUG: <core> [core/parser/msg_parser.c:187]: get_hdr_field(): content_length=0 4(45262) DEBUG: <core> [core/parser/msg_parser.c:91]: get_hdr_field(): found end of header 4(45262) DEBUG: <core> [core/forward.c:901]: do_forward_reply(): reply cannot be forwarded - no 2nd via 4(45262) DEBUG: <core> [core/receive.c:624]: receive_msg(): reply-route executed in: 22900 usec 4(45262) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 4(45262) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 4(45262) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 4(45262) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 4(45262) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 4(45262) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 4(45262) DEBUG: <core> [core/xavp.c:630]: xavp_destroy_list(): destroying xavp list (nil) 4(45262) DEBUG: <core> [core/xavp.c:630]: xavp_destroy_list(): destroying xavp list (nil) 4(45262) DEBUG: <core> [core/xavp.c:630]: xavp_destroy_list(): destroying xavp list (nil) 4(45262) DEBUG: <core> [core/receive.c:635]: receive_msg(): cleaning up 6(45264) INFO: <script>: 2024-10-31 10-54-07 [debug] /opt/kamailio/routing.lua:181: 487 INVITE Type: term State: callout Callid: 68443192-0f66b617ce5917df 6(45264) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $rs 6(45264) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $rs 6(45264) DEBUG: <core> [core/pvapi.c:410]: pv_cache_lookup(): pvar [$rs] found in cache 6(45264) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $hdr(RAck) 6(45264) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $hdr(RAck) 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [RAck] type 0 6(45264) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$hdr(RAck)] added in cache 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Server] type 29 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Content-Length] type 12 6(45264) DEBUG: <core> [core/parser/msg_parser.c:187]: get_hdr_field(): content_length=0 6(45264) DEBUG: <core> [core/parser/msg_parser.c:91]: get_hdr_field(): found end of header 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Via] type 1 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [RAck] type 0 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [To] type 3 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [RAck] type 0 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [From] type 4 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [RAck] type 0 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [CSeq] type 5 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [RAck] type 0 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Call-ID] type 6 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [RAck] type 0 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Server] type 29 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [RAck] type 0 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Content-Length] type 12 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [RAck] type 0 6(45264) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $hdr(Require) 6(45264) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $hdr(Require) 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Require] type 18 6(45264) DEBUG: pv [pv_core.c:3926]: pv_parse_hdr_name(): using hdr type (18) instead of <Require> 6(45264) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$hdr(Require)] added in cache 6(45264) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $hdr(RSeq) 6(45264) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $hdr(RSeq) 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [RSeq] type 0 6(45264) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$hdr(RSeq)] added in cache 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Via] type 1 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [RSeq] type 0 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [To] type 3 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [RSeq] type 0 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [From] type 4 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [RSeq] type 0 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [CSeq] type 5 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [RSeq] type 0 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Call-ID] type 6 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [RSeq] type 0 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Server] type 29 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [RSeq] type 0 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Content-Length] type 12 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [RSeq] type 0 6(45264) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $hdr(User-Agent) 6(45264) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $hdr(User-Agent) 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [User-Agent] type 28 6(45264) DEBUG: pv [pv_core.c:3926]: pv_parse_hdr_name(): using hdr type (28) instead of <User-Agent> 6(45264) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$hdr(User-Agent)] added in cache 6(45264) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $hdr(Accept) 6(45264) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $hdr(Accept) 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Accept] type 23 6(45264) DEBUG: pv [pv_core.c:3926]: pv_parse_hdr_name(): using hdr type (23) instead of <Accept> 6(45264) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$hdr(Accept)] added in cache 6(45264) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $hdr(Server) 6(45264) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $hdr(Server) 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Server] type 29 6(45264) DEBUG: pv [pv_core.c:3926]: pv_parse_hdr_name(): using hdr type (29) instead of <Server> 6(45264) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$hdr(Server)] added in cache 6(45264) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $hdr(Server) 6(45264) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $hdr(Server) 6(45264) DEBUG: <core> [core/pvapi.c:410]: pv_cache_lookup(): pvar [$hdr(Server)] found in cache 6(45264) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $hdr(Supported) 6(45264) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $hdr(Supported) 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Supported] type 17 6(45264) DEBUG: pv [pv_core.c:3926]: pv_parse_hdr_name(): using hdr type (17) instead of <Supported> 6(45264) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$hdr(Supported)] added in cache 6(45264) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $hdr(Allow) 6(45264) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $hdr(Allow) 6(45264) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Allow] type 21 6(45264) DEBUG: pv [pv_core.c:3926]: pv_parse_hdr_name(): using hdr type (21) instead of <Allow> 6(45264) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$hdr(Allow)] added in cache 6(45264) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $rm 6(45264) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $rm 6(45264) DEBUG: <core> [core/pvapi.c:410]: pv_cache_lookup(): pvar [$rm] found in cache 6(45264) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $rs 6(45264) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $rs 6(45264) DEBUG: <core> [core/pvapi.c:410]: pv_cache_lookup(): pvar [$rs] found in cache 6(45264) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: xinfo is str: 2024-10-31 10-54-07 [debug] /opt/kamailio/kamailio.lua:71: ksr_reply_route: 26.79 ms 6(45264) INFO: <script>: 2024-10-31 10-54-07 [debug] /opt/kamailio/kamailio.lua:71: ksr_reply_route: 26.79 ms 6(45264) DEBUG: app_lua [app_lua_mod.c:169]: sr_kemi_config_engine_lua(): execution of route type 128 with no name returned 1 6(45264) DEBUG: tm [t_lookup.c:1565]: t_check_msg(): msg (0x735e6b5b91d0) id=1/45264 global id=0/0 T start=0xffffffffffffffff 6(45264) DEBUG: tm [t_lookup.c:1410]: t_reply_matching(): t_reply_matching: hash 43770 label 0 branch 0 6(45264) DEBUG: tm [t_lookup.c:1539]: t_reply_matching(): no matching transaction exists 6(45264) DEBUG: tm [t_lookup.c:1542]: t_reply_matching(): failure to match a transaction 6(45264) DEBUG: tm [t_lookup.c:1637]: t_check_msg(): msg (0x735e6b5b91d0) id=1/45264 global id=1/45264 T end=(nil) 6(45264) DEBUG: tm [t_reply.c:2376]: reply_received(): transaction not found - (branch -1) 6(45264) DEBUG: app_lua [app_lua_api.c:511]: sr_lua_reload_script(): No need to reload [/opt/kamailio/kamailio.lua] is version 0 6(45264) DEBUG: app_lua [app_lua_api.c:688]: app_lua_run_ex(): executing Lua function: [[ksr_slreply]] 6(45264) DEBUG: app_lua [app_lua_api.c:690]: app_lua_run_ex(): lua top index is: 17 6(45264) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: xinfo is str: 2024-10-31 10-54-07 [debug] /opt/kamailio/kamailio.lua:169: Reply received on_sl_reply 6(45264) INFO: <script>: 2024-10-31 10-54-07 [debug] /opt/kamailio/kamailio.lua:169: Reply received on_sl_reply 6(45264) DEBUG: app_lua [app_lua_mod.c:166]: sr_kemi_config_engine_lua(): execution of route type 513 with name [ksr_slreply] returned 1 6(45264) DEBUG: <core> [core/forward.c:901]: do_forward_reply(): reply cannot be forwarded - no 2nd via 6(45264) DEBUG: <core> [core/receive.c:624]: receive_msg(): reply-route executed in: 28304 usec 6(45264) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 6(45264) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 6(45264) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 6(45264) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 6(45264) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 6(45264) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 6(45264) DEBUG: <core> [core/xavp.c:630]: xavp_destroy_list(): destroying xavp list (nil) 6(45264) DEBUG: <core> [core/xavp.c:630]: xavp_destroy_list(): destroying xavp list (nil) 6(45264) DEBUG: <core> [core/xavp.c:630]: xavp_destroy_list(): destroying xavp list (nil) 6(45264) DEBUG: <core> [core/receive.c:635]: receive_msg(): cleaning up 5(45263) DEBUG: <core> [core/udp_server.c:715]: udp_rcv_loop(): received on udp socket: (106/100/345) [[SIP/2.0 487 Request Terminated 0D 0A Via: SIP/2.0/UDP 10.192.117.6:5084;branch=z9hG4bKafaa.fe4571d3000000]] 5(45263) DEBUG: <core> [core/parser/parse_fline.c:247]: parse_first_line(): first line type 2 (reply(status)) flags 1 5(45263) DEBUG: <core> [core/parser/msg_parser.c:732]: parse_msg(): SIP Reply (status): 5(45263) DEBUG: <core> [core/parser/msg_parser.c:733]: parse_msg(): version: <SIP/2.0> 5(45263) DEBUG: <core> [core/parser/msg_parser.c:735]: parse_msg(): status: <487> 5(45263) DEBUG: <core> [core/parser/msg_parser.c:737]: parse_msg(): reason: <Request Terminated> 5(45263) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Via] type 1 5(45263) DEBUG: <core> [core/parser/parse_via.c:1309]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKafaa.fe4571d3000000000000000000000000.0>; state=16 5(45263) DEBUG: <core> [core/parser/parse_via.c:2663]: parse_via(): end of header reached, state=5 5(45263) DEBUG: <core> [core/parser/msg_parser.c:592]: parse_headers(): Via found, flags=2 5(45263) DEBUG: <core> [core/parser/msg_parser.c:594]: parse_headers(): this is the first via 5(45263) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [To] type 3 5(45263) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=501b95048bf50805 5(45263) DEBUG: <core> [core/parser/parse_addr_spec.c:904]: parse_addr_spec(): end of header reached, state=29 5(45263) DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): <To> [45]; uri=[sip:2345@sip.osp.com] 5(45263) DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body (22)[<sip:2345@sip.osp.com>], to tag (16)[501b95048bf50805] 5(45263) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [From] type 4 5(45263) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [CSeq] type 5 5(45263) DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <1> <INVITE> 5(45263) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Call-ID] type 6 5(45263) DEBUG: <core> [core/receive.c:392]: receive_msg(): --- received sip message - reply - call-id: [68443192-0f66b617ce5917df] - cseq: [1 INVITE] 5(45263) DEBUG: <core> [core/receive.c:263]: ksr_evrt_pre_routing(): event route core:pre-routing not defined 5(45263) DEBUG: app_lua [app_lua_api.c:511]: sr_lua_reload_script(): No need to reload [/opt/kamailio/kamailio.lua] is version 0 5(45263) DEBUG: app_lua [app_lua_api.c:688]: app_lua_run_ex(): executing Lua function: [[ksr_reply_route]] 5(45263) DEBUG: app_lua [app_lua_api.c:690]: app_lua_run_ex(): lua top index is: 17 5(45263) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: xinfo is str: 2024-10-31 10-54-07 [debug] /opt/kamailio/kamailio.lua:67: ++ Reply received $rs $rr 5(45263) DEBUG: <core> [core/pvapi.c:502]: pv_spec_lookup(): PV <$rs> is not in cache 5(45263) DEBUG: <core> [core/pvapi.c:352]: pv_cache_add(): PV cache not initialized, doing it now 5(45263) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$rs] added in cache 5(45263) DEBUG: <core> [core/pvapi.c:502]: pv_spec_lookup(): PV <$rr> is not in cache 5(45263) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$rr] added in cache 5(45263) INFO: <script>: 2024-10-31 10-54-07 [debug] /opt/kamailio/kamailio.lua:67: ++ Reply received 487 Request Terminated 5(45263) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $ci 5(45263) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $ci 5(45263) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$ci] added in cache 5(45263) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $mb 5(45263) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $mb 5(45263) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$mb] added in cache 5(45263) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $mb 5(45263) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $mb 5(45263) DEBUG: <core> [core/pvapi.c:410]: pv_cache_lookup(): pvar [$mb] found in cache 5(45263) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: xinfo is str: 2024-10-31 10-54-07 [debug] /opt/kamailio/kamailio.lua:71: ksr_reply_route: 6.68 ms 5(45263) INFO: <script>: 2024-10-31 10-54-07 [debug] /opt/kamailio/kamailio.lua:71: ksr_reply_route: 6.68 ms 5(45263) DEBUG: app_lua [app_lua_mod.c:169]: sr_kemi_config_engine_lua(): execution of route type 128 with no name returned 1 5(45263) DEBUG: tm [t_lookup.c:1565]: t_check_msg(): msg (0x735e6b5b91d0) id=1/45263 global id=0/0 T start=0xffffffffffffffff 5(45263) DEBUG: tm [t_lookup.c:1410]: t_reply_matching(): t_reply_matching: hash 43770 label 0 branch 0 5(45263) DEBUG: tm [t_lookup.c:1539]: t_reply_matching(): no matching transaction exists 5(45263) DEBUG: tm [t_lookup.c:1542]: t_reply_matching(): failure to match a transaction 5(45263) DEBUG: tm [t_lookup.c:1637]: t_check_msg(): msg (0x735e6b5b91d0) id=1/45263 global id=1/45263 T end=(nil) 5(45263) DEBUG: tm [t_reply.c:2376]: reply_received(): transaction not found - (branch -1) 5(45263) DEBUG: app_lua [app_lua_api.c:511]: sr_lua_reload_script(): No need to reload [/opt/kamailio/kamailio.lua] is version 0 5(45263) DEBUG: app_lua [app_lua_api.c:688]: app_lua_run_ex(): executing Lua function: [[ksr_slreply]] 5(45263) DEBUG: app_lua [app_lua_api.c:690]: app_lua_run_ex(): lua top index is: 17 5(45263) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: xinfo is str: 2024-10-31 10-54-07 [debug] /opt/kamailio/kamailio.lua:169: Reply received on_sl_reply 5(45263) INFO: <script>: 2024-10-31 10-54-07 [debug] /opt/kamailio/kamailio.lua:169: Reply received on_sl_reply 5(45263) DEBUG: app_lua [app_lua_mod.c:166]: sr_kemi_config_engine_lua(): execution of route type 513 with name [ksr_slreply] returned 1 5(45263) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Server] type 29 5(45263) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Content-Length] type 12 5(45263) DEBUG: <core> [core/parser/msg_parser.c:187]: get_hdr_field(): content_length=0 5(45263) DEBUG: <core> [core/parser/msg_parser.c:91]: get_hdr_field(): found end of header 5(45263) DEBUG: <core> [core/forward.c:901]: do_forward_reply(): reply cannot be forwarded - no 2nd via 5(45263) DEBUG: <core> [core/receive.c:624]: receive_msg(): reply-route executed in: 8967 usec 5(45263) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 5(45263) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 5(45263) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 5(45263) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 5(45263) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 5(45263) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 5(45263) DEBUG: <core> [core/xavp.c:630]: xavp_destroy_list(): destroying xavp list (nil) 5(45263) DEBUG: <core> [core/xavp.c:630]: xavp_destroy_list(): destroying xavp list (nil) 5(45263) DEBUG: <core> [core/xavp.c:630]: xavp_destroy_list(): destroying xavp list (nil) 5(45263) DEBUG: <core> [core/receive.c:635]: receive_msg(): cleaning up 7(45265) DEBUG: <core> [core/udp_server.c:715]: udp_rcv_loop(): received on udp socket: (106/100/345) [[SIP/2.0 487 Request Terminated 0D 0A Via: SIP/2.0/UDP 10.192.117.6:5084;branch=z9hG4bKafaa.fe4571d3000000]] 7(45265) DEBUG: <core> [core/parser/parse_fline.c:247]: parse_first_line(): first line type 2 (reply(status)) flags 1 7(45265) DEBUG: <core> [core/parser/msg_parser.c:732]: parse_msg(): SIP Reply (status): 7(45265) DEBUG: <core> [core/parser/msg_parser.c:733]: parse_msg(): version: <SIP/2.0> 7(45265) DEBUG: <core> [core/parser/msg_parser.c:735]: parse_msg(): status: <487> 7(45265) DEBUG: <core> [core/parser/msg_parser.c:737]: parse_msg(): reason: <Request Terminated> 7(45265) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Via] type 1 7(45265) DEBUG: <core> [core/parser/parse_via.c:1309]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKafaa.fe4571d3000000000000000000000000.0>; state=16 7(45265) DEBUG: <core> [core/parser/parse_via.c:2663]: parse_via(): end of header reached, state=5 7(45265) DEBUG: <core> [core/parser/msg_parser.c:592]: parse_headers(): Via found, flags=2 7(45265) DEBUG: <core> [core/parser/msg_parser.c:594]: parse_headers(): this is the first via 7(45265) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [To] type 3 7(45265) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=501b95048bf50805 7(45265) DEBUG: <core> [core/parser/parse_addr_spec.c:904]: parse_addr_spec(): end of header reached, state=29 7(45265) DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): <To> [45]; uri=[sip:2345@sip.osp.com] 7(45265) DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body (22)[<sip:2345@sip.osp.com>], to tag (16)[501b95048bf50805] 7(45265) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [From] type 4 7(45265) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [CSeq] type 5 7(45265) DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <1> <INVITE> 7(45265) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Call-ID] type 6 7(45265) DEBUG: <core> [core/receive.c:392]: receive_msg(): --- received sip message - reply - call-id: [68443192-0f66b617ce5917df] - cseq: [1 INVITE] 7(45265) DEBUG: <core> [core/receive.c:263]: ksr_evrt_pre_routing(): event route core:pre-routing not defined 7(45265) DEBUG: app_lua [app_lua_api.c:511]: sr_lua_reload_script(): No need to reload [/opt/kamailio/kamailio.lua] is version 0 7(45265) DEBUG: app_lua [app_lua_api.c:688]: app_lua_run_ex(): executing Lua function: [[ksr_reply_route]] 7(45265) DEBUG: app_lua [app_lua_api.c:690]: app_lua_run_ex(): lua top index is: 17 7(45265) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: xinfo is str: 2024-10-31 10-54-08 [debug] /opt/kamailio/kamailio.lua:67: ++ Reply received $rs $rr 7(45265) DEBUG: <core> [core/pvapi.c:502]: pv_spec_lookup(): PV <$rs> is not in cache 7(45265) DEBUG: <core> [core/pvapi.c:352]: pv_cache_add(): PV cache not initialized, doing it now 7(45265) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$rs] added in cache 7(45265) DEBUG: <core> [core/pvapi.c:502]: pv_spec_lookup(): PV <$rr> is not in cache 7(45265) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$rr] added in cache 7(45265) INFO: <script>: 2024-10-31 10-54-08 [debug] /opt/kamailio/kamailio.lua:67: ++ Reply received 487 Request Terminated 7(45265) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $ci 7(45265) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $ci 7(45265) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$ci] added in cache 7(45265) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $mb 7(45265) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $mb 7(45265) DEBUG: <core> [core/pvapi.c:386]: pv_cache_add(): pvar [$mb] added in cache 7(45265) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: get is str: $mb 7(45265) DEBUG: <core> [core/kemi.c:2988]: sr_kemi_pv_get_mode(): pv get: $mb 7(45265) DEBUG: <core> [core/pvapi.c:410]: pv_cache_lookup(): pvar [$mb] found in cache 7(45265) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: xinfo is str: 2024-10-31 10-54-08 [debug] /opt/kamailio/kamailio.lua:71: ksr_reply_route: 6.48 ms 7(45265) INFO: <script>: 2024-10-31 10-54-08 [debug] /opt/kamailio/kamailio.lua:71: ksr_reply_route: 6.48 ms 7(45265) DEBUG: app_lua [app_lua_mod.c:169]: sr_kemi_config_engine_lua(): execution of route type 128 with no name returned 1 7(45265) DEBUG: tm [t_lookup.c:1565]: t_check_msg(): msg (0x735e6b5b91d0) id=1/45265 global id=0/0 T start=0xffffffffffffffff 7(45265) DEBUG: tm [t_lookup.c:1410]: t_reply_matching(): t_reply_matching: hash 43770 label 0 branch 0 7(45265) DEBUG: tm [t_lookup.c:1539]: t_reply_matching(): no matching transaction exists 7(45265) DEBUG: tm [t_lookup.c:1542]: t_reply_matching(): failure to match a transaction 7(45265) DEBUG: tm [t_lookup.c:1637]: t_check_msg(): msg (0x735e6b5b91d0) id=1/45265 global id=1/45265 T end=(nil) 7(45265) DEBUG: tm [t_reply.c:2376]: reply_received(): transaction not found - (branch -1) 7(45265) DEBUG: app_lua [app_lua_api.c:511]: sr_lua_reload_script(): No need to reload [/opt/kamailio/kamailio.lua] is version 0 7(45265) DEBUG: app_lua [app_lua_api.c:688]: app_lua_run_ex(): executing Lua function: [[ksr_slreply]] 7(45265) DEBUG: app_lua [app_lua_api.c:690]: app_lua_run_ex(): lua top index is: 17 7(45265) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: xinfo is str: 2024-10-31 10-54-08 [debug] /opt/kamailio/kamailio.lua:169: Reply received on_sl_reply 7(45265) INFO: <script>: 2024-10-31 10-54-08 [debug] /opt/kamailio/kamailio.lua:169: Reply received on_sl_reply 7(45265) DEBUG: app_lua [app_lua_mod.c:166]: sr_kemi_config_engine_lua(): execution of route type 513 with name [ksr_slreply] returned 1 7(45265) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Server] type 29 7(45265) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Content-Length] type 12 7(45265) DEBUG: <core> [core/parser/msg_parser.c:187]: get_hdr_field(): content_length=0 7(45265) DEBUG: <core> [core/parser/msg_parser.c:91]: get_hdr_field(): found end of header 7(45265) DEBUG: <core> [core/forward.c:901]: do_forward_reply(): reply cannot be forwarded - no 2nd via 7(45265) DEBUG: <core> [core/receive.c:624]: receive_msg(): reply-route executed in: 8419 usec 7(45265) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 7(45265) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 7(45265) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 7(45265) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 7(45265) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 7(45265) DEBUG: <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil) 7(45265) DEBUG: <core> [core/xavp.c:630]: xavp_destroy_list(): destroying xavp list (nil) 7(45265) DEBUG: <core> [core/xavp.c:630]: xavp_destroy_list(): destroying xavp list (nil) 7(45265) DEBUG: <core> [core/xavp.c:630]: xavp_destroy_list(): destroying xavp list (nil) 7(45265) DEBUG: <core> [core/receive.c:635]: receive_msg(): cleaning up 8(45266) DEBUG: <core> [core/udp_server.c:715]: udp_rcv_loop(): received on udp socket: (106/100/345) [[SIP/2.0 487 Request Terminated 0D 0A Via: SIP/2.0/UDP 10.192.117.6:5084;branch=z9hG4bKafaa.fe4571d3000000]] 8(45266) DEBUG: <core> [core/parser/parse_fline.c:247]: parse_first_line(): first line type 2 (reply(status)) flags 1 8(45266) DEBUG: <core> [core/parser/msg_parser.c:732]: parse_msg(): SIP Reply (status): 8(45266) DEBUG: <core> [core/parser/msg_parser.c:733]: parse_msg(): version: <SIP/2.0> 8(45266) DEBUG: <core> [core/parser/msg_parser.c:735]: parse_msg(): status: <487> 8(45266) DEBUG: <core> [core/parser/msg_parser.c:737]: parse_msg(): reason: <Request Terminated> 8(45266) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Via] type 1 8(45266) DEBUG: <core> [core/parser/parse_via.c:1309]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKafaa.fe4571d3000000000000000000000000.0>; state=16 8(45266) DEBUG: <core> [core/parser/parse_via.c:2663]: parse_via(): end of header reached, state=5 8(45266) DEBUG: <core> [core/parser/msg_parser.c:592]: parse_headers(): Via found, flags=2 8(45266) DEBUG: <core> [core/parser/msg_parser.c:594]: parse_headers(): this is the first via 8(45266) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [To] type 3 8(45266) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=501b95048bf50805 8(45266) DEBUG: <core> [core/parser/parse_addr_spec.c:904]: parse_addr_spec(): end of header reached, state=29 8(45266) DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): <To> [45]; uri=[sip:2345@sip.osp.com] 8(45266) DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body (22)[<sip:2345@sip.osp.com>], to tag (16)[501b95048bf50805] 8(45266) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [From] type 4 8(45266) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [CSeq] type 5 8(45266) DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <1> <INVITE> 8(45266) DEBUG: <core> [core/parser/parse_hname2.c:315]: parse_sip_header_name(): parsed header name [Call-ID] type 6 8(45266) DEBUG: <core> [core/receive.c:392]: receive_msg(): --- received sip message - reply - call-id: [68443192-0f66b617ce5917df] - cseq: [1 INVITE] 8(45266) DEBUG: <core> [core/receive.c:263]: ksr_evrt_pre_routing(): event route core:pre-routing not defined 8(45266) DEBUG: app_lua [app_lua_api.c:511]: sr_lua_reload_script(): No need to reload [/opt/kamailio/kamailio.lua] is version 0 8(45266) DEBUG: app_lua [app_lua_api.c:688]: app_lua_run_ex(): executing Lua function: [[ksr_reply_route]] 8(45266) DEBUG: app_lua [app_lua_api.c:690]: app_lua_run_ex(): lua top index is: 17 8(45266) DEBUG: app_lua [app_lua_api.c:1023]: sr_kemi_lua_exec_func_ex(): param[0] for: xinfo is str: 2024-10-31 10-54-10 [debug] /opt/kamailio/kamailio.lua:67: ++ Reply received $rs $rr -- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/4011 You are receiving this because you are subscribed to this thread. Message ID: &lt;kamailio/kamailio/issues/4011(a)github.com&gt;