zabbix(pz_monz)でログ監視のトリガーが動かない

Question

pg_monzテンプレートを使用してPostgreSQLの監視を使ってみて本番環境投入の検討をしています。
テンプレートにあるログ監視を使用して、slackへの通知を設定したいのですが
トリガーの設定からつまずいております。

Zabbixは2.4を使用しています。

pg_monzのログ監視設定は以下のようになっています。

logrt["{$PGLOGDIR}/postgres.*","PANIC|FATAL|ERROR|[Ee]rror"]

トリガーの条件式はこのようにしています。

(({db1:logrt["{$PGLOGDIR}/postgres.*","PANIC|FATAL|ERROR|[Ee]rror"].iregexp(error)})=0)

この状態にして、echo "error" >> postgres.20180420 のようにテストを行うのですがトリガーが起動しません。
logrtに対しての条件式が間違っていると思うのですが、ご指摘お願いいたします。

04/26追記

上手くいかないため、内容追記しなおします。

SQLの失敗がロギングされるよう設定し、以下のようなシェルスクリプトでPostgreSQLにエラーを出力しています。

while true
do
 export PGPASSWORD=password
 psql -U postgres -d mydb -h hostname  -c "SELET error";
 sleep 10;
done

テンプレートのpg.logは以下の通りデフォルトです。

ホストに登録しているマクロは以下の通りです。

ホストのpg.logは以下の通りになっています。

ディレクトリ・ファイルの権限などはこのようになっています。

-bash-4.2$ ll /usr/local/pgsql/data/pg_log/postgres -d
drwxr-xr-x 2 zabbix zabbix 4096 Apr 25 16:01 /usr/local/pgsql/data/pg_log/postgres

-bash-4.2$ ll /usr/local/pgsql/data/pg_log/postgres -l
total 416
-rw-r--r-- 1 zabbix zabbix 378537 Apr 25 16:00 postgresql.log.2018-04-25-15
-rw-r--r-- 1 zabbix zabbix  35091 Apr 25 16:06 postgresql.log.2018-04-25-16

/var/log/zabbix/zabbix_agent.logおよび/var/log/zabbix/zabbix_server.logにエラーメッセージは何も出力はありません。
ランタイムコンフィギュレーションを利用して、zabbix_agentd -R log_level_increase="active check"を行ったりしましたが
エラーメッセージは確認されませんでした。

pg_monzのデフォルトにあるすべてのアイテムは有効されており、それらの値は最新データにて正しく確認できています。
RDS PostgreSQLのログをboto3のdownload_db_log_file_portionを使用してサーバーにダウンロードしています。
そのためエンコードもチェックしたのですが、問題なさそうです。

[root@ip-10-10-1-132 ~]# file -i /usr/local/pgsql/data/pg_log/postgres/postgresql.log.2018-04-25-16
/usr/local/pgsql/data/pg_log/postgres/postgresql.log.2018-04-25-16: text/plain; charset=us-ascii

Answer 1

• 監視対象のログファイルを正しく指定できているか

テンプレートから導入したのでないのであれば、TaichiYanagiyaさんの言うとおり{$PGLOGDIR}が設定されていない可能性があります。
当該アイテムのステイタスは有効になっているでしょうか。

• ログのパーミション

実際のチェックはzabbix agentで行われます。監視対象となるログファイルはzabbix agentを動作させているアカウントに対してread permissionがあるでしょうか。

Comments

[psps]

やはりその観点になって確認し正しく設定していると思うのですが、上手くいきません。。。userparameterの方も見たりしてデバッグしてみます。。。

Answer 2

regexp() / iregexp() は文字列に合致した場合、1 を返すので、トリガーの評価式は「=0」ではなく、「=1」になると思います。

https://www.zabbix.com/documentation/2.4/manual/appendix/triggers/functions

ただ、このアイテムの設定だと、"error" でトリガーが「正常」→「障害」になりますが、その後、"PANIC" や "FATAL" で「障害」→「正常」に戻ると思います。
想定した動作でしょうか？

###(2018/04/24 00:58) 追記
まず、「最新データ」でこのアイテムに "PANIC", "FATAL", "ERROR" などに合致した文字列が取りこめているか確認ください。
次に、"PANIC", "FATAL", "ERROR" それぞれをログファイルに追記し、「最新データ」で取りこめていることを確認するとともに、「トリガー」や「イベント」で、状態(正常/障害)がどう変化するのかを確認すると理解が深まると思います。

Comments

[psps]

ご回答ありがとうございます。すいません、何か根本的に誤解しているみたいです。もちろんerrorのメッセージがログファイルに出たら、トリガーを発生させてアクションを実行しようとしています。手元で調べておりますが、宜しければご指摘お願いします。

[psps]

そもそも最新データに取り込めていないようです。その原因からわからない状態です。。。

[psps]

pg_monzテンプレートの設定ではうまくいかず、適当にzabbix-serverに対してログ監視を設定して/var/log/messagesなどに監視設定してみると、最新データにて見れることがわかりました。テンプレートの設定との関連でうまくいってないようです。

[TaichiYanagiya]

Server, Agent 両方のログを確認するといいと思います。
ログファイルのパーミッションとか、{$PGLOGDIR} の値とか。

[psps]

確認しエラーも出ておらずです。マクロも設定しています。

[TaichiYanagiya]

アイテム一覧で、右側の「ステータス」欄はどうなっていますでしょうか？
「取得不可」となっているようならば、その右の「情報」欄のアイコンにポインターを合わせると理由が表示されます。

[psps]

確認していますが、エラーは表示されていません。詳細追記させていただきました。

[TaichiYanagiya]

> RDS PostgreSQLのログをboto3のdownload_db_log_file_portionを使用してサーバーにダウンロードしています。

ファイルに追記ではなく、まるごとコピーしているのですね。
ファイルの内容が切り詰められたりしていないでしょうか。

logrt はファイルのタイムスタンプで最新のファイルを判定し、そのファイルパスと既読の行数を Agent 側で記録していたと思います。
追記ではなくコピーの場合、記録している情報と合わなくなるかもしれません。

最新のファイルが postgresql.log.2018-04-25-16 だとして、"touch postgresql.log.2018-04-25-16" でタイムスタンプを更新すると、最新のファイルと認識すると思います(Agent のログに "consider it to be a new file" と出ます)。
その後、そのファイルに "ERROR" などが追記されれば最新データに表示されませんでしょうか？

[psps]

download_db_log_file_portionのAPIから返るmarkerを利用してスクリプトのロジックを組み、毎分毎続きのポジションからログをダウンロードするようcronで実行しています。そのため追記で、ファイルスタンプの値も最新の時刻になります。これまでの調査しているなかでもちろんPostgreSQLのログファイルもtailしながら確認しているのでファイルのタイムスタンプは更新され続けています。

やはり設定は正しいように思われるので、何らかの不具合である可能性を含めて調査したいと思います。

[TaichiYanagiya]

Zabbix が監視するログファイルを 1つに固定し、RDS のログ(差分)を一時ファイルとして作成して、それを追記していくのはどうでしょうか。
一時ファイルのファイル名は、監視対象とならないよう、 "postgres" で始まらないものにします。
また、ファイル名を固定にするのであれば、logrt ではなく log を使ってもいいと思います。

[psps]

ワークアラウンドの提案ありがとうございます。

何もエラーが出ていないですが、logrtのみ最新のトレンドの「最新のチェック時間」が現在時刻に更新されないため、アクティブチェックが正常に動作していない可能性を疑っておりました。

以下ログでもserverとactive checkの疎通は問題なくとれていると思っております。
ただ、agent側じゃ"active checks #1 [idle 1 sec"のidleというのと
server側は"[{"response":"success","data":[]}]!というところが気になっています。

<zabbix agent>

```
18595:20180427:231337.638 active checks #1 [getting list of active checks]
18595:20180427:231337.638 In refresh_active_checks() host:'127.0.0.1' port:10051
18595:20180427:231337.638 sending [{"request":"active checks","host":"Zabbix-server"}]
18595:20180427:231337.639 End of refresh_active_checks():SUCCEED
18595:20180427:231337.639 active checks #1 [processing active checks]
18595:20180427:231337.639 In process_active_checks() server:'127.0.0.1' port:10051)
18595:20180427:231337.639 End of process_active_checks()
18595:20180427:231337.639 active checks #1 [idle 1 sec]
18595:20180427:231338.640 active checks #1 [idle 1 sec]
```

<server>
```
18117:20180427:231437.656 trapper got '{"request":"active checks","host":"Zabbix-server"}'
18117:20180427:231437.656 In send_list_of_active_checks_json()
18117:20180427:231437.657 send_list_of_active_checks_json() sending [{"response":"success","data":[]}]
18117:20180427:231437.657 End of send_list_of_active_checks_json():SUCCEED
```

[psps]

pg_monzと同じホストではなく、既存のzabbix-serverに対して同様のlogrtの設定を行ったところ正常に動作し始めました。原因はわかりませんが、目的はこれで達成できるのでこれで解決としたいと思います。

長らくアドバイスいただきありがとうございました。

[psps]

pg_monzと同じホストに設定しているときは以下のログがなかったですが、zabbix-serverに対して設定した時にはdebuglevelを4にすると以下が確認できました。

```
23852:20180428:104846.875 In process_logrt() is_logrt:1 filename:'/var/log/rds_postgres/postgres/postgresql.*' lastlogsize:312208 mtime:1524912481 error_count:0
23852:20180428:104846.875 process_logrt() old file list:
23852:20180428:104846.876 process_logrt() new file list: (mtime:1524912481 lastlogsize:312208 start_idx:0)
23852:20180428:104846.876 End of process_logrt():SUCCEED error_count:0
```

またzabbix_server.logの方にも以下のように条件にマッチしたというログが見れました。

```
trapper got '{"request":"agent data","data":[{"host":"Zabbix-server","key":"logrt[\"{$PGLOGDIR}/postgres/postgresql.*\",\"PANIC|FATAL|ERROR|[Ee]rror\"]","value":"2018-04-28 10:21:06 UTC:10.10.1.132(36426):postgres@mydb:[9476]:STATEMENT: SELET error","lastlogsize":224491,"mtime":1524910921,"clock":1524910922,"ns":561633047}
```

そのため、WebUIやエラーログ上にエラーは表示されないが、process_logrt()が実行されていないことがわかりました。何らかの要因が設定ファイルかホスト設定にあるのかもしれないです。

[psps]

申し訳ございません、ベストアンサーを選んで質問を閉じてしまいましたが

>ただ、このアイテムの設定だと、"error" でトリガーが「正常」→「障害」になりますが、その後、"PANIC" や "FATAL" で「障害」→「正常」に戻ると思います。
>想定した動作でしょうか？

こちらその通りでした。iregexpでFATALなどが0を返すため、正常に戻ってしまうためかと思いますが、宜しければトリガーの条件でこのような時zabbixでは条件式どうすればよいかご教示ください。

[TaichiYanagiya]

アイテムで "ERROR|[Ee]rror" のみを取得するのが確実です。
この場合、一度、「正常」→「障害」になると、自動ではステータスは「正常」に戻りませんので、トリガーで「障害イベントを継続して生成」にチェックを入れます。