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.




DGFIP Nicolas Jouanin
Analyste - TVA8ième directive
Bureau SI-1C / DAP2
Tel: 02.51.88.50.18

Eco-attitude 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,

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.
Hello Jouanin,

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:

Previous
From: Yeb Havinga
Date:
Subject: Re: Two different execution plan for the same request
Next
From: Yeb Havinga
Date:
Subject: Re: Two different execution plan for the same request