sr-dev February 2024

sr-dev@lists.kamailio.org

19 participants
234 discussions

[kamailio/kamailio] extented haproxy protocol support (PR #3731)

by sergey-safarov

#### 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) - [x] New feature (non-breaking change which adds new functionality) - [ ] Breaking change (fix or feature that would change existing functionality) #### Checklist: - [ ] PR should be backported to stable branches - [x] Tested changes locally - [x] Related to issue #3667 #### Description Allow creating Record-Route and Via header using destination address and port in the haproxy protocol header. PR created behalf @ivanuschak You can view, comment on, or merge this pull request online at: https://github.com/kamailio/kamailio/pull/3731 -- Commit Summary -- * core: extented haproxy protocol parser * rr: extented haproxy protocol suppport * path: extented haproxy protocol suppport * websocket: extented haproxy protocol suppport * siptrace: extented haproxy protocol suppport -- File Changes -- M src/core/forward.h (4) M src/core/msg_translator.c (137) M src/core/parser/msg_parser.h (1) M src/core/receive.c (6) M src/core/receive.h (3) M src/core/tcp_conn.h (1) M src/core/tcp_main.c (22) M src/core/tcp_read.c (20) M src/modules/path/path.c (2) M src/modules/rr/loose.c (4) M src/modules/rr/record.c (6) M src/modules/siptrace/siptrace.c (89) M src/modules/websocket/ws_frame.c (9) M src/modules/websocket/ws_handshake.c (3) -- Patch Links -- https://github.com/kamailio/kamailio/pull/3731.patch https://github.com/kamailio/kamailio/pull/3731.diff -- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/pull/3731 You are receiving this because you are subscribed to this thread. Message ID: <kamailio/kamailio/pull/3731(a)github.com>

3 days, 11 hours

[kamailio/kamailio] uac_req_send crash Kamailio (Issue #3522)

by suharik71

### Description  Hello. I use uac_req_send to send registration to the asterisk pool. If some asterisk did not authorize and re-sent the 401 code, the module causes a kamailio crash ### Troubleshooting ds_select("BACKENDS","0"); while(ds_set_dst()) { xlog("L_DBG",">>> BACKEND du=$du\n"); $uac_req(ruri)="sip:" + $(du{uri.host}); $uac_req(furi)="sip:" + $avp(username) + "@" + $(du{uri.host}); $uac_req(turi)=$uac_req(furi); uac_req_send(); ds_next_dst(); } #### Reproduction  #### Debugging Data  ``` [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1". Core was generated by `/usr/sbin/kamailio -P /run/kamailio/kamailio.pid -f /etc/kamailio/kamailio.cfg'. Program terminated with signal SIGSEGV, Segmentation fault. #0 0x00005557272803b9 in timer_list_expire (t=1180105352, h=0x7f73b30a3bb8, slow_l=0x7f73b30a73a0, slow_mark=2907) at core/timer.c:846 846 core/timer.c: No such file or directory. (gdb) bt full #0 0x00005557272803b9 in timer_list_expire (t=1180105352, h=0x7f73b30a3bb8, slow_l=0x7f73b30a73a0, slow_mark=2907) at core/timer.c:846 tl = 0x7f73b3a49a88 ret = 0 #1 0x00005557272809cf in timer_handler () at core/timer.c:922 saved_ticks = 1180105352 run_slow_timer = 0 i = 859 __func__ = "timer_handler" #2 0x0000555727280f53 in timer_main () at core/timer.c:961 No locals. #3 0x0000555726f77736 in main_loop () at /build/kamailio-5.6.4+ubuntu22.04/src/main.c:1831 i = 6 pid = 0 si = 0x0 si_desc = "udp receiver child=5 sock=10.153.5.40:5060\000\000\020\000\000\000\003\000\000\000!\000\000\000\000\262\270\224RE&\035(\247K'WU\000\000WqA'WU\000\000\000\000\000\000\000\000\000\000c\367@'WU\000\000!\000\000\000\000\000\000\000\260\325\022\371s\177\000\000 \236.\220\375\177\000\000ݕ\024'WU\000" nrprocs = 6 woneinit = 1 __func__ = "main_loop" #4 0x0000555726f83d11 in main (argc=12, argv=0x7ffd902ea398) at /build/kamailio-5.6.4+ubuntu22.04/src/main.c:3078 cfg_stream = 0x555727e12380 c = -1 r = 0 tmp = 0x7ffd902ebe36 "" tmp_len = 0 port = 0 proto = 0 ahost = 0x0 aport = 0 options = 0x55572744e898 ":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 = 4270110361 rfd = 4 debug_save = 0 debug_flag = 0 dont_fork_cnt = 0 n_lst = 0x7ffd902ea398 p = 0x7ffd902ea310 "" st = {st_dev = 25, st_ino = 5514, st_nlink = 2, st_mode = 16888, st_uid = 0, st_gid = 0, __pad0 = 0, st_rdev = 0, st_size = 40, st_blksize = 4096, st_blocks = 0, st_atim = {tv_sec = 1690276408, tv_nsec = 971865637}, st_mtim = {tv_sec = 1690276408, tv_nsec = 971865637}, st_ctim = {tv_sec = 1690276408, tv_nsec = 971865637}, __glibc_reserved = {0, 0, 0}} tbuf = '\000' <repeats 80 times>, "\377\000\000\000\377\000\000\000\000\377\000\000\000\000\000\000", '/' <repeats 16 times>, "\230\r", '\000' <repeats 14 times>, "`", '\000' <repeats 15 times>, "\001", '\000' <repeats 144 times>... option_index = 12 long_options = {{name = 0x55572740a2e9 "help", has_arg = 0, flag = 0x0, val = 104}, {name = 0x55572740b84a "version", has_arg = 0, flag = 0x0, val = 118}, {name = 0x55572740f6e4 "alias", has_arg = 1, flag = 0x0, val = 1024}, {name = 0x55572740a2ee "subst", has_arg = 1, flag = 0x0, val = 1025}, {name = 0x55572740a2f4 "substdef", has_arg = 1, flag = 0x0, val = 1026}, {name = 0x55572740a2fd "substdefs", has_arg = 1, flag = 0x0, val = 1027}, {name = 0x55572740a307 "server-id", has_arg = 1, flag = 0x0, val = 1028}, {name = 0x55572740a311 "loadmodule", has_arg = 1, flag = 0x0, val = 1029}, {name = 0x55572740a31c "modparam", has_arg = 1, flag = 0x0, val = 1030}, {name = 0x55572740a325 "log-engine", has_arg = 1, flag = 0x0, val = 1031}, {name = 0x55572740b967 "debug", has_arg = 1, flag = 0x0, val = 1032}, {name = 0x55572740a330 "cfg-print", has_arg = 0, flag = 0x0, val = 1033}, {name = 0x55572740a33a "atexit", has_arg = 1, flag = 0x0, val = 1034}, {name = 0x0, has_arg = 0, flag = 0x0, val = 0}} __func__ = "main" (gdb) info locals tl = 0x7f73b3a49a88 ret = 0 (gdb) list 841 in core/timer.c (gdb) ``` ``` [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1". Core was generated by `/usr/sbin/kamailio -P /run/kamailio/kamailio.pid -f /etc/kamailio/kamailio.cfg'. Program terminated with signal SIGSEGV, Segmentation fault. #0 0x00007f73f575d4d0 in free_hash_table () at /build/kamailio-5.6.4+ubuntu22.04/src/modules/tm/h_table.c:464 464 /build/kamailio-5.6.4+ubuntu22.04/src/modules/tm/h_table.c: No such file or directory. (gdb) bt full #0 0x00007f73f575d4d0 in free_hash_table () at /build/kamailio-5.6.4+ubuntu22.04/src/modules/tm/h_table.c:464 p_cell = 0x0 tmp_cell = 0x0 i = 64459 __func__ = "free_hash_table" #1 0x00007f73f5793e46 in tm_shutdown () at /build/kamailio-5.6.4+ubuntu22.04/src/modules/tm/t_funcs.c:88 __func__ = "tm_shutdown" #2 0x00005557271db17b in destroy_modules () at core/sr_module.c:842 t = 0x7f73f68a65a0 foo = 0x7f73f68a59e0 __func__ = "destroy_modules" #3 0x0000555726f64029 in cleanup (show_status=1) at /build/kamailio-5.6.4+ubuntu22.04/src/main.c:561 memlog = 0 __func__ = "cleanup" #4 0x0000555726f66044 in shutdown_children (sig=15, show_status=1) at /build/kamailio-5.6.4+ubuntu22.04/src/main.c:704 __func__ = "shutdown_children" #5 0x0000555726f697dc in handle_sigs () at /build/kamailio-5.6.4+ubuntu22.04/src/main.c:802 chld = 0 chld_status = 139 any_chld_stopped = 1 memlog = 0 __func__ = "handle_sigs" #6 0x0000555726f78f42 in main_loop () at /build/kamailio-5.6.4+ubuntu22.04/src/main.c:1900 i = 6 pid = 37846 si = 0x0 si_desc = "udp receiver child=5 sock=10.153.5.40:5060\000\000\020\000\000\000\003\000\000\000!\000\000\000\000\262\270\224RE&\035(\247K'WU\000\000WqA'WU\000\000\000\000\000\000\000\000\000\000c\367@'WU\000\000!\000\000\000\000\000\000\000\260\325\022\371s\177\000\000 \236.\220\375\177\000\000ݕ\024'WU\000" nrprocs = 6 woneinit = 1 __func__ = "main_loop" #7 0x0000555726f83d11 in main (argc=12, argv=0x7ffd902ea398) at /build/kamailio-5.6.4+ubuntu22.04/src/main.c:3078 cfg_stream = 0x555727e12380 c = -1 r = 0 tmp = 0x7ffd902ebe36 "" tmp_len = 0 port = 0 proto = 0 ahost = 0x0 aport = 0 options = 0x55572744e898 ":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 = 4270110361 rfd = 4 debug_save = 0 debug_flag = 0 dont_fork_cnt = 0 n_lst = 0x7ffd902ea398 p = 0x7ffd902ea310 "" st = {st_dev = 25, st_ino = 5514, st_nlink = 2, st_mode = 16888, st_uid = 0, st_gid = 0, __pad0 = 0, st_rdev = 0, st_size = 40, st_blksize = 4096, st_blocks = 0, st_atim = {tv_sec = 1690276408, tv_nsec = 971865637}, st_mtim = {tv_sec = 1690276408, tv_nsec = 971865637}, st_ctim = {tv_sec = 1690276408, tv_nsec = 971865637}, __glibc_reserved = {0, 0, 0}} tbuf = '\000' <repeats 80 times>, "\377\000\000\000\377\000\000\000\000\377\000\000\000\000\000\000", '/' <repeats 16 times>, "\230\r", '\000' <repeats 14 times>, "`", '\000' <repeats 15 times>, "\001", '\000' <repeats 144 times>... option_index = 12 long_options = {{name = 0x55572740a2e9 "help", has_arg = 0, flag = 0x0, val = 104}, {name = 0x55572740b84a "version", has_arg = 0, flag = 0x0, val = 118}, {name = 0x55572740f6e4 "alias", has_arg = 1, flag = 0x0, val = 1024}, {name = 0x55572740a2ee "subst", has_arg = 1, flag = 0x0, val = 1025}, {name = 0x55572740a2f4 "substdef", has_arg = 1, flag = 0x0, val = 1026}, {name = 0x55572740a2fd "substdefs", has_arg = 1, flag = 0x0, val = 1027}, {name = 0x55572740a307 "server-id", has_arg = 1, flag = 0x0, val = 1028}, {name = 0x55572740a311 "loadmodule", has_arg = 1, flag = 0x0, val = 1029}, {name = 0x55572740a31c "modparam", has_arg = 1, flag = 0x0, val = 1030}, {name = 0x55572740a325 "log-engine", has_arg = 1, flag = 0x0, val = 1031}, {name = 0x55572740b967 "debug", has_arg = 1, flag = 0x0, val = 1032}, {name = 0x55572740a330 "cfg-print", has_arg = 0, flag = 0x0, val = 1033}, {name = 0x55572740a33a "atexit", has_arg = 1, flag = 0x0, val = 1034}, {name = 0x0, has_arg = 0, flag = 0x0, val = 0}} __func__ = "main" (gdb) info locals p_cell = 0x0 tmp_cell = 0x0 i = 64459 __func__ = "free_hash_table" (gdb) list 459 in /build/kamailio-5.6.4+ubuntu22.04/src/modules/tm/h_table.c ``` #### Log Messages  ``` CRITICAL: <core> [core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed pointer (0x7f8a6c440050), called from uac: uac_send.c: uac_send_tm_callback(860), first free uac: uac_send.c: uac_send_info_clone(110) - ignoring CRITICAL: <core> [core/mem/q_malloc.c:123]: qm_debug_check_frag(): BUG: qm: fragm. 0x7f74379f46b0 (address 0x7f74379f46e8) beginning overwritten (0)! Memory allocator was called from uac: uac_send.c:860. Fragment marked by (null):0. Exec from core/mem/q_malloc.c:511. ``` #### SIP Traffic  ``` proto:UDP 2023-07-25T10:00:44.452898Z 10.153.5.40:5060 ---> 192.168.50.107:5060 REGISTER sip:192.168.50.107 SIP/2.0 Via: SIP/2.0/UDP 10.153.5.40;branch=z9hG4bK6a0b.834627a6000000000000000000000000.0 To: <sip:3408@192.168.50.107> From: <sip:3408@192.168.50.107>;tag=b2f228866a24b161d346cfb256d45132-a0527658 CSeq: 10 REGISTER Call-ID: 2332840947916a3e-39417(a)10.153.5.40 Max-Forwards: 70 Content-Length: 0 Contact: <sip:3408@10.153.5.40:5060> Expires: 150 User-Agent: PortSIP UC Client Android - v11.8.1 proto:UDP 2023-07-25T10:00:44.464436Z 192.168.50.107:5060 ---> 10.153.5.40:5060 SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.153.5.40;rport=5060;received=10.153.5.40;branch=z9hG4bK6a0b.834627a6000000000000000000000000.0 Call-ID: 2332840947916a3e-39417(a)10.153.5.40 From: <sip:3408@192.168.50.107>;tag=b2f228866a24b161d346cfb256d45132-a0527658 To: <sip:3408@192.168.50.107>;tag=z9hG4bK6a0b.834627a6000000000000000000000000.0 CSeq: 10 REGISTER WWW-Authenticate: Digest realm="vpp",nonce="1690279244/67fc12dbaf6a76fa34181a4bd504de00",opaque="1680d45809efac86",algorithm=md5,qop="auth" Server: Asterisk Content-Length: 0 proto:UDP 2023-07-25T10:00:44.466447Z 10.153.5.40:5060 ---> 192.168.50.107:5060 REGISTER sip:192.168.50.107 SIP/2.0 Via: SIP/2.0/UDP 10.153.5.40;branch=z9hG4bK7a0b.5673b4d4000000000000000000000000.0 To: <sip:3408@192.168.50.107> From: <sip:3408@192.168.50.107>;tag=b2f228866a24b161d346cfb256d45132-a0527658 CSeq: 11 REGISTER Call-ID: 2332840947916a3e-39417(a)10.153.5.40 Max-Forwards: 70 Content-Length: 0 Contact: <sip:3408@10.153.5.40:5060> Expires: 150 Authorization: Digest username="3408", realm="vpp", nonce="1690279244/67fc12dbaf6a76fa34181a4bd504de00", uri="sip:192.168.50.107", opaque="1680d45809efac86", qop=auth, nc=00000001, cnonce="1935694403", response="38bc75e831e1267ce943bcc50f76390a", algorithm=MD5 User-Agent: PortSIP UC Client Android - v11.8.1 proto:UDP 2023-07-25T10:00:44.477675Z 192.168.50.107:5060 ---> 10.153.5.40:5060 SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.153.5.40;rport=5060;received=10.153.5.40;branch=z9hG4bK7a0b.5673b4d4000000000000000000000000.0 Call-ID: 2332840947916a3e-39417(a)10.153.5.40 From: <sip:3408@192.168.50.107>;tag=b2f228866a24b161d346cfb256d45132-a0527658 To: <sip:3408@192.168.50.107>;tag=z9hG4bK7a0b.5673b4d4000000000000000000000000.0 CSeq: 11 REGISTER WWW-Authenticate: Digest realm="vpp",nonce="1690279244/67fc12dbaf6a76fa34181a4bd504de00",opaque="5adc30b867f02d18",algorithm=md5,qop="auth" Server: Asterisk Content-Length: 0 ``` ### Possible Solutions  ### 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: unknown compiled with gcc 11.3.0 ``` * **Operating System**:  ``` 5.15.0-76-generic #83-Ubuntu SMP Thu Jun 15 19:16:32 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux ``` -- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/3522 You are receiving this because you are subscribed to this thread. Message ID: <kamailio/kamailio/issues/3522(a)github.com>

1 week, 6 days

[kamailio/kamailio] User-params parsing fails in multiple ways (Issue #3762)

by Alex Hermann

2 weeks, 5 days

[kamailio/kamailio] tm: memory leak in case dropping messages in local-request event route (PR #3403)

by Simon Darienko

#### 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 - [ ] Related to issue #XXXX (replace XXXX with an open issue number) #### Description I faced an issue with memory leak in case drop NOTIFY messages in the "local-request" event route in `mem_copy_subs` and `build_uac_req` analysis of mem leak: kamcmd corex.shm_summary <code>... Mar 23 12:00:28 pbx kamailio[72308]: NOTICE: fm_status: fm_sums(): count= 11 size= 7520 bytes from presence: hash.c: mem_copy_subs(141)<br> Mar 23 12:00:28 pbx kamailio[72308]: NOTICE: fm_status: fm_sums(): count= 23 size= 22536 bytes from tm: t_msgbuilder.c: build_uac_req(1618) ...</code> a lot of dropped messages in local-request event route <code>... Mar 23 12:01:09 pbx kamailio[72308]: NOTICE: fm_status: fm_sums(): count= 83 size= 51256 bytes from presence: hash.c: mem_copy_subs(141) Mar 23 12:01:09 pbx kamailio[72308]: NOTICE: fm_status: fm_sums(): count= 98 size= 116864 bytes from tm: t_msgbuilder.c: build_uac_req(1618) ...</code> no messages, no activities <code>... Mar 23 12:02:34 pbx kamailio[72308]: NOTICE: fm_status: fm_sums(): count= 83 size= 51256 bytes from presence: hash.c: mem_copy_subs(141) Mar 23 12:02:34 pbx kamailio[72308]: NOTICE: fm_status: fm_sums(): count= 96 size= 115432 bytes from tm: t_msgbuilder.c: build_uac_req(1618) ...</code> In the code, we have a comment like "never free cbp here because if t_uac_prepare fails, cbp is not freed and thus caller has no chance to discover if it is freed or not", but we'll free the cbp in two cases: 1. in case of error, but we have if (ret == E_DROP) then ret = 0; (so, no error result) 2. in case call insert_tmcb for cbp, but we don't do it for E_DROP You can view, comment on, or merge this pull request online at: https://github.com/kamailio/kamailio/pull/3403 -- Commit Summary -- * tm: memory leak in case dropping messages in local-request event route -- File Changes -- M src/modules/tm/uac.c (8) -- Patch Links -- https://github.com/kamailio/kamailio/pull/3403.patch https://github.com/kamailio/kamailio/pull/3403.diff -- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/pull/3403 You are receiving this because you are subscribed to this thread. Message ID: <kamailio/kamailio/pull/3403(a)github.com>

2 weeks, 5 days

[kamailio/kamailio] registrar: adding contact and UA to xavp_cfg (Issue #3753)

by nirvanr-nextiva

### Description We are using Kamailio as a 'mid-registrar', and saving the location record (i.e calling registrar.save()) in the reply-route depending on received status code from other registrar. We noticed the saved location record had the contact URI (incl. instance id) and UA from response message; instead we would like to use the contact and UA from the original request. This feature change is similar to what was added for `tcpconn_id` in PR: https://github.com/kamailio/kamailio/pull/3430. i.e. we would set the request's contact URI and UA in `xavp_cfg` variable. Then `registrar.save.c` would use the contact and UA from `xavp_cfg`. Thanks. -- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/3753 You are receiving this because you are subscribed to this thread. Message ID: <kamailio/kamailio/issues/3753(a)github.com>

2 weeks, 6 days

[kamailio/kamailio] ndb_reids module in event_route[tcp:closed] route block error: "no redis context for server" (Issue #3768)

by liangbaolin

### Description The process of using kamailio prompts the following error： ERROR: ndb_redis [redis_client.c:963]: redisc_exec(): no redis context for server: srvN I did not encounter similar errors in version 5.4.8, and there were no similar errors in other routing blocks. Suspect that the new core version has unknown logical issues with the routing block of the module in event_route.  #### Log Messages  ``` 2024-02-26T03:39:11.161557654Z 51(97) DEBUG: <core> [core/tcp_read.c:280]: tcp_read_data(): EOF on connection 0x7f24539006a0 (state: 0, flags: c018) - FD 24, bytes 0, rd-flags 10000 ([12.0.1.6]:22827 -> [12.0.1.6]:5060)51(97) DEBUG: <core> [core/tcp_read.c:343]: tcp_read(): read 0 bytes: 2024-02-26T03:39:11.161563494Z 2024-02-26T03:39:11.161567864Z 51(97) DEBUG: <core> [core/tcp_read.c:1532]: tcp_read_req(): read= 0 bytes, parsed=0, state=0, error=1 2024-02-26T03:39:11.161574144Z 51(97) DEBUG: <core> [core/tcp_read.c:1534]: tcp_read_req(): last char=0x00, parsed msg= 2024-02-26T03:39:11.161579134Z 2024-02-26T03:39:11.161584594Z 51(97) DEBUG: <core> [core/tcp_read.c:1544]: tcp_read_req(): EOF 2024-02-26T03:39:11.161598914Z 51(97) DEBUG: <core> [core/io_wait.h:598]: io_watch_del(): DBG: io_watch_del (0x563e1ce29740, 24, -1, 0x10) fd_no=2 called 2024-02-26T03:39:11.161604494Z 51(97) DEBUG: <core> [core/tcp_read.c:1927]: handle_io(): removing from list 0x7f24539006a0 id 1 fd 24, state 2, flags c018, main fd 132, refcnt 2 ([12.0.1.6]:22827 -> [12.0.1.6]:5060) 2024-02-26T03:39:11.161610294Z 51(97) DEBUG: <core> [core/tcp_read.c:1702]: release_tcpconn(): releasing con 0x7f24539006a0, state -1, fd=24, id=1 ([12.0.1.6]:22827 -> [12.0.1.6]:5060) 2024-02-26T03:39:11.161615934Z 51(97) DEBUG: <core> [core/tcp_read.c:1705]: release_tcpconn(): extra_data (nil) 2024-02-26T03:39:11.162263374Z 83(129) DEBUG: <core> [core/tcp_main.c:3747]: handle_tcp_child(): reader response= 7f24539006a0, -1 from 0 2024-02-26T03:39:11.162286594Z 83(129) DEBUG: <core> [core/tcp_main.c:3671]: tcp_emit_closed_event(): TCP closed event creation triggered (reason: 0) 2024-02-26T03:39:11.162293034Z 83(129) DEBUG: tcpops [tcpops.c:311]: tcpops_handle_tcp_closed(): received TCP closed event 2024-02-26T03:39:11.162299134Z 83(129) DEBUG: tcpops [tcpops.c:261]: tcpops_tcp_closed_run_route(): event reason id: 0 rt: 1 2024-02-26T03:39:11.162304234Z 83(129) ERROR: tcpops [tcpops.c:278]: tcpops_tcp_closed_run_route(): run_top_route() before tev->id: 1 2024-02-26T03:39:11.162311444Z 83(129) DEBUG: <core> [core/tcp_main.c:1713]: _tcpconn_find(): 1 port 0 2024-02-26T03:39:11.162316784Z 83(129) DEBUG: <core> [core/tcp_main.c:1721]: _tcpconn_find(): c=0x7f24539006a0, c->id=1, port=22827 2024-02-26T03:39:11.162322944Z 83(129) DEBUG: <core> [core/ip_addr.c:577]: print_ip(): ip=12.0.1.6 2024-02-26T03:39:11.162328584Z 83(129) DEBUG: <core> [core/tcp_main.c:1725]: _tcpconn_find(): found connection by id: 1 2024-02-26T03:39:11.162333764Z 83(129) DEBUG: <core> [core/tcp_main.c:1713]: _tcpconn_find(): 1 port 0 2024-02-26T03:39:11.162338674Z 83(129) DEBUG: <core> [core/tcp_main.c:1721]: _tcpconn_find(): c=0x7f24539006a0, c->id=1, port=22827 2024-02-26T03:39:11.162343764Z 83(129) DEBUG: <core> [core/ip_addr.c:577]: print_ip(): ip=12.0.1.6 2024-02-26T03:39:11.162349254Z 83(129) DEBUG: <core> [core/tcp_main.c:1725]: _tcpconn_find(): found connection by id: 1 2024-02-26T03:39:11.162355494Z 83(129) DEBUG: <core> [core/pvapi.c:1418]: pv_printf_mode(): final buffer length 101 2024-02-26T03:39:11.162360924Z 83(129) ERROR: <script>: tcp connection closed conid: (1), tcp(conid): 1, Ri: 12.0.1.185, Rp: 5060 , si: 12.0.1.6 , sp: 22827 2024-02-26T03:39:11.162375744Z 83(129) DEBUG: <core> [core/tcp_main.c:1713]: _tcpconn_find(): 1 port 0 2024-02-26T03:39:11.162381944Z 83(129) DEBUG: <core> [core/tcp_main.c:1721]: _tcpconn_find(): c=0x7f24539006a0, c->id=1, port=22827 2024-02-26T03:39:11.162388024Z 83(129) DEBUG: <core> [core/ip_addr.c:577]: print_ip(): ip=12.0.1.6 2024-02-26T03:39:11.162395164Z 83(129) DEBUG: <core> [core/tcp_main.c:1725]: _tcpconn_find(): found connection by id: 1 2024-02-26T03:39:11.162400884Z 83(129) DEBUG: <core> [core/tcp_main.c:1713]: _tcpconn_find(): 1 port 0 2024-02-26T03:39:11.162406634Z 83(129) DEBUG: <core> [core/tcp_main.c:1721]: _tcpconn_find(): c=0x7f24539006a0, c->id=1, port=22827 2024-02-26T03:39:11.162412284Z 83(129) DEBUG: <core> [core/ip_addr.c:577]: print_ip(): ip=12.0.1.6 2024-02-26T03:39:11.162417034Z 83(129) DEBUG: <core> [core/tcp_main.c:1725]: _tcpconn_find(): found connection by id: 1 2024-02-26T03:39:11.162422294Z 83(129) DEBUG: <core> [core/pvapi.c:1418]: pv_printf_mode(): final buffer length 27 2024-02-26T03:39:11.162427844Z 83(129) ERROR: <script>: tcp connection closed (1) 2024-02-26T03:39:11.162433574Z 83(129) DEBUG: <core> [core/tcp_main.c:1713]: _tcpconn_find(): 1 port 0 2024-02-26T03:39:11.162439254Z 83(129) DEBUG: <core> [core/tcp_main.c:1721]: _tcpconn_find(): c=0x7f24539006a0, c->id=1, port=22827 2024-02-26T03:39:11.162444184Z 83(129) DEBUG: <core> [core/ip_addr.c:577]: print_ip(): ip=12.0.1.6 2024-02-26T03:39:11.162449324Z 83(129) DEBUG: <core> [core/tcp_main.c:1725]: _tcpconn_find(): found connection by id: 1 2024-02-26T03:39:11.162454724Z 83(129) DEBUG: <core> [core/pvapi.c:1418]: pv_printf_mode(): final buffer length 1 2024-02-26T03:39:11.162460094Z 83(129) DEBUG: <core> [core/pvapi.c:1418]: pv_printf_mode(): final buffer length 52 2024-02-26T03:39:11.162466084Z 83(129) DEBUG: <core> [core/tcp_main.c:1713]: _tcpconn_find(): 1 port 0 2024-02-26T03:39:11.162471724Z 83(129) DEBUG: <core> [core/tcp_main.c:1721]: _tcpconn_find(): c=0x7f24539006a0, c->id=1, port=22827 2024-02-26T03:39:11.162477324Z 83(129) DEBUG: <core> [core/ip_addr.c:577]: print_ip(): ip=12.0.1.6 2024-02-26T03:39:11.162482144Z 83(129) DEBUG: <core> [core/tcp_main.c:1725]: _tcpconn_find(): found connection by id: 1 2024-02-26T03:39:11.162487154Z 83(129) DEBUG: <core> [core/pvapi.c:1418]: pv_printf_mode(): final buffer length 52 2024-02-26T03:39:11.162501164Z 83(129) DEBUG: ndb_redis [redis_client.c:399]: redisc_get_server(): Hash 2100282857 (srvN) 2024-02-26T03:39:11.162508124Z 83(129) DEBUG: ndb_redis [redis_client.c:402]: redisc_get_server(): Entry 2694209461 (12.0.1.9:7469), rsrv->ctxRedis = (nil) 2024-02-26T03:39:11.162514104Z 83(129) DEBUG: ndb_redis [redis_client.c:402]: redisc_get_server(): Entry 2694209462 (12.0.1.8:7469), rsrv->ctxRedis = (nil) 2024-02-26T03:39:11.162520554Z 83(129) DEBUG: ndb_redis [redis_client.c:402]: redisc_get_server(): Entry 2694209448 (12.0.1.7:7469), rsrv->ctxRedis = (nil) 2024-02-26T03:39:11.162526404Z 83(129) DEBUG: ndb_redis [redis_client.c:402]: redisc_get_server(): Entry 2694210133 (12.0.1.9:7369), rsrv->ctxRedis = (nil) 2024-02-26T03:39:11.162532034Z 83(129) DEBUG: ndb_redis [redis_client.c:402]: redisc_get_server(): Entry 2694210134 (12.0.1.8:7369), rsrv->ctxRedis = (nil) 2024-02-26T03:39:11.162537324Z 83(129) DEBUG: ndb_redis [redis_client.c:402]: redisc_get_server(): Entry 2694210120 (12.0.1.7:7369), rsrv->ctxRedis = (nil) 2024-02-26T03:39:11.162542824Z 83(129) DEBUG: ndb_redis [redis_client.c:402]: redisc_get_server(): Entry 2100282854 (srvM), rsrv->ctxRedis = (nil) 2024-02-26T03:39:11.162548064Z 83(129) DEBUG: ndb_redis [redis_client.c:402]: redisc_get_server(): Entry 2100282857 (srvN), rsrv->ctxRedis = (nil) 2024-02-26T03:39:11.162554074Z 83(129) DEBUG: ndb_redis [redis_client.c:402]: redisc_get_server(): Entry 2100306023 (srvTPS), rsrv->ctxRedis = (nil) 2024-02-26T03:39:11.162559184Z 83(129) DEBUG: ndb_redis [redis_client.c:408]: redisc_get_server(): Entry 2694209461 (12.0.1.9:7469), rsrv->ctxRedis = (nil) 2024-02-26T03:39:11.162564524Z 83(129) DEBUG: ndb_redis [redis_client.c:408]: redisc_get_server(): Entry 2694209462 (12.0.1.8:7469), rsrv->ctxRedis = (nil) 2024-02-26T03:39:11.162569904Z 83(129) DEBUG: ndb_redis [redis_client.c:408]: redisc_get_server(): Entry 2694209448 (12.0.1.7:7469), rsrv->ctxRedis = (nil) 2024-02-26T03:39:11.162575334Z 83(129) DEBUG: ndb_redis [redis_client.c:408]: redisc_get_server(): Entry 2694210133 (12.0.1.9:7369), rsrv->ctxRedis = (nil) 2024-02-26T03:39:11.162580154Z 83(129) DEBUG: ndb_redis [redis_client.c:408]: redisc_get_server(): Entry 2694210134 (12.0.1.8:7369), rsrv->ctxRedis = (nil) 2024-02-26T03:39:11.162585964Z 83(129) DEBUG: ndb_redis [redis_client.c:408]: redisc_get_server(): Entry 2694210120 (12.0.1.7:7369), rsrv->ctxRedis = (nil) 2024-02-26T03:39:11.162592294Z 83(129) DEBUG: ndb_redis [redis_client.c:408]: redisc_get_server(): Entry 2100282854 (srvM), rsrv->ctxRedis = (nil) 2024-02-26T03:39:11.162597644Z 83(129) DEBUG: ndb_redis [redis_client.c:408]: redisc_get_server(): Entry 2100282857 (srvN), rsrv->ctxRedis = (nil) 2024-02-26T03:39:11.162611324Z 83(129) DEBUG: ndb_redis [redis_client.c:413]: redisc_get_server(): Using entry 2100282857 (srvN) 2024-02-26T03:39:11.162617084Z 83(129) DEBUG: ndb_redis [redis_client.c:960]: redisc_exec(): rsrv->ctxRedis = (nil) 2024-02-26T03:39:11.162622004Z 83(129) ERROR: ndb_redis [redis_client.c:963]: redisc_exec(): no redis context for server: srvN 2024-02-26T03:39:11.162627834Z 83(129) ERROR: tcpops [tcpops.c:280]: tcpops_tcp_closed_run_route(): run_top_route() after tev->id: 1 2024-02-26T03:39:11.162633294Z 83(129) DEBUG: <core> [core/tcp_main.c:3904]: handle_tcp_child(): case CONN_EOF tcp_emit_closed_event before 5 ``` #### SIP Traffic  ``` event_route[tcp:closed] { xlog("L_ERR", "$proto connection closed conid: ($conid), tcp(conid): $tcp(conid), Ri: $Ri, Rp: $Rp , si: $si , sp: $sp\n"); if($conid ne $null) { xlog("L_ERR", "$proto connection closed ($conid)\n"); route(TCPEVENT); } } route[TCPEVENT] { if(redis_cmd("srvN", "get %s", "$conid", "r")) { ..... } } #redis module config loadmodule "ndb_redis" modparam("ndb_redis", "cluster", 1) modparam("ndb_redis", "allow_dynamic_nodes", 1) modparam("ndb_redis", "server", "name=srvN;addr=NDB_N_REDIS_CLUSTER_MAINADDR;port=NDB_N_REDIS_CLUSTER_MAINPORT;pass=NDB_REDIS_PASSWORD") modparam("ndb_redis", "server", "name=srvM;addr=NDB_M_REDIS_CLUSTER_MAINADDR;port=NDB_M_REDIS_CLUSTER_MAINPORT;pass=NDB_REDIS_PASSWORD") modparam("ndb_redis", "server", "name=12.0.1.7:7369;addr=12.0.1.7;port=7369;pass=NDB_REDIS_PASSWORD") modparam("ndb_redis", "server", "name=12.0.1.8:7369;addr=12.0.1.8;port=7369;pass=NDB_REDIS_PASSWORD") modparam("ndb_redis", "server", "name=12.0.1.9:7369;addr=12.0.1.9;port=7369;pass=NDB_REDIS_PASSWORD") modparam("ndb_redis", "server", "name=12.0.1.7:7469;addr=12.0.1.7;port=7469;pass=NDB_REDIS_PASSWORD") modparam("ndb_redis", "server", "name=12.0.1.8:7469;addr=12.0.1.8;port=7469;pass=NDB_REDIS_PASSWORD") modparam("ndb_redis", "server", "name=12.0.1.9:7469;addr=12.0.1.9;port=7469;pass=NDB_REDIS_PASSWORD") ``` * **Operating System**:  ``` version: kamailio 5.7.4 (x86_64/linux) 9920d9-dirty flags: , EXTRA_DEBUGUSE_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_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: 9920d9 -dirty compiled on 09:59:52 Feb 26 2024 with gcc 7.5.0 ``` -- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/3768 You are receiving this because you are subscribed to this thread. Message ID: <kamailio/kamailio/issues/3768(a)github.com>

3 weeks, 4 days

[kamailio/kamailio] Segfault in pua_dialoginfo.c when starting up with a dialog in the database (Issue #3743)

by Gianluca Nitti

### Description Kamailio segfaults on startup. After a bit of digging, it looks like the issue is caused by trying to publish something related to an expired dalog which is present in the database: ``` kamailio=# select * from dialog; id | hash_entry | hash_id | callid | from_uri | from_tag | to_uri | to_tag | caller_cseq | callee_cseq | caller_route_set | callee_route_set | caller_contact | callee_contact | caller_sock | callee_sock | state | start_time | timeout | sflags | iflags | toroute_name | req_ur i | xdata ----+------------+---------+---------------------------+------------------------------+----------+-------------------------------------------+---------------+-------------+- ------------+--------------------------------------------+------------------+---------------------------------------------------------------------------+-------------------- -----------------------------------+----------------------+----------------------+-------+------------+------------+--------+--------+--------------+------------------------ -------------------+------- 90 | 3720 | 11295 | msowdcchfzrlapg@localhost | sip:101@example.voismart.com | msfvz | sip:*9001*0039123456@example.voismart.com | HBQj442BFrH0N | 131 | 0 | <sip:172.23.42.1;lr=on;ftag=msfvz;nat=yes> | | sip:101_example_voismart_com@172.23.42.1:5065;alias=192.168.1.201~32878~1 | sip:*9001*003912345 6@172.23.42.211:5060;transport=udp | udp:172.23.42.3:5060 | udp:172.23.42.3:5060 | 4 | 1706715542 | 1706801943 | 0 | 1 | | sip:*9001*0039123456@ex ample.voismart.com | (1 row) ``` ### Troubleshooting #### Debugging Data  ``` (gdb) bt full #0 0x00007f193de1bc93 in free_str_list_all (del_current=0x2e656c706d617865) at /usr/local/src/pkg/src/modules/pua_dialoginfo/pua_dialoginfo.c:1109 del_next = <optimized out> __func__ = "free_str_list_all" #1 0x00007f193de1ebc6 in free_dlginfo_cell (param=0x7f1942265dc8) at /usr/local/src/pkg/src/modules/pua_dialoginfo/pua_dialoginfo.c:1079 cell = 0x7f1942265dc8 cell = <optimized out> __func__ = <optimized out> #2 free_dlginfo_cell (param=0x7f1942265dc8) at /usr/local/src/pkg/src/modules/pua_dialoginfo/pua_dialoginfo.c:1070 cell = 0x0 __func__ = "free_dlginfo_cell" #3 0x00007f1940b7120b in destroy_dlg_callbacks_list (cb=0x0) at /usr/local/src/pkg/src/modules/dialog/dlg_cb.c:74 cb_t = 0x7f1942266050 __func__ = "destroy_dlg_callbacks_list" #4 0x00007f1940ba5229 in destroy_dlg (dlg=0x7f1941b1a8a0) at /usr/local/src/pkg/src/modules/dialog/dlg_hash.c:369 ret = <optimized out> var = <optimized out> __func__ = "destroy_dlg" #5 0x00007f1940ba6b08 in destroy_dlg_table () at /usr/local/src/pkg/src/modules/dialog/dlg_hash.c:436 dlg = 0x0 l_dlg = <optimized out> i = 3720 __func__ = <optimized out> #6 destroy_dlg_table () at /usr/local/src/pkg/src/modules/dialog/dlg_hash.c:422 dlg = <optimized out> l_dlg = <optimized out> i = <optimized out> __func__ = "destroy_dlg_table" #7 0x00007f1940b57b06 in mod_destroy () at /usr/local/src/pkg/src/modules/dialog/dialog.c:871 No locals. #8 0x000055dd96a6d1e2 in destroy_modules () at core/sr_module.c:872 t = 0x7f1949d9d5f0 foo = 0x7f1949d94710 __func__ = "destroy_modules" #9 0x000055dd96864d01 in cleanup (show_status=1) at /usr/local/src/pkg/src/main.c:573 memlog = <optimized out> --Type <RET> for more, q to quit, c to continue without paging-- __func__ = "cleanup" #10 0x000055dd96c92a4d in shutdown_children.constprop.0 (show_status=show_status@entry=1, sig=15) at /usr/local/src/pkg/src/main.c:721 __func__ = <optimized out> #11 0x000055dd9685fcd5 in handle_sigs () at /usr/local/src/pkg/src/main.c:821 chld = <optimized out> chld_status = 139 any_chld_stopped = <optimized out> memlog = <optimized out> __func__ = "handle_sigs" #12 0x000055dd96868aa4 in main_loop () at /usr/local/src/pkg/src/main.c:1988 i = <optimized out> pid = <optimized out> si = <optimized out> si_desc = "udp receiver child=31 sock=172.23.42.3:9999\000\335U\000\000\000\260\312I\031\177\000\000\003\000\000\000\377\377\377\377\004\220\312\226\335U\000\000\004\000\000\000\031\177\000\000\003\000\000\000\000\000\000\000\t\000\000\000\000\000\000\000Tue Feb \000\023&\252U\314\342\207:34 2024\005\000\000\000\000\000\000" nrprocs = <optimized out> woneinit = 1 error = <optimized out> __func__ = "main_loop" #13 0x000055dd96859ffc in main (argc=<optimized out>, argv=<optimized out>) at /usr/local/src/pkg/src/main.c:3212 cfg_stream = <optimized out> c = <optimized out> r = <optimized out> tmp = 0x7ffe9d9b7db4 "" tmp_len = 1274056464 port = 32537 proto = 1275323104 ahost = 0x0 aport = 0 options = 0x55dd96cac300 ":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 = 3377142042 rfd = <optimized out> debug_save = <optimized out> debug_flag = <optimized out> --Type <RET> for more, q to quit, c to continue without paging-- dont_fork_cnt = <optimized out> n_lst = <optimized out> p = <optimized out> st = {st_dev = 194, st_ino = 570312884, st_nlink = 2, st_mode = 16872, st_uid = 101, st_gid = 101, __pad0 = 0, st_rdev = 0, st_size = 6, st_blksize = 4096, st_blocks = 0, st_atim = {tv_sec = 1707216241, tv_nsec = 46870706}, st_mtim = {tv_sec = 1707216227, tv_nsec = 573144090}, st_ctim = {tv_sec = 1707216227, tv_nsec = 573144090}, __glibc_reserved = {0, 0, 0}} tbuf = '\000' <repeats 16 times>, '/' <repeats 16 times>, "\230\r", '\000' <repeats 14 times>, "`", '\000' <repeats 15 times>, "\001", '\000' <repeats 143 times>... option_index = 12 __func__ = "main" long_options = {{name = 0x55dd96cabfe2 "help", has_arg = 0, flag = 0x0, val = 104}, {name = 0x55dd96cb3dc8 "version", has_arg = 0, flag = 0x0, val = 118}, { name = 0x55dd96cc3731 "alias", has_arg = 1, flag = 0x0, val = 1024}, {name = 0x55dd96cabfe7 "subst", has_arg = 1, flag = 0x0, val = 1025}, { name = 0x55dd96cabfed "substdef", has_arg = 1, flag = 0x0, val = 1026}, {name = 0x55dd96cabff6 "substdefs", has_arg = 1, flag = 0x0, val = 1027}, { name = 0x55dd96cac000 "server-id", has_arg = 1, flag = 0x0, val = 1028}, {name = 0x55dd96cac00a "loadmodule", has_arg = 1, flag = 0x0, val = 1029}, { name = 0x55dd96cac015 "modparam", has_arg = 1, flag = 0x0, val = 1030}, {name = 0x55dd96cac01e "log-engine", has_arg = 1, flag = 0x0, val = 1031}, { name = 0x55dd96cb3ee5 "debug", has_arg = 1, flag = 0x0, val = 1032}, {name = 0x55dd96cac029 "cfg-print", has_arg = 0, flag = 0x0, val = 1033}, { name = 0x55dd96cac033 "atexit", has_arg = 1, flag = 0x0, val = 1034}, {name = 0x55dd96cac03a "all-errors", has_arg = 0, flag = 0x0, val = 1035}, {name = 0x0, has_arg = 0, flag = 0x0, val = 0}} (gdb) info locals del_next = <optimized out> __func__ = "free_str_list_all" (gdb) list 1104 in /usr/local/src/pkg/src/modules/pua_dialoginfo/pua_dialoginfo.c ``` #### Log Messages  ``` 65(75) DEBUG: dialog [dlg_timer.c:232]: get_expired_dlgs(): start with tl=0x7f1941b1a900 tl->prev=0x7f1941a084d8 tl->next=0x7f1941a084d8 (45536602) at 45536603 and end with end=0x7f1941a084d8 end->prev=0x7f1941b1a900 end->next=0x7f1941b1a900 65(75) DEBUG: dialog [dlg_timer.c:237]: get_expired_dlgs(): getting tl=0x7f1941b1a900 tl->prev=0x7f1941a084d8 tl->next=0x7f1941a084d8 with 45536602 65(75) DEBUG: dialog [dlg_timer.c:243]: get_expired_dlgs(): end with tl=0x7f1941a084d8 tl->prev=0x7f1941b1a900 tl->next=0x7f1941b1a900 and d_timer->first.next->prev=(nil) 65(75) DEBUG: dialog [dlg_timer.c:280]: dlg_timer_routine(): tl=0x7f1941b1a900 next=(nil) 65(75) DEBUG: dialog [dlg_cb.c:267]: run_dlg_callbacks(): dialog=0x7f1941b1a8a0, type=64 65(75) DEBUG: pua_dialoginfo [pua_dialoginfo.c:395]: __dialog_sendpublish(): dialog over, from=sip:101@example.voismart.com 65(75) DEBUG: pua_dialoginfo [dialog_publish.c:410]: dialog_publish_multi(): CALLING dialog_publish for URI 65(75) DEBUG: <core> [core/parser/parse_uri.c:1389]: parse_uri(): bad uri, state 0 parsed: <> (4) / <> (28) 65(75) ERROR: pua_dialoginfo [dialog_publish.c:303]: dialog_publish(): failed to parse the PUBLISH R-URI 123(133) CRITICAL: <core> [core/pass_fd.c:281]: receive_fd(): EOF on 133 123(133) DEBUG: <core> [core/tcp_main.c:3955]: handle_ser_child(): dead child 65, pid 75 (shutting down?) 123(133) DEBUG: <core> [core/io_wait.h:597]: io_watch_del(): DBG: io_watch_del (0x55dd96e1fba0, 133, -1, 0x0) fd_no=157 called 0(1) ALERT: <core> [main.c:791]: handle_sigs(): child process 75 exited by a signal 11 0(1) ALERT: <core> [main.c:795]: handle_sigs(): core was generated 0(1) INFO: <core> [main.c:818]: handle_sigs(): terminating due to SIGCHLD 2(12) INFO: <core> [main.c:874]: sig_usr(): signal 15 received 3(13) INFO: <core> [main.c:874]: sig_usr(): signal 15 received ``` ### Additional Information * **Kamailio Version** - output of `kamailio -v` ``` version: kamailio 5.7.4 (x86_64/linux) dc393e 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_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: dc393e compiled with gcc 11.4.0 ``` * **Operating System**:  ``` Linux c7a9e0ef942e 6.6.13-200.fc39.x86_64 #1 SMP PREEMPT_DYNAMIC Sat Jan 20 18:03:28 UTC 2024 x86_64 x86_64 x86_64 GNU/Linux ``` Running in a Docker container based on Ubuntu Jammy which builds kamailio from git tag 5.7.4. -- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/3743 You are receiving this because you are subscribed to this thread. Message ID: <kamailio/kamailio/issues/3743(a)github.com>

3 weeks, 4 days

[kamailio/kamailio] Crash in dns_cache.c with use_dns_cache=off (Issue #3350)

by Дилян Палаузов

With Kamailio 5.6.3 I add this code ```diff -- Routing to foreign domains function ksr_route_sipout() + local y = KSR.enum.enum_query() + KSR.err('ENUM RESULT ' .. tostring(y) .. ' :RURI ' .. KSR.kx.get_ruri() .. '\n') if KSR.is_myself_ruri() then return 1; end KSR.hdr.append("P-Hint: outbound\r\n"); ``` and dial +437200101011 . The code above produces the output “ENUM RESULT 1 :RURI sip:enum-test@sip.nemox.net”. I have the DNS-related settings: ``` dns_try_naptr=on use_dns_cache=off dns_cache_init=off ``` Kamailio logs during the dial-in process: ```sip INVITE sip:+437200101011@sip.example.org SIP/2.0 Via: SIP/2.0/UDP 192.168.0.199:40867;rport;branch=z9hG4bKU2Fc14H2NX4Kc Max-Forwards: 70 From: <sip:myself@sip.example.org>;tag=vmjX7H12KrH1B To: <sip:+437200101011@sip.example.org> Call-ID: 8956e785-1905-123c-24bb-e4aaeae9dd8b CSeq: 62865320 INVITE Contact: <sip:myself@sip.example.org> User-Agent: calls sofia-sip/1.13.12 Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE Supported: timer, 100rel, replaces, gruu, outbound Content-Type: application/sdp Content-Disposition: session Content-Length: 240 v=0 o=- 9163509233734166984 5909793187606445082 IN IP4 192.168.0.199 s=- c=IN IP4 22.222.222.222 t=0 0 m=audio 43264 RTP/AVP 9 8 0 3 a=rtpmap:9 G722/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtcp:33730 6(7) ERROR: <core> [core/kemi.c:96]: sr_kemi_core_err(): ksr_sipdump_event 1--------- sipdump:msg SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.0.199:40867;rport=40867;branch=z9hG4bKU2Fc14H2NX4Kc;received=22.222.222.222 From: <sip:myself@sip.example.org>;tag=vmjX7H12KrH1B To: <sip:+437200101011@sip.example.org>;tag=44af9dbde0a62ae84f5c1ff272adb901.20dd651d Call-ID: 8956e785-1905-123c-24bb-e4aaeae9dd8b CSeq: 62865320 INVITE Proxy-Authenticate: Digest realm="example.int", nonce="Y9QB/GPUANBJum6LTOLsDnjaSLKc/8o1A1zk1oUtFXzlFe/OfiMEAg==" Content-Length: 0 8(9) ERROR: <core> [core/kemi.c:96]: sr_kemi_core_err(): ksr_sipdump_event 1--------- sipdump:msg ACK sip:+437200101011@sip.example.org SIP/2.0 Via: SIP/2.0/UDP 192.168.0.199:40867;rport;branch=z9hG4bKU2Fc14H2NX4Kc Max-Forwards: 70 From: <sip:myself@sip.example.org>;tag=vmjX7H12KrH1B To: <sip:+437200101011@sip.example.org>;tag=44af9dbde0a62ae84f5c1ff272adb901.20dd651d Call-ID: 8956e785-1905-123c-24bb-e4aaeae9dd8b CSeq: 62865320 ACK Content-Length: 0 5(6) ERROR: <core> [core/kemi.c:96]: sr_kemi_core_err(): ksr_sipdump_event 1--------- sipdump:msg INVITE sip:+437200101011@sip.example.org SIP/2.0 Via: SIP/2.0/UDP 192.168.0.199:40867;rport;branch=z9hG4bKvB942Z25j6t6Q Max-Forwards: 70 From: <sip:myself@sip.example.org>;tag=vmjX7H12KrH1B To: <sip:+437200101011@sip.example.org> Call-ID: 8956e785-1905-123c-24bb-e4aaeae9dd8b CSeq: 62865321 INVITE Contact: <sip:myself@sip.example.org> User-Agent: calls sofia-sip/1.13.12 Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE Supported: timer, 100rel, replaces, gruu, outbound Proxy-Authorization: Digest username="myself", realm="example.int", nonce="Y9QB/GPUANBJum6LTOLsDnjaSLKc/8o1A1zk1oUtFXzlFe/OfiMEAg==", algorithm=MD5, uri="sip:+437200101011@sip.example.org", response="da2f40487bb63329105222dab911d9bd" Content-Type: application/sdp Content-Disposition: session Content-Length: 240 v=0 o=- 9163509233734166984 5909793187606445082 IN IP4 192.168.0.199 s=- c=IN IP4 22.222.222.222 t=0 0 m=audio 43264 RTP/AVP 9 8 0 3 a=rtpmap:9 G722/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtcp:33730 5(6) ERROR: <core> [core/kemi.c:96]: sr_kemi_core_err(): ENUM RESULT 1 :RURI sip:enum-test@sip.nemox.net 5(6) ERROR: <core> [core/kemi.c:96]: sr_kemi_core_err(): ksr_sipdump_event 1--------- sipdump:msg SIP/2.0 100 trying -- your call is important to us Via: SIP/2.0/UDP 192.168.0.199:40867;rport=40867;branch=z9hG4bKvB942Z25j6t6Q;received=22.222.222.222 From: <sip:myself@sip.example.org>;tag=vmjX7H12KrH1B To: <sip:+437200101011@sip.example.org> Call-ID: 8956e785-1905-123c-24bb-e4aaeae9dd8b CSeq: 62865321 INVITE Authentication-Info: nextnonce="Y9QB/GPUANBJum6LTOLsDnjaSLKc/8o1A1zk1oUtFXzlFe/OfiMEAg==", qop=, rspauth="d9dd065ba472cbc3f8cc4505dbd2ad60", cnonce="", nc= Content-Length: 0 0(1) ALERT: <core> [main.c:774]: handle_sigs(): child process 6 exited by a signal 11 24(25) CRITICAL: <core> [core/pass_fd.c:277]: receive_fd(): EOF on 13 0(1) ALERT: <core> [main.c:777]: handle_sigs(): core was generated ``` The full backtrace is: ``` #0 0x00000000004867e5 in atomic_cmpxchg_int (var=0x0, old=0, new_v=1) at core/mem/../atomic/atomic_x86.h:224 ret = 32663 #1 0x0000000000486831 in futex_get (lock=0x0) at core/mem/../futexlock.h:99 v = 0 i = 1024 #2 0x0000000000490ce5 in dns_hash_get (name=0x7ffe2446dbc0, type=33, h=0x7ffe2446da90, err=0x7ffe2446da7c) at core/dns_cache.c:673 e = 0x0 #3 0x00000000004972a7 in dns_get_entry (name=0x7ffe2446dbc0, type=33) at core/dns_cache.c:2001 h = 608623712 e = 0x0 cname_val = { s = 0x0, len = 5860299 } err = 32766 rec_cnt = 1 __func__ = "dns_get_entry" #4 0x0000000000499289 in dns_srv_get_he (name=0x7ffe2446dbc0, port=0x7ffe2446df1c, flags=0) at core/dns_cache.c:2455 e = 0x2 rr = 0x0 rr_name = { s = 0xa3e33d203 <error: Cannot access memory at address 0xa3e33d203>, len = 1043567768 } he = 0x0 now = 611930531 rr_no = 0 '\000' #5 0x0000000000597aae in no_naptr_srv_sip_resolvehost (name=0x7ffe2446e100, port=0x7ffe2446df1c, proto=0x7f973a751788 "\001") at core/resolve.c:1599 srv_proto_list = {{ proto = 1 '\001', proto_pref = 30 }, { proto = 2 '\002', proto_pref = 20 }, { proto = 4 '\004', proto_pref = 20 }, { proto = 3 '\003', proto_pref = 10 }, { proto = 0 '\000', proto_pref = 0 }, { proto = 13 '\r', proto_pref = 1 }, { proto = 80 'P', proto_pref = 319 }} he = 0x0 ip = 0x0 srv_name = { s = 0x929320 <tmp_srv> "_sip._udp.sip.nemox.net", len = 23 } tmp_srv = "_sip._udp.sip.nemox.net", '\000' <repeats 232 times> i = 0 list_len = 4 __func__ = "no_naptr_srv_sip_resolvehost" #6 0x0000000000598333 in naptr_sip_resolvehost (name=0x7ffe2446e100, port=0x7ffe2446df1c, proto=0x7f973a751788 "\001") at core/resolve.c:1675 he = 0x0 ip = 0x0 tmp = "sip.nemox.net", '\000' <repeats 242 times> l = 0x0 naptr_head = 0x0 n_proto = 0 '\000' srv_name = { s = 0x7f97390fee12 <sr_kemi_lua_exec_func_514> "UH\211\345H\203\354\020H\211}\370H\213E\370\276\002\002", len = 1051642410 } tried_bmp = 0 origproto = 0 '\000' __func__ = "naptr_sip_resolvehost" #7 0x00000000005983c6 in _sip_resolvehost (name=0x7ffe2446e100, port=0x7ffe2446df1c, proto=0x7f973a751788 "\001") at core/resolve.c:1707 res = 0x0 #8 0x000000000049943c in dns_srv_sip_resolvehost (name=0x7ffe2446e100, port=0x7ffe2446df1c, proto=0x7f973a751788 "\001") at core/dns_cache.c:2516 he = 0x7f9739119c91 <luaD_callnoyield+449> ip = 0x7f97390fca97 <sr_kemi_lua_exec_func_221> tmp = '\000' <repeats 255 times> srv_name = { s = 0x1a67740 "\020h\247\001", len = 0 } srv_proto = 0 '\000' __func__ = "dns_srv_sip_resolvehost" #9 0x000000000049b3de in dns_sip_resolvehost (name=0x7ffe2446e100, port=0x7ffe2446df1c, proto=0x7f973a751788 "\001") at core/dns_cache.c:2738 No locals. #10 0x000000000059846b in sip_hostport2su (su=0x7f973a751700, name=0x7ffe2446e100, port=5060, proto=0x7f973a751788 "\001") at core/resolve.c:1727 he = 0x7f973e33d2be __func__ = "sip_hostport2su" #11 0x00007f9739efdff0 in uri2dst2 (dns_h=0x7f973a751888, dst=0x7f973a7516f8, force_send_socket=0x0, sflags=..., uri=0x7f973e3390d0, proto=0) at /git/voip/kamailio/src/modules/tm/ut.h:308 parsed_uri = { user = { s = 0x7f973e33d2b4 "enum-test(a)sip.nemox.net", len = 9 }, passwd = { s = 0x0, len = 0 }, host = { s = 0x7f973e33d2be "sip.nemox.net", len = 13 }, port = { s = 0x0, len = 0 }, params = { s = 0x0, len = 0 }, sip_params = { s = 0x0, len = 0 }, headers = { s = 0x0, len = 0 }, port_no = 0, proto = 0, type = SIP_URI_T, flags = 0, transport = { s = 0x0, len = 0 }, ttl = { s = 0x0, len = 0 }, user_param = { s = 0x0, len = 0 }, maddr = { s = 0x0, len = 0 }, method = { s = 0x0, len = 0 }, lr = { s = 0x0, len = 0 }, r2 = { s = 0x0, len = 0 }, gr = { s = 0x0, len = 0 }, transport_val = { s = 0x0, len = 0 }, ttl_val = { s = 0x0, len = 0 }, user_param_val = { s = 0x0, len = 0 }, maddr_val = { s = 0x0, len = 0 }, method_val = { s = 0x0, len = 0 }, lr_val = { s = 0x0, len = 0 }, r2_val = { s = 0x0, len = 0 }, gr_val = { s = 0x0, len = 0 } } uri_proto = PROTO_NONE host = 0x7ffe2446e100 ip_found = 0 to = { s = { sa_family = 57744, sa_data = "F$\376\177\000\000\211\216\0169\227\177\000" }, sin = { sin_family = 57744, sin_port = 9286, sin_addr = { s_addr = 32766 }, sin_zero = "\211\216\0169\227\177\000" }, sin6 = { sin6_family = 57744, sin6_port = 9286, sin6_flowinfo = 32766, sin6_addr = { __in6_u = { __u6_addr8 = "\211\216\0169\227\177\000\000\001\000\000\000\000\000\000", __u6_addr16 = {36489, 14606, 32663, 0, 1, 0, 0, 0}, __u6_addr32 = {957255305, 32663, 1, 0} } }, sin6_scope_id = 1042640912 }, sas = { ss_family = 57744, __ss_padding = "F$\376\177\000\000\211\216\0169\227\177\000\000\001\000\000\000\000\000\000\000\020p%>\227\177\000\000\260\340F$\376\177\000\000\304\311K", '\000' <repeats 37 times>, "\020;\v:\227\177\000\000\360\2153>\227\177\000\000Px\246\001\000\000\000\000\230\2243>\227\177\000\000\002\000\000\000\000\000\000", __ss_align = 27947488 } } err = 32766 __func__ = "uri2dst2" #12 0x00007f9739f00878 in prepare_new_uac (t=0x7f973a751408, i_req=0x7f973e338df0, branch=0, uri=0x7ffe2446e490, path=0x7ffe2446e470, next_hop=0x7f973e3390d0, fsocket=0x0, snd_flags=..., fproto=0, flags=2, instance=0x7ffe2446e460, ruid=0x7ffe2446e450, location_ua=0x7ffe2446e440) at t_fwd.c:447 shbuf = 0x0 add_rm_backup = 0x7f973e33b288 body_lumps_backup = 0x0 parsed_uri_bak = { user = { s = 0x7f973e33a634 "enum-test(a)sip.nemox.net", len = 9 }, passwd = { s = 0x0, len = 0 }, host = { s = 0x7f973e33a63e "sip.nemox.net", len = 13 }, port = { s = 0x0, len = 0 }, params = { s = 0x0, len = 0 }, sip_params = { s = 0x0, len = 0 }, headers = { s = 0x0, len = 0 }, port_no = 0, proto = 0, type = SIP_URI_T, flags = 0, transport = { s = 0x0, len = 0 }, ttl = { s = 0x0, len = 0 }, user_param = { s = 0x0, len = 0 }, maddr = { s = 0x0, len = 0 }, method = { s = 0x0, len = 0 }, lr = { s = 0x0, len = 0 }, r2 = { s = 0x0, len = 0 }, gr = { s = 0x0, len = 0 }, transport_val = { s = 0x0, len = 0 }, ttl_val = { s = 0x0, len = 0 }, user_param_val = { s = 0x0, len = 0 }, maddr_val = { s = 0x0, len = 0 }, method_val = { s = 0x0, len = 0 }, lr_val = { s = 0x0, len = 0 }, r2_val = { s = 0x0, len = 0 }, gr_val = { s = 0x0, len = 0 } } ret = -1 len = 32663 parsed_uri_ok_bak = 1 free_new_uri = 1 msg_uri_bak = { s = 0x7f973e33a630 "sip:enum-test@sip.nemox.net", len = 27 } dst_uri_bak = { s = 0x0, len = 0 } dst_uri_backed_up = 1 path_bak = { s = 0x0, len = 0 } free_path = 1 instance_bak = { s = 0x0, len = 0 } free_instance = 1 ruid_bak = { s = 0x0, len = 0 } free_ruid = 1 ua_bak = { s = 0x0, len = 0 } free_ua = 1 backup_route_type = 1 test_dst = 23 fwd_snd_flags_bak = { f = 0, blst_imask = 0 } rpl_snd_flags_bak = { f = 1, blst_imask = 0 } force_send_socket_bak = 0x0 dst = 0x7f973a7516f8 ctx = { rec_lev = 0, run_flags = 0, last_retcode = 0, jmp_env = {{ __jmpbuf = {140729507046528, 107383054981, 140729507046336, 7983668, 140729507046712, 140729507046688, 0, 0}, __mask_was_saved = 0, __saved_mask = { __val = {0, 0, 0, 0, 1016, 2510101137099545603, 12909040900923746448, 140729507046448, 7983053, 3689621524717335394, 0, 140729507046488, 140729507046688, 8, 8872581, 4179003179399} } }} } bctx = 0x0 keng = 0x913440 <_sr_kemi_eng_list> __func__ = "prepare_new_uac" #13 0x00007f9739f058f0 in add_uac (t=0x7f973a751408, request=0x7f973e338df0, uri=0x7f973e3390d0, next_hop=0x7f973e3390d0, path=0x7f973e339498, proxy=0x0, fsocket=0x0, snd_flags=..., proto=0, flags=2, instance=0x7f973e3394a8, ruid=0x7f973e3394c0, location_ua=0x7f973e3394d0) at t_fwd.c:814 ret = 0 branch = 0 __func__ = "add_uac" #14 0x00007f9739f0f73f in t_forward_nonack (t=0x7f973a751408, p_msg=0x7f973e338df0, proxy=0x0, proto=0) at t_fwd.c:1694 branch_ret = 0 lowest_ret = -1 added_branches = 0 first_branch = 0 i = 32766 t_invite = 0x7f973e33c570 success_branch = 608627136 try_new = 1 lock_replies = 939792 backup_bflags = 0 obranch = { uri = { s = 0x1f600000000 <error: Cannot access memory at address 0x1f600000000>, len = 27594632 }, dst_uri = { s = 0x1 <error: Cannot access memory at address 0x1>, len = 27947488 }, q = 27687040, path = { s = 0x7f97390fca97 <sr_kemi_lua_exec_func_221> "UH\211\345H\203\354\020H\211}\370H\213E\370\276", <incomplete sequence \335>, len = 608627072 }, flags = 972537629, force_socket = 0x1, ruid = { s = 0x7ffe2446e950 "", len = 608627120 }, instance = { s = 0x6400000001 <error: Cannot access memory at address 0x6400000001>, len = 1043566064 }, location_ua = { s = 0x7f973a751408 "p\344\032:\227\177", len = 8388608 }, otcpid = 7449488 } __func__ = "t_forward_nonack" #15 0x00007f9739ef6bc5 in t_relay_to (p_msg=0x7f973e338df0, proxy=0x0, proto=0, replicate=0) at t_funcs.c:332 ret = 0 new_tran = 1 t = 0x7f973a751408 dst = { send_sock = 0x7ffe2446eb80, to = { s = { sa_family = 50040, sa_data = "3>\227\177\000\000\000\000\000\000\000\000\000" }, sin = { sin_family = 50040, sin_port = 15923, sin_addr = { s_addr = 32663 }, sin_zero = "\000\000\000\000\000\000\000" }, sin6 = { sin6_family = 50040, sin6_port = 15923, sin6_flowinfo = 32663, sin6_addr = { __in6_u = { __u6_addr8 = "\000\000\000\000\000\000\000\000\020p%>\227\177\000", __u6_addr16 = {0, 0, 0, 0, 28688, 15909, 32663, 0}, __u6_addr32 = {0, 0, 1042640912, 32663} } }, sin6_scope_id = 27687040 }, sas = { ss_family = 50040, __ss_padding = "3>\227\177\000\000\000\000\000\000\000\000\000\000\020p%>\227\177\000\000\200x\246\001\000\000\000\000\320\377\377\377\377\377\377\377\000\000\000\000\000\000\000\000\300c\252\001\000\000\000\000\200x\246\001\000\000\000\000\360\273\0179\227\177\000\000\200\353F$\376\177\000\000\257\363G\000\000\000\000\000\000\000\000\000S\003\000\000\360\2153>\227\177", '\000' <repeats 14 times>, "\022\000\000", __ss_align = 140287560368784 } }, id = 1043579664, send_flags = { f = 32663, blst_imask = 0 }, proto = 0 '\000', proto_pad0 = 0 '\000', proto_pad1 = 0 } port = 0 host = { s = 0x0, len = 1043579608 } comp = 0 __func__ = "t_relay_to" #16 0x00007f9739f48a33 in _w_t_relay_to (p_msg=0x7f973e338df0, proxy=0x0, force_proto=0) at tm.c:1764 t = 0x7ffe2446ec30 res = 3 __func__ = "_w_t_relay_to" #17 0x00007f9739f51dec in ki_t_relay (msg=0x7f973e338df0) at tm.c:2917 No locals. #18 0x00007f97390eb94c in sr_kemi_lua_exec_func_ex (L=0x1a50f88, ket=0x7f9739ff5be0 <tm_kemi_exports>, pdelta=0) at app_lua_api.c:1022 i = 1 argc = 0 ret = 1 fname = 0x7f9739ff5bf0 <tm_kemi_exports+16> mname = 0x7f9739ff5be0 <tm_kemi_exports> vps = {{ n = 27739704, s = { s = 0x1a74638 "ksr_failure_manage", len = 18 } }, { n = 0, s = { s = 0x0, len = 0 } }, { n = 0, s = { s = 0x0, len = 0 } }, { n = 0, s = { s = 0x0, len = 0 } }, { n = 0, s = { s = 0x0, len = 0 } }, { n = 0, s = { s = 0x0, len = 0 } }} env_L = 0x7f9739175a00 <_sr_L_env> xret = 0x7f973a047580 <_sr_kemi_kx_xval> __func__ = "sr_kemi_lua_exec_func_ex" #19 0x00007f97390f337e in sr_kemi_lua_exec_func (L=0x1a50f88, eidx=221) at app_lua_api.c:1706 ket = 0x7f9739ff5be0 <tm_kemi_exports> ret = 1 tvb = { tv_sec = 0, tv_usec = 0 } tve = { tv_sec = 0, tv_usec = 0 } tz = { tz_minuteswest = 1052892288, tz_dsttime = 32663 } tdiff = 27594832 dinfo = { event = 1043568344, name = 0x7f973e339980 <incomplete sequence \350>, namewhat = 0x7ffe2446f03e "", what = 0x3000000018 <error: Cannot access memory at address 0x3000000018>, source = 0x7ffe2446efa0 "\200x\246\001", srclen = 140729507049184, currentline = 8989040, linedefined = 0, lastlinedefined = 73, nups = 0 '\000', nparams = 0 '\000', isvararg = 0 '\000', istailcall = 0 '\000', ftransfer = 4176, ntransfer = 421, short_src = "\000\000\000\000\004\000\000\000\000\000\000\000I\000\000\000\000\000\000\000\204\275\256>\227\177\000\000\300\a\000\000\000\000\000\000@\000\000\000\000\000\000\000\005\000\000\000\000\000\000\000P\020\245\001\000\000\000", i_ci = 0x1a50f88 } __func__ = "sr_kemi_lua_exec_func" #20 0x00007f97390fcab4 in sr_kemi_lua_exec_func_221 (L=0x1a50f88) at app_lua_kemi_export.c:1813 No locals. #21 0x00007f97391193c1 in luaD_precall () from /var/lib/containers/storage/overlay/1ba9d537e5be2b3a47b220bd68cdb6646cd0a1f4ebb83a234c8bcc2324ca5f3f/merged/lib64/kamailio/modules/app_lua.so No symbol table info available. #22 0x00007f973912d4cb in luaV_execute () from /var/lib/containers/storage/overlay/1ba9d537e5be2b3a47b220bd68cdb6646cd0a1f4ebb83a234c8bcc2324ca5f3f/merged/lib64/kamailio/modules/app_lua.so No symbol table info available. #23 0x00007f9739119c91 in luaD_callnoyield () from /var/lib/containers/storage/overlay/1ba9d537e5be2b3a47b220bd68cdb6646cd0a1f4ebb83a234c8bcc2324ca5f3f/merged/lib64/kamailio/modules/app_lua.so No symbol table info available. #24 0x00007f973911802a in luaD_rawrunprotected () from /var/lib/containers/storage/overlay/1ba9d537e5be2b3a47b220bd68cdb6646cd0a1f4ebb83a234c8bcc2324ca5f3f/merged/lib64/kamailio/modules/app_lua.so No symbol table info available. #25 0x00007f973911a1e0 in luaD_pcall () from /var/lib/containers/storage/overlay/1ba9d537e5be2b3a47b220bd68cdb6646cd0a1f4ebb83a234c8bcc2324ca5f3f/merged/lib64/kamailio/modules/app_lua.so No symbol table info available. #26 0x00007f97391143df in lua_pcallk () from /var/lib/containers/storage/overlay/1ba9d537e5be2b3a47b220bd68cdb6646cd0a1f4ebb83a234c8bcc2324ca5f3f/merged/lib64/kamailio/modules/app_lua.so No symbol table info available. #27 0x00007f97390e7f0d in app_lua_run_ex (msg=0x7f973e338df0, func=0x7f973914d598 "ksr_request_route", p1=0x0, p2=0x0, p3=0x0, emode=1) at app_lua_api.c:773 n = 0 ret = 0 txt = { s = 0x7ffe2446f520 "\020\370F$\376\177", len = 5783320 } bmsg = 0x0 ltop = 36 __func__ = "app_lua_run_ex" #28 0x00007f9739106f07 in sr_kemi_config_engine_lua (msg=0x7f973e338df0, rtype=1, rname=0x0, rparam=0x0) at app_lua_mod.c:119 ret = -1 __func__ = "sr_kemi_config_engine_lua" #29 0x00000000005048bf in sr_kemi_route (keng=0x913440 <_sr_kemi_eng_list>, msg=0x7f973e338df0, rtype=1, ename=0x0, edata=0x0) at core/kemi.c:3784 sfbk = 0 ret = 1054122048 #30 0x000000000058890a in receive_msg (buf=0x9b22a0 <buf> "INVITE sip:+437200101011@sip.example.org SIP/2.0\r\nVia: SIP/2.0/UDP 192.168.0.199:40867;TH=div;rport;branch=z9hG4bKvB942Z25j6t6Q\r\nMax-Forwards: 69\r\nFrom: <sip:myself@sip.example.org>;tag=vmjX7H12KrH1B\r\nTo: <sip:+437200101011@sip.example.org>\r\nCall-ID: 8956e785-1905-123c-24bb-e4aaeae9dd8b\r\nCSeq: 62865321 INVITE\r\nContact: <sip:myself@sip.example.org>\r\nUser-Agent: calls sofia-sip/1.13.12\r\nAllow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE\r\nSupported: timer, 100rel, replaces, gruu, outbound\r\nProxy-Authorization: Digest username=\"myself\", realm=\"example.int\", nonce=\"Y9QB/GPUANBJum6LTOLsDnjaSLKc/8o1A1zk1oUtFXzlFe/OfiMEAg==\", algorithm=MD5, uri=\"sip:+437200101011@sip.example.org\", response=\"da2f40487bb63329105222dab911d9bd\"\r\nContent-Type: application/sdp\r\nContent-Disposition: session\r\nContent-Length: 240\r\nTH: dih\r\n\r\nv=0\r\no=- 9163509233734166984 5909793187606445082 IN IP4 192.168.0.199\r\ns=-\r\nc=IN IP4 22.222.222.222\r\nt=0 0\r\nm=audio 43264 RTP/AVP 9 8 0 3\r\na=rtpmap:9 G722/8000\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:3 GSM/8000\r\na=rtcp:33730\r\n", len=1093, rcv_info=0x7ffe2446fae0) at core/receive.c:502 msg = 0x7f973e338df0 ctx = { rec_lev = 256, run_flags = 16777216, last_retcode = 0, jmp_env = {{ __jmpbuf = {1099511627776, 512, 0, 0, 0, 0, 0, 0}, __mask_was_saved = 0, __saved_mask = { __val = {0, 0, 0, 0, 0, 0, 0, 4294967296, 1225543208507932942, 33554432, 3298534883584, 72057594037928192, 72057594037927936, 1099511627776, 512, 0} } }} } bctx = 0x0 ret = 0 tvb = { tv_sec = 0, tv_usec = 0 } tve = { tv_sec = 0, tv_usec = 0 } diff = 0 inb = { s = 0x9b22a0 <buf> "INVITE sip:+437200101011@sip.example.org SIP/2.0\r\nVia: SIP/2.0/UDP 192.168.0.199:40867;TH=div;rport;branch=z9hG4bKvB942Z25j6t6Q\r\nMax-Forwards: 69\r\nFrom: <sip:myself@sip.example.org>;tag=vmjX7H12KrH1B\r\nTo: <sip:+437200101011@sip.example.org>\r\nCall-ID: 8956e785-1905-123c-24bb-e4aaeae9dd8b\r\nCSeq: 62865321 INVITE\r\nContact: <sip:myself@sip.example.org>\r\nUser-Agent: calls sofia-sip/1.13.12\r\nAllow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE\r\nSupported: timer, 100rel, replaces, gruu, outbound\r\nProxy-Authorization: Digest username=\"myself\", realm=\"example.int\", nonce=\"Y9QB/GPUANBJum6LTOLsDnjaSLKc/8o1A1zk1oUtFXzlFe/OfiMEAg==\", algorithm=MD5, uri=\"sip:+437200101011@sip.example.org\", response=\"da2f40487bb63329105222dab911d9bd\"\r\nContent-Type: application/sdp\r\nContent-Disposition: session\r\nContent-Length: 240\r\nTH: dih\r\n\r\nv=0\r\no=- 9163509233734166984 5909793187606445082 IN IP4 192.168.0.199\r\ns=-\r\nc=IN IP4 22.222.222.222\r\nt=0 0\r\nm=audio 43264 RTP/AVP 9 8 0 3\r\na=rtpmap:9 G722/8000\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:3 GSM/8000\r\na=rtcp:33730\r\n", len = 1093 } netinfo = { data = { s = 0x0, len = 0 }, bufsize = 0, rcv = 0x0, dst = 0x0 } keng = 0x913440 <_sr_kemi_eng_list> evp = { data = 0x7ffe2446f630, obuf = { s = 0x0, len = 0 }, rcv = 0x7ffe2446fae0, dst = 0x0, req = 0x0, rpl = 0x0, rplcode = 0, mode = 0 } cidlockidx = 0 cidlockset = 0 errsipmsg = 0 exectime = 0 __func__ = "receive_msg" #31 0x00000000006cad81 in udp_rcv_loop () at core/udp_server.c:544 len = 1077 buf = "INVITE sip:+437200101011@sip.example.org SIP/2.0\r\nVia: SIP/2.0/UDP 192.168.0.199:40867;TH=div;rport;branch=z9hG4bKvB942Z25j6t6Q\r\nMax-Forwards: 69\r\nFrom: <sip:myself@sip.example.org>;tag=vmjX7H12KrH1B\r\nTo: <sip:+437200101011@sip.example.org>\r\nCall-ID: 8956e785-1905-123c-24bb-e4aaeae9dd8b\r\nCSeq: 62865321 INVITE\r\nContact: <sip:myself@sip.example.org>\r\nUser-Agent: calls sofia-sip/1.13.12\r\nAllow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE\r\nSupported: timer, 100rel, replaces, gruu, outbound\r\nProxy-Authorization: Digest username=\"myself\", realm=\"example.int\", nonce=\"Y9QB/GPUANBJum6LTOLsDnjaSLKc/8o1A1zk1oUtFXzlFe/OfiMEAg==\", algorithm=MD5, uri=\"sip:+437200101011@sip.example.org\", response=\"da2f40487bb63329105222dab911d9bd\"\r\nContent-Type: application/sdp\r\nContent-Disposition: session\r\nContent-Length: 240\r\nTH: dih\r\n\r\nv=0\r\no=- 9163509233734166984 5909793187606445082 IN IP4 192.168.0.199\r\ns=-\r\nc=IN IP4 22.222.222.222\r\nt=0 0\r\nm=audio 43264 RTP/AVP 9 8 0 3\r\na=rtpmap:9 G722/8000\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:3 GSM/8000\r\na=rtcp:33730\r\n", '\000' <repeats 64442 times> tmp = 0x13a3d9090 <error: Cannot access memory at address 0x13a3d9090> fromaddr = 0x7f973e338ba8 fromaddrlen = 16 rcvi = { src_ip = { af = 2, len = 4, u = { addrl = {2576512599, 0}, addr32 = {2576512599, 0, 0, 0}, addr16 = {30295, 39314, 0, 0, 0, 0, 0, 0}, addr = "Wv\222\231", '\000' <repeats 11 times> } }, dst_ip = { af = 2, len = 4, u = { addrl = {1317948560, 0}, addr32 = {1317948560, 0, 0, 0}, addr16 = {19600, 20110, 0, 0, 0, 0, 0, 0}, addr = "\220L\216N", '\000' <repeats 11 times> } }, src_port = 40867, dst_port = 5060, proto_reserved1 = 0, proto_reserved2 = 0, src_su = { s = { sa_family = 2, sa_data = "\237\243Wv\222\231\000\000\000\000\000\000\000" }, sin = { sin_family = 2, sin_port = 41887, sin_addr = { s_addr = 2576512599 }, sin_zero = "\000\000\000\000\000\000\000" }, sin6 = { sin6_family = 2, sin6_port = 41887, sin6_flowinfo = 2576512599, 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 = "\237\243Wv\222\231", '\000' <repeats 111 times>, __ss_align = 0 } }, bind_address = 0x7f973e2e7768, 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 = "\000\000\000\000\000\000\000\000\270\003G$\376\177\000\000\370\235\216\000\000\000\000\000@\240\324>\227\177\000\000\340\370F$\376\177\000\000D\204\0209\227\177\000\000\370\235\216\000\000\000\000\000@\240\324>\005\000\000\000\260\371F$\376\177\000\000\263\372b", '\000' <repeats 57 times>, "\005\000\000\000P\2210>\227\177", '\000' <repeats 90 times>, "\274\202=:\227\177\000\000\000\000\000\000\004\000\000\000\260-\205\000\000\000\000\000\370\235\216\000\000\000\000\000@\240\324>\005\000\000\000\200\372F$\376\177\000\000\263\372b", '\000' <repeats 13 times>, "0^\235\000\000\000\000\000\000^\235\000\000\000\000\000\230g\235\000\000\000\000\000K\306[\302!\307S\354\230\"7(ɘR\354\263ƚ\316\005\000\000\000\350\2260>\227\177\000\000 ^\235\000\000\000\000\000\230g\235\000\000\000\000\000\031\216\n\274\001\000\000\000@h\235\000\000\000\000\000P\372F$\376\177\000\000\240h\235\000\000\000\000\000\240g\235\000\000\000\000\000\000^\235\000\000\000\000\000p\372F$\376\177\000\000\235\275y\000\000\000\000\000p\372F$\376\177\000\000\274\202=:\227\177\000\000\000\000\000\000\000\000\000\000\270\003G$\376\177\000\000\370\235\216\000\000\000\000\000@\240\324>\227\177\000\0000\373F$\376\177\000\000\250\002c\000\000\000\000\000\320\372F$\376\177\000\000\213\305y\000\000\000\000" i = -1 j = 41600 l = 5 __func__ = "udp_rcv_loop" #32 0x000000000042d3af in main_loop () at main.c:1722 i = 4 pid = 0 si = 0x7f973e2e7768 si_desc = "udp receiver child=4 sock=111.11.111.11:5060\000\000d\000p\375F$\376\177\000\000\000\000\000\000\000\000\000\000\200\375F$\376\177\000\000s\300\3229\227\177\000\000\020\376F$\376\177\000\000\v\006\3239\227\177\000\000`\375F$\376\177\000\0001\rp\000\000\000\000\000\320/\203\000\000\000\000\000\001\000\000\000k\000\000" nrprocs = 8 woneinit = 1 __func__ = "main_loop" #33 0x00000000004390be in main (argc=3, argv=0x7ffe24470398) at main.c:3078 cfg_stream = 0x1931380 c = -1 r = 0 tmp = 0x0 tmp_len = 0 port = 0 proto = 0 ahost = 0x0 aport = 0 options = 0x8081f8 ":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 = 3092184453 rfd = 4 debug_save = 0 debug_flag = 0 dont_fork_cnt = 2 n_lst = 0x0 p = 0x0 st = { st_dev = 65025, st_ino = 3424267, st_nlink = 3, st_mode = 16895, st_uid = 65534, st_gid = 65534, __pad0 = 0, st_rdev = 0, st_size = 4096, st_blksize = 4096, st_blocks = 8, st_atim = { tv_sec = 1674835346, tv_nsec = 294486590 }, st_mtim = { tv_sec = 1674837962, tv_nsec = 574996365 }, st_ctim = { tv_sec = 1674837962, tv_nsec = 574996365 }, __glibc_reserved = {0, 0, 0} } tbuf = "D\377F$\376\177", '\000' <repeats 18 times>, "hq\247>\227\177\000\000\200\374\245>\227\177\000\000\020\000G$\376\177\000\000\b\000G$\376\177\000\000W\301\000\000\000\000\000\000``\321>\227\177\000\000\005", '\000' <repeats 23 times>, "\210\266\324>\227\177\000\000\000p\321>\227\177\000\000\342z\321>\227\177\000\000f\024\322>\227\177\000\000\260إ>", '\000' <repeats 12 times>, "\260Z\321>\227\177\000\0008^\321>\227\177\000\000\344U0\000\000\000\000\000hq\247>\227\177\000\000\220\000G$\376\177\000\000\b\000G$\376\177\000\000\340h\321>\227\177\000\000/\v\322>\227\177\000\000\004\000\000\000\000\000\000\000\340h\321>\227\177\000\000\001", '\000' <repeats 15 times>, "\001\000\000\000\000\000\000\000\260Z\321>\227\177\000\000\260Z\321>\227\177\000\000\001\000\000\000\003\000\000\000\020\000G$\376\177\000\0008^\321>\227\177\000\000\000\000\000\000\000\000\000\000\001", '\000' <repeats 16 times>, "\037G$\376\177\000\000\001\261\324>\227\177\000\000\377\377\377\377\000\000\000\000\330w\321>\227\177\000\000\360\252\324>\227\177\000\0006\027g\n3@\022\000\000\263\324>\227\177\000\000\306\363v\n3@\022\000\005", '\000' <repeats 15 times>, "\260Z\321>\227\177\000\000\017\000\000\000\000\000\000\000\300\321\301>\227\177\000\000\270\003G$\376\177\000\000\370\235\216\000\000\000\000\000@\240\324>\227\177\000\000^n\322>\227\177\000\000\001", '\000' <repeats 15 times>, "\330w\321>\227\177\000\000\340\326\322>\227\177\000\000\000\000\000\000\000\000\000\000\020\003G$\376\177\000\000\003", '\000' <repeats 14 times> option_index = 0 long_options = {{ name = 0x80a91f "help", has_arg = 0, flag = 0x0, val = 104 }, { name = 0x8054cc "version", has_arg = 0, flag = 0x0, val = 118 }, { name = 0x80a924 "alias", has_arg = 1, flag = 0x0, val = 1024 }, { name = 0x80a92a "subst", has_arg = 1, flag = 0x0, val = 1025 }, { name = 0x80a930 "substdef", has_arg = 1, flag = 0x0, val = 1026 }, { name = 0x80a939 "substdefs", has_arg = 1, flag = 0x0, val = 1027 }, { name = 0x80a943 "server-id", has_arg = 1, flag = 0x0, val = 1028 }, { name = 0x80a94d "loadmodule", has_arg = 1, flag = 0x0, val = 1029 }, { name = 0x80a958 "modparam", has_arg = 1, flag = 0x0, val = 1030 }, { name = 0x80a961 "log-engine", has_arg = 1, flag = 0x0, val = 1031 }, { name = 0x80a96c "debug", has_arg = 1, flag = 0x0, val = 1032 }, { name = 0x80a972 "cfg-print", has_arg = 0, flag = 0x0, val = 1033 }, { name = 0x80a97c "atexit", has_arg = 1, flag = 0x0, val = 1034 }, { name = 0x0, has_arg = 0, flag = 0x0, val = 0 }} __func__ = "main" quit ``` 111.11.111.11 is the IP address of the server. 22.222.222.222 is my public IP address. 192.168.0.199 is my address behind NAT. -- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/3350 You are receiving this because you are subscribed to this thread. Message ID: <kamailio/kamailio/issues/3350(a)github.com>

3 weeks, 5 days

[kamailio/kamailio] tcpops module event_route[tcp:closed] route block $conid is null (Issue #3767)

by liangbaolin

### Description During the process of using version 5.7.4 of Kamailio, I found that the $conid cannot be correctly obtained in the TCP: closed routing block of the TCP module event_route. I am certain that it is normal in version 5.4.8. ### Troubleshooting ``` pv [pv_core.c:2725]: pv_get_tcpconn_id() ``` #### Reproduction The test scenario initiated a register registration process for me, and after completing the disconnection of the TCP connection, triggered this event. #### Log Messages  ``` 2024-02-26T01:35:55.902002512Z 52(98) DEBUG: <core> [core/receive.c:635]: receive_msg(): cleaning up 2024-02-26T01:35:55.902034482Z 52(98) DEBUG: <core> [core/tcp_read.c:280]: tcp_read_data(): EOF on connection 0x7f99a1546a80 (state: 0, flags: c018) - FD 24, bytes 0, rd-flags 10000 ([12.0.1.6]:15821 -> [12.0.1.6]:5060)52(98) DEBUG: <core> [core/tcp_read.c:343]: tcp_read(): read 0 bytes: 2024-02-26T01:35:55.902051542Z 2024-02-26T01:35:55.902058282Z 52(98) DEBUG: <core> [core/tcp_read.c:1532]: tcp_read_req(): read= 0 bytes, parsed=0, state=0, error=1 2024-02-26T01:35:55.902063282Z 52(98) DEBUG: <core> [core/tcp_read.c:1534]: tcp_read_req(): last char=0x00, parsed msg= 2024-02-26T01:35:55.902069402Z 2024-02-26T01:35:55.902074032Z 52(98) DEBUG: <core> [core/tcp_read.c:1544]: tcp_read_req(): EOF 2024-02-26T01:35:55.902101372Z 52(98) DEBUG: <core> [core/io_wait.h:598]: io_watch_del(): DBG: io_watch_del (0x559e8a029740, 24, -1, 0x10) fd_no=2 called 2024-02-26T01:35:55.902153162Z 52(98) DEBUG: <core> [core/tcp_read.c:1927]: handle_io(): removing from list 0x7f99a1546a80 id 2 fd 24, state 2, flags c018, main fd 134, refcnt 2 ([12.0.1.6]:15821 -> [12.0.1.6]:5060) 2024-02-26T01:35:55.902168112Z 52(98) DEBUG: <core> [core/tcp_read.c:1702]: release_tcpconn(): releasing con 0x7f99a1546a80, state -1, fd=24, id=2 ([12.0.1.6]:15821 -> [12.0.1.6]:5060) 2024-02-26T01:35:55.902173372Z 52(98) DEBUG: <core> [core/tcp_read.c:1705]: release_tcpconn(): extra_data (nil) 2024-02-26T01:35:55.902208402Z 83(129) DEBUG: <core> [core/tcp_main.c:3747]: handle_tcp_child(): reader response= 7f99a1546a80, -1 from 1 2024-02-26T01:35:55.902224742Z 83(129) DEBUG: <core> [core/tcp_main.c:3904]: handle_tcp_child(): case CONN_EOF tcp_emit_closed_event before 5 2024-02-26T01:35:55.902229802Z 83(129) DEBUG: <core> [core/tcp_main.c:3671]: tcp_emit_closed_event(): TCP closed event creation triggered (reason: 0) 2024-02-26T01:35:55.902318572Z 83(129) DEBUG: tcpops [tcpops.c:311]: tcpops_handle_tcp_closed(): received TCP closed event 2024-02-26T01:35:55.902331352Z 83(129) DEBUG: tcpops [tcpops.c:261]: tcpops_tcp_closed_run_route(): event reason id: 0 rt: 1 2024-02-26T01:35:55.902335132Z 83(129) ERROR: tcpops [tcpops.c:278]: tcpops_tcp_closed_run_route(): run_top_route() before tev->id: 2 2024-02-26T01:35:55.902480972Z 83(129) DEBUG: <core> [core/tcp_main.c:1713]: _tcpconn_find(): 2 port 0 2024-02-26T01:35:55.902493872Z 83(129) DEBUG: pv [pv_core.c:2725]: pv_get_tcpconn_id(): no conid 2024-02-26T01:35:55.902498762Z 83(129) DEBUG: pv [pv_core.c:2726]: pv_get_tcpconn_id(): msg->rcv.proto_reserved1: 2 2024-02-26T01:35:55.902503592Z 83(129) DEBUG: <core> [core/tcp_main.c:1713]: _tcpconn_find(): 2 port 0 2024-02-26T01:35:55.902508262Z 83(129) DEBUG: <core> [core/pvapi.c:1418]: pv_printf_mode(): final buffer length 111 2024-02-26T01:35:55.902513422Z 83(129) ERROR: <script>: tcp connection closed conid: (<null>), tcp(conid): <null>, Ri: 12.0.1.185, Rp: 5060 , si: 12.0.1.6 , sp: 15821 2024-02-26T01:35:55.902607692Z 83(129) DEBUG: <core> [core/tcp_main.c:1713]: _tcpconn_find(): 2 port 0 2024-02-26T01:35:55.902625622Z 83(129) DEBUG: pv [pv_core.c:2725]: pv_get_tcpconn_id(): no conid 2024-02-26T01:35:55.902630672Z 83(129) DEBUG: pv [pv_core.c:2726]: pv_get_tcpconn_id(): msg->rcv.proto_reserved1: 2 2024-02-26T01:35:55.902635822Z 83(129) ERROR: tcpops [tcpops.c:280]: tcpops_tcp_closed_run_route(): run_top_route() after tev->id: 2 2024-02-26T01:35:58.777642759Z 41(87) DEBUG: ims_dialog [dlg_handlers.c:2026]: print_all_dlgs(): ********************41(87) DEBUG: ims_dialog [dlg_handlers.c:2027]: print_all_dlgs(): printing 65536 dialogs ``` #### SIP Traffic  ``` my test script block event_route[tcp:closed] { xlog("L_ERR", "$proto connection closed conid: ($conid), tcp(conid): $tcp(conid), Ri: $Ri, Rp: $Rp , si: $si , sp: $sp\n"); } file: src/modules/pv/pv_core.c int pv_get_tcpconn_id(struct sip_msg *msg, pv_param_t *param, pv_value_t *res) { ... if((con = tcpconn_get(msg->rcv.proto_reserved1, 0, 0, 0, 0)) == NULL) // return false { LM_DBG("no conid\n"); //additional custom log LM_DBG("msg->rcv.proto_reserved1: %d\n",msg->rcv.proto_reserved1); return pv_get_null(msg, param, res); } .... } file: src/core/tcp_main.c struct tcp_connection *tcpconn_lookup(int id, struct ip_addr *ip, int port, union sockaddr_union *local_addr, int try_local_port, ticks_t timeout) { ... if(unlikely(c == NULL)) { c = _tcpconn_find(id, ip, port, &local_ip, local_port); // retrun c == null } ... } struct tcp_connection *_tcpconn_find( int id, struct ip_addr *ip, int port, struct ip_addr *l_ip, int l_port) { ... if(likely(id)) { hash = tcp_id_hash(id); for(c = tcpconn_id_hash[hash]; c; c = c->id_next) { //tcpconn_id_hash find c is null #ifdef EXTRA_DEBUG LM_DBG("c=%p, c->id=%d, port=%d\n", c, c->id, c->rcv.src_port); print_ip("ip=", &c->rcv.src_ip, "\n"); #endif .... } inline static int tcpconn_try_unhash(struct tcp_connection *tcpconn) { ... _tcpconn_detach(tcpconn); //executed ... lock_release(&tcpconn->write_lock); ... } static inline void _tcpconn_detach(struct tcp_connection *c) { ... tcpconn_listrm(tcpconn_id_hash[c->id_hash], c, id_next, id_prev); //remove c ... } ``` ### Possible Solutions  ### Additional Information * **Kamailio Version** - output of `kamailio -v` ``` version: kamailio 5.7.4 (x86_64/linux) 9920d9-dirty flags: , EXTRA_DEBUGUSE_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_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: 9920d9 -dirty compiled on 09:59:52 Feb 26 2024 with gcc 7.5.0 ``` -- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/3767 You are receiving this because you are subscribed to this thread. Message ID: <kamailio/kamailio/issues/3767(a)github.com>

3 weeks, 5 days

[kamailio/kamailio] Kamailio 5.6 (and 5.7) core dumps. (Issue #3725)

by Mattis Lind

### Description We have a quite basic scenario which sends a SIP MESSAGE and then receives SIP MESSAGE back. It also sets up two voice calls using SIP INVITE. It is only this specific scenario that is causing the core dump. Some time the core dump occur just a few seconds after the call/message scenario, but occasionally it takes up to 50 minutes. We have been using the uac module for sending SIP MESSAGE in several other scenarios without experiencing a crash. We always see the same lines in the log just prior to the core dump: CRITICAL: <core> [core/pass_fd.c:281]: receive_fd(): EOF on 49 We are using Kamailio 5.6 retrieved from the kamailio repository: http://deb.kamailio.org/kamailio56. We are running Kamailio in a Docker container which runs on "5.10.0-25-cloud-amd64 #1 SMP Debian 5.10.191-1 (2023-08-16) x86_64 GNU/Linux" We have also tried Kamailio 5.7 from the same repo which crashes in exactly the same way. ### Troubleshooting #### Reproduction We have troubles to consistently reproduce it and it only happen from time to time when running a specific scenario sending SIP MESSAGE using the uac module. It does not happen for every call of this call scenario. At one instance Kamailo crashed with just 15 seconds in-between during the call scenario. #### Debugging Data ``` # gdb /usr/sbin/kamailio /core GNU gdb (Debian 10.1-1.7) 10.1.90.20210103-git Copyright (C) 2021 Free Software Foundation, Inc. License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html> This is free software: you are free to change and redistribute it. There is NO WARRANTY, to the extent permitted by law. Type "show copying" and "show warranty" for details. This GDB was configured as "x86_64-linux-gnu". Type "show configuration" for configuration details. For bug reporting instructions, please see: <https://www.gnu.org/software/gdb/bugs/>. Find the GDB manual and other documentation resources online at: <http://www.gnu.org/software/gdb/documentation/>. For help, type "help". Type "apropos word" to search for commands related to "word"... Reading symbols from /usr/sbin/kamailio... (No debugging symbols found in /usr/sbin/kamailio) warning: Can't open file /dev/zero (deleted) during file-backed mapping note processing [New LWP 4777] [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1". Core was generated by `/usr/sbin/kamailio -DD -M 18 -m 192 -A serverId=17173 -A sendTraceLocal="sip:10'. Program terminated with signal SIGSEGV, Segmentation fault. #0 __strlen_evex () at ../sysdeps/x86_64/multiarch/strlen-evex.S:77 77 ../sysdeps/x86_64/multiarch/strlen-evex.S: No such file or directory. (gdb) bt full #0 __strlen_evex () at ../sysdeps/x86_64/multiarch/strlen-evex.S:77 No locals. #1 0x00007f5425e34b78 in __vfprintf_internal (s=s@entry=0x55a06e969a60, format=format@entry=0x55a06e558020 "%s: %.*s%s%s%sBUG: qm: fragm. %p (address %p) beginning overwritten (%lx)! Memory allocator was called from %s:%u. Fragment marked by %s:%lu. Exec from %s:%u.\n", ap=ap@entry=0x7ffd6bebfb50, mode_flags=mode_flags@entry=0) at vfprintf-internal.c:1647 len = <optimized out> step0_jumps = {0, 1717, 1621, 3413, 3317, 3997, 2677, 2837, 3613, 1773, 4309, 4445, 3517, 4437, 4389, 2789, 4197, 3917, 3221, 2997, 1141, 1365, 1997, 1925, 1885, 733, 3709, 533, 533, 4101} space = <optimized out> is_short = <optimized out> use_outdigits = 0 outc = <optimized out> step1_jumps = {0, 0, 0, 0, 0, 0, 0, 0, 0, 1773, 4309, 4445, 3517, 4437, 4389, 2789, 4197, 3917, 3221, 2997, 1141, 1365, 1997, 1925, 1885, 733, 3709, 533, 533, 0} group = 0 prec = -1 step2_jumps = {0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 4309, 4445, 3517, 4437, 4389, 2789, 4197, 3917, 3221, 2997, 1141, 1365, 1997, 1925, 1885, 733, 3709, 533, 533, 0} string = 0x756d6f7266222c22 <error: Cannot access memory at address 0x756d6f7266222c22> left = 0 is_long_double = <optimized out> width = 0 signed_number = <optimized out> step3a_jumps = {0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 4213, 0, 0, 0, 4389, 2789, 4197, 3917, 3221, 0, 0, 0, 0, 1925, 0, 0, 0, 0, 0, 0} alt = <optimized out> showsign = 0 is_long = 0 is_char = <optimized out> pad = <optimized out> step3b_jumps = {0 <repeats 11 times>, 3517, 0, 0, 4389, 2789, 4197, 3917, 3221, 2997, 1141, 1365, 1997, 1925, 1885, 733, 3709, 0, 0, 0} step4_jumps = {0 <repeats 14 times>, 4389, 2789, 4197, 3917, 3221, 2997, 1141, 1365, 1997, 1925, 1885, 733, 3709, 0, 0, 0} args_value = <optimized out> is_negative = <optimized out> number = {longlong = <optimized out>, word = <optimized out>} base = <optimized out> the_arg = {pa_wchar = 4777 L'\x12a9', pa_int = 4777, pa_long_int = 4777, pa_long_long_int = 4777, pa_u_int = 4777, pa_u_long_int = 4777, pa_u_long_long_int = 4777, pa_double = 2.3601515901836347e-320, pa_long_double = 1.74131181638025811763e-4947, pa_float128 = 3.09319115455554459548860449034534676e-4962, pa_string = 0x12a9 <error: Cannot access memory at address 0x12a9>, pa_wstring = 0x12a9 <error: Cannot access memory at address 0x12a9>, pa_pointer = 0x12a9, pa_user = 0x12a9} spec = 115 's' _buffer = {__routine = 0x4, __arg = 0xd, __canceltype = 1855363680, __prev = 0xe0} _avail = <optimized out> thousands_sep = 0x0 grouping = 0xffffffffffffffff <error: Cannot access memory at address 0xffffffffffffffff> done = 238 f = 0x55a06e5580a7 "s:%lu. Exec from %s:%u.\n" lead_str_end = 0x55a06e558020 "%s: %.*s%s%s%sBUG: qm: fragm. %p (address %p) beginning overwritten (%lx)! Memory allocator was called from %s:%u. Fragment marked by %s:%lu. Exec from %s:%u.\n" end_of_spec = <optimized out> work_buffer = "h\r\000\000\000\000\000\000\000\000\000\000\060\000\000\000\000\000\000\000\375\177\000\000 \372\353k\375\177\000\000\237MSn\n\000\000\000\000\000\000\000\240U", '\000' <repeats 18 times>, "P\225Un\240U\000\000\000\000\000\000[\214A\323\f\000\000\000\000\000\000\000\377\377\377\377\377\377\377\377\206\002", '\000' <repeats 14 times>, "\004\000\000\000\000\000\000\000 \367\353k\375\177\000\000\301\225Un\240U\000\000\323\262\vn\240U\000\000\000\000\000\000\000\000\000\000s\374On\240U\000\000W\225Un\240U\000\000\350>\212\027T\177\000\000 \323\365$T\177\000\000\060\a\354k\375\177\000\00--Type <RET> for more, q to quit, c to continue without paging-- 0\220\371\227n\240U\000\000"... workend = 0x7ffd6bebf9f8 "" ap_save = {{gp_offset = 16, fp_offset = 48, overflow_arg_area = 0x7ffd6bebfc30, reg_save_area = 0x7ffd6bebfb70}} nspecs_done = 10 save_errno = 4 readonly_format = 0 do_longlong_number = <optimized out> __result = <optimized out> #2 0x00007f5425ec079f in __vsyslog_internal (pri=<optimized out>, fmt=0x55a06e558020 "%s: %.*s%s%s%sBUG: qm: fragm. %p (address %p) beginning overwritten (%lx)! Memory allocator was called from %s:%u. Fragment marked by %s:%lu. Exec from %s:%u.\n", ap=0x7ffd6bebfb50, mode_flags=0) at ../misc/syslog.c:233 now_tm = {tm_sec = 8, tm_min = 18, tm_hour = 12, tm_mday = 23, tm_mon = 0, tm_year = 124, tm_wday = 2, tm_yday = 22, tm_isdst = 0, tm_gmtoff = 0, tm_zone = 0x55a06e94c5e0 "UTC"} now = 1706012288 fd = <optimized out> f = 0x55a06e969a60 buf = 0x0 bufsize = 0 msgoff = 21 saved_errno = <optimized out> failbuf = "`\232\226n\240U\000\000\000\204\201\247[\214A\323`\374\353k\375\177\000\000\300p\371%T" clarg = {buf = <optimized out>, oldaction = <optimized out>} #3 0x00007f5425ec0c46 in __syslog (pri=<optimized out>, fmt=<optimized out>) at ../misc/syslog.c:117 ap = {{gp_offset = 48, fp_offset = 48, overflow_arg_area = 0x7ffd6bebfc70, reg_save_area = 0x7ffd6bebfb70}} #4 0x000055a06e3b7839 in ?? () No symbol table info available. #5 0x000055a06e3bc039 in qm_free () No symbol table info available. #6 0x000055a06e3c7c28 in qm_shm_free () No symbol table info available. #7 0x00007f542325fb8e in uac_send_tm_callback () from /usr/lib/x86_64-linux-gnu/kamailio/modules/uac.so No symbol table info available. #8 0x00007f5424a2f002 in run_trans_callbacks_internal () from /usr/lib/x86_64-linux-gnu/kamailio/modules/tm.so No symbol table info available. #9 0x00007f5424a2f179 in run_trans_callbacks () from /usr/lib/x86_64-linux-gnu/kamailio/modules/tm.so No symbol table info available. #10 0x00007f54249d5e8c in free_cell_helper () from /usr/lib/x86_64-linux-gnu/kamailio/modules/tm.so No symbol table info available. #11 0x00007f5424aa8f82 in wait_handler () from /usr/lib/x86_64-linux-gnu/kamailio/modules/tm.so No symbol table info available. #12 0x000055a06e37a263 in ?? () No symbol table info available. #13 0x000055a06e37a79d in ?? () No symbol table info available. #14 0x000055a06e37acc6 in timer_main () No symbol table info available. #15 0x000055a06e0a5f62 in main_loop () No symbol table info available. --Type <RET> for more, q to quit, c to continue without paging-- #16 0x000055a06e0b120c in main () No symbol table info available. (gdb) info locals No locals. (gdb) list 72 in ../sysdeps/x86_64/multiarch/strlen-evex.S ``` #### Log Messages ``` Log file: 2024-01-23T13:18:08.828+01:00 Jan 23 12:18:08 /usr/sbin/kamailio[4789]: INFO: <script>: Incoming SIP TCP request conid 21 call-id un0rihsRLJLvP-grn6LO-A 2024-01-23T13:18:08.835+01:00 Jan 23 12:18:08 /usr/sbin/kamailio[4789]: INFO: <script>: Incoming SIP TCP request conid 21 call-id WQjhldpRJbxjZRYe7fWgbw 2024-01-23T13:18:08.860+01:00 Jan 23 12:18:08 /usr/sbin/kamailio[4795]: CRITICAL: <core> [core/pass_fd.c:281]: receive_fd(): EOF on 49 2024-01-23T13:18:09.486+01:00 Jan 23 12:18:09 /usr/sbin/kamailio[4751]: ALERT: <core> [main.c:783]: handle_sigs(): child process 4777 exited by a signal 11 2024-01-23T13:18:09.486+01:00 Jan 23 12:18:09 /usr/sbin/kamailio[4751]: ALERT: <core> [main.c:787]: handle_sigs(): core was generated 2024-01-23T13:18:09.516+01:00 Jan 23 12:18:09 /usr/sbin/kamailio[4751]: INFO: <core> [core/sctp_core.c:53]: sctp_core_destroy(): SCTP API not initialized 2024-01-23T13:18:09.570+01:00 Started /root/sipconfig/startkamailio.sh 2024-01-23T13:18:09.570+01:00 info: :-) Starting Kamailio ``` #### SIP Traffic ### Possible Solutions ### Additional Information * **Kamailio Version** - output of `kamailio -v` ``` # /usr/sbin/kamailio -v version: kamailio 5.6.5 (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: unknown compiled with gcc 10.2.1 ``` * **Operating System**: ``` # lsb_release -a No LSB modules are available. Distributor ID: Debian Description: Debian GNU/Linux 11 (bullseye) Release: 11 Codename: bullseye Linux ip-nn-nn-nn-nn 5.10.0-25-cloud-amd64 #1 SMP Debian 5.10.191-1 (2023-08-16) x86_64 GNU/Linux ``` -- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/3725 You are receiving this because you are subscribed to this thread. Message ID: <kamailio/kamailio/issues/3725(a)github.com>

3 weeks, 5 days

Jump to page:

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009

2008

sr-dev February 2024