みなさんこんにちはごきげんよう。
時々登場する編集長の菊池です。
先日とあるスマホアプリ用のサーバー側 API (Rails で実装してあります)で、
『flash に入れた値が、値を取り出してないのに消えてしまう!?なんで!?』
と困っていた現場に行って原因を調査していたところ、思い込みとかいろいろ気がついたので、今回はその時の話しを書こうと思います。
Rails の flash については皆さんご存知だと思います。リクエストをまたいで値を持ち越す仕組みで、flash に設定した値は次のリクエストまで持ち越せて、flash から値を読み込むと flash から値が消えます。session に入れた値は明示的に消す必要がありますが、flash は読み込むと消えてしまうところが違います。
ざっと簡単に書くと
リクエスト1:flash に値を設定
リクエスト2:flash から値を取り出して利用
リクエスト3:flash に設定していた値は無くなっている
ということで、さきほどの現場でも、次のリクエストまで一時的に引き継ぎたい値を入れていた訳なんですが、値を取り出してみたら空になってしまって困ってました。しかも、取り出せる時と取り出せない時がある状況で、こういうのは調べにくくて困るんですよね...
ということで、困っていた状況を簡単に書くと
リクエスト1:flash に値を設定
リクエスト2:flash から値を取り出して利用しようと思ったら空っぽだった!
何ででしょうねー
状況を確認するために、簡単なテストサーバーを作って確認してみたんですが、そこで思い込みの一つに気がつきました。
flash って値を取り出したら消えるんだよね?
→ flash に入れた値は、次のリクエストまでの命。次のリクエストで flash に触らないと、設定した値は消えちゃいます。
ということで、こう使えそうに思ってませんか?
リクエスト1:flash に値を設定
リクエスト2:flash は何もいじらない
リクエスト3:flash から値を取り出して利用できそうな感じだけど...
実際はこうなります
リクエスト1:flash に値を設定
リクエスト2:flash は何もいじらない
リクエスト3:flash に設定した値は消えて無くなっている
ということなんですが、問題となっている現場で Rails のログを確認してみるも、間にリクエストが挟まっていることはありませんでした。
んー
ちなみに、この現場ではクッキーセッションではなく redis-rails を使って Redis にセッション情報を保存して運用していました。それから、スマホアプリ側ではサーバーに並列してリクエストを送っているとの情報をゲット。
並列にリクエストを送ってるところがちょっと怪しい...
ということで、目を皿のようにしてログを見てみたんですが、ログ上は意図した順番でリクエストが処理されていました。
んーーーーー、んん!!!
順番にリクエストが処理されているように見えるものの、それぞれのリクエストの終了タイミングはどうなっているのか!?
ということで、コントローラーの before_filter と after_filter にログ出力をセットして確認してみたところ。
各リクエストの開始と終了のタイミングはこうなってました
リクエスト1:[開始]ちょっと時間のかかる処理...
リクエスト2:[開始]リクエスト1処理中に flash へ値を設定
リクエスト2:[終了]
リクエスト1:[終了]
リクエスト3:[開始] flash に設定していた値は無くなっている
リクエストの終了タイミングで flash を含む session 情報を Redis に保存すると考えると、リクエスト1では flash 設定してないんで空で上書きしちゃってるようです。
ログ上は
リクエスト1:[開始]ちょっと時間のかかる処理...
リクエスト2:[開始]リクエスト1処理中に flash へ値を設定
リクエスト3:[開始] flash に設定していた値は無くなっている
となっていたので気がつかなかった!
こういう順番だと問題無しです
リクエスト1:[開始]ちょっと時間のかかる処理...
リクエスト1:[終了]
リクエスト2:[開始]リクエスト1処理中に flash へ値を設定
リクエスト2:[終了]
リクエスト3:[開始] flash に設定していた値は残っている
ということで、原因がわかったので対処の方法もいろいろ出て来ますね。
スマホアプリ相手だと並列にリクエストが送られて来る事も多いんで、flash 使う時は気をつけて使った方がよさそうです。
ということで、機会があったらまた何か記事にしたいと思います。また会いましょう。
菊池でした。