Apacheのログについて

2021年12月15日

アジェンダ
定義内容について
各出力項目の意味について
Apacheがアクセスを受け付けた時刻と処理が終了した時刻


定義内容について
一般的にWEBサーバ(Apache)のログ出力形式については、httpd.confというApache
の設定が記述されているファイルにされています。例えば、以下の形式が該当します。

---------------------------------------------------------------------------
grep -n "LogFormat" /etc/httpd/conf/httpd.conf | grep -v "#"
497:LogFormat "%h %l %u %t "%r" %>s %b "%{Referer}i" "%{User-Agent}i"" combined
498:LogFormat "%h %l %u %t "%r" %>s %b" common
499:LogFormat "%{Referer}i -> %U" referer
500:LogFormat "%{User-agent}i" agent
---------------------------------------------------------------------------
標準では上記の様になっていますので今回は、"combined"詳細なログ定義に
%D リクエストを処理するのにかかった時間、マイクロ秒単位と
%t リクエストを受付けた時刻。 CLF の時刻の書式 (標準の英語の書式)を組み合わせて
受付時刻と処理終了時刻について説明していきます。

各出力項目の意味について
実際に詳細ログ設定に%Tを追加すると下記のようになります。

---------------------------------------------------------------------------
LogFormat "%h %l %u %t %T %D "%r" %>s %b "%{Referer}i" "%{User-Agent}i"" combined
---------------------------------------------------------------------------
これの各、項目についてまず説明していきます。(箇条書き)
    %h リモートホスト
    %l リモートログ名 これは、IdentityCheck ディレクティブが On に設定されていない限り、 - になります。
    %u 認証ユーザー Authuser名 認証がないときは、 - になる。
    %t リクエストを受付けた時刻(Apacheがアクセスを受け付けた時刻)
    %T リクエストを扱うのにかかった時間、秒単位
    %D リクエストを扱うのにかかった時間、マイクロ秒単位(Apacheがリクエストを受け付けて処理が終了した時刻)
    %r リクエストの最初の行("GET /motion.html HTTP/1.1")
    %s ステータスコード
    %b レスポンスのバイト数(コンテンツサイズ)
    %{Referer}i リファラ(アクセス元) サーバに送られたリクエストヘッダ内容 設定されていないときは - となる。
    %{User-Agent}i ユーザーエージェント サーバに送られたリクエストヘッダ内容(Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit ...)
    combined ログ定義名
Apacheがアクセスを受け付けた時刻と処理が終了した時刻
    実際のログ出力を例にアクセスを受け付けた時刻と処理が終了した時刻を見ていきます。
---------------------------------------------------------------------------
***.***.***.*** - - [30/Mar/2019:13:15:58 +0900] 0 170474 "GET / HTTP/1.1" 200 322550 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/73.0.3683.86 Safari/537.36"
---------------------------------------------------------------------------

このアクセスログを例に取ると以下の様になります。
---------------------------------------------------------------------------
アクセスを受け付けた時刻:30/Mar/2019:13:15:58
処理が終了した時刻   :170474 = 170ミリ秒後処理が完了した
---------------------------------------------------------------------------