Opensips 2.1.0 100% CPU load

[sjap]

Today I discovered my opensips server is using 100% of my cpu since yesterday.. It have been installed for a few weeks without any issues.. (non prod setup)

[root@opensips-2 ~]# opensips -V
version: opensips 2.1.0 (x86_64/linux)
flags: STATS: On, DISABLE_NAGLE, USE_MCAST, 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 08:02:47 May 8 2015 with gcc 4.8.3

Tasks: 124 total, 4 running, 120 sleeping, 0 stopped, 0 zombie
%Cpu(s): 12.6 us, 52.9 sy, 0.0 ni, 34.0 id, 0.6 wa, 0.0 hi, 0.0 si, 0.0 st
KiB Mem : 5947400 total, 5430060 free, 147644 used, 369696 buff/cache
KiB Swap: 1703932 total, 1703932 free, 0 used. 5590216 avail Mem

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
13058 root 20 0 1240056 2136 644 R 100.0 0.0 3:39.90 opensips
13059 root 20 0 1240056 2136 644 R 100.0 0.0 3:40.12 opensips
29 root 20 0 0 0 0 S 6.7 0.0 0:00.41 kworker/1:1
666 root 20 0 195088 4244 3404 S 6.7 0.1 0:00.26 vmtoolsd

[root@opensips-2 ~]# strace -p 13058
recvfrom(9, 0x78f080, 65535, 0, 0x7fc05bfa1e28, 0x7ffc99176f78) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(9, 0x78f080, 65535, 0, 0x7fc05bfa1e28, 0x7ffc99176f78) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(9, 0x78f080, 65535, 0, 0x7fc05bfa1e28, 0x7ffc99176f78) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(9, 0x78f080, 65535, 0, 0x7fc05bfa1e28, 0x7ffc99176f78) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(9, 0x78f080, 65535, 0, 0x7fc05bfa1e28, 0x7ffc99176f78) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(9, 0x78f080, 65535, 0, 0x7fc05bfa1e28, 0x7ffc99176f78) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(9, 0x78f080, 65535, 0, 0x7fc05bfa1e28, 0x7ffc99176f78) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(9, 0x78f080, 65535, 0, 0x7fc05bfa1e28, 0x7ffc99176f78) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(9, 0x78f080, 65535, 0, 0x7fc05bfa1e28, 0x7ffc99176f78) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(9, 0x78f080, 65535, 0, 0x7fc05bfa1e28, 0x7ffc99176f78) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(9, 0x78f080, 65535, 0, 0x7fc05bfa1e28, 0x7ffc99176f78) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(9, 0x78f080, 65535, 0, 0x7fc05bfa1e28, 0x7ffc99176f78) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(9, 0x78f080, 65535, 0, 0x7fc05bfa1e28, 0x7ffc99176f78) = -1 EAGAIN (Resource temporarily unavailable)

And nothing is really changed for days now :S

[bogdan-iancu]

@sjap , could you run an "opensipsctl trap" command in order to get the backtrace of all opensips processes ? and post the output somewhere (some pastbin)

[sjap]

@bogdan-iancu sure :)

http://pastebin.com/mznqMHfU

[bogdan-iancu]

Based on the top information and "opensipsctl trap", can you tell me which opensips process is using 100% cpu ?

[sjap]

It shoud be PID: 13058, and 13059

PID TTY STAT TIME COMMAND
13055 ? S 0:00 /sbin/opensips -P /var/run/opensips.pid -m 1024
13057 ? S 0:00 _ /sbin/opensips -P /var/run/opensips.pid -m 1024
13058 ? R 245:33 _ /sbin/opensips -P /var/run/opensips.pid -m 1024
13059 ? R 245:36 _ /sbin/opensips -P /var/run/opensips.pid -m 1024
13060 ? R 0:06 _ /sbin/opensips -P /var/run/opensips.pid -m 1024
13061 ? S 0:02 _ /sbin/opensips -P /var/run/opensips.pid -m 1024
13062 ? S 0:01 _ /sbin/opensips -P /var/run/opensips.pid -m 1024
13063 ? S 0:00 _ /sbin/opensips -P /var/run/opensips.pid -m 1024
13064 ? S 0:00 _ /sbin/opensips -P /var/run/opensips.pid -m 1024
13065 ? S 0:00 _ /sbin/opensips -P /var/run/opensips.pid -m 1024

[bogdan-iancu]

and if you do an "opensipsctl ps", what is the name of those processes ?

[sjap]

I made a typo, so I had to restart opensips and it got new pids. But it seems to be the BIN receiver that is taking so much cpu.

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
23606 root 20 0 1240056 2136 644 R 100.0 0.0 0:28.17 opensips
23607 root 20 0 1240056 2136 644 R 100.0 0.0 0:28.15 opensips

[root@opensips-2 ~]# opensipsctl ps
Process:: ID=0 PID=23603 Type=attendant
Process:: ID=1 PID=23605 Type=MI FIFO
Process:: ID=2 PID=23606 Type=BIN receiver udp:85.218.129.117:5062
Process:: ID=3 PID=23607 Type=BIN receiver udp:85.218.129.117:5062
Process:: ID=4 PID=23608 Type=time_keeper
Process:: ID=5 PID=23609 Type=timer
Process:: ID=6 PID=23610 Type=SIP receiver udp:85.218.129.117:5060
Process:: ID=7 PID=23611 Type=SIP receiver udp:85.218.129.117:5060
Process:: ID=8 PID=23612 Type=SIP receiver udp:85.218.129.117:5060
Process:: ID=9 PID=23613 Type=SIP receiver udp:85.218.129.117:5060
[root@opensips-2 ~]#

PS: I'm running opensips on a fully patch CentOS 7.1.1503 (Core)

[bogdan-iancu]

@sjap , this problem was fixed long time in 2.1 . See the commit:
66ab6ca
I suggest you should use the sources from GIT repo, rather than packages.

[sjap]

Oh, I see. - Thanks alot :)