Thread: Difference in execution plans pg12 vs pg14

Difference in execution plans pg12 vs pg14

From

Дмитрий Иванов

Date:

11 December 2021, 04:00:40

Afternoon. I was able to make the necessary changes to my base needed to migrate win_pg12 to debian pg14.
But there is a new problem, which was not there at the initial stage so I checked:

win_pg12:
-> Index Scan using index_class_tree_full on class c (cost=0.28..2.50 rows=1 width=235) (actual time=0.030..0.032 rows=1 loops=1)
Index Cond: (id = 650)
debian_pg14:
-> Index Scan using index_class_tree_full on class c (cost=0.28..2.50 rows=1 width=235) (actual time=842.795..842.796 rows=1 loops=1)
Index Cond: (id = 650)

I'm wondering where to dig next...

Best regards, Dmitry!

Attachment

Re: Difference in execution plans pg12 vs pg14

From

Adrian Klaver

Date:

11 December 2021, 04:13:28

On 12/10/21 17:00, Дмитрий Иванов wrote:
> Afternoon. I was able to make the necessary changes to my base needed to 
> migrate win_pg12 to debian pg14.
> But there is a new problem, which was not there at the initial stage so 
> I checked:
> 
> win_pg12:
> ->  Index Scan using index_class_tree_full on class c  (cost=0.28..2.50 
> rows=1 width=235) (actual time=0.030..0.032 rows=1 loops=1)
>                       Index Cond: (id = 650)
> debian_pg14:
> ->  Index Scan using index_class_tree_full on class c  (cost=0.28..2.50 
> rows=1 width=235) (actual time=842.795..842.796 rows=1 loops=1)
>                       Index Cond: (id = 650)
> 
> I'm wondering where to dig next...

Did you run ANALYZE(updates table stats) on the 14 instance after doing 
the upgrade?

> --
> Best regards, Dmitry!


-- 
Adrian Klaver
adrian.klaver@aklaver.com

Re: Difference in execution plans pg12 vs pg14

From

Дмитрий Иванов

Date:

11 December 2021, 04:51:55

Yes, I did.

I reset table statistics, did (VACUUM) ANALYZE, recreated index. Nothing changes.

I've deleted the database many times, dozens of times. Maybe something is broken?

Regards, Dmitry!

сб, 11 дек. 2021 г. в 06:13, Adrian Klaver <adrian.klaver@aklaver.com>:

On 12/10/21 17:00, Дмитрий Иванов wrote:
> Afternoon. I was able to make the necessary changes to my base needed to
> migrate win_pg12 to debian pg14.
> But there is a new problem, which was not there at the initial stage so
> I checked:
>
> win_pg12:
> -> Index Scan using index_class_tree_full on class c (cost=0.28..2.50
> rows=1 width=235) (actual time=0.030..0.032 rows=1 loops=1)
> Index Cond: (id = 650)
> debian_pg14:
> -> Index Scan using index_class_tree_full on class c (cost=0.28..2.50
> rows=1 width=235) (actual time=842.795..842.796 rows=1 loops=1)
> Index Cond: (id = 650)
>
> I'm wondering where to dig next...

Did you run ANALYZE(updates table stats) on the 14 instance after doing
the upgrade?

> --
> Best regards, Dmitry!

--
Adrian Klaver
adrian.klaver@aklaver.com

Re: Difference in execution plans pg12 vs pg14

From

Adrian Klaver

Date:

11 December 2021, 04:59:37

On 12/10/21 17:51, Дмитрий Иванов wrote:
> Yes, I did.
> I reset table statistics, did (VACUUM) ANALYZE, recreated index. Nothing 
> changes.
> I've deleted the database many times, dozens of times. Maybe something 
> is broken?

How did you do the upgrade?

> --
> Regards, Dmitry!
> 
> 
> сб, 11 дек. 2021 г. в 06:13, Adrian Klaver <adrian.klaver@aklaver.com 
> <mailto:adrian.klaver@aklaver.com>>:
> 
>     On 12/10/21 17:00, Дмитрий Иванов wrote:
>      > Afternoon. I was able to make the necessary changes to my base
>     needed to
>      > migrate win_pg12 to debian pg14.
>      > But there is a new problem, which was not there at the initial
>     stage so
>      > I checked:
>      >
>      > win_pg12:
>      > ->  Index Scan using index_class_tree_full on class c
>       (cost=0.28..2.50
>      > rows=1 width=235) (actual time=0.030..0.032 rows=1 loops=1)
>      >                       Index Cond: (id = 650)
>      > debian_pg14:
>      > ->  Index Scan using index_class_tree_full on class c
>       (cost=0.28..2.50
>      > rows=1 width=235) (actual time=842.795..842.796 rows=1 loops=1)
>      >                       Index Cond: (id = 650)
>      >
>      > I'm wondering where to dig next...
> 
>     Did you run ANALYZE(updates table stats) on the 14 instance after doing
>     the upgrade?
> 
>      > --
>      > Best regards, Dmitry!
> 
> 
>     -- 
>     Adrian Klaver
>     adrian.klaver@aklaver.com <mailto:adrian.klaver@aklaver.com>
> 


-- 
Adrian Klaver
adrian.klaver@aklaver.com

Re: Difference in execution plans pg12 vs pg14

From

Дмитрий Иванов

Date:

11 December 2021, 05:33:39

Yes, I did.

Step1

sudo /usr/lib/postgresql/14/bin/pg_dump --file "/home/dismay/uchet/Uchet.backup" --host "server" --port "5999" --username "back" --no-password --verbose --format=c --quote-all-identifiers --blobs --disable-triggers --encoding="UTF8" "Uchet"

Step2

Manual DROP/CREATE BASE from template 0 (We have to do this because of the difference in locales Win EDB 'Russian_Russia.1251' <> Debian 'ru_RU.UTF-8')

Step3

sudo /usr/lib/postgresql/14/bin/pg_restore --host "127.0.0.1" --port "5998" --username "back" --no-password --dbname "Uchet" --disable-triggers --format=c --verbose "/home/dismay/uchet/Uchet.backup" 2> "/home/dismay/uchet/uchet_all.log"

Regards, Dmitry!

сб, 11 дек. 2021 г. в 06:59, Adrian Klaver <adrian.klaver@aklaver.com>:

On 12/10/21 17:51, Дмитрий Иванов wrote:
> Yes, I did.
> I reset table statistics, did (VACUUM) ANALYZE, recreated index. Nothing
> changes.
> I've deleted the database many times, dozens of times. Maybe something
> is broken?

How did you do the upgrade?

> --
> Regards, Dmitry!
>
>
> сб, 11 дек. 2021 г. в 06:13, Adrian Klaver <adrian.klaver@aklaver.com
> <mailto:adrian.klaver@aklaver.com>>:
>
> On 12/10/21 17:00, Дмитрий Иванов wrote:
> > Afternoon. I was able to make the necessary changes to my base
> needed to
> > migrate win_pg12 to debian pg14.
> > But there is a new problem, which was not there at the initial
> stage so
> > I checked:
> >
> > win_pg12:
> > -> Index Scan using index_class_tree_full on class c
> (cost=0.28..2.50
> > rows=1 width=235) (actual time=0.030..0.032 rows=1 loops=1)
> > Index Cond: (id = 650)
> > debian_pg14:
> > -> Index Scan using index_class_tree_full on class c
> (cost=0.28..2.50
> > rows=1 width=235) (actual time=842.795..842.796 rows=1 loops=1)
> > Index Cond: (id = 650)
> >
> > I'm wondering where to dig next...
>
> Did you run ANALYZE(updates table stats) on the 14 instance after doing
> the upgrade?
>
> > --
> > Best regards, Dmitry!
>
>
> --
> Adrian Klaver
> adrian.klaver@aklaver.com <mailto:adrian.klaver@aklaver.com>
>

--
Adrian Klaver
adrian.klaver@aklaver.com

Re: Difference in execution plans pg12 vs pg14

From

Imre Samu

Date:

11 December 2021, 07:12:23

Hi Dmitry,

pg12:

> Execution Time: 44.123 ms

pg14:

> JIT:
> Functions: 167
> Options: Inlining true, Optimization true, Expressions true, Deforming true
> Timing: Generation 9.468 ms, Inlining 55.237 ms, Optimization 507.548 ms, Emission 347.932 ms, Total 920.185 ms
> Execution Time: 963.258 ms

please check the JIT settings ;

and test with: jit = off;

regards,

Imre

Дмитрий Иванов <firstdismay@gmail.com> ezt írta (időpont: 2021. dec. 11., Szo, 2:01):

Afternoon. I was able to make the necessary changes to my base needed to migrate win_pg12 to debian pg14.
But there is a new problem, which was not there at the initial stage so I checked:

win_pg12:
-> Index Scan using index_class_tree_full on class c (cost=0.28..2.50 rows=1 width=235) (actual time=0.030..0.032 rows=1 loops=1)
Index Cond: (id = 650)
debian_pg14:
-> Index Scan using index_class_tree_full on class c (cost=0.28..2.50 rows=1 width=235) (actual time=842.795..842.796 rows=1 loops=1)
Index Cond: (id = 650)

I'm wondering where to dig next...
--
Best regards, Dmitry!

Re: Difference in execution plans pg12 vs pg14

From

Дмитрий Иванов

Date:

11 December 2021, 12:32:01

Ok, I will check.

Now I have even more questions. This behavior appeared, it was not there in the first place. jit-compilation down my long aggregation queries by about half on average. How do I adjust this correctly?

#jit_provider = 'llvmjit' # JIT library to use

#jit_above_cost = 100000 # perform JIT compilation if available
# and query more expensive than this;
# -1 disables
#jit_inline_above_cost = 500000 # inline small functions if query is
# more expensive than this; -1 disables
#jit_optimize_above_cost = 500000 # use expensive JIT optimizations if
# query is more expensive than this;
# -1 disables
jit = off # allow JIT compilation

Regards, Dmitry!

сб, 11 дек. 2021 г. в 09:12, Imre Samu <pella.samu@gmail.com>:

Hi Dmitry,

pg12:
> Execution Time: 44.123 ms

pg14:
> JIT:
> Functions: 167
> Options: Inlining true, Optimization true, Expressions true, Deforming true
> Timing: Generation 9.468 ms, Inlining 55.237 ms, Optimization 507.548 ms, Emission 347.932 ms, Total 920.185 ms
> Execution Time: 963.258 ms

please check the JIT settings ;
and test with: jit = off;

regards,
Imre

Дмитрий Иванов <firstdismay@gmail.com> ezt írta (időpont: 2021. dec. 11., Szo, 2:01):
Afternoon. I was able to make the necessary changes to my base needed to migrate win_pg12 to debian pg14.
But there is a new problem, which was not there at the initial stage so I checked:

win_pg12:
-> Index Scan using index_class_tree_full on class c (cost=0.28..2.50 rows=1 width=235) (actual time=0.030..0.032 rows=1 loops=1)
Index Cond: (id = 650)
debian_pg14:
-> Index Scan using index_class_tree_full on class c (cost=0.28..2.50 rows=1 width=235) (actual time=842.795..842.796 rows=1 loops=1)
Index Cond: (id = 650)

I'm wondering where to dig next...
--
Best regards, Dmitry!

Attachment

exp_pg_14_jit_off.txt

Re: Difference in execution plans pg12 vs pg14

From

"Peter J. Holzer"

Date:

11 December 2021, 14:18:18

On 2021-12-11 06:00:40 +0500, Дмитрий Иванов wrote:
> Afternoon. I was able to make the necessary changes to my base needed to
> migrate win_pg12 to debian pg14.
> But there is a new problem, which was not there at the initial stage so I
> checked:
>
> win_pg12:
> ->  Index Scan using index_class_tree_full on class c  (cost=0.28..2.50 rows=1
> width=235) (actual time=0.030..0.032 rows=1 loops=1)
>                      Index Cond: (id = 650)
> debian_pg14:  
> ->  Index Scan using index_class_tree_full on class c  (cost=0.28..2.50 rows=1
> width=235) (actual time=842.795..842.796 rows=1 loops=1)
>                      Index Cond: (id = 650)

Is this repeatable or did it just occur once?

32 µs to retrieve a single row via index probably means that it was
already cached in RAM
842796 µs to retrieve a single row via index doesn't even look realistic
for a completely cold database on a slow rotating hard disk. If this
happened only once I suspect that something else interfered (maybe
another I/O intensive process, if this is on a VM maybe even on another
guest). If it is repeatable, something very weird is going on.

        hp

--
   _  | Peter J. Holzer    | Story must make more sense than reality.
|_|_) |                    |
| |   | hjp@hjp.at         |    -- Charles Stross, "Creative writing
__/   | http://www.hjp.at/ |       challenge!"

Attachment

signature.asc

Re: Difference in execution plans pg12 vs pg14

From

Дмитрий Иванов

Date:

11 December 2021, 15:56:16

Thanks to Imre Samu's help, I found out that this is an unwarranted interference of the JIT compilation. When it is disabled, the short queries work stably. Before the problem started, I purposely increased the amount of surrogate data to evaluate performance. Perhaps the logic for enabling JIT compilation is different in different versions of Postgres. It didn't show up as clearly on long queries because they were rewritten without JOIN VIEW and provide filtering before aggregation and linking. I want to make rougher JIT compiler settings (I think disabling it is fundamentally wrong) and rewrite all queries similar to long queries. Thanks.

Regards, Dmitry!

сб, 11 дек. 2021 г. в 16:18, Peter J. Holzer <hjp-pgsql@hjp.at>:

Is this repeatable or did it just occur once?

32 µs to retrieve a single row via index probably means that it was
already cached in RAM
842796 µs to retrieve a single row via index doesn't even look realistic
for a completely cold database on a slow rotating hard disk. If this
happened only once I suspect that something else interfered (maybe
another I/O intensive process, if this is on a VM maybe even on another
guest). If it is repeatable, something very weird is going on.

hp

--
_ | Peter J. Holzer | Story must make more sense than reality.
|_|_) | |
| | | hjp@hjp.at | -- Charles Stross, "Creative writing
__/ | http://www.hjp.at/ | challenge!"