広瀬です。

最近ログ監視系ばかりの投稿で大変恐縮なのですが、先に投稿させていただいた件にも
若干リンクする部分があるのですが、以下の条件時にログを拾わないケースもありました。
少々長文ですが、ご容赦ください。

※先の投稿： http://www.zabbix.jp/node/1541

◆環境
監視環境：ZABBBIX Ver1.8.11
ログ出力方式：Tomcat＋log4j
ログローテート条件：ファイルサイズによるローテーション
利用アイテム：logrt
詳細キー記述：logrt[/filepath/zabbix/alert.log.*,ERROR,,]
トリガー：logrt[/filepath/zabbix/alert.log.*,ERROR,,].regexp(E-XXXXX)

◆ログファイルローテーション前の状態
[user@host zabbix]$ ls -al
合計 1020
-rw-rw-r-- 1 tomcat tomcat 1034953 6月 7 13:32 alert.log

◆同時点でのログ内容
2012-06-07 13:32:51,260 TP-Processor1 ERROR E-02033 [L1][2012-06-07 13:32:51] エラー本文～～～～(中略)

上記のエラーまでは正常に検知されています。
問題は以下の時点では検出されなかった（＝ログファイル自体を読み込めていないため、最新情報のヒストリにもありません）

◆ローテーション直後のファイル状態
[user@host zabbix]$ ls --full-time
合計 1040
-rw-rw-r-- 1 tomcat tomcat 0 2012-06-08 15:07:08.000000000 +0900 alert.log
-rw-rw-r-- 1 tomcat tomcat 1049303 2012-06-08 15:07:08.000000000 +0900 alert.log.1

◆直後の1世代前のログ内容(このログの前が、先に書いたERROR E-02033)
2012-06-08 15:07:08,249 TP-Processor112 ERROR E-00123 [L0][2012-06-08 15:07:08] エラー本文～～～～(中略)
～スタックトレース内容～～～

2012-06-08 15:07:08,255 TP-Processor39 ERROR E-00123 [L0][2012-06-08 15:07:08] エラー本文～～～～(中略)
～スタックトレース内容～～～

ローテーションされた瞬間に、新しいログファイルが生成されましたが０バイトのファイルのため、
新規ログには何も吐かれていません。しかし、１世代前のログには6/7の13時半ごろに検出している
ログなので、上記の6/8の15時7分の検出対象が見事に監視から漏れました。

◆上記時点のログファイル監視状態（エージェントログから）

26266:20120608:151244.631 In process_logrt() filename [/filepath/zabbix/alert.log.*] lastlogsize [0] mtime [1339135628]
26266:20120608:151244.631 In split_filename() filename:'/filepath/zabbix/alert.log.*'
26266:20120608:151244.631 In split_string(): str [/filepath/zabbix/alert.log.*] del [/alert.log.*]
26266:20120608:151244.631 End split_string(): part1 [/filepath/zabbix/] part2 [alert.log.*]
26266:20120608:151244.631 End split_filename() directory:'/filepath/zabbix/' format:'alert.log.*'
26266:20120608:151244.631 we are in the *nix directory reading cycle
26266:20120608:151244.631 cannot process read entry [/filepath/zabbix/..]
26266:20120608:151244.631 cannot process read entry [/filepath/zabbix/.]
26266:20120608:151244.632 adding the file [/filepath/zabbix/alert.log] to logfiles
26266:20120608:151244.632 In add_logfile() filename:'alert.log' mtime:'1339135628'
26266:20120608:151244.632 add_logfile() logfiles:0x1edb4c60 logfiles_alloc:64
26266:20120608:151244.632 adding the file [/filepath/zabbix/alert.log.1] to logfiles
26266:20120608:151244.632 In add_logfile() filename:'alert.log.1' mtime:'1339135628'
26266:20120608:151244.632 In free_logfiles() number of logfiles [2]

エージェントのログは、どうやらローテーション後のファイルを見にいっている様に見受けられました。
この時点で、おそらくTomcat自身はすでにlog4jで開いている対象のzabbix.logなのかzabbix.log.1なの
かは、/proc配下のファイルディスクリプタ(とそのプロセス関係)を確認しなかったので、不明ではあり
ます。

この後、17時にzabbix.logに新たにエラーが出た際に、先の投稿にもあるように、過去ログである
zabbix.log.1の内容を先頭から末尾まで再度なめてしまい、エラーがその数だけ出てしまった様です。

◆本事象の再発。

5／30の投稿した件でこれで2度目。また別途、試験環境での発生も確認しました。

以前の投稿に於いて、TNKさん、KAZさん、kodaiさん等の指摘にもありました通り、ファイルを掴んで
いる状態と、そのタイミングに於いて何らかの問題がやはりログ監視には根底として相性的なものが
存在するのだろうと思います。

とりわけ、ログサイズ指定のローテーション時には再発率が高確率であることもわかりました。
日付指定の場合に限って言えば、このような事象は今のところは皆無です(ただし、別の投稿のような
事例もあるようですが・・・ http://www.zabbix.jp/node/1550 )

ZABBIX側のみの機能だけで何とかするには限界があるのは当然の事ですが、ログ出力自体にもなんらか
の手を加えるのが一番最良な方法に感じました。

と、なんか感想みたいになってしまいましたが、こんな事もあるようですという事象報告まで