[OpenSIPS-Users] CPU at 100% on some threads

[Daniel Zanutti]

Hi

We are having a weird issue on a high load server, could you guys please
help me find out a solution?

These opensips threads freeze for a few seconds at 100% CPU and drop some
packets. So some new calls fails to be processed:

[image: Inline image 2]

Running on a Debian 8.6 x64 - 12 cores/48GB Ram server:
# opensips -V
version: opensips 1.11.6-notls (x86_64/linux)
flags: STATS: On, USE_IPV6, USE_TCP, DISABLE_NAGLE, USE_MCAST, SHM_MEM,
SHM_MMAP, PKG_MALLOC, F_MALLOC, FAST_LOCK-ADAPTIVE_WAIT
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16,
MAX_URI_SIZE 1024, BUF_SIZE 65535
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
main.c compiled on 10:46:04 Oct 20 2016 with gcc 4.9.2

I got the gdb of one of one frozen thread, it's seems to be something
related to fastlock:

(gdb) bt full
#0  0x00007ff4cc9e4bb7 in sched_yield () at
../sysdeps/unix/syscall-template.S:81
No locals.
#1  0x00007ff4cacd9d5d in get_lock (lock=0x7ff3cb6e2678) at
../../evi/../fastlock.h:182
        i = 0
#2  _lock (s=0x7ff3cb6e2678) at lock.h:102
No locals.
#3  reply_received (p_msg=0x7ff4cc809c38) at t_reply.c:1556
        msg_status = 302
        last_uac_status = 503
        branch = 1
        reply_status = <optimized out>
        timer = 140689351533517
        cancel_bitmap = 0
        uac = <optimized out>
        t = 0x7ff3cb6e0e20
        backup_list = <optimized out>
        has_reply_route = 1
        __FUNCTION__ = "reply_received"
#4  0x000000000044d613 in forward_reply (msg=msg at entry=0x7ff4cc809c38) at
forward.c:575
        new_buf = 0x0
        to = 0x0
        new_len = 32755
        mod = 0x7ff4cc71b2b0
        proto = <optimized out>
        id = 0
        send_sock = <optimized out>
        s = <optimized out>
        len = <optimized out>
        __FUNCTION__ = "forward_reply"
#5  0x00000000004340ff in receive_msg (buf=<optimized out>, len=<optimized
out>, rcv_info=rcv_info at entry=0x7fff9f1182f0) at receive.c:214
        msg = 0x7ff4cc809c38
        start = {tv_sec = 140735862113030, tv_usec = 140689389048549}
        rc = 3
        __FUNCTION__ = "receive_msg"
#6  0x0000000000462ef4 in udp_rcv_loop () at udp_server.c:422
        len = <optimized out>
        buf = "SIP/2.0 302 Moved Temporarily\r\nVia: SIP/2.0/UDP
2.2.2.2:5060;rport=5060;received=2.2.2.2;branch=z9hG4bK9ef.5fb57785.1\r\nVia:
SIP/2.0/UDP 1.1.1.1:5060;rport=5060;received=1.1.1"...
        from = 0x7ff4cc809c00
        fromlen = 16
        ri = {src_ip = {af = 2, len = 4, u = {addrl = {41876154, 1}, addr32
= {41876154, 0, 1, 0}, addr16 = {64186, 638, 0, 0, 1, 0, 0, 0}, addr =
"\272\372~\002\000\000\000\000\001\000\000\000\000\000\000"}}, dst_ip = {af
= 2,
            len = 4, u = {addrl = {769317832, 0}, addr32 = {769317832, 0,
0, 0}, addr16 = {56264, 11738, 0, 0, 0, 0, 0, 0}, addr = "\310\333\332-",
'\000' <repeats 11 times>}}, src_port = 5060, dst_port = 5060, proto = 1,
          proto_reserved1 = 0, proto_reserved2 = 0, src_su = {s =
{sa_family = 2, sa_data = "\023ĺ\372~\002\000\000\000\000\000\000\000"},
sin = {sin_family = 2, sin_port = 50195, sin_addr = {s_addr = 41876154},
              sin_zero = "\000\000\000\000\000\000\000"}, sin6 =
{sin6_family = 2, sin6_port = 50195, sin6_flowinfo = 41876154, sin6_addr =
{__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0,
0, 0, 0, 0, 0},
                  __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}},
bind_address = 0x7ff4cc71ade0}
        p = <optimized out>
        msg = {
          s = 0x81e780 <buf> "SIP/2.0 302 Moved Temporarily\r\nVia:
SIP/2.0/UDP 2.2.2.2:5060;rport=5060;received=2.2.2.2;branch=z9hG4bK9ef.5fb57785.1\r\nVia:
SIP/2.0/UDP 1.1.1.1:5060;rport=5060;received=1.1.1"..., len = 537}
        __FUNCTION__ = "udp_rcv_loop"
#7  0x00000000004161e0 in main_loop () at main.c:929
        i = 3
        pid = <optimized out>
        si = 0x7ff4cc71ade0
        startup_done = 0x0
        chd_rank = 4
        rc = <optimized out>
        load_p = 0x7ff3c61ac430
#8  main (argc=<optimized out>, argv=<optimized out>) at main.c:1613
        cfg_log_stderr = <optimized out>
        cfg_stream = <optimized out>
        c = <optimized out>
        r = <optimized out>
---Type <return> to continue, or q <return> to quit---
        tmp = 0x7fff9f118efe ""
        tmp_len = <optimized out>
        port = <optimized out>
        proto = <optimized out>
        options = 0x5c0aa8 "f:cCm:M:b:l:n:N:rRvdDFETSVhw:t:u:g:P:G:W:o:"
        ret = -1
        seed = 3165191676
        rfd = <optimized out>
        __FUNCTION__ = "main"


Any idea?

Thanks!
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opensips.org/pipermail/users/attachments/20170221/3ea8cf9a/attachment-0001.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: image.png
Type: image/png
Size: 16795 bytes
Desc: not available
URL: <http://lists.opensips.org/pipermail/users/attachments/20170221/3ea8cf9a/attachment-0001.png>