WAL partition overloaded--by autovacuum?

Hi everyone,

I'm running 8.4.2 on a CentOS machine, and postgres recently died with signal 6 because the pg_xlog partition filled up
(33GB)on 7/4/10 10:34:23 (perfect timing, as I was hiking in the mountains in the remotest parts of our country).  I
didsome digging and found the following: 

-- The current state of /db/data/pg_xlog (after postgres died on 7/4/10) indicates there are 2056 files, all created
between7/4/10 10:01 and 7/4/10 10:34, and a quick bash-kung-fu check shows that these files were created anywhere from
3per minute (10:22) to 106 per minute (10:12) 
-- wal_buffers=8MB; commit_siblings=200; commit_delay=0; checkpoint_segments=16
-- All other WAL-related parameters are either defaults or commented out

-- syslog shows that on 7/2/10 from 10:16:11 to 10:21:51, messages similar to this occurred 29 times:
> Jul  2 10:16:11 db4.sac postgres[20526]: [56-1] 2010-07-02 10:16:11.117 PDT [user=,db=  PID:20526 XID:0]LOG:
checkpointsare occurring too frequently (4 seconds apart) 
> Jul  2 10:16:11 db4.sac postgres[20526]: [56-2] 2010-07-02 10:16:11.117 PDT [user=,db=  PID:20526 XID:0]HINT:
Considerincreasing the configuration parameter "checkpoint_segments". 

-- On 7/4/10 from 09:09:02 to 09:10:08, the same type of messages occurred 21 times in syslog
-- This message did not occur on 7/3/10 at all

-- Preceding the "checkpoints are occurring too frequently" syslog entries are autovacuum entries:
> Jul  2 10:16:04 db4.sac postgres[11357]: [7-1] 2010-07-02 10:16:04.576 PDT [user=,db=  PID:11357 XID:0]LOG:
automaticvacuum of table "tii._sac_global.sl_event": index scans: 1 
> Jul  2 10:16:04 db4.sac postgres[11357]: [7-2]     pages: 0 removed, 25 remain
> Jul  2 10:16:04 db4.sac postgres[11357]: [7-3]     tuples: 676 removed, 955 remain
> Jul  2 10:16:04 db4.sac postgres[11357]: [7-4]     system usage: CPU 0.01s/0.00u sec elapsed 0.02 sec
> Jul  2 10:16:04 db4.sac postgres[11357]: [8-1] 2010-07-02 10:16:04.580 PDT [user=,db=  PID:11357 XID:197431667]LOG:
automaticanalyze of table "tii._sac_global.sl_event" system usage: CPU 0.00s/0.00u sec elapsed 0.00 sec 
> Jul  2 10:16:04 db4.sac postgres[11357]: [9-1] 2010-07-02 10:16:04.965 PDT [user=,db=  PID:11357 XID:0]LOG:
automaticvacuum of table "tii._sac_global.sl_confirm": index scans: 1 
> Jul  2 10:16:04 db4.sac postgres[11357]: [9-2]     pages: 0 removed, 154 remain
> Jul  2 10:16:04 db4.sac postgres[11357]: [9-3]     tuples: 1834 removed, 8385 remain
> Jul  2 10:16:04 db4.sac postgres[11357]: [9-4]     system usage: CPU 0.32s/0.04u sec elapsed 0.37 sec

> Jul  4 09:08:56 db4.sac postgres[21798]: [13-1] 2010-07-04 09:08:56.107 PDT [user=,db=  PID:21798 XID:0]LOG:
automaticvacuum of table "tii.public.city": index scans: 0 
> Jul  4 09:08:56 db4.sac postgres[21798]: [13-2]    pages: 0 removed, 151 remain
> Jul  4 09:08:56 db4.sac postgres[21798]: [13-3]    tuples: 0 removed, 20223 remain
> Jul  4 09:08:56 db4.sac postgres[21798]: [13-4]    system usage: CPU 0.00s/0.00u sec elapsed 0.01 sec
> Jul  4 09:08:56 db4.sac postgres[21798]: [14-1] 2010-07-04 09:08:56.118 PDT [user=,db=  PID:21798 XID:0]LOG:
automaticvacuum of table "tii.public.country": index scans: 1 
> Jul  4 09:08:56 db4.sac postgres[21798]: [14-2]    pages: 0 removed, 2 remain
> Jul  4 09:08:56 db4.sac postgres[21798]: [14-3]    tuples: 77 removed, 185 remain
> Jul  4 09:08:56 db4.sac postgres[21798]: [14-4]    system usage: CPU 0.00s/0.00u sec elapsed 0.00 sec
> Jul  4 09:08:56 db4.sac postgres[21798]: [15-1] 2010-07-04 09:08:56.335 PDT [user=,db=  PID:21798 XID:0]LOG:
automaticvacuum of table "tii.public.gm3_clipboard": index scans: 1 
> Jul  4 09:08:56 db4.sac postgres[21798]: [15-2]    pages: 0 removed, 897 remain
> Jul  4 09:08:56 db4.sac postgres[21798]: [15-3]    tuples: 2 removed, 121594 remain
> Jul  4 09:08:56 db4.sac postgres[21798]: [15-4]    system usage: CPU 0.07s/0.08u sec elapsed 0.20 sec
...snip...
> Jul  4 09:10:25 db4.sac postgres[22066]: [23-1] 2010-07-04 09:10:25.921 PDT [user=,db=  PID:22066 XID:0]LOG:
automaticvacuum of table "tii.public.pm_assignment": index scans: 1 
> Jul  4 09:10:25 db4.sac postgres[22066]: [23-2]    pages: 0 removed, 995 remain
> Jul  4 09:10:25 db4.sac postgres[22066]: [23-3]    tuples: 323 removed, 83964 remain
> Jul  4 09:10:25 db4.sac postgres[22066]: [23-4]    system usage: CPU 0.01s/0.09u sec elapsed 0.52 sec
> Jul  4 09:10:25 db4.sac postgres[22073]: [7-1] 2010-07-04 09:10:25.978 PDT [user=,db=  PID:22073 XID:0]LOG:
automaticvacuum of table "tii.public.pm_question_type": index scans: 0 
> Jul  4 09:10:25 db4.sac postgres[22073]: [7-2]     pages: 0 removed, 1 remain
> Jul  4 09:10:25 db4.sac postgres[22073]: [7-3]     tuples: 0 removed, 2 remain
> Jul  4 09:10:25 db4.sac postgres[22073]: [7-4]     system usage: CPU 0.00s/0.00u sec elapsed 0.00 sec
> Jul  4 09:10:26 db4.sac postgres[22066]: [24-1] 2010-07-04 09:10:26.301 PDT [user=,db=  PID:22066 XID:0]LOG:
automaticvacuum of table "tii.public.pm_association_rule": index scans: 1 
> Jul  4 09:10:26 db4.sac postgres[22066]: [24-2]    pages: 0 removed, 286 remain
> Jul  4 09:10:26 db4.sac postgres[22066]: [24-3]    tuples: 46 removed, 51321 remain
> Jul  4 09:10:26 db4.sac postgres[22066]: [24-4]    system usage: CPU 0.00s/0.03u sec elapsed 0.34 sec
> Jul  4 09:10:26 db4.sac postgres[22066]: [25-1] 2010-07-04 09:10:26.328 PDT [user=,db=  PID:22066 XID:0]LOG:
automaticvacuum of table "tii.public.role": index scans: 0 
> Jul  4 09:10:26 db4.sac postgres[22066]: [25-2]    pages: 0 removed, 1 remain
> Jul  4 09:10:26 db4.sac postgres[22066]: [25-3]    tuples: 0 removed, 5 remain
> Jul  4 09:10:26 db4.sac postgres[22066]: [25-4]    system usage: CPU 0.00s/0.00u sec elapsed 0.00 sec
> Jul  4 09:10:26 db4.sac postgres[22066]: [26-1] 2010-07-04 09:10:26.373 PDT [user=,db=  PID:22066 XID:0]LOG:
automaticvacuum of table "tii.public.pm_review_type": index scans: 0 
> Jul  4 09:10:26 db4.sac postgres[22066]: [26-2]    pages: 0 removed, 1 remain
> Jul  4 09:10:26 db4.sac postgres[22066]: [26-3]    tuples: 0 removed, 4 remain
> Jul  4 09:10:26 db4.sac postgres[22066]: [26-4]    system usage: CPU 0.00s/0.00u sec elapsed 0.00 sec
> Jul  4 09:10:26 db4.sac postgres[22066]: [27-1] 2010-07-04 09:10:26.428 PDT [user=,db=  PID:22066 XID:0]LOG:
automaticvacuum of table "tii.public.permission": index scans: 0 
> Jul  4 09:10:26 db4.sac postgres[22066]: [27-2]    pages: 0 removed, 1 remain
> Jul  4 09:10:26 db4.sac postgres[22066]: [27-3]    tuples: 0 removed, 8 remain
> Jul  4 09:10:26 db4.sac postgres[22066]: [27-4]    system usage: CPU 0.00s/0.00u sec elapsed 0.01 sec

-- min_duration_statement=1000, so there is a chance that the volume of really-fast write traffic might be masked, but
I'mdoubtful as this is our low-usage season (we run a web service for the education sector). 

-- Another tidbit of information is that I am using slony 2.0.3 for replication, and my sync_interval is 500.  However,
I'mdoubtful that slony traffic is responsible because my other nodes use the exact same config and hardware, and none
ofthem had this issue. 

-- My last administrative action on this machine was to SIGHUP this machine to push changes to pg_hba.conf on 6/29/10.
Justnow, I diff-ed my postgresql.conf file with a copy that I keep in svn--no changes at all. 

This leads me to believe that there was a sudden flurry of write activity that occurred, and the process that would
flushWAL files to /db/data/ couldn't keep up, thereby filling up the disk.  I'm wondering if anyone else out there
mightbe able to give me some insight or comments to my assessment--is it accurate?  Any input would be helpful, and
I'lltry to make necessary architectural changes to keep this from happening again. 

Your help is much appreciated!
--Richard