14 Sep
2023
14 Sep
'23
3:58 a.m.
### Description
All as per https://github.com/kamailio/kamailio/issues/3563
#### Debugging Data
```
PID: 4209 (kamailio)
UID: 990 (kamailio)
GID: 988 (kamailio)
Signal: 6 (ABRT)
Timestamp: Thu 2023-09-14 00:20:29 UTC (32min ago)
Command Line: /usr/sbin/kamailio -DD -P /run/kamailio/kamailio.pid -f
/etc/kamailio/kamailio.cfg -m 256 -M 8 --atexit=no
Executable: /usr/sbin/kamailio
Control Group: /system.slice/kamailio.service
Unit: kamailio.service
Slice: system.slice
Boot ID: 3fc4251c606f4c6183610573f44c46ba
Machine ID: 16e913e686424f13b970f9b1044cc6b3
Hostname: kamrtc01.voiceflex.com
Storage:
/var/lib/systemd/coredump/core.kamailio.990.3fc4251c606f4c6183610573f44c46ba.4209.1694650829000000.zst
(present)
Size on Disk: 3.3M
Message: Process 4209 (kamailio) of user 990 dumped core.
Stack trace of thread 4209:
#0 0x00007f1338ea158c __pthread_kill_implementation (libc.so.6 +
0xa158c)
#1 0x00007f1338e54d46 raise (libc.so.6 + 0x54d46)
#2 0x00007f1338e287f3 abort (libc.so.6 + 0x287f3)
#3 0x00000000007164db qm_debug_check_frag (kamailio + 0x3164db)
#4 0x000000000071a703 qm_free (kamailio + 0x31a703)
#5 0x0000000000725209 qm_shm_free (kamailio + 0x325209)
#6 0x00007f13370043d6 ser_free (tls.so + 0x313d6)
#7 0x00007f1337dbc1ee state_machine.part.0 (libssl.so.3 + 0x621ee)
#8 0x00007f133702c584 tls_accept (tls.so + 0x59584)
#9 0x00007f13370378be tls_h_read_f (tls.so + 0x648be)
#10 0x00000000006c79bc tcp_read_headers (kamailio + 0x2c79bc)
#11 0x00000000006cfb94 tcp_read_req (kamailio + 0x2cfb94)
#12 0x00000000006d4cc3 handle_io (kamailio + 0x2d4cc3)
#13 0x00000000006c271d io_wait_loop_epoll (kamailio + 0x2c271d)
#14 0x00000000006d7a47 tcp_receive_loop (kamailio + 0x2d7a47)
#15 0x00000000006b7689 tcp_init_children (kamailio + 0x2b7689)
#16 0x000000000042fae9 main_loop (kamailio + 0x2fae9)
#17 0x0000000000439969 main (kamailio + 0x39969)
#18 0x00007f1338e3feb0 __libc_start_call_main (libc.so.6 + 0x3feb0)
#19 0x00007f1338e3ff60 __libc_start_main@@GLIBC_2.34 (libc.so.6 +
0x3ff60)
#20 0x000000000041dc65 _start (kamailio + 0x1dc65)
ELF object binary architecture: AMD x86-64
(gdb) bt full
#0 0x00007f1338ea158c in __pthread_kill_implementation () from /lib64/libc.so.6
No symbol table info available.
#1 0x00007f1338e54d46 in raise () from /lib64/libc.so.6
No symbol table info available.
#2 0x00007f1338e287f3 in abort () from /lib64/libc.so.6
No symbol table info available.
#3 0x00000000007164db in qm_debug_check_frag (qm=0x7f1326fd3000, f=0x7f1327793800,
file=0x7f133704afe1 "tls: tls_init.c", line=405, efile=0x8a1659
"core/mem/q_malloc.c", eline=511) at core/mem/q_malloc.c:129
p = 0x7f1327732cd0
__func__ = "qm_debug_check_frag"
#4 0x000000000071a703 in qm_free (qmp=0x7f1326fd3000, p=0x7f1327793838,
file=0x7f133704afe1 "tls: tls_init.c", func=0x7f133704cae0 <__func__.0>
"ser_free", line=405, mname=0x7f133704af52 "tls") at
core/mem/q_malloc.c:511
qm = 0x7f1326fd3000
f = 0x7f1327793800
size = 140729200190032
next = 0x1
prev = 0x7f132700c6c8
__func__ = "qm_free"
#5 0x0000000000725209 in qm_shm_free (qmp=0x7f1326fd3000, p=0x7f1327793838,
file=0x7f133704afe1 "tls: tls_init.c", func=0x7f133704cae0 <__func__.0>
"ser_free", line=405, mname=0x7f133704af52 "tls") at
core/mem/q_malloc.c:1350
No locals.
#6 0x00007f13370043d6 in ser_free (ptr=0x7f1327793838, fname=0x7f1337dd6146
"crypto/packet.c", fline=509) at tls_init.c:405
__func__ = "ser_free"
#7 0x00007f1337dbc1ee in WPACKET_cleanup (pkt=0x7ffe11fca310) at crypto/packet.c:509
sub = <optimized out>
parent = 0x0
#8 write_state_machine (s=0x7f1327f185e0) at ssl/statem/statem.c:873
post_work = <optimized out>
mt = 2
pkt = {buf = 0x7f1327da93e0, staticbuf = 0x0, curr = 122, written = 122, maxsize =
18446744073709551615, subs = 0x7f1327793838, endfirst = 0}
ret = <optimized out>
pre_work = 0x7f1337dc9260 <ossl_statem_server_pre_work>
get_construct_message_f = 0x7f1337dc2920
<ossl_statem_server_construct_message>
confunc = 0x7f1337dca970 <tls_construct_server_hello>
st = 0x7f1327f18628
transition = 0x7f1337dc9cf0 <ossl_statem_server_write_transition>
cb = 0x7f1336ff1e72 <sr_ssl_ctx_info_callback>
st = <optimized out>
ret = <optimized out>
transition = <optimized out>
pre_work = <optimized out>
post_work = <optimized out>
get_construct_message_f = <optimized out>
cb = <optimized out>
confunc = <optimized out>
mt = <optimized out>
pkt = {buf = <optimized out>, staticbuf = <optimized out>, curr =
<optimized out>, written = <optimized out>, maxsize = <optimized out>,
subs = <optimized out>, endfirst = <optimized out>}
__func__ = {<optimized out> <repeats 20 times>}
tmpret = <optimized out>
#9 state_machine (s=0x7f1327f185e0, server=<optimized out>) at
ssl/statem/statem.c:451
buf = 0x0
cb = <optimized out>
st = <optimized out>
ret = <optimized out>
ssret = <optimized out>
__func__ = {<optimized out> <repeats 14 times>}
#10 0x00007f133702c584 in tls_accept (c=0x7f1327b9eed8, error=0x7ffe11fea584) at
tls_server.c:470
ret = 0
ssl = 0x7f1327f185e0
cert = 0x1
tls_c = 0x7f13277de980
tls_log = 32766
__func__ = "tls_accept"
#11 0x00007f13370378be in tls_h_read_f (c=0x7f1327b9eed8, flags=0x7ffe11fea9c0) at
tls_server.c:1175
r = 0x7f1327b9f000
bytes_free = 16383
bytes_read = 617
read_size = 16383
ssl_error = 0
ssl_read = 0
ssl = 0x7f1327f185e0
rd_buf =
"\026\003\001\002d\001\000\002`\003\003\037\017\360\302a4J\025k\341\210\000B\216ݖ\023\243#\n?\267]\214A\017\370P\374\063a(
\241^2\243\006\360>\334\033(+\363d\b\350$\rt\311\321\351\205l\024\021\322|z\\o\235\353\000
\372\372\023\001\023\002\023\003\300+\300/\300,\300\060̨̩\300\023\300\024\000\234\000\235\000/\000\065\001\000\001\367\252\252\000\000\000\005\000\005\001\000\000\000\000\000\n\000\n\000\b\n\n\000\035\000\027\000\030\000#\000\000\000\033\000\003\002\000\002\000\027\000\000\000+\000\a\006\312\312\003\004\003\003\000\063\000+\000)\n\n\000\001\000\000\035\000
2\326\305\"봉\332\366\363SV\036ɩ\322u\316\061\030\225\353Yi"...
wr_buf =
"\027\003\003\001\032j\276\373Ӥw:1\221<uUV;\357&\211N\001#M\"`\234\370\365\213C\265B\004\006y\250/\246Nd\334h\f\343\065:k\341\321\023\257\360T\020,\255\271\235\201_\003\272\005\237A\356\326\313\355\351\340D^f\023_J\223\360\303:\310gi\313v\306\025\352d\360\343\246/,-\207+\301x\217\246F\300\361\064F\212\377YN\323\065A\323\365Zɞb!3\"8\024\235\066\033\311\t\361\334[\225\227\004c\230\223\210ʑL\213\331\027\022\370\257\265\352s\225\066\370jc\256(\246@\"\245f%\335\026\071\232\374\065\066ar\265\066B\213\024cT/\356\315`\233\350\234\027N\375\254]\360\064\064\305\070z\355"...
rd = {buf = 0x7ffe11fda580 "\026\003\001\002d\001", pos = 617, used =
617, size = 65536}
wr = {
buf = 0x7ffe11fca580
"\027\003\003\001\032j\276\373Ӥw:1\221<uUV;\357&\211N\001#M\"`\234\370\365\213C\265B\004\006y\250/\246Nd\334h\f\343\065:k\341\321\023\257\360T\020,\255\271\235\201_\003\272\005\237A\356\326\313\355\351\340D^f\023_J\223\360\303:\310gi\313v\306\025\352d\360\343\246/,-\207+\301x\217\246F\300\361\064F\212\377YN\323\065A\323\365Zɞb!3\"8\024\235\066\033\311\t\361\334[\225\227\004c\230\223\210ʑL\213\331\027\022\370\257\265\352s\225\066\370jc\256(\246@\"\245f%\335\026\071\232\374\065\066ar\265\066B\213\024cT/\356\315`\233\350\234\027N\375\254]\360\064",
<incomplete sequence \305>..., pos = 0, used = 0, size = 65536}
tls_c = 0x7f13277de980
enc_rd_buf = 0x0
n = 0
flush_flags = 0
err_src = 0x7f13370545a0 "TLS read:"
ip_buf = '\000' <repeats 63 times>
x = 954920009
tls_dbg = 4095
__func__ = "tls_h_read_f"
#12 0x00000000006c79bc in tcp_read_headers (c=0x7f1327b9eed8, read_flags=0x7ffe11fea9c0)
at core/tcp_read.c:441
bytes = 65535
remaining = 0
p = 0x7f1327a0789b "l'\244\016v \247T~ \267E\"l\350Um
\356Uj'\260\032-z\261\025+z\267\020\062+\340E'c\340\027~\177\371\030|-\342\r*y\341E)*\262\025|y\265\025!l\357Eg>\275Rz=\351\026/~\331*^\"\270Oht\364a\\\005\370c^"
r = 0x7f1327b9f000
mc = 32531
body_len = 10144
mfline = 0x7f13276af2b8
"\201\376\002\367\025p\362%G5\265lF$\267w5\003\233U/\a\227Gg\004\221\v{\025\220Py\021\233U;\023\235H5#\273u:B\334\025\030z\244LtJ\322v\\
\335\027;@\335rF#\322Fc@\313My\002\203U\"B\233\v|\036\204Dy\031\226\036w\002\223Kv\030\317_,\030\265\021w;\313\022-B\303\022!}\370ht\b\337cz\002\205Dg\024\201\037\065G\302(\037$\235\037\065L\201LeJ\205@w\002\206FU\a\227Gg\004\221\v{\025\220Py\021\233U;\023\235H+}\370cg\037\237\037\065L\201LeJ\205@w\002\206FU\a\227Gg\004\221\v{\025\220Py\021\233U"...
mtransid = {s = 0x7f1327a072d0 "C", len = 664826600}
__func__ = "tcp_read_headers"
#13 0x00000000006cfb94 in tcp_read_req (con=0x7f1327b9eed8, bytes_read=0x7ffe11fea9c4,
read_flags=0x7ffe11fea9c0) at core/tcp_read.c:1469
bytes = -1
total_bytes = 0
resp = 1
size = 0
req = 0x7f1327b9f000
dst = {send_sock = 0x7f1327a072d0, to = {s = {sa_family = 0, sa_data =
"\000\020\002\000\000\000\001\000\376\021\022\000\000"}, sin = {sin_family = 0,
sin_port = 4096, sin_addr = {s_addr = 2}, sin_zero =
"\001\000\376\021\022\000\000"}, sin6 = {sin6_family = 0, sin6_port = 4096,
sin6_flowinfo = 2, sin6_addr = {__in6_u = {__u6_addr8 =
"\001\000\376\021\022\000\000\000ಙ\000\000\000\000", __u6_addr16 = {1, 4606,
18, 0, 45792, 153, 0, 0}, __u6_addr32 = {301858817, 18, 10072800,
0}}}, sin6_scope_id = 955546528}, sas = {ss_family = 0,
__ss_padding =
"\000\020\002\000\000\000\001\000\376\021\022\000\000\000ಙ\000\000\000\000\000\240{\364\070\023\177\000\000ht\240'\023\177\000\000\000\251\376\021\353:\"%\240\264\231\000\000\000\000\000\024\000\000\000\000\000\000\000\001\000\000\000\001\000\000\000\023\000\000\000\376\177\000\000-uQ\000\000\000\000\000\270\251\376\021\376\177\000\000\b",
'\000' <repeats 22 times>,
__ss_align = 140729200322640}}, id = 1, send_flags = {f = 0, blst_imask =
0}, proto = 48 '0', proto_pad0 = -88 '\250', proto_pad1 = 4606}
c = 108 'l'
ret = 0
__func__ = "tcp_read_req"
#14 0x00000000006d4cc3 in handle_io (fm=0x7f1338799c88, events=1, idx=-1) at
core/tcp_read.c:1780
ret = 8
--Type <RET> for more, q to quit, c to continue without paging--
n = 8
read_flags = RD_CONN_SHORT_READ
con = 0x7f1327b9eed8
s = 19
resp = 1
t = 623000299
ee = 0x0
__func__ = "handle_io"
#15 0x00000000006c271d in io_wait_loop_epoll (h=0x99b2e0 <io_w>, t=2, repeat=0) at
core/io_wait.h:1070
n = 1
r = 0
fm = 0x7f1338799c88
revents = 1
__func__ = "io_wait_loop_epoll"
#16 0x00000000006d7a47 in tcp_receive_loop (unix_sock=43) at core/tcp_read.c:1976
__func__ = "tcp_receive_loop"
#17 0x00000000006b7689 in tcp_init_children (woneinit=0x7ffe11fead7c) at
core/tcp_main.c:5239
r = 1
i = 3
reader_fd_1 = 43
pid = 0
si_desc = "tcp receiver
(generic)\000\000\000\000\000\000\000\000\000\000\023e\204\000\000\000\000\000\033\000\000\000\000\000\000\000\240{\364\070\023\177\000\000\000\000\000\020\000\000\000\000\020\255\376\021\376\177\000\000\034\003e\000\000\000\000\000\020\255\376\021\376\177\000\000\345\030n\000\000\000\000\000\300\254\376\021\376\177\000\000\252\264~\000\000\000\000\000\023e\204\000\000\000\000\000\310\311\000'
\000\000"
si = 0x0
__func__ = "tcp_init_children"
#18 0x000000000042fae9 in main_loop () at main.c:1851
i = 4
pid = 4200
si = 0x0
si_desc = "udp receiver child=3
sock=172.16.128.55:5090\000\062\216\366\340\255\376\021\376\177\000\000\000\000\000\000\000\000\000\000@\263\376\021\376\177\000\000\023e\204\000\000\000\000\000\033\000\000\000\000\000\000\000X_j8\023\177\000\000\000\000\000\020\000\000\000\000:|\364\070\023\177\000\000\060\000\000\000\060\000\000\000\370\256\376\021\376\177\000"
nrprocs = 4
woneinit = 1
__func__ = "main_loop"
#19 0x0000000000439969 in main (argc=11, argv=0x7ffe11feb458) at main.c:3086
cfg_stream = 0xa20380
c = -1
r = 0
tmp = 0x7ffe11febea4 ""
tmp_len = 0
port = 0
proto = 0
ahost = 0x0
aport = 0
options = 0x8322d8
":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 = 444252184
rfd = 4
debug_save = 0
debug_flag = 0
dont_fork_cnt = 2
n_lst = 0x200000064
p = 0x0
st = {st_dev = 24, st_ino = 891, st_nlink = 2, st_mode = 16832, st_uid = 990,
st_gid = 988, __pad0 = 0, st_rdev = 0, st_size = 100, st_blksize = 4096, st_blocks = 0,
st_atim = {tv_sec = 1694643229, tv_nsec = 729000000}, st_mtim = {tv_sec = 1694648370,
tv_nsec = 514732637}, st_ctim = {tv_sec = 1694648370, tv_nsec = 514732637},
__glibc_reserved = {0, 0, 0}}
tbuf =
"\331l\030\071\023\177\000\000\070+\025\071\023\177\000\000а\376\021\376\177\000\000\a\000\000\000\000\000\000\000\330\030\025\071\023\177\000\000\a\000\000\000#\000\000\000\060z\030\071\023\177\000\000\245F\026\071\023\177\000\000\000\000\000\000\000\000\000\000\220Y\026\071\023\177\000\000\070\000\341\070\023\177\000\000\000\212\024\071\023\177\000\000\000\000\000\000\000\000\000\000\240\260\376\021\376\177\000\000\360n\030\071\023\177\000\000\330*\025\071\023\177\000\000\330*\025\071\023\177\000\000\000\000\000\000\000\000\000\000ؘ\024\071\023\177\000\000\240\260\376\021\376\177\000\000\220\205\030\071\023\177\000\000\000\020\025\071\023\177\000\000\022\034\025\071\023\177\000\000\066\021\026\071\023\177\000\000\344#\340\070\023\177\000\000\272\250"...
option_index = 12
long_options = {{name = 0x834976 "help", has_arg = 0, flag = 0x0, val =
104}, {name = 0x82f4f4 "version", has_arg = 0, flag = 0x0, val = 118}, {name =
0x83497b "alias", has_arg = 1, flag = 0x0, val = 1024}, {name = 0x834981
"subst", has_arg = 1, flag = 0x0, val = 1025}, {name = 0x834987
"substdef", has_arg = 1, flag = 0x0, val = 1026}, {name = 0x834990
"substdefs", has_arg = 1, flag = 0x0, val = 1027}, {
name = 0x83499a "server-id", has_arg = 1, flag = 0x0, val = 1028},
{name = 0x8349a4 "loadmodule", has_arg = 1, flag = 0x0, val = 1029}, {name =
0x8349af "modparam", has_arg = 1, flag = 0x0, val = 1030}, {name = 0x8349b8
"log-engine", has_arg = 1, flag = 0x0, val = 1031}, {name = 0x8349c3
"debug", has_arg = 1, flag = 0x0, val = 1032}, {name = 0x8349c9
"cfg-print", has_arg = 0, flag = 0x0, val = 1033}, {
name = 0x8349d3 "atexit", has_arg = 1, flag = 0x0, val = 1034},
{name = 0x8349da "all-errors", has_arg = 0, flag = 0x0, val = 1035}, {name =
0x0, has_arg = 0, flag = 0x0, val = 0}}
__func__ = "main"
```
#### Log Messages
Sep 14 00:20:29 kamrtc01 /usr/sbin/kamailio[4209]: CRITICAL: <core>
[core/mem/q_malloc.c:519]: qm_free(): BUG: freeing already freed pointer (0x7f13277938b0),
called from tls: tls_init.c: ser_free(405), first free tls: tls_init.c: ser_free(405) -
ignoring
Sep 14 00:20:29 kamrtc01 /usr/sbin/kamailio[4209]: CRITICAL: <core>
[core/mem/q_malloc.c:123]: qm_debug_check_frag(): BUG: qm: fragm. 0x7f1327793800 (address
0x7f1327793838) beginning overwritten (0)! Memory allocator was called from tls:
tls_init.c:405. Fragment marked by (null):0. Exec from core/mem/q_malloc.c:511.
Sep 14 00:20:29 kamrtc01 systemd[1]: Started Process Core Dump (PID 5579/UID 0).
Sep 14 00:20:29 kamrtc01 systemd-coredump[5580]: Process 4209 (kamailio) of user 990
dumped core.#012#012Stack trace of thread 4209:#012#0 0x00007f1338ea158c
__pthread_kill_implementation (libc.so.6 + 0xa158c)#012#1 0x00007f1338e54d46 raise
(libc.so.6 + 0x54d46)#012#2 0x00007f1338e287f3 abort (libc.so.6 + 0x287f3)#012#3
0x00000000007164db qm_debug_check_frag (kamailio + 0x3164db)#012#4 0x000000000071a703
qm_free (kamailio + 0x31a703)#012#5 0x0000000000725209 qm_shm_free (kamailio +
0x325209)#012#6 0x00007f13370043d6 ser_free (tls.so + 0x313d6)#012#7 0x00007f1337dbc1ee
state_machine.part.0 (libssl.so.3 + 0x621ee)#012#8 0x00007f133702c584 tls_accept (tls.so
+ 0x59584)#012#9 0x00007f13370378be tls_h_read_f (tls.so + 0x648be)#012#10
0x00000000006c79bc tcp_read_headers (kamailio + 0x2c79bc)#012#11 0x00000000006cfb94
tcp_read_req (kamailio + 0x2cfb94)#012#12 0x00000000006d4cc3 handle_io (kamailio +
0x2d4cc3)#012#13 0x00000000006c271d io_wait_loop_epoll (kamailio + 0x2c271d)#012#14
0x00000000006d7a47 tcp_receive_loop (kamailio + 0x2d7a47)#012#15 0x00000000006b7689
tcp_init_children (kamailio + 0x2b7689)#012#16 0x000000000042fae9 main_loop (kamailio +
0x2fae9)#012#17 0x0000000000439969 main (kamailio + 0x39969)#012#18 0x00007f1338e3feb0
__libc_start_call_main (libc.so.6 + 0x3feb0)#012#19 0x00007f1338e3ff60
__libc_start_main@@GLIBC_2.34 (libc.so.6 + 0x3ff60)#012#20 0x000000000041dc65 _start
(kamailio + 0x1dc65)#012ELF object binary architecture: AMD x86-64
#### SIP Traffic
There is sip traffic logged via the siptrace module to homer but the only packets logged
are REGISTERs and I suspect this bug is in TLS somewhere further up the chain before it
ever gets to sip traffic.
--
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/3566
You are receiving this because you are subscribed to this thread.
Message ID: <kamailio/kamailio/issues/3566(a)github.com>