Re: pg_dump 3 times as slow after 8.4 -> 9.5 upgrade

[Matthew Hall]

> On Nov 21, 2017, at 10:18 PM, Henrik Cednert (Filmlance) 
>  wrote:
> 
> WHat's the normal way to deal with compression? Dump uncompressed and use 
> something that threads better to compress the dump?

I would say most likely your zlib is screwed up somehow, like maybe it didn't 
get optimized right by the C compiler or something else sucks w/ the 
compression settings. The CPU should easily blast away at that faster than 
disks can read.

I did do some studies of this previously some years ago, and I found gzip -6 
offered the best ratio between size reduction and CPU time out of a very wide 
range of formats, but at the time xz was also not yet available.

If I were you I would first pipe the uncompressed output through a separate 
compression command, then you can experiment with the flags and threads, and 
you already get another separate process for the kernel to put on other CPUs as 
an automatic bonus for multi-core with minimal work.

After that, xz is GNU standard now and has xz -T for cranking up some threads, 
with little extra effort for the user. But it can be kind of slow so probably 
need to lower the compression level somewhat depending a bit on some time 
testing. I would try on some medium sized DB table, like a bit over the size of 
system RAM, instead of dumping this great big DB, in order to benchmark a 
couple times until it looks happy.

Matthew

Re: pg_dump 3 times as slow after 8.4 -> 9.5 upgrade

[Henrik Cednert (Filmlance)]

Hello

I've ran it with all the different compression levels on one of the smaller 
db's now. And not sending any flags to it see is, as I've seen hinted on some 
page on internet, same as level 6.

I do, somewhat, share the opinion that something is up with zlib. But at the 
same time I haven't touch it since the 8.4 installation so it's a mystery how 
it could've failed on its own. The only thing performed was an upgrade from 8.4 
to 9.5. But yes, I can not really say exactly what that upgrade touched and 
what it didn't touch. Will investigate further.


COMPRESSION LEVEL: 0
FILE SIZE: 6205982696
real 0m38.218s
user 0m3.558s
sys 0m17.309s


COMPRESSION LEVEL: 1
FILE SIZE: 1391475419
real 4m3.725s
user 3m54.132s
sys 0m5.565s


COMPRESSION LEVEL: 2
FILE SIZE: 1344563403
real 4m18.574s
user 4m9.466s
sys 0m5.417s


COMPRESSION LEVEL: 3
FILE SIZE: 1267601394
real 5m23.373s
user 5m14.339s
sys 0m5.462s


COMPRESSION LEVEL: 4
FILE SIZE: 1241632684
real 6m19.501s
user 6m10.148s
sys 0m5.655s


COMPRESSION LEVEL: 5
FILE SIZE: 1178377949
real 9m18.449s
user 9m9.733s
sys 0m5.169s


COMPRESSION LEVEL: 6
FILE SIZE: 1137727582
real 13m28.424s
user 13m19.842s
sys 0m5.036s


COMPRESSION LEVEL: 7
FILE SIZE: 1126257786
real 16m39.392s
user 16m30.094s
sys 0m5.724s


COMPRESSION LEVEL: 8
FILE SIZE: 804793
real 30m37.135s
user 30m26.785s
sys 0m6.660s


COMPRESSION LEVEL: 9
FILE SIZE: 1112194596
real 33m40.325s
user 33m27.122s
sys 0m6.498s


COMPRESSION LEVEL AT DEFAULT NO FLAG PASSED TO 'pg_dump'
FILE SIZE: 1140261276
real 13m18.178s
user 13m9.417s
sys 0m5.242s


--
Henrik Cednert
cto | compositor

Filmlance International
mobile [ + 46 (0)704 71 89 54 ]
skype  [ cednert ]

On 22 Nov 2017, at 11:32, Matthew Hall 
mailto:mh...@mhcomputing.net>> wrote:


On Nov 21, 2017, at 10:18 PM, Henrik Cednert (Filmlance) 
mailto:henrik.cedn...@filmlance.se>> wrote:

WHat's the normal way to deal with compression? Dump uncompressed and use 
something that threads better to compress the dump?

I would say most likely your zlib is screwed up somehow, like maybe it didn't 
get optimized right by the C compiler or something else sucks w/ the 
compression settings. The CPU should easily blast away at that faster than 
disks can read.

I did do some studies of this previously some years ago, and I found gzip -6 
offered the best ratio between size reduction and CPU time out of a very wide 
range of formats, but at the time xz was also not yet available.

If I were you I would first pipe the uncompressed output through a separate 
compression command, then you can experiment with the flags and threads, and 
you already get another separate process for the kernel to put on other CPUs as 
an automatic bonus for multi-core with minimal work.

After that, xz is GNU standard now and has xz -T for cranking up some threads, 
with little extra effort for the user. But it can be kind of slow so probably 
need to lower the compression level somewhat depending a bit on some time 
testing. I would try on some medium sized DB table, like a bit over the size of 
system RAM, instead of dumping this great big DB, in order to benchmark a 
couple times until it looks happy.

Matthew

Re: pg_dump 3 times as slow after 8.4 -> 9.5 upgrade

[Henrik Cednert (Filmlance)]

When investigating the zlib lead I looked at 8.4 installation and 9.5 
installation. 9.5 includes zlib.h (/Library/PostgreSQL//9.5/include/zlib.h), 
but 8.4 doesn't. But that's a header file and I have no idea how that really 
works and if that's the one used by pgres9.5 or not. The version in it says 
1.2.8 and that's what the Instruments are showing when I monitor pg_dump while 
running.

Guess I'll have to install instruments in a dev env and do a pg_dump with 8.4 
to see the difference. Tedious. =/

--
Henrik Cednert
cto | compositor

Filmlance International
mobile [ + 46 (0)704 71 89 54 ]
skype  [ cednert ]

On 22 Nov 2017, at 13:17, Henrik Cednert (Filmlance) 
mailto:henrik.cedn...@filmlance.se>> wrote:


This sender failed our fraud detection checks and may not be who they appear to 
be. Learn about spoofing
Feedback
Hello

I've ran it with all the different compression levels on one of the smaller 
db's now. And not sending any flags to it see is, as I've seen hinted on some 
page on internet, same as level 6.

I do, somewhat, share the opinion that something is up with zlib. But at the 
same time I haven't touch it since the 8.4 installation so it's a mystery how 
it could've failed on its own. The only thing performed was an upgrade from 8.4 
to 9.5. But yes, I can not really say exactly what that upgrade touched and 
what it didn't touch. Will investigate further.


COMPRESSION LEVEL: 0
FILE SIZE: 6205982696
real 0m38.218s
user 0m3.558s
sys 0m17.309s


COMPRESSION LEVEL: 1
FILE SIZE: 1391475419
real 4m3.725s
user 3m54.132s
sys 0m5.565s


COMPRESSION LEVEL: 2
FILE SIZE: 1344563403
real 4m18.574s
user 4m9.466s
sys 0m5.417s


COMPRESSION LEVEL: 3
FILE SIZE: 1267601394
real 5m23.373s
user 5m14.339s
sys 0m5.462s


COMPRESSION LEVEL: 4
FILE SIZE: 1241632684
real 6m19.501s
user 6m10.148s
sys 0m5.655s


COMPRESSION LEVEL: 5
FILE SIZE: 1178377949
real 9m18.449s
user 9m9.733s
sys 0m5.169s


COMPRESSION LEVEL: 6
FILE SIZE: 1137727582
real 13m28.424s
user 13m19.842s
sys 0m5.036s


COMPRESSION LEVEL: 7
FILE SIZE: 1126257786
real 16m39.392s
user 16m30.094s
sys 0m5.724s


COMPRESSION LEVEL: 8
FILE SIZE: 804793
real 30m37.135s
user 30m26.785s
sys 0m6.660s


COMPRESSION LEVEL: 9
FILE SIZE: 1112194596
real 33m40.325s
user 33m27.122s
sys 0m6.498s


COMPRESSION LEVEL AT DEFAULT NO FLAG PASSED TO 'pg_dump'
FILE SIZE: 1140261276
real 13m18.178s
user 13m9.417s
sys 0m5.242s


--
Henrik Cednert
cto | compositor

Filmlance International
mobile [ + 46 (0)704 71 89 54 ]
skype  [ cednert ]

On 22 Nov 2017, at 11:32, Matthew Hall 
mailto:mh...@mhcomputing.net>> wrote:


On Nov 21, 2017, at 10:18 PM, Henrik Cednert (Filmlance) 
mailto:henrik.cedn...@filmlance.se>> wrote:

WHat's the normal way to deal with compression? Dump uncompressed and use 
something that threads better to compress the dump?

I would say most likely your zlib is screwed up somehow, like maybe it didn't 
get optimized right by the C compiler or something else sucks w/ the 
compression settings. The CPU should easily blast away at that faster than 
disks can read.

I did do some studies of this previously some years ago, and I found gzip -6 
offered the best ratio between size reduction and CPU time out of a very wide 
range of formats, but at the time xz was also not yet available.

If I were you I would first pipe the uncompressed output through a separate 
compression command, then you can experiment with the flags and threads, and 
you already get another separate process for the kernel to put on other CPUs as 
an automatic bonus for multi-core with minimal work.

After that, xz is GNU standard now and has xz -T for cranking up some threads, 
with little extra effort for the user. But it can be kind of slow so probably 
need to lower the compression level somewhat depending a bit on some time 
testing. I would try on some medium sized DB table, like a bit over the size of 
system RAM, instead of dumping this great big DB, in order to benchmark a 
couple times until it looks happy.

Matthew

Query became very slow after 9.6 -> 10 upgrade

[Dmitry Shalashov]

Hi!

I've seen few letters like this on mailing list and for some reason thought
that probably it won't happen to us, but here I am lol.

It's "nestloop hits again" situation.

I'll try to provide plan from 9.6 later, but right now I have only plan
from 10.1.

Query: https://pastebin.com/9b953tT7
It was running under 3 seconds (it's our default timeout) and now it runs
for 12 minutes.

\d adroom: https://pastebin.com/vBrPGtxT (3800 rows)
\d adroom_stat: https://pastebin.com/CkBArCC9 (47mln rows, 1.5mln satisfy
condition on day column)
\d domains: https://pastebin.com/65hk7YCm (73000 rows)

All three tables are analyzed.

EXPLAIN ANALYZE: https://pastebin.com/PenHEgf0
EXPLAIN ANALYZE with nestloop off: https://pastebin.com/zX35CPCV (0.8s)

Regarding server parameters - it's a mighty beast with 2x E5-2630 v3, 192Gb
of RAM and two very, very fast NVME server class SSD's in RAID1.

What can I do with it?


Also maybe this will be useful:

1st query, runs under 1ms
select title, id, groups->0->>'provider' provider, domain_ids from adroom
where groups->0->>'provider' ~ '^target_mail_ru' and not is_paused and
current_timestamp between start_ts and stop_ts

2nd query that uses 1st one, runs under 3 ms
select distinct unnest(domain_ids) FROM (select title, id,
groups->0->>'provider' provider, domain_ids from adroom where
groups->0->>'provider' ~ '^target_mail_ru' and not is_paused and
current_timestamp between start_ts and stop_ts) t1

3rd query which returns 1.5mln rows, runs in about 0.6s
SELECT adroom_id, domain_id, shows, clicks FROM adroom_stat WHERE day
between date_trunc('day', current_timestamp - interval '1 week') and
date_trunc('day', current_timestamp)

BUT if I'll add to 3rd query one additional condition, which is basically
2nd query, it will ran same 12 minutes:
SELECT adroom_id, domain_id, shows, clicks FROM adroom_stat WHERE day
between date_trunc('day', current_timestamp - interval '1 week') and
date_trunc('day', current_timestamp) AND domain_id IN (select distinct
unnest(domain_ids) FROM (select title, id, groups->0->>'provider' provider,
domain_ids from adroom where groups->0->>'provider' ~ '^target_mail_ru' and
not is_paused and current_timestamp between start_ts and stop_ts) t1)

Plan of last query:
 Nested Loop  (cost=88.63..25617.31 rows=491 width=16) (actual
time=3.512..733248.271 rows=1442797 loops=1)
   ->  HashAggregate  (cost=88.06..88.07 rows=1 width=4) (actual
time=3.380..13.561 rows=3043 loops=1)
 Group Key: (unnest(adroom.domain_ids))
 ->  HashAggregate  (cost=88.03..88.04 rows=1 width=4) (actual
time=2.199..2.607 rows=3043 loops=1)
   Group Key: unnest(adroom.domain_ids)
   ->  ProjectSet  (cost=0.28..87.78 rows=100 width=4) (actual
time=0.701..1.339 rows=3173 loops=1)
 ->  Index Scan using adroom_active_idx on adroom
(cost=0.28..87.27 rows=1 width=167) (actual time=0.688..1.040 rows=4
loops=1)
   Index Cond: ((CURRENT_TIMESTAMP >= start_ts) AND
(CURRENT_TIMESTAMP <= stop_ts))
   Filter: (((groups -> 0) ->> 'provider'::text) ~
'^target_mail_ru'::text)
   Rows Removed by Filter: 41
   ->  Index Scan using
adroom_stat_day_adroom_id_domain_id_url_id_is_wlabp_idx on adroom_stat
(cost=0.58..25524.33 rows=491 width=16) (actual time=104.847..240.846
rows=474 loops=3043)
 Index Cond: ((day >= date_trunc('day'::text, (CURRENT_TIMESTAMP -
'7 days'::interval))) AND (day <= date_trunc('day'::text,
CURRENT_TIMESTAMP)) AND (domain_id = (unnest(adroom.domain_ids
 Planning time: 1.580 ms
 Execution time: 71.740 ms

Dmitry Shalashov, relap.io & surfingbird.ru

RE: Query became very slow after 9.6 -> 10 upgrade

[Alex Ignatov]

Hello!

What about :

select name,setting from pg_settings where name like '%_cost';

 

--

Alex Ignatov 
Postgres Professional:   http://www.postgrespro.com 
The Russian Postgres Company

 

 

From: Dmitry Shalashov [mailto:skau...@gmail.com] 
Sent: Wednesday, November 22, 2017 5:14 PM
To: pgsql-performa...@postgresql.org
Subject: Query became very slow after 9.6 -> 10 upgrade

 

Hi!

 

I've seen few letters like this on mailing list and for some reason thought 
that probably it won't happen to us, but here I am lol.

 

It's "nestloop hits again" situation.

 

I'll try to provide plan from 9.6 later, but right now I have only plan from 
10.1.

 

Query: https://pastebin.com/9b953tT7

It was running under 3 seconds (it's our default timeout) and now it runs for 
12 minutes.

 

\d adroom: https://pastebin.com/vBrPGtxT (3800 rows)

\d adroom_stat: https://pastebin.com/CkBArCC9 (47mln rows, 1.5mln satisfy 
condition on day column)

\d domains: https://pastebin.com/65hk7YCm (73000 rows)

 

All three tables are analyzed.

 

EXPLAIN ANALYZE: https://pastebin.com/PenHEgf0

EXPLAIN ANALYZE with nestloop off: https://pastebin.com/zX35CPCV (0.8s)

 

Regarding server parameters - it's a mighty beast with 2x E5-2630 v3, 192Gb of 
RAM and two very, very fast NVME server class SSD's in RAID1.

 

What can I do with it?

 

 

Also maybe this will be useful:

 

1st query, runs under 1ms

select title, id, groups->0->>'provider' provider, domain_ids from adroom where 
groups->0->>'provider' ~ '^target_mail_ru' and not is_paused and 
current_timestamp between start_ts and stop_ts

 

2nd query that uses 1st one, runs under 3 ms

select distinct unnest(domain_ids) FROM (select title, id, 
groups->0->>'provider' provider, domain_ids from adroom where 
groups->0->>'provider' ~ '^target_mail_ru' and not is_paused and 
current_timestamp between start_ts and stop_ts) t1

 

3rd query which returns 1.5mln rows, runs in about 0.6s

SELECT adroom_id, domain_id, shows, clicks FROM adroom_stat WHERE day between 
date_trunc('day', current_timestamp - interval '1 week') and date_trunc('day', 
current_timestamp)

 

BUT if I'll add to 3rd query one additional condition, which is basically 2nd 
query, it will ran same 12 minutes:

SELECT adroom_id, domain_id, shows, clicks FROM adroom_stat WHERE day between 
date_trunc('day', current_timestamp - interval '1 week') and date_trunc('day', 
current_timestamp) AND domain_id IN (select distinct unnest(domain_ids) FROM 
(select title, id, groups->0->>'provider' provider, domain_ids from adroom 
where groups->0->>'provider' ~ '^target_mail_ru' and not is_paused and 
current_timestamp between start_ts and stop_ts) t1)

 

Plan of last query:

 Nested Loop  (cost=88.63..25617.31 rows=491 width=16) (actual 
time=3.512..733248.271 rows=1442797 loops=1)

   ->  HashAggregate  (cost=88.06..88.07 rows=1 width=4) (actual 
time=3.380..13.561 rows=3043 loops=1)

 Group Key: (unnest(adroom.domain_ids))

 ->  HashAggregate  (cost=88.03..88.04 rows=1 width=4) (actual 
time=2.199..2.607 rows=3043 loops=1)

   Group Key: unnest(adroom.domain_ids)

   ->  ProjectSet  (cost=0.28..87.78 rows=100 width=4) (actual 
time=0.701..1.339 rows=3173 loops=1)

 ->  Index Scan using adroom_active_idx on adroom  
(cost=0.28..87.27 rows=1 width=167) (actual time=0.688..1.040 rows=4 loops=1)

   Index Cond: ((CURRENT_TIMESTAMP >= start_ts) AND 
(CURRENT_TIMESTAMP <= stop_ts))

   Filter: (((groups -> 0) ->> 'provider'::text) ~ 
'^target_mail_ru'::text)

   Rows Removed by Filter: 41

   ->  Index Scan using adroom_stat_day_adroom_id_domain_id_url_id_is_wlabp_idx 
on adroom_stat  (cost=0.58..25524.33 rows=491 width=16) (actual 
time=104.847..240.846 rows=474 loops=3043)

 Index Cond: ((day >= date_trunc('day'::text, (CURRENT_TIMESTAMP - '7 
days'::interval))) AND (day <= date_trunc('day'::text, CURRENT_TIMESTAMP)) AND 
(domain_id = (unnest(adroom.domain_ids

 Planning time: 1.580 ms

 Execution time: 71.740 ms

 

Dmitry Shalashov,   relap.io &   
surfingbird.ru

Re: Query became very slow after 9.6 -> 10 upgrade

[Dmitry Shalashov]

Sure, here it goes:

 name | setting
--+-
 cpu_index_tuple_cost | 0.005
 cpu_operator_cost| 0.0025
 cpu_tuple_cost   | 0.01
 parallel_setup_cost  | 1000
 parallel_tuple_cost  | 0.1
 random_page_cost | 1
 seq_page_cost| 1


Dmitry Shalashov, relap.io & surfingbird.ru

2017-11-22 17:24 GMT+03:00 Alex Ignatov :

> Hello!
>
> What about :
>
> select name,setting from pg_settings where name like '%_cost';
>
>
>
> --
>
> Alex Ignatov
> Postgres Professional: http://www.postgrespro.com
> The Russian Postgres Company
>
>
>
>
>
> *From:* Dmitry Shalashov [mailto:skau...@gmail.com]
> *Sent:* Wednesday, November 22, 2017 5:14 PM
> *To:* pgsql-performa...@postgresql.org
> *Subject:* Query became very slow after 9.6 -> 10 upgrade
>
>
>
> Hi!
>
>
>
> I've seen few letters like this on mailing list and for some reason
> thought that probably it won't happen to us, but here I am lol.
>
>
>
> It's "nestloop hits again" situation.
>
>
>
> I'll try to provide plan from 9.6 later, but right now I have only plan
> from 10.1.
>
>
>
> Query: https://pastebin.com/9b953tT7
>
> It was running under 3 seconds (it's our default timeout) and now it runs
> for 12 minutes.
>
>
>
> \d adroom: https://pastebin.com/vBrPGtxT (3800 rows)
>
> \d adroom_stat: https://pastebin.com/CkBArCC9 (47mln rows, 1.5mln satisfy
> condition on day column)
>
> \d domains: https://pastebin.com/65hk7YCm (73000 rows)
>
>
>
> All three tables are analyzed.
>
>
>
> EXPLAIN ANALYZE: https://pastebin.com/PenHEgf0
>
> EXPLAIN ANALYZE with nestloop off: https://pastebin.com/zX35CPCV (0.8s)
>
>
>
> Regarding server parameters - it's a mighty beast with 2x E5-2630 v3,
> 192Gb of RAM and two very, very fast NVME server class SSD's in RAID1.
>
>
>
> What can I do with it?
>
>
>
>
>
> Also maybe this will be useful:
>
>
>
> 1st query, runs under 1ms
>
> select title, id, groups->0->>'provider' provider, domain_ids from adroom
> where groups->0->>'provider' ~ '^target_mail_ru' and not is_paused and
> current_timestamp between start_ts and stop_ts
>
>
>
> 2nd query that uses 1st one, runs under 3 ms
>
> select distinct unnest(domain_ids) FROM (select title, id,
> groups->0->>'provider' provider, domain_ids from adroom where
> groups->0->>'provider' ~ '^target_mail_ru' and not is_paused and
> current_timestamp between start_ts and stop_ts) t1
>
>
>
> 3rd query which returns 1.5mln rows, runs in about 0.6s
>
> SELECT adroom_id, domain_id, shows, clicks FROM adroom_stat WHERE day
> between date_trunc('day', current_timestamp - interval '1 week') and
> date_trunc('day', current_timestamp)
>
>
>
> BUT if I'll add to 3rd query one additional condition, which is basically
> 2nd query, it will ran same 12 minutes:
>
> SELECT adroom_id, domain_id, shows, clicks FROM adroom_stat WHERE day
> between date_trunc('day', current_timestamp - interval '1 week') and
> date_trunc('day', current_timestamp) AND domain_id IN (select distinct
> unnest(domain_ids) FROM (select title, id, groups->0->>'provider' provider,
> domain_ids from adroom where groups->0->>'provider' ~ '^target_mail_ru' and
> not is_paused and current_timestamp between start_ts and stop_ts) t1)
>
>
>
> Plan of last query:
>
>  Nested Loop  (cost=88.63..25617.31 rows=491 width=16) (actual
> time=3.512..733248.271 rows=1442797 loops=1)
>
>->  HashAggregate  (cost=88.06..88.07 rows=1 width=4) (actual
> time=3.380..13.561 rows=3043 loops=1)
>
>  Group Key: (unnest(adroom.domain_ids))
>
>  ->  HashAggregate  (cost=88.03..88.04 rows=1 width=4) (actual
> time=2.199..2.607 rows=3043 loops=1)
>
>Group Key: unnest(adroom.domain_ids)
>
>->  ProjectSet  (cost=0.28..87.78 rows=100 width=4) (actual
> time=0.701..1.339 rows=3173 loops=1)
>
>  ->  Index Scan using adroom_active_idx on adroom
> (cost=0.28..87.27 rows=1 width=167) (actual time=0.688..1.040 rows=4
> loops=1)
>
>Index Cond: ((CURRENT_TIMESTAMP >= start_ts)
> AND (CURRENT_TIMESTAMP <= stop_ts))
>
>Filter: (((groups -> 0) ->> 'provider'::text) ~
> '^target_mail_ru'::text)
>
>Rows Removed by Filter: 41
>
>->  Index Scan using 
> adroom_stat_day_adroom_id_domain_id_url_id_is_wlabp_idx
> on adroom_stat  (cost=0.58..25524.33 rows=491 width=16) (actual
> time=104.847..240.846 rows=474 loops=3043)
>
>  Index Cond: ((day >= date_trunc('day'::text, (CURRENT_TIMESTAMP -
> '7 days'::interval))) AND (day <= date_trunc('day'::text,
> CURRENT_TIMESTAMP)) AND (domain_id = (unnest(adroom.domain_ids
>
>  Planning time: 1.580 ms
>
>  Execution time: 71.740 ms
>
>
>
> Dmitry Shalashov, relap.io & surfingbird.ru
>

Bad estimates

[Artur Zając]

Hi,

We have table created like this:

CREATE TABLE xyz AS SELECT generate_series(1,1000,1) AS gs;

Now:

db=# explain analyze select * from xyz where gs&1=1;

  QUERY PLAN

---
 Seq Scan on xyz  (cost=0.00..260815.38 rows=68920 width=4) (actual
time=0.044..2959.728 rows=500 loops=1)
   Filter: ((gs & 1) = 1)
   Rows Removed by Filter: 500
 Planning time: 0.133 ms
 Execution time: 3340.886 ms
(5 rows)

And after adding additional clause to WHERE:

db=# explain analyze select * from xyz where gs&1=1 and gs&2=2;

 QUERY PLAN

-
 Seq Scan on xyz  (cost=0.00..329735.50 rows=345 width=4) (actual
time=0.045..3010.430 rows=250 loops=1)
   Filter: (((gs & 1) = 1) AND ((gs & 2) = 2))
   Rows Removed by Filter: 750
 Planning time: 0.106 ms
 Execution time: 3176.355 ms
(5 rows)

And one more clause:

newrr=# explain analyze select * from xyz where gs&1=1 and gs&2=2 and
gs&4=4;
QUERY PLAN

---
 Seq Scan on xyz  (cost=0.00..398655.62 rows=2 width=4) (actual
time=0.052..3329.422 rows=125 loops=1)
   Filter: (((gs & 1) = 1) AND ((gs & 2) = 2) AND ((gs & 4) = 4))
   Rows Removed by Filter: 875
 Planning time: 0.119 ms
 Execution time: 3415.839 ms
(5 rows)

As we can see estimates differs significally from the actual records count -
only three clauses are reducing estimated number of records from 1000 to
2.

I noticed that each additional clause reduces the number about 200 times and
define DEFAULT_NUM_DISTINCT is responsible for this behaviur.

I think that this variable should be lower or maybe estimation using
DEFAULT_NUM_DISTTINCT should be done once per table.

Artur Zajac

RE: Query became very slow after 9.6 -> 10 upgrade

[Alex Ignatov]

Here is my select right after initdb:

 

postgres=# select name,setting from pg_settings where name like '%_cost';

 name | setting

--+-

cpu_index_tuple_cost | 0.005

cpu_operator_cost| 0.0025

cpu_tuple_cost   | 0.01

parallel_setup_cost  | 1000

parallel_tuple_cost  | 0.1

random_page_cost | 4

seq_page_cost| 1

 

 

Can you generate plan with random_page_cost = 4?

 

 

--

Alex Ignatov 
Postgres Professional:   http://www.postgrespro.com 
The Russian Postgres Company

 

From: Dmitry Shalashov [mailto:skau...@gmail.com] 
Sent: Wednesday, November 22, 2017 5:29 PM
To: Alex Ignatov 
Cc: pgsql-performa...@postgresql.org
Subject: Re: Query became very slow after 9.6 -> 10 upgrade

 

Sure, here it goes:

 

 name | setting

--+-

 cpu_index_tuple_cost | 0.005

 cpu_operator_cost| 0.0025

 cpu_tuple_cost   | 0.01

 parallel_setup_cost  | 1000

 parallel_tuple_cost  | 0.1

 random_page_cost | 1

 seq_page_cost| 1




 

Dmitry Shalashov,   relap.io &   
surfingbird.ru

 

2017-11-22 17:24 GMT+03:00 Alex Ignatov mailto:a.igna...@postgrespro.ru> >:

Hello!

What about :

select name,setting from pg_settings where name like '%_cost';

 

--

Alex Ignatov 
Postgres Professional:   http://www.postgrespro.com 
The Russian Postgres Company

 

 

From: Dmitry Shalashov [mailto:skau...@gmail.com  ] 
Sent: Wednesday, November 22, 2017 5:14 PM
To: pgsql-performa...@postgresql.org  
Subject: Query became very slow after 9.6 -> 10 upgrade

 

Hi!

 

I've seen few letters like this on mailing list and for some reason thought 
that probably it won't happen to us, but here I am lol.

 

It's "nestloop hits again" situation.

 

I'll try to provide plan from 9.6 later, but right now I have only plan from 
10.1.

 

Query: https://pastebin.com/9b953tT7

It was running under 3 seconds (it's our default timeout) and now it runs for 
12 minutes.

 

\d adroom: https://pastebin.com/vBrPGtxT (3800 rows)

\d adroom_stat: https://pastebin.com/CkBArCC9 (47mln rows, 1.5mln satisfy 
condition on day column)

\d domains: https://pastebin.com/65hk7YCm (73000 rows)

 

All three tables are analyzed.

 

EXPLAIN ANALYZE: https://pastebin.com/PenHEgf0

EXPLAIN ANALYZE with nestloop off: https://pastebin.com/zX35CPCV (0.8s)

 

Regarding server parameters - it's a mighty beast with 2x E5-2630 v3, 192Gb of 
RAM and two very, very fast NVME server class SSD's in RAID1.

 

What can I do with it?

 

 

Also maybe this will be useful:

 

1st query, runs under 1ms

select title, id, groups->0->>'provider' provider, domain_ids from adroom where 
groups->0->>'provider' ~ '^target_mail_ru' and not is_paused and 
current_timestamp between start_ts and stop_ts

 

2nd query that uses 1st one, runs under 3 ms

select distinct unnest(domain_ids) FROM (select title, id, 
groups->0->>'provider' provider, domain_ids from adroom where 
groups->0->>'provider' ~ '^target_mail_ru' and not is_paused and 
current_timestamp between start_ts and stop_ts) t1

 

3rd query which returns 1.5mln rows, runs in about 0.6s

SELECT adroom_id, domain_id, shows, clicks FROM adroom_stat WHERE day between 
date_trunc('day', current_timestamp - interval '1 week') and date_trunc('day', 
current_timestamp)

 

BUT if I'll add to 3rd query one additional condition, which is basically 2nd 
query, it will ran same 12 minutes:

SELECT adroom_id, domain_id, shows, clicks FROM adroom_stat WHERE day between 
date_trunc('day', current_timestamp - interval '1 week') and date_trunc('day', 
current_timestamp) AND domain_id IN (select distinct unnest(domain_ids) FROM 
(select title, id, groups->0->>'provider' provider, domain_ids from adroom 
where groups->0->>'provider' ~ '^target_mail_ru' and not is_paused and 
current_timestamp between start_ts and stop_ts) t1)

 

Plan of last query:

 Nested Loop  (cost=88.63..25617.31 rows=491 width=16) (actual 
time=3.512..733248.271 rows=1442797 loops=1)

   ->  HashAggregate  (cost=88.06..88.07 rows=1 width=4) (actual 
time=3.380..13.561 rows=3043 loops=1)

 Group Key: (unnest(adroom.domain_ids))

 ->  HashAggregate  (cost=88.03..88.04 rows=1 width=4) (actual 
time=2.199..2.607 rows=3043 loops=1)

   Group Key: unnest(adroom.domain_ids)

   ->  ProjectSet  (cost=0.28..87.78 rows=100 width=4) (actual 
time=0.701..1.339 rows=3173 loops=1)

 ->  Index Scan using adroom_active_idx on adroom  
(cost=0.28..87.27 rows=1 width=167) (actual time=0.688..1.040 rows=4 loops=1)

   Index Cond: ((CURRENT_TIMESTAMP >= start_ts) AND 
(CURRENT_TIMESTAMP <= stop_ts))

   Filter: (((groups -> 0) ->> 'provider'::text) ~ 
'^target_mail_ru'::text)

Re: Bad estimates

[Don Seiler]

I'm assuming you never analyzed the table after creation & data load? What
does this show you:

select * from pg_stat_all_tables where relname='xyz';

Don.

-- 
Don Seiler
www.seiler.us

Re: Query became very slow after 9.6 -> 10 upgrade

[Dmitry Shalashov]

I believe that with SSD disks random_page_cost should be very cheap, but
here you go (I decided to settle on EXPLAIN without ANALYZE this time, is
this is good enough?):

 Sort  (cost=18410.26..18410.27 rows=1 width=63)
   Sort Key: (sum(st.shows)) DESC
   CTE a
 ->  Index Scan using adroom_active_idx on adroom  (cost=0.28..301.85
rows=1 width=233)
   Index Cond: ((CURRENT_TIMESTAMP >= start_ts) AND
(CURRENT_TIMESTAMP <= stop_ts))
   Filter: (((groups -> 0) ->> 'provider'::text) ~
'^target_mail_ru'::text)
   CTE b
 ->  HashAggregate  (cost=1.28..1.29 rows=1 width=40)
   Group Key: a.provider, a.id, unnest(a.domain_ids)
   ->  ProjectSet  (cost=0.00..0.53 rows=100 width=40)
 ->  CTE Scan on a  (cost=0.00..0.02 rows=1 width=68)
   ->  GroupAggregate  (cost=18107.09..18107.11 rows=1 width=63)
 Group Key: b.provider, d.domain
 ->  Sort  (cost=18107.09..18107.09 rows=1 width=55)
   Sort Key: b.provider, d.domain
   ->  Nested Loop  (cost=1.00..18107.08 rows=1 width=55)
 Join Filter: ((b.id = st.adroom_id) AND (b.domain_id =
st.domain_id))
 ->  Nested Loop  (cost=0.42..8.46 rows=1 width=59)
   ->  CTE Scan on b  (cost=0.00..0.02 rows=1
width=40)
   ->  Index Scan using domains_pkey on domains d
(cost=0.42..8.44 rows=1 width=19)
 Index Cond: (id = b.domain_id)
 ->  Index Scan using
adroom_stat_day_adroom_id_domain_id_url_id_is_wlabp_idx on adroom_stat st
(cost=0.58..180
91.26 rows=491 width=16)
   Index Cond: ((day >= date_trunc('day'::text,
(CURRENT_TIMESTAMP - '7 days'::interval))) AND (day <=
date_trunc('day'::text, CURRENT_TIMESTAMP)) AND (domain_id = d.id))


Dmitry Shalashov, relap.io & surfingbird.ru

2017-11-22 17:44 GMT+03:00 Alex Ignatov :

> Here is my select right after initdb:
>
>
>
> postgres=# select name,setting from pg_settings where name like '%_cost';
>
>  name | setting
>
> --+-
>
> cpu_index_tuple_cost | 0.005
>
> cpu_operator_cost| 0.0025
>
> cpu_tuple_cost   | 0.01
>
> parallel_setup_cost  | 1000
>
> parallel_tuple_cost  | 0.1
>
> random_page_cost | 4
>
> seq_page_cost| 1
>
>
>
>
>
> Can you generate plan with random_page_cost = 4?
>
>
>
>
>
> --
>
> Alex Ignatov
> Postgres Professional: http://www.postgrespro.com
> The Russian Postgres Company
>
>
>
> *From:* Dmitry Shalashov [mailto:skau...@gmail.com]
> *Sent:* Wednesday, November 22, 2017 5:29 PM
> *To:* Alex Ignatov 
> *Cc:* pgsql-performa...@postgresql.org
> *Subject:* Re: Query became very slow after 9.6 -> 10 upgrade
>
>
>
> Sure, here it goes:
>
>
>
>  name | setting
>
> --+-
>
>  cpu_index_tuple_cost | 0.005
>
>  cpu_operator_cost| 0.0025
>
>  cpu_tuple_cost   | 0.01
>
>  parallel_setup_cost  | 1000
>
>  parallel_tuple_cost  | 0.1
>
>  random_page_cost | 1
>
>  seq_page_cost| 1
>
>
>
>
> Dmitry Shalashov, relap.io & surfingbird.ru
>
>
>
> 2017-11-22 17:24 GMT+03:00 Alex Ignatov :
>
> Hello!
>
> What about :
>
> select name,setting from pg_settings where name like '%_cost';
>
>
>
> --
>
> Alex Ignatov
> Postgres Professional: http://www.postgrespro.com
> The Russian Postgres Company
>
>
>
>
>
> *From:* Dmitry Shalashov [mailto:skau...@gmail.com]
> *Sent:* Wednesday, November 22, 2017 5:14 PM
> *To:* pgsql-performa...@postgresql.org
> *Subject:* Query became very slow after 9.6 -> 10 upgrade
>
>
>
> Hi!
>
>
>
> I've seen few letters like this on mailing list and for some reason
> thought that probably it won't happen to us, but here I am lol.
>
>
>
> It's "nestloop hits again" situation.
>
>
>
> I'll try to provide plan from 9.6 later, but right now I have only plan
> from 10.1.
>
>
>
> Query: https://pastebin.com/9b953tT7
>
> It was running under 3 seconds (it's our default timeout) and now it runs
> for 12 minutes.
>
>
>
> \d adroom: https://pastebin.com/vBrPGtxT (3800 rows)
>
> \d adroom_stat: https://pastebin.com/CkBArCC9 (47mln rows, 1.5mln satisfy
> condition on day column)
>
> \d domains: https://pastebin.com/65hk7YCm (73000 rows)
>
>
>
> All three tables are analyzed.
>
>
>
> EXPLAIN ANALYZE: https://pastebin.com/PenHEgf0
>
> EXPLAIN ANALYZE with nestloop off: https://pastebin.com/zX35CPCV (0.8s)
>
>
>
> Regarding server parameters - it's a mighty beast with 2x E5-2630 v3,
> 192Gb of RAM and two very, very fast NVME server class SSD's in RAID1.
>
>
>
> What can I do with it?
>
>
>
>
>
> Also maybe this will be useful:
>
>
>
> 1st query, runs under 1ms
>
> select title, id, groups->0->>'provider' provider, domain_ids from adroom
> where groups->0->>'provider' ~ '^target_mail_ru' and not is_paused and
> current_timestamp between start_ts and stop_ts
>
>
>
> 2nd query that uses 1st one, runs under 3 ms
>
> select distinct unnest(domain_ids) FRO

Re: Bad estimates (DEFAULT_UNK_SEL)

[Justin Pryzby]

On Wed, Nov 22, 2017 at 03:29:54PM +0100, Artur Zając wrote:
> CREATE TABLE xyz AS SELECT generate_series(1,1000,1) AS gs;
> 
> db=# explain analyze select * from xyz where gs&1=1;
>  Seq Scan on xyz  (cost=0.00..260815.38 rows=68920 width=4) (actual 
> time=0.044..2959.728 rows=500 loops=1)
...
> newrr=# explain analyze select * from xyz where gs&1=1 and gs&2=2 and gs&4=4;
>  Seq Scan on xyz  (cost=0.00..398655.62 rows=2 width=4) (actual 
> time=0.052..3329.422 rows=125 loops=1)

> I noticed that each additional clause reduces the number about 200 times and
> define DEFAULT_NUM_DISTINCT is responsible for this behaviur.

I think it's actually:

src/include/utils/selfuncs.h-/* default selectivity estimate for boolean and 
null test nodes */
src/include/utils/selfuncs.h-#define DEFAULT_UNK_SEL0.005

..which is 1/200.

Note, you can do this, which helps a bit by collecting stats for the index
expr:

postgres=# CREATE INDEX ON xyz((gs&1));
postgres=# ANALYZE xyz;
postgres=# explain analyze SELECT * FROM xyz WHERE gs&1=1 AND gs&2=2 AND gs&4=4;
 Bitmap Heap Scan on xyz  (cost=91643.59..259941.99 rows=124 width=4) (actual 
time=472.376..2294.035 rows=125 loops=1)
   Recheck Cond: ((gs & 1) = 1)
   Filter: (((gs & 2) = 2) AND ((gs & 4) = 4))
   Rows Removed by Filter: 375
   Heap Blocks: exact=44248
   ->  Bitmap Index Scan on xyz_expr_idx  (cost=0.00..91643.55 rows=4962016 
width=0) (actual time=463.477..463.477 rows=500 loops=1)
 Index Cond: ((gs & 1) = 1)

Justin

Re: Bad estimates

[Tom Lane]

=?iso-8859-2?Q?Artur_Zaj=B1c?=  writes:
[ poor estimates for WHERE clauses like "(gs & 1) = 1" ]

Don't hold your breath waiting for that to get better on its own.
You need to work with the planner, not expect it to perform magic.
It has no stats that would help it discover what the behavior of
that sort of WHERE clause is; nor is there a good reason for it
to think that the selectivity of such a clause is only 0.5 rather
than something more in line with the usual behavior of an equality
constraint on an integer value.

One way you could attack the problem, if you're wedded to this data
representation, is to create expression indexes on the terms "(gs & x)"
for all the values of x you use.  Not only would that result in better
estimates (after an ANALYZE) but it would also open the door to satisfying
this type of query through an index search.  A downside is that updating
all those indexes could make DML on the table pretty expensive.

If you're not wedded to this data representation, consider replacing that
integer flags column with a bunch of boolean columns.  You might or might
not want indexes on the booleans, but in any case ANALYZE would create
stats that would allow decent estimates for "WHERE boolval".

regards, tom lane

RE: Bad estimates

[Alex Ignatov]

It doesn’t help in this case.

 

--

Alex Ignatov 
Postgres Professional:   http://www.postgrespro.com 
The Russian Postgres Company

 

From: Don Seiler [mailto:d...@seiler.us] 
Sent: Wednesday, November 22, 2017 5:49 PM
To: Artur Zając 
Cc: pgsql-performance@lists.postgresql.org
Subject: Re: Bad estimates

 

I'm assuming you never analyzed the table after creation & data load? What does 
this show you:

 

select * from pg_stat_all_tables where relname='xyz';

 

Don.

 

-- 

Don Seiler
www.seiler.us  

Re: Query became very slow after 9.6 -> 10 upgrade

[Tomas Vondra]

IMHO the problems here are due to poor cardinality estimates.

For example in the first query, the problem is here:

->  Nested Loop  (cost=0.42..2.46 rows=1 width=59)
 (actual time=2.431..91.330 rows=3173 loops=1)
->  CTE Scan on b  (cost=0.00..0.02 rows=1 width=40)
   (actual time=2.407..23.115 rows=3173 loops=1)
->  Index Scan using domains_pkey on domains d
(cost=0.42..2.44 rows=1 width=19)
(actual time=0.018..0.018 rows=1 loops=3173)

That is, the database expects the CTE to return 1 row, but it returns
3173 of them, which makes the nested loop very inefficient.

Similarly for the other query, where this happens:

 Nested Loop  (cost=88.63..25617.31 rows=491 width=16)
  (actual time=3.512..733248.271 rows=1442797 loops=1)
   ->  HashAggregate  (cost=88.06..88.07 rows=1 width=4)
  (actual time=3.380..13.561 rows=3043 loops=1)

That is, about 1:3000 difference in both cases.

Those estimation errors seem to be caused by a condition that is almost
impossible to estimate, because in both queries it does this:

groups->0->>'provider' ~ '^something'

That is, it's a regexp on an expression. You might try creating an index
on the expression (which is the only way to add expression statistics),
and reformulate the condition as LIKE (which I believe we can estimate
better than regular expressions, but I haven't tried).

So something like

CREATE INDEX ON adroom ((groups->0->>'provider'));

WHERE groups->0->>'provider' LIKE 'something%';

regards

-- 
Tomas Vondra  http://www.2ndQuadrant.com
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Re: Bad estimates

[Laurenz Albe]

Artur Zając wrote:
> We have table created like this:
> 
> CREATE TABLE xyz AS SELECT generate_series(1,1000,1) AS gs;
> 
> Now:
> 
> explain analyze select * from xyz where gs&1=1;

>  Seq Scan on xyz  (cost=0.00..260815.38 rows=68920 width=4)
>   (actual time=0.044..2959.728 rows=500 loops=1)
>Filter: ((gs & 1) = 1)
>Rows Removed by Filter: 500
[...]
> And one more clause:
> 
> explain analyze select * from xyz where gs&1=1 and gs&2=2 and gs&4=4;

>  Seq Scan on xyz  (cost=0.00..398655.62 rows=2 width=4)
>   (actual time=0.052..3329.422 rows=125 loops=1)
>Filter: (((gs & 1) = 1) AND ((gs & 2) = 2) AND ((gs & 4) = 4))
>Rows Removed by Filter: 875

> As we can see estimates differs significally from the actual records count -
> only three clauses are reducing estimated number of records from 1000 to
> 2.
> 
> I noticed that each additional clause reduces the number about 200 times and
> define DEFAULT_NUM_DISTINCT is responsible for this behaviur.
> 
> I think that this variable should be lower or maybe estimation using
> DEFAULT_NUM_DISTTINCT should be done once per table.

The problem is that the expression "gs & 1" is a black box for the
optimizer; it cannot estimate how selective the condition is and falls
back to a default value that is too low.

You can create an index to
a) improve the estimate
and
b) speed up the queries:

CREATE INDEX ON xyz ((gs & 1), (gs & 2), (gs & 4));

Don't forget to ANALYZE afterwards.

Yours,
Laurenz Albe

Re: Query became very slow after 9.6 -> 10 upgrade

[Tom Lane]

Dmitry Shalashov  writes:
> BUT if I'll add to 3rd query one additional condition, which is basically
> 2nd query, it will ran same 12 minutes:
> SELECT adroom_id, domain_id, shows, clicks FROM adroom_stat WHERE day
> between date_trunc('day', current_timestamp - interval '1 week') and
> date_trunc('day', current_timestamp) AND domain_id IN (select distinct
> unnest(domain_ids) FROM (select title, id, groups->0->>'provider' provider,
> domain_ids from adroom where groups->0->>'provider' ~ '^target_mail_ru' and
> not is_paused and current_timestamp between start_ts and stop_ts) t1)

> Plan of last query:
>  Nested Loop  (cost=88.63..25617.31 rows=491 width=16) (actual
> time=3.512..733248.271 rows=1442797 loops=1)
>->  HashAggregate  (cost=88.06..88.07 rows=1 width=4) (actual
> time=3.380..13.561 rows=3043 loops=1)
>  Group Key: (unnest(adroom.domain_ids))
>  ->  HashAggregate  (cost=88.03..88.04 rows=1 width=4) (actual
> time=2.199..2.607 rows=3043 loops=1)
>Group Key: unnest(adroom.domain_ids)
>->  ProjectSet  (cost=0.28..87.78 rows=100 width=4) (actual
> time=0.701..1.339 rows=3173 loops=1)

Hm, seems like the problem is that that lower HashAggregate is estimated
as having only one row out, which is way off and doesn't sound like a
particularly bright default estimate anyway.  (And then we're doing an
additional HashAggregate on top of that, which is useless --- implies
that something isn't realizing that the output of the SELECT DISTINCT
is already distinct.)

I'm suspicious that this is breakage from the work that was done on
targetlist SRFs in v10, but that's just a guess at this point.

Trying simple test queries involving WHERE x IN (SELECT DISTINCT
unnest(foo) FROM ...), I do not see a behavior like this, so there is some
not-very-obvious contributing factor in your situation.  Can you put
together a self-contained test case that produces a bogus one-row
estimate?  Extra points if it produces duplicate HashAgg steps.

regards, tom lane

RE: Bad estimates

[Artur Zając]

Thank you for your response,

Clause used by me is not important (I used binary & operator only for
example), I tried to show some kind of problems.

Now I did another test:

alter table xyz add x int;
alter table xyz add y int;
alter table xyz add z int;
update xyz set x=gs,y=gs,z=gs;

create index xyza_i1 on xyz ((x%200));
create index xyza_i2 on xyz ((y%200));
create index xyza_i3 on xyz ((z%200));

vacuum full verbose xyza;

And now:

explain analyze select gs from xyza where (x%200)=1 and (y%200)=1 and
(z%200)=1;

QUERY PLAN

--
 Bitmap Heap Scan on xyz  (cost=2782.81..2786.83 rows=1 width=4) (actual
time=134.827..505.642 rows=5 loops=1)
   Recheck Cond: (((z % 200) = 1) AND ((y % 200) = 1) AND ((x % 200) = 1))
   Heap Blocks: exact=5
   ->  BitmapAnd  (cost=2782.81..2782.81 rows=1 width=0) (actual
time=108.712..108.712 rows=0 loops=1)
 ->  Bitmap Index Scan on xyza_i3  (cost=0.00..927.43 rows=5
width=0) (actual time=22.857..22.857 rows=5 loops=1)
   Index Cond: ((z % 200) = 1)
 ->  Bitmap Index Scan on xyza_i2  (cost=0.00..927.43 rows=5
width=0) (actual time=26.058..26.058 rows=5 loops=1)
   Index Cond: ((y % 200) = 1)
 ->  Bitmap Index Scan on xyza_i1  (cost=0.00..927.43 rows=5
width=0) (actual time=23.079..23.079 rows=5 loops=1)
   Index Cond: ((x % 200) = 1)
 Planning time: 0.340 ms
 Execution time: 513.171 ms
(12 rows)

Estimates are exactly the same because it's assumed that if first clause
reduces records count by n, second by m, third by o then bringing all of
them together will reduce the result records count by n*m*o, so it is the
general behaviour, independent of whether they are statistics or not.

You suggest:

> If you're not wedded to this data representation, consider replacing that
integer flags column with a bunch of boolean columns.  You might or might
not want indexes on the booleans, but > in any case ANALYZE would create
stats that would allow decent estimates for "WHERE boolval".

But, did you ever think about something like this?

CREATE STATISTICS ON (x&1) FROM xyz;

(using the syntax similar to CREATE STATISTICS from PostgreSQL 10).

Sometimes It's not possibile to divide one column into many , and as I know,
it is not worth creating an index if there are few different values in the
table.


Artur Zajac 


-Original Message-
From: Tom Lane [mailto:t...@sss.pgh.pa.us] 
Sent: Wednesday, November 22, 2017 4:02 PM
To: Artur Zając 
Cc: pgsql-performance@lists.postgresql.org
Subject: Re: Bad estimates

=?iso-8859-2?Q?Artur_Zaj=B1c?=  writes:
[ poor estimates for WHERE clauses like "(gs & 1) = 1" ]

Don't hold your breath waiting for that to get better on its own.
You need to work with the planner, not expect it to perform magic.
It has no stats that would help it discover what the behavior of that sort
of WHERE clause is; nor is there a good reason for it to think that the
selectivity of such a clause is only 0.5 rather than something more in line
with the usual behavior of an equality constraint on an integer value.

One way you could attack the problem, if you're wedded to this data
representation, is to create expression indexes on the terms "(gs & x)"
for all the values of x you use.  Not only would that result in better
estimates (after an ANALYZE) but it would also open the door to satisfying
this type of query through an index search.  A downside is that updating all
those indexes could make DML on the table pretty expensive.

If you're not wedded to this data representation, consider replacing that
integer flags column with a bunch of boolean columns.  You might or might
not want indexes on the booleans, but in any case ANALYZE would create stats
that would allow decent estimates for "WHERE boolval".

regards, tom lane

Re: pg_dump 3 times as slow after 8.4 -> 9.5 upgrade

[Andres Freund]

Hi,

On 2017-11-22 02:32:45 -0800, Matthew Hall wrote:
> I would say most likely your zlib is screwed up somehow, like maybe it
> didn't get optimized right by the C compiler or something else sucks
> w/ the compression settings. The CPU should easily blast away at that
> faster than disks can read.

Huh? Zlib compresses at a few 10s of MB/s.

Greetings,

Andres Freund

Re: pg_dump 3 times as slow after 8.4 -> 9.5 upgrade

[Matthew Hall]

On Nov 22, 2017, at 5:06 AM, Henrik Cednert (Filmlance) 
 wrote:
> 
> When investigating the zlib lead I looked at 8.4 installation and 9.5 
> installation. 9.5 includes zlib.h (/Library/PostgreSQL//9.5/include/zlib.h), 
> but 8.4 doesn't. But that's a header file and I have no idea how that really 
> works and if that's the one used by pgres9.5 or not. The version in it says 
> 1.2.8 and that's what the Instruments are showing when I monitor pg_dump 
> while running. 
> 
> Guess I'll have to install instruments in a dev env and do a pg_dump with 8.4 
> to see the difference. Tedious. =/ 

I would also check the library linkages of the pg_dump binaries.

See if one thing is using an embedded zlib and the other a system zlib.

Then you could imagine one didn't get compiled with the best-performing CFLAGS, 
etc.

Matthew.

Re: pg_dump 3 times as slow after 8.4 -> 9.5 upgrade

[Henrik Cednert (Filmlance)]

Hi Matthew

Actually running that test in a vm right now. =)

This is the same db dumped from 9.5 and 8.4 with compression 6 in the same 
system (smaller db in a vm).

9.5:
real 82m33.744s
user 60m55.069s
sys 3m3.375s

8.4
real 42m46.381s
user 23m50.145s
sys 2m9.853s

When looking at a sample and/or instruments I think I can confirm what your 
hunch was/is. But I'm not skilled enough to say what's right and wrong nor what 
action to take. But 8.4 seems to use a system library libz.1.dylib while the 
9.4 dump refers to libz.1.2.8.dylib which I think is the one shipping with that 
particular installation I'm using (/Library/PostgreSQL//9.5/include/zlib.h).
https://www.dropbox.com/s/q1f4p7jzw0ceynh/libz.png?dl=0

https://pastebin.com/RWWsumQL

I have no idea if I can relink the libs in 9.5 to other ones? support from the 
software company in question have suggested updating to a newer version of 9.5 
but not sure that'll solve it. I'm on thin ice here and not sure how to 
proceed. I'm not even sure if I should or if I should dump uncompressed and let 
something threaded take care of the compression. Sadly i'm the type of guy that 
can't let go so would be nice to get this to work properly anyways. =)

CHeers and many thanks again.



--
Henrik Cednert
cto | compositor

Filmlance International

On 22 Nov 2017, at 20:52, Matthew Hall 
mailto:mh...@mhcomputing.net>> wrote:

On Nov 22, 2017, at 5:06 AM, Henrik Cednert (Filmlance) 
mailto:henrik.cedn...@filmlance.se>> wrote:

When investigating the zlib lead I looked at 8.4 installation and 9.5 
installation. 9.5 includes zlib.h (/Library/PostgreSQL//9.5/include/zlib.h), 
but 8.4 doesn't. But that's a header file and I have no idea how that really 
works and if that's the one used by pgres9.5 or not. The version in it says 
1.2.8 and that's what the Instruments are showing when I monitor pg_dump while 
running.

Guess I'll have to install instruments in a dev env and do a pg_dump with 8.4 
to see the difference. Tedious. =/

I would also check the library linkages of the pg_dump binaries.

See if one thing is using an embedded zlib and the other a system zlib.

Then you could imagine one didn't get compiled with the best-performing CFLAGS, 
etc.

Matthew.

Re: Query became very slow after 9.6 -> 10 upgrade

[Dmitry Shalashov]

Turns out we had not 9.6 but 9.5.

And query plan from 9.5 is:

 Sort  (cost=319008.18..319008.19 rows=1 width=556) (actual
time=0.028..0.028 rows=0 loops=1)
   Sort Key: (sum(st.shows)) DESC
   Sort Method: quicksort  Memory: 25kB
   CTE a
 ->  Index Scan using adroom_active_idx on adroom  (cost=0.13..5.21
rows=1 width=584) (actual time=0.004..0.004 rows=0 loops=1)
   Index Cond: ((now() >= start_ts) AND (now() <= stop_ts))
   Filter: (((groups -> 0) ->> 'provider'::text) ~
'^target_mail_ru'::text)
   CTE b
 ->  HashAggregate  (cost=1.27..1.77 rows=100 width=68) (actual
time=0.005..0.005 rows=0 loops=1)
   Group Key: a.provider, a.id, unnest(a.domain_ids)
   ->  CTE Scan on a  (cost=0.00..0.52 rows=100 width=68) (actual
time=0.004..0.004 rows=0 loops=1)
   ->  HashAggregate  (cost=319001.17..319001.18 rows=1 width=556) (actual
time=0.013..0.013 rows=0 loops=1)
 Group Key: b.provider, d.domain
 ->  Hash Join  (cost=16.55..319001.16 rows=1 width=556) (actual
time=0.013..0.013 rows=0 loops=1)
   Hash Cond: ((st.adroom_id = b.id) AND (st.domain_id =
b.domain_id))
   ->  Hash Join  (cost=13.05..318633.29 rows=48581 width=536)
(never executed)
 Hash Cond: (st.domain_id = d.id)
 ->  Index Scan using
adroom_stat_day_adroom_id_domain_id_url_id_is_wlabp_idx on adroom_stat st
(cost=0.58..313307.30 rows=1287388 width=16) (never executed)
   Index Cond: ((day >= date_trunc('day'::text,
(now() - '7 days'::interval))) AND (day <= date_trunc('day'::text, now(
 ->  Hash  (cost=11.10..11.10 rows=110 width=520)
(never executed)
   ->  Seq Scan on domains d  (cost=0.00..11.10
rows=110 width=520) (never executed)
   ->  Hash  (cost=2.00..2.00 rows=100 width=40) (actual
time=0.007..0.007 rows=0 loops=1)
 Buckets: 1024  Batches: 1  Memory Usage: 8kB
 ->  CTE Scan on b  (cost=0.00..2.00 rows=100 width=40)
(actual time=0.007..0.007 rows=0 loops=1)
 Planning time: 6.641 ms
 Execution time: 0.203 ms


Also I prepared test case for Tom and sent it to him.


Dmitry Shalashov, relap.io & surfingbird.ru

2017-11-22 18:19 GMT+03:00 Tom Lane :

> Dmitry Shalashov  writes:
> > BUT if I'll add to 3rd query one additional condition, which is basically
> > 2nd query, it will ran same 12 minutes:
> > SELECT adroom_id, domain_id, shows, clicks FROM adroom_stat WHERE day
> > between date_trunc('day', current_timestamp - interval '1 week') and
> > date_trunc('day', current_timestamp) AND domain_id IN (select distinct
> > unnest(domain_ids) FROM (select title, id, groups->0->>'provider'
> provider,
> > domain_ids from adroom where groups->0->>'provider' ~ '^target_mail_ru'
> and
> > not is_paused and current_timestamp between start_ts and stop_ts) t1)
>
> > Plan of last query:
> >  Nested Loop  (cost=88.63..25617.31 rows=491 width=16) (actual
> > time=3.512..733248.271 rows=1442797 loops=1)
> >->  HashAggregate  (cost=88.06..88.07 rows=1 width=4) (actual
> > time=3.380..13.561 rows=3043 loops=1)
> >  Group Key: (unnest(adroom.domain_ids))
> >  ->  HashAggregate  (cost=88.03..88.04 rows=1 width=4) (actual
> > time=2.199..2.607 rows=3043 loops=1)
> >Group Key: unnest(adroom.domain_ids)
> >->  ProjectSet  (cost=0.28..87.78 rows=100 width=4)
> (actual
> > time=0.701..1.339 rows=3173 loops=1)
>
> Hm, seems like the problem is that that lower HashAggregate is estimated
> as having only one row out, which is way off and doesn't sound like a
> particularly bright default estimate anyway.  (And then we're doing an
> additional HashAggregate on top of that, which is useless --- implies
> that something isn't realizing that the output of the SELECT DISTINCT
> is already distinct.)
>
> I'm suspicious that this is breakage from the work that was done on
> targetlist SRFs in v10, but that's just a guess at this point.
>
> Trying simple test queries involving WHERE x IN (SELECT DISTINCT
> unnest(foo) FROM ...), I do not see a behavior like this, so there is some
> not-very-obvious contributing factor in your situation.  Can you put
> together a self-contained test case that produces a bogus one-row
> estimate?  Extra points if it produces duplicate HashAgg steps.
>
> regards, tom lane
>

Re: pg_dump 3 times as slow after 8.4 -> 9.5 upgrade

[Patrick KUI-LI]

Hello,

I had this behaviors when the upgraded pg 9.5 was on ssl mode by default.

So i deactivated ssl mode in postgresql.conf. That's all.

Regards,

Patrick



On 11/21/2017 03:28 PM, Henrik Cednert (Filmlance) wrote:
> Hello
>
> We use a system in filmproduction called DaVinci Resolve. It uses a
> pgsql database when you work in a collaborative workflow and multiple
> people share projects. Previously it was using pgsql 8.4 but for a new
> major upgrade they recommend an upgrade to 9.5. Probably also to some
> macOS limitation/support and that 9.x is required for macOS >10.11.
>
> They (BlackMagic Design) provide three tools for the migration. 
> 1. For for dumping everything form the old 8.4 database
> 2. One for upgrading from 8.4 to 9.5
> 3. One for restoring the backup in step 1 in 9.5
>
> All that went smoothly and working in the systems also works smoothly
> and as good as previously, maybe even a bit better/faster. 
>
> What's not working smoothly is my daily pg_dump's though. I don't have
> a reference to what's a big and what's a small database since I'm no
> db-guy and don't really maintain nor work with it on a daily basis.
> Pretty much only this system we use that has a db system like this.
> Below is a list of what we dump.
>
> 930M Nov 18 13:31 filmserver03_2017-11-18_132043_dailies_2017_01.backup
> 2.2K Nov 18 13:20 filmserver03_2017-11-18_132043_postgres.backup
> 522K Nov 18 13:20 filmserver03_2017-11-18_132043_resolve.backup
> 23G Nov 18 19:37 filmserver03_2017-11-18_132043_resolve_2017_01.backup
> 5.1G Nov 18 20:54 filmserver03_2017-11-18_132043_resolve_2017_02.backup
> 10G Nov 18 23:34
> filmserver03_2017-11-18_132043_resolve_filmserver02.backup
> 516K Nov 18 23:35 filmserver03_2017-11-18_132043_temp_backup_test.backup
> 1.9G Nov 19 00:05 filmserver03_2017-11-18_132043_temp_dev_resolve14.backup
>
>
> The last pg_dump with 8.4 took 212 minutes and 49 seconds.And now with
> 9.5 the very same pg_dump takes 644 minutes and 40 seconds. To it
> takes about three times as long now and I have no idea to why. Nothing
> in the system or hardware other than the pgsql upgrade have change.  
>
> I dump the db's with a custom script and this is the line I use to get
> the DB's:
> DATABASES=$(${BINARY_PATH}/psql --user=postgres -w --no-align
> --tuples-only --command="SELECT datname from pg_database WHERE NOT
> datistemplate")
>
> After that I iterate over them with a for loop and dump with:
> ${BINARY_PATH}/pg_dump --host=localhost --user=postgres --no-password
> --blobs --format=custom --verbose
> --file=${pg_dump_filename}_${database}.backup ${database} | tee -a
> ${log_pg_dump}_${database}.log    
>
> When observing the system during the dump it LOOKS like it did in 8.4.
> pg_dump is using 100% of one core and from what I can see it does this
> through out the operation. But it's still so much slower. I read
> about the parallell option in pg_dump for 9.5 but sadly I cannot dump
> like that because the application in question can (probably) not
> import that format on it's own and I would have to use pgrestore or
> something. Which in theory is fine but sometimes one of the artists
> have to import the db backup. So need to keep it simple.
>
> The system is:
> MacPro 5,1
> 2x2.66 GHz Quad Core Xeon
> 64 GB RAM
> macOS 10.11.6
> PostgreSQL 9.5.4
> DB on a 6 disk SSD RAID
>
>
> I hope I got all the info needed. Really hope someone with more
> expertise and skills than me can point me in the right direction.
>
> Cheers and thanks
>
>
> --
> Henrik Cednert
> cto | compositor
>
>

Re: Query became very slow after 9.6 -> 10 upgrade

[Tom Lane]

Dmitry Shalashov  writes:
> Turns out we had not 9.6 but 9.5.

I'd managed to reproduce the weird planner behavior locally in the
regression database:

regression=# create table foo (f1 int[], f2 int);
CREATE TABLE
regression=# explain select * from tenk1 where unique2 in (select distinct 
unnest(f1) from foo where f2=1);
QUERY PLAN  
   
---
 Nested Loop  (cost=30.85..80.50 rows=6 width=244)
   ->  HashAggregate  (cost=30.57..30.63 rows=6 width=4)
 Group Key: (unnest(foo.f1))
 ->  HashAggregate  (cost=30.42..30.49 rows=6 width=4)
   Group Key: unnest(foo.f1)
   ->  ProjectSet  (cost=0.00..28.92 rows=600 width=4)
 ->  Seq Scan on foo  (cost=0.00..25.88 rows=6 width=32)
   Filter: (f2 = 1)
   ->  Index Scan using tenk1_unique2 on tenk1  (cost=0.29..8.30 rows=1 
width=244)
 Index Cond: (unique2 = (unnest(foo.f1)))
(10 rows)

Digging into it, the reason for the duplicate HashAggregate step was that
query_supports_distinctness() punted on SRFs-in-the-targetlist, basically
on the argument that it wasn't worth extra work to handle that case.
Thinking a bit harder, it seems to me that the correct analysis is:
1. If we are proving distinctness on the grounds of a DISTINCT clause,
then it doesn't matter whether there are any SRFs, because DISTINCT
removes duplicates after tlist SRF expansion.
2. But tlist SRFs break the ability to prove distinctness on the grounds
of GROUP BY, unless all of them are within grouping columns.
It still seems like detecting the second case is harder than it's worth,
but we can trivially handle the first case, with little more than some
code rearrangement.

The other problem is that the output rowcount of the sub-select (ie, of
the HashAggregate) is being estimated as though the SRF weren't there.
This turns out to be because estimate_num_groups() doesn't consider the
possibility of SRFs in the grouping columns.  It never has, but in 9.6 and
before the problem was masked by the fact that grouping_planner scaled up
the result rowcount by tlist_returns_set_rows() *after* performing
grouping.  Now we're effectively doing that in the other order, which is
more correct, but that means estimate_num_groups() has to apply some sort
of adjustment.  I suggest that it just multiply its old estimate by the
maximum of the SRF expansion counts.  That's likely to be an overestimate,
but it's really hard to do better without specific knowledge of the
individual SRF's behavior.

In short, I propose the attached fixes.  I've checked this and it seems
to fix Dmitry's original problem according to the test case he sent
off-list.

regards, tom lane

diff --git a/src/backend/optimizer/plan/analyzejoins.c b/src/backend/optimizer/plan/analyzejoins.c
index 5b0da14..5783f90 100644
*** a/src/backend/optimizer/plan/analyzejoins.c
--- b/src/backend/optimizer/plan/analyzejoins.c
*** rel_is_distinct_for(PlannerInfo *root, R
*** 744,751 
  bool
  query_supports_distinctness(Query *query)
  {
! 	/* we don't cope with SRFs, see comment below */
! 	if (query->hasTargetSRFs)
  		return false;
  
  	/* check for features we can prove distinctness with */
--- 744,751 
  bool
  query_supports_distinctness(Query *query)
  {
! 	/* SRFs break distinctness except with DISTINCT, see below */
! 	if (query->hasTargetSRFs && query->distinctClause == NIL)
  		return false;
  
  	/* check for features we can prove distinctness with */
*** query_is_distinct_for(Query *query, List
*** 787,806 
  	Assert(list_length(colnos) == list_length(opids));
  
  	/*
- 	 * A set-returning function in the query's targetlist can result in
- 	 * returning duplicate rows, if the SRF is evaluated after the
- 	 * de-duplication step; so we play it safe and say "no" if there are any
- 	 * SRFs.  (We could be certain that it's okay if SRFs appear only in the
- 	 * specified columns, since those must be evaluated before de-duplication;
- 	 * but it doesn't presently seem worth the complication to check that.)
- 	 */
- 	if (query->hasTargetSRFs)
- 		return false;
- 
- 	/*
  	 * DISTINCT (including DISTINCT ON) guarantees uniqueness if all the
  	 * columns in the DISTINCT clause appear in colnos and operator semantics
! 	 * match.
  	 */
  	if (query->distinctClause)
  	{
--- 787,796 
  	Assert(list_length(colnos) == list_length(opids));
  
  	/*
  	 * DISTINCT (including DISTINCT ON) guarantees uniqueness if all the
  	 * columns in the DISTINCT clause appear in colnos and operator semantics
! 	 * match.  This is true even if there are SRFs in the DISTINCT columns or
! 	 * elsewhere in the tlist.
  	 */
  	if (query->distinctClause)
  	{
*** query_is_distinct_for(Query *query, List
*** 820,825 
--- 810,825 
  	}
  
  	/*
+ 	 * Otherwise, a