[pgpool-general: 2000] Re: 40% performance loss when using pgpool with postgres foreign data wrapper
Lonni J Friedman
netllama at gmail.com
Tue Aug 6 10:30:43 JST 2013
Thanks for investigating. At least I now have a better understanding
of what is happening and why.
On Sun, Aug 4, 2013 at 9:01 PM, Tatsuo Ishii <ishii at postgresql.org> wrote:
> Hi Lonni,
>
> I finally had a chance to try it out. I have a Laptop with SSD, 2 CORE
> i5, mem 8GB machine running Linux. First of all, I noticed
> Postgres_fdw addes quite performance loss even without pgpool-II. The
> performance drops from test case #4(Without pgpool & without FDW) to
> test case #3(without pgpool & with FDW) is 75.3%. This is because
> Postgres_fdw adds lots of query to the original. Without FDW, the
> query looks like this:
>
> 13083 2013-08-05 12:14:44 JST LOG: statement: SELECT abalance FROM pgbench_accounts WHERE aid = 25806;
>
> With FDW:
>
> 12987 2013-08-05 12:12:57 JST LOG: statement: START TRANSACTION ISOLATION LEVEL REPEATABLE READ
> 12987 2013-08-05 12:12:57 JST LOG: execute <unnamed>: DECLARE c1 CURSOR FOR
> SELECT abalance FROM public.pgbench_accounts WHERE ((aid = 79891))
> 12987 2013-08-05 12:12:57 JST LOG: statement: FETCH 100 FROM c1
> 12987 2013-08-05 12:12:57 JST LOG: statement: CLOSE c1
> 12987 2013-08-05 12:12:57 JST LOG: statement: COMMIT TRANSACTION
>
> As you can see the number of quries grows from 1 to 5.
>
> Remeber that pgpool needs to read and write packets from clients. Thus
> if the number of packets needed to be processed grows, the performance
> penalty will be larger. In fact, the performance loss #2(with pgpool &
> without FDW) vs. #1(with pgpool & FDW) is 76.8%, which is almost same
> as the loss above.
>
> In short, I see no strange behavior with pgpool-II+Postgres_fdw.
>
> 1) With pgpool & FDW:
> pgbench->PostgreSQL 9.3 beta2, fdw(port 11000)->pgpool-II 3.3.0 (port 11002)->PostgreSQL 9.3 beta2(port 11001)
> [t-ishii at localhost fdw]$ pgbench -n -S -c 1 -T30 -p 11000 test
> transaction type: SELECT only
> scaling factor: 1
> query mode: simple
> number of clients: 1
> number of threads: 1
> duration: 30 s
> number of transactions actually processed: 37871
> tps = 1262.356526 (including connections establishing)
> tps = 1262.481595 (excluding connections establishing)
>
> 2) With pgpool & without FDW:
> pgbench->pgpool-II 3.3.0 (port 11002)->PostgreSQL 9.3 beta2(port 11001)
> [t-ishii at localhost fdw]$ pgbench -n -S -c 1 -T30 -p 11002 test
> transaction type: SELECT only
> scaling factor: 1
> query mode: simple
> number of clients: 1
> number of threads: 1
> duration: 30 s
> number of transactions actually processed: 163473
> tps = 5449.067306 (including connections establishing)
> tps = 5449.106357 (excluding connections establishing)
>
> 3) Without pgpool & with FDW:
> pgbench->PostgreSQL 9.3 beta2, fdw(port 11000)->PostgreSQL 9.3 beta2(port 11001)
> [t-ishii at localhost fdw]$ pgbench -n -S -c 1 -T30 -p 11000 test2
> transaction type: SELECT only
> scaling factor: 1
> query mode: simple
> number of clients: 1
> number of threads: 1
> duration: 30 s
> number of transactions actually processed: 60157
> tps = 2005.152526 (including connections establishing)
> tps = 2005.247571 (excluding connections establishing)
>
> 4) Without pgpool & without FDW:
> pgbench->PostgreSQL 9.3 beta2(port 11001)
> [t-ishii at localhost fdw]$ pgbench -n -S -c 1 -T30 -p 11001 test
> transaction type: SELECT only
> scaling factor: 1
> query mode: simple
> number of clients: 1
> number of threads: 1
> duration: 30 s
> number of transactions actually processed: 244106
> tps = 8136.839544 (including connections establishing)
> tps = 8137.810924 (excluding connections establishing)
>
>
>> Hi Tatsuo,
>> Have you had a chance to replicate this problem yet?
>>
>> thanks
>>
>> On Fri, Jul 26, 2013 at 9:35 AM, Lonni J Friedman <netllama at gmail.com> wrote:
>>> 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)
--
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
L. Friedman netllama at gmail.com
LlamaLand https://netllama.linux-sxs.org
More information about the pgpool-general
mailing list