Performance of Postgresql Foreign Data Wrapper

From: "Cassiano, Marco" <mcassiano(at)manord(dot)com>
To: "pgsql-performance(at)postgresql(dot)org" <pgsql-performance(at)postgresql(dot)org>
Subject: Performance of Postgresql Foreign Data Wrapper
Date: 2015-01-14 16:48:10
Message-ID: 1361CEF686657C41A139AD8C3145632B44B33A8F@E2010-MB1.manord.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

Hello,

If possible, I would need your help/suggestions for this problem :

I'm experiencing a serious performance problem using postgresql foreign data wrapper.
In particular, a simple query performed via fdw lasts 80 times more than the same query performed directly on the local server.

Here are the details :

I have two postgresql servers both located on the same server farm, based on Vmware Esxi 5.1.
They're communicating directly on the same subnet, so network should't interfere with performance.
On the first server, which I'll call LOCAL, I defined a postgres_fdw foreign server pointing to the other server, which I'll call REMOTE.
Both servers are running Postgresql 9.3.5 (see bottom for complete details on server configuration)

On the local server I defined a foreign table "v_mdn_colli_testata" pointing to the remote server.
The foreign table is defined in this way :

CREATE FOREIGN TABLE logimat.v_mdn_colli_testata
(id bigint ,
collo character varying(20) ,
stato character(1) ,
id_spedizione bigint ,
id_es_rientro bigint ,
peso numeric(15,3) ,
volume numeric(15,3) ,
ordine character varying(20) ,
data timestamp without time zone ,
capoconto text ,
conto text ,
causale character varying(10) ,
descrizione character varying(50) ,
tipo character varying(10) ,
capoconto_v text ,
conto_v text ,
magazzino character varying(5) ,
tipo_spedizione integer ,
data_spedizione date ,
consegna_spedizione character varying(2) ,
documento character varying(20) ,
data_documento timestamp without time zone ,
borderau character varying(15) ,
data_borderau timestamp without time zone )
SERVER fdw_remote_server
OPTIONS (schema_name 'public', table_name 'v_mdn_colli_testata');
ALTER FOREIGN TABLE logimat.v_mdn_colli_testata
OWNER TO dba;

The table pointed on the remote server by the foreign table is actually a view defined in this way :

CREATE OR REPLACE VIEW v_mdn_colli_testata AS
SELECT uds.id,
uds.codice AS collo,
uds.flag1 AS stato,
uds.id_spedizione,
uds.id_reso AS id_es_rientro,
uds.peso_netto AS peso,
uds.volume,
o.ordine,
o.data,
"substring"(o.destinatario::text, 1, 6) AS capoconto,
"substring"(o.destinatario::text, 7, 7) AS conto,
o.causale,
o.desc_causale AS descrizione,
o.tipo_ordine AS tipo,
"substring"(o.corriere::text, 1, 6) AS capoconto_v,
"substring"(o.corriere::text, 7, 7) AS conto_v,
o.magazzino_prespedizione AS magazzino,
o.priorita_codice AS tipo_spedizione,
o.priorita_data AS data_spedizione,
o.priorita_consegna AS consegna_spedizione,
doc.ddt AS documento,
doc.data_ddt AS data_documento,
doc.borderau,
doc.data_borderau
FROM ordine_allestimento o
LEFT JOIN allestimento al ON o.azienda::text = al.azienda::text AND o.divisione::text = al.divisione::text AND o.sezione::text = al.sezione::text AND o.ordine::text = al.ordine::text AND o.riga::text = al.riga::text
LEFT JOIN azienda az ON az.codice::text = o.azienda::text
LEFT JOIN soggetto s ON s.id_azienda = az.id AND s.soggetto::text = o.destinatario::text
LEFT JOIN lista_allestimento_riga lr ON lr.id = al.id_riga_lista
LEFT JOIN lista_allestimento la ON la.id = lr.id_lista
LEFT JOIN documento_riga dr ON dr.id_riga_lista = lr.id
LEFT JOIN documento doc ON doc.id = dr.id_documento
LEFT JOIN packing_list_riga pr ON pr.id_riga_lista = lr.id
LEFT JOIN oper_pian op ON op.id = pr.id_oper_pian
LEFT JOIN uds ON uds.id = pr.id_uds
LEFT JOIN packing_list pl ON pl.id = uds.id_packing_list
WHERE la.id_tipo_lista = 147916620 AND uds.id IS NOT NULL;

And here's is the problem :

on the REMOTE SERVER, the query :

select * from public.v_mdn_colli_testata where collo='U0019502'

has an execution time slightly greater than 100 ms :

INFOLOG=# select * from public.v_mdn_colli_testata where collo='U0019502';
-[ RECORD 1 ]-------+------------------------------
id | 165999157
collo | U0019502
stato | P
id_spedizione |
id_es_rientro |
peso | 0.500
volume | 0.000
ordine | 001824
data | 2015-01-08 16:56:03.714
capoconto | 000100
conto | 0001401
causale | PMP
descrizione | INVIO MATERIALE PUBBLICITARIO
tipo | ORDT
capoconto_v | 000200
conto_v | 0006128
magazzino | 00039
tipo_spedizione | 0
data_spedizione |
consegna_spedizione |
documento | 00000026
data_documento | 2015-01-09 15:54:17.706
borderau | 00003212
data_borderau | 2015-01-09 00:00:00

Time: 104.907 ms
***************************************************************

on the LOCAL server instead, the same query performed on the foreign table lasts much longer :

mdn=# select * from logimat.v_mdn_colli_testata where collo='U0019502';
-[ RECORD 1 ]-------+------------------------------
id | 165999157
collo | U0019502
stato | P
id_spedizione |
id_es_rientro |
peso | 0.500
volume | 0.000
ordine | 001824
data | 2015-01-08 16:56:03.714
capoconto | 000100
conto | 0001401
causale | PMP
descrizione | INVIO MATERIALE PUBBLICITARIO
tipo | ORDT
capoconto_v | 000200
conto_v | 0006128
magazzino | 00039
tipo_spedizione | 0
data_spedizione |
consegna_spedizione |
documento | 00000026
data_documento | 2015-01-09 15:54:17.706
borderau | 00003212
data_borderau | 2015-01-09 00:00:00

Time: 9887.533 ms
***************************************************************

Both query were issued repeatedly to get rid of disk access and database connection overhead time.

Activating duration and statement logging on the remote server I can see that the query issued through the fdw from the LOCAL SERVER
is actually performed by opening a cursor :

2015-01-14 13:53:31 GMT 192.168.2.31(58031) mdn INFOLOG 0 54b64297.327c - LOG: statement: START TRANSACTION ISOLATION LEVEL REPEATABLE READ
2015-01-14 13:53:31 GMT 192.168.2.31(58031) mdn INFOLOG 0 54b64297.327c - LOG: execute <unnamed>: DECLARE c1 CURSOR FOR SELECT id, collo, stato, id_spedizione, id_es_rientro, peso, volume, ordine, data, capoconto, conto, causale, descrizione, tipo, capoconto_v, conto_v, magazzino, tipo_spedizione, data_spedizione, consegna_spedizione, documento, data_documento, borderau, data_borderau FROM public.v_mdn_colli_testata WHERE ((collo = 'U0019502'::text))
2015-01-14 13:53:31 GMT 192.168.2.31(58031) mdn INFOLOG 0 54b64297.327c - LOG: statement: FETCH 100 FROM c1
2015-01-14 13:53:41 GMT 192.168.2.31(58031) mdn INFOLOG 0 54b64297.327c - LOG: duration: 9887.533 ms
2015-01-14 13:53:41 GMT 192.168.2.31(58031) mdn INFOLOG 0 54b64297.327c - LOG: statement: CLOSE c1
2015-01-14 13:53:41 GMT 192.168.2.31(58031) mdn INFOLOG 0 54b64297.327c - LOG: statement: COMMIT TRANSACTION

My questions are :

IS THIS THE EXPECT BEHAVIOUR ?
IS THERE ANY WAY TO MODIFY IT AND IMPROVE THE PERFORMANCE ?

I hope everything is clear
THANKS VERY MUCH IN ADVANCE

Marco

I include information about my environment :

HARDWARE:
---------
Both servers are virtual machines running on Vmware Esxi 5.1
LOCAL : 2 vCpu Intel Xeon E5-2690v2 3.00 Ghz , 6GB RAM
REMOTE : 2 cpu, Intel Xeon E7-2860 2.27 GHz , 6GB RAM

Storage on SAN-based datastore

POSTGRESQL VERSION :
---------------------

LOCAL SERVER : PostgreSQL 9.3.5 on x86_64-unknown-linux-gnu, compiled by gcc (GCC) 4.4.7 20120313 (Red Hat 4.4.7-3), 64-bit
REMOTE SERVER: PostgreSQL 9.3.5 on x86_64-unknown-linux-gnu, compiled by gcc (GCC) 4.4.7 20120313 (Red Hat 4.4.7-3), 64-bit

Postgresql compiled from source with :

OPTIONS :
./configure --with-python --with-gssapi --with-krb-srvnam=POSTGRES
MODULES :
- pg_upgrade
- adminpack
- pg_upgrade_support
- pgrowlocks
- pg_archivecleanup
- pg_test_fsync
- pg_buffercache
- postgres_fdw
- pg_buffercache.sql
- itcodes/italian_codes

POSTGRESQL CONFIGURATION :
---------------------------

LOCAL SERVER:

mdn=# SELECT name, current_setting(name), source
mdn-# FROM pg_settings
mdn-# WHERE source NOT IN ('default', 'override');
name | current_setting | source
--------------------------------+--------------------------------+----------------------
application_name | psql | client
autovacuum | on | configuration file
autovacuum_max_workers | 7 | configuration file
autovacuum_naptime | 10min | configuration file
autovacuum_vacuum_cost_delay | 20ms | configuration file
autovacuum_vacuum_cost_limit | 200 | configuration file
bytea_output | escape | configuration file
checkpoint_completion_target | 0.8 | configuration file
checkpoint_segments | 32 | configuration file
checkpoint_timeout | 10min | configuration file
checkpoint_warning | 30s | configuration file
client_encoding | UTF8 | client
client_min_messages | warning | configuration file
debug_pretty_print | off | configuration file
debug_print_parse | off | configuration file
debug_print_plan | off | configuration file
debug_print_rewritten | off | configuration file
default_statistics_target | 200 | configuration file
effective_cache_size | 5870MB | configuration file
fsync | on | configuration file
full_page_writes | on | configuration file
krb_server_keyfile | /usr/local/pgconf/PGpgsviltab | configuration file
krb_srvname | POSTGRES | configuration file
lc_messages | en_US.UTF-8 | configuration file
lc_monetary | en_US.UTF-8 | configuration file
lc_numeric | en_US.UTF-8 | configuration file
lc_time | en_US.UTF-8 | configuration file
listen_addresses | * | configuration file
log_autovacuum_min_duration | 1s | configuration file
log_checkpoints | on | configuration file
log_connections | off | configuration file
log_destination | stderr,syslog | configuration file
log_directory | /dbms/logs | configuration file
log_disconnections | off | configuration file
log_duration | off | configuration file
log_error_verbosity | default | configuration file
log_filename | postgresql-%Y-%m-%d_%H%M%S.log | configuration file
log_line_prefix | %t %r %u %d %x %c - | configuration file
log_min_duration_statement | 6s | configuration file
log_min_error_statement | error | configuration file
log_min_messages | warning | configuration file
log_rotation_age | 1d | configuration file
log_rotation_size | 0 | configuration file
log_statement | none | configuration file
log_truncate_on_rotation | off | configuration file
logging_collector | on | configuration file
maintenance_work_mem | 300MB | configuration file
max_connections | 100 | configuration file
max_stack_depth | 2MB | environment variable
port | 5432 | configuration file
random_page_cost | 2 | configuration file
shared_buffers | 1GB | configuration file
superuser_reserved_connections | 3 | configuration file
synchronous_commit | off | configuration file
syslog_facility | local1 | configuration file
syslog_ident | postgres | configuration file
temp_buffers | 8MB | configuration file
TimeZone | Europe/Rome | configuration file
track_activities | on | configuration file
track_counts | on | configuration file
vacuum_cost_delay | 0 | configuration file
vacuum_cost_limit | 200 | configuration file
wal_buffers | 16MB | configuration file
work_mem | 12MB | configuration file
(64 rows)

REMOTE SERVER:

INFOLOG=# SELECT name, current_setting(name), source
INFOLOG-# FROM pg_settings
INFOLOG-# WHERE source NOT IN ('default', 'override');
name | current_setting | source
--------------------------------+-----------------------------------------------+----------------------
application_name | psql | client
archive_command | /usr/local/bin/pg_wal_archive_script.sh %p %f | configuration file
archive_mode | on | configuration file
archive_timeout | 0 | configuration file
autovacuum | on | configuration file
autovacuum_max_workers | 7 | configuration file
autovacuum_naptime | 10min | configuration file
autovacuum_vacuum_cost_delay | 20ms | configuration file
autovacuum_vacuum_cost_limit | 200 | configuration file
bytea_output | escape | configuration file
checkpoint_completion_target | 0.8 | configuration file
checkpoint_segments | 32 | configuration file
checkpoint_timeout | 10min | configuration file
client_encoding | UTF8 | client
client_min_messages | warning | configuration file
debug_pretty_print | off | configuration file
debug_print_parse | off | configuration file
debug_print_plan | off | configuration file
debug_print_rewritten | off | configuration file
default_statistics_target | 200 | configuration file
effective_cache_size | 5870MB | configuration file
fsync | on | configuration file
full_page_writes | on | configuration file
lc_messages | en_US.UTF-8 | configuration file
lc_monetary | en_US.UTF-8 | configuration file
lc_numeric | en_US.UTF-8 | configuration file
lc_time | en_US.UTF-8 | configuration file
listen_addresses | * | configuration file
log_autovacuum_min_duration | 1s | configuration file
log_checkpoints | on | configuration file
log_connections | off | configuration file
log_destination | stderr,syslog | configuration file
log_directory | /dbms/logs | configuration file
log_disconnections | off | configuration file
log_duration | off | configuration file
log_error_verbosity | default | configuration file
log_filename | postgresql-%Y-%m-%d_%H%M%S.log | configuration file
log_line_prefix | %t %r %u %d %x %c - | configuration file
log_min_duration_statement | 6s | configuration file
log_min_error_statement | error | configuration file
log_min_messages | error | configuration file
log_rotation_age | 1d | configuration file
log_rotation_size | 0 | configuration file
log_statement | none | configuration file
log_truncate_on_rotation | off | configuration file
logging_collector | on | configuration file
maintenance_work_mem | 300MB | configuration file
max_connections | 250 | configuration file
max_stack_depth | 2MB | environment variable
max_wal_senders | 5 | configuration file
port | 5432 | configuration file
random_page_cost | 2 | configuration file
shared_buffers | 1GB | configuration file
superuser_reserved_connections | 6 | configuration file
synchronous_commit | off | configuration file
syslog_facility | local4 | configuration file
syslog_ident | postgres | configuration file
temp_buffers | 8MB | configuration file
track_activities | on | configuration file
track_counts | on | configuration file
vacuum_cost_delay | 0 | configuration file
vacuum_cost_limit | 200 | configuration file
wal_buffers | 16MB | configuration file
wal_keep_segments | 10 | configuration file
wal_level | hot_standby | configuration file
work_mem | 12MB | configuration file
(66 rows)

OPERATING SYSTEM :
----------------------

LOCAL SERVER :

Centos 6.4
uname -a
Linux pg64test1.manord.com 2.6.32-358.14.1.el6.x86_64 #1 SMP Tue Jul 16 23:51:20 UTC 2013 x86_64 x86_64 x86_64 GNU/Linux

REMOTE SERVER :

Centos 6.5
uname -a
Linux pg64infolog.manord.com 2.6.32-431.3.1.el6.x86_64 #1 SMP Fri Jan 3 21:39:27 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Huan Ruan 2015-01-15 11:30:55 shared_buffers vs Linux file cache
Previous Message Merlin Moncure 2015-01-12 16:02:12 Re: New server optimization advice