5.5 mysqld daemon with installed handlersocket plugin ignores any signals

Bug #1319904 reported by Nikolai on 2014-05-15
24
This bug affects 3 people
Affects Status Importance Assigned to Milestone
Percona Server moved to https://jira.percona.com/projects/PS
Invalid
Undecided
Unassigned
5.1
Invalid
Undecided
Unassigned
5.5
Fix Released
High
Laurynas Biveinis
5.6
Invalid
Undecided
Unassigned

Bug Description

After updating from Percona-Server-5.5.35-rel33.0 to the latest release Percona-Server-5.5.37-rel35.0 i faced the following problem - mysqld daemon did not stop even after receiving SIGTEM signal. I tried to stop it with init-script and with kill -15 `pidof mysqld`. In fact, mysqld ignores this signal completely and continues to work as usual.

i discovered that the problem appears only while enabling handlersocket plugin and affected all versions higher than Percona-Server-5.5.35-rel33 on SLES 11.3, CentOS 6.4 and Debian Squeeze

how to reproduce:
install Percona-Server higher than Percona-Server-5.5.35
install handlersocket as usual
 mysql> INSTALL PLUGIN handlersocket SONAME 'handlersocket.so';
add next row in my.cnf in [mysqld] section - loose_handlersocket_port = 9998
restart percona server
after than you can try to stop it. mysqld ignores any signal except SIGKILL

here is my config

[mysqld]
socket = /local/mysql/mysql.sock
datadir = /local/mysql/data/
innodb_file_per_table
innodb_data_home_dir = /local/mysql/innodb/
innodb_data_file_path = ibdata1:1G:autoextend
innodb_log_group_home_dir = /local/mysql/var/
innodb_log_file_size = 1G
loose_handlersocket_port = 9998

Nikolai (korolev-n) on 2014-05-21
description: updated
Download full text (6.8 KiB)

Confirmed on Ubuntu:

openxs@ao756:~$ mysql -uroot -proot test
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 37
Server version: 5.5.37-35.0-657.saucy (Ubuntu)

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 '%handlers%';
mysql> show variables like '%handlers%';
+-------------------------------+-------+
| Variable_name | Value |
+-------------------------------+-------+
| handlersocket_accept_balance | 0 |
| handlersocket_address | |
| handlersocket_backlog | 32768 |
| handlersocket_epoll | 1 |
| handlersocket_plain_secret | |
| handlersocket_plain_secret_wr | |
| handlersocket_port | 9998 |
| handlersocket_port_wr | |
| handlersocket_rcvbuf | 0 |
| handlersocket_readsize | 0 |
| handlersocket_sndbuf | 0 |
| handlersocket_threads | 16 |
| handlersocket_threads_wr | 1 |
| handlersocket_timeout | 300 |
| handlersocket_verbose | 10 |
| handlersocket_wrlock_timeout | 12 |
+-------------------------------+-------+
16 rows in set (0,01 sec)

mysql> show plugins;
+--------------------------------+----------+--------------------+------------------+---------+
| Name | Status | Type | Library | License |
+--------------------------------+----------+--------------------+------------------+---------+
| binlog | ACTIVE | STORAGE ENGINE | NULL | GPL |
| mysql_native_password | ACTIVE | AUTHENTICATION | NULL | GPL |
| mysql_old_password | ACTIVE | AUTHENTICATION | NULL | GPL |
| MyISAM | ACTIVE | STORAGE ENGINE | NULL | GPL |
| MEMORY | ACTIVE | STORAGE ENGINE | NULL | GPL |
| CSV | ACTIVE | STORAGE ENGINE | NULL | GPL |
| MRG_MYISAM | ACTIVE | STORAGE ENGINE | NULL | GPL |
| ARCHIVE | ACTIVE | STORAGE ENGINE | NULL | GPL |
| PERFORMANCE_SCHEMA | ACTIVE | STORAGE ENGINE | NULL | GPL |
| FEDERATED | DISABLED | STORAGE ENGINE | NULL | GPL |
| InnoDB | ACTIVE | STORAGE ENGINE | NULL | GPL |
| INNODB_RSEG | ACTIVE | INFORMATION SCHEMA | NULL | GPL |
| INNODB_UNDO_LOGS | ACTIVE | INFORMATION SCHEMA | NULL | GPL |
| INNODB_TRX | ACTIVE | INFORMATION SCHEMA | NULL | GPL |
| INNODB_LOCKS | ACTIVE |...

Read more...

tags: added: handlersocket
Serge (laaxags) wrote :

With all respect to Percona - but why use third-party HandlerSocket instead of an own Percona solution ?

Percona developers could create a native Percona plugin what allows to perform the some of MySQL operations (simple ones only) like SELECT or INSERT - but applying to MySQL as NoSQL - same what HandlerSocket does.

It can be used by own Percona syntax for such commands, let's say
SELECT id, title, date - applies to MySQL using standard way, but specific syntax like
SELECTNS id, title,date - or - INSERTNS id, title,date - Percona understands as NoSQL query and perform it accordingly using a native analog of HandlerSocket.

It would be ideal for simple only bulk operations.
Just an idea, but why not ?
Great successes to Percona team anyway !

I can confirm on Ubuntu 14.04 the same problem
But it appears to be much worse as Percona 5.5.37 seems to come with handlersocket installed by default. So all I did was install Percona and now can't stop the server. As this is part of our automatic install script for EC2 machine bootstrapping, this bug kills the whole procedure. Any idea when will it be fixed?

Btw, tried Percona 5.6, but it has another problem, it crashes during the inplace database recovery (of the database created by Percona 5.5.).

Download full text (7.1 KiB)

I can not reproduce this with 5.6 on CentOS:

[openxs@centos ~]$ ps aux | grep mysqld
root 1139 0.0 0.1 108300 1624 ? S 19:01 0:00 /bin/sh /usr/bin/mysqld_safe --datadir=/var/lib/mysql --pid-file=/var/lib/mysql/centos.pid
mysql 1408 0.4 29.9 1126148 460864 ? Sl 19:01 0:07 /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --user=mysql --log-error=/var/log/mysqld.log --pid-file=/var/lib/mysql/centos.pid --socket=/var/lib/mysql/mysql.sock
openxs 1561 0.0 0.0 103244 848 pts/0 S+ 19:25 0:00 grep mysqld
[openxs@centos ~]$ mysql -uroot test
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 1
Server version: 5.6.17-66.0 Percona Server (GPL), Release 66.0, Revision 608

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> INSTALL PLUGIN handlersocket SONAME 'handlersocket.so';
Query OK, 0 rows affected (0.07 sec)

mysql> exit
Bye
[openxs@centos ~]$ su
Password:
[root@centos openxs]# service mysql stop
Shutting down MySQL (Percona Server).. SUCCESS!
[root@centos openxs]# vi /etc/my.cnf
[root@centos openxs]# grep handler /etc/my.cnf
loose_handlersocket_port=9998
[root@centos openxs]# service mysql start
Starting MySQL (Percona Server)... SUCCESS!
[root@centos openxs]# kill -15 `pidof mysqld`
[root@centos openxs]# ps aux | grep mysqld
root 1932 0.0 0.0 103244 844 pts/0 S+ 19:27 0:00 grep mysqld
[root@centos openxs]# service mysql start
Starting MySQL (Percona Server)... SUCCESS!
[root@centos openxs]# mysql -uroot test
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 1
Server version: 5.6.17-66.0 Percona Server (GPL), Release 66.0, Revision 608

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 plugins;
+-----------------------------+----------+--------------------+------------------+---------+
| Name | Status | Type | Library | License |
+-----------------------------+----------+--------------------+------------------+---------+
| binlog | ACTIVE | STORAGE ENGINE | NULL | GPL |
| mysql_native_password | ACTIVE | AUTHENTICATION | NULL | GPL |
| mysql_old_password | ACTIVE | AUTHENTICATION | NULL | GPL |
| sha256_password | ACTIVE | AUTHENTICATION | NULL | GPL |
| MyISAM | ACTIVE | STORAGE ENGINE | NULL | GPL |
| MRG_MYISAM | ACT...

Read more...

IMHO PS 5.5 mysqld ignoring SIGTERM by default (because HS is installed by default) warrants a priority bump.

Lisio (lisio) wrote :

How to reproduce on Ubuntu 14.04:

Add Percona repositories to apt sources:
    deb http://repo.percona.com/apt trusty main
    deb-src http://repo.percona.com/apt trusty main
Install Percona XtraDB Cluster
    apt-get install percona-xtradb-cluster-55 percona-xtradb-cluster-galera-2 percona-xtradb-cluster-galera-2.x
Add HandlerSocket config lines to /etc/mysql/my.cnf
    loose_handlersocket_port = 9998
    loose_handlersocket_port_wr = 9999
Start mysql service
    service mysql start
Stop mysql service
    service mysql stop
Wait for years

markus_albe (markus-albe) wrote :
Download full text (4.0 KiB)

Customer reproduced with 5.6.21 and I verified through code inspection:

Error log showed

2014-11-25 05:16:14 31200 [Note] /usr/sbin/mysqld: Normal shutdown
2014-11-25 05:16:14 31200 [Note] Giving 24 client threads a chance to die gracefully
2014-11-25 05:16:14 31200 [Note] Event Scheduler: Purging the queue. 0 events
2014-11-25 05:16:14 31200 [Note] Shutting down slave threads
2014-11-25 05:16:16 31200 [Note] Forcefully disconnecting 24 remaining clients

Then pmp showed:
23 __lll_lock_wait(libpthread.so.0),_L_lock_995(libpthread.so.0),pthread_mutex_lock(libpthread.so.0),dena::dbcontext::term_thread(handlersocket.so),dena::hstcpsvr_worker::run(handlersocket.so),dena::thread::thread_main(handlersocket.so),start_thread(libpthread.so.0),clone(libc.so.6)

1 __lll_lock_wait(libpthread.so.0),_L_lock_995(libpthread.so.0),pthread_mutex_lock(libpthread.so.0),remove_global_thread,dena::dbcontext::term_thread(handlersocket.so),dena::hstcpsvr_worker::run(handlersocket.so),dena::thread::thread_main(handlersocket.so),start_thread(libpthread.so.0),clone(libc.so.6)

Definition of dena::dbcontext::term_thread (from https://github.com/DeNA/HandlerSocket-Plugin-for-MySQL/blob/master/handlersocket/database.cpp#L346):

dbcontext::term_thread()
{
DBG_THR(fprintf(stderr, "HNDSOCK thread end %p\n", thd));
unlock_tables_if();
my_pthread_setspecific_ptr(THR_THD, 0);
{
pthread_mutex_lock(&LOCK_thread_count);
#if MYSQL_VERSION_ID >= 50600
remove_global_thread(thd);
#else
--thread_count;
#endif
delete thd;
thd = 0;
pthread_mutex_unlock(&LOCK_thread_count);
my_thread_end();
}
}

And definition of remove_global_thread (from 5.6.21/sql/mysqld.cc@892):

void remove_global_thread(THD *thd)
{
  DBUG_PRINT("info", ("remove_global_thread %p current_linfo %p",
                      thd, thd->current_linfo));
  mysql_mutex_lock(&LOCK_thd_remove);
  mysql_mutex_lock(&LOCK_thread_count);
  DBUG_ASSERT(thd->release_resources_done());
  /*
    Used by binlog_reset_master. It would be cleaner to use
    DEBUG_SYNC here, but that's not possible because the THD's debug
    sync feature has been shut down at this point.
   */
  DBUG_EXECUTE_IF("sleep_after_lock_thread_count_before_delete_thd",
                  sleep(5););

  const size_t num_erased= global_thread_list->erase(thd);
  if (num_erased == 1)
    --global_thread_count;
  // Removing a THD that was never added is an error.
  DBUG_ASSERT(1 == num_erased);

  mysql_mutex_unlock(&LOCK_thd_remove);
  mysql_cond_broadcast(&COND_thread_count);
  mysql_mutex_unlock(&LOCK_thread_count);
}

So my understanding is that the second time this tries to acquire the mutex here (mysql_mutex_lock(&LOCK_thread_count)) it will wait forever because LOCK_thread_count is not a recursive mutex (thanks Vlad for input about that):

fgrep -RnI --exclude-dir=build* --exclude-dir=mysql-test --exclude=tags --exclude=*.P* --exclude=*.T* "LOCK_thread_count" . | grep init
./tests/thread_test.c:196: pthread_mutex_init(&LOCK_thread_count,MY_MUTEX_INIT_FAST);
./sql/mysqld.cc:3638: mysql_mutex_init(key_LOCK_thread_count, &LOCK_thread_count, MY_MUTEX_INIT_FAST);
./mysys/thr_lock.c:1608: if ((error= mysql_mutex_init(0, &LOCK_thread_count, MY_MUTEX_INIT_F...

Read more...

tags: added: i48431

Markus, can you report this upstream?

Markus, sorry, that would be the HandlerSocket upstream, not Oracle.

The bug triggers only if HS is configured, merely installing the packages does not result in unstoppable server.

tags: added: pxc

The 5.5 and 5.6 issues are different.

For 5.5, the shutdown hang is caused by mysqld signal handler never having its initialisation completed if HS is installed. That happens because both HS and signal_hand wait for COND_server_started, which is signalled using mysql_cond_signal, meaning that only one waiter is woken up, which happens to be the HS one. The signal handler waiter does not have a time out.

This is a regression introduced in the upstream fix for http://bugs.mysql.com/bug.php?id=62311, backported to our 5.5 as bug 1249193. The upstream 5.6 later fixed the regression as

$ bzr log -r 4754.1.1
------------------------------------------------------------
revno: 4754.1.1
committer: <email address hidden>
branch nick: 5.6-bug16315379
timestamp: Tue 2013-02-12 11:17:24 +0100
message:
  Bug#16315379 COND_SERVER_STARTED MAY HAVE MULTIPLE WAITERS
   - Always use pthread_cond_broadcast when signalling COND_server_started since there
     may be more than one thread waiting for the condition.

summary: - mysqld daemon with installed handlersocket plugin did not stop
+ mysqld daemon with installed handlersocket plugin ignores any signals

Since the 5.5 and 5.6 issues have different underlying cause, and different (although overlapping) user symptoms, I have moved the 5.6 one (comments #8 and #14) to a new bug 1397859. The current bug will remain about 5.5 only, as that issue was reported first.

summary: - mysqld daemon with installed handlersocket plugin ignores any signals
+ 5.5 mysqld daemon with installed handlersocket plugin ignores any
+ signals
tags: removed: i48431

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

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Duplicates of this bug

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.