ログ日記

作業ログと日記とメモ

トップ > PostgreSQL > トランザクションIDがループ？

トランザクションIDがループ？

PostgreSQL

データベースが落ちてた。

2009-09-27 06:35:15 JST LOG:  transaction ID wrap limit is 2147484146, limited by database "template1"
2009-09-27 06:35:15 JST WARNING:  database "template1" must be vacuumed within 536699235 transactions
2009-09-27 06:35:15 JST HINT:  To avoid a database shutdown, execute a full-database VACUUM in "template1".
2009-09-27 06:35:15 JST LOG:  autovacuum process (PID 8137) was terminated by signal 11
2009-09-27 06:35:15 JST LOG:  terminating any other active server processes
2009-09-27 06:35:15 JST LOG:  all server processes terminated; reinitializing
2009-09-27 06:35:15 JST LOG:  database system was interrupted at 2009-09-27 06:34:04 JST
2009-09-27 06:35:15 JST LOG:  checkpoint record is at 3/D855E940
2009-09-27 06:35:15 JST LOG:  redo record is at 3/D855E940; undo record is at 0/0; shutdown TRUE
2009-09-27 06:35:15 JST LOG:  next transaction ID: 1610782932; next OID: 25286
2009-09-27 06:35:15 JST LOG:  next MultiXactId: 32; next MultiXactOffset: 63
2009-09-27 06:35:15 JST LOG:  database system was not properly shut down; automatic recovery in progress
2009-09-27 06:35:16 JST LOG:  redo starts at 3/D855E984
2009-09-27 06:35:16 JST LOG:  record with zero length at 3/D856324C
2009-09-27 06:35:16 JST LOG:  redo done at 3/D8563224
2009-09-27 06:35:16 JST LOG:  database system is ready
2009-09-27 06:35:16 JST LOG:  transaction ID wrap limit is 2147484146, limited by database "hogehoge"

このログに気付かず…

2009-09-27 10:29:29 JST LOG:  transaction ID wrap limit is 2147484146, limited by database "template1"
2009-09-27 10:29:29 JST WARNING:  database "template1" must be vacuumed within 536349130 transactions
2009-09-27 10:29:29 JST HINT:  To avoid a database shutdown, execute a full-database VACUUM in "template1".
2009-09-27 10:29:29 JST LOG:  autovacuum process (PID 26589) was terminated by signal 11
2009-09-27 10:29:29 JST LOG:  terminating any other active server processes
2009-09-27 10:29:40 JST FATAL:  the database system is in recovery mode
2009-09-27 10:29:40 JST FATAL:  the database system is in recovery mode
2009-09-27 10:29:47 JST FATAL:  the database system is in recovery mode
2009-09-27 10:29:47 JST FATAL:  the database system is in recovery mode
2009-09-27 10:29:50 JST FATAL:  the database system is in recovery mode
2009-09-27 10:29:50 JST FATAL:  the database system is in recovery mode

落ちた。



postgres=# select version();
                                                    version
----------------------------------------------------------------------------------------------------------------
 PostgreSQL 8.1.15 on i486-pc-linux-gnu, compiled by GCC cc (GCC) 4.1.2 20061115 (prerelease) (Debian 4.1.1-21)
mp_live=# select datname, datvacuumxid, datfrozenxid, age(datfrozenxid)
from pg_database;
datname | datvacuumxid | datfrozenxid | age
-----------+--------------+--------------+-------------
postgres  | 2140511881 | 1070040079 | 1078428152
mp_live   | 2140510678 | 1066768855 | 1081699376
template1 | 2140511881 | 1070047126 | 1078421105
template0 |        499 |        499 | -2146499564
mp_base   | 2140511881 | 1070049511 | 1078418720
(5 rows)
http://archives.free.net.ph/message/20080602.121520.3db27680.ja.html

初めはこんな感じだった。
マイナスにはなってなかったけども…あまり意味が分かってない。499って何だろ。

> 今後はすべてのデーターベースに対してやりたいと思います。
> vacuumdb -a -z
> でいいんですよね。

　それで良いと思います。
　ご健闘を祈ります。

http://ml.postgresql.jp/pipermail/pgsql-jp/2006-September/021121.html

ということでやってみる。
しばらくの間は

2009-09-27 15:37:06 JST LOG:  autovacuum: processing database "template0"
2009-09-27 15:37:06 JST LOG:  transaction ID wrap limit is 2685012982, limited by database "postgres"
2009-09-27 15:37:06 JST LOG:  autovacuum process (PID 18709) was terminated by signal 11
2009-09-27 15:37:06 JST LOG:  terminating any other active server processes
2009-09-27 15:37:06 JST LOG:  all server processes terminated; reinitializing
2009-09-27 15:37:06 JST LOG:  database system was interrupted at 2009-09-27 15:36:06 JST
2009-09-27 15:37:06 JST LOG:  checkpoint record is at 3/D8ED4BB4
2009-09-27 15:37:06 JST LOG:  redo record is at 3/D8ED4BB4; undo record is at 0/0; shutdown TRUE
2009-09-27 15:37:06 JST LOG:  next transaction ID: 1611493174; next OID: 58054
2009-09-27 15:37:06 JST LOG:  next MultiXactId: 32; next MultiXactOffset: 63
2009-09-27 15:37:06 JST LOG:  database system was not properly shut down; automatic recovery in progress
2009-09-27 15:37:06 JST LOG:  redo starts at 3/D8ED4BF8
2009-09-27 15:37:06 JST LOG:  record with zero length at 3/D8ED8274
2009-09-27 15:37:06 JST LOG:  redo done at 3/D8ED824C
2009-09-27 15:37:06 JST LOG:  database system is ready
2009-09-27 15:37:06 JST LOG:  transaction ID wrap limit is 2685012982, limited by database "postgres"

こんなログがずっと出てた。
template0はvacuumとは関係ないんだよね…自信なし。


そして度々autovacuumでWarningが出る。

2009-09-27 15:40:24 JST WARNING:  terminating connection because of crash of another server process
2009-09-27 15:40:24 JST DETAIL:  The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally
 and possibly corrupted shared memory.
2009-09-27 15:40:24 JST HINT:  In a moment you should be able to reconnect to the database and repeat your command.

普通のクエリもWARNINGで落ちて通らない時がある。



そんで数十分ほど調べてる間にWarningが出なくなってた。
時間差？



というかautovacuum使ってるから大丈夫と思ってたんだけど、どうやらダメだったみたい。
警告が出る前のログは

2009-09-27 01:46:08 JST LOG:  autovacuum: processing database "hogehoge"
2009-09-27 01:47:10 JST LOG:  autovacuum: processing database "postgres"
2009-09-27 01:48:10 JST LOG:  autovacuum: processing database "hogehoge"
2009-09-27 01:49:27 JST LOG:  autovacuum: processing database "postgres"

これ。template1に対するvacuumが必要？で、現状は

2009-09-27 16:06:03 JST LOG:  autovacuum: processing database "hogehoge"
2009-09-27 16:07:45 JST LOG:  autovacuum: processing database "postgres"
2009-09-27 16:08:52 JST LOG:  autovacuum: processing database "template0"
2009-09-27 16:09:53 JST LOG:  autovacuum: processing database "hogehoge"
2009-09-27 16:11:12 JST LOG:  autovacuum: processing database "postgres"
2009-09-27 16:12:18 JST LOG:  autovacuum: processing database "template0"

うーん。よく分からない。
ずっと止まってたtemplate0のageも少しずつ上がってきたし、499の値が変わってた。



どの時点で何が変わったのか分からないまま取り敢えずエラーは出なくなった…。

過去のバックアップなどから失われたトランザクションが何かを調べ、
現在の状態のバックアップをとっておいて
pg_resetxlogやpg_filedumpを使ってトランザクションIDを書き換え
段階的に取り出す。ということが(理論的には)可能かもしれません。

http://ml.postgresql.jp/pipermail/pgsql-jp/2005-November/019994.html

こういう処理が走っている？

datvacuumxid xid この値より前のIDを持つトランザクションによって挿入あるいは削除された全ての行は、コミット済みあるいはアボート済みのものとして認識されています。コミットログ空間を再利用できるかどうかを判断する際に使用されます。
datfrozenxid xid このデータベースの中で、datfrozenxidよりも前のIDを持つトランザクションによって挿入された全ての行は、恒久的な（「凍結した」）トランザクションIDを持つように変更されています。トランザクションIDの回り込み問題を解決するために、データベースにVACUUMをかける必要があるかどうか判断する際に役立ちます。

http://www.postgresql.jp/document/pg813doc/html/catalog-pg-database.html

autovacuumが何をしてくれて、何をしてくれないのかを正確に把握しないと…。