[pgpool-general-jp: 986] Re: current transaction is aborted が発生する

松山大樹 t.matsuyama @ wowcom.co.jp
2011年 8月 25日 (木) 13:56:02 JST


こんにちは。

>> ちょっと曖昧な書き方だったと思いますが、
>> 「エラー処理をしている」と書いたのは、
>>
>> ERROR: current transaction is aborted, commands ignored until end of
>> transaction block
>>
>> などが発生した時点で、Java側では例外が発生するので、それを受けて
>> 自動的にロールバックが走る、という意味でした。このあたりは、
>> Seasar2 + S2Dao を使っているので、フレームワークに任せてます。
> 
> しかし、今回のケースでは current transaction is aborted... の前に
> dealock detcted などのエラーが発生しているはずで、それが例外処理されて
> いないのはおかしいですね(逆に例外処理されていれば、current transaction
> is aborted... の状態に到達しない)。フレームワークかアプリケーションに問
> 題があるのではないでしょうか。

pgpool のログを見ると、

2011-08-24 21:19:34 DEBUG: pid 3205: detect_error: kind: E
2011-08-24 21:19:34 DEBUG: pid 3205: detect_deadlock_error: received
deadlock error message from backend
2011-08-24 21:19:34 DEBUG: pid 3205: do_command: kind: E
2011-08-24 21:19:34 DEBUG: pid 3205: do_command: kind: Z
2011-08-24 21:19:34 DEBUG: pid 3205: do_command: transaction state: E
2011-08-24 21:19:34 DEBUG: pid 3205: do_command: Query: send invalid
query from pgpool to abort transaction
2011-08-24 21:19:34 DEBUG: pid 3205: wait_for_query_response: waiting
for backend 1 completing the query
2011-08-24 21:19:34 DEBUG: pid 3204: detect_error: kind: 1
2011-08-24 21:19:34 DEBUG: pid 3204: wait_for_query_response: waiting
for backend 1 completing the query
2011-08-24 21:19:34 DEBUG: pid 3205: detect_error: kind: E
2011-08-24 21:19:34 DEBUG: pid 3205: do_command: kind: E
2011-08-24 21:19:34 DEBUG: pid 3204: read_kind_from_backend: read kind
from 0 th backend 1 NUM_BACKENDS: 2
2011-08-24 21:19:34 DEBUG: pid 3205: do_command: kind: Z
2011-08-24 21:19:34 DEBUG: pid 3204: read_kind_from_backend: read kind
from 1 th backend 1 NUM_BACKENDS: 2
2011-08-24 21:19:34 DEBUG: pid 3205: do_command: transaction state: E
2011-08-24 21:19:34 DEBUG: pid 3205: Parse: waiting for master
completing the query
2011-08-24 21:19:34 DEBUG: pid 3204: pool_add_sent_message: prepared
statement "" already exists
2011-08-24 21:19:34 DEBUG: pid 3204: can_query_context_destroy: query
context is still used.
2011-08-24 21:19:34 LOG:   pid 3205: pool_send_and_wait: Error or notice
message from backend: : DB node id: 0 backend pid: 3228 statement:
INSERT INTO xxxxxxx message: current transaction is aborted, commands
ignored until end of transaction block
2011-08-24 21:19:34 DEBUG: pid 3205: detect_error: kind: E
2011-08-24 21:19:34 LOG:   pid 3205: Parse: Error or notice message from
backend: : DB node id: 0 backend pid: 3228 statement: INSERT INTO
xxxxxxx message: current transaction is aborted, commands ignored until
end of transaction block
2011-08-24 21:19:34 DEBUG: pid 3205: wait_for_query_response: waiting
for backend 1 completing the query
2011-08-24 21:19:34 LOG:   pid 3205: pool_send_and_wait: Error or notice
message from backend: : DB node id: 1 backend pid: 3229 statement:
INSERT INTO xxxxxxx message: current transaction is aborted, commands
ignored until end of transaction block
2011-08-24 21:19:34 DEBUG: pid 3205: read_kind_from_backend: read kind
from 0 th backend E NUM_BACKENDS: 2

となっていて、最初にdeadlock を検知しているようですが、アプリケーション
(Java)側では、

Caused by: org.postgresql.util.PSQLException: ERROR: current transaction
is aborted, commands ignored until end of transaction block
	at
org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2077)
 :
 :

で例外になっています。

これによると、pgpool-II が、最初のデッドロックを、エラーとして、アプリ
ケーションに(というよりJDBCドライバに)返していないように見えますが。


そもそも、なんでデッドロックが発生しているのか、よくわからないのですが。

> --
> Tatsuo Ishii
> SRA OSS, Inc. Japan
> English: http://www.sraoss.co.jp/index_en.php
> Japanese: http://www.sraoss.co.jp
> 
>> 単体のデータベースに接続している場合は、そもそも上記のエラーが
>> 発生したことがないので、pgpool-II を経由した場合に発生する原因と
>> 回避方法がわかれば、と思い、質問させてもらいました。
>>
>> 現在は、対象のテーブルのserial列を、integer に変更して、
>> テーブルロックをなくした状態で、どうなるかな、と試しているところです。
>> 今のところ、エラーは発生していませんが、レプリケーションモードで、
>> nextval() で取得したシーケンスの値の不整合の可能性で、実際に使用する
>> べきかどうか躊躇しています。
>>
>>
>>>>>> postgreSQL8.4.8 + pgpool-II 3.1.0-beta2 で、テストをしています。
>>>>>>
>>>>>> 発生条件が今ひとつはっきりしないのですが、たまに、
>>>>>>
>>>>>> ERROR: current transaction is aborted, commands ignored until end of
>>>>>> transaction block
>>>>>>
>>>>>> というエラーで、insert などが失敗することがあります。
>>>>>>
>>>>>> 発生確率が高いのは、
>>>>>>
>>>>>> あるプロセスで、
>>>>>>     beginTran
>>>>>>     select nextval('xxxxxxx') でシーケンスを取得
>>>>>>     insert yyyyyyyyy
>>>>>>     commit
>>>>>> のような連続した登録(50回ぐらい)を行っているときに、
>>>>>> 別のプロセスで同じように、
>>>>>>     beginTran
>>>>>>     select nextval('xxxxxxx') でシーケンスを取得
>>>>>>     insert yyyyyyyyy
>>>>>>     commit
>>>>>> を実行する、という状態です。
>>>>>> ただ、確実にこの状態なら発生するというわけではないのですが。
>>>>>>
>>>>>> また、発生したときの状況を聞くと、だいたい多くの人間が使用していて、
>>>>>> ひんぱんにselect、insert、update が発生しているときのようです。
>>>>>>
>>>>>> 漠然とした状況で申し訳ありませんが、原因として何が考えられるでしょうか。
>>>>>
>>>>> 個人メールでログを送っていただいたので見てみました。PostgreSQLのログに
>>>>> 出ていますが、原因はデッドロックですね。以下のような対策を取られると良
>>>>> いと思います。
>>>>>
>>>>> 1) アプリケーションがクエリの成功/失敗を確認していない。クエリを実行し
>>>>>       てエラーが返ってきたら、アプリケーションはトランザクションをアボート
>>>>>       してエラー処理をすべき。
>>>>
>>>> アプリケーションは、エラー処理を行っています。今回のようなエラーが発生し
>>>> た場合、処理としてはロールバックしています。
>>>
>>>>>> ERROR: current transaction is aborted, commands ignored until end of
>>>>>> transaction block
>>>>>>
>>>>>> というエラーで、insert などが失敗することがあります。
>>>
>>> とあったことから、エラー処理をしていないのではないかと思いました。それ
>>> とも、エラー処理をしているにも関わらず上記メッセージが出るのですか?それ
>>> ならそれで別の問題になるので、詳細を教えてください。
>>>
>>>> 今回、質問したかったのは、そもそも、なぜエラーが発生するか、ということで
>>>> した。
>>>> pgpool-II を経由せず、直接、単体のpostgreSQL に接続した場合は、同様の
>>>> 処理を行っても、エラーが発生しなかったので。
>>>>
>>>>> 2) insert_lockがオンになっていると、pgpool-IIはSERIAL型の列を持つテーブ
>>>>>       ルにINSERTしようとしたときに、そのテーブルにロックを取る。このことを
>>>>>       考慮してデッドロックが発生しないように明示的なロックを取るなどの対策
>>>>>       をとる。
>>>>
>>>> なるほど。
>>>> ユーザマニュアルに、
>>>> ---------------------------------------------------------------------
>>>> なお、pgpool-II 3.0以降では、対応するシーケンステーブルに対して行ロック
>>>> を行なうことによって排他制御を行ないます。それ以前のバージョンと比べる
>>>> と、VACUUM(autovacuumを含む)とのロック競合がなくなるメリットがあります。
>>>> ---------------------------------------------------------------------
>>>> とあったので、テーブルに対してはロックをかけないのかと思っていました。
>>>> この記述は、insert_lock がtrue の場合の記述でしょうか?それとも、
>>>> insert_lock の設定に関係なく、pgpool-II 3.0以降についての記述でしょうか?
>>>
>>> 詳細は北川君のメールで。ログを見た限りでは、insert_lockをオンにしており、
>>> ご利用の設定では結果としてテーブルロックがかかります。
>>>
>>>>> 3) (デッドロックとは関係ありませんが) select nextval('xxxxxxx') のよう
>>>>>       なパターンをレプリケーションモードで実行すると、取得したシーケンスの
>>>>>       値が不整合になる可能性があるのでおすすめしません。このようなトランザ
>>>>>       クションが並列実行しないように明示的なロックで制御するか、select
>>>>>       nextvalとinsertをまとめて、insertだけにする。
>>>>
>>>> そうですね。そこが少し不安だったのですが。
>>>> シーケンスの取得は、全て select nextval() で行っていて、変更できない
>>>> ので、master/slave モードを使うことを考えるか、postgreSQL 9.0 の
>>>> streaming replication が使えるか調査してみることにします。
>>> --
>>> Tatsuo Ishii
>>> SRA OSS, Inc. Japan
>>> English: http://www.sraoss.co.jp/index_en.php
>>> Japanese: http://www.sraoss.co.jp
>>>
>>>
>>>
>>
>>



pgpool-general-jp メーリングリストの案内