Thread: Message queue table - strange performance drop with changing limit size.
Hi. I have a "message queue" table, that contains in the order of 1-10m "messages". It is implemented using TheSchwartz: http://search.cpan.org/~bradfitz/TheSchwartz-1.07/lib/TheSchwartz.pm So when a "worker" picks the next job it goes into the "job" table an select the top X highest priority messages with the "funcid" that it can work on. The table looks like this: db=# \d workqueue.job Table "workqueue.job" Column | Type | Modifiers ---------------+----------+--------------------------------------------------------------- jobid | integer | not null default nextval('workqueue.job_jobid_seq'::regclass) funcid | integer | not null arg | bytea | uniqkey | text | insert_time | integer | run_after | integer | not null grabbed_until | integer | not null priority | smallint | coalesce | text | Indexes: "job_funcid_key" UNIQUE, btree (funcid, uniqkey) "funcid_coalesce_priority" btree (funcid, "coalesce", priority) "funcid_prority_idx2" btree (funcid, priority) "job_jobid_idx" btree (jobid) efam=# explain ANALYZe select jobid from workqueue.job where job.funcid in (3) order by priority asc limit 1000; QUERY PLAN ------------------------------------------------------------------------------------------------------------------------------------------------ Limit (cost=0.00..2008.53 rows=1000 width=6) (actual time=0.077..765.169 rows=1000 loops=1) -> Index Scan using funcid_prority_idx2 on job (cost=0.00..7959150.95 rows=3962674 width=6) (actual time=0.074..763.664 rows=1000 loops=1) Index Cond: (funcid = 3) Total runtime: 766.104 ms (4 rows) efam=# explain ANALYZe select jobid from workqueue.job where job.funcid in (3) order by priority asc limit 50; QUERY PLAN ---------------------------------------------------------------------------------------------------------------------------------------------- Limit (cost=0.00..100.43 rows=50 width=6) (actual time=0.037..505.765 rows=50 loops=1) -> Index Scan using funcid_prority_idx2 on job (cost=0.00..7959150.95 rows=3962674 width=6) (actual time=0.035..505.690 rows=50 loops=1) Index Cond: (funcid = 3) Total runtime: 505.959 ms (4 rows) efam=# explain ANALYZe select jobid from workqueue.job where job.funcid in (3) order by priority asc limit 10; QUERY PLAN -------------------------------------------------------------------------------------------------------------------------------------------- Limit (cost=0.00..20.09 rows=10 width=6) (actual time=0.056..0.653 rows=10 loops=1) -> Index Scan using funcid_prority_idx2 on job (cost=0.00..7959152.95 rows=3962674 width=6) (actual time=0.054..0.640 rows=10 loops=1) Index Cond: (funcid = 3) Total runtime: 0.687 ms (4 rows) So what I see is that "top 10" takes < 1ms, top 50 takes over 500 times more, and top 1000 only 1.5 times more than top 50. What can the reason be for the huge drop between limit 10 and limit 50 be? -- Jesper
Re: Message queue table - strange performance drop with changing limit size.
From
Greg Williamson
Date:
Jesper -- I apologize for top-quoting -- a challenged reader. This doesn't directly address your question, but I can't help but notice that the estimates for rows is _wildly_ off theactual number in each and every query. How often / recently have you run ANALYZE on this table ? Are the timing results consistent over several runs ? It is possible that caching effects are entering into the time results. Greg Williamson ----- Original Message ---- From: Jesper Krogh <jesper@krogh.cc> To: pgsql-performance@postgresql.org Sent: Fri, January 1, 2010 3:48:43 AM Subject: [PERFORM] Message queue table - strange performance drop with changing limit size. Hi. I have a "message queue" table, that contains in the order of 1-10m "messages". It is implemented using TheSchwartz: http://search.cpan.org/~bradfitz/TheSchwartz-1.07/lib/TheSchwartz.pm So when a "worker" picks the next job it goes into the "job" table an select the top X highest priority messages with the "funcid" that it can work on. The table looks like this: db=# \d workqueue.job Table "workqueue.job" Column | Type | Modifiers ---------------+----------+--------------------------------------------------------------- jobid | integer | not null default nextval('workqueue.job_jobid_seq'::regclass) funcid | integer | not null arg | bytea | uniqkey | text | insert_time | integer | run_after | integer | not null grabbed_until | integer | not null priority | smallint | coalesce | text | Indexes: "job_funcid_key" UNIQUE, btree (funcid, uniqkey) "funcid_coalesce_priority" btree (funcid, "coalesce", priority) "funcid_prority_idx2" btree (funcid, priority) "job_jobid_idx" btree (jobid) efam=# explain ANALYZe select jobid from workqueue.job where job.funcid in (3) order by priority asc limit 1000; QUERY PLAN ------------------------------------------------------------------------------------------------------------------------------------------------ Limit (cost=0.00..2008.53 rows=1000 width=6) (actual time=0.077..765.169 rows=1000 loops=1) -> Index Scan using funcid_prority_idx2 on job (cost=0.00..7959150.95 rows=3962674 width=6) (actual time=0.074..763.664 rows=1000 loops=1) Index Cond: (funcid = 3) Total runtime: 766.104 ms (4 rows) efam=# explain ANALYZe select jobid from workqueue.job where job.funcid in (3) order by priority asc limit 50; QUERY PLAN ---------------------------------------------------------------------------------------------------------------------------------------------- Limit (cost=0.00..100.43 rows=50 width=6) (actual time=0.037..505.765 rows=50 loops=1) -> Index Scan using funcid_prority_idx2 on job (cost=0.00..7959150.95 rows=3962674 width=6) (actual time=0.035..505.690 rows=50 loops=1) Index Cond: (funcid = 3) Total runtime: 505.959 ms (4 rows) efam=# explain ANALYZe select jobid from workqueue.job where job.funcid in (3) order by priority asc limit 10; QUERY PLAN -------------------------------------------------------------------------------------------------------------------------------------------- Limit (cost=0.00..20.09 rows=10 width=6) (actual time=0.056..0.653 rows=10 loops=1) -> Index Scan using funcid_prority_idx2 on job (cost=0.00..7959152.95 rows=3962674 width=6) (actual time=0.054..0.640 rows=10 loops=1) Index Cond: (funcid = 3) Total runtime: 0.687 ms (4 rows) So what I see is that "top 10" takes < 1ms, top 50 takes over 500 times more, and top 1000 only 1.5 times more than top 50. What can the reason be for the huge drop between limit 10 and limit 50 be? -- Jesper -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
Re: Message queue table - strange performance drop with changing limit size.
From
Jesper Krogh
Date:
Greg Williamson wrote: > Jesper -- > > I apologize for top-quoting -- a challenged reader. > > This doesn't directly address your question, but I can't help but > notice that the estimates for rows is _wildly_ off the actual number > in each and every query. How often / recently have you run ANALYZE on > this table ? It is actually rather accurate, what you see in the explain analyze is the "limit" number getting in.. where the inner "rows" estiemate is for the where clause+filter. > Are the timing results consistent over several runs ? It is possible > that caching effects are entering into the time results. Yes, they are very consistent. It have subsequently found out that it depends on the amount of "workers" doing it in parallel. I seem to top at around 12 processes. I think I need to rewrite the message-queue stuff in a way that can take advantage of some stored procedures instead. Currenly it picks out the "top X" randomize it in the client picks one and tries to "grab" it. .. and over again if it fails. When the select top X begins to consume signifcant time it self the process bites itself and gradually gets worse. The workload for the individual jobs are "small". ~1-2s. -- Jesper
Re: Message queue table - strange performance drop with changing limit size.
From
Dimitri Fontaine
Date:
Jesper Krogh <jesper@krogh.cc> writes: > I have a "message queue" table, that contains in the order of 1-10m > "messages". It is implemented using TheSchwartz: > http://search.cpan.org/~bradfitz/TheSchwartz-1.07/lib/TheSchwartz.pm One way to approach queueing efficiently with PostgreSQL is to rely on PGQ. New upcoming 3.0 version (alpha1 has been released) contains the basics for having cooperative consumers, stable version (2.1.10) only allows multiple consumers to all do the same work (think replication). http://wiki.postgresql.org/wiki/Skytools http://wiki.postgresql.org/wiki/PGQ_Tutorial Regards, -- dim
Jesper Krogh wrote: > So what I see is that "top 10" takes < 1ms, top 50 takes over 500 times > more, and top 1000 only 1.5 times more than top 50. > What can the reason be for the huge drop between limit 10 and limit 50 be? > Normally this means you're hitting much higher performing cached behavior with the smaller amount that's degrading significantly once you've crossed some threshold. L1 and L2 CPUs caches vs. regular RAM, shared_buffers vs. OS cache changes, and cached in RAM vs. read from disk are three transition spots where you can hit a large drop in performance just by crossing some boundary, going from "just fits" to "doesn't fit and data thrashes around". Larger data sets do not take a linearly larger amount of time to run queries against--they sure can degrade order of magnitude faster than that. > Indexes: > "job_funcid_key" UNIQUE, btree (funcid, uniqkey) > "funcid_coalesce_priority" btree (funcid, "coalesce", priority) > "funcid_prority_idx2" btree (funcid, priority) > "job_jobid_idx" btree (jobid) > There may very well be an underlying design issue here though. Indexes are far from free to maintain. You've got a fair number of them with a lot of redundant information, which is adding a significant amount of overhead for questionable gains. If you added those just from the theory of "those are the fields combinations I search via", you really need to benchmarking that design decision--it's rarely that easy to figure out what works best. For example, if on average there are a small number of things attached to each funcid, the middle two indexes here are questionable--it may be more efficient to the system as a whole to just grab them all rather than pay the overhead to maintain all these indexes. This is particularly true if you're deleting or updating entries ito remove them from this queue, which is going to add a lot of VACUUM-related cleanup here as well. In your situation, I might try dropping both funcid_coalesce_priority and then funcid_prority_idx2 and watching what happens to your performance and plans, just to learn more about whether they're really needed. A look at the various pg_stat_* view to help determine what physical I/O and index use is actually going on might be useful too. -- Greg Smith 2ndQuadrant Baltimore, MD PostgreSQL Training, Services and Support greg@2ndQuadrant.com www.2ndQuadrant.com