Обсуждение: Template zero xid issue
Our template 0 database has an XID issue:
postgres=# select datname, age(datfrozenxid) from pg_database;
datname | age
--------------+------------
postgres | 1073965753
.
.
.
template1 | 1073892377
template0 | 2146706522
(7 rows)
When we try a vacuum full, it skips template 0:
[root@p02c06d130 mxl]# /mxl/var/pgsql/bin/vacuumdb -a -z -U postgres
vacuumdb: vacuuming database "postgres"
VACUUM
.
.
.
VACUUM
vacuumdb: vacuuming database "template1"
VACUUM
Suggestions for how to fix this issue?
Thanks,
Keaton
"Keaton Adams" <kadams@mxlogic.com> writes:
> Our template 0 database has an XID issue:
No, it doesn't. template0 never needs vacuuming.
regards, tom lane
Our production DB shut down because of it:
<2007-08-06 09:44:08 MDT>LOG: background writer process (PID 24439)
exited with exit code 0
<2007-08-06 09:44:08 MDT>LOG: terminating any other active server
processes
<2007-08-06 09:44:08 MDT>LOG: all server processes terminated;
reinitializing
<2007-08-06 09:44:08 MDT>LOG: database system was shut down at
2007-08-06 09:44:08 MDT
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>LOG: checkpoint record is at 1A7/4C987A2C
<2007-08-06 09:44:08 MDT>LOG: redo record is at 1A7/4C987A2C; undo
record is at 0/0; shutdown TRUE
<2007-08-06 09:44:08 MDT>LOG: next transaction ID: 2146747335; next
OID: 677503791
<2007-08-06 09:44:08 MDT>LOG: next MultiXactId: 2937; next
MultiXactOffset: 5901
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>LOG: database system is ready
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>LOG: transaction ID wrap limit is 2147484146,
limited by database "template0"
<2007-08-06 09:44:08 MDT>WARNING: database "template0" must be vacuumed
within 736811 transactions
<2007-08-06 09:44:08 MDT>HINT: To avoid a database shutdown, execute a
full-database VACUUM in "template0".
<2007-08-06 09:44:08 MDT>LOG: shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>LOG: database system is shut down
-----Original Message-----
From: Tom Lane [mailto:tgl@sss.pgh.pa.us]
Sent: Monday, August 06, 2007 9:51 AM
To: Keaton Adams
Cc: pgsql-general@postgresql.org
Subject: Re: [GENERAL] Template zero xid issue
"Keaton Adams" <kadams@mxlogic.com> writes:
> Our template 0 database has an XID issue:
No, it doesn't. template0 never needs vacuuming.
regards, tom lane
So it is odd that over 14,000 XIDs are being consumed on template zero
in just over one minute?
bash-3.00$ date; psql -dpostgres -frun.sql
Mon Aug 6 10:18:12 MDT 2007
datname | age
--------------+------------
postgres | 1074342864
.
.
.
template1 | 1074269488
template0 | 1074078525
(7 rows)
bash-3.00$ date; psql -dpostgres -frun.sql
Mon Aug 6 10:19:27 MDT 2007
datname | age
--------------+------------
postgres | 1074357079
.
.
.
template1 | 1074283703
template0 | 1074092740
(7 rows)
What would be using template0 at this rate?
-Keaton
-----Original Message-----
From: pgsql-general-owner@postgresql.org
[mailto:pgsql-general-owner@postgresql.org] On Behalf Of Keaton Adams
Sent: Monday, August 06, 2007 10:14 AM
To: Tom Lane
Cc: pgsql-general@postgresql.org
Subject: Re: [GENERAL] Template zero xid issue
Our production DB shut down because of it:
<2007-08-06 09:44:08 MDT>LOG: background writer process (PID 24439)
exited with exit code 0
<2007-08-06 09:44:08 MDT>LOG: terminating any other active server
processes
<2007-08-06 09:44:08 MDT>LOG: all server processes terminated;
reinitializing
<2007-08-06 09:44:08 MDT>LOG: database system was shut down at
2007-08-06 09:44:08 MDT
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>LOG: checkpoint record is at 1A7/4C987A2C
<2007-08-06 09:44:08 MDT>LOG: redo record is at 1A7/4C987A2C; undo
record is at 0/0; shutdown TRUE
<2007-08-06 09:44:08 MDT>LOG: next transaction ID: 2146747335; next
OID: 677503791
<2007-08-06 09:44:08 MDT>LOG: next MultiXactId: 2937; next
MultiXactOffset: 5901
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>LOG: database system is ready
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>LOG: transaction ID wrap limit is 2147484146,
limited by database "template0"
<2007-08-06 09:44:08 MDT>WARNING: database "template0" must be vacuumed
within 736811 transactions
<2007-08-06 09:44:08 MDT>HINT: To avoid a database shutdown, execute a
full-database VACUUM in "template0".
<2007-08-06 09:44:08 MDT>LOG: shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>FATAL: the database system is shutting down
<2007-08-06 09:44:08 MDT>LOG: database system is shut down
-----Original Message-----
From: Tom Lane [mailto:tgl@sss.pgh.pa.us]
Sent: Monday, August 06, 2007 9:51 AM
To: Keaton Adams
Cc: pgsql-general@postgresql.org
Subject: Re: [GENERAL] Template zero xid issue
"Keaton Adams" <kadams@mxlogic.com> writes:
> Our template 0 database has an XID issue:
No, it doesn't. template0 never needs vacuuming.
regards, tom lane
---------------------------(end of broadcast)---------------------------
TIP 3: Have you checked our extensive FAQ?
http://www.postgresql.org/docs/faq
"Keaton Adams" <kadams@mxlogic.com> writes:
> Our production DB shut down because of it:
[ squint... ] Which PG version is this exactly? Is template0 marked as
datallowconn in pg_database, or not?
regards, tom lane
Sorry, I should have mentioned that to begin with: psql 8.1.4
mxl=# select datname, datallowconn from pg_database;
datname | datallowconn
--------------+--------------
postgres | t
.
.
.
template1 | t
template0 | f
(7 rows)
It's set to false.
mxl=# \c template0;
FATAL: database "template0" is not currently accepting connections
Previous connection kept
-----Original Message-----
From: Tom Lane [mailto:tgl@sss.pgh.pa.us]
Sent: Monday, August 06, 2007 10:30 AM
To: Keaton Adams
Cc: pgsql-general@postgresql.org
Subject: Re: [GENERAL] Template zero xid issue
"Keaton Adams" <kadams@mxlogic.com> writes:
> Our production DB shut down because of it:
[ squint... ] Which PG version is this exactly? Is template0 marked as
datallowconn in pg_database, or not?
regards, tom lane
"Keaton Adams" <kadams@mxlogic.com> writes:
> So it is odd that over 14,000 XIDs are being consumed on template zero
> in just over one minute?
You misunderstand what you are looking at --- that's the cluster-wide
XID consumption rate, not any one database's.
regards, tom lane
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Keaton Adams wrote: > Sorry, I should have mentioned that to begin with: psql 8.1.4 1. Upgrade to the actual stable release, which is 8.1.9 2. IIRC there is a bug in 8.1.4 that causes template0 to increment when it shouldn't. Update the template0 to allow connections, vacuum full, dissallow connections, and then upgrade. Sincerely, Joshua D. Drake > > > mxl=# select datname, datallowconn from pg_database; > datname | datallowconn > --------------+-------------- > postgres | t > . > . > . > template1 | t > template0 | f > (7 rows) > > It's set to false. > > mxl=# \c template0; > FATAL: database "template0" is not currently accepting connections > Previous connection kept > > > -----Original Message----- > From: Tom Lane [mailto:tgl@sss.pgh.pa.us] > Sent: Monday, August 06, 2007 10:30 AM > To: Keaton Adams > Cc: pgsql-general@postgresql.org > Subject: Re: [GENERAL] Template zero xid issue > > "Keaton Adams" <kadams@mxlogic.com> writes: >> Our production DB shut down because of it: > > [ squint... ] Which PG version is this exactly? Is template0 marked as > datallowconn in pg_database, or not? > > regards, tom lane > > ---------------------------(end of broadcast)--------------------------- > TIP 4: Have you searched our list archives? > > http://archives.postgresql.org/ > - -- === The PostgreSQL Company: Command Prompt, Inc. === Sales/Support: +1.503.667.4564 || 24x7/Emergency: +1.800.492.2240 Providing the most comprehensive PostgreSQL solutions since 1997 http://www.commandprompt.com/ Donate to the PostgreSQL Project: http://www.postgresql.org/about/donate PostgreSQL Replication: http://www.commandprompt.com/products/ -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.6 (GNU/Linux) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org iD8DBQFGt1HXATb/zqfZUUQRAuOHAJ9jSKZXU9CzLWcgy2DYSRXLMTsqTQCgnw4V jVsSNPjay0w6MHxGWsdu8no= =oJhU -----END PGP SIGNATURE-----
"Keaton Adams" <kadams@mxlogic.com> writes:
> Sorry, I should have mentioned that to begin with: psql 8.1.4
Hmm, you know that's pretty old don't you? The latest release in
that branch is 8.1.9 (and there'll be an 8.1.10 before long).
> It's set to false.
> mxl=3D# \c template0;
> FATAL: database "template0" is not currently accepting connections
> Previous connection kept
That's what it should be, but nonconnectable databases are supposed to
be ignored in figuring the XID wraparound limit, so I don't see how you
got the warning mentioning template0.
Do you have autovacuum enabled? I think there are some relevant
post-8.1.4 changes in autovac.
regards, tom lane
"Joshua D. Drake" <jd@commandprompt.com> writes:
> 2. IIRC there is a bug in 8.1.4 that causes template0 to increment when
> it shouldn't. Update the template0 to allow connections, vacuum full,
> dissallow connections, and then upgrade.
That should be "vacuum freeze" but otherwise this is the correct
recovery process. However, before destroying the evidence I'd like to
find out how he got into this state ...
regards, tom lane
We needed the DB up right away; one of the operations guys connected
through a standalone backend to vacuum template0 and now the DB is up
again:
"sudo -u postgres /mxl/var/pgsql/bin/postgres -D /mxl/var/pgsql/data -O
-P template0
Once I got in, I just ran a VACUUM VERBOSE ANALYZE; to "reset"
the XID counter."
So just to be clear on this statement:
"You misunderstand what you are looking at --- that's the cluster-wide
XID consumption rate, not any one database's."
In the docs it says that "the value stored in the datfrozenxid field is
the freeze cutoff XID that was used by the last database-wide vacuum
operation. All normal XIDs older than this cutoff XID are guaranteed to
have been replaced by FrozenXID within that database." The query to
check is:
select datname, age(datfrozenxid) from pg_database;
"The age column measures the number of transactions from the cutoff XID
to the current transaction's XID. When the age approaches two billion,
the database must be vacuumed again to avoid risk of wraparound
failures."
So, if XID is database instance (cluster-wide), that would explain why
the actual increment of the age value is the same across all DB's, even
though the actual XID numbers are different per db?
bash-3.00$ date; psql -dpostgres -frun.sql
Mon Aug 6 11:20:03 MDT 2007
datname | age
--------------+------------
postgres | 1075005030
mxl | 1075004446
.
.
.
template1 | 1074931654
template0 | 1074740691
(7 rows)
bash-3.00$ date; psql -dpostgres -frun.sql
Mon Aug 6 11:23:53 MDT 2007
datname | age
--------------+------------
postgres | 1075046568
mxl | 1075045984
.
.
.
template1 | 1074973192
template0 | 1074782229
(7 rows)
Postgres increment: 41,538
Mxl increment: 41,538
Template 1 increment: 41,538
Template 0 increment: 41,538
But, the actual reset of the FrozenXID needs to take place at the
individual DB level, and that's where the full-db vacuum comes into
play, correct?
And the bug in 8.1.4 is allowing the FrozenXID on template0 to increment
when it shouldn't be doing so, and since the normal vacuum ignores a
read-only db such as template0, that is why we had to force a vacuum
after the DB shut down?
Do I have this right?
Thanks again,
Keaton
-----Original Message-----
From: Tom Lane [mailto:tgl@sss.pgh.pa.us]
Sent: Monday, August 06, 2007 11:02 AM
To: Joshua D. Drake
Cc: Keaton Adams; pgsql-general@postgresql.org
Subject: Re: [GENERAL] Template zero xid issue
"Joshua D. Drake" <jd@commandprompt.com> writes:
> 2. IIRC there is a bug in 8.1.4 that causes template0 to increment
when
> it shouldn't. Update the template0 to allow connections, vacuum full,
> dissallow connections, and then upgrade.
That should be "vacuum freeze" but otherwise this is the correct
recovery process. However, before destroying the evidence I'd like to
find out how he got into this state ...
regards, tom lane
"Keaton Adams" <kadams@mxlogic.com> writes:
> Do I have this right?
It's not clear. You didn't answer the question about whether you were
running autovac, but even if you were I'm not sure why you got the
complaint about template0. AFAICS the only way for template0 to be
installed as oldest_datname is if vac_truncate_clog() is invoked in
template0, allowing it to be the initial selection before the loop
starts. Which could happen if autovac is on, since it will try to
vacuum template0, and in 8.1.4 it neglects to use the FREEZE option.
But even then, if we just finished a DB-wide vacuum on template0,
it should not have had the oldest datfrozenxid; and certainly not one
old enough to provoke complaints.
Actually there's a whole lot that isn't clear about this. Your first
report showed a warning --- not an error --- about template0, so it's
not at all clear that the "database system is shutting down" messages
had anything to do with that at all. And you later posted some queries
that weren't drawing any such message. What was the exact sequence of
events here?
Alvaro: you have any thoughts about this? I'm suspicious that we ought
to change 8.1's vac_truncate_clog() to not include the current database
automatically, since it might be not-datallowconn; but I don't see how
that potential bug could actually be exposed as a fault.
regards, tom lane
Auto vacuum is not enabled:
#-----------------------------------------------------------------------
----
# AUTOVACUUM PARAMETERS
#-----------------------------------------------------------------------
----
#autovacuum = off # enable autovacuum subprocess?
#autovacuum_naptime = 60 # time between autovacuum runs,
in secs
#autovacuum_vacuum_threshold = 1000 # min # of tuple updates before
# vacuum
#autovacuum_analyze_threshold = 500 # min # of tuple updates before
# analyze
#autovacuum_vacuum_scale_factor = 0.4 # fraction of rel size before
# vacuum
#autovacuum_analyze_scale_factor = 0.2 # fraction of rel size before
# analyze
#autovacuum_vacuum_cost_delay = -1 # default vacuum cost delay for
# autovac, -1 means use
# vacuum_cost_delay
#autovacuum_vacuum_cost_limit = -1 # default vacuum cost limit for
# autovac, -1 means use
# vacuum_cost_limit
Instead, the vacuumdb command is run on the DBs to perform a full DB
vacuum every Saturday. The DB template0 is skipped by the vacuumdb
process, according to the output:
/xyz/var/pgsql/bin/vacuumdb -a -z -U postgres
vacuumdb: vacuuming database "postgres"
VACUUM
vacuumdb: vacuuming database "mxl"
VACUUM
vacuumdb: vacuuming database "template1"
VACUUM
1. Ops has a job that monitors datfrozenxid. An event was triggered this
morning because the count on template0 was approaching the limit. I
don't have the original output, but it looked something like this:
mxl=# select datname, age(datfrozenxid) from pg_database;
datname | age
--------------+------------
postgres | 1478038975
mxl_survey | 1478038263
mxl | 1478036889
template1 | 1478010730
template0 | 2146747335
2. As we were attempting to figure out why this was the case, Postgres
stopped accepting commands, as reported in the log:
<2007-08-06 09:42:50 MDT>ERROR: database is not accepting commands to
avoid wraparound data loss in database "template0"
<2007-08-06 09:42:50 MDT>HINT: Stop the postmaster and use a standalone
backend to vacuum database "template0".
3. One of the admins initiated a shutdown request to the DB. The
shutdown was NOT automatically done by Postgres as I had originally
stated, but it became necessary nonetheless:
<2007-08-06 09:44:05 MDT>LOG: received fast shutdown request
<2007-08-06 09:44:05 MDT>LOG: aborting any active transactions
<2007-08-06 09:44:05 MDT>FATAL: terminating connection due to
administrator command
<2007-08-06 09:44:05 MDT>FATAL: terminating connection due to
administrator command
<2007-08-06 09:44:05 MDT>FATAL: terminating connection due to
administrator command
4. During the shutdown we continued to receive these messages in the
log:
<2007-08-06 09:44:08 MDT>LOG: transaction ID wrap limit is 2147484146,
limited by database "template0"
<2007-08-06 09:44:08 MDT>WARNING: database "template0" must be vacuumed
within 736811 transactions
<2007-08-06 09:44:08 MDT>HINT: To avoid a database shutdown, execute a
full-database VACUUM in "template0".
5. Once the DB was down, a standalone backend was used to execute a
vacuum against template0:
sudo -u postgres /mxl/var/pgsql/bin/postgres -D /mxl/var/pgsql/data -O
-P template0
>VACUUM VERBOSE ANALYZE;
6. The DB started successfully and normal operations resumed.
We do have a second 8.1.4 DB running the same type of transaction load
and the datfrozenxid query shows template0 having a larger 'age' value
than any of the other databases in the cluster:
postgres=# select datname, age(datfrozenxid) from pg_database;
datname | age
--------------+------------
postgres | 1108184564
mxl | 1108182478
template1 | 1108156319
template0 | 1497605405
So before it grows into the 2.1 billion value we'll need to do a manual
reset of the FrozenXID on this DB as well.
Of course, we are looking into an 8.1.9 upgrade to avoid this problem in
the future.
Thanks,
Keaton
-----Original Message-----
From: Tom Lane [mailto:tgl@sss.pgh.pa.us]
Sent: Monday, August 06, 2007 1:11 PM
To: Keaton Adams
Cc: Joshua D. Drake; Alvaro Herrera; pgsql-general@postgresql.org
Subject: Re: [GENERAL] Template zero xid issue
"Keaton Adams" <kadams@mxlogic.com> writes:
> Do I have this right?
It's not clear. You didn't answer the question about whether you were
running autovac, but even if you were I'm not sure why you got the
complaint about template0. AFAICS the only way for template0 to be
installed as oldest_datname is if vac_truncate_clog() is invoked in
template0, allowing it to be the initial selection before the loop
starts. Which could happen if autovac is on, since it will try to
vacuum template0, and in 8.1.4 it neglects to use the FREEZE option.
But even then, if we just finished a DB-wide vacuum on template0,
it should not have had the oldest datfrozenxid; and certainly not one
old enough to provoke complaints.
Actually there's a whole lot that isn't clear about this. Your first
report showed a warning --- not an error --- about template0, so it's
not at all clear that the "database system is shutting down" messages
had anything to do with that at all. And you later posted some queries
that weren't drawing any such message. What was the exact sequence of
events here?
Alvaro: you have any thoughts about this? I'm suspicious that we ought
to change 8.1's vac_truncate_clog() to not include the current database
automatically, since it might be not-datallowconn; but I don't see how
that potential bug could actually be exposed as a fault.
regards, tom lane
"Keaton Adams" <kadams@mxlogic.com> writes:
> Auto vacuum is not enabled:
Hmph. That shoots down the one semi-plausible idea I had about how you
got into this state. It seems that the unexpected limit_datname value
must have come from flatfiles.c, but that *certainly* won't pick up
any database with datallowconn = false. Is it possible that someone
was manually tinkering with the content of pg_database.datallowconn?
I see several other hard-to-explain aspects about the log excerpts you
sent, notably the key warning itself:
> <2007-08-06 09:44:08 MDT>WARNING: database "template0" must be vacuumed
> within 736811 transactions
8.1 was designed to clamp down *hard* at 1000000 transactions from the
wraparound point, so how did you get to consume almost 300000 more
transactions beyond that limit?
Could you send me the whole postmaster log from the point of the first
sign of trouble, rather than just excerpts? I suspect there might be
useful evidence you omitted.
regards, tom lane