Postgres is eating my CPU

Postmaster is eating my CPU -- see ps and top output at
http://jamesthornton.com/misc/postgres.txt or below (it wraps too much
when posting to Google, but my server keeps getting overloaded).

As you can see from the ps output, there are several INSERT statements
-- these return after restarting Postgres and even rebooting the
system. I checked the system log for that server, and there are only
~30 INSERTS over the last ~12 hours (all INSERTs called by AOLserver
into the referer_log). Futhermore, I haven't been running any INSERT
statements from psql, and no one else has access to this system.

Yesterday, I ran "vacuum analyze" for the first time in a long time --
could that have caused this situation?

System: Postgres 7.0.3, AOLserver 3.4/OpenACS 3.2.5/Postgres driver
2.0, Linux 7.1

P.S. -- Here's Don Baccus' reply from the OpenACS bboard...

This is very strange ... my guess is that for some reason a lock is
being held persistently and your processes are spinning on it. This
should never (cough) happen.

This is one for the PG hackers group, I think - Tom Lane's more likely
to be able to give you help here than any of us.

----------------------

ps -fU postgres...

UID PID PPID C STIME TTY TIME CMD
postgres 1842 1 0 12:41 ? 00:00:00
/usr/local/pgsql/bin/postmaster -B 6000 -o -S 2000 -S -D
/usr/local/pgsql/data
postgres 1872 1842 82 12:41 ? 01:06:20
/usr/local/pgsql/bin/postgres localhost nsadmin james INSERT
postgres 1997 1842 0 13:11 ? 00:00:02
/usr/local/pgsql/bin/postgres localhost nsadmin james idle
postgres 2025 1842 21 13:15 ? 00:10:04
/usr/local/pgsql/bin/postgres localhost nsadmin james INSERT
postgres 2072 1842 27 13:30 ? 00:08:51
/usr/local/pgsql/bin/postgres localhost nsadmin james INSERT
postgres 2077 1842 25 13:31 ? 00:07:41
/usr/local/pgsql/bin/postgres localhost nsadmin james INSERT
postgres 2079 1842 25 13:31 ? 00:07:44
/usr/local/pgsql/bin/postgres localhost nsadmin james INSERT
postgres 2082 1842 25 13:31 ? 00:07:40
/usr/local/pgsql/bin/postgres localhost nsadmin james INSERT
postgres 2086 1842 26 13:33 ? 00:07:41
/usr/local/pgsql/bin/postgres localhost nsadmin james INSERT
postgres 2090 1842 0 13:35 ? 00:00:01
/usr/local/pgsql/bin/postgres localhost nsadmin james idle
postgres 2122 1842 6 13:41 ? 00:01:22
/usr/local/pgsql/bin/postgres localhost nsadmin james INSERT
postgres 2131 1842 0 13:41 ? 00:00:00
/usr/local/pgsql/bin/postgres localhost nsadmin buxs idle
postgres 2187 1842 20 13:54 ? 00:01:32
/usr/local/pgsql/bin/postgres localhost nsadmin james INSERT
postgres 2189 1842 19 13:54 ? 00:01:28
/usr/local/pgsql/bin/postgres localhost nsadmin james INSERT
postgres 2205 1842 0 13:59 ? 00:00:00
/usr/local/pgsql/bin/postgres localhost nsadmin buxs idle
postgres 2217 1842 0 14:00 ? 00:00:00
/usr/local/pgsql/bin/postgres localhost nsadmin james idle
postgres 2218 1842 0 14:00 ? 00:00:00
/usr/local/pgsql/bin/postgres localhost nsadmin buxs idle
postgres 2219 1842 0 14:00 ? 00:00:00
/usr/local/pgsql/bin/postgres localhost nsadmin buxs idle
postgres 2220 1842 0 14:00 ? 00:00:00
/usr/local/pgsql/bin/postgres localhost nsadmin james idle

top output for postgres user...

2:19pm up 2:31, 2 users, load average: 3.54, 5.55, 6.03
118 processes: 113 sleeping, 5 running, 0 zombie, 0 stopped
CPU states: 195.3% user, 4.6% system, 0.0% nice, 807224.6% idle
Mem: 319596K av, 289688K used, 29908K free, 0K shrd,
30884K buff
Swap: 658584K av, 12K used, 658572K free
79636K cached

PID USER PRI NI SIZE RSS SHARE STAT %CPU %MEM TIME COMMAND
2122 postgres 9 0 12300 12M 4560 S 31.5 3.8 2:16
postmaster
2072 postgres 9 0 4144 4144 3524 S 23.1 1.2 9:40
postmaster
2189 postgres 15 0 4152 4152 3528 R 21.2 1.2 2:22
postmaster
2077 postgres 15 0 4152 4152 3532 R 18.2 1.2 8:31
postmaster
1872 postgres 9 0 11848 11M 4128 R 16.5 3.7 67:14
postmaster
2187 postgres 9 0 4148 4148 3528 S 16.1 1.2 2:23
postmaster
2082 postgres 9 0 4144 4144 3524 S 15.9 1.2 8:30
postmaster
2079 postgres 9 0 4140 4140 3520 S 14.8 1.2 8:39
postmaster
2086 postgres 9 0 4140 4140 3516 S 14.2 1.2 8:38
postmaster
2025 postgres 9 0 11800 11M 4084 R 11.5 3.6 10:54
postmaster
2090 postgres 9 0 15548 15M 6748 S 1.1 4.8 0:01
postmaster
1842 postgres 8 0 1904 1904 1792 S 0.0 0.5 0:00
postmaster
1997 postgres 9 0 13864 13M 5752 S 0.0 4.3 0:02
postmaster
2131 postgres 9 0 4696 4696 4004 S 0.0 1.4 0:00
postmaster
2205 postgres 9 0 3996 3996 3388 S 0.0 1.2 0:00
postmaster
2217 postgres 9 0 11164 10M 3544 S 0.0 3.4 0:00
postmaster
2218 postgres 9 0 11704 11M 3616 S 0.0 3.6 0:00
postmaster
2219 postgres 9 0 11604 11M 3584 S 0.0 3.6 0:00
postmaster
2220 postgres 9 0 3472 3472 2980 S 0.0 1.0 0:00
postmaster

top output for nsadmin user (nsd = AOLserver, which is the only server
accessing Postgres)...

2:19pm up 2:31, 2 users, load average: 3.54, 5.55, 6.03
118 processes: 113 sleeping, 5 running, 0 zombie, 0 stopped
CPU states: 195.3% user, 4.6% system, 0.0% nice, 807224.6% idle
Mem: 319596K av, 289688K used, 29908K free, 0K shrd,
30884K buff
Swap: 658584K av, 12K used, 658572K free
79636K cached

PID USER PRI NI SIZE RSS SHARE STAT %CPU %MEM TIME COMMAND
2273 nsadmin 18 0 1084 1084 840 R 4.4 0.3 0:01 top
1122 nsadmin 9 0 1408 1408 1020 S 0.0 0.4 0:00 bash
1588 nsadmin 9 0 1428 1428 1028 S 0.0 0.4 0:00 bash
1852 nsadmin 9 0 19784 19M 1828 S 0.0 6.1 0:03 nsd
1855 nsadmin 9 0 58344 56M 1744 S 0.0 18.2 0:03 nsd
1858 nsadmin 8 0 58344 56M 1744 S 0.0 18.2 0:00 nsd
1859 nsadmin 9 0 58344 56M 1744 S 0.0 18.2 0:00 nsd
1860 nsadmin 8 0 19784 19M 1828 S 0.0 6.1 0:00 nsd
1861 nsadmin 9 0 19784 19M 1828 S 0.0 6.1 0:00 nsd
1862 nsadmin 9 0 58344 56M 1744 S 0.0 18.2 0:00 nsd
1863 nsadmin 9 0 19784 19M 1828 S 0.0 6.1 0:00 nsd
1864 nsadmin 9 0 19784 19M 1828 S 0.0 6.1 0:00 nsd
1865 nsadmin 9 0 58344 56M 1744 S 0.0 18.2 0:00 nsd
1946 nsadmin 9 0 58344 56M 1744 S 0.0 18.2 0:00 nsd
1951 nsadmin 9 0 58344 56M 1744 S 0.0 18.2 0:00 nsd
2044 nsadmin 9 0 58344 56M 1744 S 0.0 18.2 0:01 nsd
2067 nsadmin 9 0 58344 56M 1744 S 0.0 18.2 0:00 nsd
2069 nsadmin 9 0 58344 56M 1744 S 0.0 18.2 0:00 nsd
2078 nsadmin 9 0 58344 56M 1744 S 0.0 18.2 0:00 nsd
2080 nsadmin 9 0 58344 56M 1744 S 0.0 18.2 0:00 nsd
2081 nsadmin 9 0 58344 56M 1744 S 0.0 18.2 0:00 nsd
2174 nsadmin 9 0 58344 56M 1744 S 0.0 18.2 0:00 nsd
2182 nsadmin 9 0 58344 56M 1744 S 0.0 18.2 0:00 nsd
2188 nsadmin 9 0 58344 56M 1744 S 0.0 18.2 0:00 nsd
2190 nsadmin 9 0 58344 56M 1744 S 0.0 18.2 0:00 nsd
2191 nsadmin 9 0 58344 56M 1744 S 0.0 18.2 0:00 nsd
2192 nsadmin 9 0 58344 56M 1744 S 0.0 18.2 0:00 nsd
2197 nsadmin 9 0 58344 56M 1744 S 0.0 18.2 0:00 nsd
2268 nsadmin 9 0 58344 56M 1744 S 0.0 18.2 0:00 nsd