database corruption help
Hi, my wal archiving broke and postgresql filled up the local disk with transaction logs, which i foolishly deleted in a moment of madness, after resetting the transaction log a few of my tables are damaged but repairable. However the system tables also seemed to have suffered. My main problem is duplicate rows which violated the primary key and if i do a reindex system i get similar errors, for example:
ERROR: could not create unique index "pg_class_oid_index"
a quick inspection of the pg_class table doesn't show any duplicates, is there anyway i can find out which row(s) are duplicated and remove them without a full db restore?
also doing something like this doesn't return anything which worked for my other tables
select oid from pg_class where oid in(select oid from pg_class group by oid having count(oid)>1 )
Many thanks
--
Got needs? Get Goblin'! - http://www.pricegoblin.co.uk/
"John Lister" <john.lister-ps@kickstone.com> writes:
ERROR: could not create unique index "pg_class_oid_index"
a quick inspection of the pg_class table doesn't show any duplicates, is there anyway i can find out which row(s) are duplicated and remove them without a full db restore?
also doing something like this doesn't return anything which worked for my other tables
select oid from pg_class where oid in(select oid from pg_class group by oid having count(oid)>1 )
Try doing it with enable_indexscan = off and enable_bitmapscan = off.
The system might be relying on the old, bogus index to do the group by
oid.
regards, tom lane
Cheers tom, that did it - i've removed the duplicates and seeing what else
is broken.
.
Show quoted text
"John Lister" <john.lister-ps@kickstone.com> writes:
ERROR: could not create unique index "pg_class_oid_index"
a quick inspection of the pg_class table doesn't show any duplicates, is
there anyway i can find out which row(s) are duplicated and remove them
without a full db restore?also doing something like this doesn't return anything which worked for
my other tablesselect oid from pg_class where oid in(select oid from pg_class group by
oid having count(oid)>1 )Try doing it with enable_indexscan = off and enable_bitmapscan = off.
The system might be relying on the old, bogus index to do the group by
oid.regards, tom lane
John Lister <john.lister@kickstone.com> writes:
Although saying that..
reindex now works, but doing a vacuum verbose complains that the index
is out of step with the table and i should reindex..
would i be better shutting the db down, restarting in standalone mode
(and also using the -P option) before reindexing?
Yeah, if you have reason not to trust the system indexes then -P is
a good idea until they are fixed. Standalone mode per se isn't that
important --- you could do this from a regular session with -P specified
via PGOPTIONS.
regards, tom lane
Import Notes
Reply to msg id not found: 4990840C.4090900@kickstone.com
Yeah, if you have reason not to trust the system indexes then -P is
a good idea until they are fixed. Standalone mode per se isn't that
important --- you could do this from a regular session with -P specified
via PGOPTIONS.
still getting the same problem.
PGOPTIONS="-P"
psql backendreindex system backend;
NOTICE: table "pg_class" was reindexed
NOTICE: table "pg_statistic" was reindexed
NOTICE: table "pg_ts_config" was reindexed ...
vacuum full verbose pg_class
INFO: vacuuming "pg_catalog.pg_class"
INFO: "pg_class": found 7 removable, 1839 nonremovable row versions
in 18812 pages
DETAIL: 27 dead row versions cannot be removed yet.
Nonremovable row versions range from 160 to 229 bytes long.
There were 929452 unused item pointers.
Total free space (including removable row versions) is 149628172 bytes.
18749 pages are or will become empty, including 0 at the end of the
table.
0 pages containing 0 free bytes are potential move destinations.
CPU 0.01s/0.07u sec elapsed 0.17 sec.
INFO: index "pg_class_oid_index" now contains 1812 row versions in
7 pages
DETAIL: 0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.01u sec elapsed 0.09 sec.
WARNING: index "pg_class_oid_index" contains 1812 row versions, but
table contains 1807 row versions
HINT: Rebuild the index with REINDEX.
INFO: index "pg_class_relname_nsp_index" now contains 1812 row
versions in 23 pages
DETAIL: 0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.01u sec elapsed 0.09 sec.
WARNING: index "pg_class_relname_nsp_index" contains 1812 row
versions, but table contains 1807 row versions
HINT: Rebuild the index with REINDEX.
Just noticed the 7 dead rows above, are they likely to be causing a
problem?
BTW this is postgresql 8.3.5 if that makes a difference...
I'm guessing it is fairly important to get rid of these warnings....
Thanks
John Lister <john.lister-ps@kickstone.com> writes:
still getting the same problem.
PGOPTIONS="-P"
psql backend
I think you need export PGOPTIONS="-P" to make that work. Whether
it's related to your problem isn't clear though.
regards, tom lane
Sorry, had exported it - bad cut/pasting...
I even tried it in single-user mode passing -P directly but got the same
result
Also confused/concerned by the 7 dead rows in pg_class. as i've
restarted the server all transaction should have finished so i'd like to
reclaim these - especially as vacuum reports the table is using 80Mb+
Thanks
Show quoted text
still getting the same problem.
PGOPTIONS="-P"
psql backendI think you need export PGOPTIONS="-P" to make that work. Whether
it's related to your problem isn't clear though.regards, tom lane
I seem to have more dead rows now..
doing a vacuum full on pg_class gives me
INFO: vacuuming "pg_catalog.pg_class"INFO: "pg_class": found 37
removable, 1845 nonremovable row versions in 18905 pages
DETAIL: 27 dead row versions cannot be removed yet.
Nonremovable row versions range from 160 to 229 bytes long.
There were 933834 unused item pointers.
Total free space (including removable row versions) is 150368692 bytes.
18839 pages are or will become empty, including 0 at the end of the table.
0 pages containing 0 free bytes are potential move destinations.
CPU 0.01s/0.05u sec elapsed 0.17 sec.INFO: index "pg_class_oid_index"
now contains 1813 row versions in 7 pages
DETAIL: 56 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.INFO: index
"pg_class_relname_nsp_index" now contains 1818 row versions in 24 pages
DETAIL: 63 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.WARNING: index
"pg_class_relname_nsp_index" contains 1818 row versions, but table
contains 1813 row versions
HINT: Rebuild the index with REINDEX.INFO: analyzing
"pg_catalog.pg_class"INFO: "pg_class": scanned 3000 of 18905 pages,
containing 227 live rows and 6 dead rows; 227 rows in sample, 1430
estimated total rows
Total query runtime: 4469 ms.
I've restarted the server which should have got rid of any
outstanding/long running transactions - which it though was the major
cause of lingering dead rows.
Any ideas how to fix this as i'd like to reduce this from 150+Mb which
can't be good for performance....
Thanks
John Lister <john.lister-ps@kickstone.com> writes:
I seem to have more dead rows now..
doing a vacuum full on pg_class gives me
INFO: vacuuming "pg_catalog.pg_class"INFO: "pg_class": found 37
removable, 1845 nonremovable row versions in 18905 pages
DETAIL: 27 dead row versions cannot be removed yet.
Nonremovable row versions range from 160 to 229 bytes long.
There were 933834 unused item pointers.
Total free space (including removable row versions) is 150368692 bytes.
18839 pages are or will become empty, including 0 at the end of the table.
0 pages containing 0 free bytes are potential move destinations.
Hmm, that last seems to indicate that do_shrinking has been reset.
It looks like the cases where that happens are reported with elog(LOG)
which means they probably only went to the postmaster log (maybe we
should fix things so that vacuum verbose reports those). What have
you got in the postmaster log?
regards, tom lane
I'm running ubuntu and can see references to only one log file which i'm
assuming is the postmaster log..
Anyway the only relevant bits are:
GMT LOG: relation "pg_class" TID 15538/4: dead HOT-updated tuple ---
cannot shrink relation
2009-02-12 21:06:40 GMT STATEMENT: VACUUM FULL VERBOSE ANALYZE pg_class
2009-02-12 21:06:40 GMT WARNING: index "pg_class_relname_nsp_index"
contains 1818 row versions, but table contains 1813 row versions
If that helps...
Thanks
Show quoted text
John Lister <john.lister-ps@kickstone.com> writes:
I seem to have more dead rows now..
doing a vacuum full on pg_class gives meINFO: vacuuming "pg_catalog.pg_class"INFO: "pg_class": found 37
removable, 1845 nonremovable row versions in 18905 pages
DETAIL: 27 dead row versions cannot be removed yet.
Nonremovable row versions range from 160 to 229 bytes long.
There were 933834 unused item pointers.
Total free space (including removable row versions) is 150368692 bytes.
18839 pages are or will become empty, including 0 at the end of the table.
0 pages containing 0 free bytes are potential move destinations.Hmm, that last seems to indicate that do_shrinking has been reset.
It looks like the cases where that happens are reported with elog(LOG)
which means they probably only went to the postmaster log (maybe we
should fix things so that vacuum verbose reports those). What have
you got in the postmaster log?regards, tom lane
John Lister <john.lister-ps@kickstone.com> writes:
GMT LOG: relation "pg_class" TID 15538/4: dead HOT-updated tuple ---
cannot shrink relation
Hmm. The comments in vacuum.c about this case suppose that it could
only be a transient condition, ie the tuple became dead while we were
looking at the page. Evidently it's persistent for you, which means
that for some reason heap_page_prune() is failing to remove an
already-dead tuple. I suspect this implies a corrupt HOT chain, but
maybe the data is okay and what you've got is really a bug in
heap_page_prune.
Could you send a dump of page 15538 of pg_class, using pg_filedump?
The source code for it is here:
http://sources.redhat.com/rhdb/utilities.html
Best would be -i -f format, ie
pg_filedump -i -f -R 15538 $PGDATA/base/something/1259
regards, tom lane
Originally in psql-admin, but copied here at the request of Tom to..
Story so far, transaction log archiving went wrong causing the
transaction log disk to fill up. Foolishly i deleted the unarchived
transaction logs (early monday morning) which required a pg_resetxlog to
get the db up and running again. Since then we've had some minor db
corruption which has been fixed (mainly duplicate primary keys) except
for the pg_class table.
If i do a vacuum full on pg_class i get something like this:
INFO: vacuuming "pg_catalog.pg_class"INFO: "pg_class": found 37
removable, 1845 nonremovable row versions in 18905 pages
DETAIL: 27 dead row versions cannot be removed yet.
Nonremovable row versions range from 160 to 229 bytes long.
There were 933834 unused item pointers.
Total free space (including removable row versions) is 150368692 bytes.
18839 pages are or will become empty, including 0 at the end of the table.
0 pages containing 0 free bytes are potential move destinations.
CPU 0.01s/0.05u sec elapsed 0.17 sec.INFO: index "pg_class_oid_index"
now contains 1813 row versions in 7 pages
DETAIL: 56 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.INFO: index
"pg_class_relname_nsp_index" now contains 1818 row versions in 24 pages
DETAIL: 63 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.WARNING: index
"pg_class_relname_nsp_index" contains 1818 row versions, but table
contains 1813 row versions
HINT: Rebuild the index with REINDEX.INFO: analyzing
"pg_catalog.pg_class"INFO: "pg_class": scanned 3000 of 18905 pages,
containing 227 live rows and 6 dead rows; 227 rows in sample, 1430
estimated total rows
Total query runtime: 4469 ms.
As you can see there are non-removable dead rows (which slowly grows)
and the table size is also increasing in size.. A reindex on the
indexes mentions also succeeds but another vacuum reports the same thing...
In the log files the relevant bits are:
GMT LOG: relation "pg_class" TID 15538/4: dead HOT-updated tuple ---
cannot shrink relation
2009-02-12 21:06:40 GMT STATEMENT: VACUUM FULL VERBOSE ANALYZE pg_class
2009-02-12 21:06:40 GMT WARNING: index "pg_class_relname_nsp_index"
contains 1818 row versions, but table contains 1813 row versions
and finally the last message in the psql-admin thread suggested dumping
the above page, which is attached before.
Hmm. The comments in vacuum.c about this case suppose that it could
only be a transient condition, ie the tuple became dead while we were
looking at the page. Evidently it's persistent for you, which means
that for some reason heap_page_prune() is failing to remove an
already-dead tuple. I suspect this implies a corrupt HOT chain, but
maybe the data is okay and what you've got is really a bug in
heap_page_prune.
Could you send a dump of page 15538 of pg_class, using pg_filedump?
The source code for it is here:
http://sources.redhat.com/rhdb/utilities.html
Best would be -i -f format, ie
pg_filedump -i -f -R 15538 $PGDATA/base/something/1259regards, tom lane
Any help would be appreciated as the pg_class table is constantly
growing which i'm guessing is going to start to affect performance
fairly soon. I'd like to avoid a full restore from backup if possible.
Thanks
JOHN
Attachments:
dump.txttext/plain; name=dump.txtDownload
*******************************************************************
* PostgreSQL File/Block Formatted Dump Utility - Version 8.3.0
*
* File: /mnt/data/postgresql/8.3/base/16392/1259
* Options used: -i -f -R 15538
*
* Dump created on: Thu Feb 12 22:30:43 2009
*******************************************************************
Block 15538 ********************************************************
<Header> -----
Block Offset: 0x07964000 Offsets: Lower 220 (0x00dc)
Block: Size 8192 Version 4 Upper 5632 (0x1600)
LSN: logid 428 recoff 0xbce5c3a0 Special 8192 (0x2000)
Items: 49 Free Space: 5412
TLI: 0x0001 Prune XID: 0x00000000 Flags: 0x0001 (HAS_FREE_LINES)
Length (including item array): 220
0000: ac010000 a0c3e5bc 01000100 dc000016 ................
0010: 00200420 00000000 00000000 00000000 . . ............
0020: 00000000 609f4001 c09e4001 209e4001 ....`.@...@. .@.
0030: 809d4001 e09c4001 00000000 00000000 ..@...@.........
0040: 409c4001 a09b4001 009b4001 609a4001 @.@...@...@.`.@.
0050: c0994001 20994001 80984001 00000000 ..@. .@...@.....
0060: 00000000 e0974001 40974001 a0964001 ......@.@.@...@.
0070: 00964001 00000000 00000000 00000000 ..@.............
0080: 00000000 00000000 00000000 00000000 ................
0090: 00000000 00000000 00000000 00000000 ................
00a0: 00000000 00000000 00000000 00000000 ................
00b0: 00000000 00000000 00000000 00000000 ................
00c0: 00000000 00000000 00000000 00000000 ................
00d0: 00000000 00000000 00000000 ............
<Data> ------
Item 1 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 2 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 3 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 4 -- Length: 160 Offset: 8032 (0x1f60) Flags: NORMAL
XMIN: 471107346 XMAX: 471107808 CID|XVAC: 0 OID: 187262
Block Id: 15538 linp Index: 5 Attributes: 27 Size: 32
infomask: 0x2509 (HASNULL|HASOID|XMIN_COMMITTED|XMAX_COMMITTED|UPDATED|HOT_UPDATED|HEAP_ONLY)
t_bits: [0]: 0xff [1]: 0xff [2]: 0xff [3]: 0x01
1f60: 1287141c e088141c 00000000 0000b23c ...............<
1f70: 05001bc0 092520ff ffff0100 7edb0200 .....% .....~...
1f80: 74656d70 5f717565 75650000 00000000 temp_queue......
1f90: 00000000 00000000 00000000 00000000 ................
1fa0: 00000000 00000000 00000000 00000000 ................
1fb0: 00000000 00000000 00000000 00000000 ................
1fc0: 15400000 80db0200 00400000 00000000 .@.......@......
1fd0: 34974300 00000000 00000000 00000000 4.C.............
1fe0: 00000000 00000000 01007200 03000000 ..........r.....
1ff0: 00000000 00000000 00010000 1287141c ................
Item 5 -- Length: 160 Offset: 7872 (0x1ec0) Flags: NORMAL
XMIN: 471107808 XMAX: 471108256 CID|XVAC: 0 OID: 187262
Block Id: 15538 linp Index: 6 Attributes: 27 Size: 32
infomask: 0x2509 (HASNULL|HASOID|XMIN_COMMITTED|XMAX_COMMITTED|UPDATED|HOT_UPDATED|HEAP_ONLY)
t_bits: [0]: 0xff [1]: 0xff [2]: 0xff [3]: 0x01
1ec0: e088141c a08a141c 00000000 0000b23c ...............<
1ed0: 06001bc0 092520ff ffff0100 7edb0200 .....% .....~...
1ee0: 74656d70 5f717565 75650000 00000000 temp_queue......
1ef0: 00000000 00000000 00000000 00000000 ................
1f00: 00000000 00000000 00000000 00000000 ................
1f10: 00000000 00000000 00000000 00000000 ................
1f20: 15400000 80db0200 00400000 00000000 .@.......@......
1f30: 39974300 00000000 00000000 00000000 9.C.............
1f40: 00000000 00000000 01007200 03000000 ..........r.....
1f50: 00000000 00000000 00010000 de88141c ................
Item 6 -- Length: 160 Offset: 7712 (0x1e20) Flags: NORMAL
XMIN: 471108256 XMAX: 471108887 CID|XVAC: 0 OID: 187262
Block Id: 15538 linp Index: 7 Attributes: 27 Size: 32
infomask: 0x2509 (HASNULL|HASOID|XMIN_COMMITTED|XMAX_COMMITTED|UPDATED|HOT_UPDATED|HEAP_ONLY)
t_bits: [0]: 0xff [1]: 0xff [2]: 0xff [3]: 0x01
1e20: a08a141c 178d141c 00000000 0000b23c ...............<
1e30: 07001bc0 092520ff ffff0100 7edb0200 .....% .....~...
1e40: 74656d70 5f717565 75650000 00000000 temp_queue......
1e50: 00000000 00000000 00000000 00000000 ................
1e60: 00000000 00000000 00000000 00000000 ................
1e70: 00000000 00000000 00000000 00000000 ................
1e80: 15400000 80db0200 00400000 00000000 .@.......@......
1e90: 3e974300 00000000 00000000 00000000 >.C.............
1ea0: 00000000 00000000 01007200 03000000 ..........r.....
1eb0: 00000000 00000000 00010000 9f8a141c ................
Item 7 -- Length: 160 Offset: 7552 (0x1d80) Flags: NORMAL
XMIN: 471108887 XMAX: 471109460 CID|XVAC: 0 OID: 187262
Block Id: 15538 linp Index: 8 Attributes: 27 Size: 32
infomask: 0x2509 (HASNULL|HASOID|XMIN_COMMITTED|XMAX_COMMITTED|UPDATED|HOT_UPDATED|HEAP_ONLY)
t_bits: [0]: 0xff [1]: 0xff [2]: 0xff [3]: 0x01
1d80: 178d141c 548f141c 00000000 0000b23c ....T..........<
1d90: 08001bc0 092520ff ffff0100 7edb0200 .....% .....~...
1da0: 74656d70 5f717565 75650000 00000000 temp_queue......
1db0: 00000000 00000000 00000000 00000000 ................
1dc0: 00000000 00000000 00000000 00000000 ................
1dd0: 00000000 00000000 00000000 00000000 ................
1de0: 15400000 80db0200 00400000 00000000 .@.......@......
1df0: 43974300 00000000 00000000 00000000 C.C.............
1e00: 00000000 00000000 01007200 03000000 ..........r.....
1e10: 00000000 00000000 00010000 148d141c ................
Item 8 -- Length: 160 Offset: 7392 (0x1ce0) Flags: NORMAL
XMIN: 471109460 XMAX: 471110027 CID|XVAC: 0 OID: 187262
Block Id: 15538 linp Index: 9 Attributes: 27 Size: 32
infomask: 0x2509 (HASNULL|HASOID|XMIN_COMMITTED|XMAX_COMMITTED|UPDATED|HOT_UPDATED|HEAP_ONLY)
t_bits: [0]: 0xff [1]: 0xff [2]: 0xff [3]: 0x01
1ce0: 548f141c 8b91141c 00000000 0000b23c T..............<
1cf0: 09001bc0 092520ff ffff0100 7edb0200 .....% .....~...
1d00: 74656d70 5f717565 75650000 00000000 temp_queue......
1d10: 00000000 00000000 00000000 00000000 ................
1d20: 00000000 00000000 00000000 00000000 ................
1d30: 00000000 00000000 00000000 00000000 ................
1d40: 15400000 80db0200 00400000 00000000 .@.......@......
1d50: 48974300 00000000 00000000 00000000 H.C.............
1d60: 00000000 00000000 01007200 03000000 ..........r.....
1d70: 00000000 00000000 00010000 548f141c ............T...
Item 9 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 10 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 11 -- Length: 160 Offset: 7232 (0x1c40) Flags: NORMAL
XMIN: 471111085 XMAX: 471111481 CID|XVAC: 0 OID: 187262
Block Id: 15538 linp Index: 12 Attributes: 27 Size: 32
infomask: 0x2509 (HASNULL|HASOID|XMIN_COMMITTED|XMAX_COMMITTED|UPDATED|HOT_UPDATED|HEAP_ONLY)
t_bits: [0]: 0xff [1]: 0xff [2]: 0xff [3]: 0x01
1c40: ad95141c 3997141c 00000000 0000b23c ....9..........<
1c50: 0c001bc0 092520ff ffff0100 7edb0200 .....% .....~...
1c60: 74656d70 5f717565 75650000 00000000 temp_queue......
1c70: 00000000 00000000 00000000 00000000 ................
1c80: 00000000 00000000 00000000 00000000 ................
1c90: 00000000 00000000 00000000 00000000 ................
1ca0: 15400000 80db0200 00400000 00000000 .@.......@......
1cb0: 57974300 00000000 00000000 00000000 W.C.............
1cc0: 00000000 00000000 01007200 03000000 ..........r.....
1cd0: 00000000 00000000 00010000 ad95141c ................
Item 12 -- Length: 160 Offset: 7072 (0x1ba0) Flags: NORMAL
XMIN: 471111481 XMAX: 471112070 CID|XVAC: 0 OID: 187262
Block Id: 15538 linp Index: 13 Attributes: 27 Size: 32
infomask: 0x2509 (HASNULL|HASOID|XMIN_COMMITTED|XMAX_COMMITTED|UPDATED|HOT_UPDATED|HEAP_ONLY)
t_bits: [0]: 0xff [1]: 0xff [2]: 0xff [3]: 0x01
1ba0: 3997141c 8699141c 00000000 0000b23c 9..............<
1bb0: 0d001bc0 092520ff ffff0100 7edb0200 .....% .....~...
1bc0: 74656d70 5f717565 75650000 00000000 temp_queue......
1bd0: 00000000 00000000 00000000 00000000 ................
1be0: 00000000 00000000 00000000 00000000 ................
1bf0: 00000000 00000000 00000000 00000000 ................
1c00: 15400000 80db0200 00400000 00000000 .@.......@......
1c10: 5c974300 00000000 00000000 00000000 \.C.............
1c20: 00000000 00000000 01007200 03000000 ..........r.....
1c30: 00000000 00000000 00010000 3897141c ............8...
Item 13 -- Length: 160 Offset: 6912 (0x1b00) Flags: NORMAL
XMIN: 471112070 XMAX: 471112509 CID|XVAC: 0 OID: 187262
Block Id: 15538 linp Index: 14 Attributes: 27 Size: 32
infomask: 0x2509 (HASNULL|HASOID|XMIN_COMMITTED|XMAX_COMMITTED|UPDATED|HOT_UPDATED|HEAP_ONLY)
t_bits: [0]: 0xff [1]: 0xff [2]: 0xff [3]: 0x01
1b00: 8699141c 3d9b141c 00000000 0000b23c ....=..........<
1b10: 0e001bc0 092520ff ffff0100 7edb0200 .....% .....~...
1b20: 74656d70 5f717565 75650000 00000000 temp_queue......
1b30: 00000000 00000000 00000000 00000000 ................
1b40: 00000000 00000000 00000000 00000000 ................
1b50: 00000000 00000000 00000000 00000000 ................
1b60: 15400000 80db0200 00400000 00000000 .@.......@......
1b70: 61974300 00000000 00000000 00000000 a.C.............
1b80: 00000000 00000000 01007200 03000000 ..........r.....
1b90: 00000000 00000000 00010000 7e99141c ............~...
Item 14 -- Length: 160 Offset: 6752 (0x1a60) Flags: NORMAL
XMIN: 471112509 XMAX: 471113050 CID|XVAC: 0 OID: 187262
Block Id: 15538 linp Index: 15 Attributes: 27 Size: 32
infomask: 0x2509 (HASNULL|HASOID|XMIN_COMMITTED|XMAX_COMMITTED|UPDATED|HOT_UPDATED|HEAP_ONLY)
t_bits: [0]: 0xff [1]: 0xff [2]: 0xff [3]: 0x01
1a60: 3d9b141c 5a9d141c 00000000 0000b23c =...Z..........<
1a70: 0f001bc0 092520ff ffff0100 7edb0200 .....% .....~...
1a80: 74656d70 5f717565 75650000 00000000 temp_queue......
1a90: 00000000 00000000 00000000 00000000 ................
1aa0: 00000000 00000000 00000000 00000000 ................
1ab0: 00000000 00000000 00000000 00000000 ................
1ac0: 15400000 80db0200 00400000 00000000 .@.......@......
1ad0: 66974300 00000000 00000000 00000000 f.C.............
1ae0: 00000000 00000000 01007200 03000000 ..........r.....
1af0: 00000000 00000000 00010000 1b9b141c ................
Item 15 -- Length: 160 Offset: 6592 (0x19c0) Flags: NORMAL
XMIN: 471113050 XMAX: 471113635 CID|XVAC: 0 OID: 187262
Block Id: 15538 linp Index: 16 Attributes: 27 Size: 32
infomask: 0x2509 (HASNULL|HASOID|XMIN_COMMITTED|XMAX_COMMITTED|UPDATED|HOT_UPDATED|HEAP_ONLY)
t_bits: [0]: 0xff [1]: 0xff [2]: 0xff [3]: 0x01
19c0: 5a9d141c a39f141c 00000000 0000b23c Z..............<
19d0: 10001bc0 092520ff ffff0100 7edb0200 .....% .....~...
19e0: 74656d70 5f717565 75650000 00000000 temp_queue......
19f0: 00000000 00000000 00000000 00000000 ................
1a00: 00000000 00000000 00000000 00000000 ................
1a10: 00000000 00000000 00000000 00000000 ................
1a20: 15400000 80db0200 00400000 00000000 .@.......@......
1a30: 6b974300 00000000 00000000 00000000 k.C.............
1a40: 00000000 00000000 01007200 03000000 ..........r.....
1a50: 00000000 00000000 00010000 5a9d141c ............Z...
Item 16 -- Length: 160 Offset: 6432 (0x1920) Flags: NORMAL
XMIN: 471113635 XMAX: 471114151 CID|XVAC: 0 OID: 187262
Block Id: 15538 linp Index: 17 Attributes: 27 Size: 32
infomask: 0x2509 (HASNULL|HASOID|XMIN_COMMITTED|XMAX_COMMITTED|UPDATED|HOT_UPDATED|HEAP_ONLY)
t_bits: [0]: 0xff [1]: 0xff [2]: 0xff [3]: 0x01
1920: a39f141c a7a1141c 00000000 0000b23c ...............<
1930: 11001bc0 092520ff ffff0100 7edb0200 .....% .....~...
1940: 74656d70 5f717565 75650000 00000000 temp_queue......
1950: 00000000 00000000 00000000 00000000 ................
1960: 00000000 00000000 00000000 00000000 ................
1970: 00000000 00000000 00000000 00000000 ................
1980: 15400000 80db0200 00400000 00000000 .@.......@......
1990: 70974300 00000000 00000000 00000000 p.C.............
19a0: 00000000 00000000 01007200 03000000 ..........r.....
19b0: 00000000 00000000 00010000 9f9f141c ................
Item 17 -- Length: 160 Offset: 6272 (0x1880) Flags: NORMAL
XMIN: 471114151 XMAX: 471114646 CID|XVAC: 0 OID: 187262
Block Id: 15538 linp Index: 18 Attributes: 27 Size: 32
infomask: 0x2509 (HASNULL|HASOID|XMIN_COMMITTED|XMAX_COMMITTED|UPDATED|HOT_UPDATED|HEAP_ONLY)
t_bits: [0]: 0xff [1]: 0xff [2]: 0xff [3]: 0x01
1880: a7a1141c 96a3141c 00000000 0000b23c ...............<
1890: 12001bc0 092520ff ffff0100 7edb0200 .....% .....~...
18a0: 74656d70 5f717565 75650000 00000000 temp_queue......
18b0: 00000000 00000000 00000000 00000000 ................
18c0: 00000000 00000000 00000000 00000000 ................
18d0: 00000000 00000000 00000000 00000000 ................
18e0: 15400000 80db0200 00400000 00000000 .@.......@......
18f0: 75974300 00000000 00000000 00000000 u.C.............
1900: 00000000 00000000 01007200 03000000 ..........r.....
1910: 00000000 00000000 00010000 a7a1141c ................
Item 18 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 19 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 20 -- Length: 160 Offset: 6112 (0x17e0) Flags: NORMAL
XMIN: 471115662 XMAX: 471116262 CID|XVAC: 0 OID: 187262
Block Id: 15538 linp Index: 21 Attributes: 27 Size: 32
infomask: 0x2509 (HASNULL|HASOID|XMIN_COMMITTED|XMAX_COMMITTED|UPDATED|HOT_UPDATED|HEAP_ONLY)
t_bits: [0]: 0xff [1]: 0xff [2]: 0xff [3]: 0x01
17e0: 8ea7141c e6a9141c 00000000 0000b23c ...............<
17f0: 15001bc0 092520ff ffff0100 7edb0200 .....% .....~...
1800: 74656d70 5f717565 75650000 00000000 temp_queue......
1810: 00000000 00000000 00000000 00000000 ................
1820: 00000000 00000000 00000000 00000000 ................
1830: 00000000 00000000 00000000 00000000 ................
1840: 15400000 80db0200 00400000 00000000 .@.......@......
1850: 84974300 00000000 00000000 00000000 ..C.............
1860: 00000000 00000000 01007200 03000000 ..........r.....
1870: 00000000 00000000 00010000 8ea7141c ................
Item 21 -- Length: 160 Offset: 5952 (0x1740) Flags: NORMAL
XMIN: 471116262 XMAX: 471116790 CID|XVAC: 0 OID: 187262
Block Id: 15538 linp Index: 22 Attributes: 27 Size: 32
infomask: 0x2509 (HASNULL|HASOID|XMIN_COMMITTED|XMAX_COMMITTED|UPDATED|HOT_UPDATED|HEAP_ONLY)
t_bits: [0]: 0xff [1]: 0xff [2]: 0xff [3]: 0x01
1740: e6a9141c f6ab141c 00000000 0000b23c ...............<
1750: 16001bc0 092520ff ffff0100 7edb0200 .....% .....~...
1760: 74656d70 5f717565 75650000 00000000 temp_queue......
1770: 00000000 00000000 00000000 00000000 ................
1780: 00000000 00000000 00000000 00000000 ................
1790: 00000000 00000000 00000000 00000000 ................
17a0: 15400000 80db0200 00400000 00000000 .@.......@......
17b0: 89974300 00000000 00000000 00000000 ..C.............
17c0: 00000000 00000000 01007200 03000000 ..........r.....
17d0: 00000000 00000000 00010000 e6a9141c ................
Item 22 -- Length: 160 Offset: 5792 (0x16a0) Flags: NORMAL
XMIN: 471116790 XMAX: 471117318 CID|XVAC: 0 OID: 187262
Block Id: 15538 linp Index: 23 Attributes: 27 Size: 32
infomask: 0x2509 (HASNULL|HASOID|XMIN_COMMITTED|XMAX_COMMITTED|UPDATED|HOT_UPDATED|HEAP_ONLY)
t_bits: [0]: 0xff [1]: 0xff [2]: 0xff [3]: 0x01
16a0: f6ab141c 06ae141c 00000000 0000b23c ...............<
16b0: 17001bc0 092520ff ffff0100 7edb0200 .....% .....~...
16c0: 74656d70 5f717565 75650000 00000000 temp_queue......
16d0: 00000000 00000000 00000000 00000000 ................
16e0: 00000000 00000000 00000000 00000000 ................
16f0: 00000000 00000000 00000000 00000000 ................
1700: 15400000 80db0200 00400000 00000000 .@.......@......
1710: 8e974300 00000000 00000000 00000000 ..C.............
1720: 00000000 00000000 01007200 03000000 ..........r.....
1730: 00000000 00000000 00010000 f6ab141c ................
Item 23 -- Length: 160 Offset: 5632 (0x1600) Flags: NORMAL
XMIN: 471117318 XMAX: 0 CID|XVAC: 0 OID: 187262
Block Id: 15538 linp Index: 23 Attributes: 27 Size: 32
infomask: 0x2909 (HASNULL|HASOID|XMIN_COMMITTED|XMAX_INVALID|UPDATED|HEAP_ONLY)
t_bits: [0]: 0xff [1]: 0xff [2]: 0xff [3]: 0x01
1600: 06ae141c 00000000 00000000 0000b23c ...............<
1610: 17001b80 092920ff ffff0100 7edb0200 .....) .....~...
1620: 74656d70 5f717565 75650000 00000000 temp_queue......
1630: 00000000 00000000 00000000 00000000 ................
1640: 00000000 00000000 00000000 00000000 ................
1650: 00000000 00000000 00000000 00000000 ................
1660: 15400000 80db0200 00400000 00000000 .@.......@......
1670: 93974300 00000000 00000000 00000000 ..C.............
1680: 00000000 00000000 01007200 03000000 ..........r.....
1690: 00000000 00000000 00010000 06ae141c ................
Item 24 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 25 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 26 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 27 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 28 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 29 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 30 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 31 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 32 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 33 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 34 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 35 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 36 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 37 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 38 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 39 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 40 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 41 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 42 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 43 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 44 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 45 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 46 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 47 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 48 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
Item 49 -- Length: 0 Offset: 0 (0x0000) Flags: UNUSED
*** End of Requested Range Encountered. Last Block Read: 15538 ***
Import Notes
Reply to msg id not found: 4994A45B.4030707@kickstone.com
Please send to pgsql-hackers --- I'd like to get more eyeballs on this.
There's no personally identifiable information here except that you've
got a table named temp_queue that you've repeatedly TRUNCATEd or
CLUSTERed or some such (likely the former since the reltuples counts
are all zero). It'd be useful to know exactly what you were doing
with it, though.regards, tom lane
More info as requested....
TEMP_QUEUE is used continously throughout the day (for some reason which
i chose not to use a normal temp table) data is grouped and inserted
from other tables, before being processed, and you are right the table
is then truncated before repeating - this happens at least once a minute
throughout the day..
After restarted following the pg_resetxlog, i noticed that the
temp_queue table was missing (had been created a day ago). I couldn't
select from it and had problems trying to recreate it (bits seemed to
exist already). I couldn't see it in pg_class or the other catalogs, but
after selecting to ignore the presumably corrupt indexes it appeared so
i manually removed the references (I've since learned about the -P
option to the server which may have helped here). The corruption in
pg_class manifested itself as multiple rows (for this and another table)
with the same OIDs
So not sure at what point what if anything got corrupted and what my
subsequent actions did to compound this..
Thanks
John Lister wrote:
Show quoted text
Originally in psql-admin, but copied here at the request of Tom to..
Story so far, transaction log archiving went wrong causing the
transaction log disk to fill up. Foolishly i deleted the unarchived
transaction logs (early monday morning) which required a pg_resetxlog
to get the db up and running again. Since then we've had some minor db
corruption which has been fixed (mainly duplicate primary keys) except
for the pg_class table.
If i do a vacuum full on pg_class i get something like this:INFO: vacuuming "pg_catalog.pg_class"INFO: "pg_class": found 37
removable, 1845 nonremovable row versions in 18905 pages
DETAIL: 27 dead row versions cannot be removed yet.
Nonremovable row versions range from 160 to 229 bytes long.
There were 933834 unused item pointers.
Total free space (including removable row versions) is 150368692 bytes.
18839 pages are or will become empty, including 0 at the end of the
table.
0 pages containing 0 free bytes are potential move destinations.
CPU 0.01s/0.05u sec elapsed 0.17 sec.INFO: index "pg_class_oid_index"
now contains 1813 row versions in 7 pages
DETAIL: 56 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.INFO: index
"pg_class_relname_nsp_index" now contains 1818 row versions in 24 pages
DETAIL: 63 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.WARNING: index
"pg_class_relname_nsp_index" contains 1818 row versions, but table
contains 1813 row versions
HINT: Rebuild the index with REINDEX.INFO: analyzing
"pg_catalog.pg_class"INFO: "pg_class": scanned 3000 of 18905 pages,
containing 227 live rows and 6 dead rows; 227 rows in sample, 1430
estimated total rows
Total query runtime: 4469 ms.As you can see there are non-removable dead rows (which slowly grows)
and the table size is also increasing in size.. A reindex on the
indexes mentions also succeeds but another vacuum reports the same
thing...In the log files the relevant bits are:
GMT LOG: relation "pg_class" TID 15538/4: dead HOT-updated tuple ---
cannot shrink relation
2009-02-12 21:06:40 GMT STATEMENT: VACUUM FULL VERBOSE ANALYZE pg_class
2009-02-12 21:06:40 GMT WARNING: index "pg_class_relname_nsp_index"
contains 1818 row versions, but table contains 1813 row versionsand finally the last message in the psql-admin thread suggested
dumping the above page, which is attached before.Hmm. The comments in vacuum.c about this case suppose that it could
only be a transient condition, ie the tuple became dead while we were
looking at the page. Evidently it's persistent for you, which means
that for some reason heap_page_prune() is failing to remove an
already-dead tuple. I suspect this implies a corrupt HOT chain, but
maybe the data is okay and what you've got is really a bug in
heap_page_prune.Could you send a dump of page 15538 of pg_class, using pg_filedump?
The source code for it is here:
http://sources.redhat.com/rhdb/utilities.html
Best would be -i -f format, ie
pg_filedump -i -f -R 15538 $PGDATA/base/something/1259regards, tom lane
Any help would be appreciated as the pg_class table is constantly
growing which i'm guessing is going to start to affect performance
fairly soon. I'd like to avoid a full restore from backup if possible.Thanks
JOHN
------------------------------------------------------------------------
John Lister <john.lister-ps@kickstone.com> writes:
Originally in psql-admin, but copied here at the request of Tom to..
Thanks for forwarding this. The reason I wanted to call it to the
attention of pgsql-hackers is that the page contents seem a bit odd,
and I'm not sure that we should just write it off as "pilot error".
What we've got here is a page full of transient states of the pg_class
row for temp_queue, which as you explained is constantly being
re-TRUNCATEd by your application. So the data contents of each state
of the row vary only in relfilenode, as expected. One would also expect
that all the copies on a particular page of pg_class would form a single
HOT chain (the database is 8.3.5). What we've actually got is a chain
that is broken in two places and lacks a root tuple(!).
How could it have got that way? John's ill-advised removal of the
transaction logs should have resulted only in the page being a lot older
than it should be, not in a logically corrupt page.
The only other corruption mechanism I can think of is that pg_clog might
contain commit bits for some logically inconsistent set of transaction
numbers, due to some pages of pg_clog having made it to disk and others
not. That could result in some of the intermediate tuples in the chain
not being seen as dead --- but that's not what we see here either.
Aside from the "how did this happen" puzzle, the real point of any
investigation of course ought to be whether we can make heap_page_prune
more robust. At the very least it's undesirable to be leaving the page
in a state where VACUUM FULL will decide it can't shrink.
Ideas anyone?
regards, tom lane
John Lister <john.lister-ps@kickstone.com> writes:
Any help would be appreciated as the pg_class table is constantly
growing which i'm guessing is going to start to affect performance
fairly soon. I'd like to avoid a full restore from backup if possible.
BTW, what I would recommend as a recovery action is to zero out that
page of pg_class while the postmaster is stopped. We know that none
of those rows are useful to you, and there shouldn't be any index
entries pointing at them (since they're all HOT tuples), so at least
in theory that won't cause any damage. Then you can try another
VACUUM FULL and see if there are any more pages with, er, issues.
If you're on a machine that has /dev/zero then something like this
should work:
dd bs=8k count=1 seek=15538 conv=notrunc if=/dev/zero of=$PGDATA/base/16392/1259
but it'd be a good idea to save a copy of the target file so you can try
again if you mess up.
Also, it'd really be prudent to do a dump, initdb, reload once you
get to a point where pg_dump succeeds without complaints. We don't
have any good way to know what other corruption might be lurking
undetected.
regards, tom lane
Cheers, i'll give it ago. I'm probably going to do a full restore over
the weekend while i can shut things down without too many complaints...
I can save any of the files if you are interested in them later on...
JOHN
Tom Lane wrote:
Show quoted text
John Lister <john.lister-ps@kickstone.com> writes:
Any help would be appreciated as the pg_class table is constantly
growing which i'm guessing is going to start to affect performance
fairly soon. I'd like to avoid a full restore from backup if possible.BTW, what I would recommend as a recovery action is to zero out that
page of pg_class while the postmaster is stopped. We know that none
of those rows are useful to you, and there shouldn't be any index
entries pointing at them (since they're all HOT tuples), so at least
in theory that won't cause any damage. Then you can try another
VACUUM FULL and see if there are any more pages with, er, issues.If you're on a machine that has /dev/zero then something like this
should work:dd bs=8k count=1 seek=15538 conv=notrunc if=/dev/zero of=$PGDATA/base/16392/1259
but it'd be a good idea to save a copy of the target file so you can try
again if you mess up.Also, it'd really be prudent to do a dump, initdb, reload once you
get to a point where pg_dump succeeds without complaints. We don't
have any good way to know what other corruption might be lurking
undetected.regards, tom lane
Tom Lane wrote:
Aside from the "how did this happen" puzzle, the real point of any
investigation of course ought to be whether we can make heap_page_prune
more robust. At the very least it's undesirable to be leaving the page
in a state where VACUUM FULL will decide it can't shrink.
I'm as puzzled as you are on how it happened.
The fundamental problem here is that we have HOT-updated tuples that are
missing the root tuple. heap_prune_chain doesn't know how to remove the
dead tuples from such chains, and neither does vacuum. What's worse is
that there's no index pointer to the live tuple in the chain, and even
VACUUM FULL doesn't fix that.
Could we modify heap_page_prune so that it detects such orphaned HOT
tuples, and clears the HOT_UPDATED flag for them? That would at least
let you recover. I'm pretty wary of trying to "fix" things after
corruption in general since you can't be sure what's correct and what's
not, but clearing the HOT_UPDATED flag seems safe and more likely to
help than hurt. Clearing the flag would let the tuple become indexed
again in a VACUUM FULL or REINDEX, so it would fix the inconsistency
that otherwise a sequential scan can see the tuple but an index scan can
not. It would also allow the next heap_page_prune operation to remove
the remaining dead tuples in the chain.
--
Heikki Linnakangas
EnterpriseDB http://www.enterprisedb.com
On Fri, 2009-02-13 at 11:19 -0500, Tom Lane wrote:
Aside from the "how did this happen" puzzle, the real point of any
investigation of course ought to be whether we can make heap_page_prune
more robust. At the very least it's undesirable to be leaving the page
in a state where VACUUM FULL will decide it can't shrink.
I think it would be useful to have a function that can scan a table to
see if this issue exists. ISTM if it has happened once it can have
happened many times. It would be useful to have some more trouble
reports so we can assess the size and scope of this problem.
--
Simon Riggs www.2ndQuadrant.com
PostgreSQL Training, Services and Support
On Fri, Feb 13, 2009 at 9:49 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
The only other corruption mechanism I can think of is that pg_clog might
contain commit bits for some logically inconsistent set of transaction
numbers, due to some pages of pg_clog having made it to disk and others
not. That could result in some of the intermediate tuples in the chain
not being seen as dead --- but that's not what we see here either.
Or can it be otherwise where some transactions which in fact
committed, are marked as aborted because of clog corruption ? In that
case, some of the intermediate tuples in the HOT chain may get removed
(because we handle aborted heap-only tuples separately) and break the
HOT chain.
I am also looking at the pruning logic to see if I can spot something unusual.
Thanks,
Pavan
--
Pavan Deolasee
EnterpriseDB http://www.enterprisedb.com