Re: Two different execution plan for the same request

From: "JOUANIN Nicolas (44)" <nicolas(dot)jouanin(at)dgfip(dot)finances(dot)gouv(dot)fr>
To: Yeb Havinga <yebhavinga(at)gmail(dot)com>
Cc: pgsql-performance(at)postgresql(dot)org
Subject: Re: Two different execution plan for the same request
Date: 2010-07-07 08:47:45
Message-ID: 4C343F31.2050402@dgfip.finances.gouv.fr
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: 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.













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(at)gmail(dot)com

Pour: JOUANIN Nicolas (44) nicolas(dot)jouanin(at)dgfip(dot)finances(dot)gouv(dot)fr

Copie à: pgsql-performance(at)postgresql(dot)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

Attachment Content-Type Size
schema.sql text/plain 4.7 KB

In response to

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Mark Kirkwood 2010-07-07 08:58:35 Re: [Slony1-general] WAL partition overloaded--by autovacuum?
Previous Message Yeb Havinga 2010-07-07 08:27:05 Re: Two different execution plan for the same request