Access_Logについてちょこっとだけ考えた

ApacheのAccess_logが一体どのタイミングで記録されてるのかな〜ということを予想をすると、ウェブサーバーにリクエストが届いた時かな?!
と思いがちです。思いがちと言いますか、そう思っていました。

この実験に先立ってTCPのTime_wait値をめっちゃ短くしてやろうと思いましたが、TCPの設定変更はKernelのリビルドが必要だったのでやりません!実験と言っても、とってもとっても簡単な方法でやります。
最初はSynFloodのプログラムを拾ってきて弄ってみて、TCPの接続ごとのケースを試してみようかな?なんていう調子に乗った事を考えましたが、ずいぶんと時間がかかりそうなので今回はやめておきます。
だけど面白そうなのでまた別の機会にこの辺については実験をやりたいな〜と思います。

では本題に。

方法とは、Telnetでリクエストを出さずに放置します。
これだと残らないと思うでしょ?
ところがどっこいなんだ。
Establishedになるし、Access_logにも残ります。

ではさっそくですが実験に入ります。
ウェブサーバーはまずはnetstatで状態を確認してみましょうか。
Access_logは後のお楽しみで。

ではTelnetしてみます。


root@deb:/home/user# telnet 相手のサーバ http
Trying 相手のサーバ ...
Connected to 相手のサーバ.
Escape character is '^]'.

Telnetが上のような状態だと、まずはウェブサーバー側の状態はSYNを受け取った状態が続きます。
ちなみにSSHやSMTPなどはすぐにサービスの方が応答するのでいきなり(ではないけど)Establishedとなります。

tcp      SYN_RECV
tcp      SYN_RECV
tcp      SYN_RECV
tcp      SYN_RECV

しばらくすると接続が確立されるのです。
Telnetの方は変化はなくって、今はApacheがクライアントからのリクエストを待つ待機時間と思われます。

tcp   SYN_RECV
tcp   SYN_RECV
tcp   ESTABLISHED
tcp   ESTABLISHED
tcp   ESTABLISHED

そして放置を続けるとそのうちTIMEOUTします。
TelnetはConnectionがCloseされます。

Escape character is '^]'.
Connection closed by foreign host.
tcp      ESTABLISHED
tcp      ESTABLISHED
tcp      ESTABLISHED
tcp      TIME_WAIT
tcp      TIME_WAIT
tcp      TIME_WAIT
tcp      TIME_WAIT
tcp      TIME_WAIT
tcp      TIME_WAIT
tcp      TIME_WAIT

Access_logはこのTime_waitになったところで記録されます。

どんなログか見てみます。

[07/May/2015:18:49:49 +0900] "-" 408 -

・・・

408ってなんでしょうか。

408 Request Timeout タイムアウト  1.1
クライアントは、サーバの待機時間内にリクエストを発行しなかった。

サーバの待機時間内にリクエストを発行しなかった。

nandate

そうなんです。
リクエストを発行しなかった。というログが残ります。

怒らないでね。

Similar Posts:


Leave a Reply

Your email address will not be published. Required fields are marked *