mixi engineer blog

*** 引っ越しました。最新の情報はこちら → https://medium.com/mixi-developers *** ミクシィ・グループで、実際に開発に携わっているエンジニア達が執筆している公式ブログです。様々なサービスの開発や運用を行っていく際に得た技術情報から採用情報まで、有益な情報を幅広く取り扱っています。

memcachedのaccept_new_connsがスレッドセーフじゃない件がmemcached-1.4.6で修正されたにょ

こんにちは、たんぽぽGの森本です

memcached-1.4.6がリリースされました。
mixi大規模障害の原因となった不具合が解消されているとのことなので検証してみました。

動作確認

過去のバージョンで不具合が発生することと新しいバージョン(1.4.6)で不具合が発生しないことを確認するために
負荷テストを行いました。

memcachedの設定は

memcached -U 0 -u nobody -p 11222  -t 4 -m 16000 -C -c 1000 -v

としました。
-l オプションを指定していないので eth0, lo の二つのネットワークI/Fに対してlistenを行う設定です。

クライアント側のスクリプトは前回と同様にmalaさん作のテストスクリプトを用いました。

./memcachedos.pl localhost 11222 5

memcached-1.4.4の動作確認

5回試行してそれぞれ
  • 4分17秒で停止
  • 0分40秒で停止
  • 1分15秒で停止
  • 14分52秒で停止
  • 0分44秒で停止
と、バラツキはあるものの不具合が再現できました。

memcached-1.4.5の動作確認

5回試行してそれぞれ
  • 9分27秒で停止
  • 13分03秒で停止
  • 9分14秒で停止
  • 10分38秒で停止
  • 9分45秒で停止
こちらもバラツキはあるものの不具合が再現できました。

memcached-1.4.6の動作確認

「XX時間問題なく動き続けました」とテンプレを用意していたのですが、なんとmemcachedの反応が非常に遅くなってました。

以下の症状が観測されました。

  • 1000req/sぐらいでていたのが 0.3req/s ぐらいになっていた
  • telnetはつながるが、レスポンスが返ってこない
  • 経過時間は2時間弱
  • event_add: No such file or directoryが大量にでてた

accept()したあと event_add()するまでに、すごい時間がかかっているためclientが接続を切ってしまい"No such file or directory"が出ているのでは?と予想しています。

ひきつづき調査中です。

なにかわかれば報告したいと思います。

差分の詳細

1.4.6のRelease Notesにある "fix race crash for accepting new connections" を調べてみました。

1.4.4での障害は

・接続数がMAXになる
・接続受付を中断
・あるクライアントが接続を切る
・接続に余裕ができる
・接続受付を開始

の「接続受付を開始」において排他制御が崩れ main_baseをmain threadとworker threadの両方が操作しているために起こっていました。

以前のコードでは接続が切られたあとに呼ばれる conn_close() から直接 accept_new_conns が
呼ばれていましたが、今回のバージョンではその部分はフラグ(allow_new_conns)を立てるだけに修正されていました。

static void conn_close(conn *c) {
     MEMCACHED_CONN_RELEASE(c->sfd);
     close(c->sfd);
-    accept_new_conns(true);
+    pthread_mutex_lock(&conn_lock);
+    allow_new_conns = true;
+    pthread_mutex_unlock(&conn_lock);
     conn_cleanup(c);

さらに、このフラグ(allow_new_conns)を監視するtimerが追加されました。

+static volatile bool allow_new_conns = true;
+static struct event maxconnsevent;
+static void maxconns_handler(const int fd, const short which, void *arg) {
+    struct timeval t = {.tv_sec = 0, .tv_usec = 10000};
+
+    if (allow_new_conns == false) {
+        /* reschedule in 10ms if we need to keep polling */
+        evtimer_set(&maxconnsevent, maxconns_handler, 0);
+        event_base_set(main_base, &maxconnsevent);
+        evtimer_add(&maxconnsevent, &t);
+    } else {
+        evtimer_del(&maxconnsevent);
+        accept_new_conns(true);
+    }
+}

maxconns_handlerは接続受付中止時に do_accept_new_conns から起動されます。

簡略化して書くと

main thread : do_accept_new_conns {
  if(受付無理){
    maxconns_handler起動
  }
}

worker thread :  conn_close {
   allow_new_conns = true; // 接続に余裕ができた
}

main thread : maxconns_handler {
  if(not allow_new_conns){
    //  まだ接続に余裕がない
    10msにもう一度調べる
  }else{
    timer削除
    accept_new_conns(true); // 新規接続受付開始;
  }
}
となっています。

まとめ

1.4.5以前

worker threadが、直接accept_new_conns()を呼びmain_baseを操作する。

1.4.6

worker threadはフラグを立てるだけ。main threadがaccept_new_conns()を呼びmain_baseが操作する。

つまり「main_baseを触るのは main threadのみ」となっており、main_base操作に対する排他制御自体が必要なくなり、障害の原因が根本から解決されていました。
ただ、別の問題が発生してしまっているのでもうすこし調査してみます。

ちなみに、1.4.6ではincr/decrがスレッドセーフでなかったバグも解決されているようなので、要チェックです。