Bug #75293 Memcached Process at 100% CPU
Submitted: 22 Dec 2014 18:31 Modified: 13 Jan 2015 13:00
Reporter: Paul M Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Cluster: Memcached Severity:S2 (Serious)
Version:7.3.2+, 7.3.7, 7.5.5 OS:Linux (CentOS 6/7)
Assigned to: CPU Architecture:Any

[22 Dec 2014 18:31] Paul M 
Description:
I am seeing memcached process at 100% when setting a key or getting a key when I telnet into memcached or I do this via a PHP script.

With memcached at 100%.  The server seriously loses performance.  Queries are down to a crawl.  The box is useless for production.

Versions 7.3.2+ seem to be affected. 

I do not have any problems with 7.3.1 and therefore I am kinda stuck on this version for production.

The install instructions came from:  http://www.clusterdb.com/mysql-cluster/scalabale-persistent-ha-nosql-memcache-storage-usin...

But I have also installed from: http://www.clusterdb.com/mysql-cluster/deploying-mysql-cluster-over-multiple-hosts

Whatever installation guide I use.  The result is the same with 7.3.2+.  Memcached is 100%.

Also, I have tried Centos 6 and Centos7.  The result is the same.

I am enclosing full instructions for Centos 6 so you know exactly what I am doing.  To test I am installing on a single server.  It doesn't matter if its a single server or distributed setup.  The result is the same.

How to repeat:
Installation Instructions for Centos 6.

yum -y remove mysql-libs
yum -y install ntp vim wget mlocate htop unzip crontabs yum-plugin-fastestmirror net-tools psmisc telnet
yum -y groupinstall 'Development Tools'
yum -y install libaio-devel

# turn off selinux
sed -i 's/^SELINUX=enforcing/SELINUX=disabled/' /etc/sysconfig/selinux
sed -i 's/^SELINUX=enforcing/SELINUX=disabled/' /etc/selinux/config

# turn off selinux for this session
setenforce 0

service iptables stop
chkconfig iptables off

groupadd mysql
useradd -r -g mysql mysql

# create data dir
mkdir -p /var/lib/mysql-cluster/data

# change ownership
chown mysql:mysql -R /var/lib/mysql-cluster

wget https://downloads.mariadb.com/files/mysql-cluster-gpl-7.3/MySQL-Cluster-server-gpl-7.3.7-1...
wget https://downloads.mariadb.com/files/mysql-cluster-gpl-7.3/MySQL-Cluster-client-gpl-7.3.7-1...

rpm -Uvh MySQL-Cluster-server-gpl-7.3.7-1.el6.x86_64.rpm
rpm -Uvh MySQL-Cluster-client-gpl-7.3.7-1.el6.x86_64.rpm

mkdir -p /var/lib/mysql-cluster/ndb_data
mkdir -p /var/lib/mysql-cluster/mysqld_data

# config.ini
cat > /var/lib/mysql-cluster/config.ini <<EOF
[ndb_mgmd]
hostname=localhost
datadir=/var/lib/mysql-cluster/ndb_data
NodeId=1

[ndbd default]
noofreplicas=2
datadir=/var/lib/mysql-cluster/ndb_data

[ndbd]
hostname=localhost
NodeId=3

[ndbd]
hostname=localhost
NodeId=4

[mysqld]
NodeId=50

[mysqld]
NodeId=51

[mysqld]
NodeId=52

[mysqld]
NodeId=53

[mysqld]
NodeId=54
EOF

# my.cnf
cat > /etc/my.cnf <<EOF
[mysqld]
ndbcluster
datadir=/var/lib/mysql-cluster/mysqld_data
EOF

# install db
mysql_install_db --datadir=/var/lib/mysql-cluster/mysqld_data --user=root

# start nodes
ndb_mgmd -f /var/lib/mysql-cluster/config.ini
ndbd
ndbd

# start mysql server
mysqld --defaults-file=/etc/my.cnf --user=root

# install memcached
mysql -h 127.0.0.1 -P3306 -u root < /usr/share/mysql/memcache-api/ndb_memcache_metadata.sql

# start memcached
memcached -E /usr/lib64/ndb_engine.so -e "connectstring=localhost:1186;role=db-only" -vv -c 20 -u root

# telnet into memcached
telnet localhost 11211

#set key
set maidenhead 0 0 3 
SL6 

Now memcached is at 100%.
[22 Dec 2014 22:49] Paul M 
Forgot to mention.

The OS is on a Virtual Machine.  

Either on my dev laptop, running VMWare Fusion.

Or on my servers, which run ESXi 5.5.

I have not tested nor do I have any physical hardware.
[23 Dec 2014 19:19] Paul M 
Seeing as I need 7.3.1 for Centos 7 and there is no rpm.  I thought I would build one.

But just for fun, I thought I'd rebuild 7.3.7 from src.rpm.

I still get the same result:

PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND    11241 root      20   0  667032  16100   3148 S 98.7  1.6   0:21.32 memcached 

See that,  %CPU = 98.7
[2 Jan 2015 20:03] Paul M 
I get this same behaviour under ubuntu 14.10 and using the debian package.

I tried Debian Linux 7 (x86, 64-bit), DEB.
[13 Jan 2015 13:00] MySQL Verification Team 
Hello Paul M,

Thank you for the report.
Observed similar behavior on CentOS7 with MySQL Cluster 7.3.7(binary tarball).

Thanks,
Umesh
[13 Jan 2015 13:01] MySQL Verification Team 
// Environment

// OS and binary details

[root@ushastry mysql-cluster-advanced-7.3.7]# more docs/INFO_SRC 
revision-id: mauritz.sundell@oracle.com-20141009130427-cwuq3yrz4eu63xn6
date: 2014-10-09 15:04:27 +0200
build-date: 2014-10-09 15:29:27 +0200
revno: 4444
branch-nick: mysql-cluster-7.3.7-release

MySQL source 5.6.21
[root@ushastry mysql-cluster-advanced-7.3.7]# cat /etc/*release
CentOS Linux release 7.0.1406 (Core) 
NAME="CentOS Linux"
VERSION="7 (Core)"
ID="centos"
ID_LIKE="rhel fedora"
VERSION_ID="7"
PRETTY_NAME="CentOS Linux 7 (Core)"
ANSI_COLOR="0;31"
CPE_NAME="cpe:/o:centos:centos:7"
HOME_URL="https://www.centos.org/"
BUG_REPORT_URL="https://bugs.centos.org/"

CentOS Linux release 7.0.1406 (Core) 
CentOS Linux release 7.0.1406 (Core)
[13 Jan 2015 13:02] MySQL Verification Team 
// Setup etc followed from http://www.clusterdb.com/mysql-cluster/scalabale-persistent-ha-nosql-memcache-storage-usin...

// CLI
 
 [ushastry@ushastry mysql-cluster-advanced-7.3.7]$ telnet localhost 11211
 Trying ::1...
 Connected to localhost.
 Escape character is '^]'.
 set maidenhead 0 0 3
 SL6
 STORED
 get maidenhead
 VALUE maidenhead 0 3
 SL6
 END
 set maidenhead 0 0 3
 OL8
 STORED
 set maindeenhead 0 0 10
 OL6OL7OL8
 STORED
 truncate_all
 ERROR
 flush_all
 
[root@ushastry mysql-cluster-advanced-7.3.7]# top |grep memcached

 6442 root      20   0  670324  20708   3544 S 84.0  0.6   1:38.83 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 95.8  0.6   1:41.72 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 96.7  0.6   1:44.64 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 97.6  0.6   1:47.58 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 96.3  0.6   1:50.48 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 97.2  0.6   1:53.41 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 96.9  0.6   1:56.33 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 97.3  0.6   1:59.26 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 97.0  0.6   2:02.18 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 97.1  0.6   2:05.11 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 94.6  0.6   2:07.96 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 97.0  0.6   2:10.88 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 97.2  0.6   2:13.81 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 97.4  0.6   2:16.75 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 94.5  0.6   2:19.60 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 97.3  0.6   2:22.53 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 97.3  0.6   2:25.46 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 97.0  0.6   2:28.38 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 97.4  0.6   2:31.31 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 97.3  0.6   2:34.24 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 97.4  0.6   2:37.17 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 97.0  0.6   2:40.09 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 97.3  0.6   2:43.02 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 97.3  0.6   2:45.95 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 97.5  0.6   2:48.89 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 97.1  0.6   2:51.82 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 97.1  0.6   2:54.75 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 97.6  0.6   2:57.69 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 97.4  0.6   3:00.62 memcached                                                                                                    
 6442 root      20   0  670324  20708   3544 S 95.6  0.6   3:03.50 memcached
[13 Jan 2015 13:03] MySQL Verification Team 
// memcached
 
 [root@ushastry mysql-cluster-advanced-7.3.7]# bin/memcached -E /home/ushastry/Downloads/mysql-cluster-advanced-7.3.7/lib/ndb_engine.so -e "connectstring=localhost:1186;role=db-only" -vv -c 20 -u root
 13-Jan-2015 07:48:59 EST NDB Memcache 5.6.21-ndb-7.3.7 started [NDB 7.3.7; MySQL 5.6.21]
 Contacting primary management server (localhost:1186) ... 
 Connected to "localhost:1186" as node id 51.
 Retrieved 3 key prefixes for server role "db-only".
 The default behavior is that: 
     GET uses NDB only
     SET uses NDB only
     DELETE uses NDB only.
 The 2 explicitly defined key prefixes are "b:" (demo_table_large) and "t:" (demo_table_tabs)
 Server started with 4 threads.
 Priming the pump ... 
 Connected to "" as node id 52.
 Scheduler: using 2 connections to cluster 0
 Scheduler: starting for 1 cluster; c0,f0,g1,t1
 done [0.772 sec].
 Loaded engine: NDB Memcache 5.6.21-ndb-7.3.7
 Supplying the following features: compare and swap, persistent storage, LRU
 <49 server listening (auto-negotiate)
 <50 server listening (auto-negotiate)
 <51 send buffer was 212992, now 268435456
 <52 send buffer was 212992, now 268435456
 <51 server listening (udp)
 <52 server listening (udp)
 <51 server listening (udp)
 <52 server listening (udp)
 <51 server listening (udp)
 <52 server listening (udp)
 <51 server listening (udp)
 <52 server listening (udp)
 50 - Running task: (conn_listening)
 <53 new auto-negotiating client connection
 53 - Running task: (conn_new_cmd)
 53 - Running task: (conn_waiting)
 53 - Running task: (conn_read)
 53 - Running task: (conn_parse_cmd)
 53: Client using the ascii protocol
 <53 set maidenhead 0 0 3
 53 - Running task: (conn_nread)
 53 - Running task: (conn_nread)
 53 - Running task: (conn_nread)
 Pipeline 0 attached to S scheduler.
 Got notify from 53, status 0
 >53 STORED
 53 - Running task: (conn_read)
 53 - Running task: (conn_parse_cmd)
 <53 get maidenhead
 Got notify from 53, status 0
 <53 get maidenhead
 >53 sending key maidenhead
 >53 END
 53 - Running task: (conn_read)
 53 - Running task: (conn_parse_cmd)
 <53 set maidenhead 0 0 3
 53 - Running task: (conn_nread)
 53 - Running task: (conn_nread)
 53 - Running task: (conn_nread)
 Got notify from 53, status 0
 >53 STORED
 53 - Running task: (conn_read)
 53 - Running task: (conn_parse_cmd)
 <53 set maindeenhead 0 0 10
 53 - Running task: (conn_nread)
 53 - Running task: (conn_nread)
 53 - Running task: (conn_nread)
 Got notify from 53, status 0
 >53 STORED
 53 - Running task: (conn_swallow)
 53 - Running task: (conn_swallow)
 53 - Running task: (conn_new_cmd)
 53 - Running task: (conn_waiting)
 53 - Running task: (conn_read)
 53 - Running task: (conn_parse_cmd)
  <53 flush_all
 >53 OK
 53 - Running task: (conn_write)
 53 - Running task: (conn_write)
 53 - Running task: (conn_new_cmd)
 53 - Running task: (conn_waiting)
[9 Feb 2015 11:39] Joshua Gigg 
I'm seeing the same with 7.3.8, and I also tried 7.4.2, 7.4.3. All running on CentOS 6 x64.
[18 May 2015 12:48] Carlo Nicora 
Hello,
Another confirmation on the issue with Ubuntu 14.10 and mysql-cluster-gpl-7.4.6-linux-glibc2.5-x86_64

Any hint on how to avoid the issue? If I download the memcached and the ndb lib from the 7.3.1 would that work in your opinion?

Ciao
Carlo
[18 May 2015 22:01] Carlo Nicora 
BTW: I tried to use the memcached and the ndb_engine.so coming from version 7.2

Using memcached (7.2 or 7.4) with ndb_engine.so (7.4) creates the same error with CPU skyrocketing high

using the ndb_engine.so (7.2) fails with error Invalid table "ndbmemcache.memcache_server_roles"
[16 Sep 2015 15:56] Joel Hanger 
I'm also seeing this on Centos 6.7 x64
Cluster 7.4.7
[16 Feb 2017 9:19] Jonathan Hartley 
This is also happening on

mysql-5.7.17 ndb-7.5.5 - Centos7 

Is there a fix for this or at least a workround
[21 Feb 2017 10:55] MySQL Verification Team 
Bug #85049 marked as duplicate of this
[24 Feb 2017 19:18] John Duncan 
Posted by developer:
 
I just pushed a fix to 7.4, 7.5, and 7.6 that should improve this situation.

On 7.6 the problem may be entirely fixed.

I have not yet conducted much testing & so I appreciate continued feedback on this bug report.