Awk のTips...
FTPデーモンのログ出力を取り出す
(2001.07.11)

概要

　「定型データの料理法」のひとつ。

解説

　ftpデーモンによってログのフォーマットは異なる可能性がありますが、 たとえばSolaris標準のftpデーモンはこんな感じになっています。 （なお、このログは、ftp起動時のコマンド行オプションでログ採取を 指定した上、/etc/syslog.confの設定をちょっと変えないと記録するこ とはできません）

May 31 10:11:12 host ftpd[446]: FTPD: connection from somewhere at Thu May 31 10:11:12 2001
May 31 10:11:12 host ftpd[446]: <--- 220
May 31 10:11:12 host ftpd[446]: host FTP server (SunS 5.6) ready.
May 31 10:11:12 host ftpd[446]: FTPD: command: USER nulpleno
May 31 10:11:12 host ftpd[446]: <--- 331
May 31 10:11:12 host ftpd[446]: Password required for nulpleno.
May 31 10:11:12 host ftpd[446]: FTPD: command: PASS
May 31 10:11:12 host ftpd[446]: <--- 230
May 31 10:11:12 host ftpd[446]: User nulpleno logged in.
May 31 10:11:12 host ftpd[446]: FTPD: command: CWD /tmp

　こういう出力がひとつのファイルにどどどどと書き込まれるわけです。 []の中にある446とかいうのが、セッションごとに起こされるプロセス のプロセスIDです。FTPデーモンは「マルチスレッド」ですから、接続 要求があるたびにプロセスを起こしてそいつがセッションの面倒を見る んですが、てことは、実際のログは上のログのようにきれいではなく、 さまざまなプロセスIDのデーモンからの出力が入り乱れることになりま す。

　こういうログをそのまま眺めるのは、非効率。ここはやはり一念発起 してちょっとしたツールを書き、後の作業をラクにするべきでしょう。 「今日の10円は明日の100円となって帰ってくる」と、古代ローマの哲 学者も言っています(うそ)。

　そういえば、「ＩＴ時代」の前に栄えていた「パソコン通信時代」で は、BBSの書き込みを履歴「ログ」などと言っていて、「ログカッター」 なるソフトウェアが主としてフリーウェアで出回っていました。これも、 それとは意味合いが違うけれども、ログカッターと言えるでしょう。

やっつけ方その1

　プログラミングに関する古代ローマの格言に「ひとりで全部やろ うとすんな」というのと、「入力データの特徴をよく見ろ」 「入力データを正規化しろ」というのがあります。

　データベースが浸透しきった現在では「正規化」というと「スキーマ の正規化」を想像する人が多いかも知れませんが、大げさなことではな く、プログラム上、できるだけ条件分岐が少なくなるようにデータ を整えろということです。たとえば、FTPデーモンのログ出力がほ かの種類のログと混ざっているような状況はデータ処理には面倒なだけ ですから、できるなら「FTPデーモン専用のログファイル」を作ってし まえば都合がいいわけです。不幸なことに、Solarisではこういう風に 処置することはできなさそうですが。

　そこで、FTPデーモンのログに目を向けると、必ず"ftpd"という文字 列が含まれることが判ります。ならば、第一段階としてログファ イルからFTPデーモンのログだけ切り出してしまえればいい。そうすれ ば、第二段階以降では確実にFTPデーモンのログだけを相手にすればい いことになります。

　「ひとりで全部やろうとすんな」。さすが、古代ローマのプログラマー はよく判っていました。「入力の中から特定の文型(パターン)だけ抽出 する」なら、Unixではgrepというコマンドがうってつけです。

コード

grep 'ftpd' ${LOG_FILE} > ${FTP_LOG_TMP}

やっつけ方その2

　FTPデーモンのログだけ取り分けられたら、次には、「FTPセッション ごとにログをまとめる」ということが必要になるでしょう。

　ここで、「お、ソートするの？　プロセスIDでソートするのね？」と 考え出すと、古代ローマのプログラマーが「ことをいたずらに複雑 に考えんな」と指摘する状態に陥ります。全体をソートする必要は あまりないので、ファイルの先頭からプロセスIDごとに行を取り出して あげればよろしい。そのファイルにプロセスID 200と400と800のログが 含まれているなら、まず200の行を全部拾い出して集め、次に400、最後 に800を集めれば、目的は達成できます。

　これはよいアイデアですが、問題がひとつあって、「抽出するために はプロセスIDを知らなければならないけど、どうやって知るの？」とい うことです。ふむ。知らなければならんのなら、知ればよろしい。

コード

  1: BEGIN{
  2: 　　　　# PIDを取り出しやすくするために、欄区切子を[]にする
  3: 　　　　FS="[\\[\\]]"
  4: 　　　　saved_pid = ""
  5: 　　　　n = 0
  6: }
  7: 
  8: $2 != saved_pid{
  9: 　　　　if(! already_appeared($2)){
 10: 　　　　　　　　pids[n++] = $2
 11: 　　　　}
 12: 　　　　saved_pid = $2
 13: }
 14: 
 15: END{
 16: 　　　　for(i = 0; i < n; i++){
 17: 　　　　　　　　printf("%d ", pids[i]);
 18: 　　　　}
 19: }
 20: 
 21: function already_appeared(pid)
 22: {
 23: 　　　　for(i = 0; i < n; i++){
 24: 　　　　　　　　if(pids[i] == pid){
 25: 　　　　　　　　　　　　return 1
 26: 　　　　　　　　}
 27: 　　　　}
 28: 　　　　return 0
 29: }

　このプログラムを先に作ったFTPデーモンのログだけが含まれている ファイルに対して走らせれば、プロセスIDが出力されます。シェルを 使えばこの出力をシェル変数に取り込むのは簡単なことで、

pids=`awk -f above_mentioned_program ${FTP_LOG_TMP}`

などとすればイッパツです。

やっつけ方その3

　プロセスIDを拾い上げたら、それをキーにして、いよいよ「FTPセッ ションごとにログをまとめる」ということをすればいい。これはもう、 「すればいい」としか言えないほどに簡単な作業ですね。

コード

  1: BEGIN{
  2: 　　　　# やはり欄区切子を[]にする
  3: 　　　　FS="[\\[\\]]"
  4: }
  5: 
  6: $2 == pid{
  7: 　　　　print
  8: }

　ここで気をつけなければいけないのは、$2と比べているpidです。こ れはAwk的には変数ですが、上のプログラムのどこにもこの変数に値を 代入している箇所がありません。

　実はAwkには、プログラム呼出時にコマンド行上で変数に値を代入す ることができます。Awkの版によって形式が異なるようですが、基本的 にはvar=valueという形です。

　これを含めて、このプログラムの呼出形式を書くと、こんな感じです。

  1: for pid in $pids
  2: do
  3:   awk -f the_program pid=$pid ${FTP_LOG_TMP}
  4: done

補足

　上のその1〜3のプログラムを適宜組み合わせれば、最終的に「FTPデー モンのログを、FTPセッション単位に切り出す」ということができます。 もうちょっと加工したい、たとえばセッションの全記録ではなくて接続 してきたユーザー名と特定のコマンドだけ判ればいい、という要望があ れば、その3の出力をさらにパイプでつないでそのような抽出を行なう プログラムに食わせれば、簡単に実現できます。

(2001.07.11)