[OpenSIPS-Devel] [opensips] deadlock in opensips causing 100% cpu (#630)

Sat Sep 5 15:40:46 CEST 2015

Thanks Vlad for debugging this issue on our server. The GDB information as requested 

Loaded symbols for /lib64/libnss_files.so.2
0x00007feb5b4232f7 in sched_yield () from /lib64/libc.so.6
Missing separate debuginfos, use: debuginfo-install glibc-2.12-1.166.el6.x86_64 keyutils-libs-1.4-4.el6.x86_64 krb5-libs-1.10.3-42.el6.x86_64 libcom_err-1.41.12-18.el6.x86_64 libselinux-2.0.94-5.3.el6_4.1.x86_64 openssl-1.0.1e-42.el6.x86_64 zlib-1.2.3-29.el6.x86_64
(gdb) bt
#0  0x00007feb5b4232f7 in sched_yield () from /lib64/libc.so.6
#1  0x00000000004bd305 in get_lock (tcpconn=0x7feb478bbc28) at fastlock.h:182
#2  tcpconn_destroy (tcpconn=0x7feb478bbc28) at tcp_main.c:1502
#3  0x00000000004bf93e in handle_tcp_child (tcp_c=0x7feb58fa72d4, fd_i=<value optimized out>) at tcp_main.c:1779
#4  0x00000000004c1abc in io_wait_loop_epoll () at io_wait.h:845
#5  tcp_main_loop () at tcp_main.c:2152
#6  0x000000000043b038 in main_loop (argc=<value optimized out>, argv=<value optimized out>) at main.c:1040
#7  main (argc=<value optimized out>, argv=<value optimized out>) at main.c:1612
(gdb) f 2
#2  tcpconn_destroy (tcpconn=0x7feb478bbc28) at tcp_main.c:1502
1502    tcp_main.c: No such file or directory.
        in tcp_main.c
(gdb) 
#2  tcpconn_destroy (tcpconn=0x7feb478bbc28) at tcp_main.c:1502
1502    in tcp_main.c
(gdb) 
#2  tcpconn_destroy (tcpconn=0x7feb478bbc28) at tcp_main.c:1502
1502    in tcp_main.c
(gdb) 
#2  tcpconn_destroy (tcpconn=0x7feb478bbc28) at tcp_main.c:1502
1502    in tcp_main.c
(gdb) ^Z
[2]+  Stopped                 gdb /usr/sbin/opensips 10320
[root at ffdray-mm630-195-10 zuser]# fg
gdb /usr/sbin/opensips 10320
(gdb) 
#2  tcpconn_destroy (tcpconn=0x7feb478bbc28) at tcp_main.c:1502
1502    in tcp_main.c
(gdb) 
#2  tcpconn_destroy (tcpconn=0x7feb478bbc28) at tcp_main.c:1502
1502    in tcp_main.c
(gdb) 
#2  tcpconn_destroy (tcpconn=0x7feb478bbc28) at tcp_main.c:1502
1502    in tcp_main.c
(gdb) f 1
#1  0x00000000004bd305 in get_lock (tcpconn=0x7feb478bbc28) at fastlock.h:182
182     fastlock.h: No such file or directory.
        in fastlock.h
(gdb) p 2
$1 = 2
(gdb) fg 2

Loaded symbols for /lib64/libnss_files.so.2
0x00007feb5b4232f7 in sched_yield () from /lib64/libc.so.6
Missing separate debuginfos, use: debuginfo-install glibc-2.12-1.166.el6.x86_64 keyutils-libs-1.4-4.el6.x86_64 krb5-libs-1.10.3-42.el6.x86_64 libcom_err-1.41.12-18.el6.x86_64 libselinux-2.0.94-5.3.el6_4.1.x86_64 openssl-1.0.1e-42.el6.x86_64 zlib-1.2.3-29.el6.x86_64
(gdb) f 2
#2  tcpconn_destroy (tcpconn=0x7feb478bbc28) at tcp_main.c:1502
1502    tcp_main.c: No such file or directory.
        in tcp_main.c
(gdb) p *tcpconn
$1 = {s = 19, fd = -1, write_lock = 0, id = 13, rcv = {src_ip = {af = 2, len = 4, u = {addrl = {214158346, 0}, addr32 = {214158346, 0, 0, 0}, addr16 = {52234, 3267, 0, 0, 0, 0, 0, 0}, 
        addr = "\n\314\303\f", '\000' <repeats 11 times>}}, dst_ip = {af = 2, len = 4, u = {addrl = {180603914, 0}, addr32 = {180603914, 0, 0, 0}, addr16 = {52234, 2755, 0, 0, 0, 0, 0, 0}, 
        addr = "\n\314\303\n", '\000' <repeats 11 times>}}, src_port = 5060, dst_port = 5070, proto = 2, proto_reserved1 = 0, proto_reserved2 = 0, src_su = {s = {sa_family = 2, 
        sa_data = "\023\304\n\314\303\f\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 50195, sin_addr = {s_addr = 214158346}, sin_zero = "\000\000\000\000\000\000\000"}}, 
    bind_address = 0x7feb58f9a398}, refcnt = -11, type = PROTO_TCP, flags = 0, state = S_CONN_BAD, extra_data = 0x0, timeout = 0, lifetime = 0, id_hash = 13, id_next = 0x0, id_prev = 0x0, c_next = 0x0, 
  c_prev = 0x0, con_aliases = {{parent = 0x7feb478bbc28, next = 0x7feb478bbcd8, prev = 0x7feb478bbcd8, port = 5060, hash = 974}, {parent = 0x0, next = 0x0, prev = 0x0, port = 0, hash = 0}, {parent = 0x0, 
      next = 0x0, prev = 0x0, port = 0, hash = 0}, {parent = 0x0, next = 0x0, prev = 0x0, port = 0, hash = 0}}, aliases = 1, con_req = 0x0, msg_attempts = 0, async_chunks = 0x7feb478bbd98, 
  async_chunks_no = 0, oldest_chunk = 0}
(gdb) ^Z

Loaded symbols for /lib64/libnss_files.so.2
0x00007feb5b4232f7 in sched_yield () from /lib64/libc.so.6
Missing separate debuginfos, use: debuginfo-install glibc-2.12-1.166.el6.x86_64 keyutils-libs-1.4-4.el6.x86_64 krb5-libs-1.10.3-42.el6.x86_64 libcom_err-1.41.12-18.el6.x86_64 libselinux-2.0.94-5.3.el6_4.1.x86_64 openssl-1.0.1e-42.el6.x86_64 zlib-1.2.3-29.el6.x86_64
(gdb) bt
#0  0x00007feb5b4232f7 in sched_yield () from /lib64/libc.so.6
#1  0x00000000004bbe3f in get_lock (send_sock=0x7feb58f9a398, type=2, buf=<value optimized out>, len=<value optimized out>, to=<value optimized out>, id=<value optimized out>) at fastlock.h:182
#2  tcpconn_put (send_sock=0x7feb58f9a398, type=2, buf=<value optimized out>, len=<value optimized out>, to=<value optimized out>, id=<value optimized out>) at tcp_main.c:986
#3  tcp_send (send_sock=0x7feb58f9a398, type=2, buf=<value optimized out>, len=<value optimized out>, to=<value optimized out>, id=<value optimized out>) at tcp_main.c:1284
#4  0x0000000000430df9 in msg_send (send_sock=<value optimized out>, proto=<value optimized out>, to=0x7feb58fd12d8, id=<value optimized out>, 
    buf=0x7feb58fd13b0 "SIP/2.0 200 OK\r\nTo: <sip:testtoUser841 at ipc.com>;tag=906d8fc2\r\nVia: SIP/2.0/TCP 10.204.195.10:5069;branch=z9hG4bK+34727d29480074253143b3dd032b47a71+10.204.195.105069+1\r\nCSeq: 991486681 INFO\r\nContent-Le"..., len=366) at forward.h:115
#5  0x00000000004330ba in forward_reply (msg=0x7feb58fd0580) at forward.c:624
#6  0x000000000048102f in receive_msg (buf=<value optimized out>, len=<value optimized out>, rcv_info=<value optimized out>) at receive.c:214
#7  0x00000000004c4540 in tcp_read_req (con=0x7feb478bbc28, bytes_read=0x7fffeda7370c) at tcp_read.c:697
#8  0x00000000004c5908 in handle_io (fm=<value optimized out>, idx=-1, event_type=<value optimized out>) at tcp_read.c:1033
#9  0x00000000004c8083 in io_wait_loop_epoll (unix_sock=<value optimized out>) at io_wait.h:845
#10 tcp_receive_loop (unix_sock=<value optimized out>) at tcp_read.c:1141
#11 0x00000000004b12e9 in tcp_init_children (chd_rank=<value optimized out>, startup_done=0x0) at tcp_main.c:2389
#12 0x000000000043aebf in main_loop (argc=<value optimized out>, argv=<value optimized out>) at main.c:1011
#13 main (argc=<value optimized out>, argv=<value optimized out>) at main.c:1612
(gdb) f 3
#3  tcp_send (send_sock=0x7feb58f9a398, type=2, buf=<value optimized out>, len=<value optimized out>, to=<value optimized out>, id=<value optimized out>) at tcp_main.c:1284
1284    tcp_main.c: No such file or directory.
        in tcp_main.c
(gdb) f 2
#2  tcpconn_put (send_sock=0x7feb58f9a398, type=2, buf=<value optimized out>, len=<value optimized out>, to=<value optimized out>, id=<value optimized out>) at tcp_main.c:986
986     in tcp_main.c
(gdb) p tcpconn
No symbol "tcpconn" in current context.
(gdb) p con
No symbol "con" in current context.
(gdb) p conn
$1 = (aaa_conn *) 0x0
(gdb) f 2
#2  tcpconn_put (send_sock=0x7feb58f9a398, type=2, buf=<value optimized out>, len=<value optimized out>, to=<value optimized out>, id=<value optimized out>) at tcp_main.c:986
986     in tcp_main.c
(gdb) p c
$2 = (struct tcp_connection *) 0x7feb478bc138
(gdb) p *c
$3 = {s = 33, fd = 17, write_lock = 0, id = 11, rcv = {src_ip = {af = 2, len = 4, u = {addrl = {180603914, 0}, addr32 = {180603914, 0, 0, 0}, addr16 = {52234, 2755, 0, 0, 0, 0, 0, 0}, 
        addr = "\n\314\303\n", '\000' <repeats 11 times>}}, dst_ip = {af = 2, len = 4, u = {addrl = {180603914, 0}, addr32 = {180603914, 0, 0, 0}, addr16 = {52234, 2755, 0, 0, 0, 0, 0, 0}, 
        addr = "\n\314\303\n", '\000' <repeats 11 times>}}, src_port = 50746, dst_port = 5070, proto = 2, proto_reserved1 = 11, proto_reserved2 = 0, src_su = {s = {sa_family = 2, 
        sa_data = "\306:\n\314\303\n\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 15046, sin_addr = {s_addr = 180603914}, sin_zero = "\000\000\000\000\000\000\000"}}, 
    bind_address = 0x7feb58f9a398}, refcnt = 2, type = PROTO_TCP, flags = 2, state = S_CONN_ACCEPT, extra_data = 0x0, timeout = 5839, lifetime = 0, id_hash = 11, id_next = 0x0, id_prev = 0x0, c_next = 0x0, 
  c_prev = 0x0, con_aliases = {{parent = 0x7feb478bc138, next = 0x0, prev = 0x0, port = 50746, hash = 560}, {parent = 0x0, next = 0x0, prev = 0x0, port = 0, hash = 0}, {parent = 0x0, next = 0x0, prev = 0x0, 
      port = 0, hash = 0}, {parent = 0x0, next = 0x0, prev = 0x0, port = 0, hash = 0}}, aliases = 1, con_req = 0x7feb58fe7b40, msg_attempts = 0, async_chunks = 0x7feb478bc2a8, async_chunks_no = 0, 
  oldest_chunk = 0}
(gdb) f 7
#7  0x00000000004c4540 in tcp_read_req (con=0x7feb478bbc28, bytes_read=0x7fffeda7370c) at tcp_read.c:697
697     tcp_read.c: No such file or directory.
        in tcp_read.c
(gdb) p size
$4 = 36452
(gdb) f 7
#7  0x00000000004c4540 in tcp_read_req (con=0x7feb478bbc28, bytes_read=0x7fffeda7370c) at tcp_read.c:697
697     in tcp_read.c
(gdb) p con
$5 = (struct tcp_connection *) 0x7feb478bbc28
(gdb) ^Z
[3]+  Stopped                 gdb /usr/sbin/opensips 10314
[root at ffdray-mm630-195-10 zuser]# jobs
[1]   Stopped                 top
[2]-  Stopped                 gdb /usr/sbin/opensips 10320
[3]+  Stopped                 gdb /usr/sbin/opensips 10314
[root at ffdray-mm630-195-10 zuser]# fg 2
gdb /usr/sbin/opensips 10320
(gdb) bt
#0  0x00007feb5b4232f7 in sched_yield () from /lib64/libc.so.6
#1  0x00000000004bd305 in get_lock (tcpconn=0x7feb478bbc28) at fastlock.h:182
#2  tcpconn_destroy (tcpconn=0x7feb478bbc28) at tcp_main.c:1502
#3  0x00000000004bf93e in handle_tcp_child (tcp_c=0x7feb58fa72d4, fd_i=<value optimized out>) at tcp_main.c:1779
#4  0x00000000004c1abc in io_wait_loop_epoll () at io_wait.h:845
#5  tcp_main_loop () at tcp_main.c:2152
#6  0x000000000043b038 in main_loop (argc=<value optimized out>, argv=<value optimized out>) at main.c:1040
#7  main (argc=<value optimized out>, argv=<value optimized out>) at main.c:1612
(gdb) q
A debugging session is active.

        Inferior 1 [process 10320] will be detached.

Thanks

---
Reply to this email directly or view it on GitHub:
https://github.com/OpenSIPS/opensips/issues/630
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opensips.org/pipermail/devel/attachments/20150905/bdca8c22/attachment.htm>