概要
2013年9月9日から2013年9月15日までErogameScapeに接続できない状態でした。
2013年9月9日から2013年9月15日までErogameScapeに接続できない状態でした。
現在は復旧しております。
原因は有効なログが手元にないので推測の域をでないのですが、当時のpsコマンドの結果から、どれかのテーブル(おそらくuserreviewテーブル)のLOCKが獲得できなくてあらかじめ用意されたpostgresqlのコネクションを使い切ってpostgresqlへ接続できなくなり、ErogameScapeに接続できなくなったと思われます。
当時、どのテーブルがロックされ続けているのかの確認をするコマンドをうてばよかったのですが、うっていなかったため、どのテーブルのロックの獲得ができなかったのか特定ができません。
前に一度この事象が発生したことがあり、その際はpsコマンドの結果からおそらくユーザーSQLが原因であろうと推測し対策をしました。
具体的には新規に作成されたSQLは実行コストを制限するというものでした。
当時、既存のSQLについてはそのままとしたのですが、今回の件を受けて既存のSQLについてもコストを調査し、コストが高いものは非公開とさせて頂きました。
この結果、今まで使えていたSQLが使えなくなっています。
原因はユーザーSQLであるという確証はないのですが(psコマンドの結果からすると?な感じです)、そうではないという確証もないので、すみません、まずはこの対策をさせて頂きました。
waitingが多数発生した場合、ログに残してロックを解除するスクリプトがcloudpackブログ - cloudpack(クラウドパック)Amazon EC2などクラウドの導入設計、運用・保守サービス: Postgres waitingがたまったら強制解除にありましたので、こちらを実装しました。
障害が長引いたのは私が不在だったためです。
サーバーは必要最低限のアクセスしか出来ないようにしているので、障害があった際は私がサーバーの前まで行かないと復旧できません。
それはそれでどうかと思うのですが、私の知識で出来るセキュリティ対策と天秤にかけて、現状のようになっています。
この状況を解決するには私が賢くなるか、賢い方に教えて頂くかになると思うのですが、どちらもハードルが高いです。
詳細
ErogameScapeは2台のパソコンで動かしています。
DBにはpostgresqlを使用し、2台のパソコン各々にpostgresqlを動作させ、pgpoolで冗長を取っています。
当時の1台目のサーバーのpsコマンドの出力は以下の通りでした。
[********@erogamescape ~]$ cat 20130915.log | grep waiting 842 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(57118) LOCK TABLE waiting 871 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(57196) LOCK TABLE waiting 1108 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(57267) LOCK TABLE waiting 1109 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(57271) LOCK TABLE waiting 1116 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(57277) LOCK TABLE waiting 1214 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(57465) LOCK TABLE waiting 1700 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58063) LOCK TABLE waiting 1753 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58294) LOCK TABLE waiting 1857 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58383) LOCK TABLE waiting 1903 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58401) LOCK TABLE waiting 1908 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58436) LOCK TABLE waiting 1947 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58560) LOCK TABLE waiting 1986 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58672) LOCK TABLE waiting 2067 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58874) LOCK TABLE waiting 2089 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58983) LOCK TABLE waiting 2129 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(59131) LOCK TABLE waiting 2136 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(59169) LOCK TABLE waiting 2157 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(59253) LOCK TABLE waiting 2164 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(59264) LOCK TABLE waiting 2165 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(59272) LOCK TABLE waiting 2192 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(59307) LOCK TABLE waiting 2200 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(59359) LOCK TABLE waiting 2201 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(59376) LOCK TABLE waiting 2208 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(59491) LOCK TABLE waiting 2240 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(59892) LOCK TABLE waiting 2267 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60402) LOCK TABLE waiting 2313 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60563) LOCK TABLE waiting 2341 ? Ss 0:12 postgres: ******** ******** 192.168.0.2(33981) VACUUM waiting 2344 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60649) UPDATE waiting 2345 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60673) LOCK TABLE waiting 2432 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60752) LOCK TABLE waiting 2439 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60813) LOCK TABLE waiting 2446 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60832) LOCK TABLE waiting 2450 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60901) LOCK TABLE waiting 2451 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60928) LOCK TABLE waiting 2477 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(32849) LOCK TABLE waiting 2484 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(33128) LOCK TABLE waiting 2611 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(33531) LOCK TABLE waiting 2617 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(33608) LOCK TABLE waiting 2619 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(33620) LOCK TABLE waiting 2620 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(33625) LOCK TABLE waiting 2625 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(33861) LOCK TABLE waiting 2650 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(34543) LOCK TABLE waiting 2655 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(34959) LOCK TABLE waiting 2668 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(35158) LOCK TABLE waiting 2669 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(35191) LOCK TABLE waiting 2674 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(35354) LOCK TABLE waiting 2678 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(35470) LOCK TABLE waiting 2705 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(35851) LOCK TABLE waiting 2712 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(35938) LOCK TABLE waiting 2714 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(36009) LOCK TABLE waiting 2731 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(36291) LOCK TABLE waiting 2737 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(36809) LOCK TABLE waiting 2739 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(36969) LOCK TABLE waiting 2740 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(37003) LOCK TABLE waiting 2810 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(38692) LOCK TABLE waiting 2813 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(38823) LOCK TABLE waiting 2819 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(39241) LOCK TABLE waiting 2858 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(39561) LOCK TABLE waiting 2859 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(39675) LOCK TABLE waiting 2861 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(39737) LOCK TABLE waiting 2863 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(39816) LOCK TABLE waiting 2866 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(39947) LOCK TABLE waiting 2868 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(40134) LOCK TABLE waiting 2870 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(40216) LOCK TABLE waiting 2875 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(40577) LOCK TABLE waiting 2876 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(40763) LOCK TABLE waiting 2974 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(41120) LOCK TABLE waiting 3026 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(41192) LOCK TABLE waiting 3273 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(41457) LOCK TABLE waiting 3421 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(41712) LOCK TABLE waiting 3553 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(41892) LOCK TABLE waiting 3608 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(42292) LOCK TABLE waiting 3609 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(45322) LOCK TABLE waiting 3629 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(42615) LOCK TABLE waiting 3630 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(42622) LOCK TABLE waiting 3635 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(42796) LOCK TABLE waiting 3662 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(43240) LOCK TABLE waiting 3671 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(43487) LOCK TABLE waiting 3672 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(43593) LOCK TABLE waiting 3678 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(43842) LOCK TABLE waiting 3680 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(43962) LOCK TABLE waiting 3683 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(44065) LOCK TABLE waiting 3686 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(44138) LOCK TABLE waiting 3695 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(44410) LOCK TABLE waiting 3704 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(44484) LOCK TABLE waiting 3721 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(45363) LOCK TABLE waiting 3723 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(45430) LOCK TABLE waiting 3732 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(45703) LOCK TABLE waiting 3737 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(45932) LOCK TABLE waiting 3741 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(46241) LOCK TABLE waiting 3743 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(46263) LOCK TABLE waiting 3747 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(46358) LOCK TABLE waiting 3750 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(46375) LOCK TABLE waiting 3757 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(46431) LOCK TABLE waiting 3766 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(46475) LOCK TABLE waiting 3768 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(46667) LOCK TABLE waiting 3770 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(46885) LOCK TABLE waiting 3774 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(47164) LOCK TABLE waiting 3775 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(47245) LOCK TABLE waiting 3779 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(47858) LOCK TABLE waiting 3781 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(48012) LOCK TABLE waiting 3805 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(48638) LOCK TABLE waiting 3817 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(48769) LOCK TABLE waiting 3822 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(48837) LOCK TABLE waiting 3832 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(49218) LOCK TABLE waiting 3838 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(53792) LOCK TABLE waiting 3840 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(49396) LOCK TABLE waiting 3841 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(49414) LOCK TABLE waiting 3843 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(49516) LOCK TABLE waiting 3849 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(49600) LOCK TABLE waiting 3851 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(49633) LOCK TABLE waiting 3868 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(49701) LOCK TABLE waiting 3869 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(49705) LOCK TABLE waiting 3874 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(49807) LOCK TABLE waiting 3971 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(49878) LOCK TABLE waiting 4448 ? Ss 0:10 postgres: ******** ******** 192.168.0.2(58662) VACUUM waiting 4549 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(50041) LOCK TABLE waiting 4600 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(50127) LOCK TABLE waiting 5258 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(50368) LOCK TABLE waiting 5586 ? Ss 0:12 postgres: ******** ******** 192.168.0.2(50897) VACUUM waiting 5917 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(55418) LOCK TABLE waiting 5954 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(50495) LOCK TABLE waiting 5955 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(50501) LOCK TABLE waiting 5957 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(50505) LOCK TABLE waiting 6026 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(50595) LOCK TABLE waiting 6050 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(50629) LOCK TABLE waiting 6906 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(37406) LOCK TABLE waiting 7557 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(51042) LOCK TABLE waiting 8192 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(51140) LOCK TABLE waiting 8200 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(51154) LOCK TABLE waiting 8970 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(51282) LOCK TABLE waiting 9724 ? Ss 0:10 postgres: ******** ******** 192.168.0.2(55184) VACUUM waiting 10225 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(52159) LOCK TABLE waiting 10671 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58523) LOCK TABLE waiting 10681 ? Ss 0:13 postgres: ******** ******** 192.168.0.2(59101) VACUUM waiting 13081 ? Ss 0:11 postgres: ******** ******** 192.168.0.2(42113) VACUUM waiting 13949 ? Ss 0:12 postgres: ******** ******** 192.168.0.2(60879) VACUUM waiting 14340 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(36418) LOCK TABLE waiting 16205 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(43918) LOCK TABLE waiting 16504 ? Ss 0:07 postgres: ******** ******** 192.168.0.2(46920) VACUUM waiting 16518 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(53097) LOCK TABLE waiting 17357 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(53245) LOCK TABLE waiting 17387 ? Ss 0:11 postgres: ******** ******** 192.168.0.2(38856) VACUUM waiting 19877 ? Ss 0:04 postgres: ******** ******** 192.168.0.2(53310) VACUUM waiting 20628 ? Ss 0:10 postgres: ******** ******** 192.168.0.2(48334) VACUUM waiting 22710 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(54272) LOCK TABLE waiting 23173 ? Ss 0:15 postgres: ******** ******** 192.168.0.2(58004) VACUUM waiting 23712 ? Ss 0:10 postgres: ******** ******** 192.168.0.2(48797) VACUUM waiting 24642 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(54489) LOCK TABLE waiting 25813 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(45276) LOCK TABLE waiting 25986 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(50454) LOCK TABLE waiting 26094 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(53746) LOCK TABLE waiting 26450 ? Ss 0:11 postgres: ******** ******** 192.168.0.2(35952) VACUUM waiting 27000 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(35568) LOCK TABLE waiting 27075 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(39790) LOCK TABLE waiting 27078 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(39899) LOCK TABLE waiting 27276 ? Ss 0:10 postgres: ******** ******** 192.168.0.2(60642) VACUUM waiting 27856 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(47920) LOCK TABLE waiting 28042 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(53992) LOCK TABLE waiting 28051 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(54198) LOCK TABLE waiting 28150 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58474) LOCK TABLE waiting 28298 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(36520) LOCK TABLE waiting 28773 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(38179) LOCK TABLE waiting 28986 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(41314) LOCK TABLE waiting 28997 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(41431) LOCK TABLE waiting 29037 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(42460) LOCK TABLE waiting 29062 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(44100) LOCK TABLE waiting 29114 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(45545) LOCK TABLE waiting 29129 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(45627) LOCK TABLE waiting 29152 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(46473) LOCK TABLE waiting 29177 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(47993) DELETE waiting 29192 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(48813) LOCK TABLE waiting 29223 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(52453) LOCK TABLE waiting 29286 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(54872) LOCK TABLE waiting 29354 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(59312) LOCK TABLE waiting 29607 ? Ss 0:10 postgres: ******** ******** 192.168.0.2(52579) VACUUM waiting 29788 ? Ss 0:08 postgres: ******** ******** 192.168.0.2(43110) VACUUM waiting 29985 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(33745) LOCK TABLE waiting 30002 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(34163) LOCK TABLE waiting 30062 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(35973) LOCK TABLE waiting 30090 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(38160) LOCK TABLE waiting 30099 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(38277) LOCK TABLE waiting 30124 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(40599) LOCK TABLE waiting 30144 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(41052) LOCK TABLE waiting 30150 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(41633) LOCK TABLE waiting 30219 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(43994) LOCK TABLE waiting 30220 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(44032) LOCK TABLE waiting 30222 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(44058) LOCK TABLE waiting 30235 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(44598) LOCK TABLE waiting 30236 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(44681) LOCK TABLE waiting 30237 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(44729) LOCK TABLE waiting 30258 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(45182) LOCK TABLE waiting 30259 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(45237) LOCK TABLE waiting 30260 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(45402) LOCK TABLE waiting 30261 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(45427) LOCK TABLE waiting 30270 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(45880) LOCK TABLE waiting 30271 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(45906) LOCK TABLE waiting 30321 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(46702) LOCK TABLE waiting 30336 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(47241) LOCK TABLE waiting 30342 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(47432) LOCK TABLE waiting 30377 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(47775) LOCK TABLE waiting 30387 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(48193) LOCK TABLE waiting 30392 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(48829) LOCK TABLE waiting 30399 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(49109) LOCK TABLE waiting 30402 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(49118) LOCK TABLE waiting 30407 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(49146) LOCK TABLE waiting 30419 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(49348) LOCK TABLE waiting 30564 ? Ss 0:07 postgres: ******** ******** 192.168.0.2(42302) VACUUM waiting 31016 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(50460) LOCK TABLE waiting 31056 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(51483) LOCK TABLE waiting 31060 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(51621) LOCK TABLE waiting 31070 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(52276) LOCK TABLE waiting 31081 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(52532) LOCK TABLE waiting 31134 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(53156) LOCK TABLE waiting 31135 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(53179) LOCK TABLE waiting 31140 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(53375) LOCK TABLE waiting 31151 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(53735) LOCK TABLE waiting 31157 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(53961) LOCK TABLE waiting 31159 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(54045) LOCK TABLE waiting 31161 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(54186) LOCK TABLE waiting 31164 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(54273) LOCK TABLE waiting 31169 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(54534) LOCK TABLE waiting 31178 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(54918) LOCK TABLE waiting 31182 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(55034) LOCK TABLE waiting 31186 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(55143) LOCK TABLE waiting 31194 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(55817) LOCK TABLE waiting 31200 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(55884) LOCK TABLE waiting 31204 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(55992) LOCK TABLE waiting 31209 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(56090) LOCK TABLE waiting 31218 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(56150) LOCK TABLE waiting 31219 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(56167) LOCK TABLE waiting 31222 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(56258) LOCK TABLE waiting 31223 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(56298) LOCK TABLE waiting 31225 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(56308) LOCK TABLE waiting 31231 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(56393) LOCK TABLE waiting 31240 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(56447) LOCK TABLE waiting 31241 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(56451) LOCK TABLE waiting 31308 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(56641) LOCK TABLE waiting 31916 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(56728) LOCK TABLE waiting 31918 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(56738) LOCK TABLE waiting 31972 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(56791) LOCK TABLE waiting 31977 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(56809) LOCK TABLE waiting 31995 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(56839) LOCK TABLE waiting 32066 ? Ss 0:37 postgres: ******** ******** 192.168.0.2(60697) VACUUM waiting 32483 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(53850) LOCK TABLE waitingテーブルのロック待ちが発生しているのが一目瞭然です。
もう一台のサーバーのpsコマンドの結果は以下のとおりでした。
[********@erogamescape ~]$ cat 20130915.log | grep postgres | grep -v nobody 616 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(49421) idle in transaction 651 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(49584) idle in transaction 661 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(49670) idle in transaction 1279 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(49911) idle in transaction 1892 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(50019) idle 1894 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(50038) idle in transaction 1895 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(50044) idle in transaction 1896 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(50048) idle in transaction 1916 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(50123) idle 1919 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(50138) idle in transaction 1932 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(50172) idle in transaction 2520 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(50263) idle 2529 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(50293) idle 2534 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(50299) idle 3483 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(50577) idle 3737 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(50585) idle in transaction 3760 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(50683) idle in transaction 3765 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(50697) idle in transaction 4360 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(50825) idle in transaction 10543 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(52640) idle in transaction 11148 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(52788) idle in transaction 13556 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(49712) idle 13578 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(51879) idle 14197 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60233) idle 14218 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58293) idle 14814 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58441) idle 14824 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(53691) idle 14899 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(53185) idle 15053 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(53335) idle in transaction 15313 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58856) idle 15394 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58491) idle 15397 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58503) idle 15408 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58529) idle 15410 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58547) idle 15437 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(53815) idle in transaction 16060 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(40859) idle 16859 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(35176) idle 24607 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(44819) idle in transaction 25500 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(35111) idle in transaction 25648 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(46074) idle 25695 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(46095) idle 25810 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(46322) idle 26324 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(53535) idle in transaction 26365 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(55963) idle 26391 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(57880) idle 26393 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58017) idle in transaction 26394 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58043) idle 26469 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(36386) idle 27042 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(37691) idle 27069 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(38970) idle 27148 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(43620) idle 27169 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(45088) idle in transaction 27186 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(53393) idle in transaction 27207 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(47572) idle 27209 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(47668) idle 27213 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(48037) idle 27241 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(51960) idle 27243 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(51996) idle in transaction 27249 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(52312) idle 27274 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(54356) idle 27276 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(54417) idle in transaction 27278 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(54484) idle 27282 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(54598) idle 27298 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(55962) idle 27301 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(56472) idle 27303 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(56754) idle 27917 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(33646) idle 27919 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(33706) idle in transaction 27925 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(34100) idle 27948 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(35516) idle in transaction 27952 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(36091) idle 27956 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(36785) idle 27990 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(41054) idle 28080 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(47736) idle in transaction 28676 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(49782) idle 28705 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(52356) idle 28709 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(55858) idle 28731 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(53504) idle in transaction 31245 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(57008) idle in transaction 31293 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(57180) idle 31294 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(57361) idle 31296 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(57674) idle 31305 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(57798) idle 31324 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(57921) idle 31325 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(57926) idle in transaction 31328 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(57944) idle in transaction 31333 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(57979) idle in transaction 31357 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58103) idle in transaction 31379 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58215) idle in transaction 31384 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58268) idle 31391 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58280) idle 31397 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58313) idle 31411 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58386) idle 31413 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58417) idle in transaction 31427 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58515) idle 31429 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58526) idle in transaction 31450 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58630) idle 31456 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58674) idle in transaction 31461 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58712) idle in transaction 31464 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58743) idle 31467 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58762) idle 31469 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58774) idle 31474 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58796) idle in transaction 31480 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58807) idle in transaction 31481 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58815) idle in transaction 31482 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58821) idle 31491 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58840) idle 31492 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58846) idle 31493 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58850) idle in transaction 31500 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58902) idle in transaction 31501 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58919) idle in transaction 31503 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(58971) idle 31508 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(59034) idle in transaction 31509 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(59057) idle 31511 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(59179) idle 31512 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(59188) idle 31518 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(59435) idle in transaction 31520 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(59631) idle 31523 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(59836) idle 31524 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(59945) idle in transaction 31525 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(59955) idle 31526 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(59994) idle 31527 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60029) idle 31529 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60089) idle 31531 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60106) idle in transaction 31533 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60192) idle in transaction 31534 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60216) idle in transaction 31535 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60231) idle 31537 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60252) idle 31540 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60295) idle in transaction 31547 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60356) idle in transaction 31548 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60359) idle 31550 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60375) idle in transaction 31553 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60444) idle in transaction 31554 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60471) idle in transaction 31558 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60625) idle in transaction 31559 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60721) idle 31560 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60806) idle 31561 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60883) idle 31562 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(60904) idle in transaction 31564 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(33074) idle in transaction 31566 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(33151) idle in transaction 31567 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(33163) idle in transaction 31568 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(33168) idle in transaction 31571 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(33404) idle in transaction 31572 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(33597) idle 31573 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(33655) idle 31575 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(33687) idle 31576 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(33917) idle 31577 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(33992) idle 31578 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(34082) idle 31579 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(34086) idle in transaction 31580 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(34260) idle 31582 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(34374) idle 31583 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(34378) idle 31584 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(34494) idle 31585 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(34502) idle in transaction 31586 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(34507) idle 31590 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(34701) idle in transaction 31591 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(34735) idle 31592 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(34737) idle in transaction 31594 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(34897) idle in transaction 31595 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(35009) idle 31596 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(35013) idle in transaction 31603 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(35252) idle 31606 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(35342) idle 31608 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(35394) idle in transaction 31615 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(35481) idle in transaction 31616 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(35552) idle in transaction 31618 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(35567) idle 31621 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(35703) idle 31622 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(35802) idle 31623 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(35834) idle in transaction 31625 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(36084) idle 31628 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(36352) idle in transaction 31630 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(36512) idle in transaction 31631 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(36546) idle in transaction 31634 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(36750) idle 31636 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(36853) idle 31637 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(36936) idle 31644 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(37151) idle 31645 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(37278) idle 31647 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(37519) idle 31654 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(37841) idle 31655 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(37900) idle 31657 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(38235) idle in transaction 31660 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(38366) idle in transaction 31661 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(38427) idle 31664 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(38718) idle 31665 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(38784) idle in transaction 31667 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(38927) idle 31670 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(39104) idle in transaction 31671 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(39218) idle in transaction 31672 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(39280) idle in transaction 31674 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(39359) idle in transaction 31676 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(39406) idle 31677 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(39490) idle in transaction 31680 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(39677) idle in transaction 31682 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(39759) idle in transaction 31684 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(39949) idle 31687 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(40120) idle in transaction 31688 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(40306) idle in transaction 31690 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(40495) idle 31695 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(40663) idle in transaction 31708 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(40697) idle 31733 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(40713) idle 31785 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(40735) idle in transaction 32039 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(41000) idle in transaction 32064 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(41029) idle 32093 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(41101) idle 32101 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(41110) idle 32231 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(41255) idle in transaction 32237 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(41287) idle 32294 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(41360) idle 32295 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(41435) idle in transaction 32296 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(41489) idle 32297 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(41498) idle 32299 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(41586) idle 32305 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(41835) idle in transaction 32307 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(42018) idle 32308 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(42033) idle 32310 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(42052) idle 32313 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(42158) idle in transaction 32314 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(42165) idle in transaction 32316 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(42339) idle in transaction 32318 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(42407) idle 32336 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(42777) idle 32337 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(42783) idle in transaction 32341 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(42991) idle 32343 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(43030) idle in transaction 32344 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(43136) idle in transaction 32346 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(43292) idle 32348 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(43385) idle in transaction 32350 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(43505) idle in transaction 32352 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(43608) idle in transaction 32353 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(43669) idle 32354 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(43681) idle in transaction 32356 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(43953) idle in transaction 32357 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(44027) idle in transaction 32358 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(44110) idle 32360 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(44320) idle 32364 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(44567) idle 32367 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(44675) idle 32370 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(44906) idle in transaction 32371 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(44960) idle 32372 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(44973) idle in transaction 32374 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(45012) idle 32379 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(45246) idle in transaction 32383 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(45397) idle 32384 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(45475) idle in transaction 32388 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(45784) idle in transaction 32390 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(45806) idle in transaction 32393 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(45901) idle in transaction 32394 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(45918) idle in transaction 32395 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(45946) idle 32396 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(45974) idle in transaction 32397 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(46018) idle in transaction 32398 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(46210) idle in transaction 32400 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(46428) idle in transaction 32403 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(46564) idle 32404 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(46707) idle in transaction 32406 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(46788) idle in transaction 32409 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(47401) idle in transaction 32410 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(47555) idle in transaction 32411 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(47607) idle 32412 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(47725) idle 32416 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(48181) idle in transaction 32425 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(48266) idle 32426 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(48312) idle in transaction 32431 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(48380) idle in transaction 32441 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(48761) idle in transaction 32444 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(48829) idle 32445 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(48899) idle 32447 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(48939) idle in transaction 32448 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(48957) idle in transaction 32451 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(49059) idle in transaction 32456 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(49143) idle in transaction 32458 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(49176) idle in transaction 32465 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(49244) idle in transaction 32466 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(49248) idle in transaction 32472 ? Ss 0:00 postgres: ******** ******** 192.168.0.2(49350) idle in transactionトランザクション中でアイドルのプロセスがいっばいです。
ここで、どのテーブルがロック待ちなのか、pg_stat_activityテーブル、pg_locksテーブルの内容を保存してから再起動すればよかったのですが、当時の私にそんな知識はなかったので、再起動してしまいました。
結果、何が原因だったのか分かりません。
ただpsコマンドの結果から、どのユーザー権限で実行されたSQLか?は分かりました。
LOCK TABLE waitingとなっているプロセスは、ユーザーSQLを実行する権限でした。
ユーザーSQLには実行に超時間要するものがあり、今回のような事象を引き起こす可能性が高いと判断しました。
そこで、実行コストの高いユーザーSQLを非公開とさせて頂きました。
(再度公開とするためには、現在規定しているコスト以下に修正する必要があります。)
今回のような事象を引き起こした原因の1つは、長期ロック保持があるかを確認すべきところしていなかったことにあると思っています。
ロック待ちとなっている処理内容は稼動統計情報を活用しよう(2)—Let's Postgresで確認できることが分かりましたので、cronで定期時にSQLをチェックし、ロック待ちとなっている処理を常時確認できるようにいたしました。
またloudpackブログ - cloudpack(クラウドパック)Amazon EC2などクラウドの導入設計、運用・保守サービス: Postgres waitingがたまったら強制解除を参考に、waitingが発生しているプロセスが5を超えて発生した場合、in transactionなSQLの接続を強制的に切断するようにしました。
今回の例ではin transactionな状態になっているのは、もう一つのサーバーのみでした。
もう一つのサーバーのみSQLの接続が強制的に切断された場合、pgpoolがどのような動作をするのか検証していないので不明です。
サーバー同士でデータの不整合が発生する可能性があります。
今回のような事象が発生する前に、ロック待ちとなっている処理を確認できることを祈ります。
ログがないのでなんともですが、上図のCPUの使用率からLOCK TABLE waitingが発生したのは8日の12時以降と推測します。
そしてサーバーが応答できなくなったのは、9日の12時頃と推測します。
同じ原因でLOCK TABLE watingが発生しても1日は耐えられそうですので、自分が不在でなければユーザーのみなさんに分からないうちに対処が完了できると思っています。
終わりに
以上が事象の報告と対策のご説明です。
大変ご迷惑をおかけいたしました。
また、「こうした方がいい」というご意見がございましたら、ぜひコメントを頂きたく思います。
今後ともよろしくお願いします。
ただpsコマンドの結果から、どのユーザー権限で実行されたSQLか?は分かりました。
LOCK TABLE waitingとなっているプロセスは、ユーザーSQLを実行する権限でした。
ユーザーSQLには実行に超時間要するものがあり、今回のような事象を引き起こす可能性が高いと判断しました。
そこで、実行コストの高いユーザーSQLを非公開とさせて頂きました。
(再度公開とするためには、現在規定しているコスト以下に修正する必要があります。)
今回のような事象を引き起こした原因の1つは、長期ロック保持があるかを確認すべきところしていなかったことにあると思っています。
ロック待ちとなっている処理内容は稼動統計情報を活用しよう(2)—Let's Postgresで確認できることが分かりましたので、cronで定期時にSQLをチェックし、ロック待ちとなっている処理を常時確認できるようにいたしました。
またloudpackブログ - cloudpack(クラウドパック)Amazon EC2などクラウドの導入設計、運用・保守サービス: Postgres waitingがたまったら強制解除を参考に、waitingが発生しているプロセスが5を超えて発生した場合、in transactionなSQLの接続を強制的に切断するようにしました。
今回の例ではin transactionな状態になっているのは、もう一つのサーバーのみでした。
もう一つのサーバーのみSQLの接続が強制的に切断された場合、pgpoolがどのような動作をするのか検証していないので不明です。
サーバー同士でデータの不整合が発生する可能性があります。
今回のような事象が発生する前に、ロック待ちとなっている処理を確認できることを祈ります。
ログがないのでなんともですが、上図のCPUの使用率からLOCK TABLE waitingが発生したのは8日の12時以降と推測します。
そしてサーバーが応答できなくなったのは、9日の12時頃と推測します。
同じ原因でLOCK TABLE watingが発生しても1日は耐えられそうですので、自分が不在でなければユーザーのみなさんに分からないうちに対処が完了できると思っています。
終わりに
以上が事象の報告と対策のご説明です。
大変ご迷惑をおかけいたしました。
また、「こうした方がいい」というご意見がございましたら、ぜひコメントを頂きたく思います。
今後ともよろしくお願いします。