API+Postgresql 接続NG

postgresql構成の場合のZabbixについて、API接続でトラブルがあります。
下記、皆様の御知恵を拝借できれば幸いです。

-------------------------------------
【構成】
・OS Ubuntu 13.04 (64bit)
・Apache2
・導入  zabbix-server-pgsql, zabbix-frontend-php, php5-pgsql

-------------------------------------
【症状】
(上記環境でzabbix監視は正常に動作しています)
ZabbixAPIを利用し、itemやtriggerの値を参照しようとしているのですが、成功するケースとしないケースがあります。
成功しない場合は、20分以上待たされます。
(長時間の場合は手元の処理で遮断してしまうので、それ以上待つ場合どうなるかは不明です)

postgresql側でログを見てみると、成功の場合はINSERT INTO sessionsのログがあり、そこから処理が始まっています。
失敗の場合、そのログが出ません。

--------------------------------------------------------
【成功のケース】
2013-09-30 18:19:01 JST LOG: statement: set bytea_output = escape
2013-09-30 18:19:01 JST LOG: statement: SELECT n.* FROM nodes n WHERE n.nodetype=1 ORDER BY n.nodeid
2013-09-30 18:19:01 JST LOG: statement: select t.httptestid,t.name,t.macros,t.agent,t.authentication,t.http_user,t.http_password from httptest t,applications a,hosts h where t.applicationid=a.applicationid and a.hostid=h.hostid and t.nextcheck<=1380532741 and mod(t.httptestid,1)=0 and t.status=0 and h.proxy_hostid is null and h.status=0 and (h.maintenance_status=0 or h.maintenance_type=0) and t.httptestid between 0 and 99999999999999
2013-09-30 18:19:01 JST LOG: statement: select min(t.nextcheck) from httptest t,applications a,hosts h where t.applicationid=a.applicationid and a.hostid=h.hostid and mod(t.httptestid,1)=0 and t.status=0 and h.proxy_hostid is null and h.status=0 and (h.maintenance_status=0 or h.maintenance_type=0) and t.httptestid between 0 and 99999999999999
2013-09-30 18:19:01 JST LOG: statement: begin
2013-09-30 18:19:01 JST LOG: statement: SELECT u.userid,u.attempt_failed,u.attempt_clock,u.attempt_ip FROM users u WHERE u.alias='apiuser' AND u.userid BETWEEN 000000000000000 AND 099999999999999
2013-09-30 18:19:01 JST LOG: statement: SELECT g.usrgrpid FROM usrgrp g,users_groups ug WHERE ug.userid=6 AND g.usrgrpid=ug.usrgrpid AND g.users_status=1 LIMIT 1 OFFSET 0
2013-09-30 18:19:01 JST LOG: statement: SELECT MAX(g.gui_access) AS gui_access FROM usrgrp g,users_groups ug WHERE ug.userid=6 AND g.usrgrpid=ug.usrgrpid
2013-09-30 18:19:01 JST LOG: statement: SELECT c.* FROM config c WHERE c.configid BETWEEN 000000000000000 AND 099999999999999

**ここ->** 2013-09-30 18:19:01 JST LOG: statement: INSERT INTO sessions (sessionid,userid,lastaccess,status) VALUES ('ef436251d7394ff3df33358ef6f3e294',6,1380532741,0)

2013-09-30 18:19:01 JST LOG: statement: SELECT u.userid,u.alias,u.name,u.surname,u.url,u.autologin,u.autologout,u.lang,u.refresh,u.type, u.theme,u.attempt_failed,u.attempt_ip,u.attempt_clock,u.rows_per_page FROM users u WHERE u.userid=6
2013-09-30 18:19:01 JST LOG: statement: SELECT ug.userid FROM usrgrp g,users_groups ug WHERE ug.userid=6 AND g.usrgrpid=ug.usrgrpid AND g.debug_mode=1
2013-09-30 18:19:01 JST LOG: statement: commit
2013-09-30 18:19:01 JST LOG: statement: set bytea_output = escape
2013-09-30 18:19:01 JST LOG: statement: SELECT n.* FROM nodes n WHERE n.nodetype=1 ORDER BY n.nodeid
2013-09-30 18:19:01 JST LOG: statement: begin
...

--------------------------------------------------------
【失敗のケース】 18:17:01にAPI処理を実行開始
2013-09-30 18:17:00 JST LOG: statement: begin;
2013-09-30 18:17:00 JST LOG: statement: select hostid,host,maintenance_type,maintenance_from from hosts where status=0 and maintenance_status=1
2013-09-30 18:17:00 JST LOG: statement: commit;
2013-09-30 18:17:01 JST LOG: statement: select hostid,status from hosts where host='sv08' and status in (0,1) and proxy_hostid is null and hostid between 0 and 99999999999999
2013-09-30 18:17:01 JST LOG: statement: begin;
2013-09-30 18:17:01 JST LOG: statement: select autoreg_hostid from autoreg_host where proxy_hostid is null and host='sv08' and autoreg_hostid between 0 and 99999999999999
2013-09-30 18:17:01 JST LOG: statement: update autoreg_host set listen_ip='192.168.0.108',listen_dns='sv08.ops.hogehoge.net',listen_port=10050 where autoreg_hostid=21
2013-09-30 18:17:01 JST LOG: statement: select nextid from ids where nodeid=0 and table_name='events' and field_name='eventid'
2013-09-30 18:17:01 JST LOG: statement: update ids set nextid=nextid+1 where nodeid=0 and table_name='events' and field_name='eventid'
2013-09-30 18:17:01 JST LOG: statement: select nextid from ids where nodeid=0 and table_name='events' and field_name='eventid'
2013-09-30 18:17:01 JST LOG: statement: insert into events (eventid,source,object,objectid,clock,ns,value,value_changed) values (311567,2,3,21,1380532621,0,1,0)
2013-09-30 18:17:01 JST LOG: statement: select actionid,evaltype from actions where status=0 and eventsource=2 and actionid between 0 and 99999999999999
2013-09-30 18:17:01 JST LOG: statement: commit;
2013-09-30 18:17:01 JST LOG: statement: begin;
2013-09-30 18:17:01 JST LOG: statement: select escalationid,actionid,triggerid,eventid,r_eventid,esc_step,status,nextcheck from escalations where 1=1 and escalationid between 0 and 99999999999999 order by actionid,triggerid,escalationid
2013-09-30 18:17:01 JST LOG: statement: commit;
2013-09-30 18:17:01 JST LOG: statement: select t.httptestid,t.name,t.macros,t.agent,t.authentication,t.http_user,t.http_password from httptest t,applications a,hosts h where t.applicationid=a.applicationid and a.hostid=h.hostid and t.nextcheck<=1380532621 and mod(t.httptestid,1)=0 and t.status=0 and h.proxy_hostid is null and h.status=0 and (h.maintenance_status=0 or h.maintenance_type=0) and t.httptestid between 0 and 99999999999999
2013-09-30 18:17:01 JST LOG: statement: select min(t.nextcheck) from httptest t,applications a,hosts h where t.applicationid=a.applicationid and a.hostid=h.hostid and mod(t.httptestid,1)=0 and t.status=0 and h.proxy_hostid is null and h.status=0 and (h.maintenance_status=0 or h.maintenance_type=0) and t.httptestid between 0 and 99999999999999
2013-09-30 18:17:01 JST LOG: statement: select i.itemid,i.key_,h.host,i.type,i.history,i.lastvalue,i.prevvalue,i.hostid,i.value_type,i.delta,i.prevorgvalue,i.lastclock,i.units,i.multiplier,i.formula,i.status,i.valuemapid,i.trends,i.data_type from hosts h,items i where h.hostid=i.hostid and h.status=0 and i.status=0 and ((h.host='sv02.ops.hogehoge.net' and i.key_='vm.memory.size[pavailable]')) and h.hostid between 0 and 99999999999999
2013-09-30 18:17:01 JST LOG: statement: select hostid,status from hosts where host='sv07' and status in (0,1) and proxy_hostid is null and hostid between 0 and 99999999999999
2013-09-30 18:17:01 JST LOG: statement: begin;
2013-09-30 18:17:01 JST LOG: statement: select autoreg_hostid from autoreg_host where proxy_hostid is null and host='sv07' and autoreg_hostid between 0 and 99999999999999
2013-09-30 18:17:01 JST LOG: statement: update autoreg_host set listen_ip='192.168.0.107',listen_dns='sv07.ops.hogehoge.net',listen_port=10050 where autoreg_hostid=17
2013-09-30 18:17:01 JST LOG: statement: select nextid from ids where nodeid=0 and table_name='events' and field_name='eventid'
2013-09-30 18:17:01 JST LOG: statement: update ids set nextid=nextid+1 where nodeid=0 and table_name='events' and field_name='eventid'
2013-09-30 18:17:01 JST LOG: statement: select nextid from ids where nodeid=0 and table_name='events' and field_name='eventid'
2013-09-30 18:17:01 JST LOG: statement: insert into events (eventid,source,object,objectid,clock,ns,value,value_changed) values (311568,2,3,17,1380532621,0,1,0)
2013-09-30 18:17:01 JST LOG: statement: select actionid,evaltype from actions where status=0 and eventsource=2 and actionid between 0 and 99999999999999
2013-09-30 18:17:01 JST LOG: statement: commit;
--------------------------------------------------------

上記を見比べるに、頻繁にbeggin-commitの処理が行われていることから、間が悪く別の処理でlockしてる際にAPIをたたくと処理に失敗、放置となるのかなと思われます。
同様の処理をmysql環境でも実施していますが、そちらではこのような症状は見たことがありません。
(完全に同一環境というわけではないので、別の原因かもしれませんが)
Zabbix-Serverについてログをdebugレベルで設定していますが、関係しそうなログは出ていませんでした。

またApachのログについて、成功・失敗ともに接続履歴はあります。
失敗のほうについては、1ログのみ、成功については、API処理に伴う大量のログが出ています。

ZabbixAPIの実装についてご存知の方、上記の振る舞いについて情報いただければ幸いです。
以上、よろしくお願いいたします。

--------------------------------------------------
別件ですが、上記環境でweb frontendをインストールすると依存関係でphp5-mysql側をインストールしようする症状があります。
不要なphp5-mysqlを入れないように切り替えたいのですが、このような質問はubuntuのフォーラムでやったほうがよさそうでしょうか。

コメント表示オプション

お好みのコメント表示方法を選び「設定の保存」をクリックすると変更が反映されます。
ユーザー fripper の写真

Web フロントエンドや API からの接続は、php5-pgsql や php5-mysql のモジュールを通してそれぞれの DBMS へ直結されていて、
処理的には、zabbix_server のプロセスは間に挟まっていません。

ひとつ気になるのは、DBMS 側の同時接続数の上限です

zabbix_server の設定内容がほぼデフォルト設定であったとして、poller や trapper など、複数プロセスが起動するため、おおよそ 20 弱の接続を消費します。
そこへ加えて、WebUI や API からの DB 接続が掛かります。

DBMS 側での同時接続上限が少ない場合、DBへの接続に失敗して、タイムアウトしてしまうような症状が起きるかもしれません。

Apache 側がどのような設定になっているかにも依ると思います。
mpm_prefork + mod_php の場合ならば、apache のプロセス数上限=接続数とみなせます
mpm_event / mpm_worker 系+ fastcgi 系 の場合には、apache のプロセス数上限 x プロセスあたりのスレッド数上限 などになってしまうこともあり得ます

mysql で構築した環境と、postgresql で構築した環境で、DBMS 側の上限設定が異なっていることはありませんでしょうか?

ユーザー nhoge の写真

>fripper様

コメントありがとうございます。
mysql環境は状況揃えてみるのでまだ確認してませんが、ざっくりセッション制限を拾ってみた結果は下記のとおりです。

○postgresql : max_connection 100(初期値)
 定期的に netstat -an | grep :5432 | grep Establishedで監視してみましたが、大体50チョイ位で推移していました。
 監視周期が2秒なので、短期的なスパイクで検知できてない可能性はありますが、、、、
 またpostgresqlのログを確認しましたが、sorry, too many clients already、connection limit exceeded for non-superusersなどのセッション数超過のアラームは出ていませんでした。
 
○Apach
 mod_php+prefork
 Max Clients 150

他に確認点などありますでしょうか。

ユーザー nhoge の写真

状況の追加です。

○postgres構成:
 通常の処理で、dbでロールバックのログが多
 zabbixで監視項目について、頻繁に通信失敗のログが出る
 (DBとの接続失敗・ロールバックが原因?)

○mysql構成:
 ロールバックのログなし
 通信失敗はあまり見られず
 APIはこちらでも失敗するケース多

isolationレベルの違いが原因かな、とも思ったのですが、さらに調査が必要そうです。