9月 10
Flareのフェイルオーバー機能をテストしてみました。
ノード監視 + フェイルオーバー (インデックスサーバにより各サーバを監視し、ダウンした場合にはサービスアウトします。また、masterサーバがダウンした場合はslaveサーバのうち1台がmasterサーバに昇格します)
Flare – GREE Labsより
今回は後半のmasterサーバーがダウンした場合のテストです。
実際にダウンしてしまうというよりも、メンテナンスのためにを故意にダウンさせるケースを想定しています。実際の挙動を確認しておくことで、本番環境で自信を持ってmasterサーバーを落とすことができます。
設定ファイル
インストールは公式ドキュメントをご覧いただくとして、各サーバーの設定から。
1台のサーバーにインデックスサーバー*1、各ノードサーバー*3を立ち上げるため、ポートを変えて起動します。
インデックスサーバー
/etc/flare/flarei.conf
data-dir = /opt/flare/flarei log-facility = local0 max-connection = 256 monitor-threshold = 3 monitor-interval = 1 server-name = localhost server-port = 12120 thread-pool-size = 8
マスターノードサーバー
/etc/flare/flared_master.conf
data-dir = /opt/flare/flared_master index-server-name = localhost index-server-port = 12120 log-facility = local1 max-connection = 1024 mutex-slot = 64 proxy-concurrency = 2 server-name = localhost server-port = 11211 storage-type = tch thread-pool-size = 16 storage-ap = 4 storage-bucket-size = 16777216
スレーブノードサーバー
/etc/flare/flared_slave.conf
data-dir = /opt/flare/flared_slave index-server-name = localhost index-server-port = 12120 log-facility = local2 max-connection = 1024 mutex-slot = 64 proxy-concurrency = 2 server-name = localhost server-port = 11212 storage-type = tch thread-pool-size = 16 storage-ap = 4 storage-bucket-size = 16777216
プロキシノードサーバー
/etc/flare/flared_proxy.conf
data-dir = /opt/flare/flared_proxy index-server-name = localhost index-server-port = 12120 log-facility = local3 max-connection = 1024 mutex-slot = 64 proxy-concurrency = 2 server-name = localhost server-port = 11213 storage-type = tch thread-pool-size = 16 storage-ap = 4 storage-bucket-size = 16777216
syslog設定
/etc/syslog.conf
# Log flare local0.* /var/log/flarei.log local1.* /var/log/flared_master.log local2.* /var/log/flared_slave.log local3.* /var/log/flared_proxy.log
通常運用状態を再現
設定が終わったら、各サーバーを起動します。
sudo /usr/local/flare/bin/flarei -f /etc/flare/flarei.conf --daemonize sudo /usr/local/flare/bin/flared -f /etc/flare/flared_master.conf --daemonize sudo /usr/local/flare/bin/flared -f /etc/flare/flareid_slave.conf --daemonize sudo /usr/local/flare/bin/flared -f /etc/flare/flared_proxy.conf --daemonize
起動が終わったらインデックスサーバーへ接続し、node roleコマンドで以下の状態に設定します。
stats nodes STAT localhost:11211:role master STAT localhost:11211:state active STAT localhost:11211:partition 0 STAT localhost:11211:balance 1 STAT localhost:11211:thread_type 16 STAT localhost:11212:role slave STAT localhost:11212:state active STAT localhost:11212:partition 0 STAT localhost:11212:balance 2 STAT localhost:11212:thread_type 17 STAT localhost:11213:role proxy STAT localhost:11213:state active STAT localhost:11213:partition -1 STAT localhost:11213:balance 0 STAT localhost:11213:thread_type 18
通常運用では、クライアントはproxyサーバーへ接続します。その後proxyサーバーが、get時にはmaster:slave=1:2の比率（設定で変えられます）で分散してアクセスし、set時にはmasterサーバーへアクセスします。書き込まれたmasterサーバーはslaveサーバーへデータをレプリケートします。
この状態で、masterサーバーを落としてみます。
マスターダウンからスレーブの昇格
killコマンドでmasterサーバーを落とすと、インデックスサーバーがダウンを検知し、slaveサーバーを昇格させます。
状態を確認すると、
stats nodes STAT localhost:11211:role proxy STAT localhost:11211:state down STAT localhost:11211:partition -1 STAT localhost:11211:balance 0 STAT localhost:11211:thread_type 16 STAT localhost:11212:role master STAT localhost:11212:state active STAT localhost:11212:partition 0 STAT localhost:11212:balance 2 STAT localhost:11212:thread_type 17 STAT localhost:11213:role proxy STAT localhost:11213:state active STAT localhost:11213:partition -1 STAT localhost:11213:balance 0 STAT localhost:11213:thread_type 18 END
元masterサーバがダウンしてproxyサーバーに、元slaveサーバーがmasterサーバーに昇格しています。
無事成功しました。
昇格時のログ
ログを確認すると、挙動がよく理解できます。
インデックスサーバーのログ
/var/log/flarei.log
Sep 1 13:55:20 flare-test flarei[10772]: [1152215360][WRN][connection.cc:448-write] connection seems to be already closed (sock=-1) Sep 1 13:55:21 flare-test flarei[10772]: [1152215360][WRN][connection.cc:122-open] connect() failed: Connection refused (111) -> wait for 500000 usec Sep 1 13:55:24 flare-test last message repeated 7 times Sep 1 13:55:25 flare-test flarei[10772]: [1152215360][ERR][connection.cc:129-open] connect() failed Sep 1 13:55:26 flare-test flarei[10772]: [1152215360][WRN][connection.cc:122-open] connect() failed: Connection refused (111) -> wait for 500000 usec Sep 1 13:55:29 flare-test last message repeated 7 times Sep 1 13:55:30 flare-test flarei[10772]: [1152215360][ERR][connection.cc:129-open] connect() failed Sep 1 13:55:30 flare-test flarei[10772]: [1152215360][NTC][cluster.cc:338-down_node] handling node down event [node_key=localhost:11211] Sep 1 13:55:30 flare-test flarei[10772]: [1152215360][ERR][cluster.cc:357-down_node] master node down -> finding an active slave and shift its role to master Sep 1 13:55:30 flare-test flarei[10772]: [1152215360][NTC][cluster.cc:380-down_node] found new master node (node_key=localhost:11212, partition=0, balance=2) Sep 1 13:55:30 flare-test flarei[10772]: [1152215360][NTC][cluster.cc:396-down_node] setting node state to down (and clearing role, etc) Sep 1 13:55:30 flare-test flarei[10772]: [1152215360][NTC][cluster.cc:1308-_reconstruct_node_partition] reconstructing node partition map... (from 3 entries in node map) Sep 1 13:55:30 flare-test flarei[10772]: [1152215360][NTC][cluster.cc:1416-_reconstruct_node_partition] node partition map: Sep 1 13:55:30 flare-test flarei[10772]: [1152215360][NTC][cluster.cc:1421-_reconstruct_node_partition] 0: master (node_key=localhost:11212, node_balance=2) Sep 1 13:55:30 flare-test flarei[10772]: [1152215360][NTC][cluster.cc:1435-_reconstruct_node_partition] node partition map (prepare): Sep 1 13:55:31 flare-test flarei[10772]: [1152215360][WRN][connection.cc:122-open] connect() failed: Connection refused (111) -> wait for 500000 usec Sep 1 13:55:34 flare-test last message repeated 7 times
インデックスサーバーは設定ファイルのmonitor-intervalの秒数ごとに各ノードへ死活チェックを行っています。
今回は1（秒）に設定しているので、マスターがダウンしてから最長1秒でダウンを検知します。
検知した後monitor-thresholdの回数分（3回）、死活チェックをリトライします。リトライの間は0.5秒のインターバルがあり、最後の死活チェックが終わると、ノードのダウンを決定し、新しいマスターを探します。
新しいマスター候補が見つかると昇格させ、晴れてマスターになります。
ログでは10秒で昇格を果たしていますが、環境やデータ量によって変わる可能性はありそうです。
スレーブサーバーのログ
/var/log/flared_slave.log
Sep 1 13:55:30 flare-test flared[11476]: [1036380480][NTC][cluster.cc:759-reconstruct_node] reconstructing node map... (3 entries) Sep 1 13:55:30 flare-test flared[11476]: [1036380480][NTC][cluster.cc:785-reconstruct_node] update: node_balance (1 -> 0) Sep 1 13:55:30 flare-test flared[11476]: [1036380480][NTC][cluster.cc:1308-_reconstruct_node_partition] reconstructing node partition map... (from 3 entries in node map) Sep 1 13:55:30 flare-test flared[11476]: [1036380480][NTC][cluster.cc:1416-_reconstruct_node_partition] node partition map: Sep 1 13:55:30 flare-test flared[11476]: [1036380480][NTC][cluster.cc:1421-_reconstruct_node_partition] 0: master (node_key=localhost:11212, node_balance=2) Sep 1 13:55:30 flare-test flared[11476]: [1036380480][NTC][cluster.cc:1435-_reconstruct_node_partition] node partition map (prepare): Sep 1 13:55:30 flare-test flared[11476]: [1036380480][NTC][cluster.cc:1061-_shift_node_state] shifting node_state (node_key=localhost:11211, old_state=0, new_state=2) Sep 1 13:55:30 flare-test flared[11476]: [1036380480][NTC][cluster.cc:1078-_shift_node_role] shifting node_role (node_key=localhost:11212, old_role=1, old_partition=0, new_role=0, new_partition=0) Sep 1 13:55:30 flare-test flared[11476]: [1036380480][NTC][cluster.cc:1078-_shift_node_role] shifting node_role (node_key=localhost:11211, old_role=0, old_partition=0, new_role=2, new_partition=-1)
こちらにもインデックスサーバーの指令を受けて、マスターになるログが残っていました。
クライアントへの影響
マスターをダウンさせた時に接続中だったクライアントがどうなるのかを調べてみました。
set
以下は”key_” + 1〜100万をキーに20バイトの文字列をsetするプログラムで、keyの後ろの数字は処理時間を表しています。
set key_500261:0
set key_500262:0
set key_500263:0
set key_500264:0
set key_500265:16.000910997391
set key_500266:0
set key_500267:0
set key_500268:0
5行目の処理時にマスターがダウンし処理が止まりますが、マスター昇格後、無事書き込みが完了しています。
時間はかかるものの、書き込みは失敗しませんでした。
get
以下は上のプログラムでsetした値をgetするプログラムで、key:value:処理時間を表しています。
get key_245:01234567890123456789:0
get key_246:01234567890123456789:0
get key_247:01234567890123456789:0
get key_248:01234567890123456789:0
get key_249:01234567890123456789:0
get key_250::31.737808942795
get key_251:01234567890123456789:0
get key_252:01234567890123456789:0
get key_253:01234567890123456789:0
get key_254:01234567890123456789:0
get key_255:01234567890123456789:0
6行目の処理時にマスターがダウンし処理が止まり、そのままデータが取得できず、タイムアウトしてしまいました。
スレーブの台数が多ければ止まらなかったかもしれませんが、この構成では5回中5回、全て同じ結果でした。テスト不足ではありますが、getの処理は失敗することがありそうです。
