Thread: Re: [ADMIN] database corruption help
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, iepg_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/1259 > > regards, 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 ******************************************************************* * 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 ***
>Please send to pgsql-hackers --- I'd like to get more eyeballs on this.>There's no personally identifiable informationhere 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>withit, 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: > 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/1259 >> >> regards, 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: > 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.comPostgreSQL 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