Hi, We've had some more crashes on the current master build. (gdb) bt #0 qm_insert_free (qm=0x7fc1e1b9e010, p=<value optimized out>) at mem/q_malloc.c:181 #1 qm_free (qm=0x7fc1e1b9e010, p=<value optimized out>) at mem/q_malloc.c:527 #2 0x000000000055027f in reset_ruid (msg=0x7fc1e1c35360) at parser/msg_parser.c:911 #3 free_sip_msg (msg=0x7fc1e1c35360) at parser/msg_parser.c:730 #4 0x00000000004a4012 in receive_msg (buf=<value optimized out>, len=<value optimized out>, rcv_info=<value optimized out>) at receive.c:297 #5 0x000000000052a251 in tcp_read_req (con=0x7fc1ca4c6e00, bytes_read=0x7fff041b327c, read_flags=0x7fff041b3274) at tcp_read.c:1387 #6 0x000000000052c53b in handle_io (fm=<value optimized out>, events=1, idx=-1) at tcp_read.c:1617 #7 0x000000000052eb69 in io_wait_loop_epoll (unix_sock=<value optimized out>) at io_wait.h:1092 #8 tcp_receive_loop (unix_sock=<value optimized out>) at tcp_read.c:1728 #9 0x00000000004fc0eb in tcp_init_children () at tcp_main.c:4959 #10 0x000000000046c3d5 in main_loop () at main.c:1702 #11 0x000000000046dec9 in main (argc=<value optimized out>, argv=<value optimized out>) at main.c:2533
(gdb) frame 2 #2 0x000000000055027f in reset_ruid (msg=0x7fc1e1c35360) at parser/msg_parser.c:911 911 pkg_free(msg->ruid.s); (gdb) p msg->ruid $7 = {s = 0x845d20 "", len = 20}
Might this be related to the changes made on Sept 19th to the free_sip_msg functions?
Regards, Hugh
I would theorise that this is connected to the crash reports I was complaining about earlier in Sep. Try to apply the patches and see if it helps.
Hugh Waite hugh.waite@crocodile-rcs.com wrote:
Hi, We've had some more crashes on the current master build. (gdb) bt #0 qm_insert_free (qm=0x7fc1e1b9e010, p=<value optimized out>) at mem/q_malloc.c:181 #1 qm_free (qm=0x7fc1e1b9e010, p=<value optimized out>) at mem/q_malloc.c:527 #2 0x000000000055027f in reset_ruid (msg=0x7fc1e1c35360) at parser/msg_parser.c:911 #3 free_sip_msg (msg=0x7fc1e1c35360) at parser/msg_parser.c:730 #4 0x00000000004a4012 in receive_msg (buf=<value optimized out>, len=<value optimized out>, rcv_info=<value optimized out>) at receive.c:297 #5 0x000000000052a251 in tcp_read_req (con=0x7fc1ca4c6e00, bytes_read=0x7fff041b327c, read_flags=0x7fff041b3274) at tcp_read.c:1387 #6 0x000000000052c53b in handle_io (fm=<value optimized out>, events=1, idx=-1) at tcp_read.c:1617 #7 0x000000000052eb69 in io_wait_loop_epoll (unix_sock=<value optimized out>) at io_wait.h:1092 #8 tcp_receive_loop (unix_sock=<value optimized out>) at tcp_read.c:1728 #9 0x00000000004fc0eb in tcp_init_children () at tcp_main.c:4959 #10 0x000000000046c3d5 in main_loop () at main.c:1702 #11 0x000000000046dec9 in main (argc=<value optimized out>, argv=<value
optimized out>) at main.c:2533
(gdb) frame 2 #2 0x000000000055027f in reset_ruid (msg=0x7fc1e1c35360) at parser/msg_parser.c:911 911 pkg_free(msg->ruid.s); (gdb) p msg->ruid $7 = {s = 0x845d20 "", len = 20}
Might this be related to the changes made on Sept 19th to the free_sip_msg functions?
Regards, Hugh
-- Sent from my mobile, and thus lacking in the refinement one might expect from a fully fledged keyboard.
Alex Balashov - Principal Evariste Systems LLC 235 E Ponce de Leon Ave Suite 106 Decatur, GA 30030 United States Tel: +1-678-954-0671 Web: http://www.evaristesys.com/, http://www.alexbalashov.com
Hello,
can you give bt full as well as kamailio -v output? Any log error messages?
Also, it would be good to recompile with MEMDBG=1 and watch for errors in the logs to see if there is a buffer overflow.
Cheers, Daniel
On 10/2/13 7:19 PM, Hugh Waite wrote:
Hi, We've had some more crashes on the current master build. (gdb) bt #0 qm_insert_free (qm=0x7fc1e1b9e010, p=<value optimized out>) at mem/q_malloc.c:181 #1 qm_free (qm=0x7fc1e1b9e010, p=<value optimized out>) at mem/q_malloc.c:527 #2 0x000000000055027f in reset_ruid (msg=0x7fc1e1c35360) at parser/msg_parser.c:911 #3 free_sip_msg (msg=0x7fc1e1c35360) at parser/msg_parser.c:730 #4 0x00000000004a4012 in receive_msg (buf=<value optimized out>, len=<value optimized out>, rcv_info=<value optimized out>) at receive.c:297 #5 0x000000000052a251 in tcp_read_req (con=0x7fc1ca4c6e00, bytes_read=0x7fff041b327c, read_flags=0x7fff041b3274) at tcp_read.c:1387 #6 0x000000000052c53b in handle_io (fm=<value optimized out>, events=1, idx=-1) at tcp_read.c:1617 #7 0x000000000052eb69 in io_wait_loop_epoll (unix_sock=<value optimized out>) at io_wait.h:1092 #8 tcp_receive_loop (unix_sock=<value optimized out>) at tcp_read.c:1728 #9 0x00000000004fc0eb in tcp_init_children () at tcp_main.c:4959 #10 0x000000000046c3d5 in main_loop () at main.c:1702 #11 0x000000000046dec9 in main (argc=<value optimized out>, argv=<value optimized out>) at main.c:2533
(gdb) frame 2 #2 0x000000000055027f in reset_ruid (msg=0x7fc1e1c35360) at parser/msg_parser.c:911 911 pkg_free(msg->ruid.s); (gdb) p msg->ruid $7 = {s = 0x845d20 "", len = 20}
Might this be related to the changes made on Sept 19th to the free_sip_msg functions?
Regards, Hugh
On 02/10/2013 19:18, Daniel-Constantin Mierla wrote:
Hello,
can you give bt full as well as kamailio -v output? Any log error messages?
Also, it would be good to recompile with MEMDBG=1 and watch for errors in the logs to see if there is a buffer overflow.
Cheers, Daniel
On 10/2/13 7:19 PM, Hugh Waite wrote:
Hi, We've had some more crashes on the current master build. (gdb) bt #0 qm_insert_free (qm=0x7fc1e1b9e010, p=<value optimized out>) at mem/q_malloc.c:181 #1 qm_free (qm=0x7fc1e1b9e010, p=<value optimized out>) at mem/q_malloc.c:527 #2 0x000000000055027f in reset_ruid (msg=0x7fc1e1c35360) at parser/msg_parser.c:911 #3 free_sip_msg (msg=0x7fc1e1c35360) at parser/msg_parser.c:730 #4 0x00000000004a4012 in receive_msg (buf=<value optimized out>, len=<value optimized out>, rcv_info=<value optimized out>) at receive.c:297 #5 0x000000000052a251 in tcp_read_req (con=0x7fc1ca4c6e00, bytes_read=0x7fff041b327c, read_flags=0x7fff041b3274) at tcp_read.c:1387 #6 0x000000000052c53b in handle_io (fm=<value optimized out>, events=1, idx=-1) at tcp_read.c:1617 #7 0x000000000052eb69 in io_wait_loop_epoll (unix_sock=<value optimized out>) at io_wait.h:1092 #8 tcp_receive_loop (unix_sock=<value optimized out>) at tcp_read.c:1728 #9 0x00000000004fc0eb in tcp_init_children () at tcp_main.c:4959 #10 0x000000000046c3d5 in main_loop () at main.c:1702 #11 0x000000000046dec9 in main (argc=<value optimized out>, argv=<value optimized out>) at main.c:2533
(gdb) frame 2 #2 0x000000000055027f in reset_ruid (msg=0x7fc1e1c35360) at parser/msg_parser.c:911 911 pkg_free(msg->ruid.s); (gdb) p msg->ruid $7 = {s = 0x845d20 "", len = 20}
Might this be related to the changes made on Sept 19th to the free_sip_msg functions?
Regards, Hugh
Extra output below. Nothing was printed in the logs (WARNING or ERROR level) before the crash. It seemed to be quite reproduceable when there was traffic being sent to registered websocket clients, but there is no-one online now. We'll have multiple people logged on tomorrow morning.
Regards, Hugh
kamailio -v version: kamailio 4.1.0-dev9 (x86_64/linux) flags: STATS: Off, USE_TCP, USE_TLS, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, 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 4MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: unknown compiled on 13:35:36 Oct 2 2013 with gcc 4.4.7
(gdb) bt full #0 qm_insert_free (qm=0x7fc1e1b9e010, p=<value optimized out>) at mem/q_malloc.c:181 f = 0x845d10 prev = 0x65332d3231653163 hash = 0 #1 qm_free (qm=0x7fc1e1b9e010, p=<value optimized out>) at mem/q_malloc.c:527 f = 0x845d10 size = <value optimized out> next = <value optimized out> prev = <value optimized out> __FUNCTION__ = "qm_free" #2 0x000000000055027f in reset_ruid (msg=0x7fc1e1c35360) at parser/msg_parser.c:911 No locals. #3 free_sip_msg (msg=0x7fc1e1c35360) at parser/msg_parser.c:730 No locals. #4 0x00000000004a4012 in receive_msg (buf=<value optimized out>, len=<value optimized out>, rcv_info=<value optimized out>) at receive.c:297 msg = 0x7fc1e1c35360 ctx = {rec_lev = 0, run_flags = 0, last_retcode = 1, jmp_env = {{__jmpbuf = {1048575, -3596212518023615478, 140470693039152, 140470299422208, 140470299422208, 140733262279292, 140733262279292, 140733262279284}, __mask_was_saved = -900960744, __saved_mask = {__val = {5406222, 532575944923, 541165879417, 4294967297, 1042, 140470299422952, 5409666, 65535, 140733262279284, 140470300510264, 140470697171281, 1042, 140470300510984, 18446744072809678880, 16, 17179869210}}}}} ret = <value optimized out> inb = { s = 0x23d7cc0 "OPTIONS sip:gavin.llewellyn@crocodiletalk.com SIP/2.0\r\nVia: SIP/2.0/TCP edge00-int.crocodilertc.net:5080;branch=z9hG4bKab92.bb8249afcf13f20080f25121e49865b8.0\r\nVia: SIP/2.0/WSS qvis2mie4gas.invalid;rp"..., len = 1028} __FUNCTION__ = "receive_msg" #5 0x000000000052a251 in tcp_read_req (con=0x7fc1ca4c6e00, bytes_read=0x7fff041b327c, read_flags=0x7fff041b3274) at tcp_read.c:1387 bytes = <value optimized out> total_bytes = 1028 resp = 1 size = <value optimized out> req = 0x7fc1ca4c6e80 dst = {send_sock = 0x14, to = {s = {sa_family = 1, sa_data = "\000\000\001\000\000\000\001 \000\000x\313\306", <incomplete sequence \341>}, sin = {sin_family = 1, sin_port = 0, sin_addr = {s_addr = 1}, sin_zero = "\001 \000\000x\313\306", <incomplete sequence \341>}, sin6 = {sin6_family = 1, sin6_port = 0, sin6_flowinfo = 1, sin6_addr = {__in6_u = { __u6_addr8 = "\001 \000\000x\313\306\341\301\177\000\000\000\000\000", __u6_addr16 = {8193, 0, 52088, 57798, 32705, 0, 0, 0}, __u6_addr32 = {8193, 3787901816, 32705, 0}}}, sin6_scope_id = 68891240}}, id = 32767, proto = 8 '\b', send_flags = { f = 0 '\000', blst_imask = 0 '\000'}} c = 13 '\r' ret = <value optimized out> __FUNCTION__ = "tcp_read_req" #6 0x000000000052c53b in handle_io (fm=<value optimized out>, events=1, idx=-1) at tcp_read.c:1617 ret = <value optimized out> n = <value optimized out> read_flags = 1 con = 0x7fc1ca4c6e00 s = <value optimized out> resp = <value optimized out> t = <value optimized out> __FUNCTION__ = "handle_io" #7 0x000000000052eb69 in io_wait_loop_epoll (unix_sock=<value optimized out>) at io_wait.h:1092
One more question, what is the value of db_mode for usrloc module?
Cheers, Daniel
On 10/2/13 9:28 PM, Hugh Waite wrote:
On 02/10/2013 19:18, Daniel-Constantin Mierla wrote:
Hello,
can you give bt full as well as kamailio -v output? Any log error messages?
Also, it would be good to recompile with MEMDBG=1 and watch for errors in the logs to see if there is a buffer overflow.
Cheers, Daniel
On 10/2/13 7:19 PM, Hugh Waite wrote:
Hi, We've had some more crashes on the current master build. (gdb) bt #0 qm_insert_free (qm=0x7fc1e1b9e010, p=<value optimized out>) at mem/q_malloc.c:181 #1 qm_free (qm=0x7fc1e1b9e010, p=<value optimized out>) at mem/q_malloc.c:527 #2 0x000000000055027f in reset_ruid (msg=0x7fc1e1c35360) at parser/msg_parser.c:911 #3 free_sip_msg (msg=0x7fc1e1c35360) at parser/msg_parser.c:730 #4 0x00000000004a4012 in receive_msg (buf=<value optimized out>, len=<value optimized out>, rcv_info=<value optimized out>) at receive.c:297 #5 0x000000000052a251 in tcp_read_req (con=0x7fc1ca4c6e00, bytes_read=0x7fff041b327c, read_flags=0x7fff041b3274) at tcp_read.c:1387 #6 0x000000000052c53b in handle_io (fm=<value optimized out>, events=1, idx=-1) at tcp_read.c:1617 #7 0x000000000052eb69 in io_wait_loop_epoll (unix_sock=<value optimized out>) at io_wait.h:1092 #8 tcp_receive_loop (unix_sock=<value optimized out>) at tcp_read.c:1728 #9 0x00000000004fc0eb in tcp_init_children () at tcp_main.c:4959 #10 0x000000000046c3d5 in main_loop () at main.c:1702 #11 0x000000000046dec9 in main (argc=<value optimized out>, argv=<value optimized out>) at main.c:2533
(gdb) frame 2 #2 0x000000000055027f in reset_ruid (msg=0x7fc1e1c35360) at parser/msg_parser.c:911 911 pkg_free(msg->ruid.s); (gdb) p msg->ruid $7 = {s = 0x845d20 "", len = 20}
Might this be related to the changes made on Sept 19th to the free_sip_msg functions?
Regards, Hugh
Extra output below. Nothing was printed in the logs (WARNING or ERROR level) before the crash. It seemed to be quite reproduceable when there was traffic being sent to registered websocket clients, but there is no-one online now. We'll have multiple people logged on tomorrow morning.
Regards, Hugh
kamailio -v version: kamailio 4.1.0-dev9 (x86_64/linux) flags: STATS: Off, USE_TCP, USE_TLS, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, 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 4MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: unknown compiled on 13:35:36 Oct 2 2013 with gcc 4.4.7
(gdb) bt full #0 qm_insert_free (qm=0x7fc1e1b9e010, p=<value optimized out>) at mem/q_malloc.c:181 f = 0x845d10 prev = 0x65332d3231653163 hash = 0 #1 qm_free (qm=0x7fc1e1b9e010, p=<value optimized out>) at mem/q_malloc.c:527 f = 0x845d10 size = <value optimized out> next = <value optimized out> prev = <value optimized out> __FUNCTION__ = "qm_free" #2 0x000000000055027f in reset_ruid (msg=0x7fc1e1c35360) at parser/msg_parser.c:911 No locals. #3 free_sip_msg (msg=0x7fc1e1c35360) at parser/msg_parser.c:730 No locals. #4 0x00000000004a4012 in receive_msg (buf=<value optimized out>, len=<value optimized out>, rcv_info=<value optimized out>) at receive.c:297 msg = 0x7fc1e1c35360 ctx = {rec_lev = 0, run_flags = 0, last_retcode = 1, jmp_env = {{__jmpbuf = {1048575, -3596212518023615478, 140470693039152, 140470299422208, 140470299422208, 140733262279292, 140733262279292, 140733262279284}, __mask_was_saved = -900960744, __saved_mask = {__val = {5406222, 532575944923, 541165879417, 4294967297, 1042, 140470299422952, 5409666, 65535, 140733262279284, 140470300510264, 140470697171281, 1042, 140470300510984, 18446744072809678880, 16, 17179869210}}}}} ret = <value optimized out> inb = { s = 0x23d7cc0 "OPTIONS sip:gavin.llewellyn@crocodiletalk.com SIP/2.0\r\nVia: SIP/2.0/TCP edge00-int.crocodilertc.net:5080;branch=z9hG4bKab92.bb8249afcf13f20080f25121e49865b8.0\r\nVia: SIP/2.0/WSS qvis2mie4gas.invalid;rp"..., len = 1028} __FUNCTION__ = "receive_msg" #5 0x000000000052a251 in tcp_read_req (con=0x7fc1ca4c6e00, bytes_read=0x7fff041b327c, read_flags=0x7fff041b3274) at tcp_read.c:1387 bytes = <value optimized out> total_bytes = 1028 resp = 1 size = <value optimized out> req = 0x7fc1ca4c6e80 dst = {send_sock = 0x14, to = {s = {sa_family = 1, sa_data = "\000\000\001\000\000\000\001 \000\000x\313\306", <incomplete sequence \341>}, sin = {sin_family = 1, sin_port = 0, sin_addr = {s_addr = 1}, sin_zero = "\001 \000\000x\313\306", <incomplete sequence \341>}, sin6 = {sin6_family = 1, sin6_port = 0, sin6_flowinfo = 1, sin6_addr = {__in6_u = { __u6_addr8 = "\001 \000\000x\313\306\341\301\177\000\000\000\000\000", __u6_addr16 = {8193, 0, 52088, 57798, 32705, 0, 0, 0}, __u6_addr32 = {8193, 3787901816, 32705, 0}}}, sin6_scope_id = 68891240}}, id = 32767, proto = 8 '\b', send_flags = { f = 0 '\000', blst_imask = 0 '\000'}} c = 13 '\r' ret = <value optimized out> __FUNCTION__ = "tcp_read_req" #6 0x000000000052c53b in handle_io (fm=<value optimized out>, events=1, idx=-1) at tcp_read.c:1617 ret = <value optimized out> n = <value optimized out> read_flags = 1 con = 0x7fc1ca4c6e00 s = <value optimized out> resp = <value optimized out> t = <value optimized out> __FUNCTION__ = "handle_io" #7 0x000000000052eb69 in io_wait_loop_epoll (unix_sock=<value optimized out>) at io_wait.h:1092
usrloc db_mode is 3. db_ops_ruid is 1 as well
Hugh On 02/10/2013 20:41, Daniel-Constantin Mierla wrote:
One more question, what is the value of db_mode for usrloc module?
Cheers, Daniel
On 10/2/13 9:28 PM, Hugh Waite wrote:
On 02/10/2013 19:18, Daniel-Constantin Mierla wrote:
Hello,
can you give bt full as well as kamailio -v output? Any log error messages?
Also, it would be good to recompile with MEMDBG=1 and watch for errors in the logs to see if there is a buffer overflow.
Cheers, Daniel
On 10/2/13 7:19 PM, Hugh Waite wrote:
Hi, We've had some more crashes on the current master build. (gdb) bt #0 qm_insert_free (qm=0x7fc1e1b9e010, p=<value optimized out>) at mem/q_malloc.c:181 #1 qm_free (qm=0x7fc1e1b9e010, p=<value optimized out>) at mem/q_malloc.c:527 #2 0x000000000055027f in reset_ruid (msg=0x7fc1e1c35360) at parser/msg_parser.c:911 #3 free_sip_msg (msg=0x7fc1e1c35360) at parser/msg_parser.c:730 #4 0x00000000004a4012 in receive_msg (buf=<value optimized out>, len=<value optimized out>, rcv_info=<value optimized out>) at receive.c:297 #5 0x000000000052a251 in tcp_read_req (con=0x7fc1ca4c6e00, bytes_read=0x7fff041b327c, read_flags=0x7fff041b3274) at tcp_read.c:1387 #6 0x000000000052c53b in handle_io (fm=<value optimized out>, events=1, idx=-1) at tcp_read.c:1617 #7 0x000000000052eb69 in io_wait_loop_epoll (unix_sock=<value optimized out>) at io_wait.h:1092 #8 tcp_receive_loop (unix_sock=<value optimized out>) at tcp_read.c:1728 #9 0x00000000004fc0eb in tcp_init_children () at tcp_main.c:4959 #10 0x000000000046c3d5 in main_loop () at main.c:1702 #11 0x000000000046dec9 in main (argc=<value optimized out>, argv=<value optimized out>) at main.c:2533
(gdb) frame 2 #2 0x000000000055027f in reset_ruid (msg=0x7fc1e1c35360) at parser/msg_parser.c:911 911 pkg_free(msg->ruid.s); (gdb) p msg->ruid $7 = {s = 0x845d20 "", len = 20}
Might this be related to the changes made on Sept 19th to the free_sip_msg functions?
Regards, Hugh
Extra output below. Nothing was printed in the logs (WARNING or ERROR level) before the crash. It seemed to be quite reproduceable when there was traffic being sent to registered websocket clients, but there is no-one online now. We'll have multiple people logged on tomorrow morning.
Regards, Hugh
kamailio -v version: kamailio 4.1.0-dev9 (x86_64/linux) flags: STATS: Off, USE_TCP, USE_TLS, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, 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 4MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: unknown compiled on 13:35:36 Oct 2 2013 with gcc 4.4.7
(gdb) bt full #0 qm_insert_free (qm=0x7fc1e1b9e010, p=<value optimized out>) at mem/q_malloc.c:181 f = 0x845d10 prev = 0x65332d3231653163 hash = 0 #1 qm_free (qm=0x7fc1e1b9e010, p=<value optimized out>) at mem/q_malloc.c:527 f = 0x845d10 size = <value optimized out> next = <value optimized out> prev = <value optimized out> __FUNCTION__ = "qm_free" #2 0x000000000055027f in reset_ruid (msg=0x7fc1e1c35360) at parser/msg_parser.c:911 No locals. #3 free_sip_msg (msg=0x7fc1e1c35360) at parser/msg_parser.c:730 No locals. #4 0x00000000004a4012 in receive_msg (buf=<value optimized out>, len=<value optimized out>, rcv_info=<value optimized out>) at receive.c:297 msg = 0x7fc1e1c35360 ctx = {rec_lev = 0, run_flags = 0, last_retcode = 1, jmp_env = {{__jmpbuf = {1048575, -3596212518023615478, 140470693039152, 140470299422208, 140470299422208, 140733262279292, 140733262279292, 140733262279284}, __mask_was_saved = -900960744, __saved_mask = {__val = {5406222, 532575944923, 541165879417, 4294967297, 1042, 140470299422952, 5409666, 65535, 140733262279284, 140470300510264, 140470697171281, 1042, 140470300510984, 18446744072809678880, 16, 17179869210}}}}} ret = <value optimized out> inb = { s = 0x23d7cc0 "OPTIONS sip:gavin.llewellyn@crocodiletalk.com SIP/2.0\r\nVia: SIP/2.0/TCP edge00-int.crocodilertc.net:5080;branch=z9hG4bKab92.bb8249afcf13f20080f25121e49865b8.0\r\nVia: SIP/2.0/WSS qvis2mie4gas.invalid;rp"..., len = 1028} __FUNCTION__ = "receive_msg" #5 0x000000000052a251 in tcp_read_req (con=0x7fc1ca4c6e00, bytes_read=0x7fff041b327c, read_flags=0x7fff041b3274) at tcp_read.c:1387 bytes = <value optimized out> total_bytes = 1028 resp = 1 size = <value optimized out> req = 0x7fc1ca4c6e80 dst = {send_sock = 0x14, to = {s = {sa_family = 1, sa_data = "\000\000\001\000\000\000\001 \000\000x\313\306", <incomplete sequence \341>}, sin = {sin_family = 1, sin_port = 0, sin_addr = {s_addr = 1}, sin_zero = "\001 \000\000x\313\306", <incomplete sequence \341>}, sin6 = {sin6_family = 1, sin6_port = 0, sin6_flowinfo = 1, sin6_addr = {__in6_u = { __u6_addr8 = "\001 \000\000x\313\306\341\301\177\000\000\000\000\000", __u6_addr16 = {8193, 0, 52088, 57798, 32705, 0, 0, 0}, __u6_addr32 = {8193, 3787901816, 32705, 0}}}, sin6_scope_id = 68891240}}, id = 32767, proto = 8 '\b', send_flags = { f = 0 '\000', blst_imask = 0 '\000'}} c = 13 '\r' ret = <value optimized out> __FUNCTION__ = "tcp_read_req" #6 0x000000000052c53b in handle_io (fm=<value optimized out>, events=1, idx=-1) at tcp_read.c:1617 ret = <value optimized out> n = <value optimized out> read_flags = 1 con = 0x7fc1ca4c6e00 s = <value optimized out> resp = <value optimized out> t = <value optimized out> __FUNCTION__ = "handle_io" #7 0x000000000052eb69 in io_wait_loop_epoll (unix_sock=<value optimized out>) at io_wait.h:1092
Nothing suspect so far. The crash is induced by my commit in to reset_ruid() in free sip msg function. It is needed otherwise is a leak, as set_ruid() is doing pkg_malloc(). So before was not crashing in this free, but leaked memory.
If you can reproduce it tomorrow, can you try to grab the logs with debug=3 (eventually with cfgtrace=1 for debugger module)? Apparently is an overwrite of the pointer, even should be a simple processing (I guess), because it is an OPTIONS request.
Cheers, Daniel
On 10/2/13 9:54 PM, Hugh Waite wrote:
usrloc db_mode is 3. db_ops_ruid is 1 as well
Hugh On 02/10/2013 20:41, Daniel-Constantin Mierla wrote:
One more question, what is the value of db_mode for usrloc module?
Cheers, Daniel
On 10/2/13 9:28 PM, Hugh Waite wrote:
On 02/10/2013 19:18, Daniel-Constantin Mierla wrote:
Hello,
can you give bt full as well as kamailio -v output? Any log error messages?
Also, it would be good to recompile with MEMDBG=1 and watch for errors in the logs to see if there is a buffer overflow.
Cheers, Daniel
On 10/2/13 7:19 PM, Hugh Waite wrote:
Hi, We've had some more crashes on the current master build. (gdb) bt #0 qm_insert_free (qm=0x7fc1e1b9e010, p=<value optimized out>) at mem/q_malloc.c:181 #1 qm_free (qm=0x7fc1e1b9e010, p=<value optimized out>) at mem/q_malloc.c:527 #2 0x000000000055027f in reset_ruid (msg=0x7fc1e1c35360) at parser/msg_parser.c:911 #3 free_sip_msg (msg=0x7fc1e1c35360) at parser/msg_parser.c:730 #4 0x00000000004a4012 in receive_msg (buf=<value optimized out>, len=<value optimized out>, rcv_info=<value optimized out>) at receive.c:297 #5 0x000000000052a251 in tcp_read_req (con=0x7fc1ca4c6e00, bytes_read=0x7fff041b327c, read_flags=0x7fff041b3274) at tcp_read.c:1387 #6 0x000000000052c53b in handle_io (fm=<value optimized out>, events=1, idx=-1) at tcp_read.c:1617 #7 0x000000000052eb69 in io_wait_loop_epoll (unix_sock=<value optimized out>) at io_wait.h:1092 #8 tcp_receive_loop (unix_sock=<value optimized out>) at tcp_read.c:1728 #9 0x00000000004fc0eb in tcp_init_children () at tcp_main.c:4959 #10 0x000000000046c3d5 in main_loop () at main.c:1702 #11 0x000000000046dec9 in main (argc=<value optimized out>, argv=<value optimized out>) at main.c:2533
(gdb) frame 2 #2 0x000000000055027f in reset_ruid (msg=0x7fc1e1c35360) at parser/msg_parser.c:911 911 pkg_free(msg->ruid.s); (gdb) p msg->ruid $7 = {s = 0x845d20 "", len = 20}
Might this be related to the changes made on Sept 19th to the free_sip_msg functions?
Regards, Hugh
Extra output below. Nothing was printed in the logs (WARNING or ERROR level) before the crash. It seemed to be quite reproduceable when there was traffic being sent to registered websocket clients, but there is no-one online now. We'll have multiple people logged on tomorrow morning.
Regards, Hugh
kamailio -v version: kamailio 4.1.0-dev9 (x86_64/linux) flags: STATS: Off, USE_TCP, USE_TLS, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, 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 4MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: unknown compiled on 13:35:36 Oct 2 2013 with gcc 4.4.7
(gdb) bt full #0 qm_insert_free (qm=0x7fc1e1b9e010, p=<value optimized out>) at mem/q_malloc.c:181 f = 0x845d10 prev = 0x65332d3231653163 hash = 0 #1 qm_free (qm=0x7fc1e1b9e010, p=<value optimized out>) at mem/q_malloc.c:527 f = 0x845d10 size = <value optimized out> next = <value optimized out> prev = <value optimized out> __FUNCTION__ = "qm_free" #2 0x000000000055027f in reset_ruid (msg=0x7fc1e1c35360) at parser/msg_parser.c:911 No locals. #3 free_sip_msg (msg=0x7fc1e1c35360) at parser/msg_parser.c:730 No locals. #4 0x00000000004a4012 in receive_msg (buf=<value optimized out>, len=<value optimized out>, rcv_info=<value optimized out>) at receive.c:297 msg = 0x7fc1e1c35360 ctx = {rec_lev = 0, run_flags = 0, last_retcode = 1, jmp_env = {{__jmpbuf = {1048575, -3596212518023615478, 140470693039152, 140470299422208, 140470299422208, 140733262279292, 140733262279292, 140733262279284}, __mask_was_saved = -900960744, __saved_mask = {__val = {5406222, 532575944923, 541165879417, 4294967297, 1042, 140470299422952, 5409666, 65535, 140733262279284, 140470300510264, 140470697171281, 1042, 140470300510984, 18446744072809678880, 16, 17179869210}}}}} ret = <value optimized out> inb = { s = 0x23d7cc0 "OPTIONS sip:gavin.llewellyn@crocodiletalk.com SIP/2.0\r\nVia: SIP/2.0/TCP edge00-int.crocodilertc.net:5080;branch=z9hG4bKab92.bb8249afcf13f20080f25121e49865b8.0\r\nVia: SIP/2.0/WSS qvis2mie4gas.invalid;rp"..., len = 1028} __FUNCTION__ = "receive_msg" #5 0x000000000052a251 in tcp_read_req (con=0x7fc1ca4c6e00, bytes_read=0x7fff041b327c, read_flags=0x7fff041b3274) at tcp_read.c:1387 bytes = <value optimized out> total_bytes = 1028 resp = 1 size = <value optimized out> req = 0x7fc1ca4c6e80 dst = {send_sock = 0x14, to = {s = {sa_family = 1, sa_data = "\000\000\001\000\000\000\001 \000\000x\313\306", <incomplete sequence \341>}, sin = {sin_family = 1, sin_port = 0, sin_addr = {s_addr = 1}, sin_zero = "\001 \000\000x\313\306", <incomplete sequence \341>}, sin6 = {sin6_family = 1, sin6_port = 0, sin6_flowinfo = 1, sin6_addr = {__in6_u = { __u6_addr8 = "\001 \000\000x\313\306\341\301\177\000\000\000\000\000", __u6_addr16 = {8193, 0, 52088, 57798, 32705, 0, 0, 0}, __u6_addr32 = {8193, 3787901816, 32705, 0}}}, sin6_scope_id = 68891240}}, id = 32767, proto = 8 '\b', send_flags = { f = 0 '\000', blst_imask = 0 '\000'}} c = 13 '\r' ret = <value optimized out> __FUNCTION__ = "tcp_read_req" #6 0x000000000052c53b in handle_io (fm=<value optimized out>, events=1, idx=-1) at tcp_read.c:1617 ret = <value optimized out> n = <value optimized out> read_flags = 1 con = 0x7fc1ca4c6e00 s = <value optimized out> resp = <value optimized out> t = <value optimized out> __FUNCTION__ = "handle_io" #7 0x000000000052eb69 in io_wait_loop_epoll (unix_sock=<value optimized out>) at io_wait.h:1092
I have checked in a fix for this bug. The pkg malloc'd string was backed-up at the top of the function, but not restored, leaving the ruid pointing at a static variable.
Many thanks to Daniel for searching and finding the bug that I created in the first place.
Hugh
On 02/10/2013 21:42, Daniel-Constantin Mierla wrote:
Nothing suspect so far. The crash is induced by my commit in to reset_ruid() in free sip msg function. It is needed otherwise is a leak, as set_ruid() is doing pkg_malloc(). So before was not crashing in this free, but leaked memory.
If you can reproduce it tomorrow, can you try to grab the logs with debug=3 (eventually with cfgtrace=1 for debugger module)? Apparently is an overwrite of the pointer, even should be a simple processing (I guess), because it is an OPTIONS request.
Cheers, Daniel
On 10/2/13 9:54 PM, Hugh Waite wrote:
usrloc db_mode is 3. db_ops_ruid is 1 as well
Hugh On 02/10/2013 20:41, Daniel-Constantin Mierla wrote:
One more question, what is the value of db_mode for usrloc module?
Cheers, Daniel
On 10/2/13 9:28 PM, Hugh Waite wrote:
On 02/10/2013 19:18, Daniel-Constantin Mierla wrote:
Hello,
can you give bt full as well as kamailio -v output? Any log error messages?
Also, it would be good to recompile with MEMDBG=1 and watch for errors in the logs to see if there is a buffer overflow.
Cheers, Daniel
On 10/2/13 7:19 PM, Hugh Waite wrote:
Hi, We've had some more crashes on the current master build. (gdb) bt #0 qm_insert_free (qm=0x7fc1e1b9e010, p=<value optimized out>) at mem/q_malloc.c:181 #1 qm_free (qm=0x7fc1e1b9e010, p=<value optimized out>) at mem/q_malloc.c:527 #2 0x000000000055027f in reset_ruid (msg=0x7fc1e1c35360) at parser/msg_parser.c:911 #3 free_sip_msg (msg=0x7fc1e1c35360) at parser/msg_parser.c:730 #4 0x00000000004a4012 in receive_msg (buf=<value optimized out>, len=<value optimized out>, rcv_info=<value optimized out>) at receive.c:297 #5 0x000000000052a251 in tcp_read_req (con=0x7fc1ca4c6e00, bytes_read=0x7fff041b327c, read_flags=0x7fff041b3274) at tcp_read.c:1387 #6 0x000000000052c53b in handle_io (fm=<value optimized out>, events=1, idx=-1) at tcp_read.c:1617 #7 0x000000000052eb69 in io_wait_loop_epoll (unix_sock=<value optimized out>) at io_wait.h:1092 #8 tcp_receive_loop (unix_sock=<value optimized out>) at tcp_read.c:1728 #9 0x00000000004fc0eb in tcp_init_children () at tcp_main.c:4959 #10 0x000000000046c3d5 in main_loop () at main.c:1702 #11 0x000000000046dec9 in main (argc=<value optimized out>, argv=<value optimized out>) at main.c:2533
(gdb) frame 2 #2 0x000000000055027f in reset_ruid (msg=0x7fc1e1c35360) at parser/msg_parser.c:911 911 pkg_free(msg->ruid.s); (gdb) p msg->ruid $7 = {s = 0x845d20 "", len = 20}
Might this be related to the changes made on Sept 19th to the free_sip_msg functions?
Regards, Hugh
Extra output below. Nothing was printed in the logs (WARNING or ERROR level) before the crash. It seemed to be quite reproduceable when there was traffic being sent to registered websocket clients, but there is no-one online now. We'll have multiple people logged on tomorrow morning.
Regards, Hugh
kamailio -v version: kamailio 4.1.0-dev9 (x86_64/linux) flags: STATS: Off, USE_TCP, USE_TLS, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, 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 4MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: unknown compiled on 13:35:36 Oct 2 2013 with gcc 4.4.7
(gdb) bt full #0 qm_insert_free (qm=0x7fc1e1b9e010, p=<value optimized out>) at mem/q_malloc.c:181 f = 0x845d10 prev = 0x65332d3231653163 hash = 0 #1 qm_free (qm=0x7fc1e1b9e010, p=<value optimized out>) at mem/q_malloc.c:527 f = 0x845d10 size = <value optimized out> next = <value optimized out> prev = <value optimized out> __FUNCTION__ = "qm_free" #2 0x000000000055027f in reset_ruid (msg=0x7fc1e1c35360) at parser/msg_parser.c:911 No locals. #3 free_sip_msg (msg=0x7fc1e1c35360) at parser/msg_parser.c:730 No locals. #4 0x00000000004a4012 in receive_msg (buf=<value optimized out>, len=<value optimized out>, rcv_info=<value optimized out>) at receive.c:297 msg = 0x7fc1e1c35360 ctx = {rec_lev = 0, run_flags = 0, last_retcode = 1, jmp_env = {{__jmpbuf = {1048575, -3596212518023615478, 140470693039152, 140470299422208, 140470299422208, 140733262279292, 140733262279292, 140733262279284}, __mask_was_saved = -900960744, __saved_mask = {__val = {5406222, 532575944923, 541165879417, 4294967297, 1042, 140470299422952, 5409666, 65535, 140733262279284, 140470300510264, 140470697171281, 1042, 140470300510984, 18446744072809678880, 16, 17179869210}}}}} ret = <value optimized out> inb = { s = 0x23d7cc0 "OPTIONS sip:gavin.llewellyn@crocodiletalk.com SIP/2.0\r\nVia: SIP/2.0/TCP edge00-int.crocodilertc.net:5080;branch=z9hG4bKab92.bb8249afcf13f20080f25121e49865b8.0\r\nVia: SIP/2.0/WSS qvis2mie4gas.invalid;rp"..., len = 1028} __FUNCTION__ = "receive_msg" #5 0x000000000052a251 in tcp_read_req (con=0x7fc1ca4c6e00, bytes_read=0x7fff041b327c, read_flags=0x7fff041b3274) at tcp_read.c:1387 bytes = <value optimized out> total_bytes = 1028 resp = 1 size = <value optimized out> req = 0x7fc1ca4c6e80 dst = {send_sock = 0x14, to = {s = {sa_family = 1, sa_data = "\000\000\001\000\000\000\001 \000\000x\313\306", <incomplete sequence \341>}, sin = {sin_family = 1, sin_port = 0, sin_addr = {s_addr = 1}, sin_zero = "\001 \000\000x\313\306", <incomplete sequence \341>}, sin6 = {sin6_family = 1, sin6_port = 0, sin6_flowinfo = 1, sin6_addr = {__in6_u = { __u6_addr8 = "\001 \000\000x\313\306\341\301\177\000\000\000\000\000", __u6_addr16 = {8193, 0, 52088, 57798, 32705, 0, 0, 0}, __u6_addr32 = {8193, 3787901816, 32705, 0}}}, sin6_scope_id = 68891240}}, id = 32767, proto = 8 '\b', send_flags = { f = 0 '\000', blst_imask = 0 '\000'}} c = 13 '\r' ret = <value optimized out> __FUNCTION__ = "tcp_read_req" #6 0x000000000052c53b in handle_io (fm=<value optimized out>, events=1, idx=-1) at tcp_read.c:1617 ret = <value optimized out> n = <value optimized out> read_flags = 1 con = 0x7fc1ca4c6e00 s = <value optimized out> resp = <value optimized out> t = <value optimized out> __FUNCTION__ = "handle_io" #7 0x000000000052eb69 in io_wait_loop_epoll (unix_sock=<value optimized out>) at io_wait.h:1092
-
Alex Balashov -
Daniel-Constantin Mierla -
Hugh Waite