First connection after changing wsrep_cluster_address hangs

[Alex Yurchenko]

As reported by Patrick Zoblisein:

I've been doing some more testing of the `SET GLOBAL wsrep_cluster_address='<>;` functionality and I'm still able to hang my node - regardless of whether it's changing the cluster_address to another node in the cluster, or removing the node from the cluster via gcomm://;

Performing the dynamic change in my lab environment works - no issues as Seppo notes above. It's not until I make a connection to the node, "post-set-GLOBAL-wsrep_cluster_address" - here is a lot of output showing no connections (other than my working one) while I bounce back and forth between cluster_address':

[root@lab1 pxc]# mysql -u root -p
Enter password:
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 4
Server version: 5.5.20-beta23.4-log Percona XtraDB Cluster (GPL) 5.5.20-beta23.4, Revision 3724, wsrep_23.4.r3724

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql> show processlist;
+----+-----------------+-----------+------+---------+------+------------------------+------------------+-----------+---------------+-----------+
| Id | User | Host | db | Command | Time | State | Info | Rows_sent | Rows_examined | Rows_read |
+----+-----------------+-----------+------+---------+------+------------------------+------------------+-----------+---------------+-----------+
| 1 | system user | | NULL | Sleep | 13 | wsrep aborter idle | NULL | 0 | 0 | 1 |
| 2 | system user | | NULL | Sleep | 13 | NULL | NULL | 0 | 0 | 1 |
| 3 | event_scheduler | localhost | NULL | Daemon | 13 | Waiting on empty queue | NULL | 0 | 0 | 1 |
| 4 | root | localhost | NULL | Query | 0 | sleeping | show processlist | 0 | 0 | 1 |
+----+-----------------+-----------+------+---------+------+------------------------+------------------+-----------+---------------+-----------+
4 rows in set (0.00 sec)

mysql> show variables like 'wsrep_cluster_address';
+-----------------------+----------------------------+
| Variable_name | Value |
+-----------------------+----------------------------+
| wsrep_cluster_address | gcomm://1.2.3.4:1260 |
+-----------------------+----------------------------+
1 row in set (0.00 sec)

mysql> show processlist;
+----+-----------------+-----------+------+---------+------+------------------------+------------------+-----------+---------------+-----------+
| Id | User | Host | db | Command | Time | State | Info | Rows_sent | Rows_examined | Rows_read |
+----+-----------------+-----------+------+---------+------+------------------------+------------------+-----------+---------------+-----------+
| 1 | system user | | NULL | Sleep | 38 | wsrep aborter idle | NULL | 0 | 0 | 1 |
| 2 | system user | | NULL | Sleep | 38 | NULL | NULL | 0 | 0 | 1 |
| 3 | event_scheduler | localhost | NULL | Daemon | 38 | Waiting on empty queue | NULL | 0 | 0 | 1 |
| 4 | root | localhost | NULL | Query | 0 | sleeping | show processlist | 0 | 0 | 2 |
+----+-----------------+-----------+------+---------+------+------------------------+------------------+-----------+---------------+-----------+
4 rows in set (0.00 sec)

mysql> set global wsrep_cluster_address='gcomm://';
Query OK, 0 rows affected (2.01 sec)

mysql> show processlist;
+----+-----------------+-----------+------+---------+------+------------------------+------------------+-----------+---------------+-----------+
| Id | User | Host | db | Command | Time | State | Info | Rows_sent | Rows_examined | Rows_read |
+----+-----------------+-----------+------+---------+------+------------------------+------------------+-----------+---------------+-----------+
| 3 | event_scheduler | localhost | NULL | Daemon | 67 | Waiting on empty queue | NULL | 0 | 0 | 1 |
| 4 | root | localhost | NULL | Query | 0 | sleeping | show processlist | 0 | 0 | 2 |
| 5 | system user | | NULL | Sleep | 4 | wsrep aborter idle | NULL | 0 | 0 | 1 |
| 6 | system user | | NULL | Sleep | 4 | NULL | NULL | 0 | 0 | 1 |
+----+-----------------+-----------+------+---------+------+------------------------+------------------+-----------+---------------+-----------+
4 rows in set (0.00 sec)

mysql> set global wsrep_cluster_address='gcomm://1.2.3.4:1260';
Query OK, 0 rows affected (3.00 sec)

mysql> set global wsrep_cluster_address='gcomm://';
Query OK, 0 rows affected (2.00 sec)

mysql> show variables like 'wsrep_cluster_address';
+-----------------------+----------+
| Variable_name | Value |
+-----------------------+----------+
| wsrep_cluster_address | gcomm:// |
+-----------------------+----------+
1 row in set (0.01 sec)

mysql> set global wsrep_cluster_address='gcomm://1.2.3.5:1270';
Query OK, 0 rows affected (3.01 sec)

mysql> show variables like 'wsrep_cluster_address';
+-----------------------+----------------------------+
| Variable_name | Value |
+-----------------------+----------------------------+
| wsrep_cluster_address | gcomm://1.2.3.5:1270 |
+-----------------------+----------------------------+
1 row in set (0.00 sec)

mysql> set global wsrep_cluster_address='gcomm://';
Query OK, 0 rows affected (2.00 sec)

Now, I try to make another connection - which just sits there:
[root@lab1 workarea]# mysql -u root -p
Enter password:

Flip over to my working connection and I see a new connection stuck in the "login" state:
mysql> show processlist;
+----+----------------------+-----------------+------+---------+------+------------------------+------------------+-----------+---------------+-----------+
| Id | User | Host | db | Command | Time | State | Info | Rows_sent | Rows_examined | Rows_read |
+----+----------------------+-----------------+------+---------+------+------------------------+------------------+-----------+---------------+-----------+
| 3 | event_scheduler | localhost | NULL | Daemon | 810 | Waiting on empty queue | NULL | 0 | 0 | 1 |
| 4 | root | localhost | NULL | Query | 0 | sleeping | show processlist | 0 | 0 | 2 |
| 13 | system user | | NULL | Sleep | 430 | NULL | NULL | 0 | 0 | 1 |
| 14 | system user | | NULL | Sleep | 430 | wsrep aborter idle | NULL | 0 | 0 | 1 |
| 15 | unauthenticated user | connecting host | NULL | Connect | NULL | login | NULL | 0 | 0 | 1 |
+----+----------------------+-----------------+------+---------+------+------------------------+------------------+-----------+---------------+-----------+
5 rows in set (0.00 sec)

NOTE - this does not block all new connections by the way - open another window and make another connection and we're OK.
[root@lab1 ~]# mysql -u root -p
Enter password:
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 16
Server version: 5.5.20-beta23.4-log Percona XtraDB Cluster (GPL) 5.5.20-beta23.4 , Revision 3724, wsrep_23.4.r3724

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql> show processlist;
+----+----------------------+-----------------+------+---------+------+------------------------+------------------+-----------+---------------+-----------+
| Id | User | Host | db | Command | Time | State | Info | Rows_sent | Rows_examined | Rows_read |
+----+----------------------+-----------------+------+---------+------+------------------------+------------------+-----------+---------------+-----------+
| 3 | event_scheduler | localhost | NULL | Daemon | 1016 | Waiting on empty queue | NULL | 0 | 0 | 1 |
| 4 | root | localhost | NULL | Sleep | 206 | | NULL | 0 | 0 | 2 |
| 13 | system user | | NULL | Sleep | 636 | NULL | NULL | 0 | 0 | 1 |
| 14 | system user | | NULL | Sleep | 636 | wsrep aborter idle | NULL | 0 | 0 | 1 |
| 15 | unauthenticated user | connecting host | NULL | Connect | NULL | login | NULL | 0 | 0 | 1 |
| 16 | root | localhost | NULL | Query | 0 | sleeping | show processlist | 0 | 0 | 1 |
+----+----------------------+-----------------+------+---------+------+------------------------+------------------+-----------+---------------+-----------+
6 rows in set (0.00 sec)

The issue then becomes not being able to do another dynamic setting of the cluster_address:

mysql> set global wsrep_cluster_address='1.2.3.4:1260';

(wsrep_debug is equal to 1 in the cnf file)
120329 23:48:27 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
120329 23:48:27 [Note] WSREP: Assign initial position for certification: 150026, protocol version: 2
120329 23:48:27 [Note] WSREP: Synchronized with group, ready for connections
120329 23:48:27 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
120330 0:00:03 [Note] WSREP: Stop replication
120330 0:00:03 [Note] WSREP: Provider disconnect
120330 0:00:03 [Note] WSREP: Closing send monitor...
120330 0:00:03 [Note] WSREP: Closed send monitor.
120330 0:00:03 [Note] WSREP: gcomm: terminating thread
120330 0:00:03 [Note] WSREP: gcomm: joining thread
120330 0:00:03 [Note] WSREP: gcomm: closing backend
120330 0:00:03 [Note] WSREP: GMCast::handle_stable_view: view((empty))
120330 0:00:03 [Note] WSREP: Received self-leave message.
120330 0:00:03 [Note] WSREP: gcomm: closed
120330 0:00:03 [Note] WSREP: Flow-control interval: [0, 0]
120330 0:00:03 [Note] WSREP: Received SELF-LEAVE. Closing connection.
120330 0:00:03 [Note] WSREP: Shifting SYNCED -> CLOSED (TO: 150026)
120330 0:00:03 [Note] WSREP: RECV thread exiting 0: Success
120330 0:00:03 [Note] WSREP: New cluster view: global state: b2a15cb4-7786-11e1-0800-0a71e5c1d29d:150026, view# -1: non-Primary, number of nodes: 0, my index: -1, protocol version 1
120330 0:00:03 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
120330 0:00:03 [Note] WSREP: recv_thread() joined.
120330 0:00:03 [Note] WSREP: Closing slave action queue.
120330 0:00:03 [Note] WSREP: closing connection 15
120330 0:00:03 [Note] WSREP: closing connection 4
120330 0:00:03 [Note] WSREP: applier thread exiting (code:0)
120330 0:00:03 [Note] WSREP: closing applier 13
120330 0:00:05 [Note] WSREP: SST kill local trx: 15
120330 0:00:05 [Note] WSREP: SST kill local trx: 4
120330 0:00:05 [Note] WSREP: waiting for client connections to close: 5

My once working connection is no longer:

mysql> show processlist;
ERROR 2006 (HY000): MySQL server has gone away
No connection. Trying to reconnect...

Performing a shutdown of the mysql service hangs and eventually times out - only option is to kill -9.

Is there anything I can do to better troubleshoot the hung user connection?

Thanks
Patrick

[Alex Yurchenko (ayurchen)]

This concerns only the very first connection. Subsequent connections go through.

[Seppo Jaakola (seppo-jaakola)]

Tried with latest wsrep-5.5 and wsrep-5.6 builds and could not reproduce the issue anymore

Revisions were as follows:
5.5.35: http://bazaar.launchpad.net/~codership/codership-mysql/wsrep-5.5/revision/3935
5.6.15: http://bazaar.launchpad.net/~codership/codership-mysql/5.6/revision/4030

[Shahriyar Rzayev (rzayev-sehriyar)]

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