困り事相談

postgres の動作の知見をいただきたく、質問させていただきます。

◆現象
　postgres サービスを停止(正常終了)したが、
　プロセス postgres.exe が、15分程度いくつか動作したままになっている
　
　※Windows環境
　※発生環境(顧客環境で、開発で再現できず)では
　・pg_ctl.exe -> なし(終了)
　・postgres.exe -> 5件
　が、サービス停止後も15分程度動作していた
　※
　　C:/Program Files/xxxx/xxxxx/postgresql/bin/pg_ctl.exe runservice -N "DatabaseServer" -D "C:/Program Files/xxxx/xxxxx/postgresql/data" -w
　　のパスで、postgres のサービスを起動/停止している

◆確認したいこと
　1.上記のようにプロセスが残存するのは正常動作なのか?
　2.上記の現象はどういう場合に発生するのか?
　3.上記の状態で、postgres サービスを再度起動すると起動に失敗するか?
　　※イベントログに
　　2016-07-13 12:26:32 GMT::@:[1504]: FATAL:  lock file "postmaster.pid" already exists
　　2016-07-13 12:26:32 GMT::@:[1504]: HINT:  Is another postmaster (PID 1472) running in data directory "D:/xxxx/xxxxx/postgresql/data"?
　　などが出ており、上記残存プロセスがロックしていたのではないかと推測しています。

第一感

こちとら、承認欲求拗らせたQiita投稿厨が社内データベース大臣になってしまったけど、PostgreSQL歴3年半しかないの。2013/1に異動になって、前任者の肩越しにコンソール作業覗いて「ぽすぐれのSQLインタプリターはpsqlっていうんだ」と初めて知って自席で大急ぎでググってたの。ましてWindows版のServiceの異常動作なんてわかるわけないじゃない。客先だけの現象とか、絶対無理。この肩書き背負ってられるのもここまで。

という心境でごめんなさいメールを書き始めたところ、突然神託が降りてきた。

神託

これは「SQLアンチパターン」の和田サンが、締めのスライドにしているお言葉。
2016-07-30に岡山での中国地方DB勉強会で再見したばかりだったから、連想トリガになってくれたんじゃないかな。

この問題！篠田の虎の巻でやったところだ！

2016-03月の社内読書会ではとくに引っかかりも議論にもならなかったんですが、「2.3.3 インスタンス停止失敗時の動作」検証があるんですよ。Linux上の検証ですけど。

pg_ctl stop -m smart コマンドは接続ユーザーの終了を待ちますが、タイムアウト（デフ
ォルト 60 秒）を経過すると pg_ctl コマンドが戻り値１で終了します。
タイムアウトした場合でも、インスタンスはシャットダウン中のステータスのままです。
このため、新規のクライアント接続はできない状態に陥ります。既存のセッションがすべて
終了すると自動的にインスタンスは終了します。

ということで、誰か接続したままになっているのではないでしょうか？

pg_ctl はサービスをシャットダウン中のステータスにして返ってくる。
既存のセッションがいきているから postgres.exe が残っている。

所要時間

約30分
やっててよかったDB読書会。
行ってよかった中国地方DB勉強会 in 岡山。

篠田の虎の巻ことPostgreSQL Internals(1) はPostgreSQLとつきあうなら、各人の携帯端末で常に持ち歩いておくといいですよ。

第二次相談

あくまで実施結果ではあるのですが、
net stop で実行すると、fast モードでシャットダウンされています。
※ net stop でのシャットダウンモードについて、デフォルトやモード指定方法についての情報を
Webでだいぶさがしたのですが見つけられませんでした。

上記コマンド実施時の、data/pg_log/ 下ログ:

postgresql.log

  15:35:43 JST::@:[3924]: LOG:  received fast shutdown request
  15:35:43 JST::@:[3924]: LOG:  aborting any active transactions
  15:35:43 JST::@:[3272]: LOG:  autovacuum launcher shutting down
  15:35:44 JST::@:[2960]: LOG:  shutting down
  15:35:44 JST::@:[2960]: LOG:  database system is shut down

第二次調査

本当だ。同じような状況の質問は2つほど拾えたけど、誰も答えてない。
自分のWindows7でもそうなるし、Webで拾った質問だと Win 2008 64 R2 serverでも同じらしい。
明示してないのに、デフォルトの smart じゃなくて、fast を使うとは油断ならんというか、不自然というか。

まさかのご本人降臨

net stop でのシャットダウンモードについて、Slack(postgresql-jp.slack.com)で質問したら、虎の巻の篠田さんがソースチェックしてくださいました。

PostgreSQL 9.3のソースを見ると、src/bin/pg_ctl/pg_ctl.c のpgwin32_ServiceMain関数で、kill(postmasterPID, SIGINT); している。

ハードコーディングでの"Fast"モードでした。
Slackでは 9.5以降は、pg_ctl のデフォールトモードが "Smart"から"Fast"に変わったことの注意喚起ももらいました。

中間まとめ

虎の巻の引用部分をFastで読み替えると

pg_ctl stop -m fast コマンドは実行中のトランザクションをロールバックし、クライアントとの接続を強制的に切断した後、サーバを停止しますが、タイムアウト（デフォルト 60 秒）を経過すると pg_ctl コマンドが戻り値１で終了します。
タイムアウトした場合でも、インスタンスはシャットダウン中のステータスのままです。
このため、新規のクライアント接続はできない状態に陥ります。既存のセッションがすべて終了すると自動的にインスタンスは終了します。

実検証していませんが、こうでしょうね。

残る謎は、なぜrollbackに15分もかかるセッションがあるのか。しかも複数。　
rollbackでデッドロックは、RDBMSとして設計レベルで回避してるだろうに。