Not the answer you need?
Register and ask your own question!

Cluster does not start

jsobrierjsobrier EntrantInactive User Role Beginner
I have Percona-XtraDB-Cluster-server 5.6.21 installed on 3 nodes. The cluster used to work on 2 nodes, but I cannot bring it back up.

I have bootstrapped the cluster on node1. But node2 fails:

WSREP_SST: [INFO] Evaluating socat -u TCP-LISTEN:4444,reuseaddr stdio | xbstream -x; RC=( ${PIPESTATUS[@]} ) (20150209 02:15:30.956)
grep: /var/lib/mysql//xtrabackup_checkpoints: No such file or directory
WSREP_SST: [INFO] Preparing the backup at /var/lib/mysql/ (20150209 02:15:41.121)
WSREP_SST: [INFO] Evaluating innobackupex --no-version-check --apply-log $rebuildcmd ${DATA} &>${DATA}/innobackup.prepare.log (20150209 02:15:41.122)
2015-02-09 02:15:41 2672050 [Warning] WSREP: 1.0 (node1.com): State transfer to 0.0 (node2.com) failed: -22 (Invalid argument)
2015-02-09 02:15:41 2672050 [ERROR] WSREP: gcs/src/gcs_group.cpp:int gcs_group_handle_join_msg(gcs_group_t*, const gcs_recv_msg_t*)():722: Will never receive state. Need to abort.
2015-02-09 02:15:41 2672050 [Note] WSREP: gcomm: terminating thread
2015-02-09 02:15:41 2672050 [Note] WSREP: gcomm: joining thread
2015-02-09 02:15:41 2672050 [Note] WSREP: gcomm: closing backend
WSREP_SST: [ERROR] Cleanup after exit with status:1 (20150209 02:15:41.489)
2015-02-09 02:15:41 2672050 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role 'joiner' --address 'node2.com' --auth user:pass' --datadir '/var/lib/mysql/' --defaults-file '/etc/my.cnf' --parent '2672050' '' : 1 (Operation not permitted)
2015-02-09 02:15:41 2672050 [ERROR] WSREP: Failed to read uuid:seqno from joiner script.
2015-02-09 02:15:41 2672050 [ERROR] WSREP: SST failed: 1 (Operation not permitted)
2015-02-09 02:15:41 2672050 [ERROR] Aborting

I don't know how to debug this issue. Any idea?

Comments

  • werebear73werebear73 Entrant Inactive User Role Beginner
    I am having a similar issue with 5.6.21-70 on CentOS 7

    NODE 1 - mysql-error.log
    WSREP_SST: [ERROR] innobackupex finished with error: 1.  Check /var/lib/mysql//innobackup.backup.log (20150219 18:01:58.157)
    WSREP_SST: [ERROR] Cleanup after exit with status:22 (20150219 18:01:58.158)
    WSREP_SST: [INFO] Cleaning up temporary directories (20150219 18:01:58.161)
    2015-02-19 18:01:58 10231 [ERROR] WSREP: Failed to read from: wsrep_sst_xtrabackup-v2 --role 'donor' --address '192.168.88.181:4444/xtrabackup_sst//1' --auth 'sstuser:xxxxx' --socket '/var/lib/mysql/mysql.sock' --datadir '/var/lib/mysql/' --defaults-file '/etc/my.cnf'   '' --gtid '7cac0fcf-b83b-11e4-a754-ba12038dc0d4:2'
    2015-02-19 18:01:58 10231 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role 'donor' --address '192.168.88.181:4444/xtrabackup_sst//1' --auth 'sstuser:xxxxx' --socket '/var/lib/mysql/mysql.sock' --datadir '/var/lib/mysql/' --defaults-file '/etc/my.cnf'   '' --gtid '7cac0fcf-b83b-11e4-a754-ba12038dc0d4:2': 22 (Invalid argument)
    2015-02-19 18:01:58 10231 [ERROR] WSREP: Command did not run: wsrep_sst_xtrabackup-v2 --role 'donor' --address '192.168.88.181:4444/xtrabackup_sst//1' --auth 'sstuser:xxxxx' --socket '/var/lib/mysql/mysql.sock' --datadir '/var/lib/mysql/' --defaults-file '/etc/my.cnf'   '' --gtid '7cac0fcf-b83b-11e4-a754-ba12038dc0d4:2'
    

    NODE 1 - innobackup.backup.log
    150219 18:01:58  innobackupex: Connecting to MySQL server with DSN 'dbi:mysql:;mysql_read_default_file=/etc/my.cnf;mysql_read_default_group=xtrabackup;mysql_socket=/var/lib/mysql/mysql.sock' as 'sstuser'  (using password: YES).
    innobackupex: got a fatal error with the following stacktrace: at /usr//bin/innobackupex line 3004.
            main::mysql_connect('abort_on_error', 1) called at /usr//bin/innobackupex line 1539
    innobackupex: Error: Failed to connect to MySQL server: DBI connect(';mysql_read_default_file=/etc/my.cnf;mysql_read_default_group=xtrabackup;mysql_socket=/var/lib/mysql/mysql.sock','sstuser',...) failed: Access denied for user 'sstuser'@'localhost' (using password: YES) at /usr//bin/innobackupex line 2988.
    

    NODE 2 - mysql-error.log
    WSREP_SST: [INFO] Cleaning the binlog directory /var/lib/mysql as well (20150219 18:01:48.073)
    rm: cannot remove ‘/var/lib/mysql/*.index’: No such file or directory
    WSREP_SST: [INFO] Evaluating socat -u TCP-LISTEN:4444,reuseaddr stdio | xbstream -x; RC=( ${PIPESTATUS[@]} ) (20150219 18:01:48.079)
    2015-02-19 18:01:49 11547 [Note] WSREP: (5e5687d2, 'tcp://0.0.0.0:4567') turning message relay requesting off
    grep: /var/lib/mysql//xtrabackup_checkpoints: No such file or directory
    WSREP_SST: [INFO] Preparing the backup at /var/lib/mysql/ (20150219 18:01:58.162)
    2015-02-19 18:01:58 11547 [Warning] WSREP: 1.0 (Node1): State transfer to 0.0 (Node2) failed: -22 (Invalid argument)
    2015-02-19 18:01:58 11547 [ERROR] WSREP: gcs/src/gcs_group.cpp:int gcs_group_handle_join_msg(gcs_group_t*, const gcs_recv_msg_t*)():722: Will never receive state. Need to abort.
    2015-02-19 18:01:58 11547 [Note] WSREP: gcomm: terminating thread
    2015-02-19 18:01:58 11547 [Note] WSREP: gcomm: joining thread
    2015-02-19 18:01:58 11547 [Note] WSREP: gcomm: closing backend
    WSREP_SST: [INFO] Evaluating innobackupex --no-version-check  --apply-log $rebuildcmd ${DATA} &>${DATA}/innobackup.prepare.log (20150219 18:01:58.165)
    WSREP_SST: [ERROR] Cleanup after exit with status:1 (20150219 18:01:58.344)
    2015-02-19 18:01:58 11547 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role 'joiner' --address '192.168.88.181' --auth 'sstuser:xxxxx' --datadir '/var/lib/mysql/' --defaults-file '/etc/my.cnf' --parent '11547'  '' : 1 (Operation not permitted)
    2015-02-19 18:01:58 11547 [ERROR] WSREP: Failed to read uuid:seqno from joiner script.
    2015-02-19 18:01:58 11547 [ERROR] WSREP: SST failed: 1 (Operation not permitted)
    2015-02-19 18:01:58 11547 [ERROR] Aborting
    
  • mirfanmirfan Database Administrator Inactive User Role Beginner
    As you can see it errors "Access denied for user 'sstuser'@'localhost'"
    Is "sstuser" created ? Can you please share my.cnf on failed node. You may found this useful http://www.percona.com/doc/percona-xtradb-cluster/5.5/howtos/cenots_howto.html
  • Keyur MakwanaKeyur Makwana Entrant Current User Role Beginner
    Hi,

    I am facing similar error as posted by jsobrier in intial post.

    * I am using below version of Percona XtraDB Cluster
    # rpm -qa | grep -i percona
    percona-xtrabackup-2.2.9-5067.el6.x86_64
    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
    Percona-Server-shared-51-5.1.73-rel14.12.624.rhel6.x86_64
    Percona-XtraDB-Cluster-shared-56-5.6.22-25.8.978.el6.x86_64
    Percona-XtraDB-Cluster-client-56-5.6.22-25.8.978.el6.x86_64
    Percona-XtraDB-Cluster-56-5.6.22-25.8.978.el6.x86_64
    percona-release-0.1-3.noarch

    * sstuser has proper grants
    mysql> show grants for [email protected];
    +
    +
    | Grants for [email protected] |
    +
    +
    | GRANT RELOAD, LOCK TABLES, REPLICATION CLIENT ON *.* TO 'sstuser'@'localhost' IDENTIFIED BY PASSWORD '*BD7D7##########27D4E3DD' |
    +
    +
    1 row in set (0.00 sec)

    mysql>


    * Below is the error seen on 2nd node which I am trying to join with first donor node.

    2015-03-27 21:03:35 19495 [Note] WSREP: 0.0 (t_jd_pxc1): State transfer to 1.0 (t_jd_pxc2) complete.
    2015-03-27 21:03:35 19495 [Note] WSREP: Member 0.0 (t_jd_pxc1) synced with group.
    WSREP_SST: [INFO] Preparing the backup at /var/lib/SAN/SQL/mysql//.sst (20150327 21:03:35.790)
    WSREP_SST: [INFO] Evaluating innobackupex --no-version-check --apply-log $rebuildcmd ${DATA} &>${DATA}/innobackup.prepare.log (20150327 21:03:35.793)
    WSREP_SST: [ERROR] Cleanup after exit with status:1 (20150327 21:03:49.314)
    2015-03-27 21:03:49 19495 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role 'joiner' --address '192.168.1.14' --auth 'sstuser:somepassword' --datadir '/var/lib/SAN/SQL/mysql/' --defaults-file '/etc/my.cnf' --parent '19495' '' : 1 (Operation not permitted)
    2015-03-27 21:03:49 19495 [ERROR] WSREP: Failed to read uuid:seqno from joiner script.
    2015-03-27 21:03:49 19495 [ERROR] WSREP: SST failed: 1 (Operation not permitted)
    2015-03-27 21:03:49 19495 [ERROR] Aborting

    2015-03-27 21:03:51 19495 [Note] WSREP: Closing send monitor...
    2015-03-27 21:03:51 19495 [Note] WSREP: Closed send monitor.
    2015-03-27 21:03:51 19495 [Note] WSREP: gcomm: terminating thread
    2015-03-27 21:03:51 19495 [Note] WSREP: gcomm: joining thread
    2015-03-27 21:03:51 19495 [Note] WSREP: gcomm: closing backend
    2015-03-27 21:03:52 19495 [Note] WSREP: view(view_id(NON_PRIM,77a9e035,6) memb {
    a5793a87,0
    } joined {
    } left {
    } partitioned {
    77a9e035,0
    })
    2015-03-27 21:03:52 19495 [Note] WSREP: view((empty))
    2015-03-27 21:03:52 19495 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1
    2015-03-27 21:03:52 19495 [Note] WSREP: gcomm: closed
    2015-03-27 21:03:52 19495 [Note] WSREP: Flow-control interval: [16, 16]
    2015-03-27 21:03:52 19495 [Note] WSREP: Received NON-PRIMARY.
    2015-03-27 21:03:52 19495 [Note] WSREP: Shifting JOINER -> OPEN (TO: 488602)
    2015-03-27 21:03:52 19495 [Note] WSREP: Received self-leave message.
    2015-03-27 21:03:52 19495 [Note] WSREP: Flow-control interval: [0, 0]
    2015-03-27 21:03:52 19495 [Note] WSREP: Received SELF-LEAVE. Closing connection.
    2015-03-27 21:03:52 19495 [Note] WSREP: Shifting OPEN -> CLOSED (TO: 488602)
    2015-03-27 21:03:52 19495 [Note] WSREP: RECV thread exiting 0: Success
    2015-03-27 21:03:52 19495 [Note] WSREP: recv_thread() joined.
    2015-03-27 21:03:52 19495 [Note] WSREP: Closing replication queue.
    2015-03-27 21:03:52 19495 [Note] WSREP: Closing slave action queue.
    2015-03-27 21:03:52 19495 [Note] WSREP: Service disconnected.
    2015-03-27 21:03:52 19495 [Note] WSREP: rollbacker thread exiting
    2015-03-27 21:03:53 19495 [Note] WSREP: Some threads may fail to exit.
    2015-03-27 21:03:53 19495 [Note] Binlog end
    2015-03-27 21:03:53 19495 [Note] /usr/sbin/mysqld: Shutdown complete

    Error in my_thread_global_end(): 1 threads didn't exit
    150327 21:03:58 mysqld_safe mysqld from pid file /var/lib/SAN/SQL/mysql/hostname.pid ended

    * Log files on DONOR server shows

    ** innobackup.backup.log
    >> log scanned up to (585254827608)
    >> log scanned up to (585254827608)
    innobackupex: Backing up files '/var/lib/SAN/SQL/mysql//performance_schema/*.{frm,isl,MYD,MYI,MAD,MAI,MRG,TRG,TRN,ARM,ARZ,CSM,CSV,opt,par}' (53 files)
    innobackupex: Backing up file '/var/lib/SAN/SQL/mysql//perconatest/employees.frm'
    innobackupex: Backing up file '/var/lib/SAN/SQL/mysql//perconatest/employees1.frm'
    innobackupex: Backing up file '/var/lib/SAN/SQL/mysql//perconatest/db.opt'
    innobackupex: Backing up file '/var/lib/SAN/SQL/mysql//perconatest/employees.MYD'
    innobackupex: Backing up file '/var/lib/SAN/SQL/mysql//perconatest/employees.MYI'
    innobackupex: Backing up file '/var/lib/SAN/SQL/mysql//percona/checksums.frm'
    innobackupex: Backing up file '/var/lib/SAN/SQL/mysql//percona/db.opt'
    150327 21:03:34 innobackupex: Finished backing up non-InnoDB tables and files

    150327 21:03:34 innobackupex: Executing LOCK BINLOG FOR BACKUP...
    150327 21:03:34 innobackupex: Executing FLUSH NO_WRITE_TO_BINLOG ENGINE LOGS...
    150327 21:03:34 innobackupex: Waiting for log copying to finish

    >> log scanned up to (585254827608)
    xtrabackup: The latest check point (for incremental): '585254827608'
    xtrabackup: Stopping log copying thread.
    .>> log scanned up to (585254827608)

    xtrabackup: Creating suspend file '/tmp/tmp.V2pOoaughI/xtrabackup_log_copied' with pid '4364'
    xtrabackup: Transaction log of lsn (585188196236) to (585254827608) was copied.
    150327 21:03:35 innobackupex: Executing UNLOCK BINLOG
    150327 21:03:35 innobackupex: Executing UNLOCK TABLES
    150327 21:03:35 innobackupex: All tables unlocked

    innobackupex: Backup created in directory '/tmp/tmp.H3UsCgCUbj'
    innobackupex: MySQL binlog position: filename 'mysql-bin.000789', position 297004215
    150327 21:03:35 innobackupex: Connection to database server closed
    150327 21:03:35 innobackupex: completed OK!


    ** mysqld.log
    2015-03-27 21:03:35 20563 [Note] WSREP: 0.0 (t_jd_pxc1): State transfer to 1.0 (t_jd_pxc2) complete.
    2015-03-27 21:03:35 20563 [Note] WSREP: Shifting DONOR/DESYNCED -> JOINED (TO: 486111)
    2015-03-27 21:03:35 20563 [Note] WSREP: Member 0.0 (t_jd_pxc1) synced with group.
    2015-03-27 21:03:35 20563 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 486111)
    2015-03-27 21:03:35 20563 [Note] WSREP: Synchronized with group, ready for connections
    2015-03-27 21:03:35 20563 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
    WSREP_SST: [INFO] Total time on donor: 0 seconds (20150327 21:03:35.785)
    WSREP_SST: [INFO] Cleaning up temporary directories (20150327 21:03:35.789)
    2015-03-27 21:03:52 20563 [Note] WSREP: forgetting a5793a87 (tcp://192.168.1.14:4567)
    2015-03-27 21:03:52 20563 [Note] WSREP: Node 77a9e035 state prim
    2015-03-27 21:03:52 20563 [Note] WSREP: view(view_id(PRIM,77a9e035,7) memb {
    77a9e035,0
    } joined {
    } left {
    } partitioned {
    a5793a87,0
    })
    2015-03-27 21:03:52 20563 [Note] WSREP: save pc into disk
    2015-03-27 21:03:52 20563 [Note] WSREP: forgetting a5793a87 (tcp://192.168.1.14:4567)
    2015-03-27 21:03:52 20563 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 1
    2015-03-27 21:03:52 20563 [Note] WSREP: STATE_EXCHANGE: sent state UUID: abfa7343-d496-11e4-b392-e7d84f9dbee8
    2015-03-27 21:03:52 20563 [Note] WSREP: STATE EXCHANGE: sent state msg: abfa7343-d496-11e4-b392-e7d84f9dbee8
    2015-03-27 21:03:52 20563 [Note] WSREP: STATE EXCHANGE: got state msg: abfa7343-d496-11e4-b392-e7d84f9dbee8 from 0 (t_jd_pxc1)
    2015-03-27 21:03:52 20563 [Note] WSREP: Quorum results:
    version = 3,
    component = PRIMARY,
    conf_id = 6,
    members = 1/1 (joined/total),
    act_id = 488602,
    last_appl. = 488493,
    protocols = 0/7/3 (gcs/repl/appl),
    group UUID = 77aa765d-d46d-11e4-87da-876501f74653
    2015-03-27 21:03:52 20563 [Note] WSREP: Flow-control interval: [16, 16]
    2015-03-27 21:03:52 20563 [Note] WSREP: New cluster view: global state: 77aa765d-d46d-11e4-87da-876501f74653:488602, view# 7: Primary, number of nodes: 1, my index: 0, protocol version 3
    2015-03-27 21:03:52 20563 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
    2015-03-27 21:03:52 20563 [Note] WSREP: REPL Protocols: 7 (3, 2)
    2015-03-27 21:03:52 20563 [Note] WSREP: Service thread queue flushed.
    2015-03-27 21:03:52 20563 [Note] WSREP: Assign initial position for certification: 488602, protocol version: 3
    2015-03-27 21:03:52 20563 [Note] WSREP: Service thread queue flushed.
    2015-03-27 21:03:57 20563 [Note] WSREP: cleaning up a5793a87 (tcp://192.168.1.14:4567)


    What could be the issue here ?
Sign In or Register to comment.

MySQL, InnoDB, MariaDB and MongoDB are trademarks of their respective owners.
Copyright ©2005 - 2020 Percona LLC. All rights reserved.