PHPの集計プログラムでPostgreSQLのログにConnection reset by peerと表示されて完走しないままプロセスが残留してしまう

前提・実現したいこと

PHP(5.2.17)+PostgreSQL(8.4.20)で集計のプログラムを作成しています。

cronによって定期実行させている、
幾つかの集計クエリーを実行して終了するバッチプログラムで、
サブクエリのあるINSERTや集計前のデータクリアの為のDELETE等、
時間がかかるクエリーの実行が有ると
まれにDB側にメッセージを残して処理が途中で停止し、
バッチプログラムのプロセスが残りっぱなしになる事が有るので
必ず完走させることが目的となります。

宜しくお願い致します。

2018.12.20 追記
トランザクションの分割を行い2日程動かしました。
現状では完走しないケースがまだ有りますが、
対応後で、若干エラー内容は変わりました。
一旦時間がかかるクエリーを個別にチューニングして様子を見ています。
Dec 20 01:02:51 [4191-1] LOG: could not send data to client: Broken pipe
Dec 20 01:02:51 [4192-1] LOG: unexpected EOF on client connection
Dec 20 01:02:51 [4193-1] LOG: disconnection: session time: 0:02:49.872 user=ユーザー database=データベース host=ホスト port=ポート

2018.12.21 追記
トランザクションの分割のみでは結果が同じ模様。
引っかかった物からクエリーチューニングを行っているが、
難航中。（自由に実行、集中して作業が出来ないのが辛い所）

発生している問題・エラーメッセージ

PostgreSQL側に以下のメッセージが表示されます。

LOG: could not receive data from client: Connection reset by peer
LOG: unexpected EOF on client connection
LOG: disconnection: session time: 0:02:51.973 user=USER database=DATABASE host=HOST port=PORT

該当のソースコード

【初回質問時（パターンA）】
$con = new PDO(DSN, USERNAME, PASSWORD);
$con->begin();
$con->exec($delete_sql1, $where); //集計テーブルクリア
$con->exec($delete_sql2, $where); //集計テーブルクリア
$con->exec($delete_sql3, $where); //集計テーブルクリア
//<<---↑このクエリに時間がかかった場合はログがここまでになる
$con->exec($insert_sql1, $where); //集計テーブルへ集計データを挿入
$con->exec($insert_sql2, $where); //集計テーブルへ集計データを挿入
$con->exec($insert_sql3, $where); //集計テーブルへ集計データを挿入
$con->commit();

↓

【トランザクション分割（パターンB）】
$con = new PDO(DSN, USERNAME, PASSWORD);
$con->begin();
$con->exec($delete_sql1, $where); //集計テーブルクリア
$con->commit();
$con->begin();
$con->exec($delete_sql2, $where); //集計テーブルクリア
$con->commit();
$con->begin();
$con->exec($delete_sql3, $where); //集計テーブルクリア
//<<---↑このクエリに時間がかかった場合はログがここまでになる
$con->commit();
$con->begin();
$con->exec($insert_sql1, $where); //集計テーブルへ集計データを挿入
$con->commit();
$con->begin();
$con->exec($insert_sql2, $where); //集計テーブルへ集計データを挿入
$con->commit();
$con->begin();
$con->exec($insert_sql3, $where); //集計テーブルへ集計データを挿入
$con->commit();

試したこと

【パターンA時】
PHP側に
set_time_limit(0);
ini_set("session.gc_maxlifetime", 60*30);
を入れてみましたが改善できませんでした。

【パターンB時】
トランザクションを分割しました。

補足情報（FW/ツールのバージョンなど）

PHP(5.2.17)
PostgreSQL(8.4.20)

行動規範の内容に同意します

回答3件

困ったときの stackoverflow
WHERE句や、バインド文字が長いとおきる模様

How to debug could not receive data from client: Connection reset by peer - StackOverflow

down vote
accepted
I know this is an older post, but I just found it because I had the same error today in my postgres logs. I narrowed it down to a PDO select statement. I'm using Zend Framework 1.10.3 on Ubuntu Precise.

The following pdo statement generated an error if $opinion is a long text string. The column opinion is type Text in my postgres table. The query succeeds if $opinion is under a certain number of characters. 1000 characters works fine. 2000 characters fails with "could not receive data from client: Connection reset by peer".

  $select = $this->db->select()
           ->from( 'datauserstopics' )
           ->where("opinion = ?",trim($opinion))
           ->where("datatopicsid = ?",trim($tid))
           ->where("datausersid= ?",$datausersid);

$stmt = $this->db->query($select);
I circumvented the problem by using: ->where("substr(opinion,1,100) = ?",trim(substr($opinion,1,100)))

This is not a perfect solution, but for my purposes, the select statement using substr() suffices.

Note that I have no problem inserting long strings into the same table/column. The disconnect problem only appears for me on the PDO select with relatively long text strings.

投稿2018/12/18 03:36

退会済みユーザー

総合スコア0

退会済みユーザー

2018/12/18 03:47

>asahina1979 さん回答有難う御座います！クエリー全体で360文字で、バインドされる文字の長さは最大で20文字でしたので、今回は別の原因の様です。バインド等が長過ぎた場合も Connection reset by peer となるのですね。勉強不足でした。

退会済みユーザー

2018/12/18 03:59

この回答者（SO)の人の設定だと1000文字（バイト）ってだけであって同じバイト数だから安全とは限らないけどね。

行動規範の内容に同意します

エラーのハンドリングは全て行えていますか？
9以降でしたが、エラーの状態で、COMMITしてしまうと、DBにプロセスが残るというのを経験したことがあります。

追記

postgres側で、Connection reset by peerということはpostgreas処理中にセッションが切断したって事ですね。
先の回答は逆の話ですから関係なさそうです。

追記

postgresからのメッセージを受けているなら、postgres自身のタイムアウトの可能性が高そうですね。
statement_timeoutを確認してみて下さい

投稿2018/12/18 02:06

編集2018/12/18 04:06

sazi

総合スコア25173

退会済みユーザー

2018/12/18 02:09

横から興味本位で恐縮ですが、それって仕様でした？バグでした？

退会済みユーザー

2018/12/18 02:13

早速の回答有難う御座います。現状エラーのハンドリングは全ては行えてないです。 PostgreSQLのログから、クエリー発行でのエラーは発生していませんが、上記エラーメッセージで止まるため、COMMITの処理までは到達していないです。

sazi

2018/12/18 02:18 編集

>te2ji　さんエラーハンドリングが不足しているという処理の不備でしたので、調査までは行っていません。 >dntym さん伝えたいのは、エラーを無視して先に進めると別なところでエラーになるという事です。

退会済みユーザー

2018/12/18 02:21

興味本位の質問に回答ありがとうございました！

退会済みユーザー

2018/12/18 02:28

>sazi さん有難う御座います。先ずはエラーハンドリング整備をすすめます。

sazi

2018/12/18 02:44

phpは詳しくないので分かりませんが、php側でセッションが切断されたかどうかはログなど残らないのでしょうか？

退会済みユーザー

2018/12/18 02:58

コメント有難う御座います。セッション切断によるPHP側での直接なエラー出力は個人的には見たことが無いです（知らないだけかもしれません） PHPとの接続がタイムアウトの際にはPHP側はPDOオブジェクトからエラーが受け取れるので手動でエラーログを出しています。タイムアウトの場合PostgreSQL側のログは以下のメッセージでした。 LOG: could not receive data from client: Connection timed out LOG: unexpected EOF on client connection 今回のエラーは初遭遇なのでちょっと難航してます。

退会済みユーザー

2018/12/18 04:17

>sazi さん続報有難う御座います。statement_timeoutは設定されていない事を確認しました。 ./postgresql.conf #statement_timeout = 0 # in milliseconds, 0 is disabled データベース=# show statement_timeout; statement_timeout ------------------- 0 (1 row)

sazi

2018/12/18 04:21

うーん。因みに時間の掛かるクエリーというのはどの程度のものですか？

退会済みユーザー

2018/12/18 04:51

>sazi さんコメント有難う御座います。 ①~③はそれぞれ別のサーバーで同じソースコードが動いており、データ件数はバラツキがあります。バッチプログラムを再実行すると全く同じ処理を繰り返して実行することが出来ます。プロセスが残った場合は一度KILLして再実行すると概ね完走できます（止まる事もあります） ① LOG: statement: delete from テーブル名 where entry_date < '2017-12-03 00:00:00' LOG: duration: 171337.362 ms LOG: could not receive data from client: Connection reset by peer ② LOG: statement: delete from テーブル名 where entry_date < '2017-12-03 00:00:00' LOG: duration: 145444.582 ms LOG: could not receive data from client: Connection reset by peer ③ LOG: statement: insert into テーブル名 (カラム) サブクエリ LOG: duration: 156413.171 ms LOG: could not receive data from client: Connection reset by peer

sazi

2018/12/18 05:09

その時のCPU負荷やI/Oの負荷はどの程度でしょう？トランザクションが大きすぎて、サーバーそのものに負荷がかかっているのではないでしょうか

sazi

2018/12/18 05:11

wal_buffersはどうなっていますか？

退会済みユーザー

2018/12/18 05:32

こちらはサンプルが少ないので申し訳ないのですが、 CPU使用率は 1% 程度で I/O負荷は 30% 程度でした。 wal_buffersは設定されていませんでした。 ./postgresql.conf #wal_buffers = 64kB # min 32kB メモリが集計開始直前まで利用率がほぼ 100%、スワップ利用率が 1.75% で、集計辺りから70%台に下がっているので負荷については危険な香りはしますね。

sazi

2018/12/18 05:50

処理にかかる時間からみるとトランザクションバッファに収まり切れていないとみるべきでしょう。 wal_buffersを広げて、後はそれに収まらなければ、トランザクション分割という対処かと思います。

退会済みユーザー

2018/12/18 06:19

>sazi さん回答有難う御座います。 wal_buffersの設定変更が難しいため、トランザクション分割から進めてみます。

行動規範の内容に同意します

ベストアンサー

トランザクションの分割とクエリーの最適化で完走。

クエリに時間がかかってもそのまま実行する様にしたかったのですが、
個別のクエリーを最適化しエラーが出ない範囲内に収める事で収束しました。

$con = new PDO(DSN, USERNAME, PASSWORD);
$con->begin();
$con->exec($delete_sql1, $where); //集計テーブルクリア
$con->exec($delete_sql2, $where); //集計テーブルクリア
$con->exec($delete_sql3, $where); //集計テーブルクリア
//<<---↑このクエリに時間がかかった場合はログがここまでになる

$con->exec($insert_sql1, $where); //集計テーブルへ集計データを挿入
$con->exec($insert_sql2, $where); //集計テーブルへ集計データを挿入
$con->exec($insert_sql3, $where); //集計テーブルへ集計データを挿入
$con->commit();

↓

$con = new PDO(DSN, USERNAME, PASSWORD);
$con->begin();
$con->exec($delete_sql1, $where); //集計テーブルクリア
$con->commit();
$con->begin();
$con->exec($delete_sql2, $where); //集計テーブルクリア
$con->commit();
$con->begin();
$con->exec($delete_sql3, $where); //集計テーブルクリア
$con->commit();

$con->begin();
$con->exec($insert_sql1, $where); //集計テーブルへ集計データを挿入
$con->commit();
$con->begin();
$con->exec($insert_sql2, $where); //集計テーブルへ集計データを挿入
$con->commit();
$con->begin();
$con->exec($insert_sql3, $where); //集計テーブルへ集計データを挿入
$con->commit();