sr-dev October 2024

sr-dev@lists.kamailio.org

14 participants
114 discussions

[kamailio/kamailio] [JWT module] Verification doesn't check if the JWT is expired (Issue #4007)
by Lyuboslav Alexandrov 15 Nov '24

15 Nov '24

### 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>

2 5

[kamailio/kamailio] The tm.cancel function immediately deletes the transaction. (Issue #4011)
by JuanPascual2 15 Nov '24

15 Nov '24

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>

2 4

[kamailio/kamailio] tm: move local-request event route to the right location to access CANCEL (PR #3979)
by Xenofon Karamanos 14 Nov '24

14 Nov '24

#### 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>

5 9

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

08 Nov '24

### 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>

7 21

Kamailio Developers Meeting, Nov 19-20, 2024, in Dusseldorf
by Daniel-Constantin Mierla 06 Nov '24

06 Nov '24

Hello, Kamailio SIP Server project is organizing another meeting of its developers and community members during November 19-20, 2024 (Tue-Wed), hosted again by sipgate.de in Dusseldorf, Germany. The event is intended to facilitate the interaction between Kamailio developers and contributors in order to offer a convenient environment for working together on several topics of high interest for the project, including writing code for Kamailio and its tools, improving documentation, or discuss about future development. Everyone from the community is welcome to join, developer or user interested in helping the project. Please note we have a limited capacity of seats in the meeting room, the main policy for accepting participants being first come first server. Also, very important to be aware that this is not an event to learn how to use Kamailio. More details about the event, the venue, how to register, are available at: * https://www.kamailio.org/w/developers-meeting/ Looking forward to those two intensive hacking Kamailio days in Dusseldorf! Cheers, Daniel -- Daniel-Constantin Mierla (@ asipto.com) twitter.com/miconda -- linkedin.com/in/miconda Kamailio Consultancy, Training and Development Services -- asipto.com

1 3

[kamailio/kamailio] Segmentation fault when sending ACK for 487 to duplicate URI using siptrace module (Issue #3970)
by Muhammad Shahzad Shafi 06 Nov '24

06 Nov '24

### Description  We have random kamailio crashes with Segmentation Fault. It happens when ACK for canceled call is received by Kamailio SIP proxy and forwarded to trace server using siptrace module. ### Troubleshooting #### Reproduction  So far the problem happens only in live environment, we are unable to reproduce it in our Dev environment. #### Debugging Data  ``` #0 0x00007f3a0fa747b4 in msg_send_buffer (dst=0x7f3924d6ba60, buf=0x55fba122c280 <buf> "ACK sip:49xxxxxxxxxx@sip.proxy.de:5060 SIP/2.0\r\nMax-Forwards: 19\r\nRecord-Route: <sip:aa.bb.cc.dd;lr=on;ftag=2041847FA948DA9D>\r\nVia: SIP/2.0/UDP aa.bb.cc.dd;branch=z9hG4bKebee.750c2ac00"..., len=605, flags=1) at ../../core/forward.h:220 new_dst = {send_sock = 0x2000000, to = {s = {sa_family = 0, sa_data = "\000\000\001\000\000\000\020\374 \004\000\000"}, sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 1}, sin_zero = "\020\374 \004\000\000"}, sin6 = {sin6_family = 0, sin6_port = 0, sin6_flowinfo = 1, sin6_addr = {__in6_u = {__u6_addr8 = "\020\374 \004\000\000\000\257\335\017\241\373U\000", __u6_addr16 = {64528, 41154, 4, 0, 56751, 41231, 22011, 0}, __u6_addr32 = {2697133072, 4, 2702171567, 22011}}}, sin6_scope_id = 0}, sas = {ss_family = 0, __ss_padding = "\000\000\001\000\000\000\020\374 \004\000\000\000\257\335\017\241\373U", '\000' <repeats 11 times>, "\244\066\246\324.\301\351\300$}n\374\177\000\000\021\006\371\240\373U\000\000\360#}n\374\177\000\000\223\vΠ\373U\000\000\000\000\000\000\000\000\000\000(a)$}n\374\177\000\000\067(}n5060\000\244\066\246\324.\301\351\374'}n\374\177\000\000\000\000\000\000\000\000\000", __ss_align = 140722162182140}}, id = 59, send_flags = {f = 0, blst_imask = 0}, proto = 64 '@', proto_pad0 = 36 '$', proto_pad1 = 28285} outb = { s = 0x55fba122c280 <buf> "ACK sip:49xxxxxxxxxx@sip.proxy.de:5060 SIP/2.0\r\nMax-Forwards: 19\r\nRecord-Route: <sip:aa.bb.cc.dd;lr=on;ftag=2041847FA948DA9D>\r\nVia: SIP/2.0/UDP aa.bb.cc.dd;branch=z9hG4bKebee.750c2ac00"..., len = 605} netinfo = {data = {s = 0xb000003a8 <error: Cannot access memory at address 0xb000003a8>, len = 29}, bufsize = 1853694672, rcv = 0x7c101230db, dst = 0x1} evp = {data = 0x0, obuf = {s = 0x0, len = 0}, rcv = 0x0, dst = 0x0, req = 0x0, rpl = 0x0, rplcode = 0, mode = 0} port = -1597834224 ip = {af = 2697133072, len = 0, u = {addrl = {3221225482794, 1512}, addr32 = {10794, 750, 1512, 0}, addr16 = {10794, 0, 750, 0, 1512, 0, 0, 0}, addr = "**\000\000\356\002\000\000\350\005\000\000\000\000\000"}} from = 0x0 local_addr = {s = {sa_family = 18112, sa_data = "\235\037\071\177\000\000\320[~\033\071\177\000"}, sin = {sin_family = 18112, sin_port = 8093, sin_addr = {s_addr = 32569}, sin_zero = "\320[~\033\071\177\000"}, sin6 = { sin6_family = 18112, sin6_port = 8093, sin6_flowinfo = 32569, sin6_addr = {__in6_u = {__u6_addr8 = "\320[~\033\071\177\000\000\210\006w\021:\177\000", __u6_addr16 = {23504, 7038, 32569, 0, 1672, 4471, 32570, 0}, __u6_addr32 = {461265872, 32569, 293013128, 32570}}}, sin6_scope_id = 291708464}, sas = {ss_family = 18112, __ss_padding = "\235\037\071\177\000\000\320[~\033\071\177\000\000\210\006w\021:\177\000\000\060\036c\021:\177\000\000\000\000\000\000\000\000\000\000\005\304\"\241\373U\000\000\207\001\000\000?\000\000\000@\033\366\240\373U\000\000\200#}n\374\177\000\000\020\300\274\020:\177\000\000\330\001\000\000\000\000\000\000\060'}n\374\177\000\000\300#}n\374\177\000\000\324#V\020:\177\000\000\320$}n\374\177\000", __ss_align = 16843795572198908928}} con = 0x0 wsev = {type = 0, buf = 0xe9c12ed4a636a400 <error: Cannot access memory at address 0xe9c12ed4a636a400>, len = 1853694896, id = 32764} ret = 32764 __func__ = "msg_send_buffer" #1 0x00007f3a0fa7ca80 in trace_send_duplicate ( buf=0x55fba122c280 <buf> "ACK sip:49xxxxxxxxxx@sip.proxy.de:5060 SIP/2.0\r\nMax-Forwards: 19\r\nRecord-Route: <sip:aa.bb.cc.dd;lr=on;ftag=2041847FA948DA9D>\r\nVia: SIP/2.0/UDP aa.bb.cc.dd;branch=z9hG4bKebee.750c2ac00"..., len=605, dst2=0x7f3924d6ba60) at siptrace_send.c:356 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 117 times>, __ss_align = 0}}, id = 0, send_flags = {f = 0, blst_imask = 0}, proto = 0 '\000', proto_pad0 = 0 '\000', proto_pad1 = 0} pdst = 0x7f3924d6ba60 p = 0x0 __func__ = "trace_send_duplicate" #2 0x00007f3a0fa3f730 in sip_trace_store (sto=0x7ffc6e7d2730, dst=0x7f3924d6ba60, correlation_id_str=0x0) at siptrace.c:593 ret = 1 __func__ = "sip_trace_store" #3 0x00007f3a0fa49101 in sip_trace (msg=0x7f3a1189d500, dst=0x7f3924d6ba60, correlation_id_str=0x0, dir=0x0) at siptrace.c:1303 sto = {avp = 0x0, avp_value = {n = 0, s = {s = 0x0, len = 0}, re = 0x0}, state = {flags = 0, id = 0, name = {n = 0, s = {s = 0x0, len = 0}, re = 0x0}, avp = 0x0}, body = { s = 0x55fba122c280 <buf> "ACK sip:49xxxxxxxxxx@sip.proxy.de:5060 SIP/2.0\r\nMax-Forwards: 19\r\nRecord-Route: <sip:aa.bb.cc.dd;lr=on;ftag=2041847FA948DA9D>\r\nVia: SIP/2.0/UDP aa.bb.cc.dd;branch=z9hG4bKebee.750c2ac00"..., len = 605}, alloc_body = 0, callid = {s = 0x55fba122c45d <buf+477> "19C4ED5E658858CF(a)ab.bc.cd.da\r\nCSeq: 9 ACK\r\nUser-Agent: AVM FRITZ!Box 7590 (UI) 154.07.59 (May 8 2024)\r\nContent-Length: 0\r\n\r\n", len = 31}, method = { s = 0x55fba122c280 <buf> "ACK sip:49xxxxxxxxxx@sip.proxy.de:5060 SIP/2.0\r\nMax-Forwards: 19\r\nRecord-Route: <sip:aa.bb.cc.dd;lr=on;ftag=2041847FA948DA9D>\r\nVia: SIP/2.0/UDP aa.bb.cc.dd;branch=z9hG4bKebee.750c2ac00"..., len = 3}, status = {s = 0x7f3a0fa7d065 "", len = 0}, dir = 0x7f3a0fa7ffb5 "in", fromtag = { s = 0x55fba122c3f4 <buf+372> "2041847FA948DA9D\r\nTo: <sip:49yyyyyyyyyy@sip.proxy.de>;tag=8e46bdec-8fb1-4814-b516-575f5cd3315c\r\nCall-ID: 19C4ED5E658858CF(a)ab.bc.cd.da\r\nCSeq: 9 ACK\r\nUser-Agent: AVM FRITZ!Box 7590 (UI) 154.07.59 (Ma"..., len = 16}, fromip = {s = 0x7ffc6e7d2838 "udp:aa.bb.cc.dd:5060", len = 24}, totag = { s = 0x55fba122c42e <buf+430> "8e46bdec-8fb1-4814-b516-575f5cd3315c\r\nCall-ID: 19C4ED5E658858CF(a)ab.bc.cd.da\r\nCSeq: 9 ACK\r\nUser-Agent: AVM FRITZ!Box 7590 (UI) 154.07.59 (May 8 2024)\r\nContent-Length: 0\r\n\r\n", len = 36}, toip = {s = 0x7ffc6e7d27fc "udp:aa.bb.cc.dd:5060", len = 23}, alloc_headers = 0, toip_buff = "udp:aa.bb.cc.dd:5060", '\000' <repeats 36 times>, fromip_buff = "udp:aa.bb.cc.dd:5060", '\000' <repeats 35 times>, tv = {tv_sec = 1725002318, tv_usec = 379190}, stat = 0x92} snd_inf = 0x0 __func__ = "sip_trace" #4 0x00007f3a0fa51497 in trace_tm_neg_ack_in (t=0x7f3921846038, type=4096, ps=0x7ffc6e7d2ad0) at siptrace.c:1769 info = 0x7f3924d6ba50 __func__ = "trace_tm_neg_ack_in" #5 0x00007f3a10659002 in run_trans_callbacks_internal (cb_lst=0x7f39218460b0, type=4096, trans=0x7f3921846038, params=0x7ffc6e7d2ad0) at t_hooks.c:258 cbp = 0x7f39205f2fb8 backup_from = 0x55fba123c2b0 <def_list+16> backup_to = 0x55fba123c2b8 <def_list+24> backup_dom_from = 0x55fba123c2c0 <def_list+32> backup_dom_to = 0x55fba123c2c8 <def_list+40> backup_uri_from = 0x55fba123c2a0 <def_list> backup_uri_to = 0x55fba123c2a8 <def_list+8> backup_xavps = 0x55fba123c3f8 <_xavp_list_head> backup_xavus = 0x55fba123c400 <_xavu_list_head> backup_xavis = 0x55fba123c408 <_xavi_list_head> __func__ = "run_trans_callbacks_internal" #6 0x00007f3a10659179 in run_trans_callbacks (type=4096, trans=0x7f3921846038, req=0x7f3a1189d500, rpl=0x0, code=4) at t_hooks.c:285 params = {req = 0x7f3a1189d500, rpl = 0x0, param = 0x7f39205f2fc8, code = 4, flags = 0, branch = 0, t_rbuf = 0x0, dst = 0x0, send_buf = {s = 0x0, len = 0}} #7 0x00007f3a106ec1bb in t_check_trans (msg=0x7f3a1189d500) at tm.c:2488 t = 0x7f3921846038 branch = 292764808 ret = 32570 #8 0x00007f3a106ec257 in w_t_check_trans (msg=0x7f3a1189d500, foo=0x0, bar=0x0) at tm.c:2509 No locals. #9 0x000055fba0c58367 in do_action (h=0x7ffc6e7d3400, a=0x7f3a10d8e8d0, msg=0x7f3a1189d500) at core/action.c:1079 ret = -5 v = 481060096 dst = {send_sock = 0x0, to = {s = {sa_family = 0, sa_data = "\000\000\000\000\000\000 2}n\374\177\000"}, sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = " 2}n\374\177\000"}, sin6 = {sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = {__u6_addr8 = " 2}n\374\177\000\000ouڠ\373U\000", __u6_addr16 = {12832, 28285, 32764, 0, 30063, 41178, 22011, 0}, __u6_addr32 = {1853698592, 32764, 2698671471, 22011}}}, sin6_scope_id = 1853698656}, sas = {ss_family = 0, __ss_padding = "\000\000\000\000\000\000 2}n\374\177\000\000ouڠ\373U\000\000`2}n\374\177\000\000P2}n\374\177\000\000pmN\021:\177\000\000\000Չ\021:\177\000\000\001", '\000' <repeats 11 times>, "\324.\301\351\060\214+\021:\177\000\000\000\000\000\000\001\000\000\000\020\374 \373U", '\000' <repeats 25 times>, __ss_align = 140722162184688}}, id = 1853699008, send_flags = {f = 32764, blst_imask = 0}, proto = 64 '@', proto_pad0 = 108 'l', proto_pad1 = 4430} tmp = 0xe9c12ed4a636a400 <error: Cannot access memory at address 0xe9c12ed4a636a400> new_uri = 0x7f390fa416c8 "" end = 0x7f3a1012a2eb "dialog" crt = 0x7f391ff27010 "0" cmd = 0x7f3a10c68118 len = 262176768 user = 32569 uri = {user = {s = 0x1 <error: Cannot access memory at address 0x1>, len = 461265892}, passwd = {s = 0x7ffc6e7d2f80 "", len = 536880704}, host = {s = 0x1 <error: Cannot access memory at address 0x1>, len = 461265892}, port = { s = 0x7ffc6e7d2e60 "p/}n\006", len = 269282911}, params = {s = 0x16e7d2e80 <error: Cannot access memory at address 0x16e7d2e80>, len = 461265892}, sip_params = {s = 0x7ffc6e7d2e80 "@/}n\374\177", len = 269282911}, headers = {s = 0x66e7d2f70 <error: Cannot access memory at address 0x66e7d2f70>, len = 269627611}, port_no = 41707, proto = 4114, type = 32570, flags = (unknown: 0xa636a400), transport = {s = 0x7ffc6e7d2f40 "`/}n\374\177", len = 269321843}, ttl = {s = 0x1ff27048 <error: Cannot access memory at address 0x1ff27048>, len = 10794}, user_param = {s = 0x7ffc000005e8 <error: Cannot access memory at address 0x7ffc000005e8>, len = 269526667}, maddr = {s = 0x7f391f9d46c0 "\002", len = 461265872}, method = {s = 0x100000478 <error: Cannot access memory at address 0x100000478>, len = 530400960}, lr = { s = 0x5e8112b6508 <error: Cannot access memory at address 0x5e8112b6508>, len = 530400960}, r2 = {s = 0x7ffc6e7d2f30 "", len = 461265872}, gr = {s = 0x1 <error: Cannot access memory at address 0x1>, len = 461265892}, transport_val = {s = 0x7f391d7ffc08 "\240\374\177\035\071\177", len = -1506368512}, ttl_val = {s = 0x16e7d2f50 <error: Cannot access memory at address 0x16e7d2f50>, len = 461265892}, user_param_val = { s = 0x7ffc6e7d2f50 "`0}n\374\177", len = 269282911}, maddr_val = {s = 0x600000000 <error: Cannot access memory at address 0x600000000>, len = 461265892}, method_val = {s = 0x7ffc6e7d2f60 "p/}n\374\177", len = -1506368512}, lr_val = {s = 0x7ffc6e7d3060 "\200\060}n\374\177", len = 269351486}, r2_val = {s = 0x7ffc6e7d2f70 "`0}n\374\177", len = 269554093}, gr_val = {s = 0x7ffc6e7d3060 "\200\060}n\374\177", len = 269242067}} next_hop = {user = {s = 0x0, len = 530400960}, passwd = {s = 0x0, len = 294245632}, host = {s = 0x0, len = 269627637}, port = {s = 0x100000478 <error: Cannot access memory at address 0x100000478>, len = 530400960}, params = { s = 0x5e86e7d2ff0 <error: Cannot access memory at address 0x5e86e7d2ff0>, len = 269282911}, sip_params = {s = 0x608012157 <error: Cannot access memory at address 0x608012157>, len = 461265872}, headers = { s = 0x55fba0c2fc10 <_start> "1\355I\211\321^H\211\342H\203\344\360PTL\215\005ZaE", len = -1506368512}, port_no = 12464, proto = 28285, type = 32764, flags = (URI_USER_NORMALIZE | URI_SIP_USER_PHONE | unknown: 0x100d8670), transport = {s = 0x3e0 <error: Cannot access memory at address 0x3e0>, len = 10794}, ttl = {s = 0x7f3a000005e8 "", len = 0}, user_param = {s = 0x1 <error: Cannot access memory at address 0x1>, len = -1506368512}, maddr = { s = 0x0, len = 0}, method = {s = 0x55fba0c2fc10 <_start> "1\355I\211\321^H\211\342H\203\344\360PTL\215\005ZaE", len = 0}, lr = {s = 0x0, len = 0}, r2 = {s = 0x7ffc6e7d3080 "`1}n\374\177", len = 1853698640}, gr = { s = 0x7f3a114e6d88 "", len = 294245632}, transport_val = {s = 0x7ffc6e7d3160 " 2}n\374\177", len = 269543303}, ttl_val = {s = 0x7ffc6e7d30c0 "\300F\235\037\071\177", len = 1853698640}, user_param_val = { s = 0x7f3a114e6d88 "", len = 294245632}, maddr_val = {s = 0x5e86e7d30d0 <error: Cannot access memory at address 0x5e86e7d30d0>, len = -1506368512}, method_val = {s = 0x7f391f9d46c0 "\002", len = 0}, lr_val = {s = 0x0, len = 269554093}, r2_val = {s = 0x7ffc6e7d31d0 "\360\061}n\374\177", len = 269242067}, gr_val = {s = 0x0, len = 0}} u = 0x7f390fa08000 port = 4114 dst_host = 0xcfa0f542d7 i = 16 flags = 32569 avp = 0x4a0c2fc10 st = {flags = 48, id = 0, name = {n = 262176768, s = {s = 0x7f390fa08000 "", len = 535981944}, re = 0x7f390fa08000}, avp = 0x7f391ff270a8} sct = 0x55fba0f5a088 <qm_free+8063> sjt = 0x16e7d2d90 rve = 0x7f390fa082e0 mct = 0x7ffc6e7d2e60 rv = 0x7f390fa08000 rv1 = 0x6a10f4e54 c1 = {cache_type = 290, val_type = RV_NONE, c = {avp_val = {n = 269627637, s = {s = 0x7f3a101230f5 "dlg_hash.c", len = 1144}, re = 0x7f3a101230f5}, pval = {rs = {s = 0x7f3a101230f5 "dlg_hash.c", len = 1144}, ri = -1506368512, flags = -373215532}}, i2s = "\300YO\021\350\005\000\000\000\000\000\000\001\000\000\000\020\374 \373U"} s = {s = 0x7f3a1012a770 <__func__.11> "set_dlg_variable_unsafe", len = 269657780} srevp = {0x0, 0x7f3a1189d500} 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 = NUMBER_ST, u = {number = 1, string = 0x1 <error: Cannot access memory at address 0x1>, str = {s = 0x1 <error: Cannot access memory at address 0x1>, len = 0}, data = 0x1, attr = 0x1, select = 0x1}}, {type = RVE_FREE_FIXUP_ST, u = {number = 0, string = 0x0, str = {s = 0x0, len = 13}, data = 0x0, attr = 0x0, select = 0x0}}, {type = RVE_FREE_FIXUP_ST, u = {number = 0, string = 0x0, str = {s = 0x0, len = 1}, 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" #10 0x000055fba0c67391 in run_actions (h=0x7ffc6e7d3400, a=0x7f3a10d8e8d0, msg=0x7f3a1189d500) at core/action.c:1584 t = 0x7f3a10d8e8d0 ret = -1 tvb = {tv_sec = 0, tv_usec = 0} tve = {tv_sec = 0, tv_usec = 0} tz = {tz_minuteswest = 294245632, tz_dsttime = 32570} tdiff = 294245632 __func__ = "run_actions" #11 0x000055fba0c67aff in run_actions_safe (h=0x7ffc6e7d5890, a=0x7f3a10d8e8d0, msg=0x7f3a1189d500) at core/action.c:1648 ctx = {rec_lev = 1, run_flags = 0, last_retcode = 0, jmp_env = {{__jmpbuf = {4294967296, 6741736921070007646, 94539222285328, 0, 0, 0, 6741736921084687710, 684806027146655070}, __mask_was_saved = 0, __saved_mask = {__val = { 139887379076352, 0, 0, 0, 0, 0, 0, 0, 0, 140722162185472, 139887358911444, 140722162185440, 0, 33554432, 20328504, 10576624}}}}} ret = 32764 ign_on_break = 0 #12 0x000055fba0e1226d in rval_get_int (h=0x7ffc6e7d5890, msg=0x7f3a1189d500, i=0x7ffc6e7d37e0, rv=0x7f3a10d8ea28, cache=0x0) at core/rvalue.c:949 r_avp = 0xf6a0c67aff avp_val = {n = 281523440, s = {s = 0x7f3a10c7b4f0 "ou\003\020:\177", len = -1593034239}, re = 0x7f3a10c7b4f0} pval = {rs = {s = 0x7f3a10c6c4a0 "\346\024S\020:\177", len = 0}, ri = 1, flags = 22011} tmp = {s = 0x3a8 <error: Cannot access memory at address 0x3a8>, len = 280805392} s = 0x0 r = 32764 ret = 0 destroy_pval = 0 __func__ = "rval_get_int" #13 0x000055fba0e17841 in rval_expr_eval_int (h=0x7ffc6e7d5890, msg=0x7f3a1189d500, res=0x7ffc6e7d37e0, rve=0x7f3a10d8ea20) at core/rvalue.c:1947 i1 = -1506368512 i2 = -373215532 ret = -1 c1 = {cache_type = 1853699856, val_type = 32764, c = {avp_val = {n = -1595865264, s = {s = 0x55fba0e10750 <rval_new_str+136> "H\213E\370H\213P\bH\213E\350\213@\bH\230H\001\320", <incomplete sequence \306>, len = -1597834224}, re = 0x55fba0e10750 <rval_new_str+136>}, pval = {rs = {s = 0x55fba0e10750 <rval_new_str+136> "H\213E\370H\213P\bH\213E\350\213@\bH\230H\001\320", <incomplete sequence \306>, len = -1597834224}, ri = 1853699936, flags = 32764}}, i2s = "\001\000\000\000\000\000\000\000X\026s\021:\177\000\000\335\304\"\241\373U"} c2 = {cache_type = 13, val_type = 17, c = {avp_val = {n = 0, s = {s = 0x0, len = 290409088}, re = 0x0}, pval = {rs = {s = 0x0, len = 290409088}, ri = 1853700172, flags = 32764}}, i2s = "\335\304\"\241\373U\000\000\330\304\"\241\373U\000\000\000\000\000\000\001"} rv1 = 0x0 rv2 = 0x0 __func__ = "rval_expr_eval_int" #14 0x000055fba0c57dbd in do_action (h=0x7ffc6e7d5890, a=0x7f3a10d925d8, msg=0x7f3a1189d500) at core/action.c:1055 ret = -5 v = 14401040 dst = {send_sock = 0x7f3a1189d500, to = {s = {sa_family = 22672, sa_data = "}n\374\177\000\000\000\000\000\000:\177\000"}, sin = {sin_family = 22672, sin_port = 28285, sin_addr = {s_addr = 32764}, sin_zero = "\000\000\000\000:\177\000"}, sin6 = {sin6_family = 22672, sin6_port = 28285, sin6_flowinfo = 32764, sin6_addr = {__in6_u = {__u6_addr8 = "\000\000\000\000:\177\000\000\000\000\000\000\000\000\000", __u6_addr16 = {0, 0, 32570, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 32570, 0, 0}}}, sin6_scope_id = 294245632}, sas = {ss_family = 22672, __ss_padding = "}n\374\177\000\000\000\000\000\000:\177", '\000' <repeats 11 times>, "Չ\021:\177\000\000\240V}n\374\177\000\000\000\000\000\000\000\000\000\000<\310\"\241\373U\000\000XP\307\020:\177\000\000>\310\"\241\373U\000\000\000\000\000\000\000\000\000\000@\022\060\021\377\377\377\377pA}\021:\177\000\000\000\000\000\000\001", '\000' <repeats 11 times>, "\020\274\241\242\373U\000", __ss_align = 0}}, id = 0, send_flags = {f = 0, blst_imask = 0}, proto = 0 '\000', proto_pad0 = 0 '\000', proto_pad1 = 0} tmp = 0x55fba0c67391 <run_actions+2339> "\211\205\274\376\377\377H\307\005F\243P" new_uri = 0x55fba0f78206 <parse_headers+2307> "\351\021\066" end = 0x7ffc6e7d3990 "" crt = 0x55fba0c2fc10 <_start> "1\355I\211\321^H\211\342H\203\344\360PTL\215\005ZaE" cmd = 0x55fba0c2fc10 <_start> len = 8 user = 0 uri = {user = {s = 0x55fba0c2fc10 <_start> "1\355I\211\321^H\211\342H\203\344\360PTL\215\005ZaE", len = 0}, passwd = {s = 0x0, len = -1506368512}, host = {s = 0x7f3a114f4a80 "\002", len = 0}, port = { s = 0x55fba0c2fc10 <_start> "1\355I\211\321^H\211\342H\203\344\360PTL\215\005ZaE", len = 0}, params = {s = 0x0, len = 0}, sip_params = {s = 0x7ffc6e7d3bf0 "\020=}n\374\177", len = -1597607023}, headers = { s = 0x7ffc6e7d3b10 "\300;}n\374\177", len = 272678193}, port_no = 15376, proto = 28285, type = 32764, flags = (unknown: 0x1189d500), transport = { s = 0x55fba0c2fc10 <_start> "1\355I\211\321^H\211\342H\203\344\360PTL\215\005ZaE", len = 294245632}, ttl = {s = 0x7f3a10d8db28 "\272\002", len = 1853701168}, user_param = {s = 0x7ffc6e7d3bc0 "\360;}n\374\177", len = -1597605121}, maddr = {s = 0x7f3a114f9a60 "\b\021", len = 294245632}, method = {s = 0x0, len = 1853707936}, lr = {s = 0x0, len = 0}, r2 = {s = 0x0, len = 0}, gr = { s = 0x2a0c2fc10 <error: Cannot access memory at address 0x2a0c2fc10>, len = 272871469}, transport_val = {s = 0x0, len = -1506368512}, ttl_val = {s = 0x7ffc6e7d3bc0 "\360;}n\374\177", len = 272753303}, user_param_val = { s = 0xb823755e <error: Cannot access memory at address 0xb823755e>, len = 294245632}, maddr_val = {s = 0x7ffc00000000 <error: Cannot access memory at address 0x7ffc00000000>, len = -1506368512}, method_val = { s = 0x1a113016f0 <error: Cannot access memory at address 0x1a113016f0>, len = 0}, lr_val = {s = 0x7f3a118ba988 "", len = 294245632}, r2_val = {s = 0x0, len = 294365576}, gr_val = { s = 0x55fba0c2fc10 <_start> "1\355I\211\321^H\211\342H\203\344\360PTL\215\005ZaE", len = 0}} next_hop = {user = {s = 0x0, len = -1506368512}, passwd = {s = 0x7ffc6e7d3d00 "p>}n\374\177", len = 0}, host = {s = 0x55fba0c2fc10 <_start> "1\355I\211\321^H\211\342H\203\344\360PTL\215\005ZaE", len = 0}, port = {s = 0x0, len = -1506368512}, params = {s = 0x7ffc6e7d3bf0 "\020=}n\374\177", len = 0}, sip_params = {s = 0x55fba0c2fc10 <_start> "1\355I\211\321^H\211\342H\203\344\360PTL\215\005ZaE", len = 0}, headers = {s = 0x0, len = 0}, port_no = 15632, proto = 28285, type = 32764, flags = (URI_USER_NORMALIZE | URI_SIP_USER_PHONE | unknown: 0xa0c67afc), transport = {s = 0x7f3a1189d500 ">D%", len = 294245632}, ttl = {s = 0x7f3a10d8db28 "\272\002", len = 1853708432}, user_param = {s = 0x7f3a10d27680 "\370\001", len = 0}, maddr = {s = 0x0, len = 1}, method = {s = 0x100000000 <error: Cannot access memory at address 0x100000000>, len = -1109166754}, lr = { s = 0x55fba0c2fc10 <_start> "1\355I\211\321^H\211\342H\203\344\360PTL\215\005ZaE", len = 0}, r2 = {s = 0x0, len = 0}, gr = {s = 0x5d8f7602bec3755e <error: Cannot access memory at address 0x5d8f7602bec3755e>, len = 337605982}, transport_val = {s = 0x0, len = 0}, ttl_val = {s = 0x5d8f7602bf03755e <error: Cannot access memory at address 0x5d8f7602bf03755e>, len = 337605982}, user_param_val = {s = 0x0, len = 0}, maddr_val = { s = 0x0, len = 0}, method_val = {s = 0x0, len = -1506368512}, lr_val = {s = 0x1 <error: Cannot access memory at address 0x1>, len = 0}, r2_val = { s = 0x55fba0c2fc10 <_start> "1\355I\211\321^H\211\342H\203\344\360PTL\215\005ZaE", len = 0}, gr_val = {s = 0x0, len = 0}} u = 0xe9c12ed4a636a400 port = 201 dst_host = 0x10476dde i = 298 flags = 0 avp = 0x0 st = {flags = 0, id = 0, name = {n = -1591556899, s = {s = 0x55fba122c4dd <buf+605> "", len = 293390512}, re = 0x55fba122c4dd <buf+605>}, avp = 0x55fba122c4db <buf+603>} sct = 0x0 sjt = 0x7ffc6e7d3a60 rve = 0x7f3a10d8ea20 mct = 0x0 rv = 0x7ffc6e7d3aa0 rv1 = 0x100000000 c1 = {cache_type = 1853701712, val_type = 32764, c = {avp_val = {n = -1595858323, s = { s = 0x55fba0e1226d <rval_get_int+341> "\205\300\017\237\300\017\266\320H\213\205\370\376\377\377\211\020H\213\205\b\377\377\377\213@\004\203\340\371\211\302H\213\205\b\377\377\377\211P\004\351y\006", len = 1853701712}, re = 0x55fba0e1226d <rval_get_int+341>}, pval = {rs = { s = 0x55fba0e1226d <rval_get_int+341> "\205\300\017\237\300\017\266\320H\213\205\370\376\377\377\211\020H\213\205\b\377\377\377\213@\004\203\340\371\211\302H\213\205\b\377\377\377\211P\004\351y\006", len = 1853701712}, ri = -1506368512, flags = -373215532}}, i2s = "H\266O\021:\177\000\000\000\000\000\000\000\000\000\000\300\337\330\020:\177"} s = {s = 0x200 <error: Cannot access memory at address 0x200>, len = 294245632} srevp = {0x7ffc6e7d3e70, 0xe9c12ed4a636a400} 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 = NUMBER_ST, u = {number = 1, string = 0x1 <error: Cannot access memory at address 0x1>, str = {s = 0x1 <error: Cannot access memory at address 0x1>, len = 0}, data = 0x1, attr = 0x1, select = 0x1}}, {type = RVE_FREE_FIXUP_ST, u = {number = 0, string = 0x0, str = {s = 0x0, len = 13}, data = 0x0, attr = 0x0, select = 0x0}}, {type = RVE_FREE_FIXUP_ST, u = {number = 0, string = 0x0, str = {s = 0x0, len = 1}, 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" #15 0x000055fba0c67391 in run_actions (h=0x7ffc6e7d5890, a=0x7f3a10d925d8, msg=0x7f3a1189d500) at core/action.c:1584 t = 0x7f3a10d925d8 ret = -1 tvb = {tv_sec = 0, tv_usec = 0} tve = {tv_sec = 0, tv_usec = 0} tz = {tz_minuteswest = 1853708432, tz_dsttime = 32764} tdiff = 1853702160 __func__ = "run_actions" #16 0x000055fba0c582d3 in do_action (h=0x7ffc6e7d5890, a=0x7f3a10d95ce8, msg=0x7f3a1189d500) at core/action.c:1070 ret = 1 v = 1 dst = {send_sock = 0x7f3a1189d500, to = {s = {sa_family = 22672, sa_data = "}n\374\177\000\000\330S}\021:\177\000"}, sin = {sin_family = 22672, sin_port = 28285, sin_addr = {s_addr = 32764}, sin_zero = "\330S}\021:\177\000"}, sin6 = {sin6_family = 22672, sin6_port = 28285, sin6_flowinfo = 32764, sin6_addr = {__in6_u = {__u6_addr8 = "\330S}\021:\177\000\000\000\000\000\000\000\000\000", __u6_addr16 = {21464, 4477, 32570, 0, 0, 0, 0, 0}, __u6_addr32 = {293426136, 32570, 0, 0}}}, sin6_scope_id = 294245632}, sas = {ss_family = 22672, __ss_padding = "}n\374\177\000\000\330S}\021:\177", '\000' <repeats 11 times>, "Չ\021:\177\000\000\240V}n\374\177", '\000' <repeats 11 times>, "Չ\021:\177\000\000P\001\310\020:\177\000\000`G}n\374\177\000\000\000\000\000\000\000\000\000\000\240V}n\377\377\377\377\200\346\301\020:\177\000\000\000\000\000\000\001", '\000' <repeats 11 times>, "\001\000\000\000\000\000\000", __ss_align = 0}}, id = 0, send_flags = {f = 0, blst_imask = 0}, proto = 0 '\000', proto_pad0 = 0 '\000', proto_pad1 = 0} tmp = 0x7f3a1189d500 ">D%" new_uri = 0x7ffc6e7d4310 "" end = 0x7f3a1189d500 ">D%" crt = 0x0 cmd = 0x55fba122c2c6 <buf+70> len = 1853702572 user = 32764 uri = {user = {s = 0x7f3a1189d500 ">D%", len = 293462816}, passwd = {s = 0x55fba0c2fc10 <_start> "1\355I\211\321^H\211\342H\203\344\360PTL\215\005ZaE", len = -1506368512}, host = {s = 0x0, len = 0}, port = { s = 0x55fba0c2fc10 <_start> "1\355I\211\321^H\211\342H\203\344\360PTL\215\005ZaE", len = 0}, params = {s = 0x0, len = 0}, sip_params = {s = 0x7ffc6e7d4420 "@E}n\374\177", len = -1597607023}, headers = { s = 0x55fba0c2fc10 <_start> "1\355I\211\321^H\211\342H\203\344\360PTL\215\005ZaE", len = 0}, port_no = 0, proto = 0, type = ERROR_URI_T, flags = 0, transport = {s = 0x7ffc6e7d4940 "\340J}n\374\177", len = 294245632}, ttl = {s = 0x7f3a10d27680 "\370\001", len = 1853703264}, user_param = {s = 0x0, len = 294245632}, maddr = {s = 0x7f3a10d21f18 "\340\001", len = 1853704992}, method = {s = 0x0, len = 1853707936}, lr = {s = 0x0, len = 0}, r2 = {s = 0x0, len = 0}, gr = {s = 0x30 <error: Cannot access memory at address 0x30>, len = -1506368512}, transport_val = {s = 0x7ffc6e7d43f0 " D}n\374\177", len = 266269062}, ttl_val = { s = 0x55fb00000000 <error: Cannot access memory at address 0x55fb00000000>, len = 294245632}, user_param_val = {s = 0x55fba10c3df8 <__func__.25> "rval_new_empty", len = -1593034239}, maddr_val = { s = 0x55fba122c42e <buf+430> "8e46bdec-8fb1-4814-b516-575f5cd3315c\r\nCall-ID: 19C4ED5E658858CF(a)ab.bc.cd.da\r\nCSeq: 9 ACK\r\nUser-Agent: AVM FRITZ!Box 7590 (UI) 154.07.59 (May 8 2024)\r\nContent-Length: 0\r\n\r\n", len = 36}, method_val = {s = 0x7f3a11866718 "\026", len = 0}, lr_val = {s = 0x7f3a10d11f38 "", len = 294245632}, r2_val = {s = 0x0, len = 282140472}, gr_val = {s = 0x7ffc6e7d4510 "\200F}n\374\177", len = -1595836351}} next_hop = {user = {s = 0x55fb000005e8 <error: Cannot access memory at address 0x55fb000005e8>, len = -1506368512}, passwd = {s = 0x7f391e380230 "\002", len = 0}, host = { s = 0x55fba0c2fc10 <_start> "1\355I\211\321^H\211\342H\203\344\360PTL\215\005ZaE", len = 0}, port = {s = 0x0, len = -1506368512}, params = {s = 0x7ffc6e7d4420 "@E}n\374\177", len = 0}, sip_params = { s = 0x55fba0c2fc10 <_start> "1\355I\211\321^H\211\342H\203\344\360PTL\215\005ZaE", len = 0}, headers = {s = 0x0, len = 0}, port_no = 17728, proto = 28285, type = 32764, flags = (URI_USER_NORMALIZE | URI_SIP_USER_PHONE | unknown: 0xa0c67afc), transport = {s = 0x0, len = 294245632}, ttl = {s = 0x7f3a10d27680 "\370\001", len = 1853708432}, user_param = {s = 0x7f3a10d25078 "\354\001", len = 0}, maddr = {s = 0x0, len = -1}, method = {s = 0x100000000 <error: Cannot access memory at address 0x100000000>, len = 1111717214}, lr = {s = 0x55fba0c2fc10 <_start> "1\355I\211\321^H\211\342H\203\344\360PTL\215\005ZaE", len = 0}, r2 = {s = 0x0, len = 0}, gr = {s = 0x5d8f76024f23755e <error: Cannot access memory at address 0x5d8f76024f23755e>, len = 337605982}, 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 = 0x55fba0c2fc10 <_start> "1\355I\211\321^H\211\342H\203\344\360PTL\215\005ZaE", len = 0}, lr_val = {s = 0x0, len = 0}, r2_val = { s = 0x7ffc6e7d4680 "\360G}n\374\177", len = -1595834862}, gr_val = {s = 0x7f3a11866710 "\a", len = -1506368512}} u = 0x1400000000 port = 42550 dst_host = 0x7ffc6e7d56a0 i = 294245632 flags = 32570 avp = 0x7ffc00000046 st = {flags = 1853702832, id = 32764, name = {n = 268744002, s = {s = 0x7f3a1004b542 <w_process_maxfwd_header+982> "H\213M\310dH+\f%(", len = 293462808}, re = 0x7f3a1004b542 <w_process_maxfwd_header+982>}, avp = 0x0} sct = 0x1a636a400 sjt = 0x7f3a114fd540 rve = 0x7f3a10d8dfb8 mct = 0x7ffc6e7d41a0 rv = 0x14a0c2fc10 rv1 = 0x55fba0e17ea4 <rval_expr_eval_int+1806> c1 = {cache_type = 1853703808, val_type = 32764, c = {avp_val = {n = -1595858323, s = { s = 0x55fba0e1226d <rval_get_int+341> "\205\300\017\237\300\017\266\320H\213\205\370\376\377\377\211\020H\213\205\b\377\377\377\213@\004\203\340\371\211\302H\213\205\b\377\377\377\211P\004\351y\006", len = 0}, re = 0x55fba0e1226d <rval_get_int+341>}, pval = {rs = { s = 0x55fba0e1226d <rval_get_int+341> "\205\300\017\237\300\017\266\320H\213\205\370\376\377\377\211\020H\213\205\b\377\377\377\213@\004\203\340\371\211\302H\213\205\b\377\377\377\211P\004\351y\006", len = 0}, ri = 0, flags = 1}}, i2s = "\020\374 \373U\000\000\000\000\000\000\000\000\000\000\330w\322\020:\177"} s = {s = 0x0, len = 1} srevp = {0x7f3a1189d500, 0xe9c12ed4a636a400} 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 = NUMBER_ST, u = {number = 1, string = 0x1 <error: Cannot access memory at address 0x1>, str = {s = 0x1 <error: Cannot access memory at address 0x1>, len = 0}, data = 0x1, attr = 0x1, select = 0x1}}, {type = RVE_FREE_FIXUP_ST, u = {number = 0, string = 0x0, str = {s = 0x0, len = 13}, data = 0x0, attr = 0x0, select = 0x0}}, {type = RVE_FREE_FIXUP_ST, u = {number = 0, string = 0x0, str = {s = 0x0, len = 1}, 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" #17 0x000055fba0c67391 in run_actions (h=0x7ffc6e7d5890, a=0x7f3a10d95ce8, msg=0x7f3a1189d500) at core/action.c:1584 t = 0x7f3a10d95ce8 ret = -1 tvb = {tv_sec = 0, tv_usec = 0} tve = {tv_sec = 0, tv_usec = 0} tz = {tz_minuteswest = 1853708432, tz_dsttime = 32764} tdiff = 1853704256 __func__ = "run_actions" #18 0x000055fba0c58329 in do_action (h=0x7ffc6e7d5890, a=0x7f3a10d95e38, msg=0x7f3a1189d500) at core/action.c:1074 ret = 1 v = 0 dst = {send_sock = 0x7f3a1189d500, to = {s = {sa_family = 22672, sa_data = "}n\374\177\000\000\000\000\000\000\000\000\000"}, sin = {sin_family = 22672, sin_port = 28285, sin_addr = {s_addr = 32764}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 22672, sin6_port = 28285, sin6_flowinfo = 32764, 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 = 1853705952}, sas = {ss_family = 22672, __ss_padding = "}n\374\177", '\000' <repeats 18 times>, "\340N}n\374\177\000\000\006\202\367\240\373U", '\000' <repeats 11 times>, "\244\066\246\324.\301\351\377\377\377\377\006\000\000\000\000\000\000\000\001\000\000\000\020\374 \373U", '\000' <repeats 26 times>, "\060O}n\374\177\000\000\242lӠ\373U\000", __ss_align = 139887367046936}}, id = 282216064, send_flags = {f = 32570, blst_imask = 0}, proto = 0 '\000', proto_pad0 = -43 '\325', proto_pad1 = 4489} tmp = 0x180000000000 <error: Cannot access memory at address 0x180000000000> new_uri = 0x101f0ccbd0 <error: Cannot access memory at address 0x101f0ccbd0> end = 0x0 crt = 0x0 cmd = 0x7f391f0ccbd0 len = -1595858323 user = 22011 uri = {user = {s = 0x55fba10eec6a "core", len = 293419024}, passwd = {s = 0x55fba10eed78 <__func__.17> "create_avp", len = -1506368512}, host = {s = 0x48 <error: Cannot access memory at address 0x48>, len = 0}, port = { s = 0x55fba0c2fc10 <_start> "1\355I\211\321^H\211\342H\203\344\360PTL\215\005ZaE", len = 0}, params = {s = 0x0, len = 0}, sip_params = {s = 0x7ffc6e7d4c50 "pM}n\374\177", len = -1597607023}, headers = { s = 0x55fba0c2fc10 <_start> "1\355I\211\321^H\211\342H\203\344\360PTL\215\005ZaE", len = 0}, port_no = 0, proto = 0, type = ERROR_URI_T, flags = 0, transport = {s = 0x7ffc6e7d4c00 "@M}n\374\177", len = 294245632}, ttl = { s = 0x7f3a10d25078 "\354\001", len = 1853705360}, user_param = {s = 0x7f3a10d21f18 "\340\001", len = 1853708432}, maddr = {s = 0x7ffc6e7d4b40 "", 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 = 0x5d8f760258a3755e <error: Cannot access memory at address 0x5d8f760258a3755e>, len = 337605982}, ttl_val = {s = 0x0, len = 1853705136}, user_param_val = { s = 0x7f7ffc6e7d4c40 <error: Cannot access memory at address 0x7f7ffc6e7d4c40>, len = 282179676}, maddr_val = {s = 0x7ffc6e7d4c80 "\320L}n\374\177", len = -1594708756}, method_val = {s = 0x7f3a10d1c180 "", len = 0}, lr_val = {s = 0x7f3a10d1b85d "target_geo_number)", len = 17}, r2_val = {s = 0x8 <error: Cannot access memory at address 0x8>, len = 280805392}, gr_val = {s = 0x100000043 <error: Cannot access memory at address 0x100000043>, len = 274080724}} next_hop = {user = {s = 0x7f391f0ccc08 "\177", len = 520932376}, passwd = {s = 0x7f3a10bcc010 "\001", len = -1506368512}, host = {s = 0x7ffc6e7d4d40 "\260N}n\374\177", len = -1595858323}, port = { s = 0x14800000187 <error: Cannot access memory at address 0x14800000187>, len = -1506368512}, params = {s = 0x55fba0c2fc10 <_start> "1\355I\211\321^H\211\342H\203\344\360PTL\215\005ZaE", len = 0}, sip_params = { s = 0x55fba0c2fc10 <_start> "1\355I\211\321^H\211\342H\203\344\360PTL\215\005ZaE", len = 0}, headers = {s = 0x0, len = 0}, port_no = 19824, proto = 28285, type = 32764, flags = (URI_USER_NORMALIZE | URI_SIP_USER_PHONE | unknown: 0xa0c67afc), transport = {s = 0x55fba0c2fc10 <_start> "1\355I\211\321^H\211\342H\203\344\360PTL\215\005ZaE", len = 294245632}, ttl = {s = 0x7f3a10d25078 "\354\001", len = 1853708432}, user_param = {s = 0x7ffc6e7d4cd0 "^u\203_\002v\217]^u\037\024t\353\200\t", len = 0}, maddr = {s = 0x0, len = 1}, method = {s = 0x100000000 <error: Cannot access memory at address 0x100000000>, len = 1386444126}, lr = {s = 0x55fba0c2fc10 <_start> "1\355I\211\321^H\211\342H\203\344\360PTL\215\005ZaE", len = 0}, r2 = {s = 0x0, len = 0}, gr = { s = 0x5d8f76025f83755e <error: Cannot access memory at address 0x5d8f76025f83755e>, len = 337605982}, transport_val = {s = 0x7f3a00000000 "", len = 0}, ttl_val = {s = 0x7f3a10d1b85d "target_geo_number)", len = 17}, user_param_val = {s = 0x1a00000101 <error: Cannot access memory at address 0x1a00000101>, len = -1506368512}, maddr_val = {s = 0x10a0c2fc10 <error: Cannot access memory at address 0x10a0c2fc10>, len = 0}, method_val = { s = 0x55fba0c2fc10 <_start> "1\355I\211\321^H\211\342H\203\344\360PTL\215\005ZaE", len = 0}, lr_val = {s = 0x0, len = 0}, r2_val = {s = 0x7ffc6e7d4eb0 " P}n\374\177", len = -1595836351}, gr_val = {s = 0x7f3a10d1b810 "", len = 294245632}} u = 0x7f3a1189d500 port = 42550 dst_host = 0x0 i = 294245632 flags = 32764 avp = 0x7f3a10d21f18 st = {flags = 520932432, id = 4, name = {n = -1592832428, s = {s = 0x55fba10f4e54 "core", len = 1853705024}, re = 0x55fba10f4e54}, avp = 0xe9c12ed4a636a400} sct = 0x7f390fa08000 sjt = 0x0 rve = 0x7f3a10d277d0 mct = 0x7f391f0ccc80 rv = 0x55fba0c2fc10 <_start> rv1 = 0x7ffc6e7d4b20 c1 = {cache_type = 1853705904, val_type = 32764, c = {avp_val = {n = -1595858323, s = { s = 0x55fba0e1226d <rval_get_int+341> "\205\300\017\237\300\017\266\320H\213\205\370\376\377\377\211\020H\213\205\b\377\377\377\213@\004\203\340\371\211\302H\213\205\b\377\377\377\211P\004\351y\006", len = 282215880}, re = 0x55fba0e1226d <rval_get_int+341>}, pval = {rs = { s = 0x55fba0e1226d <rval_get_int+341> "\205\300\017\237\300\017\266\320H\213\205\370\376\377\377\211\020H\213\205\b\377\377\377\213@\004\203\340\371\211\302H\213\205\b\377\377\377\211P\004\351y\006", len = 282215880}, ri = 294245632, flags = 32570}}, i2s = "\200\301\321\020:\177\000\000\000\000\000\000\000\000\000\000\320Q\322\020:\177"} s = {s = 0x0, len = 0} srevp = {0x400014e90, 0xe9c12ed4a636a400} 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 = NUMBER_ST, u = {number = 1, string = 0x1 <error: Cannot access memory at address 0x1>, str = {s = 0x1 <error: Cannot access memory at address 0x1>, len = 0}, data = 0x1, attr = 0x1, select = 0x1}}, {type = RVE_FREE_FIXUP_ST, u = {number = 0, string = 0x0, str = {s = 0x0, len = 13}, data = 0x0, attr = 0x0, select = 0x0}}, {type = RVE_FREE_FIXUP_ST, u = {number = 0, string = 0x0, str = {s = 0x0, len = 1}, 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" #19 0x000055fba0c67391 in run_actions (h=0x7ffc6e7d5890, a=0x7f3a10d27448, msg=0x7f3a1189d500) at core/action.c:1584 t = 0x7f3a10d95e38 ret = 1 tvb = {tv_sec = 0, tv_usec = 0} tve = {tv_sec = 0, tv_usec = 0} tz = {tz_minuteswest = 1853708432, tz_dsttime = 32764} tdiff = 1853706352 __func__ = "run_actions" #20 0x000055fba0c582d3 in do_action (h=0x7ffc6e7d5890, a=0x7f3a10d9a5d0, msg=0x7f3a1189d500) at core/action.c:1070 ret = 1 v = 1 dst = {send_sock = 0x0, to = {s = {sa_family = 41984, sa_data = "6\246\324.\301\351\000W}n\374\177\000"}, sin = {sin_family = 41984, sin_port = 42550, sin_addr = {s_addr = 3921751764}, sin_zero = "\000W}n\374\177\000"}, sin6 = {sin6_family = 41984, sin6_port = 42550, sin6_flowinfo = 3921751764, sin6_addr = {__in6_u = {__u6_addr8 = "\000W}n\374\177\000\000\000\000\000\000\001\000\000", __u6_addr16 = {22272, 28285, 32764, 0, 0, 0, 1, 0}, __u6_addr32 = {1853708032, 32764, 0, 1}}}, sin6_scope_id = 2697133072}, sas = {ss_family = 41984, __ss_padding = "6\246\324.\301\351\000W}n\374\177\000\000\000\000\000\000\001\000\000\000\020\374 \373U\000\000\000\000\000\000\000\000\000\000\b\000\000\000\000\000\000\000\000Չ\021:\177\000\000\000W}n\374\177\000\000\234\236\371\240\373U\000\000\270\266\017\241\373U\000\000`cn\021:\177\000\000\335\304\"\241\373U\000\000\204\304\"\241\373U\000\000`W}n\374\177\000\000\213\304\"\241\373U\000", __ss_align = 0}}, id = -1591556899, send_flags = { f = 22011, blst_imask = 0}, proto = -122 '\206', proto_pad0 = -60 '\304', proto_pad1 = -24286} tmp = 0x5a10f4e54 <error: Cannot access memory at address 0x5a10f4e54> new_uri = 0x7f3a10721b45 "tm: t_reply.c" end = 0x7f3a11629608 "SIP/2.0 181 Call Is Being Forwarded\r\nVia: SIP/2.0/UDP 212.227.124.146;branch=z9hG4bK5233.276159011cb03ac27a88b9214d0464e1.0\r\nVia: SIP/2.0/UDP 89.246.251.196:5060;branch=z9hG4bKobcj3a20101lnev2u0f0.1\r\n"... crt = 0x7f3a116283e0 "8\a" cmd = 0x55fba123c400 <_xavu_list_head> len = 270422824 user = 32570 uri = {user = {s = 0x7ffc6e7d52d0 "0S}n\374\177", len = -1592832423}, passwd = {s = 0x12c00000187 <error: Cannot access memory at address 0x12c00000187>, len = -1594483904}, host = {s = 0x7ffc6e7d52f0 "", len = 280805392}, port = {s = 0x30 <error: Cannot access memory at address 0x30>, len = 280805392}, params = {s = 0x7ffc6e7d5330 "`S}n\374\177", len = 274080724}, sip_params = { s = 0x400a15238 <error: Cannot access memory at address 0x400a15238>, len = 0}, headers = {s = 0x2000000 <error: Cannot access memory at address 0x2000000>, len = 20331672}, port_no = 22264, proto = 161, type = ERROR_URI_T, flags = (unknown: 0xc9c368), transport = {s = 0xdbbe10 <error: Cannot access memory at address 0xdbbe10>, len = 8}, ttl = {s = 0x130 <error: Cannot access memory at address 0x130>, len = -1506368512}, user_param = {s = 0x7ffc6e7d5360 "`T}n\374\177", len = -1597109357}, maddr = {s = 0x0, len = -1592832428}, method = {s = 0x7ffc6e7d5460 "\300U}n\374\177", len = 0}, lr = {s = 0x7ffc6e7d5460 "\300U}n\374\177", len = -1594524464}, r2 = {s = 0x55fba110b760 <__func__.3> "parse_via", len = -1592832423}, gr = {s = 0x55fba10fddaf "core", len = -1594483904}, transport_val = {s = 0x55fba10fdda0 <__func__.3> "parse_to_param", len = -1592794504}, ttl_val = {s = 0x30 <error: Cannot access memory at address 0x30>, len = 280805392}, user_param_val = {s = 0x7ffc6e7d5410 "@T}n\374\177", len = 274080724}, maddr_val = { s = 0x100000001 <error: Cannot access memory at address 0x100000001>, len = 0}, method_val = {s = 0x7f3a10bcc010 "\001", len = 292437752}, lr_val = {s = 0x400a15450 <error: Cannot access memory at address 0x400a15450>, len = -1592742288}, r2_val = {s = 0xdbbe10 <error: Cannot access memory at address 0xdbbe10>, len = -1506368512}, gr_val = {s = 0x7ffc6e7d5540 "\207\001", len = -1593999801}} next_hop = {user = {s = 0x7ffc6e7d5440 "\020\374 \004", len = -1597109357}, passwd = {s = 0x0, len = -1506368512}, host = {s = 0x7ffc6e7d5540 "\207\001", len = 0}, port = { s = 0x4a0c2fc10 <error: Cannot access memory at address 0x4a0c2fc10>, len = -1592795729}, params = {s = 0x0, len = -1506368512}, sip_params = {s = 0x7ffc6e7d55c0 "-\001", len = -1594334232}, headers = { s = 0x55fba110b760 <__func__.3> "parse_via", len = -1592736384}, port_no = 64, proto = 0, type = ERROR_URI_T, flags = (unknown: 0x6e7d5608), transport = {s = 0x2000000 <error: Cannot access memory at address 0x2000000>, len = 291681256}, ttl = {s = 0x55fba122c4dd <buf+605> "", len = -1591557079}, user_param = {s = 0xd10bcc010 <error: Cannot access memory at address 0xd10bcc010>, len = 29}, maddr = { s = 0x13a <error: Cannot access memory at address 0x13a>, len = -1506368512}, method = {s = 0x7ffc6e7d5500 "", len = -1597109357}, lr = {s = 0x0, len = -1592832428}, r2 = {s = 0x7ffc6e7d5600 "\020\374 \373U", len = 0}, gr = {s = 0x7ffc6e7d5600 "\020\374 \373U", len = 1853707636}, transport_val = {s = 0x400000001 <error: Cannot access memory at address 0x400000001>, len = -1591557245}, ttl_val = { s = 0x4a0c2fc10 <error: Cannot access memory at address 0x4a0c2fc10>, len = 292437808}, user_param_val = {s = 0x0, len = -1592832423}, maddr_val = {s = 0x8900000187 <error: Cannot access memory at address 0x8900000187>, len = -1594483904}, method_val = {s = 0x7ffc6e7d5590 "", len = 280805392}, lr_val = {s = 0x30 <error: Cannot access memory at address 0x30>, len = 280805392}, r2_val = {s = 0x7ffc6e7d55d0 "", len = -1594175840}, gr_val = { s = 0x7f3a116e6388 "\004", len = 292447096}} u = 0x7f3a00000000 port = 0 dst_host = 0x7f3a10bcc010 i = 520577136 flags = 32764 avp = 0x7ffc6e7d52d0 st = {flags = 294245632, id = 1, name = {n = 520577432, s = {s = 0x7f391f076198 "\001", len = 1853706896}, re = 0x7f391f076198}, avp = 0x7f3a1068f69d <futex_release+29>} sct = 0x87ea636a400 sjt = 0x7f3a107244f0 <__func__.7> rve = 0x7f3a10d251c8 mct = 0x7f3a10720a2b rv = 0x0 rv1 = 0x55fba0f5a0a5 <qm_free+8092> c1 = {cache_type = 10573800, val_type = RV_NONE, c = {avp_val = {n = 13223000, s = {s = 0xc9c458 <error: Cannot access memory at address 0xc9c458>, len = 14401040}, re = 0xc9c458}, pval = {rs = { s = 0xc9c458 <error: Cannot access memory at address 0xc9c458>, len = 14401040}, ri = 8, flags = 0}}, i2s = "-\001\000\000\000\000\000\000\000\244\066\246\324.\301\351\000V}n\374\177"} s = {s = 0x0, len = -1506368512} srevp = {0x2000000, 0x1363ba8} 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 = NUMBER_ST, u = {number = 1, string = 0x1 <error: Cannot access memory at address 0x1>, str = {s = 0x1 <error: Cannot access memory at address 0x1>, len = 0}, data = 0x1, attr = 0x1, select = 0x1}}, {type = RVE_FREE_FIXUP_ST, u = {number = 0, string = 0x0, str = {s = 0x0, len = 13}, data = 0x0, attr = 0x0, select = 0x0}}, {type = RVE_FREE_FIXUP_ST, u = {number = 0, string = 0x0, str = {s = 0x0, len = 1}, 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" #21 0x000055fba0c67391 in run_actions (h=0x7ffc6e7d5890, a=0x7f3a10d103d8, msg=0x7f3a1189d500) at core/action.c:1584 t = 0x7f3a10d9a5d0 ret = 1 tvb = {tv_sec = 0, tv_usec = 0} tve = {tv_sec = 0, tv_usec = 0} tz = {tz_minuteswest = 294245632, tz_dsttime = 32570} tdiff = 0 __func__ = "run_actions" #22 0x000055fba0c67c0b in run_top_route (a=0x7f3a10d103d8, msg=0x7f3a1189d500, c=0x0) at core/action.c:1669 ctx = {rec_lev = 4, run_flags = 0, last_retcode = 1, jmp_env = {{__jmpbuf = {4294967296, 6741736920216466782, 94539222285328, 0, 0, 0, 6741736919895602526, 684806027146655070}, __mask_was_saved = 0, __saved_mask = {__val = {0, 94539222285328, 0, 0, 0, 140722162194768, 94539222747906, 140722162194768, 139887376539184, 0, 16843795572198908928, 4294967296, 4294967296, 94539222285328, 0, 0}}}}} p = 0x7ffc6e7d5890 ret = 0 sfbk = 0 #23 0x000055fba0dc51b2 in receive_msg ( buf=0x55fba122c280 <buf> "ACK sip:49xxxxxxxxxx@sip.proxy.de:5060 SIP/2.0\r\nMax-Forwards: 19\r\nRecord-Route: <sip:aa.bb.cc.dd;lr=on;ftag=2041847FA948DA9D>\r\nVia: SIP/2.0/UDP aa.bb.cc.dd;branch=z9hG4bKebee.750c2ac00"..., len=605, rcv_info=0x7ffc6e7d5d60) at core/receive.c:515 msg = 0x7f3a1189d500 ctx = {rec_lev = 0, run_flags = 0, last_retcode = 1, jmp_env = {{__jmpbuf = {4294967296, 6741736920216466782, 94539222285328, 0, 0, 0, 6741736919895602526, 684806027146655070}, __mask_was_saved = 0, __saved_mask = {__val = { 139887403032960, 76, 94539225362399, 139887379090320, 139887379090320, 139887365636112, 294259544, 6148676624, 139883052278512, 140722162195472, 16843795572198908928, 0, 0, 94539222285328, 0, 0}}}}} bctx = 0x0 ret = 0 tvb = {tv_sec = 0, tv_usec = 0} tve = {tv_sec = 0, tv_usec = 0} diff = 0 inb = { s = 0x55fba122c280 <buf> "ACK sip:49xxxxxxxxxx@sip.proxy.de:5060 SIP/2.0\r\nMax-Forwards: 19\r\nRecord-Route: <sip:aa.bb.cc.dd;lr=on;ftag=2041847FA948DA9D>\r\nVia: SIP/2.0/UDP aa.bb.cc.dd;branch=z9hG4bKebee.750c2ac00"..., len = 605} netinfo = {data = {s = 0x0, len = 0}, bufsize = 0, rcv = 0x0, dst = 0x0} keng = 0x0 evp = {data = 0x7ffc6e7d5a80, obuf = {s = 0x0, len = 0}, rcv = 0x7ffc6e7d5d60, dst = 0x0, req = 0x0, rpl = 0x0, rplcode = 0, mode = 0} cidlockidx = 0 cidlockset = 0 errsipmsg = 0 exectime = 0 __func__ = "receive_msg" #24 0x000055fba0f28a26 in udp_rcv_loop () at core/udp_server.c:544 len = 605 buf = "ACK sip:49xxxxxxxxxx@sip.proxy.de:5060 SIP/2.0\r\nMax-Forwards: 19\r\nRecord-Route: <sip:aa.bb.cc.dd;lr=on;ftag=2041847FA948DA9D>\r\nVia: SIP/2.0/UDP aa.bb.cc.dd;branch=z9hG4bKebee.750c2ac00"... tmp = 0x55fba11871a0 <buff> "aa.bb.cc.dd" fromaddr = 0x7f3a118a0b90 fromaddrlen = 16 rcvi = {src_ip = {af = 2, len = 4, u = {addrl = {2189222868, 0}, addr32 = {2189222868, 0, 0, 0}, addr16 = {58324, 33404, 0, 0, 0, 0, 0, 0}, addr = "\324\343|\202", '\000' <repeats 11 times>}}, dst_ip = {af = 2, len = 4, u = { addrl = {3809666004, 0}, addr32 = {3809666004, 0, 0, 0}, addr16 = {58324, 58130, 0, 0, 0, 0, 0, 0}, addr = "\324\343\022\343", '\000' <repeats 11 times>}}, src_port = 5060, dst_port = 5060, proto_reserved1 = 0, proto_reserved2 = 0, src_su = {s = {sa_family = 2, sa_data = "\023\304\324\343|\202\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 50195, sin_addr = {s_addr = 2189222868}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, sin6_port = 50195, sin6_flowinfo = 2189222868, 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\304\324\343|\202", '\000' <repeats 111 times>, __ss_align = 0}}, bind_address = 0x7f3a11892470, 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 = " \b%\241<\000\000\000\030\204\310\020:\177\000\000\210\347p6\000\000\000\000\001\000\000\000 \000\000\000\000\376$\241\373U\000\000x\a%\241\373U\000\000\205\337X\341r\177\017Z\000\244\066\246\324.\301\351\240^}n\374\177\000\000\234\036\001\241\373U\000\000\200\a%\241\373U\000\000\200\b%\241\373U\000\000\300^}n\374\177\000\000\000\244\066\246\324.\301\351\300^}n\374\177\000\000\300\032\337\033\071\177\000\000\020\374 \373U", '\000' <repeats 26 times>, "\200_}n\374\177\000\000\315\336\347\240\373U\000\000 _}n\374\177\000\000H'\001\241<", '\000' <repeats 11 times>, "J"... i = 0 j = 0 l = 0 __func__ = "udp_rcv_loop" #25 0x000055fba0c4109b in main_loop () at main.c:1722 i = 11 pid = 0 si = 0x7f3a11892470 si_desc = "udp receiver child=11 sock=aa.bb.cc.dd:5060\000\000\002\000\000\000I\000\000\000\000\244\066\246\324.\301\351\000\000\000\000\000\000\000\000\352\004\000\000\000\000\000\000\020\374 \373U", '\000' <repeats 26 times>, "\060b}n\374\177\000\000sOߠ\373U\000" nrprocs = 16 woneinit = 1 __func__ = "main_loop" #26 0x000055fba0c4e20c in main (argc=10, argv=0x7ffc6e7d6788) at main.c:3078 cfg_stream = 0x55fba28dc2a0 c = -1 r = 0 tmp = 0x7ffc6e7d6e51 "" tmp_len = 316488736 port = 32570 proto = 316400256 ahost = 0x0 aport = 0 options = 0x55fba1089258 ":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 = 3674059014 rfd = 4 debug_save = 0 debug_flag = 0 dont_fork_cnt = 0 n_lst = 0x0 p = 0x0 st = {st_dev = 23, st_ino = 1615, st_nlink = 2, st_mode = 16888, st_uid = 5061, st_gid = 5061, __pad0 = 0, st_rdev = 0, st_size = 40, st_blksize = 4096, st_blocks = 0, st_atim = {tv_sec = 1722351337, tv_nsec = 496334843}, st_mtim = {tv_sec = 1722351337, tv_nsec = 496334843}, st_ctim = {tv_sec = 1722351337, tv_nsec = 496334843}, __glibc_reserved = {0, 0, 0}} tbuf = '\000' <repeats 20 times>, " ", '\000' <repeats 35 times>, "\006\000\000\000\000\000\000\200", '\000' <repeats 56 times>, "\006\000\000\000\000\000\000\200", '\000' <repeats 168 times>... option_index = 12 long_options = {{name = 0x55fba108b6c6 "help", has_arg = 0, flag = 0x0, val = 104}, {name = 0x55fba108650c "version", has_arg = 0, flag = 0x0, val = 118}, {name = 0x55fba108b6cb "alias", has_arg = 1, flag = 0x0, val = 1024}, { name = 0x55fba108b6d1 "subst", has_arg = 1, flag = 0x0, val = 1025}, {name = 0x55fba108b6d7 "substdef", has_arg = 1, flag = 0x0, val = 1026}, {name = 0x55fba108b6e0 "substdefs", has_arg = 1, flag = 0x0, val = 1027}, { name = 0x55fba108b6ea "server-id", has_arg = 1, flag = 0x0, val = 1028}, {name = 0x55fba108b6f4 "loadmodule", has_arg = 1, flag = 0x0, val = 1029}, {name = 0x55fba108b6ff "modparam", has_arg = 1, flag = 0x0, val = 1030}, { name = 0x55fba108b708 "log-engine", has_arg = 1, flag = 0x0, val = 1031}, {name = 0x55fba108b713 "debug", has_arg = 1, flag = 0x0, val = 1032}, {name = 0x55fba108b719 "cfg-print", has_arg = 0, flag = 0x0, val = 1033}, { name = 0x55fba108b723 "atexit", has_arg = 1, flag = 0x0, val = 1034}, {name = 0x0, has_arg = 0, flag = 0x0, val = 0}} __func__ = "main" ``` #### Log Messages  ``` Aug 30 09:18:53 proxy-kamailio[1276]: ALERT: <core> [main.c:774]: handle_sigs(): child process 1512 exited by a signal 11 Aug 30 09:18:53 proxy-kamailio[1276]: ALERT: <core> [main.c:777]: handle_sigs(): core was generated ``` #### SIP Traffic  Full SIP trace is not available. I gathered following SIP message from core dump. ``` ACK sip:49xxxxxxxxxx@sip.proxy.de:5060 SIP/2.0 Max-Forwards: 19 Record-Route: <sip:aa.bb.cc.dd;lr=on;ftag=2041847FA948DA9D> Via: SIP/2.0/UDP aa.bb.cc.dd;branch=z9hG4bKebee.750c2ac00d1232a60e4be6125f6753a4.0 Via: SIP/2.0/UDP ab.bc.cd.da:5060;received=ab.bc.cd.da;rport=5060;branch=z9hG4bK1086835C2F91ECAC From: <sip:49xxxxxxxxxx@sip.proxy.de>;tag=2041847FA948DA9D To: <sip:49yyyyyyyyyy@sip.proxy.de>;tag=8e46bdec-8fb1-4814-b516-575f5cd3315c Call-ID: 19C4ED5E658858CF(a)ab.bc.cd.da CSeq: 9 ACK User-Agent: AVM FRITZ!Box 7590 (UI) 154.07.59 (May 8 2024) Content-Length: 0 ``` ### Possible Solutions  For the moment we have no solution except may be to remove the siptrace module and relevant config. However, we can not do that either as sip trace is required for many other reasons. ### Additional Information * **Kamailio Version** - output of `kamailio -v` ``` version: kamailio 5.6.4 (x86_64/linux) flags: USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MMAP, PKG_MALLOC, 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_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: compiled with gcc 10.2.1 ``` * **Operating System**:  ``` Linux sip-proxy 5.10.0-31-amd64 #1 SMP Debian 5.10.221-1 (2024-07-14) x86_64 GNU/Linux ``` -- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/3970 You are receiving this because you are subscribed to this thread. Message ID: <kamailio/kamailio/issues/3970(a)github.com>

4 6

[kamailio/kamailio] app_python3: removal of legacy modules (PR #3986)
by space88man 05 Nov '24

05 Nov '24

#### 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 - [ ] Small bug fix (non-breaking change which fixes an issue) - [ ] New feature (non-breaking change which adds new functionality) - [X] Breaking change (fix or feature that would change existing functionality) #### Checklist:  - [ ] PR should be backported to stable branches - [X] Tested changes locally - [ ] Related to issue #XXXX (replace XXXX with an open issue number) #### Description Long overdue clean-up of `app_python3`; remove legacy modules and rely solely on KEMI. Bring it in sync with `app_python3s`. Larger background: this is part I of a series of commits to enable free-threading builds of python to be used in kamailio. https://py-free-threading.github.io/ You can view, comment on, or merge this pull request online at: https://github.com/kamailio/kamailio/pull/3986 -- Commit Summary -- * app_python3: removal of legacy modules -- File Changes -- M src/modules/app_python3/app_python3_mod.c (14) D src/modules/app_python3/mod_Core.c (68) D src/modules/app_python3/mod_Core.h (36) D src/modules/app_python3/mod_Logger.c (266) D src/modules/app_python3/mod_Logger.h (37) D src/modules/app_python3/mod_Ranks.c (96) D src/modules/app_python3/mod_Ranks.h (35) D src/modules/app_python3/mod_Router.c (84) D src/modules/app_python3/mod_Router.h (36) M src/modules/app_python3/python_iface.c (12) -- Patch Links -- https://github.com/kamailio/kamailio/pull/3986.patch https://github.com/kamailio/kamailio/pull/3986.diff -- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/pull/3986 You are receiving this because you are subscribed to this thread. Message ID: <kamailio/kamailio/pull/3986(a)github.com>

2 20

[kamailio/kamailio] Kamailio hangs on get_profile_size method. (Issue #3947)
by schiramchetty 03 Nov '24

03 Nov '24

3 4

[kamailio/kamailio] ndb_redis: Error when receiving 'MOVED' response from redis-cluster with TLS (Issue #3894)
by uv-2722 03 Nov '24

03 Nov '24

4 10

[kamailio/kamailio] WolfSSL cipher_list (Issue #3920)
by quinnmancsym 01 Nov '24

01 Nov '24

Hi there, I am currently using the tls_wolfssl module with kamailio and was wondering why the ability to set a cipher list was disabled. From my own testing, uncommenting line 975 in tls_domain.c/ksr_tls_fix_domain adds the functionality and we haven't seen any issues with this so far. Was there an issue with this when the module was first created? Should I be avoiding using this functionality? Thanks very much. -- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/3920 You are receiving this because you are subscribed to this thread. Message ID: <kamailio/kamailio/issues/3920(a)github.com>

5 6

← Newer
1
2
3
4
5
6
7
...
12
Older →

2025

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009

2008

sr-dev October 2024