アクセスログは [負荷がかからないように] 非同期で実装・・・!?
SharePoint MVP の有名な人が作ったお粗末な設計ミスと、それがリリースされてしまったお話です。
———
某大学のポータルサイトを作成したときのお話です。
今回のメンバーには、Microsoft MVP を受賞した “開発が得意な専門家” (M男) も参加していました。
■ アクセスログをとりたいという追加要望が発生
お客様より SharePoint の全サイトでアクセスログを取りたいという要求が出ました。
SharePoint 既定のログや IIS のログ以上のログを採取したいために、SharePoint の MasterPage にログ採取の仕組みを仕込む形で実施しました。
追加要望であったのでいくつか懸念が上がっていましたが、もっとも注目されたのが、ピーク時のトップページのレスポンスタイムでした。早朝はかなり集中的なアクセスが発生することが分かっていたからです。
■ M男が考えた案
パフォーマンスが絡む要件の検討方法は、いくつかの実装方法を列挙し、それぞれモックを作成してパフォーマンス カウンターを確認し、検証するのが常套手段です。
しかしながら M男は「これ一択！」とばかりにこんな案を出してきました。
M男「Ajax でロギング部分を JavaScript で非同期にしたらいいんだよ。そうするとレスポンス タイム失われなくて済むから」
_layouts フォルダ以下にログ採取用の aspx ファイルを作成して配置し、MasterPage には JavaScript でそのページへ非同期のアクセスを実装する、ということです。しかしながら私はすぐに以下のような反論をしました。
「まず、今回は閑散時の単一アクセスのレスポンス速度を考えるわけではなく、アクセス ピーク時への対処です。Web ページへのアクセスとロギングを 2 つに分けるということは、トータルで見ると処理コストは増えるので、リクエストのキューイングが発生する頃に余計にレスポンスが悪くなる可能性があります。
Web サーバーの処理タスクが、単純に処理時間が半分で到着数が 2 倍になるのであれば、(待ち行列理論により) 平均応答時間は短くなるかもしれません。
しかし、ログを取る処理も、IIS 、ASP.NET、SharePoint フレームワークを使用します。これは余計に負荷が増大すると可能性が高く、レスポンスタイムが悪化する可能性が大いにあります。」
■ 開発チームを巻き込んで暴走
残念ながら、私の力説もむなしく、この M男の Ajax 案が検証もされることなく開発チームにて採用されようとしました。やはり “SharePoint MVP” の名札は絶大です。また、私はスケジュールに追われて別のことにあたっていて、この課題に関与できていない間隙を突いた所業です。
実際に Ajax 案のまま、マスターページにログ採取用のスクリプトが組み込まれ、ログ採取の aspx ページが作成されてデプロイされました。この時には M男は、自信たっぷりの、してやったりの表情で満足気でした。
■ 実際に検証すると妄想が打ち砕かれた
私はこのままではまずいと思い、検証をしてみることにしました。
AJAX を使用した非同期の場合と、Master Page 内にロギングを行うコンポーネントを組み込んだ場合です。時間がないので、ロギングを単純にユーザー名だけ DB に書きこむ仕様にしました。アクセスも単純に HTTP リクエストをシミュレーションするだけです。検証環境なのでパフォーマンスは同じにはならないでしょう。しかし、ロギング処理専用の Web アクセスを分割することで起こることを説明するには十分です。
平均レスポンスタイムは、パフォーマンスカウンターではなく IIS ログの time-taken で確認します。
同時アクセス数が １件 2 件の場合、目立った変化はありませんでした。
少しリクエストの並列処理数を増やすと、ロギング アクセスを分けた (Ajax) ほうが、若干早いという結果になりました。
ぐっとアクセスを多くしていくと、逆にロギングアクセスを分けないほうが、平均レスポンス時間が短くなっていました。
これは想定した通りのことが起きています。おそらく、リクエストのキュー待ちが発生すると、レスポンスが逆に悪くなります。
本題に立ち返ると、今回問題にすべきは、[ピーク時の] アクセスです。1万人以上が利用するポータルで、早朝に数千人のアクセスを想定しています。やはりこれは、単純な Ajax 案で収めるには危険すぎたと思います。これは明かなる設計ミスです。
この結果を開発チームに伝えましたが、残念ながら、すでに実装したものを後戻りしたくないとの理由で、この検証結果自体が「無かったもの」とされ、Ajax 案でリリースが決定されてしまいました。
■ 非同期設計は処理のオフロード
Ajax は処理を並列化 / オフロードする手段になります。
トータルの処理は、[ページ表示処理] + [ロギング処理] なので、処理を分けるとオーバーヘッド分だけ処理の総量は増えます。
二つの処理が別サーバーにある場合、処理不可は分散され、並列化した分だけレスポンスは短くなります。
しかしながら、同じサーバー内でロギング処理を行う場合は結果は異なります。
処理リソースが不足した状態 (上ではキュー待ち状態) になれば、並列化のメリットは無く、トータルの処理量が多くなった分だけ遅くなります。
今回の M男はこのインフラ部分というか IT の基本を押さえていなかったと言えます。
私は契約の関係上、技術支援で構築時のみの参加でしたが、リリース後には早朝にレスポンス遅延の追加対処が発生しておりました。この Ajax ロギング処理だけが原因とは限りませんが、間違いなく一因となっていた可能性はあります。