These ones are no longer related to xmlrpc, but triggered by an sqlops query - first bracktrace, the other two are during the signal handling.
The one for sqlops leads quite a bit inside the libmysqlclient, which can happen because there is a buffer overflow in kamailio for the operations in the system memory or an issue in the libmysqlclient.
Trying to investigate on the first option -- does it happen
always after an xmlrpc command? If yes, it is any kind of command
or a specific xmlrpc command (I see you used htable.reload)?
Daniel-Constantin Mierla writes:do you get any error messages in the logs or error code in the xmlrpc reply?no error messages. the crash does not happen immediate when xmlrpc request is served. in the example below, the crash came about 20 sec later perhaps as result of some garbage collection activity. kamailio is listening xmlrpc requests at port 6060 and one get served: ##### T 2016/05/02 21:54:19.117214 127.0.0.1:46250 -> 127.0.0.1:6060 [AP] POST /RPC2 HTTP/1.1. User-Agent: XMLRPC++ 0.8. Host: 127.0.0.1:6060. Content-Type: text/xml. Content-length: 143. . <?xml version="1.0"?>. <methodCall><methodName>htable.reload</methodName>. <params><param><value>htable</value></param></params></methodCall>. ## T 2016/05/02 21:54:19.118067 127.0.0.1:6060 -> 127.0.0.1:46250 [AP] HTTP/1.1 200 OK. Sia: SIP/2.0/TCP 127.0.0.1:46250. Server: OpenXg SIP Proxy (4.4.0-1 (x86_64/linux)). Content-Length: 108. . <?xml version="1.0"?> <methodResponse> <params> <param> <value></value> </param> </params> </methodResponse> ##### then the crash comes: May 2 21:54:51 lohi kernel: [100671.026931] sip-proxy[1628]: segfault at 2213008 ip 00007f5debb87b45 sp 00007ffe98f51cf0 error 4 in libc-2.19.so[7f5debb0f000+1a2000] May 2 21:54:51 lohi kernel: [100671.111115] sip-proxy[1643]: segfault at 2213008 ip 00007f5debb87b45 sp 00007ffe98f54660 error 4 in libc-2.19.so[7f5debb0f000+1a2000] May 2 21:54:51 lohi kernel: [100671.114042] sip-proxy[1638]: segfault at 2213008 ip 00007f5debb87b45 sp 00007ffe98f54660 error 4 in libc-2.19.so[7f5debb0f000+1a2000] May 2 21:54:51 lohi /usr/bin/sip-proxy[1649]: CRITICAL: <core> [pass_fd.c:275]: receive_fd(): EOF on 39 May 2 21:54:51 lohi /usr/bin/sip-proxy[1563]: ALERT: <core> [main.c:739]: handle_sigs(): child process 1628 exited by a signal 11 May 2 21:54:51 lohi /usr/bin/sip-proxy[1563]: ALERT: <core> [main.c:742]: handle_sigs(): core was generated three cores are generated: 47508 -rw------- 1 root root 60002304 May 2 21:54 core.sip-proxy.sig11.1628 47508 -rw------- 1 root root 60002304 May 2 21:54 core.sip-proxy.sig11.1638 47508 -rw------- 1 root root 60002304 May 2 21:54 core.sip-proxy.sig11.1643 first one: (gdb) where #0 malloc_consolidate (av=av@entry=0x7f5debeb4620 <main_arena>) at malloc.c:4151 #1 0x00007f5debb88e98 in _int_malloc (av=0x7f5debeb4620 <main_arena>, bytes=8160) at malloc.c:3423 #2 0x00007f5debb8b020 in __GI___libc_malloc (bytes=8160) at malloc.c:2891 #3 0x00007f5de9f5fd14 in my_malloc () from /usr/lib/x86_64-linux-gnu/libmysqlclient.so.18 #4 0x00007f5de9f5b6ac in alloc_root () from /usr/lib/x86_64-linux-gnu/libmysqlclient.so.18 #5 0x00007f5de9f3fc5c in cli_read_rows () from /usr/lib/x86_64-linux-gnu/libmysqlclient.so.18 #6 0x00007f5de9f40b75 in ?? () from /usr/lib/x86_64-linux-gnu/libmysqlclient.so.18 #7 0x00007f5de9f4167e in mysql_real_query () from /usr/lib/x86_64-linux-gnu/libmysqlclient.so.18 #8 0x00007f5dea452705 in db_mysql_submit_query (_h=0x7f5deaf2f940, _s=0x7ffe98f520e0) at km_dbase.c:116 #9 0x00007f5dea89fb94 in db_do_submit_query (submit_query=<optimized out>, _query=<optimized out>, _h=<optimized out>) at db_query.c:53 #10 db_do_raw_query (_h=0x7f5deaf2f940, _s=0x7ffe98f520e0, _r=0x7ffe98f52090, submit_query=0x7f5debeb4678 <main_arena+88>, store_result=0x7f5dea453cd0 <db_mysql_store_result>) at db_query.c:180 #11 0x00007f5dde409f5c in sql_do_query (con=0x21f4080, query=0x7ffe98f520e0, res=0x7f5deb6964e8) at sql_api.c:262 #12 0x00007f5dde41554e in sql_query (msg=0x21f4080, dbl=0x7f5deaf5dbe0 "\030\333\365\352]\177", query=0x21f4080 "", res=0x7f5deb6964e8 "\245\246=|") at sqlops.c:210 #13 0x000000000053cf2a in do_action (h=0x7ffe98f52be0, a=0x7f5deb7ca0d8, msg=0x7f5deb2753e8) at action.c:1072 #14 0x000000000053ad85 in run_actions (h=0x21f4080, a=0x21f4080, msg=0x71) at action.c:1549 #15 0x000000000053c9b0 in do_action (h=0x7ffe98f52be0, a=0x7f5deb7c09e8, msg=0x7f5deb2753e8) at action.c:678 #16 0x000000000053ad85 in run_actions (h=0x21f4080, h@entry=0x7ffe98f52be0, a=0x21f4080, msg=0x71) at action.c:1549 #17 0x0000000000547757 in run_actions_safe (h=0x7ffe98f54aa0, a=<optimized out>, msg=<optimized out>) at action.c:1614 #18 0x0000000000424720 in rval_get_int (h=0x7ffe98f54aa0, msg=0x21f4080, i=0x7ffe98f52ee4, rv=0x7f5debeb4678 <main_arena+88>, cache=0x7f5debeb4628 <main_arena+8>) at rvalue.c:912 #19 0x000000000042a4ac in rval_expr_eval_int (h=0x7ffe98f54aa0, msg=0x7f5deb2753e8, res=0x7ffe98f52ee4, rve=0x7f5deb0f97f0) at rvalue.c:1910 #20 0x000000000042a5a6 in rval_expr_eval_int (h=0x7ffe98f54aa0, msg=0x7f5deb2753e8, res=0x7ffe98f53060, rve=0x7f5deb0f9f00) at rvalue.c:1918 #21 0x000000000053c797 in do_action (h=0x7ffe98f54aa0, a=0x7f5deb1006b8, msg=0x7f5deb2753e8) at action.c:1030 #22 0x000000000053ad85 in run_actions (h=0x21f4080, a=0x21f4080, msg=0x71) at action.c:1549 #23 0x000000000053c9b0 in do_action (h=0x7ffe98f54aa0, a=0x7f5deb7c09e8, msg=0x7f5deb2753e8) at action.c:678 #24 0x000000000053ad85 in run_actions (h=0x21f4080, a=0x21f4080, msg=0x71) at action.c:1549 #25 0x000000000053c7e8 in do_action (h=0x7ffe98f54aa0, a=0x7f5deaf79008, msg=0x7f5deb2753e8) at action.c:1049 #26 0x000000000053ad85 in run_actions (h=0x21f4080, a=0x21f4080, msg=0x71) at action.c:1549 #27 0x000000000053c9b0 in do_action (h=0x7ffe98f54aa0, a=0x7f5deb7c09e8, msg=0x7f5deb2753e8) at action.c:678 ---Type <return> to continue, or q <return> to quit--- #28 0x000000000053ad85 in run_actions (h=0x21f4080, a=0x21f4080, msg=0x71) at action.c:1549 #29 0x000000000053c7e8 in do_action (h=0x7ffe98f54aa0, a=0x7f5deaf77f90, msg=0x7f5deb2753e8) at action.c:1049 #30 0x000000000053ad85 in run_actions (h=0x21f4080, h@entry=0x7ffe98f54aa0, a=0x21f4080, a@entry=0x7f5deaf61b08, msg=0x71, msg@entry=0x7f5deb2753e8) at action.c:1549 #31 0x00000000005477f5 in run_top_route (a=0x7f5deaf61b08, msg=0x7f5deb2753e8, c=<optimized out>) at action.c:1635 #32 0x000000000054968e in receive_msg (buf=0x0, len=3945223144, rcv_info=0x7f5de3a2e358) at receive.c:239 #33 0x00000000005cb97a in tcp_read_req (con=0x7f5de3a2e340, bytes_read=0x7ffe98f54e24, read_flags=0x7ffe98f54e28) at tcp_read.c:1418 #34 0x00000000005d0293 in handle_io (fm=0x7f5de3a2e340, events=16512, idx=-1) at tcp_read.c:1611 #35 0x00000000005d6bce in io_wait_loop_epoll (h=<optimized out>, t=<optimized out>, repeat=<optimized out>) at io_wait.h:1061 #36 tcp_receive_loop (unix_sock=35602560) at tcp_read.c:1781 #37 0x00000000004d9df7 in tcp_init_children () at tcp_main.c:4788 #38 0x000000000050736f in main_loop () at main.c:1690 #39 0x000000000041cdbc in main (argc=0, argv=0x0) at main.c:2616 second one: (gdb) where #0 malloc_consolidate (av=av@entry=0x7f5debeb4620 <main_arena>) at malloc.c:4151 #1 0x00007f5debb88e98 in _int_malloc (av=av@entry=0x7f5debeb4620 <main_arena>, bytes=bytes@entry=8192) at malloc.c:3423 #2 0x00007f5debb8b9dc in __libc_calloc (n=<optimized out>, elem_size=<optimized out>) at malloc.c:3219 #3 0x00007f5debb80d43 in __GI_open_memstream (bufloc=bufloc@entry=0x7ffe98f547d0, sizeloc=sizeloc@entry=0x7ffe98f547d8) at memstream.c:85 #4 0x00007f5debbf307d in __GI___vsyslog_chk (pri=134, flag=flag@entry=-1, fmt=0x6d9c00 "%s: %s%s(): signal %d received\n", ap=ap@entry=0x7ffe98f548a8) at ../misc/syslog.c:167 #5 0x00007f5debbf35bf in __syslog (pri=<optimized out>, fmt=<optimized out>) at ../misc/syslog.c:117 #6 0x0000000000502f49 in sig_usr (signo=35602560) at main.c:809 #7 <signal handler called> #8 0x00007f5debbf7e53 in epoll_wait () at ../sysdeps/unix/syscall-template.S:81 #9 0x00000000005d6b81 in io_wait_loop_epoll (h=<optimized out>, t=<optimized out>, repeat=<optimized out>) at io_wait.h:1030 #10 tcp_receive_loop (unix_sock=14) at tcp_read.c:1781 #11 0x00000000004d9df7 in tcp_init_children () at tcp_main.c:4788 #12 0x000000000050736f in main_loop () at main.c:1690 #13 0x000000000041cdbc in main (argc=0, argv=0x0) at main.c:2616 third one: (gdb) where #0 malloc_consolidate (av=av@entry=0x7f5debeb4620 <main_arena>) at malloc.c:4151 #1 0x00007f5debb88e98 in _int_malloc (av=av@entry=0x7f5debeb4620 <main_arena>, bytes=bytes@entry=8192) at malloc.c:3423 #2 0x00007f5debb8b9dc in __libc_calloc (n=<optimized out>, elem_size=<optimized out>) at malloc.c:3219 #3 0x00007f5debb80d43 in __GI_open_memstream (bufloc=bufloc@entry=0x7ffe98f547d0, sizeloc=sizeloc@entry=0x7ffe98f547d8) at memstream.c:85 #4 0x00007f5debbf307d in __GI___vsyslog_chk (pri=134, flag=flag@entry=-1, fmt=0x6d9c00 "%s: %s%s(): signal %d received\n", ap=ap@entry=0x7ffe98f548a8) at ../misc/syslog.c:167 #5 0x00007f5debbf35bf in __syslog (pri=<optimized out>, fmt=<optimized out>) at ../misc/syslog.c:117 #6 0x0000000000502f49 in sig_usr (signo=35602560) at main.c:809 #7 <signal handler called> #8 0x00007f5debbf7e53 in epoll_wait () at ../sysdeps/unix/syscall-template.S:81 #9 0x00000000005d6b81 in io_wait_loop_epoll (h=<optimized out>, t=<optimized out>, repeat=<optimized out>) at io_wait.h:1030 #10 tcp_receive_loop (unix_sock=14) at tcp_read.c:1781 #11 0x00000000004d9df7 in tcp_init_children () at tcp_main.c:4788 #12 0x000000000050736f in main_loop () at main.c:1690 #13 0x000000000041cdbc in main (argc=0, argv=0x0) at main.c:2616 -- juha
-- Daniel-Constantin Mierla http://www.asipto.com http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda Kamailio World Conference, Berlin, May 18-20, 2016 - http://www.kamailioworld.com