Re: [External] Re: FDW, too long to run explain

From: Vijaykumar Jain <vjain(at)opentable(dot)com>
To: Jeff Janes <jeff(dot)janes(at)gmail(dot)com>
Cc: auxsvr <auxsvr(at)gmail(dot)com>, pgsql-general(at)lists(dot)postgresql(dot)org
Subject: Re: [External] Re: FDW, too long to run explain
Date: 2019-02-18 10:22:05
Message-ID: CAE7uO5iaWLn56Q71_sjLfv4xy+iO1ZXqyKXOtAyQ7vyBfqk4=Q@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-general

Oh Wow, i guess you are right.
I just ran example where local runs make use of parallel setup, but not FDW.

i have three servers
2 x pg10
1 x pg11

i run queries on coordinator node ( pg11 ) which makes calls to foreign
server to do a simple count.
the individual nodes run the query in parallel, the setup is repeatable.
but via FDW it runs a simple seq scan.
i guess this is for the same reason as you mentioned wrt declared cursors.

on pg11
create schema pg10;
create schema pg10_qa;
import foreign schema pg10 from server pg10 into pg10;
import foreign schema pg10_qa from server pg10_qa into pg10_qa;

explain (analyze,verbose) SELECT COUNT(1) FROM pg10.tbl_ItemTransactions;
----this query is via FDW
QUERY PLAN
----------------------------------------------------------------------------------------------------
Foreign Scan (cost=108.53..152.69 rows=1 width=8) (actual
time=6584.498..6584.500 rows=1 loops=1)
Output: (count(1))
Relations: Aggregate on (pg10.tbl_itemtransactions)
Remote SQL: SELECT count(1) FROM pg10.tbl_itemtransactions
Planning Time: 0.112 ms
Execution Time: 6585.435 ms
(6 rows)

2019-02-18 09:56:48 UTC LOG: duration: 6593.046 ms plan:
Query Text: DECLARE c1 CURSOR FOR
SELECT count(1) FROM pg10.tbl_itemtransactions
Aggregate (cost=768694.80..768694.81 rows=1 width=8) (actual
time=6593.039..6593.039 rows=1 loops=1)
Output: count(1)
Buffers: shared hit=259476
-> Seq Scan on pg10.tbl_itemtransactions (cost=0.00..666851.04
rows=40737504 width=0) (actual time=0.024..3389.245 rows=40737601 loops=1)
Output: tranid, transactiondate, transactionname
Buffers: shared hit=259476

--------

on pg10 (1) -- foreign server pg10
create schema pg10;
CREATE TABLE pg10.tbl_ItemTransactions
(
TranID SERIAL
,TransactionDate TIMESTAMPTZ
,TransactionName TEXT
);
INSERT INTO pg10.tbl_ItemTransactions
(TransactionDate, TransactionName)
SELECT x, 'dbrnd'
FROM generate_series('2014-01-01 00:00:00'::timestamptz, '2016-08-01
00:00:00'::timestamptz,'2 seconds'::interval) a(x);

explain analyze SELECT count(1) FROM pg10.tbl_itemtransactions; --this
query is local

QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------------------------------------
Finalize Aggregate (cost=472650.72..472650.73 rows=1 width=8) (actual
time=2576.053..2576.054 rows=1 loops=1)
-> Gather (cost=472650.50..472650.71 rows=2 width=8) (actual
time=2575.721..2626.980 rows=3 loops=1)
Workers Planned: 2
Workers Launched: 2
-> Partial Aggregate (cost=471650.50..471650.51 rows=1 width=8)
(actual time=2569.302..2569.302 rows=1 loops=3)
-> Parallel Seq Scan on tbl_itemtransactions
(cost=0.00..429215.60 rows=16973960 width=0) (actual time=0.048..1492.144
rows=13579200 loops=3)
Planning time: 0.405 ms
Execution time: 2627.455 ms
(8 rows)
--------

on pg10 (2) -- foreign server pg10_qa
create schema pg10_qa;
CREATE TABLE pg10_qa.tbl_ItemTransactions
(
TranID SERIAL
,TransactionDate TIMESTAMPTZ
,TransactionName TEXT
);
INSERT INTO pg10_qa.tbl_ItemTransactions
(TransactionDate, TransactionName)
SELECT x, 'dbrnd'
FROM generate_series('2014-01-01 00:00:00'::timestamptz, '2016-08-01
00:00:00'::timestamptz,'2 seconds'::interval) a(x);

explain analyze SELECT count(1) FROM pg10_qa.tbl_itemtransactions; -- this
query is local

QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------------------------------------
Finalize Aggregate (cost=472650.72..472650.73 rows=1 width=8) (actual
time=2568.469..2568.469 rows=1 loops=1)
-> Gather (cost=472650.50..472650.71 rows=2 width=8) (actual
time=2568.067..2613.006 rows=3 loops=1)
Workers Planned: 2
Workers Launched: 2
-> Partial Aggregate (cost=471650.50..471650.51 rows=1 width=8)
(actual time=2563.893..2563.893 rows=1 loops=3)
-> Parallel Seq Scan on tbl_itemtransactions
(cost=0.00..429215.60 rows=16973960 width=0) (actual time=0.017..1388.417
rows=13579200 loops=3)
Planning time: 0.048 ms
Execution time: 2613.246 ms
(8 rows)

but i guess partition elimination still works across the shards (see
attached). atleast, we'll benefit from here :) in pg11.

Regards,
Vijay

On Mon, Feb 18, 2019 at 3:07 AM Jeff Janes <jeff(dot)janes(at)gmail(dot)com> wrote:

> On Sun, Feb 17, 2019 at 6:32 AM Vijaykumar Jain <vjain(at)opentable(dot)com>
> wrote:
>
>> I am yet to figure out the reason, what we have done is implement fake
>> columns to represent samples and giving them random numbers and keeping
>> other bulls to fake limit.
>>
>> Most of the queries that were impacted were the ones that did not push
>> order by and limit to foreign servers.
>> I am also trying to upgrade pg11 to make use of parallelisation.
>>
>
> postgres_fdw operates through declared cursors, and declared cursors
> inhibit parallel query. This doesn't change in v11, see
> https://www.postgresql.org/docs/11/when-can-parallel-query-be-used.html
>
> I'm not aware of any other changes in v11 that are likely to help you out.
>
> Cheers,
>
> Jeff
>
>>

Attachment Content-Type Size
pg11_partition_and_foreign_tables__FDW_.txt text/plain 19.6 KB

In response to

Browse pgsql-general by date

  From Date Subject
Next Message Gustavsson Mikael 2019-02-18 11:09:19 Slony and triggers on slavenodes.
Previous Message hvjunk 2019-02-18 08:57:06 Re: Slot issues