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の処理は失敗することがありそうです。
