Thread: Poor delete performance AFTER vacuum analyze
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
Hello,
I have an application I wrote that uses two tables heavily. The first table
is a queue table, the second table is an archive table. The queue table is
constantly taking on new records at the rate of 10/second. My software pulls
the logs from the queue table, processes them, moves them to the archive
table, and then deletes the processed entries from the queue table.
Symptoms:
My system will run great after a full vacuum(as I would expect). It will run
all day long taking only 3-5 seconds to run and deal with approximately
100megs of new data each day. However, the instant the system finishes only
a 'vacuum analyze', the whole thing slows WAY down to where each run can take
10-15 minutes.
ie. After a full analyze vacuum, my software will load, process, move, and
delete in under 3-4 seconds. After a analyze vacuum(notice: not full), it
can load, process and move data in 3-5 seconds but the delete takes 10-15
minutes! I submit the delete as one transaction to clear out the records
processed. Trunactae won't work because other records are coming in while I
process data. Mind you the archive table is 15 million records while the
temporary table is maybe 10-20,000 records.
Now I just rewrote a portion of my application to change its behavior. What
it did before was that it would pile through a 10 gig archive table,
processed logs, etc... in about 3 minutes but I did not delete in the same
way because everything is already in one table. My software has to run every
five minutes so the three minute runtime is getting close for process
overlap(yuck).
Recap
The old system didn't delete records but plowed through the 10 gig db and
takes 3 1/2 minutes to do its job. The new system flies through the smaller
queue table(100-200k) but it dies after conducting a non-full vacuum.
Is the planner just that much better at analyzing a full then an regular
analyze or is there something else I'm missing?
The Box:
The DB is a dual P4 2.4ghz Xeon w/ 1.5 gig of RAM. IBM 335 w/ 36gig mirrored.
kernel.shmmax = 1342177280
shared_buffers = 115200 # 2*max_connections, min 16
sort_mem = 65536 # min 32
vacuum_mem = 196608 # min 1024
fsync = false
- --
Jeremy M. Guthrie
Systems Engineer
Berbee
5520 Research Park Dr.
Madison, WI 53711
Phone: 608-298-1061
Berbee...Decade 1. 1993-2003
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.2.1 (GNU/Linux)
iD8DBQE/GbajqtjaBHGZBeURAkKiAJ9zaqQISD47XycRcSgDKbNeuqqaKQCfcgim
yCdaycBg4+99Epd7EuAAxsE=
=9xlS
-----END PGP SIGNATURE-----
"Jeremy M. Guthrie" <jeremy.guthrie@berbee.com> writes:
> My system will run great after a full vacuum(as I would expect). It will run
> all day long taking only 3-5 seconds to run and deal with approximately
> 100megs of new data each day. However, the instant the system finishes only
> a 'vacuum analyze', the whole thing slows WAY down to where each run can take
> 10-15 minutes.
Could we see EXPLAIN ANALYZE for the deletion query in both the fast and
slow states?
regards, tom lane
On Sat, 19 Jul 2003, Jeremy M. Guthrie wrote: > 100megs of new data each day. However, the instant the system finishes only > a 'vacuum analyze', the whole thing slows WAY down to where each run can take > 10-15 minutes. Have you run EXPLAIN ANALYZE on the delete query before and after the vacuum? Does it explain why it goes slower? -- /Dennis
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
I looked back at my code and I also need to reclarify something. The delete
at the end is multiple delete statements within a transaction.
After full vacuum with 160,000 records in Table: (takes a bit the first time
through)
Tlog=# explain analyze delete from Tlog where Tlog_ID <= 47766002 and
host='tbp-pp';
QUERY PLAN
-
-----------------------------------------------------------------------------------------------------------------------------
Index Scan using shost_idx on tlog (cost=0.00..6281.45 rows=136 width=6)
(actual time=64529.43..64529.43 rows=0 loops=1)
Index Cond: (host = 'tbp-pp'::character varying)
Filter: (tlog_id <= 47766002)
Total runtime: 64529.52 msec
After zero records in table: (
Tlog=# explain analyze delete from Tlog where Tlog_ID <= 47766002 and
host='tbp-pp';
QUERY PLAN
-
-----------------------------------------------------------------------------------------------------------------------
Index Scan using shost_idx on tlog (cost=0.00..6281.45 rows=136 width=6)
(actual time=84.87..84.87 rows=0 loops=1)
Index Cond: (host = 'tbp-pp'::character varying)
Filter: (tlog_id <= 47766002)
Total runtime: 84.96 msec
Slow Explain after vacuum analyze: (this is when it gets bad)
TLog=# explain analyze delete from Tlog where Tlog_ID <= 47766002 and
shost='tbp-pp';
QUERY PLAN
-
------------------------------------------------------------------------------------------------------------------------------
Index Scan using shost_idx on tlog (cost=0.00..6128.52 rows=82 width=6)
(actual time=262178.82..262178.82 rows=0 loops=1)
Index Cond: (host = 'tbp-pp'::character varying)
Filter: (tlog_id <= 47766002)
Total runtime: 262178.96 msec
- --
Jeremy M. Guthrie
Systems Engineer
Berbee
5520 Research Park Dr.
Madison, WI 53711
Phone: 608-298-1061
Berbee...Decade 1. 1993-2003
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.2.1 (GNU/Linux)
iD8DBQE/GysLqtjaBHGZBeURAhNTAJ0QA2/eZM/DhSyxmXi89i6kXFQFwgCfacZY
UIMUdK95O3N0UpOTxedM6Pw=
=laUO
-----END PGP SIGNATURE-----
"Jeremy M. Guthrie" <jeremy.guthrie@berbee.com> writes:
> I looked back at my code and I also need to reclarify something. The delete
> at the end is multiple delete statements within a transaction.
I think you are going to have to show us all the details of what you're
doing in between these queries. I was expecting to see a difference in
query plans, but you've got the exact same plan in all three runs ---
so it's not the planner making the difference here, nor the ANALYZE
statistics. My best conjecture now is something odd about the way you
are deleting the old data or loading the new.
regards, tom lane