date:20130911

Re: [PERFORM] Intermittent hangs with 9.2

2013-09-11 Thread Torsten Förtsch

On 10/09/13 20:04, David Whittaker wrote:
 On Tue, Sep 10, 2013 at 11:26 AM, Andrew Dunstan and...@dunslane.net
 mailto:and...@dunslane.net wrote:
 
 
 On 09/10/2013 11:04 AM, David Whittaker wrote:
 
 
 Hi All,
 
 I've been seeing a strange issue with our Postgres install for
 about a year now, and I was hoping someone might be able to help
 point me at the cause. At what seem like fairly random intervals
 Postgres will become unresponsive to the 3 application nodes it
 services. These periods tend to last for 10 - 15 minutes before
 everything rights itself and the system goes back to normal.
 
 During these periods the server will report a spike in the
 outbound bandwidth (from about 1mbs to about 5mbs most
 recently), a huge spike in context switches / interrupts (normal
 peaks are around 2k/8k respectively, and during these periods
 they‘ve gone to 15k/22k), and a load average of 100+. CPU usage
 stays relatively low, but it’s all system time reported, user
 time goes to zero. It doesn‘t seem to be disk related since
 we’re running with a shared_buffers setting of 24G, which will
 fit just about our entire database into memory, and the IO
 transactions reported by the server, as well as the disk reads
 reported by Postgres stay consistently low.
 
 We‘ve recently started tracking how long statements take to
 execute, and we’re seeing some really odd numbers. A simple
 delete by primary key, for example, from a table that contains
 about 280,000 rows, reportedly took 18h59m46.900s. An update by
 primary key in that same table was reported as 7d 17h 58m
 30.415s. That table is frequently accessed, but obviously those
 numbers don't seem reasonable at all.
 
 Some other changes we've made to postgresql.conf:
 
 synchronous_commit = off
 
 maintenance_work_mem = 1GB
 wal_level = hot_standby
 wal_buffers = 16MB
 
 max_wal_senders = 10
 
 wal_keep_segments = 5000
 
 checkpoint_segments = 128
 
 checkpoint_timeout = 30min
 
 checkpoint_completion_target = 0.9
 
 max_connections = 500
 
 The server is a Dell Poweredge R900 with 4 Xeon E7430
 processors, 48GB of RAM, running Cent OS 6.3.
 
 So far we‘ve tried disabling Transparent Huge Pages after I
 found a number of resources online that indicated similar
 interrupt/context switch issues, but it hasn’t resolve the
 problem. I managed to catch it happening once and run a perf
 which showed:
 
 |
 +  41.40%   48154  postmaster  0x347ba9 f 0x347ba9
 +   9.55%   10956  postmaster  0x2dc820 f
 set_config_option
 +   8.64%9946  postmaster  0x5a3d4  f writeListPage
 +   5.75%6609  postmaster  0x5a2b0  f
 ginHeapTupleFastCollect
 +   2.68%3084  postmaster  0x192483 f
 build_implied_join_equality
 +   2.61%2990  postmaster  0x187a55 f
 build_paths_for_OR
 +   1.86%2131  postmaster  0x794aa  f
 get_collation_oid
 +   1.56%1822  postmaster  0x5a67e  f
 ginHeapTupleFastInsert
 +   1.53%1766  postmaster  0x1929bc f
 distribute_qual_to_rels
 +   1.33%1558  postmaster  0x249671 f cmp_numerics|
 
 I‘m not sure what 0x347ba9 represents, or why it’s an address
 rather than a method name.
 
 That's about the sum of it. Any help would be greatly
 appreciated and if you want any more information about our
 setup, please feel free to ask.
 
 
 
 I have seen cases like this with very high shared_buffers settings.
 
 24Gb for shared_buffers is quite high, especially on a 48Gb box.
 What happens if you dial that back to, say, 12Gb?
 
 
 I'd be willing to give it a try.  I'd really like to understand what's
 going on here though.  Can you elaborate on that?  Why would 24G of
 shared buffers be too high in this case?  The machine is devoted
 entirely to PG, so having PG use half of the available RAM to cache data
 doesn't feel unreasonable.

Here is what I have recently learned.

The root cause is crash safety and checkpoints. This is certainly
something you want. When you write to the database these operations
first occur in the buffer cache and the particular buffer you write to
is marked dirty. The cache is organized in chunks of 8kb. Additionally
write operations are also committed to the WAL.

A checkpoint iterates over all dirty buffers writing them to the
database. After that all buffers are clean again.

Now, if you write to a clean buffer it gets entirely written to the WAL.
That means after

Re: [PERFORM] Intermittent hangs with 9.2

2013-09-11 Thread Julien Cigar

On Tue, Sep 10, 2013 at 02:04:57PM -0400, David Whittaker wrote:
 Hi Andrew,
 
 
 On Tue, Sep 10, 2013 at 11:26 AM, Andrew Dunstan and...@dunslane.netwrote:
 
 
  On 09/10/2013 11:04 AM, David Whittaker wrote:
 
 
  Hi All,
 
  I've been seeing a strange issue with our Postgres install for about a
  year now, and I was hoping someone might be able to help point me at the
  cause. At what seem like fairly random intervals Postgres will become
  unresponsive to the 3 application nodes it services. These periods tend to
  last for 10 - 15 minutes before everything rights itself and the system
  goes back to normal.
 
  During these periods the server will report a spike in the outbound
  bandwidth (from about 1mbs to about 5mbs most recently), a huge spike in
  context switches / interrupts (normal peaks are around 2k/8k respectively,
  and during these periods they‘ve gone to 15k/22k), and a load average of
  100+. CPU usage stays relatively low, but it’s all system time reported,
  user time goes to zero. It doesn‘t seem to be disk related since we’re
  running with a shared_buffers setting of 24G, which will fit just about our
  entire database into memory, and the IO transactions reported by the
  server, as well as the disk reads reported by Postgres stay consistently
  low.
 
  We‘ve recently started tracking how long statements take to execute, and
  we’re seeing some really odd numbers. A simple delete by primary key, for
  example, from a table that contains about 280,000 rows, reportedly took
  18h59m46.900s. An update by primary key in that same table was reported as
  7d 17h 58m 30.415s. That table is frequently accessed, but obviously those
  numbers don't seem reasonable at all.
 
  Some other changes we've made to postgresql.conf:
 
  synchronous_commit = off
 
  maintenance_work_mem = 1GB
  wal_level = hot_standby
  wal_buffers = 16MB
 
  max_wal_senders = 10
 
  wal_keep_segments = 5000
 
  checkpoint_segments = 128
 
  checkpoint_timeout = 30min
 
  checkpoint_completion_target = 0.9
 
  max_connections = 500
 
  The server is a Dell Poweredge R900 with 4 Xeon E7430 processors, 48GB of
  RAM, running Cent OS 6.3.
 
  So far we‘ve tried disabling Transparent Huge Pages after I found a
  number of resources online that indicated similar interrupt/context switch
  issues, but it hasn’t resolve the problem. I managed to catch it happening
  once and run a perf which showed:
 
  |
  +  41.40%   48154  postmaster  0x347ba9 f 0x347ba9
  +   9.55%   10956  postmaster  0x2dc820 f set_config_option
  +   8.64%9946  postmaster  0x5a3d4  f writeListPage
  +   5.75%6609  postmaster  0x5a2b0  f
  ginHeapTupleFastCollect
  +   2.68%3084  postmaster  0x192483 f
  build_implied_join_equality
  +   2.61%2990  postmaster  0x187a55 f build_paths_for_OR
  +   1.86%2131  postmaster  0x794aa  f get_collation_oid
  +   1.56%1822  postmaster  0x5a67e  f
  ginHeapTupleFastInsert
  +   1.53%1766  postmaster  0x1929bc f
  distribute_qual_to_rels
  +   1.33%1558  postmaster  0x249671 f cmp_numerics|
 
  I‘m not sure what 0x347ba9 represents, or why it’s an address rather than
  a method name.
 
  That's about the sum of it. Any help would be greatly appreciated and if
  you want any more information about our setup, please feel free to ask.
 
 
 
  I have seen cases like this with very high shared_buffers settings.
 
  24Gb for shared_buffers is quite high, especially on a 48Gb box. What
  happens if you dial that back to, say, 12Gb?
 
 
 I'd be willing to give it a try.  I'd really like to understand what's
 going on here though.  Can you elaborate on that?  Why would 24G of shared
 buffers be too high in this case?  The machine is devoted entirely to PG,
 so having PG use half of the available RAM to cache data doesn't feel
 unreasonable.

Some of the overhead of bgwriter and checkpoints is more or less linear
in the size of shared_buffers. If your shared_buffers is large a lot of
data could be dirty when a checkpoint starts, resulting in an I/O spike
... (although we've spread checkpoints in recent pg versions, so this
should be less a problem nowadays).
Another reason is that the OS cache is also being used for reads and
writes and with a large shared_buffers there is a risk of doubly cached
data (in the OS cache + in shared_buffers).
In an ideal world most frequently used blocks should be in
shared_buffers and less frequently used block in the OS cache ..

 
 
 
  cheers
 
  andrew
 
 

-- 
No trees were killed in the creation of this message.
However, many electrons were terribly inconvenienced.


-- 
Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance

[PERFORM] slow sort

2013-09-11 Thread Maximilian Tyrtania

Hi there,

here is another one from the why is my query so slow? category. First post, 
so please bare with me.

The query (which takes around 6 seconds) is this:

SET work_mem TO '256MB';//else sort spills to disk

SELECT
et.subject,
COALESCE (createperson.vorname || ' ', '') || createperson.nachname AS 
Sender/Empfänger,
to_char(es.sentonat, 'DD.MM.YY') AS versendet am,
es.sentonat AS orderbydate,
COUNT (ct.*),
COALESCE (C . NAME, 'keine Angabe') :: TEXT AS für Kunde,
COUNT (ct.datetimesentonat) :: TEXT || ' von ' || COUNT (ct.*) :: TEXT 
|| ' versendet',
1 AS LEVEL,
TRUE AS hassubs,
FALSE AS opensubs,
'emailsendings:' || es. ID :: TEXT AS model_id,
NULL :: TEXT AS parent_model_id,
es. ID
FROM
emailtemplates et
JOIN emailsendings es ON et. ID = es.emailtemplate_id
LEFT JOIN companies C ON C . ID = es.customers_id
LEFT JOIN personen createperson ON createperson. ID = et.personen_create_id
LEFT JOIN contacts ct ON ct.emailsendings_id = es. ID WHERE 
f_record_visible_to_currentuser(et.*::coretable) = true 
GROUP BY
1,
2,
3,
4,
6,
8,
9,
10,
11,
12,
13
ORDER BY
es.sentonat desc

Explain analyze:

GroupAggregate  (cost=35202.88..45530.77 rows=118033 width=142) (actual 
time=5119.783..5810.680 rows=898 loops=1)
  -  Sort  (cost=35202.88..35497.96 rows=118033 width=142) (actual 
time=5119.356..5200.457 rows=352744 loops=1)
Sort Key: es.sentonat, et.subject, ((COALESCE((createperson.vorname || 
' '::text), ''::text) || createperson.nachname)), (to_char(es.sentonat, 
'DD.MM.YY'::text)), ((COALESCE(c.name, 'keine Angabe'::character 
varying))::text), (1), (true), (false), (('emailsendings:'::text || 
(es.id)::text)), (NULL::text), es.id
Sort Method:  quicksort  Memory: 198999kB
-  Nested Loop Left Join  (cost=0.00..25259.29 rows=118033 width=142) 
(actual time=1.146..1896.382 rows=352744 loops=1)
  -  Nested Loop Left Join  (cost=0.00..2783.16 rows=302 
width=102) (actual time=1.127..32.577 rows=898 loops=1)
-  Merge Join  (cost=0.00..2120.06 rows=302 width=86) 
(actual time=1.125..30.940 rows=898 loops=1)
  Merge Cond: (et.id = es.emailtemplate_id)
  -  Nested Loop Left Join  (cost=0.00..2224.95 
rows=277 width=74) (actual time=1.109..27.484 rows=830 loops=1)
-  Index Scan using emailtemplates_pkey on 
emailtemplates et  (cost=0.00..460.71 rows=277 width=63) (actual 
time=1.097..20.541 rows=830 loops=1)
  Filter: 
f_record_visible_to_currentuser((et.*)::coretable)
-  Index Scan using personen_pkey on personen 
createperson  (cost=0.00..6.36 rows=1 width=19) (actual time=0.006..0.006 
rows=1 loops=830)
  Index Cond: (createperson.id = 
et.personen_create_id)
  -  Index Scan using 
fki_emailsendings_emailtemplate_id_fkey on emailsendings es  (cost=0.00..49.83 
rows=905 width=20) (actual time=0.011..1.360 rows=898 loops=1)
-  Index Scan using firmen_pkey on companies c  
(cost=0.00..2.18 rows=1 width=24) (actual time=0.001..0.001 rows=0 loops=898)
  Index Cond: (c.id = es.customers_id)
  -  Index Scan using fki_contacts_emailsendings_id_fkey on 
contacts ct  (cost=0.00..61.55 rows=561 width=44) (actual time=0.019..0.738 
rows=393 loops=898)
Index Cond: (ct.emailsendings_id = es.id)
Total runtime: 5865.886 ms

I do have an index on es.sentonat. The sentonat-values are all unique, so I 
don't think I need indexes on all the fields I sort by. But then again, my 
understanding of this might be entirely wrong.

Depeszs' explain (http://explain.depesz.com/s/69O) tells me this:

node type   count   sum of times% of query
GroupAggregate  1   610.223 ms  10.5 %
Index Scan  5   690.503 ms  11.9 %
Merge Join  1   2.096 ms0.0 %
Nested Loop Left Join   3   1203.783 ms 20.7 %
Sort1   3304.075 ms 56.9 %

, so the sort appears to be the problem. Any pointers would be highly 
appreciated.

Maximilian Tyrtania
http://www.contactking.de



-- 
Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance

[PERFORM] Reasons for choosing one execution plan over another?

2013-09-11 Thread Mikkel Lauritsen

Hi all,

I have a number of Postgres 9.2.4 databases with the same schema but with
slightly different contents, running on small servers that are basically
alike (8-16 GB ram).

When I run the same query on these databases it results in one of two
different execution plans where one is much faster (appx. 50 times) than
the other. Each database always gives the same plan, and vacuuming,
updating statistics and reindexing doesn't seem to make any difference.

Clearly the fast plan is preferred, but I haven't been able to identify
any pattern (table sizes, tuning etc.) in why one plan is chosen over the
other, so is there any way I can make Postgres tell me why it chooses to
plan the way it does?

As reference I have included the query and execution plans for two
different databases below. The x and e tables contain about 5 and 10
million records respectively, and the performance difference is perfectly
reasonable as the outer loop has to process 3576 rows in the fast case and
154149 rows in the slow case.

Best regards  thanks,
  Mikkel Lauritsen

---

Query:

SELECT x.r, e.id, a.id
FROM x
  INNER JOIN e ON x.id = e.id
  INNER JOIN a ON x.a_id = a.id
  INNER JOIN i ON a.i_id = i.id
WHERE e.h_id = 'foo' AND i.c = 'bar';

Fast plan:

 Nested Loop  (cost=0.00..24553.77 rows=1 width=86) (actual
time=2.810..102.451 rows=20 loops=1)
   Join Filter: (x.a_id = a.id)
   Rows Removed by Join Filter: 3556
   -  Nested Loop  (cost=0.00..16.55 rows=1 width=39) (actual
time=0.036..0.046 rows=3 loops=1)
 -  Index Scan using i_c_idx on i  (cost=0.00..8.27 rows=1
width=39) (actual time=0.019..0.020 rows=1 loops=1)
   Index Cond: (c = 'bar'::text)
 -  Index Scan using a_i_id_idx on a  (cost=0.00..8.27 rows=1
width=78) (actual time=0.014..0.021 rows=3 loops=1)
   Index Cond: (i_id = i.id)
   -  Nested Loop  (cost=0.00..24523.00 rows=1138 width=86) (actual
time=2.641..33.818 rows=1192 loops=3)
 -  Index Scan using e_h_id_idx on e  (cost=0.00..6171.55
rows=1525 width=39) (actual time=0.049..1.108 rows=1857 loops=3)
   Index Cond: (h_id = 'foo'::text)
 -  Index Scan using x_id_idx on x  (cost=0.00..12.02 rows=1
width=86) (actual time=0.017..0.017 rows=1 loops=5571)
   Index Cond: (id = e.id)
 Total runtime: 102.526 ms

Slow plan:

 Nested Loop  (cost=0.00..858.88 rows=1 width=86) (actual
time=89.430..2589.905 rows=11 loops=1)
   -  Nested Loop  (cost=0.00..448.38 rows=169 width=86) (actual
time=0.135..142.246 rows=154149 loops=1)
 -  Nested Loop  (cost=0.00..16.55 rows=1 width=39) (actual
time=0.056..0.064 rows=3 loops=1)
   -  Index Scan using i_c_idx on i  (cost=0.00..8.27 rows=1
width=39) (actual time=0.030..0.030 rows=1 loops=1)
 Index Cond: (c = 'bar'::text)
   -  Index Scan using a_i_id_idx on a  (cost=0.00..8.27
rows=1 width=78) (actual time=0.022..0.028 rows=3 loops=1)
 Index Cond: (i_id = i.id)
 -  Index Scan using x_a_id_idx on x  (cost=0.00..372.48
rows=5935 width=86) (actual time=0.065..35.479 rows=51383 loops=3)
   Index Cond: (a_id = a.id)
   -  Index Scan using e_pkey on e  (cost=0.00..2.42 rows=1 width=39)
(actual time=0.015..0.015 rows=0 loops=154149)
 Index Cond: (id = x.id)
 Filter: (h_id = 'foo'::text)
 Rows Removed by Filter: 1
 Total runtime: 2589.970 ms



-- 
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] Intermittent hangs with 9.2

2013-09-11 Thread Merlin Moncure

On Tue, Sep 10, 2013 at 10:04 AM, David Whittaker d...@iradix.com wrote:
 Hi All,

 I've been seeing a strange issue with our Postgres install for about a year
 now, and I was hoping someone might be able to help point me at the cause.
 At what seem like fairly random intervals Postgres will become unresponsive
 to the 3 application nodes it services. These periods tend to last for 10 -
 15 minutes before everything rights itself and the system goes back to
 normal.

 During these periods the server will report a spike in the outbound
 bandwidth (from about 1mbs to about 5mbs most recently), a huge spike in
 context switches / interrupts (normal peaks are around 2k/8k respectively,
 and during these periods they‘ve gone to 15k/22k), and a load average of
 100+. CPU usage stays relatively low, but it’s all system time reported,
 user time goes to zero. It doesn‘t seem to be disk related since we’re
 running with a shared_buffers setting of 24G, which will fit just about our
 entire database into memory, and the IO transactions reported by the server,
 as well as the disk reads reported by Postgres stay consistently low.

 We‘ve recently started tracking how long statements take to execute, and
 we’re seeing some really odd numbers. A simple delete by primary key, for
 example, from a table that contains about 280,000 rows, reportedly took
 18h59m46.900s. An update by primary key in that same table was reported as
 7d 17h 58m 30.415s. That table is frequently accessed, but obviously those
 numbers don't seem reasonable at all.

 Some other changes we've made to postgresql.conf:

 synchronous_commit = off

 maintenance_work_mem = 1GB
 wal_level = hot_standby
 wal_buffers = 16MB

 max_wal_senders = 10

 wal_keep_segments = 5000

 checkpoint_segments = 128

 checkpoint_timeout = 30min

 checkpoint_completion_target = 0.9

 max_connections = 500

 The server is a Dell Poweredge R900 with 4 Xeon E7430 processors, 48GB of
 RAM, running Cent OS 6.3.

 So far we‘ve tried disabling Transparent Huge Pages after I found a number
 of resources online that indicated similar interrupt/context switch issues,
 but it hasn’t resolve the problem. I managed to catch it happening once and
 run a perf which showed:

 +  41.40%   48154  postmaster  0x347ba9 f 0x347ba9
 +   9.55%   10956  postmaster  0x2dc820 f set_config_option
 +   8.64%9946  postmaster  0x5a3d4  f writeListPage
 +   5.75%6609  postmaster  0x5a2b0  f
 ginHeapTupleFastCollect
 +   2.68%3084  postmaster  0x192483 f
 build_implied_join_equality
 +   2.61%2990  postmaster  0x187a55 f build_paths_for_OR
 +   1.86%2131  postmaster  0x794aa  f get_collation_oid
 +   1.56%1822  postmaster  0x5a67e  f ginHeapTupleFastInsert
 +   1.53%1766  postmaster  0x1929bc f
 distribute_qual_to_rels
 +   1.33%1558  postmaster  0x249671 f cmp_numerics

 I‘m not sure what 0x347ba9 represents, or why it’s an address rather than a
 method name.

 That's about the sum of it. Any help would be greatly appreciated and if you
 want any more information about our setup, please feel free to ask.


Reducing shared buffers to around 2gb will probably make the problem go away

*) What's your ratio reads to writes (approximately)?

*) How many connections when it happens.   Do connections pile on after that?

*) Are you willing to run custom patched postmaster to help
troubleshoot the problem?

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] slow sort

2013-09-11 Thread bricklen

On Wed, Sep 11, 2013 at 3:36 AM, Maximilian Tyrtania
li...@contactking.dewrote:


 JOIN emailsendings es ON et. ID = es.emailtemplate_id

ORDER BY
 es.sentonat desc



Perhaps on an index on (es.emailtemplate_id, es.sentonat desc) would help?

Re: [PERFORM] slow sort

2013-09-11 Thread Maximilian Tyrtania

Thanks, unfortunately it (creating that index) didn't. But I rewrote my query 
using inline subqueries, which already helped a lot.

Thanks again,

Maximilian Tyrtania
http://www.contactking.de

Am 11.09.2013 um 15:58 schrieb bricklen brick...@gmail.com:

 
 On Wed, Sep 11, 2013 at 3:36 AM, Maximilian Tyrtania li...@contactking.de 
 wrote:
 
 JOIN emailsendings es ON et. ID = es.emailtemplate_id 
 ORDER BY
 es.sentonat desc
 
 
 Perhaps on an index on (es.emailtemplate_id, es.sentonat desc) would help?



-- 
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] slow sort

2013-09-11 Thread Andrew Dunstan



On 09/11/2013 06:36 AM, Maximilian Tyrtania wrote:

Hi there,

here is another one from the why is my query so slow? category. First post, 
so please bare with me.

The query (which takes around 6 seconds) is this:

SET work_mem TO '256MB';//else sort spills to disk

SELECT
et.subject,
COALESCE (createperson.vorname || ' ', '') || createperson.nachname AS 
Sender/Empfänger,
to_char(es.sentonat, 'DD.MM.YY') AS versendet am,
es.sentonat AS orderbydate,
COUNT (ct.*),
COALESCE (C . NAME, 'keine Angabe') :: TEXT AS für Kunde,
COUNT (ct.datetimesentonat) :: TEXT || ' von ' || COUNT (ct.*) :: TEXT 
|| ' versendet',
1 AS LEVEL,
TRUE AS hassubs,
FALSE AS opensubs,
'emailsendings:' || es. ID :: TEXT AS model_id,
NULL :: TEXT AS parent_model_id,
es. ID
FROM
emailtemplates et
JOIN emailsendings es ON et. ID = es.emailtemplate_id
LEFT JOIN companies C ON C . ID = es.customers_id
LEFT JOIN personen createperson ON createperson. ID = et.personen_create_id
LEFT JOIN contacts ct ON ct.emailsendings_id = es. ID WHERE 
f_record_visible_to_currentuser(et.*::coretable) = true
GROUP BY
1,
2,
3,
4,
6,
8,
9,
10,
11,
12,
13
ORDER BY
es.sentonat desc

Explain analyze:

GroupAggregate  (cost=35202.88..45530.77 rows=118033 width=142) (actual 
time=5119.783..5810.680 rows=898 loops=1)
   -  Sort  (cost=35202.88..35497.96 rows=118033 width=142) (actual 
time=5119.356..5200.457 rows=352744 loops=1)
 Sort Key: es.sentonat, et.subject, ((COALESCE((createperson.vorname || 
' '::text), ''::text) || createperson.nachname)), (to_char(es.sentonat, 
'DD.MM.YY'::text)), ((COALESCE(c.name, 'keine Angabe'::character 
varying))::text), (1), (true), (false), (('emailsendings:'::text || 
(es.id)::text)), (NULL::text), es.id
 Sort Method:  quicksort  Memory: 198999kB
 -  Nested Loop Left Join  (cost=0.00..25259.29 rows=118033 width=142) 
(actual time=1.146..1896.382 rows=352744 loops=1)
   -  Nested Loop Left Join  (cost=0.00..2783.16 rows=302 
width=102) (actual time=1.127..32.577 rows=898 loops=1)
 -  Merge Join  (cost=0.00..2120.06 rows=302 width=86) 
(actual time=1.125..30.940 rows=898 loops=1)
   Merge Cond: (et.id = es.emailtemplate_id)
   -  Nested Loop Left Join  (cost=0.00..2224.95 
rows=277 width=74) (actual time=1.109..27.484 rows=830 loops=1)
 -  Index Scan using emailtemplates_pkey on 
emailtemplates et  (cost=0.00..460.71 rows=277 width=63) (actual 
time=1.097..20.541 rows=830 loops=1)
   Filter: 
f_record_visible_to_currentuser((et.*)::coretable)
 -  Index Scan using personen_pkey on personen 
createperson  (cost=0.00..6.36 rows=1 width=19) (actual time=0.006..0.006 rows=1 
loops=830)
   Index Cond: (createperson.id = 
et.personen_create_id)
   -  Index Scan using 
fki_emailsendings_emailtemplate_id_fkey on emailsendings es  (cost=0.00..49.83 
rows=905 width=20) (actual time=0.011..1.360 rows=898 loops=1)
 -  Index Scan using firmen_pkey on companies c  
(cost=0.00..2.18 rows=1 width=24) (actual time=0.001..0.001 rows=0 loops=898)
   Index Cond: (c.id = es.customers_id)
   -  Index Scan using fki_contacts_emailsendings_id_fkey on 
contacts ct  (cost=0.00..61.55 rows=561 width=44) (actual time=0.019..0.738 
rows=393 loops=898)
 Index Cond: (ct.emailsendings_id = es.id)
Total runtime: 5865.886 ms

I do have an index on es.sentonat. The sentonat-values are all unique, so I 
don't think I need indexes on all the fields I sort by. But then again, my 
understanding of this might be entirely wrong.

Depeszs' explain (http://explain.depesz.com/s/69O) tells me this:

node type   count   sum of times% of query
GroupAggregate  1   610.223 ms  10.5 %
Index Scan  5   690.503 ms  11.9 %
Merge Join  1   2.096 ms0.0 %
Nested Loop Left Join   3   1203.783 ms 20.7 %
Sort1   3304.075 ms 56.9 %

, so the sort appears to be the problem. Any pointers would be highly 
appreciated.



I recently had to diagnose and remedy a case such as this.

The short answer is to rewrite your query so you don't have to group by 
so many things. Collect your aggregates in a common table expression 
query (or possibly more than one, depends what you need) using the 
minimum non-aggregated columns to enable you to get correct results and 
then later decorate that with all the extra things you need such as 
constant columns and columns that are irrelevant to the aggregation.


This gets hard when queries are very complex, and harder still when the 
query is written by a

Re: [PERFORM] Reasons for choosing one execution plan over another?

2013-09-11 Thread Jeff Janes

On Wed, Sep 11, 2013 at 4:16 AM, Mikkel Lauritsen ren...@tala.dk wrote:

 Hi all,

 I have a number of Postgres 9.2.4 databases with the same schema but with
 slightly different contents, running on small servers that are basically
 alike (8-16 GB ram).

 When I run the same query on these databases it results in one of two
 different execution plans where one is much faster (appx. 50 times) than
 the other. Each database always gives the same plan, and vacuuming,
 updating statistics and reindexing doesn't seem to make any difference.

 Clearly the fast plan is preferred, but I haven't been able to identify
 any pattern (table sizes, tuning etc.) in why one plan is chosen over the
 other, so is there any way I can make Postgres tell me why it chooses to
 plan the way it does?


Are you sure the schemas are identical, including the existence of
identical indexes?

Also, using explain (analyze, buffers) gives more info than just explain
analyze

If you can get both systems to use the same plan, then you can compare the
cost estimates of each directly. But that is easier said than done.

You can temporarily drop an index used in the slow query but not the fast
one, to see what plan that comes up with:

begin; drop index x_a_id_idx; run query; rollback;

Cheers,

Jeff

Re: [PERFORM] Reasons for choosing one execution plan over another?

2013-09-11 Thread Giuseppe Broccolo


Il 11/09/2013 13:16, Mikkel Lauritsen ha scritto:

Hi all,

I have a number of Postgres 9.2.4 databases with the same schema but with
slightly different contents, running on small servers that are basically
alike (8-16 GB ram).

I think that your answer can be found in your statement slightly 
different contents. Planner choices query execution plans basing on 
statistics obtained during ANALYSE operations, including the autovacuum. 
In this way, Planner can decide which execution plan is the most 
suitable. Different content of values in your table could correspond to 
different statistical distribution of values in your columns and of rows 
in your tables, bringing to different choices of the Planner. Execution 
times can be very different, also by factor 10-100.


There is a parameter (stat_target) which set the selectivity of 
statistical samples of a table. Maybe, but it's not necessarily true, 
you could obtain more comparable execution times for the two execution 
plans changing it, probably increasing them.


 Giuseppe.

--
Giuseppe Broccolo - 2ndQuadrant Italy
PostgreSQL Training, Services and Support
giuseppe.brocc...@2ndquadrant.it | www.2ndQuadrant.it



--
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] Intermittent hangs with 9.2

2013-09-11 Thread Andres Freund

On 2013-09-11 07:43:35 -0500, Merlin Moncure wrote:
  I've been seeing a strange issue with our Postgres install for about a year
  now, and I was hoping someone might be able to help point me at the cause.
  At what seem like fairly random intervals Postgres will become unresponsive
  to the 3 application nodes it services. These periods tend to last for 10 -
  15 minutes before everything rights itself and the system goes back to
  normal.
 
  During these periods the server will report a spike in the outbound
  bandwidth (from about 1mbs to about 5mbs most recently), a huge spike in
  context switches / interrupts (normal peaks are around 2k/8k respectively,
  and during these periods they‘ve gone to 15k/22k), and a load average of
  100+. CPU usage stays relatively low, but it’s all system time reported,
  user time goes to zero. It doesn‘t seem to be disk related since we’re
  running with a shared_buffers setting of 24G, which will fit just about our
  entire database into memory, and the IO transactions reported by the server,
  as well as the disk reads reported by Postgres stay consistently low.
 
  We‘ve recently started tracking how long statements take to execute, and
  we’re seeing some really odd numbers. A simple delete by primary key, for
  example, from a table that contains about 280,000 rows, reportedly took
  18h59m46.900s. An update by primary key in that same table was reported as
  7d 17h 58m 30.415s. That table is frequently accessed, but obviously those
  numbers don't seem reasonable at all.
 
  Some other changes we've made to postgresql.conf:
 
  synchronous_commit = off
 
  maintenance_work_mem = 1GB
  wal_level = hot_standby
  wal_buffers = 16MB
 
  max_wal_senders = 10
 
  wal_keep_segments = 5000
 
  checkpoint_segments = 128
 
  checkpoint_timeout = 30min
 
  checkpoint_completion_target = 0.9
 
  max_connections = 500
 
  The server is a Dell Poweredge R900 with 4 Xeon E7430 processors, 48GB of
  RAM, running Cent OS 6.3.
 
  So far we‘ve tried disabling Transparent Huge Pages after I found a number
  of resources online that indicated similar interrupt/context switch issues,
  but it hasn’t resolve the problem. I managed to catch it happening once and
  run a perf which showed:
 
  +  41.40%   48154  postmaster  0x347ba9 f 0x347ba9
  +   9.55%   10956  postmaster  0x2dc820 f set_config_option
  +   8.64%9946  postmaster  0x5a3d4  f writeListPage
  +   5.75%6609  postmaster  0x5a2b0  f
  ginHeapTupleFastCollect
  +   2.68%3084  postmaster  0x192483 f
  build_implied_join_equality
  +   2.61%2990  postmaster  0x187a55 f build_paths_for_OR
  +   1.86%2131  postmaster  0x794aa  f get_collation_oid
  +   1.56%1822  postmaster  0x5a67e  f ginHeapTupleFastInsert
  +   1.53%1766  postmaster  0x1929bc f
  distribute_qual_to_rels
  +   1.33%1558  postmaster  0x249671 f cmp_numerics
 
  I‘m not sure what 0x347ba9 represents, or why it’s an address rather than a
  method name.

Try converting it to something more meaningful with addr2line, that
often has more sucess.

  That's about the sum of it. Any help would be greatly appreciated and if you
  want any more information about our setup, please feel free to ask.

 Reducing shared buffers to around 2gb will probably make the problem go away

That profile doesn't really look like one of the problem you are
referring to would look like.

Based on the profile I'd guess it's possible that you're seing problems
with GIN's fastupdate mechanism.
Try ALTER INDEX whatever SET (FASTUPDATE = OFF); VACUUM
whatever's_table for all gin indexes.

It's curious that set_config_option is so high in the profile... Any
chance you could recompile postgres with -fno-omit-frame-pointers in
CFLAGS? That would allow you to use perf -g. The performance price of
that usually is below 1% for postgres.

Greetings,

Andres Freund

-- 
 Andres Freund http://www.2ndQuadrant.com/
 PostgreSQL Development, 24x7 Support, Training  Services


-- 
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] Intermittent hangs with 9.2

2013-09-11 Thread Merlin Moncure

On Wed, Sep 11, 2013 at 12:17 PM, Andres Freund and...@2ndquadrant.com wrote:
 On 2013-09-11 07:43:35 -0500, Merlin Moncure wrote:
  I've been seeing a strange issue with our Postgres install for about a year
  now, and I was hoping someone might be able to help point me at the cause.
  At what seem like fairly random intervals Postgres will become unresponsive
  to the 3 application nodes it services. These periods tend to last for 10 -
  15 minutes before everything rights itself and the system goes back to
  normal.
 
  During these periods the server will report a spike in the outbound
  bandwidth (from about 1mbs to about 5mbs most recently), a huge spike in
  context switches / interrupts (normal peaks are around 2k/8k respectively,
  and during these periods they‘ve gone to 15k/22k), and a load average of
  100+. CPU usage stays relatively low, but it’s all system time reported,
  user time goes to zero. It doesn‘t seem to be disk related since we’re
  running with a shared_buffers setting of 24G, which will fit just about our
  entire database into memory, and the IO transactions reported by the 
  server,
  as well as the disk reads reported by Postgres stay consistently low.
 
  We‘ve recently started tracking how long statements take to execute, and
  we’re seeing some really odd numbers. A simple delete by primary key, for
  example, from a table that contains about 280,000 rows, reportedly took
  18h59m46.900s. An update by primary key in that same table was reported as
  7d 17h 58m 30.415s. That table is frequently accessed, but obviously those
  numbers don't seem reasonable at all.
 
  Some other changes we've made to postgresql.conf:
 
  synchronous_commit = off
 
  maintenance_work_mem = 1GB
  wal_level = hot_standby
  wal_buffers = 16MB
 
  max_wal_senders = 10
 
  wal_keep_segments = 5000
 
  checkpoint_segments = 128
 
  checkpoint_timeout = 30min
 
  checkpoint_completion_target = 0.9
 
  max_connections = 500
 
  The server is a Dell Poweredge R900 with 4 Xeon E7430 processors, 48GB of
  RAM, running Cent OS 6.3.
 
  So far we‘ve tried disabling Transparent Huge Pages after I found a number
  of resources online that indicated similar interrupt/context switch issues,
  but it hasn’t resolve the problem. I managed to catch it happening once and
  run a perf which showed:
 
  +  41.40%   48154  postmaster  0x347ba9 f 0x347ba9
  +   9.55%   10956  postmaster  0x2dc820 f set_config_option
  +   8.64%9946  postmaster  0x5a3d4  f writeListPage
  +   5.75%6609  postmaster  0x5a2b0  f
  ginHeapTupleFastCollect
  +   2.68%3084  postmaster  0x192483 f
  build_implied_join_equality
  +   2.61%2990  postmaster  0x187a55 f build_paths_for_OR
  +   1.86%2131  postmaster  0x794aa  f get_collation_oid
  +   1.56%1822  postmaster  0x5a67e  f 
  ginHeapTupleFastInsert
  +   1.53%1766  postmaster  0x1929bc f
  distribute_qual_to_rels
  +   1.33%1558  postmaster  0x249671 f cmp_numerics
 
  I‘m not sure what 0x347ba9 represents, or why it’s an address rather than a
  method name.

 Try converting it to something more meaningful with addr2line, that
 often has more sucess.

  That's about the sum of it. Any help would be greatly appreciated and if 
  you
  want any more information about our setup, please feel free to ask.

 Reducing shared buffers to around 2gb will probably make the problem go away

 That profile doesn't really look like one of the problem you are
 referring to would look like.

yup -- I think you're right.

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] Performance bug in prepared statement binding in 9.2?

2013-09-11 Thread Josh Berkus

All,

We've confirmed that this issue is caused by having long-running idle
transactions on the server.  When we disabled their queueing system
(which prodiced hour-long idle txns), the progressive slowness went away.

Why that should affect 9.X far more strongly than 8.4, I'm not sure
about.  Does that mean that 8.4 was unsafe, or that this is something
which *could* be fixed in later versions?

I'm also confused as to why this would affect BIND time rather than
EXECUTE time.

-- 
Josh Berkus
PostgreSQL Experts Inc.
http://pgexperts.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] Performance bug in prepared statement binding in 9.2?

2013-09-11 Thread Andrew Dunstan



On 09/11/2013 02:35 PM, Josh Berkus wrote:

All,

We've confirmed that this issue is caused by having long-running idle
transactions on the server.  When we disabled their queueing system
(which prodiced hour-long idle txns), the progressive slowness went away.

Why that should affect 9.X far more strongly than 8.4, I'm not sure
about.  Does that mean that 8.4 was unsafe, or that this is something
which *could* be fixed in later versions?

I'm also confused as to why this would affect BIND time rather than
EXECUTE time.




One thing that this made me wonder is why we don't have 
transaction_timeout, or maybe transaction_idle_timeout.


cheers

andrew


--
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] Reasons for choosing one execution plan over another?

2013-09-11 Thread Mikkel Lauritsen

Hi all,

On Wed, 11 Sep 2013 18:55:38 +0200, Giuseppe Broccolo
giuseppe.brocc...@2ndquadrant.it wrote:
 Il 11/09/2013 13:16, Mikkel Lauritsen ha scritto:
  Hi all,
 
  I have a number of Postgres 9.2.4 databases with the same schema but
  with slightly different contents, running on small servers that are
  basically alike (8-16 GB ram).

 I think that your answer can be found in your statement slightly 
 different contents.

Yup, that's what I've been thinking myself so far - it definitely doesn't
look as if I'm hitting a bug, and I've been through the schema so I feel
reasonably sure that I'm not missing an index.

In the example from my original mail the i and a tables are identical in
the two databases. The slow plan is chosen when the x and e tables contain
3.2M and 6.2M rows, the fast plan has 12.8M and 17M rows.

So - does anybody with enough insight in the planner know if it sounds
likely that it would choose the given plans in these two cases, or if
it's more likely that I have a tuning problem that leads to bad planning?

And if the different plans are to be expected, is there any way I can hint
at the planner to make it choose the fast plan in both cases?

FWIW if I do a very simple query like

SELECT e.id FROM e INNER JOIN x USING (id) WHERE e.h_id = 'foo';

on the two databases I also end up with two different plans (included
below). Here the execution time difference is much less pronounced (note
that the fast execution is on inferior hardware and with a much larger
result), but the way the join is executed is the same as in the initial
larger plans. Setting seq_page_cost and random_page_cost to the same
value makes the planner choose the fast plan in both cases, but unfortu-
nately that has no effect on my initial problem :-/

Best regards  thanks,
  Mikkel Lauritsen

---

Fast plan:

 Nested Loop  (cost=0.00..24523.00 rows=1138 width=39) (actual
time=2.546..33.858 rows=1192 loops=1)
   Buffers: shared hit=8991
   -  Index Scan using e_h_id_idx on e  (cost=0.00..6171.55 rows=1525
width=39) (actual time=0.053..1.211 rows=1857 loops=1)
 Index Cond: (healthtrack_id =
'-95674114670403931535179954575983492851'::text)
 Buffers: shared hit=350
   -  Index Only Scan using x_pkey on x  (cost=0.00..12.02 rows=1
width=39) (actual time=0.017..0.017 rows=1 loops=1857)
 Index Cond: (id = e.id)
 Heap Fetches: 1192
 Buffers: shared hit=8641
 Total runtime: 34.065 ms


Slow plan:

 Nested Loop  (cost=22.25..7020.66 rows=277 width=39) (actual
time=0.298..13.996 rows=228 loops=1)
   Buffers: shared hit=3173
   -  Bitmap Heap Scan on e  (cost=22.25..2093.50 rows=537 width=39)
(actual time=0.219..0.628 rows=697 loops=1)
 Recheck Cond: (healthtrack_id = 'foo'::text)
 Buffers: shared hit=152
 -  Bitmap Index Scan on e_h_id_idx  (cost=0.00..22.12 rows=537
width=0) (actual time=0.188..0.188 rows=697 loops=1)
   Index Cond: (h_id = 'foo'::text)
   Buffers: shared hit=9
   -  Index Only Scan using x_pkey on x  (cost=0.00..9.17 rows=1
width=39) (actual time=0.018..0.018 rows=0 loops=697)
 Index Cond: (id = e.id)
 Heap Fetches: 228
 Buffers: shared hit=3021
 Total runtime: 14.070 ms


-- 
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] Performance bug in prepared statement binding in 9.2?

2013-09-11 Thread Andres Freund

On 2013-09-11 15:06:23 -0400, Andrew Dunstan wrote:
 
 On 09/11/2013 02:35 PM, Josh Berkus wrote:
 All,
 
 We've confirmed that this issue is caused by having long-running idle
 transactions on the server.  When we disabled their queueing system
 (which prodiced hour-long idle txns), the progressive slowness went away.
 
 Why that should affect 9.X far more strongly than 8.4, I'm not sure
 about.  Does that mean that 8.4 was unsafe, or that this is something
 which *could* be fixed in later versions?
 
 I'm also confused as to why this would affect BIND time rather than
 EXECUTE time.
 
 
 
 One thing that this made me wonder is why we don't have transaction_timeout,
 or maybe transaction_idle_timeout.

Because it's harder than it sounds, at least if you want to support
idle-in-transactions. Note that we do not support pg_cancel_backend()
for those yet...

Also, I think it might lead to papering over actual issues with
applications leaving transactions open. I don't really see a valid
reason for an application needing cancelling of long idle transactions.

Greetings,

Andres Freund

-- 
 Andres Freund http://www.2ndQuadrant.com/
 PostgreSQL Development, 24x7 Support, Training  Services


-- 
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] Reasons for choosing one execution plan over another?

2013-09-11 Thread Gavin Flower


On 12/09/13 04:55, Giuseppe Broccolo wrote:

Il 11/09/2013 13:16, Mikkel Lauritsen ha scritto:

Hi all,

I have a number of Postgres 9.2.4 databases with the same schema but 
with

slightly different contents, running on small servers that are basically
alike (8-16 GB ram).

I think that your answer can be found in your statement slightly 
different contents. Planner choices query execution plans basing on 
statistics obtained during ANALYSE operations, including the 
autovacuum. In this way, Planner can decide which execution plan is 
the most suitable. Different content of values in your table could 
correspond to different statistical distribution of values in your 
columns and of rows in your tables, bringing to different choices of 
the Planner. Execution times can be very different, also by factor 
10-100.


There is a parameter (stat_target) which set the selectivity of 
statistical samples of a table. Maybe, but it's not necessarily true, 
you could obtain more comparable execution times for the two execution 
plans changing it, probably increasing them.


 Giuseppe.

Even identical content could lead to different plans, as the sampling is 
done randomly (or at least 'randomly' according to the documentation).

Re: [PERFORM] Performance bug in prepared statement binding in 9.2?

2013-09-11 Thread Andres Freund

On 2013-09-11 11:35:45 -0700, Josh Berkus wrote:
 All,
 
 We've confirmed that this issue is caused by having long-running idle
 transactions on the server.  When we disabled their queueing system
 (which prodiced hour-long idle txns), the progressive slowness went away.
 
 Why that should affect 9.X far more strongly than 8.4, I'm not sure
 about.  Does that mean that 8.4 was unsafe, or that this is something
 which *could* be fixed in later versions?

The explanation is in
http://archives.postgresql.org/message-id/20130910132133.GJ1024477%40alap2.anarazel.de

The referenced commit introduced a planner feature. Funnily you seem to
have been the trigger for it's introduction ;)

 I'm also confused as to why this would affect BIND time rather than
 EXECUTE time.

Because we're doing the histogram checks during planning and not during
execution.

Greetings,

Andres Freund

-- 
 Andres Freund http://www.2ndQuadrant.com/
 PostgreSQL Development, 24x7 Support, Training  Services


-- 
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] Performance bug in prepared statement binding in 9.2?

2013-09-11 Thread Josh Berkus


 The explanation is in
 http://archives.postgresql.org/message-id/20130910132133.GJ1024477%40alap2.anarazel.de
 
 The referenced commit introduced a planner feature. Funnily you seem to
 have been the trigger for it's introduction ;)

Oh, crap, the off the end of the index optimization?

It's the story of our lives: we can't optimize anything without
deoptimizing something else.  Dammit.

-- 
Josh Berkus
PostgreSQL Experts Inc.
http://pgexperts.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] Intermittent hangs with 9.2

Re: [PERFORM] Intermittent hangs with 9.2

[PERFORM] slow sort

[PERFORM] Reasons for choosing one execution plan over another?

Re: [PERFORM] Intermittent hangs with 9.2

Re: [PERFORM] slow sort

Re: [PERFORM] slow sort

Re: [PERFORM] slow sort

Re: [PERFORM] Reasons for choosing one execution plan over another?

Re: [PERFORM] Reasons for choosing one execution plan over another?

Re: [PERFORM] Intermittent hangs with 9.2

Re: [PERFORM] Intermittent hangs with 9.2

Re: [PERFORM] Performance bug in prepared statement binding in 9.2?

Re: [PERFORM] Performance bug in prepared statement binding in 9.2?

Re: [PERFORM] Reasons for choosing one execution plan over another?

Re: [PERFORM] Performance bug in prepared statement binding in 9.2?

Re: [PERFORM] Reasons for choosing one execution plan over another?

Re: [PERFORM] Performance bug in prepared statement binding in 9.2?

Re: [PERFORM] Performance bug in prepared statement binding in 9.2?

19 matches

Site Navigation

Mail list logo

Footer information