前回のあらすじ
不思議な光る石のペンダントをつけた少女が空から降りてきた。天使が舞い降りたと思い走って近づく少年。その少女は伝説となった天空の城の王の末裔。少年もまた亡き父の言葉を信じ、天空の城の存在を信じていた。悪意を持った別の王の末裔が少女をさらい、城を悪用しようとすることから、少年は少女と城を守るため、海賊とともに空に旅立った。
ドキドキするストーリーですね！
．．．。
続きです。最終的に接続エラーが出て、処理が継続できない状態に陥るっていうところでした。問題解決する前に、現時点でのパフォーマンスを確認してみます。
前回同様Apache Benchで実行しますが、10000回だとエラーになってしまって計測に失敗してしまうので、桁を下げて1000回(-n 1000 –c 8)としてましょう。
計測方法はabを3回実行してRequest per secondの平均を取ります。
InProc
1回目：538.39
2回目：588.10
3回目：660.41
平均：595.63
StateServer
1回目：525.43
2回目：567.28
3回目：599.09
平均：563.93
SQLServer
1回目：282.39
2回目：370.53
3回目：352.21
平均：335.04
MongoDB
1回目：129.71
2回目：146.35
3回目：145.03
平均：140.36
うん。早くない。ちなみに無印UniversalProviderだと 30.15 とドンマイな感じ。
Universal Provider
ちなみに、5回で平均を取りたかったけど、MongoDB版が5回目で接続エラーになって取れなかったので3回にしました。これは良くない！まずはちゃんと10000回普通に動かせるようにしないと。
と、いうわけで、MongoDB C# Official Driverのドキュメントに目を通してみると、内部でConnection Poolingを利用していると書かれています。が、挙動からはPoolがちゃんと利用されてないんじゃないかと、疑ってみました。 だって、接続エラーって．．．。使いまわしてるならそんなことにならないはず、という根拠のない診断。うさんくさいドクターハウス。
CSharp Driver Tutorial – MongoDB
MongoDB C# Driver API Documentation - Table of Content
詳細はドキュメントから判断出来なかったので、ソースを追いかけてみました。オープンソースだといろいろ調べれていいですねー。
mongodb/mongo-csharp-driver – GitHub
チラチラ見た結果からいうと、MongoServerクラスに保持しているMongoServerInstanceがConnectionPoolを管理していて、MongoServer.Disconnectを呼ぶとすべてのPoolをクローズして回る仕組みのようです。なんでだろ。理由はいいとして、そういう作りなんだということは、finallyで必ずDisconnectを呼び出すのはよろしくないかなー。そんな事しなくても、Poolに保持しているものは10秒ごとにMaxConnectionLifeTime/MaxConnectionIdleTimeを確認して破棄されるようになってるみたいなので、ほっといてもいいんじゃね？みたいな。
と、いうわけで、ソース中のすべてのDisconnectを削除します。
その状態で、abで確認します。
3回実行した結果は525.43 / 599.09 / 572.34。平均：565.62。ワォ！一気に上がりました。せっかくなので10000回出来るかどうかもチェック。
行けるようになりましたー。ちゃんと接続を使い回してくれてるようです。パフォーマンスも接続を使いまわすことで一気に改善しました。んじゃ、なんで、そういう作りにしてなかったのか？っていうのが気になります。
理由はありました。どういうことかというと、Poolが保持しているMongoConnectionは生成された時点でReplicaSetのPrimaryを判定して保持しています。つまり、Failoverした直後、Poolが破棄されない限り接続エラーがおきて、正しくデータの書き込みができなくなるということでしょう。
abを実行し、その最中にstepDownでFailoverしてみます。
Safemode detected an error 'not master'. (Response was { "err" : "not master", "code" : 10056, "n" : 0, "lastOp" : NumberLong("5676991341247070789"), "connectionId" : 13356, "ok" : 1.0 }).
masterじゃないダニ！と言われ、書き込みできないエラーが発生しました。SafeModeじゃなくても同じようにエラーになることは確認済み。
と、得意げにドヤ顔したところで、それはつまりDisconnectしなくなったからでしょ？と、おっしゃるとおりな理由でのエラーなんですけどね。つまり、Failoverした後もちゃんと接続が継続できるようにするために毎回Disconnectしてたわけですね。
あちゃー、これはどうしたものか。なんて、あたかも今、解決策を思いつくような振りになってますけど、事前に調査してわかってることを書いてるだけなんで．．．。てへ！
つまり今回のエラーの原因はPoolから取り出したMongoConnectionがPrimary(Master)を指してないから例外が起きるわけです。そして、MongoServer.Disconnectを呼ぶことでPoolのすべてのコネクションが破棄されるというのはソース見て確認済み。つまりMongoDBに対する処理で例外が発生したらMongoServer.Disconnectを呼び出し、処理をリトライすることで、Failover後に決定したNodeに接続するようにしてあげればよい、という方法が取れましょう。MaxConnectionLifeTimeを短くしてみては？っていうのもあるでしょうが短すぎると接続エラーになりそうだし。
で、用意したのが以下のようなリトライ実行するヘルパー。
public class MongoDbInvokeSetting
{
public string ServerName { get; set; }
public string DatabaseName { get; set; }
public int RetryCount { get; set; }
public int RetrySeconds { get; set; }
}
public class MongoDbHelper
{
/// <summary>
/// リトライを繰り返すInvoker
/// </summary>
/// <param name="setting"></param>
/// <param name="functor"></param>
public static void RetryInvoker(MongoDbInvokeSetting setting, Action<MongoServer> functor)
{
var retry = setting.RetryCount;
Exception exception = null;
while (retry > 0)
{
var server = MongoServer.Create(setting.ServerName);
try
{
functor(server);
break;
}
catch (MongoException ex)
{
exception = ex;
// ↓こいつでPool内の全コネクションクリアが走るはず。
server.Disconnect();
}
retry--;
// とりあえずn秒待ってみる。
Thread.Sleep(setting.RetrySeconds * 1000);
}
// ここでイベントログに書き出すか、Exceptionを出力する必要がある。
// 後続の処理に進んだら困るならException。
// ログなら進んでもいいかもねー。
}
}
ダサくない！ダサくないよ！これでいいんだもん！
このコードを書いてる途中、さすがに心配になったんですけど(これでいいのかっていうね)、そんなおり以下のページを見つけました。
File: REPLICA_SETS — MongoRuby-1.4.1
似たようなリトライさせてますね。だもんで、いいってことで。
これを使って実行する書き方は↓こう。
MongoDbHelper.RetryInvoker(GetSetting(), server =>
{
// serverを使ってCollection検索したり、
// データ追加したり...
});
GetSettingは設定を入れたものを返しましょう。サーバー名とかリトライ回数とか。
これつかって丸っとしたもので、実行しつつFailoverさせてみます(abでエラーが出ないことを確認しました)。
大成功！エラーも起きずFailover成功しました。データも欠落なくいけてます。
で、この状態でのパフォーマスンスを測定してみます。
3回実行したのが485.62 / 496.92 / 552.61 平均：511.72。
遅くなったじゃん！っていう感じしますけど、あったまって無かったみたい。実質Disconnect削除のパフォーマンスと同じ数値でした。
でも～、これだと～、なんていうかパンチが弱い。十分いいとは思うんだけど～。どこか早くできそうなところないかなー、とMongoSessionStateStoreのソースを見ているとありましたねー。
private string Serialize(SessionStateItemCollection items)
{
using (MemoryStream ms = new MemoryStream())
using (BinaryWriter writer = new BinaryWriter(ms))
{
...
return Convert.ToBase64String(ms.ToArray());
}
}
private SessionStateStoreData Deserialize(HttpContext context,
string serializedItems, int timeout)
{
using (MemoryStream ms =
new MemoryStream(Convert.FromBase64String(serializedItems)))
{
...
}
}
ほら、ここ。Base64に変換してstringにしてるじゃないですか。コレいらなくない？BsonBinaryArray使えばbyte[]をそのまま入れることが出来るんじゃないのー？と、気になったので試した結果が↓こちら。
3回実行したのが 542.95 / 538.68 / 534.19、 平均：538.61。微妙．．．。まぁ、いいか。
ちなみにこのままだと、Expireしたセッション削除が残り続けるので、SetAndReleaseItemExclusiveの中で2000回に一回くらいクリーンアップするように仕込んでみました。その状態で10000回実行。
10000回中5回クリーンアップしてるけど、まぁまぁ。外部タスクにしてしまえば影響はでないものなので、ここはいいでしょう。
ち・な・み・に、SQLServerだと平均335.04ですからね。いいじゃないですか。ねぇ。Shardingしてみても同じマシンだとあまり変化でなかったです。と、いうのもCPUを最も使ってるのがIISExpressのプロセスだったので、アプリケーションが遅いってことですから。あとは、マシン分けて計測しかないですが、少なくとも同一環境内ではMongoDBでのSessionStateStoreがStateServerに負けないくらいの速度を実現しました(何度か試したらStateServerはもっと早かったけどー、そこは情報操作！)。
