とあるMySQLとチョコレートの話 - アルミ缶の上にアルフォート

何回もログを仕込んでようやく原因がわかったバグを潰したメモです。

1ユーザーにつき1個だけチョコレートを作りたいとします。
※今回はDBのunique制約でどうこうするとかいうレベルではなく、チョコレートが2回作られる時点でアウトとします。

以下の挙動をもつAPIをつくります。

	リクエストユーザー	挙動
1	まだチョコレートをもってないユーザー	チョコレートを作ってあげて、作ったチョコレートを返す
2	チョコレートをもっているユーザー	チョコレートを返す

というわけで、以下のかんじで作ってみました。

function get_or_create_choco(user_id) {
  var choco = select_choco(user_id); //DB(master)からチョコレートをとる
  if (choco) {
    return choco;
  }
  else {
    choco = create_choco(user_id); //チョコレートを作ってDBにinsert
    return choco;
  }
}

これはだめぽよです。
リクエストが並列で2回きた場合、create_chocoが2回呼ばれてしまうのです。
というわけで、例えばmemcachedでロックを貼ってみました。

function get_or_create_choco(user_id) {
  var choco = select_choco(user_id); //DB(master)からチョコレートをとる
  if (choco) {
    return choco;
  }
  else {
    var lock = create_choco_lock(user_id) //memcachedで特定のキーでaddしてみる
    if (lock) { //ロック取得成功時
      choco = create_choco(user_id); //チョコレートを作ってDBにinsert
      return choco;
    }
    else { //ロック取得失敗時
　　　sleep 0.2;
      choco = select_choco(user_id); //DB(master)からチョコレートをとる
      return choco;
    }
  }
}

こうすれば、短期間にきた2回目のリクエストはロックを取得できないので、
0.2秒くらい休んだあとにDBを見に行けば、既に1回目のリクエストでチョコレートは作られているはずなので、
無事に作られたチョコレートを返せるはずです。

もう一工夫。これはかなり頻繁に叩かれる処理なので、ちょっとmemcachedを効かせてみます。

function get_or_create_choco(user_id) {
  var choco = select_choco(user_id); // memdからチョコを取る。なかったらDB(master)からチョコを取る。DBにあったらmemdにセットしてあげる。
  if (choco) {
    return choco;
  }
  else {
    var lock = create_choco_lock(user_id) //memcachedで特定のキーでaddしてみる
    if (lock) { //ロック取得成功時
      choco = create_choco(user_id); //チョコレートを作ってDBにinsert
      return choco;
    }
    else { //ロック取得失敗時
　　　sleep 0.2;
      choco = select_choco(user_id); // memdからチョコを取る。なかったらDB(master)からチョコを取る。DBにあったらmemdにセットしてあげる。
      return choco;
    }
  }
}

これで完成。
しかし低確率で、なぜかチョコレートを返せないときがありました。

もろもろログを増やしたところ、どうもロック取得失敗時に、select_chocoしてもチョコが取れないようなのです。つまり、2回目のリクエストにおいて、memdにもDBにもチョコがないと言われている。

色々原因を考えました。
・sleepが足りない？
　・休む時間を伸ばしてあげてもダメ
・1回目のリクエストにおいて、memdやmysqlでのエラーはおきてる？
　・おきてない
・チョコのmemdへのsetが失敗している？
・memdは複数台あるので、同じkeyなのに別のmemdを見に行ってる？
　・memdになかったらDBにfallbackするし関係なさそう
・memd evictionしてる？
　・してない
・memdに「チョコなかったよー」ってネガティブキャッシュしてる？
　・してない

答えをいうと、REPEATABLE READとAutoCommit=0によるものでした。

AutoCommit=0でmasterに接続しており、コネクションを使いまわしていたので、2回のselect_chocoでトランザクションが継続していました＞＜
問題となるケースは、一番頭でselect_chocoをしていて空振っています。で、同じconnectionを使いまわしているので、それ以降は他のプロセスがいくらchocoを作っていても、いくらsleepしても「このユーザーはチョコがない」ことが確定してしまっています。シュレーディンガーの猫ですね。
そもそもcreate_chocoでmemdにセットすべきなのにしていないので、(短期間における)2回目のリクエストでは必ずDBを覗きにきてしまい、チョコがないことが確定しているのであぼーんという話。

基本はmaster DBからはちゃんとcommitして抜けているのですが、select_chocoのときだけ単なるselectじゃーんということで、commitしておりませんでした＞＜

あとはcommitとかコネクション使い回しとかがライブラリでいいかんじに隠蔽されてたのであんまり強く意識してなかったのも敗因です。。

最終的には、
(1)select_chocoではスコープから抜けるときにちゃんとcommitしてトランザクションを完結させる
(2)create_chocoでちゃんとチョコをmemdにもセットする
かんじで修正しました。

皆さんもシュレーディンガーの猫には気をつけましょう。単なるselectもcommitしないと罠になるかもよ。というお話なのでした。