JiangHai2011 created an issue (kamailio/kamailio#4567)
### Description
during sipp REGISTER test with the rate 2000cps, there is a low rate to meet
kamailio tcp_read crashes on tls_accept
### Troubleshooting
[issue.log](https://github.com/user-attachments/files/24850462/issue.log)
#### Reproduction
just run sipp tool with REGISTER in 2000cps
#### Debugging Data
[New LWP 7527]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/opt/kamailio/sbin/kamailio -m 700 -M 128'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x0000ffff93f3b230 in sr_ssl_ctx_info_callback (ssl=0xffff93b17400,
event=16, ret=1) at tls_domain.c:827
827 if(data->flags & F_TLS_CON_HANDSHAKED) {
Missing separate debuginfos, use: debuginfo-install
bzip2-libs-1.0.6-13.amzn2.0.3.aarch64 elfutils-libelf-0.176-2.amzn2.0.2.aarch64
elfutils-libs-0.176-2.amzn2.0.2.aarch64 glibc-2.26-63.amzn2.aarch64
libcap-2.54-1.amzn2.0.2.aarch64 libgcc-7.3.1-18.amzn2.aarch64
systemd-libs-219-78.amzn2.0.24.aarch64 xz-libs-5.2.2-1.amzn2.0.3.aarch64
zlib-1.2.7-19.amzn2.0.3.aarch64
(gdb) bt
#0 0x0000ffff93f3b230 in sr_ssl_ctx_info_callback (ssl=0xffff93b17400,
event=16, ret=1) at tls_domain.c:827
#1 0x0000ffff93ec1478 in state_machine (s=0xffff93b17400, server=1) at
ssl/statem/statem.c:347
#2 0x0000ffff93ec1284 in ossl_statem_accept (s=0xffff93b17400) at
ssl/statem/statem.c:255
#3 0x0000ffff93ea7cf0 in SSL_do_handshake (s=0xffff93b17400) at
ssl/ssl_lib.c:3732
#4 0x0000ffff93ea38a4 in SSL_accept (s=0xffff93b17400) at ssl/ssl_lib.c:1674
#5 0x0000ffff93f6f390 in tls_accept (c=0xffff93adb950, error=0xffffe2615cd4)
at tls_server.c:457
#6 0x0000ffff93f7aeb4 in tls_h_read_f (c=0xffff93adb950, flags=0xffffe26161b0)
at tls_server.c:1153
#7 0x00000000007754fc in tcp_read_headers (c=0xffff93adb950,
read_flags=0xffffe26161b0) at core/tcp_read.c:451
#8 0x000000000077d5cc in tcp_read_req (con=0xffff93adb950,
bytes_read=0xffffe26161b4, read_flags=0xffffe26161b0) at core/tcp_read.c:1515
#9 0x00000000007837c8 in handle_io (fm=0xffff98ddbe00, events=1, idx=-1) at
core/tcp_read.c:1831
#10 0x0000000000770110 in io_wait_loop_epoll (h=0xb21cf8 <io_w>, t=2, repeat=0)
at core/io_wait.h:1075
#11 0x00000000007866f0 in tcp_receive_loop (unix_sock=22) at
core/tcp_read.c:2031
#12 0x00000000005aa1ec in tcp_init_children (woneinit=0xffffe2616604) at
core/tcp_main.c:5400
#13 0x00000000004386ec in main_loop () at main.c:2030
#14 0x00000000004456e8 in main (argc=5, argv=0xffffe2616b48) at main.c:3406
(gdb)
#### Log Messages
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: tls [tls_server.c:1316]:
tls_h_read_f(): src addr: 192.168.121.107:6475
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: tls [tls_server.c:1319]:
tls_h_read_f(): dst addr: 192.168.121.150:5061
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: <core>
[core/tcp_read.c:1531]: tcp_read_req(): error reading - c: 0xffff93a81810 r:
0xffff93a81938 (-1)
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: tls [tls_util.h:50]:
tls_err_ret(): TLS accept:error:07064041:memory buffer
routines:BUF_MEM_grow:malloc failure (sni: unknown)
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: tls [tls_util.h:50]:
tls_err_ret(): TLS accept:error:14161044:SSL routines:state_machine:internal
error (sni: unknown)
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: tls [tls_server.c:1316]:
tls_h_read_f(): src addr: 192.168.121.107:6104
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: tls [tls_server.c:1319]:
tls_h_read_f(): dst addr: 192.168.121.150:5061
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: <core>
[core/tcp_read.c:1531]: tcp_read_req(): error reading - c: 0xffff9390a7b0 r:
0xffff9390a8d8 (-1)
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: <core>
[core/mem/q_malloc.c:324]: qm_find_free(): qm_find_free(0xffff67f2a000, 21856);
Free fragment not found!
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: <core>
[core/mem/q_malloc.c:463]: qm_malloc(): qm_malloc(0xffff67f2a000, 21856) called
from tls: tls_init.c: ser_realloc(372), module: tls; Free fragment not found!
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: <core>
[core/mem/q_malloc.c:324]: qm_find_free(): qm_find_free(0xffff67f2a000, 16720);
Free fragment not found!
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: <core>
[core/mem/q_malloc.c:463]: qm_malloc(): qm_malloc(0xffff67f2a000, 16720) called
from tls: tls_init.c: ser_malloc(364), module: tls; Free fragment not found!
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: tls [tls_server.c:1312]:
tls_h_read_f(): protocol level error
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: tls [tls_server.c:1312]:
tls_h_read_f(): protocol level error
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: tls [tls_util.h:50]:
tls_err_ret(): TLS accept:error:07064041:memory buffer
routines:BUF_MEM_grow:malloc failure (sni: unknown)
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: tls [tls_util.h:50]:
tls_err_ret(): TLS accept:error:14161044:SSL routines:state_machine:internal
error (sni: unknown)
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: tls [tls_server.c:1316]:
tls_h_read_f(): src addr: 192.168.121.107:59508
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: tls [tls_server.c:1319]:
tls_h_read_f(): dst addr: 192.168.121.150:5061
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: <core>
[core/tcp_read.c:1531]: tcp_read_req(): error reading - c: 0xffff93a8dac0 r:
0xffff93a8dbe8 (-1)
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: tls [tls_util.h:50]:
tls_err_ret(): TLS read:error:1409C041:SSL
routines:ssl3_setup_read_buffer:malloc failure (sni: unknown)
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: tls [tls_server.c:1316]:
tls_h_read_f(): src addr: 192.168.121.107:6094
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: tls [tls_server.c:1319]:
tls_h_read_f(): dst addr: 192.168.121.150:5061
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: <core>
[core/tcp_read.c:1531]: tcp_read_req(): error reading - c: 0xffff938d8190 r:
0xffff938d82b8 (-1)
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: WARNING: <core>
[core/tcp_read.c:1890]: handle_io(): F_TCPCONN connection marked as bad:
0xffff938cf880 id 74598 fd 56 refcnt 1 ([192.168.121.150]:6034 ->
[192.168.121.150]:5061)
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: <core>
[core/mem/q_malloc.c:324]: qm_find_free(): qm_find_free(0xffff67f2a000, 21856);
Free fragment not found!
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: <core>
[core/mem/q_malloc.c:463]: qm_malloc(): qm_malloc(0xffff67f2a000, 21856) called
from tls: tls_init.c: ser_realloc(372), module: tls; Free fragment not found!
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: <core>
[core/mem/q_malloc.c:324]: qm_find_free(): qm_find_free(0xffff67f2a000, 16720);
Free fragment not found!
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: <core>
[core/mem/q_malloc.c:463]: qm_malloc(): qm_malloc(0xffff67f2a000, 16720) called
from tls: tls_init.c: ser_malloc(364), module: tls; Free fragment not found!
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: tls [tls_server.c:1312]:
tls_h_read_f(): protocol level error
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: tls [tls_server.c:1312]:
tls_h_read_f(): protocol level error
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: tls [tls_util.h:50]:
tls_err_ret(): TLS accept:error:1409C041:SSL
routines:ssl3_setup_read_buffer:malloc failure (sni: unknown)
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: tls [tls_util.h:50]:
tls_err_ret(): TLS accept:error:07064041:memory buffer
routines:BUF_MEM_grow:malloc failure (sni: unknown)
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: tls [tls_server.c:1316]:
tls_h_read_f(): src addr: 192.168.121.107:6055
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: tls [tls_util.h:50]:
tls_err_ret(): TLS accept:error:14161044:SSL routines:state_machine:internal
error (sni: unknown)
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: tls [tls_server.c:1319]:
tls_h_read_f(): dst addr: 192.168.121.150:5061
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: tls [tls_server.c:1316]:
tls_h_read_f(): src addr: 192.168.121.107:7645
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: <core>
[core/tcp_read.c:1531]: tcp_read_req(): error reading - c: 0xffff938fbc30 r:
0xffff938fbd58 (-1)
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: tls [tls_server.c:1319]:
tls_h_read_f(): dst addr: 192.168.121.150:5061
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: <core>
[core/tcp_read.c:1531]: tcp_read_req(): error reading - c: 0xffff93982d70 r:
0xffff93982e98 (-1)
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: <core>
[core/mem/q_malloc.c:324]: qm_find_free(): qm_find_free(0xffff67f2a000, 21856);
Free fragment not found!
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: <core>
[core/mem/q_malloc.c:463]: qm_malloc(): qm_malloc(0xffff67f2a000, 21856) called
from tls: tls_init.c: ser_realloc(372), module: tls; Free fragment not found!
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: tls [tls_server.c:1312]:
tls_h_read_f(): protocol level error
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: tls [tls_util.h:50]:
tls_err_ret(): TLS accept:error:07064041:memory buffer
routines:BUF_MEM_grow:malloc failure (sni: unknown)
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: tls [tls_util.h:50]:
tls_err_ret(): TLS accept:error:14161044:SSL routines:state_machine:internal
error (sni: unknown)
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: tls [tls_server.c:1316]:
tls_h_read_f(): src addr: 192.168.121.107:7657
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: tls [tls_server.c:1319]:
tls_h_read_f(): dst addr: 192.168.121.150:5061
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: ERROR: <core>
[core/tcp_read.c:1531]: tcp_read_req(): error reading - c: 0xffff93ab47e0 r:
0xffff93ab4908 (-1)
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: <core>
[core/mem/q_malloc.c:324]: qm_find_free(): qm_find_free(0xffff67f2a000, 21856);
Free fragment not found!
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: <core>
[core/mem/q_malloc.c:463]: qm_malloc(): qm_malloc(0xffff67f2a000, 21856) called
from tls: tls_init.c: ser_realloc(372), module: tls; Free fragment not found!
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: tls [tls_server.c:1312]:
tls_h_read_f(): protocol level error
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: tls [tls_util.h:50]:
tls_err_ret(): TLS accept:error:07064041:memory buffer
routines:BUF_MEM_grow:malloc failure (sni: unknown)
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: tls [tls_util.h:50]:
tls_err_ret(): TLS accept:error:14161044:SSL routines:state_machine:internal
error (sni: unknown)
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: tls [tls_server.c:1316]:
tls_h_read_f(): src addr: 192.168.121.107:6047
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: tls [tls_server.c:1319]:
tls_h_read_f(): dst addr: 192.168.121.150:5061
Jan 22 10:29:49 gds-sip-150 sipproxy[7525]: ERROR: <core>
[core/tcp_read.c:1531]: tcp_read_req(): error reading - c: 0xffff939122d0 r:
0xffff939123f8 (-1)
Jan 22 10:29:49 gds-sip-150 sipproxy[7527]: INFO: tls [tls_util.c:112]:
tls_openssl_clear_errors(): clearing leftover error before SSL_* calls:
error:0F066041:common libcrypto routines:CRYPTO_set_ex_data:malloc failure
//some other tcp_read worker's logs are skipped here ... --- the complete
log file is attached
//only tcp_read[7527] 's log are shown here ...
Jan 22 10:29:50 gds-sip-150 sipproxy[7518]: ALERT: <core> [main.c:814]:
handle_sigs(): child process 7527 exited by a signal 11
Jan 22 10:29:50 gds-sip-150 sipproxy[7518]: ALERT: <core> [main.c:818]:
handle_sigs(): core was generated
Jan 22 10:29:50 gds-sip-150 sipproxy[7518]: INFO: <core> [main.c:841]:
handle_sigs(): terminating due to SIGCHLD
Jan 22 10:29:50 gds-sip-150 sipproxy[7521]: INFO: <core> [main.c:897]:
sig_usr(): signal 15 received
Jan 22 10:29:50 gds-sip-150 sipproxy[7528]: INFO: <core> [main.c:897]:
sig_usr(): signal 15 received
Jan 22 10:29:50 gds-sip-150 sipproxy[7523]: INFO: <core> [main.c:897]:
sig_usr(): signal 15 received
Jan 22 10:29:50 gds-sip-150 sipproxy[7520]: INFO: <core> [main.c:897]:
sig_usr(): signal 15 received
Jan 22 10:29:50 gds-sip-150 sipproxy[7522]: INFO: <core> [main.c:897]:
sig_usr(): signal 15 received
Jan 22 10:29:52 gds-sip-150 sipproxy[7518]: INFO: <core> [core/sctp_core.c:53]:
sctp_core_destroy(): SCTP API not initialized
#### SIP Traffic
None
### Possible Solutions
None
### Additional Information
# /opt/kamailio/sbin/kamailio -V
version: kamailio 4.4.7 (aarch64/linux)
flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, DISABLE_NAGLE,
USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC,
TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT-NOSMP,
USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16,
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 on 09:25:13 Jan 24 2026 with gcc 7.3.1
* **Operating System**:
# lsb_release -a
-bash: lsb_release: command not found
# uname -a
Linux gds-sip-150 4.14.320-243.544.amzn2.aarch64 #1 SMP Tue Aug 1 21:03:02 UTC
2023 aarch64 aarch64 aarch64 GNU/Linux
--
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/4567
You are receiving this because you are subscribed to this thread.
Message ID: <kamailio/kamailio/issues/[email protected]>_______________________________________________
Kamailio - Development Mailing List -- [email protected]
To unsubscribe send an email to [email protected]
Important: keep the mailing list in the recipients, do not reply only to the
sender!
