2014-09-21 08:58:26: run.sh: Including /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/conf/conf2.cnf-node1 and /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/conf/conf2.cnf-node2 for conf2 2014-09-21 08:58:26: run.sh: Starting server 1 2014-09-21 08:58:26: run.sh: Starting server with id=1... 2014-09-21 08:58:26: run.sh: Creating server root directory: /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var1 2014-09-21 08:58:26: run.sh: Creating server temporary directory: /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var1/tmp 2014-09-21 08:58:26: run.sh: Creating server data directory: /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var1/data 2014-09-21 08:58:26: run.sh: Calling mysql_install_db Installing MySQL system tables...2014-09-21 08:58:26 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details). OK Filling help tables...2014-09-21 08:58:45 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details). OK To start mysqld at boot time you have to copy support-files/mysql.server to the right place for your system PLEASE REMEMBER TO SET A PASSWORD FOR THE MySQL root USER ! To do so, start the server, then issue the following commands: /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/bin/mysqladmin -u root password 'new-password' /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/bin/mysqladmin -u root -h 75fde48ae41e password 'new-password' Alternatively you can run: /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/bin/mysql_secure_installation which will also give you the option of removing the test databases and anonymous user created by default. This is strongly recommended for production servers. See the manual for more instructions. You can start the MySQL daemon with: cd . ; /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/bin/mysqld_safe & You can test the MySQL daemon with mysql-test-run.pl cd mysql-test ; perl mysql-test-run.pl Please report any problems with Percona XtraDB Cluster 5.6 at https://bugs.launchpad.net/percona-xtradb-cluster/+filebug The latest information about Percona XtraDB Cluster 5.6 is available on the web at http://www.percona.com/doc/percona-xtradb-cluster/5.6/ Support Percona XtraDB Cluster 5.6 by buying support at http://www.percona.com/products/mysql-support WARNING: Default config file /etc/my.cnf exists on the system This file will be read by default by the MySQL server If you do not want to use this, either remove it, or use the --defaults-file argument to mysqld_safe when starting the server Starting /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/bin//mysqld --defaults-file=/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var1/my.cnf --innodb_flush_method=O_DIRECT --innodb_autoinc_lock_mode=2 --innodb_locks_unsafe_for_binlog=1 --wsrep-slave-threads=2 --innodb_file_per_table --binlog-format=ROW --wsrep-provider=/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/lib/libgalera_smm.so --wsrep_cluster_address=gcomm:// --wsrep_sst_receive_address=127.0.0.1:34202 --wsrep_node_incoming_address=127.0.0.1 --wsrep_provider_options=gmcast.listen_addr=tcp://127.0.0.1:23713 --wsrep_sst_method=xtrabackup-v2 --wsrep_sst_auth=root:password --wsrep_node_address=127.0.0.1 2014-09-21 08:58:49 0 [Warning] WSREP: wsrep_sst_receive_address is set to '127.0.0.1:34202' which makes it impossible for another host to reach this one. Please set it to the address which this node can be connected at by other cluster members. 2014-09-21 08:58:49 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details). 2014-09-21 08:58:50: run.sh: Made 1 attempts to connect to server 2014-09-21 08:58:50: run.sh: Server with id=1 has been started on port 26687, socket /tmp/xbtemp.y21894/mysql.sock.p21933 2014-09-21 08:58:50: run.sh: Sleeping before loading data 2014-09-21 08:58:58: run.sh: Loading sbtest database schema 2014-09-21 08:59:00: run.sh: Loading sbtest database data 2014-09-21 08:59:10: run.sh: Setting password to 'password' 2014-09-21 08:59:10: run.sh: ===> /usr/bin/mysql --defaults-file=/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var1/my.cnf 2014-09-21 08:59:10: run.sh: Starting server 901 2014-09-21 08:59:10: run.sh: Starting server with id=901... 2014-09-21 08:59:10: run.sh: Creating server root directory: /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var901 2014-09-21 08:59:10: run.sh: Creating server temporary directory: /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var901/tmp 2014-09-21 08:59:10: run.sh: Creating server data directory: /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var901/data 2014-09-21 08:59:10: run.sh: Skiping mysql_install_db of node 901 for SST Starting /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/bin//mysqld --defaults-file=/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var901/my.cnf --innodb_flush_method=O_DIRECT --innodb_autoinc_lock_mode=2 --innodb_locks_unsafe_for_binlog=1 --wsrep-slave-threads=2 --innodb_file_per_table --binlog-format=ROW --wsrep-provider=/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/lib/libgalera_smm.so --wsrep_cluster_address=gcomm://127.0.0.1:23713 --wsrep_sst_receive_address=127.0.0.1:23038 --wsrep_node_incoming_address=127.0.0.1 --wsrep_provider_options=gmcast.listen_addr=tcp://127.0.0.1:31049 --wsrep_sst_method=xtrabackup-v2 --wsrep_sst_auth=root:password --wsrep_node_address=127.0.0.1 2014-09-21 08:59:10 0 [Warning] WSREP: wsrep_sst_receive_address is set to '127.0.0.1:23038' which makes it impossible for another host to reach this one. Please set it to the address which this node can be connected at by other cluster members. 2014-09-21 08:59:10 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details). 2014-09-21 08:59:11: run.sh: Made 1 attempts to connect to server 2014-09-21 08:59:12: run.sh: Made 2 attempts to connect to server 2014-09-21 08:59:13: run.sh: Made 3 attempts to connect to server 2014-09-21 08:59:14: run.sh: Made 4 attempts to connect to server 2014-09-21 08:59:15: run.sh: Made 5 attempts to connect to server 2014-09-21 08:59:16: run.sh: Made 6 attempts to connect to server 2014-09-21 08:59:17: run.sh: Made 7 attempts to connect to server 2014-09-21 08:59:18: run.sh: Made 8 attempts to connect to server 2014-09-21 08:59:19: run.sh: Made 9 attempts to connect to server 2014-09-21 08:59:20: run.sh: Made 10 attempts to connect to server 2014-09-21 08:59:21: run.sh: Made 11 attempts to connect to server 2014-09-21 08:59:22: run.sh: Made 12 attempts to connect to server 2014-09-21 08:59:23: run.sh: Made 13 attempts to connect to server 2014-09-21 08:59:24: run.sh: Made 14 attempts to connect to server 2014-09-21 08:59:25: run.sh: Made 15 attempts to connect to server 2014-09-21 08:59:26: run.sh: Made 16 attempts to connect to server 2014-09-21 08:59:27: run.sh: Made 17 attempts to connect to server 2014-09-21 08:59:28: run.sh: Made 18 attempts to connect to server 2014-09-21 08:59:29: run.sh: Made 19 attempts to connect to server 2014-09-21 08:59:30: run.sh: Made 20 attempts to connect to server 2014-09-21 08:59:31: run.sh: Made 21 attempts to connect to server 2014-09-21 08:59:32: run.sh: Made 22 attempts to connect to server 2014-09-21 08:59:33: run.sh: Made 23 attempts to connect to server 2014-09-21 08:59:34: run.sh: Made 24 attempts to connect to server 2014-09-21 08:59:35: run.sh: Made 25 attempts to connect to server 2014-09-21 08:59:36: run.sh: Made 26 attempts to connect to server 2014-09-21 08:59:37: run.sh: Made 27 attempts to connect to server 2014-09-21 08:59:38: run.sh: Made 28 attempts to connect to server 2014-09-21 08:59:39: run.sh: Made 29 attempts to connect to server 2014-09-21 08:59:40: run.sh: Made 30 attempts to connect to server 2014-09-21 08:59:41: run.sh: Made 31 attempts to connect to server 2014-09-21 08:59:42: run.sh: Made 32 attempts to connect to server 2014-09-21 08:59:43: run.sh: Made 33 attempts to connect to server 2014-09-21 08:59:44: run.sh: Made 34 attempts to connect to server 2014-09-21 08:59:45: run.sh: Made 35 attempts to connect to server 2014-09-21 08:59:46: run.sh: Made 36 attempts to connect to server 2014-09-21 08:59:47: run.sh: Made 37 attempts to connect to server 2014-09-21 08:59:48: run.sh: Made 38 attempts to connect to server 2014-09-21 08:59:49: run.sh: Made 39 attempts to connect to server 2014-09-21 08:59:50: run.sh: Made 40 attempts to connect to server 2014-09-21 08:59:51: run.sh: Made 41 attempts to connect to server 2014-09-21 08:59:52: run.sh: Made 42 attempts to connect to server 2014-09-21 08:59:53: run.sh: Made 43 attempts to connect to server 2014-09-21 08:59:54: run.sh: Server process PID=22282 died. 2014-09-21 08:59:54: run.sh: Can't start the server. Server log (if exists): 2014-09-21 08:59:54: run.sh: ---------------- 2014-09-21 08:59:54: run.sh: Error log for server with id: 1 2014-09-21 08:58:26 21959 [Note] WSREP: Read nil XID from storage engines, skipping position init 2014-09-21 08:58:26 21959 [Note] WSREP: wsrep_load(): loading provider library 'none' 2014-09-21 08:58:26 21959 [Note] InnoDB: Using atomics to ref count buffer pool pages 2014-09-21 08:58:26 21959 [Note] InnoDB: The InnoDB memory heap is disabled 2014-09-21 08:58:26 21959 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2014-09-21 08:58:26 21959 [Note] InnoDB: Memory barrier is not used 2014-09-21 08:58:26 21959 [Note] InnoDB: Compressed tables use zlib 1.2.3 2014-09-21 08:58:26 21959 [Note] InnoDB: Using Linux native AIO 2014-09-21 08:58:26 21959 [Note] InnoDB: Using CPU crc32 instructions 2014-09-21 08:58:26 21959 [Note] InnoDB: Initializing buffer pool, size = 128.0M 2014-09-21 08:58:26 21959 [Note] InnoDB: Completed initialization of buffer pool 2014-09-21 08:58:26 21959 [Note] InnoDB: The first specified data file ./ibdata1 did not exist: a new database to be created! 2014-09-21 08:58:26 21959 [Note] InnoDB: Setting file ./ibdata1 size to 12 MB 2014-09-21 08:58:26 21959 [Note] InnoDB: Database physically writes the file full: wait... 2014-09-21 08:58:26 21959 [Note] InnoDB: Setting log file ./ib_logfile101 size to 48 MB 2014-09-21 08:58:27 21959 [Note] InnoDB: Setting log file ./ib_logfile1 size to 48 MB 2014-09-21 08:58:29 21959 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0 2014-09-21 08:58:29 21959 [Warning] InnoDB: New log files created, LSN=45781 2014-09-21 08:58:29 21959 [Note] InnoDB: Doublewrite buffer not found: creating new 2014-09-21 08:58:29 21959 [Note] InnoDB: Doublewrite buffer created 2014-09-21 08:58:29 21959 [Note] InnoDB: 128 rollback segment(s) are active. 2014-09-21 08:58:29 21959 [Warning] InnoDB: Creating foreign key constraint system tables. 2014-09-21 08:58:29 21959 [Note] InnoDB: Foreign key constraint system tables created 2014-09-21 08:58:29 21959 [Note] InnoDB: Creating tablespace and datafile system tables. 2014-09-21 08:58:29 21959 [Note] InnoDB: Tablespace and datafile system tables created. 2014-09-21 08:58:29 21959 [Note] InnoDB: Waiting for purge to start 2014-09-21 08:58:30 21959 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.20-68.0 started; log sequence number 0 2014-09-21 08:58:30 21959 [Note] RSA private key file not found: /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var1/data//private_key.pem. Some authentication plugins will not work. 2014-09-21 08:58:30 21959 [Note] RSA public key file not found: /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var1/data//public_key.pem. Some authentication plugins will not work. 2014-09-21 08:58:43 21959 [Note] WSREP: Service disconnected. 2014-09-21 08:58:44 21959 [Note] WSREP: Some threads may fail to exit. 2014-09-21 08:58:44 21959 [Note] Binlog end 2014-09-21 08:58:44 21959 [Note] InnoDB: FTS optimize thread exiting. 2014-09-21 08:58:44 21959 [Note] InnoDB: Starting shutdown... 2014-09-21 08:58:45 21959 [Note] InnoDB: Shutdown completed; log sequence number 1625977 2014-09-21 08:58:45 22059 [Note] WSREP: Read nil XID from storage engines, skipping position init 2014-09-21 08:58:45 22059 [Note] WSREP: wsrep_load(): loading provider library 'none' 2014-09-21 08:58:45 22059 [Note] InnoDB: Using atomics to ref count buffer pool pages 2014-09-21 08:58:45 22059 [Note] InnoDB: The InnoDB memory heap is disabled 2014-09-21 08:58:45 22059 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2014-09-21 08:58:45 22059 [Note] InnoDB: Memory barrier is not used 2014-09-21 08:58:45 22059 [Note] InnoDB: Compressed tables use zlib 1.2.3 2014-09-21 08:58:45 22059 [Note] InnoDB: Using Linux native AIO 2014-09-21 08:58:45 22059 [Note] InnoDB: Using CPU crc32 instructions 2014-09-21 08:58:45 22059 [Note] InnoDB: Initializing buffer pool, size = 128.0M 2014-09-21 08:58:45 22059 [Note] InnoDB: Completed initialization of buffer pool 2014-09-21 08:58:45 22059 [Note] InnoDB: Highest supported file format is Barracuda. 2014-09-21 08:58:45 22059 [Note] InnoDB: 128 rollback segment(s) are active. 2014-09-21 08:58:45 22059 [Note] InnoDB: Waiting for purge to start 2014-09-21 08:58:45 22059 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.20-68.0 started; log sequence number 1625977 2014-09-21 08:58:45 22059 [Note] RSA private key file not found: /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var1/data//private_key.pem. Some authentication plugins will not work. 2014-09-21 08:58:45 22059 [Note] RSA public key file not found: /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var1/data//public_key.pem. Some authentication plugins will not work. 2014-09-21 08:58:46 22059 [Note] WSREP: Service disconnected. 2014-09-21 08:58:47 22059 [Note] WSREP: Some threads may fail to exit. 2014-09-21 08:58:47 22059 [Note] Binlog end 2014-09-21 08:58:47 22059 [Note] InnoDB: FTS optimize thread exiting. 2014-09-21 08:58:47 22059 [Note] InnoDB: Starting shutdown... 2014-09-21 08:58:48 22059 [Note] InnoDB: Shutdown completed; log sequence number 1625987 2014-09-21 08:58:49 22096 [Note] WSREP: Read nil XID from storage engines, skipping position init 2014-09-21 08:58:49 22096 [Note] WSREP: wsrep_load(): loading provider library '/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/lib/libgalera_smm.so' 2014-09-21 08:58:49 22096 [Note] WSREP: wsrep_load(): Galera 3.7(r7f44a18) by Codership Oy loaded successfully. 2014-09-21 08:58:49 22096 [Note] WSREP: CRC-32C: using hardware acceleration. 2014-09-21 08:58:49 22096 [Warning] WSREP: Could not open saved state file for reading: /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var1/data//grastate.dat 2014-09-21 08:58:49 22096 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1 2014-09-21 08:58:49 22096 [Note] WSREP: Passing config to GCS: base_host = 127.0.0.1; base_port = 4567; cert.log_conflicts = no; debug = no; evs.inactive_check_period = PT0.5S; evs.inactive_timeout = PT15S; evs.join_retrans_period = PT1S; evs.max_install_timeouts = 3; evs.send_window = 4; evs.stats_report_period = PT1M; evs.suspect_timeout = PT5S; evs.user_send_window = 2; evs.view_forget_timeout = PT24H; gcache.dir = /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var1/data/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var1/data//galera.cache; gcache.page_size = 128M; gcache.size = 128M; gcs.fc_debug = 0; gcs.fc_factor = 1.0; gcs.fc_limit = 16; gcs.fc_master_slave = no; gcs.max_packet_size = 64500; gcs.max_throttle = 0.25; gcs.recv_q_hard_limit = 9223372036854775807; gcs.recv_q_soft_limit = 0.25; gcs.sync_donor = no; gmcast.listen_addr 2014-09-21 08:58:49 22096 [Note] WSREP: Service thread queue flushed. 2014-09-21 08:58:49 22096 [Note] WSREP: Assign initial position for certification: -1, protocol version: -1 2014-09-21 08:58:49 22096 [Note] WSREP: wsrep_sst_grab() 2014-09-21 08:58:49 22096 [Note] WSREP: Start replication 2014-09-21 08:58:49 22096 [Note] WSREP: Setting initial position to 00000000-0000-0000-0000-000000000000:-1 2014-09-21 08:58:49 22096 [Note] WSREP: protonet asio version 0 2014-09-21 08:58:49 22096 [Note] WSREP: Using CRC-32C for message checksums. 2014-09-21 08:58:49 22096 [Note] WSREP: backend: asio 2014-09-21 08:58:49 22096 [Warning] WSREP: access file(gvwstate.dat) failed(No such file or directory) 2014-09-21 08:58:49 22096 [Note] WSREP: restore pc from disk failed 2014-09-21 08:58:49 22096 [Note] WSREP: GMCast version 0 2014-09-21 08:58:49 22096 [Note] WSREP: (07b8fa9f, 'tcp://127.0.0.1:23713') listening at tcp://127.0.0.1:23713 2014-09-21 08:58:49 22096 [Note] WSREP: (07b8fa9f, 'tcp://127.0.0.1:23713') multicast: , ttl: 1 2014-09-21 08:58:49 22096 [Note] WSREP: EVS version 0 2014-09-21 08:58:49 22096 [Note] WSREP: PC version 0 2014-09-21 08:58:49 22096 [Note] WSREP: gcomm: connecting to group 'my_wsrep_cluster', peer '' 2014-09-21 08:58:49 22096 [Note] WSREP: start_prim is enabled, turn off pc_recovery 2014-09-21 08:58:49 22096 [Note] WSREP: Node 07b8fa9f state prim 2014-09-21 08:58:49 22096 [Note] WSREP: save pc into disk 2014-09-21 08:58:49 22096 [Note] WSREP: gcomm: connected 2014-09-21 08:58:49 22096 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636 2014-09-21 08:58:49 22096 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0) 2014-09-21 08:58:49 22096 [Note] WSREP: Opened channel 'my_wsrep_cluster' 2014-09-21 08:58:49 22096 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 1 2014-09-21 08:58:49 22096 [Note] WSREP: Waiting for SST to complete. 2014-09-21 08:58:49 22096 [Note] WSREP: Starting new group from scratch: 07b9a06f-418f-11e4-b20e-2a254b5cfbc3 2014-09-21 08:58:49 22096 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 07b9b901-418f-11e4-9531-12d2e0744e15 2014-09-21 08:58:49 22096 [Note] WSREP: STATE EXCHANGE: sent state msg: 07b9b901-418f-11e4-9531-12d2e0744e15 2014-09-21 08:58:49 22096 [Note] WSREP: STATE EXCHANGE: got state msg: 07b9b901-418f-11e4-9531-12d2e0744e15 from 0 (75fde48ae41e) 2014-09-21 08:58:49 22096 [Note] WSREP: Quorum results: version = 3, component = PRIMARY, conf_id = 0, members = 1/1 (joined/total), act_id = 0, last_appl. = -1, protocols = 0/6/3 (gcs/repl/appl), group UUID = 07b9a06f-418f-11e4-b20e-2a254b5cfbc3 2014-09-21 08:58:49 22096 [Note] WSREP: Flow-control interval: [16, 16] 2014-09-21 08:58:49 22096 [Note] WSREP: Restored state OPEN -> JOINED (0) 2014-09-21 08:58:49 22096 [Note] WSREP: Member 0.0 (75fde48ae41e) synced with group. 2014-09-21 08:58:49 22096 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 0) 2014-09-21 08:58:49 22096 [Note] WSREP: New cluster view: global state: 07b9a06f-418f-11e4-b20e-2a254b5cfbc3:0, view# 1: Primary, number of nodes: 1, my index: 0, protocol version 3 2014-09-21 08:58:49 22096 [Note] WSREP: SST complete, seqno: 0 2014-09-21 08:58:49 22096 [Note] Plugin 'FEDERATED' is disabled. 2014-09-21 08:58:49 7f917a1cb720 InnoDB: Warning: Using innodb_locks_unsafe_for_binlog is DEPRECATED. This option may be removed in future releases. Please use READ COMMITTED transaction isolation level instead, see http://dev.mysql.com/doc/refman/5.6/en/set-transaction.html. 2014-09-21 08:58:49 22096 [Note] InnoDB: Using atomics to ref count buffer pool pages 2014-09-21 08:58:49 22096 [Note] InnoDB: The InnoDB memory heap is disabled 2014-09-21 08:58:49 22096 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2014-09-21 08:58:49 22096 [Note] InnoDB: Memory barrier is not used 2014-09-21 08:58:49 22096 [Note] InnoDB: Compressed tables use zlib 1.2.3 2014-09-21 08:58:49 22096 [Note] InnoDB: Using Linux native AIO 2014-09-21 08:58:49 22096 [Note] InnoDB: Using CPU crc32 instructions 2014-09-21 08:58:49 22096 [Note] InnoDB: Initializing buffer pool, size = 128.0M 2014-09-21 08:58:49 22096 [Note] InnoDB: Completed initialization of buffer pool 2014-09-21 08:58:49 22096 [Note] InnoDB: Highest supported file format is Barracuda. 2014-09-21 08:58:49 22096 [Note] InnoDB: 128 rollback segment(s) are active. 2014-09-21 08:58:49 22096 [Note] InnoDB: Waiting for purge to start 2014-09-21 08:58:49 22096 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.20-68.0 started; log sequence number 1625987 2014-09-21 08:58:49 22096 [Warning] No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: 07d48502-418f-11e4-bb05-86e22078d498. 2014-09-21 08:58:49 22096 [Note] RSA private key file not found: /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var1/data//private_key.pem. Some authentication plugins will not work. 2014-09-21 08:58:49 22096 [Note] RSA public key file not found: /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var1/data//public_key.pem. Some authentication plugins will not work. 2014-09-21 08:58:49 22096 [Note] Server hostname (bind-address): '*'; port: 26687 2014-09-21 08:58:49 22096 [Note] IPv6 is available. 2014-09-21 08:58:49 22096 [Note] - '::' resolves to '::'; 2014-09-21 08:58:49 22096 [Note] Server socket created on IP: '::'. 2014-09-21 08:58:49 22096 [Note] Event Scheduler: Loaded 0 events 2014-09-21 08:58:49 22096 [Note] /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/bin//mysqld: ready for connections. Version: '5.6.20-68.0-25.7' socket: '/tmp/xbtemp.y21894/mysql.sock.p21933' port: 26687 Percona XtraDB Cluster binary (GPL) 5.6.20-25.7, Revision 886, wsrep_25.7.r4126 2014-09-21 08:58:49 22096 [Note] WSREP: inited wsrep sidno 1 2014-09-21 08:58:49 22096 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 2014-09-21 08:58:49 22096 [Note] WSREP: REPL Protocols: 6 (3, 2) 2014-09-21 08:58:49 22096 [Note] WSREP: Service thread queue flushed. 2014-09-21 08:58:49 22096 [Note] WSREP: Assign initial position for certification: 0, protocol version: 3 2014-09-21 08:58:49 22096 [Note] WSREP: Service thread queue flushed. 2014-09-21 08:58:49 22096 [Note] WSREP: Synchronized with group, ready for connections 2014-09-21 08:58:49 22096 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 2014-09-21 08:59:10 22096 [Note] WSREP: (07b8fa9f, 'tcp://127.0.0.1:23713') turning message relay requesting on, nonlive peers: 2014-09-21 08:59:10 22096 [Note] WSREP: declaring 144e68c9 at tcp://127.0.0.1:31049 stable 2014-09-21 08:59:10 22096 [Note] WSREP: Node 07b8fa9f state prim 2014-09-21 08:59:10 22096 [Note] WSREP: save pc into disk 2014-09-21 08:59:10 22096 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 2 2014-09-21 08:59:10 22096 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 149b5c2a-418f-11e4-90f2-ee74d6232eba 2014-09-21 08:59:10 22096 [Note] WSREP: STATE EXCHANGE: sent state msg: 149b5c2a-418f-11e4-90f2-ee74d6232eba 2014-09-21 08:59:10 22096 [Note] WSREP: STATE EXCHANGE: got state msg: 149b5c2a-418f-11e4-90f2-ee74d6232eba from 0 (75fde48ae41e) 2014-09-21 08:59:11 22096 [Note] WSREP: STATE EXCHANGE: got state msg: 149b5c2a-418f-11e4-90f2-ee74d6232eba from 1 (75fde48ae41e) 2014-09-21 08:59:11 22096 [Note] WSREP: Quorum results: version = 3, component = PRIMARY, conf_id = 1, members = 1/2 (joined/total), act_id = 7, last_appl. = 4, protocols = 0/6/3 (gcs/repl/appl), group UUID = 07b9a06f-418f-11e4-b20e-2a254b5cfbc3 2014-09-21 08:59:11 22096 [Note] WSREP: Flow-control interval: [23, 23] 2014-09-21 08:59:11 22096 [Note] WSREP: New cluster view: global state: 07b9a06f-418f-11e4-b20e-2a254b5cfbc3:7, view# 2: Primary, number of nodes: 2, my index: 0, protocol version 3 2014-09-21 08:59:11 22096 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 2014-09-21 08:59:11 22096 [Note] WSREP: REPL Protocols: 6 (3, 2) 2014-09-21 08:59:11 22096 [Note] WSREP: Service thread queue flushed. 2014-09-21 08:59:11 22096 [Note] WSREP: Assign initial position for certification: 7, protocol version: 3 2014-09-21 08:59:11 22096 [Note] WSREP: Service thread queue flushed. 2014-09-21 08:59:11 22096 [Note] WSREP: Member 1.0 (75fde48ae41e) requested state transfer from '*any*'. Selected 0.0 (75fde48ae41e)(SYNCED) as donor. 2014-09-21 08:59:11 22096 [Note] WSREP: Shifting SYNCED -> DONOR/DESYNCED (TO: 7) 2014-09-21 08:59:11 22096 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 2014-09-21 08:59:11 22096 [Note] WSREP: Running: 'wsrep_sst_xtrabackup-v2 --role 'donor' --address '127.0.0.1:23038/xtrabackup_sst' --auth 'root:password' --socket '/tmp/xbtemp.y21894/mysql.sock.p21933' --datadir '/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var1/data/' --defaults-file '/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var1/my.cnf' '' --gtid '07b9a06f-418f-11e4-b20e-2a254b5cfbc3:7'' 2014-09-21 08:59:11 22096 [Note] WSREP: sst_donor_thread signaled with 0 WSREP_SST: [INFO] Streaming with xbstream (20140921 08:59:12.048) WSREP_SST: [INFO] Using socat as streamer (20140921 08:59:12.049) WSREP_SST: [INFO] Using /tmp/xbtemp.y21894/tmp.cMzvh22728 as innobackupex temporary directory (20140921 08:59:12.155) WSREP_SST: [INFO] Streaming GTID file before SST (20140921 08:59:12.159) WSREP_SST: [INFO] Evaluating xbstream -c ${INFO_FILE} | gzip | socat -u stdio TCP:127.0.0.1:23038 ; RC=( ${PIPESTATUS[@]} ) (20140921 08:59:12.161) WSREP_SST: [INFO] Sleeping before data transfer for SST (20140921 08:59:12.163) 2014-09-21 08:59:13 22096 [Note] WSREP: (07b8fa9f, 'tcp://127.0.0.1:23713') turning message relay requesting off WSREP_SST: [INFO] Streaming the backup to joiner at 127.0.0.1 23038 (20140921 08:59:22.166) WSREP_SST: [INFO] Evaluating innobackupex --defaults-file=/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var1/my.cnf --no-version-check $tmpopts $INNOEXTRA --galera-info --stream=$sfmt $itmpdir 2>/home/dbennett/logs/innobackup.backup.14092108591411304352.log | gzip | socat -u stdio TCP:127.0.0.1:23038; RC=( ${PIPESTATUS[@]} ) (20140921 08:59:22.169) 2014-09-21 08:59:24 22096 [Note] WSREP: Provider paused at 07b9a06f-418f-11e4-b20e-2a254b5cfbc3:7 (13) 2014-09-21 08:59:28 22096 [Note] WSREP: resuming provider at 13 2014-09-21 08:59:28 22096 [Note] WSREP: Provider resumed. 2014-09-21 08:59:28 22096 [Note] WSREP: 0.0 (75fde48ae41e): State transfer to 1.0 (75fde48ae41e) complete. 2014-09-21 08:59:28 22096 [Note] WSREP: Shifting DONOR/DESYNCED -> JOINED (TO: 7) 2014-09-21 08:59:28 22096 [Note] WSREP: Member 0.0 (75fde48ae41e) synced with group. 2014-09-21 08:59:28 22096 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 7) 2014-09-21 08:59:28 22096 [Note] WSREP: Synchronized with group, ready for connections 2014-09-21 08:59:28 22096 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. WSREP_SST: [INFO] Total time on donor: 0 seconds (20140921 08:59:28.727) WSREP_SST: [INFO] Cleaning up temporary directories (20140921 08:59:28.730) 2014-09-21 08:59:48 22096 [Note] WSREP: forgetting 144e68c9 (tcp://127.0.0.1:31049) 2014-09-21 08:59:48 22096 [Note] WSREP: Node 07b8fa9f state prim 2014-09-21 08:59:48 22096 [Note] WSREP: save pc into disk 2014-09-21 08:59:48 22096 [Note] WSREP: forgetting 144e68c9 (tcp://127.0.0.1:31049) 2014-09-21 08:59:48 22096 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 1 2014-09-21 08:59:48 22096 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 2ae615bb-418f-11e4-a361-973bf5f01fb2 2014-09-21 08:59:48 22096 [Note] WSREP: STATE EXCHANGE: sent state msg: 2ae615bb-418f-11e4-a361-973bf5f01fb2 2014-09-21 08:59:48 22096 [Note] WSREP: STATE EXCHANGE: got state msg: 2ae615bb-418f-11e4-a361-973bf5f01fb2 from 0 (75fde48ae41e) 2014-09-21 08:59:48 22096 [Note] WSREP: Quorum results: version = 3, component = PRIMARY, conf_id = 2, members = 1/1 (joined/total), act_id = 7, last_appl. = 4, protocols = 0/6/3 (gcs/repl/appl), group UUID = 07b9a06f-418f-11e4-b20e-2a254b5cfbc3 2014-09-21 08:59:48 22096 [Note] WSREP: Flow-control interval: [16, 16] 2014-09-21 08:59:48 22096 [Note] WSREP: New cluster view: global state: 07b9a06f-418f-11e4-b20e-2a254b5cfbc3:7, view# 3: Primary, number of nodes: 1, my index: 0, protocol version 3 2014-09-21 08:59:48 22096 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 2014-09-21 08:59:48 22096 [Note] WSREP: REPL Protocols: 6 (3, 2) 2014-09-21 08:59:48 22096 [Note] WSREP: Service thread queue flushed. 2014-09-21 08:59:48 22096 [Note] WSREP: Assign initial position for certification: 7, protocol version: 3 2014-09-21 08:59:48 22096 [Note] WSREP: Service thread queue flushed. 2014-09-21 08:59:53 22096 [Note] WSREP: cleaning up 144e68c9 (tcp://127.0.0.1:31049) 2014-09-21 08:59:54: run.sh: ---------------- 2014-09-21 08:59:54: run.sh: ---------------- 2014-09-21 08:59:54: run.sh: Error log for server with id: 901 2014-09-21 08:59:10 22282 [Note] WSREP: Read nil XID from storage engines, skipping position init 2014-09-21 08:59:10 22282 [Note] WSREP: wsrep_load(): loading provider library '/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/lib/libgalera_smm.so' 2014-09-21 08:59:10 22282 [Note] WSREP: wsrep_load(): Galera 3.7(r7f44a18) by Codership Oy loaded successfully. 2014-09-21 08:59:10 22282 [Note] WSREP: CRC-32C: using hardware acceleration. 2014-09-21 08:59:10 22282 [Warning] WSREP: Could not open saved state file for reading: /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var901/data//grastate.dat 2014-09-21 08:59:10 22282 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1 2014-09-21 08:59:10 22282 [Note] WSREP: Passing config to GCS: base_host = 127.0.0.1; base_port = 4567; cert.log_conflicts = no; debug = no; evs.inactive_check_period = PT0.5S; evs.inactive_timeout = PT15S; evs.join_retrans_period = PT1S; evs.max_install_timeouts = 3; evs.send_window = 4; evs.stats_report_period = PT1M; evs.suspect_timeout = PT5S; evs.user_send_window = 2; evs.view_forget_timeout = PT24H; gcache.dir = /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var901/data/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var901/data//galera.cache; gcache.page_size = 128M; gcache.size = 128M; gcs.fc_debug = 0; gcs.fc_factor = 1.0; gcs.fc_limit = 16; gcs.fc_master_slave = no; gcs.max_packet_size = 64500; gcs.max_throttle = 0.25; gcs.recv_q_hard_limit = 9223372036854775807; gcs.recv_q_soft_limit = 0.25; gcs.sync_donor = no; gmcast.listen_a 2014-09-21 08:59:10 22282 [Note] WSREP: Service thread queue flushed. 2014-09-21 08:59:10 22282 [Note] WSREP: Assign initial position for certification: -1, protocol version: -1 2014-09-21 08:59:10 22282 [Note] WSREP: wsrep_sst_grab() 2014-09-21 08:59:10 22282 [Note] WSREP: Start replication 2014-09-21 08:59:10 22282 [Note] WSREP: Setting initial position to 00000000-0000-0000-0000-000000000000:-1 2014-09-21 08:59:10 22282 [Note] WSREP: protonet asio version 0 2014-09-21 08:59:10 22282 [Note] WSREP: Using CRC-32C for message checksums. 2014-09-21 08:59:10 22282 [Note] WSREP: backend: asio 2014-09-21 08:59:10 22282 [Warning] WSREP: access file(gvwstate.dat) failed(No such file or directory) 2014-09-21 08:59:10 22282 [Note] WSREP: restore pc from disk failed 2014-09-21 08:59:10 22282 [Note] WSREP: GMCast version 0 2014-09-21 08:59:10 22282 [Note] WSREP: (144e68c9, 'tcp://127.0.0.1:31049') listening at tcp://127.0.0.1:31049 2014-09-21 08:59:10 22282 [Note] WSREP: (144e68c9, 'tcp://127.0.0.1:31049') multicast: , ttl: 1 2014-09-21 08:59:10 22282 [Note] WSREP: EVS version 0 2014-09-21 08:59:10 22282 [Note] WSREP: PC version 0 2014-09-21 08:59:10 22282 [Note] WSREP: gcomm: connecting to group 'my_wsrep_cluster', peer '127.0.0.1:23713' 2014-09-21 08:59:10 22282 [Note] WSREP: (144e68c9, 'tcp://127.0.0.1:31049') turning message relay requesting on, nonlive peers: 2014-09-21 08:59:10 22282 [Note] WSREP: declaring 07b8fa9f at tcp://127.0.0.1:23713 stable 2014-09-21 08:59:10 22282 [Note] WSREP: Node 07b8fa9f state prim 2014-09-21 08:59:10 22282 [Note] WSREP: save pc into disk 2014-09-21 08:59:11 22282 [Note] WSREP: gcomm: connected 2014-09-21 08:59:11 22282 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636 2014-09-21 08:59:11 22282 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0) 2014-09-21 08:59:11 22282 [Note] WSREP: Opened channel 'my_wsrep_cluster' 2014-09-21 08:59:11 22282 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 2 2014-09-21 08:59:11 22282 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID. 2014-09-21 08:59:11 22282 [Note] WSREP: Waiting for SST to complete. 2014-09-21 08:59:11 22282 [Note] WSREP: STATE EXCHANGE: sent state msg: 149b5c2a-418f-11e4-90f2-ee74d6232eba 2014-09-21 08:59:11 22282 [Note] WSREP: STATE EXCHANGE: got state msg: 149b5c2a-418f-11e4-90f2-ee74d6232eba from 0 (75fde48ae41e) 2014-09-21 08:59:11 22282 [Note] WSREP: STATE EXCHANGE: got state msg: 149b5c2a-418f-11e4-90f2-ee74d6232eba from 1 (75fde48ae41e) 2014-09-21 08:59:11 22282 [Note] WSREP: Quorum results: version = 3, component = PRIMARY, conf_id = 1, members = 1/2 (joined/total), act_id = 7, last_appl. = -1, protocols = 0/6/3 (gcs/repl/appl), group UUID = 07b9a06f-418f-11e4-b20e-2a254b5cfbc3 2014-09-21 08:59:11 22282 [Note] WSREP: Flow-control interval: [23, 23] 2014-09-21 08:59:11 22282 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 7) 2014-09-21 08:59:11 22282 [Note] WSREP: State transfer required: Group state: 07b9a06f-418f-11e4-b20e-2a254b5cfbc3:7 Local state: 00000000-0000-0000-0000-000000000000:-1 2014-09-21 08:59:11 22282 [Note] WSREP: New cluster view: global state: 07b9a06f-418f-11e4-b20e-2a254b5cfbc3:7, view# 2: Primary, number of nodes: 2, my index: 1, protocol version 3 2014-09-21 08:59:11 22282 [Warning] WSREP: Gap in state sequence. Need state transfer. 2014-09-21 08:59:11 22282 [Note] WSREP: Running: 'wsrep_sst_xtrabackup-v2 --role 'joiner' --address '127.0.0.1:23038' --auth 'root:password' --datadir '/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var901/data/' --defaults-file '/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var901/my.cnf' --parent '22282' '' ' WSREP_SST: [INFO] Streaming with xbstream (20140921 08:59:11.606) WSREP_SST: [INFO] Using socat as streamer (20140921 08:59:11.607) which: no timeout in (/usr/sbin:/sbin:/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64//bin:/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/bin:/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/../bin:/home/dbennett/work/1/percona-xtrabackup-2.2.4-Linux-x86_64/bin:/home/dbennett/work/1:/usr/kerberos/bin:/usr/local/bin:/bin:/usr/bin:/home/dbennett/bin) WSREP_SST: [INFO] Evaluating socat -u TCP-LISTEN:23038,reuseaddr stdio | gzip -dc | xbstream -x; RC=( ${PIPESTATUS[@]} ) (20140921 08:59:11.733) 2014-09-21 08:59:11 22282 [Note] WSREP: Prepared SST request: xtrabackup-v2|127.0.0.1:23038/xtrabackup_sst 2014-09-21 08:59:11 22282 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 2014-09-21 08:59:11 22282 [Note] WSREP: REPL Protocols: 6 (3, 2) 2014-09-21 08:59:11 22282 [Note] WSREP: Service thread queue flushed. 2014-09-21 08:59:11 22282 [Note] WSREP: Assign initial position for certification: 7, protocol version: 3 2014-09-21 08:59:11 22282 [Note] WSREP: Service thread queue flushed. 2014-09-21 08:59:11 22282 [Warning] WSREP: Failed to prepare for incremental state transfer: Local state UUID (00000000-0000-0000-0000-000000000000) does not match group state UUID (07b9a06f-418f-11e4-b20e-2a254b5cfbc3): 1 (Operation not permitted) at galera/src/replicator_str.cpp:prepare_for_IST():455. IST will be unavailable. 2014-09-21 08:59:11 22282 [Note] WSREP: Member 1.0 (75fde48ae41e) requested state transfer from '*any*'. Selected 0.0 (75fde48ae41e)(SYNCED) as donor. 2014-09-21 08:59:11 22282 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 7) 2014-09-21 08:59:11 22282 [Note] WSREP: Requesting state transfer: success, donor: 0 WSREP_SST: [INFO] Proceeding with SST (20140921 08:59:12.250) WSREP_SST: [INFO] Cleaning the existing datadir (20140921 08:59:12.252) removed `/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var901/data/gvwstate.dat' WSREP_SST: [INFO] Evaluating socat -u TCP-LISTEN:23038,reuseaddr stdio | gzip -dc | xbstream -x; RC=( ${PIPESTATUS[@]} ) (20140921 08:59:12.263) 2014-09-21 08:59:13 22282 [Note] WSREP: (144e68c9, 'tcp://127.0.0.1:31049') turning message relay requesting off 2014-09-21 08:59:28 22282 [Note] WSREP: 0.0 (75fde48ae41e): State transfer to 1.0 (75fde48ae41e) complete. 2014-09-21 08:59:28 22282 [Note] WSREP: Member 0.0 (75fde48ae41e) synced with group. WSREP_SST: [INFO] Index compaction detected (20140921 08:59:41.253) WSREP_SST: [INFO] Rebuilding during prepare with 4 threads (20140921 08:59:41.261) WSREP_SST: [INFO] Compressed qpress files found (20140921 08:59:41.266) WSREP_SST: [INFO] Decompression with 12 threads (20140921 08:59:41.269) WSREP_SST: [INFO] Evaluating find /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var901/data/ -type f -name '*.qp' -printf '%p\n%h\n' | xargs -n 2 qpress -T12d (20140921 08:59:41.272) WSREP_SST: [INFO] Removing qpress files after decompression (20140921 08:59:41.315) WSREP_SST: [INFO] Preparing the backup at /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var901/data/ (20140921 08:59:41.318) WSREP_SST: [INFO] Evaluating innobackupex --no-version-check --apply-log $rebuildcmd ${DATA} &>/home/dbennett/logs/innobackup.prepare.14092108591411304351.log (20140921 08:59:41.320) WSREP_SST: [ERROR] Cleanup after exit with status:1 (20140921 08:59:45.373) WSREP_SST: [INFO] Removing the sst_in_progress file (20140921 08:59:45.375) 2014-09-21 08:59:45 22282 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role 'joiner' --address '127.0.0.1:23038' --auth 'root:password' --datadir '/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var901/data/' --defaults-file '/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var901/my.cnf' --parent '22282' '' : 1 (Operation not permitted) 2014-09-21 08:59:45 22282 [ERROR] WSREP: Failed to read uuid:seqno from joiner script. 2014-09-21 08:59:45 22282 [ERROR] WSREP: SST failed: 1 (Operation not permitted) 2014-09-21 08:59:45 22282 [ERROR] Aborting 2014-09-21 08:59:47 22282 [Note] WSREP: Closing send monitor... 2014-09-21 08:59:47 22282 [Note] WSREP: Closed send monitor. 2014-09-21 08:59:47 22282 [Note] WSREP: gcomm: terminating thread 2014-09-21 08:59:47 22282 [Note] WSREP: gcomm: joining thread 2014-09-21 08:59:47 22282 [Note] WSREP: gcomm: closing backend 2014-09-21 08:59:48 22282 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1 2014-09-21 08:59:48 22282 [Note] WSREP: gcomm: closed 2014-09-21 08:59:48 22282 [Note] WSREP: Flow-control interval: [16, 16] 2014-09-21 08:59:48 22282 [Note] WSREP: Received NON-PRIMARY. 2014-09-21 08:59:48 22282 [Note] WSREP: Shifting JOINER -> OPEN (TO: 7) 2014-09-21 08:59:48 22282 [Note] WSREP: Received self-leave message. 2014-09-21 08:59:48 22282 [Note] WSREP: Flow-control interval: [0, 0] 2014-09-21 08:59:48 22282 [Note] WSREP: Received SELF-LEAVE. Closing connection. 2014-09-21 08:59:48 22282 [Note] WSREP: Shifting OPEN -> CLOSED (TO: 7) 2014-09-21 08:59:48 22282 [Note] WSREP: RECV thread exiting 0: Success 2014-09-21 08:59:48 22282 [Note] WSREP: recv_thread() joined. 2014-09-21 08:59:48 22282 [Note] WSREP: Closing replication queue. 2014-09-21 08:59:48 22282 [Note] WSREP: Closing slave action queue. 2014-09-21 08:59:48 22282 [Note] WSREP: Service disconnected. 2014-09-21 08:59:48 22282 [Note] WSREP: rollbacker thread exiting 2014-09-21 08:59:49 22282 [Note] WSREP: Some threads may fail to exit. 2014-09-21 08:59:49 22282 [Note] Binlog end 2014-09-21 08:59:49 22282 [Note] /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/bin//mysqld: Shutdown complete Error in my_thread_global_end(): 1 threads didn't exit 2014-09-21 08:59:54: run.sh: ---------------- 2014-09-21 08:59:54: run.sh: ---------------- 2014-09-21 08:59:54: run.sh: Innobackupex log for server with id: 1 cat: /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var1/data/innobackup*.log: No such file or directory 2014-09-21 08:59:54: run.sh: ---------------- 2014-09-21 08:59:54: run.sh: ---------------- 2014-09-21 08:59:54: run.sh: Innobackupex log for server with id: 901 cat: /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var901/data/innobackup*.log: No such file or directory 2014-09-21 08:59:54: run.sh: ---------------- 2014-09-21 08:59:54: run.sh: ---------------- 2014-09-21 08:59:54: run.sh: Configuration for server with id: 1 [mysqld] socket=/tmp/xbtemp.y21894/mysql.sock.p21933 port=26687 server-id=1 basedir=/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64 datadir=/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var1/data tmpdir=/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var1/tmp log-error=/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var1/data/mysqld1.err pid-file=/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/mysqld1.pid !include /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/conf/conf2.cnf-node1 [client] socket=/tmp/xbtemp.y21894/mysql.sock.p21933 user=root 2014-09-21 08:59:54: run.sh: ---------------- 2014-09-21 08:59:54: run.sh: ---------------- 2014-09-21 08:59:54: run.sh: Configuration for server with id: 901 [mysqld] socket=/tmp/xbtemp.y21894/mysql.sock.B22259 port=5492 server-id=901 basedir=/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64 datadir=/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var901/data tmpdir=/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var901/tmp log-error=/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/var901/data/mysqld901.err pid-file=/home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/var/w1/mysqld901.pid !include /home/dbennett/work/1/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/percona-xtradb-cluster-tests/conf/conf2.cnf-node2 [client] socket=/tmp/xbtemp.y21894/mysql.sock.B22259 user=root 2014-09-21 08:59:54: run.sh: ----------------