cannot stop mysql with memcached plugin

[Dmitriy]

Function "/etc/init.d/mysql stop" not working with memcached plugin

[Nilnandan Joshi (nilnandan-joshi)]

Unable to reproduce this error. Even, I'm not seeing any error while shutdown in attached error log except this,

2014-11-12 17:20:51 7332 [Note] Forcefully disconnecting 0 remaining clients
Waited for 50 seconds for memcached thread to exit. Now force terminating the thread
2014-11-12 17:21:41 7332 [Note] Binlog end

Do you think, is this the issue? If yes, then please provide exact steps to reproduce it.

mysql> install plugin daemon_memcached soname "libmemcached.so";
Query OK, 0 rows affected (0.00 sec)

mysql> show plugins;
+-----------------------------+----------+--------------------+-----------------+---------+
| Name | Status | Type | Library | License |
+-----------------------------+----------+--------------------+-----------------+---------+
| binlog | ACTIVE | STORAGE ENGINE | NULL | GPL |
...
| daemon_memcached | ACTIVE | DAEMON | libmemcached.so | GPL |
+-----------------------------+----------+--------------------+-----------------+---------+
47 rows in set (0.00 sec)

nilnandan@Dell-XPS:/usr/share/mysql$ telnet 127.0.0.1 11211
Trying 127.0.0.1...
Connected to 127.0.0.1.
Escape character is '^]'.
set a11 10 0 9
123456789
STORED
get a11
VALUE a11 10 9
123456789
END

2014-11-19 12:45:39 4008 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.6.21-70.0' socket: '/var/run/mysqld/mysqld.sock' port: 3306 Percona Server (GPL), Release 70.0, Revision 688
2014-11-19 12:45:42 4008 [Note] /usr/sbin/mysqld: Normal shutdown

2014-11-19 12:45:42 4008 [Note] Giving 0 client threads a chance to die gracefully
2014-11-19 12:45:42 4008 [Note] Event Scheduler: Purging the queue. 0 events
2014-11-19 12:45:42 4008 [Note] Shutting down slave threads
2014-11-19 12:45:42 4008 [Note] Forcefully disconnecting 0 remaining clients
2014-11-19 12:45:44 4008 [Note] Binlog end
2014-11-19 12:45:44 4008 [Note] Shutting down plugin 'partition'
2014-11-19 12:45:44 4008 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA'
2014-11-19 12:45:44 4008 [Note] Shutting down plugin 'ARCHIVE'
2014-11-19 12:45:44 4008 [Note] Shutting down plugin 'BLACKHOLE'
2014-11-19 12:45:44 4008 [Note] Shutting down plugin 'INNODB_CHANGED_PAGES'
2014-11-19 12:45:44 4008 [Note] Shutting down plugin 'INNODB_SYS_DATAFILES'
2014-11-19 12:45:44 4008 [Note] Shutting down plugin 'INNODB_SYS_TABLESPACES'
2014-11-19 12:45:44 4008 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN_COLS'
2014-11-19 12:45:44 4008 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN'
2014-11-19 12:45:44 4008 [Note] Shutting down plugin 'INNODB_SYS_FIELDS'
2014-11-19 12:45:44 4008 [Note] Shutting down plugin 'INNODB_SYS_COLUMNS'
2014-11-19 12:45:44 4008 [Note] Shutting down plugin 'INNODB_SYS_INDEXES'
2014-11-19 12:45:44 4008 [Note] Shutting down plugin 'INNODB_SYS_TABLESTATS'
2014-11-19 12:45:44 4008 [Note] Shutting down plugin 'INNODB_SYS_TABLES'
2014-11-19 12:45:44 4008 [Note] Shutting down plugin 'INNODB_FT_INDEX_TABLE'
2014-11-19 12:45:44 4008 [Note] Shutting down plugin 'INNODB_FT_INDEX_CACHE'
2014-11-19 12:45:44 4008 [Note] Shutting down plugin 'INNODB_FT_CONFIG'
2014-11-19 12:45:44 4008 [No...

[Dmitriy (testino)]

1) Create innodb_memcached base(get from oracle mysql)
mysql> source /usr/share/mysql/innodb_memcached_config.sql
2) Change cache policy
mysq> update innodb_memcache.cache_policies set get_policy='caching', set_policy='caching', delete_policy='caching', flush_policy='caching' where policy_name='cache_policy';

mysql> select * from innodb_memcache.cache_policies;
+--------------+------------+------------+---------------+--------------+
| policy_name | get_policy | set_policy | delete_policy | flush_policy |
+--------------+------------+------------+---------------+--------------+
| cache_policy | caching | caching | caching | caching |
+--------------+------------+------------+---------------+--------------+
3) Install memcached plugin
mysql> install plugin daemon_memcached soname "libmemcached.so";

4) change mysql config my.cnf(see attach)

5) Restart mysql.

6) telnet 127.0.0.1 11211
[root@mysql ~]# telnet 127.0.0.1 11211
Trying 127.0.0.1...
Connected to 127.0.0.1.
Escape character is '^]'.
set test 0 3600 4
1234
STORED
get test
VALUE test 0 4
1234
END
quit
Connection closed by foreign host.

7) Stop mysql

[Dmitriy (testino)]

OS Centos 6.5 and RH 6.5

[Nilnandan Joshi (nilnandan-joshi)]

Followed above steps but couldn't able to reproduce on Ubuntu 14.04. I'll try to test it for CentOS 6.5.
Can you tell me what exactly error I should get while shutting it down? Thanks.

[Valerii Kravchuk (valerii-kravchuk)]

I was NOT able to reproduce this with 5.6.21-70.0 on CentOS 6.6 with the steps listed in the previous comment (I had to set SELinux to permissive mode though to let memcached plugin bind to port 11211 though).

Look:

[root@centos openxs]# telnet 127.0.0.1 11211
Trying 127.0.0.1...
Connected to 127.0.0.1.
Escape character is '^]'.
set test 0 3600 4
1234
STORED
get test
VALUE test 0 4
1234
END
quit
Connection closed by foreign host.
[root@centos openxs]# service mysql stop
Shutting down MySQL (Percona Server).... SUCCESS!

and in the error log I see:

InnoDB MEMCACHED: Memcached uses atomic increment
2014-11-20 13:43:06 5022 [Note] Server hostname (bind-address): '*'; port: 3306
2014-11-20 13:43:06 5022 [Note] IPv6 is available.
2014-11-20 13:43:06 5022 [Note] - '::' resolves to '::';
2014-11-20 13:43:06 5022 [Note] Server socket created on IP: '::'.
2014-11-20 13:43:06 5022 [Note] Event Scheduler: Loaded 0 events
2014-11-20 13:43:06 5022 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.6.21-70.0' socket: '/var/lib/mysql/mysql.sock' port: 3306 Percona Server (GPL), Release 70.0, Revision 688
2014-11-20 13:44:50 5022 [Note] /usr/sbin/mysqld: Normal shutdown

2014-11-20 13:44:50 5022 [Note] Giving 0 client threads a chance to die gracefully
2014-11-20 13:44:50 5022 [Note] Event Scheduler: Purging the queue. 0 events
2014-11-20 13:44:50 5022 [Note] Shutting down slave threads
2014-11-20 13:44:50 5022 [Note] Forcefully disconnecting 0 remaining clients
2014-11-20 13:44:52 5022 [Note] Binlog end
2014-11-20 13:44:52 5022 [Note] Shutting down plugin 'partition'
2014-11-20 13:44:52 5022 [Note] Shutting down plugin 'ARCHIVE'
2014-11-20 13:44:52 5022 [Note] Shutting down plugin 'BLACKHOLE'
2014-11-20 13:44:52 5022 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA'
2014-11-20 13:44:52 5022 [Note] Shutting down plugin 'INNODB_CHANGED_PAGES'
2014-11-20 13:44:52 5022 [Note] Shutting down plugin 'INNODB_SYS_DATAFILES'
2014-11-20 13:44:52 5022 [Note] Shutting down plugin 'INNODB_SYS_TABLESPACES'
2014-11-20 13:44:52 5022 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN_COLS'
2014-11-20 13:44:52 5022 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN'
2014-11-20 13:44:52 5022 [Note] Shutting down plugin 'INNODB_SYS_FIELDS'
2014-11-20 13:44:52 5022 [Note] Shutting down plugin 'INNODB_SYS_COLUMNS'
2014-11-20 13:44:52 5022 [Note] Shutting down plugin 'INNODB_SYS_INDEXES'
2014-11-20 13:44:52 5022 [Note] Shutting down plugin 'INNODB_SYS_TABLESTATS'
2014-11-20 13:44:52 5022 [Note] Shutting down plugin 'INNODB_SYS_TABLES'
2014-11-20 13:44:52 5022 [Note] Shutting down plugin 'INNODB_FT_INDEX_TABLE'
2014-11-20 13:44:52 5022 [Note] Shutting down plugin 'INNODB_FT_INDEX_CACHE'
2014-11-20 13:44:52 5022 [Note] Shutting down plugin 'INNODB_FT_CONFIG'
2014-11-20 13:44:52 5022 [Note] Shutting down plugin 'INNODB_FT_BEING_DELETED'
2014-11-20 13:44:52 5022 [Note] Shutting down plugin 'INNODB_FT_DELETED'
2014-11-20 13:44:52 5022 [Note] Shutting down plugin 'INNODB_FT_DEFAULT_STOPWORD'
2014-11-20 13:44:52 5022 [Note] Shutting down plugin 'INNODB_METRICS'
2014-11-20 13:44:52 5022 [Note] Shutting down plugin 'INNODB_BUFFER_POOL_STATS'
2014-11-20 13:44:52 5022 [Note] Shutti...

[Dmitriy (testino)]

i am install fresh centos 6.6 and use step in comment #3 with attached mysql config
And this error stil present(with default config all fine).

So after some time i find problem option:
it is
innodb_api_enable_binlog = 1
with this option mysql cannot stop. Please check it with my config.

[Valerii Kravchuk (valerii-kravchuk)]

Yes, this was a missing small detail:

[root@centos openxs]# mysql -uroot test
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 2
Server version: 5.6.21-70.0-log Percona Server (GPL), Release 70.0, Revision 688

Copyright (c) 2009-2014 Percona LLC and/or its affiliates
Copyright (c) 2000, 2014, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> show variables like 'innodb_api%';
+-------------------------------+-------+
| Variable_name | Value |
+-------------------------------+-------+
| innodb_api_bk_commit_interval | 5 |
| innodb_api_disable_rowlock | OFF |
| innodb_api_enable_binlog | ON |
| innodb_api_enable_mdl | OFF |
| innodb_api_trx_level | 0 |
+-------------------------------+-------+
5 rows in set (0.00 sec)

mysql> show master status;
+-------------------+----------+--------------+------------------+-------------------+
| File | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+-------------------+----------+--------------+------------------+-------------------+
| centos-bin.000001 | 224 | | | |
+-------------------+----------+--------------+------------------+-------------------+
1 row in set (0.00 sec)

mysql> exit
Bye
[root@centos openxs]# service mysql stop
Shutting down MySQL (Percona Server).................................................. SUCCESS!
[root@centos openxs]# tail -100 /var/log/mysqld.log
...

2014-11-20 17:24:11 2581 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.21-70.0 started; log sequence number 3746264
InnoDB MEMCACHED: Memcached uses atomic increment
2014-11-20 17:24:11 2581 [Note] Server hostname (bind-address): '*'; port: 3306
2014-11-20 17:24:11 2581 [Note] IPv6 is available.
2014-11-20 17:24:11 2581 [Note] - '::' resolves to '::';
2014-11-20 17:24:11 2581 [Note] Server socket created on IP: '::'.
2014-11-20 17:24:11 2581 [Note] Event Scheduler: Loaded 0 events
2014-11-20 17:24:11 2581 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.6.21-70.0-log' socket: '/var/lib/mysql/mysql.sock' port: 3306 Percona Server (GPL), Release 70.0, Revision 688
2014-11-20 17:24:35 2581 [Note] /usr/sbin/mysqld: Normal shutdown

2014-11-20 17:24:35 2581 [Note] Giving 0 client threads a chance to die gracefully
2014-11-20 17:24:35 2581 [Note] Event Scheduler: Purging the queue. 0 events
2014-11-20 17:24:35 2581 [Note] Shutting down slave threads
2014-11-20 17:24:35 2581 [Note] Forcefully disconnecting 0 remaining clients
 InnoDB_Memcached: Waited for 50 seconds for memcached thread to exit. Now force terminating the thread
141120 17:25:25 mysqld_safe Number of processes running now: 0
141120 17:25:25 mysqld_safe mysqld restarted
...

[Laurynas Biveinis (laurynas-biveinis)]

Is this an upstream issue?

[Nilnandan Joshi (nilnandan-joshi)]

Laurynas,

I found almost same bug reported upstream http://bugs.mysql.com/bug.php?id=74956
Not sure, if it is same like user mentioned here. Please let me know if I need to test anything else.

[Dmitriy (testino)]

fixed on last version.

[Shahriyar Rzayev (rzayev-sehriyar)]

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-844