[SR-Users] xmlrpc crash

Daniel-Constantin Mierla miconda at gmail.com
Tue May 3 08:15:15 CEST 2016


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)?

Cheers,
Daniel

On 02/05/16 21:03, Juha Heinanen wrote:
> 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 at 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 at 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 at entry=0x7ffe98f54aa0, a=0x21f4080, a at entry=0x7f5deaf61b08, msg=0x71, 
>     msg at 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 at entry=0x7f5debeb4620 <main_arena>) at malloc.c:4151
> #1  0x00007f5debb88e98 in _int_malloc (av=av at entry=0x7f5debeb4620 <main_arena>, bytes=bytes at 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 at entry=0x7ffe98f547d0, sizeloc=sizeloc at entry=0x7ffe98f547d8)
>     at memstream.c:85
> #4  0x00007f5debbf307d in __GI___vsyslog_chk (pri=134, flag=flag at entry=-1, fmt=0x6d9c00 "%s: %s%s(): signal %d received\n", 
>     ap=ap at 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 at entry=0x7f5debeb4620 <main_arena>) at malloc.c:4151
> #1  0x00007f5debb88e98 in _int_malloc (av=av at entry=0x7f5debeb4620 <main_arena>, bytes=bytes at 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 at entry=0x7ffe98f547d0, sizeloc=sizeloc at entry=0x7ffe98f547d8)
>     at memstream.c:85
> #4  0x00007f5debbf307d in __GI___vsyslog_chk (pri=134, flag=flag at entry=-1, fmt=0x6d9c00 "%s: %s%s(): signal %d received\n", 
>     ap=ap at 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

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sip-router.org/pipermail/sr-users/attachments/20160503/b44f195b/attachment.html>


More information about the sr-users mailing list