Xrhrft

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

psql 10: Buffers: shared hit=4.439.193

psql 09: Buffers: shared hit=____7.493 read=686

https://www.postgresql.org/docs/11/sql-explain.html

Include information on buffer usage. Specifically, include the number of shared blocks hit, read, dirtied, and written, the number of
local blocks hit, read, dirtied, and written, and the number of temp
blocks read and written. A hit means that a read was avoided because
the block was found already in cache when needed. Shared blocks
contain data from regular tables and indexes; local blocks contain
data from temporary tables and indexes; while temp blocks contain
short-term working data used in sorts, hashes, Materialize plan nodes,
and similar cases. The number of blocks dirtied indicates the number
of previously unmodified blocks that were changed by this query; while
the number of blocks written indicates the number of
previously-dirtied blocks evicted from cache by this backend during
query processing. The number of blocks shown for an upper-level node
includes those used by all its child nodes. In text format, only
non-zero values are printed. This parameter may only be used when
ANALYZE is also enabled. It defaults to FALSE.

something is wrong with db
on the p09 there are ~8000 buffer involvements
on the p10 there are 4M buffer hits

if that is on the same dataset there must be a lot of empty/deleted row in the databes.

if that is the case then vacuum should help.

the execuption plans are quite different, the estimation of naumber of rows involved is different
updated statisc on specific columns may help

https://www.citusdata.com/blog/2018/03/06/postgres-planner-and-its-usage-of-statistics/

psql 09 plan does not have a separate sorting part.
maybe the indexes are not the same. psql 09 may already be getting the date in the right order ....

The default postgresql.conf configure is just for small footprint, it will be slow if your database is large and with complicated joins.

Saw from your postgresql10 configure file that your shared memory is only "128MB" (also many other settings are very small). You need to configure it.

Bug tuning the Postgresql is a big topic and different kind of hardwares would also need different settings, which also comes with trial and error to continuously improve it.

Not able to discuss here, I am just able to provide the "tuned setting" I used to use.
Target:
- Use not more than 4GB memory in my server (as my server is not dedicated to run Postgres db)
- Server have > 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