Kamailio 5.5 crashed when sending reply (bt full below). Before the crash there had been several mysql related error messages ("Lost connection to MySQL server during query" and "Too many connections") in syslog when async worker tried to insert accounting data. So perhaps this core dump has something to do with that.
-- Juha
Reading symbols from /usr/bin/sip-proxy...done. [New LWP 21324] [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/bin/sip-proxy -f /etc/sip-proxy/sip-proxy.cfg -P /run/sip-proxy/sip-proxy.'. Program terminated with signal SIGSEGV, Segmentation fault. #0 0x00007fd274ce3b6e in run_trans_callbacks_internal (cb_lst=0x7fd2532503a8, type=512, trans=0x7fd253250330, params=0x7fff9b8eb2b0) at t_hooks.c:254 254 t_hooks.c: No such file or directory. (gdb) bt full #0 0x00007fd274ce3b6e in run_trans_callbacks_internal (cb_lst=0x7fd2532503a8, type=512, trans=0x7fd253250330, params=0x7fff9b8eb2b0) at t_hooks.c:254 cbp = 0x10 backup_from = 0x5613ccfb37f0 <def_list+16> backup_to = 0x5613ccfb37f8 <def_list+24> backup_dom_from = 0x5613ccfb3800 <def_list+32> backup_dom_to = 0x5613ccfb3808 <def_list+40> backup_uri_from = 0x5613ccfb37e0 <def_list> backup_uri_to = 0x5613ccfb37e8 <def_list+8> backup_xavps = 0x5613ccf56270 <_xavp_list_head> backup_xavus = 0x5613ccf56278 <_xavu_list_head> backup_xavis = 0x5613ccf56280 <_xavi_list_head> __func__ = "run_trans_callbacks_internal" #1 0x00007fd274ce41f7 in run_trans_callbacks_with_buf (type=512, rbuf=0x7fd253250400, req=0x7fd252d6dd20, repl=0x7fd2758bf0b0, flags=0) at t_hooks.c:303 params = {req = 0x7fd252d6dd20, rpl = 0x7fd2758bf0b0, param = 0x7fd254760f60, code = 486, flags = 0, branch = 0, t_rbuf = 0x7fd253250400, dst = 0x7fd253250450, send_buf = { s = 0x7fd25325b9f0 "@", len = 579}} trans = 0x7fd253250330 #2 0x00007fd274c88c15 in relay_reply (t=0x7fd253250330, p_msg=0x7fd2758bf0b0, branch=0, msg_status=486, cancel_data=0x7fff9b8eb580, do_put_on_wait=1) at t_reply.c:2133 relay = 0 save_clone = 0 buf = 0x7fd275ca0ff0 "SIP/2.0 486 Busy Here\r\nTo: sip:XXXXX@XXXXX.com;user=phone;tag=h7g4Esbg_11002529899813\r\nFrom: sip:XXXXX@XXXXX;tag=as6964f29d\r\nCal"... res_len = 579 relayed_code = 486 relayed_msg = 0x7fd2758bf0b0 reply_bak = 0x7fd2510f1000 bm = {to_tag_val = {s = 0x7fd25216e4c0 "@\003", len = 1377234752}} totag_retr = 0 reply_status = RPS_COMPLETED uas_rb = 0x7fd253250400 to_tag = 0x7fd25216e820 reason = {s = 0x7fd25216e830 "0", len = 1394935248} onsend_params = {req = 0x9b8eb420, rpl = 0x7fd274c6b10d <futex_get+40>, param = 0x1, code = 1359984720, flags = 32722, branch = 0, t_rbuf = 0x7fff9b8eb460, dst = 0xa0679800, send_buf = { s = 0x19b8eb450 <error: Cannot access memory at address 0x19b8eb450>, len = 1359984720}} ip = {af = 2609820752, len = 32767, u = {addrl = {94643040895493, 0}, addr32 = {3436528133, 22035, 0, 0}, addr16 = {16901, 52437, 22035, 0, 0, 0, 0, 0}, addr = "\005B\325\314\023V\000\000\000\000\000\000\000\000\000"}} __func__ = "relay_reply" #3 0x00007fd274c8de6b in reply_received (p_msg=0x7fd2758bf0b0) at t_reply.c:2680 msg_status = 486 last_uac_status = 180 ack = 0x7fd25216e830 "0" ack_len = 459 branch = 0 reply_status = 32722 onreply_route = 2 cancel_data = {cancel_bitmap = 0, reason = {cause = 0, u = {text = {s = 0x0, len = 1977055608}, e2e_cancel = 0x0, packed_hdrs = {s = 0x0, len = 1977055608}}}} uac = 0x7fd2532505c0 t = 0x7fd253250330 lack_dst = {send_sock = 0x40, to = {s = {sa_family = 49168, sa_data = "\207u\322\177\000\000\220\266\216\233\377\177\000"}, sin = {sin_family = 49168, sin_port = 30087, sin_addr = { s_addr = 32722}, sin_zero = "\220\266\216\233\377\177\000"}, sin6 = {sin6_family = 49168, sin6_port = 30087, sin6_flowinfo = 32722, sin6_addr = {__in6_u = { __u6_addr8 = "\220\266\216\233\377\177\000\000L=\215s\322\177\000", __u6_addr16 = {46736, 39822, 32767, 0, 15692, 29581, 32722, 0}, __u6_addr32 = {2609821328, 32767, 1938636108, 32722}}}, sin6_scope_id = 1971831024}, sas = {ss_family = 49168, __ss_padding = "\207u\322\177\000\000\220\266\216\233\377\177\000\000L=\215s\322\177\000\000\360\300\207u\322\177", '\000' <repeats 13 times>, "\b\000\000\000\000\060Z\264u\322\177\000\000\213\t\342\316\023V\000\000;\b\342\316\023V\000\000\020\313\320\000\000\000\000\000\020\000\000\000\000\000\000\000I\001\000\000\000\000\000\000\000\230g\240\210\347A\357\300\266\216\233\377\177\000\000\000\230g\240\210\347", <incomplete sequence \357>, __ss_align = 0}}, id = 0, send_flags = {f = 0, blst_imask = 0}, proto = 0 '\000', proto_pad0 = 0 '\000', proto_pad1 = 0} backup_user_from = 0x5613ccfb37f0 <def_list+16> backup_user_to = 0x5613ccfb37f8 <def_list+24> backup_domain_from = 0x5613ccfb3800 <def_list+32> backup_domain_to = 0x5613ccfb3808 <def_list+40> backup_uri_from = 0x5613ccfb37e0 <def_list> backup_uri_to = 0x5613ccfb37e8 <def_list+8> backup_xavps = 0x5613ccf56270 <_xavp_list_head> backup_xavus = 0x5613ccf56278 <_xavu_list_head> backup_xavis = 0x5613ccf56280 <_xavi_list_head> replies_locked = 1 branch_ret = 0 prev_branch = 1971830800 blst_503_timeout = 32722 hf = 0xb5c750 onsend_params = {req = 0x7fff9b8eb5e0, rpl = 0xef41e788a0679800, param = 0x30, code = 0, flags = 0, branch = 0, t_rbuf = 0x0, dst = 0x7fd27d972cb0 <__syslog>, send_buf = { s = 0x5613ccec69b3 "INFO", len = -1603823616}} ctx = {rec_lev = 0, run_flags = 2, last_retcode = -1, jmp_env = {{__jmpbuf = {0, -5133089567146157739, 0, 140542026919088, 94643042412979, 536870912, -5133089567232140971, -1505551737941960363}, __mask_was_saved = 0, __saved_mask = {__val = {140735803210560, 13683472, 7765887371, 140735803209568, 94643041089583, 0, 17240315422543681536, 0, 0, 0, 0, 94643042412979, 17240315422543681536, 140735803209872, 94643041372964, 2866715017336}}}}} bctx = 0x7fd27587c010 keng = 0x0 ret = 0 evname = {s = 0x7fd274d3696f "on_sl_reply", len = 11} __func__ = "reply_received" #4 0x00005613ccbba0d4 in do_forward_reply (msg=0x7fd2758bf0b0, mode=0) at core/forward.c:764 new_buf = 0x0 dst = {send_sock = 0x0, to = {s = {sa_family = 0, sa_data = '\000' <repeats 13 times>}, sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}, sas = {ss_family = 0, __ss_padding = '\000' <repeats 117 times>, __ss_align = 0}}, id = 0, send_flags = {f = 0, blst_imask = 0}, proto = 0 '\000', proto_pad0 = 0 '\000', proto_pad1 = 0} new_len = 0 r = 2 ip = {af = 1, len = 6356993, u = {addrl = {140735803210560, 140541891965104}, addr32 = {2609822528, 32767, 1972105392, 32722}, addr16 = {47936, 39822, 32767, 0, 61616, 30091, 32722, 0}, addr = "@\273\216\233\377\177\000\000\260\360\213u\322\177\000"}} s = 0xef41e788a0679800 <error: Cannot access memory at address 0xef41e788a0679800> len = -1685145520 __func__ = "do_forward_reply" #5 0x00005613ccbbc23c in forward_reply (msg=0x7fd2758bf0b0) at core/forward.c:865 No locals. #6 0x00005613ccc5eea9 in receive_msg ( buf=0x5613cee206f0 "SIP/2.0 486 Busy Here\r\nTo: sip:XXXXX@XXXXX;user=phone;tag=h7g4Esbg_11002529899813\r\nFrom: sip:XXXXX@XXXXX;tag=as6964f29d\r\nCal"..., len=667, rcv_info=0x7fd253b7cad8) at core/receive.c:587 msg = 0x7fd2758bf0b0 ctx = {rec_lev = 0, run_flags = 0, last_retcode = 1, jmp_env = {{__jmpbuf = {0, -5133089566915471019, 0, 140542026919088, 94643042412979, 536870912, -5133089567001454251, -1505551737941960363}, __mask_was_saved = 0, __saved_mask = {__val = {94643073835016, 65535, 17240315422543681536, 18446744073709551536, 2, 0, 140542026919088, 94643042412979, 536870912, 140735803211024, 94643040635195, 140735803211696, 65535, 65536, 4095, 140735803211580}}}}} bctx = 0x0 ret = 1 tvb = {tv_sec = 0, tv_usec = 0} tve = {tv_sec = 0, tv_usec = 0} diff = 0 inb = {s = 0x5613cee206f0 "SIP/2.0 486 Busy Here\r\nTo: sip:XXXXX@XXXXX;user=phone;tag=h7g4Esbg_11002529899813\r\nFrom: sip:XXXXX@XXXXX;tag=as6964f29d\r\nCal"..., len = 667} netinfo = {data = {s = 0x5613cee206f0 "SIP/2.0 486 Busy Here\r\nTo: sip:XXXXX@XXXXX;user=phone;tag=h7g4Esbg_11002529899813\r\nFrom: <sip:XXXXX@XXXXX;tag=as6964f29d\r\nCal"..., len = 667}, rcv = 0x7fd253b7cad8, dst = 0x0} keng = 0x0 evp = {data = 0x7fff9b8eba90, obuf = {s = 0x0, len = 0}, rcv = 0x7fd253b7cad8, dst = 0x0, req = 0x0, rpl = 0x0, rplcode = 0, mode = 0} cidlockidx = 0 cidlockset = 0 errsipmsg = 0 exectime = 0 __func__ = "receive_msg" #7 0x00005613ccd1cf15 in receive_tcp_msg (tcpbuf=0x7fd253b7ce60 "SIP/2.0 486 Busy Here\r\nTo: sip:XXXXX@XXXXX;user=phone;tag=h7g4Esbg_11002529899813\r\nFrom: sip:XXXXX@XXXXX;tag=as6964f29d\r\nCal"..., len=667, rcv_info=0x7fd253b7cad8, con=0x7fd253b7cac0) at core/tcp_read.c:1424 buf = 0x5613cee206f0 "SIP/2.0 486 Busy Here\r\nTo: sip:XXXXX@XXXXX;user=phone;tag=h7g4Esbg_11002529899813\r\nFrom: sip:XXXXX@XXXXX;tag=as6964f29d\r\nCal"... bsize = 65535 blen = 65535 __func__ = "receive_tcp_msg" #8 0x00005613ccd1f554 in tcp_read_req (con=0x7fd253b7cac0, bytes_read=0x7fff9b8ebf34, read_flags=0x7fff9b8ebf3c) at core/tcp_read.c:1607 bytes = 667 total_bytes = 667 resp = 1 size = 0 req = 0x7fd253b7cbe8 dst = {send_sock = 0x7fff9b8ebec0, to = {s = {sa_family = 32062, sa_data = "\303\314\023V\000\000p\276\216\233\377\177\000"}, sin = {sin_family = 32062, sin_port = 52419, sin_addr = {s_addr = 22035}, sin_zero = "p\276\216\233\377\177\000"}, sin6 = {sin6_family = 32062, sin6_port = 52419, sin6_flowinfo = 22035, sin6_addr = {__in6_u = {__u6_addr8 = "p\276\216\233\377\177\000\000\030\000\000\000\000\000\000", __u6_addr16 = {48752, 39822, 32767, 0, 24, 0, 0, 0}, __u6_addr32 = {2609823344, 32767, 24, 0}}}, sin6_scope_id = 0}, sas = {ss_family = 32062, __ss_padding = "\303\314\023V\000\000p\276\216\233\377\177\000\000\030", '\000' <repeats 15 times>, "\225q\\037P\000\000\000\070,\214u\322\177\000\000\000\244\374\314\023V\000\000\000\000\000\000\001 \000\000\070,\214u\322\177\000\000\001\000\000\000\000\000\000\000\300ʷS\322\177\000\000\200\276\216\233\377\177\000\000\070,\214u\322\177\000\000\200\277\216\233\377\177\000\000\b\000\000\000\000\000\000", __ss_align = 20}}, id = 1, send_flags = {f = 1, blst_imask = 0}, proto = 31 '\037', proto_pad0 = 0 '\000', proto_pad1 = 0} c = 49 '1' ret = 0 __func__ = "tcp_read_req" #9 0x00005613ccd23eb4 in handle_io (fm=0x7fd2758c2c38, events=1, idx=-1) at core/tcp_read.c:1857 ret = 0 n = 1404553920 read_flags = RD_CONN_SHORT_READ con = 0x7fd253b7cac0 s = 1404554328 resp = 1 t = 526152085 ee = 0x0 __func__ = "handle_io" #10 0x00005613ccd0dd1e in io_wait_loop_epoll (h=0x5613ccfca240 <io_w>, t=2, repeat=0) at core/io_wait.h:1070 n = 1 r = 0 fm = 0x7fd2758c2c38 revents = 1 __func__ = "io_wait_loop_epoll" #11 0x00005613ccd25981 in tcp_receive_loop (unix_sock=39) at core/tcp_read.c:1978 __func__ = "tcp_receive_loop" #12 0x00005613ccb8561b in tcp_init_children (woneinit=0x7fff9b8ec338) at core/tcp_main.c:5139 r = 2 i = 7 reader_fd_1 = 39 pid = 0 si_desc = "tcp receiver (generic)\000\000\205\220\274\314\023V\000\000\020Î\233\377\177\000\000\301\200\313\314\000\000\000\000AS\000\000\000\000\000\000۸\352\314\023V\000\000\246\000\216\233\377\177\000\000\034\352\340\314\023V\000\000\340\302\216\233\001\000\000\000\360\311\017Q\322\177\000\000\340\302\216\233\377\177\000\000\340\227:S\001\000\000\000\000Î\233\377\177\000\000\274\353\340\314\023V\000" si = 0x0 __func__ = "tcp_init_children" #13 0x00005613cca62bba in main_loop () at main.c:1857 i = 8 pid = 21313 si = 0x0 si_desc = "udp receiver child=7 sock=XXX.XXX.XXX.XXX:5060\000\000\000\003\000\000\000 \000\000\000\000\230g\240\210\347A\357\000\000\000\000\000\000\000\000\210P\347\314\023V\000\000\000\000\000\000\000\000\000\000\260,\227}\322\177\000\000\263i\354\314\023V\000\000\000\000\000 \000\000\000\000\260Ď\233\377\177\000\000\t\205\317\314\023V\000" nrprocs = 8 woneinit = 1 __func__ = "main_loop" #14 0x00005613cca6d4aa in main (argc=17, argv=0x7fff9b8ec9f8) at main.c:3053 cfg_stream = 0x5613cecb6290 c = -1 r = 0 tmp = 0x7fff9b8ecf3f "" tmp_len = 2109797928 port = 32722 proto = 2109962736 ahost = 0x0 aport = 0 options = 0x5613cce77ce0 ":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 = 3769828628 rfd = 4 debug_save = 0 debug_flag = 0 dont_fork_cnt = 0 n_lst = 0x0 p = 0x0 st = {st_dev = 21, st_ino = 17087, st_nlink = 2, st_mode = 16832, st_uid = 109, st_gid = 115, __pad0 = 0, st_rdev = 0, st_size = 40, st_blksize = 4096, st_blocks = 0, st_atim = {tv_sec = 1620845793, tv_nsec = 887985330}, st_mtim = {tv_sec = 1625090397, tv_nsec = 157181302}, st_ctim = {tv_sec = 1625090401, tv_nsec = 197141517}, __glibc_reserved = {0, 0, 0}} tbuf = "\000\000\000\000\000\000\000\000\b\000\000\000\000\000\000\000\060\207\303}\322\177\000\000\000\000\000\000\000\000\000\000\240q\237\233\377\177\000\000\364\212\301}\322\177\000\000\b\000\000\000\000\000\000\000\230r\237\233\377\177\000\000\060\207\303}\322\177\000\000\230ǎ\233\377\177\000\000\224ǎ\233\377\177", '\000' <repeats 18 times>, "\230r\237\233\377\177\000\000\250q\237\233\377\177\000\000'\376\237}\322\177\000\000&\260be\000\000\000\000\000Ɏ\233\377\177\000\000\300\212\225\001\000\000\000\000`Ȏ\233\377\177\000\000PȎ\233\377\177\000\000\230ǎ\233\377\177\000\000X\207\303}\322\177\000\000\001", '\000' <repeats 31 times>... option_index = 0 long_options = {{name = 0x5613cce79f3f "help", has_arg = 0, flag = 0x0, val = 104}, {name = 0x5613cce754e0 "version", has_arg = 0, flag = 0x0, val = 118}, {name = 0x5613cce79f44 "alias", has_arg = 1, flag = 0x0, val = 1024}, {name = 0x5613cce79f4a "subst", has_arg = 1, flag = 0x0, val = 1025}, {name = 0x5613cce79f50 "substdef", has_arg = 1, flag = 0x0, val = 1026}, {name = 0x5613cce79f59 "substdefs", has_arg = 1, flag = 0x0, val = 1027}, {name = 0x5613cce79f63 "server-id", has_arg = 1, flag = 0x0, val = 1028}, {name = 0x5613cce79f6d "loadmodule", has_arg = 1, flag = 0x0, val = 1029}, {name = 0x5613cce79f78 "modparam", has_arg = 1, flag = 0x0, val = 1030}, {name = 0x5613cce79f81 "log-engine", has_arg = 1, flag = 0x0, val = 1031}, {name = 0x5613cce79f8c "debug", has_arg = 1, flag = 0x0, val = 1032}, {name = 0x5613cce79f92 "cfg-print", has_arg = 0, flag = 0x0, val = 1033}, {name = 0x5613cce79f9c "atexit", has_arg = 1, flag = 0x0, val = 1034}, {name = 0x0, has_arg = 0, flag = 0x0, val = 0}} __func__ = "main"
s = 0xef41e788a0679800 <error: Cannot access memory at address 0xef41e788a0679800> len = -1685145520
you can check https://github.com/kamailio/kamailio/issues/2788 https://github.com/kamailio/kamailio/issues/2736
Here changed memory handling You can try the current master or manually apply commits with fix
If the issue still reproduced please report using the master branch if possible.
On Fri, Jul 2, 2021 at 11:30 AM Juha Heinanen jh@tutpro.com wrote:
Kamailio 5.5 crashed when sending reply (bt full below). Before the crash there had been several mysql related error messages ("Lost connection to MySQL server during query" and "Too many connections") in syslog when async worker tried to insert accounting data. So perhaps this core dump has something to do with that.
-- Juha
Reading symbols from /usr/bin/sip-proxy...done. [New LWP 21324] [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/bin/sip-proxy -f /etc/sip-proxy/sip-proxy.cfg -P /run/sip-proxy/sip-proxy.'. Program terminated with signal SIGSEGV, Segmentation fault. #0 0x00007fd274ce3b6e in run_trans_callbacks_internal (cb_lst=0x7fd2532503a8, type=512, trans=0x7fd253250330, params=0x7fff9b8eb2b0) at t_hooks.c:254 254 t_hooks.c: No such file or directory. (gdb) bt full #0 0x00007fd274ce3b6e in run_trans_callbacks_internal (cb_lst=0x7fd2532503a8, type=512, trans=0x7fd253250330, params=0x7fff9b8eb2b0) at t_hooks.c:254 cbp = 0x10 backup_from = 0x5613ccfb37f0 <def_list+16> backup_to = 0x5613ccfb37f8 <def_list+24> backup_dom_from = 0x5613ccfb3800 <def_list+32> backup_dom_to = 0x5613ccfb3808 <def_list+40> backup_uri_from = 0x5613ccfb37e0 <def_list> backup_uri_to = 0x5613ccfb37e8 <def_list+8> backup_xavps = 0x5613ccf56270 <_xavp_list_head> backup_xavus = 0x5613ccf56278 <_xavu_list_head> backup_xavis = 0x5613ccf56280 <_xavi_list_head> __func__ = "run_trans_callbacks_internal" #1 0x00007fd274ce41f7 in run_trans_callbacks_with_buf (type=512, rbuf=0x7fd253250400, req=0x7fd252d6dd20, repl=0x7fd2758bf0b0, flags=0) at t_hooks.c:303 params = {req = 0x7fd252d6dd20, rpl = 0x7fd2758bf0b0, param = 0x7fd254760f60, code = 486, flags = 0, branch = 0, t_rbuf = 0x7fd253250400, dst = 0x7fd253250450, send_buf = { s = 0x7fd25325b9f0 "@", len = 579}} trans = 0x7fd253250330 #2 0x00007fd274c88c15 in relay_reply (t=0x7fd253250330, p_msg=0x7fd2758bf0b0, branch=0, msg_status=486, cancel_data=0x7fff9b8eb580, do_put_on_wait=1) at t_reply.c:2133 relay = 0 save_clone = 0 buf = 0x7fd275ca0ff0 "SIP/2.0 486 Busy Here\r\nTo: sip:XXXXX@XXXXX.com;user=phone;tag=h7g4Esbg_11002529899813\r\nFrom: sip:XXXXX@XXXXX;tag=as6964f29d\r\nCal"... res_len = 579 relayed_code = 486 relayed_msg = 0x7fd2758bf0b0 reply_bak = 0x7fd2510f1000 bm = {to_tag_val = {s = 0x7fd25216e4c0 "@\003", len = 1377234752}} totag_retr = 0 reply_status = RPS_COMPLETED uas_rb = 0x7fd253250400 to_tag = 0x7fd25216e820 reason = {s = 0x7fd25216e830 "0", len = 1394935248} onsend_params = {req = 0x9b8eb420, rpl = 0x7fd274c6b10d <futex_get+40>, param = 0x1, code = 1359984720, flags = 32722, branch = 0, t_rbuf = 0x7fff9b8eb460, dst = 0xa0679800, send_buf = { s = 0x19b8eb450 <error: Cannot access memory at address 0x19b8eb450>, len = 1359984720}} ip = {af = 2609820752, len = 32767, u = {addrl = {94643040895493, 0}, addr32 = {3436528133, 22035, 0, 0}, addr16 = {16901, 52437, 22035, 0, 0, 0, 0, 0}, addr = "\005B\325\314\023V\000\000\000\000\000\000\000\000\000"}} __func__ = "relay_reply" #3 0x00007fd274c8de6b in reply_received (p_msg=0x7fd2758bf0b0) at t_reply.c:2680 msg_status = 486 last_uac_status = 180 ack = 0x7fd25216e830 "0" ack_len = 459 branch = 0 reply_status = 32722 onreply_route = 2 cancel_data = {cancel_bitmap = 0, reason = {cause = 0, u = {text = {s = 0x0, len = 1977055608}, e2e_cancel = 0x0, packed_hdrs = {s = 0x0, len = 1977055608}}}} uac = 0x7fd2532505c0 t = 0x7fd253250330 lack_dst = {send_sock = 0x40, to = {s = {sa_family = 49168, sa_data = "\207u\322\177\000\000\220\266\216\233\377\177\000"}, sin = {sin_family = 49168, sin_port = 30087, sin_addr = { s_addr = 32722}, sin_zero = "\220\266\216\233\377\177\000"}, sin6 = {sin6_family = 49168, sin6_port = 30087, sin6_flowinfo = 32722, sin6_addr = {__in6_u = { __u6_addr8 = "\220\266\216\233\377\177\000\000L=\215s\322\177\000", __u6_addr16 = {46736, 39822, 32767, 0, 15692, 29581, 32722, 0}, __u6_addr32 = {2609821328, 32767, 1938636108, 32722}}}, sin6_scope_id = 1971831024}, sas = {ss_family = 49168, __ss_padding = "\207u\322\177\000\000\220\266\216\233\377\177\000\000L=\215s\322\177\000\000\360\300\207u\322\177", '\000' <repeats 13 times>, "\b\000\000\000\000\060Z\264u\322\177\000\000\213\t\342\316\023V\000\000;\b\342\316\023V\000\000\020\313\320\000\000\000\000\000\020\000\000\000\000\000\000\000I\001\000\000\000\000\000\000\000\230g\240\210\347A\357\300\266\216\233\377\177\000\000\000\230g\240\210\347", <incomplete sequence \357>, __ss_align = 0}}, id = 0, send_flags = {f = 0, blst_imask = 0}, proto = 0 '\000', proto_pad0 = 0 '\000', proto_pad1 = 0} backup_user_from = 0x5613ccfb37f0 <def_list+16> backup_user_to = 0x5613ccfb37f8 <def_list+24> backup_domain_from = 0x5613ccfb3800 <def_list+32> backup_domain_to = 0x5613ccfb3808 <def_list+40> backup_uri_from = 0x5613ccfb37e0 <def_list> backup_uri_to = 0x5613ccfb37e8 <def_list+8> backup_xavps = 0x5613ccf56270 <_xavp_list_head> backup_xavus = 0x5613ccf56278 <_xavu_list_head> backup_xavis = 0x5613ccf56280 <_xavi_list_head> replies_locked = 1 branch_ret = 0 prev_branch = 1971830800 blst_503_timeout = 32722 hf = 0xb5c750 onsend_params = {req = 0x7fff9b8eb5e0, rpl = 0xef41e788a0679800, param = 0x30, code = 0, flags = 0, branch = 0, t_rbuf = 0x0, dst = 0x7fd27d972cb0 <__syslog>, send_buf = { s = 0x5613ccec69b3 "INFO", len = -1603823616}} ctx = {rec_lev = 0, run_flags = 2, last_retcode = -1, jmp_env = {{__jmpbuf = {0, -5133089567146157739, 0, 140542026919088, 94643042412979, 536870912, -5133089567232140971, -1505551737941960363}, __mask_was_saved = 0, __saved_mask = {__val = {140735803210560, 13683472, 7765887371, 140735803209568, 94643041089583, 0, 17240315422543681536, 0, 0, 0, 0, 94643042412979, 17240315422543681536, 140735803209872, 94643041372964, 2866715017336}}}}} bctx = 0x7fd27587c010 keng = 0x0 ret = 0 evname = {s = 0x7fd274d3696f "on_sl_reply", len = 11} __func__ = "reply_received" #4 0x00005613ccbba0d4 in do_forward_reply (msg=0x7fd2758bf0b0, mode=0) at core/forward.c:764 new_buf = 0x0 dst = {send_sock = 0x0, to = {s = {sa_family = 0, sa_data = '\000' <repeats 13 times>}, sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}, sas = {ss_family = 0, __ss_padding = '\000' <repeats 117 times>, __ss_align = 0}}, id = 0, send_flags = {f = 0, blst_imask = 0}, proto = 0 '\000', proto_pad0 = 0 '\000', proto_pad1 = 0} new_len = 0 r = 2 ip = {af = 1, len = 6356993, u = {addrl = {140735803210560, 140541891965104}, addr32 = {2609822528, 32767, 1972105392, 32722}, addr16 = {47936, 39822, 32767, 0, 61616, 30091, 32722, 0}, addr = "@\273\216\233\377\177\000\000\260\360\213u\322\177\000"}} s = 0xef41e788a0679800 <error: Cannot access memory at address 0xef41e788a0679800> len = -1685145520 __func__ = "do_forward_reply" #5 0x00005613ccbbc23c in forward_reply (msg=0x7fd2758bf0b0) at core/forward.c:865 No locals. #6 0x00005613ccc5eea9 in receive_msg ( buf=0x5613cee206f0 "SIP/2.0 486 Busy Here\r\nTo: sip:XXXXX@XXXXX;user=phone;tag=h7g4Esbg_11002529899813\r\nFrom: sip:XXXXX@XXXXX;tag=as6964f29d\r\nCal"..., len=667, rcv_info=0x7fd253b7cad8) at core/receive.c:587 msg = 0x7fd2758bf0b0 ctx = {rec_lev = 0, run_flags = 0, last_retcode = 1, jmp_env = {{__jmpbuf = {0, -5133089566915471019, 0, 140542026919088, 94643042412979, 536870912, -5133089567001454251, -1505551737941960363}, __mask_was_saved = 0, __saved_mask = {__val = {94643073835016, 65535, 17240315422543681536, 18446744073709551536, 2, 0, 140542026919088, 94643042412979, 536870912, 140735803211024, 94643040635195, 140735803211696, 65535, 65536, 4095, 140735803211580}}}}} bctx = 0x0 ret = 1 tvb = {tv_sec = 0, tv_usec = 0} tve = {tv_sec = 0, tv_usec = 0} diff = 0 inb = {s = 0x5613cee206f0 "SIP/2.0 486 Busy Here\r\nTo: sip:XXXXX@XXXXX;user=phone;tag=h7g4Esbg_11002529899813\r\nFrom: sip:XXXXX@XXXXX;tag=as6964f29d\r\nCal"..., len = 667} netinfo = {data = {s = 0x5613cee206f0 "SIP/2.0 486 Busy Here\r\nTo: sip:XXXXX@XXXXX;user=phone;tag=h7g4Esbg_11002529899813\r\nFrom: <sip:XXXXX@XXXXX;tag=as6964f29d\r\nCal"..., len = 667}, rcv = 0x7fd253b7cad8, dst = 0x0} keng = 0x0 evp = {data = 0x7fff9b8eba90, obuf = {s = 0x0, len = 0}, rcv = 0x7fd253b7cad8, dst = 0x0, req = 0x0, rpl = 0x0, rplcode = 0, mode = 0} cidlockidx = 0 cidlockset = 0 errsipmsg = 0 exectime = 0 __func__ = "receive_msg" #7 0x00005613ccd1cf15 in receive_tcp_msg (tcpbuf=0x7fd253b7ce60 "SIP/2.0 486 Busy Here\r\nTo: sip:XXXXX@XXXXX;user=phone;tag=h7g4Esbg_11002529899813\r\nFrom: sip:XXXXX@XXXXX;tag=as6964f29d\r\nCal"..., len=667, rcv_info=0x7fd253b7cad8, con=0x7fd253b7cac0) at core/tcp_read.c:1424 buf = 0x5613cee206f0 "SIP/2.0 486 Busy Here\r\nTo: sip:XXXXX@XXXXX;user=phone;tag=h7g4Esbg_11002529899813\r\nFrom: sip:XXXXX@XXXXX;tag=as6964f29d\r\nCal"... bsize = 65535 blen = 65535 __func__ = "receive_tcp_msg" #8 0x00005613ccd1f554 in tcp_read_req (con=0x7fd253b7cac0, bytes_read=0x7fff9b8ebf34, read_flags=0x7fff9b8ebf3c) at core/tcp_read.c:1607 bytes = 667 total_bytes = 667 resp = 1 size = 0 req = 0x7fd253b7cbe8 dst = {send_sock = 0x7fff9b8ebec0, to = {s = {sa_family = 32062, sa_data = "\303\314\023V\000\000p\276\216\233\377\177\000"}, sin = {sin_family = 32062, sin_port = 52419, sin_addr = {s_addr = 22035}, sin_zero = "p\276\216\233\377\177\000"}, sin6 = {sin6_family = 32062, sin6_port = 52419, sin6_flowinfo = 22035, sin6_addr = {__in6_u = {__u6_addr8 = "p\276\216\233\377\177\000\000\030\000\000\000\000\000\000", __u6_addr16 = {48752, 39822, 32767, 0, 24, 0, 0, 0}, __u6_addr32 = {2609823344, 32767, 24, 0}}}, sin6_scope_id = 0}, sas = {ss_family = 32062, __ss_padding = "\303\314\023V\000\000p\276\216\233\377\177\000\000\030", '\000' <repeats 15 times>, "\225q\\037P\000\000\000\070,\214u\322\177\000\000\000\244\374\314\023V\000\000\000\000\000\000\001 \000\000\070,\214u\322\177\000\000\001\000\000\000\000\000\000\000\300ʷS\322\177\000\000\200\276\216\233\377\177\000\000\070,\214u\322\177\000\000\200\277\216\233\377\177\000\000\b\000\000\000\000\000\000", __ss_align = 20}}, id = 1, send_flags = {f = 1, blst_imask = 0}, proto = 31 '\037', proto_pad0 = 0 '\000', proto_pad1 = 0} c = 49 '1' ret = 0 __func__ = "tcp_read_req" #9 0x00005613ccd23eb4 in handle_io (fm=0x7fd2758c2c38, events=1, idx=-1) at core/tcp_read.c:1857 ret = 0 n = 1404553920 read_flags = RD_CONN_SHORT_READ con = 0x7fd253b7cac0 s = 1404554328 resp = 1 t = 526152085 ee = 0x0 __func__ = "handle_io" #10 0x00005613ccd0dd1e in io_wait_loop_epoll (h=0x5613ccfca240 <io_w>, t=2, repeat=0) at core/io_wait.h:1070 n = 1 r = 0 fm = 0x7fd2758c2c38 revents = 1 __func__ = "io_wait_loop_epoll" #11 0x00005613ccd25981 in tcp_receive_loop (unix_sock=39) at core/tcp_read.c:1978 __func__ = "tcp_receive_loop" #12 0x00005613ccb8561b in tcp_init_children (woneinit=0x7fff9b8ec338) at core/tcp_main.c:5139 r = 2 i = 7 reader_fd_1 = 39 pid = 0 si_desc = "tcp receiver (generic)\000\000\205\220\274\314\023V\000\000\020Î\233\377\177\000\000\301\200\313\314\000\000\000\000AS\000\000\000\000\000\000۸\352\314\023V\000\000\246\000\216\233\377\177\000\000\034\352\340\314\023V\000\000\340\302\216\233\001\000\000\000\360\311\017Q\322\177\000\000\340\302\216\233\377\177\000\000\340\227:S\001\000\000\000\000Î\233\377\177\000\000\274\353\340\314\023V\000" si = 0x0 __func__ = "tcp_init_children" #13 0x00005613cca62bba in main_loop () at main.c:1857 i = 8 pid = 21313 si = 0x0 si_desc = "udp receiver child=7 sock=XXX.XXX.XXX.XXX:5060\000\000\000\003\000\000\000 \000\000\000\000\230g\240\210\347A\357\000\000\000\000\000\000\000\000\210P\347\314\023V\000\000\000\000\000\000\000\000\000\000\260,\227}\322\177\000\000\263i\354\314\023V\000\000\000\000\000 \000\000\000\000\260Ď\233\377\177\000\000\t\205\317\314\023V\000" nrprocs = 8 woneinit = 1 __func__ = "main_loop" #14 0x00005613cca6d4aa in main (argc=17, argv=0x7fff9b8ec9f8) at main.c:3053 cfg_stream = 0x5613cecb6290 c = -1 r = 0 tmp = 0x7fff9b8ecf3f "" tmp_len = 2109797928 port = 32722 proto = 2109962736 ahost = 0x0 aport = 0 options = 0x5613cce77ce0 ":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 = 3769828628 rfd = 4 debug_save = 0 debug_flag = 0 dont_fork_cnt = 0 n_lst = 0x0 p = 0x0 st = {st_dev = 21, st_ino = 17087, st_nlink = 2, st_mode = 16832, st_uid = 109, st_gid = 115, __pad0 = 0, st_rdev = 0, st_size = 40, st_blksize = 4096, st_blocks = 0, st_atim = {tv_sec = 1620845793, tv_nsec = 887985330}, st_mtim = {tv_sec = 1625090397, tv_nsec = 157181302}, st_ctim = {tv_sec = 1625090401, tv_nsec = 197141517}, __glibc_reserved = {0, 0, 0}} tbuf = "\000\000\000\000\000\000\000\000\b\000\000\000\000\000\000\000\060\207\303}\322\177\000\000\000\000\000\000\000\000\000\000\240q\237\233\377\177\000\000\364\212\301}\322\177\000\000\b\000\000\000\000\000\000\000\230r\237\233\377\177\000\000\060\207\303}\322\177\000\000\230ǎ\233\377\177\000\000\224ǎ\233\377\177", '\000' <repeats 18 times>, "\230r\237\233\377\177\000\000\250q\237\233\377\177\000\000'\376\237}\322\177\000\000&\260be\000\000\000\000\000Ɏ\233\377\177\000\000\300\212\225\001\000\000\000\000`Ȏ\233\377\177\000\000PȎ\233\377\177\000\000\230ǎ\233\377\177\000\000X\207\303}\322\177\000\000\001", '\000' <repeats 31 times>... option_index = 0 long_options = {{name = 0x5613cce79f3f "help", has_arg = 0, flag = 0x0, val = 104}, {name = 0x5613cce754e0 "version", has_arg = 0, flag = 0x0, val = 118}, {name = 0x5613cce79f44 "alias", has_arg = 1, flag = 0x0, val = 1024}, {name = 0x5613cce79f4a "subst", has_arg = 1, flag = 0x0, val = 1025}, {name = 0x5613cce79f50 "substdef", has_arg = 1, flag = 0x0, val = 1026}, {name = 0x5613cce79f59 "substdefs", has_arg = 1, flag = 0x0, val = 1027}, {name = 0x5613cce79f63 "server-id", has_arg = 1, flag = 0x0, val = 1028}, {name = 0x5613cce79f6d "loadmodule", has_arg = 1, flag = 0x0, val = 1029}, {name = 0x5613cce79f78 "modparam", has_arg = 1, flag = 0x0, val = 1030}, {name = 0x5613cce79f81 "log-engine", has_arg = 1, flag = 0x0, val = 1031}, {name = 0x5613cce79f8c "debug", has_arg = 1, flag = 0x0, val = 1032}, {name = 0x5613cce79f92 "cfg-print", has_arg = 0, flag = 0x0, val = 1033}, {name = 0x5613cce79f9c "atexit", has_arg = 1, flag = 0x0, val = 1034}, {name = 0x0, has_arg = 0, flag = 0x0, val = 0}} __func__ = "main" __________________________________________________________ Kamailio - Users Mailing List - Non Commercial Discussions
- sr-users@lists.kamailio.org
Important: keep the mailing list in the recipients, do not reply only to the sender! Edit mailing list options or unsubscribe:
Sergey Safarov writes:
s = 0xef41e788a0679800 <error: Cannot access memory at address
0xef41e788a0679800> len = -1685145520
you can check https://github.com/kamailio/kamailio/issues/2788 https://github.com/kamailio/kamailio/issues/2736
Here changed memory handling You can try the current master or manually apply commits with fix
I don't think these two crashes are related. My config doe not use substdef's.
-- Juha
Hello,
is clone_msg parameter let to its default value?
* https://www.kamailio.org/docs/modules/stable/modules/acc.html#acc.p.clone_ms...
Provide also the output in gdb for:
p *trans
Cheers, Daniel
On 02.07.21 10:27, Juha Heinanen wrote:
Kamailio 5.5 crashed when sending reply (bt full below). Before the crash there had been several mysql related error messages ("Lost connection to MySQL server during query" and "Too many connections") in syslog when async worker tried to insert accounting data. So perhaps this core dump has something to do with that.
-- Juha
Reading symbols from /usr/bin/sip-proxy...done. [New LWP 21324] [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/bin/sip-proxy -f /etc/sip-proxy/sip-proxy.cfg -P /run/sip-proxy/sip-proxy.'. Program terminated with signal SIGSEGV, Segmentation fault. #0 0x00007fd274ce3b6e in run_trans_callbacks_internal (cb_lst=0x7fd2532503a8, type=512, trans=0x7fd253250330, params=0x7fff9b8eb2b0) at t_hooks.c:254 254 t_hooks.c: No such file or directory. (gdb) bt full #0 0x00007fd274ce3b6e in run_trans_callbacks_internal (cb_lst=0x7fd2532503a8, type=512, trans=0x7fd253250330, params=0x7fff9b8eb2b0) at t_hooks.c:254 cbp = 0x10 backup_from = 0x5613ccfb37f0 <def_list+16> backup_to = 0x5613ccfb37f8 <def_list+24> backup_dom_from = 0x5613ccfb3800 <def_list+32> backup_dom_to = 0x5613ccfb3808 <def_list+40> backup_uri_from = 0x5613ccfb37e0 <def_list> backup_uri_to = 0x5613ccfb37e8 <def_list+8> backup_xavps = 0x5613ccf56270 <_xavp_list_head> backup_xavus = 0x5613ccf56278 <_xavu_list_head> backup_xavis = 0x5613ccf56280 <_xavi_list_head> __func__ = "run_trans_callbacks_internal" #1 0x00007fd274ce41f7 in run_trans_callbacks_with_buf (type=512, rbuf=0x7fd253250400, req=0x7fd252d6dd20, repl=0x7fd2758bf0b0, flags=0) at t_hooks.c:303 params = {req = 0x7fd252d6dd20, rpl = 0x7fd2758bf0b0, param = 0x7fd254760f60, code = 486, flags = 0, branch = 0, t_rbuf = 0x7fd253250400, dst = 0x7fd253250450, send_buf = { s = 0x7fd25325b9f0 "@", len = 579}} trans = 0x7fd253250330 #2 0x00007fd274c88c15 in relay_reply (t=0x7fd253250330, p_msg=0x7fd2758bf0b0, branch=0, msg_status=486, cancel_data=0x7fff9b8eb580, do_put_on_wait=1) at t_reply.c:2133 relay = 0 save_clone = 0 buf = 0x7fd275ca0ff0 "SIP/2.0 486 Busy Here\r\nTo: sip:XXXXX@XXXXX.com;user=phone;tag=h7g4Esbg_11002529899813\r\nFrom: sip:XXXXX@XXXXX;tag=as6964f29d\r\nCal"... res_len = 579 relayed_code = 486 relayed_msg = 0x7fd2758bf0b0 reply_bak = 0x7fd2510f1000 bm = {to_tag_val = {s = 0x7fd25216e4c0 "@\003", len = 1377234752}} totag_retr = 0 reply_status = RPS_COMPLETED uas_rb = 0x7fd253250400 to_tag = 0x7fd25216e820 reason = {s = 0x7fd25216e830 "0", len = 1394935248} onsend_params = {req = 0x9b8eb420, rpl = 0x7fd274c6b10d <futex_get+40>, param = 0x1, code = 1359984720, flags = 32722, branch = 0, t_rbuf = 0x7fff9b8eb460, dst = 0xa0679800, send_buf = { s = 0x19b8eb450 <error: Cannot access memory at address 0x19b8eb450>, len = 1359984720}} ip = {af = 2609820752, len = 32767, u = {addrl = {94643040895493, 0}, addr32 = {3436528133, 22035, 0, 0}, addr16 = {16901, 52437, 22035, 0, 0, 0, 0, 0}, addr = "\005B\325\314\023V\000\000\000\000\000\000\000\000\000"}} __func__ = "relay_reply" #3 0x00007fd274c8de6b in reply_received (p_msg=0x7fd2758bf0b0) at t_reply.c:2680 msg_status = 486 last_uac_status = 180 ack = 0x7fd25216e830 "0" ack_len = 459 branch = 0 reply_status = 32722 onreply_route = 2 cancel_data = {cancel_bitmap = 0, reason = {cause = 0, u = {text = {s = 0x0, len = 1977055608}, e2e_cancel = 0x0, packed_hdrs = {s = 0x0, len = 1977055608}}}} uac = 0x7fd2532505c0 t = 0x7fd253250330 lack_dst = {send_sock = 0x40, to = {s = {sa_family = 49168, sa_data = "\207u\322\177\000\000\220\266\216\233\377\177\000"}, sin = {sin_family = 49168, sin_port = 30087, sin_addr = { s_addr = 32722}, sin_zero = "\220\266\216\233\377\177\000"}, sin6 = {sin6_family = 49168, sin6_port = 30087, sin6_flowinfo = 32722, sin6_addr = {__in6_u = { __u6_addr8 = "\220\266\216\233\377\177\000\000L=\215s\322\177\000", __u6_addr16 = {46736, 39822, 32767, 0, 15692, 29581, 32722, 0}, __u6_addr32 = {2609821328, 32767, 1938636108, 32722}}}, sin6_scope_id = 1971831024}, sas = {ss_family = 49168, __ss_padding = "\207u\322\177\000\000\220\266\216\233\377\177\000\000L=\215s\322\177\000\000\360\300\207u\322\177", '\000' <repeats 13 times>, "\b\000\000\000\000\060Z\264u\322\177\000\000\213\t\342\316\023V\000\000;\b\342\316\023V\000\000\020\313\320\000\000\000\000\000\020\000\000\000\000\000\000\000I\001\000\000\000\000\000\000\000\230g\240\210\347A\357\300\266\216\233\377\177\000\000\000\230g\240\210\347", <incomplete sequence \357>, __ss_align = 0}}, id = 0, send_flags = {f = 0, blst_imask = 0}, proto = 0 '\000', proto_pad0 = 0 '\000', proto_pad1 = 0} backup_user_from = 0x5613ccfb37f0 <def_list+16> backup_user_to = 0x5613ccfb37f8 <def_list+24> backup_domain_from = 0x5613ccfb3800 <def_list+32> backup_domain_to = 0x5613ccfb3808 <def_list+40> backup_uri_from = 0x5613ccfb37e0 <def_list> backup_uri_to = 0x5613ccfb37e8 <def_list+8> backup_xavps = 0x5613ccf56270 <_xavp_list_head> backup_xavus = 0x5613ccf56278 <_xavu_list_head> backup_xavis = 0x5613ccf56280 <_xavi_list_head> replies_locked = 1 branch_ret = 0 prev_branch = 1971830800 blst_503_timeout = 32722 hf = 0xb5c750 onsend_params = {req = 0x7fff9b8eb5e0, rpl = 0xef41e788a0679800, param = 0x30, code = 0, flags = 0, branch = 0, t_rbuf = 0x0, dst = 0x7fd27d972cb0 <__syslog>, send_buf = { s = 0x5613ccec69b3 "INFO", len = -1603823616}} ctx = {rec_lev = 0, run_flags = 2, last_retcode = -1, jmp_env = {{__jmpbuf = {0, -5133089567146157739, 0, 140542026919088, 94643042412979, 536870912, -5133089567232140971, -1505551737941960363}, __mask_was_saved = 0, __saved_mask = {__val = {140735803210560, 13683472, 7765887371, 140735803209568, 94643041089583, 0, 17240315422543681536, 0, 0, 0, 0, 94643042412979, 17240315422543681536, 140735803209872, 94643041372964, 2866715017336}}}}} bctx = 0x7fd27587c010 keng = 0x0 ret = 0 evname = {s = 0x7fd274d3696f "on_sl_reply", len = 11} __func__ = "reply_received" #4 0x00005613ccbba0d4 in do_forward_reply (msg=0x7fd2758bf0b0, mode=0) at core/forward.c:764 new_buf = 0x0 dst = {send_sock = 0x0, to = {s = {sa_family = 0, sa_data = '\000' <repeats 13 times>}, sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}, sas = {ss_family = 0, __ss_padding = '\000' <repeats 117 times>, __ss_align = 0}}, id = 0, send_flags = {f = 0, blst_imask = 0}, proto = 0 '\000', proto_pad0 = 0 '\000', proto_pad1 = 0} new_len = 0 r = 2 ip = {af = 1, len = 6356993, u = {addrl = {140735803210560, 140541891965104}, addr32 = {2609822528, 32767, 1972105392, 32722}, addr16 = {47936, 39822, 32767, 0, 61616, 30091, 32722, 0}, addr = "@\273\216\233\377\177\000\000\260\360\213u\322\177\000"}} s = 0xef41e788a0679800 <error: Cannot access memory at address 0xef41e788a0679800> len = -1685145520 __func__ = "do_forward_reply" #5 0x00005613ccbbc23c in forward_reply (msg=0x7fd2758bf0b0) at core/forward.c:865 No locals. #6 0x00005613ccc5eea9 in receive_msg ( buf=0x5613cee206f0 "SIP/2.0 486 Busy Here\r\nTo: sip:XXXXX@XXXXX;user=phone;tag=h7g4Esbg_11002529899813\r\nFrom: sip:XXXXX@XXXXX;tag=as6964f29d\r\nCal"..., len=667, rcv_info=0x7fd253b7cad8) at core/receive.c:587 msg = 0x7fd2758bf0b0 ctx = {rec_lev = 0, run_flags = 0, last_retcode = 1, jmp_env = {{__jmpbuf = {0, -5133089566915471019, 0, 140542026919088, 94643042412979, 536870912, -5133089567001454251, -1505551737941960363}, __mask_was_saved = 0, __saved_mask = {__val = {94643073835016, 65535, 17240315422543681536, 18446744073709551536, 2, 0, 140542026919088, 94643042412979, 536870912, 140735803211024, 94643040635195, 140735803211696, 65535, 65536, 4095, 140735803211580}}}}} bctx = 0x0 ret = 1 tvb = {tv_sec = 0, tv_usec = 0} tve = {tv_sec = 0, tv_usec = 0} diff = 0 inb = {s = 0x5613cee206f0 "SIP/2.0 486 Busy Here\r\nTo: sip:XXXXX@XXXXX;user=phone;tag=h7g4Esbg_11002529899813\r\nFrom: sip:XXXXX@XXXXX;tag=as6964f29d\r\nCal"..., len = 667} netinfo = {data = {s = 0x5613cee206f0 "SIP/2.0 486 Busy Here\r\nTo: sip:XXXXX@XXXXX;user=phone;tag=h7g4Esbg_11002529899813\r\nFrom: <sip:XXXXX@XXXXX;tag=as6964f29d\r\nCal"..., len = 667}, rcv = 0x7fd253b7cad8, dst = 0x0} keng = 0x0 evp = {data = 0x7fff9b8eba90, obuf = {s = 0x0, len = 0}, rcv = 0x7fd253b7cad8, dst = 0x0, req = 0x0, rpl = 0x0, rplcode = 0, mode = 0} cidlockidx = 0 cidlockset = 0 errsipmsg = 0 exectime = 0 __func__ = "receive_msg" #7 0x00005613ccd1cf15 in receive_tcp_msg (tcpbuf=0x7fd253b7ce60 "SIP/2.0 486 Busy Here\r\nTo: sip:XXXXX@XXXXX;user=phone;tag=h7g4Esbg_11002529899813\r\nFrom: sip:XXXXX@XXXXX;tag=as6964f29d\r\nCal"..., len=667, rcv_info=0x7fd253b7cad8, con=0x7fd253b7cac0) at core/tcp_read.c:1424 buf = 0x5613cee206f0 "SIP/2.0 486 Busy Here\r\nTo: sip:XXXXX@XXXXX;user=phone;tag=h7g4Esbg_11002529899813\r\nFrom: sip:XXXXX@XXXXX;tag=as6964f29d\r\nCal"... bsize = 65535 blen = 65535 __func__ = "receive_tcp_msg" #8 0x00005613ccd1f554 in tcp_read_req (con=0x7fd253b7cac0, bytes_read=0x7fff9b8ebf34, read_flags=0x7fff9b8ebf3c) at core/tcp_read.c:1607 bytes = 667 total_bytes = 667 resp = 1 size = 0 req = 0x7fd253b7cbe8 dst = {send_sock = 0x7fff9b8ebec0, to = {s = {sa_family = 32062, sa_data = "\303\314\023V\000\000p\276\216\233\377\177\000"}, sin = {sin_family = 32062, sin_port = 52419, sin_addr = {s_addr = 22035}, sin_zero = "p\276\216\233\377\177\000"}, sin6 = {sin6_family = 32062, sin6_port = 52419, sin6_flowinfo = 22035, sin6_addr = {__in6_u = {__u6_addr8 = "p\276\216\233\377\177\000\000\030\000\000\000\000\000\000", __u6_addr16 = {48752, 39822, 32767, 0, 24, 0, 0, 0}, __u6_addr32 = {2609823344, 32767, 24, 0}}}, sin6_scope_id = 0}, sas = {ss_family = 32062, __ss_padding = "\303\314\023V\000\000p\276\216\233\377\177\000\000\030", '\000' <repeats 15 times>, "\225q\\037P\000\000\000\070,\214u\322\177\000\000\000\244\374\314\023V\000\000\000\000\000\000\001 \000\000\070,\214u\322\177\000\000\001\000\000\000\000\000\000\000\300ʷS\322\177\000\000\200\276\216\233\377\177\000\000\070,\214u\322\177\000\000\200\277\216\233\377\177\000\000\b\000\000\000\000\000\000", __ss_align = 20}}, id = 1, send_flags = {f = 1, blst_imask = 0}, proto = 31 '\037', proto_pad0 = 0 '\000', proto_pad1 = 0} c = 49 '1' ret = 0 __func__ = "tcp_read_req" #9 0x00005613ccd23eb4 in handle_io (fm=0x7fd2758c2c38, events=1, idx=-1) at core/tcp_read.c:1857 ret = 0 n = 1404553920 read_flags = RD_CONN_SHORT_READ con = 0x7fd253b7cac0 s = 1404554328 resp = 1 t = 526152085 ee = 0x0 __func__ = "handle_io" #10 0x00005613ccd0dd1e in io_wait_loop_epoll (h=0x5613ccfca240 <io_w>, t=2, repeat=0) at core/io_wait.h:1070 n = 1 r = 0 fm = 0x7fd2758c2c38 revents = 1 __func__ = "io_wait_loop_epoll" #11 0x00005613ccd25981 in tcp_receive_loop (unix_sock=39) at core/tcp_read.c:1978 __func__ = "tcp_receive_loop" #12 0x00005613ccb8561b in tcp_init_children (woneinit=0x7fff9b8ec338) at core/tcp_main.c:5139 r = 2 i = 7 reader_fd_1 = 39 pid = 0 si_desc = "tcp receiver (generic)\000\000\205\220\274\314\023V\000\000\020Î\233\377\177\000\000\301\200\313\314\000\000\000\000AS\000\000\000\000\000\000۸\352\314\023V\000\000\246\000\216\233\377\177\000\000\034\352\340\314\023V\000\000\340\302\216\233\001\000\000\000\360\311\017Q\322\177\000\000\340\302\216\233\377\177\000\000\340\227:S\001\000\000\000\000Î\233\377\177\000\000\274\353\340\314\023V\000" si = 0x0 __func__ = "tcp_init_children" #13 0x00005613cca62bba in main_loop () at main.c:1857 i = 8 pid = 21313 si = 0x0 si_desc = "udp receiver child=7 sock=XXX.XXX.XXX.XXX:5060\000\000\000\003\000\000\000 \000\000\000\000\230g\240\210\347A\357\000\000\000\000\000\000\000\000\210P\347\314\023V\000\000\000\000\000\000\000\000\000\000\260,\227}\322\177\000\000\263i\354\314\023V\000\000\000\000\000 \000\000\000\000\260Ď\233\377\177\000\000\t\205\317\314\023V\000" nrprocs = 8 woneinit = 1 __func__ = "main_loop" #14 0x00005613cca6d4aa in main (argc=17, argv=0x7fff9b8ec9f8) at main.c:3053 cfg_stream = 0x5613cecb6290 c = -1 r = 0 tmp = 0x7fff9b8ecf3f "" tmp_len = 2109797928 port = 32722 proto = 2109962736 ahost = 0x0 aport = 0 options = 0x5613cce77ce0 ":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 = 3769828628 rfd = 4 debug_save = 0 debug_flag = 0 dont_fork_cnt = 0 n_lst = 0x0 p = 0x0 st = {st_dev = 21, st_ino = 17087, st_nlink = 2, st_mode = 16832, st_uid = 109, st_gid = 115, __pad0 = 0, st_rdev = 0, st_size = 40, st_blksize = 4096, st_blocks = 0, st_atim = {tv_sec = 1620845793, tv_nsec = 887985330}, st_mtim = {tv_sec = 1625090397, tv_nsec = 157181302}, st_ctim = {tv_sec = 1625090401, tv_nsec = 197141517}, __glibc_reserved = {0, 0, 0}} tbuf = "\000\000\000\000\000\000\000\000\b\000\000\000\000\000\000\000\060\207\303}\322\177\000\000\000\000\000\000\000\000\000\000\240q\237\233\377\177\000\000\364\212\301}\322\177\000\000\b\000\000\000\000\000\000\000\230r\237\233\377\177\000\000\060\207\303}\322\177\000\000\230ǎ\233\377\177\000\000\224ǎ\233\377\177", '\000' <repeats 18 times>, "\230r\237\233\377\177\000\000\250q\237\233\377\177\000\000'\376\237}\322\177\000\000&\260be\000\000\000\000\000Ɏ\233\377\177\000\000\300\212\225\001\000\000\000\000`Ȏ\233\377\177\000\000PȎ\233\377\177\000\000\230ǎ\233\377\177\000\000X\207\303}\322\177\000\000\001", '\000' <repeats 31 times>... option_index = 0 long_options = {{name = 0x5613cce79f3f "help", has_arg = 0, flag = 0x0, val = 104}, {name = 0x5613cce754e0 "version", has_arg = 0, flag = 0x0, val = 118}, {name = 0x5613cce79f44 "alias", has_arg = 1, flag = 0x0, val = 1024}, {name = 0x5613cce79f4a "subst", has_arg = 1, flag = 0x0, val = 1025}, {name = 0x5613cce79f50 "substdef", has_arg = 1, flag = 0x0, val = 1026}, {name = 0x5613cce79f59 "substdefs", has_arg = 1, flag = 0x0, val = 1027}, {name = 0x5613cce79f63 "server-id", has_arg = 1, flag = 0x0, val = 1028}, {name = 0x5613cce79f6d "loadmodule", has_arg = 1, flag = 0x0, val = 1029}, {name = 0x5613cce79f78 "modparam", has_arg = 1, flag = 0x0, val = 1030}, {name = 0x5613cce79f81 "log-engine", has_arg = 1, flag = 0x0, val = 1031}, {name = 0x5613cce79f8c "debug", has_arg = 1, flag = 0x0, val = 1032}, {name = 0x5613cce79f92 "cfg-print", has_arg = 0, flag = 0x0, val = 1033}, {name = 0x5613cce79f9c "atexit", has_arg = 1, flag = 0x0, val = 1034}, {name = 0x0, has_arg = 0, flag = 0x0, val = 0}} __func__ = "main" __________________________________________________________ Kamailio - Users Mailing List - Non Commercial Discussions
- sr-users@lists.kamailio.org
Important: keep the mailing list in the recipients, do not reply only to the sender! Edit mailing list options or unsubscribe:
Daniel-Constantin Mierla writes:
is clone_msg parameter let to its default value?
Yes, not set.
Provide also the output in gdb for:
p *trans
Below, Juha
-----------------------------------------------
(gdb) p *trans $1 = {next_c = 0x3835332b00002fc3, prev_c = 0x3337343432333432, hash_index = 0, label = 12, flags = 0, nr_of_outgoings = 0, fcount = 0, ref_count = {val = 0}, from = {s = 0x0, len = 0}, callid = {s = 0x0, len = 0}, cseq_n = {s = 0x0, len = 0}, to = {s = 0x0, len = 0}, method = {s = 0x0, len = 0}, tmcb_hl = {first = 0x0, reg_types = 0}, wait_timer = { next = 0x0, prev = 0x0, expire = 0, initial_timeout = 0, data = 0x0, f = 0x0, flags = 0, slow_idx = 0}, wait_start = 0, uas = {request = 0x0, end_request = 0x0, response = {rbtype = 0, flags = 0, t_active = 0, branch = 0, buffer_len = 0, buffer = 0x0, my_T = 0x0, timer = {next = 0x0, prev = 0x0, expire = 0, initial_timeout = 0, data = 0x0, f = 0x0, flags = 0, slow_idx = 0}, dst = {send_sock = 0x0, to = {s = {sa_family = 0, sa_data = '\000' <repeats 13 times>}, sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = { __u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}, sas = {ss_family = 0, __ss_padding = '\000' <repeats 117 times>, __ss_align = 0}}, id = 0, send_flags = {f = 0, blst_imask = 0}, proto = 0 '\000', proto_pad0 = 0 '\000', proto_pad1 = 0}, retr_expire = 0, fr_expire = 0}, local_totag = {s = 0x0, len = 0}, cancel_reas = 0x0, status = 0}, uac = 0x0, async_backup = {backup_route = 0, backup_branch = 0, blind_uac = 0, ruri_new = 0}, fwded_totags = 0x0, uri_avps_from = 0x0, uri_avps_to = 0x0, user_avps_from = 0x0, user_avps_to = 0x0, domain_avps_from = 0x0, domain_avps_to = 0x0, xavps_list = 0x0, xavus_list = 0x0, xavis_list = 0x0, reply_mutex = {val = 0}, reply_locker_pid = {val = 0}, reply_rec_lock_level = 0, fr_timeout = 0, fr_inv_timeout = 0, rt_t1_timeout_ms = 0, rt_t2_timeout_ms = 0, end_of_life = 0, relayed_reply_branch = 0, on_failure = 0, on_branch_failure = 0, on_reply = 0, on_branch = 0, on_branch_delayed = 0, md5 = 0x7fd2532505a0 ""}
Transactions seems to be destroyed. Can you find out how long it took from the moment the reply was received and the crash happened?
Cheers, Daniel
On 02.07.21 16:12, Juha Heinanen wrote:
Daniel-Constantin Mierla writes:
is clone_msg parameter let to its default value?
Yes, not set.
Provide also the output in gdb for:
p *trans
Below, Juha
(gdb) p *trans $1 = {next_c = 0x3835332b00002fc3, prev_c = 0x3337343432333432, hash_index = 0, label = 12, flags = 0, nr_of_outgoings = 0, fcount = 0, ref_count = {val = 0}, from = {s = 0x0, len = 0}, callid = {s = 0x0, len = 0}, cseq_n = {s = 0x0, len = 0}, to = {s = 0x0, len = 0}, method = {s = 0x0, len = 0}, tmcb_hl = {first = 0x0, reg_types = 0}, wait_timer = { next = 0x0, prev = 0x0, expire = 0, initial_timeout = 0, data = 0x0, f = 0x0, flags = 0, slow_idx = 0}, wait_start = 0, uas = {request = 0x0, end_request = 0x0, response = {rbtype = 0, flags = 0, t_active = 0, branch = 0, buffer_len = 0, buffer = 0x0, my_T = 0x0, timer = {next = 0x0, prev = 0x0, expire = 0, initial_timeout = 0, data = 0x0, f = 0x0, flags = 0, slow_idx = 0}, dst = {send_sock = 0x0, to = {s = {sa_family = 0, sa_data = '\000' <repeats 13 times>}, sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = { __u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}, sas = {ss_family = 0, __ss_padding = '\000' <repeats 117 times>, __ss_align = 0}}, id = 0, send_flags = {f = 0, blst_imask = 0}, proto = 0 '\000', proto_pad0 = 0 '\000', proto_pad1 = 0}, retr_expire = 0, fr_expire = 0}, local_totag = {s = 0x0, len = 0}, cancel_reas = 0x0, status = 0}, uac = 0x0, async_backup = {backup_route = 0, backup_branch = 0, blind_uac = 0, ruri_new = 0}, fwded_totags = 0x0, uri_avps_from = 0x0, uri_avps_to = 0x0, user_avps_from = 0x0, user_avps_to = 0x0, domain_avps_from = 0x0, domain_avps_to = 0x0, xavps_list = 0x0, xavus_list = 0x0, xavis_list = 0x0, reply_mutex = {val = 0}, reply_locker_pid = {val = 0}, reply_rec_lock_level = 0, fr_timeout = 0, fr_inv_timeout = 0, rt_t1_timeout_ms = 0, rt_t2_timeout_ms = 0, end_of_life = 0, relayed_reply_branch = 0, on_failure = 0, on_branch_failure = 0, on_reply = 0, on_branch = 0, on_branch_delayed = 0, md5 = 0x7fd2532505a0 ""}
Daniel-Constantin Mierla writes:
Transactions seems to be destroyed. Can you find out how long it took from the moment the reply was received and the crash happened?
Can be difficult to find when 486 Busy Here was received, because this Kamailio instance is not configured to log replies and pcap is not available.
-- Juha
Daniel-Constantin Mierla writes:
Transactions seems to be destroyed. Can you find out how long it took from the moment the reply was received and the crash happened?
It turned out that ngrep was available. It showed that reply
T 2021/07/02 06:07:02.069728 edgeproxy:5060 -> proxy:5060 [AP] #213066195 SIP/2.0 486 Busy Here. To: sip:XXXX@XXXX;user=phone;tag=h7g4Esbg_11002529899813. From: sip:XXXX@XXXX;tag=as6964f29d. Call-ID: XXXX@XXXX. CSeq: 102 INVITE. Reason: Q.850;cause=17. Content-Length: 0. Via: SIP/2.0/TCP XXXX;branch=z9hG4bK23e2.ce8205fde3fb53d2c403a1dd91cb7ebe.0;i=c3f1,SIP/2.0/TCP XXXX:5060;branch=z9hG4bK23e2.9d4d2e31445231782f2498b2f0f1a5c4.0. Contact: sip:atpsh-60d17ef9-4664-fe4a6-leg2@XXXX;transport=tcp. Record-Route: sip:XXXX;transport=tcp;lr;ftag=as6964f29d;pm=6-0;ice.
arrived at 06:07:02 and proxy crashed at 06:10:09. So the reply was hanging in the proxy for more than 3 minutes.
We'll try to find if there was any accounting/mysql related errors during that period.
-- Juha
On 02.07.21 19:31, Juha Heinanen wrote:
Daniel-Constantin Mierla writes:
Transactions seems to be destroyed. Can you find out how long it took from the moment the reply was received and the crash happened?
It turned out that ngrep was available. It showed that reply
T 2021/07/02 06:07:02.069728 edgeproxy:5060 -> proxy:5060 [AP] #213066195 SIP/2.0 486 Busy Here. To: sip:XXXX@XXXX;user=phone;tag=h7g4Esbg_11002529899813. From: sip:XXXX@XXXX;tag=as6964f29d. Call-ID: XXXX@XXXX. CSeq: 102 INVITE. Reason: Q.850;cause=17. Content-Length: 0. Via: SIP/2.0/TCP XXXX;branch=z9hG4bK23e2.ce8205fde3fb53d2c403a1dd91cb7ebe.0;i=c3f1,SIP/2.0/TCP XXXX:5060;branch=z9hG4bK23e2.9d4d2e31445231782f2498b2f0f1a5c4.0. Contact: sip:atpsh-60d17ef9-4664-fe4a6-leg2@XXXX;transport=tcp. Record-Route: sip:XXXX;transport=tcp;lr;ftag=as6964f29d;pm=6-0;ice.
arrived at 06:07:02 and proxy crashed at 06:10:09. So the reply was hanging in the proxy for more than 3 minutes.
We'll try to find if there was any accounting/mysql related errors during that period.
Probably it hit end of lifetime:
* https://www.kamailio.org/docs/modules/stable/modules/tm.html#tm.p.max_inv_li...
There is also (iirc) a hard cleanup of hung transactions, if a module or script blocks it indefinitely.
Cheers, Daniel
Daniel-Constantin Mierla writes:
Probably it hit end of lifetime:
* https://www.kamailio.org/docs/modules/stable/modules/tm.html#tm.p.max_inv_li...
Yes, 3 minutes matches well with 180 sec.
There is also (iirc) a hard cleanup of hung transactions, if a module or script blocks it indefinitely.
Does it need to be turned on somwhow?
-- Juha