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.
Performances should be better on the pre-production but unfortunatelly this is not the case.
Below are the execution plan on development env and pre-production. As you can see
pre-production performance are poor, far slower than dev. env !
For information, enable_seqscan is turned off (some DBA advice).
Also I can get the same execution plan on both environment by turning off enable_mergejoin and
enable_hashjoin on the pre-production. Then execution matches and performances are much
better.
Could anyone help to guess why both servers don't have the same execution plans ? Can this be due
to hardware difference ?

Let me know if you need more detailed informations on these configurations.

Thanks.

Dev. environment :
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=3586307.73..3586341.94 rows=205 width=123) (actual
time=440.626..440.875 rows=1 loops=1)
-> Sort (cost=3586307.73..3586316.28 rows=3421 width=123) (actual
time=440.624..440.723 rows=187 loops=1)
Sort Key: constantestablenbienservice.code, constantestablenbienservice.id,
constantestablenbienservice.lib_code
Sort Method: quicksort Memory: 24kB
-> Nested Loop Left Join (cost=40.38..3586106.91 rows=3421 width=123) (actual
time=71.696..440.240 rows=187 loops=1)
Filter: (constantestablenbienservice.parent IS NULL)
-> Nested Loop Left Join (cost=40.38..3554085.80 rows=6842 width=4) (actual
time=66.576..433.797 rows=187 loops=1)
-> Nested Loop (cost=0.00..5041.46 rows=1246 width=25) (actual time=22.923..23.054
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=5.534..5.537 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..5020.68 rows=1246 width=50) (actual time=17.382..17.460 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=40.38..2836.96
rows=911 width=29) (actual time=13.511..13.677 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..40.15 rows=911 width=0)
(actual time=13.144..13.144 rows=6 loops=30)
Index Cond: ((constantestablebienservice.id_operation)::text =
(constantestableoperation.id_tech)::text)
-> Index Scan using n_bien_service_pkey on n_bien_service constantestablenbienservice
(cost=0.00..4.67 rows=1 width=127) (actual time=0.030..0.031 rows=1 loops=187)
Index Cond: (constantestablebienservice.bs_code = constantestablenbienservice.id)
Total runtime: 2.558 ms
(20 lignes)

Pre-production:
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=2679729.52..2679763.24 rows=205 width=123) (actual
time=740448.007..740448.269 rows=1 loops=1)
-> Sort (cost=2679729.52..2679737.95 rows=3372 width=123) (actual
time=740448.004..740448.111 rows=187 loops=1)
Sort Key: constantestablenbienservice.code, constantestablenbienservice.id,
constantestablenbienservice.lib_code
Sort Method: quicksort Memory: 24kB
-> Hash Left Join (cost=2315662.87..2679531.93 rows=3372 width=123) (actual
time=723479.640..740447.597 rows=187 loops=1)
Hash Cond: (constantestablebienservice.bs_code = constantestablenbienservice.id)
Filter: (constantestablenbienservice.parent IS NULL)
-> Hash Left Join (cost=2315640.98..2679417.33 rows=6743 width=4) (actual
time=723464.693..740432.218 rows=187 loops=1)
Hash Cond: ((constantestableoperation.id_tech)::text =
(constantestablebienservice.id_operation)::text)
-> Nested Loop (cost=39.49..4659.51 rows=1228 width=25) (actual time=0.131..0.309
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.047..0.050 rows=1 loops=1)
Index Cond: ((id_tech)::text = 'y+3eRapRQjW8mtL4wHd4/A=='::text)
-> Bitmap Heap Scan on t_operation constantestableoperation (cost=39.49..4638.90
rows=1228 width=50) (actual time=0.079..0.192 rows=30 loops=1)
Recheck Cond: ((constantestableoperation.id_demande)::text =
'y+3eRapRQjW8mtL4wHd4/A=='::text)
Filter: ((constantestableoperation.type_operation)::text = 'acq'::text)
-> Bitmap Index Scan on idx_operation_demande (cost=0.00..39.18 rows=1228 width=0)
(actual time=0.061..0.061 rows=30 loops=1)
Index Cond: ((constantestableoperation.id_demande)::text =
'y+3eRapRQjW8mtL4wHd4/A=='::text)
-> Hash (cost=1486192.10..1486192.10 rows=42894672 width=29) (actual
time=723119.538..723119.538 rows=42894671 loops=1)
-> Index Scan using idx_bien_service_code on t_bien_service constantestablebienservice
(cost=0.00..1486192.10 rows=42894672 width=29) (actual time=21.546..671603.500
rows=42894671 loops=1)
-> Hash (cost=19.33..19.33 rows=205 width=127) (actual time=14.706..14.706 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=10.262..14.401 rows=205 loops=1)
Total runtime: 740465.922 ms
(22 lignes)

Search Discussions

  • Yeb Havinga at Jul 7, 2010 at 8:26 am

    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
  • JOUANIN Nicolas (44) at Jul 7, 2010 at 8:46 am
    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@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
  • Yeb Havinga at Jul 7, 2010 at 8:58 am

    JOUANIN Nicolas (44) wrote:
    The strange thing is that this morning explain analyze now gives a
    much better duration :

    There were no modification made on the database except a restart
    yesterday evening and a vacuumdb --analyse ran at night.
    If the earlier bad query was run on a fresh imported database that was
    not ANALYZEd, it would explain the different and likely bad plan. If you
    want to know for sure this is the cause, instead of e.g. faulty
    hardware, you could verify redoing the import + query without analyze.

    regards,
    Yeb Havinga
  • Guillaume Smet at Jul 7, 2010 at 9:00 am
    Hi Nicolas,

    On Wed, Jul 7, 2010 at 10:47 AM, JOUANIN Nicolas (44)
    wrote:
    There were no modification made on the database except a restart yesterday evening and a vacuumdb --analyse ran at night.
    It's not really surprising considering you probably kept the
    default_statistics_target to 10 (it's the default in 8.3).

    Consider raising it to 100 in your postgresql.conf (100 is the default
    for newer versions), then reload, and run a new ANALYZE.

    You might need to set it higher on specific columns if you have a lot
    of data and your data distribution is weird.

    And, btw, please upgrade to the latest 8.3.x.

    HTH

    --
    Guillaume
  • JOUANIN Nicolas (44) at Jul 7, 2010 at 11:26 am
    It seems to work fine (same execution plan and less duration) after :
    - setting default_statistics_target to 100
    - full vacuum with analyze
    - reindexdb

    Thanks.

    -------- Message original --------
    Sujet : Re: [PERFORM] Two different execution plan for the same request
    De : Guillaume Smet <guillaume.smet@gmail.com>
    Pour : JOUANIN Nicolas (44) <nicolas.jouanin@dgfip.finances.gouv.fr>
    Copie à : Yeb Havinga <yebhavinga@gmail.com>, pgsql-performance@postgresql.org
    Date : 07/07/2010 10:59
    Hi Nicolas, On Wed, Jul 7, 2010 at 10:47 AM, JOUANIN Nicolas (44)
    wrote: There were no modification made on the
    database except a restart yesterday evening and a vacuumdb --analyse ran at night. It's not
    really surprising considering you probably kept the default_statistics_target to 10 (it's
    the default in 8.3). Consider raising it to 100 in your postgresql.conf (100 is the default for
    newer versions), then reload, and run a new ANALYZE. You might need to set it higher on specific
    columns if you have a lot of data and your data distribution is weird. And, btw, please upgrade
    to the latest 8.3.x. HTH
  • Matthew Wakeling at Jul 7, 2010 at 12:34 pm

    On Wed, 7 Jul 2010, JOUANIN Nicolas (44) wrote:
    It seems to work fine (same execution plan and less duration) after :
    - setting default_statistics_target to 100
    - full vacuum with analyze
    Don't do VACUUM FULL.

    Matthew

    --
    I suppose some of you have done a Continuous Maths course. Yes? Continuous
    Maths? <menacing stares from audience> Whoah, it was like that, was it!
    -- Computer Science Lecturer

Related Discussions

Discussion Navigation
viewthread | post
Discussion Overview
grouppgsql-performance @
categoriespostgresql
postedJul 7, '10 at 8:00a
activeJul 7, '10 at 12:34p
posts7
users4
websitepostgresql.org
irc#postgresql

People

Translate

site design / logo © 2022 Grokbase