Hi Bogdan,
Performance testing is really getting hit because of this issue. I
will appreciate any feedback on this issue.
Thanks
Rahul
*From:*Gupta, Rahul
*Sent:* Friday, July 17, 2015 2:36 PM
*To:* [email protected]
*Subject:* opensips taking 100% cpu
Hi,
I am using 1.11.3-tls version and opensips processes are taking 100% CPU.
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
12635 root 20 0 335m 1876 1068 R 100.0 0.0 335:02.96 opensips
12636 root 20 0 335m 1944 1140 R 100.0 0.0 335:03.71 opensips
12641 root 20 0 335m 88m 87m R 100.0 0.1 333:26.96 opensips
12645 root 20 0 335m 63m 62m R 100.0 0.1 333:23.76 opensips
12632 root 20 0 335m 1196 408 R 99.8 0.0 38:22.68 opensips
12647 root 20 0 335m 19m 18m R 99.8 0.0 561:16.07 opensips
12634 root 20 0 335m 1876 1068 R 99.5 0.0 333:22.10 opensips
None of the commands from opensipsctl are working, so I can’t use
opensipsctl trap to generate gbd info. I ran the gdb on couple of the
PID and got the following back trace. Seems like opensips is stuck in
some lock.
[root@sa-z2-ccm1 ~]# gdb /usr/sbin/opensips 12633
GNU gdb (GDB) Red Hat Enterprise Linux (7.2-60.el6_4.1)
Copyright (C) 2010 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later
<http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /usr/sbin/opensips...done.
Attaching to program: /usr/sbin/opensips, process 12633
Reading symbols from /lib64/snoopy.so...done.
Loaded symbols for /lib64/snoopy.so
Reading symbols from /lib64/libdl.so.2...(no debugging symbols
found)...done.
Loaded symbols for /lib64/libdl.so.2
Reading symbols from /lib64/libresolv.so.2...(no debugging symbols
found)...done.
Loaded symbols for /lib64/libresolv.so.2
Reading symbols from /usr/lib64/libssl.so.10...(no debugging symbols
found)...done.
Loaded symbols for /usr/lib64/libssl.so.10
Reading symbols from /usr/lib64/libcrypto.so.10...(no debugging
symbols found)...done.
Loaded symbols for /usr/lib64/libcrypto.so.10
Reading symbols from /lib64/libc.so.6...(no debugging symbols
found)...done.
Loaded symbols for /lib64/libc.so.6
Reading symbols from /lib64/ld-linux-x86-64.so.2...(no debugging
symbols found)...done.
Loaded symbols for /lib64/ld-linux-x86-64.so.2
Reading symbols from /lib64/libgssapi_krb5.so.2...(no debugging
symbols found)...done.
Loaded symbols for /lib64/libgssapi_krb5.so.2
Reading symbols from /lib64/libkrb5.so.3...(no debugging symbols
found)...done.
Loaded symbols for /lib64/libkrb5.so.3
Reading symbols from /lib64/libcom_err.so.2...(no debugging symbols
found)...done.
Loaded symbols for /lib64/libcom_err.so.2
Reading symbols from /lib64/libk5crypto.so.3...(no debugging symbols
found)...done.
Loaded symbols for /lib64/libk5crypto.so.3
Reading symbols from /lib64/libz.so.1...(no debugging symbols
found)...done.
Loaded symbols for /lib64/libz.so.1
Reading symbols from /lib64/libkrb5support.so.0...(no debugging
symbols found)...done.
Loaded symbols for /lib64/libkrb5support.so.0
Reading symbols from /lib64/libkeyutils.so.1...(no debugging symbols
found)...done.
Loaded symbols for /lib64/libkeyutils.so.1
Reading symbols from /lib64/libpthread.so.0...(no debugging symbols
found)...done.
[Thread debugging using libthread_db enabled]
Loaded symbols for /lib64/libpthread.so.0
Reading symbols from /lib64/libselinux.so.1...(no debugging symbols
found)...done.
Loaded symbols for /lib64/libselinux.so.1
Reading symbols from /usr/lib64/opensips/modules/signaling.so...done.
Loaded symbols for /usr/lib64/opensips/modules/signaling.so
Reading symbols from /usr/lib64/opensips/modules/sl.so...done.
Loaded symbols for /usr/lib64/opensips/modules/sl.so
Reading symbols from /usr/lib64/opensips/modules/tm.so...done.
Loaded symbols for /usr/lib64/opensips/modules/tm.so
Reading symbols from /usr/lib64/opensips/modules/rr.so...done.
Loaded symbols for /usr/lib64/opensips/modules/rr.so
Reading symbols from /usr/lib64/opensips/modules/maxfwd.so...done.
Loaded symbols for /usr/lib64/opensips/modules/maxfwd.so
Reading symbols from /usr/lib64/opensips/modules/sipmsgops.so...done.
Loaded symbols for /usr/lib64/opensips/modules/sipmsgops.so
Reading symbols from /usr/lib64/opensips/modules/mi_fifo.so...done.
Loaded symbols for /usr/lib64/opensips/modules/mi_fifo.so
Reading symbols from /usr/lib64/opensips/modules/uri.so...done.
Loaded symbols for /usr/lib64/opensips/modules/uri.so
Reading symbols from /usr/lib64/opensips/modules/usrloc.so...done.
Loaded symbols for /usr/lib64/opensips/modules/usrloc.so
Reading symbols from /usr/lib64/opensips/modules/registrar.so...done.
Loaded symbols for /usr/lib64/opensips/modules/registrar.so
Reading symbols from /usr/lib64/opensips/modules/acc.so...done.
Loaded symbols for /usr/lib64/opensips/modules/acc.so
Reading symbols from /lib64/libnss_files.so.2...(no debugging symbols
found)...done.
Loaded symbols for /lib64/libnss_files.so.2
0x00007fbea5ead527 in sched_yield () from /lib64/libc.so.6
Missing separate debuginfos, use: debuginfo-install
glibc-2.12-1.132.el6.x86_64 keyutils-libs-1.4-4.el6.x86_64
krb5-libs-1.10.3-33.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-30.el6.x86_64
zlib-1.2.3-29.el6.x86_64
(gdb) bt
#0 0x00007fbea5ead527 in sched_yield () from /lib64/libc.so.6
#1 0x00000000004b29cc in get_lock (send_sock=0x7fbea3a25398, type=2,
buf=0x7fbea3a34ae8 "INFO sip:[email protected]:5069;transport=TCP
<sip:[email protected]:5069;transport=TCP> SIP/2.0\r\nContent-Type:
application/msml+xml\r\nTo:
<sip:[email protected]>;tag=10.204.178.95069+1+155c0002+eae86f8a\r\nVia:
SIP/2.0/TCP 10.241.242.4:5060;br"..., len=864, to=0x7fffce949820,
id=0) at fastlock.h:182
#2 tcpconn_get (send_sock=0x7fbea3a25398, type=2,
buf=0x7fbea3a34ae8 "INFO sip:[email protected]:5069;transport=TCP
<sip:[email protected]:5069;transport=TCP> SIP/2.0\r\nContent-Type:
application/msml+xml\r\nTo:
<sip:[email protected]>;tag=10.204.178.95069+1+155c0002+eae86f8a\r\nVia:
SIP/2.0/TCP 10.241.242.4:5060;br"..., len=864, to=0x7fffce949820,
id=0) at tcp_main.c:900
#3 tcp_send (send_sock=0x7fbea3a25398, type=2,
buf=0x7fbea3a34ae8 "INFO sip:[email protected]:5069;transport=TCP
<sip:[email protected]:5069;transport=TCP> SIP/2.0\r\nContent-Type:
application/msml+xml\r\nTo:
<sip:[email protected]>;tag=10.204.178.95069+1+155c0002+eae86f8a\r\nVia:
SIP/2.0/TCP 10.241.242.4:5060;br"..., len=864, to=0x7fffce949820,
id=0) at tcp_main.c:1088
#4 0x000000000042e469 in msg_send (send_sock=<value optimized out>,
proto=<value optimized out>, to=0x7fffce949820, id=<value optimized out>,
buf=0x7fbea3a34ae8 "INFO sip:[email protected]:5069;transport=TCP
<sip:[email protected]:5069;transport=TCP> SIP/2.0\r\nContent-Type:
application/msml+xml\r\nTo:
<sip:[email protected]>;tag=10.204.178.95069+1+155c0002+eae86f8a\r\nVia:
SIP/2.0/TCP 10.241.242.4:5060;br"..., len=864) at forward.h:115
#5 0x000000000042ecfd in forward_request (msg=0x7fbea3a37018,
p=0x7fbea3a37bd0) at forward.c:444
#6 0x0000000000415156 in do_action (a=0x7fbea3a310f8,
msg=0x7fbea3a37018) at action.c:498
#7 0x00000000004137dc in run_action_list (a=<value optimized out>,
msg=0x7fbea3a37018) at action.c:171
#8 0x000000000048de9f in eval_elem (e=0x7fbea3a311d8,
msg=0x7fbea3a37018, val=0x0) at route.c:1618
#9 0x000000000048f7f3 in eval_expr (e=0x7fbea3a311d8,
msg=0x7fbea3a37018, val=0x0) at route.c:1963
#10 0x000000000048f78a in eval_expr (e=0x7fbea3a31228,
msg=0x7fbea3a37018, val=0x0) at route.c:1979
#11 0x000000000048f7b9 in eval_expr (e=0x7fbea3a31278,
msg=0x7fbea3a37018, val=0x0) at route.c:1984
#12 0x0000000000416864 in do_action (a=0x7fbea3a31570,
msg=0x7fbea3a37018) at action.c:1087
#13 0x00000000004137dc in run_action_list (a=<value optimized out>,
msg=0x7fbea3a37018) at action.c:171
#14 0x0000000000413ae9 in run_actions (a=<value optimized out>,
msg=<value optimized out>) at action.c:136
#15 0x00000000004190bc in do_action (a=0x7fbea3a2af60,
msg=0x7fbea3a37018) at action.c:743
#16 0x00000000004137dc in run_action_list (a=<value optimized out>,
msg=0x7fbea3a37018) at action.c:171
#17 0x0000000000419c93 in do_action (a=0x7fbea3a2bb28,
msg=0x7fbea3a37018) at action.c:1105
#18 0x00000000004137dc in run_action_list (a=<value optimized out>,
msg=0x7fbea3a37018) at action.c:171
#19 0x0000000000419c93 in do_action (a=0x7fbea3a2bce8,
msg=0x7fbea3a37018) at action.c:1105
#20 0x00000000004137dc in run_action_list (a=<value optimized out>,
msg=0x7fbea3a37018) at action.c:171
#21 0x000000000041c508 in run_actions (a=0x7fbea3a287d8,
msg=0x7fbea3a37018) at action.c:136
#22 run_top_route (a=0x7fbea3a287d8, msg=0x7fbea3a37018) at action.c:211
#23 0x0000000000479c87 in receive_msg (buf=<value optimized out>,
len=<value optimized out>, rcv_info=<value optimized out>) at
receive.c:172
#24 0x00000000004dd771 in udp_rcv_loop () at udp_server.c:424
#25 0x0000000000437cd3 in main_loop (argc=<value optimized out>,
argv=<value optimized out>) at main.c:942
#26 main (argc=<value optimized out>, argv=<value optimized out>) at
main.c:1634
Any Ideas why is this happening ? I am running opensips with debug=2
mode and my logs are filled with the following messages
2015-07-17T08:54:02.000-04:00 [local2] [crit] sa-z2-ccm1.ipc.com
/usr/sbin/opensips[12647]: CRITICAL:core:io_watch_del: invalid fd
5735, not in [0, 2189)
2015-07-17T08:54:02.000-04:00 [local2] [crit] sa-z2-ccm1.ipc.com
/usr/sbin/opensips[12647]: CRITICAL:core:io_watch_del: invalid fd
5736, not in [0, 2189)
2015-07-17T08:54:02.000-04:00 [local2] [crit] sa-z2-ccm1.ipc.com
/usr/sbin/opensips[12647]: CRITICAL:core:io_watch_del: invalid fd
5737, not in [0, 2189)
2015-07-17T08:54:02.000-04:00 [local2] [crit] sa-z2-ccm1.ipc.com
/usr/sbin/opensips[12647]: CRITICAL:core:handle_io: uknown fd type
-1549462248
2015-07-17T08:54:02.000-04:00 [local2] [crit] sa-z2-ccm1.ipc.com
/usr/sbin/opensips[12647]: CRITICAL:core:handle_io: uknown fd type
-1549462224
2015-07-17T08:54:02.000-04:00 [local2] [crit] sa-z2-ccm1.ipc.com
/usr/sbin/opensips[12647]: CRITICAL:core:handle_io: uknown fd type
-1549462176
Is this a known issue ? Any workarounds or fixes available for this ?
Thanks
Rahul Gupta
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
DISCLAIMER: This e-mail may contain information that is confidential,
privileged or otherwise protected from disclosure. If you are not an
intended recipient of this e-mail, do not duplicate or redistribute it
by any means. Please delete it and any attachments and notify the
sender that you have received it in error. Unintended recipients are
prohibited from taking action on the basis of information in this
e-mail.E-mail messages may contain computer viruses or other defects,
may not be accurately replicated on other systems, or may be
intercepted, deleted or interfered with without the knowledge of the
sender or the intended recipient. If you are not comfortable with the
risks associated with e-mail messages, you may decide not to use
e-mail to communicate with IPC. IPC reserves the right, to the extent
and under circumstances permitted by applicable law, to retain,
monitor and intercept e-mail messages to and from its systems.
