sr-dev October 2024

sr-dev@lists.kamailio.org

14 participants
110 discussions

[kamailio/kamailio] [JWT module] Verification doesn't check if the JWT is expired (Issue #4007)

by Lyuboslav Alexandrov

### Description  I used `jwt_verify()` function and expected to automatically handle the expiration check. But it doesn't. ### Troubleshooting #### Reproduction Have the following Kamailio config: ``` loadmodule "jwt.so" ... modparam("jwt", "key_mode", 0) .... $var(authorization_header_value) = "eyJhbGciOiJSUzI1NiIsInR5cCI6IkpXVCJ9.eyJzdWIiOiIxNDQ0ODEiLCJuYW1lIjoiSm9obiBEb2UiLCJpYXQiOjExMTYyMzkwMjJ9.Ce0o-10D-ghrfQ8jAZTFgJxw6pufLa6gtoCsylI9cPQo2MANVKV1sjwwKtbLfPzSobz1VhOVZ3RtbFME1GKwEOQq0MuNh7EsmMypjAyBbSPj3he0H4ysa3Lt2i8nJ2Z02j_PU387EEwziC4ilkbXNLXdx43ji_SP--dF3rij2C1Wv8AWbNloPnIAIgtTMdXRuxQPPGFhpBLfUPa54dgrRjLRSGzUJKNbszVljhpzqLM6rJ7hsf2MiB3Ww0goRH7r_9-rm4s9eYMK1xaCPlxBUIxw9bVbNkpiFypq_IcdhXnfyTsF4FUuXSgoUqGD6dOCOh6umsDfl7rrBTMRDdqT1CcBj-_CIWSwmxreVxYz1ET5cZe0oj1GnZRYFXrJzUFd1y9srV6qKY-QK1hlflONd_YZ23hpT1hXOVF0fsgB5JQBjDYBi2kLKms5zi-EAmoIVr1JVJS5-tE_iS3p40YGblI0oOOfxeKCtskgl9KtsRvUWi_25pU5BOEX8KiXVkJ2MH9KFYv2-HXrBVkZyY4kCsHIedz8k_nMfOICrh932pC2bgkQLJEZLSwtO8nTK5G1OrS_VLYwqJv0oGtnmcupexTGYiDjN6t1nqnH6s6409z16M-pKG2wwrt-40sFJh-5eDrpqs8KreSDdOYZsoB5POn7ipqZ0OfbVUCT4TzYYPA"; $var(jwt_verification) = jwt_verify("/etc/kamailio/oauth_pub.pem", "RS256", "sub='$fU'", "$var(authorization_header_value)" ); xlog("JWT verification Status: $var(jwt_verification)"); #Outputs 1 ... ``` If you decode the JWT you'll see that the timestamp in the `iat` header is in the past. #### Debugging Data #### Log Messages ``` {1 90377072 REGISTER 1d0833c1-0d75-123e-8abe-560004469ea4} <script>: JWT verification Status: 1 ``` ### Possible Solutions Compare the timestamp from the token's `iat` claim with the current timestamp and fail the verification if it's in the past. ### Additional Information * **Kamailio Version** - output of `kamailio -v` ``` version: kamailio 5.8.2 (x86_64/linux) 3fa5f4 flags: USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MMAP, PKG_MALLOC, MEM_JOIN_FREE, Q_MALLOC, F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLOCKLIST, HAVE_RESOLV_RES, TLS_PTHREAD_MUTEX_SHARED ADAPTIVE_WAIT_LOOPS 1024, MAX_RECV_BUFFER_SIZE 262144, MAX_SEND_BUFFER_SIZE 262144, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: 3fa5f4 compiled on 10:39:56 Jun 12 2024 with gcc 8.5.0 ``` * **Operating System**:  ``` Rocky Linux 8.10 (Green Obsidian) ``` -- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/4007 You are receiving this because you are subscribed to this thread. Message ID: <kamailio/kamailio/issues/4007(a)github.com>

1 week, 1 day

[kamailio/kamailio] Wrong Route header order in called party re-INVITE when using topos (Issue #3778)

by Javi Montoro

Hi There, We found a situation where topos seems to break, let me explain... Assuming the following scenario: ``` Caller ---- Callee A: ------INVITE-----> Record-Route:A.A.A.A, Record-Route:B.B.B.B B: <-----200 OK------ C: <-----INVITE------ Route: A.A.A.A, B.B.B.B D: ------200 OK-----> Record-Route:B.B.B.B, Record-Route:A.A.A.A (reversed order) E: <======INVITE===== Route: B.B.B.B, A.A.A.A (wrong) ``` A and B establish the connection from caller to callee, and topos works fine. C (re-INVITE from callee) sends the Route header according to the Record-Routes from the original INVITE (A) D is the 200 OK sent from the caller to the first re-INVITE (C) coming from the callee, with the Record-Route headers reversed, because is the order in which the callee received them; and according to the RFC it's working as intended: ``` When a UAS responds to a request with a response that establishes a dialog (such as a 2xx to INVITE), the UAS MUST copy all Record-Route header field values from the request into the response (including the URIs, URI parameters, and any Record-Route header field parameters, whether they are known or unknown to the UAS) and MUST maintain the order of those values. [...] [When a UAC receives a response...] The route set MUST be set to the list of URIs in the Record-Route header field from the response, taken in reverse order and preserving all URI parameters. ``` E takes the Route order from the last 200 OK ignoring they are in reversed order and assuming the top one is the first one, when it should be the other way around, sending to an IP address not reachable from the callee. And I think here is the issue, topos should not update the path on the Record-Routes from a 200 OK but if it does, it should take the reverse order When disabling topos, everything works fine, or with topos enabled, by setting rr_update=0 works for us, but what if there is a real path update, rr_update=0 wouldn't work for us anymore. The Kamailio version is 5.8.0-rc0 Let me know if you need more information. Thanks a lot, Javi -- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/3778 You are receiving this because you are subscribed to this thread. Message ID: <kamailio/kamailio/issues/3778(a)github.com>

1 week, 1 day

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

by JuanPascual2

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: <kamailio/kamailio/issues/4011(a)github.com>

1 week, 1 day

[kamailio/kamailio] tm: move local-request event route to the right location to access CANCEL (PR #3979)

by Xenofon Karamanos

#### Pre-Submission Checklist    - [x] Commit message has the format required by CONTRIBUTING guide - [x] Commits are split per component (core, individual modules, libs, utils, ...) - [x] Each component has a single commit (if not, squash them into one commit) - [x] No commits to README files for modules (changes must be done to docbook files in `doc/` subfolder, the README file is autogenerated) #### Type Of Change - [x] Small bug fix (non-breaking change which fixes an issue) - [ ] New feature (non-breaking change which adds new functionality) - [ ] Breaking change (fix or feature that would change existing functionality) #### Checklist:  - [x] PR should be backported to stable branches - [x] Tested changes locally - [x] Related to issue #3831 #### Description  This PR fixes the error introduced in #3962, about not being able to access the generated CANCEL message. You can view, comment on, or merge this pull request online at: https://github.com/kamailio/kamailio/pull/3979 -- Commit Summary -- * tm: move local-request event route to the right location to access CANCEL -- File Changes -- M src/modules/tm/t_cancel.c (93) -- Patch Links -- https://github.com/kamailio/kamailio/pull/3979.patch https://github.com/kamailio/kamailio/pull/3979.diff -- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/pull/3979 You are receiving this because you are subscribed to this thread. Message ID: <kamailio/kamailio/pull/3979(a)github.com>

1 week, 2 days

[kamailio/kamailio] Service crashed for IMS VoLTE MT call (Issue #3973)

by citicims

### Description  ### Troubleshooting #### Reproduction  #### Debugging Data ``` root@imstester04:~/core_dump_test# gdb kamailio core._usr_local_sbin_kamailio.0.d660bb15-1623-4c0c-ae29-64c78dc89d8c.3799655.792169952 GNU gdb (Ubuntu 9.2-0ubuntu1~20.04.2) 9.2 Copyright (C) 2020 Free Software Foundation, Inc. License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html> This is free software: you are free to change and redistribute it. There is NO WARRANTY, to the extent permitted by law. Type "show copying" and "show warranty" for details. This GDB was configured as "x86_64-linux-gnu". Type "show configuration" for configuration details. For bug reporting instructions, please see: <http://www.gnu.org/software/gdb/bugs/>. Find the GDB manual and other documentation resources online at: <http://www.gnu.org/software/gdb/documentation/>. For help, type "help". Type "apropos word" to search for commands related to "word"... Reading symbols from kamailio... [New LWP 3799655] [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1". Core was generated by `/usr/local/sbin/kamailio -P /var/run/kamailio_pcscf/kamailio_pcscf.pid -f /etc/'. Program terminated with signal SIGABRT, Aborted. #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50 50 ../sysdeps/unix/sysv/linux/raise.c: No such file or directory. (gdb) bt full #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50 set = {__val = {0, 19989655252, 140370540584975, 1725509713, 94706844523408, 341, 64424509453, 21474836492, 532575944712, 1065151889412, 140368121167872, 28800, 94706843944736, 560, 71148340464, 0}} pid = <optimized out> tid = <optimized out> ret = <optimized out> #1 0x00007faa94995859 in __GI_abort () at abort.c:79 save_stage = 1 act = {__sigaction_handler = {sa_handler = 0x0, sa_sigaction = 0x0}, sa_mask = {__val = {0, 140366190491840, 140366190223360, 0, 0, 0, 0, 0, 94706838593952, 94706840315664, 94706840316072, 140366318452096, 2001317716380379136, 0, 94706840315898, 0}}, sa_flags = -1483647068, sa_restorer = 0x7faa94a8b410 <__syslog>} sigs = {__val = {32, 0 <repeats 15 times>}} #2 0x00005622a778e1c7 in qm_debug_check_frag (qm=0x7fa98ce82000, f=0x7fa9948cbd80, file=0x7faa908fc84e "rom %s:%u\n", line=171, efile=0x5622a7932729 "core/mem/q_malloc.c", eline=546) at core/mem/q_malloc.c:143 p = 0x0 __func__ = "qm_debug_check_frag" #3 0x00005622a77923f8 in qm_free (qmp=0x7fa98ce82000, p=0x7fa9948cbdc0, file=0x7faa908fc84e "rom %s:%u\n", func=0x7faa908fc460 "%s%s%sadd_blind failed\n", line=171, mname=0x7faa908fc28e "") at core/mem/q_malloc.c:546 qm = 0x7fa98ce82000 f = 0x7fa9948cbd80 size = 0 next = 0x0 prev = 0x0 __func__ = "qm_free" #4 0x00007faa907e3749 in free_cell_helper (dead_cell=0x7fa994875c90, silent=0, fname=0x7faa90915362 <__func__.11447+2> "_init_timers", fline=651) at h_table.c:126 b = 0x0 i = 0 rpl = 0x7ffca5bc65e0 tt = 0x1 foo = 0x0 cbs = 0x7fa98cfb76d0 cbs_tmp = 0x7faa907e1041 <t_write_req+481> __func__ = "free_cell_helper" #5 0x00007faa9089f28f in wait_handler (ti=872968975, wait_tl=0x7fa994875d48, data=0x7fa994875c90) at timer.c:651 p_cell = 0x7fa994875c90 ret = 0 unlinked = 0 rcount = 1 __func__ = "wait_handler" #6 0x00005622a7522813 in timer_list_expire (t=872968975, h=0x7fa98cf0a950, slow_l=0x7fa98cf0dd50, slow_mark=6936) at core/timer.c:861 tl = 0x7fa994875d48 ret = 0 #7 0x00005622a7522d52 in timer_handler () at core/timer.c:925 saved_ticks = 872968975 run_slow_timer = 0 i = 792 __func__ = "timer_handler" #8 0x00005622a7523280 in timer_main () at core/timer.c:963 No locals. #9 0x00005622a744501a in main_loop () at main.c:1932 i = 64 pid = 0 si = 0x0 si_desc = "udp receiver child=63 sock=10.51.0.10:20004\000\324\002\000\000\003\000\000\000\345\002\000\000\000h\214\017\334\033\306\033\000\000\000\000\000\000\000\000\210��\247\"V\000\000\000\000\000\000\000\000\000\000\303W\221\247\"V\000\000\345\002\000\000\000\000\000\000\020\264\250\224\252\177\000\000\340i\274\245\374\177\000\000\061\237_\247\"V\000" nrprocs = 64 woneinit = 1 __func__ = "main_loop" #10 0x00005622a7450425 in main (argc=13, argv=0x7ffca5bc6f48) at main.c:3257 cfg_stream = 0x5622a7b512a0 --Type <RET> for more, q to quit, c to continue without paging--c c = -1 r = 0 tmp = 0x7ffca5bc7e58 "" tmp_len = 32682 port = 5060 proto = 0 aproto = 0 ahost = 0x0 aport = 0 options = 0x5622a78c0368 ":f:cm:M:dVIhEeb:B:l:L:n:vKrRDTN:W:w:t:u:g:P:G:SQ:O:a:A:x:X:Y:" ret = -1 seed = 3374692201 rfd = 4 debug_save = 0 debug_flag = 0 dont_fork_cnt = 0 n_lst = 0x0 p = 0x7faa94cfa410 "" st = {st_dev = 25, st_ino = 754, st_nlink = 2, st_mode = 16832, st_uid = 0, st_gid = 0, __pad0 = 0, st_rdev = 0, st_size = 40, st_blksize = 4096, st_blocks = 0, st_atim = {tv_sec = 1717582113, tv_nsec = 155483622}, st_mtim = {tv_sec = 1717582113, tv_nsec = 155483622}, st_ctim = {tv_sec = 1717582113, tv_nsec = 155483622}, __glibc_reserved = {0, 0, 0}} l1 = 4096 tbuf = "\020n\274\245\374\177\000\000\273\327��\252\177", '\000' <repeats 18 times>, "��\277X��\377\377\000\000\000\000\000\000\000\000\004\000\000\000\000\000\000\000\001\000\000\000\000\000\000\000\000\207��\252\177\000\000@#\227\224\252\177\000\000`\201��\252\177\000\000\001l\274\245\374\177\000\000\350y��\252\177", '\000' <repeats 26 times>, "\220\274\266\224\252\177\000\000\004\000\000\024\000\000\000\000 \224\267\224\252\177", '\000' <repeats 130 times>... option_index = 0 long_options = {{name = 0x5622a78c28f6 "help", has_arg = 0, flag = 0x0, val = 104}, {name = 0x5622a78bd54c "version", has_arg = 0, flag = 0x0, val = 118}, {name = 0x5622a78c28fb "alias", has_arg = 1, flag = 0x0, val = 1024}, {name = 0x5622a78c2901 "subst", has_arg = 1, flag = 0x0, val = 1025}, {name = 0x5622a78c2907 "substdef", has_arg = 1, flag = 0x0, val = 1026}, {name = 0x5622a78c2910 "substdefs", has_arg = 1, flag = 0x0, val = 1027}, {name = 0x5622a78c291a "server-id", has_arg = 1, flag = 0x0, val = 1028}, {name = 0x5622a78c2924 "loadmodule", has_arg = 1, flag = 0x0, val = 1029}, {name = 0x5622a78c292f "modparam", has_arg = 1, flag = 0x0, val = 1030}, {name = 0x5622a78c2938 "log-engine", has_arg = 1, flag = 0x0, val = 1031}, {name = 0x5622a78c2943 "debug", has_arg = 1, flag = 0x0, val = 1032}, {name = 0x5622a78c2949 "cfg-print", has_arg = 0, flag = 0x0, val = 1033}, {name = 0x5622a78c2953 "atexit", has_arg = 1, flag = 0x0, val = 1034}, {name = 0x5622a78c295a "all-errors", has_arg = 0, flag = 0x0, val = 1035}, {name = 0x0, has_arg = 0, flag = 0x0, val = 0}} __func__ = "main" (gdb) (gdb) (gdb) ``` #### Log Messages #### SIP Traffic ### Possible Solutions ### Additional Information * **Kamailio Version** - output of `kamailio -v` `Kamailio release 5.8.2`` ``` * **Operating System**:  ``` (paste your output here) ``` -- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/3973 You are receiving this because you are subscribed to this thread. Message ID: <kamailio/kamailio/issues/3973(a)github.com>

1 week, 4 days

[kamailio/kamailio] fr_timer documentation mistake (Issue #3939)

by Dmitry Sinina

Documentation https://www.kamailio.org/docs/modules/devel/modules/tm.html#tm.p.fr_timer says: >Timer which hits if no **final reply** for a request or ACK for a negative INVITE reply arrives (in milliseconds). Looks like it is not correct description - fr_timer value works until 1xx(not **final**) response received and then timer restarted with fr_inv_timer value there: https://github.com/kamailio/kamailio/blob/master/src/modules/tm/t_reply.c#L… Looks like old doc from sip router https://sip-router.org/wiki/ref_manual/timers explains it correctly: > fr_timer This timer is used for all SIP requests. It hits if no reply for an INVITE request or other request has been received (F in milliseconds). If a provisional reply is received for an INVITE (any 1xx), then the fr_inv_timer will be used instead. And if no replies (at all) for an INVITE are received before `fr_timer` hits, the transaction is terminated with a 408 in failure route. -- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/3939 You are receiving this because you are subscribed to this thread. Message ID: <kamailio/kamailio/issues/3939(a)github.com>

1 week, 4 days

[kamailio/kamailio] Module CNCXX coredump Kamailio version 5.8.2 (Issue #4009)

by itpanda2024

### Description We upgrade Kamailio from V5.6.5 to V5.8.2 . When call out , out of credit and drop calls. Kamailio v5.8.2 crashed . We think our system not enough memory so we up to memory but the same issue. Anyone met this issue , please help us. Thanks Our system : - OS: Centos 9 stream - Kamailo vesion 5.8.2 #### Reproduction #### Debugging Data <Program terminated with signal SIGSEGV, Segmentation fault. #0 0x00007f0f1f38902c in __delete_call (call=0x7f0f207d4d90, credit_data=0x7f0f203d42e0) at cnxcc_mod.c:879 879 clist_rm(call, next, prev); Missing separate debuginfos, use: dnf debuginfo-install MariaDB-shared-10.5.25-1.el9.x86_64 hiredis-1.0.2-2.el9.x86_64 (gdb) bt full #0 0x00007f0f1f38902c in __delete_call (call=0x7f0f207d4d90, credit_data=0x7f0f203d42e0) at cnxcc_mod.c:879 __func__ = "__delete_call" #1 0x00007f0f1f383f27 in __stop_billing (callid=0x7f0f207d7378) at cnxcc_mod.c:643 cd_entry = 0x7f0f204f8360 call = 0x7f0f207d4d90 hts = 0x7f0f1f3bf910 <_data+48> credit_data = 0x7f0f203d42e0 __func__ = "__stop_billing" #2 0x00007f0f1f381928 in __dialog_terminated_callback (cell=0x7f0f207d7300, type=64, _params=0x7f0f1f7a8800 <params>) at cnxcc_mod.c:479 __func__ = "__dialog_terminated_callback" #3 0x00007f0f1f6f7490 in run_dlg_callbacks (type=64, dlg=0x7f0f207d7300, req=0x7f0f40eda090, rpl=0x0, dir=2, dlg_data=0x0) at dlg_cb.c:269 cb = 0x7f0f207d7860 __func__ = "run_dlg_callbacks" #4 0x00007f0f1f725c84 in dlg_terminated (req=0x7f0f40eda090, dlg=0x7f0f207d7300, dir=2) at dlg_handlers.c:404 iuid = 0x0 __func__ = "dlg_terminated" #5 0x00007f0f1f735844 in dlg_onroute (req=0x7f0f40eda090, route_params=0x7ffe01fc4a70, param=0x0) at dlg_handlers.c:1502 dlg = 0x7f0f207d7300 iuid = 0x7f0f20cfc690 val = {s = 0x9f4ae7 <buf+775> "2e3.2d72>\r\nP-SR-XUID: atpsh-6722434b-b03-6\r\n\r\n", len = 8} callid = { s = 0x9f4924 <buf+324> "3506e2a7-0fdc-123e-aebc-00505697ee23\r\nCSeq: 90509168 BYE\r\nUser-Agent: FreeSWITCH\r\nAllow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE\r\nSupporte"..., len = 36} ftag = { s = 0x9f48ce <buf+238> "FF27yjy610cZS\r\nTo: \"sipp\" <sip:0999999990@172.16.172.221>;tag=BU30ZvQFDtgHS\r\nCall-ID: 3506e2a7-0fdc-123e-aebc-00505697ee23\r\nCSeq: 90509168 BYE\r\nUser-Agent: FreeSWITCH\r\nAllow: INVITE, ACK, BYE, CANCEL,"..., len = 13} ttag = { s = 0x9f490c <buf+300> "BU30ZvQFDtgHS\r\nCall-ID: 3506e2a7-0fdc-123e-aebc-00505697ee23\r\nCSeq: 90509168 BYE\r\nUser-Agent: FreeSWITCH\r\nAllow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBL"..., len = 13} h_entry = 994 h_id = 10194 new_state = 5 old_state = 4 unref = 2 event = 7 timeout = 0 reset = 0 dir = 2 ret = 0 __func__ = "dlg_onroute" #6 0x00007f0f1fae7e88 in run_rr_callbacks (req=0x7f0f40eda090, rr_param=0x7ffe01fc4b30) at rr_cb.c:96 l_param = { s = 0x9f4a6b <buf+651> "lr;ftag=BU30ZvQFDtgHS;vsf=", 'A' <repeats 36 times>, "BgM-;vst=", 'A' <repeats 37 times>, "QEAAwUIADA-;did=2e3.2d72>\r\nP-SR-XUID: atpsh-6722434b-b03-6\r\n\r\n", len = 132} --Type <RET> for more, q to quit, c to continue without paging--c cbp = 0x7f0f40edfa10 __func__ = "run_rr_callbacks" #7 0x00007f0f1fad6e59 in after_loose (_m=0x7f0f40eda090, preloaded=0) at loose.c:1021 hdr = 0x7f0f40e08460 puri = {user = {s = 0x0, len = 0}, passwd = {s = 0x0, len = 0}, host = { s = 0x9f4a56 <buf+630> "172.16.172.221:65000;lr;ftag=BU30ZvQFDtgHS;vsf=", 'A' <repeats 36 times>, "BgM-;vst=", 'A' <repeats 37 times>, "QEAAwUIADA-;did=2e3.2d72>\r\nP-SR-XUID: atpsh-6722434b-b03-6\r\n\r\n", len = 14}, port = { s = 0x9f4a65 <buf+645> "65000;lr;ftag=BU30ZvQFDtgHS;vsf=", 'A' <repeats 36 times>, "BgM-;vst=", 'A' <repeats 37 times>, "QEAAwUIADA-;did=2e3.2d72>\r\nP-SR-XUID: atpsh-6722434b-b03-6\r\n\r\n", len = 5}, params = { s = 0x9f4a6b <buf+651> "lr;ftag=BU30ZvQFDtgHS;vsf=", 'A' <repeats 36 times>, "BgM-;vst=", 'A' <repeats 37 times>, "QEAAwUIADA-;did=2e3.2d72>\r\nP-SR-XUID: atpsh-6722434b-b03-6\r\n\r\n", len = 132}, sip_params = { s = 0x9f4a6b <buf+651> "lr;ftag=BU30ZvQFDtgHS;vsf=", 'A' <repeats 36 times>, "BgM-;vst=", 'A' <repeats 37 times>, "QEAAwUIADA-;did=2e3.2d72>\r\nP-SR-XUID: atpsh-6722434b-b03-6\r\n\r\n", len = 132}, headers = {s = 0x0, len = 0}, port_no = 65000, proto = 0, type = SIP_URI_T, flags = 0, transport = {s = 0x0, len = 0}, ttl = {s = 0x0, len = 0}, user_param = {s = 0x0, len = 0}, maddr = { s = 0x0, len = 0}, method = {s = 0x0, len = 0}, lr = { s = 0x9f4a6b <buf+651> "lr;ftag=BU30ZvQFDtgHS;vsf=", 'A' <repeats 36 times>, "BgM-;vst=", 'A' <repeats 37 times>, "QEAAwUIADA-;did=2e3.2d72>\r\nP-SR-XUID: atpsh-6722434b-b03-6\r\n\r\n", len = 2}, r2 = {s = 0x0, len = 0}, gr = {s = 0x0, len = 0}, transport_val = { s = 0x0, len = 0}, ttl_val = {s = 0x0, len = 0}, user_param_val = {s = 0x0, len = 0}, maddr_val = {s = 0x0, len = 0}, method_val = {s = 0x0, len = 0}, lr_val = {s = 0x0, len = 0}, r2_val = {s = 0x0, len = 0}, gr_val = {s = 0x0, len = 0}} rt = 0x7f0f40e08660 res = 1 status = 1 uri = { s = 0x9f4a52 <buf+626> "sip:172.16.172.221:65000;lr;ftag=BU30ZvQFDtgHS;vsf=", 'A' <repeats 36 times>, "BgM-;vst=", 'A' <repeats 37 times>, "QEAAwUIADA-;did=2e3.2d72>\r\nP-SR-XUID: atpsh-6722434b-b03-6\r\n\r\n", len = 157} uri_is_myself = 1 use_ob = 0 rparams = { s = 0x9f4a6b <buf+651> "lr;ftag=BU30ZvQFDtgHS;vsf=", 'A' <repeats 36 times>, "BgM-;vst=", 'A' <repeats 37 times>, "QEAAwUIADA-;did=2e3.2d72>\r\nP-SR-XUID: atpsh-6722434b-b03-6\r\n\r\n", len = 132} __func__ = "after_loose" #8 0x00007f0f1fad75e5 in loose_route_mode (_m=0x7f0f40eda090, _mode=0) at loose.c:1056 ret = 0 __func__ = "loose_route_mode" #9 0x00007f0f1fae9cfb in w_loose_route (msg=0x7f0f40eda090, p1=0x0, p2=0x0) at rr_mod.c:273 No locals. #10 0x0000000000443202 in do_action (h=0x7ffe01fc56e0, a=0x7f0f40e9d320, msg=0x7f0f40eda090) at core/action.c:1121 ret = -5 li = 0 v = 0 dst = {send_sock = 0x0, to = {s = {sa_family = 0, sa_data = '\000' <repeats 13 times>}, sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}, sas = {ss_family = 0, __ss_padding = '\000' <repeats 86 times>, "\020\016\272@\017\177", '\000' <repeats 25 times>, __ss_align = 0}}, id = 0, send_flags = {f = 0, blst_imask = 0}, proto = 0 '\000', proto_pad0 = 0 '\000', proto_pad1 = 0} tmp = 0x0 new_uri = 0x0 end = 0x0 crt = 0x0 cmd = 0x7f0f40b91310 len = 0 user = 0 uri = {user = {s = 0x0, len = 0}, passwd = {s = 0x0, len = 0}, host = {s = 0x0, len = 0}, port = {s = 0x0, len = 0}, params = { s = 0x0, len = 0}, sip_params = {s = 0x0, len = 0}, headers = {s = 0x0, len = 0}, port_no = 0, proto = 0, type = ERROR_URI_T, flags = 0, transport = {s = 0x0, len = 0}, ttl = {s = 0x0, len = 0}, user_param = {s = 0x0, len = 0}, maddr = {s = 0x0, len = 0}, method = {s = 0x0, len = 0}, lr = {s = 0x0, len = 0}, r2 = {s = 0x0, len = 0}, gr = {s = 0x0, len = 0}, transport_val = {s = 0x0, len = 0}, ttl_val = {s = 0x0, len = 0}, user_param_val = {s = 0x0, len = 0}, maddr_val = {s = 0x0, len = 0}, method_val = { s = 0x0, len = 0}, lr_val = {s = 0x0, len = 0}, r2_val = {s = 0x0, len = 0}, gr_val = {s = 0x0, len = 0}} next_hop = {user = {s = 0x0, len = 0}, passwd = {s = 0x0, len = 0}, host = {s = 0x0, len = 0}, port = {s = 0x0, len = 0}, params = { s = 0x0, len = 0}, sip_params = {s = 0x0, len = 0}, headers = {s = 0x0, len = 0}, port_no = 0, proto = 0, type = ERROR_URI_T, flags = 0, transport = {s = 0x0, len = 0}, ttl = {s = 0x0, len = 0}, user_param = {s = 0x0, len = 0}, maddr = {s = 0x0, len = 0}, method = {s = 0x0, len = 0}, lr = {s = 0x0, len = 0}, r2 = {s = 0x0, len = 0}, gr = {s = 0x0, len = 0}, transport_val = {s = 0x0, len = 0}, ttl_val = {s = 0x0, len = 0}, user_param_val = {s = 0x0, len = 0}, maddr_val = {s = 0x0, len = 0}, method_val = { s = 0x0, len = 0}, lr_val = {s = 0x0, len = 0}, r2_val = {s = 0x0, len = 0}, gr_val = {s = 0x0, len = 0}} u = 0x0 port = 0 dst_host = 0x0 i = 0 flags = 0 avp = 0x7f0f40eda090 st = {flags = 0, id = 0, name = {n = 0, s = {s = 0x0, len = 0}, re = 0x0}, avp = 0x0} sct = 0x7ffe01fc5570 sjt = 0x7f0f40e9bdb0 rve = 0x0 mct = 0x0 rv = 0x0 rv1 = 0x7f0f40e65470 c1 = {cache_type = RV_CACHE_EMPTY, val_type = RV_NONE, c = {avp_val = {n = 0, s = {s = 0x0, len = 0}, re = 0x0}, pval = {rs = { s = 0x0, len = 0}, ri = 0, flags = 0}}, i2s = '\000' <repeats 21 times>} s = {s = 0x0, len = 0} srevp = {0x0, 0x0} evp = {data = 0x0, obuf = {s = 0x0, len = 0}, rcv = 0x0, dst = 0x0, req = 0x0, rpl = 0x0, rplcode = 0, mode = 0} mod_f_params = {{type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, {type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, { type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, { type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, { type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, { type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, { type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, { type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}} __func__ = "do_action" #11 0x0000000000450a6d in run_actions (h=0x7ffe01fc56e0, a=0x7f0f40e9d320, msg=0x7f0f40eda090) at core/action.c:1618 t = 0x7f0f40e9d320 ret = -1 tvb = {tv_sec = 0, tv_usec = 0} tve = {tv_sec = 0, tv_usec = 0} tz = {tz_minuteswest = 0, tz_dsttime = 0} tdiff = 533967288 __func__ = "run_actions" #12 0x000000000045110f in run_actions_safe (h=0x7ffe01fc6b70, a=0x7f0f40e9d320, msg=0x7f0f40eda090) at core/action.c:1681 ctx = {rec_lev = 1, run_flags = 0, last_retcode = 0, jmp_env = {{__jmpbuf = {4294967296, 7972416043526547515, 140728931744408, 4394786, 9616872, 139703624372224, 7972416043509770299, -7971453441872074693}, __mask_was_saved = 0, __saved_mask = { __val = {139702937259984, 0, 0, 140728931735408, 4294967296, 140728931744408, 4394786, 9616872, 139703624372224, 140728931735792, 6261792, 140728931735696, 139702934448925, 0, 140728931735836, 139703490298096}}}}} ret = 33315352 ign_on_break = 0 #13 0x00000000005f3e0c in rval_get_long (h=0x7ffe01fc6b70, msg=0x7f0f40eda090, i=0x7ffe01fc5f60, rv=0x7f0f40e9d488, cache=0x0) at core/rvalue.c:973 r_avp = 0x0 avp_val = {n = 9616872, s = {s = 0x92bde8 "\340\334A", len = 1223135232}, re = 0x92bde8} pval = {rs = {s = 0x400000000 <error: Cannot access memory at address 0x400000000>, len = 33316704}, ri = 8623258264, flags = 533967288} tmp = {s = 0x0, len = 1} s = 0x0 r = 0 ret = 0 destroy_pval = 0 __func__ = "rval_get_long" #14 0x00000000005f8c20 in rval_expr_eval_long (h=0x7ffe01fc6b70, msg=0x7f0f40eda090, res=0x7ffe01fc5f60, rve=0x7f0f40e9d480) at core/rvalue.c:1854 i1 = 1 i2 = 140728931744408 ret = -1 c1 = {cache_type = RV_CACHE_EMPTY, val_type = RV_NONE, c = {avp_val = {n = 0, s = {s = 0x0, len = 0}, re = 0x0}, pval = {rs = { s = 0x0, len = 0}, ri = 0, flags = 0}}, i2s = '\000' <repeats 20 times>, "\001"} c2 = {cache_type = RV_CACHE_EMPTY, val_type = RV_NONE, c = {avp_val = {n = 139703490551952, s = {s = 0x7f0f40eda090 "@", len = 0}, re = 0x7f0f40eda090}, pval = {rs = {s = 0x7f0f40eda090 "@", len = 0}, ri = 0, flags = 0}}, i2s = '\000' <repeats 21 times>} rv1 = 0x7f0f1fcb3b77 <t_check_trans+249> rv2 = 0x7ffe01fc5a30 __func__ = "rval_expr_eval_long" #15 0x0000000000442c83 in do_action (h=0x7ffe01fc6b70, a=0x7f0f40ea0e60, msg=0x7f0f40eda090) at core/action.c:1097 ret = -5 li = 7972416043847411771 v = 0 dst = {send_sock = 0x7ffe01fc5ff0, to = {s = {sa_family = 15884, sa_data = "_", '\000' <repeats 12 times>}, sin = { sin_family = 15884, sin_port = 95, sin_addr = {s_addr = 0}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = { sin6_family = 15884, sin6_port = 95, sin6_flowinfo = 0, sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}, sas = {ss_family = 15884, __ss_padding = "_", '\000' <repeats 25 times>, "\377\377\377\377\000\000\000\000\000\000\000\000(^\346@\017\177\000\000\210b\374\001\376\177\000\000\220\240\355@\017\177\000\000pk\374\001\376\177\000\000轒\000\000\000\000\000\000\220\347H\017\177\000\0000`\374\001\376\177\000\000\017\021E\000\000\000\000\000\240`\374\001\376\177\000\000\220\240\355@\017\177\000", __ss_align = 139703490068560}}, id = 33319792, send_flags = {f = 32766, blst_imask = 0}, proto = 0 '\000', proto_pad0 = 0 '\000', proto_pad1 = 0} tmp = 0x8000000 <error: Cannot access memory at address 0x8000000> new_uri = 0x7ffe01fc6160 "\b" end = 0x7f0f40ee3f60 "X-FS-Support" crt = 0x7f0f1fdcfaa6 <pkg_proc_update_stats+115> "H\213\r\203l" cmd = 0x7ffe01fc6120 len = 32766 user = 33317200 uri = {user = {s = 0x0, len = 0}, passwd = {s = 0x0, len = 0}, host = {s = 0x0, len = 0}, port = { s = 0xffffffff01fc7a98 <error: Cannot access memory at address 0xffffffff01fc7a98>, len = 0}, params = { s = 0x92bde8 "\340\334A", len = 0}, sip_params = {s = 0x7ffe01fc7a98 "?~\374\001\376\177", len = 4394786}, headers = { s = 0x92bde8 "\340\334A", len = 1223135232}, port_no = 24256, proto = 508, type = 32766, flags = (URI_USER_NORMALIZE | URI_SIP_USER_PHONE | unknown: 0x45110c), transport = {s = 0x0, len = 1089314960}, ttl = { s = 0x7f0f40e65bd0 "\200\001", len = 33319792}, user_param = {s = 0x0, len = -1}, maddr = { s = 0x100000000 <error: Cannot access memory at address 0x100000000>, len = -234461125}, method = { s = 0x7ffe01fc7a98 "?~\374\001\376\177", len = 4394786}, lr = {s = 0x92bde8 "\340\334A", len = 1223135232}, r2 = { s = 0x6ea3b626f106683b <error: Cannot access memory at address 0x6ea3b626f106683b>, len = 1168533563}, gr = {s = 0x0, len = 0}, transport_val = {s = 0x0, len = 5531605}, ttl_val = {s = 0x0, len = 0}, user_param_val = {s = 0x7ffe01fc62f0 "\200\003", len = 33317320}, maddr_val = {s = 0x7ffe01fc61cc "", len = 1088756432}, method_val = {s = 0x0, len = 33317872}, lr_val = { s = 0x0, len = 0}, r2_val = {s = 0x0, len = 0}, gr_val = {s = 0x0, len = -1}} next_hop = {user = {s = 0x0, len = 0}, passwd = {s = 0x0, len = 0}, host = {s = 0x0, len = 0}, port = {s = 0x0, len = 0}, params = { s = 0x7ffe01fc7a98 "?~\374\001\376\177", len = 4394786}, sip_params = {s = 0x92bde8 "\340\334A", len = 1223135232}, headers = { s = 0x7ffe01fc5db0 "\300^\374\001\376\177", len = 4524653}, port_no = 0, proto = 0, type = ERROR_URI_T, flags = 0, transport = { s = 0x0, len = 0}, ttl = {s = 0x0, len = 1089314960}, user_param = {s = 0x7f0f40e65bd0 "\200\001", len = 33316320}, maddr = { s = 0x0, len = 0}, method = {s = 0x0, len = 0}, lr = {s = 0x0, len = 0}, r2 = {s = 0x0, len = 0}, gr = {s = 0x0, len = 0}, transport_val = {s = 0x0, len = 0}, ttl_val = {s = 0x0, len = 0}, user_param_val = {s = 0x7f0f40b9f568 "~\365\216\037\017\177", len = 0}, maddr_val = {s = 0x0, len = 0}, method_val = {s = 0x0, len = 0}, lr_val = {s = 0x0, len = 0}, r2_val = {s = 0x0, len = 0}, gr_val = {s = 0x0, len = 0}} u = 0x7f0f409ff010 port = 0 dst_host = 0x92bde8 i = 1088720928 flags = 0 avp = 0x7f0f40e496c8 st = {flags = 0, id = 0, name = {n = 0, s = {s = 0x0, len = 0}, re = 0x0}, avp = 0x0} sct = 0x0 sjt = 0x0 rve = 0x7f0f40e9d480 mct = 0x7f0f40e65e20 rv = 0x0 rv1 = 0x7f0f40e68340 c1 = {cache_type = RV_CACHE_EMPTY, val_type = RV_NONE, c = {avp_val = {n = 0, s = {s = 0x0, len = 0}, re = 0x0}, pval = {rs = { s = 0x0, len = 0}, ri = 0, flags = 0}}, i2s = "\000\000\000\000\000\000\000\000h\365\271@\017\177\000\000\000\000\000\000\000"} s = {s = 0x0, len = 0} srevp = {0x0, 0x0} evp = {data = 0x0, obuf = {s = 0x0, len = 0}, rcv = 0x0, dst = 0x0, req = 0x0, rpl = 0x0, rplcode = 0, mode = 0} mod_f_params = {{type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, {type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, { type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, { type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, { type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, { type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, { type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, { type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}} __func__ = "do_action" #16 0x0000000000450a6d in run_actions (h=0x7ffe01fc6b70, a=0x7f0f40e9d0d0, msg=0x7f0f40eda090) at core/action.c:1618 t = 0x7f0f40ea0e60 ret = 1 tvb = {tv_sec = 0, tv_usec = 0} tve = {tv_sec = 0, tv_usec = 0} tz = {tz_minuteswest = 8725541, tz_dsttime = 0} tdiff = 1088848992 __func__ = "run_actions" #17 0x000000000043f70a in do_action (h=0x7ffe01fc6b70, a=0x7f0f40e696e0, msg=0x7f0f40eda090) at core/action.c:709 ret = -5 li = 16 v = 1 dst = {send_sock = 0x92bde8, to = {s = {sa_family = 36864, sa_data = "\347H\017\177\000\000@h\374\001\376\177\000"}, sin = { sin_family = 36864, sin_port = 18663, sin_addr = {s_addr = 32527}, sin_zero = "@h\374\001\376\177\000"}, sin6 = { sin6_family = 36864, sin6_port = 18663, sin6_flowinfo = 32527, sin6_addr = {__in6_u = { __u6_addr8 = "@h\374\001\376\177\000\000\361=t\000\000\000\000", __u6_addr16 = {26688, 508, 32766, 0, 15857, 116, 0, 0}, __u6_addr32 = {33318976, 32766, 7618033, 0}}}, sin6_scope_id = 28}, sas = {ss_family = 36864, __ss_padding = "\347H\017\177\000\000@h\374\001\376\177\000\000\361=t\000\000\000\000\000\034", '\000' <repeats 15 times>, "\377\377\377\377\377\377\377\377\220\240\355@\017\177\000\000轒\000\000\000\000\000\000\220\347H\017\177\000\000\320h\374\001\376\177\000\000H\ru\000\000\000\000\000\360g\374\001\376\177\000\000\246\372\334\037\017\177\000\000\000\000\000\000\000\000\000\000di\374\001\376\177\000", __ss_align = 134217728}}, id = 1086994592, send_flags = {f = 32527, blst_imask = 0}, proto = 21 '\025', proto_pad0 = 75 'K', proto_pad1 = 159} tmp = 0x7ffe01fc6a60 "\020k\374\001\376\177" new_uri = 0x7ffe01fc69f0 "" end = 0x4 <error: Cannot access memory at address 0x4> crt = 0x7f0f40eda090 "@" cmd = 0x7f0f40b9f0d0 len = 32527 user = 1089145792 uri = {user = {s = 0x7f0f40e08630 "", len = 0}, passwd = {s = 0x8000000 <error: Cannot access memory at address 0x8000000>, len = 129248720}, host = {s = 0x3a5670 <error: Cannot access memory at address 0x3a5670>, len = 4969008}, port = { s = 0x57e920 <fork_tcp_process+5074> ";", len = 16}, params = {s = 0x4e <error: Cannot access memory at address 0x4e>, len = 7598071}, sip_params = {s = 0x7ffe01fc6630 "@g\374\001\376\177", len = 4978977}, headers = {s = 0x0, len = 1084226000}, port_no = 62544, proto = 16543, type = 19, flags = (unknown: 0x409ff9d0), transport = {s = 0x7ffe01fc6740 "@h\374\001\376\177", len = 7502474}, ttl = {s = 0x7ffe01fc6740 "@h\374\001\376\177", len = 7492948}, user_param = {s = 0x8bb92b "core", len = 7494079}, maddr = {s = 0x8bc708 <__func__.21> "parse_headers", len = 9157624}, method = {s = 0x7f0f40e085c0 "\220\001", len = 1084223504}, lr = {s = 0x8bc708 <__func__.21> "parse_headers", len = 9157624}, r2 = { s = 0x40 <error: Cannot access memory at address 0x40>, len = 1084223504}, gr = {s = 0x0, len = 0}, transport_val = { s = 0x9f4b13 <buf+819> "\r\n", len = 0}, ttl_val = {s = 0x8be270 <__func__.3> "parse_to_param", len = 9168712}, user_param_val = {s = 0x30 <error: Cannot access memory at address 0x30>, len = 1084223504}, maddr_val = {s = 0x7f0f40e08630 "", len = 1088455888}, method_val = {s = 0x0, len = 1084223504}, lr_val = { s = 0x130 <error: Cannot access memory at address 0x130>, len = 1088456064}, r2_val = { s = 0x400000000 <error: Cannot access memory at address 0x400000000>, len = 0}, gr_val = { s = 0x7ffe01fc7a98 "?~\374\001\376\177", len = 4394786}} next_hop = {user = {s = 0x4a <error: Cannot access memory at address 0x4a>, len = 10438703}, passwd = { s = 0x7 <error: Cannot access memory at address 0x7>, len = 8}, host = {s = 0x7f0f40cc6060 "\001", len = 0}, port = { s = 0x7f0f40e521c0 "\001", len = 1088827984}, params = { s = 0xffffffffffffffff <error: Cannot access memory at address 0xffffffffffffffff>, len = 1088758208}, sip_params = {s = 0x0, len = 1086993056}, headers = {s = 0x7f0f40e07b30 "\003", len = 1088454800}, port_no = 40176, proto = 16617, type = 32527, flags = 0, transport = {s = 0x7f0f40ca3db0 <incomplete sequence \353>, len = 0}, ttl = {s = 0x0, len = 0}, user_param = { s = 0x440e631a0 <error: Cannot access memory at address 0x440e631a0>, len = 9193958}, maddr = {s = 0x0, len = 0}, method = { s = 0x7ffe01fc65c0 "", len = 7807783}, lr = {s = 0x0, len = 0}, r2 = {s = 0x1 <error: Cannot access memory at address 0x1>, len = 1088455952}, gr = {s = 0x9f4b15 <buf+821> "", len = 10439410}, transport_val = {s = 0x0, len = 33318544}, ttl_val = { s = 0x9f4b15 <buf+821> "", len = 10439230}, user_param_val = {s = 0x0, len = 0}, maddr_val = {s = 0x0, len = 0}, method_val = { s = 0x0, len = 7534444}, lr_val = {s = 0x7ffe01fc65c0 "", len = 1084223504}, r2_val = {s = 0x7f0f40e08630 "", len = 1084223504}, gr_val = {s = 0x7ffe01fc6600 "0f\374\001\376\177", len = 534575782}} u = 0x7ffe01fc6b90 port = 0 dst_host = 0x7f0f40e085c0 i = 41 flags = 0 avp = 0x7627ed <parse_cseq+2542> st = {flags = 0, id = 0, name = {n = 0, s = {s = 0x0, len = 65537}, re = 0x0}, avp = 0x9f47e0 <buf>} sct = 0x7f0f40eda090 sjt = 0x7f0f40eb0bc0 rve = 0x7f0f40e66660 mct = 0x7ffe01fc68f0 rv = 0x0 rv1 = 0x7ffe01fc6a10 c1 = {cache_type = 10504224, val_type = RV_NONE, c = {avp_val = {n = 10504232, s = {s = 0xa04828 <def_list+40> "", len = 1085943864}, re = 0xa04828 <def_list+40>}, pval = {rs = {s = 0xa04828 <def_list+40> "", len = 1085943864}, ri = 10504544, flags = 10504552}}, i2s = "\200\371\253\037\017\177\000\000p\371\253\037\017\177\000\000\020\362\253\037\017\177"} s = {s = 0xa04810 <def_list+16> "", len = 33320176} srevp = {0x7ffe01fc6c30, 0x7f0f1fa499ae <tps_msg_received+3364>} evp = {data = 0x0, obuf = {s = 0x0, len = 0}, rcv = 0x0, dst = 0x0, req = 0x0, rpl = 0x0, rplcode = 0, mode = 0} mod_f_params = {{type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, {type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, { type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, { type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, { type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, { type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, { type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}, { type = NOSUBTYPE, u = {number = 0, string = 0x0, str = {s = 0x0, len = 0}, data = 0x0, attr = 0x0, select = 0x0}}} __func__ = "do_action" #18 0x0000000000450a6d in run_actions (h=0x7ffe01fc6b70, a=0x7f0f40e63e00, msg=0x7f0f40eda090) at core/action.c:1618 t = 0x7f0f40e696e0 ret = -1 tvb = {tv_sec = 0, tv_usec = 0} tve = {tv_sec = 0, tv_usec = 0} tz = {tz_minuteswest = 1089314960, tz_dsttime = 32527} tdiff = 4394786 __func__ = "run_actions" #19 0x00000000004511d7 in run_top_route (a=0x7f0f40e63e00, msg=0x7f0f40eda090, c=0x0) at core/action.c:1701 ctx = {rec_lev = 2, run_flags = 0, last_retcode = 1, jmp_env = {{__jmpbuf = {4294967296, 7972416042383599675, 140728931744408, 4394786, 9616872, 139703624372224, 7972416042299713595, -7971453441872074693}, __mask_was_saved = 0, __saved_mask = { __val = {6379359, 4294967296, 139703490551952, 140728898420737, 4294967296, 140728931744408, 4394786, 9616872, 139703624372224, 140728931740736, 0, 4611686022722355200, 0, 139703490412128, 4294967296, 140728931744408}}}}} p = 0x7ffe01fc6b70 ret = 9616872 sfbk = 0 #20 0x00000000005ab16e in receive_msg ( buf=0x9f47e0 <buf> "BYE sip:gw+internal_sip_gw03@172.16.172.242:65000;transport=udp;gw=internal_sip_gw03 SIP/2.0\r\nVia: SIP/2.0/UDP 172.16.172.230:5080;TH=dcv;rport;branch=z9hG4bKX9Zm25Xe6316g\r\nMax-Forwards: 69\r\nFrom: <si"..., len=821, rcv_info=0x7ffe01fc7200) at core/receive.c:518 msg = 0x7f0f40eda090 ctx = {rec_lev = 0, run_flags = 2, last_retcode = 1, jmp_env = {{__jmpbuf = {4294967296, 7972416042383599675, 140728931744408, 4394786, 9616872, 139703624372224, 7972416042299713595, -7971453441872074693}, __mask_was_saved = 0, __saved_mask = { __val = {0, 0, 0, 1880844493789993498, 1880844493789993498, 1880844493789993498, 1880844493789993498, 0, 0, 0, 0, 2314885530818453536, 2314885530818453536, 2314885530818453536, 2314885530818453536, 0}}}}} bctx = 0x0 ret = 0 tvb = {tv_sec = 0, tv_usec = 0} tve = {tv_sec = 0, tv_usec = 0} diff = 0 inb = { s = 0x9f47e0 <buf> "BYE sip:gw+internal_sip_gw03@172.16.172.242:65000;transport=udp;gw=internal_sip_gw03 SIP/2.0\r\nVia: SIP/2.0/UDP 172.16.172.230:5080;TH=dcv;rport;branch=z9hG4bKX9Zm25Xe6316g\r\nMax-Forwards: 69\r\nFrom: <si"..., len = 821} netinfo = {data = {s = 0x0, len = 0}, bufsize = 0, rcv = 0x0, dst = 0x0} keng = 0x0 evp = {data = 0x7ffe01fc6d60, obuf = {s = 0x0, len = 0}, rcv = 0x7ffe01fc7200, dst = 0x0, req = 0x0, rpl = 0x0, rplcode = 0, mode = 0} cidlockidx = 0 cidlockset = 0 errsipmsg = 0 exectime = 0 __func__ = "receive_msg" #21 0x00000000006f9272 in udp_rcv_loop () at core/udp_server.c:751 len = 598 buf = "BYE sip:gw+internal_sip_gw03@172.16.172.242:65000;transport=udp;gw=internal_sip_gw03 SIP/2.0\r\nVia: SIP/2.0/UDP 172.16.172.230:5080;TH=dcv;rport;branch=z9hG4bKX9Zm25Xe6316g\r\nMax-Forwards: 69\r\nFrom: <si"... tmp = 0x1201ae640 <error: Cannot access memory at address 0x1201ae640> fromaddr = 0x7f0f40e99c00 fromaddrlen = 16 rcvi = {src_ip = {af = 2, len = 4, u = {addrl = {3870036140, 0}, addr32 = {3870036140, 0, 0, 0}, addr16 = {4268, 59052, 0, 0, 0, 0, 0, 0}, addr = "\254\020\254\346", '\000' <repeats 11 times>}}, dst_ip = {af = 2, len = 4, u = {addrl = {3719041196, 0}, addr32 = {3719041196, 0, 0, 0}, addr16 = {4268, 56748, 0, 0, 0, 0, 0, 0}, addr = "\254\020\254\335", '\000' <repeats 11 times>}}, src_port = 5080, dst_port = 65000, proto_reserved1 = 0, proto_reserved2 = 0, src_su = {s = {sa_family = 2, sa_data = "\023ج\020\254\346\000\000\000\000\000\000\000"}, sin = { sin_family = 2, sin_port = 55315, sin_addr = {s_addr = 3870036140}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = { sin6_family = 2, sin6_port = 55315, sin6_flowinfo = 3870036140, sin6_addr = {__in6_u = { __u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}, sas = {ss_family = 2, __ss_padding = "\023ج\020\254\346", '\000' <repeats 111 times>, __ss_align = 0}}, bind_address = 0x7f0f40b88fa0, rflags = 0, proto = 1 '\001', proto_pad0 = 0 '\000', proto_pad1 = 0} evp = {data = 0x0, obuf = {s = 0x0, len = 0}, rcv = 0x0, dst = 0x0, req = 0x0, rpl = 0x0, rplcode = 0, mode = 0} printbuf = "\340o\374\001\376\177\000\000f*\260\037\017\177\000\000)\262\272\037\017\177\000\000\340b5\037\017\177\000\000\020p\374\001\376\177\000\000\322\v\272\037\017\177\000\000\000\000\000\000\000\000\000\000\340b5\037\017\177\000\000\000\000\000\000\000\000\000\000p\233\351@\017\177\000\000@p\374\001\376\177\000\000 e\032 \017\177\000\000\230z\374\001\376\177\000\000\"\017C\000\000\000\000\000轒\000\000\000\000\000\000\220\347H\017\177\000\000`p\374\001\376\177\000\000ǥ\272\037\017\177\000\000\360b5\037\017\177\000\000p\233\351@\017\177\000\000\000q\374\001\376\177\000\000\257:3\037\017\177\000\000\000\000\000\000\260\000\000\000p/\306@\260", '\000' <repeats 91 times>... i = -1 j = 506880 l = 176 __func__ = "udp_rcv_loop" #22 0x000000000042dcb6 in main_loop () at main.c:1815 i = 47 pid = 0 si = 0x7f0f40b88fa0 si_desc = "udp receiver child=47 sock=172.16.172.221:65000\0000\000\000\000\000\000\000\000\000\345\032 \017\177\000\000@t\374\001\001\000\000\000\200\211\341\037\017\177\000\000\310/\272@\017\177\000\000\037%r\000\000\000\000\000\230z\374\001\376\177\000\000\200\211\341\037\017\177\000\000轒\000\000\000\000\000\000\220\347H\001\000\000" nrprocs = 128 woneinit = 1 __func__ = "main_loop" #23 0x0000000000439e7d in main (argc=10, argv=0x7ffe01fc7a98) at main.c:3256 cfg_stream = 0xfa5380 c = -1 r = 0 tmp = 0x7ffe01fc7ea8 "" tmp_len = 0 port = 5060 proto = 0 aproto = 0 ahost = 0x0 aport = 0 options = 0x8433f8 ":f:cm:M:dVIhEeb:B:l:L:n:vKrRDTN:W:w:t:u:g:P:G:SQ:O:a:A:x:X:Y:" ret = -1 seed = 1463919274 rfd = 4 debug_save = 0 debug_flag = 0 dont_fork_cnt = 2 n_lst = 0x7ffe01fc7980 p = 0x1800000 <error: Cannot access memory at address 0x1800000> st = {st_dev = 24, st_ino = 1005, st_nlink = 2, st_mode = 16832, st_uid = 991, st_gid = 988, __pad0 = 0, st_rdev = 0, st_size = 40, st_blksize = 4096, st_blocks = 0, st_atim = {tv_sec = 1730298568, tv_nsec = 63999933}, st_mtim = {tv_sec = 1730298573, tv_nsec = 240999872}, st_ctim = {tv_sec = 1730298573, tv_nsec = 240999872}, __glibc_reserved = {0, 0, 0}} l1 = 512 tbuf = "B\215\347H\017\177\000\000\210J\344H\017\177\000\000\020w\374\001\376\177\000\000\006\000\000\000\000\000\000\000\b7\344H\017\177\000\000\006\000\000\000\020\000\000\0000\232\347H\017\177\000\000\325\031\345H\017\177\000\000\000\000\000\000\000\000\000\000\240,\345H\017\177\000\000\370\377\240H\017\177\000\000\020\033\344H\017\177\000\000\000\000\000\000\000\000\000\000\001\000\000\000\000\000\000\000\340v\374\001\376\177\000\000\240J\344H\017\177\000\000\240J\344H\017\177\000\000\000\000\000\000\000\000\000\000p)\344H\017\177\000\000\340v\374\001\376\177\000\000\200\245\347H\017\177\000\000\0000\344H\017\177\000\000\342;\344H\017\177\000\000v\344\344H\017\177\000\000\334#\240H\017\177\000\000"... option_index = 0 long_options = {{name = 0x845b26 "help", has_arg = 0, flag = 0x0, val = 104}, {name = 0x84054c "version", has_arg = 0, flag = 0x0, val = 118}, {name = 0x845b2b "alias", has_arg = 1, flag = 0x0, val = 1024}, {name = 0x845b31 "subst", has_arg = 1, flag = 0x0, val = 1025}, {name = 0x845b37 "substdef", has_arg = 1, flag = 0x0, val = 1026}, {name = 0x845b40 "substdefs", has_arg = 1, flag = 0x0, val = 1027}, {name = 0x845b4a "server-id", has_arg = 1, flag = 0x0, val = 1028}, {name = 0x845b54 "loadmodule", has_arg = 1, flag = 0x0, val = 1029}, {name = 0x845b5f "modparam", has_arg = 1, flag = 0x0, val = 1030}, { name = 0x845b68 "log-engine", has_arg = 1, flag = 0x0, val = 1031}, {name = 0x845b73 "debug", has_arg = 1, flag = 0x0, val = 1032}, {name = 0x845b79 "cfg-print", has_arg = 0, flag = 0x0, val = 1033}, {name = 0x845b83 "atexit", has_arg = 1, flag = 0x0, val = 1034}, {name = 0x845b8a "all-errors", has_arg = 0, flag = 0x0, val = 1035}, {name = 0x0, has_arg = 0, flag = 0x0, val = 0}} __func__ = "main" (gdb) ) ``` #### Log Messages Oct 30 21:32:19 KAM-V2-02 kamailio[2711]: 188(2711) ERROR: {1 90509167 INVITE 3b4b542a-0fdc-123e-aebc-00505697ee23} <script>: cut prefix : 172.16.172.230:5080 Oct 30 21:32:23 KAM-V2-02 kamailio[2687]: 176(2687) BUG: {1 90509168 BYE 3506e2a7-0fdc-123e-aebc-00505697ee23} cnxcc [cnxcc_mod.c:869]: __delete_call(): number of concurrent calls dropped to negative value: -1 Oct 30 21:32:23 KAM-V2-02 kamailio[2687]: 176(2687) BUG: {1 90509168 BYE 3506e2a7-0fdc-123e-aebc-00505697ee23} cnxcc [cnxcc_mod.c:874]: __delete_call(): number of calls dropped to negative value: -1 Oct 30 21:32:23 KAM-V2-02 kernel: kamailio[2687]: segfault at 8 ip 00007f0f1f38902c sp 00007ffe01fc4470 error 6 in cnxcc.so[7f0f1f377000+3c000] likely on CPU 10 (core 0, socket 5) Oct 30 21:32:23 KAM-V2-02 kernel: Code: 48 8b 05 c7 5f 03 00 8b 00 8d 50 ff 48 8b 05 bb 5f 03 00 89 10 48 8b 85 78 ff ff ff 48 8b 00 48 8b 95 78 ff ff ff 48 8b 52 08 <48> 89 50 08 48 8b 85 78 ff ff ff 48 8b 40 08 48 8b 95 78 ff ff ff Oct 30 21:32:23 KAM-V2-02 mariadbd[1313]: 2024-10-30 21:32:23 189 [Warning] Aborted connection 189 to db: 'kamailio' user: 'kamailio' host: 'localhost' (Got an error reading communication packets) Oct 30 21:32:23 KAM-V2-02 kamailio[3130]: 395(3130) CRITICAL: <core> [core/pass_fd.c:281]: receive_fd(): EOF on 186 Oct 30 21:32:23 KAM-V2-02 kamailio[2331]: 0(2331) ALERT: <core> [main.c:805]: handle_sigs(): child process 2687 exited by a signal 11 Oct 30 21:32:23 KAM-V2-02 kamailio[2331]: 0(2331) ALERT: <core> [main.c:809]: handle_sigs(): core was generated #### SIP Traffic  ``` (paste your sip traffic here) ``` ### Possible Solutions  ### Additional Information * **Kamailio Version** - output of `kamailio -v` version: kamailio 5.8.2 (x86_64/linux) 3fa5f4 flags: USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MMAP, PKG_MALLOC, MEM_JOIN_FREE, Q_MALLOC, F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLOCKLIST, HAVE_RESOLV_RES, TLS_PTHREAD_MUTEX_SHARED ADAPTIVE_WAIT_LOOPS 1024, MAX_RECV_BUFFER_SIZE 262144, MAX_SEND_BUFFER_SIZE 262144, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: 3fa5f4 compiled on 22:03:02 Oct 28 2024 with gcc 11.5.0 * **Operating System**: CentOS Stream release 9 NAME="CentOS Stream" VERSION="9" ID="centos" ID_LIKE="rhel fedora" VERSION_ID="9" PLATFORM_ID="platform:el9" PRETTY_NAME="CentOS Stream 9" ANSI_COLOR="0;31" LOGO="fedora-logo-icon" CPE_NAME="cpe:/o:centos:centos:9" HOME_URL="https://centos.org/" BUG_REPORT_URL="https://issues.redhat.com/" REDHAT_SUPPORT_PRODUCT="Red Hat Enterprise Linux 9" REDHAT_SUPPORT_PRODUCT_VERSION="CentOS Stream" CentOS Stream release 9 CentOS Stream release 9 -- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/4009 You are receiving this because you are subscribed to this thread. Message ID: <kamailio/kamailio/issues/4009(a)github.com>

1 week, 5 days

[kamailio/kamailio] free_fixup functions in cmd_export_t are not called (Issue #3814)

by Xenofon Karamanos

### Description It seems that the fixup_free_* functions are not getting called when used with: ``` static cmd_export_t cmds[] = { {"acc_log_request", (cmd_function)w_acc_log_request, 1, acc_fixup, free_acc_fixup, ANY_ROUTE}, // ... {0, 0, 0, 0, 0, 0} }; static int free_acc_fixup(void **param, int param_no) { LM_CRIT("acc free fixup = %d\n", param_no); if(*param) { pkg_free(*param); *param = 0; } return 0; } ``` Nothing is getting logged from the function. Is this expected not to print in free_fixup due to the destruction of kamailio and the logging is not reliable? I also used gdb and added some breakpoints in `fixup` and `free_fixup` functions in some other modules (file_out) and the breakpoint was only found in `fixup` but not in `free_fixup`. When is the `free_fixup` supposed to be called, at kamailio destruction or after fixing it and before the main loop starts?  ### Troubleshooting #### Reproduction  Use any module that has a custom (maybe also provided from core) `free_fixup` function, and monitor if `free_fixup` is called using debug mode. #### Log Messages  ``` Apr 15 15:52:03 app01 kamailio[812169]: INFO: <core> [core/mem/q_malloc.c:402]: qm_malloc(): qm_malloc(0x7fcdcab18010, 56) called from file_out: file_out.c: fo_fixup_str_index(287) Apr 15 15:52:03 app01 kamailio[812169]: INFO: <core> [core/mem/q_malloc.c:449]: qm_malloc(): qm_malloc(0x7fcdcab18010, 64) returns address 0x7fcdcacc4280 frag. 0x7fcdcacc4240 (size=64) on 1 -th hit``` `0x7fcdcacc4240` fragment is not found anywhere in the logs reported that it was freed unlike other malloced resources. ``` ### Additional Information * **Kamailio Version** - output of `kamailio -v` ``` version: kamailio 5.9.0-dev0 (x86_64/linux) 8bc64a flags: USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MMAP, PKG_MALLOC, MEM_JOIN_FREE, Q_MALLOC, F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLOCKLIST, HAVE_RESOLV_RES, TLS_PTHREAD_MUTEX_SHARED ADAPTIVE_WAIT_LOOPS 1024, MAX_RECV_BUFFER_SIZE 262144, MAX_SEND_BUFFER_SIZE 262144, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: 8bc64a compiled on 15:32:09 Apr 15 2024 with gcc 10.5.0 ``` * **Operating System**:  ``` No LSB modules are available. Distributor ID: Ubuntu Description: Ubuntu 20.04.6 LTS Release: 20.04 Codename: focal 5.4.0-176-generic #196-Ubuntu SMP Fri Mar 22 16:46:39 UTC 2024 x86_64 x86_64 x86_64 GNU/Linux ``` -- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/3814 You are receiving this because you are subscribed to this thread. Message ID: <kamailio/kamailio/issues/3814(a)github.com>

2 weeks, 1 day

[kamailio/kamailio] tcp_timer_check_connections() logs on CRITICAL and is not caught by event_route[tcp:timeout] (Issue #3995)

by Fritjof Höst

### Description Hi! We are in the progress of upgrading from Kamailio 5.5 to 5.8. During our testing we have noticed a new error being reported from Kamailio. We don’t see any other errors following it. ```jsx /usr/sbin/kamailio[201]: CRITICAL: <core> [core/tcp_main.c:5544]: tcp_timer_check_connections(): message processing timeout on connection id: 67896 (state: 3) - closing ``` It does seem to be [new code](https://github.com/kamailio/kamailio/blob/master/src/core/tcp_main.c#… in Kamailio reporting this issue. Given that this is a fairly expected thing, cleaning up a connection which receives no traffic within the given time, is there a need for it to be reported on CRITICAL? I’d also expect it to be caught by ``` event_route[tcp:timeout] { xlog("L_INFO","connection $conid timeouts (unanswered keepalives)"); } ``` given that [the description](https://www.kamailio.org/docs/modules/stable/modules/tcpops.ht… of this one is `Called for connection timeouts (unanswered keepalives).`. ### Troubleshooting We don't have any way to reproduce it, we are still investigating it to figure out the cause. It happens around every 2 hours, so we think there might some some scheduled test or job running in our test system causing this. ### Additional Information * **Kamailio Version** - 5.8.3 * **Operating System**: Debian 12 AMI from the AWS Marketplace. -- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/3995 You are receiving this because you are subscribed to this thread. Message ID: <kamailio/kamailio/issues/3995(a)github.com>

2 weeks, 1 day

[kamailio/kamailio] BUG: freeing already freed pointer (0x7f19a3edec68), called from tls: tls_init.c with random core dumps (Issue #3205)

by Tim Chubb

### Description  Im getting frequent log entries like this: `CRITICAL: <core> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed pointer (0x7f19a3edec68), called from tls: tls_init.c: ser_free(323), first free tls: tls_init.c: ser_free(323) - ignoring` This on a fresh VM running Ubuntu 22.04 LTS on the 5.6 branch (building latest release tag) As well as that log message being printed on a frequent basis (every 2 to 3 mins) i am experiencing random crashes/restarts of kamailio. Looking at the core dumps tls_init seems to precipitate the core dump. I have tried using both the TLS module, and TLSA, in the case of TLSA to rule out OpenSSL3 being an issue i have tried linking against locally built OpenSSL 3.0.5 and OpenSSL 1.1.1q with identical results I am in the process of repeating the build on Ubuntu 20.04 LTS to rule out weirdness with packages and similar issues i have experienced whilst evaluating 22.04 LTS ### Troubleshooting #### Reproduction  #### Debugging Data  ``` (gdb) bt full #0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=140425701996352) at ./nptl/pthread_kill.c:44 tid = <optimized out> ret = 0 pd = 0x7fb76815b740 old_mask = {__val = {523986010119, 910533066753, 1, 140425395047168, 94230980435360, 0, 5677797456, 140425395047168, 140725986283600, 140425393986269, 94230963279192, 140425395047168, 94230963279402, 7970739754, 140725986283664, 140425394028321}} ret = <optimized out> pd = <optimized out> old_mask = <optimized out> ret = <optimized out> tid = <optimized out> ret = <optimized out> resultvar = <optimized out> resultvar = <optimized out> __arg3 = <optimized out> __arg2 = <optimized out> __arg1 = <optimized out> _a3 = <optimized out> _a2 = <optimized out> _a1 = <optimized out> __futex = <optimized out> resultvar = <optimized out> __arg3 = <optimized out> __arg2 = <optimized out> __arg1 = <optimized out> _a3 = <optimized out> _a2 = <optimized out> _a1 = <optimized out> __futex = <optimized out> __private = <optimized out> __oldval = <optimized out> result = <optimized out> #1 __pthread_kill_internal (signo=6, threadid=140425701996352) at ./nptl/pthread_kill.c:78 No locals. #2 __GI___pthread_kill (threadid=140425701996352, signo=signo@entry=6) at ./nptl/pthread_kill.c:89 No locals. #3 0x00007fb7681a0476 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26 ret = <optimized out> #4 0x00007fb7681867f3 in __GI_abort () at ./stdlib/abort.c:79 save_stage = 1 act = {__sigaction_handler = {sa_handler = 0x100000000, sa_sigaction = 0x100000000}, sa_mask = {__val = {140425395047168, 140725986283888, 140425393986269, 140425394365984, 140425394130944, 140425394801736, 5734026312, 140725986283952, 140425394028321, 15624006419995803439, 94230961557227, 94230963279168, 94230963279576, 140425422497024, 13020282480951897856, 72}}, sa_flags = -619194838, sa_restorer = 0x0} sigs = {__val = {32, 13020282480951897856, 140725986284000, 94230961610857, 13546569962021497653, 14189927350396752214, 94230962920532, 0, 94230963279402, 140425394130944, 10, 38654707763, 12, 140425395047168, 32, 1438623432}} #5 0x000055b3dafd8f12 in qm_debug_check_frag (qm=0x7fb755bc1000, f=0x7fb7576ce500, file=0x7fb766123154 "tls: tls_init.c", line=323, efile=0x55b3db17d559 "core/mem/q_malloc.c", eline=511) at core/mem/q_malloc.c:129 p = 0x7fb755ca0b00 __func__ = "qm_debug_check_frag" #6 0x000055b3dafdd788 in qm_free (qmp=0x7fb755bc1000, p=0x7fb7576ce538, file=0x7fb766123154 "tls: tls_init.c", func=0x7fb766124990 <__func__.0> "ser_free", line=323, mname=0x7fb766123150 "tls") at core/mem/q_malloc.c:511 qm = 0x7fb755bc1000 f = 0x7fb7576ce500 size = 24 next = 0x7fb7576ce500 prev = 0x7fb7576ce3f8 __func__ = "qm_free" #7 0x000055b3dafe954e in qm_shm_free (qmp=0x7fb755bc1000, p=0x7fb7576ce538, file=0x7fb766123154 "tls: tls_init.c", func=0x7fb766124990 <__func__.0> "ser_free", line=323, mname=0x7fb766123150 "tls") at core/mem/q_malloc.c:1350 No locals. #8 0x00007fb7660db698 in ser_free (ptr=0x7fb7576ce538, fname=0x7fb765efa6e5 "../crypto/err/err_local.h", fline=88) at tls_init.c:323 __func__ = "ser_free" #9 0x00007fb765d2e907 in ERR_pop_to_mark () from /lib/x86_64-linux-gnu/libcrypto.so.3 No symbol table info available. #10 0x00007fb765d76a42 in ?? () from /lib/x86_64-linux-gnu/libcrypto.so.3 No symbol table info available. #11 0x00007fb765d669f5 in EVP_PKEY_set_type_by_keymgmt () from /lib/x86_64-linux-gnu/libcrypto.so.3 No symbol table info available. #12 0x00007fb765d5ef9a in ?? () from /lib/x86_64-linux-gnu/libcrypto.so.3 No symbol table info available. #13 0x00007fb765d69973 in EVP_PKEY_generate () from /lib/x86_64-linux-gnu/libcrypto.so.3 No symbol table info available. #14 0x00007fb766029279 in ?? () from /lib/x86_64-linux-gnu/libssl.so.3 No symbol table info available. #15 0x00007fb76607a621 in ?? () from /lib/x86_64-linux-gnu/libssl.so.3 No symbol table info available. --Type <RET> for more, q to quit, c to continue without paging--c #16 0x00007fb7660687fd in ?? () from /lib/x86_64-linux-gnu/libssl.so.3 No symbol table info available. #17 0x00007fb766104216 in tls_accept (c=0x7fb7576db4e8, error=0x7ffd526c58a4) at tls_server.c:468 ret = 1382832224 ssl = 0x7fb75755bef0 cert = 0x7fb75742dbb0 tls_c = 0x7fb7574429a8 tls_log = 1712337076 __func__ = "tls_accept" pkey = 0x0 #18 0x00007fb76610f86d in tls_h_read_f (c=0x7fb7576db4e8, flags=0x7ffd526e5dac) at tls_server.c:1173 r = 0x7fb7576db610 bytes_free = 16383 bytes_read = 150 read_size = 16383 ssl_error = 0 ssl_read = 0 ssl = 0x7fb75755bef0 rd_buf = "\026\003\003\000\221\001\000\000\215\003\003b\347\222\177\213T\226\b\b\214\273\355\255[l\354\211\371rJ;<\033\356B\374y\024cg\352\067\000\000\020\300\060\300/\300(\300'\300,\300+\300$\300#\001\000\000T\000\000\000\022\000\020\000\000\rdr.teamsdr.uk\000\005\000\005\001\000\000\000\000\000\n\000\006\000\004\000\030\000\027\000\v\000\002\001\000\000\r\000\024\000\022\004\001\005\001\002\001\004\003\005\003\002\003\002\002\006\001\006\003\000#\000\000\000\027\000\000\377\001\000\001\000G\225 E\030j\223\313Hb\244@\271\323\030GQ\254\272\024\032z=H-\277\360\226\035qw\244\270(\004D\004\241\023\062\064\026\226\376\321\067\274\370\376?"... wr_buf = "\026\003\003\000E\002\000\000A\003\003OHu\016\240\363=\252\356\260#\221\a\310ò&\237\000:FɆ\351DOWNGRD\001\000\300\060\000\000\031\377\001\000\001\000\000\000\000\000\000\v\000\004\003\000\001\002\000#\000\000\000\027\000\000\026\003\003\020\006\v\000\020\002\000\017\377\000\005x0\202\005t0\202\004\\\240\003\002\001\002\002\022\004\062_\v\313\031\021 \240[\376N\227\346\310\004e\r0\r\006\t*\206H\206\367\r\001\001\v\005\000\060\062\061\v0\t\006\003U\004\006\023\002US1\026\060\024\006\003U\004\n\023\rLet's Encrypt1\v0\t\006\003U\004\003\023\002R30\036\027\r22070519555"... rd = {buf = 0x7ffd526c5a00 "\026\003\003", pos = 150, used = 150, size = 65536} wr = {buf = 0x7ffd526d5a00 "\026\003\003", pos = 0, used = 4096, size = 65536} tls_c = 0x7fb7574429a8 enc_rd_buf = 0x0 n = 0 flush_flags = 1 err_src = 0x7fb76612c9b0 "TLS read:" ip_buf = "172.16.51.200", '\000' <repeats 50 times> x = 0 tls_dbg = 0 __func__ = "tls_h_read_f" #19 0x000055b3daf819f3 in tcp_read_headers (c=0x7fb7576db4e8, read_flags=0x7ffd526e5dac) at core/tcp_read.c:441 bytes = 4 remaining = 0 p = 0x7fb75736b870 "2" r = 0x7fb7576db610 mc = 32695 body_len = 22326 mfline = 0x7fb755b9dadd <futex_release+29> "\211E\374\203}\374\002\017\224\300\017\266\300H\205\300t6H\213E\350H\203\354\bj" mtransid = {s = 0x55b3db16d884 "", len = 1439304448} __func__ = "tcp_read_headers" #20 0x000055b3daf8ac9d in tcp_read_req (con=0x7fb7576db4e8, bytes_read=0x7ffd526e5da8, read_flags=0x7ffd526e5dac) at core/tcp_read.c:1469 bytes = -1 total_bytes = 0 resp = 1 size = 154618822664 req = 0x7fb7576db610 dst = {send_sock = 0x1, to = {s = {sa_family = 2816, sa_data = "\312U\267\177\000\000\320\\nR\375\177\000"}, sin = {sin_family = 2816, sin_port = 21962, sin_addr = {s_addr = 32695}, sin_zero = "\320\\nR\375\177\000"}, sin6 = {sin6_family = 2816, sin6_port = 21962, sin6_flowinfo = 32695, sin6_addr = {__in6_u = {__u6_addr8 = "\320\\nR\375\177\000\000\030\000\000\000\000\000\000", __u6_addr16 = {23760, 21102, 32765, 0, 24, 0, 0, 0}, __u6_addr32 = {1382964432, 32765, 24, 0}}}, sin6_scope_id = 1382964400}, sas = {ss_family = 2816, __ss_padding = "\312U\267\177\000\000\320\\nR\375\177\000\000\030\000\000\000\000\000\000\000\260\\nR\001\000\000\000\000\v\312U\267\177\000\000\260\\nR\375\177\000\000\335ڹU\267\177\000\000\204\330\026۳U\000\000\000\v\312U\267\177\000\000\002\000\000\000\000\000\000\000\002\000\000\000\001\000\000\000\360\\nR\375\177\000\000!\177\272U\267\177\000\000\360]nR\375\177\000\000\024]nR\375\177\000", __ss_align = 17179869204}}, id = -619259776, send_flags = {f = 21939, blst_imask = 0}, proto = 110 'n', proto_pad0 = -11 '\365', proto_pad1 = 28435} c = 0 '\000' ret = 1438243549 __func__ = "tcp_read_req" #21 0x000055b3daf9072c in handle_io (fm=0x7fb766755bb8, events=1, idx=-1) at core/tcp_read.c:1780 ret = 8 n = 8 read_flags = RD_CONN_SHORT_READ con = 0x7fb7576db4e8 s = 12 resp = 140425703179696 t = 1467216201 ee = 0x0 __func__ = "handle_io" #22 0x000055b3daf7bd70 in io_wait_loop_epoll (h=0x55b3db270960 <io_w>, t=2, repeat=0) at core/io_wait.h:1070 n = 1 r = 0 fm = 0x7fb766755bb8 revents = 1 __func__ = "io_wait_loop_epoll" #23 0x000055b3daf93760 in tcp_receive_loop (unix_sock=36) at core/tcp_read.c:1976 __func__ = "tcp_receive_loop" #24 0x000055b3daf6fdde in tcp_init_children (woneinit=0x7ffd526e6198) at core/tcp_main.c:5236 r = 0 i = 7 reader_fd_1 = 36 pid = 0 si_desc = "tcp receiver (generic)\000\000\356\376\357ڳU\000\000panR\375\177\000\000\036\350\371\332\000\000\000\000\070\n\037f\000\000\000\000\313\307\025۳U\000\000\241\000nR\375\177\000\000\fj\f۳U\000\000\000\000\000\000\000\000\000\000ز\277U\267\177\000\000\036\000\000\000\000\000\000\000\020\316\363U\001\000\000\000`anR\375\177\000\000\036l\f۳U\000" si = 0x0 __func__ = "tcp_init_children" #25 0x000055b3dacbe65c in main_loop () at main.c:1851 i = 4 pid = 7714 si = 0x0 si_desc = "udp receiver child=3 sock=127.0.0.1:5050\000\060\066\060\000\000\000\000\003\000\000\000\036\000\000\000\000/a\230\356U\261\264X\307\036۳U\000\000\210\360\020۳U\000\000\000\000\000\000\000\000\000\000s\\\022۳U\000\000\036\000\000\000\000\000\000\000\260\305'h\267\177\000\000\060cnR\375\177\000\000zI\347ڳU\000" nrprocs = 4 woneinit = 1 __func__ = "main_loop" #26 0x000055b3dacc95b0 in main (argc=11, argv=0x7ffd526e68a8) at main.c:3085 cfg_stream = 0x55b3dc09c380 c = -1 r = 0 tmp = 0x7ffd526e7e37 "" tmp_len = 0 port = 0 proto = 0 ahost = 0x0 aport = 0 options = 0x55b3db112278 ":f:cm:M:dVIhEeb:l:L:n:vKrRDTN:W:w:t:u:g:P:G:SQ:O:a:A:x:X:Y:" ret = -1 seed = 1456913526 rfd = 4 debug_save = 0 debug_flag = 0 dont_fork_cnt = 0 n_lst = 0x7fb768491cee <_dl_runtime_resolve_xsave+142> p = 0x7ffd526e68a8 "\334}nR\375\177" st = {st_dev = 25, st_ino = 1712, st_nlink = 2, st_mode = 16892, st_uid = 9002, st_gid = 9002, __pad0 = 0, st_rdev = 0, st_size = 40, st_blksize = 4096, st_blocks = 0, st_atim = {tv_sec = 1659341338, tv_nsec = 499520451}, st_mtim = {tv_sec = 1659341338, tv_nsec = 499520451}, st_ctim = {tv_sec = 1659341338, tv_nsec = 499520451}, __glibc_reserved = {0, 0, 0}} tbuf = '\000' <repeats 64 times>, "\377\000\000\000\000\000\000\000\000\377", '\000' <repeats 18 times>, "\377", '\000' <repeats 19 times>, "`", '\000' <repeats 15 times>, "\001", '\000' <repeats 145 times>... option_index = 0 long_options = {{name = 0x55b3db1146b6 "help", has_arg = 0, flag = 0x0, val = 104}, {name = 0x55b3db10f521 "version", has_arg = 0, flag = 0x0, val = 118}, {name = 0x55b3db1146bb "alias", has_arg = 1, flag = 0x0, val = 1024}, {name = 0x55b3db1146c1 "subst", has_arg = 1, flag = 0x0, val = 1025}, {name = 0x55b3db1146c7 "substdef", has_arg = 1, flag = 0x0, val = 1026}, {name = 0x55b3db1146d0 "substdefs", has_arg = 1, flag = 0x0, val = 1027}, {name = 0x55b3db1146da "server-id", has_arg = 1, flag = 0x0, val = 1028}, {name = 0x55b3db1146e4 "loadmodule", has_arg = 1, flag = 0x0, val = 1029}, {name = 0x55b3db1146ef "modparam", has_arg = 1, flag = 0x0, val = 1030}, {name = 0x55b3db1146f8 "log-engine", has_arg = 1, flag = 0x0, val = 1031}, {name = 0x55b3db114703 "debug", has_arg = 1, flag = 0x0, val = 1032}, {name = 0x55b3db114709 "cfg-print", has_arg = 0, flag = 0x0, val = 1033}, {name = 0x55b3db114713 "atexit", has_arg = 1, flag = 0x0, val = 1034}, {name = 0x55b3db11471a "all-errors", has_arg = 0, flag = 0x0, val = 1035}, {name = 0x0, has_arg = 0, flag = 0x0, val = 0}} __func__ = "main" (gdb) info locals tid = <optimized out> ret = 0 pd = 0x7fb76815b740 old_mask = {__val = {523986010119, 910533066753, 1, 140425395047168, 94230980435360, 0, 5677797456, 140425395047168, 140725986283600, 140425393986269, 94230963279192, 140425395047168, 94230963279402, 7970739754, 140725986283664, 140425394028321}} ret = <optimized out> pd = <optimized out> old_mask = <optimized out> ret = <optimized out> tid = <optimized out> ret = <optimized out> resultvar = <optimized out> resultvar = <optimized out> __arg3 = <optimized out> __arg2 = <optimized out> __arg1 = <optimized out> _a3 = <optimized out> _a2 = <optimized out> _a1 = <optimized out> __futex = <optimized out> resultvar = <optimized out> __arg3 = <optimized out> __arg2 = <optimized out> __arg1 = <optimized out> _a3 = <optimized out> _a2 = <optimized out> _a1 = <optimized out> __futex = <optimized out> __private = <optimized out> __oldval = <optimized out> result = <optimized out> (gdb) list 39 in ./nptl/pthread_kill.cq ``` #### Log Messages  ``` Aug 1 12:21:45 kam-test01 /usr/local/sbin/kamailio[25442]: INFO: <core> [core/sctp_core.c:53]: sctp_core_destroy(): SCTP API not initialized Aug 1 12:21:47 kam-test01 kamailio: INFO: <core> [core/sctp_core.c:74]: sctp_core_check_support(): SCTP API not enabled - if you want to use it, load sctp module Aug 1 12:21:47 kam-test01 kamailio: INFO: <core> [core/tcp_main.c:5080]: init_tcp(): using epoll_lt as the io watch method (auto detected) Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_mod.c:399]: mod_init(): use OpenSSL version: 30000020 Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_mod.c:401]: mod_init(): With ECDH-Support! Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_mod.c:404]: mod_init(): With Diffie Hellman Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: auth [auth_mod.c:345]: mod_init(): qop set, but nonce-count (nonce_count) support disabled Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: rr [../outbound/api.h:52]: ob_load_api(): unable to import bind_ob - maybe module is not loaded Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: rr [rr_mod.c:188]: mod_init(): outbound module not available Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: db_text [dbt_lib.c:146]: dbt_cache_get_db(): using database at: /etc/kamailio/dbtext Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: WARNING: tls [tls_init.c:804]: tls_h_mod_init_f(): tls: openssl bug #1491 (crash/mem leaks on low memory) workaround disabled Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: <core> [main.c:3062]: main(): processes (at least): 30 - shm size: 134217728 - pkg size: 33554432 Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: <core> [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 for fd 9 Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: <core> [core/udp_server.c:207]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 on fd 9 Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: <core> [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 for fd 10 Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: <core> [core/udp_server.c:207]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 on fd 10 Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: <core> [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 for fd 11 Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: <core> [core/udp_server.c:207]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 on fd 11 Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:328]: ksr_tls_fill_missing(): TLSs<default>: tls_method=20 Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:340]: ksr_tls_fill_missing(): TLSs<default>: certificate='/etc/kamailio/livecert/fullchain.pem' Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:347]: ksr_tls_fill_missing(): TLSs<default>: ca_list='/etc/kamailio/livecert/chain.pem' Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:354]: ksr_tls_fill_missing(): TLSs<default>: ca_path='(null)' Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:361]: ksr_tls_fill_missing(): TLSs<default>: crl='(null)' Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:364]: ksr_tls_fill_missing(): TLSs<default>: require_certificate=0 Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:372]: ksr_tls_fill_missing(): TLSs<default>: cipher_list='AES256-SHA' Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:379]: ksr_tls_fill_missing(): TLSs<default>: private_key='/etc/kamailio/livecert/privkey.pem' Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:382]: ksr_tls_fill_missing(): TLSs<default>: verify_certificate=0 Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:386]: ksr_tls_fill_missing(): TLSs<default>: verify_depth=9 Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:389]: ksr_tls_fill_missing(): TLSs<default>: verify_client=0 Aug 1 12:21:47 kam-test01 /usr/local/sbin/kamailio[25502]: NOTICE: tls [tls_domain.c:1144]: ksr_tls_fix_domain(): registered server_name callback handler for socket [:0], server_name='<default>' ... Aug 1 12:21:49 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:750]: set_verification(): TLSs<default>: No client certificate required and no checks performed Aug 1 12:21:49 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:328]: ksr_tls_fill_missing(): TLSc<default>: tls_method=18 Aug 1 12:21:49 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:340]: ksr_tls_fill_missing(): TLSc<default>: certificate='/etc/kamailio/livecert/fullchain.pem' Aug 1 12:21:49 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:347]: ksr_tls_fill_missing(): TLSc<default>: ca_list='/etc/kamailio/livecert/chain.pem' Aug 1 12:21:49 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:354]: ksr_tls_fill_missing(): TLSc<default>: ca_path='(null)' Aug 1 12:21:49 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:361]: ksr_tls_fill_missing(): TLSc<default>: crl='(null)' Aug 1 12:21:49 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:364]: ksr_tls_fill_missing(): TLSc<default>: require_certificate=0 Aug 1 12:21:49 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:372]: ksr_tls_fill_missing(): TLSc<default>: cipher_list='ECDHE-RSA-AES256-GCM-SHA384' Aug 1 12:21:49 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:379]: ksr_tls_fill_missing(): TLSc<default>: private_key='/etc/kamailio/livecert/privkey.pem' Aug 1 12:21:49 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:382]: ksr_tls_fill_missing(): TLSc<default>: verify_certificate=0 Aug 1 12:21:49 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:386]: ksr_tls_fill_missing(): TLSc<default>: verify_depth=9 Aug 1 12:21:49 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:389]: ksr_tls_fill_missing(): TLSc<default>: verify_client=0 Aug 1 12:21:50 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:753]: set_verification(): TLSc<default>: Server MAY present invalid certificate Aug 1 12:21:50 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:328]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: tls_method=22 Aug 1 12:21:50 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:340]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: certificate='/etc/kamailio/livecert/fullchain.pem' Aug 1 12:21:50 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:347]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: ca_list='/etc/kamailio/livecert/chain.pem' Aug 1 12:21:50 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:354]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: ca_path='(null)' Aug 1 12:21:50 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:361]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: crl='(null)' Aug 1 12:21:50 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:364]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: require_certificate=0 Aug 1 12:21:50 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:372]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: cipher_list='ECDHE-RSA-AES256-GCM-SHA384' Aug 1 12:21:50 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:379]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: private_key='/etc/kamailio/livecert/privkey.pem' Aug 1 12:21:50 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:382]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: verify_certificate=0 Aug 1 12:21:50 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:386]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: verify_depth=9 Aug 1 12:21:50 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:389]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: verify_client=0 Aug 1 12:21:50 kam-test01 /usr/local/sbin/kamailio[25502]: NOTICE: tls [tls_domain.c:1144]: ksr_tls_fix_domain(): registered server_name callback handler for socket [172.16.51.200:5067], server_name='test2.test.com' ... Aug 1 12:21:51 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:750]: set_verification(): TLSs<172.16.51.200:5067>: No client certificate required and no checks performed Aug 1 12:21:51 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:328]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: tls_method=22 Aug 1 12:21:51 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:340]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: certificate='/etc/kamailio/livecert/fullchain.pem' Aug 1 12:21:51 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:347]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: ca_list='/etc/kamailio/livecert/chain.pem' Aug 1 12:21:51 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:354]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: ca_path='(null)' Aug 1 12:21:51 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:361]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: crl='(null)' Aug 1 12:21:51 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:364]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: require_certificate=0 Aug 1 12:21:51 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:372]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: cipher_list='ECDHE-RSA-AES256-GCM-SHA384' Aug 1 12:21:51 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:379]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: private_key='/etc/kamailio/livecert/privkey.pem' Aug 1 12:21:51 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:382]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: verify_certificate=0 Aug 1 12:21:51 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:386]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: verify_depth=9 Aug 1 12:21:51 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:389]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: verify_client=0 Aug 1 12:21:52 kam-test01 /usr/local/sbin/kamailio[25502]: NOTICE: tls [tls_domain.c:1144]: ksr_tls_fix_domain(): registered server_name callback handler for socket [172.16.51.200:5067], server_name='test.test.com' ... Aug 1 12:21:53 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:750]: set_verification(): TLSs<172.16.51.200:5067>: No client certificate required and no checks performed Aug 1 12:21:53 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:328]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: tls_method=22 Aug 1 12:21:53 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:340]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: certificate='/etc/kamailio/livecert/fullchain.pem' Aug 1 12:21:53 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:347]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: ca_list='/etc/kamailio/livecert/chain.pem' Aug 1 12:21:53 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:354]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: ca_path='(null)' Aug 1 12:21:53 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:361]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: crl='(null)' Aug 1 12:21:53 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:364]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: require_certificate=0 Aug 1 12:21:53 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:372]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: cipher_list='ECDHE-RSA-AES256-GCM-SHA384' Aug 1 12:21:53 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:379]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: private_key='/etc/kamailio/livecert/privkey.pem' Aug 1 12:21:53 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:382]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: verify_certificate=0 Aug 1 12:21:53 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:386]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: verify_depth=9 Aug 1 12:21:53 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:389]: ksr_tls_fill_missing(): TLSs<172.16.51.200:5067>: verify_client=0 Aug 1 12:21:53 kam-test01 /usr/local/sbin/kamailio[25502]: NOTICE: tls [tls_domain.c:1144]: ksr_tls_fix_domain(): registered server_name callback handler for socket [172.16.51.200:5067], server_name='test3.test.com' ... Aug 1 12:21:54 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:750]: set_verification(): TLSs<172.16.51.200:5067>: No client certificate required and no checks performed Aug 1 12:21:54 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:328]: ksr_tls_fill_missing(): TLSc<172.16.51.200:5067>: tls_method=18 Aug 1 12:21:54 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:340]: ksr_tls_fill_missing(): TLSc<172.16.51.200:5067>: certificate='/etc/kamailio/livecert/fullchain.pem' Aug 1 12:21:54 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:347]: ksr_tls_fill_missing(): TLSc<172.16.51.200:5067>: ca_list='/etc/kamailio/livecert/chain.pem' Aug 1 12:21:54 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:354]: ksr_tls_fill_missing(): TLSc<172.16.51.200:5067>: ca_path='(null)' Aug 1 12:21:54 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:361]: ksr_tls_fill_missing(): TLSc<172.16.51.200:5067>: crl='(null)' Aug 1 12:21:54 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:364]: ksr_tls_fill_missing(): TLSc<172.16.51.200:5067>: require_certificate=0 Aug 1 12:21:54 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:372]: ksr_tls_fill_missing(): TLSc<172.16.51.200:5067>: cipher_list='ECDHE-RSA-AES256-GCM-SHA384' Aug 1 12:21:54 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:379]: ksr_tls_fill_missing(): TLSc<172.16.51.200:5067>: private_key='/etc/kamailio/livecert/privkey.pem' Aug 1 12:21:54 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:382]: ksr_tls_fill_missing(): TLSc<172.16.51.200:5067>: verify_certificate=0 Aug 1 12:21:54 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:386]: ksr_tls_fill_missing(): TLSc<172.16.51.200:5067>: verify_depth=9 Aug 1 12:21:54 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:389]: ksr_tls_fill_missing(): TLSc<172.16.51.200:5067>: verify_client=0 Aug 1 12:21:56 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: tls [tls_domain.c:753]: set_verification(): TLSc<172.16.51.200:5067>: Server MAY present invalid certificate Aug 1 12:21:56 kam-test01 /usr/local/sbin/kamailio[25504]: INFO: rtpengine [rtpengine.c:2929]: rtpp_test(): rtpengine instance <udp:127.0.0.1:2223> found, support for it enabled Aug 1 12:21:56 kam-test01 /usr/local/sbin/kamailio[25520]: INFO: jsonrpcs [jsonrpcs_sock.c:443]: jsonrpc_dgram_process(): a new child 0/25520 Aug 1 12:21:56 kam-test01 /usr/local/sbin/kamailio[25523]: INFO: ctl [io_listener.c:213]: io_listen_loop(): io_listen_loop: using epoll_lt io watch method (config) Aug 1 12:21:57 kam-test01 /usr/local/sbin/kamailio[25525]: ERROR: <script>: 758:No dispatcher sets up yet Aug 1 12:21:57 kam-test01 /usr/local/sbin/kamailio[25525]: ERROR: <script>: 758:No dispatcher sets up yet Aug 1 12:21:57 kam-test01 /usr/local/sbin/kamailio[25525]: WARNING: <script>: 548:[LOCATION] Location not found rc: -1 sip:lPBKm2s70BBd6u@sipuat.voicesimplified.com;transport=TLS Aug 1 12:21:57 kam-test01 /usr/local/sbin/kamailio[25525]: ERROR: <script>: 758:No dispatcher sets up yet Aug 1 12:21:59 kam-test01 /usr/local/sbin/kamailio[25532]: ERROR: <core> [core/tcp_main.c:4672]: tcpconn_main_timeout(): connect 185.29.208.21:5061 failed (timeout) Aug 1 12:22:06 kam-test01 /usr/local/sbin/kamailio[25508]: NOTICE: <script>: Destination up: sip:redacted Aug 1 12:22:06 kam-test01 /usr/local/sbin/kamailio[25510]: NOTICE: <script>: Destination up: sip:redacted Aug 1 12:22:06 kam-test01 /usr/local/sbin/kamailio[25511]: NOTICE: <script>: Destination up: sip:redacted Aug 1 12:22:06 kam-test01 /usr/local/sbin/kamailio[25508]: NOTICE: <script>: Destination up: sip:redacted Aug 1 12:22:06 kam-test01 /usr/local/sbin/kamailio[25504]: NOTICE: <script>: Destination up: sip:redacted Aug 1 12:22:06 kam-test01 /usr/local/sbin/kamailio[25505]: NOTICE: <script>: Destination up: sip:redacted Aug 1 12:22:06 kam-test01 /usr/local/sbin/kamailio[25504]: NOTICE: <script>: Destination up: sip:redacted Aug 1 12:22:07 kam-test01 /usr/local/sbin/kamailio[25506]: NOTICE: <script>: Destination up: sip:redacted Aug 1 12:22:07 kam-test01 /usr/local/sbin/kamailio[25505]: NOTICE: <script>: Destination up: sip:redacted Aug 1 12:22:07 kam-test01 /usr/local/sbin/kamailio[25506]: NOTICE: <script>: Destination up: sip:redacted Aug 1 12:22:07 kam-test01 /usr/local/sbin/kamailio[25507]: NOTICE: <script>: Destination up: sip:redacted Aug 1 12:22:07 kam-test01 /usr/local/sbin/kamailio[25506]: NOTICE: <script>: Destination up: sip:redacted Aug 1 12:22:07 kam-test01 /usr/local/sbin/kamailio[25506]: NOTICE: <script>: Destination up: sip:redacted Aug 1 12:24:48 kam-test01 /usr/local/sbin/kamailio[25525]: INFO: <script>: R-URI Alias Found and processed Aug 1 12:24:48 kam-test01 /usr/local/sbin/kamailio[25510]: INFO: <script>: R-URI Alias Found and processed Aug 1 12:26:06 kam-test01 /usr/local/sbin/kamailio[25513]: WARNING: tm [t_reply.c:1677]: t_retransmit_reply(): no resolved dst to retransmit Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25526]: CRITICAL: <core> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed pointer (0x7f7a8a860d80), called from tls: tls_init.c: ser_free(323), first free tls: tls_init.c: ser_free(323) - ignoring Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25532]: CRITICAL: <core> [core/pass_fd.c:277]: receive_fd(): EOF on 36 Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25502]: ALERT: <core> [main.c:776]: handle_sigs(): child process 25526 exited by a signal 11 Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25502]: ALERT: <core> [main.c:779]: handle_sigs(): core was generated Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25502]: INFO: <core> [main.c:801]: handle_sigs(): terminating due to SIGCHLD Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25532]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25513]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25531]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25522]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25521]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25525]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25520]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25514]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25529]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25511]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25515]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25509]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25519]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25516]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25517]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25512]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25510]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25506]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25504]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25524]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25518]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25523]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25508]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25528]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25530]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25505]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25507]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received Aug 1 12:27:17 kam-test01 /usr/local/sbin/kamailio[25527]: INFO: <core> [main.c:856]: sig_usr(): signal 15 received ``` ### Additional Information Tested against kamailio 5.6 and devel branches with a distclean between builds ``` (paste your output here) ``` * **Operating System**:  ``` No LSB modules are available. Distributor ID: Ubuntu Description: Ubuntu 22.04.1 LTS Release: 22.04 Codename: jammy Linux kam-test01 5.15.0-1014-azure #17-Ubuntu SMP Thu Jun 23 19:04:16 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux ``` -- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/3205 You are receiving this because you are subscribed to this thread. Message ID: <kamailio/kamailio/issues/3205(a)github.com>

2 weeks, 2 days

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009

2008

sr-dev October 2024