Re: Error seen when vacuuming pg_largeobject table

Tom,

Got it to happen again after a power fail. Here is the logs this time
with verbose.

bash-2.05b$ ./postgres -D /t/data/sql -P -O aesop

POSTGRES backend interactive interface
$Revision: 1.245.2.2 $ $Date: 2002/02/27 23:17:01 $

backend> reindex index pg_largeobject_loid_pn_index;
backend>
bash-2.05b$ ./postmaster -D /t/data/sql -i &
[1] 324
bash-2.05b$ ./psql -d aesop -U chris
Welcome to psql, the PostgreSQL interactive terminal.

Type: \copyright for distribution terms
\h for help with SQL commands
\? for help on internal slash commands
\g or terminate with semicolon to execute query
\q to quit

aesop=# vacuum full verbose;
NOTICE: --Relation pg_type-- blocks 3
NOTICE: Pages 3: Changed 1, reaped 1, Empty 0, New 0; Tup 154: Vac 0,
Keep/VTL 0/0, UnUsed 17, MinLen 106, MaxLen 106; Re-using: Free/Avail.
Space 7200/7200; EndEmpty/Avail. Pages 0/3.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Index pg_type_oid_index: Pages 2; Tuples 154: Deleted 0.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Index pg_type_typname_index: Pages 2; Tuples 154: Deleted 0.
CPU 0.00s/0.00u sec elapsed 0.48 sec.
NOTICE: Rel pg_type: Pages: 3 --> 3; Tuple(s) moved: 0.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: --Relation pg_attribute-- blocks 16
NOTICE: Pages 16: Changed 5, reaped 4, Empty 0, New 0; Tup 947: Vac 97,
Keep/VTL 0/0, UnUsed 156, MinLen 98, MaxLen 98; Re-using: Free/Avail.
Space 31252/6760; EndEmpty/Avail. Pages 3/1.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Index pg_attribute_relid_attnam_index: Pages 16; Tuples 947:
Deleted 0.
CPU 0.00s/0.00u sec elapsed 0.03 sec.
NOTICE: Index pg_attribute_relid_attnum_index: Pages 7; Tuples 947:
Deleted 0.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Rel pg_attribute: Pages: 16 --> 13; Tuple(s) moved: 0.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: --Relation pg_class-- blocks 6
NOTICE: Pages 6: Changed 3, reaped 5, Empty 0, New 0; Tup 122: Vac 19,
Keep/VTL 0/0, UnUsed 145, MinLen 116, MaxLen 152; Re-using: Free/Avail.
Space 33476/1292; EndEmpty/Avail. Pages 4/1.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Index pg_class_oid_index: Pages 2; Tuples 122: Deleted 0.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Index pg_class_relname_index: Pages 4; Tuples 122: Deleted 0.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Rel pg_class: Pages: 6 --> 2; Tuple(s) moved: 0.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: --Relation pg_group-- blocks 0
NOTICE: Pages 0: Changed 0, reaped 0, Empty 0, New 0; Tup 0: Vac 0,
Keep/VTL 0/0, UnUsed 0, MinLen 0, MaxLen 0; Re-using: Free/Avail. Space
0/0; EndEmpty/Avail. Pages 0/0.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Index pg_group_name_index: Pages 1; Tuples 0.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Index pg_group_sysid_index: Pages 1; Tuples 0.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: --Relation pg_database-- blocks 1
NOTICE: Pages 1: Changed 0, reaped 1, Empty 0, New 0; Tup 3: Vac 0,
Keep/VTL 0/0, UnUsed 2, MinLen 92, MaxLen 92; Re-using: Free/Avail.
Space 7876/7876; EndEmpty/Avail. Pages 0/1.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Index pg_database_datname_index: Pages 2; Tuples 3: Deleted 0.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Index pg_database_oid_index: Pages 2; Tuples 3: Deleted 0.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Rel pg_database: Pages: 1 --> 1; Tuple(s) moved: 0.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: --Relation pg_inherits-- blocks 0
NOTICE: Pages 0: Changed 0, reaped 0, Empty 0, New 0; Tup 0: Vac 0,
Keep/VTL 0/0, UnUsed 0, MinLen 0, MaxLen 0; Re-using: Free/Avail. Space
0/0; EndEmpty/Avail. Pages 0/0.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Index pg_inherits_relid_seqno_index: Pages 1; Tuples 0.
CPU 0.00s/0.00u sec elapsed 0.01 sec.
NOTICE: --Relation pg_index-- blocks 2
NOTICE: Pages 2: Changed 1, reaped 1, Empty 0, New 0; Tup 57: Vac 0,
Keep/VTL 0/0, UnUsed 16, MinLen 160, MaxLen 160; Re-using: Free/Avail.
Space 6932/6796; EndEmpty/Avail. Pages 0/1.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Index pg_index_indrelid_index: Pages 2; Tuples 57: Deleted 0.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Index pg_index_indexrelid_index: Pages 2; Tuples 57: Deleted 0.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Rel pg_index: Pages: 2 --> 2; Tuple(s) moved: 0.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: --Relation pg_operator-- blocks 10
NOTICE: Pages 10: Changed 0, reaped 0, Empty 0, New 0; Tup 623: Vac 0,
Keep/VTL 0/0, UnUsed 0, MinLen 116, MaxLen 116; Re-using: Free/Avail.
Space 6960/6852; EndEmpty/Avail. Pages 0/1.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Index pg_operator_oid_index: Pages 4; Tuples 623.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Index pg_operator_oprname_l_r_k_index: Pages 8; Tuples 623.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Rel pg_operator: Pages: 10 --> 10; Tuple(s) moved: 0.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: --Relation pg_opclass-- blocks 1
NOTICE: Pages 1: Changed 0, reaped 0, Empty 0, New 0; Tup 51: Vac 0,
Keep/VTL 0/0, UnUsed 0, MinLen 80, MaxLen 80; Re-using: Free/Avail.
Space 3888/3888; EndEmpty/Avail. Pages 0/1.
CPU 0.01s/0.00u sec elapsed 0.00 sec.
NOTICE: Index pg_opclass_am_name_index: Pages 2; Tuples 51.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Index pg_opclass_oid_index: Pages 2; Tuples 51.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Rel pg_opclass: Pages: 1 --> 1; Tuple(s) moved: 0.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: --Relation pg_am-- blocks 1
NOTICE: Pages 1: Changed 0, reaped 0, Empty 0, New 0; Tup 4: Vac 0,
Keep/VTL 0/0, UnUsed 0, MinLen 120, MaxLen 120; Re-using: Free/Avail.
Space 7676/7676; EndEmpty/Avail. Pages 0/1.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Index pg_am_name_index: Pages 2; Tuples 4.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Index pg_am_oid_index: Pages 2; Tuples 4.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Rel pg_am: Pages: 1 --> 1; Tuple(s) moved: 0.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: --Relation pg_amop-- blocks 2
NOTICE: Pages 2: Changed 0, reaped 0, Empty 0, New 0; Tup 180: Vac 0,
Keep/VTL 0/0, UnUsed 0, MinLen 44, MaxLen 44; Re-using: Free/Avail.
Space 7704/7692; EndEmpty/Avail. Pages 0/1.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Index pg_amop_opc_opr_index: Pages 2; Tuples 180.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Index pg_amop_opc_strategy_index: Pages 2; Tuples 180.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Rel pg_amop: Pages: 2 --> 2; Tuple(s) moved: 0.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: --Relation pg_amproc-- blocks 1
NOTICE: Pages 1: Changed 0, reaped 0, Empty 0, New 0; Tup 57: Vac 0,
Keep/VTL 0/0, UnUsed 0, MinLen 44, MaxLen 44; Re-using: Free/Avail.
Space 5436/5436; EndEmpty/Avail. Pages 0/1.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Index pg_amproc_opc_procnum_index: Pages 2; Tuples 57.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Rel pg_amproc: Pages: 1 --> 1; Tuple(s) moved: 0.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: --Relation pg_language-- blocks 1
NOTICE: Pages 1: Changed 0, reaped 0, Empty 0, New 0; Tup 3: Vac 0,
Keep/VTL 0/0, UnUsed 0, MinLen 79, MaxLen 84; Re-using: Free/Avail.
Space 7912/7912; EndEmpty/Avail. Pages 0/1.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Index pg_language_name_index: Pages 2; Tuples 3.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Index pg_language_oid_index: Pages 2; Tuples 3.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Rel pg_language: Pages: 1 --> 1; Tuple(s) moved: 0.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: --Relation pg_largeobject-- blocks 637
NOTICE: Pages 637: Changed 0, reaped 396, Empty 0, New 8; Tup 2380: Vac
517, Keep/VTL 0/0, UnUsed 22, MinLen 70, MaxLen 2092; Re-using:
Free/Avail. Space 1946640/1946008; EndEmpty/Avail. Pages 0/621.
CPU 0.05s/0.01u sec elapsed 0.05 sec.
NOTICE: Index pg_largeobject_loid_pn_index: Pages 1; Tuples 0: Deleted
0.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Index pg_largeobject_loid_pn_index: NUMBER OF INDEX' TUPLES (0)
IS NOT THE SAME AS HEAP' (2380).
Recreate the index.
server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.
The connection to the server was lost. Attempting reset: Succeeded.

aesop=#
aesop=# vacuum verbose pg_largeobject;
NOTICE: Index pg_largeobject_loid_pn_index: Pages 1; Tuples 0: Deleted
0.
CPU 0.01s/0.00u sec elapsed 0.00 sec.
NOTICE: Removed 517 tuples in 376 pages.
CPU 0.05s/0.12u sec elapsed 1.62 sec.
NOTICE: Pages 637: Changed 0, Empty 1; Tup 2380: Vac 517, Keep 0,
UnUsed 22.
Total CPU 0.11s/0.12u sec elapsed 1.68 sec.
VACUUM
aesop=# vacuum full verbose pg_largeobject;
NOTICE: Pages 637: Changed 0, reaped 396, Empty 7, New 1; Tup 2380: Vac
0, Keep/VTL 0/0, UnUsed 539, MinLen 70, MaxLen 2092; Re-using:
Free/Avail. Space 1946640/1946008; EndEmpty/Avail. Pages 0/621.
CPU 0.05s/0.00u sec elapsed 0.05 sec.
NOTICE: Index pg_largeobject_loid_pn_index: Pages 1; Tuples 0: Deleted
0.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Index pg_largeobject_loid_pn_index: NUMBER OF INDEX' TUPLES (0)
IS NOT THE SAME AS HEAP' (2380).
Recreate the index.
server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.
The connection to the server was lost. Attempting reset: Failed. !# \q
bash-2.05b$ pg_ctl stop -D /t/data/sql -m fast waiting for postmaster to
shut down......done postmaster successfully shut down
[1]+ Done ./postmaster -D /t/data/sql -i
bash-2.05b$ ./postgres -D /t/data/sql -P -O aesop

POSTGRES backend interactive interface
$Revision: 1.245.2.2 $ $Date: 2002/02/27 23:17:01 $

backend> reindex index pg_largeobject_loid_pn_index;
bash-2.05b$ ./postmaster -D /t/data/sql -i &
[1] 359
bash-2.05b$ ./psql -d aesop -U chris
Welcome to psql, the PostgreSQL interactive terminal.

Type: \copyright for distribution terms
\h for help with SQL commands
\? for help on internal slash commands
\g or terminate with semicolon to execute query
\q to quit

aesop=# vacuum full verbose pg_largeobject;
NOTICE: --Relation pg_largeobject-- blocks 637
NOTICE: Pages 637: Changed 0, reaped 396, Empty 7, New 1; Tup 2380: Vac
0, Keep/VTL 0/0, UnUsed 539, MinLen 70, MaxLen 2092; Re-using:
Free/Avail. Space 1946640/1946008; EndEmpty/Avail. Pages 0/621.
CPU 0.05s/0.00u sec elapsed 0.05 sec.
NOTICE: Index pg_largeobject_loid_pn_index: Pages 1; Tuples 0: Deleted
0.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
NOTICE: Index pg_largeobject_loid_pn_index: NUMBER OF INDEX' TUPLES (0)
IS NOT THE SAME AS HEAP' (2380).
Recreate the index.
server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.
The connection to the server was lost. Attempting reset: Failed. !# \q
bash-2.05b$

-----Original Message-----
From: Tom Lane [mailto:tgl(at)sss(dot)pgh(dot)pa(dot)us]
Sent: Tuesday, January 27, 2004 1:16 PM
To: cjwhite(at)cisco(dot)com
Cc: pgsql-admin(at)postgresql(dot)org
Subject: Re: [ADMIN] Error seen when vacuuming pg_largeobject table

"Chris White \(cjwhite\)" <cjwhite(at)cisco(dot)com> writes:
> Here is the info. I am running 7.2.1.

7.2.1 is a bit long in the tooth; you really ought to be running 7.2.4
if you are still in the 7.2 series. However I don't think that has much
to do with your immediate problem.

The only thing that struck me about your transcript is that you didn't
show shutting down and restarting the postmaster. You didn't try to run
a standalone backend concurrently with the postmaster did you? (There
are supposed to be interlocks against that, but maybe they failed.) The
failures sort of look like the standalone backend's changes did not
completely propagate back to the regular database, and that's the only
very plausible mechanism I can think of for that ...

Also, I really wanted to see the output of vacuum verbose. Just
"vacuum" doesn't tell anything much.

regards, tom lane