Difference in execution plans pg12 vs pg14

Started by Дмитрий Ивановover 4 years ago9 messagesgeneral
Jump to latest
#1Дмитрий Иванов
firstdismay@gmail.com

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!

Attachments:

exp_pg14.txttext/plain; charset=US-ASCII; name=exp_pg14.txtDownload
exp_pg12.txttext/plain; charset=US-ASCII; name=exp_pg12.txtDownload
#2Adrian Klaver
adrian.klaver@aklaver.com
In reply to: Дмитрий Иванов (#1)
Re: Difference in execution plans pg12 vs pg14

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

#3Дмитрий Иванов
firstdismay@gmail.com
In reply to: Adrian Klaver (#2)
Re: Difference in execution plans pg12 vs pg14

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>:

Show quoted text

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

#4Adrian Klaver
adrian.klaver@aklaver.com
In reply to: Дмитрий Иванов (#3)
Re: Difference in execution plans pg12 vs pg14

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

#5Дмитрий Иванов
firstdismay@gmail.com
In reply to: Adrian Klaver (#4)
Re: Difference in execution plans pg12 vs pg14

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>:

Show quoted text

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

#6Imre Samu
pella.samu@gmail.com
In reply to: Дмитрий Иванов (#1)
Re: Difference in execution plans pg12 vs pg14

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):

Show quoted text

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!

#7Дмитрий Иванов
firstdismay@gmail.com
In reply to: Imre Samu (#6)
Re: Difference in execution plans pg12 vs pg14

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>:

Show quoted text

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!

Attachments:

exp_pg_14_jit_off.txttext/plain; charset=US-ASCII; name=exp_pg_14_jit_off.txtDownload
#8Peter J. Holzer
hjp-pgsql@hjp.at
In reply to: Дмитрий Иванов (#1)
Re: Difference in execution plans pg12 vs pg14

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!"

#9Дмитрий Иванов
firstdismay@gmail.com
In reply to: Peter J. Holzer (#8)
Re: Difference in execution plans pg12 vs pg14

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>:

Show quoted text

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!"