WebSurfer's Home

トップ > Blog 1   |   ログイン
APMLフィルター

IIS ログの time-taken

by WebSurfer 2016年7月1日 14:39

IIS のログの中に time-taken という項目があります。具体的にいつからいつまでの時間かについて調べたのですが、その過程でいくつか発見があったので備忘録として書いておきます。

リクエスト処理の流れ

上の図は IIS7 がブラウザから要求を受けて応答を返すまでの流れを示しています。この図で time-taken はいつからいつまでになるかを簡単に書くと、上の図の ② で HTTP.sys が要求の最初のバイトを受け取ってから、⑨ で要求に対する最後の応答を返すまでとなります。

それに加えて、IIS6 からは最後のパケットに対するクライアントからの ACK を受け取るまでが time-taken に含まれるようになったとのことです。

詳しくは以下の Microsoft Support KB944884 の記事を見てください。

Description of the time-taken field in IIS 6.0 and IIS 7.0 HTTP logging

タイトルが "IIS 6.0 and IIS 7.0" となっていますが、IIS7.5 以降も同じだと思います。また、また例外の "TCP buffering is used" は ASP.NET Web アプリには関係なさそうです(公式文書などで裏は取れていませんが、この記事の下の方に書いた報告などからも ASP.NET でバッファを有効にしているとは考えにくいです)。

Microsoft の別の記事(例えば、Default Log File Settings for Web Sites とか W3C Logging)に "Time taken does not reflect time across the network" と書いてあるものもありますが、古い記述のままで修正がされてないものと思われます。

というわけで、今回分かったことを箇条書きにすると以下の通りです:

  1. time-taken は上の図で ② から ⑨ までの時間。
  2. 通常、一番最初の要求を受けてワーカープロセスを起動・初期化しログファイルを開くという操作が行われる。なので、一番最初の要求では time-taken はその分長くなる。
  3. IIS6 以降では上に紹介した KB944884 の記事に書いてあるように network time も time-taken に含まれる。それゆえ、サイズの大きなファイルを遅いネットワークでダウンロードしたりすると time-taken の値は予想よりかなり大きくなることがある。
  4. トレース情報で調べられる時間やプログラムで Stopwatch などを使って調べられる時間は上の図の ⑦ から ⑧ までの範囲内なので、当然 time-Taken の方が長くなる。

上記 3 すなわち「network time も time-taken に含まれる」を裏付けるような、time-taken の値が executionTimeout を越えているとか、プログラムのコードで実際に計った時間よりはるかに長いという報告を stackoverflow に見つけましたので、参考にリンクを張っておきます。

In our IIS logs, why do requests last 5 min and longer when executionTimeout is 110 seconds?

Difference in time-taken in IIS and ASP.NET

Tags: , ,

Windows Server

基本認証

by WebSurfer 2015年11月23日 14:19

IIS7 で基本認証を行う際のブラウザとサーバーのやり取りを調べましたので備忘録として書いておきます。

基本認証のやり取り

上の画像は IIS7 と IE9 で基本認証を行った場合の要求 / 応答を Fiddler2 でキャプチャしたものです。

  1. 最初の要求に対してはサーバーから応答ヘッダに WWW-Authenticate: Basic realm="xxx" を含む HTTP 401 応答が返ってきます。上の画像の #2 がそれです。xxx には IIS7 の場合ホスト名が入ります。
  2. ブラウザはそれを受けてユーザーに[ユーザー名]と[パスワード]の入力を促すダイアログを表示します。
  3. ユーザーがダイアログに[ユーザー名]と[パスワード]を入力して[OK]ボタンをクリックすると、ブラウザは 1 で要求したページを再度 GET 要求します。上の画像の #3 がそれです。
  4. その際、ブラウザは認証用のヘッダ Authorization: Basic UGFwaWt...(上の画像で赤枠で囲った部分を見てください)をサーバーに送ります。UGFwaWt... の部分は[ユーザ名]と[パスワード]をコロン ":" でつなぎ Base64 でエンコードしたものです。
  5. サーバーはこのヘッダを見てユーザーを認証し、HTTP 200 ステータスコード(成功)と共に要求されたコンテンツをブラウザに送信します。
  6. これ以降、ユーザーがブラウザを閉じない限りホスト名 xxx に対しては認証用のヘッダ(画像で赤枠で囲ったものと同じ)が要求ヘッダに含まれて送信され、要求のたび自動的に認証が行われるようになります。上の画像の #4, #5 がそれです。

以上、基本認証でのブラウザとサーバーのやり取りを簡単にまとめてみました。

フォーム認証と Windows 認証の場合は、それぞれ先の記事「Forms 認証のログイン・ログオフ動作」と「非ドメインユーザーの誘導」に書きましたので興味がありましたら見てください。

Tags: ,

Authentication

IIS 基本認証と資格情報のキャッシュ

by WebSurfer 2015年5月27日 16:15

IIS で基本認証を使用している場合、パスワードの変更をした後も、依然として古いパスワードが有効になる(すなわち、新旧パスワードのどちらでもログインできる)という話を書きます。

IIS 基本認証

基本認証はあまり使われてないようなので、ここに書いたような問題に遭遇することはまれかもしれませんが、理由と対処方法を調べたので備忘録として書いておきます。

まず、理由ですが、Microsoft の TechNet の記事 IIS Insider の「パスワードの変更をした後も、依然として古いパスワードが有効となる」のセクションに書いてあるように、"ユーザーのログオン資格情報は、基本認証および匿名認証の両方で、IIS 上に 15 分間キャッシュされます" ということによります。

キャッシュするのはパフォーマンスの向上のためですが、何らかの事情でデフォルトの 15 分は長すぎるという場合は調整は可能です。

具体的には、Microsoft サポートの記事 IIS におけるユーザー トークンのデフォルトの間隔の変更 に書いてありますように、レジストリで変更することができます。

上の記事は IIS6 以下が対象ですが、ブログの記事 List of registry keys affecting IIS7 behavior の 3. 項によると、レジストリ UserTokenTTL の設定については IIS7 に関しても同じとのことです。

実際、IIS7.5 を使っているユーザーがレジストリに UserTokenTTL を新規登録(既存ではないとのこと)したところ、キャッシュの有効期限をコントロールできるようになったという報告があります。

ただし、一番上に紹介した記事に書いてありますように、"キャッシュが存在しない場合、すべてのアクセスで、認証を行う必要があり、パフォーマンスが大幅に低下する可能性があります" とのことですので、あまり短くするのは避けた方がよさそうです。

Tags: , , ,

Authentication

About this blog

2010年5月にこのブログを立ち上げました。その後 ブログ2 を追加し、ここは ASP.NET 関係のトピックス、ブログ2はそれ以外のトピックスに分けました。

Calendar

<<  2017年2月  >>
2930311234
567891011
12131415161718
19202122232425
2627281234
567891011

View posts in large calendar