MariaDB 10.1 Galera Cluster が起動できない

Question

いろいろ検索かけましたが解決の手がかりが見つかりません。
どなたか、お力添えをお願い致します。。

Galeraクラスタとして稼働させたいのですが、
wsrep_on=ONにしてMariaDBを起動させようとするとエラーになってしまいます。
（error.logの内容は本文下部に記載）

試しにwsrep_on=offにしたところ、単体のMariaDBとしては起動することはできます。

具体的に、以下のように起動を試みておりますが、失敗となります。

# service mysql start --wsrep-new-cluster
Starting mysql (via systemctl):  Job for mariadb.service failed because the control process exited with error code. See "systemctl status mariadb.service" and "journalctl -xe" for details.
                                                           [失敗]

環境は以下になります。
OS
# cat /etc/redhat-release
CentOS Linux release 7.2.1511 (Core)
DB
# mysql -V
mysql Ver 15.1 Distrib 10.1.16-MariaDB, for Linux (x86_64) using readline 5.1

/etc/my.cnf.d/server.cnf

[mysqld]

character-set-server=utf8

max_connections = 2000

expire_logs_days=7
log_bin=mysql-bin
log_error=error.log
#slow_query_log_file = db0-slow.log
long_query_time = 2

innodb_file_per_table = 1
innodb_log_file_size = 128M
innodb_log_buffer_size = 64M
innodb_buffer_pool_size = 30G

#
# * Galera-related settings
#
[galera]
# Mandatory settings
wsrep_on=ON
wsrep_cluster_name=db_cluster_2
wsrep_provider=/usr/lib64/galera/libgalera_smm.so
wsrep_node_address=192.168.2.104
wsrep_cluster_address=gcomm://

wsrep_dbug_option=1
wsrep_debug=1

binlog_format=row
default_storage_engine=InnoDB
innodb_autoinc_lock_mode=2

error.log

handlersocket: initialized
2016-07-21 11:37:20 140324149786752 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2016-07-21 11:37:20 140324149786752 [Note] InnoDB: The InnoDB memory heap is disabled
2016-07-21 11:37:20 140324149786752 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2016-07-21 11:37:20 140324149786752 [Note] InnoDB: Memory barrier is not used
2016-07-21 11:37:20 140324149786752 [Note] InnoDB: Compressed tables use zlib 1.2.7
2016-07-21 11:37:20 140324149786752 [Note] InnoDB: Using Linux native AIO
2016-07-21 11:37:20 140324149786752 [Note] InnoDB: Using SSE crc32 instructions
2016-07-21 11:37:20 140324149786752 [Note] InnoDB: Initializing buffer pool, size = 30.0G
2016-07-21 11:37:21 140324149786752 [Note] InnoDB: Completed initialization of buffer pool
2016-07-21 11:37:21 140324149786752 [Note] InnoDB: Highest supported file format is Barracuda.
2016-07-21 11:37:21 140324149786752 [Note] InnoDB: 128 rollback segment(s) are active.
2016-07-21 11:37:21 140324149786752 [Note] InnoDB: Waiting for purge to start
2016-07-21 11:37:21 140324149786752 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.30-76.3 started; log sequence number 1617266
2016-07-21 11:37:21 140324149786752 [Warning] InnoDB: Skipping buffer pool dump/restore during wsrep recovery.
2016-07-21 11:37:21 140324149786752 [Note] Plugin 'FEEDBACK' is disabled.
2016-07-21 11:37:21 140324149786752 [Note] Server socket created on IP: '::'.
2016-07-21 11:37:21 140324149786752 [Note] WSREP: Read WSREPXid from InnoDB:  00000000-0000-0000-0000-000000000000:-1
2016-07-21 11:37:21 140324149786752 [Note] WSREP: Recovered position: 00000000-0000-0000-0000-000000000000:-1
handlersocket: terminated

journalctl -xe

 7月 23 18:23:31 db1 polkitd[947]: Registered Authentication Agent for unix-process:17364:34048626 (system bus name :1.288 [/usr/bin/pkttyagent --notify-fd 5 --fallback], object path /org/freedesktop/PolicyKit1/AuthenticationAgent, loca
 7月 23 18:23:31 db1 systemd[1]: Starting MariaDB database server...
-- Subject: Unit mariadb.service has begun start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit mariadb.service has begun starting up.
 7月 23 18:23:36 db1 sh[17372]: WSREP: Failed to recover position: '2016-07-23 18:23:32 140580170864768 [Note] /usr/sbin/mysqld (mysqld 10.1.16-MariaDB) starting as process 17445 ...'
 7月 23 18:23:36 db1 systemd[1]: mariadb.service: control process exited, code=exited status=1
 7月 23 18:23:36 db1 systemd[1]: Failed to start MariaDB database server.
-- Subject: Unit mariadb.service has failed
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit mariadb.service has failed.
--
-- The result is failed.
 7月 23 18:23:36 db1 systemd[1]: Unit mariadb.service entered failed state.
 7月 23 18:23:36 db1 systemd[1]: mariadb.service failed.
 7月 23 18:23:36 db1 polkitd[947]: Unregistered Authentication Agent for unix-process:17364:34048626 (system bus name :1.288, object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale ja_JP.UTF-8) (disconnected from bus)

Comments

[退会済みユーザー]

エラーログには「ERROR」等の文字列は内容に見えますが、どのような出力結果をご覧になって、「エラー」と判断されたのでしょうか？

[suzushin0619]

ご確認頂きましてありがとうございます。
「起動時のコマンドとその結果」、その際の「 jounalctl -xe の結果」を本文に記載させて頂きました。
何か解決のヒントだけでも頂けると幸いです。

Answer 1

ご質問内容への追記、ありがとうございます。

7月 23 18:23:36 db1 sh[17372]: WSREP: Failed to recover position: '2016-07-23 18:23:32 140580170864768 [Note] /usr/sbin/mysqld (mysqld 10.1.16-MariaDB) starting as process 17445 ...'

お分かりかもしれませんが、上記が理由だと思われます。
詳細な仕組みをご説明できず恐縮ですが、Galeraが記録しているリストア開始ポジションが実際とずれていることが原因だと思います。
私の解決方法は、データディレクトリ配下を初期化し、データのみをリロード、という手法をとりました。
データディレクトリ配下にgalera.cacheというファイルがあるはずで、これがポジションを記録しているのですが、これを削除する方法でも解決できるかもしれません。（私の場合は、時間の関係で確実性を優先してデータディレクトリ初期化＆リロードをしました）

お役に立ちましたら光栄です。

Comments

[suzushin0619]

ご回答まことにありがとうございます。

確認したところデータディレクトリにgalera.cacheが存在しておりませんでした。
初回のGaleraの起動で失敗しているので作成されていないのかなと予想しております。

また、yum remove mariadb、データディレクトリ、/etc/my.cnf.d/*を削除してから再インストールしてもやはり起動に失敗してしまいました。

ただ、ご指摘の通りリストアポジション周りが怪しく思いますので、まずこちらを中心に調査を続けたいと思います。

Answer 2

公式にも10.1.16で同じ様なユーザーがおり、こちらを元に取り急ぎの解決ができました。
https://jira.mariadb.org/browse/MDEV-10420

内容としましては、バージョンを10.1.14に下げてインストールするのみです。
バージョン指定の方法は以下の公式の通りです。
https://mariadb.com/kb/ja/yum/

設定ファイルなどは10.1.16でエラーになったものと完全に同一なので、
このバージョンに何かしらの不具合があるのではと思います。

10.1.14で無事に起動後、10.1.16へのアップデートをいちおう試したら、やはりエラーになりました。
10.1.16で問題なく動いているサーバーもあるので、何か条件や回避策があるのではとも思っています。