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 クライアントは、サーバの待機時間内にリクエストを発行しなかった。
サーバの待機時間内にリクエストを発行しなかった。
そうなんです。
リクエストを発行しなかった。というログが残ります。
怒らないでね。
