Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtp (Exim 4.84_2) (envelope-from ) id 1eHVwf-0006Mz-Dv for pgsql-performance@arkaria.postgresql.org; Wed, 22 Nov 2017 14:24:10 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.84_2) (envelope-from ) id 1eHVwe-0004yb-Oi for pgsql-performance@arkaria.postgresql.org; Wed, 22 Nov 2017 14:24:08 +0000 Received: from makus.postgresql.org ([2001:4800:1501:1::229]) by malur.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_CBC_SHA384:256) (Exim 4.84_2) (envelope-from ) id 1eHVwe-0004yR-8J for pgsql-performance@lists.postgresql.org; Wed, 22 Nov 2017 14:24:08 +0000 Received: from mail.postgrespro.ru ([93.174.131.138]) by makus.postgresql.org with esmtp (Exim 4.89) (envelope-from ) id 1eHVwa-0008CU-1H for pgsql-performance@postgresql.org; Wed, 22 Nov 2017 14:24:07 +0000 Received: from localhost (localhost [127.0.0.1]) by mail.postgrespro.ru (Postfix) with ESMTP id 0AAAC21C1D05; Wed, 22 Nov 2017 17:24:01 +0300 (MSK) X-Virus-Scanned: Debian amavisd-new at postgrespro.ru Received: from inferno (unknown [192.168.27.1]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client did not present a certificate) by mail.postgrespro.ru (Postfix) with ESMTPSA id DC70C21C176B; Wed, 22 Nov 2017 17:24:00 +0300 (MSK) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=postgrespro.ru; s=mail; t=1511360640; bh=jzC/6B2yJksUr0xxXii8tOSRVV38XfuV1Oy3YDnNAOk=; h=From:To:References:In-Reply-To:Subject:Date; b=QIRiaZt/rngaI+Kj2NIq/2gJSHRkfIOKOSGtyypzwL4fpuRD2ciatBBI3HR7h1U9W cVcSYiuWHnF1xOvk7W1rOzFX3qX/+EsCd/320kCpu7LHuC36DfzJaKvUoPUDZXdy7E siIx231RVTmOO/Rk3DJijKQBg+ct519fZmevILig= From: "Alex Ignatov" To: "'Dmitry Shalashov'" , References: In-Reply-To: Subject: RE: Query became very slow after 9.6 -> 10 upgrade Date: Wed, 22 Nov 2017 17:24:01 +0300 Message-ID: <1379201d3639d$8b61bcd0$a2253670$@postgrespro.ru> MIME-Version: 1.0 Content-Type: multipart/alternative; boundary="----=_NextPart_000_13793_01D363B6.B0B02D50" X-Mailer: Microsoft Outlook 16.0 Thread-Index: AQJHb1HcTOXyxzMxs6YDVgBR4dXi9aI4W2zA Content-Language: ru List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Precedence: bulk This is a multipart message in MIME format. ------=_NextPart_000_13793_01D363B6.B0B02D50 Content-Type: text/plain; charset="utf-8" Content-Transfer-Encoding: quoted-printable Hello! What about : select name,setting from pg_settings where name like '%_cost'; =20 -- Alex Ignatov=20 Postgres Professional: = http://www.postgrespro.com=20 The Russian Postgres Company =20 =20 From: Dmitry Shalashov [mailto:skaurus@gmail.com]=20 Sent: Wednesday, November 22, 2017 5:14 PM To: pgsql-performance@postgresql.org Subject: Query became very slow after 9.6 -> 10 upgrade =20 Hi! =20 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. =20 It's "nestloop hits again" situation. =20 I'll try to provide plan from 9.6 later, but right now I have only plan = from 10.1. =20 Query: https://pastebin.com/9b953tT7 It was running under 3 seconds (it's our default timeout) and now it = runs for 12 minutes. =20 \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) =20 All three tables are analyzed. =20 EXPLAIN ANALYZE: https://pastebin.com/PenHEgf0 EXPLAIN ANALYZE with nestloop off: https://pastebin.com/zX35CPCV (0.8s) =20 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. =20 What can I do with it? =20 =20 Also maybe this will be useful: =20 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 =20 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 =20 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) =20 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) =20 Plan of last query: Nested Loop (cost=3D88.63..25617.31 rows=3D491 width=3D16) (actual = time=3D3.512..733248.271 rows=3D1442797 loops=3D1) -> HashAggregate (cost=3D88.06..88.07 rows=3D1 width=3D4) (actual = time=3D3.380..13.561 rows=3D3043 loops=3D1) Group Key: (unnest(adroom.domain_ids)) -> HashAggregate (cost=3D88.03..88.04 rows=3D1 width=3D4) = (actual time=3D2.199..2.607 rows=3D3043 loops=3D1) Group Key: unnest(adroom.domain_ids) -> ProjectSet (cost=3D0.28..87.78 rows=3D100 width=3D4) = (actual time=3D0.701..1.339 rows=3D3173 loops=3D1) -> Index Scan using adroom_active_idx on adroom = (cost=3D0.28..87.27 rows=3D1 width=3D167) (actual time=3D0.688..1.040 = rows=3D4 loops=3D1) Index Cond: ((CURRENT_TIMESTAMP >=3D = start_ts) AND (CURRENT_TIMESTAMP <=3D 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=3D0.58..25524.33 rows=3D491 width=3D16) (actual = time=3D104.847..240.846 rows=3D474 loops=3D3043) Index Cond: ((day >=3D date_trunc('day'::text, = (CURRENT_TIMESTAMP - '7 days'::interval))) AND (day <=3D = date_trunc('day'::text, CURRENT_TIMESTAMP)) AND (domain_id =3D = (unnest(adroom.domain_ids)))) Planning time: 1.580 ms Execution time: 733331.740 ms =20 Dmitry Shalashov, relap.io & = surfingbird.ru ------=_NextPart_000_13793_01D363B6.B0B02D50 Content-Type: text/html; charset="utf-8" Content-Transfer-Encoding: quoted-printable

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:skaurus@gmail.com]
Sent: Wednesday, = November 22, 2017 5:14 PM
To: = pgsql-performance@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.

 

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<= o:p>

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=3D88.63..25617.31 = rows=3D491 width=3D16) (actual time=3D3.512..733248.271 rows=3D1442797 = loops=3D1)

  =  ->  HashAggregate  (cost=3D88.06..88.07 rows=3D1 = width=3D4) (actual time=3D3.380..13.561 rows=3D3043 = loops=3D1)

    =      Group Key: = (unnest(adroom.domain_ids))

         ->  = HashAggregate  (cost=3D88.03..88.04 rows=3D1 width=3D4) (actual = time=3D2.199..2.607 rows=3D3043 loops=3D1)

              =  Group Key: unnest(adroom.domain_ids)

              =  ->  ProjectSet  (cost=3D0.28..87.78 rows=3D100 = width=3D4) (actual time=3D0.701..1.339 rows=3D3173 = loops=3D1)

    =                 =  ->  Index Scan using adroom_active_idx on adroom  = (cost=3D0.28..87.27 rows=3D1 width=3D167) (actual time=3D0.688..1.040 = rows=3D4 loops=3D1)

  =                     =      Index Cond: ((CURRENT_TIMESTAMP >=3D start_ts) = AND (CURRENT_TIMESTAMP <=3D 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=3D0.58..25524.33 rows=3D491 width=3D16) (actual = time=3D104.847..240.846 rows=3D474 = loops=3D3043)

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

 Planning time: 1.580 = ms

 Execution time: = 733331.740 ms

 

Dmitry = Shalashov, relap.io & surfingbird.ru

<= /div>
------=_NextPart_000_13793_01D363B6.B0B02D50--