Postgresql – Postgres 9.0 vs Postgres 10 & 11 Performance

performancepostgresqlpostgresql-performance

We want to move our databases from webhosting provider (postgres 9.0) to our local network server (tried both postgres 10 and latest 11)
Our machine is windows server, fast XEON machine with 16gb ram, just for the database.

But even after raising default_statistics_targer = 4000 and analyzing for statistics we have trouble running a lot of views which worked very fast before.
Seems the webhosting provider server was fine tuned and our execution plans are probably odd for some reason.

Our Postgres is stock install config.

Simplified example query is bellow
(biggest table is "dale table which is several million records big (it's binding table with foreign keys)
other tables are much smaller, tenth thousands of records
(System is vacuum analyzed and it's fresh install)

EXPLAIN ANALYZE
SELECT REKLAMACNY_LIST.ID REKLAMACNY_LIST_ID
FROM REKLAMACNY_LIST
WHERE REKLAMACNY_LIST.VALIDTO IS NULL
  AND
    ( SELECT NOT tr.typ_odstupenia::boolean
     AND sr.konecny_stav::boolean
     FROM dale d1
     CROSS JOIN typ_reklamacie tr
     CROSS JOIN dale d2
     CROSS JOIN stav_reklamacie sr
     WHERE TRUE
       AND d1.fk7 = reklamacny_list.id
       AND d2.fk7 = reklamacny_list.id
       AND d1.fk1 = tr.id
       AND d2.fk3 = sr.id
       AND sr.validto IS NULL
       AND tr.validto IS NULL
       AND d1.validto IS NULL
       AND d2.validto IS NULL )
ORDER BY reklamacny_list_id DESC
LIMIT 100

Explain analyze for our testing postgres 11 server

"Limit  (cost=0.29..18432.84 rows=100 width=4) (actual time=11804.484..331036.595 rows=91 loops=1)"
"  ->  Index Scan Backward using reklamacny_list_pk on reklamacny_list  (cost=0.29..2578713.84 rows=13990 width=4) (actual time=11804.482..331036.524 rows=91 loops=1)"
"        Index Cond: (id > 0)"
"        Filter: ((validto IS NULL) AND (SubPlan 1))"
"        Rows Removed by Filter: 29199"
"        SubPlan 1"
"          ->  Hash Join  (cost=5.30..87.57 rows=250 width=1) (actual time=5.246..11.824 rows=1 loops=27981)"
"                Hash Cond: (d2.fk3 = sr.id)"
"                ->  Merge Join  (cost=1.85..80.76 rows=324 width=9) (actual time=5.222..11.806 rows=6 loops=27981)"
"                      Merge Cond: (d1.fk1 = tr.id)"
"                      ->  Nested Loop  (cost=0.71..25556.34 rows=324 width=8) (actual time=5.211..11.794 rows=6 loops=27981)"
"                            ->  Index Scan using dale_idx_fk1 on dale d1  (cost=0.29..25510.95 rows=18 width=4) (actual time=5.195..11.772 rows=1 loops=27981)"
"                                  Filter: (fk7 = reklamacny_list.id)"
"                                  Rows Removed by Filter: 28432"
"                            ->  Materialize  (cost=0.42..41.38 rows=18 width=4) (actual time=0.011..0.015 rows=6 loops=27890)"
"                                  ->  Index Scan using dale_fk7_idx on dale d2  (cost=0.42..41.29 rows=18 width=4) (actual time=0.007..0.010 rows=6 loops=27890)"
"                                        Index Cond: (fk7 = reklamacny_list.id)"
"                      ->  Sort  (cost=1.14..1.15 rows=6 width=9) (actual time=0.009..0.009 rows=1 loops=27890)"
"                            Sort Key: tr.id"
"                            Sort Method: quicksort  Memory: 25kB"
"                            ->  Seq Scan on typ_reklamacie tr  (cost=0.00..1.06 rows=6 width=9) (actual time=0.002..0.004 rows=6 loops=27890)"
"                                  Filter: (validto IS NULL)"
"                ->  Hash  (cost=2.74..2.74 rows=57 width=9) (actual time=0.046..0.047 rows=57 loops=1)"
"                      Buckets: 1024  Batches: 1  Memory Usage: 11kB"
"                      ->  Seq Scan on stav_reklamacie sr  (cost=0.00..2.74 rows=57 width=9) (actual time=0.012..0.030 rows=57 loops=1)"
"                            Filter: (validto IS NULL)"
"                            Rows Removed by Filter: 17"
"Planning Time: 10.174 ms"
"Execution Time: 331036.893 ms"

executions takes forever versus immediate result on our testing postgres 10.0

"Limit  (cost=0.29..163635.75 rows=100 width=4) (actual time=24.199..925.691 rows=70 loops=1)"
"  ->  Index Scan Backward using reklamacny_list_pk on reklamacny_list  (cost=0.29..21326610.37 rows=13033 width=4) (actual time=24.195..925.660 rows=70 loops=1)"
"        Index Cond: (id > 0)"
"        Filter: ((validto IS NULL) AND (SubPlan 1))"
"        Rows Removed by Filter: 27218"
"        SubPlan 1"
"          ->  Nested Loop  (cost=4.22..781.03 rows=1293 width=1) (actual time=0.018..0.034 rows=1 loops=26066)"
"                ->  Hash Join  (cost=3.80..377.12 rows=76 width=5) (actual time=0.005..0.005 rows=1 loops=26066)"
"                      Hash Cond: (d2.fk3 = sr.id)"
"                      ->  Index Scan using dale_fk7_idx on dale d2  (cost=0.42..372.47 rows=100 width=4) (actual time=0.002..0.004 rows=5 loops=26066)"
"                            Index Cond: (fk7 = reklamacny_list.id)"
"                      ->  Hash  (cost=2.71..2.71 rows=54 width=9) (actual time=0.049..0.049 rows=54 loops=1)"
"                            Buckets: 1024  Batches: 1  Memory Usage: 11kB"
"                            ->  Seq Scan on stav_reklamacie sr  (cost=0.00..2.71 rows=54 width=9) (actual time=0.016..0.032 rows=54 loops=1)"
"                                  Filter: (validto IS NULL)"
"                                  Rows Removed by Filter: 17"
"                ->  Materialize  (cost=0.42..374.87 rows=17 width=24) (actual time=0.013..0.027 rows=1 loops=25987)"
"                      ->  Nested Loop  (cost=0.42..374.78 rows=17 width=24) (actual time=0.010..0.024 rows=1 loops=25987)"
"                            Join Filter: (d1.fk1 = tr.id)"
"                            Rows Removed by Join Filter: 32"
"                            ->  Seq Scan on typ_reklamacie tr  (cost=0.00..1.06 rows=1 width=28) (actual time=0.001..0.002 rows=6 loops=25987)"
"                                  Filter: (validto IS NULL)"
"                            ->  Index Scan using dale_fk7_idx on dale d1  (cost=0.42..372.47 rows=100 width=4) (actual time=0.002..0.003 rows=5 loops=155922)"
"                                  Index Cond: (fk7 = reklamacny_list.id)"
"Planning time: 8.460 ms"
"Execution time: 925.870 ms"

This is just one example. But almost every query is simply many times slower on 11 and even things which takes forever also on 10, are immediately returned by web providers postgres 9.0 (which also hosts hundreds of different databases)

Do you have some point what might be the issue worth investigating?

Does adjusting some memory parameters can help? (Server has 16gb just for postgres and OS, there will be around 50 users connecting)
Actually raising default_statisticts_target=10000 helped a lot but even then.

A different version of the request with coalesce otherwise the same

EXPLAIN ANALYZE
SELECT REKLAMACNY_LIST.ID REKLAMACNY_LIST_ID
FROM REKLAMACNY_LIST
WHERE REKLAMACNY_LIST.VALIDTO IS NULL
  AND REKLAMACNY_LIST.ID > 0
  AND ((
          ( SELECT (NOT COALESCE(tr.typ_odstupenia, 'False')::boolean)
           AND COALESCE(sr.konecny_stav, 'False'):: boolean
           FROM dale d1
           CROSS JOIN typ_reklamacie tr
           CROSS JOIN dale d2
           CROSS JOIN stav_reklamacie sr
           WHERE TRUE
             AND d1.fk7 = reklamacny_list.id
             AND d2.fk7 = reklamacny_list.id
             AND d1.fk1 = tr.id
             AND d2.fk3 = sr.id
             AND sr.validto IS NULL
             AND tr.validto IS NULL
             AND d1.validto IS NULL
             AND d2.validto IS NULL )))
ORDER BY reklamacny_list_id DESC
LIMIT 100

On Postgres 11 it jumps to 10 seconds (great difference from the previous version of request without coalesce)

"Limit  (cost=0.29..18432.84 rows=100 width=4) (actual time=447.853..10695.583 rows=100 loops=1)"
"  ->  Index Scan Backward using reklamacny_list_pk on reklamacny_list  (cost=0.29..2578713.84 rows=13990 width=4) (actual time=447.851..10695.495 rows=100 loops=1)"
"        Index Cond: (id > 0)"
"        Filter: ((validto IS NULL) AND (SubPlan 1))"
"        Rows Removed by Filter: 687"
"        SubPlan 1"
"          ->  Hash Join  (cost=5.30..87.57 rows=250 width=1) (actual time=11.436..14.102 rows=1 loops=758)"
"                Hash Cond: (d2.fk3 = sr.id)"
"                ->  Merge Join  (cost=1.85..80.76 rows=324 width=9) (actual time=11.407..14.076 rows=5 loops=758)"
"                      Merge Cond: (d1.fk1 = tr.id)"
"                      ->  Nested Loop  (cost=0.71..25556.34 rows=324 width=8) (actual time=11.389..14.056 rows=5 loops=758)"
"                            ->  Index Scan using dale_idx_fk1 on dale d1  (cost=0.29..25510.95 rows=18 width=4) (actual time=11.361..14.023 rows=1 loops=758)"
"                                  Filter: (fk7 = reklamacny_list.id)"
"                                  Rows Removed by Filter: 28432"
"                            ->  Materialize  (cost=0.42..41.38 rows=18 width=4) (actual time=0.017..0.021 rows=5 loops=754)"
"                                  ->  Index Scan using dale_fk7_idx on dale d2  (cost=0.42..41.29 rows=18 width=4) (actual time=0.009..0.012 rows=5 loops=754)"
"                                        Index Cond: (fk7 = reklamacny_list.id)"
"                      ->  Sort  (cost=1.14..1.15 rows=6 width=9) (actual time=0.015..0.015 rows=2 loops=754)"
"                            Sort Key: tr.id"
"                            Sort Method: quicksort  Memory: 25kB"
"                            ->  Seq Scan on typ_reklamacie tr  (cost=0.00..1.06 rows=6 width=9) (actual time=0.003..0.006 rows=6 loops=754)"
"                                  Filter: (validto IS NULL)"
"                ->  Hash  (cost=2.74..2.74 rows=57 width=9) (actual time=0.092..0.092 rows=57 loops=1)"
"                      Buckets: 1024  Batches: 1  Memory Usage: 11kB"
"                      ->  Seq Scan on stav_reklamacie sr  (cost=0.00..2.74 rows=57 width=9) (actual time=0.032..0.068 rows=57 loops=1)"
"                            Filter: (validto IS NULL)"
"                            Rows Removed by Filter: 17"
"Planning Time: 1.556 ms"
"Execution Time: 10695.752 ms"

on

postgres 10

"Limit  (cost=0.29..163635.75 rows=100 width=4) (actual time=1.958..20.024 rows=100 loops=1)"
"  ->  Index Scan Backward using reklamacny_list_pk on reklamacny_list  (cost=0.29..21326610.37 rows=13033 width=4) (actual time=1.957..20.011 rows=100 loops=1)"
"        Index Cond: (id > 0)"
"        Filter: ((validto IS NULL) AND (SubPlan 1))"
"        Rows Removed by Filter: 572"
"        SubPlan 1"
"          ->  Nested Loop  (cost=4.22..781.03 rows=1293 width=1) (actual time=0.017..0.031 rows=1 loops=609)"
"                ->  Hash Join  (cost=3.80..377.12 rows=76 width=5) (actual time=0.004..0.004 rows=1 loops=609)"
"                      Hash Cond: (d2.fk3 = sr.id)"
"                      ->  Index Scan using dale_fk7_idx on dale d2  (cost=0.42..372.47 rows=100 width=4) (actual time=0.002..0.003 rows=5 loops=609)"
"                            Index Cond: (fk7 = reklamacny_list.id)"
"                      ->  Hash  (cost=2.71..2.71 rows=54 width=9) (actual time=0.037..0.037 rows=54 loops=1)"
"                            Buckets: 1024  Batches: 1  Memory Usage: 11kB"
"                            ->  Seq Scan on stav_reklamacie sr  (cost=0.00..2.71 rows=54 width=9) (actual time=0.009..0.023 rows=54 loops=1)"
"                                  Filter: (validto IS NULL)"
"                                  Rows Removed by Filter: 17"
"                ->  Materialize  (cost=0.42..374.87 rows=17 width=24) (actual time=0.013..0.025 rows=1 loops=604)"
"                      ->  Nested Loop  (cost=0.42..374.78 rows=17 width=24) (actual time=0.010..0.022 rows=1 loops=604)"
"                            Join Filter: (d1.fk1 = tr.id)"
"                            Rows Removed by Join Filter: 31"
"                            ->  Seq Scan on typ_reklamacie tr  (cost=0.00..1.06 rows=1 width=28) (actual time=0.001..0.002 rows=6 loops=604)"
"                                  Filter: (validto IS NULL)"
"                            ->  Index Scan using dale_fk7_idx on dale d1  (cost=0.42..372.47 rows=100 width=4) (actual time=0.002..0.003 rows=5 loops=3624)"
"                                  Index Cond: (fk7 = reklamacny_list.id)"
"Planning time: 1.418 ms"
"Execution time: 20.193 ms"

I am attaching full logs in zip file (including configuration postgres.conf).
It seems like raising default statistic target helps but only with very high values.
https://www.dropbox.com/s/7m3wy9nkapqitca/SpeedTest.zip?dl=0

Best Answer

The default postgresql.conf configuration is just for small footprint database and it will be slow if your database is large and is queried using complicated joins.

I saw from your postgresql10 configuration file that your shared memory is only set to 128MB (also many other settings are very small). You need to reconfigure this.

Tuning the PostgreSQL server is a big topic and different kinds of hardware would also need different settings, which also comes with trial and error while continuously improving the settings/configuration.

I am unable to discuss the whole topie here, I am just able to provide the tuned settings I used to use.

Target

  • Use no more than 4 GB memory in my server (as my server is not dedicated to run PostgreSQL DB)
  • Server has > 8 cores
max_connections : 800
shared_buffers : 1536MB
work_mem : 24MB
maintenance_work_mem : 480MB
vacuum_cost_delay : 20ms
synchronous_commit : local
wal_buffers : 8MB
max_wal_size : 1536GB
checkpoint_completion_target : 0.9
effective_cache_size : 4GB
deadlock_timeout : 3s
log_min_duration_statement : 5000
log_error_verbosity : verbose
log_autovacuum_min_duration : 10000
log_lock_waits : on