@1993__LISA__Automated System Monitoring and Notification With Swatch

# Automated System Monitoring and Notification With Swatch > [!abstract] 概要(abstract の日本語訳) > 本論文は、多数のサーバとワークステーション上のイベントを監視するアプローチを記述する。現代の UNIX システムはハードウェアとオペレーティングシステムソフトウェアの健全性・状態に関する多様な情報をログできる能力を持つが、一般にそのように設定されていない。この情報がログされている場合でも、それはしばしば定期的に監視されない場所や、侵入に成功した者による削除・改変を受けやすい場所に隠されている。また、システム管理者はしばしば数十台に及ぶ複数のシステムを監視しなければならない。これらの問題に対処するため、我々のアプローチはまず特定のシステムプログラムを改変してそのログ能力を強化することから始まる。加えて、我々のアプローチは、これらの各システムのログ機能を、重要なシステム情報とセキュリティ関連情報のコピーを、信頼できる安全な中央ログホストシステムへ送るように設定することを求める。予想されるとおり、この中央ログは1日に1メガバイト以上のデータを見ることになる。システム管理者が大量のデータに圧倒されないようにするため、我々は容易に設定可能なログファイルフィルタ/モニタである swatch を開発した。swatch はログファイルを監視し、不要なデータをフィルタで除去し、ログ中のパターンに基づいて1つ以上のユーザ指定アクション(ベルを鳴らす、メールを送る、スクリプトを実行する等)を実行する。 ## 論文情報 - タイトル: Automated System Monitoring and Notification With Swatch - 著者: Stephen E. Hansen, E. Todd Atkins(Stanford University, Electrical Engineering Computer Facility) - 媒体: Proceedings of the Seventh Systems Administration Conference(LISA '93), USENIX Association, Monterey, CA, 1993-11-01〜11-05(掲載ページ 145–152) - URL: https://www.usenix.org/conference/lisa-93/automated-system-monitoring-and-notification-swatch - ソフトウェア: swatch(Simple WATCHer)。当時、匿名 FTP で Sierra.Stanford.EDU の pub/sources から配布されていた。 ## 概要 Stanford 大学 Electrical Engineering Computer Facility(EECF)の著者らが、十数台のファイル/CPU サーバと 50 台超のクライアントマシンからなる環境で、システムのログ生成能力の強化・syslog による中央ログ集約・パターンベースの自動フィルタ/通知ツール swatch という 3 段構えの監視パイプラインを実運用した経験を報告する論文である。ログの取得(1)・集約(2)・選別と通知(3)を分離した設計として整理でき、(3) を担う swatch がこの論文の主要な貢献である。 ## 問題設定 - **前提**: 標準の UNIX システムは、システム管理者が健全性を把握する助けをほとんど行わない。多くのサイトでは、ログ情報は「事後の post-mortem のための記録」として扱われ、平時の運用管理のためのツールとしては使われていない。 - **入力**: 各サーバ・ワークステーションが生成する syslog メッセージ(カーネル、デーモン、各種ユーティリティ由来)。 - **出力**: 望ましくは、重大なイベント発生時のシステム管理者への即時通知(ベル、メール、ページャ呼び出し、スクリプト実行等)であり、かつ大量の非重要メッセージによる圧倒を避けること。 - **規模感**: EECF の中央ログホスト(LOGMASTER)は、sendmail のステータスメッセージを除いてもなお1日あたり約1メガバイトの syslog メッセージを受け取る。sendmail のステータスメッセージは1ホストのログ全体の 50%(多い場合は 90%)を占めるため、サーバ側に残し LOGMASTER には送らない設計にしている。 ## 提案手法 - **(1) ログ生成能力の強化**: fingerd・ftpd・ruserok・rshd・login の各プログラムを改変し、接続元ホスト・試行ユーザ名・コマンド等をより詳細に syslog へ報告させる(Table 1、本ページに転記)。login はログイン試行回数を3回に減らし、`Incomplete Login Attempt`・`Repeated Login Attempt`・`Root Login Refused` を syslog に報告するよう改変されている。tcp wrapper(Wietse Venema 作)も接続情報の syslog 出力源として併用する。 - **(2) syslog による中央集約**: 各サーバは `/var/log/syslog` に自ホストのログを保持しつつ(日次ローテーション・圧縮・約1週間保存)、健全性・セキュリティに関わるメッセージを中央ログホスト LOGMASTER へ転送する。Appendix A(本ページ末尾に転記)は転送設定を含む `/etc/syslog.conf` の実例である。集約の利点として、(a) 元ホストのログが破壊・改竄されても中央側の記録が保全される冗長性、(b) 複数システム・複数ユーティリティの情報を時系列順の単一ファイルへ集めることで、単独では見逃される攻撃パターン(複数ホストにまたがる連続した不正ログイン試行等)を発見しやすくする点、の2つを挙げる。 - **(3) swatch によるパターンマッチ通知**: 中央ログを人手で `egrep` により継続監視するのは非現実的であるという判断から、swatch(Simple WATCHer)を設計した。設計目標は次の4点: ① 数分で使い方を習得できる設定方式であること、② 受信情報に対して実行できる単純なアクション集合を持つこと、③ ユーザが独自アクションを定義でき、入力の一部を引数として使えること、④ 実行中でも停止・再起動なしに再設定できること。 - **設定ファイル形式**(Figure 1、本ページに転記): 各非コメント行はタブ区切りの4フィールド(パターン式、アクション、時間間隔、タイムスタンプ位置)からなる。パターンはカンマ区切りで複数指定でき、Perl の正規表現(egrep に近い)を用いる。 - **アクション**: echo(制御端末へのエコー表示、モード指定で通常/太字/下線/点滅/反転が選べる)、bell(ベル信号、回数指定可)、ignore(以降の処理をスキップ。より一般的なパターンより先に無視したい行を弾くのに使う)、write/mail(該当行をユーザリストへ write/mail コマンドで送信)、pipe(マッチ行を別コマンドへの入力として使う)、exec(マッチ行のフィールドを `$N`(N番目のフィールド)や `$0`/`$*`(行全体)として引数展開しコマンドを実行)。 - **時間間隔とタイムスタンプ**: 同種メッセージの連投(例: file system full が1分間に数十件)を抑制するため、時間間隔(HH:MM:SS)を指定すると、その間隔内の重複通知を間引く。タイムスタンプ位置は、ログ内の時刻表記を履歴リストとの比較のために取り除く目的で、時間間隔指定時のみ併用できる。 - **制御プログラムの実装**: swatch は Perl(Awk・C に似た文法と当時の管理者への普及を理由に採用)で書かれ、設定ファイルを一度 Perl スクリプト(watcher)へトランスレートしてから fork/exec する。watcher は SIGALRM・SIGHUP を受けると現在の watcher を終了し設定ファイルを読み直して新しい watcher を起動する(無停止の再設定)。SIGQUIT・SIGTERM・SIGINT を受けるとクリーンアップして終了する。 - **3通りの起動モード**: ① `-t` でログファイルへの `tail` 相当の追記監視(既定は `/var/log/syslog`)、② `-f` でファイル全体を1回だけ読み切るバッチモード(不在期間のログの事後点検に使う)、③ `-c`/`-p` で他プログラムの標準出力(例: `lastcomm`)を監視する。 ## 新規性 - 当時(1993年)、UNIX の syslog は事後のデバッグ用途として使われるのが一般的であり、本論文はそれを「継続監視とリアルタイム通知」のためのパイプラインへ転用する具体的な設計(ログ強化 → 中央集約 → パターンマッチ通知)を、実運用経験に基づいて提示した点に新規性がある。 - swatch の設定ファイルは、パターン・アクション・時間間隔・タイムスタンプ位置という宣言的な4フィールド形式を採り、時間窓による重複通知の抑制(現代のアラート抑制・重複排除に相当する発想)を1993年時点で導入している。 - 実行中の無停止再設定(SIGHUP による設定リロード)や、マッチ内容をコマンド引数へ展開する `exec` アクションなど、後年のログ監視・アラーティングツールに共通する設計要素を早期に実装している。 ## 実験設定本論文は定量的な比較評価やベンチマークを行う研究論文ではなく、Stanford 大学 EECF における実運用経験の報告(experience report)である。定量的に述べられている数値は次の観察に限られる。 - LOGMASTER が受け取る syslog メッセージ量: sendmail のステータスメッセージを除いても約1メガバイト/日。 - sendmail のステータスメッセージが1ホストのログに占める割合: 通常 50%、最大で 90%。 - 個人設定ファイル(Figure 3)の実運用例(Figure 4)として、6時間・2300行超の syslog 入力に対する swatch の出力サンプルが示される。 ## 実験結果 - Example 1(常時稼働の背景監視、Figure 2 に設定例)では、"file system full"・"panic"・"reboot"・不正ログイン試行(`INVALID`/`REPEATED`/`INCOMPLETE`)等の高優先度イベントを検知し、メール送信とページャ呼び出しスクリプト(`call_pager`)の実行を組み合わせて通知する。パターンには5分間隔の重複抑制を設定し、"file system full" のような1分間に数十件出るメッセージの通知を数百件から実用的な件数へ削減できたと報告する。 - Example 2(個人ウィンドウでの対話的監視、Figure 3・4)では、著者個人が興味を持つイベント(fingerd による自分宛のプローブ、`su` の失敗、無効ログイン試行、tftp の異常アクセス等)を echo/bell アクションでフォアグラウンドウィンドウに表示する設定を示す。 - 運用結果として、著者らは「侵入者が複数システムをプローブしている事例を、中央集約とswatchがなければ見逃していたはずの状況で複数回検知できた」「週末や深夜の空調故障によるシステム停止を、実際のシステムクラッシュに至る前に防げたことが数回あった」と述べる。 ## 考察 - **強み**: ログ生成強化・中央集約・パターンマッチ通知という3層構成を、実運用データに基づいて設計・チューニングした具体的な事例研究である。設定ファイルの4フィールド形式と時間間隔による抑制は、単純ながら実効性のある設計として提示されている。 - **限界・課題(著者自身が明記)**: sendmail・ntp・ypserv・xdm・xlogin 等、追加のユーティリティのログ能力強化がまだ必要だと述べており、swatch 自体への大きな変更は他サイトからのフィードバックを集めてから行う方針を示す。定量評価は EECF 単一サイトの運用経験に基づくものであり、他環境への一般化可能性や誤検知率・見逃し率についての体系的な測定は行われていない。 ## 強み / 弱点・課題 - **Strengths**: パターン・アクション・時間間隔・タイムスタンプという小さな宣言的語彙で「継続的なログ監視から人手に依存しない通知」までを実現し、Perl による実装(設定ファイル→ Perl スクリプトへのトランスレート)とシグナルによる無停止再設定という、当時としては実装上も簡潔な設計を選んでいる。 - **Weaknesses/Limitations**: 単一サイト(Stanford EECF)の運用経験に基づく報告であり、定量的な効果測定(誤検知率・見逃し率・通知遅延等)は行われていない。パターンは人手で書く正規表現に依存しており、未知のパターンやログフォーマットの変化には追従できない。 ## Appendix A: syslog 設定ファイルの実例論文付録に掲載された `/etc/syslog.conf` の抜粋。LOGMASTER(loghost)への転送設定を含む。 ``` *.err;kern.debug;auth.notice;user.none /dev/console *.err;kern.debug;daemon,auth.notice;mail.crit;user.none /var/adm/messages lpr.debug /var/adm/lpd-errs *.alert;kern.err;daemon.err;user.none root *.emerg;user.none * ifdef(`LOGHOST', auth.notice /var/log/authlog daemon.info;auth.notice;mail.debug;kern.debug /var/log/syslog *.err;daemon.none;mail.none;kern.none;auth.none;user.none /var/log/syslog ) ifdef(`LOGHOST', user.alert /var/log/syslog ) ifdef(`LOGHOST', , user.err /dev/console user.alert root ) *.info;kern.none;mail.none @logmaster kern.debug;mail.err @logmaster ``` (Source: Appendix A, p.151–152) ## 図表(テキストとして再現) 論文の Figure 1〜4・Table 1 はいずれも本文中に直接組版されたテキスト(設定ファイル・出力ログの抜粋)であり、ラスター/ベクター画像としては存在しない(PDF から抽出できる埋め込み画像は USENIX ロゴ1点のみで、本文参照がないため図表として扱わない)。以下、原文の体裁のまま転記する。 **Table 1: List of logging enhancements made to several system programs.** | Program | Logging Enhancements | |---|---| | fingerd | Reports the originating host and the finger target(s) to syslog. | | ftpd | Reports originating host to syslog. Reports file transfers to a local log file along with the local user name and, if the user is "anonymous", the password. | | ruserok | Used by rshd and login when called by rlogind. Disallows and reports to syslog any attempts to use a /etc/hosts.equiv or ~/.rhosts file that contains a '+'. | | rshd | Reports the access status, local user, remote user and host, and the command issued to a local log file. | | login | Reduced number of tries to three. Reports to syslog on 'Incomplete Login Attempt', 'Repeated Login Attempt', and 'Root Login Refused'. Includes the account names attempted and the originating host. | (Source: Table 1, p.145) **Figure 1: Format of pattern action line for a Swatch configuration file.** ``` /pattern/[,/pattern/,...] action[,action,...] [ [ [ HH:] MM:] SS [ start:length ] ] ``` (Source: Figure 1, p.147) **Figure 2: Swatch configuration file for continuous monitoring** ``` # # Swatch configuration file for constant system monitoring in the background # # Test the pager every once in a while /test pager/ exec="/etc/call_pager 5551234 123" # # Bad login attempts /INVALID|REPEATED|INCOMPLETE/ exec="/etc/backfinger $0" # # EECF /EE-CF.*(panic|halt)/ mail=action,exec="/etc/call_pager 5551212 0911" 05:00 0:16 /EE-CF.*reboot/ mail=action,exec="/etc/call_pager 5551212 0411" 05:00 0:16 /EE-CF.*SunOS Release/ mail=action,exec="/etc/call_pager 5551212 0411" 05:00 0:16 /EE-CF.*file system full/ mail=action,exec="/etc/call_pager 5551212 0611" 05:00 0:16 # # Sierra /Sierra.*WizMON/ mail=action,exec="/etc/call_pager 5551234 1666" 05:00 0:16 /Sierra.*(panic|halt)/ mail=action,exec="/etc/call_pager 5551234 1911" 05:00 0:16 /Sierra.*reboot/ mail=action,exec="/etc/call_pager 5551234 1411" 05:00 0:16 /Sierra.*SunOS Release/ mail=action,exec="/etc/call_pager 5551234 1411" 05:00 0:16 /Sierra.*file system full/ mail=action,exec="/etc/call_pager 5551234 1611" 05:00 0:16 ``` (Source: Figure 2, p.148) **Figure 3: Personalized swatch configuration file** ``` # # Personal Swatch configuration file to be run in a window on a workstation # # These probes should be harmless, but who knows? # /fingerd.*(root|[Tt]ip|guest|atkins)/ echo,bell,exec="/bin/date >> /home/atkins/tmp/finger.log",exec="/usr/local/etc/backfinger @$6 >> /home/atkins/tmp/finger.log" # # This should never happen /su: atkins/ echo,bell /su: .* failed/ echo,bell=3 /[dD]enied/||/DENIED/ echo=boldunderline,bell # Alert me of bad login attempts and find out who is on that system /INVALID|REPEATED|INCOMPLETE/ echo=underline,bell=3 # Important program errors /LOGIN/ echo=boldunderline,bell=3 /passwd/ echo=bold,bell=3 /ruserok/ echo=bold,bell=3 # Ignore this stuff /sendmail/,/nntp/,/xntp|ntpd/,/faxspooler/ ignore # Report unusual tftp info /tftpd.*(ncd|kfps|normal exit)/ ignore /tftpd/ echo,bell=3 # Kernel problems /(panic|halt|SunOS Release)/ echo=blink,bell 3:00 0:16 /file system full/ echo=bold,bell=3 5:00 0:16 # Try to ignore uninteresting kernel messages /vmunix.*(at|on)/ ignore /vmunix/ echo,bell 1:00 0:16 ``` (Source: Figure 3, p.149) **Figure 4: Output from swatch using the configuration file in Figure 3 over the course of 6 hours and more than 2300 lines of input** ``` Sep 13 05:07:23 Sierra vmunix: ie0: no carrier Sep 13 07:32:07 Sierra ftpd[17910]: FTP LOGIN FROM thermo-amy.Stanford.EDU [36.65.0.83], eaton Sep 13 07:35:58 Sierra ftpd[18015]: FTP LOGIN FROM thermo-amy.Stanford.EDU [36.65.0.83], eaton Sep 13 07:58:30 gloworm login: INCOMPLETE LOGIN ATTEMPT ON ttyp2 FROM deis17.cineca.it Sep 13 08:15:35 loading-zone.Stanford.EDU vmunix: /loading-zone: file system full Sep 13 08:15:35 stjames vmunix: NFS write error: on host loading-zone remote file system full Sep 13 08:53:25 Sierra login: REPEATED LOGIN FAILURES ON ttypb FROM uwmfe.neep.wisc.edu: help, newuser, d Sep 13 09:26:59 Sierra su: 'su root' failed for quinn on /dev/ttyp9 Sep 13 09:45:04 espresso.Stanford.EDU login: ROOT LOGIN ttyp0 FROM coffee Sep 13 10:04:50 Gordon-Biersch vmunix: pid 16100: killed due to swap problems in exec: I/O error mapping pages Sep 13 10:05:20 Sierra ftpd[21910]: FTP LOGIN FROM thermo-amy.Stanford.EDU [36.65.0.83], eaton Sep 13 10:06:25 Gordon-Biersch vmunix: /tmp: file system full, anon reservation exceeded Sep 13 10:06:43 Gordon-Biersch vmunix: pid 16118: killed due to swap problems in exec: I/O error mapping pages Sep 13 10:07:02 Gordon-Biersch vmunix: pid 16124: killed due to swap problems in exec: I/O error mapping pages Sep 13 10:09:34 Sierra ftpd[22085]: FTP LOGIN FROM thermo-amy.Stanford.EDU [36.65.0.83], eaton Sep 13 10:33:55 Gordon-Biersch fingerd[16484]: pudleys.Stanford.EDU (36.2.0.92.1654) -> "atkins" Sep 13 11:35:13 espresso.Stanford.EDU vmunix: SunOS Release 4.1.1 (ISL_CLIENT) #1: Mon Jan 13 08:58:58 PST 1992 Sep 13 11:54:22 espresso.Stanford.EDU vmunix: rebooting... Sep 13 11:56:50 espresso.Stanford.EDU vmunix: zs3: silo overflow Sep 13 12:06:05 Sierra ftpd[28258]: FTP LOGIN FROM vali.Stanford.EDU [36.59.0.32], fanning Sep 13 12:11:10 Sierra ftpd[29236]: FTP LOGIN FROM me-bradshaw.Stanford.EDU [36.65.0.71], bradshaw ``` (Source: Figure 4, p.149. 原文は6時間・2300行超の入力に対する出力例で、上記は抜粋。) ## 関連 - ソース: [[@2010__LISA__Log Analysis and Event Correlation Using Variable Temporal Event Correlator (VTEC)]] - 概念: [[ログベースイベント相関]]