database vacuum from cron hanging

This may or may not be related to previous threads regarding vacuum problems.
Following the last thread, we built the development snapshot of Oct 6 with
--enable-integer-datetimes and --enable-debug. We have had the autovacuum
running every ten seconds. The only table which will meet the autovacuum
criteria is a table with 72 rows which is frequently updated. This part was doing
fine -- keeping the pages to about 20 without any noticable performance hit.

We also set up nightly crontab jobs:

# Do a vacuum of the dtr database every evening starting at 6:00 p.m.
0 18 * * * /usr/local/pgsql/bin/psql -c "vacuum analyze verbose;" dtr 1> /home/postgres/vacuum-analyze-dtr.out 2>&1
# Do a dump of the dtr database every evening starting at 8:00 p.m.
0 20 * * * /usr/local/pgsql/bin/pg_dump -f /var/pgsql/data/dumps/dtr.dump -Fc dtr

I checked the output files from these after the first night, and all seemed well.
There were messages at the end regarding the fsm settings, but after close
review and checking the archives, decided it was OK. I guess I failed to run a ps
on the postgres user, or failed to notice the process that was left hanging.
Anyway, after complaints that the server was getting slow today, I took another
look. Below is a cut and paste from my ssh session.

dtr2:/var/pgsql/data # ps aux|grep ^postgres
postgres 29479 0.0 0.0 172112 4984 ? S Oct07 0:03 /usr/local/pgsql/bin/postmaster -D /var/pgsql/data
postgres 29481 0.0 1.9 172296 165296 ? S Oct07 0:12 postgres: writer process
postgres 29482 0.0 0.0 7908 2816 ? S Oct07 0:43 postgres: stats buffer process
postgres 29483 0.0 0.0 7228 2028 ? S Oct07 0:43 postgres: stats collector process
postgres 30948 0.0 0.0 172968 8124 ? S Oct07 0:00 postgres: dtr dtr 127.0.0.1(32794) idle
postgres 744 0.0 0.0 2440 1056 ? Ss Oct07 0:00 /bin/sh -c /usr/local/pgsql/bin/psql -c "vacuum analyze verbose;" dtr 1> /home/postgres/vacuum-analyze-dtr.out 2>&1
postgres 746 0.0 0.0 3200 1004 ? S Oct07 0:00 /usr/local/pgsql/bin/psql -c vacuum analyze verbose; dtr
postgres 748 0.0 0.0 190008 7544 ? S Oct07 0:00 postgres: postgres dtr [local] VACUUM
postgres 12664 0.0 0.0 2440 1052 ? Ss Oct08 0:00 /bin/sh -c /usr/local/pgsql/bin/psql -c "vacuum analyze verbose;" dtr 1> /home/postgres/vacuum-analyze-dtr.out 2>&1
postgres 12666 0.0 0.0 3200 1004 ? S Oct08 0:00 /usr/local/pgsql/bin/psql -c vacuum analyze verbose; dtr
postgres 12687 0.0 0.0 173636 7572 ? S Oct08 0:00 postgres: postgres dtr [local] VACUUM waiting
postgres 24647 0.0 0.0 2440 1052 ? Ss Oct09 0:00 /bin/sh -c /usr/local/pgsql/bin/psql -c "vacuum analyze verbose;" dtr 1> /home/postgres/vacuum-analyze-dtr.out 2>&1
postgres 24649 0.0 0.0 3200 1000 ? S Oct09 0:00 /usr/local/pgsql/bin/psql -c vacuum analyze verbose; dtr
postgres 24670 0.0 0.0 173636 7888 ? S Oct09 0:00 postgres: postgres dtr [local] VACUUM waiting
postgres 4273 0.0 0.0 2440 1056 ? Ss Oct10 0:00 /bin/sh -c /usr/local/pgsql/bin/psql -c "vacuum analyze verbose;" dtr 1> /home/postgres/vacuum-analyze-dtr.out 2>&1
postgres 4275 0.0 0.0 3200 1004 ? S Oct10 0:00 /usr/local/pgsql/bin/psql -c vacuum analyze verbose; dtr
postgres 4281 0.0 0.0 173104 7512 ? S Oct10 0:00 postgres: postgres dtr [local] VACUUM waiting
postgres 14689 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32863) idle
postgres 14690 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32864) idle
postgres 14691 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32865) idle
postgres 14692 0.0 0.0 172864 6944 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32866) idle
postgres 14693 0.0 0.1 173128 8632 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32867) idle
postgres 14694 15.9 1.4 173112 120924 ? R 11:33 14:27 postgres: dtr dtr 127.0.0.1(32868) UPDATE
postgres 14695 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32869) idle
postgres 14696 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32870) idle
postgres 14697 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32871) idle
postgres 14698 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32872) idle
postgres 14699 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32873) idle
postgres 14700 16.0 1.4 173116 120532 ? S 11:33 14:27 postgres: dtr dtr 127.0.0.1(32874) idle
postgres 14701 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32875) idle
postgres 14702 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32876) idle
postgres 14703 16.0 1.4 173108 121692 ? S 11:33 14:28 postgres: dtr dtr 127.0.0.1(32877) idle
postgres 14704 15.9 1.4 173068 120704 ? S 11:33 14:24 postgres: dtr dtr 127.0.0.1(32878) idle
postgres 14705 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32879) idle
postgres 14706 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32880) idle
postgres 14707 15.9 1.4 173112 120448 ? S 11:33 14:23 postgres: dtr dtr 127.0.0.1(32881) idle
postgres 14708 15.8 1.4 173108 120144 ? S 11:33 14:17 postgres: dtr dtr 127.0.0.1(32882) idle
postgres 14961 0.0 0.1 173128 9692 ? S 12:03 0:00 postgres: dtr dtr 165.219.88.90(54422) idle
postgres 14963 0.0 0.0 172604 5880 ? S 12:03 0:00 postgres: dtr dtr 165.219.88.90(54424) idle
postgres 14970 0.0 0.1 173080 13440 ? S 12:04 0:00 postgres: dtr dtr 165.219.88.90(54430) idle
postgres 15021 0.0 0.0 172604 5880 ? S 12:12 0:00 postgres: dtr dtr 165.219.88.90(54452) idle
dtr2:/var/pgsql/data # strace -tt -p 4281
Process 4281 attached - interrupt to quit
13:03:57.061515 semop(4980740, 0xbfffc430, 1 <unfinished ...>
Process 4281 detached
dtr2:/var/pgsql/data # gdb
GNU gdb 6.3
Copyright 2004 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB. Type "show warranty" for details.
This GDB was configured as "i586-suse-linux".
(gdb) attach 4281
Attaching to process 4281
Reading symbols from /usr/local/pgsql/bin/postgres...done.
Using host libthread_db library "/lib/libthread_db.so.1".
Reading symbols from /lib/libz.so.1...done.
Loaded symbols for /lib/libz.so.1
Reading symbols from /lib/libreadline.so.5...done.
Loaded symbols for /lib/libreadline.so.5
Reading symbols from /lib/libcrypt.so.1...done.
Loaded symbols for /lib/libcrypt.so.1
Reading symbols from /lib/libresolv.so.2...done.
Loaded symbols for /lib/libresolv.so.2
Reading symbols from /lib/libnsl.so.1...done.
Loaded symbols for /lib/libnsl.so.1
Reading symbols from /lib/libdl.so.2...done.
Loaded symbols for /lib/libdl.so.2
Reading symbols from /lib/i686/libm.so.6...done.
Loaded symbols for /lib/i686/libm.so.6
Reading symbols from /lib/i686/libc.so.6...done.
Loaded symbols for /lib/i686/libc.so.6
Reading symbols from /lib/libncurses.so.5...done.
Loaded symbols for /lib/libncurses.so.5
Reading symbols from /lib/ld-linux.so.2...done.
Loaded symbols for /lib/ld-linux.so.2
0x401aac58 in semop () from /lib/i686/libc.so.6
(gdb) bt
#0 0x401aac58 in semop () from /lib/i686/libc.so.6
#1 0x0816a3d4 in PGSemaphoreLock (sema=0x0, interruptOK=1 '\001') at pg_sema.c:418
#2 0x0818d260 in ProcSleep (lockMethodTable=0x4a2a520c, lockmode=4, lock=0x4a31b3a0, proclock=0x4a340be8) at proc.c:757
#3 0x0818c558 in LockAcquire (lockmethodid=1, locktag=0xbfffc540, isTempObject=0 '\0', lockmode=4, sessionLock=0 '\0', dontWait=0 '\0') at lock.c:1090
#4 0x0818a8f9 in LockRelation (relation=0x4a585ce0, lockmode=4) at lmgr.c:144
#5 0x0808c909 in relation_open (relationId=2606, lockmode=4) at heapam.c:454
#6 0x08118d3a in vacuum_rel (relid=2606, vacstmt=0x83471c8, expected_relkind=114 'r') at vacuum.c:1005
#7 0x0811a23b in vacuum (vacstmt=0x83471c8, relids=0x0) at vacuum.c:450
#8 0x08196bf6 in PortalRunUtility (portal=0x834ef28, query=0x8347260, dest=0x8347218, completionTag=0xbfffcb00 "") at pquery.c:991
#9 0x08198099 in PortalRun (portal=0x834ef28, count=2147483647, dest=0x8347218, altdest=0x8347218, completionTag=0xbfffcb00 "") at pquery.c:1058
#10 0x08193b48 in exec_simple_query (query_string=0x8346f08 "vacuum analyze verbose;") at postgres.c:1017
#11 0x0819570a in PostgresMain (argc=4, argv=0x82ec108, username=0x82ec0e0 "postgres") at postgres.c:3184
#12 0x081716e5 in ServerLoop () at postmaster.c:2862
#13 0x0817235e in PostmasterMain (argc=3, argv=0x82e9d38) at postmaster.c:941
#14 0x0813aab8 in main (argc=3, argv=0x82e9d38) at main.c:268
(gdb) quit
The program is running. Quit anyway (and detach it)? (y or n) y
Detaching from program: /usr/local/pgsql/bin/postgres, process 4281
dtr2:/var/pgsql/data # ps aux|grep ^postgres
postgres 29479 0.0 0.0 172112 4984 ? S Oct07 0:03 /usr/local/pgsql/bin/postmaster -D /var/pgsql/data
postgres 29481 0.0 1.9 172296 165296 ? S Oct07 0:12 postgres: writer process
postgres 29482 0.0 0.0 7908 2816 ? S Oct07 0:43 postgres: stats buffer process
postgres 29483 0.0 0.0 7228 2028 ? S Oct07 0:43 postgres: stats collector process
postgres 30948 0.0 0.0 172968 8124 ? S Oct07 0:00 postgres: dtr dtr 127.0.0.1(32794) idle
postgres 744 0.0 0.0 2440 1056 ? Ss Oct07 0:00 /bin/sh -c /usr/local/pgsql/bin/psql -c "vacuum analyze verbose;" dtr 1> /home/postgres/vacuum-analyze-dtr.out 2>&1
postgres 746 0.0 0.0 3200 1004 ? S Oct07 0:00 /usr/local/pgsql/bin/psql -c vacuum analyze verbose; dtr
postgres 748 0.0 0.0 190008 7544 ? S Oct07 0:00 postgres: postgres dtr [local] VACUUM
postgres 12664 0.0 0.0 2440 1052 ? Ss Oct08 0:00 /bin/sh -c /usr/local/pgsql/bin/psql -c "vacuum analyze verbose;" dtr 1> /home/postgres/vacuum-analyze-dtr.out 2>&1
postgres 12666 0.0 0.0 3200 1004 ? S Oct08 0:00 /usr/local/pgsql/bin/psql -c vacuum analyze verbose; dtr
postgres 12687 0.0 0.0 173636 7572 ? S Oct08 0:00 postgres: postgres dtr [local] VACUUM waiting
postgres 24647 0.0 0.0 2440 1052 ? Ss Oct09 0:00 /bin/sh -c /usr/local/pgsql/bin/psql -c "vacuum analyze verbose;" dtr 1> /home/postgres/vacuum-analyze-dtr.out 2>&1
postgres 24649 0.0 0.0 3200 1000 ? S Oct09 0:00 /usr/local/pgsql/bin/psql -c vacuum analyze verbose; dtr
postgres 24670 0.0 0.0 173636 7888 ? S Oct09 0:00 postgres: postgres dtr [local] VACUUM waiting
postgres 4273 0.0 0.0 2440 1056 ? Ss Oct10 0:00 /bin/sh -c /usr/local/pgsql/bin/psql -c "vacuum analyze verbose;" dtr 1> /home/postgres/vacuum-analyze-dtr.out 2>&1
postgres 4275 0.0 0.0 3200 1004 ? S Oct10 0:00 /usr/local/pgsql/bin/psql -c vacuum analyze verbose; dtr
postgres 14689 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32863) idle
postgres 14690 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32864) idle
postgres 14691 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32865) idle
postgres 14692 0.0 0.0 172864 6944 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32866) idle
postgres 14693 0.0 0.1 173128 8632 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32867) idle
postgres 14694 16.0 1.4 173112 121268 ? S 11:33 14:43 postgres: dtr dtr 127.0.0.1(32868) idle
postgres 14695 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32869) idle
postgres 14696 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32870) idle
postgres 14697 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32871) idle
postgres 14698 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32872) idle
postgres 14699 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32873) idle
postgres 14700 16.0 1.4 173116 120912 ? S 11:33 14:43 postgres: dtr dtr 127.0.0.1(32874) idle
postgres 14701 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32875) idle
postgres 14702 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32876) idle
postgres 14703 16.0 1.4 173108 122108 ? S 11:33 14:43 postgres: dtr dtr 127.0.0.1(32877) idle
postgres 14704 15.9 1.4 173068 121288 ? S 11:33 14:36 postgres: dtr dtr 127.0.0.1(32878) idle
postgres 14705 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32879) idle
postgres 14706 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32880) idle
postgres 14707 15.9 1.4 173112 120864 ? S 11:33 14:35 postgres: dtr dtr 127.0.0.1(32881) idle
postgres 14708 15.8 1.4 173108 120540 ? R 11:33 14:30 postgres: dtr dtr 127.0.0.1(32882) UPDATE
postgres 14961 0.0 0.1 173128 9692 ? S 12:03 0:00 postgres: dtr dtr 165.219.88.90(54422) idle
postgres 14963 0.0 0.0 172604 5880 ? S 12:03 0:00 postgres: dtr dtr 165.219.88.90(54424) idle
postgres 14970 0.0 0.1 173080 13440 ? S 12:04 0:00 postgres: dtr dtr 165.219.88.90(54430) idle
postgres 15021 0.0 0.0 172604 5880 ? S 12:12 0:00 postgres: dtr dtr 165.219.88.90(54452) idle
postgres 4281 0.0 0.0 173104 7512 ? S Oct10 0:00 postgres: postgres dtr [local] VACUUM waiting
dtr2:/var/pgsql/data # gdb
GNU gdb 6.3
Copyright 2004 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB. Type "show warranty" for details.
This GDB was configured as "i586-suse-linux".
(gdb) attach 748
Attaching to process 748
Reading symbols from /usr/local/pgsql/bin/postgres...done.
Using host libthread_db library "/lib/libthread_db.so.1".
[snip]
0x401aac58 in semop () from /lib/i686/libc.so.6
(gdb) bt
#0 0x401aac58 in semop () from /lib/i686/libc.so.6
#1 0x0816a3d4 in PGSemaphoreLock (sema=0x0, interruptOK=1 '\001') at pg_sema.c:418
#2 0x0818cf96 in ProcWaitForSignal () at proc.c:985
#3 0x0818171e in LockBufferForCleanup (buffer=782) at bufmgr.c:1859
#4 0x08093c9a in btbulkdelete (fcinfo=0xfffffffc) at nbtree.c:639
#5 0x082031d7 in FunctionCall3 (flinfo=0x1, arg1=4294967292, arg2=4294967292, arg3=4294967292) at fmgr.c:1182
#6 0x0808f054 in index_bulk_delete (indexRelation=0x4a59d960, callback=0x811aa20 <dummy_tid_reaped>, callback_state=0x0) at indexam.c:687
#7 0x0811ba85 in lazy_vacuum_rel (onerel=0x4a572ea0, vacstmt=0x8347088) at vacuumlazy.c:625
#8 0x081193c2 in vacuum_rel (relid=<value optimized out>, vacstmt=0x8347088, expected_relkind=114 'r') at vacuum.c:1074
#9 0x0811a23b in vacuum (vacstmt=0x8347088, relids=0x0) at vacuum.c:450
#10 0x08196bf6 in PortalRunUtility (portal=0x834ede8, query=0x8347120, dest=0x83470d8, completionTag=0xbfffcb00 "") at pquery.c:991
#11 0x08198099 in PortalRun (portal=0x834ede8, count=2147483647, dest=0x83470d8, altdest=0x83470d8, completionTag=0xbfffcb00 "") at pquery.c:1058
#12 0x08193b48 in exec_simple_query (query_string=0x8346dc8 "vacuum analyze verbose;") at postgres.c:1017
#13 0x0819570a in PostgresMain (argc=4, argv=0x82ec108, username=0x82ec0e0 "postgres") at postgres.c:3184
#14 0x081716e5 in ServerLoop () at postmaster.c:2862
#15 0x0817235e in PostmasterMain (argc=3, argv=0x82e9d38) at postmaster.c:941
#16 0x0813aab8 in main (argc=3, argv=0x82e9d38) at main.c:268
(gdb) detach
Detaching from program: /usr/local/pgsql/bin/postgres, process 748
(gdb) attach 12687
Attaching to program: /usr/local/pgsql/bin/postgres, process 12687
Symbols already loaded for /lib/libz.so.1
[snip]
0x401aac58 in semop () from /lib/i686/libc.so.6
(gdb) bt
#0 0x401aac58 in semop () from /lib/i686/libc.so.6
#1 0x0816a3d4 in PGSemaphoreLock (sema=0x0, interruptOK=1 '\001') at pg_sema.c:418
#2 0x0818d260 in ProcSleep (lockMethodTable=0x4a2a520c, lockmode=4, lock=0x4a31b3a0, proclock=0x4a340b70) at proc.c:757
#3 0x0818c558 in LockAcquire (lockmethodid=1, locktag=0xbfffc540, isTempObject=0 '\0', lockmode=4, sessionLock=0 '\0', dontWait=0 '\0') at lock.c:1090
#4 0x0818a8f9 in LockRelation (relation=0x4a572ea0, lockmode=4) at lmgr.c:144
#5 0x0808c909 in relation_open (relationId=2606, lockmode=4) at heapam.c:454
#6 0x08118d3a in vacuum_rel (relid=2606, vacstmt=0x83470b0, expected_relkind=114 'r') at vacuum.c:1005
#7 0x0811a23b in vacuum (vacstmt=0x83470b0, relids=0x0) at vacuum.c:450
#8 0x08196bf6 in PortalRunUtility (portal=0x83512a0, query=0x8347148, dest=0x8347100, completionTag=0xbfffcb00 "") at pquery.c:991
#9 0x08198099 in PortalRun (portal=0x83512a0, count=2147483647, dest=0x8347100, altdest=0x8347100, completionTag=0xbfffcb00 "") at pquery.c:1058
#10 0x08193b48 in exec_simple_query (query_string=0x8346df0 "vacuum analyze verbose;") at postgres.c:1017
#11 0x0819570a in PostgresMain (argc=4, argv=0x82ec108, username=0x82ec0e0 "postgres") at postgres.c:3184
#12 0x081716e5 in ServerLoop () at postmaster.c:2862
#13 0x0817235e in PostmasterMain (argc=3, argv=0x82e9d38) at postmaster.c:941
#14 0x0813aab8 in main (argc=3, argv=0x82e9d38) at main.c:268
(gdb) detach 12687
Detaching from program: /usr/local/pgsql/bin/postgres, process 12687
ptrace: Input/output error.
(gdb) detach
Detaching from program: /usr/local/pgsql/bin/postgres, process 12687
(gdb) attach 24670
Attaching to program: /usr/local/pgsql/bin/postgres, process 24670
Symbols already loaded for /lib/libz.so.1
[snip]
0x401aac58 in semop () from /lib/i686/libc.so.6
(gdb) bt
#0 0x401aac58 in semop () from /lib/i686/libc.so.6
#1 0x0816a3d4 in PGSemaphoreLock (sema=0x0, interruptOK=1 '\001') at pg_sema.c:418
#2 0x0818d260 in ProcSleep (lockMethodTable=0x4a2a520c, lockmode=4, lock=0x4a31b3a0, proclock=0x4a3409e0) at proc.c:757
#3 0x0818c558 in LockAcquire (lockmethodid=1, locktag=0xbfffc540, isTempObject=0 '\0', lockmode=4, sessionLock=0 '\0', dontWait=0 '\0') at lock.c:1090
#4 0x0818a8f9 in LockRelation (relation=0x4a572ea0, lockmode=4) at lmgr.c:144
#5 0x0808c909 in relation_open (relationId=2606, lockmode=4) at heapam.c:454
#6 0x08118d3a in vacuum_rel (relid=2606, vacstmt=0x83470d8, expected_relkind=114 'r') at vacuum.c:1005
#7 0x0811a23b in vacuum (vacstmt=0x83470d8, relids=0x0) at vacuum.c:450
#8 0x08196bf6 in PortalRunUtility (portal=0x83512c8, query=0x8347170, dest=0x8347128, completionTag=0xbfffcb00 "") at pquery.c:991
#9 0x08198099 in PortalRun (portal=0x83512c8, count=2147483647, dest=0x8347128, altdest=0x8347128, completionTag=0xbfffcb00 "") at pquery.c:1058
#10 0x08193b48 in exec_simple_query (query_string=0x8346e18 "vacuum analyze verbose;") at postgres.c:1017
#11 0x0819570a in PostgresMain (argc=4, argv=0x82ec108, username=0x82ec0e0 "postgres") at postgres.c:3184
#12 0x081716e5 in ServerLoop () at postmaster.c:2862
#13 0x0817235e in PostmasterMain (argc=3, argv=0x82e9d38) at postmaster.c:941
#14 0x0813aab8 in main (argc=3, argv=0x82e9d38) at main.c:268
(gdb) detach
Detaching from program: /usr/local/pgsql/bin/postgres, process 24670
(gdb) quit
dtr2:/var/pgsql/data # ps aux|grep ^postgres
postgres 29479 0.0 0.0 172112 4984 ? S Oct07 0:03 /usr/local/pgsql/bin/postmaster -D /var/pgsql/data
postgres 29481 0.0 1.9 172296 165296 ? S Oct07 0:12 postgres: writer process
postgres 29482 0.0 0.0 7908 2816 ? S Oct07 0:43 postgres: stats buffer process
postgres 29483 0.0 0.0 7228 2028 ? S Oct07 0:43 postgres: stats collector process
postgres 30948 0.0 0.0 172968 8124 ? S Oct07 0:00 postgres: dtr dtr 127.0.0.1(32794) idle
postgres 744 0.0 0.0 2440 1056 ? Ss Oct07 0:00 /bin/sh -c /usr/local/pgsql/bin/psql -c "vacuum analyze verbose;" dtr 1> /home/postgres/vacuum-analyze-dtr.out 2>&1
postgres 746 0.0 0.0 3200 1004 ? S Oct07 0:00 /usr/local/pgsql/bin/psql -c vacuum analyze verbose; dtr
postgres 12664 0.0 0.0 2440 1052 ? Ss Oct08 0:00 /bin/sh -c /usr/local/pgsql/bin/psql -c "vacuum analyze verbose;" dtr 1> /home/postgres/vacuum-analyze-dtr.out 2>&1
postgres 12666 0.0 0.0 3200 1004 ? S Oct08 0:00 /usr/local/pgsql/bin/psql -c vacuum analyze verbose; dtr
postgres 24647 0.0 0.0 2440 1052 ? Ss Oct09 0:00 /bin/sh -c /usr/local/pgsql/bin/psql -c "vacuum analyze verbose;" dtr 1> /home/postgres/vacuum-analyze-dtr.out 2>&1
postgres 24649 0.0 0.0 3200 1000 ? S Oct09 0:00 /usr/local/pgsql/bin/psql -c vacuum analyze verbose; dtr
postgres 4273 0.0 0.0 2440 1056 ? Ss Oct10 0:00 /bin/sh -c /usr/local/pgsql/bin/psql -c "vacuum analyze verbose;" dtr 1> /home/postgres/vacuum-analyze-dtr.out 2>&1
postgres 4275 0.0 0.0 3200 1004 ? S Oct10 0:00 /usr/local/pgsql/bin/psql -c vacuum analyze verbose; dtr
postgres 14689 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32863) idle
postgres 14690 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32864) idle
postgres 14691 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32865) idle
postgres 14692 0.0 0.0 172864 6944 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32866) idle
postgres 14693 0.0 0.1 173128 8632 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32867) idle
postgres 14694 16.0 1.4 173112 124100 ? S 11:33 16:22 postgres: dtr dtr 127.0.0.1(32868) idle
postgres 14695 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32869) idle
postgres 14696 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32870) idle
postgres 14697 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32871) idle
postgres 14698 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32872) idle
postgres 14699 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32873) idle
postgres 14700 16.0 1.4 173116 123524 ? S 11:33 16:22 postgres: dtr dtr 127.0.0.1(32874) idle
postgres 14701 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32875) idle
postgres 14702 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32876) idle
postgres 14703 16.1 1.5 173108 124592 ? R 11:33 16:24 postgres: dtr dtr 127.0.0.1(32877) UPDATE
postgres 14704 15.9 1.4 173068 124024 ? S 11:33 16:15 postgres: dtr dtr 127.0.0.1(32878) idle
postgres 14705 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32879) idle
postgres 14706 0.0 0.0 172604 5880 ? S 11:33 0:00 postgres: dtr dtr 127.0.0.1(32880) idle
postgres 14707 15.9 1.4 173112 123384 ? S 11:33 16:16 postgres: dtr dtr 127.0.0.1(32881) idle
postgres 14708 15.9 1.4 173108 123244 ? S 11:33 16:12 postgres: dtr dtr 127.0.0.1(32882) idle
postgres 14961 0.0 0.1 173128 9692 ? S 12:03 0:00 postgres: dtr dtr 165.219.88.90(54422) idle
postgres 14963 0.0 0.0 172604 5880 ? S 12:03 0:00 postgres: dtr dtr 165.219.88.90(54424) idle
postgres 14970 0.0 0.1 173080 13440 ? S 12:04 0:00 postgres: dtr dtr 165.219.88.90(54430) idle
postgres 15021 0.0 0.0 172604 5880 ? S 12:12 0:00 postgres: dtr dtr 165.219.88.90(54452) idle
postgres 4281 0.0 0.0 173104 7512 ? S Oct10 0:00 postgres: postgres dtr [local] VACUUM waiting
postgres 748 0.0 0.0 190008 7544 ? S Oct07 0:00 postgres: postgres dtr [local] VACUUM
postgres 12687 0.0 0.0 173636 7572 ? S Oct08 0:00 postgres: postgres dtr [local] VACUUM waiting
postgres 24670 0.0 0.0 173636 7888 ? S Oct09 0:00 postgres: postgres dtr [local] VACUUM waiting
dtr2:/var/pgsql/data # /usr/local/pgsql/bin/psql postgres postgres
Welcome [snip]

postgres=# select * from pg_locks;
locktype | database | relation | page | tuple | transactionid | classid | objid | objsubid | transaction | pid | mode | granted
---------------+----------+----------+------+-------+---------------+---------+-------+----------+-------------+-------+--------------------------+---------
relation | 16385 | 2606 | | | | | | | 840981 | 4281 | ShareUpdateExclusiveLock | f
relation | 16385 | 780964 | | | | | | | 1235647 | 14700 | AccessShareLock | t
relation | 16385 | 780964 | | | | | | | 1235647 | 14700 | RowExclusiveLock | t
relation | 16385 | 2666 | | | | | | | 398272 | 748 | RowExclusiveLock | t
relation | 16385 | 2666 | | | | | | | 398272 | 748 | ShareUpdateExclusiveLock | t
relation | 16385 | 2667 | | | | | | | 398272 | 748 | ShareUpdateExclusiveLock | t
relation | 16385 | 16641 | | | | | | | 1235647 | 14700 | AccessShareLock | t
relation | 16385 | 16641 | | | | | | | 1235647 | 14700 | RowExclusiveLock | t
transactionid | | | | | 1235647 | | | | 1235647 | 14700 | ExclusiveLock | t
relation | 16385 | 2606 | | | | | | | 398272 | 748 | ShareUpdateExclusiveLock | t
relation | 10792 | 10341 | | | | | | | 1235648 | 15940 | AccessShareLock | t
transactionid | | | | | 418209 | | | | 418209 | 12687 | ExclusiveLock | t
relation | 16385 | 2665 | | | | | | | 398272 | 748 | ShareUpdateExclusiveLock | t
relation | 16385 | 2606 | | | | | | | 418209 | 12687 | ShareUpdateExclusiveLock | f
transactionid | | | | | 1235648 | | | | 1235648 | 15940 | ExclusiveLock | t
transactionid | | | | | 398272 | | | | 398272 | 748 | ExclusiveLock | t
relation | 16385 | 2664 | | | | | | | 398272 | 748 | ShareUpdateExclusiveLock | t
transactionid | | | | | 840981 | | | | 840981 | 4281 | ExclusiveLock | t
relation | 16385 | 2606 | | | | | | | 435559 | 24670 | ShareUpdateExclusiveLock | f
transactionid | | | | | 435559 | | | | 435559 | 24670 | ExclusiveLock | t
(20 rows)
dtr=> \q

Being relatively new to Linux, PostgreSQL, and crontab, it is entirely possible
that is all illuminates nothing but my ignorance regarding how to schedule the
nightly maintenance, but it seemed possible that this could reflect a vacuum
bug.

-Kevin