IISログをもとに性能について考えたり調べたりしたのでメモを残しておきます。
- 慢性的に性能が悪い（応答が遅い）システムがあると仮定
- システムではIISを利用と仮定（IISにこだわる必要はないけど具体性を持たす）
- IISログは入手可能、それ以外はブラックボックスとする。
- IISより先で性能悪化が起きていると仮定（IIS側のキューは滞留しない）
IISログについて
IISログファイルの場所
IIS７以降では、 inetpub\logs\Logfilesあたりにあるはず
IISログの読み方（ざっくり）
ログには、ヘッダ行と、レコードがあります。追記型なので、ヘッダ行は複数回出現しているでしょう。ヘッダ行を見れば、#Fieldとしてどのような項目をアウトプットしているかわかります。ログフォーマットをカスタマイズしている場合でも、ヘッダを見れば確認できるはずです。
IISログの読み込み
Excelで、「空白区切り」で読み込むのが手っ取り早いでしょう。他にもPythonのように分析に強い言語で取り込むのもあり。PythonだとPandas.DataFrameに読み込ませておくと何かと集計が便利ですから。
IISログを読んでいく。
HTTPステータスの傾向
ここで、500番台が多発していたら、OSレベルでおかしくなってる。メモリの使い方やCPUに負荷のかかる処理が他にないかという観点でチューニングするのがいい。例えばJavaアプリのメモリ上限を制限かけ忘れてたり、ウィルスチェック処理が悪影響だったり。他にも想定してないHTTPステータスが多い場合は設定確認を行うのがいいです。
ここでは、遅いけどレスポンスはある、、IISより先が何か起きてると仮定して話を進めます。
time–takenフィールドに着目
性能悪化を数値的に確認するには、まずこの項目を確認します。IISがユーザからの通信を受信し、結果を送信するまでの時間で、単位はミリ秒です。
このフィールドを見て、特定の時間帯で性能が遅いかどうか確認します。もしIISログ上は遅くない場合は、ネットワークがおかしいです。ネットワーク専門家に問合わせましょう。
ここでは、性能の遅いレコードが散見されることが確認できるかがポイント。早い応答のレコードも紛れているかもしれませんが、傾向を目視でいいので確認。以下データに着目します。
- 分析対象の開始・終了時間
- 分析対象時間帯のログレコード数
- 開始・終了時間における平均のtime-token
これらの数字から色々推測ができるのではないか、この記事の趣旨はそこです。
M/M/1待ち行列理論で考えてみる
実際のデータがあれば裏付けできるのですが、今手元になく…その考察は後日更新することにします。 数字は仮説でおいて理屈で考えてみます。
- 分析対象の開始・終了時間 ⇒ 9:00～10:00 とする
- 分析対象時間帯のログレコード数 ⇒ 5000件 とする
- 開始・終了時間における平均のtime-token ⇒ 30,000[ミリ秒]＝3秒 とする
つまり、当時のユーザは平均で3秒くらい待たされていたとします。あくまで平均なので、早い体感の人も、遅い体感の人もいたことだと思います。クレームが出始めるには十分遅いと思います。
さてこの数字で、M/M/1モデルに当てはめて考えてみようと思います。ググってみたけど、具体的にIISログと紐づけて検討するような記事が見つから。自分なりに考えてみます。
λ：平均到着率
「分析対象時間帯のログレコード数」という部分が該当すると考えました。
1時間で1000件としたので、1秒あたり、5000／3600＝1.34件近く到着していたことになります。
ここでM/M/1の開設で「ポアソン分布に従う」という表現を見かけますね。
これは１～２件とか0件とかバラツキはある前提だということで理解すれば納得感ある感じです。
Tr：平均応答時間
ブラウザからIISまでの経路は計測はなく、IISの受信から応答までの時間は取れてます。
「開始・終了時間における平均のtime-token 」で、3秒です。1件あたり平均3秒待つということ。
なお、平均待ち時間Twと、平均処理時間Tsの関係は、Tr ＝ Tw ＋ Tsになるということです。
性能問題を解決するということは、このTrを短くしたいので、
目標＝TwとTsのいずれか、または両方を小さくしたい
ということになります。
今回の問題では、Tw、とTsが不明瞭なので、推測したいということになります。
ρ：占有率（混み具合）、平均サービス率μ、平均処理時間Ts
さて、今回のケースの占有率を考えます。ちょっと自信ないですが、情報処理試験では下記問題が何度も出題されているので参考にしてみます。
答えは覚えてしまってますが、0.21を選ばせる問題となってます。この時の占有率ρの計算では、平均処理時間Ts=0.3ということから、1時間あたり、5000×0.3＝1500秒 が1時間で占有されたとして、ρ＝1500/3600 として計算します。
IISのログも同じ発想が使えると考えてみたいのですが、今回、平均処理時間Ts、つまりアプリケーション側の処理性能時間がわからない状況です。当初Time-tokenをTsとみなそうとも考えましたが、計算がおかしくなりました。そうですよね。。。さてどうしましょう。めっちゃほしい。
占有率ρを求めたいが、処理時間Tsに相当するものがない。逆に応答時間Trはわかっている。
ここで、今使える各種の公式をかき集めてみます。（理解は置いておいて）
- Tr＝Tw＋Ts ＝ {ρ/(1ーρ)} × Ts ＋ Ts
- Ts＝1/μ
- ρ＝λ/μ
⇒
- μがわかれば、λがわかってるので、ρがわかる。
- μがわかれば、Tsは逆数なのでTsがわかる
- μがわかれば、Trの数式が解ける。
ということで、μについての二次方程式に持ち込めばいけそう。って簡単に言ってますが、頭から煙が出そうです。
そこで、μとλの値をいれると、ρ、Tw、Ts、Trを計算するようなExcelを作ります。これなら簡単な四則演算でできます。
そして、Tr=3秒になるような、μ、ρの値を探してみることにしました。
その結果、ρ＝81%、μ＝1.71[件/秒] くらいで、Tr＝3秒くらいになりそうです。
施策を考える。
『目標＝TwとTsのいずれか、または両方を小さくしたい』です。
Ts（処理時間）を小さくしたい ということと μ（処理能力を高くしたい）は同じということです。
上記の推測でμやρが出せたので、各種数字を整理しておきます。
- λ：平均到着率＝1.34 [件/秒]
- μ：平均処理率＝1.71 [件/秒]
- ρ：混み具合＝81[%]
- Ts：平均処理時間＝0.58[秒]
- Tw：平均待ち時間＝2.49[秒]
- Tr:平均応答時間＝約3.0[秒]
性能を上げるための施策
『目標＝TwとTsのいずれか、または両方を小さくしたい』 これは変わりません。そのためにどうするかということです。思いつくところは以下。
- アプリ・データベースチューニング
- Ts（処理時間）を小さくしたい ＝ μ（処理能力を高くしたい）
- 同時処理数をチューニング
- λ（到着率）を分散させる
まずは、Tsを小さくすることを考えましょう。つまり逆数であるμ（処理能力）を上げる。データベースの応答に問題がある場合が多く、性能悪化させているキラーSQLを探してINDEXを貼ってやる手段が非常に有効。ロジックも変更せず改善できるので効果は大きいです。性能悪化のSQLは、有効なDBセッションで実行されるSQLの実行コストを監視すればよいので、比較的どのようデータベースでもやり方があるはず。
他に、アプリケーションロジックをチューニングすることが考えられますが、変更管理を検討することになり、手間もコストもかかるので応急対応には向きません。
もう一つは、同時実行数を増やす施策です。チケット売り場でいえばチケット窓口を増やすってこと。システムでいえば、アプリケーションプロセスやスレッドを増やしたり、Webサーバを増やす対応にあんります。
サーバ資源を有効に活用できてない場合は、まずはプロセスやスレッドの見直しは有効です。
サーバ資源も有効に使えてるとなると、もうサーバ性能を上げる（スケールアップ）か台数増やす(スケールアウト）するしかないです。お金が絡みますが、言い方を変えればお金で解決できる手段です。
適切な同時実行数を推測する
さて、上記施策のうち、IIS以外のところがブラックボックスでチューニングできない仮定しましょう。そうすると、同時実行を増やすということが考えられます。簡単にいえばIISから先のアプリケーションサーバの台数（アプリケーションプロセス数やスレッド数含め）を増やすということですね。どれだけ増やせばいいのか。
同時実行が増えるということの意味
同時実行が増えるということは、「λ：平均到着率」を分散できるという計算ができます。
例えば、1時間に5000件到着したものを1台ではなく、2台で対応すれば、1台あたり2500件で済むという計算とします。
おや、もしかしたら、1台目3000件、2台目2000件 となるかもしれないし、おかしいな計算です。
M/M/2モデルとするのがベターなのですが、、、このM/M/s （ｓ＝窓口数）というモデルが、sの増加に伴う数式がメチャクチャ複雑になります。（参考：複数窓口での待ち行列（Ｍ／Ｍ／ｓ））
M/M/1よりも本当はもっと効率よいのだけれど、という数値計算は、性能検討上は安全側に計算されるので、ここでは一旦、M/M/1のままで良いと割り切ることにします。
さて、上記の例で、せめてTr（平均応答時間）を1秒以下程度にしたいとすればどうすればいいか。
ρ：占有率（混み具合）＝70%以上は危険
まずは、M/M/1モデルでは、平均サービス率について指数分布を前提としています。って、なんのことかという話ですね、占有率が増えれば指数関数的に効率悪くなる、、といってもわかりにくい。
つまり、占有率は70%超えないように設計しとこう、70%超えると急に悪化するよ、ということです。
今回の場合、既にρが80%という状態。まずは、処理性能を変えずにρを70%以下にすることを考えます。同時実行を2つにして（1つ増やす）1時間あたり2500件サバくことにし、平均処理時間は同じくらいとなる設定を探します。以下のようになりました。（Excelで数字を試行錯誤して求めました）
- λ：平均到着率＝0.69 [件/秒] ←2台にしたのでここ半減
- μ：平均処理率＝1.73 [件/秒] ←処理性能は変化しないように調整
- ρ：混み具合＝40[%] ←ここを70%以下にする目的。結果的には大幅減
- Ts：平均処理時間＝0.58[秒] ←処理性能は変化しないように調整
- Tw：平均待ち時間＝0.34[秒]
- Tr:平均応答時間＝0.96[秒] ★劇的改善の予感
ここでわかるのは、アプリケーションのチューニングをしなくても、平均応答時間が1秒切るような改善となる点です。もちろん理論値なので本当にそうなるのか自信ないですが。お客様に説明する際は、1台追加でよいのか2台、3台と追加が必要な話なのか。理論武装の一つの手段とはなるのではないでしょうか。
まとめ
IISログだけから、待ち行列理論で推理できる色々な数値パラメータについて検討してみました。何かのお役に立てばうれしいです。
このブログは、将来に備えた技術力アップや資産運用を情報発信していきます。Twitterもやってますので良ければフォローしてください。 是非意見交換しましょう。
コメント