Hello all, I have a hard situation in hands. my autovacuum does not seem to be able to get his job done; database is under active INSERTs/UPDATEs; CPU is in aprox 50% iowait for the past 5 hours; I've tried turning off autovacuum and the effect goes away; I turn it back on and it goes back to 50% iowait; my IO system is nothing special at all; besides turning autovacuum off and running vacuum by hand once in a while, what else can I do to get out of this situation ? bellow some logs I'm seriously considering turning off autovacuum for good; but I'dd like to get input concerning other approaches... I mean... if I don't turn it of, how can I be sure this will not happen again... we ship products with PG inside... I must be absolutelly sure this will not ever happen in any of our costumers. I'm a bit confuse... sorry :) ! Joao ============================================ 2010-05-13 20:55:00 WEST DEBUG: server process (PID 6197) exited with exit code 0 2010-05-13 20:55:00 WEST DEBUG: forked new backend, pid=6573 socket=6 2010-05-13 20:57:41 WEST ERROR: failed to re-find parent key in "timeslots_strs_var_ts_key" 2010-05-13 20:58:42 WEST LOG: autovacuum: processing database "postgres" 2010-05-13 20:59:35 WEST DEBUG: checkpoint starting 2010-05-13 20:59:35 WEST DEBUG: checkpoint complete; 0 transaction log file(s) added, 0 removed, 0 recycled 2010-05-13 20:59:42 WEST LOG: autovacuum: processing database "template1" 2010-05-13 21:00:00 WEST DEBUG: server process (PID 6573) exited with exit code 0 2010-05-13 21:00:00 WEST DEBUG: forked new backend, pid=6846 socket=6 2010-05-13 21:01:00 WEST LOG: autovacuum: processing database "egbert" 2010-05-13 21:01:00 WEST DEBUG: autovac: will VACUUM ANALYZE timeslots 2010-05-13 21:01:00 WEST DEBUG: vacuuming "public.timeslots" 2010-05-13 21:02:39 WEST DEBUG: index "timeslots_timestamp_index" now contains 3971156 row versions in 15338 pages 2010-05-13 21:02:39 WEST DETAIL: 351 index row versions were removed. 0 index pages have been deleted, 0 are currently reusable. CPU 0.67s/1.28u sec elapsed 71.06 sec. 2010-05-13 21:03:51 WEST DEBUG: index "timeslots_timeslot_index" now contains 3971159 row versions in 18724 pages 2010-05-13 21:03:51 WEST DETAIL: 351 index row versions were removed. 0 index pages have been deleted, 0 are currently reusable. CPU 0.86s/1.31u sec elapsed 71.65 sec. 2010-05-13 21:04:35 WEST DEBUG: checkpoint starting 2010-05-13 21:04:37 WEST DEBUG: checkpoint complete; 0 transaction log file(s) added, 0 removed, 0 recycled 2010-05-13 21:04:58 WEST DEBUG: index "timeslots_var_index" now contains 3971167 row versions in 23857 pages 2010-05-13 21:04:58 WEST DETAIL: 351 index row versions were removed. 0 index pages have been deleted, 0 are currently reusable. CPU 1.34s/1.36u sec elapsed 67.49 sec. 2010-05-13 21:05:00 WEST DEBUG: server process (PID 6846) exited with exit code 0 2010-05-13 21:05:01 WEST DEBUG: forked new backend, pid=7319 socket=6 2010-05-13 21:09:35 WEST DEBUG: checkpoint starting 2010-05-13 21:09:37 WEST DEBUG: checkpoint complete; 0 transaction log file(s) added, 0 removed, 0 recycled 2010-05-13 21:10:08 WEST DEBUG: server process (PID 7319) exited with exit code 0 2010-05-13 21:10:08 WEST DEBUG: forked new backend, pid=7845 socket=6 2010-05-13 21:14:35 WEST DEBUG: checkpoint starting 2010-05-13 21:14:37 WEST DEBUG: checkpoint complete; 0 transaction log file(s) added, 0 removed, 0 recycled 2010-05-13 21:15:00 WEST DEBUG: server process (PID 7845) exited with exit code 0 2010-05-13 21:15:00 WEST DEBUG: forked new backend, pid=8214 socket=6 2010-05-13 21:19:35 WEST DEBUG: checkpoint starting 2010-05-13 21:19:41 WEST DEBUG: checkpoint complete; 0 transaction log file(s) added, 0 removed, 0 recycled 2010-05-13 21:20:00 WEST DEBUG: server process (PID 8214) exited with exit code 0 2010-05-13 21:20:00 WEST DEBUG: forked new backend, pid=8521 socket=6 2010-05-13 21:24:35 WEST DEBUG: checkpoint starting 2010-05-13 21:24:38 WEST DEBUG: checkpoint complete; 0 transaction log file(s) added, 0 removed, 0 recycled 2010-05-13 21:25:00 WEST DEBUG: server process (PID 8521) exited with exit code 0 2010-05-13 21:25:00 WEST DEBUG: forked new backend, pid=8919 socket=6 2010-05-13 21:29:37 WEST DEBUG: checkpoint starting 2010-05-13 21:29:40 WEST DEBUG: checkpoint complete; 0 transaction log file(s) added, 0 removed, 0 recycled 2010-05-13 21:30:00 WEST DEBUG: server process (PID 8919) exited with exit code 0 2010-05-13 21:30:00 WEST DEBUG: forked new backend, pid=9239 socket=6 2010-05-13 21:34:35 WEST DEBUG: checkpoint starting 2010-05-13 21:34:38 WEST DEBUG: checkpoint complete; 0 transaction log file(s) added, 0 removed, 0 recycled 2010-05-13 21:35:00 WEST DEBUG: server process (PID 9239) exited with exit code 0 2010-05-13 21:35:00 WEST DEBUG: forked new backend, pid=9672 socket=6 2010-05-13 21:39:35 WEST DEBUG: checkpoint starting 2010-05-13 21:39:36 WEST DEBUG: checkpoint complete; 0 transaction log file(s) added, 0 removed, 0 recycled 2010-05-13 21:40:00 WEST DEBUG: server process (PID 9672) exited with exit code 0 2010-05-13 21:40:00 WEST DEBUG: forked new backend, pid=9979 socket=6 2010-05-13 21:44:35 WEST DEBUG: checkpoint starting 2010-05-13 21:44:36 WEST DEBUG: checkpoint complete; 0 transaction log file(s) added, 0 removed, 0 recycled 2010-05-13 21:44:59 WEST ERROR: failed to re-find parent key in "timeslots_strs_var_ts_key" 2010-05-13 21:45:00 WEST DEBUG: server process (PID 9979) exited with exit code 0 2010-05-13 21:45:00 WEST DEBUG: forked new backend, pid=10340 socket=6 2010-05-13 21:46:00 WEST LOG: autovacuum: processing database "postgres" 2010-05-13 21:47:00 WEST LOG: autovacuum: processing database "template1" 2010-05-13 21:48:01 WEST LOG: autovacuum: processing database "egbert" 2010-05-13 21:48:01 WEST DEBUG: autovac: will VACUUM ANALYZE timeslots 2010-05-13 21:48:01 WEST DEBUG: vacuuming "public.timeslots" 2010-05-13 21:49:30 WEST DEBUG: index "timeslots_timestamp_index" now contains 3971435 row versions in 15340 pages 2010-05-13 21:49:30 WEST DETAIL: 405 index row versions were removed. 0 index pages have been deleted, 0 are currently reusable. CPU 0.78s/1.23u sec elapsed 63.81 sec. 2010-05-13 21:49:35 WEST DEBUG: checkpoint starting 2010-05-13 21:49:37 WEST DEBUG: removing file "pg_subtrans/00AE" 2010-05-13 21:49:37 WEST DEBUG: checkpoint complete; 0 transaction log file(s) added, 0 removed, 0 recycled 2010-05-13 21:50:00 WEST DEBUG: server process (PID 10340) exited with exit code 0 2010-05-13 21:50:01 WEST DEBUG: forked new backend, pid=10642 socket=6 2010-05-13 21:50:47 WEST DEBUG: index "timeslots_timeslot_index" now contains 3971451 row versions in 18726 pages 2010-05-13 21:50:47 WEST DETAIL: 405 index row versions were removed. 0 index pages have been deleted, 0 are currently reusable. CPU 0.88s/1.32u sec elapsed 76.99 sec. 2010-05-13 21:51:56 WEST DEBUG: index "timeslots_var_index" now contains 3971471 row versions in 23861 pages 2010-05-13 21:51:56 WEST DETAIL: 405 index row versions were removed. 0 index pages have been deleted, 0 are currently reusable. CPU 1.10s/1.40u sec elapsed 69.38 sec. 2010-05-13 21:54:35 WEST DEBUG: checkpoint starting 2010-05-13 21:54:36 WEST DEBUG: checkpoint complete; 0 transaction log file(s) added, 0 removed, 0 recycled 2010-05-13 21:55:00 WEST DEBUG: server process (PID 10642) exited with exit code 0 2010-05-13 21:55:00 WEST DEBUG: forked new backend, pid=11061 socket=6 2010-05-13 21:59:35 WEST DEBUG: checkpoint starting 2010-05-13 21:59:37 WEST DEBUG: checkpoint complete; 0 transaction log file(s) added, 0 removed, 0 recycled 2010-05-13 22:00:00 WEST DEBUG: server process (PID 11061) exited with exit code 0 2010-05-13 22:00:01 WEST DEBUG: forked new backend, pid=11398 socket=6 2010-05-13 22:04:35 WEST DEBUG: checkpoint starting 2010-05-13 22:04:36 WEST DEBUG: checkpoint complete; 0 transaction log file(s) added, 0 removed, 0 recycled 2010-05-13 22:05:00 WEST DEBUG: forked new backend, pid=11725 socket=6 2010-05-13 22:05:00 WEST DEBUG: server process (PID 11398) exited with exit code 0 2010-05-13 22:09:35 WEST DEBUG: checkpoint starting 2010-05-13 22:09:39 WEST DEBUG: checkpoint complete; 0 transaction log file(s) added, 0 removed, 0 recycled 2010-05-13 22:10:00 WEST DEBUG: server process (PID 11725) exited with exit code 0 2010-05-13 22:10:00 WEST DEBUG: forked new backend, pid=12073 socket=6 2010-05-13 22:14:35 WEST DEBUG: checkpoint starting 2010-05-13 22:14:39 WEST DEBUG: checkpoint complete; 0 transaction log file(s) added, 0 removed, 0 recycled 2010-05-13 22:15:00 WEST DEBUG: forked new backend, pid=12328 socket=6 2010-05-13 22:15:00 WEST DEBUG: server process (PID 12073) exited with exit code 0 2010-05-13 22:19:35 WEST DEBUG: checkpoint starting 2010-05-13 22:19:38 WEST DEBUG: checkpoint complete; 0 transaction log file(s) added, 0 removed, 0 recycled 2010-05-13 22:20:00 WEST DEBUG: server process (PID 12328) exited with exit code 0 2010-05-13 22:20:00 WEST DEBUG: forked new backend, pid=12601 socket=6 2010-05-13 22:24:35 WEST DEBUG: checkpoint starting 2010-05-13 22:24:37 WEST DEBUG: checkpoint complete; 0 transaction log file(s) added, 0 removed, 0 recycled 2010-05-13 22:25:02 WEST DEBUG: server process (PID 12601) exited with exit code 0 2010-05-13 22:25:02 WEST DEBUG: forked new backend, pid=12864 socket=6 2010-05-13 22:29:35 WEST DEBUG: checkpoint starting 2010-05-13 22:29:36 WEST DEBUG: checkpoint complete; 0 transaction log file(s) added, 0 removed, 0 recycled 2010-05-13 22:30:00 WEST DEBUG: server process (PID 12864) exited with exit code 0 2010-05-13 22:30:00 WEST DEBUG: forked new backend, pid=13109 socket=6 2010-05-13 22:31:29 WEST ERROR: failed to re-find parent key in "timeslots_strs_var_ts_key" 2010-05-13 22:32:29 WEST LOG: autovacuum: processing database "postgres" 2010-05-13 22:33:29 WEST LOG: autovacuum: processing database "template1" 2010-05-13 22:34:29 WEST LOG: autovacuum: processing database "egbert" 2010-05-13 22:34:29 WEST DEBUG: autovac: will VACUUM ANALYZE timeslots 2010-05-13 22:34:29 WEST DEBUG: vacuuming "public.timeslots" 2010-05-13 22:34:35 WEST DEBUG: checkpoint starting 2010-05-13 22:34:36 WEST DEBUG: checkpoint complete; 0 transaction log file(s) added, 0 removed, 0 recycled 2010-05-13 22:35:00 WEST DEBUG: server process (PID 13109) exited with exit code 0 2010-05-13 22:35:00 WEST DEBUG: forked new backend, pid=13329 socket=6 2010-05-13 22:36:06 WEST DEBUG: index "timeslots_timestamp_index" now contains 3971652 row versions in 15341 pages 2010-05-13 22:36:06 WEST DETAIL: 321 index row versions were removed. 0 index pages have been deleted, 0 are currently reusable. CPU 0.81s/1.24u sec elapsed 72.89 sec. 2010-05-13 22:37:16 WEST DEBUG: index "timeslots_timeslot_index" now contains 3971652 row versions in 18727 pages 2010-05-13 22:37:16 WEST DETAIL: 321 index row versions were removed. 0 index pages have been deleted, 0 are currently reusable. CPU 0.97s/1.35u sec elapsed 69.51 sec. 2010-05-13 22:38:27 WEST DEBUG: index "timeslots_var_index" now contains 3971656 row versions in 23861 pages 2010-05-13 22:38:27 WEST DETAIL: 321 index row versions were removed. 0 index pages have been deleted, 0 are currently reusable. CPU 1.39s/1.43u sec elapsed 70.76 sec. 2010-05-13 22:39:35 WEST DEBUG: checkpoint starting 2010-05-13 22:39:38 WEST DEBUG: checkpoint complete; 0 transaction log file(s) added, 0 removed, 0 recycled 2010-05-13 22:40:00 WEST DEBUG: server process (PID 13329) exited with exit code 0 2010-05-13 22:40:00 WEST DEBUG: forked new backend, pid=13549 socket=6 2010-05-13 22:44:36 WEST DEBUG: checkpoint starting 2010-05-13 22:44:45 WEST DEBUG: checkpoint complete; 0 transaction log file(s) added, 0 removed, 0 recycled 2010-05-13 22:45:00 WEST DEBUG: server process (PID 13549) exited with exit code 0 2010-05-13 22:45:00 WEST DEBUG: forked new backend, pid=13918 socket=6 2010-05-13 22:49:35 WEST DEBUG: checkpoint starting 2010-05-13 22:49:38 WEST DEBUG: checkpoint complete; 0 transaction log file(s) added, 0 removed, 0 recycled 2010-05-13 22:50:01 WEST DEBUG: server process (PID 13918) exited with exit code 0 2010-05-13 22:50:01 WEST DEBUG: forked new backend, pid=14218 socket=6 2010-05-13 22:50:22 WEST DEBUG: forked new backend, pid=14278 socket=6 2010-05-13 22:51:11 WEST DEBUG: server process (PID 14278) exited with exit code 0 2010-05-13 22:51:20 WEST DEBUG: forked new backend, pid=14368 socket=6 2010-05-13 22:51:22 WEST DEBUG: server process (PID 14368) exited with exit code 0 2010-05-13 22:52:52 WEST DEBUG: forked new backend, pid=14516 socket=6 2010-05-13 22:52:52 WEST DEBUG: server process (PID 14516) exited with exit code 0 2010-05-13 22:54:35 WEST DEBUG: checkpoint starting 2010-05-13 22:54:37 WEST DEBUG: checkpoint complete; 0 transaction log file(s) added, 0 removed, 0 recycled 2010-05-13 22:55:00 WEST DEBUG: server process (PID 14218) exited with exit code 0 2010-05-13 22:55:00 WEST DEBUG: forked new backend, pid=14775 socket=6 2010-05-13 22:59:35 WEST DEBUG: checkpoint starting 2010-05-13 22:59:40 WEST DEBUG: checkpoint complete; 0 transaction log file(s) added, 0 removed, 0 recycled 2010-05-13 23:00:01 WEST DEBUG: server process (PID 14775) exited with exit code 0 2010-05-13 23:00:01 WEST DEBUG: forked new backend, pid=15443 socket=6 2010-05-13 23:04:35 WEST DEBUG: checkpoint starting 2010-05-13 23:04:43 WEST DEBUG: checkpoint complete; 0 transaction log file(s) added, 0 removed, 0 recycled 2010-05-13 23:05:00 WEST DEBUG: forked new backend, pid=16028 socket=6 2010-05-13 23:05:00 WEST DEBUG: server process (PID 15443) exited with exit code 0 -- Sent via pgsql-general mailing list (pgsql-general@xxxxxxxxxxxxxx) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-general
