How to recover MariaDB Galera Cluster after full crash?

Question

I crashed all my 3 nodes. After all nodes have been started I noticed that mariadb is dead. An I couldn't run it again.

I am using CentOS 7 on all servers

I tried to start first node and then others but without success.

First of all I tried to find the newest seqno as documentation says. So I looked in this file on all 3 nodes: /var/lib/mysql/grastate.dat and noticed that content is identical on all 3 nodes (uuid is the same and seqno is the same)! Here is this file:

# GALERA saved state
version: 2.1
uuid:    ec3e180d-bbff-11e6-b989-3273ac13ba57
seqno:   -1
cert_index:

Ok. As all nodes are identical I can run any node as a new one and add another nodes to it. I used next command:

galera_new_cluster 

And it didn't work. Node didn't start.

Here is what I got:

-- Unit mariadb.service has begun starting up.
Dec 07 18:20:55 GlusterDC1_1 sh[4298]: 2016-12-07 18:20:55 139806456780992 [Note] /usr/sbin/mysqld (mysqld 10.1.19-MariaDB) starting as process 4332 ...
Dec 07 18:20:58 GlusterDC1_1 sh[4298]: WSREP: Recovered position ec3e180d-bbff-11e6-b989-3273ac13ba57:83
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [Note] /usr/sbin/mysqld (mysqld 10.1.19-MariaDB) starting as process 4364 ...
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [Note] WSREP: Read nil XID from storage engines, skipping position init
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib64/galera/libgalera_smm.so'
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [Note] WSREP: wsrep_load(): Galera 25.3.18(r3632) by Codership Oy <info@codership.com> loaded successfully.
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [Note] WSREP: CRC-32C: using hardware acceleration.
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [Note] WSREP: Found saved state: ec3e180d-bbff-11e6-b989-3273ac13ba57:-1
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [Note] WSREP: Passing config to GCS: base_dir = /var/lib/mysql/; base_host = 192.168.0.120; base_port = 4567; cert.log_conflicts = no; debug = no; evs.auto_evict = 0; evs.delay_margin = PT1S; evs.delayed_keep_period = PT30S; 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 = /var/lib/mysql/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = /var/lib/mysql//galera.cache; gcache.page_size = 128M; gcache.size = 128M; gcomm.thread_prio = ; 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.segment = 0; gmcast.version = 0; pc.announce_timeout = PT3S; pc.checksum = false; pc.ignore_quorum = false
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830658434816 [Note] WSREP: Service thread queue flushed.
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [Note] WSREP: Assign initial position for certification: 83, protocol version: -1
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [Note] WSREP: wsrep_sst_grab()
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [Note] WSREP: Start replication
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [Note] WSREP: 'wsrep-new-cluster' option used, bootstrapping the cluster
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [Note] WSREP: Setting initial position to ec3e180d-bbff-11e6-b989-3273ac13ba57:83
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [Note] WSREP: protonet asio version 0
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [Note] WSREP: Using CRC-32C for message checksums.
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [Note] WSREP: backend: asio
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [Note] WSREP: gcomm thread scheduling priority set to other:0
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [Warning] WSREP: access file(/var/lib/mysql//gvwstate.dat) failed(No such file or directory)
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [Note] WSREP: restore pc from disk failed
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [Note] WSREP: GMCast version 0
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [Note] WSREP: (23356fd8, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [Note] WSREP: (23356fd8, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [Note] WSREP: EVS version 0
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [Note] WSREP: gcomm: bootstrapping new group 'my_cluster'
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [Note] WSREP: start_prim is enabled, turn off pc_recovery
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [ERROR] WSREP: Address already in use
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [ERROR] WSREP: failed to open gcomm backend connection: 98: error while trying to listen 'tcp://0.0.0.0:4567?socket.non_blocking=1', asio error 'Address already in use': 98 (Address already in use)
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: at gcomm/src/asio_tcp.cpp:listen():810
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [ERROR] WSREP: gcs/src/gcs_core.cpp:gcs_core_open():208: Failed to open backend connection: -98 (Address already in use)
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [ERROR] WSREP: gcs/src/gcs.cpp:gcs_open():1380: Failed to open channel 'my_cluster' at 'gcomm://192.168.0.120,192.168.0.121,192.168.0.122': -98 (Address already in use)
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [ERROR] WSREP: gcs connect failed: Address already in use
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [ERROR] WSREP: wsrep::connect(gcomm://192.168.0.120,192.168.0.121,192.168.0.122) failed: 7
Dec 07 18:20:58 GlusterDC1_1 mysqld[4364]: 2016-12-07 18:20:58 139830894778560 [ERROR] Aborting
Dec 07 18:20:59 GlusterDC1_1 systemd[1]: mariadb.service: main process exited, code=exited, status=1/FAILURE
Dec 07 18:20:59 GlusterDC1_1 systemd[1]: Failed to start MariaDB database server.
-- Subject: Unit mariadb.service has failed

Ok, I tried to run node manually. With next command:

systemctl start mariadb

And I got:

-- Unit mariadb.service has begun starting up.
Dec 07 18:31:55 GlusterDC1_1 sh[4505]: 2016-12-07 18:31:55 139834720598208 [Note] /usr/sbin/mysqld (mysqld 10.1.19-MariaDB) starting as process 4539 ...
Dec 07 18:31:58 GlusterDC1_1 sh[4505]: WSREP: Recovered position ec3e180d-bbff-11e6-b989-3273ac13ba57:83
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [Note] /usr/sbin/mysqld (mysqld 10.1.19-MariaDB) starting as process 4571 ...
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [Note] WSREP: Read nil XID from storage engines, skipping position init
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib64/galera/libgalera_smm.so'
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [Note] WSREP: wsrep_load(): Galera 25.3.18(r3632) by Codership Oy <info@codership.com> loaded successfully.
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [Note] WSREP: CRC-32C: using hardware acceleration.
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [Note] WSREP: Found saved state: ec3e180d-bbff-11e6-b989-3273ac13ba57:-1
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [Note] WSREP: Passing config to GCS: base_dir = /var/lib/mysql/; base_host = 192.168.0.120; base_port = 4567; cert.log_conflicts = no; debug = no; evs.auto_evict = 0; evs.delay_margin = PT1S; evs.delayed_keep_period = PT30S; 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 = /var/lib/mysql/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = /var/lib/mysql//galera.cache; gcache.page_size = 128M; gcache.size = 128M; gcomm.thread_prio = ; 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.segment = 0; gmcast.version = 0; pc.announce_timeout = PT3S; pc.checksum = false; pc.ignore_quorum = false
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525285508864 [Note] WSREP: Service thread queue flushed.
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [Note] WSREP: Assign initial position for certification: 83, protocol version: -1
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [Note] WSREP: wsrep_sst_grab()
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [Note] WSREP: Start replication
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [Note] WSREP: Setting initial position to ec3e180d-bbff-11e6-b989-3273ac13ba57:83
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [Note] WSREP: protonet asio version 0
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [Note] WSREP: Using CRC-32C for message checksums.
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [Note] WSREP: backend: asio
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [Note] WSREP: gcomm thread scheduling priority set to other:0
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [Warning] WSREP: access file(/var/lib/mysql//gvwstate.dat) failed(No such file or directory)
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [Note] WSREP: restore pc from disk failed
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [Note] WSREP: GMCast version 0
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [Note] WSREP: (acad4591, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [Note] WSREP: (acad4591, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [Note] WSREP: EVS version 0
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [Note] WSREP: gcomm: connecting to group 'my_cluster', peer '192.168.0.120:,192.168.0.121:,192.168.0.122:'
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [ERROR] WSREP: Address already in use
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [ERROR] WSREP: failed to open gcomm backend connection: 98: error while trying to listen 'tcp://0.0.0.0:4567?socket.non_blocking=1', asio error 'Address already in use': 98 (Address already in use)
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: at gcomm/src/asio_tcp.cpp:listen():810
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [ERROR] WSREP: gcs/src/gcs_core.cpp:gcs_core_open():208: Failed to open backend connection: -98 (Address already in use)
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [ERROR] WSREP: gcs/src/gcs.cpp:gcs_open():1380: Failed to open channel 'my_cluster' at 'gcomm://192.168.0.120,192.168.0.121,192.168.0.122': -98 (Address already in use)
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [ERROR] WSREP: gcs connect failed: Address already in use
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [ERROR] WSREP: wsrep::connect(gcomm://192.168.0.120,192.168.0.121,192.168.0.122) failed: 7
Dec 07 18:31:58 GlusterDC1_1 mysqld[4571]: 2016-12-07 18:31:58 140525521279168 [ERROR] Aborting
Dec 07 18:31:59 GlusterDC1_1 systemd[1]: mariadb.service: main process exited, code=exited, status=1/FAILURE
Dec 07 18:31:59 GlusterDC1_1 systemd[1]: Failed to start MariaDB database server.
-- Subject: Unit mariadb.service has failed

I tired both commands on other nodes and got the same error.

Also I tried to run next commands but without success too:

/etc/init.d/mysql start --wsrep-new-cluster

service mysql start --wsrep_cluster_address="gcomm://192.168.0.120,192.168.0.121,192.168.0.122" \
--wsrep_cluster_name="my_cluster"

Is it possible to recover a cluster in such situation?

Answer 1

Pre-Recovery Settings:

1. Ensure that the MYSQL_HOME path is being exported in the .profile. If the MySQL install is in a different location, then make that change to the MYSQL_HOME.(Example: MYSQL_HOME=/path/to/mysql)

Crash Recovery Steps:

1. Find a valid seqno. Look at the grastate.dat file on each server to see which machine has the most current data. The node with the biggest seqno is the node with the current data.

2. Next, look at three grastate.dat files.

a) Node0: This grastate.dat shows a graceful shutdown. Note the seqno. We are looking for the node with the largest seqno.

/var/lib/mysql/grastate.dat
version: 2.1
uuid: cbd332a9-f617-11e2-b77d-3ee9fa637069
seqno: 43760

b) Node1: This grastate.dat file shows -1 in the seqno. This node crashed during transaction processing. Start this node using the wsrep-recover option. MySQL will store the last committed GTID in the InnoDB data header.

/var/lib/mysql/grastate.dat
version: 2.1
uuid: cbd332a9-f617-11e2-b77d-3ee9fa637069
seqno: -1

c) Node2: This grastate.dat file has no seqno or group ID. This node crashed during DDL.

/var/lib/mysql/grastate.dat
version: 2.1
uuid: 00000000-0000-0000-0000-000000000000
seqno: -1

3. Next, recover the node with the uuid, but no seqno. To get the seqno, use the --wsrep-recover option. To recover the seqno:

/path/to/mysql/bin/mysqld --wsrep-recover. Mysqld will read the InnoDB header files and shutdown immediately. The last wsrep position is printed in mysqld.log file.

Example: 140716 12:55:45 [Note] WSREP: Found saved state: cbd332a9- f617-11e2-b77d-3ee9fa637069:36742

4. Look at the seqno from Node0 (seqno: 43760) and Node1 (seqno: -1). Node0 has the current snapshot of data and should be started first.

5. On Node0, issue this command to start the node:

a) nohup /path/to/mysql/bin/mysqld_safe -- wsrep_cluster_address=gcomm:// &; wait for this node to come online.

b) Then start Node1, and Node2. These two nodes should be started one at a time, and can be started as you normally would.

c) Once all three nodes are up and in a primary state, restart Node0 in the normal fashion (so it comes up as part of the entire cluster, not just a bootstrap).

6. If Node1 or Node2 had the highest seqno, then that Node would be booted as the bootstrap, and you would allow the remaining nodes to start up one at a time (connecting to the Node with the highest seqno).

Answer 2

If you are in the position where your seqno is -1, and you need to bootstrap that node, you can recovery the correct seqno by running:

# galera_recovery

Which will output the correct seqno plus it will update the grastate.dat file.