[pgpool-general: 1947] Re: 40% performance loss when using pgpool with postgres foreign data wrapper

Lonni J Friedman netllama at gmail.com
Sat Jul 27 01:35:23 JST 2013


On Thu, Jul 25, 2013 at 5:11 PM, Tatsuo Ishii <ishii at postgresql.org> wrote:
>> On Wed, Jul 24, 2013 at 6:27 PM, Tatsuo Ishii <ishii at postgresql.org> wrote:
>>>> On Wed, Jul 24, 2013 at 5:19 PM, Tatsuo Ishii <ishii at postgresql.org> wrote:
>>>>>> On Tue, Jul 23, 2013 at 9:59 PM, Tatsuo Ishii <ishii at postgresql.org> wrote:
>>>>>>>> On Tue, Jul 23, 2013 at 5:42 PM, Tatsuo Ishii <ishii at postgresql.org> wrote:
>>>>>>>>> Not sure how is like your configuration. Did you actually test like this?
>>>>>>>>>
>>>>>>>>> pgbench/psql -> CLUSTER_A -> PG_FDW -> pgpool_B -> CLUSTER_B
>>>>>>>>
>>>>>>>> Yes, that's the config that exhibited the 40% performance loss.
>>>>>>>
>>>>>>> If you try this:
>>>>>>>
>>>>>>> pgbench/psql -> pgpool_B -> CLUSTER_B
>>>>>>>
>>>>>>> How is the performance?
>>>>>>
>>>>>> Perf is pretty good, nearly the same as:
>>>>>> pgbench/psql -> CLUSTER_A
>>>>>
>>>>> Interesting.
>>>>>
>>>>>> Actual output:
>>>>>> ########
>>>>>> Scale option ignored, using pgbench_branches table count = 10000
>>>>>> transaction type: TPC-B (sort of)
>>>>>> scaling factor: 10000
>>>>>> query mode: simple
>>>>>> number of clients: 10
>>>>>> number of threads: 10
>>>>>> duration: 3600 s
>>>>>> number of transactions actually processed: 7922742
>>>>>> tps = 2200.752746 (including connections establishing)
>>>>>> tps = 2200.760460 (excluding connections establishing)
>>>>>> ########
>>>>>>
>>>>>> It seems conclusive that pgpool is somehow not handling the FDW stuff
>>>>>> well.  Can you try setting something similar up on your end, and see
>>>>>> if you can reproduce the perf loss?  It doesn't require any special
>>>>>> data, just the normal default pgbench schema.
>>>>>
>>>>> I'll give it a try when I have spare time. At this point my wild guess
>>>>> is PG_FDW does not generate good enough query plan. Can you show
>>>>> EXPLAIN VERBOSE result?
>>>>
>>>> How do I run pgbench with EXPLAIN?
>>>
>>> In this configuration:
>>> pgbench/psql -> CLUSTER_A -> PG_FDW -> pgpool_B -> CLUSTER_B
>>>
>>> 1) enable query log at CLUSTER_A
>>>
>>> 2) run pgbench
>>>
>>> 3) you will get some SELECTs, INSERTs, UPDATEs query. Choose one of
>>>    them from each type of query as samples.
>>>
>>> 4) EXPLAIN ANALYZE query_sample
>
> Sorry, you need to execute EXPLAIN ANALYZE VEBOSE to get the remote
> execution plan. Also the PostgreSQL manual suggests that ANALYZE on
> the foreign table helps to update the remote table statistics.

I re-ran the commands with VERBOSE, but that still had no impact, as
the queries without pgpool had the same cost as with pgpool.  Here's
the output:
######
nightly=# EXPLAIN ANALYZE VERBOSE SELECT aid, bid, abalance, filler,
ctid FROM public.pgbench_accounts WHERE ((aid = 708983046)) FOR UPDATE
;
                                                           QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------
 LockRows  (cost=100.00..111.38 rows=1 width=734) (actual
time=0.801..0.803 rows=1 loops=1)
   Output: aid, bid, abalance, filler, ctid, pgbench_accounts.*
   ->  Foreign Scan on public.pgbench_accounts  (cost=100.00..111.37
rows=1 width=734) (actual time=0.800..0.801 rows=1 loops=1)
         Output: aid, bid, abalance, filler, ctid, pgbench_accounts.*
         Remote SQL: SELECT aid, bid, abalance, filler, ctid FROM
public.pgbench_accounts WHERE ((aid = 708983046)) FOR UPDATE
 Total runtime: 1.448 ms
(6 rows)

nightly=# EXPLAIN ANALYZE VERBOSE SELECT NULL FROM public.pgbench_branches ;
                                                            QUERY PLAN
----------------------------------------------------------------------------------------------------------------------------------
 Foreign Scan on public.pgbench_branches  (cost=100.00..212.39
rows=3413 width=0) (actual time=1.537..267.226 rows=10000 loops=1)
   Output: NULL::unknown
   Remote SQL: SELECT NULL FROM public.pgbench_branches
 Total runtime: 268.820 ms
(4 rows)

nightly=# EXPLAIN ANALYZE VERBOSE SELECT abalance FROM
public.pgbench_accounts WHERE ((aid = 346327473)) ;
                                                        QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------
 Foreign Scan on public.pgbench_accounts  (cost=100.00..146.86 rows=15
width=4) (actual time=0.931..0.933 rows=1 loops=1)
   Output: abalance
   Remote SQL: SELECT abalance FROM public.pgbench_accounts WHERE
((aid = 346327473))
 Total runtime: 1.634 ms
(4 rows)

nightly=# EXPLAIN ANALYZE VERBOSE UPDATE public.pgbench_branches SET
bbalance = '85975' WHERE ctid = '(123,130)';
                                                           QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------
 Update on public.pgbench_branches  (cost=100.00..112.65 rows=1
width=366) (actual time=0.968..0.968 rows=0 loops=1)
   Remote SQL: UPDATE public.pgbench_branches SET bbalance = $2 WHERE ctid = $1
   ->  Foreign Scan on public.pgbench_branches  (cost=100.00..112.65
rows=1 width=366) (actual time=0.956..0.956 rows=0 loops=1)
         Output: bid, 85975, filler, ctid
         Remote SQL: SELECT bid, filler, ctid FROM
public.pgbench_branches WHERE ((ctid = '(123,130)'::tid)) FOR UPDATE
 Total runtime: 1.660 ms
(6 rows)

nightly=# EXPLAIN ANALYZE VERBOSE INSERT INTO
public.pgbench_history(tid, bid,aid, delta, mtime, filler) VALUES
('10526','8889','708983046','1806','2013-07-25 13:30:35.078487',NULL);
                                                          QUERY PLAN
------------------------------------------------------------------------------------------------------------------------------
 Insert on public.pgbench_history  (cost=0.00..0.01 rows=1 width=0)
(actual time=1.164..1.164 rows=0 loops=1)
   Remote SQL: INSERT INTO public.pgbench_history(tid, bid, aid,
delta, mtime, filler) VALUES ($1, $2, $3, $4, $5, $6)
   ->  Result  (cost=0.00..0.01 rows=1 width=0) (actual
time=0.001..0.002 rows=1 loops=1)
         Output: 10526, 8889, 708983046, 1806, '2013-07-25
13:30:35.078487'::timestamp without time zone, NULL::character(22)
 Total runtime: 1.976 ms
(5 rows)
######





>> ok, I did as you suggested, however it didn't really provide any
>> useful clues.  The EXPLAIN cost ranges were identical regardless of
>> whether pgpool_B was in the configuration.  However, the pgbench tps
>> numbers remained dramatically different (by about 40%).  Anyway,
>> here's the EXPLAIN output for the most common queries:
>>
>> nightly=# EXPLAIN ANALYZE SELECT aid, bid, abalance, filler, ctid FROM
>> public.pgbench_accounts WHERE ((aid = 708983046)) FOR UPDATE ;
>>                                                         QUERY PLAN
>> --------------------------------------------------------------------------------------------------------------------------
>>  LockRows  (cost=100.00..111.38 rows=1 width=734) (actual
>> time=2.729..2.731 rows=1 loops=1)
>>    ->  Foreign Scan on pgbench_accounts  (cost=100.00..111.37 rows=1
>> width=734) (actual time=2.728..2.730 rows=1 loops=1)
>>  Total runtime: 4.297 ms
>> (3 rows)
>>
>> nightly=# EXPLAIN ANALYZE SELECT NULL FROM public.pgbench_branches ;
>>                                                         QUERY PLAN
>> ---------------------------------------------------------------------------------------------------------------------------
>>  Foreign Scan on pgbench_branches  (cost=100.00..212.39 rows=3413
>> width=0) (actual time=3.148..174.946 rows=10000 loops=1)
>>  Total runtime: 177.309 ms
>> (2 rows)
>>
>> nightly=# EXPLAIN ANALYZE SELECT abalance FROM public.pgbench_accounts
>> WHERE ((aid = 346327473)) ;
>>                                                     QUERY PLAN
>> -------------------------------------------------------------------------------------------------------------------
>>  Foreign Scan on pgbench_accounts  (cost=100.00..146.86 rows=15
>> width=4) (actual time=2.365..2.366 rows=1 loops=1)
>>  Total runtime: 3.587 ms
>> (2 rows)
>>
>> nightly=# EXPLAIN ANALYZE UPDATE public.pgbench_branches SET bbalance
>> = '85975' WHERE ctid = '(123,130)';
>>                                                         QUERY PLAN
>> --------------------------------------------------------------------------------------------------------------------------
>>  Update on pgbench_branches  (cost=100.00..112.65 rows=1 width=366)
>> (actual time=3.043..3.043 rows=0 loops=1)
>>    ->  Foreign Scan on pgbench_branches  (cost=100.00..112.65 rows=1
>> width=366) (actual time=3.037..3.037 rows=0 loops=1)
>>  Total runtime: 4.321 ms
>> (3 rows
>>
>> nightly=# EXPLAIN ANALYZE INSERT INTO public.pgbench_history(tid, bid,
>> aid, delta, mtime, filler) VALUES
>> ('10526','8889','708983046','1806','2013-07-25 13:30:35.078487',NULL);
>>                                               QUERY PLAN
>> -------------------------------------------------------------------------------------------------------
>>  Insert on pgbench_history  (cost=0.00..0.01 rows=1 width=0) (actual
>> time=2.576..2.576 rows=0 loops=1)
>>    ->  Result  (cost=0.00..0.01 rows=1 width=0) (actual
>> time=0.002..0.002 rows=1 loops=1)
>>  Total runtime: 4.042 ms
>> (3 rows)


More information about the pgpool-general mailing list