2010年9月5日日曜日

クッキーとビスケットは何が違うんですか?

IMG_0056

なにこのモンスター...。

IMG_2568

これがラテアートになると↑こうなっちゃうんだから不思議です。

ここ最近ずっと悩まされていた問題にかたがつきました。石野さん、例の問題がやっと落ち着きました。

「ユー、ブログにちゃんと書いときなYO」と大きな後輩に言われ、いじめが怖いのでちゃんと書いておくことにします。

そもそも問題となった現象は「au端末でのPOSTリクエスト時に500エラー(Internal Server Error)が発生する」というものです。これはあくまで表面的な現象で本質は別のところにあるんですが、この状況から問題を特定し解決するに至る長い長い戦い。血で血を洗う争い。

結論だけ先に書くと「ASP.NETでセッションをLB配下で利用する場合、machineKeyだけじゃなくIIS7でのSite IDも同一の値にしておかないと、SQLServerセッションストアでセッションデータを正しく取り出せない」です。

PRB: セッション状態が損失 Web ファームで SqlServer または StateServer セッション モードを使用します。

これまでこの問題に出会ったことがなかったので原因を特定するのにとても苦労しました。

Web サイトのアプリケーション パスを同期化する

こっちではインスタンスIDと言ってますね。

ちなみに、構築環境はテスト環境(ステージング)と本番環境(ライブ)の2つありステージングでは全く問題が発生しないという前提条件があります。サーバー機は同一(Windows Server 2008 R2でIIS7.5)なのにくわえアセンブリもバイナリレベルで同一(.NET 3.5SP1)です。SSLのホスト名と発行元が違う、あと暗号化ビット長がテスト環境では1024ビット、本番では2048ビットという違いもあります。LBでIPスティッキー設定をしてるので同一IPからのリクエストはすべて同一ホストにルーティングされるようにもなってます。そもそもセッションはDBにいれてるんだからスティッキー必要ないんだけど、そのことに気がつかず、必要でしょ!みたいなのりで環境設定を行ったのも問題を見つけづらくする原因でした。

パフォーマンス: ASP.NET アプリケーションのスケーリング戦略
ロードバランスクラスタの実装

最初に疑ったのは証明書のビット長。auで2048ビットで問題があるという情報を良く見かけますよね。プログラムコードはテスト環境で問題なく動いてるものだから、問題が内在してるとしても、それは別の問題で今回の現象が発生する原因ではないと思ってるので、あくまで環境の違いに焦点をあわせてひたすら調査です。で、会社に無理をお願いして2048ビット長の証明書を買ってもらうも、あいかわらずテスト環境では問題が再現できない。ということで、auでの2048ビット問題がどうのこうのではないということでしょう。

発行元に問題があるのかいうのが最後まで拭いきれ無かったんですが、同一発行元できちんと機能する部分が他サイトであったので、そこも問題視しづらい。けど、ひっかかる、みたいな。

テストコードを書いて再現可能な端末でいろいろ試した結果、どうもセッションの内容が直前に設定した値じゃなく、ずいぶん前の値が表示されてる気がする(時間をセッションにいれてたので)。セッション内容が混線してるようにも思えたけど、標準のSessionIDManagerが発行するSessionIDはRNGCryptoServiceProviderを使ったランダム値を使っている(公式なものは見つけられてないですが、Reflectorで確認したので間違いないはず)ので、新規セッションで重複したものが発行されてるとはとても考えにくい。試してみるとわかりますが、RNGCryptoServiceProviderはかなり優秀で現実的な範囲で重複しない値をランダムに生成してくれます。SQLServerをセッションストアに使ってるので、セッションテーブルの中身を見たりしてみたんですが、ちゃんと入ってるように見える。

そこで熊さんが「Application名とか違うんじゃない?」とつぶやきました。でもSessionState設定にそんな項目ないじゃないですか。その時ふとappcmdでIISの設定を見比べてる時に違いがあったことを思い出しました。SiteIDが違った気がする、と。熊さんナイス!

sticky

↑赤線で囲ってるところです(これは自マシン)。

そこからいろいろたどって上記KBにたどり着くわけです。で、セッション用のテーブル内容を見てみると、確かにアプリケーションを特定するための情報にSite IDが含まれてる。これがまた公式な資料ではApplicationPathという表現だったりして、SiteIDに直結しない。しかもたぶんですが、IIS6までと発行ルールが違う上に、今回の対象サーバーで対象サーバ群の中でサイトの生成数が違ったりしてて、まさにマルチテナントの罠。クラウド環境を使う場合にもどういう風に構成されてるか知らないと、痛い目を見ることになりますYO。

セッション内容がへンな感じになるのはつまりこんな感じです。

  • URIセッションとして一度生成されたあと、次回以降のリクエストでは別サーバーにLBで振られ、ASP.NETがセッションIDを取り出した後、DBからセッション情報を取り出す際にSite IDの違うサーバー上での処理なので、新規セッション扱いとなるというパターン
  • その後のリクエストでは、サーバー毎に取り出す(または保存する)セッション情報が異なる結果になり、直前のセッションが取り出せないというパターン

まさに科学では説明できないような現象にしか思えない...。呪いなんじゃないかと。起きている事象だけを見るとサッパリなんですが、ここにつながるであろうヒント的な挙動は何度か発生してたんです。それをまた軽く流してたのがよくなかったというのは、原因がわかったからなのか、個人的な問題なのか。いずれにせよ、もっと早くに問題に着手していればここまでの痛手にはなってなかったような気もします。反省。

ここまで読んで「au関係なくね?」と思った人は勘がいいですね。つまりauだけに存在するこれとは別の問題とセッションの問題の2つが同時に発生していたわけです。auだけに存在する問題に関してはプログラム的な不具合だとコードを変えてもいいんですが、それだとテスト環境でうまく動く説明がつかない。まぁCookie関連の問題なんですけどね。全然食ってくれないau。なのでそこは別の問題としてコードを変えて対応しました。テスト環境では動くけど、何か闇の力が働いてたんでしょう。HTTPSだし。

auのSSLでのCookieの挙動がおかしい - maru.cc@はてな

晴れてすべての問題が解決し、枕を高くして安心して眠れる日々を送れることになったと思いきや、別の問題で結局徹夜。なんでやねん!