Re: [PERFORM] UPDATEDs slowing SELECTs in a fully cached database
On 08/07/2011 01:56, lars wrote: Setup: PostgreSQL 9.1beta2 on a high memory (~68gb, 12 cores) EC2 Linux instance (kernel 2.6.35) with the database and WAL residing on the same EBS volume with EXT4 (data=ordered, barriers=1) - yes that is not an ideal setup (WAL should be on separate drive, EBS is slow to begin, etc), but I am mostly interested in read performance for a fully cached database. I know you said you know these things - but do you really know the (huge) extent to which all your IO is slowed? Even context switches in a virtualized environment are slowed down by a huge margin - which would make practically all in-memory lock operations very slow - much slower than they would be on real hardware, and EBS by definition is even slower then regular private virtual storage environments. I regrettably didn't bookmark the page which did exact measurements of EBS, but http://www.google.com/search?q=how+slow+is+ec2 will illustrate my point. (of course, you may already know all this :) ). -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] UPDATEDs slowing SELECTs in a fully cached database
On Tue, Jul 12, 2011 at 8:22 AM, Ivan Voras ivo...@freebsd.org wrote: On 08/07/2011 01:56, lars wrote: Setup: PostgreSQL 9.1beta2 on a high memory (~68gb, 12 cores) EC2 Linux instance (kernel 2.6.35) with the database and WAL residing on the same EBS volume with EXT4 (data=ordered, barriers=1) - yes that is not an ideal setup (WAL should be on separate drive, EBS is slow to begin, etc), but I am mostly interested in read performance for a fully cached database. I know you said you know these things - but do you really know the (huge) extent to which all your IO is slowed? Even context switches in a virtualized environment are slowed down by a huge margin - which would make practically all in-memory lock operations very slow - much slower than they would be on real hardware, and EBS by definition is even slower then regular private virtual storage environments. I regrettably didn't bookmark the page which did exact measurements of EBS, but http://www.google.com/search?q=how+slow+is+ec2 will illustrate my point. (of course, you may already know all this :) ). sure, but the OP's question is valid: in postgres, readers don't block writers, so why is the reader waiting? I'd like to know definitively: *) is the reader bottlenecked on disk i/o (it seems yes) *) is that disk i/o heap or wal (it seems wal) *) is that disk i/o reading/writing (it seems writing) *) given the above, why is this happening (presumably disk page tidying)? We need some more information here. I'd like to see the table information -- at least the average width of the record both pre/post update, if it is or is not toasted, and the number of size and indexes pre/post update. I'm really suspicious of the virtualization tech as well -- is it possible to run this test on at least semi decent native hardware? merlin -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] UPDATEDs slowing SELECTs in a fully cached database
On 12/07/2011 16:18, Merlin Moncure wrote: On Tue, Jul 12, 2011 at 8:22 AM, Ivan Vorasivo...@freebsd.org wrote: On 08/07/2011 01:56, lars wrote: Setup: PostgreSQL 9.1beta2 on a high memory (~68gb, 12 cores) EC2 Linux instance (kernel 2.6.35) with the database and WAL residing on the same EBS volume with EXT4 (data=ordered, barriers=1) - yes that is not an ideal setup (WAL should be on separate drive, EBS is slow to begin, etc), but I am mostly interested in read performance for a fully cached database. I know you said you know these things - but do you really know the (huge) extent to which all your IO is slowed? Even context switches in a virtualized environment are slowed down by a huge margin - which would make practically all in-memory lock operations very slow - much slower than they would be on real hardware, and EBS by definition is even slower then regular private virtual storage environments. I regrettably didn't bookmark the page which did exact measurements of EBS, but http://www.google.com/search?q=how+slow+is+ec2 will illustrate my point. (of course, you may already know all this :) ). sure, but the OP's question is valid: in postgres, readers don't block writers, so why is the reader waiting? Yes, but I'm suggesting a different question: are we sure we are not seeing the influences of the environment (EC2+EBS) instead of the software system? We need some more information here. Definitely. -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] UPDATEDs slowing SELECTs in a fully cached database
On 12/07/2011 02:09, lars wrote: Oh, and iowait hovers around 20% when SELECTs are slow: avg-cpu: %user %nice %system %iowait %steal %idle 1.54 0.00 0.98 18.49 0.07 78.92 When SELECTs are fast it looks like this: avg-cpu: %user %nice %system %iowait %steal %idle 8.72 0.00 0.26 0.00 0.00 91.01 Note that this is a 12 core VM. So one core at 100% would show as 8.33% CPU. Now only if you could do an iostat -x and show the output in both cases... -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] Memory usage of auto-vacuum
Hello, Here is an update on my problem : - the problem was caused by VACUUM ANALYZE, but by a plain VACUUM ; - it was exactly the same with manual and automatic VACUUM ANALYZE ; - it was caused by a GIN index on a tsvector, using a very high (1) statistics target. Setting back the statistics to 1000 reduced the amount of RAM used to a very reasonable amount. The value of 1 is indeed not very realistic, but I think that would deserve some mention on the documentation, if possible with an estimate of the maximal memory usage for a given statistics target and table size. Do you think it's a good idea, and if so, if that estimate can be reasonably made ? Regards, -- Gaël Le Mignot - g...@pilotsystems.net Pilot Systems - 9, rue Desargues - 75011 Paris Tel : +33 1 44 53 05 55 - www.pilotsystems.net Gérez vos contacts et vos newsletters : www.cockpit-mailing.com -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] UPDATEDs slowing SELECTs in a fully cached database
On Tue, Jul 12, 2011 at 9:36 AM, Kevin Grittner kevin.gritt...@wicourts.gov wrote: lars lhofha...@yahoo.com wrote: I am not trying to optimize this particular use case, but rather to understand what Postgres is doing, and why SELECT queries are affected negatively (sometimes severely) by concurrent (or even preceding) UPDATEs at all when the database resides in the cache completely. I think we're stuck in terms of trying to guess what is causing the behavior you are seeing. Things which would help get it unstuck: (1) More information about your load process. Looking at the code, I could sort of see a possible path to this behavior if the load process involves any adjustments beyond straight INSERTs or COPYs in. (2) You could poke around with a profiler, a debugger, and/or the contrib/pageinspect module to sort things out. hm, also strace on the 'select' process might give some clues. merlin -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
[PERFORM] Planner choosing NestedLoop, although it is slower...
Hi, all. I have a query, looking like this: SELECT pub_date FROM tubesite_object INNER JOIN tubesite_image ON tubesite_image.object_ptr_id = tubesite_object.id WHERE tubesite_object.site_id = 8 AND tubesite_object.pub_date E'2011-07-12 13:25:00' ORDER BY tubesite_object.pub_date ASC LIMIT 21; That query takes cca 10-15 seconds to run. Here is query plan: Limit (cost=0.00..415.91 rows=21 width=8) (actual time=11263.089..11263.089 rows=0 loops=1) - Nested Loop (cost=0.00..186249.55 rows=9404 width=8) (actual time=11263.087..11263.087 rows=0 loops=1) - Index Scan using tubesite_object_pub_date_idx on tubesite_object (cost=0.00..183007.09 rows=9404 width=12) (actual time=0.024..11059.487 rows=9374 loops=1) Index Cond: (pub_date '2011-07-12 13:25:00-05'::timestamp with time zone) Filter: (site_id = 8) - Index Scan using tubesite_image_pkey on tubesite_image (cost=0.00..0.33 rows=1 width=4) (actual time=0.021..0.021 rows=0 loops=9374) Index Cond: (tubesite_image.object_ptr_id = tubesite_object.id) Total runtime: 11263.141 ms This query runs quickly (around second or two) when there is only few connections to the database. Once I have 50-80 connections (200 is the limit, although I never have more than 120-150 connections), that query takes around 10-15 seconds. But, if I disable nestedloops, here is the query plan: Limit (cost=22683.45..22683.51 rows=21 width=8) (actual time=136.009..136.009 rows=0 loops=1) - Sort (cost=22683.45..22706.96 rows=9404 width=8) (actual time=136.007..136.007 rows=0 loops=1) Sort Key: tubesite_object.pub_date Sort Method: quicksort Memory: 25kB - Hash Join (cost=946.51..22429.91 rows=9404 width=8) (actual time=135.934..135.934 rows=0 loops=1) Hash Cond: (tubesite_object.id = tubesite_image.object_ptr_id) - Bitmap Heap Scan on tubesite_object (cost=545.40..21828.97 rows=9404 width=12) (actual time=20.874..104.075 rows=9374 loops=1) Recheck Cond: (site_id = 8) Filter: (pub_date '2011-07-12 13:25:00-05'::timestamp with time zone) - Bitmap Index Scan on tubesite_object_site_id (cost=0.00..543.05 rows=9404 width=0) (actual time=18.789..18.789 rows=9374 loops=1) Index Cond: (site_id = 8) - Hash (cost=215.49..215.49 rows=14849 width=4) (actual time=21.068..21.068 rows=14849 loops=1) - Seq Scan on tubesite_image (cost=0.00..215.49 rows=14849 width=4) (actual time=0.029..9.073 rows=14849 loops=1) Total runtime: 136.287 ms Now, if I disable nested loops in postgres.conf, then my load average on the server goes skyhigh (i presume because a lot of other queries are now being planned incorrectly). I have set up default_statistics_target to 2000, and have vacumed and analyzed the database. Here are the other options I have set up in postgresql.conf (that differ from the default settings): version | PostgreSQL 8.4.8 on x86_64-pc-linux-gnu, compiled by GCC gcc-4.3.real (Debian 4.3.2-1.1) 4.3.2, 64-bit checkpoint_segments | 64 default_statistics_target | 2000 effective_cache_size| 20GB external_pid_file | /var/run/postgresql/8.4-main.pid lc_collate | en_US.UTF-8 lc_ctype| en_US.UTF-8 listen_addresses| * log_autovacuum_min_duration | 0 log_checkpoints | on log_line_prefix | %t [%p]: [%l-1] log_min_duration_statement | 1s maintenance_work_mem| 256MB max_connections | 200 max_stack_depth | 3MB port| 5432 server_encoding | UTF8 shared_buffers | 2GB statement_timeout | 30min temp_buffers| 4096 TimeZone| localtime track_activity_query_size | 2048 unix_socket_directory | /var/run/postgresql wal_buffers | 128MB work_mem| 64MB Why is planner using NestedLoops, that is, what can I do to make him NOT to use NestedLoops (other than issuing SET enable_nestloop TO false; before each query) ? Mario -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] UPDATEDs slowing SELECTs in a fully cached database
On 07/12/2011 08:13 AM, Ivan Voras wrote: On 12/07/2011 02:09, lars wrote: Oh, and iowait hovers around 20% when SELECTs are slow: avg-cpu: %user %nice %system %iowait %steal %idle 1.54 0.00 0.98 18.49 0.07 78.92 When SELECTs are fast it looks like this: avg-cpu: %user %nice %system %iowait %steal %idle 8.72 0.00 0.26 0.00 0.00 91.01 Note that this is a 12 core VM. So one core at 100% would show as 8.33% CPU. Now only if you could do an iostat -x and show the output in both cases... Sure (sorry for missing details): iostat -x during selects when all's fine: avg-cpu: %user %nice %system %iowait %steal %idle 8.250.000.000.000.00 91.75 Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz avgqu-sz await svctm %util xvdap10.00 1.000.002.00 0.0024.00 12.00 0.000.00 0.00 0.00 xvdf 0.00 0.000.000.00 0.00 0.00 0.00 0.000.00 0.00 0.00 xvdg 0.00 0.000.000.00 0.00 0.00 0.00 0.000.00 0.00 0.00 xvdap1 is OS volumn. xvdf holds the database files xvdg holds the WAL No IO on database/WAL volumes, one core is pegged close to 100% CPU. iostat -x during update: avg-cpu: %user %nice %system %iowait %steal %idle 1.050.000.584.000.00 94.37 Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz avgqu-sz await svctm %util xvdap10.00 0.000.000.00 0.00 0.00 0.00 0.000.00 0.00 0.00 xvdf 0.00 0.007.000.00 128.00 0.00 18.29 0.000.00 0.00 0.00 xvdg 0.00 7352.000.00 804.00 0.00 62368.00 77.5766.07 68.83 0.86 69.20 Just updating the WAL. --- and while it's checkpointing: avg-cpu: %user %nice %system %iowait %steal %idle 0.640.000.328.880.00 90.16 Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz avgqu-sz await svctm %util xvdap10.00 0.000.000.00 0.00 0.00 0.00 0.000.00 0.00 0.00 xvdf 0.00 2548.002.00 1658.0032.00 33408.00 20.14 144.18 86.69 0.60 100.00 xvdg 0.00 5428.000.00 778.00 0.00 58480.00 75.1777.44 100.22 1.21 94.00 Updating the WAL, and database volume due to checkpointing. -- iostat -x after I stopped the update process and checkpointing is done: avg-cpu: %user %nice %system %iowait %steal %idle 0.000.000.000.000.00 100.00 Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz avgqu-sz await svctm %util xvdap10.00 0.000.000.00 0.00 0.00 0.00 0.000.00 0.00 0.00 xvdf 0.00 0.000.000.00 0.00 0.00 0.00 0.000.00 0.00 0.00 xvdg 0.00 0.000.000.00 0.00 0.00 0.00 0.000.00 0.00 0.00 No activity at all. - iostat -x after I started the select queries after the updates: avg-cpu: %user %nice %system %iowait %steal %idle 2.090.001.49 12.150.00 84.26 Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz avgqu-sz await svctm %util xvdap10.00 0.000.000.00 0.00 0.00 0.00 0.000.00 0.00 0.00 xvdf 0.00 8.000.002.00 0.0080.00 40.00 0.002.00 2.00 0.40 xvdg 0.00 7844.001.00 1098.00 8.00 82336.00 74.9358.27 59.39 0.70 77.20 Heavy writes to the WAL volume. select * from pg_stat_activity; datid | datname | procpid | usesysid | usename | application_name | client_addr | client_hostname | client_port | backend_start | xact_start | qu ery_start | waiting | current_query ---+-+-+--+--+--+-+-+-+---+---+ ---+-+--- 16385 | lars|2654 |16384 | lars | | 127.0.0.1 | | 44972 | 2011-07-12 18:44:09.479581+00 | 2011-07-12 18:50:32.629412+00 | 2011-07-12 18:50:32.629473+00 | f | select count(*) from test where tenant = $1 and created_date = $2 16385 | lars|2658 | 10 | postgres | psql | | | -1 | 2011-07-12 18:49:02.675436+00 | 2011-07-12 18:50:32.631013+00 | 2011-07-12 18:50:32.631013+00 |
Re: [PERFORM] UPDATEDs slowing SELECTs in a fully cached database
lars lhofha...@yahoo.com wrote: select count(*) from test where tenant = $1 and created_date = $2 Ah, that might be a major clue -- prepared statements. What sort of a plan do you get for that as a prepared statement? (Note, it is very likely *not* to be the same plan as you get if you run with literal values!) It is not at all unlikely that it could resort to a table scan if you have one tenant which is five or ten percent of the table, which would likely trigger the pruning as it passed over the modified pages. -Kevin -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] UPDATEDs slowing SELECTs in a fully cached database
lars lhofha...@yahoo.com wrote: select count(*) from test where tenant = $1 and created_date = $2 Thinking about this some more, it would be interesting to know your PostgreSQL configuration. I seem to remember you mentioning some settings up-thread, but I'm not sure whether it was comprehensive. Could you paste the result of running the query on this Wiki page?: http://wiki.postgresql.org/wiki/Server_Configuration It might be that if you generate your queries with literals rather than using server-side prepared statements, and tweak a couple configuration settings, this problem will evaporate. -Kevin -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] Planner choosing NestedLoop, although it is slower...
Mario Splivalo mario.spliv...@megafon.hr writes: Limit (cost=0.00..415.91 rows=21 width=8) (actual time=11263.089..11263.089 rows=0 loops=1) - Nested Loop (cost=0.00..186249.55 rows=9404 width=8) (actual time=11263.087..11263.087 rows=0 loops=1) Why is planner using NestedLoops, Because it thinks the LIMIT will kick in and end the query when the join is only 21/9404ths (ie, a fraction of a percent) complete. A NestLoop results in saving a lot of work in that situation, whereas hash-and-sort has to do the whole join despite the LIMIT. What you need to look into is why the estimated join size is 9400 rows when the actual join size is zero. Are both tables ANALYZEd? Are you intentionally selecting rows that have no join partners? regards, tom lane -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] UPDATEDs slowing SELECTs in a fully cached database
On 07/12/2011 12:08 PM, Kevin Grittner wrote: larslhofha...@yahoo.com wrote: select count(*) from test where tenant = $1 and created_date = $2 Ah, that might be a major clue -- prepared statements. What sort of a plan do you get for that as a prepared statement? (Note, it is very likely *not* to be the same plan as you get if you run with literal values!) It is not at all unlikely that it could resort to a table scan if you have one tenant which is five or ten percent of the table, which would likely trigger the pruning as it passed over the modified pages. -Kevin So a read of a row *will* trigger dead tuple pruning, and that requires WAL logging, and this is known/expected? This is actually the only answer I am looking for. :) I have not seen this documented anywhere. I know that Postgres will generate general plans for prepared statements (how could it do otherwise?), I also know that it sometimes chooses a sequential scan. This can always be tweaked to touch fewer rows and/or use a different plan. That's not my objective, though! The fact that a select (maybe a big analytical query we'll run) touching many rows will update the WAL and wait (apparently) for that IO to complete is making a fully cached database far less useful. I just artificially created this scenario. ... Just dropped the table to test something so I can't get the plan right now. Will send an update as soon as I get it setup again. Thanks again. -- Lars -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] UPDATEDs slowing SELECTs in a fully cached database
lars lhofha...@yahoo.com wrote: So a read of a row *will* trigger dead tuple pruning, and that requires WAL logging, and this is known/expected? Yes, because pruning dead line pointers will make subsequent reads faster. It's intended to be an optimization. This is actually the only answer I am looking for. :) I have not seen this documented anywhere. You would currently need to look at the README-HOT file or source code, I think. There probably should be some mention in the user docs, but I haven't noticed any, and it is more technical than most of the documentation gets. Perhaps a note block somewhere... The fact that a select (maybe a big analytical query we'll run) touching many rows will update the WAL and wait (apparently) for that IO to complete is making a fully cached database far less useful. Well, I've never run into this because I have directly attached storage through a RAID controller with a battery-backed cache configured for write-back. The pruning is pretty light on CPU usage, and with a BBU controller, the WAL writes just move from one cache to another. If that's not an option for you, you could contrive to have the update code reread the modified rows after COMMIT, or configure your autovacuum to be very aggressive so that a background process usually takes care of this before a SELECT gets to it. And there's a good chance that tuning your query and/or running with literal values available to the planner would be a big net win even without this issue; if this issue is a problem for you, it's just another reason to do that tuning. Just dropped the table to test something so I can't get the plan right now. Will send an update as soon as I get it setup again. I'll be surprised if you don't see a seqscan. The most interesting bit at this point (at least to me) is working on tuning the cost factors for the planner. -Kevin -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] UPDATEDs slowing SELECTs in a fully cached database
On 07/12/2011 01:04 PM, lars wrote:
On 07/12/2011 12:08 PM, Kevin Grittner wrote:
larslhofha...@yahoo.com wrote:
select count(*) from test where tenant = $1 and created_date = $2
Ah, that might be a major clue -- prepared statements.
What sort of a plan do you get for that as a prepared statement?
(Note, it is very likely *not* to be the same plan as you get if you
run with literal values!) It is not at all unlikely that it could
resort to a table scan if you have one tenant which is five or ten
percent of the table, which would likely trigger the pruning as it
passed over the modified pages.
-Kevin
So a read of a row *will* trigger dead tuple pruning, and that
requires WAL logging, and this is known/expected?
This is actually the only answer I am looking for. :) I have not seen
this documented anywhere.
I know that Postgres will generate general plans for prepared
statements (how could it do otherwise?),
I also know that it sometimes chooses a sequential scan.
This can always be tweaked to touch fewer rows and/or use a different
plan. That's not my objective, though!
The fact that a select (maybe a big analytical query we'll run)
touching many rows will update the WAL and wait
(apparently) for that IO to complete is making a fully cached database
far less useful.
I just artificially created this scenario.
... Just dropped the table to test something so I can't get the plan
right now. Will send an update as soon as I get
it setup again.
Thanks again.
-- Lars
Ok... Slightly changes the indexes:
\d test
Table lars.test
Column| Type | Modifiers
--+---+---
tenant | character(15) |
created_by | character(15) |
created_date | date |
Indexes:
i1 btree (tenant)
So just just a simple index on tenant.
prepare x as select count(*) from test where tenant = $1 and
created_date = $2;
PREPARE
explain execute x('001','2011-6-30');
QUERY PLAN
---
Aggregate (cost=263301.40..263301.41 rows=1 width=0)
- Bitmap Heap Scan on test (cost=3895.99..263299.28 rows=847 width=0)
Recheck Cond: (tenant = $1)
Filter: (created_date = $2)
- Bitmap Index Scan on i1 (cost=0.00..3895.77 rows=169372
width=0)
Index Cond: (tenant = $1)
(6 rows)
-- this is when the WAL rows are written:
explain (analyze on, buffers on) execute x('001','2011-6-30');
QUERY PLAN
Aggregate (cost=263301.40..263301.41 rows=1 width=0) (actual
time=191.150..191.151 rows=1 loops=1)
Buffers: shared hit=3716
- Bitmap Heap Scan on test (cost=3895.99..263299.28 rows=847
width=0) (actual time=1.966..188.221 rows=3712 loops=1)
Recheck Cond: (tenant = $1)
Filter: (created_date = $2)
Buffers: shared hit=3716
- Bitmap Index Scan on i1 (cost=0.00..3895.77 rows=169372
width=0) (actual time=1.265..1.265 rows=3712 loops=1)
Index Cond: (tenant = $1)
Buffers: shared hit=20
Total runtime: 191.243 ms
(10 rows)
-- this is when no WAL is written:
explain (analyze on, buffers on) execute x('001','2011-6-30');
QUERY PLAN
Aggregate (cost=263301.40..263301.41 rows=1 width=0) (actual
time=11.529..11.530 rows=1 loops=1)
Buffers: shared hit=3715
- Bitmap Heap Scan on test (cost=3895.99..263299.28 rows=847
width=0) (actual time=1.341..9.187 rows=3712 loops=1)
Recheck Cond: (tenant = $1)
Filter: (created_date = $2)
Buffers: shared hit=3715
- Bitmap Index Scan on i1 (cost=0.00..3895.77 rows=169372
width=0) (actual time=0.756..0.756 rows=3712 loops=1)
Index Cond: (tenant = $1)
Buffers: shared hit=19
Total runtime: 11.580 ms
(10 rows)
If you wanted to recreate this scenario I created a simple script to
create the table:
create table test(tenant char(15), created_by char(15), created_date date);
insert into test values('x', 'y','2011-6-30');
insert into test select * from test;
insert into test select * from test;
insert into test select * from test;
insert into test select * from test;
insert into test select * from test;
insert into test select * from test;
insert into test select * from test;
insert into test select * from test;
insert into test select * from test;
insert into test select * from test;
insert into test select * from test;
insert into test select * from test;
insert into test select * from test;
insert into test select * from test;
insert
Re: [PERFORM] UPDATEDs slowing SELECTs in a fully cached database
On Tue, Jul 12, 2011 at 2:08 PM, Kevin Grittner kevin.gritt...@wicourts.gov wrote: lars lhofha...@yahoo.com wrote: select count(*) from test where tenant = $1 and created_date = $2 Ah, that might be a major clue -- prepared statements. I'm really skeptical that this is the case -- the table is 100m and there is no way you are banging through 100m in 500ms records particularly if doing i/o. Also regarding the page cleanup, IIRC the optimization only takes place if the dead tuples are HOT -- when the OP opened the thread he stated it was happening with update on indexed field (and later tested it on unindexed field). Something is not adding up here. Perhaps there is an alternate route to WAL logged activity from selects I'm not thinking of. Right now I'm thinking to run the selects on table 'a' and the inserts concurrently on table 'b' and seeing how that behaves. Another way to get to the bottom is to oprofile the selecting-during-load backend to see where the time is getting spent. Alternative way to do this is to strace attach to the selecting-during-load backend to see if it's really writing to the WAL (I'm really curious about this). Another interesting test would be to try and reproduce the results on native machine. It should be possible to do this on your workstation with a more modestly sized scaling factor. merlin -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] UPDATEDs slowing SELECTs in a fully cached database
lars lhofha...@yahoo.com wrote:
vacuum analyze;
I tried this out on a 16 core, 64 GB machine. It was a replication
target for a few dozen source databases into a couple 2 TB reporting
databases, and had some light testing going on, but it was only at
about 50% capacity, so that shouldn't throw this off by *too* much,
I hope. Since our data is long-lived enough to worry about
transaction ID freezing issues, I always follow a bulk load with
VACUUM FREEZE ANALYZE; so I did that here. I also just threw this
into the 2 TB database without changing our configuration. Among
other things, that means that autovacuum was on.
prepare x as select count(*) from test where tenant = $1 and
created_date = $2;
prepare y as update test set created_by = $1 where tenant = $2 and
created_date = $3;
execute y('001', '001','2011-6-30');
execute x('001','2011-6-30');
I ran x a bunch of times to get a baseline, then y once, then x a
bunch more times. The results were a bit surprising:
cir= \timing
Timing is on.
cir= execute x('001','2011-6-30');
count
---
3456
(1 row)
Time: 9.823 ms
cir= execute x('001','2011-6-30');
count
---
3456
(1 row)
Time: 8.481 ms
cir= execute x('001','2011-6-30');
count
---
3456
(1 row)
Time: 14.054 ms
cir= execute x('001','2011-6-30');
count
---
3456
(1 row)
Time: 10.169 ms
cir= execute y('001', '001','2011-6-30');
UPDATE 3456
Time: 404.244 ms
cir= execute x('001','2011-6-30');
count
---
3456
(1 row)
Time: 128.643 ms
cir= execute x('001','2011-6-30');
count
---
3456
(1 row)
Time: 2.657 ms
cir= execute x('001','2011-6-30');
count
---
3456
(1 row)
Time: 5.883 ms
cir= execute x('001','2011-6-30');
count
---
3456
(1 row)
Time: 2.645 ms
cir= execute x('001','2011-6-30');
count
---
3456
(1 row)
Time: 2.753 ms
cir= execute x('001','2011-6-30');
count
---
3456
(1 row)
Time: 2.253 ms
Running the update made the next SELECT slow, then it was much
*faster*. My best guess is that the data landed in a more
concentrated set of pages after the update, and once autovacuum
kicked in and cleaned things up it was able to get to that set of
data faster.
On the face of it, though, this looks like Postgres would not be
that useful as database that resides (mostly) in the cache.
autovacuum | off
Well, certainly not while under modification without running
autovacuum. That's disabling an integral part of what keeps
performance up. There are very few, if any, situations where
running PostgreSQL in production without autovacuum makes any sense,
and benchmarks which disable it don't give a very accurate picture
of typical performance. Now, if you're looking to artificially
create a worst-case scenario, then it makes sense, but I'm not clear
on the point of it.
I do understand the impulse, though. When we first started using
PostgreSQL there were certain very small tables which were updated
very frequently which got slow when autovacuum kicked in. We made
autovacuum less aggressive, and found that things go worse! Se we
went the other way and made autovacuum much more aggressive than the
defaults, and everything was fine.
-Kevin
--
Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] Planner choosing NestedLoop, although it is slower...
On 07/12/2011 10:04 PM, Tom Lane wrote: Mario Splivalomario.spliv...@megafon.hr writes: Limit (cost=0.00..415.91 rows=21 width=8) (actual time=11263.089..11263.089 rows=0 loops=1) - Nested Loop (cost=0.00..186249.55 rows=9404 width=8) (actual time=11263.087..11263.087 rows=0 loops=1) Why is planner using NestedLoops, Because it thinks the LIMIT will kick in and end the query when the join is only 21/9404ths (ie, a fraction of a percent) complete. A NestLoop results in saving a lot of work in that situation, whereas hash-and-sort has to do the whole join despite the LIMIT. What you need to look into is why the estimated join size is 9400 rows when the actual join size is zero. Are both tables ANALYZEd? Are you intentionally selecting rows that have no join partners? Hi, Tom. Yes, both tables have been ANALYZEd. What do you mean, intentilnaly selecting rows taht have no join partners? Mario -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] UPDATEDs slowing SELECTs in a fully cached database
On 07/12/2011 02:51 PM, Kevin Grittner wrote:
I ran x a bunch of times to get a baseline, then y once, then x a
bunch more times. The results were a bit surprising:
cir= \timing
Timing is on.
cir= execute x('001','2011-6-30');
count
---
3456
(1 row)
Time: 9.823 ms
cir= execute x('001','2011-6-30');
count
---
3456
(1 row)
Time: 8.481 ms
cir= execute x('001','2011-6-30');
count
---
3456
(1 row)
Time: 14.054 ms
cir= execute x('001','2011-6-30');
count
---
3456
(1 row)
Time: 10.169 ms
cir= execute y('001', '001','2011-6-30');
UPDATE 3456
Time: 404.244 ms
cir= execute x('001','2011-6-30');
count
---
3456
(1 row)
Time: 128.643 ms
cir= execute x('001','2011-6-30');
count
---
3456
(1 row)
Time: 2.657 ms
cir= execute x('001','2011-6-30');
count
---
3456
(1 row)
Time: 5.883 ms
cir= execute x('001','2011-6-30');
count
---
3456
(1 row)
Time: 2.645 ms
cir= execute x('001','2011-6-30');
count
---
3456
(1 row)
Time: 2.753 ms
cir= execute x('001','2011-6-30');
count
---
3456
(1 row)
Time: 2.253 ms
Interesting. When you did you test, did you also find WAL write activity
when running x the first time after y?
(It's very hard to catch in only a single query, though).
Running the update made the next SELECT slow, then it was much
*faster*. My best guess is that the data landed in a more
concentrated set of pages after the update, and once autovacuum
kicked in and cleaned things up it was able to get to that set of
data faster.
autovacuum | off
Well, certainly not while under modification without running
autovacuum. That's disabling an integral part of what keeps
performance up.
Oh, it's just switched off for testing, so that I can control when
vacuum runs and make sure that it's not
skewing the results while I am measuring something.
In a real database I would probably err on vacuuming more than less.
For a fully cached database I would probably want to switch off HOT
pruning and compaction (which from what we see
is done synchronously with the select) and leave it up to the
asynchronous auto vacuum to do that. But maybe I am
still not quite understanding the performance implications.
--
Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] Planner choosing NestedLoop, although it is slower...
Mario Splivalo mario.spliv...@megafon.hr writes: On 07/12/2011 10:04 PM, Tom Lane wrote: What you need to look into is why the estimated join size is 9400 rows when the actual join size is zero. Are both tables ANALYZEd? Are you intentionally selecting rows that have no join partners? Yes, both tables have been ANALYZEd. What do you mean, intentilnaly selecting rows taht have no join partners? I'm wondering why the actual join size is zero. That seems like a rather unexpected case for a query like this. regards, tom lane -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] UPDATEDs slowing SELECTs in a fully cached database
On 07/12/2011 02:38 PM, Merlin Moncure wrote:
Something is not adding up here. Perhaps there is an alternate route
to WAL logged activity from selects I'm not thinking of. Right now
I'm thinking to run the selects on table 'a' and the inserts
concurrently on table 'b' and seeing how that behaves. Another way to
get to the bottom is to oprofile the selecting-during-load backend to
see where the time is getting spent. Alternative way to do this is
to strace attach to the selecting-during-load backend to see if it's
really writing to the WAL (I'm really curious about this).
Another interesting test would be to try and reproduce the results on
native machine. It should be possible to do this on your workstation
with a more modestly sized scaling factor.
merlin
Just tried with two of my test tables.
Updates on 'a' have no (measurable) effect on select from 'b'.
Back to the first case, here's an strace from the backend doing the
select right after the updates.
Q\0\0\0`select count(*) from test1 ..., 8192, 0, NULL, NULL) = 97
gettimeofday({1310512219, 723762}, NULL) = 0
open(base/16385/33032, O_RDWR)= 8
lseek(8, 0, SEEK_END) = 1073741824
open(base/16385/33032.1, O_RDWR|O_CREAT, 0600) = 9
lseek(9, 0, SEEK_END) = 1073741824
open(base/16385/33032.2, O_RDWR|O_CREAT, 0600) = 10
lseek(10, 0, SEEK_END) = 191348736
open(base/16385/33035, O_RDWR)= 11
lseek(11, 0, SEEK_END) = 1073741824
open(base/16385/33035.1, O_RDWR|O_CREAT, 0600) = 12
lseek(12, 0, SEEK_END) = 3571712
lseek(10, 0, SEEK_END) = 191348736
brk(0x28ad000) = 0x28ad000
mmap(NULL, 135168, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0x7f5f28ca
mmap(NULL, 266240, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0x7f5f28c5f000
munmap(0x7f5f28c5f000, 266240) = 0
munmap(0x7f5f28ca, 135168) = 0
open(pg_xlog/000100BB0012, O_RDWR) = 13
lseek(13, 1564672, SEEK_SET)= 1564672
write(13,
f\320\1\0\1\0\0\0\273\0\0\0\0\340\27\22`\32\0\0002833!000...,
2400256) = 2400256
fdatasync(13) = 0
semop(229383, {{9, 1, 0}}, 1) = 0
gettimeofday({1310512219, 885287}, NULL) = 0
sendto(5,
\2\0\0\0\300\3\0\0\1@\0\0\t\0\0\0\1\0\0\0\0\0\0\0\353\4\0\0@\0\2\0...,
960, 0, NULL, 0) = 960
sendto(5,
\2\0\0\0\300\3\0\0\1@\0\0\t\0\0\0\0\0\0\0\0\0\0\0009\n\0\0@\0\2\0...,
960, 0, NULL, 0) = 960
sendto(5,
\2\0\0\0\300\3\0\0\1@\0\0\t\0\0\0\0\0\0\0\0\0\0\0v\n\0\0@\0\2\0...,
960, 0, NULL, 0) = 960
sendto(5,
\2\0\0\0\270\1\0\0\0\0\0\0\4\0\0\0\0\0\0\0\0\0\0\0\275\4\0\0\377\177\0\0...,
440, 0, NULL, 0) = 440
sendto(6,
T\0\0\0\36\0\1count\0\0\0\0\0\0\0\0\0\0\24\0\10\377\377\377\377\0\0D...,
66, 0, NULL, 0) = 66
So the backend definitely writing to the WAL, directly and synchronously.
Selecting the same set of rows again:
Q\0\0\0`select count(*) from test1 ..., 8192, 0, NULL, NULL) = 97
gettimeofday({1310512344, 823728}, NULL) = 0
lseek(10, 0, SEEK_END) = 191348736
lseek(12, 0, SEEK_END) = 3571712
lseek(10, 0, SEEK_END) = 191348736
brk(0x28d5000) = 0x28d5000
brk(0x2915000) = 0x2915000
brk(0x2897000) = 0x2897000
gettimeofday({1310512344, 831043}, NULL) = 0
sendto(5,
\2\0\0\0\350\0\0\0\1@\0\0\2\0\0\0\1\0\0\0\0\0\0\0\10\201\0\0?\0\2\0..., 232,
0, NULL, 0) = 232
sendto(6,
T\0\0\0\36\0\1count\0\0\0\0\0\0\0\0\0\0\24\0\10\377\377\377\377\0\0D...,
66, 0, NULL, 0) = 66
No writing to the WAL.
-- Lars
--
Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] Planner choosing NestedLoop, although it is slower...
On 07/13/2011 12:39 AM, Tom Lane wrote: Mario Splivalomario.spliv...@megafon.hr writes: On 07/12/2011 10:04 PM, Tom Lane wrote: What you need to look into is why the estimated join size is 9400 rows when the actual join size is zero. Are both tables ANALYZEd? Are you intentionally selecting rows that have no join partners? Yes, both tables have been ANALYZEd. What do you mean, intentilnaly selecting rows taht have no join partners? I'm wondering why the actual join size is zero. That seems like a rather unexpected case for a query like this. It is true that this particular query returns 0 rows. But it's created by django, and I can't do much to alter it. Mario -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] Planner choosing NestedLoop, although it is slower...
On 07/13/2011 12:39 AM, Tom Lane wrote: Mario Splivalomario.spliv...@megafon.hr writes: On 07/12/2011 10:04 PM, Tom Lane wrote: What you need to look into is why the estimated join size is 9400 rows when the actual join size is zero. Are both tables ANALYZEd? Are you intentionally selecting rows that have no join partners? Yes, both tables have been ANALYZEd. What do you mean, intentilnaly selecting rows taht have no join partners? I'm wondering why the actual join size is zero. That seems like a rather unexpected case for a query like this. Yes, seems that planer gets confused by LIMIT. This query: select * from tubesite_object join tubesite_image on id=object_ptr_id where site_id = 8 and pub_date '2011-07-12 13:25:00' order by pub_date desc ; Does not choose Nested Loop, and is done instantly (20 ms), and returns no rows. However, if I add LIMIT at the end, it chooses NestedLoop and it takes 500ms if I'm alone on the server, and 10+ seconds if there 50+ connections on the server. Mario -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] UPDATEDs slowing SELECTs in a fully cached database
Jeff Janes jeff.ja...@gmail.com writes: On 7/12/11, lars lhofha...@yahoo.com wrote: The fact that a select (maybe a big analytical query we'll run) touching many rows will update the WAL and wait (apparently) for that IO to complete is making a fully cached database far less useful. I just artificially created this scenario. I can't think of any reason that that WAL would have to be flushed synchronously. Maybe he's running low on shared_buffers? We would have to flush WAL before writing a dirty buffer out, so maybe excessive pressure on available buffers is part of the issue here. regards, tom lane -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] Planner choosing NestedLoop, although it is slower...
On 07/13/2011 02:53 AM, Mario Splivalo wrote: On 07/13/2011 12:39 AM, Tom Lane wrote: Mario Splivalomario.spliv...@megafon.hr writes: On 07/12/2011 10:04 PM, Tom Lane wrote: What you need to look into is why the estimated join size is 9400 rows when the actual join size is zero. Are both tables ANALYZEd? Are you intentionally selecting rows that have no join partners? Yes, both tables have been ANALYZEd. What do you mean, intentilnaly selecting rows taht have no join partners? I'm wondering why the actual join size is zero. That seems like a rather unexpected case for a query like this. Yes, seems that planer gets confused by LIMIT. This query: select * from tubesite_object join tubesite_image on id=object_ptr_id where site_id = 8 and pub_date '2011-07-12 13:25:00' order by pub_date desc ; Does not choose Nested Loop, and is done instantly (20 ms), and returns no rows. However, if I add LIMIT at the end, it chooses NestedLoop and it takes 500ms if I'm alone on the server, and 10+ seconds if there 50+ connections on the server. As explained/suggested by RhodiumToad on IRC, adding composite index on (site_id, pub_date) made nestedloop query finish in around 100 seconds! Thank you! Mario -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
Re: [PERFORM] UPDATEDs slowing SELECTs in a fully cached database
shared_buffers is big enough to hold the entire database, and there is plenty of extra space. (verified with PG_buffercache) So i don't think that is the reason. Tom Lane t...@sss.pgh.pa.us schrieb: Jeff Janes jeff.ja...@gmail.com writes: On 7/12/11, lars lhofha...@yahoo.com wrote: The fact that a select (maybe a big analytical query we'll run) touching many rows will update the WAL and wait (apparently) for that IO to complete is making a fully cached database far less useful. I just artificially created this scenario. I can't think of any reason that that WAL would have to be flushed synchronously. Maybe he's running low on shared_buffers? We would have to flush WAL before writing a dirty buffer out, so maybe excessive pressure on available buffers is part of the issue here. regards, tom lane -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance
