[pgsql-jp: 41867] Re: FATAL: canceling authentication due to timeout

[Shigeru Yanagibayashi]

かなり間が空いてしまいましたが、以前佐藤様に教えていただいた方法でテーブルを特定できるか試してみましたが、その後の問題発生時においてもテーブルを特定できるようなログが出力されませんでした。

別途ログを調査していたところ、「canceling authentication due to timeout」が一度発生直後に「expected password response, got message type 88」
が大量に記録されていました。

2016-04-28T17:05:32.460947+09:00 pgsql[6406]: [local1.err] [2-1] FATAL:  canceling authentication due to timeout
2016-04-28T17:05:32.470926+09:00 pgsql[9508]: [local1.info] [2-1] LOG:  expected password response, got message type 88
：
：300件ほど同じエラーが短時間に発生
：
2016-04-28T17:05:32.846750+09:00 pgsql[10403]: [local1.info] [2-1] LOG:  expected password response, got message type 88

他の日時にも同様の事象が一度発生していました。
以下を参照したところ、

//www.postgresql.org/message-id/ggocs4$2un5$1 ＠ news.hub.org

「It seems (not sure) to occur when user retypes password fast.」という記載がありましたが、今ひとつ確証を得られておりません。
何かご存じの方いらっしゃいましたら、是非情報をいただけると幸いです。


On 2014/12/19 09:28, Shigeru Yanagibayashi wrote:
> 柳林です。
>
> (2014/12/19 09:18), Tomoaki Sato wrote:
>> 単に負荷が高くて処理に時間がかかったか、VACUUM FULL などの強いロックを
>> 取る処理の実行中で、認証に必要なシステムカタログのロック待ちで時間がか
>> かったか、といったことが考えられます。
>>
>> log_lock_waits = on にしておくと、ロック待ちで deadlock_timeout に指定
>> された時間 (デフォルトでは 1s) を越えた場合にはテーブルを特定できます。
>>
>> 2014-12-19 09:03:46.306 JST [unknown][2254] LOG:  process 2254 still waiting for AccessShareLock on relation 1260 of database 0 after 1001.515 ms
>> 2014-12-19 09:04:45.304 JST [unknown][2254] FATAL:  canceling authentication due to timeout
>>
>> =# select '1260'::regclass;
>>   regclass
>> -----------
>>   pg_authid
>
> 有益な情報ありがとうございます。
> 早速試してみたいと思います。
>