Re: Two different execution plan for the same request - Mailing list pgsql-performance
| From | JOUANIN Nicolas (44) |
|---|---|
| Subject | Re: Two different execution plan for the same request |
| Date | |
| Msg-id | 4C343F31.2050402@dgfip.finances.gouv.fr Whole thread Raw |
| In response to | Re: Two different execution plan for the same request (Yeb Havinga <yebhavinga@gmail.com>) |
| Responses |
Re: Two different execution plan for the same request
Re: Two different execution plan for the same request |
| List | pgsql-performance |
Please find attached schema of tables and indexes involved.
Here is the pre-prod. environment config file:
listen_addresses = '*'
max_connections = 200
shared_buffers = 1024MB
work_mem = 24MB
maintenance_work_mem = 128MB
max_stack_depth = 6MB
max_fsm_pages = 204800
wal_buffers = 921MB
checkpoint_segments = 10
checkpoint_completion_target = 0.9
archive_mode = on
archive_command = 'cp -i %p /postgres/INST1/backup_xlog/%f'
enable_seqscan = off
random_page_cost = 4.0
effective_cache_size = 1536MB
log_destination = 'stderr'
logging_collector = on
log_directory = 'pg_log'
log_truncate_on_rotation = on
log_rotation_age = 1d
log_rotation_size = 0
log_min_duration_statement = 5000
log_duration = on
log_line_prefix='%t - user=%u,db=%d,sess=%c,proc=%p '
log_statement = 'all'
datestyle = 'iso, dmy'
lc_messages = 'C'
lc_monetary = 'C'
lc_numeric = 'C'
lc_time = 'C'
default_text_search_config = 'pg_catalog.english'
The development environment has :
listen_addresses = '*'
max_connections = 200
shared_buffers = 1024MB
work_mem = 24MB
maintenance_work_mem = 128MB
max_stack_depth = 6MB
max_fsm_pages = 204800
wal_buffers = 921MB
checkpoint_segments = 10
checkpoint_completion_target = 0.9
enable_seqscan = off
random_page_cost = 4.0
effective_cache_size = 1536MB
log_destination = 'stderr'
logging_collector = on
log_directory = 'pg_log'
log_truncate_on_rotation = on
log_rotation_age = 1d
log_rotation_size = 100MB
syslog_facility = 'LOCAL0'
syslog_ident = 'postgres'
silent_mode = on
log_duration = on
log_line_prefix = '%t - user=%u,db=%d '
log_statement = 'all'
datestyle = 'iso, mdy'
lc_messages = 'C'
lc_monetary = 'C'
lc_numeric = 'C'
lc_time = 'C'
default_text_search_config = 'pg_catalog.english'
The strange thing is that this morning explain analyze now gives a much better duration :
EXPLAIN analyze SELECT DISTINCT ConstantesTableNBienService.id,ConstantesTableNBienService.code,ConstantesTableNBienService.lib_code
FROM T_DEMANDE ConstantesTableDemande
LEFT OUTER JOIN T_OPERATION ConstantesTableOperation
ON ConstantesTableDemande.id_tech = ConstantesTableOperation.id_demande
LEFT OUTER JOIN T_BIEN_SERVICE ConstantesTableBienService
ON ConstantesTableBienService.id_operation = ConstantesTableOperation.id_tech
LEFT OUTER JOIN N_BIEN_SERVICE ConstantesTableNBienService
ON ConstantesTableBienService.bs_code = ConstantesTableNBienService.id
WHERE
ConstantesTableDemande.id_tech = 'y+3eRapRQjW8mtL4wHd4/A=='
AND ConstantesTableOperation.type_operation = 'acq'
AND ConstantesTableNBienService.parent is null
ORDER BY ConstantesTableNBienService.code ASC;
QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Unique (cost=3186430.11..3186466.21 rows=205 width=123) (actual time=3.075..3.325 rows=1 loops=1)
-> Sort (cost=3186430.11..3186439.13 rows=3610 width=123) (actual time=3.073..3.176 rows=187 loops=1)
Sort Key: constantestablenbienservice.code, constantestablenbienservice.id, constantestablenbienservice.lib_code
Sort Method: quicksort Memory: 24kB
-> Hash Left Join (cost=57.27..3186216.80 rows=3610 width=123) (actual time=0.913..2.795 rows=187 loops=1)
Hash Cond: (constantestablebienservice.bs_code = constantestablenbienservice.id)
Filter: (constantestablenbienservice.parent IS NULL)
-> Nested Loop Left Join (cost=35.39..3186095.62 rows=7221 width=4) (actual time=0.308..1.896 rows=187 loops=1)
-> Nested Loop (cost=0.00..5315.38 rows=1315 width=25) (actual time=0.164..0.250 rows=30 loops=1)
-> Index Scan using t_demande_pkey on t_demande constantestabledemande (cost=0.00..8.32 rows=1 width=25) (actual time=0.107..0.108 rows=1 loops=1)
Index Cond: ((id_tech)::text = 'y+3eRapRQjW8mtL4wHd4/A=='::text)
-> Index Scan using idx_operation_demande on t_operation constantestableoperation (cost=0.00..5293.91 rows=1315 width=50) (actual time=0.053..0.107 rows=30 loops=1)
Index Cond: ((constantestableoperation.id_demande)::text = 'y+3eRapRQjW8mtL4wHd4/A=='::text)
Filter: ((constantestableoperation.type_operation)::text = 'acq'::text)
-> Bitmap Heap Scan on t_bien_service constantestablebienservice (cost=35.39..2409.22 rows=770 width=29) (actual time=0.040..0.044 rows=6 loops=30)
Recheck Cond: ((constantestablebienservice.id_operation)::text = (constantestableoperation.id_tech)::text)
-> Bitmap Index Scan on idx_bien_service_operation (cost=0.00..35.19 rows=770 width=0) (actual time=0.037..0.037 rows=6 loops=30)
Index Cond: ((constantestablebienservice.id_operation)::text = (constantestableoperation.id_tech)::text)
-> Hash (cost=19.33..19.33 rows=205 width=127) (actual time=0.566..0.566 rows=205 loops=1)
-> Index Scan using n_bien_service_pkey on n_bien_service constantestablenbienservice (cost=0.00..19.33 rows=205 width=127) (actual time=0.045..0.294 rows=205 loops=1)
Total runtime: 3.518 ms
(21 lignes)
There were no modification made on the database except a restart yesterday evening and a vacuumdb --analyse ran at night.
-------- Message original --------
Sujet : Re: [PERFORM] Two different execution plan for the same request
De : Yeb Havinga <yebhavinga@gmail.com>
Pour : JOUANIN Nicolas (44) <nicolas.jouanin@dgfip.finances.gouv.fr>
Copie à : pgsql-performance@postgresql.org
Date : 07/07/2010 10:27
Here is the pre-prod. environment config file:
listen_addresses = '*'
max_connections = 200
shared_buffers = 1024MB
work_mem = 24MB
maintenance_work_mem = 128MB
max_stack_depth = 6MB
max_fsm_pages = 204800
wal_buffers = 921MB
checkpoint_segments = 10
checkpoint_completion_target = 0.9
archive_mode = on
archive_command = 'cp -i %p /postgres/INST1/backup_xlog/%f'
enable_seqscan = off
random_page_cost = 4.0
effective_cache_size = 1536MB
log_destination = 'stderr'
logging_collector = on
log_directory = 'pg_log'
log_truncate_on_rotation = on
log_rotation_age = 1d
log_rotation_size = 0
log_min_duration_statement = 5000
log_duration = on
log_line_prefix='%t - user=%u,db=%d,sess=%c,proc=%p '
log_statement = 'all'
datestyle = 'iso, dmy'
lc_messages = 'C'
lc_monetary = 'C'
lc_numeric = 'C'
lc_time = 'C'
default_text_search_config = 'pg_catalog.english'
The development environment has :
listen_addresses = '*'
max_connections = 200
shared_buffers = 1024MB
work_mem = 24MB
maintenance_work_mem = 128MB
max_stack_depth = 6MB
max_fsm_pages = 204800
wal_buffers = 921MB
checkpoint_segments = 10
checkpoint_completion_target = 0.9
enable_seqscan = off
random_page_cost = 4.0
effective_cache_size = 1536MB
log_destination = 'stderr'
logging_collector = on
log_directory = 'pg_log'
log_truncate_on_rotation = on
log_rotation_age = 1d
log_rotation_size = 100MB
syslog_facility = 'LOCAL0'
syslog_ident = 'postgres'
silent_mode = on
log_duration = on
log_line_prefix = '%t - user=%u,db=%d '
log_statement = 'all'
datestyle = 'iso, mdy'
lc_messages = 'C'
lc_monetary = 'C'
lc_numeric = 'C'
lc_time = 'C'
default_text_search_config = 'pg_catalog.english'
The strange thing is that this morning explain analyze now gives a much better duration :
EXPLAIN analyze SELECT DISTINCT ConstantesTableNBienService.id,ConstantesTableNBienService.code,ConstantesTableNBienService.lib_code
FROM T_DEMANDE ConstantesTableDemande
LEFT OUTER JOIN T_OPERATION ConstantesTableOperation
ON ConstantesTableDemande.id_tech = ConstantesTableOperation.id_demande
LEFT OUTER JOIN T_BIEN_SERVICE ConstantesTableBienService
ON ConstantesTableBienService.id_operation = ConstantesTableOperation.id_tech
LEFT OUTER JOIN N_BIEN_SERVICE ConstantesTableNBienService
ON ConstantesTableBienService.bs_code = ConstantesTableNBienService.id
WHERE
ConstantesTableDemande.id_tech = 'y+3eRapRQjW8mtL4wHd4/A=='
AND ConstantesTableOperation.type_operation = 'acq'
AND ConstantesTableNBienService.parent is null
ORDER BY ConstantesTableNBienService.code ASC;
QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Unique (cost=3186430.11..3186466.21 rows=205 width=123) (actual time=3.075..3.325 rows=1 loops=1)
-> Sort (cost=3186430.11..3186439.13 rows=3610 width=123) (actual time=3.073..3.176 rows=187 loops=1)
Sort Key: constantestablenbienservice.code, constantestablenbienservice.id, constantestablenbienservice.lib_code
Sort Method: quicksort Memory: 24kB
-> Hash Left Join (cost=57.27..3186216.80 rows=3610 width=123) (actual time=0.913..2.795 rows=187 loops=1)
Hash Cond: (constantestablebienservice.bs_code = constantestablenbienservice.id)
Filter: (constantestablenbienservice.parent IS NULL)
-> Nested Loop Left Join (cost=35.39..3186095.62 rows=7221 width=4) (actual time=0.308..1.896 rows=187 loops=1)
-> Nested Loop (cost=0.00..5315.38 rows=1315 width=25) (actual time=0.164..0.250 rows=30 loops=1)
-> Index Scan using t_demande_pkey on t_demande constantestabledemande (cost=0.00..8.32 rows=1 width=25) (actual time=0.107..0.108 rows=1 loops=1)
Index Cond: ((id_tech)::text = 'y+3eRapRQjW8mtL4wHd4/A=='::text)
-> Index Scan using idx_operation_demande on t_operation constantestableoperation (cost=0.00..5293.91 rows=1315 width=50) (actual time=0.053..0.107 rows=30 loops=1)
Index Cond: ((constantestableoperation.id_demande)::text = 'y+3eRapRQjW8mtL4wHd4/A=='::text)
Filter: ((constantestableoperation.type_operation)::text = 'acq'::text)
-> Bitmap Heap Scan on t_bien_service constantestablebienservice (cost=35.39..2409.22 rows=770 width=29) (actual time=0.040..0.044 rows=6 loops=30)
Recheck Cond: ((constantestablebienservice.id_operation)::text = (constantestableoperation.id_tech)::text)
-> Bitmap Index Scan on idx_bien_service_operation (cost=0.00..35.19 rows=770 width=0) (actual time=0.037..0.037 rows=6 loops=30)
Index Cond: ((constantestablebienservice.id_operation)::text = (constantestableoperation.id_tech)::text)
-> Hash (cost=19.33..19.33 rows=205 width=127) (actual time=0.566..0.566 rows=205 loops=1)
-> Index Scan using n_bien_service_pkey on n_bien_service constantestablenbienservice (cost=0.00..19.33 rows=205 width=127) (actual time=0.045..0.294 rows=205 loops=1)
Total runtime: 3.518 ms
(21 lignes)
There were no modification made on the database except a restart yesterday evening and a vacuumdb --analyse ran at night.
| Nicolas Jouanin Analyste - TVA8ième directive Bureau SI-1C / DAP2 | Tel: 02.51.88.50.18 | |
| Adoptez l'éco-attitude. N'imprimez ce courriel que si c'est vraiment nécessaire |
-------- Message original --------
Sujet : Re: [PERFORM] Two different execution plan for the same request
De : Yeb Havinga <yebhavinga@gmail.com>
Pour : JOUANIN Nicolas (44) <nicolas.jouanin@dgfip.finances.gouv.fr>
Copie à : pgsql-performance@postgresql.org
Date : 07/07/2010 10:27
JOUANIN Nicolas (44) wrote:Hi,Hello Jouanin,
I've trouble with some SQL request which have different execution plans when ran on two different servers. One server is the development environment, the othe rone is th pre-production env.
Both servers run postgreSQL 8.3.0 on Linux and :
- both databases contains the same data (pg_dump/pg_restore between servers)
- instances have the same configuration parameters
- vaccum and analyze is run every day.
The only difference I can see is the hardware. The pre-preoduction env. has more RAM, more CPU and a RAID5 disk array through LVM where data are stored.
Could you give some more information following the guidelines from http://wiki.postgresql.org/wiki/SlowQueryQuestions ?
Essential are the contents from both conf files (comments may be removed).
regards,
Yeb Havinga
pgsql-performance by date: