XtraBackup IST wouldn’t stop when MySQL start and synced

[Chriss]

Hello,

after upgrade to the latest Version on Centos 6.5
OLD:
percona-release-0.1-3.noarch
Percona-Server-shared-51-5.1.73-rel14.12.624.rhel6.x86_64
percona-toolkit-2.2.12-1.noarch
percona-xtrabackup-2.2.6-5042.el6.x86_64
Percona-XtraDB-Cluster-client-56-5.6.20-25.7.888.el6.x86_64
Percona-XtraDB-Cluster-galera-3-3.7-1.3254.rhel6.x86_64
Percona-XtraDB-Cluster-server-56-5.6.20-25.7.888.el6.x86_64
Percona-XtraDB-Cluster-shared-56-5.6.20-25.7.888.el6.x86_64

NEW:
Percona-Server-shared-51-5.1.73-rel14.12.624.rhel6.x86_64
Percona-XtraDB-Cluster-client-56-5.6.22-25.8.978.el6.x86_64
Percona-XtraDB-Cluster-shared-56-5.6.22-25.8.978.el6.x86_64
percona-xtrabackup-2.2.10-1.el6.x86_64
percona-toolkit-2.2.13-1.noarch
percona-release-0.1-3.noarch
Percona-XtraDB-Cluster-galera-3-3.9-1.3494.rhel6.x86_64
Percona-XtraDB-Cluster-server-56-5.6.22-25.8.978.el6.x86_64

The script "wsrep_sst_xtrabackup-v2 --role joiner " and socat remains after an "service mysql start/restart", mysql node has joined and is synced.
If i restart mysql the node terminates with an Error because the not terminated socat on port 4444.
On the next restart the node makes a coplete sync SST (not so good).

Next i notice that during the "yum update" mysql server is being stopped but never restartet, after yum update finishd i restartet mysql manually.

[Chriss (bst2002)]

ps auxfwww after "service mysql restart"

root 20588 0.2 0.0 11472 1544 pts/1 S 14:04 0:00 /bin/sh /usr/bin/mysqld_safe --datadir=/usr2/data/mysql --pid-file=/var/run/mysqld/mysqld.pid
mysql 22751 11.0 30.1 3248880 886564 pts/1 Sl 14:04 0:35 \_ /usr/sbin/mysqld --basedir=/usr --datadir=/usr2/data/mysql --plugin-dir=/usr/lib64/mysql/plugin --user=mysql --wsrep-provider=/usr/lib64/libgalera_smm.so --wsrep-provider=/usr/lib64/libgalera_smm.so --log-error=/var/log/mysqld.log --open-files-limit=65535 --pid-file=/var/run/mysqld/mysqld.pid --socket=/var/run/mysqld/mysqld.sock --port=3306 --wsrep_start_position=a37aad2f-6739-11e3-9e77-02ae5804f38e:186588386
mysql 23018 0.0 0.0 23824 972 ? S 14:04 0:00 /bin/bash -ue /usr//bin/wsrep_sst_xtrabackup-v2 --role joiner --address 10.0.2.203 --auth user:pass --datadir /usr2/data/mysql/ --defaults-file /etc/my.cnf --parent 22751
mysql 23019 0.0 0.0 16540 792 ? S 14:04 0:00 \_ logger -p daemon.err -t -wsrep-sst-joiner
mysql 23665 0.0 0.0 56624 2312 ? S 14:04 0:00 socat -u TCP-LISTEN:4444,reuseaddr stdio
mysql 23668 0.0 0.0 33820 1320 ? S 14:04 0:00 xbstream -x

mysqld.log:

015-04-14 14:04:23 22751 [Note] WSREP: SST received: a37aad2f-6739-11e3-9e77-02ae5804f38e:186588386
2015-04-14 14:04:23 22751 [Note] WSREP: Receiving IST: 361 writesets, seqnos 186588386-186588747
2015-04-14 14:04:23 22751 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.6.22-72.0-56-log' socket: '/var/run/mysqld/mysqld.sock' port: 3306 Percona XtraDB Cluster (GPL), Release rel72.0, Revision 978, WSREP version 25.8, wsrep_25.8.r4150
2015-04-14 14:04:24 22751 [Note] WSREP: IST received: a37aad2f-6739-11e3-9e77-02ae5804f38e:186588747
2015-04-14 14:04:24 22751 [Note] WSREP: 1.0 (ISP02-PXCNode03): State transfer from 4.0 (ISP02-PXCNode05) complete.
2015-04-14 14:04:24 22751 [Note] WSREP: Shifting JOINER -> JOINED (TO: 186588881)
2015-04-14 14:04:24 22751 [Note] WSREP: Member 1.0 (ISP02-PXCNode03) synced with group.
2015-04-14 14:04:24 22751 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 186588881)
2015-04-14 14:04:24 22751 [Note] WSREP: Synchronized with group, ready for connections
Warning: Using a password on the command line interface can be insecure.
2015-04-14 14:04:25 22751 [Warning] WSREP: Failed to report last committed 186588858, -4 (Interrupted system call)

[Chriss (bst2002)]

log/messages:

Apr 14 14:04:18 PXCnode3 -wsrep-sst-joiner: Streaming with xbstream
Apr 14 14:04:18 PXCnode3 -wsrep-sst-joiner: Using socat as streamer
Apr 14 14:04:18 PXCnode3 -wsrep-sst-joiner: Evaluating timeout -s9 100 socat -u TCP-LISTEN:4444,reuseaddr stdio | xbstream -x; RC=( ${PIPESTATUS[@]} )
Apr 14 14:04:21 PXCnode3 -wsrep-sst-joiner: Evaluating socat -u TCP-LISTEN:4444,reuseaddr stdio | xbstream -x; RC=( ${PIPESTATUS[@]} )
Apr 14 14:04:21 PXCnode3 -wsrep-sst-joiner: xtrabackup_ist received from donor: Running IST
Apr 14 14:04:21 PXCnode3 -wsrep-sst-joiner: Galera co-ords from recovery: a37aad2f-6739-11e3-9e77-02ae5804f38e:186588386
Apr 14 14:04:21 PXCnode3 -wsrep-sst-joiner: Total time on joiner: 0 seconds
Apr 14 14:04:21 PXCnode3 -wsrep-sst-joiner: Removing the sst_in_progress file

[Danny Gueta (danny-gueta)]

I can confirm this is happening on our cluster as-well same issue which accidentally even caused a full SST since port 444 was occupied even though IST had long finished (socat stays alive).

[Nilnandan Joshi (nilnandan-joshi)]

It seems, this is the same like https://bugs.launchpad.net/percona-xtradb-cluster/+bug/1451524